IMAP4_SSL spin because of SSLSocket.suppress_ragged_eofs

[ea534ff9-6565-40f4-8398-d59320859a28]

BPO	5949
Nosy	@warsaw, @rhettinger, @ncoghlan, @benjaminp, @bitdancer
Files	imaplib-r76683.patch: corrects the handling of EOF in readline() and _get_line() test_imaplib_issue5949-3.patch: PEP8ified tests test_imaplib_issue5949-py26.patch: tests backported for 2.6 socketserver_issue_6267.patch: backport for py26 of SocketServer patch from r73638 test_imaplib_issue5949_py3k.patch

^{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: ```python assignee = 'https://github.com/bitdancer' closed_at = created_at = labels = ['type-bug', 'library'] title = 'IMAP4_SSL spin because of SSLSocket.suppress_ragged_eofs' updated_at = user = 'https://bugs.python.org/kevinwatters' ``` bugs.python.org fields: ```python activity = actor = 'r.david.murray' assignee = 'r.david.murray' closed = True closed_date = closer = 'r.david.murray' components = ['Library (Lib)'] creation = creator = 'kevinwatters' dependencies = [] files = ['15456', '15474', '15510', '15511', '15512'] hgrepos = [] issue_num = 5949 keywords = ['patch'] message_count = 38.0 messages = ['87337', '87359', '87410', '91663', '93392', '93401', '93402', '93621', '93708', '95424', '96010', '96017', '96018', '96019', '96020', '96021', '96025', '96027', '96028', '96029', '96030', '96031', '96038', '96039', '96050', '96052', '96061', '96170', '96172', '96174', '96176', '96177', '96178', '96179', '96180', '96186', '96187', '96300'] nosy_count = 10.0 nosy_names = ['barry', 'rhettinger', 'ncoghlan', 'janssen', 'scott.dial', 'kevinwatters', 'benjamin.peterson', 'r.david.murray', 'rmore', 'rtucker'] pr_nums = [] priority = 'high' resolution = 'fixed' stage = 'resolved' status = 'closed' superseder = None type = 'behavior' url = 'https://bugs.python.org/issue5949' versions = ['Python 2.6', 'Python 3.1', 'Python 2.7', 'Python 3.2'] ```

[ea534ff9-6565-40f4-8398-d59320859a28]

I cannot reproduce this locally yet, but I have several bug reports from users showing that IMAP4_SSL connections can get stuck in an infinite loop during logout()

File "imaplib.pyo", line 529, in logout File "imaplib.pyo", line 1059, in _simple_command File "imaplib.pyo", line 889, in _command_complete File "imaplib.pyo", line 990, in _get_tagged_response File "imaplib.pyo", line 907, in _get_response File "imaplib.pyo", line 1000, in _get_line File "imaplib.pyo", line 1170, in readline File "ssl.pyo", line 136, in read

IMAP4_SSL uses ssl.wrap_socket and should probably be passing suppress_ragged_eofs=False. Without this, self.sslobj.read() may return '' forever, and both IMAP4_SSL.read() and IMAP4_SSL.readline() will spin. With suppress_ragged_eofs=False, calling logout() may raise an SSLError instead.

Thoughts?

[a0b5f834-60b6-4c16-947e-adc08ee799e4]

Isn't the call to read(1) blocking in this case?

If so the only reason it should spin would be if it returned an empty string representing EOF.

Couldn't we just add a check for an empty string and, if found, raise an EOF exception?

[ea534ff9-6565-40f4-8398-d59320859a28]

I wasn't sure--the docs for SSLSocket.read (http://docs.python.org/library/ssl.html#ssl.SSLSocket.read) say

"Reads up to nbytes bytes from the SSL-encrypted channel and returns them."

With that "up to" I wasn't sure that an empty string would necessarily mean EOF--I'm not familiar enough with _ssl.c to say either way.

[f729a738-c84f-4881-b265-6d1fa2b604a9]

I can reproduce this problem with Python 2.6. It manifests itself as a lengthy iteration through an IMAP SSL mailbox locking up after a long while and the interpreter consuming all available system memory.

I suspect this to be the combination of doom:

imaplib.py: 1166 def readline(self): 1167 """Read line from remote.""" 1168 line = [] 1169 while 1: 1170 char = self.sslobj.read(1) 1171 line.append(char) 1172 if char == "\n": return ''.join(line)

ssl.py: 130 def read(self, len=1024): 131 132 """Read up to LEN bytes and return them. 133 Return zero-length string on EOF.""" 134 135 try: 136 return self._sslobj.read(len) 137 except SSLError, x: 138 if x.args[0] == SSL_ERROR_EOF and self.suppress_ragged_eofs: 139 return '' 140 else: 141 raise

After setting suppress_ragged_eofs=False, I now get:

ssl.SSLError: [Errno 8] _ssl.c:1325: EOF occurred in violation of protocol

... instead of an explosion. This I can trap and handle much more easily than an infinite loop appending '' to a list on each iteration :-)

