From owner-freebsd-stable@FreeBSD.ORG Sun Apr 2 18:35:03 2006 Return-Path: X-Original-To: stable@freebsd.org Delivered-To: freebsd-stable@FreeBSD.ORG Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 4ACE616A400 for ; Sun, 2 Apr 2006 18:35:03 +0000 (UTC) (envelope-from pawel.worach@gmail.com) Received: from uproxy.gmail.com (uproxy.gmail.com [66.249.92.202]) by mx1.FreeBSD.org (Postfix) with ESMTP id 792DE43D49 for ; Sun, 2 Apr 2006 18:35:02 +0000 (GMT) (envelope-from pawel.worach@gmail.com) Received: by uproxy.gmail.com with SMTP id u2so579226uge for ; Sun, 02 Apr 2006 11:34:59 -0700 (PDT) DomainKey-Signature: a=rsa-sha1; q=dns; c=nofws; s=beta; d=gmail.com; h=received:message-id:date:from:to:subject:mime-version:content-type:content-transfer-encoding:content-disposition; b=gx6TuGxb6oxL1j5UDlJ1RRbRKgBz23AlxIBAOdA6hLYTW5xmKf3sR0xP4/OzLpl1xfBnjg0ccL7VVaCKefPVdWiT5rnNZ2pFdtrtBtPOc3/8fJzjwimoQw2yktLvIeUR+1UeckSnTxSnzXHP16RTAcKNTy9kECUKh5S937hbb9M= Received: by 10.78.32.16 with SMTP id f16mr92725huf; Sun, 02 Apr 2006 11:34:58 -0700 (PDT) Received: by 10.78.75.15 with HTTP; Sun, 2 Apr 2006 11:34:58 -0700 (PDT) Message-ID: Date: Sun, 2 Apr 2006 20:34:58 +0200 From: "Pawel Worach" To: stable@freebsd.org MIME-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable Content-Disposition: inline Cc: Subject: 6.1-PRE hang with sysctl and sched_ule 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: Sun, 02 Apr 2006 18:35:03 -0000 Hi, Got this interesting hang on a two way (two physical cpus with htt disabled by machdep.hyperthreading_allowed) smp box during boot. Any ideas? Kernel config is pretty much SMP with most drivers cut and KDB, DDB and BREAK_TO_DEBUGGER added. Sources are from this morning. I can only reproduce this with the ULE scheduler, switching to 4BSD makes the problem go away. KDB: enter: Line break on console [thread pid 27 tid 100017 ] Stopped at kdb_enter+0x30: leave db> show msgbuf msgbufp =3D 0xc0c3afe4 magic =3D 63062, size =3D 32740, r=3D 0, w =3D 4955, ptr =3D 0xc0c33000, ck= sum=3D 386982 Copyright (c) 1992-2006 The FreeBSD Project. Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994 The Regents of the University of California. All rights reserved. FreeBSD 6.1-PRERELEASE #0: Sun Apr 2 14:40:58 CEST 2006 root@proxy1:/usr/obj/usr/src/sys/PROXY-SMP Timecounter "i8254" frequency 1193182 Hz quality 0 CPU: Intel(R) Xeon(TM) CPU 3.60GHz (3600.15-MHz 686-class CPU) Origin =3D "GenuineIntel" Id =3D 0xf43 Stepping =3D 3 Features=3D0xbfebfbff Features2=3D0x659d> AMD Features=3D0x20000000 Hyperthreading: 2 logical CPUs real memory =3D 2147270656 (2047 MB) avail memory =3D 2099769344 (2002 MB) ACPI APIC Table: FreeBSD/SMP: Multiprocessor System Detected: 4 CPUs cpu0 (BSP): APIC ID: 0 cpu1 (AP): APIC ID: 1 cpu2 (AP): APIC ID: 6 cpu3 (AP): APIC ID: 7 ioapic4 irqs 96-119 on motherboard ioapic3 irqs 72-95 on motherboard ioapic2 irqs 48-71 on motherboard ioapic1 irqs 24-47 on motherboard ioapic0 irqs 0-23 on motherboard kbd1 at kbdmux0 npx0: [FAST] npx0: on motherboard npx0: INT 16 interface acpi0: on motherboard acpi_bus_number: can't get _ADR acpi_bus_number: can't get _ADR acpi0: Power Button (fixed) acpi_bus_number: can't get _ADR acpi_bus_number: can't get _ADR Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x588-0x58b on acpi0 cpu0: on acpi0 acpi_perf0: on cpu0 cpu1: on acpi0 cpu2: on acpi0 cpu3: on acpi0 pcib0: on acpi0 pci0: on pcib0 pci0: at device 0.1 (no driver attached) pcib1: at device 2.0 on pci0 pci2: on pcib1 pcib2: at device 0.0 on pci2 pci3: on pcib2 pcib3: at device 0.2 on pci2 pci4: on pcib3 pcib4: at device 4.0 on pci0 pci5: on pcib4 bge0: mem 0xdeff0000-= 0xdef fffff irq 16 at device 0.0 on pci5 miibus0: on bge0 brgphy0: on miibus0 brgphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseTX, 1000b= aseTX -FDX, auto bge0: Ethernet address: 00:14:5e:2a:8a:d6 pcib5: at device 5.0 on pci0 pci6: on pcib5 bge1: mem 0xdcff0000-= 0xdcf fffff irq 16 at device 0.0 on pci6 miibus1: on bge1 brgphy1: on miibus1 brgphy1: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseTX, 1000b= aseTX -FDX, auto bge1: Ethernet address: 00:14:5e:2a:8a:d7 pcib6: at device 6.0 on pci0 pci7: on pcib6 pcib7: at device 0.0 on pci7 pci8: on pcib7 ips0: mem 0xdafff000-0xdaffffff irq 38 at devic= e 14. 0 on pci8 pcib8: at device 0.2 on pci7 pci9: on pcib8 pci0: at device 8.0 (no driver attached) pci0: at device 29.0 (no driver attached) pci0: at device 29.1 (no driver attached) pci0: at device 29.7 (no driver attached) pcib9: at device 30.0 on pci0 pci1: on pcib9 pci1: at device 6.0 (no driver attached) isab0: at device 31.0 on pci0 isa0: on isab0 pci0: at device 31.1 (no driver attached) pci0: at device 31.3 (no driver attached) atkbdc0: port 0x64,0x60 irq 1 on acpi0 atkbd0: irq 1 on atkbdc0 atkbd: unable to set the command byte. kbd0 at atkbd0 atkbd0: [GIANT-LOCKED] sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acp= i0 sio0: type 16550A, console orm0: at iomem 0xc0000-0xcafff,0xcb000-0xce7ff on isa0 sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=3D0x100> sio1: configured irq 3 not in bitmap of probed irqs 0 sio1: port may not be enabled vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 Timecounters tick every 1.000 msec ips0: logical drives: 1 ips0: Logical Drive 0: RAID1 sectors: 143372288, state OK ipsd0: on ips0 ipsd0: Logical Drive (70006MB) SMP: AP CPU #3 Launched! SMP: AP CPU #1 Launched! SMP: AP CPU #2 Launched! Trying to mount root from ufs:/dev/ipsd0s1a <118>Loading configuration files. <118>kernel dumps on /dev/ipsd0s1b <118>Entropy harvesting: <118> interrupts <118> ethernet <118> point_to_point KDB: enter: Line break on console db> bt Tracing pid 27 tid 100017 td 0xc5fbb960 kdb_enter(c06725fd,c5fbb960,1,c5fbb960,c60adc00) at kdb_enter+0x30 siointr1(c60adc00,c04e99e2,c5fbb960,c6013624,e4db0c0c) at siointr1+0xd1 siointr(c60adc00,c06b0710,c62aa794,0,c5fbb960) at siointr+0x76 intr_execute_handlers(c5fb04b4,e4db0c4c,e4db0ca4,c0626833,35) at intr_execu= te_ha ndlers+0xfa lapic_handle_intr(35) at lapic_handle_intr+0x3b Xapic_isr1() at Xapic_isr1+0x33 --- interrupt, eip =3D 0xc04c933d, esp =3D 0xe4db0c90, ebp =3D 0xe4db0ca4 -= -- _mtx_lock_sleep(c06ad2c0,c5fbb960,0,0,0) at _mtx_lock_sleep+0xb4 ithread_execute_handlers(c6013624,c6090e80,0,0,0) at ithread_execute_handle= rs+0x 160 ithread_loop(c60ab670,e4db0d38,0,0,0) at ithread_loop+0x64 fork_exit(c04b9ea7,c60ab670,e4db0d38) at fork_exit+0x7b fork_trampoline() at fork_trampoline+0x8 --- trap 0x1, eip =3D 0, esp =3D 0xe4db0d6c, ebp =3D 0 --- db> show pcpu cpuid =3D 2 curthread =3D 0xc5fbb960: pid 27 "swi0: sio" curpcb =3D 0xe4db0d90 fpcurthread =3D none idlethread =3D 0xc5fba960: pid 12 "idle: cpu2" APIC ID =3D 6 currentldt =3D 0x50 db> ps pid proc uid ppid pgrp flag stat wmesg wchan cmd 53 c62a8624 0 51 35 0004002 [CPU 255] sysctl 51 c62a8000 0 49 35 0000002 [SLPQ wait 0xc62a8000][SLP] sh 50 c6255c48 0 44 35 0004002 [SLPQ piperd 0xc62b2660][SLP] dd 49 c62a820c 0 44 35 0000002 [SLPQ wait 0xc62a820c][SLP] sh 44 c6255a3c 0 35 35 0000002 [SLPQ wait 0xc6255a3c][SLP] sh 35 c62ac000 0 1 35 0004002 [SLPQ wait 0xc62ac000][SLP] sh 34 c6254624 0 0 0 0000204 [SLPQ sdflush 0xc06c05b4][SLP] softdepflush 33 c6254830 0 0 0 0000204 [SLPQ vlruwt 0xc6254830][SLP] vnlru 32 c6254a3c 0 0 0 0000204 [SLPQ syncer 0xc06ad91c][SLP] synce= r 31 c6254c48 0 0 0 0000204 [SLPQ psleep 0xc06b94cc][SLP] bufda= emon 30 c6255000 0 0 0 000020c [RUNQ] pagezero 29 c625520c 0 0 0 0000204 [SLPQ psleep 0xc06c1074][SLP] vmdae= mon 28 c6255418 0 0 0 0000204 [SLPQ psleep 0xc06c1030][SLP] paged= aemon 27 c6013624 0 0 0 0000204 [CPU 2] swi0: sio 26 c6013830 0 0 0 0000204 [CPU 0] irq1: atkbd0 25 c6013a3c 0 0 0 0000204 [IWAIT] irq38: ips0 24 c6013c48 0 0 0 0000204 [IWAIT] irq16: bge0 bge1 23 c6065000 0 0 0 0000204 [IWAIT] irq9: acpi0 22 c606520c 0 0 0 0000204 [IWAIT] swi6: task queue 9 c6065418 0 0 0 0000204 [SLPQ - 0xc6063e00][SLP] kqueue tas= kq 21 c6065624 0 0 0 0000204 [IWAIT] swi2: cambio 8 c6065830 0 0 0 0000204 [SLPQ - 0xc6064080][SLP] acpi_task2 7 c6065a3c 0 0 0 0000204 [SLPQ - 0xc6064080][SLP] acpi_task1 6 c5fbe20c 0 0 0 0000204 [SLPQ - 0xc6064080][SLP] acpi_task0 20 c5fbe418 0 0 0 0000204 [IWAIT] swi5: + 5 c5fbe624 0 0 0 0000204 [SLPQ - 0xc6011680][SLP] thread tas= kq 19 c5fbe830 0 0 0 0000204 [IWAIT] swi6: + 18 c5fbea3c 0 0 0 0000204 [SLPQ - 0xc06aa6c0][SLP] yarrow 4 c5fbec48 0 0 0 0000204 [SLPQ - 0xc06ab0a8][SLP] g_down 3 c6013000 0 0 0 0000204 [SLPQ - 0xc06ab0a4][SLP] g_up 2 c601320c 0 0 0 0000204 [SLPQ - 0xc06ab09c][SLP] g_event 17 c6013418 0 0 0 0000204 [IWAIT] swi3: vm 16 c5fb9000 0 0 0 000020c [RUNQ] swi4: clock sio 15 c5fb920c 0 0 0 0000204 [IWAIT] swi1: net 14 c5fb9418 0 0 0 000020c [Can run] idle: cpu0 13 c5fb9624 0 0 0 000020c [CPU 1] idle: cpu1 12 c5fb9830 0 0 0 000020c [Can run] idle: cpu2 11 c5fb9a3c 0 0 0 000020c [CPU 3] idle: cpu3 1 c5fb9c48 0 0 1 0004200 [SLPQ wait 0xc5fb9c48][SLP] init 10 c5fbe000 0 0 0 0000204 [SLPQ ktrace 0xc06abaf8][SLP] ktrac= e 0 c06ab1a0 0 0 0 0000200 [IWAIT] swapper db> bt 53 Tracing pid 53 tid 100045 td 0xc62aa190 sched_switch(c62aa190,0,1,9d27eb6c,5d3de4fa) at sched_switch+0x146 mi_switch(1,0,c62aa190,0,e8a9cab0) at mi_switch+0x1d5 sched_bind(c62aa190,0,c6278360,0,10) at sched_bind+0x68 cpu_est_clockrate(0,e8a9cad4,1,e8a9cadc,c07a8550) at cpu_est_clockrate+0xdc acpi_px_get(c6064e00,e8a9cb34,c06864a8,1,c0c45200) at acpi_px_get+0xda cf_get_method(c6086580,c62d5000,c0686478,1,c0c5b440) at cf_get_method+0x21a cpufreq_curr_sysctl(c608bb80,c6044800,0,e8a9cbf8,e8a9cbf8) at cpufreq_curr_sysctl+0x93 sysctl_root(0,e8a9cc68,4,e8a9cbf8,c62aa190) at sysctl_root+0x12d userland_sysctl(c62aa190,e8a9cc68,4,0,bfbfdc0c) at userland_sysctl+0x122 __sysctl(c62aa190,e8a9cd04,18,c627f700,e8a9cd10) at __sysctl+0xda syscall(bfbf003b,3b,bfbf003b,bfbfdc0c,bfbfe4d0) at syscall+0x34f Xint0x80_syscall() at Xint0x80_syscall+0x1f --- syscall (202, FreeBSD ELF32, __sysctl), eip =3D 0x481204bb, esp =3D 0xbfbfdb8c, ebp =3D 0xbfbfdbb8 --- db> reset cpu_reset: Restarting BSP cpu_reset_proxy: Stopped CPU 2 /boot.config: -hConsoles: serial port -- Pawel