Project

General

Profile

Bug #1333 » power_cpu_issue_PLUS_0hours.txt

Jon Strabala, 2011-09-06 05:34 PM

 
1
root@lab10:~# date
2
September  6, 2011 08:47:53 AM PDT
3

    
4

    
5
root@lab10:~# tail -4 /etc/system
6
* August 30, 2011 02:26:39 PM PDT
7
* try to solve CPU creep issue
8
* https://defect.opensolaris.org/bz/show_bug.cgi?id=12799
9
set cpupm_tw_gov_interval=800000
10

    
11

    
12
root@lab10:~# rup lab10
13
          lab10    up           2 mins,  load average: 0.07, 0.05, 0.02
14

    
15

    
16
root@lab10:~# uname -a
17
SunOS lab10 5.11 oi_148b i86pc i386 i86pc Solaris
18

    
19

    
20
root@lab10:~# prstat -s cpu -n 5 > /tmp/prstat.s.cpu.n.5.out
21
^C
22

    
23
root@lab10:~# cat /tmp/prstat.s.cpu.n.5.out
24
   PID USERNAME  SIZE   RSS STATE  PRI NICE      TIME  CPU PROCESS/NLWP
25
  1282 root       60M   38M sleep   59    0   0:00:02 0.1% Xorg/3
26
  1595 gdm        87M   25M sleep   59    0   0:00:00 0.0% gdm-simple-gree/1
27
    12 root       16M   14M sleep   59    0   0:00:04 0.0% svc.configd/21
28
    10 root       15M   13M sleep   59    0   0:00:01 0.0% svc.startd/14
29
   827 root     2308K 1420K sleep   59    0   0:00:00 0.0% ttymon/1
30
Total: 66 processes, 391 lwps, load averages: 0.06, 0.05, 0.02
31
   PID USERNAME  SIZE   RSS STATE  PRI NICE      TIME  CPU PROCESS/NLWP
32
  1282 root       60M   38M sleep   59    0   0:00:02 0.0% Xorg/3
33
  1595 gdm        87M   25M sleep   59    0   0:00:00 0.0% gdm-simple-gree/1
34
    12 root       16M   14M sleep   59    0   0:00:04 0.0% svc.configd/21
35
    10 root       15M   13M sleep   59    0   0:00:01 0.0% svc.startd/14
36
   827 root     2308K 1420K sleep   59    0   0:00:00 0.0% ttymon/1
37
Total: 66 processes, 391 lwps, load averages: 0.05, 0.05, 0.02
38
   PID USERNAME  SIZE   RSS STATE  PRI NICE      TIME  CPU PROCESS/NLWP
39
  1282 root       60M   38M sleep   59    0   0:00:02 0.0% Xorg/3
40
  1595 gdm        87M   25M sleep   59    0   0:00:00 0.0% gdm-simple-gree/1
41
    10 root       15M   13M sleep   59    0   0:00:01 0.0% svc.startd/14
42
   827 root     2308K 1420K sleep   59    0   0:00:00 0.0% ttymon/1
43
     1 root     2728K 1832K sleep   59    0   0:00:00 0.0% init/1
44
Total: 66 processes, 391 lwps, load averages: 0.05, 0.05, 0.02
45

    
46

    
47

    
48
root@lab10:~# mpstat 5 2
49
CPU minf mjf xcal  intr ithr  csw icsw migr smtx  srw syscl  usr sys  wt idl
50
  0  341   0   58   411  113 1453   12  102  132    1  3064    1   2   0  97
51
  1  359   0   48   136   16 1162    9   97  118    1  2439    2   1   0  97
52
  2  491   0   74   117   12  765    7   77   95    1  1958    1   1   0  98
53
  3  404   0   38   194  101  940    6   89  134    2  2273    1   1   0  98
54
  4  374   0   35   105   10  574    8   51   98    1  1475    1   1   0  99
55
  5  372   0   37   103   11  428   10   48   92    1  1136    1   1   0  99
56
  6  407   0   27    93   10  514    6   55  166    1  1440    0   1   0  99
57
  7  331   0   34   102    7  521    9   53   93    1  1701    1   1   0  98
58
CPU minf mjf xcal  intr ithr  csw icsw migr smtx  srw syscl  usr sys  wt idl
59
  0    0   0    0   321  101   51    0    2    0    0    31    0   0   0 100
