Project

General

Profile

Bug #423

speedstep cpupm called continuously on Dell Poweredge 2900

Added by Dormition Skete over 8 years ago. Updated almost 8 years ago.

Status:
New
Priority:
Normal
Assignee:
-
Category:
kernel
Start date:
2010-11-18
Due date:
% Done:

0%

Estimated time:
Difficulty:
Medium
Tags:
cpupm, speedstep, power

Description

We have a Dell PowerEdge 2900 with two 80555K, Xenon Dempsey, 5050, LGA771, C1 Processors, giving us a total of eight processing cores.

On a clean install of OpenIndiana Build 147, OpenSolaris 2009-06, and Illumos 3.0 - it does it on all of them - our processor loads average a 20% load when cpupm is enabled with the default interval of 15 seconds.

When we disable cpupm in the /etc/power.conf file, the load drops to less than 1%, as it should be.

A very nice man on the OpenIndiana list identified the problem from the below dtrace.

well it is a wild guess, because your system seems to change step very

oftten... if I read your dtrace correctly...

Is there any way to fix this?

Does this have any chance of getting fixed with the state OpenSolaris / Illumos is in right now?

dtrace -n 'profile-10ms{@[stack()] = count()}'

genunix`timeout_generic+0x41
genunix`timeout+0x5b
uhci`uhci_root_hub_allocate_intr_pipe_resource+0x97
uhci`uhci_handle_root_hub_status_change+0x153
genunix`callout_list_expire+0x77
genunix`callout_expire+0x31
genunix`callout_execute+0x1e
genunix`taskq_thread+0x248
unix`thread_start+0x8
1
unix`splr+0x92
unix`lock_set_spl+0x1d
genunix`disp_lock_enter+0x2e
unix`disp+0xad
unix`swtch+0xa4
genunix`cv_timedwait_hires+0xe0
genunix`cv_reltimedwait+0x4f
stmf`stmf_svc+0x423
genunix`taskq_thread+0x248
unix`thread_start+0x8
1
unix`disp_anywork+0xc4
unix`cpu_idle_mwait+0x7d
unix`idle+0x114
unix`thread_start+0x8
1
unix`pg_ev_thread_swtch+0x124
unix`swtch+0xdb
genunix`cv_wait+0x61
genunix`taskq_thread_wait+0x84
genunix`taskq_thread+0x2d1
unix`thread_start+0x8
1
unix`av_check_softint_pending+0x24
unix`av_dispatch_softvect+0x48
unix`dispatch_softint+0x34
unix`switch_sp_and_call+0x13
1
dtrace`dtrace_state_clean+0xc
genunix`cyclic_softint+0xdc
unix`cbe_low_level+0x17
unix`av_dispatch_softvect+0x5f
unix`dispatch_softint+0x34
unix`switch_sp_and_call+0x13
1
genunix`callout_list_expire+0xce
genunix`callout_expire+0x31
genunix`callout_execute+0x1e
genunix`taskq_thread+0x248
unix`thread_start+0x8
1
unix`mutex_enter
genunix`cyclic_softint+0xdc
unix`cbe_softclock+0x1a
unix`av_dispatch_softvect+0x5f
unix`dispatch_softint+0x34
unix`switch_sp_and_call+0x13
1
ata`ghd_timeout
genunix`callout_expire+0x31
genunix`callout_execute+0x1e
genunix`taskq_thread+0x248
unix`thread_start+0x8
1
unix`todpc_rtcget+0xa0
unix`todpc_get+0x1c
unix`tod_get+0x14
genunix`clock+0x6a9
genunix`cyclic_softint+0xdc
unix`cbe_softclock+0x1a
unix`av_dispatch_softvect+0x5f
unix`dispatch_softint+0x34
unix`switch_sp_and_call+0x13
1
unix`i86_monitor+0x1
unix`idle+0x114
unix`thread_start+0x8
1
dtrace`dtrace_state_clean+0x17
genunix`cyclic_softint+0xdc
unix`cbe_low_level+0x17
unix`av_dispatch_softvect+0x5f
unix`dispatch_softint+0x34
unix`switch_sp_and_call+0x13
1
genunix`timeout_generic+0x53
genunix`timeout+0x5b
ata`ghd_timeout+0xc8
genunix`callout_list_expire+0x77
genunix`callout_expire+0x31
genunix`callout_execute+0x1e
genunix`taskq_thread+0x248
unix`thread_start+0x8
1
unix`disp_anywork+0xd7
unix`idle+0x114
unix`thread_start+0x8
1
unix`mutex_enter+0x10
genunix`taskq_thread_wait+0x84
genunix`taskq_thread+0x2d1
unix`thread_start+0x8
2
unix`mutex_enter+0x10
genunix`taskq_thread+0x248
unix`thread_start+0x8
2
genunix`fsflush_do_pages+0x124
genunix`fsflush+0x39a
unix`thread_start+0x8
2
unix`mutex_exit
unix`av_dispatch_softvect+0x5f
unix`dispatch_softint+0x34
unix`switch_sp_and_call+0x13
2
unix`disp_getwork+0xa2
unix`idle+0x9d
unix`thread_start+0x8
2
unix`disp_getwork+0xb9
unix`idle+0x9d
unix`thread_start+0x8
2
unix`tsc_read+0xa
genunix`gethrtime_unscaled+0xd
unix`idle_enter+0x1b
unix`idle+0xc9
unix`thread_start+0x8
2
unix`todpc_rtcget+0xda
unix`todpc_get+0x1c
unix`tod_get+0x14
genunix`clock+0x6a9
genunix`cyclic_softint+0xdc
unix`cbe_softclock+0x1a
unix`av_dispatch_softvect+0x5f
unix`dispatch_softint+0x34
unix`switch_sp_and_call+0x13
2
unix`tsc_read+0xc
genunix`gethrtime_unscaled+0xd
unix`idle_enter+0x1b
unix`idle+0xc9
unix`thread_start+0x8
2
unix`disp_anywork+0xd
unix`cpu_idle_mwait+0x7d
unix`idle+0x114
unix`thread_start+0x8
2
unix`do_splx+0x8d
genunix`disp_lock_exit_nopreempt+0x43
genunix`cv_wait+0x54
genunix`taskq_thread_wait+0x84
genunix`taskq_thread+0x2d1
unix`thread_start+0x8
2
unix`cpu_idle_exit+0x116
unix`cpu_idle_mwait+0xfb
unix`idle+0x114
unix`thread_start+0x8
2
unix`disp_getwork+0xdf
unix`idle+0x9d
unix`thread_start+0x8
2
genunix`taskq_thread_wait+0x87
genunix`taskq_thread+0x2d1
unix`thread_start+0x8
2
unix`cpu_idle_exit+0x33
unix`cpu_idle_mwait+0xfb
unix`idle+0x114
unix`thread_start+0x8
2
unix`bitset_atomic_del
unix`idle+0x114
unix`thread_start+0x8
2
unix`atomic_and_64+0x4
unix`av_dispatch_softvect+0x55
unix`dispatch_softint+0x34
unix`switch_sp_and_call+0x13
2
unix`disp_getwork+0x12a
unix`idle+0x9d
unix`thread_start+0x8
2
unix`disp_getwork+0x131
unix`idle+0x9d
unix`thread_start+0x8
2
dtrace`dtrace_dynvar_clean+0xd9
dtrace`dtrace_state_clean+0x23
genunix`cyclic_softint+0xdc
unix`cbe_low_level+0x17
unix`av_dispatch_softvect+0x5f
unix`dispatch_softint+0x34
unix`switch_sp_and_call+0x13
2
unix`_resume_from_idle+0xb
2
unix`disp_anywork+0xc2
unix`cpu_idle_mwait+0x7d
unix`idle+0x114
unix`thread_start+0x8
2
unix`splr+0x92
unix`disp+0x1dd
unix`swtch+0xa4
genunix`cv_wait+0x61
genunix`taskq_thread_wait+0x84
genunix`taskq_thread+0x2d1
unix`thread_start+0x8
2
unix`atomic_add_32+0x3
unix`pg_ev_thread_swtch+0xa3
unix`swtch+0xdb
unix`idle+0xc4
unix`thread_start+0x8
2
unix`cpu_idle_mwait+0x5c
unix`idle+0x114
unix`thread_start+0x8
2
unix`idle+0x55
unix`thread_start+0x8
2
unix`scan_memory+0xc
unix`thread_start+0x8
3
unix`disp_getwork+0xb6
unix`disp+0x1c2
unix`swtch+0xa4
genunix`cv_wait+0x61
genunix`taskq_thread_wait+0x84
genunix`taskq_thread+0x2d1
unix`thread_start+0x8
3
unix`idle+0x80
unix`thread_start+0x8
3
unix`cpu_idle_mwait
unix`thread_start+0x8
3
unix`disp_anywork+0x9f
unix`cpu_idle_mwait+0x7d
unix`idle+0x114
unix`thread_start+0x8
3
4
unix`idle+0x84
unix`thread_start+0x8
4
unix`disp_getwork+0x142
unix`idle+0x9d
unix`thread_start+0x8
4
unix`cpu_idle_enter+0x5f
unix`cpu_idle_mwait+0xdc
unix`idle+0x114
unix`thread_start+0x8
4
unix`i86_mwait+0xe
unix`idle+0x114
unix`thread_start+0x8
5
unix`outw+0x8
unix`cpu_acpi_write_port+0x1e
unix`write_ctrl+0x32
unix`speedstep_pstate_transition+0x52
unix`speedstep_power+0x5f
unix`cpupm_state_change+0x100
unix`cpupm_plat_change_state+0x3f
unix`cpupm_change_state+0x2a
unix`cpupm_utilization_event+0x238
unix`cmt_ev_thread_swtch_pwr+0x97
unix`pg_ev_thread_swtch+0xd9
unix`swtch+0xdb
genunix`cv_timedwait_hires+0xe0
genunix`cv_reltimedwait+0x4f
stmf`stmf_svc+0x423
genunix`taskq_thread+0x248
unix`thread_start+0x8
5
unix`disp_anywork+0x52
unix`cpu_idle_mwait+0x7d
unix`idle+0x114
unix`thread_start+0x8
6
unix`bitset_atomic_add+0x39
unix`cpu_idle_mwait+0x78
unix`idle+0x114
unix`thread_start+0x8
6
unix`disp_anywork+0xb4
unix`cpu_idle_mwait+0x7d
unix`idle+0x114
unix`thread_start+0x8
6
unix`bitset_atomic_del+0x3d
unix`cpu_idle_mwait+0x120
unix`idle+0x114
unix`thread_start+0x8
7
unix`cpu_idle_mwait+0x3e
unix`idle+0x114
unix`thread_start+0x8
7
unix`outw+0x8
unix`cpu_acpi_write_port+0x1e
unix`write_ctrl+0x32
unix`speedstep_pstate_transition+0x52
unix`speedstep_power+0x5f
unix`cpupm_state_change+0x100
unix`cpupm_plat_change_state+0x3f
unix`cpupm_change_state+0x2a
unix`cpupm_utilization_event+0x238
unix`cmt_ev_thread_swtch_pwr+0xc0
unix`pg_ev_thread_swtch+0xd9
unix`swtch+0xdb
unix`idle+0xc4
unix`thread_start+0x8
7
unix`cpu_idle_mwait+0x108
unix`idle+0x114
unix`thread_start+0x8
9
unix`disp_getwork+0x139
unix`idle+0x9d
unix`thread_start+0x8
18
unix`dispatch_softint+0x27
unix`switch_sp_and_call+0x13
19
unix`cpu_idle_mwait+0xc1
unix`idle+0x114
unix`thread_start+0x8
35
unix`atomic_and_64+0x4
unix`cpu_idle_mwait+0x120
unix`idle+0x114
unix`thread_start+0x8
40
unix`atomic_or_64+0x4
unix`cpu_idle_mwait+0x78
unix`idle+0x114
unix`thread_start+0x8
44
unix`disp_getwork+0xb6
unix`idle+0x9d
unix`thread_start+0x8
53
unix`i86_monitor+0x10
unix`cpu_idle_mwait+0xbe
unix`idle+0x114
unix`thread_start+0x8
55
unix`outw+0x8
unix`cpu_acpi_write_port+0x1e
unix`write_ctrl+0x32
unix`speedstep_pstate_transition+0x52
unix`speedstep_power+0x5f
unix`cpupm_state_change+0x100
unix`cpupm_plat_change_state+0x3f
unix`cpupm_change_state+0x2a
unix`cpupm_utilization_event+0x238
unix`cmt_ev_thread_swtch_pwr+0x97
unix`pg_ev_thread_swtch+0xd9
unix`swtch+0xdb
genunix`cv_wait+0x61
genunix`taskq_thread_wait+0x84
genunix`taskq_thread+0x2d1
unix`thread_start+0x8
55
unix`do_splx+0x8d
unix`xc_common+0x231
unix`xc_call+0x46
unix`speedstep_power+0xb3
unix`cpupm_state_change+0x100
unix`cpupm_plat_change_state+0x3f
unix`cpupm_change_state+0x2a
unix`cpupm_utilization_event+0x238
unix`cmt_ev_thread_swtch_pwr+0xc0
unix`pg_ev_thread_swtch+0xd9
unix`swtch+0xdb
unix`idle+0xc4
unix`thread_start+0x8
60
unix`cpu_idle_exit+0x1fc
unix`cpu_idle_mwait+0xfb
unix`idle+0x114
unix`thread_start+0x8
78
unix`do_splx+0x8d
unix`xc_common+0x231
unix`xc_call+0x46
unix`speedstep_power+0xb3
unix`cpupm_state_change+0x100
unix`cpupm_plat_change_state+0x3f
unix`cpupm_change_state+0x2a
unix`cpupm_utilization_event+0x238
unix`cmt_ev_thread_swtch_pwr+0x97
unix`pg_ev_thread_swtch+0xd9
unix`swtch+0xdb
genunix`cv_timedwait_hires+0xe0
genunix`cv_reltimedwait+0x4f
stmf`stmf_svc+0x423
genunix`taskq_thread+0x248
unix`thread_start+0x8
90
unix`do_splx+0x8d
unix`xc_common+0x231
unix`xc_call+0x46
unix`speedstep_power+0xb3
unix`cpupm_state_change+0x100
unix`cpupm_plat_change_state+0x3f
unix`cpupm_change_state+0x2a
unix`cpupm_utilization_event+0x238
unix`cmt_ev_thread_swtch_pwr+0x97
unix`pg_ev_thread_swtch+0xd9
unix`swtch+0xdb
genunix`cv_wait+0x61
genunix`taskq_thread_wait+0x84
genunix`taskq_thread+0x2d1
unix`thread_start+0x8
94
unix`cpu_idle_enter+0x109
unix`cpu_idle_mwait+0xdc
unix`idle+0x114
unix`thread_start+0x8
154
unix`i86_mwait+0xd
unix`cpu_idle_mwait+0xf1
unix`idle+0x114
unix`thread_start+0x8
2731

History

#1

Updated by Albert Lee over 8 years ago

High CPU usage for CPU power management is caused by awful BIOSes telling the system to use I/O ports to request frequency transitions. Some additional info and DTrace scripts are at https://defect.opensolaris.org/bz/show_bug.cgi?id=12799

The default PM governor is event-driven. This more efficient if transitions are cheap (such as a MSR write), but produces a high rate of transitions which is pathological when transitions are expensive. You can switch back to the older, polling governor using:

cpupm enable poll-mode

in power.conf

This is a common enough problem I think the system should be updated to default to poll mode when it's using an I/O port for transitions.

#2

Updated by Albert Lee over 8 years ago

  • Project changed from OpenIndiana Distribution to illumos gate
#3

Updated by Dormition Skete over 8 years ago

Thank you very much. It seems to work fine in poll-mode. I greatly appreciate your help.

#4

Updated by Jon Strabala about 8 years ago

  • Status changed from New to Feedback
  • Difficulty set to Medium
  • Tags set to needs-triage

OpenIndiana (illumos based) is working pretty darn good, after a full month of testing on oi_148b the only remaining issue I had was that the kernel was using 6% of the CPU (50% of a single hyperthreaded core) doing absolutely nothing for no particular reason and every time I tried to 'dtrace' the issue the machine did a hard lockup (if and only if I tried to use 'kernel' dtrace functions).

