Ich verwende Python- Anfragen . Ich muss einige OAuthAktivitäten debuggen , und dafür möchte ich, dass alle ausgeführten Anforderungen protokolliert werden. Ich könnte diese Informationen mit erhalten ngrep, aber leider ist es nicht möglich, https-Verbindungen zu erfassen (die für benötigt werden OAuth)

Wie kann ich die Protokollierung aller URLs (+ Parameter) aktivieren, auf die zugegriffen Requestswird?

Die zugrunde liegende urllib3Bibliothek protokolliert alle neuen Verbindungen und URLs mit dem loggingModul , jedoch keine POSTKörper. Für GETAnfragen sollte dies ausreichen:

import logging

logging.basicConfig(level=logging.DEBUG)

Dies gibt Ihnen die ausführlichste Protokollierungsoption. Weitere Informationen zum Konfigurieren von Protokollierungsstufen und -zielen finden Sie im Protokollierungs-HOWTO .

Kurze Demo:

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

Abhängig von der genauen Version von urllib3 werden die folgenden Nachrichten protokolliert:

• INFO: Weiterleitungen
• WARN: Verbindungspool voll (wenn dies passiert, erhöhen Sie häufig die Größe des Verbindungspools)
• WARN: Fehler beim Analysieren von Headern (Antwortheader mit ungültigem Format)
• WARN: Wiederholen der Verbindung
• WARN: Zertifikat stimmte nicht mit dem erwarteten Hostnamen überein
• WARN: Empfangene Antwort mit Inhaltslänge und Übertragungscodierung, wenn eine Blockantwort verarbeitet wird
• DEBUG: Neue Verbindungen (HTTP oder HTTPS)
• DEBUG: Verbindungen wurden unterbrochen
• DEBUG: Verbindungsdetails: Methode, Pfad, HTTP-Version, Statuscode und Antwortlänge
• DEBUG: Wiederholen Sie die Anzahl der Schritte

Dies schließt keine Überschriften oder Körper ein. urllib3Verwendet die http.client.HTTPConnectionKlasse, um die Grunzarbeit zu erledigen, aber diese Klasse unterstützt keine Protokollierung. Sie kann normalerweise nur so konfiguriert werden, dass sie auf stdout druckt . Sie können es jedoch so manipulieren, dass stattdessen alle Debug-Informationen an die Protokollierung gesendet werden, indem Sie einen alternativen printNamen in dieses Modul einfügen:

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

Das Aufrufen httpclient_logging_patch()bewirkt, dass http.clientVerbindungen alle Debug-Informationen an einen Standard-Logger ausgeben und daher von folgenden Personen abgerufen werden 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

Sie müssen das Debuggen auf httplibEbene aktivieren ( requests→ urllib3→httplib ) .

Hier sind einige Funktionen zum Umschalten ( ..._on()und ..._off()) oder zum vorübergehenden Aktivieren:

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

Demo-Nutzung:

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

Sie sehen die ANFRAGE, einschließlich HEADERS und DATA, und RESPONSE mit HEADERS, jedoch ohne DATA. Das einzige, was fehlt, ist die response.body, die nicht protokolliert ist.

Quelle

Für diejenigen, die Python 3+ verwenden

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

Als ich versuchte, das Python-Protokollierungssystem ( import logging) dazu zu bringen, Debug-Protokollnachrichten auf niedriger Ebene auszugeben, war ich überrascht, dass Folgendes festgestellt wurde:

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

das urllib3benutzt eigentlich nur das Python- loggingSystem:

• requests Nein
• http.client.HTTPConnection Nein
• urllib3 Ja

Natürlich können Sie Debug-Meldungen extrahieren, HTTPConnectionindem Sie Folgendes festlegen :

HTTPConnection.debuglevel = 1

Diese Ausgaben werden jedoch lediglich über die printAnweisung ausgegeben. Um dies zu beweisen, client.pydurchsuchen Sie einfach den Python 3.7- Quellcode und sehen Sie sich die print-Anweisungen selbst an (danke @Yohann):

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

Vermutlich könnte das Umleiten von stdout auf irgendeine Weise dazu führen, dass stdout in das Protokollierungssystem eingeschlagen und möglicherweise in eine Protokolldatei erfasst wird.

Wählen Sie die ‚ urllib3‘ Logger nicht ‚ requests.packages.urllib3‘

