From owner-freebsd-fs@FreeBSD.ORG Sat Mar 5 16:47:09 2011 Return-Path: Delivered-To: fs@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id C2CCB106564A for ; Sat, 5 Mar 2011 16:47:09 +0000 (UTC) (envelope-from c47g@gmx.at) Received: from mailout-de.gmx.net (mailout-de.gmx.net [213.165.64.22]) by mx1.freebsd.org (Postfix) with SMTP id 45B9F8FC0C for ; Sat, 5 Mar 2011 16:47:08 +0000 (UTC) Received: (qmail invoked by alias); 05 Mar 2011 16:47:07 -0000 Received: from cm203-32.liwest.at (EHLO bones.gusis.at) [81.10.203.32] by mail.gmx.net (mp068) with SMTP; 05 Mar 2011 17:47:07 +0100 X-Authenticated: #9978462 X-Provags-ID: V01U2FsdGVkX19rvKdzpoBrOHZ1fB/GwcCfFFfjwerEvgBuYtZp8A lwcS34vh0Dfksl From: Christian Gusenbauer To: freebsd-current@freebsd.org, fs@freebsd.org Date: Sat, 5 Mar 2011 17:48:44 +0100 User-Agent: KMail/1.13.5 (FreeBSD/9.0-CURRENT; KDE/4.5.5; i386; ; ) References: <201103050851.38930.c47g@gmx.at> <20110305093640.GL78089@deviant.kiev.zoral.com.ua> <201103051736.04605.c47g@gmx.at> In-Reply-To: <201103051736.04605.c47g@gmx.at> MIME-Version: 1.0 Content-Type: Text/Plain; charset="us-ascii" Content-Transfer-Encoding: 7bit Message-Id: <201103051748.44554.c47g@gmx.at> X-Y-GMX-Trusted: 0 Cc: Subject: Re: FS errors during unmount after dump'ing X-BeenThere: freebsd-fs@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Filesystems List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 05 Mar 2011 16:47:09 -0000 OK, the attachment got lost, so here's the dmesg output: Copyright (c) 1992-2011 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 9.0-CURRENT #48 r219265: Fri Mar 4 18:51:23 CET 2011 root@bones.gusis.at:/usr/obj/jail/mytestjail/usr/src/sys/BONES i386 CPU: Intel(R) Core(TM)2 CPU 6600 @ 2.40GHz (2401.97-MHz 686-class CPU) Origin = "GenuineIntel" Id = 0x6f6 Family = 6 Model = f Stepping = 6 Features=0xbfebfbff Features2=0xe3bd AMD Features=0x20100000 AMD Features2=0x1 TSC: P-state invariant real memory = 2147483648 (2048 MB) avail memory = 2086711296 (1990 MB) Event timer "LAPIC" quality 400 ACPI APIC Table: FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs FreeBSD/SMP: 1 package(s) x 2 core(s) cpu0 (BSP): APIC ID: 0 cpu1 (AP): APIC ID: 1 ioapic0 irqs 0-23 on motherboard acpi0: on motherboard acpi0: Power Button (fixed) acpi0: reservation of 0, a0000 (3) failed acpi0: reservation of 100000, 7ff00000 (3) failed 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 Warning: Incorrect checksum in table [OEMB] - 0xD6, should be 0xC9 (20110211/tbutils-282) cpu1: on acpi0 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 pcib1: irq 16 at device 1.0 on pci0 pci1: on pcib1 vgapci0: port 0xac00-0xac7f mem 0xfd000000-0xfdffffff,0xc0000000-0xcfffffff,0xfc000000-0xfcffffff irq 16 at device 0.0 on pci1 nvidia0: on vgapci0 vgapci0: child nvidia0 requested pci_enable_io vgapci0: child nvidia0 requested pci_enable_io uhci0: port 0xe000-0xe01f irq 16 at device 26.0 on pci0 usbus0: on uhci0 uhci1: port 0xe080-0xe09f irq 17 at device 26.1 on pci0 usbus1: on uhci1 ehci0: mem 0xfebff400-0xfebff7ff irq 18 at device 26.7 on pci0 usbus2: EHCI version 1.0 usbus2: on ehci0 hdac0: mem 0xfebf8000-0xfebfbfff irq 22 at device 27.0 on pci0 hdac0: HDA Driver Revision: 20100226_0142 pcib2: irq 16 at device 28.0 on pci0 pci4: on pcib2 pcib3: irq 19 at device 28.3 on pci0 pci3: on pcib3 pci3: at device 0.0 (no driver attached) pcib4: irq 16 at device 28.4 on pci0 pci2: on pcib4 ahci0: mem 0xfe8fe000-0xfe8fffff irq 16 at device 0.0 on pci2 ahci0: AHCI v1.00 with 2 3Gbps ports, Port Multiplier supported ahcich0: at channel 0 on ahci0 ahcich1: at channel 1 on ahci0 atapci0: port 0xbc00-0xbc07,0xb880-0xb883,0xb800-0xb807,0xb480-0xb483,0xb400-0xb40f at device 0.1 on pci2 ata2: on atapci0 uhci2: port 0xd800-0xd81f irq 23 at device 29.0 on pci0 usbus3: on uhci2 uhci3: port 0xd880-0xd89f irq 19 at device 29.1 on pci0 usbus4: on uhci3 uhci4: port 0xdc00-0xdc1f irq 18 at device 29.2 on pci0 usbus5: on uhci4 ehci1: mem 0xfebff000-0xfebff3ff irq 23 at device 29.7 on pci0 usbus6: EHCI version 1.0 usbus6: on ehci1 pcib5: at device 30.0 on pci0 pci5: on pcib5 xl0: <3Com 3c905-TX Fast Etherlink XL> port 0xcc00-0xcc3f irq 23 at device 2.0 on pci5 miibus0: on xl0 nsphy0: PHY 24 on miibus0 nsphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto xl0: Ethernet address: 00:60:97:11:d6:21 pci5: at device 3.0 (no driver attached) isab0: at device 31.0 on pci0 isa0: on isab0 ahci1: port 0xec00-0xec07,0xe880-0xe883,0xe800-0xe807,0xe480-0xe483,0xe400-0xe41f mem 0xfebff800-0xfebfffff irq 19 at device 31.2 on pci0 ahci1: AHCI v1.10 with 6 3Gbps ports, Port Multiplier supported ahcich2: at channel 0 on ahci1 ahcich3: at channel 1 on ahci1 ahcich4: at channel 2 on ahci1 ahcich5: at channel 3 on ahci1 ahcich6: at channel 4 on ahci1 ahcich7: at channel 5 on ahci1 ichsmb0: port 0x400-0x41f irq 18 at device 31.3 on pci0 smbus0: on ichsmb0 smb0: on smbus0 acpi_button0: on acpi0 attimer0: port 0x40-0x43 irq 0 on acpi0 Timecounter "i8254" frequency 1193182 Hz quality 0 Event timer "i8254" frequency 1193182 Hz quality 100 atrtc0: port 0x70-0x71 irq 8 on acpi0 Event timer "RTC" frequency 32768 Hz quality 0 fdc0: port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on acpi0 fd0: <1440-KB 3.5" drive> on fdc0 drive 0 hpet0: iomem 0xfed00000-0xfed003ff on acpi0 Timecounter "HPET" frequency 14318180 Hz quality 900 Event timer "HPET" frequency 14318180 Hz quality 450 Event timer "HPET1" frequency 14318180 Hz quality 440 Event timer "HPET2" frequency 14318180 Hz quality 440 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 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 IntelliMouse Explorer, device ID 4 pmtimer0 on isa0 sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=0x300> vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 ata0 at port 0x1f0-0x1f7,0x3f6 irq 14 on isa0 ata1 at port 0x170-0x177,0x376 irq 15 on isa0 coretemp0: on cpu0 est0: on cpu0 p4tcc0: on cpu0 coretemp1: on cpu1 est1: on cpu1 p4tcc1: on cpu1 Timecounters tick every 1.000 msec vboxdrv: fAsync=0 offMin=0x132 offMax=0x369 hdac0: HDA Codec #0: Analog Devices AD1988A pcm0: at cad 0 nid 1 on hdac0 pcm1: at cad 0 nid 1 on hdac0 pcm2: at cad 0 nid 1 on hdac0 usbus0: 12Mbps Full Speed USB v1.0 usbus1: 12Mbps Full Speed USB v1.0 usbus2: 480Mbps High Speed USB v2.0 usbus3: 12Mbps Full Speed USB v1.0 usbus4: 12Mbps Full Speed USB v1.0 usbus5: 12Mbps Full Speed USB v1.0 usbus6: 480Mbps High Speed USB v2.0 ugen0.1: at usbus0 uhub0: on usbus0 ugen1.1: at usbus1 uhub1: on usbus1 ugen2.1: at usbus2 uhub2: on usbus2 ugen3.1: at usbus3 uhub3: on usbus3 ugen4.1: at usbus4 uhub4: on usbus4 ugen5.1: at usbus5 uhub5: on usbus5 ugen6.1: at usbus6 uhub6: on usbus6 uhub0: 2 ports with 2 removable, self powered uhub1: 2 ports with 2 removable, self powered uhub3: 2 ports with 2 removable, self powered uhub4: 2 ports with 2 removable, self powered uhub5: 2 ports with 2 removable, self powered ada0 at ahcich2 bus 0 scbus2 target 0 lun 0 ada0: ATA-8 SATA 2.x device ada0: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes) ada0: Command Queueing enabled ada0: 305245MB (625142448 512 byte sectors: 16H 63S/T 16383C) cd0 at ahcich6 bus 0 scbus6 target 0 lun 0SMP: AP CPU #1 Launched! cd0: Removable CD-ROM SCSI-0 device cd0: 150.000MB/s transfers (SATA 1.x, WDMA2, ATAPI 12bytes, PIO 8192bytes) cd0: Attempt to query device size failed: NOT READY, Medium not present - tray closed Root mount waiting for: usbus6 usbus2 uhub2: 4 ports with 4 removable, self powered uhub6: 6 ports with 6 removable, self powered Trying to mount root from ufs:/dev/label/root [rw]... ada1 at ahcich0 bus 0 scbus0 target 0 lun 0 ada1: ATA-7 SATA 2.x device ada1: 150.000MB/s transfers (SATA 1.x, UDMA6, PIO 8192bytes) ada1: Command Queueing enabled ada1: 238475MB (488397168 512 byte sectors: 16H 63S/T 16383C) GEOM: ada1s1: geometry does not match label (255h,63s != 16h,63s). GEOM: label/amanda: geometry does not match label (255h,63s != 16h,63s). GEOM: ufsid/4a9e8e3d6361b6c0: geometry does not match label (255h,63s != 16h,63s). handle_workitem_freeblocks: inode 5 block count 84 handle_workitem_freeblocks: inode 328 block count 112 handle_workitem_freeblocks: inode 5 block count 84 GEOM: ada1s1: geometry does not match label (255h,63s != 16h,63s). GEOM: label/amanda: geometry does not match label (255h,63s != 16h,63s). (ada1:ahcich0:0:0:0): lost device (ada1:ahcich0:0:0:0): removing device entry ROOT LOGIN (root) ON ttyv0 exiting on signal 15 kernel boot file is /boot/kernel/kernel /jail: unmount pending error: blocks 112 files 0 softdep_waitidle: Failed to flush worklist for 0xc5bdb510 /data: unmount pending error: blocks 84 files 0 Waiting (max 60 seconds) for system process `vnlru' to stop...done Waiting (max 60 seconds) for system process `bufdaemon' to stop...done Waiting (max 60 seconds) for system process `syncer' to stop... Syncing disks, vnodes remaining...1 0 0 done All buffers synced. softdep_waitidle: Failed to flush worklist for 0xc5bdb510 unmount of /home failed (BUSY) On Saturday 05 March 2011 17:36:04 Christian Gusenbauer wrote: > On Saturday 05 March 2011 10:36:40 Kostik Belousov wrote: > > [Added fs, please remove current on reply]. > > > > On Sat, Mar 05, 2011 at 08:51:38AM +0100, Christian Gusenbauer wrote: > > > Hi! > > > > > > Once in a week I backup my PC using amanda (which uses dump(8)). > > > Subsequently unmounting a filesystem (or during shutdown) I get errors > > > like these: > > > > > > handle_workitem_freeblocks: inode 3579904 block count 384 > > > handle_workitem_freeblocks: inode 3579962 block count 384 > > > /spare: unmount pending error: blocks 768 files 0 > > > softdep_waitidle: Failed to flush worklist for 0xc5be2288 > > > softdep_waitidle: Failed to flush worklist for 0xc5be2288 > > > softdep_waitidle: Failed to flush worklist for 0xc5be2288 > > > softdep_waitidle: Failed to flush worklist for 0xc5be2288 > > > softdep_waitidle: Failed to flush worklist for 0xc5be2288 > > > softdep_waitidle: Failed to flush worklist for 0xc5be2510 > > > softdep_waitidle: Failed to flush worklist for 0xc5be2510 > > > /data: unmount pending error: blocks 84 files 0 > > > > > > Note, I get these messages *only* after dumping filesystems! > > > > > > Is there anything wrong with my filesystems? > > > > > > Any clues? > > > > No clues, you did not provided information even to start looking. > > > > What version of the OS you are using ? > > How do you call dump, in particular, did you specified -L ? > > Are there any hung (unkillable) processes after the issue appeared ? > > Please show all kernel messages, not only the tail of it. > > Hi! > > I'm running current revision 219265. Amanda calls dump like this (ps ax > output): > > 2607 ?? DL 0:00.04 dump 0ubLshf 64 1048576 0 - /dev/label/home (dump) > > so the -L is specified. There are no hung processes. > > I attach a compressed dmesg output. It appears to me, that the > 'handle_workitem_freeblocks' message is printed during the backup. The > other messages are printed during shutdown. > > Thanks, > Christian.