Estoy usando Python Requests . Necesito depurar alguna OAuthactividad, y para eso me gustaría registrar todas las solicitudes que se realizan. Podría obtener esta información ngrep, pero desafortunadamente no es posible grep conexiones https (que son necesarias para OAuth)

¿Cómo puedo activar el registro de todas las URL (+ parámetros) a las que Requestsestá accediendo?

La urllib3biblioteca subyacente registra todas las nuevas conexiones y URL con el loggingmódulo , pero no los POSTcuerpos. Para GETsolicitudes esto debería ser suficiente:

import logging

logging.basicConfig(level=logging.DEBUG)

que le brinda la opción de registro más detallada; ver el COMO de registro para obtener más detalles sobre cómo configurar los niveles y destinos de registro.

Demostración corta:

>>> import requests
>>> import logging
>>> logging.basicConfig(level=logging.DEBUG)
>>> r = requests.get('http://httpbin.org/get?foo=bar&baz=python')
DEBUG:urllib3.connectionpool:Starting new HTTP connection (1): httpbin.org:80
DEBUG:urllib3.connectionpool:http://httpbin.org:80 "GET /get?foo=bar&baz=python HTTP/1.1" 200 366

Dependiendo de la versión exacta de urllib3, se registran los siguientes mensajes:

• INFO: Redireccionamientos
• WARN: Grupo de conexiones lleno (si esto sucede, a menudo aumente el tamaño del grupo de conexiones)
• WARN: Error al analizar los encabezados (encabezados de respuesta con formato no válido)
• WARN: Reintentando la conexión
• WARN: El certificado no coincide con el nombre de host esperado
• WARN: Respuesta recibida con Content-Length y Transfer-Encoding, al procesar una respuesta fragmentada
• DEBUG: Nuevas conexiones (HTTP o HTTPS)
• DEBUG: Conexiones perdidas
• DEBUG: Detalles de la conexión: método, ruta, versión HTTP, código de estado y longitud de la respuesta
• DEBUG: Incrementos de recuento de reintentos

Esto no incluye encabezados ni cuerpos. urllib3usa la http.client.HTTPConnectionclase para hacer el trabajo pesado, pero esa clase no admite el registro, normalmente solo se puede configurar para imprimir en stdout. Sin embargo, puede manipularlo para enviar toda la información de depuración al registro introduciendo un printnombre alternativo en ese módulo:

import logging
import http.client

httpclient_logger = logging.getLogger("http.client")

def httpclient_logging_patch(level=logging.DEBUG):
    """Enable HTTPConnection debug logging to the logging framework"""

    def httpclient_log(*args):
        httpclient_logger.log(level, " ".join(args))

    # mask the print() built-in in the http.client module to use
    # logging instead
    http.client.print = httpclient_log
    # enable debugging
    http.client.HTTPConnection.debuglevel = 1

La llamada httpclient_logging_patch()hace que las http.clientconexiones envíen toda la información de depuración a un registrador estándar, por lo que son recogidas por logging.basicConfig():

>>> httpclient_logging_patch()
>>> r = requests.get('http://httpbin.org/get?foo=bar&baz=python')
DEBUG:urllib3.connectionpool:Starting new HTTP connection (1): httpbin.org:80
DEBUG:http.client:send: b'GET /get?foo=bar&baz=python HTTP/1.1\r\nHost: httpbin.org\r\nUser-Agent: python-requests/2.22.0\r\nAccept-Encoding: gzip, deflate\r\nAccept: */*\r\nConnection: keep-alive\r\n\r\n'
DEBUG:http.client:reply: 'HTTP/1.1 200 OK\r\n'
DEBUG:http.client:header: Date: Tue, 04 Feb 2020 13:36:53 GMT
DEBUG:http.client:header: Content-Type: application/json
DEBUG:http.client:header: Content-Length: 366
DEBUG:http.client:header: Connection: keep-alive
DEBUG:http.client:header: Server: gunicorn/19.9.0
DEBUG:http.client:header: Access-Control-Allow-Origin: *
DEBUG:http.client:header: Access-Control-Allow-Credentials: true
DEBUG:urllib3.connectionpool:http://httpbin.org:80 "GET /get?foo=bar&baz=python HTTP/1.1" 200 366

Debe habilitar la depuración en el httplibnivel ( requests→ urllib3→ httplib).

Aquí hay algunas funciones para alternar ( ..._on()y ..._off()) o activarlas temporalmente:

import logging
import contextlib
try:
    from http.client import HTTPConnection # py3
except ImportError:
    from httplib import HTTPConnection # py2

def debug_requests_on():
    '''Switches on logging of the requests module.'''
    HTTPConnection.debuglevel = 1

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

def debug_requests_off():
    '''Switches off logging of the requests module, might be some side-effects'''
    HTTPConnection.debuglevel = 0

    root_logger = logging.getLogger()
    root_logger.setLevel(logging.WARNING)
    root_logger.handlers = []
    requests_log = logging.getLogger("requests.packages.urllib3")
    requests_log.setLevel(logging.WARNING)
    requests_log.propagate = False

@contextlib.contextmanager
def debug_requests():
    '''Use with 'with'!'''
    debug_requests_on()
    yield
    debug_requests_off()

Uso de demostración:

>>> requests.get('http://httpbin.org/')
<Response [200]>

>>> debug_requests_on()
>>> requests.get('http://httpbin.org/')
INFO:requests.packages.urllib3.connectionpool:Starting new HTTP connection (1): httpbin.org
DEBUG:requests.packages.urllib3.connectionpool:"GET / HTTP/1.1" 200 12150
send: 'GET / HTTP/1.1\r\nHost: httpbin.org\r\nConnection: keep-alive\r\nAccept-
Encoding: gzip, deflate\r\nAccept: */*\r\nUser-Agent: python-requests/2.11.1\r\n\r\n'
reply: 'HTTP/1.1 200 OK\r\n'
header: Server: nginx
...
<Response [200]>

>>> debug_requests_off()
>>> requests.get('http://httpbin.org/')
<Response [200]>

>>> with debug_requests():
...     requests.get('http://httpbin.org/')
INFO:requests.packages.urllib3.connectionpool:Starting new HTTP connection (1): httpbin.org
...
<Response [200]>

Verá la SOLICITUD, incluidos los ENCABEZADOS y DATOS, y la RESPUESTA con ENCABEZADOS pero sin DATOS. Lo único que falta será el response.body que no está registrado.

Fuente

Para aquellos que usan Python 3+

import requests
import logging
import http.client

http.client.HTTPConnection.debuglevel = 1

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

Al intentar que el sistema de registro de Python ( import logging) emita mensajes de registro de depuración de bajo nivel, me sorprendió descubrir que dado:

requests --> urllib3 --> http.client.HTTPConnection

que solo urllib3usa realmente el loggingsistema Python :

• requests No
• http.client.HTTPConnection No
• urllib3 si

Claro, puede extraer mensajes de depuración HTTPConnectionconfigurando:

HTTPConnection.debuglevel = 1

pero estas salidas se emiten simplemente a través de la printdeclaración. Para probar esto, simplemente grep el client.pycódigo fuente de Python 3.7 y vea las declaraciones de impresión usted mismo (gracias @Yohann):

curl https://raw.githubusercontent.com/python/cpython/3.7/Lib/http/client.py |grep -A1 debuglevel` 

Es de suponer que redirigir stdout de alguna manera podría funcionar a shoe-horn stdout en el sistema de registro y potencialmente capturarlo, por ejemplo, en un archivo de registro.

Elija el ' urllib3' registrador no ' requests.packages.urllib3'

Para capturar urllib3información de depuración a través del loggingsistema Python 3 , contrariamente a muchos consejos en Internet, y como señala @MikeSmith, no tendrá mucha suerte interceptando:

log = logging.getLogger('requests.packages.urllib3')

en su lugar necesitas:

log = logging.getLogger('urllib3')

Depurar urllib3a un archivo de registro

Aquí hay un código que registra el urllib3funcionamiento en un archivo de registro usando el loggingsistema Python :

import requests
import logging
from http.client import HTTPConnection  # py3

# log = logging.getLogger('requests.packages.urllib3')  # useless
log = logging.getLogger('urllib3')  # works

log.setLevel(logging.DEBUG)  # needed
fh = logging.FileHandler("requests.log")
log.addHandler(fh)

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

el resultado:

Starting new HTTP connection (1): httpbin.org:80
http://httpbin.org:80 "GET / HTTP/1.1" 200 3168

Habilitar las HTTPConnection.debugleveldeclaraciones print ()

Si pones HTTPConnection.debuglevel = 1

from http.client import HTTPConnection  # py3
HTTPConnection.debuglevel = 1
requests.get('http://httpbin.org/')

obtendrá la impresión de salida de la sentencia de la información adicional bajo nivel jugosa:

send: b'GET / HTTP/1.1\r\nHost: httpbin.org\r\nUser-Agent: python- 
requests/2.22.0\r\nAccept-Encoding: gzip, deflate\r\nAccept: */*\r\nConnection: keep-alive\r\n\r\n'
reply: 'HTTP/1.1 200 OK\r\n'
header: Access-Control-Allow-Credentials header: Access-Control-Allow-Origin 
header: Content-Encoding header: Content-Type header: Date header: ...

