diff options
Diffstat (limited to 'Examples/procsystime_example.txt')
-rw-r--r-- | Examples/procsystime_example.txt | 149 |
1 files changed, 149 insertions, 0 deletions
diff --git a/Examples/procsystime_example.txt b/Examples/procsystime_example.txt new file mode 100644 index 000000000000..89f98bbca7dc --- /dev/null +++ b/Examples/procsystime_example.txt @@ -0,0 +1,149 @@ +This is a demonstration of the procsystime tool, which can give details +on how processes make use of system calls. + +Here we run procsystime on processes which have the name "bash", + + # procsystime -n bash + Tracing... Hit Ctrl-C to end... + ^C + + Elapsed Times for process bash, + + SYSCALL TIME (ns) + setpgrp 27768 + gtime 28692 + lwp_sigmask 148074 + write 235814 + sigaction 553556 + ioctl 776691 + read 857401243 + +By default procsystime prints elapsed times, the time from when the syscall +was issued to it's completion. In the above output, we can see the read() +syscall took the most time for this process - 8.57 seconds for all the +reads combined. This is because the read syscall is waiting for keystrokes. + + + +Here we try the "-o" option to print CPU overhead times on "bash", + + # procsystime -o -n bash + Tracing... Hit Ctrl-C to end... + ^C + + CPU Times for process bash, + + SYSCALL TIME (ns) + setpgrp 6994 + gtime 8054 + lwp_sigmask 33865 + read 154895 + sigaction 259899 + write 343825 + ioctl 932280 + +This identifies which syscall type from bash is consuming the most CPU time. +This is ioctl, at 932 microseconds. Compare this output to the default in +the first example - both are useful for different reasons, this CPU overhead +output helps us see why processes are consuming a lot of sys time. + + + +This demonstrates using the "-a" for all details, this time with "ssh", + + # procsystime -a -n ssh + Tracing... Hit Ctrl-C to end... + ^C + + Elapsed Times for processes ssh, + + SYSCALL TIME (ns) + read 115833 + write 302419 + pollsys 114616076 + TOTAL: 115034328 + + CPU Times for processes ssh, + + SYSCALL TIME (ns) + read 82381 + pollsys 201818 + write 280390 + TOTAL: 564589 + + Syscall Counts for processes ssh, + + SYSCALL COUNT + read 4 + write 4 + pollsys 8 + TOTAL: 16 + +Now we can see elapsed times, overhead times, and syscall counts in one +report. Very handy. We can also see totals printed as "TOTAL:". + + + +procsystime also lets us just examine one PID. For example, + + # procsystime -p 1304 + Tracing... Hit Ctrl-C to end... + ^C + + Elapsed Times for PID 1304, + + SYSCALL TIME (ns) + fcntl 7323 + fstat64 21349 + ioctl 190683 + read 238197 + write 1276169 + pollsys 1005360640 + + + +Here is a longer example of running procsystime on mozilla, + + # procsystime -a -n mozilla-bin + Tracing... Hit Ctrl-C to end... + ^C + + Elapsed Times for processes mozilla-bin, + + SYSCALL TIME (ns) + readv 677958 + writev 1159088 + yield 1298742 + read 18019194 + write 35679619 + ioctl 108845685 + lwp_park 38090969432 + pollsys 65955258781 + TOTAL: 104211908499 + + CPU Times for processes mozilla-bin, + + SYSCALL TIME (ns) + yield 120345 + readv 398046 + writev 1117178 + lwp_park 8591428 + read 9752315 + write 29043460 + ioctl 37089349 + pollsys 189933470 + TOTAL: 276045591 + + Syscall Counts for processes mozilla-bin, + + SYSCALL COUNT + writev 3 + yield 9 + readv 58 + lwp_park 280 + write 1317 + read 1744 + pollsys 8268 + ioctl 16434 + TOTAL: 28113 + |