From owner-freebsd-bugs@freebsd.org Tue Oct 31 18:58:04 2017 Return-Path: Delivered-To: freebsd-bugs@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 34318E60F19 for ; Tue, 31 Oct 2017 18:58:04 +0000 (UTC) (envelope-from bugzilla-noreply@freebsd.org) Received: from kenobi.freebsd.org (kenobi.freebsd.org [IPv6:2001:1900:2254:206a::16:76]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 2214E418 for ; Tue, 31 Oct 2017 18:58:04 +0000 (UTC) (envelope-from bugzilla-noreply@freebsd.org) Received: from bugs.freebsd.org ([127.0.1.118]) by kenobi.freebsd.org (8.15.2/8.15.2) with ESMTP id v9VIw3A5041604 for ; Tue, 31 Oct 2017 18:58:03 GMT (envelope-from bugzilla-noreply@freebsd.org) From: bugzilla-noreply@freebsd.org To: freebsd-bugs@FreeBSD.org Subject: [Bug 223348] Inode number for directories change to inode number of directory two levels up causing hierarchy loop Date: Tue, 31 Oct 2017 18:58:04 +0000 X-Bugzilla-Reason: AssignedTo X-Bugzilla-Type: new X-Bugzilla-Watch-Reason: None X-Bugzilla-Product: Base System X-Bugzilla-Component: gnu X-Bugzilla-Version: CURRENT X-Bugzilla-Keywords: X-Bugzilla-Severity: Affects Only Me X-Bugzilla-Who: iz-rpi03@hs-karlsruhe.de X-Bugzilla-Status: New X-Bugzilla-Resolution: X-Bugzilla-Priority: --- X-Bugzilla-Assigned-To: freebsd-bugs@FreeBSD.org X-Bugzilla-Flags: X-Bugzilla-Changed-Fields: bug_id short_desc product version rep_platform op_sys bug_status bug_severity priority component assigned_to reporter Message-ID: Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable X-Bugzilla-URL: https://bugs.freebsd.org/bugzilla/ Auto-Submitted: auto-generated MIME-Version: 1.0 X-BeenThere: freebsd-bugs@freebsd.org X-Mailman-Version: 2.1.23 Precedence: list List-Id: Bug reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 31 Oct 2017 18:58:04 -0000 https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=3D223348 Bug ID: 223348 Summary: Inode number for directories change to inode number of directory two levels up causing hierarchy loop Product: Base System Version: CURRENT Hardware: Any OS: Any Status: New Severity: Affects Only Me Priority: --- Component: gnu Assignee: freebsd-bugs@FreeBSD.org Reporter: iz-rpi03@hs-karlsruhe.de Hi, I ran into this bug on two different systems. - One uses a r324861 amd64 GENERIC-NODEBUG kernel and userland with ZFS, - the other uses a r324918 arm RPI-B kernel an userland with UFS2. The directory hierarchy loop occures on both systems, so I think it is not related to the underlying filesystem. After installing freebsd-uucp from ports and configuring it, there exists a= new directory tree /var/spool/uucp/lyxys/[DX]. At that moment the content of lyxys/D. and lyxys/X. looked as expected. But some time after both looked for ls(1) like a copy of /var/spool/uucp. And indeed ls(1) showed the same inode number for all three directories: 63747 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 /var/spool/uucp 95493 drwxr-xr-x 4 uucp uucp 512 Oct 24 23:53 /var/spool/uucp/lyxys 63747 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 /var/spool/uucp/lyxys/D. 63747 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 /var/spool/uucp/lyxys/X. fsdb(8) showed me different inode numbers than ls(1) for the D. and X. directories. But this can be a mistake, as it was my first use of fsdb. fsck_ufs does not report any error or tries to fix something. As ZFS does not have a fsck, I tried "zpool scrub". Which also did not repo= rt any error. So both internal filesystem structures seem to be OK. Steps tried to reproduce the problem: With ZFS all I can do is a rooback to a earlier snapshot without the /var/spool/uucp directory and start again. As it is easier for me to experiment with the arm system I used the Raspber= ry Pi for the following tests. Trying to get closer to the moment this happens I set up a date(1), ls(1) l= oop on a fresh set up[1] UFS. It showed the inode change in the directory information happend sometime between, 02:57 and 03:57 CEST: Wed Oct 25 02:57:07 CEST 2017 95237 drwxr-xr-x 25 root wheel 512 Oct 24 23:38 /var 102372 drwxr-xr-x 11 root wheel 512 Mar 7 2017 /var/spool/ 102701 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 /var/spool/uucp 102711 drwxr-xr-x 4 uucp uucp 512 Oct 24 23:53 /var/spool/uucp/lyxys 102684 drwxr-xr-x 2 uucp uucp 512 Oct 24 23:53 /var/spool/uucp/lyxys/D. 102685 drwxr-xr-x 2 uucp uucp 512 Oct 24 23:53 /var/spool/uucp/lyxys/X. Wed Oct 25 03:57:08 CEST 2017 95237 drwxr-xr-x 25 root wheel 512 Oct 24 23:38 /var 102372 drwxr-xr-x 11 root wheel 512 Mar 7 2017 /var/spool/ 102701 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 /var/spool/uucp 102711 drwxr-xr-x 4 uucp uucp 512 Oct 24 23:53 /var/spool/uucp/lyxys 102701 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 /var/spool/uucp/lyxys/D. 102701 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 /var/spool/uucp/lyxys/X. As the system was not used actively, the only difference between the hours before and after the change was cron running periodic daily at 03:01:00. In the next step I searched for a way to faster set up the UFS for testing. First I used "dump -0a -f /usr/local/root_dump /" on the arm then moved the SD-card to the amd64 and with newfs -UEt /dev/da0s2a mount /dev/da0s2a /mnt mount -r /dev/da0s3a /tmp/da0s3a/ cd /mnt restore rf /tmp/da0s3a/root_dump rm restoresymtable restored the filesystem. The output of ls(1) showed everything is OK: # ls -lid var/spool/uucp var/spool/uucp/lyxys var/spool/uucp/lyxys/* 95491 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 var/spool/uucp 261 drwxr-xr-x 4 uucp uucp 512 Oct 24 23:53 var/spool/uucp/lyxys 32005 drwxr-xr-x 2 uucp uucp 512 Oct 24 23:53 var/spool/uucp/lyxys/D. 63746 drwxr-xr-x 2 uucp uucp 512 Oct 24 23:53 var/spool/uucp/lyxys/X. #=20 But after booting this filesystem on the arm: # cd /; ls -lid var/spool/uucp var/spool/uucp/lyxys var/spool/uucp/lyxys/* 95491 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 var/spool/uucp 261 drwxr-xr-x 4 uucp uucp 512 Oct 24 23:53 var/spool/uucp/lyxys 95491 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 var/spool/uucp/lyxys/D. 95491 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 var/spool/uucp/lyxys/X. #=20 Again mounted on the amd64 showed the same output. Now I tried just restoring, unmounting and mounting the UFS on the amd64 an= d it looks like it happens immediately with the unmount: # rm restoresymtable=20 # ls -lid var/spool/uucp var/spool/uucp/lyxys var/spool/uucp/lyxys/* 63747 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 var/spool/uucp 95493 drwxr-xr-x 4 uucp uucp 512 Oct 24 23:53 var/spool/uucp/lyxys 261 drwxr-xr-x 2 uucp uucp 512 Oct 24 23:53 var/spool/uucp/lyxys/D. 32002 drwxr-xr-x 2 uucp uucp 512 Oct 24 23:53 var/spool/uucp/lyxys/X. # cd; umount /mnt; mount /dev/da0s2a /mnt; cd /mnt # ls -lid var/spool/uucp var/spool/uucp/lyxys var/spool/uucp/lyxys/* 63747 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 var/spool/uucp 95493 drwxr-xr-x 4 uucp uucp 512 Oct 24 23:53 var/spool/uucp/lyxys 63747 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 var/spool/uucp/lyxys/D. 63747 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 var/spool/uucp/lyxys/X. #=20 So I have two ways of repeating this behaviour: - Waiting till periodiy daily triggers ist somehow. Or calling it immediate= ly. - Restoring the filesystem from dump(8) and unmounting it. Just to complete the information and to demonstrate the loop, this is what = the ls(1) optput looks like without -d: # ls -li var/spool/uucp var/spool/uucp/lyxys var/spool/uucp/lyxys/* var/spool/uucp: total 44 95491 drwxr-xr-x 3 uucp uucp 512 Sep 4 2013 .Failed 259 drwxrwxr-x 2 uucp uucp 512 Feb 7 2017 .Preserve 63748 drwxr-xr-x 2 uucp uucp 512 Sep 4 2013 .Received 95492 drwxrwxr-x 2 uucp uucp 512 Feb 7 2017 .Sequence 260 drwxrwxr-x 2 uucp uucp 512 Sep 4 2013 .Status 32001 drwxrwxr-x 2 uucp uucp 512 Feb 7 2017 .Temp 63749 drwxrwxr-x 2 uucp uucp 512 Feb 7 2017 .Xqtdir 67117 -rw-r--r-- 1 uucp uucp 5959 Nov 24 2014 Log 67118 -rw-r--r-- 1 uucp uucp 3728 Nov 24 2014 Stats 95493 drwxr-xr-x 4 uucp uucp 512 Oct 24 23:53 lyxys var/spool/uucp/lyxys: total 8 63747 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 D. 63747 drwxrwxr-x 10 uucp uucp 512 Feb 7 2017 X. var/spool/uucp/lyxys/D.: total 44 95491 drwxr-xr-x 3 uucp uucp 512 Sep 4 2013 .Failed 259 drwxrwxr-x 2 uucp uucp 512 Feb 7 2017 .Preserve 63748 drwxr-xr-x 2 uucp uucp 512 Sep 4 2013 .Received 95492 drwxrwxr-x 2 uucp uucp 512 Feb 7 2017 .Sequence 260 drwxrwxr-x 2 uucp uucp 512 Sep 4 2013 .Status 32001 drwxrwxr-x 2 uucp uucp 512 Feb 7 2017 .Temp 63749 drwxrwxr-x 2 uucp uucp 512 Feb 7 2017 .Xqtdir 67117 -rw-r--r-- 1 uucp uucp 5959 Nov 24 2014 Log 67118 -rw-r--r-- 1 uucp uucp 3728 Nov 24 2014 Stats 95493 drwxr-xr-x 4 uucp uucp 512 Oct 24 23:53 lyxys var/spool/uucp/lyxys/X.: total 44 95491 drwxr-xr-x 3 uucp uucp 512 Sep 4 2013 .Failed 259 drwxrwxr-x 2 uucp uucp 512 Feb 7 2017 .Preserve 63748 drwxr-xr-x 2 uucp uucp 512 Sep 4 2013 .Received 95492 drwxrwxr-x 2 uucp uucp 512 Feb 7 2017 .Sequence 260 drwxrwxr-x 2 uucp uucp 512 Sep 4 2013 .Status 32001 drwxrwxr-x 2 uucp uucp 512 Feb 7 2017 .Temp 63749 drwxrwxr-x 2 uucp uucp 512 Feb 7 2017 .Xqtdir 67117 -rw-r--r-- 1 uucp uucp 5959 Nov 24 2014 Log 67118 -rw-r--r-- 1 uucp uucp 3728 Nov 24 2014 Stats 95493 drwxr-xr-x 4 uucp uucp 512 Oct 24 23:53 lyxys #=20 A friend hinted me to the 64bit inode change as a possible cause, but as I = do not have a backup old enough I can not verify his idea easily. Ralf [1] newfs, rsync from backup without /var/spool/uucp, port reinstalled, configured. --=20 You are receiving this mail because: You are the assignee for the bug.=