60
  1    0   0    0    43    5   37    0    1    0    0    11    0   0   0 100
61
  2    0   0    0    35   10   29    0    1    0    0    22    1   0   0  99
62
  3    5   0    0    37    2   28    0    1    1    0    61    0   2   0  98
63
  4    0   0    0    89   40   88    0    0    0    0     0    0   0   0 100
64
  5    0   0    0    27    6   24    0    1    0    0     0    0   0   0 100
65
  6    0   0    0    43   11   39    0    1    0    0     0    0   0   0 100
66
  7    0   0    0    35   10   33    0    1    0    0    16    0   0   0 100
67
root@lab10:~# powertop
68
OpenIndiana PowerTOP version 1.2   (C) 2009 Intel Corporation
69

    
70
Collecting data for 5.00 second(s)
71
root@lab10:~# vi /tmp/powertop.5.samp0.txt
72
root@lab10:~# cat /tmp/powertop.5.samp0.txt
73
                                                             OpenIndiana PowerTOP version 1.2
74

    
75
C-states (idle power)   Avg     Residency                                            P-states (frequencies)
76
C0 (cpu running)                (0.8%)                                               1600 Mhz        0.0%
77
C1                      0.0ms   (0.0%)                                               1800 Mhz        0.0%
78
C2                      0.0ms   (0.0%)                                               2000 Mhz        0.0%
79
C3                      2.5ms   (99.2%)                                              2200 Mhz        0.0%
80
                                                                                     2400 Mhz        0.0%
81
                                                                                     2600 Mhz        0.0%
82
                                                                                     2800 Mhz        0.0%
83
                                                                                     3000 Mhz        0.0%
84
                                                                                     3200 Mhz        0.0%
85
                                                                                     3400 Mhz        0.0%
86
                                                                                     3597 Mhz(turbo) 100.0%
87

    
88
Wakeups-from-idle per second: 3192.6    interval: 5.0s
89
no ACPI power usage estimate available
90

    
91
Top causes for wakeups:
92
89.2% (2849.0)                 sched :  <xcalls> unix`dtrace_xcall_func
93
 3.1% (100.0)               <kernel> :  genunix`clock
94
 2.4% ( 76.6)               <kernel> :  genunix`cv_wakeup
95
 1.6% ( 50.0)               <kernel> :  SDC`sysdc_update
96
 0.3% (  8.0)               <kernel> :  cpudrv`cpudrv_monitor_disp
97
 0.2% (  7.6)               <kernel> :  ehci`ehci_handle_root_hub_status_change
98
 0.1% (  4.0)               <kernel> :  genunix`schedpaging
99
 0.1% (  2.0)            <interrupt> :  e1000g#0
100
 0.0% (  1.0)               <kernel> :  TS`ts_update
101
 0.0% (  1.0)               <kernel> :  e1000g`e1000g_local_timer
102
 0.0% (  1.0)               <kernel> :  genunix`sigalarm2proc
103
 0.0% (  1.0)            <interrupt> :  ehci#0
104
 0.0% (  1.0)            <interrupt> :  ehci#1
105
 0.0% (  0.2)               <kernel> :  ip`igmp_slowtimo
106
 0.0% (  0.2)               <kernel> :  kcf`rnd_handler
107
 0.0% (  0.2)               <kernel> :  ahci`ahci_watchdog_handler
108
 0.0% (  0.2)               <kernel> :  swrand`rnd_handler
