1This is a demonstration of the procsystime tool, which can give details 2on how processes make use of system calls. 3 4Here we run procsystime on processes which have the name "bash", 5 6 # procsystime -n bash 7 Hit Ctrl-C to stop sampling... 8 ^C 9 10 Elapsed Times for process bash, 11 12 SYSCALL TIME (ns) 13 setpgrp 27768 14 gtime 28692 15 lwp_sigmask 148074 16 write 235814 17 sigaction 553556 18 ioctl 776691 19 read 857401243 20 21By default procsystime prints elapsed times, the time from when the syscall 22was issued to it's completion. In the above output, we can see the read() 23syscall took the most time for this process - 8.57 seconds for all the 24reads combined. This is because the read syscall is waiting for keystrokes. 25 26 27 28Here we try the "-o" option to print CPU overhead times on "bash", 29 30 # procsystime -o -n bash 31 Hit Ctrl-C to stop sampling... 32 ^C 33 34 CPU Times for process bash, 35 36 SYSCALL TIME (ns) 37 setpgrp 6994 38 gtime 8054 39 lwp_sigmask 33865 40 read 154895 41 sigaction 259899 42 write 343825 43 ioctl 932280 44 45This identifies which syscall type from bash is consuming the most CPU time. 46This is ioctl, at 932 microseconds. Compare this output to the default in 47the first example - both are useful for different reasons, this CPU overhead 48output helps us see why processes are consuming a lot of sys time. 49 50 51 52This demonstrates using the "-a" for all details, this time with "ssh", 53 54 # procsystime -a -n ssh 55 Hit Ctrl-C to stop sampling... 56 ^C 57 58 Elapsed Times for processes ssh, 59 60 SYSCALL TIME (ns) 61 read 115833 62 write 302419 63 pollsys 114616076 64 TOTAL: 115034328 65 66 CPU Times for processes ssh, 67 68 SYSCALL TIME (ns) 69 read 82381 70 pollsys 201818 71 write 280390 72 TOTAL: 564589 73 74 Syscall Counts for processes ssh, 75 76 SYSCALL COUNT 77 read 4 78 write 4 79 pollsys 8 80 TOTAL: 16 81 82Now we can see elapsed times, overhead times, and syscall counts in one 83report. Very handy. We can also see totals printed as "TOTAL:". 84 85 86 87procsystime also lets us just examine one PID. For example, 88 89 # procsystime -p 1304 90 Hit Ctrl-C to stop sampling... 91 ^C 92 93 Elapsed Times for PID 1304, 94 95 SYSCALL TIME (ns) 96 fcntl 7323 97 fstat64 21349 98 ioctl 190683 99 read 238197 100 write 1276169 101 pollsys 1005360640 102 103 104 105Here is a longer example of running procsystime on mozilla, 106 107 # procsystime -a -n mozilla-bin 108 Hit Ctrl-C to stop sampling... 109 ^C 110 111 Elapsed Times for processes mozilla-bin, 112 113 SYSCALL TIME (ns) 114 readv 677958 115 writev 1159088 116 yield 1298742 117 read 18019194 118 write 35679619 119 ioctl 108845685 120 lwp_park 38090969432 121 pollsys 65955258781 122 TOTAL: 104211908499 123 124 CPU Times for processes mozilla-bin, 125 126 SYSCALL TIME (ns) 127 yield 120345 128 readv 398046 129 writev 1117178 130 lwp_park 8591428 131 read 9752315 132 write 29043460 133 ioctl 37089349 134 pollsys 189933470 135 TOTAL: 276045591 136 137 Syscall Counts for processes mozilla-bin, 138 139 SYSCALL COUNT 140 writev 3 141 yield 9 142 readv 58 143 lwp_park 280 144 write 1317 145 read 1744 146 pollsys 8268 147 ioctl 16434 148 TOTAL: 28113 149 150 151 152