Repository navigation
test_mailbox failure under a Windows VM #53766
Description
| BPO | 9557 |
|---|---|
| Nosy | @akuchling, @pitrou, @bitdancer |
| Files |
Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.
Show more details
GitHub fields:
assignee = None
closed_at = <Date 2011-03-25.20:23:25.062>
created_at = <Date 2010-08-10.13:46:09.911>
labels = ['tests', 'type-bug', 'library']
title = 'test_mailbox failure under a Windows VM'
updated_at = <Date 2011-03-25.20:23:25.061>
user = 'https://github.com/pitrou'bugs.python.org fields:
activity = <Date 2011-03-25.20:23:25.061>
actor = 'r.david.murray'
assignee = 'none'
closed = True
closed_date = <Date 2011-03-25.20:23:25.062>
closer = 'r.david.murray'
components = ['Library (Lib)', 'Tests']
creation = <Date 2010-08-10.13:46:09.911>
creator = 'pitrou'
dependencies = []
files = ['21391']
hgrepos = []
issue_num = 9557
keywords = ['patch']
message_count = 14.0
messages = ['113538', '132089', '132103', '132112', '132116', '132118', '132119', '132121', '132126', '132130', '132133', '132134', '132148', '132149']
nosy_count = 4.0
nosy_names = ['akuchling', 'pitrou', 'r.david.murray', 'python-dev']
pr_nums = []
priority = 'low'
resolution = None
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue9557'
versions = ['Python 3.1', 'Python 2.7', 'Python 3.2', 'Python 3.3']
Activity
pitrou commentedon Aug 10, 2010
I get this failure in test_mailbox under Windows XP running in a qemu virtual machine:
======================================================================
FAIL: test_reread (test.test_mailbox.TestMaildir)
----------------------------------------------------------------------
bitdancer commentedon Mar 25, 2011
It is reasonably likely that the attached patch will fix this. It also removes 3 seconds of fixed overhead from the test.
pitrou commentedon Mar 25, 2011
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.
bitdancer commentedon Mar 25, 2011
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.
pitrou commentedon Mar 25, 2011
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?)
bitdancer commentedon Mar 25, 2011
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?
pitrou commentedon Mar 25, 2011
No, they seem exactly synchronized.
bitdancer commentedon Mar 25, 2011
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.
pitrou commentedon Mar 25, 2011
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)
bitdancer commentedon Mar 25, 2011
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.
pitrou commentedon Mar 25, 2011
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)
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).
bitdancer commentedon Mar 25, 2011
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 :)
python-dev commentedon Mar 25, 2011
New changeset 9a184d8211f5 by R David Murray in branch '3.1':
bpo-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 bpo-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 bpo-9557: eliminate 3 seconds of static overhead from test_mailbox.
http://hg.python.org/cpython/rev/03c7a83bbdd3
bitdancer commentedon Mar 25, 2011
Antoine agreed in IRC that this was an acceptable closure.