_send_single_request logs sensitive data / leaks credentials

[Netherwhal]

Logs should not leak sensitive credentials/data - especially not in with log-level info.

Unfortunately httpx will log the full URL of the HTTP request, including username and password.

[tomchristie]

Hi @Netherwhal thanks for raising this, I've bumped it into a discussion as per our contribution guidelines.

Here's an example of what you've raised...

import logging
import httpx

logging.basicConfig(
    format="%(levelname)s [%(asctime)s] %(name)s - %(message)s",
    datefmt="%Y-%m-%d %H:%M:%S",
    level=logging.DEBUG
)

httpx.get("https://username:password@www.example.com")

Which will log this output...

$ venv/bin/python example.py 
DEBUG [2023-07-10 09:19:35] httpx - load_ssl_context verify=True cert=None trust_env=True http2=False
DEBUG [2023-07-10 09:19:35] httpx - load_verify_locations cafile='/Users/tomchristie/Temp/venv/lib/python3.10/site-packages/certifi/cacert.pem'
DEBUG [2023-07-10 09:19:35] httpcore.connection - connect_tcp.started host='www.example.com' port=443 local_address=None timeout=5.0 socket_options=None
DEBUG [2023-07-10 09:19:35] httpcore.connection - connect_tcp.complete return_value=<httpcore._backends.sync.SyncStream object at 0x1062fab00>
DEBUG [2023-07-10 09:19:35] httpcore.connection - start_tls.started ssl_context=<ssl.SSLContext object at 0x105456440> server_hostname='www.example.com' timeout=5.0
DEBUG [2023-07-10 09:19:36] httpcore.connection - start_tls.complete return_value=<httpcore._backends.sync.SyncStream object at 0x1062faad0>
DEBUG [2023-07-10 09:19:36] httpcore.http11 - send_request_headers.started request=<Request [b'GET']>
DEBUG [2023-07-10 09:19:36] httpcore.http11 - send_request_headers.complete
DEBUG [2023-07-10 09:19:36] httpcore.http11 - send_request_body.started request=<Request [b'GET']>
DEBUG [2023-07-10 09:19:36] httpcore.http11 - send_request_body.complete
DEBUG [2023-07-10 09:19:36] httpcore.http11 - receive_response_headers.started request=<Request [b'GET']>
DEBUG [2023-07-10 09:19:36] httpcore.http11 - receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', [(b'Content-Encoding', b'gzip'), (b'Accept-Ranges', b'bytes'), (b'Age', b'560682'), (b'Cache-Control', b'max-age=604800'), (b'Content-Type', b'text/html; charset=UTF-8'), (b'Date', b'Mon, 10 Jul 2023 08:19:36 GMT'), (b'Etag', b'"3147526947"'), (b'Expires', b'Mon, 17 Jul 2023 08:19:36 GMT'), (b'Last-Modified', b'Thu, 17 Oct 2019 07:18:26 GMT'), (b'Server', b'ECS (nyb/1D07)'), (b'Vary', b'Accept-Encoding'), (b'X-Cache', b'HIT'), (b'Content-Length', b'648')])
INFO [2023-07-10 09:19:36] httpx - HTTP Request: GET https://username:password@www.example.com "HTTP/1.1 200 OK"
DEBUG [2023-07-10 09:19:36] httpcore.http11 - receive_response_body.started request=<Request [b'GET']>
DEBUG [2023-07-10 09:19:36] httpcore.http11 - receive_response_body.complete
DEBUG [2023-07-10 09:19:36] httpcore.http11 - response_closed.started
DEBUG [2023-07-10 09:19:36] httpcore.http11 - response_closed.complete
DEBUG [2023-07-10 09:19:36] httpcore.connection - close.started
DEBUG [2023-07-10 09:19:36] httpcore.connection - close.complete

There's two different places where we might want a behaviour change here. The first is, as you've mentioned, at the INFO level.
In this case if you've got a URL with a basic-auth username and password included directly in the URL, then it'll be logged as-is.

Should we change that? Clearly, yes...

The simplest question first is what do we expect the output there to look like?...

Different options here are...

INFO [2023-07-10 09:19:36] httpx - HTTP Request: GET https://username:password@www.example.com "HTTP/1.1 200 OK"

INFO [2023-07-10 09:19:36] httpx - HTTP Request: GET https://username:[secure]@www.example.com "HTTP/1.1 200 OK"

INFO [2023-07-10 09:19:36] httpx - HTTP Request: GET https://www.example.com "HTTP/1.1 200 OK"

(My preference is probably for the last one of these, since the basic authentication is actually handled as request header)

There's also an open question around how we want to handle logging of the request/response body and headers, but I'd suggest we pause on that until we've first addressed the priority here.

[Saluev]

I believe there should be a way to specify sensitive fragments of the URL externally, for it is not only users and passwords which should not be leaked. For example, Telegram API uses URLs like https://api.telegram.org/bot{PRIVATE_TOKEN}/getUpdates and leaking bot token is also very undesirable.

[evamaxfield]

Maybe generalizing this discussion a bit, but I just encountered a lot of logging that was entirely unexpected at the log.info level.

I am doing a large-ish data processing job making requests to an API (using a wrapper library in Python, the wrapper doesn't really matter but for specifics it is the semanticscholar package). I am use tqdm's thread_map function to get a progress bar + thread these requests. The logging produced from this logger.info statement alone makes it somewhat annoying to track progress over thousands of requests to the API.

I know I can filter out specific packages from python's logger and I will do that for now but I think changing the logger.info statements to debug (or parameterizable) would be good.

All that aside, thanks for making this package! This logging is a minor annoyance (and I can work around) and I appreciate all the work that you have put into building and maintaining this project.