Um urllib3Debug-Informationen über das Python 3- loggingSystem zu erfassen , haben Sie entgegen vieler Ratschläge im Internet und wie @MikeSmith betont, nicht viel Glück beim Abfangen:

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

Stattdessen müssen Sie:

log = logging.getLogger('urllib3')

Debuggen urllib3in eine Protokolldatei

Hier ist ein Code, der die urllib3Arbeit mit dem Python- loggingSystem in einer Protokolldatei protokolliert :

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

das Ergebnis:

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

Aktivieren der HTTPConnection.debuglevelprint () - Anweisungen

Wenn Sie einstellen HTTPConnection.debuglevel = 1

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

Sie werden die erhaltenen Druck Anweisung Ausgabe zusätzlicher saftig niedriges Niveau info:

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

Denken Sie daran, dass diese Ausgabe printnicht das Python- loggingSystem verwendet und daher nicht mit einem herkömmlichen loggingStream oder File-Handler erfasst werden kann (obwohl es möglicherweise möglich ist, die Ausgabe in eine Datei zu erfassen, indem Sie stdout umleiten). .

Kombinieren Sie die beiden oben genannten Punkte - maximieren Sie alle möglichen Protokollierungen an der Konsole

Um die gesamte mögliche Protokollierung zu maximieren, müssen Sie sich mit der Konsolen- / Standardausgabe zufrieden geben:

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

Geben Sie den gesamten Ausgabebereich:

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

Ich verwende Python 3.4, Anfragen 2.19.1:

'urllib3' ist der Logger, der jetzt abgerufen werden soll (nicht mehr 'request.packages.urllib3'). Die grundlegende Protokollierung wird weiterhin durchgeführt, ohne dass http.client.HTTPConnection.debuglevel festgelegt wird

Mit einem Skript oder sogar einem Subsystem einer Anwendung für ein Netzwerkprotokoll-Debugging ist es wünschenswert zu sehen, welche Anforderungs-Antwort-Paare genau sind, einschließlich effektiver URLs, Header, Nutzdaten und des Status. Und es ist normalerweise unpraktisch, individuelle Anfragen überall zu instrumentieren. Gleichzeitig gibt es Leistungsüberlegungen, die die Verwendung einzelner (oder weniger spezialisierter) Vorschläge vorschlagen. requests.SessionIm Folgenden wird daher davon ausgegangen, dass der Vorschlag vorliegt befolgt wird.

requestsunterstützt sogenannte Event-Hooks (ab 2.23 gibt es eigentlich nur noch Hooksresponse ). Es ist im Grunde ein Ereignis-Listener, und das Ereignis wird ausgegeben, bevor die Kontrolle von zurückgegeben wird requests.request. In diesem Moment sind sowohl Anforderung als auch Antwort vollständig definiert und können daher protokolliert werden.

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)

Auf diese Weise werden im Grunde alle HTTP-Roundtrips einer Sitzung protokolliert.

Formatieren von HTTP-Roundtrip-Protokolldatensätzen

Damit die obige Protokollierung nützlich ist, kann es einen speziellen Protokollierungsformatierer geben , der die Protokollierungsdatensätze versteht reqund zusätzliche Funktionen bietet res. Es kann so aussehen:

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

Wenn Sie nun einige Anfragen mit dem folgenden Befehl ausführen session:

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

Die Ausgabe von stderrsieht wie folgt aus.

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

Ein GUI-Weg

Wenn Sie viele Fragen haben, ist eine einfache Benutzeroberfläche und eine Möglichkeit zum Filtern von Datensätzen hilfreich. Ich werde zeigen, Chronologer dafür zu verwenden (von dem ich der Autor bin).

Zunächst muss der Hook neu geschrieben werden, um Datensätze zu erstellen, loggingdie beim Senden über das Kabel serialisiert werden können. Es kann so aussehen:

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)

Zweitens muss die Protokollierungskonfiguration an die Verwendung angepasst werden logging.handlers.HTTPHandler(was Chronologer versteht).

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)

Führen Sie abschließend die Chronologer-Instanz aus. zB mit 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

Führen Sie die Anforderungen erneut aus:

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

Der Stream-Handler erzeugt:

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

Wenn Sie nun http: // localhost: 8080 / öffnen (verwenden Sie "logger" als Benutzernamen und leeres Kennwort für das grundlegende Authentifizierungs-Popup) und auf die Schaltfläche "Öffnen" klicken, sollten Sie Folgendes sehen: