| msg92550 - (view) |
Author: Ezio Melotti (ezio.melotti) *  |
Date: 2009-09-12 18:15 |
| 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 != 1 I 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. |
|
|
| msg94772 - (view) |
Author: Antoine Pitrou (pitrou) * |
Date: 2009-10-31 22:21 |
| Looking at the frequent buildbot failures, they always seem to happen in TestMaildir. Therefore, it may have to do with the metadata-updating behaviour of the filesystem (since maildir uses one file per message). Unfortunately, while I tried to reproduce the failures on my home system with 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 its mount options? (if you don't know them, look in /proc/mounts) |
|
|
| msg94777 - (view) |
Author: Antoine Pitrou (pitrou) * |
Date: 2009-10-31 23:42 |
| Ezio, could you give a try to the following patch? |
|
|
| msg94778 - (view) |
Author: Antoine Pitrou (pitrou) * |
Date: 2009-11-01 00:14 |
| Another possible explanation is that the logic for computing Maildir._last_time is wrong. It should be computed before refreshing the internal cache, not after. Here is a patch. |
|
|
| msg94779 - (view) |
Author: Antoine Pitrou (pitrou) * |
Date: 2009-11-01 01:07 |
| According to testers, both patches fail at addressing the issue. |
|
|
| msg94781 - (view) |
Author: R. David Murray (r.david.murray) * |
Date: 2009-11-01 02:01 |
| I hacked mailbox.py so that a _toc refresh is always done and ran the tests in a loop, and did not get a failure in 30+ runs, whereas without that hack I would get failures almost every run. So I think Antoine is on the right track. |
|
|
| msg94787 - (view) |
Author: Antoine Pitrou (pitrou) * |
Date: 2009-11-01 14:50 |
| 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 && 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, the mtime of the directory is set a full one second before the date at which its contents are modified. I guess the only safe solution is to explicitly flush the internal cache when we do any modifications. |
|
|
| msg94788 - (view) |
Author: Antoine Pitrou (pitrou) * |
Date: 2009-11-01 15:12 |
| Ok, here is a patch which seems to fix the problem reliably on RDM's buildbot. Ezio, can you give it a try? |
|
|
| msg94789 - (view) |
Author: Antoine Pitrou (pitrou) * |
Date: 2009-11-01 15:31 |
| PS: this is the kind of traces I had when running TestMaildir on David's buildbot: at 1257086460.18, linking/renaming ... mtime of '/home/pitrou/trunk/@test_23145_tmp/new' is now 1257086459.0 at 1257086460.21, linking/renaming ... mtime of '/home/pitrou/trunk/@test_23145_tmp/new' is now 1257086459.0 at 1257086460.24, linking/renaming ... mtime of '/home/pitrou/trunk/@test_23145_tmp/new' is now 1257086459.0 at 1257086460.27, linking/renaming ... mtime of '/home/pitrou/trunk/@test_23145_tmp/new' is now 1257086459.0 at 1257086460.3, linking/renaming ... mtime of '/home/pitrou/trunk/@test_23145_tmp/new' is now 1257086459.0 at 1257086460.33, linking/renaming ... mtime of '/home/pitrou/trunk/@test_23145_tmp/new' is now 1257086459.0 at 1257086460.36, linking/renaming ... mtime of '/home/pitrou/trunk/@test_23145_tmp/new' is now 1257086460.0 at 1257086460.38, linking/renaming ... mtime of '/home/pitrou/trunk/@test_23145_tmp/new' is now 1257086460.0 at 1257086460.4, linking/renaming ... mtime of '/home/pitrou/trunk/@test_23145_tmp/new' is now 1257086460.0 As you see, the mtime is set to 1257086459 even when time.time() returns 1257086460.00 and higher, and it's only set to 1257086460 when time.time() reaches 1257086460.36. |
|
|
| msg94815 - (view) |
Author: Antoine Pitrou (pitrou) * |
Date: 2009-11-02 01:06 |
| Ezio indicated that the patch suppressed all failures for him, so I committed it on trunk. |
|
|
| msg94827 - (view) |
Author: Antoine Pitrou (pitrou) * |
Date: 2009-11-02 12:23 |
| 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. |
|
|