While running test.regrtest, test_mailbox failed with the error:test test_mailbox failed -- Traceback (most recent call last):  File "/home/wolf/py3k/Lib/test/test_mailbox.py", line 116, in test_discard    self.assertEqual(len(self._box), 1)AssertionError: 2 != 1I ran the test again several times and got intermittent failures in several different methods. Attached there's a file with the errors I got. During the first tests I was running test_mailbox after test_zipimport, but then I was able to reproduce the failures running test_mailbox alone.I'm using Python 3.2a0 on Ubuntu 8.04.

Looking at the frequent buildbot failures, they always seem to happen inTestMaildir. Therefore, it may have to do with the metadata-updatingbehaviour of the filesystem (since maildir uses one file per message).Unfortunately, while I tried to reproduce the failures on my home systemwith a variety of filesystems (ext3, ext4, reiserfs, xfs and even vfat),I never got any failure here.Ezio, could you give details on your system, your filesystem and itsmount options? (if you don't know them, look in /proc/mounts)

Ezio, could you give a try to the following patch?

Another possible explanation is that the logic for computingMaildir._last_time is wrong. It should be computed before refreshing theinternal cache, not after. Here is a patch.

According to testers, both patches fail at addressing the issue.

I hacked mailbox.py so that a _toc refresh is always done and ran thetests in a loop, and did not get a failure in 30+ runs, whereas withoutthat hack I would get failures almost every run.  So I think Antoine ison the right track.

The explanation seems to be that some systems (including RDM's buildbot)have slightly bizarre mtime behaviour:$ date && python -c 'import os; os.link("setup.py", "t/c")' && stat t &&dateSun Nov  1 09:49:04 EST 2009  File: `t'  Size: 144       Blocks: 0          IO Block: 4096   directoryDevice: 811h/2065dInode: 223152      Links: 2Access: (0755/drwxr-xr-x)  Uid: ( 1001/  pitrou)   Gid: ( 1005/  pitrou)Access: 2009-11-01 09:10:11.000000000 -0500Modify: 2009-11-01 09:49:03.000000000 -0500Change: 2009-11-01 09:49:03.000000000 -0500Sun Nov  1 09:49:04 EST 2009As you see, the mtime of the directory is set a full one second beforethe date at which its contents are modified.I guess the only safe solution is to explicitly flush the internal cachewhen we do any modifications.

Ok, here is a patch which seems to fix the problem reliably on RDM'sbuildbot. Ezio, can you give it a try?

PS: this is the kind of traces I had when running TestMaildir on David'sbuildbot:at1257086460.18, linking/renaming ... mtime of'/home/pitrou/trunk/@test_23145_tmp/new' is now1257086459.0at1257086460.21, linking/renaming ... mtime of'/home/pitrou/trunk/@test_23145_tmp/new' is now1257086459.0at1257086460.24, linking/renaming ... mtime of'/home/pitrou/trunk/@test_23145_tmp/new' is now1257086459.0at1257086460.27, linking/renaming ... mtime of'/home/pitrou/trunk/@test_23145_tmp/new' is now1257086459.0at1257086460.3, linking/renaming ... mtime of'/home/pitrou/trunk/@test_23145_tmp/new' is now1257086459.0at1257086460.33, linking/renaming ... mtime of'/home/pitrou/trunk/@test_23145_tmp/new' is now1257086459.0at1257086460.36, linking/renaming ... mtime of'/home/pitrou/trunk/@test_23145_tmp/new' is now1257086460.0at1257086460.38, linking/renaming ... mtime of'/home/pitrou/trunk/@test_23145_tmp/new' is now1257086460.0at1257086460.4, linking/renaming ... mtime of'/home/pitrou/trunk/@test_23145_tmp/new' is now1257086460.0As you see, the mtime is set to1257086459 even when time.time() returns1257086460.00 and higher, and it's only set to1257086460 whentime.time() reaches1257086460.36.

Ezio indicated that the patch suppressed all failures for him, so Icommitted it on trunk.

Now merged into py3k and 3.1, where it has solved the buildbot issues.2.6 doesn't apply, since the caching scheme isn't present there.If there's any problem with the patch, please reopen.