Here's a little DTrace script that uses the cstate_transition probe to
report how long we're spending in C1 before being awoken:
-------------8<-------------
#!/usr/sbin/dtrace -s
::cstate_transition
/arg1 != 0/
{
self->state = arg1;
self->state_start = timestamp;
}
::cstate_transition
/arg1 == 0 && self->state_start/
{
@a[curcpu->cpu_id, self->state] = lquantize((timestamp -
self->state_start)/1000, 0, 15000, 1000);
self->state_start = 0;
}
----------8<----------------
Running this on my laptop:
# ./cst.d
dtrace: script './cst.d' matched 4 probes
^C
1 1 <---- CPU 1
value ------------- Distribution ------------- count
< 0 | 0
0 |@@ 355
1000 | 68
2000 |@ 82
3000 | 64
4000 |@ 157
5000 |@ 115
6000 | 57
7000 |@ 78
8000 | 72
9000 |@@@@@@@@@@@@@@@@ 2324
10000 |@ 112
11000 | 21
12000 | 19
13000 | 32
14000 | 23
>= 15000 |@@@@@@@@@@@@@@@@ 2379
0 1 <---- CPU 0
value ------------- Distribution ------------- count
< 0 | 0
0 |@@@@@@@ 3904
1000 |@@@@@@ 3470
2000 |@@@@@ 2871
3000 |@@@@@ 2666
4000 |@@@@ 2570
5000 |@@@ 2032
6000 |@@@ 1793
7000 |@@@ 1522
8000 |@@ 1419
9000 |@@ 1042
10000 | 2
11000 | 0
Pretty much confirms where we are at. CPU0 (which handles the clock
interrupts)
is able to sleep no longer than 10000 USEC, thanks to the clock waking
up 100 times a sec.
CPU1 is able to stay asleep longer at times, but still seems to be
waking up to do stuff
at tick intervals (probably servicing various timers, etc).
Here's a simple one that uses the cpu_change_speed probe:
----------8<-------------
#!/usr/sbin/dtrace -s
::cpu_change_speed
{
printf("CPU %d changing speed to: %d", arg0, arg1);
}
----------8<-------------
# ./pst.d
dtrace: script './pst.d' matched 1 probe
CPU ID FUNCTION:NAME
0 68399 cpudrv_power:cpu_change_speed CPU 0 changing speed to: 2333
0 68399 cpudrv_power:cpu_change_speed CPU 1 changing speed to: 2333
1 68399 cpudrv_power:cpu_change_speed CPU 0 changing speed to: 2000
1 68399 cpudrv_power:cpu_change_speed CPU 1 changing speed to: 2000
0 68399 cpudrv_power:cpu_change_speed CPU 0 changing speed to: 1667
0 68399 cpudrv_power:cpu_change_speed CPU 1 changing speed to: 1667
0 68399 cpudrv_power:cpu_change_speed CPU 0 changing speed to: 1333
0 68399 cpudrv_power:cpu_change_speed CPU 1 changing speed to: 1333
0 68399 cpudrv_power:cpu_change_speed CPU 0 changing speed to: 1000
0 68399 cpudrv_power:cpu_change_speed CPU 1 changing speed to: 1000
^C
-Eric
