cputimes_example.txt [plain text]
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!