requests logging is not documented, incomplete and works unexpectedly

[ssbarnea]

Currently logging in requests library is not properly documented.

The API Changes section of the documentation reminds about the removal of the config parameter but contains no code. See http://docs.python-requests.org/en/latest/api/?highlight=logging

import requests
import logging

# these two lines enable debugging at httplib level (requests->urllib3->httplib)
# you will see the REQUEST, including HEADERS and DATA, and RESPONSE with HEADERS but without DATA.
# the only thing missing will be the response.body which is not logged.
import httplib
httplib.HTTPConnection.debuglevel = 1

logging.basicConfig() # you need to initialize logging, otherwise you will not see anything from requests
logging.getLogger().setLevel(logging.DEBUG)
requests_log = logging.getLogger("requests")
requests_log.setLevel(logging.DEBUG)
requests_log.propagate = True

requests.get('http://httpbin.org/headers')

So this means there are a few things to do:
#1 add the above piece of code to the documentation (including the API changes section)
#2 provide proper response on few stackoverflow questions related to requests logging
#3 find a way to allow extensive logging (logging BODY too)

[sigmavirus24]

requests does no logging of its own. All logging actually done is done by urllib3 and can be set up similar to your example:

import requests
import logging

logging.getLogger().setLevel(logging.DEBUG)
requests_log = logging.getLogger("requests.packages.urllib3")
requests_log.setLevel(logging.DEBUG)
requests_log.propagate = True

Even if we did do logging, we would not log the data sent in a post. You can, however, do the following:

response = requests.get(url)
logging.debug("Response: Status code: %d", response.status_code)
logging.debug("Request: %s %s %s", response.request.method, response.request.url, response.request.body)

I'm only leaving this ticket open as a reminder for myself during the documentation refresh I have planned.

[ssbarnea]

Have you tried to run the first piece of code? I will not log anything unless you call logging.debug("...") first. I tried with requests 1.2.0 and it will not log anything until you log something.

[sigmavirus24]

No I didn't run it because I know for a fact that requests proper does no logging of its own. All logging is done by urllib3 and I strongly suspect that the logging module is only working because urllib3 is technically part of the requests namespace. I'm also writing all of this from a phone so I can't exactly run anything at the moment.

[ssbarnea]

Thanks Ian,
I do think that having a way to log what requests is sending and receiving would be extremely useful and should be part of requests itself.
Why? For example I am trying to debug python-jira package and if I want to see what is sent/received, the only way would be use Wireshark, because it would be a mess to apply your model after all calls made to requests (there are plenty!).
We could even use a custom logging level, one that would be lower than logging.DEBUG, so it would not change the current behavior unless you choose to switch to the more verbose mode.
I could implement this, but first I do want to find out that you do not have anything against this, I don't want to end-up using my custom requests library, and patch it after each requests release.

[Lukasa]

Adding extra detail was proposed in #988. Here, as there, any extra logging belongs in urllib3 and should be added there. This is being discussed at urllib3/urllib3#107.

[sigmavirus24]

Requests had logging before 1.0 and it was torn out during the refactor. Take from that what you will. I'm entirely indifferent on the proposal. It's up to @kennethreitz no matter what.

[jvtm]

AFAIK, the behavior in the example is because of python logging module itself.

If "root logger" is not initialized, nothing will be outputted. Calling logging.debug() (or .info or any other) initializes it with default settings. I think this is the same thing as calling logging.basicConfig() first.

My guess is that the same thing happens with any python library that uses logging.

If you want output (to console. file, whatever), then you need to initialize the logging to do so.

[ssbarnea]

@jvtm Thanks! Now I can update the sample code and so we can include it in the documentation.

[sigmavirus24]

@ssbarnea's pull request was merged closing this issue.

[Justsoos]

yeah, as @jvtm said, only initialize the "root logging" could set the log active for import module, and logging module can not match "requests.packages.urllib3", but "urllib3", like:

import requests
import logging

logger = logging.getLogger("urllib3")
logger.setLevel(level=logging.DEBUG)
logging.debug("")

working on python 3.6