Doug Smythies 2012.05.04 CPU's enter and exit idle at high frequencies. but with very very low actual utilization. The majority of previous testing was very high utilization. Excerpt from "Top" top - 11:57:04 up 1 day, 15:28, 3 users, load average: 0.91, 0.87, 0.76 Tasks: 144 total, 2 running, 142 sleeping, 0 stopped, 0 zombie Cpu0 : 0.9%us, 8.8%sy, 0.0%ni, 90.2%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu1 : 1.0%us, 4.8%sy, 0.0%ni, 94.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu2 : 0.0%us, 0.0%sy, 0.0%ni,100.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu3 : 0.3%us, 0.3%sy, 0.0%ni, 99.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu4 : 0.7%us, 0.0%sy, 0.0%ni, 99.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu5 : 0.0%us, 0.0%sy, 0.0%ni,100.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu6 : 0.3%us, 2.6%sy, 0.0%ni, 97.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu7 : 0.3%us, 0.3%sy, 0.0%ni, 99.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Mem: 7956400k total, 1591044k used, 6365356k free, 292288k buffers Swap: 8294396k total, 0k used, 8294396k free, 882488k cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 15970 doug 20 0 4156 88 0 S 2 0.0 0:23.23 waiter 15972 doug 20 0 4156 88 0 S 2 0.0 0:23.24 waiter 15968 doug 20 0 4156 88 0 S 2 0.0 0:23.30 waiter 15971 doug 20 0 4156 88 0 S 2 0.0 0:23.36 waiter 15969 doug 20 0 4156 88 0 S 1 0.0 0:23.51 waiter 15986 doug 20 0 17332 1332 960 R 1 0.0 0:01.24 top 1 root 20 0 24724 2616 1344 S 0 0.0 0:01.42 init Similar excerpt from test program output. Note: TOP resource time = user cpu + sys cpu times. Child 0 lp 706 of 9999: Elapsed:1411.97 s. Delta: 2.00 s. user cpu: 5.03 s. sys cpu: 18.46 s. last sleep freq.: 250.000 Hz. average sleep freq.: 250.005 Hz. Child 1 lp 706 of 9999: Elapsed:1411.98 s. Delta: 2.00 s. user cpu: 5.38 s. sys cpu: 18.31 s. last sleep freq.: 250.000 Hz. average sleep freq.: 250.004 Hz. Child 2 lp 706 of 9999: Elapsed:1411.97 s. Delta: 2.00 s. user cpu: 5.02 s. sys cpu: 18.39 s. last sleep freq.: 250.000 Hz. average sleep freq.: 250.005 Hz. Child 3 lp 706 of 9999: Elapsed:1411.97 s. Delta: 2.00 s. user cpu: 5.23 s. sys cpu: 18.35 s. last sleep freq.: 250.000 Hz. average sleep freq.: 250.005 Hz. Child 4 lp 706 of 9999: Elapsed:1411.97 s. Delta: 2.00 s. user cpu: 5.25 s. sys cpu: 18.22 s. last sleep freq.: 250.000 Hz. average sleep freq.: 250.005 Hz. Child 0 lp 707 of 9999: Elapsed:1413.97 s. Delta: 2.00 s. user cpu: 5.04 s. sys cpu: 18.47 s. last sleep freq.: 250.000 Hz. average sleep freq.: 250.005 Hz. Child 1 lp 707 of 9999: Elapsed:1413.98 s. Delta: 2.00 s. user cpu: 5.39 s. sys cpu: 18.34 s. last sleep freq.: 250.000 Hz. average sleep freq.: 250.004 Hz. Child 2 lp 707 of 9999: Elapsed:1413.97 s. Delta: 2.00 s. user cpu: 5.02 s. sys cpu: 18.41 s. last sleep freq.: 250.000 Hz. average sleep freq.: 250.005 Hz. Child 3 lp 707 of 9999: Elapsed:1413.97 s. Delta: 2.00 s. user cpu: 5.24 s. sys cpu: 18.38 s. last sleep freq.: 250.000 Hz. average sleep freq.: 250.005 Hz. Child 4 lp 707 of 9999: Elapsed:1413.97 s. Delta: 2.00 s. user cpu: 5.26 s. sys cpu: 18.24 s. last sleep freq.: 250.000 Hz. average sleep freq.: 250.005 Hz. Resource math: ~23.5 seconds / 1414 seconds * 5 occurances ~~= 0.08 real load average. Similar output from vmstat (but it was running at a different time than above): (While I have a relatively high context switch rate and interrupt rate in this example, the issue exists over a wide range) doug@s15:~/c$ vmstat -n 10 10 procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu---- r b swpd free buff cache si so bi bo in cs us sy id wa 1 0 0 6366016 292320 882488 0 0 1 1 7 12 0 0 100 0 0 0 0 6366008 292320 882488 0 0 0 0 1319 2693 1 2 98 0 0 0 0 6366008 292320 882488 0 0 0 0 1270 2541 0 0 100 0 0 0 0 6366008 292324 882488 0 0 0 1 1268 2542 0 0 100 0 0 0 0 6366008 292324 882488 0 0 0 0 1313 2678 1 1 98 0 0 0 0 6366008 292324 882488 0 0 0 0 1306 2677 0 1 98 0 0 0 0 6366008 292324 882488 0 0 0 0 1339 2773 0 3 97 0 0 0 0 6366008 292324 882488 0 0 0 0 1347 2828 0 3 96 0 0 0 0 6366008 292324 882488 0 0 0 0 1324 2721 0 2 98 0 0 0 0 6366008 292328 882488 0 0 0 1 1341 2811 0 3 97 0