Bizarre mtime behaviour

Hello, I wondered if someone had a clue about the following behaviour. While debugging an erratic test_mailbox failure on RDM's buildbot (and other machines), it turned out that the system sometimes set the wrong mtime on a directory: $ date && python -c 'import os; os.link("setup.py", "t/c")' && stat t && date Sun Nov 1 09:49:04 EST 2009 File: `t' Size: 144 Blocks: 0 IO Block: 4096 directory Device: 811h/2065d Inode: 223152 Links: 2 Access: (0755/drwxr-xr-x) Uid: ( 1001/ pitrou) Gid: ( 1005/ pitrou) Access: 2009-11-01 09:10:11.000000000 -0500 Modify: 2009-11-01 09:49:03.000000000 -0500 Change: 2009-11-01 09:49:03.000000000 -0500 Sun Nov 1 09:49:04 EST 2009 As you see above, the mtime for directory 't' is set to a full second before the actual modification has happened. Sprinkling traces of time.time() and os.path.getmtime() on Lib/mailbox.py shows this is exactly what trips up test_mailbox. I've got posted a patch to fix it (see issue #6896), but I would like to know if such OS behaviour is normal. Regards Antoine.

On Sun, Nov 1, 2009 at 08:23, Antoine Pitrou <solipsis@pitrou.net> wrote:
Hello,
I wondered if someone had a clue about the following behaviour. While debugging an erratic test_mailbox failure on RDM's buildbot (and other machines), it turned out that the system sometimes set the wrong mtime on a directory:
$ date && python -c 'import os; os.link("setup.py", "t/c")' && stat t && date
Sun Nov 1 09:49:04 EST 2009 File: `t' Size: 144 Blocks: 0 IO Block: 4096 directory Device: 811h/2065d Inode: 223152 Links: 2 Access: (0755/drwxr-xr-x) Uid: ( 1001/ pitrou) Gid: ( 1005/ pitrou) Access: 2009-11-01 09:10:11.000000000 -0500 Modify: 2009-11-01 09:49:03.000000000 -0500 Change: 2009-11-01 09:49:03.000000000 -0500 Sun Nov 1 09:49:04 EST 2009
As you see above, the mtime for directory 't' is set to a full second before the actual modification has happened.
Sprinkling traces of time.time() and os.path.getmtime() on Lib/mailbox.py shows this is exactly what trips up test_mailbox. I've got posted a patch to fix it (see issue #6896), but I would like to know if such OS behaviour is normal.
Looks like an OS bug to me. Linux I'm guessing? -- Adam Olsen, aka Rhamphoryncus

Antoine Pitrou wrote:
Adam Olsen <rhamph <at> gmail.com> writes:
Looks like an OS bug to me. Linux I'm guessing?
Yes, but only on certain boxes. I could never reproduce on my home box. RDM (David)'s buildbot is a Gentoo vserver with a reiserfs filesystem.
You'll occasionally see something similar on Windows boxes running FAT, because the timestamps stored in the filesystem have a 2 second granularity there. Not sure if this might be similar, or just a reiserfs issue. Eric.

On Sun, 2009-11-01 at 12:03 -0500, Eric Smith wrote:
Antoine Pitrou wrote:
Adam Olsen <rhamph <at> gmail.com> writes:
Looks like an OS bug to me. Linux I'm guessing?
Yes, but only on certain boxes. I could never reproduce on my home box. RDM (David)'s buildbot is a Gentoo vserver with a reiserfs filesystem.
You'll occasionally see something similar on Windows boxes running FAT, because the timestamps stored in the filesystem have a 2 second granularity there. Not sure if this might be similar, or just a reiserfs issue.
Some years ago there was a bug where the dentry cache held timestamps more granular than those that the filesystem could represent. We saw this cause build failures which were troubling to reproduce :) I haven't seen Linux arbitrarily invent time travel so far:). The FAT rounding issue is a possibility, but I didn't think reiserfs was short that much precision. I'd check that the work area you had really was reiser, not a mounted AT partition, and if its not look up the ReiserFS precision for mtime. -Rob

Le lundi 02 novembre 2009 à 08:02 +1100, Robert Collins a écrit :
The FAT rounding issue is a possibility, but I didn't think reiserfs was short that much precision.
I'd check that the work area you had really was reiser, not a mounted AT partition, and if its not look up the ReiserFS precision for mtime.
Yes it was reiserfs. As for the mtime granularity, since some displayed mtimes were even and some were odd, I assume it's one second or less. Another possibility would be that the filesystem would use a slightly different clock than time.time(), but why?
participants (4)
-
Adam Olsen
-
Antoine Pitrou
-
Eric Smith
-
Robert Collins