I can reliably reproduce this against my gmail mailbox, although it does take some number of hours. I am not sure if this would be an imaplib bug or a ssl bug; I'd think ssl, because it is Not the Python Way to bury an exception like this.

[c9c600fd-6f74-404c-b7d9-cf8ebeb09f38]

It would seem the logical patch would be to return the line when the empty string is returned. This would fall in line with the behavior of other objects with a readline() in python. In following with that, the patch I have attached returns a truncated line. Therein, the _get_line() implementation needs to actually check for the correct termination of the line (it's arguably a bug as it is, just chucking away the last two characters blindly).

[ncoghlan]

Probably too late for 2.6.3 - assigning to Barry to check anyway.

[warsaw]

I'm afraid so. Please consider this for landing after 2.6.3 is released.

[rhettinger]

Can this go into 2.6.4?

[warsaw]

Sorry, 2.6.4 will be solely to remove the brown paper bag of 2.6.3 from our heads. This can go in 2.6.5 though.

[ncoghlan]

Unassigned from Barry since this isn't an RM review issue anymore

[benjaminp]

.endswith() is a good alternative to [-2:] ==

[c9c600fd-6f74-404c-b7d9-cf8ebeb09f38]

Alright, I am attaching a new patch to correct the brain-fart inefficiency of slicing versus endswith().

I don't understand why this is so difficult to review. I don't think Janssen is the right person to have been assigned to this. While it is related to SSL, I don't think the IMAP module is even on his radar. Whereas, I use this module everyday, every 10 minutes every day to fetch my email (via getmail), and can assure you that the 110 character change is correct.

[benjaminp]

Rest assured it has little to do with the difficultly of reviewing it. Rather we are all volunteers. Do you think a test would be easy to write for this?

[c9c600fd-6f74-404c-b7d9-cf8ebeb09f38]

Ben, I understand that we are all volunteers here. My frustration in the lack of a de facto owner of the imaplib module and not with you personally or any other committer for that matter.

As it is, there is no unittests for the imaplib module, and I am not in a position to provide a complete implementation of an IMAP server. However, I have attached a simple script demonstrating the issue. An unpatched trunk will infinite loop, consuming memory, and a patched version will throw a Traceback immediately.

[benjaminp]

2009/12/5 Scott Dial \report@bugs.python.org\:

Scott Dial \scott@scottdial.com\ added the comment:

Ben, I understand that we are all volunteers here. My frustration in the lack of a de facto owner of the imaplib module and not with you personally or any other committer for that matter.\

Unfortunately imaplib predates the focus for stability in Python.

As it is, there is no unittests for the imaplib module, and I am not in a position to provide a complete implementation of an IMAP server.

There is a stub in test_imaplib.py. I wouldn't expect a complete test suite, but merely a test exposing the bug you are fixing. Every step counts.

However, I have attached a simple script demonstrating the issue. An unpatched trunk will infinite loop, consuming memory, and a patched version will throw a Traceback immediately.

[c9c600fd-6f74-404c-b7d9-cf8ebeb09f38]

I found myself in the mood to code, so in the spirit of "every step counts", I have attached a patch that updates test_imaplib accordingly. The construction of the test framework is based loosely on test_ssl and test_socketserver. If someone felt so moved to add more test cases, then one would could simply extend SimpleIMAPHandler to handle more IMAP commands.

FYI, as previously noted, on an unpatch trunk test_issue5949() is an infinite loop.

[bitdancer]

With just the test patch applied, test_imaplib passes for me on trunk r76687.

[bitdancer]

Ah, your new test isn't being run, that's why test_impalib passes. Let me figure out why your test isn't run.

[c9c600fd-6f74-404c-b7d9-cf8ebeb09f38]

The test requires regrtest.py be run with network support and the python instance be built with threads.

$ ./python Lib/test/regrtest.py -u network test_imaplib

Without network support, it just skips those test (which is the same way test_ssl). That seemed a bit fishy to me, but I was just emulating what I saw.

[bitdancer]

OK, after adding ThreadedNetworkedTests to the 'tests' list in test_main, the new tests ran and did hang. After applying the imaplib patch, the new tests completed. However, afterward I got the following traceback:

Exception in thread Thread-6 (most likely raised during interpreter
shutdown):
Traceback (most recent call last):
  File "/home/rdmurray/python/trunk/Lib/threading.py", line 526, in
__bootstrap_inner
  File "/home/rdmurray/python/trunk/Lib/threading.py", line 479, in run
  File "/home/rdmurray/python/trunk/Lib/SocketServer.py", line 583, in
process_request_thread
  File "/home/rdmurray/python/trunk/Lib/test/test_imaplib.py", line 82,
in handle_error
  File "/home/rdmurray/python/trunk/Lib/SocketServer.py", line 434, in
server_close
  File "/home/rdmurray/python/trunk/Lib/socket.py", line 192, in close
<type 'exceptions.TypeError'>: 'NoneType' object is not callable

[bitdancer]

Ah, my mistake, I misread the code, sorry.

Yes, if I supply -uall to regrtest the tests run correctly.

[c9c600fd-6f74-404c-b7d9-cf8ebeb09f38]

Thanks for giving it a try. I believe the issue is that I am raising an exception in the middle of run_server, which was not a pattern tested in the other modules I looked at. Thus, the threads for those do not get reaped correctly.

I have rewrote the test to ensure all of the spawned threads and servers are shutdown correctly.

[bitdancer]

The traceback I posted was a spurious result of my misunderstanding your test code. With -uall it worked fine. Sorry that I didn't make that clear.

Thanks for doing the work of putting the extended test framework together. Without that, this would probably have remained stuck.

I don't think the test_socketserver code is a particularly good example of unittest code, though, so I refactored what you did into something I like better. I may be wrong, so feedback welcome.

Alternative test_imaplib patch attached.

Note that in looking at this I discovered that the test suite as a whole does not currently handle --without-threads cleanly. I've opened issue 7449 for this. Since test_imaplib currently only has one non-thread-dependent test, I've written my version of the patch so that the whole test is skipped if threading is not available (this skip will come with an appropriate message in the test output).

Note also that my code generates a traceback analogous to the one I posted but only when run under -R. I'll have to look in to that.

[bitdancer]

Patch actually attached this time.

[c9c600fd-6f74-404c-b7d9-cf8ebeb09f38]

The design of your patch makes a lot of sense. I found that your patch uncovered a problem with using the ThreadingMixin (which is ultimately not necessary as long as the whole SocketServer is in its own thread). I rewrote the SimpleIMAPHandler to timeout in a timely manner and for the reap_server() to actually ensure that all threads have been shutdown.

I ended up rewriting my patch in steps towards yours before I uncovered why I was getting threads alive at shutdown. In that vein, the patch I am attaching uses the "with reaped_server(hdlr) as server:" technique, but it could be converted to use an attribute instead. I find using "with" easier to read and less error prone (failing shutdown the server and thread because human error or an uncaught exception).

[bitdancer]

IMO the context manager approach is much better than what I had. I'm still not used to using those :)

One request: I imported test_support as support because that's what it is named in py3k, and doing it that way will make porting the patch to py3k simpler. It would also be nice to pep8ify the spacing by putting two blank lines between classes (yeah, I know, a lot of the test source is not PEP-8 compliant...but we try to keep any new code compliant, and fix old code as we touch it).

Oh, and the reason I moved SocketServer below the import_module for threading is that SocketServer will die on import if threading is not available, so it seemed better to me to make the explicit check for threading first. Probably instead that import_module should be moved to the top of the import list, since if it fails the module is skipped.

[c9c600fd-6f74-404c-b7d9-cf8ebeb09f38]

I actually thought I was complying with PEP-8.. yikes. I guess my personal rules are slightly different. I think the latest attached patch is PEP-8 compliant now. And, I moved the import_module() to the top as you suggested.

[bitdancer]

Applied to trunk in r76276. However, when I tried to backport it to 2.6, the tests hang in test_connect for the SSL version. The hang isn't interruptible by ctl-C. Perhaps there's some SSL fix that hasn't been backported, and if so it would be nice to figure out if it can be backported. (Note, to backport the tests I removed the 'reap_threads' context manager calls and replaced it with a reap_children call at the end of test_main).

[bitdancer]

Added skipping of the SSL tests if ssl is not available in r76727.

[c9c600fd-6f74-404c-b7d9-cf8ebeb09f38]

I have attached a proper backport for the 2.6 maintenance branch. There were some features (not bugfixes) of the trunk that the tests depended on, which are not backported.

However, the tests still hang, because there are changes to SocketServer.py that were not backported to 2.6. The changes are needed to properly call close() on the underlying socket of the SecureTCPServer and thus trigger the EOF. To avoid the backporting of bits in SocketServer, I hacked the necessary bits into this version of the tests.

[bitdancer]

Do you know which patches? It's possible they just haven't been evaluated for backport yet, and if that's so I'll see if I can take care of it.

[c9c600fd-6f74-404c-b7d9-cf8ebeb09f38]

I tracked the necessary change to r73638 and bpo-6267. However, I am not sure it is in scope to backport all of that.

The only changed actually needed from this set to make SocketServer behave correctly with a SSLSocket is:

     def close_request(self, request):
         """Called to clean up an individual request."""
+        #explicitly shutdown.  socket.close() merely releases
+        #the socket and waits for GC to perform the actual close.
+        request.shutdown(socket.SHUT_WR)
         request.close()

Hence in my py26 patch, I have made a call to shutdown() within the handler. I would call this a bug, but nobody seems to have noticed but me, so I defer to you about the best solution.

[c9c600fd-6f74-404c-b7d9-cf8ebeb09f38]

I've revised my opinion. If you extract out only the changes to SocketServer and ignore the others, then I would consider it a good backport (fixes bugs only). I have attached such a patch.

BTW, with this patch, you can remove the shutdown() call in the test_imaplib patch.

[bitdancer]

I'll take a look at the socketserver issue, but probably not today.

In the meantime, can you take a look at this port of the tests to py3k when you get a chance? The tests pass without changes to imaplib, but the imaplib code is a bit different in py3k. I'd like your opinion on whether the fact that _get_line unconditionally chomps the last two bytes is a bug waiting to happen in some other context, even though it doesn't happen in this particular one in py3k.

[c9c600fd-6f74-404c-b7d9-cf8ebeb09f38]

It seems that on the py3k branch, the EOF situation is handled roughly in the same manner (the broken line is returned) and ultimately the IMAP4.abort exception is raised because b'* ' is an invalid response (the 'OK' having been dropped). IOW, it passes the EOF test only because trimming broke the welcome message format. If it got an EOF in the middle of a more complicated response, it would go undetected or cause a broken response.

I propose adding the following test case:

    @reap_threads
    def test_line_termination(self):

        class BadNewlineHandler(SimpleIMAPHandler):

            def cmd_CAPABILITY(self, tag, args):
                self._send(b'* CAPABILITY IMAP4rev1 AUTH\n')
                self._send('{} OK CAPABILITY
completed\r\n'.format(tag).encode('ASCII'))

        with self.reaped_server(BadNewlineHandler) as server:
            self.assertRaises(imaplib.IMAP4.abort,
                              self.imap_class, *server.server_address)

Which silently misreads the CAPABILITY response as including "AUT" and not "AUTH". It would be a perversely broken server, but I think this test case demonstrates why an explicit check and exception should be thrown always.

[bitdancer]

Unfortunately, the SocketServer patches introduced other issues (see for example bpo-6381). So I'm reluctant to backport those changes, since as you say no one had reported problems. It seems like the chance of inadvertently breaking someone's working 2.6 code is too high given the absence of any actual bug report that we'd be fixing.

So I'm inclined to go with your revised test for the 2.6 backport of this bugfix.

[bitdancer]

Committed to py3k in r76730 with the suggested additional test.

[bitdancer]

Patch modified to skip ssl tests if ssl not available in r76727 in trunk; that changeset included in all merges. p3k merge in r76730 as stated. 2.6 merge in r76761, using the 2.6 patch provided by Scott. 3.1 merge in r76762.