HTTP upgrade can block

[Lukasa]

When running plaintext HTTP/2 upgrades on my Windows machine (Windows 7, Python 2.7.10, Hyper version 0.4.0) I hit a timeout and the following traceback:

C:\Users\Cory>hyper GET http://http2bin.org/get
Traceback (most recent call last):
  File "C:\Python27\Lib\runpy.py", line 162, in _run_module_as_main
    "__main__", fname, loader, pkg_name)
  File "C:\Python27\Lib\runpy.py", line 72, in _run_code
    exec code in run_globals
  File "C:\Python27\Scripts\hyper.exe\__main__.py", line 9, in <module>
  File "C:\Python27\lib\site-packages\hyper\cli.py", line 231, in main
    data = request(args)
  File "C:\Python27\lib\site-packages\hyper\cli.py", line 219, in request
    response = conn.get_response()
  File "C:\Python27\lib\site-packages\hyper\common\connection.py", line 114, in
get_response
    return self._conn.get_response()
  File "C:\Python27\lib\site-packages\hyper\http11\connection.py", line 170, in
get_response
    self._sock.fill()
  File "C:\Python27\lib\site-packages\hyper\common\bufsocket.py", line 170, in f
ill
    count = self._sck.recv_into(self._buffer_view[self._buffer_end:])
socket.timeout: timed out

There's one obvious problem here: we should attempt to grab a response from the buffered socket before calling fill, as we may have already encountered all the data we need from the socket. At the very least, that should change.

However, making that change doesn't resolve the problem. More work is required to diagnose this.

[Lukasa]

A quick check of Wireshark shows the 101 Switching Protocols does arrive, so why does recv_into block?

[Lukasa]

This reproduces on Python 3.4 on Windows, so I believe this to be a Windows Python problem.

[Lukasa]

Just quickly confirmed that recv_into does behave as I expect on Windows: it does appear to return as soon as any bytes are sent.

[Lukasa]

Interesting. If I loop over the socket calls catching exceptions, we keep spinning for three whole socket reads before we return. This leads to a whole ten second delay.

More interestingly, the delay doesn't appear to be on our side necessarily. After those 10 seconds we receive a DATA frame from H2O, containing the HTTP/2 response, at which point everything comes through.

This is very weird.

[Lukasa]

The real question still remains: why doesn't recv_into return until that data frame arrives?

[Lukasa]

Ah, that data frame is an idle timeout from H2O, so it's not really material: that just means the connection is getting torn down to get recv_into to return.

What don't I understand here?

[Lukasa]

This is definitely a Windows problem: a Linux box on the same network does not show this behaviour.

[Lukasa]

Hmm, a thought occurred to me and I quickly tried this out on httpbin.org. No blocking issue. This seems to be related to the 101 process, but I don't really know how that can be.

[Lukasa]

Aha, that's not true: it blocks sometimes on httpbin.org. This seems to be about timing.

[deshmukhrajvardhan]

Hi Lucas,
I had a similar problem with HTTP1.1 library. (After making 90 serial 'GET' method calls)
The Wireshark pcap trace shows the full response but the BUFFER over here shows incomplete response.

This self._sock.buffer and the self._sock.fill() is provided by socket library, Right?

Any tips on how to debug this?