Date: Tue, 31 Oct 2017 18:58:04 +0000 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 Message-ID: <bug-223348-8@https.bugs.freebsd.org/bugzilla/>
next in thread | raw e-mail | index | archive | help
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.=
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?bug-223348-8>