From owner-freebsd-bugs@FreeBSD.ORG Mon Feb 11 19:40:00 2013 Return-Path: Delivered-To: freebsd-bugs@smarthost.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by hub.freebsd.org (Postfix) with ESMTP id A0C58EEB for ; Mon, 11 Feb 2013 19:40:00 +0000 (UTC) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [IPv6:2001:1900:2254:206c::16:87]) by mx1.freebsd.org (Postfix) with ESMTP id 86B6B9C6 for ; Mon, 11 Feb 2013 19:40:00 +0000 (UTC) Received: from freefall.freebsd.org (localhost [127.0.0.1]) by freefall.freebsd.org (8.14.6/8.14.6) with ESMTP id r1BJe0FP079965 for ; Mon, 11 Feb 2013 19:40:00 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.14.6/8.14.6/Submit) id r1BJe0he079964; Mon, 11 Feb 2013 19:40:00 GMT (envelope-from gnats) Resent-Date: Mon, 11 Feb 2013 19:40:00 GMT Resent-Message-Id: <201302111940.r1BJe0he079964@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, Marcin Wisnicki Received: from mx1.freebsd.org (mx1.FreeBSD.org [8.8.178.115]) by hub.freebsd.org (Postfix) with ESMTP id 83326BC8 for ; Mon, 11 Feb 2013 19:32:41 +0000 (UTC) (envelope-from nobody@FreeBSD.org) Received: from red.freebsd.org (red.freebsd.org [IPv6:2001:4f8:fff6::22]) by mx1.freebsd.org (Postfix) with ESMTP id 5CD2695A for ; Mon, 11 Feb 2013 19:32:41 +0000 (UTC) Received: from red.freebsd.org (localhost [127.0.0.1]) by red.freebsd.org (8.14.5/8.14.5) with ESMTP id r1BJWf5Z010993 for ; Mon, 11 Feb 2013 19:32:41 GMT (envelope-from nobody@red.freebsd.org) Received: (from nobody@localhost) by red.freebsd.org (8.14.5/8.14.5/Submit) id r1BJWfTw010992; Mon, 11 Feb 2013 19:32:41 GMT (envelope-from nobody) Message-Id: <201302111932.r1BJWfTw010992@red.freebsd.org> Date: Mon, 11 Feb 2013 19:32:41 GMT From: Marcin Wisnicki To: freebsd-gnats-submit@FreeBSD.org X-Send-Pr-Version: www-3.1 Subject: kern/176034: UNEXPECTED SU+J INCONSISTENCY X-BeenThere: freebsd-bugs@freebsd.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: Bug reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 11 Feb 2013 19:40:00 -0000 >Number: 176034 >Category: kern >Synopsis: UNEXPECTED SU+J INCONSISTENCY >Confidential: no >Severity: non-critical >Priority: low >Responsible: freebsd-bugs >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Mon Feb 11 19:40:00 UTC 2013 >Closed-Date: >Last-Modified: >Originator: Marcin Wisnicki >Release: FreeBSD 9.1-STABLE #2 r246611 >Organization: >Environment: FreeBSD ghost.pnet.one.pl 9.1-STABLE FreeBSD 9.1-STABLE #2 r246611+8e48f63: Mon Feb 11 14:24:23 CET 2013 root@ghost.pnet.one.pl:/usr/obj/home/system/ghost/usr/src/sys/GENERIC_DEBUG amd64 >Description: I'll start with questions: ad1. What could cause this ? ad2.1. Outputs seem to be interspersed and hardly readable. If fscks run in parallel then maybe each line should be prefixed with device name, not just errors. ad2.2. Why journaled fsck does not fall back to full fsck like it does when started manually ? ad4. / was initially marked clean even though there was some serious damage. Here goes actual report: 1. After update from 9.1-PRE-r242516 to 9.1-S-r246611 and second restart (from new kernel): > sync;sync;sync > shutdown -r now --- 8< --- Syncing disks, vnodes remaining...9 9 3 4 2 2 2 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 timed out Syncing disks, buffers remaining... 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 Giving up on 1 buffers 1 1 1 1 1 Uptime: 1d16h43m55s --- 8< --- 2. I'm using UFS SU+J for all filesystems, one of them (mounted at /home) failed to recover after restart: --- 8< --- Starting file system checks: ** SU+J Recovering /dev/gpt/ghost-root ** Reading 33554432 byte journal from inode 4. ** Building recovery table. ** Resolving unreferenced inode list. ** Processing journal entries. ** 176 journal records in 12288 bytes for 45.83% utilization ** Freed 0 inodes (0 dirs) 2 blocks, and 0 frags. ***** FILE SYSTEM MARKED CLEAN ***** /dev/gpt/ghost-root-backup: FILE SYSTEM CLEAN; SKIPPING CHECKS /dev/gpt/ghost-root-backup: clean, 3546046 free (14 frags, 443254 blocks, 0.0% fragmentation) ** SU+J Recovering /dev/gpt/ghost_tank2_enc.eli ** Reading 33554432 byte journal from inode 14. ** SU+J Recovering /dev/ufs/tank3 ** Reading 33554432 byte journal from inode 4. ** SU+J Recovering /dev/gpt/ghost-squid ** Reading 33554432 byte journal from inode 4. ** SU+J Recovering /dev/gpt/ghost-home ** Reading 33554432 byte journal from inode 4. ** Building recovery table. ** Resolving unreferenced inode list. ** Processing journal entries. ***** FILE SYSTEM MARKED CLEAN ***** ** Building recovery table. ** Resolving unreferenced inode list. ** Processing journal entries. ** 10 journal records in 12288 bytes for 2.60% utilization ** Freed 0 inodes (0 dirs) 0 blocks, and 0 frags. ***** FILE SYSTEM MARKED CLEAN ***** ** Building recovery table. ** Building recovery table. ** Resolving unreferenced inode list. ** Processing journal entries. ** Resolving unreferenced inode list. ** Processing journal entries. /dev/gpt/ghost-home: ino 23836056 nlink manipulation error, new link 65535, old link 2 /dev/gpt/ghost-home: UNEXPECTED SU+J INCONSISTENCY /dev/gpt/ghost-home: INTERNAL ERROR: GOT TO reply() /dev/gpt/ghost-home: UNEXPECTED SOFT UPDATE INCONSISTENCY; RUN fsck MANUALLY. ** 1222 journal records in 48640 bytes for 80.39% utilization ** Freed 0 inodes (0 dirs) 17 blocks, and 0 frags. ***** FILE SYSTEM MARKED CLEAN ***** THE FOLLOWING FILE SYSTEM HAD AN UNEXPECTED INCONSISTENCY: ufs: /dev/gpt/ghost-home (/home) Automatic file system check failed; help! ERROR: ABORTING BOOT (sending SIGTERM to parent)! --- 8< --- 3. Not good :( --- 8< --- # fsck -y /dev/gpt/ghost-home ** /dev/gpt/ghost-home USE JOURNAL? yes ** SU+J Recovering /dev/gpt/ghost-home ** Reading 33554432 byte journal from inode 4. RECOVER? yes ** Building recovery table. ** Resolving unreferenced inode list. ** Processing journal entries. ino 23836056 nlink manipulation error, new link 65535, old link 2 UNEXPECTED SU+J INCONSISTENCY FALLBACK TO FULL FSCK? yes ** Skipping journal, falling through to full fsck ** Last Mounted on /home ** Phase 1 - Check Blocks and Sizes ** Phase 2 - Check Pathnames ** Phase 3 - Check Connectivity UNREF DIR I=23836406 OWNER=gdm MODE=40755 SIZE=512 MTIME=Feb 11 17:55 2013 RECONNECT? yes DIR I=23836406 CONNECTED. PARENT WAS I=23836056 --- 8< --- + lots of other UNREF DIR and UNREF FILE 4. OK, now reboot, 1st try: --- 8< --- Starting jails:panic: ufs_dirrem: Bad link count 2 on parent cpuid = 1 KDB: stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a/frame 0xffffff812399c640 kdb_backtrace() at kdb_backtrace+0x37/frame 0xffffff812399c700 panic() at panic+0x1ce/frame 0xffffff812399c800 ufs_rmdir() at ufs_rmdir+0x1dc/frame 0xffffff812399c840 VOP_RMDIR_APV() at VOP_RMDIR_APV+0x34/frame 0xffffff812399c860 null_bypass() at null_bypass+0xd3/frame 0xffffff812399c9b0 VOP_RMDIR_APV() at VOP_RMDIR_APV+0x59/frame 0xffffff812399c9d0 kern_rmdirat() at kern_rmdirat+0x21a/frame 0xffffff812399cb10 ia32_syscall() at ia32_syscall+0x550/frame 0xffffff812399cc30 Xint0x80_syscall() at Xint0x80_syscall+0x91/frame 0xffffff812399cc30 --- syscall (137, FreeBSD ELF32, sys_rmdir), rip = 0x280d8683, rsp = 0xffffcd3c, rbp = 0xffffcd68 --- Uptime: 52s --- 8< --- 5. Crap :/ (kgdb) p cnp->cn_pnbuf $3 = 0xfffffe0006dd3c00 "/tmp/./.font-unix" Also lots of errors slightly due to missing named.conf. Turns out /etc/namedb symlink is unreadable. Another restart into single mode. This time running fsck -fy. No /lost+found, recreated /etc/namedb manually. Another restart and things seem to be back to normal. >How-To-Repeat: >Fix: >Release-Note: >Audit-Trail: >Unformatted: