From owner-freebsd-stable@FreeBSD.ORG Tue Jan 8 03:48:45 2008 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 8E27316A501 for ; Tue, 8 Jan 2008 03:48:45 +0000 (UTC) (envelope-from aw1@stade.co.uk) Received: from lon-mail-3.gradwell.net (lon-mail-3.gradwell.net [193.111.201.127]) by mx1.freebsd.org (Postfix) with ESMTP id CF0C713C442 for ; Tue, 8 Jan 2008 03:48:44 +0000 (UTC) (envelope-from aw1@stade.co.uk) Received: from 5aca3c8f.bb.sky.com ([90.202.60.143] helo=access2.hanley.stade.co.uk) by lon-mail-3.gradwell.net with esmtp (Gradwell gwh-smtpd 1.275) id 4782e94c.2a73.49 for freebsd-stable@freebsd.org; Tue, 8 Jan 2008 03:09:00 +0000 (envelope-sender ) Received: from steerpike.hanley.stade.co.uk (steerpike [192.168.1.10]) by access2.hanley.stade.co.uk (8.14.1/8.14.1) with ESMTP id m0838xNR057768 for ; Tue, 8 Jan 2008 03:08:59 GMT (envelope-from aw1@steerpike.hanley.stade.co.uk) Received: from steerpike.hanley.stade.co.uk (localhost [127.0.0.1]) by steerpike.hanley.stade.co.uk (8.14.2/8.14.2) with ESMTP id m0838xu2003350 for ; Tue, 8 Jan 2008 03:08:59 GMT (envelope-from aw1@steerpike.hanley.stade.co.uk) Received: (from aw1@localhost) by steerpike.hanley.stade.co.uk (8.14.2/8.14.2/Submit) id m0838wZx003333 for freebsd-stable@freebsd.org; Tue, 8 Jan 2008 03:08:58 GMT (envelope-from aw1) Date: Tue, 8 Jan 2008 03:08:57 +0000 From: Adrian Wontroba To: freebsd-stable@freebsd.org Message-ID: <20080108030857.GA93021@steerpike.hanley.stade.co.uk> Mail-Followup-To: Adrian Wontroba , freebsd-stable@freebsd.org Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline User-Agent: Mutt/1.4.2.3i X-Operating-System: FreeBSD 7.0-PRERELEASE Organization: Oh dear, I've joined one again. X-Virus-Scanned: ClamAV 0.91.2/5428/Tue Jan 8 02:45:48 2008 on access2.hanley.stade.co.uk X-Virus-Scanned: ClamAV 0.92/5428/Tue Jan 8 02:45:48 2008 on steerpike.hanley.stade.co.uk X-Virus-Status: Clean Subject: RELENG7 using lpt causes panic X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: aw1@stade.co.uk List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 08 Jan 2008 03:48:45 -0000 I've recently switched some of my home systems to RELENG7. All seemed fairly well until I tried printing a CUPS test page on my backup and print server to an elderly Laserjet IIIp, where I seem to have a reproducible panic. It has happened twice. This is painful, as I have a big home fileystem (striped over two mirrors over most of two 500 GB disks). The gmirror syncronisation and background fsck leave the system close to unusable for hours while they fight over the disks. I was somewhat startled that something so basic as printing causes a panic. There have been no hardware changes since I last printed under RELENG6, but I don't print often, so hardware decay is a possibility. Is this a known problem? If not, I'll take the time to try various tests (with /home unmounted) and raise a PR. I envisage tests such as: * Does switching to a kernel without SMP and apic make a difference? * Does direct output cause a crash? * Does polling make a difference? * Does the parallel port mode (I think extended at present) make a difference? Some detail below. Throwaway comment: On my workstation I find that a GENERIC - SMP - apic + SCHED_ULE kernel is MUCH more responsive during buildworld than a GENERIC kernel. console / dmesg =============== lpt0: [GIANT-LOCKED] lpt0: [ITHREAD] lpt0: [GIANT-LOCKED] lpt0: [ITHREAD] Fatal trap 30: reserved (unknown) fault while in kernel mode cpuid = 0; apic id = 00 instruction pointer = 0x20:0xc0a5747b stack pointer = 0x28:0xe67ea968 frame pointer = 0x28:0xe67ea96c code segment = base 0x0, limit 0xfffff, type 0x1b = DPL 0, pres 1, def32 1, gran 1 processor eflags = interrupt enabled, IOPL = 0 current process = 1421 (parallel) trap number = 30 panic: reserved (unknown) fault cpuid = 0 Uptime: 23m3s Physical memory: 1011 MB Dumping 168 MB: 153 137 121 105 89 73 57 41 25 9 Dump complete Which? ====== RELENG7 cvsupped and built in the late evening of Sunday 06/01/07 [root@rottcodd ~]# uname -a FreeBSD rottcodd.hanley.stade.co.uk 7.0-PRERELEASE FreeBSD 7.0-PRERELEASE #0: Sun Jan 6 23:33:45 GMT 2008 toor@steerpike.hanley.stade.co.uk:/usr/obj/usr/src/sys/GENERIC i386 kgdb ==== [root@rottcodd ~]# kgdb /boot/kernel/kernel.symbols /var/crash/vmcore.1 [GDB will not be able to debug user-mode threads: /usr/lib/libthread_db.so: Undefined symbol "ps_pglobal_lookup"] GNU gdb 6.1.1 [FreeBSD] Copyright 2004 Free Software Foundation, Inc. GDB is free software, covered by the GNU General Public License, and you are welcome to change it and/or distribute copies of it under certain conditions. Type "show copying" to see the conditions. There is absolutely no warranty for GDB. Type "show warranty" for details. This GDB was configured as "i386-marcel-freebsd". Unread portion of the kernel message buffer: Fatal trap 30: reserved (unknown) fault while in kernel mode cpuid = 0; apic id = 00 instruction pointer = 0x20:0xc0a5747b stack pointer = 0x28:0xe67ea968 frame pointer = 0x28:0xe67ea96c code segment = base 0x0, limit 0xfffff, type 0x1b = DPL 0, pres 1, def32 1, gran 1 processor eflags = interrupt enabled, IOPL = 0 current process = 1421 (parallel) trap number = 30 panic: reserved (unknown) fault cpuid = 0 Uptime: 23m3s Physical memory: 1011 MB Dumping 168 MB: 153 137 121 105 89 73 57 41 25 9 #0 doadump () at pcpu.h:195 195 pcpu.h: No such file or directory. in pcpu.h (kgdb) where #0 doadump () at pcpu.h:195 #1 0xc0753f07 in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:409 #2 0xc07541c9 in panic (fmt=Variable "fmt" is not available. ) at /usr/src/sys/kern/kern_shutdown.c:563 #3 0xc0a6737c in trap_fatal (frame=0xe67ea928, eva=0) at /usr/src/sys/i386/i386/trap.c:899 #4 0xc0a6813d in trap (frame=0xe67ea928) at /usr/src/sys/i386/i386/trap.c:686 #5 0xc0a4df4b in calltrap () at /usr/src/sys/i386/i386/exception.s:139 #6 0xc0a5747b in spinlock_exit () at cpufunc.h:365 #7 0xc0a53e20 in ioapic_program_intpin (intpin=0xc3f05d3c) at /usr/src/sys/i386/i386/io_apic.c:273 #8 0xc0a541b1 in ioapic_disable_intr (isrc=0xc3f05d3c) at /usr/src/sys/i386/i386/io_apic.c:375 #9 0xc0a530bc in intr_remove_handler (cookie=0xc47019c0) at /usr/src/sys/i386/i386/intr_machdep.c:208 #10 0xc0a5f1b1 in nexus_teardown_intr (dev=0xc3fc4a80, child=0xc4199980, r=0xc419d6c0, ih=0xc47019c0) at /usr/src/sys/i386/i386/nexus.c:498 #11 0xc0774942 in bus_generic_teardown_intr (dev=0xc3fc4180, child=0xc4199980, irq=0xc419d6c0, cookie=0xc47019c0) at bus_if.h:416 #12 0xc0774942 in bus_generic_teardown_intr (dev=0xc3f52d00, child=0xc4199980, irq=0xc419d6c0, cookie=0xc47019c0) at bus_if.h:416 #13 0xc0774942 in bus_generic_teardown_intr (dev=0xc403d600, child=0xc4199980, irq=0xc419d6c0, cookie=0xc47019c0) at bus_if.h:416 #14 0xc063653d in pci_teardown_intr (dev=0xc403d600, child=0xc4199980, irq=0xc419d6c0, cookie=0xc47019c0) at /usr/src/sys/dev/pci/pci.c:2866 #15 0xc0774942 in bus_generic_teardown_intr (dev=0xc403d500, child=0xc4199980, irq=0xc419d6c0, cookie=0xc47019c0) at bus_if.h:416 #16 0xc0a6c732 in isa_teardown_intr (bus=0xc416fe80, child=0xc4199980, r=0xc419d6c0, cookie=0xc47019c0) at bus_if.h:416 #17 0xc0648d41 in ppc_teardown_intr (bus=0xc419a400, child=0xc4199980, r=0xc419d6c0, ih=0xc47019c0) at bus_if.h:416 #18 0xc0645e2e in ppbus_teardown_intr (bus=0xc4199b80, child=0xc4199980, r=0xc419d6c0, ih=0xc47019c0) at bus_if.h:416 #19 0xc06468e3 in ppb_release_bus (bus=0xc4199b80, dev=0xc4199980) at bus_if.h:416 #20 0xc0642271 in lpt_release_ppbus (dev=0xc4199980) at /usr/src/sys/dev/ppbus/lpt.c:227 #21 0xc06430e5 in lptwrite (dev=0xc4156c00, uio=0xe67eac60, ioflag=0) at /usr/src/sys/dev/ppbus/lpt.c:826 #22 0xc07209ac in giant_write (dev=0xc4156c00, uio=0xe67eac60, ioflag=0) at /usr/src/sys/kern/kern_conf.c:373 #23 0xc06e9442 in devfs_write_f (fp=0xc507b2d0, uio=0xe67eac60, cred=0xc506d500, flags=0, td=0xc4a8f840) at /usr/src/sys/fs/devfs/devfs_vnops.c:1304 #24 0xc0786f87 in dofilewrite (td=0xc4a8f840, fd=5, fp=0xc507b2d0, auio=0xe67eac60, offset=-1, flags=0) at file.h:254 #25 0xc0787268 in kern_writev (td=0xc4a8f840, fd=5, auio=0xe67eac60) at /usr/src/sys/kern/sys_generic.c:401 #26 0xc07872df in write (td=0xc4a8f840, uap=0xe67eacfc) at /usr/src/sys/kern/sys_generic.c:317 #27 0xc0a67955 in syscall (frame=0xe67ead38) at /usr/src/sys/i386/i386/trap.c:1035 #28 0xc0a4dfb0 in Xint0x80_syscall () at /usr/src/sys/i386/i386/exception.s:196 #29 0x00000033 in ?? () Previous frame inner to this frame (corrupt stack?) (kgdb) quit dmesg.boot ========== Copyright (c) 1992-2008 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 is a registered trademark of The FreeBSD Foundation. FreeBSD 7.0-PRERELEASE #0: Sun Jan 6 23:33:45 GMT 2008 toor@steerpike.hanley.stade.co.uk:/usr/obj/usr/src/sys/GENERIC module_register: module g_label already exists! Module g_label failed to register: 17 Timecounter "i8254" frequency 1193182 Hz quality 0 CPU: AMD Athlon(tm) XP 3200+ (2205.02-MHz 686-class CPU) Origin = "AuthenticAMD" Id = 0x6a0 Stepping = 0 Features=0x383fbff AMD Features=0xc0400800 real memory = 1073676288 (1023 MB) avail memory = 1037062144 (989 MB) ACPI APIC Table: 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 (Jan 6 2008 23:33:21) acpi0: on motherboard acpi0: [ITHREAD] acpi0: Power Button (fixed) Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x808-0x80b on acpi0 cpu0: on acpi0 acpi_button0: on acpi0 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 agp0: on hostb0 agp0: aperture size is 128M pcib1: at device 1.0 on pci0 pci1: on pcib1 vgapci0: mem 0xde000000-0xdeffffff,0xc0000000-0xcfffffff irq 16 at device 0.0 on pci1 atapci0: port 0xec00-0xec07,0xe800-0xe803,0xe400-0xe407,0xe000-0xe003,0xdc00-0xdc0f mem 0xdfffc000-0xdfffffff irq 16 at device 5.0 on pci0 atapci0: [ITHREAD] ata2: on atapci0 ata2: [ITHREAD] ata3: on atapci0 ata3: [ITHREAD] atapci1: port 0xd800-0xd807,0xd400-0xd403,0xd000-0xd007,0xcc00-0xcc03,0xc800-0xc80f mem 0xdfff4000-0xdfff7fff irq 19 at device 7.0 on pci0 atapci1: [ITHREAD] ata4: on atapci1 ata4: [ITHREAD] ata5: on atapci1 ata5: [ITHREAD] bge0: mem 0xdffb0000-0xdffbffff irq 18 at device 11.0 on pci0 miibus0: on bge0 brgphy0: PHY 1 on miibus0 brgphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-FDX, auto bge0: Ethernet address: 00:0c:76:e9:64:ee bge0: [ITHREAD] fwohci0: port 0xc400-0xc47f mem 0xdfff3800-0xdfff3fff irq 17 at device 14.0 on pci0 fwohci0: [FILTER] fwohci0: OHCI version 1.0 (ROM=1) fwohci0: No. of Isochronous channels is 8. fwohci0: EUI64 00:10:dc:00:00:5e:9f:42 fwohci0: Phy 1394a available S400, 3 ports. fwohci0: Link S400, max_rec 2048 bytes. firewire0: on fwohci0 fwe0: on firewire0 if_fwe0: Fake Ethernet address: 02:10:dc:5e:9f:42 fwe0: Ethernet address: 02:10:dc:5e:9f:42 fwip0: on firewire0 fwip0: Firewire address: 00:10:dc:00:00:5e:9f:42 @ 0xfffe00000000, S400, maxrec 2048 sbp0: on firewire0 dcons_crom0: on firewire0 dcons_crom0: bus_addr 0x134c000 fwohci0: Initiate bus reset fwohci0: BUS reset fwohci0: node_id=0xc800ffc0, gen=1, CYCLEMASTER mode atapci2: port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xfc00-0xfc0f at device 15.0 on pci0 ata0: on atapci2 ata0: [ITHREAD] ata1: on atapci2 ata1: [ITHREAD] uhci0: port 0xb400-0xb41f irq 21 at device 16.0 on pci0 uhci0: [GIANT-LOCKED] uhci0: [ITHREAD] usb0: on uhci0 usb0: USB revision 1.0 uhub0: on usb0 uhub0: 2 ports with 2 removable, self powered uhci1: port 0xb800-0xb81f irq 21 at device 16.1 on pci0 uhci1: [GIANT-LOCKED] uhci1: [ITHREAD] usb1: on uhci1 usb1: USB revision 1.0 uhub1: on usb1 uhub1: 2 ports with 2 removable, self powered uhci2: port 0xbc00-0xbc1f irq 21 at device 16.2 on pci0 uhci2: [GIANT-LOCKED] uhci2: [ITHREAD] usb2: on uhci2 usb2: USB revision 1.0 uhub2: on usb2 uhub2: 2 ports with 2 removable, self powered uhci3: port 0xc000-0xc01f irq 21 at device 16.3 on pci0 uhci3: [GIANT-LOCKED] uhci3: [ITHREAD] usb3: on uhci3 usb3: USB revision 1.0 uhub3: on usb3 uhub3: 2 ports with 2 removable, self powered ehci0: mem 0xdfff3600-0xdfff36ff irq 21 at device 16.4 on pci0 ehci0: [GIANT-LOCKED] ehci0: [ITHREAD] usb4: EHCI version 1.0 usb4: companion controllers, 2 ports each: usb0 usb1 usb2 usb3 usb4: on ehci0 usb4: USB revision 2.0 uhub4: on usb4 uhub4: 8 ports with 8 removable, self powered isab0: at device 17.0 on pci0 isa0: on isab0 pci0: at device 17.5 (no driver attached) acpi_button1: on acpi0 atkbdc0: port 0x60,0x64 irq 1 on acpi0 atkbd0: irq 1 on atkbdc0 kbd0 at atkbd0 atkbd0: [GIANT-LOCKED] atkbd0: [ITHREAD] psm0: irq 12 on atkbdc0 psm0: [GIANT-LOCKED] psm0: [ITHREAD] psm0: model Generic PS/2 mouse, device ID 0 fdc0: port 0x3f2-0x3f3,0x3f4-0x3f5,0x3f7 irq 6 drq 2 on acpi0 fdc0: [FILTER] fd0: <1440-KB 3.5" drive> on fdc0 drive 0 sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 sio0: type 16550A sio0: [FILTER] sio1: <16550A-compatible COM port> port 0x2f8-0x2ff irq 3 on acpi0 sio1: type 16550A sio1: [FILTER] pmtimer0 on isa0 orm0: at iomem 0xc0000-0xcefff,0xcf000-0xd17ff,0xd1800-0xd3fff,0xd4000-0xd57ff pnpid ORM0000 on isa0 ppc0: at port 0x378-0x37f irq 7 on isa0 ppc0: SMC-like chipset (ECP/EPP/PS2/NIBBLE) in COMPATIBLE mode ppc0: FIFO with 16/16/9 bytes threshold ppbus0: on ppc0 plip0: on ppbus0 lpt0: on ppbus0 lpt0: Interrupt-driven port ppi0: on ppbus0 ppc0: [GIANT-LOCKED] ppc0: [ITHREAD] sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=0x300> vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 Timecounter "TSC" frequency 2205018060 Hz quality 800 Timecounters tick every 1.000 msec hptrr: no controller detected. firewire0: 1 nodes, maxhop <= 0, cable IRM = 0 (me) firewire0: bus manager 0 (me) The GEOM class LABEL is already loaded. acd0: DVDR at ata0-master UDMA33 ad4: 476940MB at ata2-master UDMA100 ad6: 476940MB at ata3-master UDMA100 ad8: 476940MB at ata4-master UDMA100 ad10: 476940MB at ata5-master UDMA100 GEOM_MIRROR: Device mirror/gmrcvar1 launched (2/2). GEOM_MIRROR: Device mirror/gmrcusr1 launched (2/2). GEOM_MIRROR: Device mirror/gmrcswp1 launched (2/2). GEOM_MIRROR: Device mirror/gmrchom1 launched (2/2). GEOM_MIRROR: Device mirror/gmrcroot launched (4/4). GEOM_MIRROR: Device mirror/gmrcvar2 launched (2/2). GEOM_MIRROR: Device mirror/gmrcusr2 launched (2/2). GEOM_MIRROR: Device mirror/gmrcswp2 launched (2/2). GEOM_MIRROR: Device mirror/gmrchom2 launched (2/2). GEOM_STRIPE: Device gsrcvar created (id=937835587). GEOM_STRIPE: Disk mirror/gmrcvar1 attached to gsrcvar. GEOM_STRIPE: Device gsrcusr created (id=533043218). GEOM_STRIPE: Disk mirror/gmrcusr1 attached to gsrcusr. GEOM_STRIPE: Device gsrcswp created (id=534629169). GEOM_STRIPE: Disk mirror/gmrcswp1 attached to gsrcswp. GEOM_STRIPE: Device gsrchom created (id=2161269149). GEOM_STRIPE: Disk mirror/gmrchom1 attached to gsrchom. GEOM_LABEL: Label for provider mirror/gmrcroot is ufs/rcroot. GEOM_STRIPE: Disk mirror/gmrcvar2 attached to gsrcvar. GEOM_STRIPE: Device gsrcvar activated. GEOM_STRIPE: Disk mirror/gmrcusr2 attached to gsrcusr. GEOM_STRIPE: Device gsrcusr activated. GEOM_STRIPE: Disk mirror/gmrcswp2 attached to gsrcswp. GEOM_STRIPE: Device gsrcswp activated. GEOM_STRIPE: Disk mirror/gmrchom2 attached to gsrchom. GEOM_STRIPE: Device gsrchom activated. GEOM_LABEL: Label for provider stripe/gsrcvar is ufs/rcvar. GEOM_LABEL: Label for provider stripe/gsrcusr is ufs/rcusr. GEOM_LABEL: Label for provider stripe/gsrcswp is label/rcswap. GEOM_LABEL: Label for provider stripe/gsrchom is ufs/rchome. Trying to mount root from ufs:/dev/ufs/rcroot bge0: link state changed to UP -- Adrian Wontroba If it happens once, it's a bug. If it happens twice, it's a feature. If it happens more than twice, it's a design philosophy.