diff options
Diffstat (limited to 'cddl/contrib/dtracetoolkit/Examples/cputimes_example.txt')
| -rw-r--r-- | cddl/contrib/dtracetoolkit/Examples/cputimes_example.txt | 210 |
1 files changed, 210 insertions, 0 deletions
diff --git a/cddl/contrib/dtracetoolkit/Examples/cputimes_example.txt b/cddl/contrib/dtracetoolkit/Examples/cputimes_example.txt new file mode 100644 index 000000000000..253a7a34bd6e --- /dev/null +++ b/cddl/contrib/dtracetoolkit/Examples/cputimes_example.txt @@ -0,0 +1,210 @@ +The following demonstrates running the cputimes program on an idle system. +We use an interval of 1 second and a count of 3, + + # ./cputimes 1 3 + 2005 Apr 27 23:37:58, + THREADS TIME (ns) + KERNEL 10795499 + PROCESS 20941091 + IDLE 970707443 + 2005 Apr 27 23:37:59, + THREADS TIME (ns) + KERNEL 8919418 + PROCESS 77446789 + IDLE 910555040 + 2005 Apr 27 23:38:00, + THREADS TIME (ns) + KERNEL 8615123 + PROCESS 78314246 + IDLE 810100417 + +In the above output, we can see a breakdown of CPU time into the catagories +KERNEL, PROCESS and IDLE. The time is measured in nanoseconds. Most of the +time is in the IDLE category, as the system is idle. Very little time +was spent serving the kernel. + + + + +In the following example, several programs are run to hog the CPUs, + + # ./cputimes 1 3 + 2005 Apr 27 23:40:58, + THREADS TIME (ns) + KERNEL 11398807 + PROCESS 992254664 + 2005 Apr 27 23:40:59, + THREADS TIME (ns) + KERNEL 9205260 + PROCESS 987561182 + 2005 Apr 27 23:41:00, + THREADS TIME (ns) + KERNEL 9196669 + PROCESS 877850474 + +Now there is no IDLE category, as the system is 100% utilised. +The programs were the following, + + while :; do :; done & + +which keeps the CPU busy. + + + + +In the following example a different style of program is run to hog the CPUs, + + while :; do date; done + +This causes many processes to be created and destroyed in a hurry, and can +be difficult to troubleshoot (tools like prstat cannot sample quick enough +to easily identify what is going on). The following is the cputimes output, + + # ./cputimes 1 3 + 2005 Apr 27 23:45:30, + THREADS TIME (ns) + KERNEL 192647392 + PROCESS 835397568 + 2005 Apr 27 23:45:31, + THREADS TIME (ns) + KERNEL 168773713 + PROCESS 810825730 + 2005 Apr 27 23:45:32, + THREADS TIME (ns) + KERNEL 151676122 + PROCESS 728477272 + +Now the kernel is doing a substantial amount of work to create and destroy +these processes. + + + + +In the following example, a large amount of network activity occurs while +cputimes is running, + + # ./cputimes 1 6 + 2005 Apr 27 23:49:29, + THREADS TIME (ns) + KERNEL 10596399 + PROCESS 21793920 + IDLE 974395713 + 2005 Apr 27 23:49:30, + THREADS TIME (ns) + KERNEL 251465759 + IDLE 357436576 + PROCESS 508986422 + 2005 Apr 27 23:49:31, + THREADS TIME (ns) + IDLE 9758227 + KERNEL 367645318 + PROCESS 385427847 + 2005 Apr 27 23:49:32, + THREADS TIME (ns) + IDLE 28351679 + KERNEL 436022725 + PROCESS 451304688 + 2005 Apr 27 23:49:33, + THREADS TIME (ns) + KERNEL 262586158 + PROCESS 325238896 + IDLE 358243503 + 2005 Apr 27 23:49:34, + THREADS TIME (ns) + KERNEL 10075578 + PROCESS 238170506 + IDLE 647956998 + +Initially the system is idle. A command is run to cause heavy network +activity, which peaks during the fourth sample - during which the kernel +is using around 40% of the CPU. The Solaris 10 command "intrstat" can +help to analyse this activity further. + + + + +Longer samples are possible. The following is a 60 second sample, + + # ./cputimes 60 1 + 2005 Apr 27 23:53:02, + THREADS TIME (ns) + KERNEL 689808449 + PROCESS 8529562214 + IDLE 50406951876 + # + + + + +cputimes has a "-a" option to print all processes. The following is a +single 1 second sample with -a, + + # ./cputimes -a 1 1 + 2005 Apr 28 00:00:32, + THREADS TIME (ns) + svc.startd 51042 + nautilus 130645 + in.routed 131823 + fmd 152822 + nscd 307042 + dsdm 415799 + mixer_applet2 551066 + gnome-smproxy 587234 + xscreensaver 672270 + fsflush 1060196 + java_vm 1552988 + wnck-applet 2060870 + dtrace 2398658 + acroread 2614687 + soffice.bin 2825117 + mozilla-bin 5497488 + KERNEL 13541120 + metacity 28924204 + gnome-terminal 74304348 + Xorg 289631407 + IDLE 465054209 + +The times are in nanoseconds, and multiple processes with the same name +have their times aggregated. The above output is at an amazing resolution - +svc.startd ran for 51 microseconds, and soffice.bin ran for 28 milliseconds. + + + + +The following is a 10 second sample on an idle desktop, + + # ./cputimes -a 10 1 + 2005 Apr 28 00:03:57, + THREADS TIME (ns) + snmpd 127859 + fmd 171897 + inetd 177134 + svc.configd 185006 + mapping-daemon 197674 + miniserv.pl 305603 + gconfd-2 330511 + xscreensaver 443207 + sendmail 473434 + nautilus 506799 + gnome-vfs-daemon 549037 + gnome-panel 770631 + nscd 885353 + svc.startd 1181286 + gnome-netstatus- 4329671 + mixer_applet2 4833519 + dtrace 6244366 + in.routed 6556075 + fsflush 9553155 + soffice.bin 13954327 + java_vm 16285243 + acroread 32126193 + gnome-terminal 34891991 + Xorg 35553412 + mozilla-bin 67855629 + KERNEL 94834997 + IDLE 9540941846 + +Wow, maybe not as idle as I thought! + + + |