Skip site navigation (1)Skip section navigation (2)
Date:      Thu, 27 May 2010 13:00:54 +0400
From:      pluknet <pluknet@gmail.com>
To:        freebsd-stable <freebsd-stable@freebsd.org>
Subject:   6.4-STABLE periodically stucks on boot around cpufreq:est
Message-ID:  <AANLkTimJiIK0C1M1LMpupmpvDl8aE7sykTIgHz0VXa6Z@mail.gmail.com>

next in thread | raw e-mail | index | archive | help
Hi,

When booting box with recent 6.4-STABLE often it's stuck
while trying to switch context in sysctl dev.0.cpu.freq handler.

AFAIK it stucks somewhere here:
/etc/rc.d/initrandom
                # XXX temporary until we can improve the entropy
                # harvesting rate.
                # Entropy below is not great, but better than nothing.
                # This unblocks the generator at startup
                ( ps -fauxww; sysctl -a; date; df -ib; dmesg; ps -fauxww ) \
                    | dd of=/dev/random bs=8k 2>/dev/null
                cat /bin/ls | dd of=/dev/random bs=8k 2>/dev/null

Some useful info (on successful boot):

[root@web72 ~]# sysctl dev.cpufreq
dev.cpufreq.0.%driver: cpufreq
dev.cpufreq.0.%parent: cpu0

[root@web72 ~]# sysctl -a dev.cpu
dev.cpu.0.%desc: ACPI CPU
dev.cpu.0.%driver: cpu
dev.cpu.0.%location: handle=\_PR_.CPU0
dev.cpu.0.%pnpinfo: _HID=none _UID=0
dev.cpu.0.%parent: acpi0
dev.cpu.0.freq: 3144
dev.cpu.0.freq_levels: 3144/-1 2751/-1 2358/-1 1965/-1 1572/-1 1179/-1
786/-1 393/-1
dev.cpu.0.cx_supported: C1/0
dev.cpu.0.cx_lowest: C1
dev.cpu.0.cx_usage: 100.00%
dev.cpu.1.%desc: ACPI CPU
dev.cpu.1.%driver: cpu
dev.cpu.1.%location: handle=\_PR_.CPU1
dev.cpu.1.%pnpinfo: _HID=none _UID=0
dev.cpu.1.%parent: acpi0
dev.cpu.1.cx_supported: C1/0
dev.cpu.1.cx_lowest: C1
dev.cpu.1.cx_usage: 100.00%
dev.cpu.2.%desc: ACPI CPU
dev.cpu.2.%driver: cpu
dev.cpu.2.%location: handle=\_PR_.CPU2
dev.cpu.2.%pnpinfo: _HID=none _UID=0
dev.cpu.2.%parent: acpi0
dev.cpu.2.cx_supported: C1/0
dev.cpu.2.cx_lowest: C1
dev.cpu.2.cx_usage: 100.00%
dev.cpu.3.%desc: ACPI CPU
dev.cpu.3.%driver: cpu
dev.cpu.3.%location: handle=\_PR_.CPU3
dev.cpu.3.%pnpinfo: _HID=none _UID=0
dev.cpu.3.%parent: acpi0
dev.cpu.3.cx_supported: C1/0
dev.cpu.3.cx_lowest: C1
dev.cpu.3.cx_usage: 100.00%
dev.cpu.4.%desc: ACPI CPU
dev.cpu.4.%driver: cpu
dev.cpu.4.%location: handle=\_PR_.CPU4
dev.cpu.4.%pnpinfo: _HID=none _UID=0
dev.cpu.4.%parent: acpi0
dev.cpu.4.cx_supported: C1/0
dev.cpu.4.cx_lowest: C1
dev.cpu.4.cx_usage: 100.00%
dev.cpu.5.%desc: ACPI CPU
dev.cpu.5.%driver: cpu
dev.cpu.5.%location: handle=\_PR_.CPU5
dev.cpu.5.%pnpinfo: _HID=none _UID=0
dev.cpu.5.%parent: acpi0
dev.cpu.5.cx_supported: C1/0
dev.cpu.5.cx_lowest: C1
dev.cpu.5.cx_usage: 100.00%
dev.cpu.6.%desc: ACPI CPU
dev.cpu.6.%driver: cpu
dev.cpu.6.%location: handle=\_PR_.CPU6
dev.cpu.6.%pnpinfo: _HID=none _UID=0
dev.cpu.6.%parent: acpi0
dev.cpu.6.cx_supported: C1/0
dev.cpu.6.cx_lowest: C1
dev.cpu.6.cx_usage: 100.00%
dev.cpu.7.%desc: ACPI CPU
dev.cpu.7.%driver: cpu
dev.cpu.7.%location: handle=\_PR_.CPU7
dev.cpu.7.%pnpinfo: _HID=none _UID=0
dev.cpu.7.%parent: acpi0
dev.cpu.7.cx_supported: C1/0
dev.cpu.7.cx_lowest: C1
dev.cpu.7.cx_usage: 100.00%

Related part of dmesg:
FreeBSD 6.4-STABLE #3: Fri May 21 14:25:41 MSD 2010
acpi_alloc_wakeup_handler: can't alloc wake memory
ACPI APIC Table: <IBM    SERVALNT>
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Intel(R) Xeon(R) CPU           X5460  @ 3.16GHz (3158.77-MHz 686-class CPU)
  Origin = "GenuineIntel"  Id = 0x10676  Stepping = 6
  Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,C
MOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
  Features2=0xce3bd<SSE3,RSVD2,MON,DS_CPL,VMX,EST,TM2,SSSE3,CX16,xTPR,PDCM,DCA,<
b19>>
  AMD Features=0x20000000<LM>
  AMD Features2=0x1<LAHF>
  Cores per package: 4
real memory  = 3221008384 (3071 MB)
avail memory = 3146702848 (3000 MB)
FreeBSD/SMP: Multiprocessor System Detected: 8 CPUs
 cpu0 (BSP): APIC ID:  0
 cpu1 (AP): APIC ID:  1
 cpu2 (AP): APIC ID:  2
 cpu3 (AP): APIC ID:  3
 cpu4 (AP): APIC ID:  4
 cpu5 (AP): APIC ID:  5
 cpu6 (AP): APIC ID:  6
 cpu7 (AP): APIC ID:  7
ioapic0 <Version 2.0> irqs 0-23 on motherboard
kbd1 at kbdmux0
ath_hal: 0.9.20.3 (AR5210, AR5211, AR5212, RF5111, RF5112, RF2413, RF5413)
hptrr: HPT RocketRAID controller driver v1.1 (May 11 2010 16:10:15)
acpi0: <IBM SERVALNT> on motherboard
acpi0: Power Button (fixed)
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x588-0x58b on acpi0
acpi_hpet0: <High Precision Event Timer> iomem 0xfed00000-0xfed003ff on acpi0
Timecounter "HPET" frequency 14318180 Hz quality 900
cpu0: <ACPI CPU> on acpi0
acpi_throttle0: <ACPI CPU Throttling> on cpu0
cpu1: <ACPI CPU> on acpi0
acpi_throttle1: <ACPI CPU Throttling> on cpu1
acpi_throttle1: failed to attach P_CNT
device_attach: acpi_throttle1 attach returned 6
cpu2: <ACPI CPU> on acpi0
acpi_throttle2: <ACPI CPU Throttling> on cpu2
acpi_throttle2: failed to attach P_CNT
device_attach: acpi_throttle2 attach returned 6
cpu3: <ACPI CPU> on acpi0
acpi_throttle3: <ACPI CPU Throttling> on cpu3
acpi_throttle3: failed to attach P_CNT
device_attach: acpi_throttle3 attach returned 6
cpu4: <ACPI CPU> on acpi0
acpi_throttle4: <ACPI CPU Throttling> on cpu4
acpi_throttle4: failed to attach P_CNT
device_attach: acpi_throttle4 attach returned 6
cpu5: <ACPI CPU> on acpi0
acpi_throttle5: <ACPI CPU Throttling> on cpu5
acpi_throttle5: failed to attach P_CNT
device_attach: acpi_throttle5 attach returned 6
cpu6: <ACPI CPU> on acpi0
acpi_throttle6: <ACPI CPU Throttling> on cpu6
acpi_throttle6: failed to attach P_CNT
device_attach: acpi_throttle6 attach returned 6
cpu7: <ACPI CPU> on acpi0
acpi_throttle7: <ACPI CPU Throttling> on cpu7
acpi_throttle7: failed to attach P_CNT
device_attach: acpi_throttle7 attach returned 6
[...]


Any hints?

db> ps
  pid  ppid  pgrp   uid   state   wmesg     wchan    cmd
   68    66    51     0  R+      CPU 255             sysctl
   66    64    51     0  S+      wait     0xc82e6648 sh
   65    59    51     0  S+      piperd   0xc85404c8 dd
   64    59    51     0  S+      wait     0xc82e6218 sh
   59    51    51     0  S+      wait     0xc82e6a78 sh
   51     1    51     0  Ss+     wait     0xc852ec90 sh
   50     0     0     0  SL      sdflush  0xc0af5654 [softdepflush]
   49     0     0     0  SL      syncer   0xc0adc1bc [syncer]
   48     0     0     0  SL      vlruwt   0xc8292a78 [vnlru]
   47     0     0     0  SL      psleep   0xc0ae7da0 [bufdaemon]
   46     0     0     0  RL                          [pagezero]
   45     0     0     0  SL      psleep   0xc0af6194 [vmdaemon]

db> bt 68
Tracing pid 68 tid 100053 td 0xc8291b60
sched_switch(c8291b60,0,1) at sched_switch+0x143
mi_switch(1,0,c8291cc0,0,c0adf600,...) at mi_switch+0x1ba
sched_bind(c8291b60,0) at sched_bind+0x52
cpu_est_clockrate(0,e897bad4,c84c1400,3,c84c1400,...) at cpu_est_clockrate+0xc1
cf_levels_method(c8214900,c858f000,e897bb48) at cf_levels_method+0x303
cf_get_method(c8214900,c857f000) at cf_get_method+0x12b
cpufreq_curr_sysctl(c8218e40,c81ea000,0,e897bc04,c8218e40,...) at
cpufreq_curr_sysctl+0x81
sysctl_root(0,e897bc74,4,e897bc04) at sysctl_root+0x107
userland_sysctl(c8291b60,e897bc74,4,0,bfbfdbdc,0,0,0,e897bc70,0) at
userland_sysctl+0x112
__sysctl(c8291b60,e897bd04) at __sysctl+0x93
syscall(3b,bfbf003b,bfbf003b,4,bfbfdbdc,...) at syscall+0x2bf
Xint0x80_syscall() at Xint0x80_syscall+0x1f
--- syscall (202, FreeBSD ELF32, __sysctl), eip = 0x2812650b, esp =
0xbfbfdb4c, ebp = 0xbfbfdb88 ---

db> bt 65
Tracing pid 65 tid 100051 td 0xc82e4000
sched_switch(c82e4000,0,1) at sched_switch+0x143
mi_switch(1,0,c85404c8,ec997bec,c06e32b9,...) at mi_switch+0x1ba
sleepq_switch(c85404c8) at sleepq_switch+0x87
sleepq_wait_sig(c85404c8) at sleepq_wait_sig+0x1d
msleep(c85404c8,c8540638,14c,c09d8540,0,...) at msleep+0x25a
pipe_read(c8536ab0,ec997cbc,c80f5700,0,c82e4000) at pipe_read+0x42d
dofileread(c82e4000,0,c8536ab0,ec997cbc,ffffffff,...) at dofileread+0x85
kern_readv(c82e4000,0,ec997cbc,804f000,2000,...) at kern_readv+0x36
read(c82e4000,ec997d04) at read+0x45
syscall(3b,3b,3b,2004,bfbfeebc,...) at syscall+0x2bf
Xint0x80_syscall() at Xint0x80_syscall+0x1f
--- syscall (3, FreeBSD ELF32, read), eip = 0x2813d8d7, esp =
0xbfbfee0c, ebp = 0xbfbfee58 ---

db> show allpcpu
Current CPU: 1

cpuid        = 0
curthread    = 0xc80fa9c0: pid 18 "swi4: clock sio"
curpcb       = 0xe6ce4d90
fpcurthread  = none
idlethread   = 0xc80fa820: pid 17 "idle: cpu0"
APIC ID      = 0
currentldt   = 0x50

cpuid        = 1
curthread    = 0xc80fa000: pid 16 "idle: cpu1"
curpcb       = 0xe6cd2d90
fpcurthread  = none
idlethread   = 0xc80fa000: pid 16 "idle: cpu1"
APIC ID      = 1
currentldt   = 0x50

cpuid        = 2
curthread    = 0xc80f8d00: pid 15 "idle: cpu2"
curpcb       = 0xe6ccfd90
fpcurthread  = none

idlethread   = 0xc80f8d00: pid 15 "idle: cpu2"
APIC ID      = 2
currentldt   = 0x50

cpuid        = 3
curthread    = 0xc80f8b60: pid 14 "idle: cpu3"
curpcb       = 0xe6cccd90
fpcurthread  = none
idlethread   = 0xc80f8b60: pid 14 "idle: cpu3"
APIC ID      = 3
currentldt   = 0x50

cpuid        = 4
curthread    = 0xc80f89c0: pid 13 "idle: cpu4"
curpcb       = 0xe6cc9d90
fpcurthread  = none
idlethread   = 0xc80f89c0: pid 13 "idle: cpu4"
APIC ID      = 4
currentldt   = 0x50
cpuid        = 5
curthread    = 0xc80f8820: pid 12 "idle: cpu5"
curpcb       = 0xe6cc6d90
fpcurthread  = none
idlethread   = 0xc80f8820: pid 12 "idle: cpu5"
APIC ID      = 5
currentldt   = 0x50

cpuid        = 6
curthread    = 0xc80f8680: pid 11 "idle: cpu6"
curpcb       = 0xe6cc3d90
fpcurthread  = none
idlethread   = 0xc80f8680: pid 11 "idle: cpu6"
APIC ID      = 6
currentldt   = 0x50

cpuid        = 7
curthread    = 0xc80f84e0: pid 10 "idle: cpu7"
curpcb       = 0xe6cc0d90
fpcurthread  = none
idlethread   = 0xc80f84e0: pid 10 "idle: cpu7"
APIC ID      = 7
currentldt   = 0x50

db> bt 18
Tracing pid 18 tid 100015 td 0xc80fa9c0
sched_switch(c0b21c20,c093091c,0,0,0,...) at sched_switch+0x143

-- 
wbr,
pluknet



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?AANLkTimJiIK0C1M1LMpupmpvDl8aE7sykTIgHz0VXa6Z>