The issue was so bad on my system any kernel level use of 'dtrace' would 
lock up the system !, So my very new motherboard has an awful BIOS - 
so bad that with a bad PM settign any real use of 'dtrace' required either 
a IPMI hard power cycle or a manual power cycle! (FYI making it quite
hard to debug the issue)

    System Configuration: Supermicro X9SCI/X9SCA
    BIOS Configuration: American Megatrends Inc. 4.6.4 02/24/2011
    BMC Configuration: IPMI 2.0 (KCS: Keyboard Controller Style)
    Intel(R) Xeon(R) CPU E31280 @ 3.50GHz SOCKET 0

Either of the below settings in /etc/power.conf do indeed solve the issue

cpupm disable
cpupm enable poll-mode

And once set to one of the lines above, both problems (CPU went to 100% IDLE and I could run dtrace scripts on the kernel with out a lockup).

# dtrace -n 'profile-10ms{@[stack()] = count()}'
^C

or

cd /opt/DTT
./hotkernel
^C

I think that perhaps the poll-mode might be the 'best' default setting unless some test can be used to detemine is the newer PM governor does not exhibit this issue.

Jon Strabala

#5

Updated by Albert Lee almost 8 years ago

  • Category set to kernel
  • Status changed from Feedback to New
  • Tags changed from needs-triage to cpupm, speedstep, power
#6

Updated by Jon Strabala almost 8 years ago

Sorry I mispoke, either of the below settings in /etc/power.conf do NOT solve the issue++

cpupm disable
cpupm enable poll-mode

Also this appears to be a duplicate of BUG 1333, e.g. https://www.illumos.org/issues/1333

Also available in: Atom PDF