Title: Test asynchat makes wrong assumptions
Type: behavior Stage:
Components: Tests Versions: Python 3.2, Python 3.3, Python 3.4, Python 3.5, Python 2.7
Status: open Resolution:
Dependencies: Superseder:
Assigned To: Nosy List: eacb, r.david.murray
Priority: normal Keywords: patch

Created on 2015-06-06 17:32 by eacb, last changed 2015-06-08 19:00 by eacb.

Messages (6)
msg244922 - (view) Author: Étienne Buira (eacb) * Date: 2015-06-06 17:32
Amount of data the server could not send back is not a reliable indication on how much data it received.
msg244939 - (view) Author: R. David Murray (r.david.murray) * (Python committer) Date: 2015-06-07 01:55
Your emendation doesn't seem to do anything differently (logic wise) than the original code.  Unless I am missing something, it is pointless to track the length of the buffer separately from the contents of the buffer.  The buffer knows its length.
msg244940 - (view) Author: R. David Murray (r.david.murray) * (Python committer) Date: 2015-06-07 01:57
(Calling that variable 'buffer' is a bit isn't really a buffer that gets filled, it is an immutable bytes object that gets replaced by a new one with the additional received data appended.)
msg244964 - (view) Author: Étienne Buira (eacb) * Date: 2015-06-07 18:19
The issue is that this buffer is also emptied at the end.

Current version assumes that the server thread will not have enough opportunity to send the whole buffer before receiving a RST.

But in reality, it's quite possible (happens reliably on a box) that:
1. many server sent chars get merged in one packet
2. RST is yielded only once the server have put all its buffer in send queue.

As a consequence, server's buffer is empty at the time it is checked, and the test is marked as failed although everything worked fine.
msg244983 - (view) Author: R. David Murray (r.david.murray) * (Python committer) Date: 2015-06-08 01:55
The comments in the test indicate that this possibility was considered and dealt with.  So that indicates it is a test bug in this particular test (test_close_when_done, for other readers), not in the fixture.  It looks like the race condition still exists, the window is just reduced.  Can you see any reason the assert shouldn't be moved to before the s.start_reserved_event.set()?  (Since I missed the clearing of the buffer, I'm not confident in my reading of the test intent :)
msg245033 - (view) Author: Étienne Buira (eacb) * Date: 2015-06-08 19:00
That would just race the other way around.

However, I missed the fact that the check of client's contents had no chance to catch an issue, as the main thread were not entering asyncore.loop after allowing the server to send.

Updated patch (against 3.3) follows (dunno why, file were not attachable).

diff -r 035aa81c2ba8 Lib/test/
--- a/Lib/test/ Tue Jun 02 18:53:46 2015 -0400
+++ b/Lib/test/ Mon Jun 08 20:14:27 2015 +0200
@@ -30,6 +30,7 @@
             # This will be set if the client wants us to wait before echoing data
             # back.
             self.start_resend_event = None
+            self.received_len = 0
         def run(self):
@@ -41,6 +42,7 @@
                 data = conn.recv(1)
                 if not data:
+                self.received_len += len(data)
                 self.buffer = self.buffer + data
             # remove the SERVER_QUIT message
@@ -226,13 +228,14 @@
         # where the server echoes all of its data before we can check that it
         # got any down below.
+        asyncore.loop(use_poll=self.usepoll, count=300, timeout=.01)
-        self.assertEqual(c.contents, [])
+        self.assertEqual(len(c.contents), 0)
         # the server might have been able to send a byte or two back, but this
         # at least checks that it received something and didn't just fail
         # (which could still result in the client not having received anything)
-        self.assertGreater(len(s.buffer), 0)
+        self.assertGreater(s.received_len, 0)
 class TestAsynchat_WithPoll(TestAsynchat):
Date User Action Args
2015-06-08 19:00:41eacbsetmessages: + msg245033
2015-06-08 18:15:24eacbsetfiles: - test_asynchat_check_received_len_if_received_len_matters.diff
2015-06-08 01:55:31r.david.murraysetmessages: + msg244983
2015-06-07 18:19:32eacbsetmessages: + msg244964
2015-06-07 01:57:44r.david.murraysetmessages: + msg244940
2015-06-07 01:55:24r.david.murraysetnosy: + r.david.murray
messages: + msg244939
2015-06-06 17:32:23eacbcreate