109
 0.0% (  0.2)               <kernel> :  unix`memscrub_wakeup
110

    
111
Suggestion: enable CPU power management by pressing the P key
112

    
113

    
114

    
115
root@lab10:~# prtdiag
116
System Configuration: Supermicro X9SCI/X9SCA
117
BIOS Configuration: American Megatrends Inc. 4.6.4 02/24/2011
118
BMC Configuration: IPMI 2.0 (KCS: Keyboard Controller Style)
119

    
120
==== Processor Sockets ====================================
121

    
122
Version                          Location Tag
123
-------------------------------- --------------------------
124
Intel(R) Xeon(R) CPU E31270 @ 3.40GHz SOCKET 0
125

    
126
==== Memory Device Sockets ================================
127

    
128
Type        Status Set Device Locator      Bank Locator
129
----------- ------ --- ------------------- ----------------
130
Unknown     in use 0   DIMM_1A             BANK0
131
Unknown     in use 0   DIMM_2A             BANK0
132
Unknown     in use 0   DIMM_1B             BANK0
133
Unknown     in use 0   DIMM_2B             BANK0
134

    
135
==== On-Board Devices =====================================
136
   To Be Filled By O.E.M.
137

    
138
==== Upgradeable Slots ====================================
139

    
140
ID  Status    Type             Description
141
--- --------- ---------------- ----------------------------
142
0   in use    PCI Express      J6B2
143
1   in use    PCI Express      J6B1
144
2   in use    PCI Express      J6D1
145
3   in use    PCI Express      J7B1
146
4   in use    PCI Express      J8B4
147

    
148

    
149

    
150
root@lab10:~# cat /etc/power.conf
151
cpu_deep_idle enable
152
cpu-threshold 10s
153
cpupm disable
154

    
155

    
156

    
157
root@lab10:~# dtrace -n 'profile-10ms{@[stack()] = count()}'
158
dtrace: description 'profile-10ms' matched 1 probe
159
^C
160

    
161

    
162
              unix`tsc_gethrtimeunscaled_delta+0x3a
163
              genunix`gethrtime_unscaled+0xd
164
              unix`cpu_acpi_idle+0x47
165
              unix`cpu_idle_adaptive+0x19
166
              unix`idle+0x114
167
              unix`thread_start+0x8
168
                1
169

    
170
              unix`i86_mwait+0xd
171
              unix`cpu_idle_mwait+0xf1
172
              unix`cpu_acpi_idle+0x8d
173
              unix`cpu_idle_adaptive+0x19
174
              unix`idle+0x114
175
              unix`thread_start+0x8
176
               10
177

    
178
              unix`acpi_cpu_cstate+0x2ae
179
              unix`cpu_acpi_idle+0x82
180
              unix`cpu_idle_adaptive+0x19
181
              unix`idle+0x114
182
              unix`thread_start+0x8
183
             8373
184

    
185

    
186

    
187
root@lab10:~# echo ::interrupts | mdb -k
188
CPU/Vect  IRQ IPL Bus    Trg Type   Share APIC/INT# ISR
189
0/0x25    16  9   PCI    Lvl Fixed  1     0x0/0x10  ehci_intr
190
1/0x20    9   9   PCI    Lvl Fixed  1     0x0/0x9   acpi_wrapper_isr
191
1/0x21    23  9   PCI    Lvl Fixed  1     0x0/0x17  ehci_intr
192
1/0x22    4   12  ISA    Edg Fixed  1     0x0/0x4   asyintr
193
2/0x20    11  14  PCI    Lvl Fixed  1     0x0/0xb   hpet_isr
194
2/0x21    -   6   PCI    Edg MSI    1     -         e1000g_intr_pciexpress
195
3/0x20    -   5   PCI    Edg MSI    1     -         ahci_intr
196
3/0x21    3   12  ISA    Edg Fixed  1     0x0/0x3   asyintr
197
5/0x20    10  12  ISA    Edg Fixed  1     0x0/0xa   asyintr
198
6/0x20    1   5   ISA    Edg Fixed  1     0x0/0x1   i8042_intr
199
6/0x21    -   6   PCI    Edg MSI    1     -         e1000g_intr_pciexpress
200
7/0x20    12  5   ISA    Edg Fixed  1     0x0/0xc   i8042_intr
201
all/0xf0  -   15  -      Edg IPI    1     -         xc_serv
202
all/0xf1  -   11  -      Edg IPI    0     -         poke_cpu
203
all/0xf2  -   14  -      Edg IPI    1     -         kcpc_hw_overflow_intr
204
all/0xf3  -   15  -      Edg IPI    1     -         apic_error_intr
205
all/0xf4  -   2   -      Edg IPI    1     -         cmi_cmci_trap
206
all/0xf5  -   14  -      Edg IPI    1     -         cbe_fire
207
all/0xf6  -   14  -      Edg IPI    1     -         cbe_fire
208

    
209

    
210
root@lab10:~# echo ::interrupts -d | mdb -k
211
CPU/Vect  IRQ IPL Bus    Trg Type   Share APIC/INT# Driver Name(s)
212
0/0x25    16  9   PCI    Lvl Fixed  1     0x0/0x10  ehci#0
213
1/0x20    9   9   PCI    Lvl Fixed  1     0x0/0x9   acpi_wrapper_isr
214
1/0x21    23  9   PCI    Lvl Fixed  1     0x0/0x17  ehci#1
215
1/0x22    4   12  ISA    Edg Fixed  1     0x0/0x4   asy#0
216
2/0x20    11  14  PCI    Lvl Fixed  1     0x0/0xb   hpet_isr
217
2/0x21    -   6   PCI    Edg MSI    1     -         e1000g#0
218
3/0x20    -   5   PCI    Edg MSI    1     -         ahci#0
219
3/0x21    3   12  ISA    Edg Fixed  1     0x0/0x3   asy#1
220
5/0x20    10  12  ISA    Edg Fixed  1     0x0/0xa   asy#2
221
6/0x20    1   5   ISA    Edg Fixed  1     0x0/0x1   i8042#0
222
6/0x21    -   6   PCI    Edg MSI    1     -         e1000g#1
223
7/0x20    12  5   ISA    Edg Fixed  1     0x0/0xc   i8042#0
224
all/0xf0  -   15  -      Edg IPI    1     -         xc_serv
225
all/0xf1  -   11  -      Edg IPI    0     -         poke_cpu
226
all/0xf2  -   14  -      Edg IPI    1     -         kcpc_hw_overflow_intr
227
all/0xf3  -   15  -      Edg IPI    1     -         apic_error_intr
228
all/0xf4  -   2   -      Edg IPI    1     -         cmi_cmci_trap
229
all/0xf5  -   14  -      Edg IPI    1     -         cbe_fire
230
all/0xf6  -   14  -      Edg IPI    1     -         cbe_fire
231

    
232

    
233
root@lab10:~# intrstat 30
234

    
235
      device |      cpu0 %tim      cpu1 %tim      cpu2 %tim      cpu3 %tim      cpu4 %tim      cpu5 %tim      cpu6 %tim      cpu7 %tim