Recuerde que esta salida usa printy no el loggingsistema Python , y por lo tanto no se puede capturar usando una loggingsecuencia tradicional o un controlador de archivos (aunque es posible capturar la salida en un archivo redirigiendo stdout) .

Combine los dos anteriores: maximice todos los registros posibles en la consola

Para maximizar todos los registros posibles, debe conformarse con la salida de consola / salida estándar con esto:

import requests
import logging
from http.client import HTTPConnection  # py3

log = logging.getLogger('urllib3')
log.setLevel(logging.DEBUG)

# logging from urllib3 to console
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)
log.addHandler(ch)

# print statements from `http.client.HTTPConnection` to console/stdout
HTTPConnection.debuglevel = 1

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

dando la gama completa de salida:

Starting new HTTP connection (1): httpbin.org:80
send: b'GET / HTTP/1.1\r\nHost: httpbin.org\r\nUser-Agent: python-requests/2.22.0\r\nAccept-Encoding: gzip, deflate\r\nAccept: */*\r\nConnection: keep-alive\r\n\r\n'
reply: 'HTTP/1.1 200 OK\r\n'
http://httpbin.org:80 "GET / HTTP/1.1" 200 3168
header: Access-Control-Allow-Credentials header: Access-Control-Allow-Origin 
header: Content-Encoding header: ...

Estoy usando Python 3.4, solicitudes 2.19.1:

'urllib3' es el registrador que se obtiene ahora (ya no 'request.packages.urllib3'). El registro básico seguirá ocurriendo sin configurar http.client.HTTPConnection.debuglevel

Al tener un script o incluso un subsistema de una aplicación para la depuración de un protocolo de red, se desea ver qué pares de solicitud-respuesta son exactamente, incluidas las URL efectivas, los encabezados, las cargas útiles y el estado. Y normalmente no es práctico instrumentar solicitudes individuales en todo el lugar. Al mismo tiempo, existen consideraciones de desempeño que sugieren el uso de una sola (o pocas especializadas) requests.Session, por lo que lo siguiente supone que se sigue la sugerencia .

requestsadmite los llamados ganchos de eventos (a partir de 2.23 en realidad solo hay responseenganches). Es básicamente un detector de eventos y el evento se emite antes de devolver el control requests.request. En este momento, tanto la solicitud como la respuesta están completamente definidas, por lo que se pueden registrar.

import logging

import requests


logger = logging.getLogger('httplogger')

def logRoundtrip(response, *args, **kwargs):
    extra = {'req': response.request, 'res': response}
    logger.debug('HTTP roundtrip', extra=extra)

session = requests.Session()
session.hooks['response'].append(logRoundtrip)

Así es básicamente cómo registrar todos los viajes de ida y vuelta HTTP de una sesión.

Formateo de registros de registro de ida y vuelta HTTP

Para que el registro anterior sea útil, puede haber un formateador de registro especializado que comprenda reqy reshaga extras en los registros de registro. Puede verse así:

import textwrap

class HttpFormatter(logging.Formatter):   

    def _formatHeaders(self, d):
        return '\n'.join(f'{k}: {v}' for k, v in d.items())

    def formatMessage(self, record):
        result = super().formatMessage(record)
        if record.name == 'httplogger':
            result += textwrap.dedent('''
                ---------------- request ----------------
                {req.method} {req.url}
                {reqhdrs}

                {req.body}
                ---------------- response ----------------
                {res.status_code} {res.reason} {res.url}
                {reshdrs}

                {res.text}
            ''').format(
                req=record.req,
                res=record.res,
                reqhdrs=self._formatHeaders(record.req.headers),
                reshdrs=self._formatHeaders(record.res.headers),
            )

        return result

formatter = HttpFormatter('{asctime} {levelname} {name} {message}', style='{')
handler = logging.StreamHandler()
handler.setFormatter(formatter)
logging.basicConfig(level=logging.DEBUG, handlers=[handler])

Ahora, si haces algunas solicitudes usando el session, como:

session.get('https://httpbin.org/user-agent')
session.get('https://httpbin.org/status/200')

La salida stderrse verá de la siguiente manera.

