httpx randonly hangs on start_tls when using proxy

[alex-oleshkevich]

Checklist

• The bug is reproducible against the latest release and/or master.
• There are no similar issues or pull requests to fix it yet.

Describe the bug

I run a script that periodically parses a 3rd-party website. These requests are proxies.
The problem is that some times httpx may hang up completely.

To reproduce

There is no 100% way to reproduce it but here is a code that I run:

import httpx, asyncio

async for i in range(1, 120):
    async with httpx.AsyncClient(proxy={'all': 'http://someproxy.com') as client:
        await client.get('https://somesite.com')
    asyncio.sleep(2)

Note, all proxies a HTTP, not HTTPS.

Logs

DEBUG [2021-03-13 19:02:27] - [av.by] create HTTP client with this proxy: {'all': 'http://Qga8Jdsj:[email protected]:46314'}.
TRACE [2021-03-13 19:02:27] httpx._config - load_ssl_context verify=True cert=None trust_env=True http2=False
TRACE [2021-03-13 19:02:27] - load_ssl_context verify=True cert=None trust_env=True http2=False
TRACE [2021-03-13 19:02:27] httpx._config - load_verify_locations cafile=/home/alex/projects/autobot-parsers/.venv/lib/python3.9/site-packages/certifi/cacert.pem
TRACE [2021-03-13 19:02:27] - load_verify_locations cafile=/home/alex/projects/autobot-parsers/.venv/lib/python3.9/site-packages/certifi/cacert.pem
TRACE [2021-03-13 19:02:27] httpcore._async.http_proxy - tunnel_request proxy_origin=(b'http', b'45.136.68.4', 46314) proxy_headers=[(b'Proxy-Authorization', b'Basic UWdhOEpkc2o6U000000=')] method=b'POST' url=(b'https', b'autobot.by', None, b'/offer-types/cars/filters/main/apply')
TRACE [2021-03-13 19:02:27] - tunnel_request proxy_origin=(b'http', b'45.136.68.4', 46314) proxy_headers=[(b'Proxy-Authorization', b'Basic UWdhOEpkc2o6U000000=')] method=b'POST' url=(b'https', b'autobot.by', None, b'/offer-types/cars/filters/main/apply')
TRACE [2021-03-13 19:02:27] httpcore._async.connection - open_socket origin=(b'http', b'45.136.68.4', 46314) timeout={'connect': 10, 'read': 10, 'write': 10, 'pool': 10}
TRACE [2021-03-13 19:02:27] - open_socket origin=(b'http', b'45.136.68.4', 46314) timeout={'connect': 10, 'read': 10, 'write': 10, 'pool': 10}
TRACE [2021-03-13 19:02:34] httpcore._async.connection - create_connection socket=<httpcore._backends.asyncio.SocketStream object at 0x7f1438cf1370> http_version='HTTP/1.1'
TRACE [2021-03-13 19:02:34] - create_connection socket=<httpcore._backends.asyncio.SocketStream object at 0x7f1438cf1370> http_version='HTTP/1.1'
TRACE [2021-03-13 19:02:34] httpcore._async.connection - connection.arequest method=b'CONNECT' url=(b'http', b'45.136.68.4', 46314, b'autobot.by:443') headers=[(b'Host', b'autobot.by:443'), (b'Accept', b'*/*'), (b'Proxy-Authorization', b'Basic UWdhOEpkc2o6U000000=')]
TRACE [2021-03-13 19:02:34] - connection.arequest method=b'CONNECT' url=(b'http', b'45.136.68.4', 46314, b'autobot.by:443') headers=[(b'Host', b'autobot.by:443'), (b'Accept', b'*/*'), (b'Proxy-Authorization', b'Basic UWdhOEpkc2o6U000000=')]
TRACE [2021-03-13 19:02:34] httpcore._async.http11 - send_request method=b'CONNECT' url=(b'http', b'45.136.68.4', 46314, b'autobot.by:443') headers=[(b'Host', b'autobot.by:443'), (b'Accept', b'*/*'), (b'Proxy-Authorization', b'Basic UWdhOEpkc2o6U000000=')]
TRACE [2021-03-13 19:02:34] - send_request method=b'CONNECT' url=(b'http', b'45.136.68.4', 46314, b'autobot.by:443') headers=[(b'Host', b'autobot.by:443'), (b'Accept', b'*/*'), (b'Proxy-Authorization', b'Basic UWdhOEpkc2o6U000000=')]
TRACE [2021-03-13 19:02:34] httpcore._async.http11 - send_data=Data(<0 bytes>)
TRACE [2021-03-13 19:02:34] - send_data=Data(<0 bytes>)
TRACE [2021-03-13 19:02:35] httpcore._async.http_proxy - tunnel_response proxy_status_code=200 proxy_reason='OK' 
TRACE [2021-03-13 19:02:35] - tunnel_response proxy_status_code=200 proxy_reason='OK' 
TRACE [2021-03-13 19:02:35] httpcore._async.http11 - receive_event=PAUSED
TRACE [2021-03-13 19:02:35] - receive_event=PAUSED
TRACE [2021-03-13 19:02:35] httpcore._async.connection - start_tls hostname=b'autobot.by' timeout={'connect': 10, 'read': 10, 'write': 10, 'pool': 10}
TRACE [2021-03-13 19:02:35] - start_tls hostname=b'autobot.by' timeout={'connect': 10, 'read': 10, 'write': 10, 'pool': 10}

There is nothing logged after this line.

Environment

• OS: Arch Linux
• Python version: 3.9
• HTTPX version: 0.17
• Async environment: asyncio
• HTTP proxy: yes
• Custom certificates: no

Additional context

[alex-oleshkevich]

I switched to aiohttp.ClientSession and it has no this issue. Instead, it raises timeout exception.

[lovelydinosaur]

Thanks @SafeEval that's a very neat summary.

Have reproduced that on my end, and am having a look into it.

[lovelydinosaur]

In news that shouldn't come as a great surprise, the request does succeed with trio.

[lovelydinosaur]

Okay, so the anyio backend also succeeds correctly in this case.

(Although there's actually an error in AsyncHTTPProxy that means the backend argument isn't properly passed along to proxy connections at the moment, tho that's separate.)

My feeling based on reviewing the anyio TLSStream implementation, is that we're going to want to switch over to using anyio by default. And that it'll also allow us to support tls-in-tls, which may well(?) be fiddly directly in asyncio.

[stankosy]

Hello @tomchristie , just a quick check-in if we have made the switch to anyio already? We also seem to be experiencing this issue and looking how to solve it.
Thanks and best regards,
Stan

Okay, so the anyio backend also succeeds correctly in this case.

(Although there's actually an error in AsyncHTTPProxy that means the backend argument isn't properly passed along to proxy connections at the moment, tho that's separate.)

My feeling based on reviewing the anyio TLSStream implementation, is that we're going to want to switch over to using anyio by default. And that it'll also allow us to support tls-in-tls, which may well(?) be fiddly directly in asyncio.

[lovelydinosaur]

Yes, the any backend is the default now Worth double checking that both httpcore and httpx are fully upgraded to the latest versions I guess.