From owner-freebsd-bugs@FreeBSD.ORG Sat May 24 18:00:11 2008 Return-Path: Delivered-To: freebsd-bugs@hub.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 2E21A10656A8 for ; Sat, 24 May 2008 18:00:11 +0000 (UTC) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [IPv6:2001:4f8:fff6::28]) by mx1.freebsd.org (Postfix) with ESMTP id 215428FC30 for ; Sat, 24 May 2008 18:00:11 +0000 (UTC) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.14.2/8.14.2) with ESMTP id m4OI0A0n015019 for ; Sat, 24 May 2008 18:00:10 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.14.2/8.14.1/Submit) id m4OI0Af2015018; Sat, 24 May 2008 18:00:10 GMT (envelope-from gnats) Resent-Date: Sat, 24 May 2008 18:00:10 GMT Resent-Message-Id: <200805241800.m4OI0Af2015018@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, "Lev A. Serebryakov" Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 9A325106567B for ; Sat, 24 May 2008 17:54:08 +0000 (UTC) (envelope-from lev@ftp.translate.ru) Received: from ftp.translate.ru (ftp.translate.ru [195.131.4.140]) by mx1.freebsd.org (Postfix) with ESMTP id D835A8FC21 for ; Sat, 24 May 2008 17:54:07 +0000 (UTC) (envelope-from lev@ftp.translate.ru) Received: by ftp.translate.ru (Postfix, from userid 1000) id B547A13DF4B; Sat, 24 May 2008 21:54:06 +0400 (MSD) Message-Id: <20080524175406.B547A13DF4B@ftp.translate.ru> Date: Sat, 24 May 2008 21:54:06 +0400 (MSD) From: "Lev A. Serebryakov" To: FreeBSD-gnats-submit@FreeBSD.org X-Send-Pr-Version: 3.113 Cc: Subject: bin/123962: gjournal (455Gb data, 8Gb journal), options INVARIANTS, files written via samba3, remove = panic ffs_truncate3 X-BeenThere: freebsd-bugs@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: "Lev A. Serebryakov" List-Id: Bug reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 24 May 2008 18:00:11 -0000 >Number: 123962 >Category: bin >Synopsis: gjournal (455Gb data, 8Gb journal), options INVARIANTS, files written via samba3, remove = panic ffs_truncate3 >Confidential: no >Severity: serious >Priority: medium >Responsible: freebsd-bugs >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Sat May 24 18:00:10 UTC 2008 >Closed-Date: >Last-Modified: >Originator: Lev A. Serebryakov >Release: FreeBSD 7.0-STABLE amd64 >Organization: >Environment: System: FreeBSD blob.home.serebryakov.spb.ru 7.0-STABLE FreeBSD 7.0-STABLE #0: Sat May 24 17:25:59 MSD 2008 lev@blob.home.serebryakov.spb.ru:/usr/obj/usr/src/sys/BLOB amd64 ================================ KERNEL CONFIG cpu HAMMER ident BLOB makeoptions DEBUG=-g # Build kernel with gdb(1) debug symbols options DDB options KDB options KDB_UNATTENDED options INVARIANTS options INVARIANT_SUPPORT options WITNESS options DEBUG_MEMGUARD options WITNESS_KDB options MUTEX_DEBUG options SCHED_ULE # ULE scheduler options PREEMPTION # Enable kernel thread preemption options INET # InterNETworking options FFS # Berkeley Fast Filesystem options SOFTUPDATES # Enable FFS soft updates support options UFS_ACL # Support for access control lists options UFS_DIRHASH # Improve performance on big directories options UFS_GJOURNAL # Enable gjournal-based UFS journaling options MD_ROOT # MD is a potential root device options NFSCLIENT # Network Filesystem Client options NFSSERVER # Network Filesystem Server options NFSLOCKD # Network Lock Manager options PROCFS # Process filesystem (requires PSEUDOFS) options PSEUDOFS # Pseudo-filesystem framework options GEOM_LABEL # Provides labelization options COMPAT_43TTY # BSD 4.3 TTY compat [KEEP THIS!] options COMPAT_IA32 # Compatible with i386 binaries options COMPAT_FREEBSD4 # Compatible with FreeBSD4 options COMPAT_FREEBSD5 # Compatible with FreeBSD5 options COMPAT_FREEBSD6 # Compatible with FreeBSD6 options SCSI_DELAY=5000 # Delay (in ms) before probing SCSI options KTRACE # ktrace(1) support options STACK # stack(9) support options SYSVSHM # SYSV-style shared memory options SYSVMSG # SYSV-style message queues options SYSVSEM # SYSV-style semaphores options _KPOSIX_PRIORITY_SCHEDULING # POSIX P1003_1B real-time extensions options KBD_INSTALL_CDEV # install a CDEV entry in /dev options ADAPTIVE_GIANT # Giant mutex is adaptive. options STOP_NMI # Stop CPUS using NMI instead of IPI options AUDIT # Security event auditing # Make an SMP-capable kernel by default options SMP # Symmetric MultiProcessor Kernel # CPU frequency control device cpufreq device coretemp device smb device smbus device ichsmb device iicbus device iicsmb device iic # Bus support. device acpi device pci # ATA and ATAPI devices device ata device atadisk # ATA disk drives options ATA_STATIC_ID # Static device numbering # atkbdc0 controls both the keyboard and the PS/2 mouse device atkbdc # AT keyboard controller device atkbd # AT keyboard device psm # PS/2 mouse device kbdmux # keyboard multiplexer device vga # VGA video card driver # syscons is the default console driver, resembling an SCO console device sc # Serial (COM) ports device sio # 8250, 16[45]50 based serial ports device uart # Generic UART driver # Parallel port device ppc device ppbus # Parallel port bus (required) device em # Intel PRO/1000 adapter Gigabit Ethernet Card # Pseudo devices. device loop # Network loopback device random # Entropy device device ether # Ethernet support device tun # Packet tunnel. device pty # Pseudo-ttys (telnet etc) device md # Memory "disks" device firmware # firmware assist module # The `bpf' device enables the Berkeley Packet Filter. # Be aware of the administrative consequences of enabling this! # Note that 'bpf' is required for DHCP. device bpf # Berkeley packet filter # USB support device uhci # UHCI PCI->USB interface device ehci # EHCI PCI->USB interface (USB 2.0) device usb # USB Bus (required) # FireWire support device firewire # FireWire bus code ================================ KERNEL CONFIG =================================== 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-STABLE #0: Sat May 24 17:25:59 MSD 2008 lev@blob.home.serebryakov.spb.ru:/usr/obj/usr/src/sys/BLOB WARNING: WITNESS option enabled, expect reduced performance. MEMGUARD DEBUGGING ALLOCATOR INITIALIZED: MEMGUARD map base: 0xffffffff80a22000 MEMGUARD map limit: 0xffffffff83223000 MEMGUARD map size: 41947136 (Bytes) Timecounter "i8254" frequency 1193182 Hz quality 0 CPU: Intel(R) Core(TM)2 Duo CPU E4500 @ 2.20GHz (2200.10-MHz K8-class CPU) Origin = "GenuineIntel" Id = 0x6fd Stepping = 13 Features=0xbfebfbff Features2=0xe39d AMD Features=0x20100800 AMD Features2=0x1 Cores per package: 2 usable memory = 4217020416 (4021 MB) avail memory = 4057751552 (3869 MB) ACPI APIC Table: FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs cpu0 (BSP): APIC ID: 0 cpu1 (AP): APIC ID: 1 WITNESS: spin lock intrcnt not in order list ioapic0 irqs 0-23 on motherboard kbd1 at kbdmux0 acpi0: on motherboard acpi0: [ITHREAD] acpi0: Power Button (fixed) acpi0: reservation of 0, a0000 (3) failed acpi0: reservation of 100000, cfd00000 (3) failed Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x808-0x80b on acpi0 acpi_hpet0: iomem 0xfed00000-0xfed003ff on acpi0 Timecounter "HPET" frequency 14318180 Hz quality 900 cpu0: on acpi0 ACPI Warning (tbutils-0243): Incorrect checksum in table [OEMB] - 51, should be 4C [20070320] coretemp0: on cpu0 est0: on cpu0 est0: Setting 2200 MHz p4tcc0: on cpu0 cpu1: on acpi0 coretemp1: on cpu1 est1: on cpu1 est1: Setting 2200 MHz p4tcc1: on cpu1 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 vgapci0: port 0xec00-0xec07 mem 0xfea80000-0xfeafffff,0xd0000000-0xdfffffff,0xfe900000-0xfe9fffff irq 16 at device 2.0 on pci0 pci0: at device 3.0 (no driver attached) em0: port 0xe880-0xe89f mem 0xfea40000-0xfea5ffff,0xfea7a000-0xfea7afff irq 20 at device 25.0 on pci0 em0: [FILTER] em0: Ethernet address: 00:1e:8c:75:03:0d uhci0: port 0xe400-0xe41f irq 16 at device 26.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 0xe480-0xe49f irq 21 at device 26.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 0xe800-0xe81f irq 18 at device 26.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 ehci0: mem 0xfea7b800-0xfea7bbff irq 18 at device 26.7 on pci0 ehci0: [GIANT-LOCKED] ehci0: [ITHREAD] usb3: EHCI version 1.0 usb3: companion controllers, 2 ports each: usb0 usb1 usb2 usb3: on ehci0 usb3: USB revision 2.0 uhub3: on usb3 uhub3: 6 ports with 6 removable, self powered uhci3: port 0xdc00-0xdc1f irq 23 at device 29.0 on pci0 uhci3: [GIANT-LOCKED] uhci3: [ITHREAD] usb4: on uhci3 usb4: USB revision 1.0 uhub4: on usb4 uhub4: 2 ports with 2 removable, self powered uhci4: port 0xe000-0xe01f irq 19 at device 29.1 on pci0 uhci4: [GIANT-LOCKED] uhci4: [ITHREAD] usb5: on uhci4 usb5: USB revision 1.0 uhub5: on usb5 uhub5: 2 ports with 2 removable, self powered uhci5: port 0xe080-0xe09f irq 18 at device 29.2 on pci0 uhci5: [GIANT-LOCKED] uhci5: [ITHREAD] usb6: on uhci5 usb6: USB revision 1.0 uhub6: on usb6 uhub6: 2 ports with 2 removable, self powered ehci1: mem 0xfea7b400-0xfea7b7ff irq 23 at device 29.7 on pci0 ehci1: [GIANT-LOCKED] ehci1: [ITHREAD] usb7: EHCI version 1.0 usb7: companion controllers, 2 ports each: usb4 usb5 usb6 usb7: on ehci1 usb7: USB revision 2.0 uhub7: on usb7 uhub7: 6 ports with 6 removable, self powered pcib1: at device 30.0 on pci0 pci1: on pcib1 fwohci0: mem 0xfebff000-0xfebfffff irq 20 at device 2.0 on pci1 fwohci0: [FILTER] fwohci0: OHCI version 1.0 (ROM=1) fwohci0: No. of Isochronous channels is 8. fwohci0: EUI64 00:1e:8c:00:00:1a:5f:da fwohci0: Phy 1394a available S400, 2 ports. fwohci0: Link S400, max_rec 2048 bytes. firewire0: on fwohci0 fwohci0: Initiate bus reset fwohci0: BUS reset fwohci0: node_id=0xc800ffc0, gen=1, CYCLEMASTER mode isab0: at device 31.0 on pci0 isa0: on isab0 atapci0: port 0xd800-0xd807,0xd480-0xd483,0xd400-0xd407,0xd080-0xd083,0xd000-0xd01f mem 0xfea79800-0xfea79fff irq 22 at device 31.2 on pci0 atapci0: [ITHREAD] atapci0: AHCI Version 01.20 controller with 6 ports detected ata2: on atapci0 ata2: [ITHREAD] ata3: on atapci0 ata3: [ITHREAD] ata4: on atapci0 ata4: [ITHREAD] ata5: on atapci0 ata5: [ITHREAD] ata6: on atapci0 ata6: [ITHREAD] ata7: on atapci0 ata7: [ITHREAD] ichsmb0: port 0x400-0x41f mem 0xfea7b000-0xfea7b0ff irq 18 at device 31.3 on pci0 ichsmb0: [GIANT-LOCKED] ichsmb0: [ITHREAD] smbus0: on ichsmb0 smb0: on smbus0 pci0: at device 31.6 (no driver attached) acpi_button0: on acpi0 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 ppbus0: [ITHREAD] ppc0: [GIANT-LOCKED] ppc0: [ITHREAD] sio0: configured irq 4 not in bitmap of probed irqs 0 sio0: port may not be enabled sio0: configured irq 4 not in bitmap of probed irqs 0 sio0: port may not be enabled sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 sio0: type 16550A sio0: [FILTER] atkbdc0: port 0x60,0x64 irq 1 on acpi0 atkbd0: irq 1 on atkbdc0 kbd0 at atkbd0 atkbd0: [GIANT-LOCKED] atkbd0: [ITHREAD] orm0: at iomem 0xcb800-0xcc7ff on isa0 sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=0x300> 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 firewire0: 1 nodes, maxhop <= 0, cable IRM = 0 (me) firewire0: bus manager 0 (me) ad4: 305245MB at ata2-master SATA300 ad6: 476940MB at ata3-master SATA300 ad10: 476940MB at ata5-master SATA300 ad12: 476940MB at ata6-master SATA300 ad14: 476940MB at ata7-master SATA300 SMP: AP CPU #1 Launched! WARNING: WITNESS option enabled, expect reduced performance. Trying to mount root from ufs:/dev/ad4s1a WARNING: / was not properly dismounted WARNING: /tmp was not properly dismounted WARNING: /usr was not properly dismounted WARNING: /var was not properly dismounted /var: mount pending error: blocks 12 files 1 =================================== dmesg.boot >Description: Kernel is prepared to hunt bugs: invariants, witness, etc. is enables (see kernel config). gjournal created on raw 500Gb disk with 8Gb journal on partition of system disk. Filesystem with default options is created on jourrnalled volume (-J is used, of course). New filesystem is mounted as /usr/home/storage /usr/home storage is shared with samba3 from ports (default options) as R/W. 1-8Gb files (16Mb each) copied from worksation to share. `rm *' is issued locally (deleting via samba "works" too), and `ffs_truncate3' invariant is triggered! Copying files from local filesystems doesn't trigger bug. 100% reproducable. >How-To-Repeat: Script started on Sat May 24 21:21:31 2008 blob# kldstat Id Refs Address Size Name 1 1 0xffffffff80100000 640258 kernel blob# gjournal load blob# gjournal label /dev/ad6 /dev/ad2s1g blob# gjournal status Name Status Components ad6.journal N/A ad6 blob# gjournal list Geom name: gjournal 1954268551 ID: 1954268551 Providers: 1. Name: ad6.journal Mediasize: 500107861504 (466G) Sectorsize: 512 Mode: r0w0e0 Consumers: 1. Name: ad6 Mediasize: 500107862016 (466G) Sectorsize: 512 Mode: r1w1e1 Role: Data 2. Name: ad4s1g Mediasize: 8590787584 (8.0G) Sectorsize: 512 Mode: r1w1e1 Jend: 8590787072 Jstart: 0 Role: Journal blob#newfs -O2 -J /dev/ad6.journal /dev/ad6.journal: 476940.0MB (976773164 sectors) block size 16384, fragment size 2048 using 2597 cylinder groups of 183.72MB, 11758 blks, 23552 inodes. super-block backups (for fsck -b #) at: 160, 376416, 752672, 1128928, 1505184, 1881440, 2257696, 2633952, 3010208, 3386464, 3762720, 4138976, 4515232, 4891488, 5267744, 5644000, 6020256, 6396512, 6772768, 7149024, [...SKIPPED...] 970364384, 970740640, 971116896, 971493152, 971869408, 972245664, 972621920, 972998176, 973374432, 973750688, 974126944, 974503200, 974879456, 975255712, 975631968, 976008224, 976384480, 976760736 blob# gjournal sync blob# mount /dev/ad6.journal /usr/home/storage blob# cd /usr/home/storage blob# ls .snap blob# df -h Filesystem Size Used Avail Capacity Mounted on /dev/ad4s1a 989M 567M 343M 62% / devfs 1.0K 1.0K 0B 100% /dev /dev/ad4s1e 989M 16K 910M 0% /tmp /dev/ad4s1f 267G 5.7G 240G 2% /usr /dev/ad4s1d 7.7G 482M 6.7G 7% /var gateway:/usr/ports 68G 62G 490M 99% /usr/ports /dev/ad6.journal 451G 4.0K 415G 0% /usr/home/storage [...FILES ARE COPIED HERE...] blob# ls _IGP0006.DNG _IGP0015.DNG _IGP0036.DNG _IGP0064.DNG _IGP0070.DNG _IGP0077.DNG _IGP0081.DNG _IGP0095.DNG _IGP0099.DNG _IGP0111.DNG _IGP0123.DNG _IGP0008.DNG _IGP0020.DNG _IGP0061.DNG _IGP0065.DNG _IGP0071.DNG _IGP0078.DNG _IGP0082.DNG _IGP0096.DNG _IGP0100.DNG _IGP0113.DNG _IGP0010.DNG _IGP0026.DNG _IGP0062.DNG _IGP0067.DNG _IGP0072.DNG _IGP0079.DNG _IGP0083.DNG _IGP0097.DNG _IGP0104.DNG _IGP0114.DNG _IGP0014.DNG _IGP0033.DNG _IGP0063.DNG _IGP0069.DNG _IGP0076.DNG _IGP0080.DNG _IGP0084.DNG _IGP0098.DNG _IGP0108.DNG _IGP0116.DNG blob# rm * panic: ffs_truncate3 ================================ kernel backtrace Unread portion of the kernel message buffer: panic: ffs_truncate3 cpuid = 0 Uptime: 17m33s Physical memory: 4021 MB Dumping 474 MB: 459 443 427 411 395 379 363 347 331 315 299 283 267 251 235 219 203 187 171 155 139 123 107 91 75 59 43 27 11 Reading symbols from /boot/kernel/geom_raid5.ko...Reading symbols from /boot/kernel/geom_raid5.ko.symbols...done. done. Loaded symbols for /boot/kernel/geom_raid5.ko Reading symbols from /boot/kernel/geom_journal.ko...Reading symbols from /boot/kernel/geom_journal.ko.symbols...done. done. Loaded symbols for /boot/kernel/geom_journal.ko #0 doadump () at pcpu.h:194 194 __asm __volatile("movq %%gs:0,%0" : "=r" (td)); (kgdb) bt #0 doadump () at pcpu.h:194 #1 0xffffffff8025bf68 in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:418 #2 0xffffffff8025c3ef in panic (fmt=Variable "fmt" is not available. ) at /usr/src/sys/kern/kern_shutdown.c:572 #3 0xffffffff8036efae in ffs_truncate (vp=0xffffff0007376000, length=0, flags=Variable "flags" is not available. ) at /usr/src/sys/ufs/ffs/ffs_inode.c:494 #4 0xffffffff8038a52f in ufs_inactive (ap=Variable "ap" is not available. ) at /usr/src/sys/ufs/ufs/ufs_inode.c:132 #5 0xffffffff802d4bce in vinactive (vp=0xffffff0007376000, td=0xffffff0004ede000) at vnode_if.h:796 #6 0xffffffff802d6f16 in vput (vp=0xffffff0007376000) at /usr/src/sys/kern/vfs_subr.c:2224 #7 0xffffffff802dc297 in kern_unlink (td=0xffffff0004ede000, path=0x90a550
, pathseg=UIO_USERSPACE) at /usr/src/sys/kern/vfs_syscalls.c:1713 #8 0xffffffff803d4c7f in syscall (frame=0xffffffffb1c38c70) at /usr/src/sys/amd64/amd64/trap.c:852 #9 0xffffffff803bbc2b in Xfast_syscall () at /usr/src/sys/amd64/amd64/exception.S:290 #10 0x0000000801152adc in ?? () Previous frame inner to this frame (corrupt stack?) (kgdb) ================================ kernel backtrace >Fix: >Release-Note: >Audit-Trail: >Unformatted: