File was modified, but mtime stayed the same (according to unison)
Hi!
Today, I got strange warning from unison:
pavel/.config/chromium/Default/Extension State/LOG.old — transport failure
• The source file /data/pavel/.config/chromium/Default/Extension State/LOG.old
has been modified but the fast update detection mechanism failed to detect it. Try running once with the fastcheck option set to 'no'.
Filesystem is plain ext4.
pavel@amd:~$ cat /proc/mounts | grep /data /dev/sda2 /data ext4 rw,relatime,errors=remount-ro,data=ordered 0 0 pavel@amd:~$ uname -a Linux amd 4.1.0-rc5 #23 SMP Wed May 27 09:19:18 CEST 2015 x86_64 GNU/Linux
Now, I know mount -oloop can do such "silent updates"... but that should not be case for chromium. unison 2.40.102. Any ideas?
Thanks,
Pavel
Signature · 2 lines
(english) http://www.livejournal.com/~pavelmachek (cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html
Quoted 5 lines · Pavel Machek
Hi!
Today, I got strange warning from unison:
Quoted 7 lines
pavel/.config/chromium/Default/Extension State/LOG.old — transport failure
• The source file /data/pavel/.config/chromium/Default/Extension State/LOG.old
has been modified but the fast update detection mechanism failed to detect it. Try running once with the fastcheck option set to 'no'.
What does this mean, precisely? Is Unison checking that files have been modified using some kind of a checksum or file comparison mechanism? And I assume that the "fast update detection mechanism" using mtime?
And if it has modified, how was it modified (can you do a diff with what the other side of the synchronization setup had for that file), and do you know by which process. and what was it trying to do? And how is unison being run?
One thing that could be going on is that if you have a file which is mmap'ed, the mtime field is set the first time the page is modified (when the page table entry is set to read/write from read-only). If unison then takes a snapshot of the file, and then file is subsequently modified via a write to the mmap'ed page, the mtime field will not be updated again. We *could* constantly reset the page table flags but it would be disastrous from a performance standpoint, and if mmap is involved, Posix does *not* guarantee that mtime field will be set each time a process writes to the mmap'ed segment --- because that would be insane.
Regards,
- Ted
Quoted 14 lines · Theodore Ts'o
Quoted 5 lines · Pavel Machek
Hi!
Today, I got strange warning from unison:
Quoted 7 lines
pavel/.config/chromium/Default/Extension State/LOG.old — transport failure
• The source file /data/pavel/.config/chromium/Default/Extension State/LOG.old
has been modified but the fast update detection mechanism failed to detect it. Try running once with the fastcheck option set to 'no'.
Quoted 4 lines
What does this mean, precisely? Is Unison checking that files have been modified using some kind of a checksum or file comparison mechanism? And I assume that the "fast update detection mechanism" using mtime?
I believe it is using checksum in the process, yes.
Quoted 4 lines
And if it has modified, how was it modified (can you do a diff with what the other side of the synchronization setup had for that file), and do you know by which process. and what was it trying to do? And how is unison being run?
No, sorry, I don't think I can get old version of file.
Quoted 10 lines
One thing that could be going on is that if you have a file which is mmap'ed, the mtime field is set the first time the page is modified (when the page table entry is set to read/write from read-only). If unison then takes a snapshot of the file, and then file is subsequently modified via a write to the mmap'ed page, the mtime field will not be updated again. We *could* constantly reset the page table flags but it would be disastrous from a performance standpoint, and if mmap is involved, Posix does *not* guarantee that mtime field will be set each time a process writes to the mmap'ed segment --- because that would be insane.
Ok, I guess mmap() can explain this. So... basically mtime is useless in detecting if file have been updated?
Thats... not welcome.
I see that constantly updating on-disk timestamp is not feasible. Could we do something like
on page_being_mmapped_rw:
file.mtime = "future".
on last_rw_mmap_disappearing:
file.mtime = now().
stat():
if file.mtime != "future":
result.mtime = file.mtime
else:
result.mtime = now()
? I see making stat slower is not welcome, but having to read complete files to determine if they were modified is even worse than that...
Pavel
Signature · 2 lines
(english) http://www.livejournal.com/~pavelmachek (cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html
Quoted 5 lines · Pavel Machek
Ok, I guess
mmap()can explain this. So... basically mtime is useless in detecting if file have been updated?Thats... not welcome.
Using mtime to detect if a file has been updated if there is a process updating the file at the same time you are trying to take snapshots and using mtime is inherently racy.
This was much more obvious for file systems with a one second mtime granularity, but because of mmap(2), it's still not true even if you have a file system with nanosecond timestamps.
Quoted 9 lines
I see that constantly updating on-disk timestamp is not feasible. Could we do something like
on
page_being_mmapped_rw:
file.mtime = "future".on
last_rw_mmap_disappearing:
file.mtime =now().
Quoted 8 lines
stat():
if file.mtime != "future":
result.mtime = file.mtime
else:
result.mtime =now()? I see making stat slower is not welcome, but having to read complete files to determine if they were modified is even worse than that...
Doing this would violate POSIX, and would probably break other programs that would be surprised when mtime goes backwards. I suspect a better thing to do is to add a new system call interface which allows a userspace process to query whether a file is either (a) opened for read, (b) opened for write, and/or (c) mmap'ed. Not all file systems would be able to return this bitfield --- for example, it wouldn't be possible to do this for NFS, for example, and it's not clear how this should or could work for overlayfs.
Unison could then be modified to use this new system call interface, so it can take special care if the file is currently opened for write or mmap'ed. Note that because of the mtime granularity issues, which can be constrained by the on-disk file system field, as well as the granularity of the hardware clocks available to the system, unison could get fooled nonetheless.
Regards,
- Ted
Quoted 24 lines · Theodore Ts'o
Quoted 5 lines · Pavel Machek
Hi!
Today, I got strange warning from unison:
Quoted 7 lines
pavel/.config/chromium/Default/Extension State/LOG.old — transport failure
• The source file /data/pavel/.config/chromium/Default/Extension State/LOG.old
has been modified but the fast update detection mechanism failed to detect it. Try running once with the fastcheck option set to 'no'.What does this mean, precisely? Is Unison checking that files have been modified using some kind of a checksum or file comparison mechanism? And I assume that the "fast update detection mechanism" using mtime?
And if it has modified, how was it modified (can you do a diff with what the other side of the synchronization setup had for that file), and do you know by which process. and what was it trying to do? And how is unison being run?
Quoted 6 lines
One thing that could be going on is that if you have a file which is mmap'ed, the mtime field is set the first time the page is modified (when the page table entry is set to read/write from read-only). If unison then takes a snapshot of the file, and then file is subsequently modified via a write to the mmap'ed page, the mtime field will not be updated again.
That's not right: when dirty mmap pages are cleaned by writeback the PTEs are cleaned, too. Hence on the next modification of that page we will get a new write page fault that modifies the mtime. IOWs, if the "snapshot" involves writing back the file, then it will be marked clean and the next page fault will cause the mtime to be updated.
In general, this means that constantly dirtied mmap files will have the mtime updated at least every 30s and background writeback cleans dirty pages. Usually, however, it is much more often than that as each clean page that is dirtied will cause the mtime to be updated due to traversal through the ->page_mkwrite -> ext4_page_mkwrite() -> file_update_time() path.
Cheers,
Dave.
Signature · 2 lines
Dave Chinner [email protected]