Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Write Error on reusing potentially closed connection #44

Closed
victoraugustolls opened this issue Mar 11, 2020 · 25 comments
Closed

Write Error on reusing potentially closed connection #44

victoraugustolls opened this issue Mar 11, 2020 · 25 comments
Labels
bug Something isn't working

Comments

@victoraugustolls
Copy link
Contributor

victoraugustolls commented Mar 11, 2020

With a service deployed with httpx version with httpcore interface, I started receiving the following error:

<class 'httpcore._exceptions.WriteError'>: [Errno 104] Connection reset by peer

The only problem is that this is when connecting to a service that others applications have no problems. The connection is (should be) HTTP/1.1 in this case.

@tomchristie
Copy link
Member

I'm going to close this one off given the ancedotal encode/httpx#841 (comment) "I just tested the original gist against httpx==0.13.0.dev2 and got the same result for http1.1 and http2."

If there's something reproducible here or any anecdotal reports of similar connection closing then we can reopen it, but given that it's just "the server closed the connection" there's not a lot here for us to act on.

@victoraugustolls
Copy link
Contributor Author

I have a service that after upgrading httpx to 0.13 started receiving the same error, and rolling back to 0.12 seems to resolve the issue.

@victoraugustolls
Copy link
Contributor Author

I don't know what details I can give here, other that:

  • The problems seems to happen when the connections is not used for some minutes.
  • My service runs under fast api.
  • The only upgraded dependency was httpx.

@victoraugustolls
Copy link
Contributor Author

victoraugustolls commented May 27, 2020

Stack trace:

File "/usr/local/lib/python3.8/site-packages/httpx/_client.py", line 1364, in post
    return await self.request(
  File "/usr/local/lib/python3.8/site-packages/httpx/_client.py", line 1137, in request
    response = await self.send(
  File "/usr/local/lib/python3.8/site-packages/httpx/_client.py", line 1158, in send
    response = await self.send_handling_redirects(
  File "/usr/local/lib/python3.8/site-packages/httpx/_client.py", line 1185, in send_handling_redirects
    response = await self.send_handling_auth(
  File "/usr/local/lib/python3.8/site-packages/httpx/_client.py", line 1222, in send_handling_auth
    response = await self.send_single_request(request, timeout)
  File "/usr/local/lib/python3.8/site-packages/httpx/_client.py", line 1254, in send_single_request
    ) = await transport.request(
  File "/usr/local/lib/python3.8/site-packages/httpcore/_async/connection_pool.py", line 152, in request
    response = await connection.request(
  File "/usr/local/lib/python3.8/site-packages/httpcore/_async/connection.py", line 78, in request
    return await self.connection.request(method, url, headers, stream, timeout)
  File "/usr/local/lib/python3.8/site-packages/httpcore/_async/http11.py", line 55, in request
    await self._send_request(method, url, headers, timeout)
  File "/usr/local/lib/python3.8/site-packages/httpcore/_async/http11.py", line 82, in _send_request
    await self._send_event(event, timeout)
  File "/usr/local/lib/python3.8/site-packages/httpcore/_async/http11.py", line 106, in _send_event
    await self.socket.write(bytes_to_send, timeout)
  File "/usr/local/lib/python3.8/site-packages/httpcore/_backends/asyncio.py", line 146, in write
    return await asyncio.wait_for(
  File "/usr/local/lib/python3.8/contextlib.py", line 131, in __exit__
    self.gen.throw(type, value, traceback)
  File "/usr/local/lib/python3.8/site-packages/httpcore/_exceptions.py", line 12, in map_exceptions
    raise to_exc(exc) from None
httpcore._exceptions.WriteError: [Errno 104] Connection reset by peer

@victoraugustolls
Copy link
Contributor Author

TRACE:

TRACE:    get_connection_from_pool=(b'https', b'[MY URL]', 443)
TRACE [2020-05-27 23:46:28] httpcore._async.connection_pool - reuse connection=<httpcore._async.connection.AsyncHTTPConnection object at 0x7f5c1fe441c0>
TRACE:    reuse connection=<httpcore._async.connection.AsyncHTTPConnection object at 0x7f5c1fe441c0>
TRACE [2020-05-27 23:46:28] httpcore._async.connection - connection.request method=b'POST' url=(b'https', b'[MY URL]', 443, b'[PATH]') headers=[(b'host', b'[MY URL]'), (b'user-agent', b'python-httpx/0.13.2'), (b'accept', b'*/*'), (b'accept-encoding', b'gzip, deflate'), (b'connection', b'keep-alive'), (b'content-type', b'application/json'), (b'traceparent', b'[VALUE]'), (b'cookie', b'[VALUE]; x-ms-routing-name=self'), (b'content-length', b'389')]
TRACE:    connection.request method=b'POST' url=(b'https', b'[MY URL]', 443, b'[MY PATH]') headers=[(b'host', b'[MY URL]'), (b'user-agent', b'python-httpx/0.13.2'), (b'accept', b'*/*'), (b'accept-encoding', b'gzip, deflate'), (b'connection', b'keep-alive'), (b'content-type', b'application/json'), (b'traceparent', b'[VALUE]'), (b'cookie', b'[VALUE]; x-ms-routing-name=self'), (b'content-length', b'389')]
TRACE [2020-05-27 23:46:28] httpcore._async.http11 - send_request method=b'POST' url=(b'https', b'[MY URL]', 443, b'[MY PATH]') headers=[(b'host', b'[MY URL]'), (b'user-agent', b'python-httpx/0.13.2'), (b'accept', b'*/*'), (b'accept-encoding', b'gzip, deflate'), (b'connection', b'keep-alive'), (b'content-type', b'application/json'), (b'traceparent', b'[VALUE]'), (b'cookie', b'[VALUE]; x-ms-routing-name=self'), (b'content-length', b'389')]
TRACE:    send_request method=b'POST' url=(b'https', b'[MY URL]', 443, b'[MY PATH]') headers=[(b'host', b'[MY URL]'), (b'user-agent', b'python-httpx/0.13.2'), (b'accept', b'*/*'), (b'accept-encoding', b'gzip, deflate'), (b'connection', b'keep-alive'), (b'content-type', b'application/json'), (b'traceparent', b'[VALUE]'), (b'cookie', b'[VALUE]; x-ms-routing-name=self'), (b'content-length', b'389')]
TRACE [2020-05-27 23:46:28] httpcore._async.connection_pool - remove from pool connection=<httpcore._async.connection.AsyncHTTPConnection object at 0x7f5c1fe441c0>
TRACE:    remove from pool connection=<httpcore._async.connection.AsyncHTTPConnection object at 0x7f5c1fe441c0>

@victoraugustolls
Copy link
Contributor Author

What it seems: after a while, the connection closes, but httpcore does not now that, attempts to write the request and throws an error.

Does httpx 0.12 reuses http 1.1 connections? I'm seeing in the trace that it is always using a new connection in http 1.1, as 0.13.2 reuses a connection, which can be the cause.

@yeraydiazdiaz
Copy link
Contributor

Hey @victoraugustolls, thanks for the detailed report. Reopening and temptatively renaming this issue.

@yeraydiazdiaz yeraydiazdiaz reopened this May 28, 2020
@yeraydiazdiaz yeraydiazdiaz changed the title Write Error Write Error on reusing potentially closed connection May 28, 2020
@tomchristie
Copy link
Member

Thanks for the info - Is there a minimal reproducible example we can use to dig into this?
Is it failing against any particular host, or can you reproduce more generally?

@tomchristie tomchristie added the bug Something isn't working label May 28, 2020
@yeraydiazdiaz
Copy link
Contributor

Does httpx 0.12 reuses http 1.1 connections? I'm seeing in the trace that it is always using a new connection in http 1.1, as 0.13.2 reuses a connection, which can be the cause.

httpcore does reuse HTTP/1.1 connections if a previous request has been closed (the connection's state is IDLE at that point). In your trace I can see a reuse_connection entry, which suggests it an idle connection was found and it tried to reuse it.

What it seems: after a while, the connection closes, but httpcore does not now that, attempts to write the request and throws an error.

There's a specific check in the connection pool for closed connections, I remember @florimondmanca working on the asyncio version and discussing it with core developers so I'd be surprised if that's not working as expected but of course you never know.

It'd be also interesting to know how many concurrent requests are you attempting when the error occurs.

We could also do with more trace logging on the _get_connection_from_pool to help us debug these situations.

@victoraugustolls
Copy link
Contributor Author

Is it failing against any particular host, or can you reproduce more generally?

In my case was a specific host because it was my only test. I will try to update my minimal case repo to reflex this issue!

It'd be also interesting to know how many concurrent requests are you attempting when the error occurs.

Only 1, local server with 1 request at a time using Postman. My tests were 1 request everything works. 5 minutes later I do another request and it fails when reusing the connection.

@tomchristie
Copy link
Member

Okay needs looking into then. The connection ought to have been expired, as we have a keep-alive timeout, and close connections once they pass that mark.

@victoraugustolls
Copy link
Contributor Author

Could the host in question be closing the connection before the returned keep alive duration, causing this issue?

@victoraugustolls
Copy link
Contributor Author

victoraugustolls commented May 28, 2020

Could the host in question be closing the connection before the returned keep alive duration, causing this issue?

I ask this because the host is a FastAPI server, running with uvicorn worker o gunicorn, with keep alive settings = 120. After exactly 121 seconds I receive the described error.

I changed the setting to 240 and I still receive the error after 121 seconds.

Response headers:

Headers({'content-length': '238', 'content-type': 'application/json', 'server': 'uvicorn', 'date': 'Thu, 28 May 2020 19:19:28 GMT'})

@victoraugustolls
Copy link
Contributor Author

So, on 0.13 if I force http/2.0 enabling it on the host, I have the same error after 121s.

The trace:

TRACE [2020-05-28 20:20:02] httpcore._async.connection_pool - get_connection_from_pool=(b'https', b'[MY URL]', 443)
TRACE [2020-05-28 20:20:02] httpcore._async.connection_pool - reuse connection=<httpcore._async.connection.AsyncHTTPConnection object at 0x7f3bcc0f2d60>
TRACE [2020-05-28 20:20:02] httpcore._async.connection - connection.request method=b'POST' url=(b'https', b'[MY URL]', 443, b'[MY PATH]') headers=[(b'host', b'[MY URL]'), (b'user-agent', b'python-httpx/0.13.2'), (b'accept', b'*/*'), (b'accept-encoding', b'gzip, deflate'), (b'connection', b'keep-alive'), (b'content-type', b'application/json'), (b'traceparent', b'[HIDDEN]'), (b'content-length', b'326')]
TRACE [2020-05-28 20:20:02] httpcore._async.http2 - send_headers stream_id=7 headers=[(b':method', b'POST'), (b':authority', b'[MY URL]'), (b':scheme', b'https'), (b':path', b'[MY PATH]'), (b'user-agent', b'python-httpx/0.13.2'), (b'accept', b'*/*'), (b'accept-encoding', b'gzip, deflate'), (b'connection', b'keep-alive'), (b'content-type', b'application/json'), (b'traceparent', b'[HIDDEN]'), (b'content-length', b'326')]
TRACE [2020-05-28 20:20:02] httpcore._async.connection_pool - remove from pool connection=<httpcore._async.connection.AsyncHTTPConnection object at 0x7f3bcc0f2d60>
Error: [Errno 104] Connection reset by peer

Traceback:

  File "/usr/local/lib/python3.8/site-packages/httpx/_client.py", line 1364, in post
    return await self.request(
  File "/usr/local/lib/python3.8/site-packages/httpx/_client.py", line 1137, in request
    response = await self.send(
  File "/usr/local/lib/python3.8/site-packages/httpx/_client.py", line 1158, in send
    response = await self.send_handling_redirects(
  File "/usr/local/lib/python3.8/site-packages/httpx/_client.py", line 1185, in send_handling_redirects
    response = await self.send_handling_auth(
  File "/usr/local/lib/python3.8/site-packages/httpx/_client.py", line 1222, in send_handling_auth
    response = await self.send_single_request(request, timeout)
  File "/usr/local/lib/python3.8/site-packages/httpx/_client.py", line 1254, in send_single_request
    ) = await transport.request(
  File "/usr/local/lib/python3.8/site-packages/httpcore/_async/connection_pool.py", line 152, in request
    response = await connection.request(
  File "/usr/local/lib/python3.8/site-packages/httpcore/_async/connection.py", line 78, in request
    return await self.connection.request(method, url, headers, stream, timeout)
  File "/usr/local/lib/python3.8/site-packages/httpcore/_async/http2.py", line 118, in request
    return await h2_stream.request(method, url, headers, stream, timeout)
  File "/usr/local/lib/python3.8/site-packages/httpcore/_async/http2.py", line 287, in request
    await self.send_headers(method, url, headers, has_body, timeout)
  File "/usr/local/lib/python3.8/site-packages/httpcore/_async/http2.py", line 323, in send_headers
    await self.connection.send_headers(self.stream_id, headers, end_stream, timeout)
  File "/usr/local/lib/python3.8/site-packages/httpcore/_async/http2.py", line 226, in send_headers
    await self.socket.write(data_to_send, timeout)
  File "/usr/local/lib/python3.8/site-packages/httpcore/_backends/asyncio.py", line 146, in write
    return await asyncio.wait_for(
  File "/usr/local/lib/python3.8/contextlib.py", line 131, in __exit__
    self.gen.throw(type, value, traceback)
  File "/usr/local/lib/python3.8/site-packages/httpcore/_exceptions.py", line 12, in map_exceptions
    raise to_exc(exc) from None
httpcore._exceptions.WriteError: [Errno 104] Connection reset by peer

@victoraugustolls
Copy link
Contributor Author

Trace on httpx=0.12:

TRACE [2020-05-28 20:31:25] httpx._dispatch.connection - close_connection
TRACE [2020-05-28 20:31:25] httpx._dispatch.connection_pool - acquire_connection origin=Origin(scheme='https' host='[MY_URL]' port=443)
TRACE [2020-05-28 20:31:25] httpx._dispatch.connection_pool - new_connection connection=HTTPConnection(origin=Origin(scheme='https' host='[MY_URL]' port=443))
TRACE [2020-05-28 20:31:25] httpx._dispatch.connection - start_connect tcp host='[MY_URL]' port=443 timeout=Timeout(timeout=20.0)
TRACE [2020-05-28 20:31:26] httpx._dispatch.connection - connected http_version='HTTP/2'
TRACE [2020-05-28 20:31:26] httpx._dispatch.http2 - send_headers stream_id=1 method='POST' target='[MY PATH]' headers=[(b':method', b'POST'), (b':authority', b'[MY_URL]'), (b':scheme', b'https'), (b':path', b'[MY PATH]'), (b'user-agent', b'python-httpx/0.12.0'), (b'accept', b'*/*'), (b'accept-encoding', b'gzip, deflate'), (b'connection', b'keep-alive'), (b'content-type', b'application/json'), (b'traceparent', b'[HIDDEN]'), (b'content-length', b'326')]
TRACE [2020-05-28 20:31:26] httpx._dispatch.http2 - send_body stream_id=1
TRACE [2020-05-28 20:31:26] httpx._dispatch.http2 - receive_event stream_id=0 event=<RemoteSettingsChanged changed_settings:{ChangedSetting(setting=SettingCodes.MAX_CONCURRENT_STREAMS, original_value=None, new_value=100), ChangedSetting(setting=16, original_value=None, new_value=2), ChangedSetting(setting=SettingCodes.INITIAL_WINDOW_SIZE, original_value=65535, new_value=1048576)}>
TRACE [2020-05-28 20:31:26] httpx._dispatch.http2 - receive_event stream_id=0 event=<WindowUpdated stream_id:0, delta:983041>
TRACE [2020-05-28 20:31:27] httpx._dispatch.http2 - receive_event stream_id=0 event=<SettingsAcknowledged changed_settings:{}>
TRACE [2020-05-28 20:31:27] httpx._dispatch.http2 - receive_event stream_id=1 event=<WindowUpdated stream_id:1, delta:326>
TRACE [2020-05-28 20:31:27] httpx._dispatch.http2 - receive_event stream_id=0 event=<WindowUpdated stream_id:0, delta:326>
TRACE [2020-05-28 20:31:27] httpx._dispatch.http2 - receive_event stream_id=1 event=<ResponseReceived stream_id:1, headers:[(b':status', b'200'), (b'content-length', b'238'), (b'content-type', b'application/json'), (b'server', b'uvicorn'), (b'date', b'Thu, 28 May 2020 20:31:31 GMT')]>
TRACE [2020-05-28 20:31:27] httpx._dispatch.http2 - receive_event stream_id=1 event=<DataReceived stream_id:1, flow_controlled_length:238, data:7b226964223a22303035314c3030303030375979>
TRACE [2020-05-28 20:31:27] httpx._dispatch.http2 - receive_event stream_id=1 event=<DataReceived stream_id:1, flow_controlled_length:0, data:>
TRACE [2020-05-28 20:31:27] httpx._dispatch.http2 - receive_event stream_id=1 event=<StreamEnded stream_id:1>
DEBUG [2020-05-28 20:31:27] httpx._client - HTTP Request: POST https://[MY_URL][MY PATH] "HTTP/2 200 OK"
TRACE [2020-05-28 20:31:27] httpx._dispatch.connection_pool - release_connection connection=HTTPConnection(origin=Origin(scheme='https' host='[MY_URL]' port=443))

Wonder why does it start with closing the connection.

@yeraydiazdiaz
Copy link
Contributor

The connection ought to have been expired, as we have a keep-alive timeout, and close connections once they pass that mark.

If you're talking about keepalive_expiry, httpx does not pass it to httpcore, though it probably should.

The default behaviour is to check if the connection has been dropped on the next request and create a new one if so, which seems to works fine on my tests.

On my Mac, using the example HTTP/1.1 Uvicorn app with TLS, a keepalive timeout of 5 seconds, the enhanced trace logs in #101 and this simple script:

import asyncio

import httpx


async def main() -> None:
    async with httpx.AsyncClient(verify=False) as client:
        await request(client)
        await asyncio.sleep(60)
        await request(client)


async def request(client: httpx.AsyncClient, url: str = None) -> None:
    url = url or "https://localhost:8000"
    response = await client.get(url)

    print("==== Response data: ====\n")
    print(response.http_version)
    print(response.status_code)
    print(response.headers)
    print("\n==== Response body: ====\n")
    print(response.text[:100], "...\n\n")


if __name__ == "__main__":
    asyncio.run(main())

No exceptions are raised and I get the following output:

✗ HTTPCORE_LOG_LEVEL=TRACE python write_timeout_keepalive.py
TRACE [2020-05-29 09:37:32] httpcore._async.connection_pool - get_connection_from_pool=(b'https', b'localhost', 8000)
TRACE [2020-05-29 09:37:32] httpcore._async.connection_pool - created connection=<httpcore._async.connection.AsyncHTTPConnection object at 0x10e027970>
TRACE [2020-05-29 09:37:32] httpcore._async.connection_pool - adding connection to pool=<httpcore._async.connection.AsyncHTTPConnection object at 0x10e027970>
TRACE [2020-05-29 09:37:32] httpcore._async.connection - open_socket origin=(b'https', b'localhost', 8000) timeout={'connect': 5.0, 'read': 5.0, 'write': 5.0, 'pool': 5.0}
TRACE [2020-05-29 09:37:32] httpcore._async.connection - create_connection socket=<httpcore._backends.asyncio.SocketStream object at 0x10e027c40> http_version='HTTP/1.1'
TRACE [2020-05-29 09:37:32] httpcore._async.connection - connection.request method=b'GET' url=(b'https', b'localhost', 8000, b'/') headers=[(b'host', b'localhost:8000'), (b'user-agent', b'python-httpx/0.13.2'), (b'accept', b'*/*'), (b'accept-encoding', b'gzip, deflate, br'), (b'connection', b'keep-alive')]
TRACE [2020-05-29 09:37:32] httpcore._async.http11 - send_request method=b'GET' url=(b'https', b'localhost', 8000, b'/') headers=[(b'host', b'localhost:8000'), (b'user-agent', b'python-httpx/0.13.2'), (b'accept', b'*/*'), (b'accept-encoding', b'gzip, deflate, br'), (b'connection', b'keep-alive')]
TRACE [2020-05-29 09:37:32] httpcore._async.http11 - send_data=Data(<0 bytes>)
TRACE [2020-05-29 09:37:32] httpcore._async.http11 - receive_event=Data(<13 bytes>)
TRACE [2020-05-29 09:37:32] httpcore._async.http11 - receive_event=EndOfMessage(headers=[])
TRACE [2020-05-29 09:37:32] httpcore._async.http11 - response_closed our_state=DONE their_state=DONE
==== Response data: ====

HTTP/1.1
200
Headers({'date': 'Fri, 29 May 2020 08:37:32 GMT', 'server': 'uvicorn', 'content-type': 'text/plain', 'transfer-encoding': 'chunked'})

==== Response body: ====

Hello, world! ...


TRACE [2020-05-29 09:38:32] httpcore._async.connection_pool - get_connection_from_pool=(b'https', b'localhost', 8000)
TRACE [2020-05-29 09:38:32] httpcore._async.connection_pool - removing dropped idle connection=<httpcore._async.connection.AsyncHTTPConnection object at 0x10e027970>
TRACE [2020-05-29 09:38:32] httpcore._async.connection_pool - removing connection from pool=<httpcore._async.connection.AsyncHTTPConnection object at 0x10e027970>
TRACE [2020-05-29 09:38:32] httpcore._async.connection_pool - created connection=<httpcore._async.connection.AsyncHTTPConnection object at 0x10df84490>
TRACE [2020-05-29 09:38:32] httpcore._async.connection_pool - adding connection to pool=<httpcore._async.connection.AsyncHTTPConnection object at 0x10df84490>
TRACE [2020-05-29 09:38:32] httpcore._async.connection - open_socket origin=(b'https', b'localhost', 8000) timeout={'connect': 5.0, 'read': 5.0, 'write': 5.0, 'pool': 5.0}
TRACE [2020-05-29 09:38:32] httpcore._async.connection - create_connection socket=<httpcore._backends.asyncio.SocketStream object at 0x10e03f7c0> http_version='HTTP/1.1'
TRACE [2020-05-29 09:38:32] httpcore._async.connection - connection.request method=b'GET' url=(b'https', b'localhost', 8000, b'/') headers=[(b'host', b'localhost:8000'), (b'user-agent', b'python-httpx/0.13.2'), (b'accept', b'*/*'), (b'accept-encoding', b'gzip, deflate, br'), (b'connection', b'keep-alive')]
TRACE [2020-05-29 09:38:32] httpcore._async.http11 - send_request method=b'GET' url=(b'https', b'localhost', 8000, b'/') headers=[(b'host', b'localhost:8000'), (b'user-agent', b'python-httpx/0.13.2'), (b'accept', b'*/*'), (b'accept-encoding', b'gzip, deflate, br'), (b'connection', b'keep-alive')]
TRACE [2020-05-29 09:38:32] httpcore._async.http11 - send_data=Data(<0 bytes>)
TRACE [2020-05-29 09:38:32] httpcore._async.http11 - receive_event=Data(<13 bytes>)
TRACE [2020-05-29 09:38:32] httpcore._async.http11 - receive_event=EndOfMessage(headers=[])
TRACE [2020-05-29 09:38:32] httpcore._async.http11 - response_closed our_state=DONE their_state=DONE
==== Response data: ====

HTTP/1.1
200
Headers({'date': 'Fri, 29 May 2020 08:38:31 GMT', 'server': 'uvicorn', 'content-type': 'text/plain', 'transfer-encoding': 'chunked'})

==== Response body: ====

Hello, world! ...


TRACE [2020-05-29 09:38:32] httpcore._async.connection_pool - removing connection from pool=<httpcore._async.connection.AsyncHTTPConnection object at 0x10df84490>

Note how the connection is not closed after reading the body and when the next request is sent we see:

TRACE [2020-05-29 09:38:32] httpcore._async.connection_pool - removing dropped idle connection=<httpcore._async.connection.AsyncHTTPConnection object at 0x10e027970>

Proving it detected the connection being closed and proceeded to create a new one.

I guess it's possible our detection of dropped connections fails on your architecture, can you detail what you are using?

@tomchristie
Copy link
Member

Oh right sure...

asyncio's dropped connection is less robust than the standard sync case, so we introduced a fairly short keep-alive period on the httpx side, which in practise means that it's not an issue since we'll expire the connections anyways... https://github.com/encode/httpx/blob/0.12.1/httpx/_dispatch/connection_pool.py#L89

However, when we switched over to httpcore in 0.13, we switched httpcore itself to default the keepalive value to None

keepalive_expiry: float = None,
and then failed to make sure we were passing keepalive_expiry=5.0 when instantiating the connection pool / proxy classes from httpx... https://github.com/encode/httpx/blob/093cb4250006dc0b73af986f7e6537b8c4395dcf/httpx/_client.py#L516

This right thing for use to do first is switch those init_transport/init_proxy_transport methods to include a fixed keepalive_expiry=5.0 value, and then issue a minor point release of httpx.

However it'd also be really helpful to have another dig into the "is the connection still alive" detection, and see if there's anything we can do to improve the robustness there. What'd be helpful for that would be having a minimal reproducible example, so...

  1. Can you reproduce the behaviour, just using uvicorn, with a basic hello world app?...
async def app(scope, receive, send):
    assert scope['type'] == 'http'

    await send({
        'type': 'http.response.start',
        'status': 200,
        'headers': [
            [b'content-type', b'text/plain'],
        ],
    })
    await send({
        'type': 'http.response.body',
        'body': b'Hello, world!',
    })
$ venv/bin/uvicorn example:app

If not, then what extra config, or setup do you need to introduce before being able to reproduce?

  1. On the client side, is this sufficient to reproduce the behaviour, or do you need to do anything else?...
import asyncio
import httpx


async def main():
    async with httpx.AsyncClient() as client:
        r = await client.get('http://127.0.0.1:8000/')
        print(r.status_code)
        print(r.text)

        await asyncio.sleep(10)

        r = await client.get('http://127.0.0.1:8000/')
        print(r.status_code)
        print(r.text)


asyncio.run(main())
  1. Can you reproduce when using the sync client? When using the trio client?

  2. Which platform are you running on?

@tomchristie
Copy link
Member

Resolved in httpx 0.13.3, but leaving this open ATM, as it would still be good to dig into making our “connection is still open” is as robust as possible.

@victoraugustolls
Copy link
Contributor Author

victoraugustolls commented May 29, 2020

I guess it's possible our detection of dropped connections fails on your architecture, can you detail what you are using?

My architecture is the host is a FastAPI service running behind gunicorn 20.0.4 inside a docker container in Azure App Service. The client follows the same architecture.

@victoraugustolls
Copy link
Contributor Author

@tomchristie I will check your comments during the weekend and come with detailed comments after, if that's ok. I will also apply #101 locally into httpx=0.13.2 to help with the trace.

@victoraugustolls
Copy link
Contributor Author

2. On the client side, is this sufficient to reproduce the behaviour, or do you need to do anything else?...

This snippet is enough to replicate, using sleep of 130 seconds.

3. Can you reproduce when using the sync client? When using the trio client?

No, only asyncio version of the snippet. I tried the 3 versions 5 times. Running against the server while running it in Azure App Service and running locally. Locally I do not have this error, but it is an http app while on Azure it is https, which can be part of the cause.

4. Which platform are you running on?

Locally Arch Linux (running code inside docker). Remotely Azure App Service.

@victoraugustolls
Copy link
Contributor Author

victoraugustolls commented May 29, 2020

Locally I do not have this error, but it is an http app while on Azure it is https, which can be part of the cause

Ok, so running against https locally and http remotely still gives an error with the api running on Azure. So I guess the option here is to deploy a mock service on azure so I can send the url here? (verify=False gives same result, error while running against Azure)

@yeraydiazdiaz
Copy link
Contributor

I'm a bit confused here, let's see if we can summarize the situation:

  • Your service is running on Azure as a docker container using FastAPI with gunicorn.
  • You have docker container that runs httpx making requests to this service.
  • This client docker container fails consistently regardless of it being ran in Azure or on your local machine.

Is that correct? Could you share details on the client Docker image?

@tomchristie
Copy link
Member

Closing as stale.

@victoraugustolls
Copy link
Contributor Author

@tomchristie @yeraydiazdiaz I have missed the notification about you comments, I'm deeply sorry.

After encode/httpx#1005 the error stopped happening! So closing this is fine 😄

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

3 participants