236
-------------+------------------------------------------------------------------------------------------------------------------------
237
      ahci#0 |         0  0.0         0  0.0         0  0.0         1  0.0         0  0.0         0  0.0         0  0.0         0  0.0
238
    e1000g#0 |         0  0.0         0  0.0         1  0.0         0  0.0         0  0.0         0  0.0         0  0.0         0  0.0
239
      ehci#0 |         0  0.0         0  0.0         0  0.0         0  0.0         0  0.0         0  0.0         0  0.0         0  0.0
240
      ehci#1 |         0  0.0         0  0.0         0  0.0         0  0.0         0  0.0         0  0.0         0  0.0         0  0.0
241
^C
242

    
243

    
244

    
245
root@lab10:~# powertop -t 30
246
OpenIndiana PowerTOP version 1.2   (C) 2009 Intel Corporation
247

    
248
Collecting data for 30.00 second(s)
249
root@lab10:~#
250
root@lab10:~#
251
root@lab10:~# vi /tmp/powerttop.30.samp0.txt
252
root@lab10:~# cat /tmp/powerttop.30.samp0.txt
253
                                                             OpenIndiana PowerTOP version 1.2
254

    
255
C-states (idle power)   Avg     Residency                                            P-states (frequencies)
256
C0 (cpu running)                (0.9%)                                               1600 Mhz        0.0%
257
C1                      0.0ms   (0.0%)                                               1800 Mhz        0.0%
258
C2                      0.0ms   (0.0%)                                               2000 Mhz        0.0%
259
C3                      2.5ms   (99.1%)                                              2200 Mhz        0.0%
260
                                                                                     2400 Mhz        0.0%
261
                                                                                     2600 Mhz        0.0%
262
                                                                                     2800 Mhz        0.0%
263
                                                                                     3000 Mhz        0.0%
264
                                                                                     3200 Mhz        0.0%
265
                                                                                     3400 Mhz        0.0%
266
                                                                                     3601 Mhz(turbo) 100.0%
267

    
268
Wakeups-from-idle per second: 3219.6    interval: 30.0s
269
no ACPI power usage estimate available
270

    
271
Top causes for wakeups:
272
88.5% (2849.0)                 sched :  <xcalls> unix`dtrace_xcall_func
273
 3.1% (100.0)               <kernel> :  genunix`clock
274
 2.4% ( 76.8)               <kernel> :  genunix`cv_wakeup
275
 1.6% ( 50.0)               <kernel> :  SDC`sysdc_update
276
 0.2% (  8.0)               <kernel> :  cpudrv`cpudrv_monitor_disp
277
 0.2% (  7.7)               <kernel> :  ehci`ehci_handle_root_hub_status_change
278
 0.1% (  4.0)               <kernel> :  genunix`schedpaging
279
 0.1% (  1.6)            <interrupt> :  e1000g#0
280
 0.0% (  1.0)               <kernel> :  TS`ts_update
281
 0.0% (  1.0)               <kernel> :  e1000g`e1000g_local_timer
282
 0.0% (  1.0)            <interrupt> :  ehci#0
283
 0.0% (  1.0)            <interrupt> :  ehci#1
284
 0.0% (  0.2)               <kernel> :  kcf`rnd_handler
285
 0.0% (  0.2)               <kernel> :  ahci`ahci_watchdog_handler
286
 0.0% (  0.1)               <kernel> :  swrand`rnd_handler
287
 0.0% (  0.1)               <kernel> :  ip`igmp_slowtimo
288
 0.0% (  0.1)                  sched :  <xcalls> unix`hati_demap_func
289
 0.0% (  0.1)               <kernel> :  genunix`kmem_update
290
 0.0% (  0.1)               <kernel> :  genunix`vmem_update
291
 0.0% (  0.0)               <kernel> :  ip`tcp_timer_callback
292

    
293

    
294

    
295

    
296

    
297

    
298

    
299

    
300

    
301

    
302
Suggestion: enable CPU power management by pressing the P key
303

    
304
root@lab10:~# top -s 10
305
root@lab10:~#
306

    
307

    
308

    
309
root@lab10:~# ls
310
check.txt  doit  power_cpu_issue_PLUS_159hours.txt  power_cpu_issue_PLUS_44hours.txt
311

    
312

    
313
root@lab10:~# vi /tmp/top.s.10
314

    
315
root@lab10:~# cat /tmp/top.s.10
316
last pid:  1921;  load avg:  0.00,  0.02,  0.01;  up 0+00:10:18                                                                                  08:55:46
317
62 processes: 61 sleeping, 1 on cpu
318
CPU states: 99.9% idle,  0.0% user,  0.1% kernel,  0.0% iowait,  0.0% swap
319
Kernel: 317 ctxsw, 698 intr, 58 syscall
320
Memory: 16G phys mem, 15G free mem, 8187M total swap, 8187M free swap
321

    
322
   PID USERNAME NLWP PRI NICE  SIZE   RES STATE    TIME    CPU COMMAND
323
  1282 root        3  59    0   60M   38M sleep    0:04  0.05% Xorg
324
  1595 gdm         1  59    0   87M   25M sleep    0:00  0.01% gdm-simple-gree
325
  1920 root        1  59    0 3852K 2520K cpu/1    0:00  0.00% top
326
  1594 gdm         1  59    0   82M   18M sleep    0:00  0.00% gnome-power-man
327
  1780 root       22  59    0 5728K 3668K sleep    0:00  0.00% nscd
328
  1585 gdm         1  59    0 7152K 5944K sleep    0:00  0.00% gconfd-2
329
  1821 admin       1  59    0 7736K 5180K sleep    0:00  0.00% sshd
330
  1122 root        6  59    0   26M   10M sleep    0:00  0.00% fbserver
331
   208 root        6  59    0 4348K 3152K sleep    0:00  0.00% devfsadm
332
    10 root       14  59    0   15M   13M sleep    0:01  0.00% svc.startd
333
   816 root        4  59    0 6728K 3872K sleep    0:00  0.00% inetd
334
    12 root       21  59    0   16M   14M sleep    0:04  0.00% svc.configd
335
   837 root       25  59    0   18M   11M sleep    0:00  0.00% fmd
336
   270 root        5  60  -20 2548K 1512K sleep    0:00  0.00% zonestatd
337

    
338
root@lab10:~#
339

    
(4-4/18)