AssertionErrors in httplib

[smontanaro]

BPO	666219
Nosy	@smontanaro

^{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 = None closed_at = created_at = labels = ['library'] title = 'AssertionErrors in httplib' updated_at = user = 'https://github.com/smontanaro' ``` bugs.python.org fields: ```python activity = actor = 'nicolary' assignee = 'jhylton' closed = True closed_date = None closer = None components = ['Library (Lib)'] creation = creator = 'skip.montanaro' dependencies = [] files = [] hgrepos = [] issue_num = 666219 keywords = [] message_count = 10.0 messages = ['14007', '14008', '14009', '14010', '14011', '14012', '14013', '14014', '14015', '14016'] nosy_count = 4.0 nosy_names = ['jhylton', 'skip.montanaro', 'showme1949', 'nicolary'] pr_nums = [] priority = 'high' resolution = 'fixed' stage = None status = 'closed' superseder = None type = None url = 'https://bugs.python.org/issue666219' versions = ['Python 2.3'] ```

[smontanaro]

I've recently noticed AssertionErrors being raised by httplib.LineAndFileWrapper.read(). It happens reliably when the server exits unexpectedly. Here's an example of an AssertionError in an xmlrpclib client when I kill the server it's talking to:

    Traceback (most recent call last):
      File "qa.py", line 22, in ?
        x = s.query(tmpl, st, en, radius, age)
      File "/Users/skip/local/lib/python2.3/xmlrpclib.py", line 985, in __call__
        return self.__send(self.__name, args)
      File "/Users/skip/local/lib/python2.3/xmlrpclib.py", line 1269, in __request
        verbose=self.__verbose
      File "/Users/skip/local/lib/python2.3/xmlrpclib.py", line 1036, in request
        return self._parse_response(h.getfile(), sock)
      File "/Users/skip/local/lib/python2.3/xmlrpclib.py", line 1165, in _parse_response
        response = file.read(1024)
      File "/Users/skip/local/lib/python2.3/httplib.py", line 1150, in read
        assert not self._line_consumed and self._line_left
    AssertionError

I don't see a problem with raising an exception in this situation. I just wonder if AssertionError is the best exception to raise (unless of course, the cause is a logic error in the httplib code). If an exception is being raised because the server went away, I think it would be better to raise IncompleteRead.

[03bde425-37ce-4291-88bd-d6cecc46a30e]

Logged In: YES user_id=31392

It's definitely the case that an AssertionError shouldn't be raised. It was my intention that the assert never fail. Do you know which part of the assert fails? Perhaps you could change the assert to print the values of _line_consumed and _line_left and run some more tests. I can't figure out how this goes wrong.

Also, do you know when the server is sending an HTTP/0.9 response? I wonder if there's a bug somewhere else and the client is guessing the wrong protocol version for the response.

[03bde425-37ce-4291-88bd-d6cecc46a30e]

Logged In: YES user_id=31392

Any more info Skip?

[smontanaro]

Logged In: YES user_id=44345

No, sorry, I haven't looked more deeply into the problem. I did investigate far enough to also see that the code was in the HTTP/0.9 weeds and am befuddled about why it would be there. It's using the vanilla xmlrpclib module at both ends. I'll try to spend a little time today.

S

[smontanaro]

Logged In: YES user_id=44345

Sorry for the delay on this. I think I'm closing in on the problem. I've been using Tim O'Malley's timeoutsocket module for quite awhile. I noticed the same problem today when using the new timeout feature in the socket module. Libraries like xmlrpclib use makefile() to get a file object to play with. File objects don't play well with timeouts because the socket is in non-blocking mode. I think what happens here is that the first line of HTTPResponse. _read_status sets line to the empty string because of the timeout setting. Tracing through the code which follows makes it clear that control will wind up in the HTTP/0.9 chunk of code.

Maybe it's worth adding a test for line == "" after the readline() call:

        line = self.fp.readline()
        if self.debuglevel > 0:
            print "reply:", repr(line)
        if line == "":
            raise BadStatusLine(line)

That would distinguish an error reading from an 0.9 server (which would return something with that first readline() call).

[03bde425-37ce-4291-88bd-d6cecc46a30e]

Logged In: YES user_id=31392

We can provoke this error by setting a very small timeout, right?

[smontanaro]

Logged In: YES user_id=44345

[small timeout?]

Not since the changes to the makefile() changes to socket.py (or at least not always). If the timeout is shorter than the response time you now can get a socket.error:

>>> socket.setdefaulttimeout(0.05)
>>> manatee = xmlrpclib.ServerProxy("http://manatee.mojam.com:5007")
>>> manatee.noop()
Traceback (most recent call last):
  File "<stdin>", line 1, in ?
  File "/Users/skip/local/lib/python2.3/xmlrpclib.py", line 1021, in __call__
    return self.__send(self.__name, args)
  File "/Users/skip/local/lib/python2.3/xmlrpclib.py", line 1308, in __request
    verbose=self.__verbose
  File "/Users/skip/local/lib/python2.3/xmlrpclib.py", line 1056, in request
    errcode, errmsg, headers = h.getreply()
  File "/Users/skip/local/lib/python2.3/httplib.py", line 1019, in getreply
    response = self._conn.getresponse()
  File "/Users/skip/local/lib/python2.3/httplib.py", line 770, in getresponse
    response.begin()
  File "/Users/skip/local/lib/python2.3/httplib.py", line 268, in begin
    version, status, reason = self._read_status()
  File "/Users/skip/local/lib/python2.3/httplib.py", line 230, in _read_status
    line = self.fp.readline()
  File "/Users/skip/local/lib/python2.3/socket.py", line 321, in readline
    data = recv(1)
socket.error: (35, 'Resource temporarily unavailable')

I think you may still get the assertion error if the timeout is sufficient to allow some of the response to be read, but not all of it (though that's just a guess).

I suspect we're better off just closing this with either "postponed" or "won't fix" at this point.

[16c2c677-f7b1-4762-9e87-c01988958dcb]

Logged In: YES user_id=811410

OK, I saw this problem pretty in several programs (mine or others). So I deed some search, here is a log that shown self._line_consumed, self._line_left, self._line and self._line_offset with bittorrent.

It is pretty obvious when the assert happens, we have a empty self._line before we even start to read. Maybe because the other end closed on us without sending any data.

A suggusted fix is to append 'and len(self._line) != 0' to the end of assert. -------------- My log on the assert ------- ==== line_consumeed, line_left \=== 0 0

0 === self._line, line_offset \===

Exception in thread Thread-3:
Traceback (most recent call last):
  File "/usr/lib/python2.2/threading.py", line 414, in
__bootstrap
    self.run()
  File "/usr/lib/python2.2/threading.py", line 402, in run
    apply(self.__target, self.__args, self.__kwargs)
  File
"/usr/lib/python2.2/site-packages/BitTorrent/Rerequester.py",
line 76, in rer
equest
    r = h.read()
  File "/usr/lib/python2.2/httplib.py", line 1148, in read
    assert not self._line_consumed and self._line_left
AssertionError

[03bde425-37ce-4291-88bd-d6cecc46a30e]

Logged In: YES user_id=31392

Thanks for the comment, showme1949. It's obvious that the assertion fails in this case. Fixed by raising an exception earlier.

[a3250015-972c-4c0f-b27b-a4150902d359]

Logged In: YES user_id=27555

I had this problem going against a Novell iChains reverse proxy and adding the following to account for an SSLv3 protocol bug in the server to the socketmodule.c fixed this problem:

SSL_CTX_set_options(self->ctx, SSL_OP_DONT_INSERT_EMPTY_FRAGMENTS);

I added this after the SSL_CTX_set_verify call in the aforementioned file. Ther are other bug workaround that one can enable or one can enable all of the workarounds with the following:

SSL_CTX_set_options(conn->ssl.ctx, SSL_OP_ALL);