* Bug : reuse same inode @ 2011-02-06 19:09 Philippe CHATAIGNON 2011-02-07 4:02 ` Ryusuke Konishi 0 siblings, 1 reply; 11+ messages in thread From: Philippe CHATAIGNON @ 2011-02-06 19:09 UTC (permalink / raw) To: linux-nilfs-u79uwXL29TY76Z2rM5mHXA Hi all, I use nilfs2 on a lvm partition for recording dvb streams : it creates big files and I often deleted them quickly so there only a few files on the partition. Today I notice a problem : where a new file were created, it takes the same inode that a file already have. So the previous file were lost, like if an hard link was made. philippe@micro11:~$ ls -li $v total 30051016 14 -rw-r--r-- 1 philippe users 93849600 6 févr. 14:51 f2_20110130_174456.ts 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 f3_20110107_205154.ts 14 -rw-r--r-- 1 philippe users 93849600 6 févr. 14:51 f3_20110206_144851.ts 19 -rw-r--r-- 1 philippe users 10623052800 6 févr. 19:55 f3_20110206_145141.ts 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 f4_20110119_204007.ts The file created today is f3_20110206_144851.ts : it reuse inode 14 that the file f2_20110130_174456.ts already had. On the third column, you can see there is only one link (and not 2 as if ln was used). Of course, I can use a snapshot to recover the old file (f2_20110130_174456.ts). philippe@micro11:~$ ls mnt/snap2/capture -li total 32584848 20 -rw-r--r-- 1 philippe users 4812800 5 févr. 17:43 canal_20110205_172318.ts 14 -rw-r--r-- 0 philippe users 13390412800 31 janv. 01:00 f2_20110130_174456.ts 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 f3_20110107_205154.ts 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 f4_20110119_204007.ts I run Archlinux x86_64 on 2.6.37. It's my first bug report. Ask me for additionnal information if I could help. Regards, PhC -- To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org More majordomo info at http://vger.kernel.org/majordomo-info.html ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Bug : reuse same inode 2011-02-06 19:09 Bug : reuse same inode Philippe CHATAIGNON @ 2011-02-07 4:02 ` Ryusuke Konishi [not found] ` <20110207.130214.221723444.ryusuke-sG5X7nlA6pw@public.gmane.org> 0 siblings, 1 reply; 11+ messages in thread From: Ryusuke Konishi @ 2011-02-07 4:02 UTC (permalink / raw) To: liste-ZXOCcuNttmoBe96aLqz0jA; +Cc: linux-nilfs-u79uwXL29TY76Z2rM5mHXA Hi, On Sun, 6 Feb 2011 20:09:28 +0100, Philippe CHATAIGNON wrote: > Hi all, > > I use nilfs2 on a lvm partition for recording dvb streams : it creates > big files and I often deleted them quickly so there only a few files on the partition. > > Today I notice a problem : where a new file were created, it takes the same inode that a file already have. > So the previous file were lost, like if an hard link was made. > > philippe@micro11:~$ ls -li $v > total 30051016 > 14 -rw-r--r-- 1 philippe users 93849600 6 févr. 14:51 f2_20110130_174456.ts > 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 f3_20110107_205154.ts > 14 -rw-r--r-- 1 philippe users 93849600 6 févr. 14:51 f3_20110206_144851.ts > 19 -rw-r--r-- 1 philippe users 10623052800 6 févr. 19:55 f3_20110206_145141.ts > 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 f4_20110119_204007.ts > > The file created today is f3_20110206_144851.ts : it reuse inode 14 > that the file f2_20110130_174456.ts already had. On the third column, you can see there > is only one link (and not 2 as if ln was used). > > Of course, I can use a snapshot to recover the old file (f2_20110130_174456.ts). > > philippe@micro11:~$ ls mnt/snap2/capture -li > total 32584848 > 20 -rw-r--r-- 1 philippe users 4812800 5 févr. 17:43 canal_20110205_172318.ts > 14 -rw-r--r-- 0 philippe users 13390412800 31 janv. 01:00 f2_20110130_174456.ts This directory list is already broken because the link count of "f2_20110130_174456.ts" is zero. Can you track the past state of this file from earlier checkpoints ? Thanks, Ryusuke Konishi > 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 f3_20110107_205154.ts > 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 f4_20110119_204007.ts > > I run Archlinux x86_64 on 2.6.37. It's my first bug report. > Ask me for additionnal information if I could help. > > Regards, > > PhC > -- > To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in > the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org > More majordomo info at http://vger.kernel.org/majordomo-info.html -- To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org More majordomo info at http://vger.kernel.org/majordomo-info.html ^ permalink raw reply [flat|nested] 11+ messages in thread
[parent not found: <20110207.130214.221723444.ryusuke-sG5X7nlA6pw@public.gmane.org>]
* Re: Bug : reuse same inode [not found] ` <20110207.130214.221723444.ryusuke-sG5X7nlA6pw@public.gmane.org> @ 2011-02-07 19:42 ` Philippe CHATAIGNON 2011-02-08 11:42 ` Ryusuke Konishi 0 siblings, 1 reply; 11+ messages in thread From: Philippe CHATAIGNON @ 2011-02-07 19:42 UTC (permalink / raw) To: linux-nilfs-u79uwXL29TY76Z2rM5mHXA; +Cc: Ryusuke Konishi Le Mon, 07 Feb 2011 13:02:14 +0900 (JST), Ryusuke Konishi <ryusuke-sG5X7nlA6pw@public.gmane.org> a écrit : > Can you track the past state of this file from earlier checkpoints ? Just before recording : philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=16940 /dev/mapper/vg11a-video mnt/snap5 philippe@micro11:~$ ls -li mnt/snap5/** 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap5/channels.conf mnt/snap5/capture: total 19452056 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 f3_20110107_205154.ts 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 f4_20110119_204007.ts 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 tf1hd_20101219_203305_schrek2.ts mnt/snap5/cut: total 4 19 -rw-r--r-- 1 philippe 1000 156 29 janv. 21:16 canal_20110129_181951.ts(0).Xcl 14 -rw-r--r-- 0 philippe users 4838067200 30 janv. 00:58 f5_20110125_202053.ts(0).Xcl Start of recording : philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=16941 /dev/mapper/vg11a-video mnt/snap6 philippe@micro11:~$ ls -li mnt/snap6/** 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap6/channels.conf mnt/snap6/capture: total 19454420 14 -rw-r--r-- 1 philippe users 2406400 30 janv. 17:45 f2_20110130_174456.ts 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 f3_20110107_205154.ts 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 f4_20110119_204007.ts 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 tf1hd_20101219_203305_schrek2.ts mnt/snap6/cut: total 2368 19 -rw-r--r-- 1 philippe 1000 156 29 janv. 21:16 canal_20110129_181951.ts(0).Xcl 14 -rw-r--r-- 1 philippe users 2406400 30 janv. 17:45 f5_20110125_202053.ts(0).Xcl That's the problem : inode 14 is reused because there was a file with 0 link (f5_20110125_202053.ts(0).Xcl) in another directory. So I tracked earlier and found that : cp15730 ------- philippe@micro11:~$ ls -li mnt/snap5/** 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap5/channels.conf mnt/snap5/capture: total 19452056 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 f3_20110107_205154.ts 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 f4_20110119_204007.ts 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 tf1hd_20101219_203305_schrek2.ts mnt/snap5/cut: total 4 14 -rw-r--r-- 1 philippe 1000 47 25 janv. 22:33 f5_20110125_202053.ts(0).Xcl All is OK cp15731 ------- philippe@micro11:~$ ls -li mnt/snap7/** 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap7/channels.conf mnt/snap7/capture: total 19452056 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 f3_20110107_205154.ts 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 f4_20110119_204007.ts 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 tf1hd_20101219_203305_schrek2.ts mnt/snap7/cut: total 9223372036848683032 14 -rw-r--r-- 0 philippe users 6214528000 24 janv. 01:30 f5_20110125_202053.ts(0).Xcl Size of file f5_20110125_202053.ts(0).Xcl is incorrect and it appears with 0 link. cp15732 ------- philippe@micro11:~$ ls -li mnt/snap2/** 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap2/channels.conf mnt/snap2/capture: total 19452056 14 -rw-r--r-- 1 philippe users 0 29 janv. 18:19 canal_20110129_181951.ts 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 f3_20110107_205154.ts 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 f4_20110119_204007.ts 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 tf1hd_20101219_203305_schrek2.ts mnt/snap2/cut: total 0 14 -rw-r--r-- 1 philippe users 0 29 janv. 18:19 f5_20110125_202053.ts(0).Xcl Inode 14 is used by 2 files. When I deleted the file canal_20110129_181951.ts, we have the situation of the cp 16940 (the first of this mail) and a file with 0 link. Problem is in cp15731, just before the creation of file canal_20110129_181951.ts. PhC -- To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org More majordomo info at http://vger.kernel.org/majordomo-info.html ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Bug : reuse same inode 2011-02-07 19:42 ` Philippe CHATAIGNON @ 2011-02-08 11:42 ` Ryusuke Konishi [not found] ` <20110208.204230.73657026.ryusuke-sG5X7nlA6pw@public.gmane.org> 0 siblings, 1 reply; 11+ messages in thread From: Ryusuke Konishi @ 2011-02-08 11:42 UTC (permalink / raw) To: liste-ZXOCcuNttmoBe96aLqz0jA; +Cc: linux-nilfs-u79uwXL29TY76Z2rM5mHXA Hi, Thank you for the detail report! It's really helpful. I understood the zero link count inode was causing a chain reaction. And the inode in question at cp15731 also seems to be overridden because gid, size, and timestamp all differs from that file at cp15730. > cp15730 > ------- > mnt/snap5/cut: > total 4 > 14 -rw-r--r-- 1 philippe 1000 47 25 janv. 22:33 f5_20110125_202053.ts(0).Xcl > cp15731 > ------- > mnt/snap7/cut: > total 9223372036848683032 > 14 -rw-r--r-- 0 philippe users 6214528000 24 janv. 01:30 f5_20110125_202053.ts(0).Xcl Can't you find another file with the inode number 14 in the snapshot cp15731 or cp15730 ? I reviewed back unlink() implementation, but haven't found any issues so far. The problem may be rooted much deeper. 'stat' command may give us much information than 'ls -l' in this case. Thanks, Ryusuke Konishi On Mon, 7 Feb 2011 20:42:32 +0100, Philippe CHATAIGNON wrote: > Le Mon, 07 Feb 2011 13:02:14 +0900 (JST), > Ryusuke Konishi <ryusuke-sG5X7nlA6pw@public.gmane.org> a écrit : > > > Can you track the past state of this file from earlier checkpoints ? > Just before recording : > philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=16940 /dev/mapper/vg11a-video mnt/snap5 > philippe@micro11:~$ ls -li mnt/snap5/** > 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap5/channels.conf > > mnt/snap5/capture: > total 19452056 > 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 f3_20110107_205154.ts > 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 f4_20110119_204007.ts > 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 tf1hd_20101219_203305_schrek2.ts > > mnt/snap5/cut: > total 4 > 19 -rw-r--r-- 1 philippe 1000 156 29 janv. 21:16 canal_20110129_181951.ts(0).Xcl > 14 -rw-r--r-- 0 philippe users 4838067200 30 janv. 00:58 f5_20110125_202053.ts(0).Xcl > > Start of recording : > philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=16941 /dev/mapper/vg11a-video mnt/snap6 > philippe@micro11:~$ ls -li mnt/snap6/** > 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap6/channels.conf > > mnt/snap6/capture: > total 19454420 > 14 -rw-r--r-- 1 philippe users 2406400 30 janv. 17:45 f2_20110130_174456.ts > 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 f3_20110107_205154.ts > 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 f4_20110119_204007.ts > 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 tf1hd_20101219_203305_schrek2.ts > > mnt/snap6/cut: > total 2368 > 19 -rw-r--r-- 1 philippe 1000 156 29 janv. 21:16 canal_20110129_181951.ts(0).Xcl > 14 -rw-r--r-- 1 philippe users 2406400 30 janv. 17:45 f5_20110125_202053.ts(0).Xcl > > That's the problem : inode 14 is reused because there was a file with 0 link (f5_20110125_202053.ts(0).Xcl) > in another directory. So I tracked earlier and found that : > > cp15730 > ------- > philippe@micro11:~$ ls -li mnt/snap5/** > 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap5/channels.conf > > mnt/snap5/capture: > total 19452056 > 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 f3_20110107_205154.ts > 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 f4_20110119_204007.ts > 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 tf1hd_20101219_203305_schrek2.ts > > mnt/snap5/cut: > total 4 > 14 -rw-r--r-- 1 philippe 1000 47 25 janv. 22:33 f5_20110125_202053.ts(0).Xcl > > All is OK > > cp15731 > ------- > philippe@micro11:~$ ls -li mnt/snap7/** > 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap7/channels.conf > > mnt/snap7/capture: > total 19452056 > 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 f3_20110107_205154.ts > 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 f4_20110119_204007.ts > 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 tf1hd_20101219_203305_schrek2.ts > > mnt/snap7/cut: > total 9223372036848683032 > 14 -rw-r--r-- 0 philippe users 6214528000 24 janv. 01:30 f5_20110125_202053.ts(0).Xcl > > Size of file f5_20110125_202053.ts(0).Xcl is incorrect and it appears with 0 link. > > > cp15732 > ------- > philippe@micro11:~$ ls -li mnt/snap2/** > 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap2/channels.conf > > mnt/snap2/capture: > total 19452056 > 14 -rw-r--r-- 1 philippe users 0 29 janv. 18:19 canal_20110129_181951.ts > 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 f3_20110107_205154.ts > 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 f4_20110119_204007.ts > 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 tf1hd_20101219_203305_schrek2.ts > > mnt/snap2/cut: > total 0 > 14 -rw-r--r-- 1 philippe users 0 29 janv. 18:19 f5_20110125_202053.ts(0).Xcl > > > Inode 14 is used by 2 files. When I deleted the file canal_20110129_181951.ts, we have > the situation of the cp 16940 (the first of this mail) and a file with 0 link. > > Problem is in cp15731, just before the creation of file canal_20110129_181951.ts. > > PhC -- To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org More majordomo info at http://vger.kernel.org/majordomo-info.html ^ permalink raw reply [flat|nested] 11+ messages in thread
[parent not found: <20110208.204230.73657026.ryusuke-sG5X7nlA6pw@public.gmane.org>]
* Re: Bug : reuse same inode [not found] ` <20110208.204230.73657026.ryusuke-sG5X7nlA6pw@public.gmane.org> @ 2011-02-08 20:32 ` Philippe CHATAIGNON 2011-02-10 5:01 ` Ryusuke Konishi 0 siblings, 1 reply; 11+ messages in thread From: Philippe CHATAIGNON @ 2011-02-08 20:32 UTC (permalink / raw) To: Ryusuke Konishi; +Cc: linux-nilfs-u79uwXL29TY76Z2rM5mHXA Le Tue, 08 Feb 2011 20:42:30 +0900 (JST), Ryusuke Konishi <ryusuke-sG5X7nlA6pw@public.gmane.org> a écrit : > Hi, > > Thank you for the detail report! It's really helpful. > > I understood the zero link count inode was causing a chain reaction. > > And the inode in question at cp15731 also seems to be overridden > because gid, size, and timestamp all differs from that file at > cp15730. > > > cp15730 > > ------- > > mnt/snap5/cut: > > total 4 > > 14 -rw-r--r-- 1 philippe 1000 47 25 janv. 22:33 > > f5_20110125_202053.ts(0).Xcl > > > cp15731 > > ------- > > mnt/snap7/cut: > > total 9223372036848683032 > > 14 -rw-r--r-- 0 philippe users 6214528000 24 janv. 01:30 > > f5_20110125_202053.ts(0).Xcl > > Can't you find another file with the inode number 14 in the snapshot > cp15731 or cp15730 ? > > I reviewed back unlink() implementation, but haven't found any issues > so far. The problem may be rooted much deeper. > > 'stat' command may give us much information than 'ls -l' in this case. Hi, in my previous mail, ls -li ** give all the files in the filesystem (directory capture has inode 12 and cut 13). In cp15730 and cp15731, there's only one file with inode 14. Heres's the 3 stat outputs : philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=15730 /dev/mapper/vg11a-video mnt/snap5 philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=15731 /dev/mapper/vg11a-video mnt/snap6 philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=15732 /dev/mapper/vg11a-video mnt/snap7 philippe@micro11:~$ stat mnt/snap5/cut/f5_20110125_202053.ts\(0\).Xcl File: « mnt/snap5/cut/f5_20110125_202053.ts(0).Xcl » Size: 47 Blocks: 8 IO Block: 4096 fichier Device: fe00h/65024d Inode: 14 Links: 1 Access: (0644/-rw-r--r--) Uid: ( 1000/philippe) Gid: ( 1000/ UNKNOWN) Access: 2011-01-25 22:33:34.914556435 +0100 Modify: 2011-01-25 22:33:34.914556435 +0100 Change: 2011-01-25 22:33:34.914556435 +0100 Birth: - philippe@micro11:~$ stat mnt/snap6/cut/f5_20110125_202053.ts\(0\).Xcl File: « mnt/snap6/cut/f5_20110125_202053.ts(0).Xcl » Size: 6214528000 Blocks: 18446744073697366064 IO Block: 4096 fichier Device: fe00h/65024d Inode: 14 Links: 0 Access: (0644/-rw-r--r--) Uid: ( 1000/philippe) Gid: ( 100/ users) Access: 2011-01-24 01:30:02.260271565 +0100 Modify: 2011-01-24 01:30:02.260271565 +0100 Change: 2011-01-25 20:28:48.894851740 +0100 Birth: - File: « mnt/snap7/cut/f5_20110125_202053.ts(0).Xcl » Size: 0 Blocks: 0 IO Block: 4096 fichier vide Device: fe00h/65024d Inode: 14 Links: 1 Access: (0644/-rw-r--r--) Uid: ( 1000/philippe) Gid: ( 100/ users) Access: 2011-01-29 18:19:51.719138031 +0100 Modify: 2011-01-29 18:19:51.719138031 +0100 Change: 2011-01-29 18:19:51.719138031 +0100 Birth: - PhC -- To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org More majordomo info at http://vger.kernel.org/majordomo-info.html ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Bug : reuse same inode 2011-02-08 20:32 ` Philippe CHATAIGNON @ 2011-02-10 5:01 ` Ryusuke Konishi [not found] ` <20110210.140105.33383103.ryusuke-sG5X7nlA6pw@public.gmane.org> 0 siblings, 1 reply; 11+ messages in thread From: Ryusuke Konishi @ 2011-02-10 5:01 UTC (permalink / raw) To: liste-ZXOCcuNttmoBe96aLqz0jA; +Cc: linux-nilfs-u79uwXL29TY76Z2rM5mHXA On Tue, 8 Feb 2011 21:32:37 +0100, Philippe CHATAIGNON wrote: > Le Tue, 08 Feb 2011 20:42:30 +0900 (JST), > Ryusuke Konishi <ryusuke-sG5X7nlA6pw@public.gmane.org> a écrit : > > > Hi, > > > > Thank you for the detail report! It's really helpful. > > > > I understood the zero link count inode was causing a chain reaction. > > > > And the inode in question at cp15731 also seems to be overridden > > because gid, size, and timestamp all differs from that file at > > cp15730. > > > > > cp15730 > > > ------- > > > mnt/snap5/cut: > > > total 4 > > > 14 -rw-r--r-- 1 philippe 1000 47 25 janv. 22:33 > > > f5_20110125_202053.ts(0).Xcl > > > > > cp15731 > > > ------- > > > mnt/snap7/cut: > > > total 9223372036848683032 > > > 14 -rw-r--r-- 0 philippe users 6214528000 24 janv. 01:30 > > > f5_20110125_202053.ts(0).Xcl > > > > Can't you find another file with the inode number 14 in the snapshot > > cp15731 or cp15730 ? > > > > I reviewed back unlink() implementation, but haven't found any issues > > so far. The problem may be rooted much deeper. > > > > 'stat' command may give us much information than 'ls -l' in this case. > > Hi, > in my previous mail, ls -li ** give all the files in the filesystem (directory capture has inode 12 and cut 13). In > cp15730 and cp15731, there's only one file with inode 14. O.K. so, it seems like something happened at the checkpoint 15731 according to your information. One thing wired is that the timestamp (mtime) looks to be rewinded at cp15731. > File: « mnt/snap6/cut/f5_20110125_202053.ts(0).Xcl » > Size: 6214528000 Blocks: 18446744073697366064 IO Block: 4096 fichier > Device: fe00h/65024d Inode: 14 Links: 0 > Access: (0644/-rw-r--r--) Uid: ( 1000/philippe) Gid: ( 100/ users) > Access: 2011-01-24 01:30:02.260271565 +0100 > Modify: 2011-01-24 01:30:02.260271565 +0100 > Change: 2011-01-25 20:28:48.894851740 +0100 Do you have any ideas on this timestamp ? Then, let's look back in a different perspective. As you know, the lscp command displays the total number of inodes (ICNT). Does it match the actual number of files and directories ? Thanks, Ryusuke Konishi > Heres's the 3 stat outputs : > philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=15730 /dev/mapper/vg11a-video mnt/snap5 > philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=15731 /dev/mapper/vg11a-video mnt/snap6 > philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=15732 /dev/mapper/vg11a-video mnt/snap7 > > philippe@micro11:~$ stat mnt/snap5/cut/f5_20110125_202053.ts\(0\).Xcl > File: « mnt/snap5/cut/f5_20110125_202053.ts(0).Xcl » > Size: 47 Blocks: 8 IO Block: 4096 fichier > Device: fe00h/65024d Inode: 14 Links: 1 > Access: (0644/-rw-r--r--) Uid: ( 1000/philippe) Gid: ( 1000/ UNKNOWN) > Access: 2011-01-25 22:33:34.914556435 +0100 > Modify: 2011-01-25 22:33:34.914556435 +0100 > Change: 2011-01-25 22:33:34.914556435 +0100 > Birth: - > > philippe@micro11:~$ stat mnt/snap6/cut/f5_20110125_202053.ts\(0\).Xcl > File: « mnt/snap6/cut/f5_20110125_202053.ts(0).Xcl » > Size: 6214528000 Blocks: 18446744073697366064 IO Block: 4096 fichier > Device: fe00h/65024d Inode: 14 Links: 0 > Access: (0644/-rw-r--r--) Uid: ( 1000/philippe) Gid: ( 100/ users) > Access: 2011-01-24 01:30:02.260271565 +0100 > Modify: 2011-01-24 01:30:02.260271565 +0100 > Change: 2011-01-25 20:28:48.894851740 +0100 > Birth: - > > File: « mnt/snap7/cut/f5_20110125_202053.ts(0).Xcl » > Size: 0 Blocks: 0 IO Block: 4096 fichier vide > Device: fe00h/65024d Inode: 14 Links: 1 > Access: (0644/-rw-r--r--) Uid: ( 1000/philippe) Gid: ( 100/ users) > Access: 2011-01-29 18:19:51.719138031 +0100 > Modify: 2011-01-29 18:19:51.719138031 +0100 > Change: 2011-01-29 18:19:51.719138031 +0100 > Birth: - > > PhC > -- > To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in > the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org > More majordomo info at http://vger.kernel.org/majordomo-info.html -- To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org More majordomo info at http://vger.kernel.org/majordomo-info.html ^ permalink raw reply [flat|nested] 11+ messages in thread
[parent not found: <20110210.140105.33383103.ryusuke-sG5X7nlA6pw@public.gmane.org>]
* Re: Bug : reuse same inode [not found] ` <20110210.140105.33383103.ryusuke-sG5X7nlA6pw@public.gmane.org> @ 2011-02-10 22:32 ` Philippe CHATAIGNON 2011-02-18 7:21 ` Ryusuke Konishi 0 siblings, 1 reply; 11+ messages in thread From: Philippe CHATAIGNON @ 2011-02-10 22:32 UTC (permalink / raw) To: Ryusuke Konishi; +Cc: linux-nilfs-u79uwXL29TY76Z2rM5mHXA Le Thu, 10 Feb 2011 14:01:05 +0900 (JST), Ryusuke Konishi <ryusuke-sG5X7nlA6pw@public.gmane.org> a écrit : > O.K. so, it seems like something happened at the checkpoint 15731 > according to your information. > > One thing wired is that the timestamp (mtime) looks to be rewinded > at cp15731. > > > File: « mnt/snap6/cut/f5_20110125_202053.ts(0).Xcl » > > Size: 6214528000 Blocks: 18446744073697366064 IO Block: > > 4096 fichier Device: fe00h/65024d Inode: 14 > > Links: 0 Access: (0644/-rw-r--r--) Uid: ( 1000/philippe) Gid: > > ( 100/ users) Access: 2011-01-24 01:30:02.260271565 +0100 > > Modify: 2011-01-24 01:30:02.260271565 +0100 > > Change: 2011-01-25 20:28:48.894851740 +0100 > > Do you have any ideas on this timestamp ? Hi, I pastebin all the lscp (25600 lines) at : http://dpaste.org/U6w6 As you can see, there is an activity at 2011-01-24 01:30:02. 14442 2011-01-24 01:29:56 cp - 101 11 14443 2011-01-24 01:30:00 cp - 925 11 14444 2011-01-24 01:30:07 cp - 625 11 14445 2011-01-25 20:20:58 cp - 320 12 14446 2011-01-25 20:21:05 cp - 544 12 philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=14443 /dev/mapper/vg11a-video mnt/snap4 philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=14444 /dev/mapper/vg11a-video mnt/snap5 philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=14445 /dev/mapper/vg11a-video mnt/snap6 philippe@micro11:~$ ls -lid mnt/snap4/**/** 12 drwxr-xr-x 2 philippe users 4096 23 janv. 22:34 mnt/snap4/capture/ 19 -rw-r--r-- 1 philippe users 4957184000 24 janv. 01:29 mnt/snap4/capture/f2_20110123_223415.ts 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 mnt/snap4/capture/f3_20110107_205154.ts 14 -rw-r--r-- 1 philippe users 6213324800 24 janv. 01:30 mnt/snap4/capture/f3_20110123_223247.ts 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 mnt/snap4/capture/f4_20110119_204007.ts 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 mnt/snap4/capture/tf1hd_20101219_203305_schrek2.ts 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap4/channels.conf 13 drwxr-xr-x 2 philippe users 4096 23 janv. 22:31 mnt/snap4/cut/ philippe@micro11:~$ ls -lid mnt/snap5/**/** 12 drwxr-xr-x 2 philippe users 4096 23 janv. 22:34 mnt/snap5/capture/ 19 -rw-r--r-- 1 philippe users 4958387200 24 janv. 01:30 mnt/snap5/capture/f2_20110123_223415.ts 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 mnt/snap5/capture/f3_20110107_205154.ts 14 -rw-r--r-- 1 philippe users 6214528000 24 janv. 01:30 mnt/snap5/capture/f3_20110123_223247.ts 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 mnt/snap5/capture/f4_20110119_204007.ts 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 mnt/snap5/capture/tf1hd_20101219_203305_schrek2.ts 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap5/channels.conf 13 drwxr-xr-x 2 philippe users 4096 23 janv. 22:31 mnt/snap5/cut/ philippe@micro11:~$ ls -lid mnt/snap6/**/** 12 drwxr-xr-x 2 philippe users 4096 25 janv. 20:20 mnt/snap6/capture/ 19 -rw-r--r-- 1 philippe users 4958387200 24 janv. 01:30 mnt/snap6/capture/f2_20110123_223415.ts 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 mnt/snap6/capture/f3_20110107_205154.ts 14 -rw-r--r-- 1 philippe users 6214528000 24 janv. 01:30 mnt/snap6/capture/f3_20110123_223247.ts 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 mnt/snap6/capture/f4_20110119_204007.ts 20 -rw-r--r-- 1 philippe users 1203200 25 janv. 20:20 mnt/snap6/capture/f5_20110125_202053.ts 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 mnt/snap6/capture/tf1hd_20101219_203305_schrek2.ts 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap6/channels.conf 13 drwxr-xr-x 2 philippe users 4096 23 janv. 22:31 mnt/snap6/cut/ Interesting file is : 14 -rw-r--r-- 1 philippe users 6214528000 24 janv. 01:30 mnt/snap5/capture/f3_20110123_223247.ts It's the timestamp, the size (6214528000) and the inode (14) of the file of the cp15731. For your information, at 1:30 the computer shuts down with 'at' command. Another remark : 2 files were recorded simultaneously (the other one is f2_20110123_223415.ts at inode 19). This file is delete in cp 14522. I don't see any trouble after deletion : philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=14521 /dev/mapper/vg11a-video mnt/snap1 philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=14522 /dev/mapper/vg11a-video mnt/snap2 philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=14523 /dev/mapper/vg11a-video mnt/snap3 philippe@micro11:~$ ls -lid mnt/snap1/**/** 12 drwxr-xr-x 2 philippe users 4096 25 janv. 20:26 mnt/snap1/capture/ 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 mnt/snap1/capture/f3_20110107_205154.ts 14 -rw-r--r-- 1 philippe users 6214528000 24 janv. 01:30 mnt/snap1/capture/f3_20110123_223247.ts 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 mnt/snap1/capture/f4_20110119_204007.ts 20 -rw-r--r-- 1 philippe users 192512000 25 janv. 20:28 mnt/snap1/capture/f5_20110125_202053.ts 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 mnt/snap1/capture/tf1hd_20101219_203305_schrek2.ts 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap1/channels.conf 13 drwxr-xr-x 2 philippe users 4096 25 janv. 20:27 mnt/snap1/cut/ 21 -rw-r--r-- 1 philippe 1000 48 25 janv. 20:23 mnt/snap1/cut/f2_20110123_223415.ts(0).Xcl 19 -rw-r--r-- 1 philippe 1000 47 25 janv. 20:27 mnt/snap1/cut/f3_20110123_223247.ts philippe@micro11:~$ ls -lid mnt/snap2/**/** 12 drwxr-xr-x 2 philippe users 4096 25 janv. 20:28 mnt/snap2/capture/ 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 mnt/snap2/capture/f3_20110107_205154.ts 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 mnt/snap2/capture/f4_20110119_204007.ts 20 -rw-r--r-- 1 philippe users 196121600 25 janv. 20:28 mnt/snap2/capture/f5_20110125_202053.ts 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 mnt/snap2/capture/tf1hd_20101219_203305_schrek2.ts 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap2/channels.conf 13 drwxr-xr-x 2 philippe users 4096 25 janv. 20:27 mnt/snap2/cut/ 21 -rw-r--r-- 1 philippe 1000 48 25 janv. 20:23 mnt/snap2/cut/f2_20110123_223415.ts(0).Xcl 19 -rw-r--r-- 1 philippe 1000 47 25 janv. 20:27 mnt/snap2/cut/f3_20110123_223247.ts philippe@micro11:~$ ls -lid mnt/snap3/**/** 12 drwxr-xr-x 2 philippe users 4096 25 janv. 20:28 mnt/snap3/capture/ 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 mnt/snap3/capture/f3_20110107_205154.ts 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 mnt/snap3/capture/f4_20110119_204007.ts 20 -rw-r--r-- 1 philippe users 199731200 25 janv. 20:29 mnt/snap3/capture/f5_20110125_202053.ts 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 mnt/snap3/capture/tf1hd_20101219_203305_schrek2.ts 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap3/channels.conf 13 drwxr-xr-x 2 philippe users 4096 25 janv. 20:27 mnt/snap3/cut/ 21 -rw-r--r-- 1 philippe 1000 48 25 janv. 20:23 mnt/snap3/cut/f2_20110123_223415.ts(0).Xcl 19 -rw-r--r-- 1 philippe 1000 47 25 janv. 20:27 mnt/snap3/cut/f3_20110123_223247.ts Remark : cp 14522 is at 2011-01-25 20:29:09 like the Change timestamp: 2011-01-25 20:28:48.894851740 +0100 that appears in the cp15731. > > Then, let's look back in a different perspective. > > As you know, the lscp command displays the total number of inodes > (ICNT). Does it match the actual number of files and directories ? Last line : 5631 2011-02-07 20:27:54 cp - 21 10 And philippe@micro11:~$ find /mnt/tmp1 /mnt/tmp1 /mnt/tmp1/.nilfs /mnt/tmp1/capture /mnt/tmp1/capture/f3_20110107_205154.ts /mnt/tmp1/capture/tf1hd_20101219_203305_schrek2.ts /mnt/tmp1/capture/f2_20110130_174456.ts /mnt/tmp1/capture/f4_20110119_204007.ts /mnt/tmp1/capture/f3_20110206_144851.ts /mnt/tmp1/channels.conf /mnt/tmp1/cut /mnt/tmp1/cut/f3_20110206_145141.ts(0).Xcl gives 10 files for me. That seems OK. Recently I noticed this message in dmesg : Feb 8 21:34:29 localhost kernel: nilfs_palloc_commit_free_entry: entry number 14 already freed and Feb 6 20:53:30 localhost kernel: nilfs_palloc_commit_free_entry: entry number 19 already freed (remember inode 19 was the second file's one) and the system hangs on umount the nilfs (slow task I presume) : Feb 7 22:21:50 localhost nilfs_cleanerd[1819]: shutdown Feb 7 22:21:50 localhost kernel: nilfs_palloc_commit_free_entry: entry number 14 already freed Feb 7 22:22:10 localhost kernel: nilfs_palloc_commit_free_entry: entry number 14 already freed Feb 7 22:25:12 localhost -- MARK -- Feb 7 22:27:02 localhost kernel: umount.nilfs2 D ffff88003f861bc0 0 2499 2498 0x00000000 Feb 7 22:27:02 localhost kernel: ffff88002c2cbc28 0000000000000086 ffff88002c2cbfd8 ffff88002c2cbfd8 Feb 7 22:27:02 localhost kernel: ffff88002c2cbfd8 ffff88003f861bc0 ffff88002c2cbfd8 ffff88002c2cbfd8 Feb 7 22:27:02 localhost kernel: ffff88002c2cbfd8 ffff88003f861ea0 ffff88002c2cbfd8 ffff88002c2ca000 Feb 7 22:27:02 localhost kernel: Call Trace: Feb 7 22:27:02 localhost kernel: [<ffffffff810480bc>] ? finish_task_switch+0x3c/0xd0 Feb 7 22:27:02 localhost kernel: [<ffffffff813a3ca1>] ? schedule+0x381/0xaa0 Feb 7 22:27:02 localhost kernel: [<ffffffff810e62f0>] ? find_get_pages_tag+0x100/0x130 Feb 7 22:27:02 localhost kernel: [<ffffffff813a49bd>] schedule_timeout+0x2bd/0x340 Feb 7 22:27:02 localhost kernel: [<ffffffff810eea44>] ? write_cache_pages+0x114/0x4e0 Feb 7 22:27:02 localhost kernel: [<ffffffff8104ee9b>] ? check_preempt_wakeup+0x18b/0x240 Feb 7 22:27:02 localhost kernel: [<ffffffff810ee3f0>] ? __writepage+0x0/0x40 Feb 7 22:27:02 localhost kernel: [<ffffffff813a37d0>] wait_for_common+0xc0/0x160 Feb 7 22:27:02 localhost kernel: [<ffffffff8104fe00>] ? default_wake_function+0x0/0x10 Feb 7 22:27:02 localhost kernel: [<ffffffff813a3918>] wait_for_completion+0x18/0x20 Feb 7 22:27:02 localhost kernel: [<ffffffff81159333>] sync_inodes_sb+0x83/0x180 Feb 7 22:27:02 localhost kernel: [<ffffffff8115de00>] __sync_filesystem+0x80/0x90 Feb 7 22:27:02 localhost kernel: [<ffffffff8115de73>] sync_filesystem+0x43/0x60 Feb 7 22:27:02 localhost kernel: [<ffffffff811373df>] generic_shutdown_super+0x2f/0x100 Feb 7 22:27:02 localhost kernel: [<ffffffff811374dc>] kill_block_super+0x2c/0x50 Feb 7 22:27:02 localhost kernel: [<ffffffff81137825>] deactivate_locked_super+0x45/0x60 Feb 7 22:27:02 localhost kernel: [<ffffffff811386b5>] deactivate_super+0x45/0x60 Feb 7 22:27:02 localhost kernel: [<ffffffff81151436>] mntput_no_expire+0x86/0xf0 Feb 7 22:27:02 localhost kernel: [<ffffffff81151f37>] sys_umount+0x67/0x370 Feb 7 22:27:02 localhost kernel: [<ffffffff8100bf12>] system_call_fastpath+0x16/0x1b Feb 7 22:29:02 localhost kernel: umount.nilfs2 D ffff88003f861bc0 0 2499 2498 0x00000000 Now I don't use this filesystem. I just keep it for debug and umount if OK. Regards, PhC -- To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org More majordomo info at http://vger.kernel.org/majordomo-info.html ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Bug : reuse same inode 2011-02-10 22:32 ` Philippe CHATAIGNON @ 2011-02-18 7:21 ` Ryusuke Konishi [not found] ` <20110218.162145.57461053.ryusuke-sG5X7nlA6pw@public.gmane.org> 0 siblings, 1 reply; 11+ messages in thread From: Ryusuke Konishi @ 2011-02-18 7:21 UTC (permalink / raw) To: liste-ZXOCcuNttmoBe96aLqz0jA; +Cc: linux-nilfs-u79uwXL29TY76Z2rM5mHXA Hi, On Thu, 10 Feb 2011 23:32:01 +0100, Philippe CHATAIGNON wrote: > Le Thu, 10 Feb 2011 14:01:05 +0900 (JST), > Ryusuke Konishi <ryusuke-sG5X7nlA6pw@public.gmane.org> a écrit : > > O.K. so, it seems like something happened at the checkpoint 15731 > > according to your information. > > > > One thing wired is that the timestamp (mtime) looks to be rewinded > > at cp15731. > > > > > File: « mnt/snap6/cut/f5_20110125_202053.ts(0).Xcl » > > > Size: 6214528000 Blocks: 18446744073697366064 IO Block: > > > 4096 fichier Device: fe00h/65024d Inode: 14 > > > Links: 0 Access: (0644/-rw-r--r--) Uid: ( 1000/philippe) Gid: > > > ( 100/ users) Access: 2011-01-24 01:30:02.260271565 +0100 > > > Modify: 2011-01-24 01:30:02.260271565 +0100 > > > Change: 2011-01-25 20:28:48.894851740 +0100 > > > > Do you have any ideas on this timestamp ? > > Hi, > I pastebin all the lscp (25600 lines) at : http://dpaste.org/U6w6 > > As you can see, there is an activity at 2011-01-24 01:30:02. > 14442 2011-01-24 01:29:56 cp - 101 11 > 14443 2011-01-24 01:30:00 cp - 925 11 > 14444 2011-01-24 01:30:07 cp - 625 11 > 14445 2011-01-25 20:20:58 cp - 320 12 > 14446 2011-01-25 20:21:05 cp - 544 12 > > philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=14443 /dev/mapper/vg11a-video mnt/snap4 > philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=14444 /dev/mapper/vg11a-video mnt/snap5 > philippe@micro11:~$ sudo mount -t nilfs2 -r -o cp=14445 /dev/mapper/vg11a-video mnt/snap6 > philippe@micro11:~$ ls -lid mnt/snap4/**/** > 12 drwxr-xr-x 2 philippe users 4096 23 janv. 22:34 mnt/snap4/capture/ > 19 -rw-r--r-- 1 philippe users 4957184000 24 janv. 01:29 mnt/snap4/capture/f2_20110123_223415.ts > 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 mnt/snap4/capture/f3_20110107_205154.ts > 14 -rw-r--r-- 1 philippe users 6213324800 24 janv. 01:30 mnt/snap4/capture/f3_20110123_223247.ts > 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 mnt/snap4/capture/f4_20110119_204007.ts > 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 mnt/snap4/capture/tf1hd_20101219_203305_schrek2.ts > 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap4/channels.conf > 13 drwxr-xr-x 2 philippe users 4096 23 janv. 22:31 mnt/snap4/cut/ > philippe@micro11:~$ ls -lid mnt/snap5/**/** > 12 drwxr-xr-x 2 philippe users 4096 23 janv. 22:34 mnt/snap5/capture/ > 19 -rw-r--r-- 1 philippe users 4958387200 24 janv. 01:30 mnt/snap5/capture/f2_20110123_223415.ts > 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 mnt/snap5/capture/f3_20110107_205154.ts > 14 -rw-r--r-- 1 philippe users 6214528000 24 janv. 01:30 mnt/snap5/capture/f3_20110123_223247.ts > 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 mnt/snap5/capture/f4_20110119_204007.ts > 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 mnt/snap5/capture/tf1hd_20101219_203305_schrek2.ts > 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap5/channels.conf > 13 drwxr-xr-x 2 philippe users 4096 23 janv. 22:31 mnt/snap5/cut/ > philippe@micro11:~$ ls -lid mnt/snap6/**/** > 12 drwxr-xr-x 2 philippe users 4096 25 janv. 20:20 mnt/snap6/capture/ > 19 -rw-r--r-- 1 philippe users 4958387200 24 janv. 01:30 mnt/snap6/capture/f2_20110123_223415.ts > 16 -rw-r--r-- 1 philippe users 8606489600 9 janv. 15:42 mnt/snap6/capture/f3_20110107_205154.ts > 14 -rw-r--r-- 1 philippe users 6214528000 24 janv. 01:30 mnt/snap6/capture/f3_20110123_223247.ts > 15 -rw-r--r-- 1 philippe users 4688870400 19 janv. 23:14 mnt/snap6/capture/f4_20110119_204007.ts > 20 -rw-r--r-- 1 philippe users 1203200 25 janv. 20:20 mnt/snap6/capture/f5_20110125_202053.ts > 17 -rw-r--r-- 1 philippe users 6545408000 9 janv. 15:45 mnt/snap6/capture/tf1hd_20101219_203305_schrek2.ts > 18 -rw-r--r-- 1 philippe users 4434 9 janv. 15:45 mnt/snap6/channels.conf > 13 drwxr-xr-x 2 philippe users 4096 23 janv. 22:31 mnt/snap6/cut/ > > Interesting file is : > 14 -rw-r--r-- 1 philippe users 6214528000 24 janv. 01:30 mnt/snap5/capture/f3_20110123_223247.ts > > It's the timestamp, the size (6214528000) and the inode (14) of the file of the cp15731. > > For your information, at 1:30 the computer shuts down with 'at' command. Another remark : 2 files were recorded > simultaneously (the other one is f2_20110123_223415.ts at inode 19). Thank you for the cooperation. Yeah, this file is exactly the file that overrode "f5_20110125_202053.ts(0).Xcl" at cp15731. I don't know why the past inode overrode the latest inode. One possible explanation is that garbage collection caused this interference, and another is interference by a snapshot mount for the checkpoint 14444. Were you mounting the snapshot cp14444 when "f5_20110125_202053.ts(0).Xcl" was destroyed at cp15731 ? If not, dummy on-memory inodes used for the garbage collection seem suspicious to me. Regards, Ryusuke Konishi -- To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org More majordomo info at http://vger.kernel.org/majordomo-info.html ^ permalink raw reply [flat|nested] 11+ messages in thread
[parent not found: <20110218.162145.57461053.ryusuke-sG5X7nlA6pw@public.gmane.org>]
* Re: Bug : reuse same inode [not found] ` <20110218.162145.57461053.ryusuke-sG5X7nlA6pw@public.gmane.org> @ 2011-02-18 19:57 ` Philippe CHATAIGNON 2011-02-19 13:22 ` Ryusuke Konishi 0 siblings, 1 reply; 11+ messages in thread From: Philippe CHATAIGNON @ 2011-02-18 19:57 UTC (permalink / raw) To: Ryusuke Konishi; +Cc: linux-nilfs-u79uwXL29TY76Z2rM5mHXA Le Fri, 18 Feb 2011 16:21:45 +0900 (JST), Ryusuke Konishi <ryusuke-sG5X7nlA6pw@public.gmane.org> a écrit : > Thank you for the cooperation. > > Yeah, this file is exactly the file that overrode > "f5_20110125_202053.ts(0).Xcl" at cp15731. > > I don't know why the past inode overrode the latest inode. One > possible explanation is that garbage collection caused this > interference, and another is interference by a snapshot mount for the > checkpoint 14444. > > Were you mounting the snapshot cp14444 when > "f5_20110125_202053.ts(0).Xcl" was destroyed at cp15731 ? > > If not, dummy on-memory inodes used for the garbage collection seem > suspicious to me. Hi, the first time I used snapshot on this fs is when I lost a file because of inode's reuse (my first mail). When file f5_...Xcl was deleted at cp15731, cp14444 was not a ss and wasn't mounted. And there were no ss on this fs (only cp). Tell me if you need additional information. This partition's size is 200G and I'll need that space in a few days. Regards, PhC -- To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org More majordomo info at http://vger.kernel.org/majordomo-info.html ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Bug : reuse same inode 2011-02-18 19:57 ` Philippe CHATAIGNON @ 2011-02-19 13:22 ` Ryusuke Konishi [not found] ` <20110219.222232.05855196.ryusuke-sG5X7nlA6pw@public.gmane.org> 0 siblings, 1 reply; 11+ messages in thread From: Ryusuke Konishi @ 2011-02-19 13:22 UTC (permalink / raw) To: liste-ZXOCcuNttmoBe96aLqz0jA Cc: linux-nilfs-u79uwXL29TY76Z2rM5mHXA, konishi.ryusuke-Zyj7fXuS5i5L9jVzuh4AOg Hi, On Fri, 18 Feb 2011 20:57:39 +0100, Philippe CHATAIGNON wrote: > Le Fri, 18 Feb 2011 16:21:45 +0900 (JST), > Ryusuke Konishi <ryusuke-sG5X7nlA6pw@public.gmane.org> a écrit : > > Thank you for the cooperation. > > > > Yeah, this file is exactly the file that overrode > > "f5_20110125_202053.ts(0).Xcl" at cp15731. > > > > I don't know why the past inode overrode the latest inode. One > > possible explanation is that garbage collection caused this > > interference, and another is interference by a snapshot mount for the > > checkpoint 14444. > > > > Were you mounting the snapshot cp14444 when > > "f5_20110125_202053.ts(0).Xcl" was destroyed at cp15731 ? > > > > If not, dummy on-memory inodes used for the garbage collection seem > > suspicious to me. > > Hi, > the first time I used snapshot on this fs is when I lost a file > because of inode's reuse (my first mail). When file f5_...Xcl was > deleted at cp15731, cp14444 was not a ss and wasn't mounted. And there > were no ss on this fs (only cp). I found GC never causes such interference. So, the inode corruption was not caused neither by the snapshot mount nor GC. Now, I'm suspecting a race condition between the removal of "f3_20110123_223247.ts" and creation of "f5_20110125_202053.ts(0).Xcl". Even though "f3_20110123_223247.ts" was removed at cp14522 (2011-01-25 20:29:09) from the "capture" directory, it seems like actual removal of the inode happened a bit later than that since the file size was pretty big. > Tell me if you need additional information. This partition's size is > 200G and I'll need that space in a few days. OK, but, please resend me the checkpoint list you pasted last week before reusing the disk. The list looks like expired on the web (sorry, it's missing on my PC). Thanks, Ryusuke Konishi -- To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org More majordomo info at http://vger.kernel.org/majordomo-info.html ^ permalink raw reply [flat|nested] 11+ messages in thread
[parent not found: <20110219.222232.05855196.ryusuke-sG5X7nlA6pw@public.gmane.org>]
* Re: Bug : reuse same inode [not found] ` <20110219.222232.05855196.ryusuke-sG5X7nlA6pw@public.gmane.org> @ 2011-02-19 15:26 ` Philippe CHATAIGNON 0 siblings, 0 replies; 11+ messages in thread From: Philippe CHATAIGNON @ 2011-02-19 15:26 UTC (permalink / raw) To: Ryusuke Konishi Cc: linux-nilfs-u79uwXL29TY76Z2rM5mHXA, konishi.ryusuke-Zyj7fXuS5i5L9jVzuh4AOg > I found GC never causes such interference. So, the inode corruption > was not caused neither by the snapshot mount nor GC. > > Now, I'm suspecting a race condition between the removal of > "f3_20110123_223247.ts" and creation of > "f5_20110125_202053.ts(0).Xcl". > > Even though "f3_20110123_223247.ts" was removed at cp14522 (2011-01-25 > 20:29:09) from the "capture" directory, it seems like actual removal > of the inode happened a bit later than that since the file size was > pretty big. On my computer, deletion of a .ts file takes ~ 4-6 seconds (~1s/1G). It may happend that a *.Xcl file is created during this time. I make a little test with that fs. During the deletion of the file f3_20110107_205154.ts (inode 16), in a another console, I touch a file about every second : The result : 19 -rw-r--r-- 1 philippe users 0 19 févr. 14:54 test1 20 -rw-r--r-- 1 philippe users 0 19 févr. 14:54 test2 22 -rw-r--r-- 1 philippe users 0 19 févr. 14:55 test3 23 -rw-r--r-- 1 philippe users 0 19 févr. 14:55 test4 16 -rw-r--r-- 1 philippe users 0 19 févr. 14:55 test5 test1, 2, 3, 4 were created instantaneously while the ts file was deleting. But not test5 : touch command waits ~ 2-3 seconds until the rm was finished on the other console. It has the same inode that the deleted file. At final, filesystem seems OK but this time zone where the created file reuse the old inode during a file deletion seems a good candidate for race condition. I ask myself : is it mandatory to reuse inode number in nilfs design ? > OK, but, please resend me the checkpoint list you pasted last week > before reusing the disk. The list looks like expired on the web > (sorry, it's missing on my PC). Here is the same checkpoint list that I pasted last week (not the actual) with no expiration time : http://dpaste.org/UmEb/ In fact, I will keep this partition and continue to use it. So I delete the 2 files that share the same inode (cf. my first mail). For the 2nd rm, I have the message : NILFS warning (device dm-0): nilfs_do_unlink: deleting nonexistent file (14), 0 I touch some files after that : 14 -rw-r--r-- 1 philippe users 0 19 févr. 14:58 test6 24 -rw-r--r-- 1 philippe users 0 19 févr. 14:58 test7 25 -rw-r--r-- 1 philippe users 0 19 févr. 14:59 test8 Filesystem seems OK and I will send a new mail if new trouble appears. Thanks for your help, Regards, PhC -- To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org More majordomo info at http://vger.kernel.org/majordomo-info.html ^ permalink raw reply [flat|nested] 11+ messages in thread
end of thread, other threads:[~2011-02-19 15:26 UTC | newest] Thread overview: 11+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2011-02-06 19:09 Bug : reuse same inode Philippe CHATAIGNON 2011-02-07 4:02 ` Ryusuke Konishi [not found] ` <20110207.130214.221723444.ryusuke-sG5X7nlA6pw@public.gmane.org> 2011-02-07 19:42 ` Philippe CHATAIGNON 2011-02-08 11:42 ` Ryusuke Konishi [not found] ` <20110208.204230.73657026.ryusuke-sG5X7nlA6pw@public.gmane.org> 2011-02-08 20:32 ` Philippe CHATAIGNON 2011-02-10 5:01 ` Ryusuke Konishi [not found] ` <20110210.140105.33383103.ryusuke-sG5X7nlA6pw@public.gmane.org> 2011-02-10 22:32 ` Philippe CHATAIGNON 2011-02-18 7:21 ` Ryusuke Konishi [not found] ` <20110218.162145.57461053.ryusuke-sG5X7nlA6pw@public.gmane.org> 2011-02-18 19:57 ` Philippe CHATAIGNON 2011-02-19 13:22 ` Ryusuke Konishi [not found] ` <20110219.222232.05855196.ryusuke-sG5X7nlA6pw@public.gmane.org> 2011-02-19 15:26 ` Philippe CHATAIGNON
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.