From owner-freebsd-stable@FreeBSD.ORG Thu May 27 09:00:56 2010 Return-Path: Delivered-To: freebsd-stable@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 40B60106566B for ; Thu, 27 May 2010 09:00:56 +0000 (UTC) (envelope-from pluknet@gmail.com) Received: from mail-gy0-f182.google.com (mail-gy0-f182.google.com [209.85.160.182]) by mx1.freebsd.org (Postfix) with ESMTP id F3C9E8FC1C for ; Thu, 27 May 2010 09:00:55 +0000 (UTC) Received: by gyh20 with SMTP id 20so4922233gyh.13 for ; Thu, 27 May 2010 02:00:55 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:mime-version:received:received:date:message-id :subject:from:to:content-type; bh=17q/8ptfNUlSVWurNc2XILukM7GrKMW83sY/e1PjRKo=; b=qAo5odd32s1vYPVKdh5Fmh3khw92hBhk/Z3MB4RAzd3G20fEx9+MpBGkJl8abpG2G6 SkTrqGxAH8rbR+fwcym6HazoWqmsVTye+ZX7o661V+j0N78pN6EHohD8xd8ooe6Jk0Zl 15g2X8NtaJQasgxM+9tsHxySFYjTWkaDxPRe4= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=mime-version:date:message-id:subject:from:to:content-type; b=q2Qr42H+ss+c5PlociL1JzRz/sFtpKK606Po+I1u6PDWa7dCd1rumHZR+F5NX82l7d nN91YzHZEgwtKb5rksd2o8HoTNGQSM0wwHxZBLGVV6i+KjFVlv/y/hdcOfNG+oki+B/q RD9JMkqA6cMP5ni0PbrIL6OnkTsAuYY0rS0pY= MIME-Version: 1.0 Received: by 10.101.129.7 with SMTP id g7mr11829184ann.84.1274950854412; Thu, 27 May 2010 02:00:54 -0700 (PDT) Received: by 10.100.208.9 with HTTP; Thu, 27 May 2010 02:00:54 -0700 (PDT) Date: Thu, 27 May 2010 13:00:54 +0400 Message-ID: From: pluknet To: freebsd-stable Content-Type: text/plain; charset=ISO-8859-1 Subject: 6.4-STABLE periodically stucks on boot around cpufreq:est X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 27 May 2010 09:00:56 -0000 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: 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 Features2=0xce3bd> AMD Features=0x20000000 AMD Features2=0x1 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 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: 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: iomem 0xfed00000-0xfed003ff on acpi0 Timecounter "HPET" frequency 14318180 Hz quality 900 cpu0: on acpi0 acpi_throttle0: on cpu0 cpu1: on acpi0 acpi_throttle1: on cpu1 acpi_throttle1: failed to attach P_CNT device_attach: acpi_throttle1 attach returned 6 cpu2: on acpi0 acpi_throttle2: on cpu2 acpi_throttle2: failed to attach P_CNT device_attach: acpi_throttle2 attach returned 6 cpu3: on acpi0 acpi_throttle3: on cpu3 acpi_throttle3: failed to attach P_CNT device_attach: acpi_throttle3 attach returned 6 cpu4: on acpi0 acpi_throttle4: on cpu4 acpi_throttle4: failed to attach P_CNT device_attach: acpi_throttle4 attach returned 6 cpu5: on acpi0 acpi_throttle5: on cpu5 acpi_throttle5: failed to attach P_CNT device_attach: acpi_throttle5 attach returned 6 cpu6: on acpi0 acpi_throttle6: on cpu6 acpi_throttle6: failed to attach P_CNT device_attach: acpi_throttle6 attach returned 6 cpu7: on acpi0 acpi_throttle7: 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