From owner-freebsd-bugs@FreeBSD.ORG Sun Oct 23 06:10:15 2005 Return-Path: X-Original-To: freebsd-bugs@hub.freebsd.org Delivered-To: freebsd-bugs@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 100BE16A41F for ; Sun, 23 Oct 2005 06:10:15 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 4AE9C43D49 for ; Sun, 23 Oct 2005 06:10:14 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j9N6AEYM094096 for ; Sun, 23 Oct 2005 06:10:14 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j9N6AEMj094095; Sun, 23 Oct 2005 06:10:14 GMT (envelope-from gnats) Resent-Date: Sun, 23 Oct 2005 06:10:14 GMT Resent-Message-Id: <200510230610.j9N6AEMj094095@freefall.freebsd.org> Resent-From: FreeBSD-gnats-submit@FreeBSD.org (GNATS Filer) Resent-To: freebsd-bugs@FreeBSD.org Resent-Reply-To: FreeBSD-gnats-submit@FreeBSD.org, "Frank Mayhar" Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 0925B16A41F for ; Sun, 23 Oct 2005 06:01:55 +0000 (GMT) (envelope-from frank@exit.com) Received: from tinker.exit.com (tinker.exit.com [206.223.0.1]) by mx1.FreeBSD.org (Postfix) with ESMTP id 8630043D4C for ; Sun, 23 Oct 2005 06:01:54 +0000 (GMT) (envelope-from frank@exit.com) Received: from realtime.exit.com (realtime [206.223.0.5]) by tinker.exit.com (8.13.4/8.13.4) with ESMTP id j9N61sh7025874 for ; Sat, 22 Oct 2005 23:01:54 -0700 (PDT) (envelope-from frank@exit.com) Message-Id: <1130047313.0@realtime.exit.com> Date: Sat, 22 Oct 2005 23:01:53 -0700 From: "Frank Mayhar" To: "FreeBSD gnats submit" X-Send-Pr-Version: gtk-send-pr 0.4.6 Cc: Subject: kern/87861: "panic: initiate_write_inodeblock_ufs2: already started" on 6.0-RC1 X-BeenThere: freebsd-bugs@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Bug reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 23 Oct 2005 06:10:15 -0000 >Number: 87861 >Category: kern >Synopsis: "panic: initiate_write_inodeblock_ufs2: already started" on 6.0-RC1 >Confidential: no >Severity: serious >Priority: high >Responsible: freebsd-bugs >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Sun Oct 23 06:10:13 GMT 2005 >Closed-Date: >Last-Modified: >Originator: Frank Mayhar >Release: FreeBSD 6.0-RC1 i386 >Organization: Exit Consulting >Environment: FreeBSD jill.exit.com 6.0-RC1 FreeBSD 6.0-RC1 #2: Sat Oct 22 20:42:16 PDT 2005 frank@jill.exit.com:/usr/obj/usr/src/sys/JILL i386 >Description: I installed an Intel SRCU42L RAID controller today. I also upgraded the system to 6.0-RC1 after running into the same problem in 5.4-stable. The running system is up-to-the-minute, build today after a fresh update. The upshot is that I built a RAID-5 array, created a file system and proceeded to fill it with the stuff I planned to move onto it. After a very short time (like, less than a minute), I see the following: g_vfs_done():da6s1e[WRITE(offset=982941696, length=131072)]error = 16 (A lot of these, at various offsets and of various lengths.) g_vfs_done():da6s1e[WRITE(offset=972455936, length=81920)]error = 16 g_vfs_done():da6s1e[WRITE(offset=972587008, length=32768)]error = 16 panic: initiate_write_inodeblock_ufs2: already started cpuid = 1 Uptime: 6m0s Dumping 1535 MB (3 chunks) chunk 0: 1MB (158 pages) ... ok chunk 1: 1534MB (392688 pages) 1518 1502 1486 1470 1454 1438 1422 1406 1390 1374 1358 1342 1326 1310 1294 1278 1262 1246 1230 1214 1198 1182 1166 1150 1134 1118 1102 1086 1070 1054 1038 1022 1006 990 974 958 942 926 910 894 878 862 846 830 814 798 782 766 750 734 718 702 686 670 654 638 622 606 590 574 558 542 526 510 494 478 462 446 430 414 398 382 366 350 334 318 302 286 270 254 238 222 206 190 174 158 142 126 110 94 78 62 46 30 14 ... ok chunk 2: 1MB (128 pages) ... ok Dump complete iir0: Flushing all Host Drives. Please wait ... g_vfs_done():da6s1e[WRITE(offset=970031104, length=10240)]error = 16 g_vfs_done():da6s1e[WRITE(offset=970072064, length=8192)]error = 16 I saved the corefile. The traceback is (kgdb) bt #0 doadump () at pcpu.h:165 #1 0xc04f4373 in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:399 #2 0xc04f46c9 in panic ( fmt=0xc066f652 "initiate_write_inodeblock_ufs2: already started") at /usr/src/sys/kern/kern_shutdown.c:555 #3 0xc05ce986 in initiate_write_inodeblock_ufs2 (inodedep=0xc360e500, bp=0x0) at /usr/src/sys/ufs/ffs/ffs_softdep.c:3865 #4 0xc05ce187 in softdep_disk_io_initiation (bp=0xd6ca5eb0) at /usr/src/sys/ufs/ffs/ffs_softdep.c:3600 #5 0xc05d600e in ffs_geom_strategy (bo=0xc309e2e0, bp=0xd6ca5eb0) at buf.h:422 #6 0xc053acdc in bufwrite (bp=0xd6ca5eb0) at buf.h:415 #7 0xc05d5fce in ffs_bufwrite (bp=0xd6ca5eb0) at /usr/src/sys/ufs/ffs/ffs_vfsops.c:1663 #8 0xc053c707 in vfs_bio_awrite (bp=0xd6ca5eb0) at buf.h:399 #9 0xc054387c in vop_stdfsync (ap=0xe718bcc0) at /usr/src/sys/kern/vfs_default.c:417 #10 0xc04a73e7 in devfs_fsync (ap=0xe718bcc0) at /usr/src/sys/fs/devfs/devfs_vnops.c:307 #11 0xc0644134 in VOP_FSYNC_APV (vop=0x0, a=0x0) at vnode_if.c:1020 #12 0xc054b6bf in sync_vnode (bo=0xc309e2e0, td=0xc2ca6900) at vnode_if.h:537 #13 0xc054b9dd in sched_sync () at /usr/src/sys/kern/vfs_subr.c:1664 #14 0xc04de109 in fork_exit (callout=0xc054b784 , arg=0x0, frame=0xe718bd38) at /usr/src/sys/kern/kern_fork.c:789 #15 0xc0627c1c in fork_trampoline () at /usr/src/sys/i386/i386/exception.s:208 I'll keep the vmcore around for as long as possible; let me know if you want more information from it. Note that this _only_ seems to happen on the RAID device, not on any of the other SCSI drives. Here's the system dmesg, just for grins: Copyright (c) 1992-2005 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.0-RC1 #2: Sat Oct 22 20:42:16 PDT 2005 frank@jill.exit.com:/usr/obj/usr/src/sys/JILL Timecounter "i8254" frequency 1193182 Hz quality 0 CPU: AMD Athlon(tm) MP 2800+ (2133.43-MHz 686-class CPU) Origin = "AuthenticAMD" Id = 0x6a0 Stepping = 0 Features=0x383fbff AMD Features=0xc0480800 real memory = 1610088448 (1535 MB) avail memory = 1568432128 (1495 MB) ACPI APIC Table: FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs cpu0 (BSP): APIC ID: 1 cpu1 (AP): APIC ID: 0 MADT: Forcing active-low polarity and level trigger for SCI ioapic0 irqs 0-23 on motherboard npx0: [FAST] npx0: on motherboard npx0: INT 16 interface acpi0: on motherboard acpi0: Power Button (fixed) acpi0: Sleep Button (fixed) pci_link0: irq 11 on acpi0 pci_link1: irq 5 on acpi0 pci_link2: irq 9 on acpi0 pci_link3: irq 10 on acpi0 Timecounter "ACPI-safe" frequency 3579545 Hz quality 1000 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x8008-0x800b on acpi0 cpu0: on acpi0 cpu1: on acpi0 acpi_button0: on acpi0 pcib0: port 0xcf8-0xcff,0x8000-0x807f,0x8080-0x80ff iomem 0xd8000-0xdbfff on acpi0 pci0: on pcib0 pcib1: at device 1.0 on pci0 pci1: on pcib1 isab0: at device 7.0 on pci0 isa0: on isab0 atapci0: port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xf000-0xf00f at device 7.1 on pci0 ata0: on atapci0 ata1: on atapci0 pci0: at device 7.3 (no driver attached) iir0: mem 0xf6200000-0xf6203fff irq 20 at device 8.0 on pci0 iir0: [GIANT-LOCKED] em0: port 0x1000-0x103f mem 0xf4080000-0xf409ffff,0xf4000000-0xf403ffff irq 21 at device 9.0 on pci0 em0: Ethernet address: 00:04:23:a8:b2:24 em0: Speed:N/A Duplex:N/A em1: port 0x1040-0x107f mem 0xf40a0000-0xf40bffff,0xf4040000-0xf407ffff irq 22 at device 9.1 on pci0 em1: Ethernet address: 00:04:23:a8:b2:25 em1: Speed:N/A Duplex:N/A em2: port 0x1080-0x10bf mem 0xf40c0000-0xf40dffff irq 23 at device 11.0 on pci0 em2: Ethernet address: 00:e0:81:2b:ac:bc em2: Speed:N/A Duplex:N/A pcib2: at device 16.0 on pci0 pci2: on pcib2 ohci0: mem 0xf4102000-0xf4102fff irq 19 at device 0.0 on pci2 ohci0: [GIANT-LOCKED] usb0: OHCI version 1.0, legacy support usb0: SMM does not respond, resetting usb0: on ohci0 usb0: USB revision 1.0 uhub0: AMD OHCI root hub, class 9/0, rev 1.00/1.00, addr 1 uhub0: 4 ports with 4 removable, self powered ohci1: mem 0xf4103000-0xf4103fff irq 16 at device 4.0 on pci2 ohci1: [GIANT-LOCKED] usb1: OHCI version 1.0 usb1: on ohci1 usb1: USB revision 1.0 uhub1: NEC OHCI root hub, class 9/0, rev 1.00/1.00, addr 1 uhub1: 3 ports with 3 removable, self powered ohci2: mem 0xf4104000-0xf4104fff irq 17 at device 4.1 on pci2 ohci2: [GIANT-LOCKED] usb2: OHCI version 1.0 usb2: on ohci2 usb2: USB revision 1.0 uhub2: NEC OHCI root hub, class 9/0, rev 1.00/1.00, addr 1 uhub2: 2 ports with 2 removable, self powered ehci0: mem 0xf4107000-0xf41070ff irq 18 at device 4.2 on pci2 ehci0: [GIANT-LOCKED] usb3: EHCI version 0.95 usb3: companion controllers, 3 ports each: usb1 usb2 usb3: on ehci0 usb3: USB revision 2.0 uhub3: NEC EHCI root hub, class 9/0, rev 2.00/1.00, addr 1 uhub3: 5 ports with 5 removable, self powered uhub4: vendor 0x050d product 0x0234, class 9/0, rev 2.00/1.00, addr 2 uhub4: single transaction translator uhub4: 4 ports with 4 removable, self powered sym0: <1010-66> port 0x2000-0x20ff mem 0xf4107400-0xf41077ff,0xf4100000-0xf4101fff irq 17 at device 5.0 on pci2 sym0: Symbios NVRAM, ID 7, Fast-80, LVD, parity checking sym0: open drain IRQ line driver, using on-chip SRAM sym0: using LOAD/STORE-based firmware. sym0: handling phase mismatch from SCRIPTS. sym0: [GIANT-LOCKED] pci2: at device 7.0 (no driver attached) fxp0: port 0x2800-0x283f mem 0xf4106000-0xf4106fff,0xf4120000-0xf413ffff irq 18 at device 8.0 on pci2 miibus0: on fxp0 inphy0: on miibus0 inphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto fxp0: Ethernet address: 00:e0:81:2b:ac:bd atkbdc0: port 0x60,0x64 irq 1 on acpi0 atkbd0: irq 1 on atkbdc0 kbd0 at atkbd0 atkbd0: [GIANT-LOCKED] psm0: irq 12 on atkbdc0 psm0: [GIANT-LOCKED] psm0: model VersaPad, device ID 0 sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 sio0: type 16550A, console sio1: <16550A-compatible COM port> port 0x2f8-0x2ff irq 3 on acpi0 sio1: type 16550A ppc0: port 0x378-0x37f,0x778-0x77f irq 7 drq 3 on acpi0 ppc0: SMC-like chipset (ECP/EPP/PS2/NIBBLE) in COMPATIBLE mode ppc0: FIFO with 16/16/9 bytes threshold ppbus0: on ppc0 lpt0: on ppbus0 lpt0: Interrupt-driven port ppi0: on ppbus0 fdc0: port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on acpi0 fdc0: [FAST] orm0: at iomem 0xc0000-0xc7fff,0xc8000-0xc97ff,0xcf000-0xd2fff,0xe0000-0xe3fff on isa0 sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=0x100> vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 uhub1: device problem (SET_ADDR_FAILED), disabling port 2 uhub2: device problem (SET_ADDR_FAILED), disabling port 1 Timecounters tick every 1.000 msec Waiting 10 seconds for SCSI devices to settle (noperiph:sym0:0:-1:-1): SCSI BUS reset delivered. (probe7:sym0:0:8:0): M_REJECT to send for : 1-6-4-a-0-3e-1-0. ses0 at iir0 bus 0 target 15 lun 0 ses0: Removable Processor SCSI-3 device ses0: SAF-TE Compliant Device ses1 at iir0 bus 1 target 15 lun 0 ses1: Removable Processor SCSI-3 device ses1: SAF-TE Compliant Device pt0 at iir0 bus 0 target 15 lun 0 pt0: Removable Processor SCSI-3 device pt1 at iir0 bus 1 target 15 lun 0 pt1: Removable Processor SCSI-3 device da4 at iir0 bus 2 target 0 lun 0 da4: Fixed Direct Access SCSI-2 device da4: Tagged Queueing Enabled da4: 208084MB (426156255 512 byte sectors: 255H 63S/T 26527C) da5 at iir0 bus 2 target 8 lun 0 da5: Fixed Direct Access SCSI-2 device da5: Tagged Queueing Enabled da5: 139878MB (286471080 512 byte sectors: 255H 63S/T 17832C) da6 at iir0 bus 2 target 14 lun 0 da6: Fixed Direct Access SCSI-2 device da6: Tagged Queueing Enabled da6: 139878MB (286471080 512 byte sectors: 255H 63S/T 17832C) da0 at sym0 bus 0 target 0 lun 0 da0: Fixed Direct Access SCSI-3 device da0: 160.000MB/s transfers (80.000MHz, offset 62, 16bit), Tagged Queueing Enabled da0: 35020MB (71722776 512 byte sectors: 255H 63S/T 4464C) da1 at sym0 bus 0 target 1 lun 0 da1: Fixed Direct Access SCSI-3 device da1: 160.000MB/s transfers (80.000MHz, offset 62, 16bit), Tagged Queueing Enabled da1: 70513MB (144410880 512 byte sectors: 255H 63S/T 8989C) SMP: AP CPU #1 Launched! da3 at sym0 bus 0 target 10 lun 0 da3: Fixed Direct Access SCSI-3 device da3: 160.000MB/s transfers (80.000MHz, offset 62, 16bit), Tagged Queueing Enabled da3: 17537MB (35916548 512 byte sectors: 255H 63S/T 2235C) da2 at sym0 bus 0 target 8 lun 0 da2: Fixed Direct Access SCSI-3 device da2: 80.000MB/s transfers (40.000MHz, offset 31, 16bit), Tagged Queueing Enabled da2: 70007MB (143374738 512 byte sectors: 255H 63S/T 8924C) GEOM_LABEL: Label for provider da3s1 is ext2fs//usr/local. Trying to mount root from ufs:/dev/da0s1a WARNING: / was not properly dismounted WARNING: /amanda was not properly dismounted WARNING: /spare was not properly dismounted WARNING: /usr was not properly dismounted WARNING: /usr/local was not properly dismounted WARNING: /var was not properly dismounted WARNING: /var/amanda was not properly dismounted WARNING: /var/spool was not properly dismounted WARNING: /usr/obj was not properly dismounted WARNING: /usr/ports was not properly dismounted WARNING: /usr/src was not properly dismounted WARNING: /cvs was not properly dismounted em1: link state changed to UP >How-To-Repeat: See above. >Fix: >Release-Note: >Audit-Trail: >Unformatted: