| msg113538 - (view) |
Author: Antoine Pitrou (pitrou) *  |
Date: 2010-08-10 13:46 |
| I get this failure in test_mailbox under Windows XP running in a qemu virtual machine: ====================================================================== FAIL: test_reread (test.test_mailbox.TestMaildir) ---------------------------------------------------------------------- Traceback (most recent call last): File "Z:\py3k\debug\lib\test\test_mailbox.py", line 764, in test_reread assert not refreshed() AssertionError ---------------------------------------------------------------------- |
|
|
| msg132089 - (view) |
Author: R. David Murray (r.david.murray) * |
Date: 2011-03-25 14:02 |
| It is reasonably likely that the attached patch will fix this. It also removes 3 seconds of fixed overhead from the test. |
|
|
| msg132103 - (view) |
Author: Antoine Pitrou (pitrou) * |
Date: 2011-03-25 15:41 |
| Well, on my new setup (Windows 7 VM with a Python checkout located on an SMB drive), the test sometimes passes and sometimes fails, regardless of the patch. I suspect that maybe maildir requires atomicity guarantees that a network FS won't provide. |
|
|
| msg132112 - (view) |
Author: R. David Murray (r.david.murray) * |
Date: 2011-03-25 16:30 |
| That could be, certainly. The code is depending on the mtime having a resolution of at least one second. Try making the constant 61 instead of 60. If that doesn't work, try putting the mtime back a lot farther and see if that makes it work If it passes with that change then it could be the assumptions made by the code are also incorrect. |
|
|
| msg132116 - (view) |
Author: Antoine Pitrou (pitrou) * |
Date: 2011-03-25 17:03 |
| Indeed, 61 seems to work. I don't understand the comment about one-second granularity, shouldn't it be one-minute? (or why do you need 61?) |
|
|
| msg132118 - (view) |
Author: R. David Murray (r.david.murray) * |
Date: 2011-03-25 17:30 |
| Hmm. You are right, I wasn't thinking clearly, and I copied that mtime setting call from another test. Now I have no idea why 61 would work, unless the clock between your virthost and your smb server is off by a minute? |
|
|
| msg132119 - (view) |
Author: Antoine Pitrou (pitrou) * |
Date: 2011-03-25 17:34 |
| > Hmm. You are right, I wasn't thinking clearly, and I copied that > mtime setting call from another test. Now I have no idea why 61 would > work, unless the clock between your virthost and your smb server is > off by a minute? No, they seem exactly synchronized. |
|
|
| msg132121 - (view) |
Author: R. David Murray (r.david.murray) * |
Date: 2011-03-25 17:41 |
| Could you print out the mtime values that are being set, and the value of self._mbox._last_read? Or, rather, print out the result of calls to os.path.getmtime on the two directories after the mtime is changed. |
|
|
| msg132126 - (view) |
Author: Antoine Pitrou (pitrou) * |
Date: 2011-03-25 17:51 |
| before: os.path.getmtime('cur') = 1301075411.6942866 before: os.path.getmtime('new') = 1301075411.693287 after: os.path.getmtime('cur') = 1301075347.38 after: os.path.getmtime('new') = 1301075347.38 self._box._last_read = 1301075407.365 time.time() = 1301075408.395 (the test passed here) |
|
|
| msg132130 - (view) |
Author: R. David Murray (r.david.murray) * |
Date: 2011-03-25 18:11 |
| Hmm. 411-61=350. Three seconds difference looks a little odd. But doesn't explain 60 vs 61 making the difference in the test. Can you change it back to 60 (or even less) and see what the values look like when the test fails? It is interesting (and possibly meaningful) that the last modified time 'before' appears to be in the future compared to time.time by 3-plus seconds. That would at least explain why the test fails without the patch. |
|
|
| msg132133 - (view) |
Author: Antoine Pitrou (pitrou) * |
Date: 2011-03-25 18:42 |
| > Hmm. 411-61=350. Three seconds difference looks a little odd. But > doesn't explain 60 vs 61 making the difference in the test. > > Can you change it back to 60 (or even less) and see what the values > look like when the test fails? Hmm, 60 doesn't fail anymore so I changed it to 1 (!) and here is the result: before: os.path.getmtime('cur') = 1301078411.882165 before: os.path.getmtime('new') = 1301078411.8801715 after: os.path.getmtime('cur') = 1301078410.802999 after: os.path.getmtime('new') = 1301078410.802999 self._box._last_read = 1301078410.787 time.time() = 1301078411.818 (it fails obviously) > It is interesting (and possibly meaningful) that the last modified > time 'before' appears to be in the future compared to time.time by > 3-plus seconds. That would at least explain why the test fails > without the patch. Yep, although the drift is varying. Sometimes small, sometimes big. At this point I think it's just caused by my setup (the fact that VM and host aren't always synchronized - I once witnessed time advancing quicker on the VM than on the host! -, and the fact that a network FS is used). |
|
|
| msg132134 - (view) |
Author: R. David Murray (r.david.murray) * |
Date: 2011-03-25 18:47 |
| All right, so how about I set the add factor to, say, 5, so that if things are mostly in sync it will succeed, and otherwise just ignore your failures :) |
|
|
| msg132148 - (view) |
Author: Roundup Robot (python-dev)  |
Date: 2011-03-25 20:21 |
| New changeset 9a184d8211f5 by R David Murray in branch '3.1': #9557: eliminate 3 seconds of static overhead from test_mailbox. http://hg.python.org/cpython/rev/9a184d8211f5 New changeset 268ab32a89a9 by R David Murray in branch '3.2': Merge #9557: eliminate 3 seconds of static overhead from test_mailbox. http://hg.python.org/cpython/rev/268ab32a89a9 New changeset 03c7a83bbdd3 by R David Murray in branch 'default': Merge #9557: eliminate 3 seconds of static overhead from test_mailbox. http://hg.python.org/cpython/rev/03c7a83bbdd3 |
|
|
| msg132149 - (view) |
Author: R. David Murray (r.david.murray) * |
Date: 2011-03-25 20:23 |
| Antoine agreed in IRC that this was an acceptable closure. |
|
|