Enregistrer toutes les requêtes du module python-requests

Question

J'utilise python Demandes . J'ai besoin de déboguer certains OAuth et pour cela, je voudrais qu'il enregistre toutes les requêtes effectuées. Je pourrais obtenir ces informations avec ngrep mais malheureusement, il n'est pas possible de grep les connexions https (qui sont nécessaires pour l'accès à l'Internet). OAuth )

Comment puis-je activer la journalisation de toutes les URL (+ paramètres) qui Requests est en train d'accéder ?

Answer 1

Vous devez activer le débogage à httplib niveau ( requests → urllib3 → httplib ).

Voici quelques fonctions permettant à la fois de basculer ( ..._on() et ..._off() ) ou l'avoir temporairement :

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()

Usage démo :

>>> 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]>

Vous verrez la DEMANDE, y compris les EN-TÊTES et les DONNÉES, et la RÉPONSE avec les EN-TÊTES mais sans les DONNÉES. La seule chose manquante sera le response.body qui n'est pas enregistré.

Source :

Answer 2

Le sous-jacent urllib3 enregistre toutes les nouvelles connexions et URL avec l'attribut logging module mais pas POST corps. Pour GET demande cela devrait être suffisant :

import logging

logging.basicConfig(level=logging.DEBUG)

qui vous donne l'option de journalisation la plus verbeuse ; voir la section HOWTO sur l'enregistrement pour plus de détails sur la façon de configurer les niveaux de journalisation et les destinations.

Démonstration courte :

>>> 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

Selon la version exacte de urllib3, les messages suivants sont enregistrés :

• INFO : Redirections
• WARN : Pool de connexion plein (si cela se produit souvent, augmentez la taille du pool de connexion)
• WARN : Failed to parse headers (en-têtes de réponse avec un format invalide)
• WARN : Retenter la connexion
• WARN : Le certificat ne correspond pas au nom d'hôte attendu
• WARN : Réponse reçue avec à la fois Content-Length et Transfer-Encoding, lors du traitement d'une réponse en bloc.
• DEBUG : Nouvelles connexions (HTTP ou HTTPS)
• DEBUG : Connexions interrompues
• DEBUG : Détails de la connexion : méthode, chemin, version HTTP, code d'état et longueur de la réponse.
• DEBUG : Incrémentation du nombre de tentatives

Cela ne comprend pas les en-têtes ni les corps. urllib3 utilise le http.client.HTTPConnection pour faire le travail de fond, mais cette classe ne supporte pas la journalisation, elle peut normalement être configurée uniquement pour imprimer vers stdout. Cependant, vous pouvez le configurer pour qu'il envoie toutes les informations de débogage à la journalisation en introduisant l'alternative suivante print dans ce module :

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

Appel à httpclient_logging_patch() causes http.client pour transmettre toutes les informations de débogage à un logger standard, et sont donc reprises par 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

Answer 3

Pour les utilisateurs de 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

Answer 4

Lorsque l'on essaie de faire fonctionner le système de journalisation Python ( import logging ) pour émettre des messages de débogage de bas niveau, j'ai été surpris de découvrir qu'étant donné :

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

que seulement urllib3 utilise en fait le langage Python logging système :

• requests pas de
• http.client.HTTPConnection pas de
• urllib3 oui

Bien sûr, vous pouvez extraire les messages de débogage de HTTPConnection par la mise en place :

HTTPConnection.debuglevel = 1

mais ces sorties sont simplement émises via le print déclaration. Pour le prouver, il suffit de grep le fichier Python 3.7 client.py code source et visualisez les instructions d'impression vous-même (merci @Yohann) :

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

On peut supposer que la redirection de stdout d'une manière ou d'une autre pourrait fonctionner pour intégrer stdout dans le système de journalisation et potentiellement capturer dans un fichier journal par exemple.

Choisissez l'option ' urllib3 ' logger not ' requests.packages.urllib3 '

Pour capturer urllib3 des informations de débogage par le biais de Python 3 logging Contrairement à de nombreux conseils sur Internet, et comme le souligne @MikeSmith, vous n'aurez pas beaucoup de chance d'intercepter le système :

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

à la place, vous devez le faire :

log = logging.getLogger('urllib3')

Débogage urllib3 vers un fichier journal

Voici un code qui enregistre les données urllib3 dans un fichier journal à l'aide de l'outil Python logging système :

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/')

le résultat :

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

Activation de la HTTPConnection.debuglevel déclarations print()

Si vous définissez HTTPConnection.debuglevel = 1

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

vous obtiendrez le imprimer sortie de déclaration d'informations supplémentaires juteuses de bas niveau :

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: ...

Rappelez-vous que cette sortie utilise print et non le Python logging et ne peuvent donc pas être capturés à l'aide d'un système traditionnel de gestion de l'information. logging gestionnaire de flux ou de fichiers (bien qu'il soit possible de capturer la sortie vers un fichier en redirigeant stdout) .

Combinez les deux ci-dessus - maximisez tous les enregistrements possibles sur la console.

Pour maximiser toutes les possibilités d'enregistrement, vous devez vous contenter de la sortie console/stdout avec ceci :

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/')

donnant toute la gamme de sortie :

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: ...

Answer 5

Si l'on dispose d'un script ou même d'un sous-système d'une application pour le débogage d'un protocole réseau, il est souhaitable de voir quelles sont exactement les paires demande-réponse, y compris les URL effectives, les en-têtes, les charges utiles et l'état. Et il n'est généralement pas pratique d'instrumenter des requêtes individuelles un peu partout. En même temps, il y a des considérations de performance qui suggèrent l'utilisation d'une seule (ou de quelques) méthode(s) spécialisée(s) d'instrumentation. requests.Session donc ce qui suit suppose que la suggestion est suivie.

requests soutient ce que l'on appelle crochets d'événements (à partir de la version 2.23, il n'y a en fait que des response crochet). Il s'agit essentiellement d'un écouteur d'événements, et l'événement est émis avant le retour du contrôle de la commande requests.request . À ce stade, la demande et la réponse sont entièrement définies et peuvent donc être enregistrées.

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)

C'est en gros la façon d'enregistrer tous les allers-retours HTTP d'une session.

Formatage des enregistrements du journal des allers-retours HTTP

Pour que l'enregistrement ci-dessus soit utile, il peut y avoir des services spécialisés. formateur de journalisme qui comprend req et res supplémentaires sur les registres d'enregistrement. Cela peut ressembler à ceci :

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])

Maintenant, si vous faites des requêtes en utilisant le session comme :

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

La sortie vers stderr se présentera comme suit.

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

Une interface graphique

Lorsque vous avez beaucoup de requêtes, il est utile d'avoir une interface utilisateur simple et un moyen de filtrer les enregistrements. Je vais montrer comment utiliser Chronologer pour cela (dont je suis l'auteur).

Premièrement, le crochet doit être réécrit pour produire des enregistrements qui logging peut être sérialisée lorsqu'elle est envoyée sur le fil. Cela peut ressembler à ça :

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)

Deuxièmement, la configuration de la journalisation doit être adaptée pour utiliser logging.handlers.HTTPHandler (ce que le Chronologer comprend).

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)

Enfin, exécutez l'instance de Chronologer, par exemple en utilisant 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

Et relancez les requêtes :

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

Le gestionnaire de flux va produire :

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

Maintenant, si vous ouvrez http://localhost:8080/ (utilisez "logger" comme nom d'utilisateur et un mot de passe vide pour la popup d'authentification de base) et cliquez sur le bouton "Ouvrir", vous devriez voir quelque chose comme ça :