6.4-STABLE periodically stucks on boot around cpufreq:est

pluknet pluknet at gmail.com
Thu Jun 3 11:29:27 UTC 2010


On 27 May 2010 13:00, pluknet <pluknet at gmail.com> wrote:
> 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.

fwiw, that is not an issue for 6.4-RELEASE.
I'm going to binary search between them.

>
> 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 at web72 ~]# sysctl dev.cpufreq
> dev.cpufreq.0.%driver: cpufreq
> dev.cpufreq.0.%parent: cpu0
>
> [root at 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


More information about the freebsd-stable mailing list