2020-05-14 22:10:13,224 DEBUG urllib3.connectionpool Starting new HTTPS connection (1): httpbin.org:443
2020-05-14 22:10:13,695 DEBUG urllib3.connectionpool https://httpbin.org:443 "GET /user-agent HTTP/1.1" 200 45
2020-05-14 22:10:13,698 DEBUG httplogger HTTP roundtrip
---------------- request ----------------
GET https://httpbin.org/user-agent
User-Agent: python-requests/2.23.0
Accept-Encoding: gzip, deflate
Accept: */*
Connection: keep-alive

None
---------------- response ----------------
200 OK https://httpbin.org/user-agent
Date: Thu, 14 May 2020 20:10:13 GMT
Content-Type: application/json
Content-Length: 45
Connection: keep-alive
Server: gunicorn/19.9.0
Access-Control-Allow-Origin: *
Access-Control-Allow-Credentials: true

{
  "user-agent": "python-requests/2.23.0"
}


2020-05-14 22:10:13,814 DEBUG urllib3.connectionpool https://httpbin.org:443 "GET /status/200 HTTP/1.1" 200 0
2020-05-14 22:10:13,818 DEBUG httplogger HTTP roundtrip
---------------- request ----------------
GET https://httpbin.org/status/200
User-Agent: python-requests/2.23.0
Accept-Encoding: gzip, deflate
Accept: */*
Connection: keep-alive

None
---------------- response ----------------
200 OK https://httpbin.org/status/200
Date: Thu, 14 May 2020 20:10:13 GMT
Content-Type: text/html; charset=utf-8
Content-Length: 0
Connection: keep-alive
Server: gunicorn/19.9.0
Access-Control-Allow-Origin: *
Access-Control-Allow-Credentials: true

Una forma de GUI

Cuando tienes muchas consultas, tener una interfaz de usuario simple y una forma de filtrar registros resulta útil. Mostraré el uso de Chronologer para eso (del cual soy autor).

Primero, el gancho se ha reescrito para producir registros que loggingpuedan serializarse cuando se envían por cable. Puede verse así:

def logRoundtrip(response, *args, **kwargs): 
    extra = {
        'req': {
            'method': response.request.method,
            'url': response.request.url,
            'headers': response.request.headers,
            'body': response.request.body,
        }, 
        'res': {
            'code': response.status_code,
            'reason': response.reason,
            'url': response.url,
            'headers': response.headers,
            'body': response.text
        },
    }
    logger.debug('HTTP roundtrip', extra=extra)

session = requests.Session()
session.hooks['response'].append(logRoundtrip)

En segundo lugar, la configuración de registro debe adaptarse para su uso logging.handlers.HTTPHandler(lo que Chronologer entiende).

import logging.handlers

chrono = logging.handlers.HTTPHandler(
  'localhost:8080', '/api/v1/record', 'POST', credentials=('logger', ''))
handlers = [logging.StreamHandler(), chrono]
logging.basicConfig(level=logging.DEBUG, handlers=handlers)

Finalmente, ejecute la instancia de Chronologer. por ejemplo, usando Docker:

docker run --rm -it -p 8080:8080 -v /tmp/db \
    -e CHRONOLOGER_STORAGE_DSN=sqlite:////tmp/db/chrono.sqlite \
    -e CHRONOLOGER_SECRET=example \
    -e CHRONOLOGER_ROLES="basic-reader query-reader writer" \
    saaj/chronologer \
    python -m chronologer -e production serve -u www-data -g www-data -m

Y vuelva a ejecutar las solicitudes:

session.get('https://httpbin.org/user-agent')
session.get('https://httpbin.org/status/200')

El controlador de flujo producirá:

DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): httpbin.org:443
DEBUG:urllib3.connectionpool:https://httpbin.org:443 "GET /user-agent HTTP/1.1" 200 45
DEBUG:httplogger:HTTP roundtrip
DEBUG:urllib3.connectionpool:https://httpbin.org:443 "GET /status/200 HTTP/1.1" 200 0
DEBUG:httplogger:HTTP roundtrip

Ahora, si abre http: // localhost: 8080 / (use "logger" para el nombre de usuario y la contraseña vacía para la ventana emergente de autenticación básica) y hace clic en el botón "Abrir", debería ver algo como:

Estoy usando un logger_config.yamlarchivo para configurar mi registro, y para que aparezcan esos registros, todo lo que tenía que hacer era agregar un disable_existing_loggers: Falseal final.

Mi configuración de registro es bastante extensa y confusa, por lo que ni siquiera conozco una buena manera de explicarlo aquí, pero si alguien también está usando un archivo YAML para configurar su registro, esto podría ayudar.

https://docs.python.org/3/howto/logging.html#configuring-logging