Httpx: h11._util.LocalProtocolError: Too little data for declared Content-Length

[x0day]

client POC:

import asyncio
import logging
import httpx

logging.basicConfig(level=logging.DEBUG)


async def test():
    client = httpx.AsyncClient()
    url = 'http://127.0.0.1:8000/debug'
    resp = await client.post(url, data='debug', allow_redirects=True)
    print(resp.content)


if __name__ == '__main__':
    asyncio.get_event_loop().run_until_complete(test())

app POC:

from starlette.responses import RedirectResponse
from starlette.applications import Starlette
import uvicorn

app = Starlette(debug=True)

@app.route('/debug', methods=['POST', 'GET'])
async def debug(request):
    return RedirectResponse(url='https://httpbin.org/headers', status_code=302)

if __name__ == '__main__':
    uvicorn.run(app)

log:

DEBUG:asyncio:Using selector: KqueueSelector
DEBUG:httpx.dispatch.connection_pool:new_connection connection=HTTPConnection(origin=Origin(scheme='http' host='127.0.0.1' port=8000))
DEBUG:httpx.dispatch.connection:start_connect host='127.0.0.1' port=8000 timeout=TimeoutConfig(timeout=5.0)
DEBUG:httpx.dispatch.connection:connected http_version='HTTP/1.1'
DEBUG:httpx.dispatch.http11:send_headers method='POST' target='/debug' headers=Headers({'host': '127.0.0.1:8000', 'user-agent': 'python-httpx/0.7.2', 'accept': '*/*', 'content-length': '5', 'accept-encoding': 'gzip, deflate', 'connection': 'keep-alive'})
DEBUG:httpx.dispatch.http11:receive_event event=NEED_DATA
DEBUG:httpx.dispatch.http11:send_data data=Data(<5 bytes>)
DEBUG:httpx.dispatch.http11:receive_event event=Response(status_code=302, headers=[(b'date', b'Tue, 03 Sep 2019 03:50:53 GMT'), (b'server', b'uvicorn'), (b'location', b'https://httpbin.org/headers'), (b'transfer-encoding', b'chunked')], http_version=b'1.1', reason=b'Found')
DEBUG:httpx.dispatch.http11:receive_event event=EndOfMessage(headers=[])
DEBUG:httpx.dispatch.http11:response_closed our_state=DONE their_state=DONE
DEBUG:httpx.dispatch.connection_pool:release_connection connection=HTTPConnection(origin=Origin(scheme='http' host='127.0.0.1' port=8000))
DEBUG:httpx.dispatch.connection_pool:new_connection connection=HTTPConnection(origin=Origin(scheme='https' host='httpbin.org' port=443))
DEBUG:httpx.dispatch.connection:start_connect host='httpbin.org' port=443 timeout=TimeoutConfig(timeout=5.0)
DEBUG:httpx.dispatch.connection:connected http_version='HTTP/1.1'
DEBUG:httpx.dispatch.http11:send_headers method='GET' target='/headers' headers=Headers({'host': 'httpbin.org', 'user-agent': 'python-httpx/0.7.2', 'accept': '*/*', 'content-length': '5', 'accept-encoding': 'gzip, deflate', 'connection': 'keep-alive'})
DEBUG:httpx.dispatch.http11:receive_event event=NEED_DATA


Traceback (most recent call last):
  File "http3/httpx/dispatch/http11.py", line 53, in send
    http_version, status_code, headers = await self._receive_response(timeout)
  File "http3/httpx/dispatch/http11.py", line 133, in _receive_response
    event = await self._receive_event(timeout)
  File "http3/httpx/dispatch/http11.py", line 174, in _receive_event
    self.READ_NUM_BYTES, timeout, flag=self.timeout_flag
  File "http3/httpx/concurrency/asyncio.py", line 92, in read
    raise ReadTimeout() from None
http3.httpx.exceptions.ReadTimeout

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "test_proto.py", line 16, in <module>
    asyncio.get_event_loop().run_until_complete(test())
  File "/lib/python3.7/asyncio/base_events.py", line 584, in run_until_complete
    return future.result()
  File "test_proto.py", line 11, in test
    resp = await client.post(url, data='debug', allow_redirects=True)
  File "http3/httpx/client.py", line 415, in post
    trust_env=trust_env,
  File "http3/httpx/client.py", line 566, in request
    trust_env=trust_env,
  File "http3/httpx/client.py", line 237, in send
    return await get_response(request)
  File "http3/httpx/middleware.py", line 72, in __call__
    return await self(next_request, get_response)
  File "http3/httpx/middleware.py", line 62, in __call__
    response = await get_response(request)
  File "http3/httpx/client.py", line 202, in get_response
    request, verify=verify, cert=cert, timeout=timeout
  File "http3/httpx/dispatch/connection_pool.py", line 126, in send
    raise exc
  File "http3/httpx/dispatch/connection_pool.py", line 121, in send
    request, verify=verify, cert=cert, timeout=timeout
  File "http3/httpx/dispatch/connection.py", line 65, in send
    response = await self.h11_connection.send(request, timeout=timeout)
  File "http3/httpx/dispatch/http11.py", line 53, in send
    http_version, status_code, headers = await self._receive_response(timeout)
  File "http3/httpx/concurrency/asyncio.py", line 285, in __aexit__
    await self.task
  File "http3/httpx/dispatch/http11.py", line 108, in _send_request_data
    await self._send_event(event, timeout)
  File "http3/httpx/dispatch/http11.py", line 123, in _send_event
    bytes_to_send = self.h11_state.send(event)
  File "site-packages/h11/_connection.py", line 469, in send
    data_list = self.send_with_data_passthrough(event)
  File "site-packages/h11/_connection.py", line 502, in send_with_data_passthrough
    writer(event, data_list.append)
  File "site-packages/h11/_writers.py", line 79, in __call__
    self.send_eom(event.headers, write)
  File "site-packages/h11/_writers.py", line 102, in send_eom
    raise LocalProtocolError("Too little data for declared Content-Length")
h11._util.LocalProtocolError: Too little data for declared Content-Length

[sethmlarson]

Thanks for the POC! Looks like the debug logging is coming in handy already :) It looks like we're not persisting the data parameter on redirects, we should be doing that.

[florimondmanca]

@sethmlarson Should we? This is a case of 302 redirect from POST, and I believe in that case we redirect with GET (see here) and strip out request content, just like browsers do (see here). So what I think we’re missing is updating the content-length header to account for that change?

[tomchristie]

Confirming @florimondmanca, yup. I've taken a crack at this in #310, tho not added a test case yet.

Also highlighted a coupla of things that look off to me right now.

[sethmlarson]

@florimondmanca Reasons why I shouldn't espond to issues at midnight haha :) thanks for setting this on the right track!