cputimes_example.txt revision 1.1
1 The following demonstrates running the cputimes program on an idle system. 2 We use an interval of 1 second and a count of 3, 3 4 # ./cputimes 1 3 5 2005 Apr 27 23:37:58, 6 THREADS TIME (ns) 7 KERNEL 10795499 8 PROCESS 20941091 9 IDLE 970707443 10 2005 Apr 27 23:37:59, 11 THREADS TIME (ns) 12 KERNEL 8919418 13 PROCESS 77446789 14 IDLE 910555040 15 2005 Apr 27 23:38:00, 16 THREADS TIME (ns) 17 KERNEL 8615123 18 PROCESS 78314246 19 IDLE 810100417 20 21 In the above output, we can see a breakdown of CPU time into the catagories 22 KERNEL, PROCESS and IDLE. The time is measured in nanoseconds. Most of the 23 time is in the IDLE category, as the system is idle. Very little time 24 was spent serving the kernel. 25 26 27 28 29 In the following example, several programs are run to hog the CPUs, 30 31 # ./cputimes 1 3 32 2005 Apr 27 23:40:58, 33 THREADS TIME (ns) 34 KERNEL 11398807 35 PROCESS 992254664 36 2005 Apr 27 23:40:59, 37 THREADS TIME (ns) 38 KERNEL 9205260 39 PROCESS 987561182 40 2005 Apr 27 23:41:00, 41 THREADS TIME (ns) 42 KERNEL 9196669 43 PROCESS 877850474 44 45 Now there is no IDLE category, as the system is 100% utilised. 46 The programs were the following, 47 48 while :; do :; done & 49 50 which keeps the CPU busy. 51 52 53 54 55 In the following example a different style of program is run to hog the CPUs, 56 57 while :; do date; done 58 59 This causes many processes to be created and destroyed in a hurry, and can 60 be difficult to troubleshoot (tools like prstat cannot sample quick enough 61 to easily identify what is going on). The following is the cputimes output, 62 63 # ./cputimes 1 3 64 2005 Apr 27 23:45:30, 65 THREADS TIME (ns) 66 KERNEL 192647392 67 PROCESS 835397568 68 2005 Apr 27 23:45:31, 69 THREADS TIME (ns) 70 KERNEL 168773713 71 PROCESS 810825730 72 2005 Apr 27 23:45:32, 73 THREADS TIME (ns) 74 KERNEL 151676122 75 PROCESS 728477272 76 77 Now the kernel is doing a substantial amount of work to create and destroy 78 these processes. 79 80 81 82 83 In the following example, a large amount of network activity occurs while 84 cputimes is running, 85 86 # ./cputimes 1 6 87 2005 Apr 27 23:49:29, 88 THREADS TIME (ns) 89 KERNEL 10596399 90 PROCESS 21793920 91 IDLE 974395713 92 2005 Apr 27 23:49:30, 93 THREADS TIME (ns) 94 KERNEL 251465759 95 IDLE 357436576 96 PROCESS 508986422 97 2005 Apr 27 23:49:31, 98 THREADS TIME (ns) 99 IDLE 9758227 100 KERNEL 367645318 101 PROCESS 385427847 102 2005 Apr 27 23:49:32, 103 THREADS TIME (ns) 104 IDLE 28351679 105 KERNEL 436022725 106 PROCESS 451304688 107 2005 Apr 27 23:49:33, 108 THREADS TIME (ns) 109 KERNEL 262586158 110 PROCESS 325238896 111 IDLE 358243503 112 2005 Apr 27 23:49:34, 113 THREADS TIME (ns) 114 KERNEL 10075578 115 PROCESS 238170506 116 IDLE 647956998 117 118 Initially the system is idle. A command is run to cause heavy network 119 activity, which peaks during the fourth sample - during which the kernel 120 is using around 40% of the CPU. The Solaris 10 command "intrstat" can 121 help to analyse this activity further. 122 123 124 125 126 Longer samples are possible. The following is a 60 second sample, 127 128 # ./cputimes 60 1 129 2005 Apr 27 23:53:02, 130 THREADS TIME (ns) 131 KERNEL 689808449 132 PROCESS 8529562214 133 IDLE 50406951876 134 # 135 136 137 138 139 cputimes has a "-a" option to print all processes. The following is a 140 single 1 second sample with -a, 141 142 # ./cputimes -a 1 1 143 2005 Apr 28 00:00:32, 144 THREADS TIME (ns) 145 svc.startd 51042 146 nautilus 130645 147 in.routed 131823 148 fmd 152822 149 nscd 307042 150 dsdm 415799 151 mixer_applet2 551066 152 gnome-smproxy 587234 153 xscreensaver 672270 154 fsflush 1060196 155 java_vm 1552988 156 wnck-applet 2060870 157 dtrace 2398658 158 acroread 2614687 159 soffice.bin 2825117 160 mozilla-bin 5497488 161 KERNEL 13541120 162 metacity 28924204 163 gnome-terminal 74304348 164 Xorg 289631407 165 IDLE 465054209 166 167 The times are in nanoseconds, and multiple processes with the same name 168 have their times aggregated. The above output is at an amazing resolution - 169 svc.startd ran for 51 microseconds, and soffice.bin ran for 28 milliseconds. 170 171 172 173 174 The following is a 10 second sample on an idle desktop, 175 176 # ./cputimes -a 10 1 177 2005 Apr 28 00:03:57, 178 THREADS TIME (ns) 179 snmpd 127859 180 fmd 171897 181 inetd 177134 182 svc.configd 185006 183 mapping-daemon 197674 184 miniserv.pl 305603 185 gconfd-2 330511 186 xscreensaver 443207 187 sendmail 473434 188 nautilus 506799 189 gnome-vfs-daemon 549037 190 gnome-panel 770631 191 nscd 885353 192 svc.startd 1181286 193 gnome-netstatus- 4329671 194 mixer_applet2 4833519 195 dtrace 6244366 196 in.routed 6556075 197 fsflush 9553155 198 soffice.bin 13954327 199 java_vm 16285243 200 acroread 32126193 201 gnome-terminal 34891991 202 Xorg 35553412 203 mozilla-bin 67855629 204 KERNEL 94834997 205 IDLE 9540941846 206 207 Wow, maybe not as idle as I thought! 208 209 210 211
Indexes created Sat Apr 25 00:22:52 UTC 2026