J'utilise des requêtes python . J'ai besoin de déboguer une OAuthactivité, et pour cela, je voudrais qu'il enregistre toutes les demandes en cours. Je pourrais obtenir ces informations avec ngrep, mais malheureusement, il n'est pas possible de grep les connexions https (qui sont nécessaires pour OAuth)

Comment puis-je activer la journalisation de toutes les URL (+ paramètres) qui Requestsaccèdent?

La urllib3bibliothèque sous-jacente enregistre toutes les nouvelles connexions et URL avec le loggingmodule , mais pas les POSTcorps. Pour les GETdemandes, cela devrait suffire:

import logging

logging.basicConfig(level=logging.DEBUG)

ce qui vous donne l'option de journalisation la plus détaillée; voir le HOWTO de journalisation pour plus de détails sur la configuration des niveaux de journalisation et des destinations.

Démo 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: Redirige
• WARN: Pool de connexions plein (si cela se produit souvent, augmentez la taille du pool de connexions)
• WARN: Échec de l'analyse des en-têtes (en-têtes de réponse au format non valide)
• WARN: Nouvelle tentative de 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 fragmentée
• 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éments du nombre de tentatives

Cela n'inclut pas les en-têtes ou les corps. urllib3utilise la http.client.HTTPConnectionclasse pour faire le grunt-work, mais cette classe ne prend pas en charge la journalisation, elle ne peut normalement être configurée que pour imprimer sur stdout. Cependant, vous pouvez le configurer pour envoyer toutes les informations de débogage à la journalisation en introduisant un printnom alternatif 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

L'appel httpclient_logging_patch()amène les http.clientconnexions à afficher toutes les informations de débogage vers un enregistreur standard, et sont donc récupérées 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

Vous devez activer le débogage au httplibniveau ( requests→ urllib3→ httplib).

Voici quelques fonctions à la fois pour basculer ( ..._on()et ..._off()) ou pour l'activer 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()

Utilisation de la démonstration:

>>> 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 qui manque sera le response.body qui n'est pas enregistré.

La source

Pour ceux qui utilisent 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

En essayant de faire en sorte que le système de journalisation Python ( import logging) émette des messages de journal de débogage de bas niveau, il m'a surpris de découvrir que:

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

qui urllib3utilise uniquement le loggingsystème Python :

• requests non
• http.client.HTTPConnection non
• urllib3 Oui

Bien sûr, vous pouvez extraire les messages de débogage HTTPConnectionen définissant:

HTTPConnection.debuglevel = 1

mais ces sorties sont simplement émises via l' printinstruction. Pour le prouver, grep simplement le client.pycode source de Python 3.7 et affichez 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 vers une sortie stdout dans le système de journalisation et potentiellement capturer, par exemple, un fichier journal.

Choisissez le ' urllib3' logger not ' requests.packages.urllib3'

Pour capturer des urllib3informations de débogage via le loggingsystème Python 3 , contrairement à de nombreux conseils sur Internet, et comme le souligne @MikeSmith, vous n'aurez pas beaucoup de chance d'intercepter:

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

à la place, vous devez:

log = logging.getLogger('urllib3')

Débogage urllib3dans un fichier journal

Voici un code qui enregistre le urllib3fonctionnement dans un fichier journal à l'aide du loggingsystème 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/')

le résultat:

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

Activation des HTTPConnection.debuglevelinstructions print ()

Si vous définissez HTTPConnection.debuglevel = 1

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

vous obtiendrez la sortie de l'instruction d' impression 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: ...

Souvenez-vous que cette sortie utilise printet non le loggingsystème Python , et ne peut donc pas être capturée à l'aide d'un loggingflux ou d'un gestionnaire de fichiers traditionnel (bien qu'il soit possible de capturer la sortie vers un fichier en redirigeant stdout) .

Combinez les deux ci-dessus - maximisez toute la journalisation possible sur la console

Pour maximiser toute la journalisation possible, 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 la gamme complète 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: ...

J'utilise python 3.4, demande 2.19.1:

'urllib3' est le logger à obtenir maintenant (et non plus 'requests.packages.urllib3'). La journalisation de base se produira toujours sans définir http.client.HTTPConnection.debuglevel

Ayant un script ou même 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 efficaces, les en-têtes, les charges utiles et l'état. Et il est généralement peu pratique d'instrumenter des demandes individuelles partout. Dans le même temps, il existe des considérations de performances qui suggèrent d'utiliser un seul (ou quelques spécialistes) requests.Session, de sorte que ce qui suit suppose que la suggestion est suivie.

requestsprend en charge ce que l'on appelle les hooks d'événement (à partir de 2.23, il n'y a en fait qu'un responsehook). Il s'agit essentiellement d'un écouteur d'événement, et l'événement est émis avant de renvoyer le contrôle requests.request. À ce moment, 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 essentiellement comment enregistrer tous les aller-retour HTTP d'une session.

Formatage des enregistrements de journal HTTP aller-retour

Pour que la journalisation ci-dessus soit utile, il peut y avoir un formateur de journalisation spécialisé qui comprend reqet des resextras sur les enregistrements de journalisation. 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 stderrressemblera à ceci.

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 manière GUI

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

Tout d'abord, le hook a été réécrit pour produire des enregistrements qui loggingpeuvent être sérialisés lors de l'envoi sur le fil. Cela peut ressembler à ceci:

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 à l'utilisation logging.handlers.HTTPHandler(ce que 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 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 exécutez à nouveau les requêtes:

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

Le gestionnaire de flux produira:

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" pour le nom d'utilisateur et un mot de passe vide pour la fenêtre contextuelle d'authentification de base) et cliquez sur le bouton "Ouvrir", vous devriez voir quelque chose comme: