Używam żądań Pythona . Muszę zdebugować pewne OAuthdziałania iw tym celu chciałbym, aby rejestrował wszystkie wykonywane żądania. Mogłem uzyskać te informacje ngrep, ale niestety nie jest możliwe grepowanie połączeń https (które są potrzebne OAuth)

Jak mogę aktywować rejestrowanie wszystkich adresów URL (+ parametrów), Requestsdo których uzyskuje się dostęp?

Podstawowa urllib3biblioteka rejestruje wszystkie nowe połączenia i adresy URL z loggingmodułem , ale nie treści POST. W przypadku GETwniosków powinno to wystarczyć:

import logging

logging.basicConfig(level=logging.DEBUG)

co daje najbardziej szczegółową opcję rejestrowania; zobacz rejestrowanie HOWTO po więcej szczegółów na temat konfigurowania poziomów logowania i miejsc docelowych.

Krótkie 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

W zależności od dokładnej wersji urllib3 rejestrowane są następujące komunikaty:

• INFO: Przekierowania
• WARN: Pula połączeń jest pełna (jeśli to się często zdarza, zwiększ rozmiar puli połączeń)
• WARN: Nie udało się przeanalizować nagłówków (nagłówki odpowiedzi z nieprawidłowym formatem)
• WARN: Ponawianie połączenia
• WARN: Certyfikat nie pasuje do oczekiwanej nazwy hosta
• WARN: Otrzymano odpowiedź z zarówno Content-Length, jak i Transfer-Encoding, podczas przetwarzania podzielonej odpowiedzi
• DEBUG: Nowe połączenia (HTTP lub HTTPS)
• DEBUG: Zerwane połączenia
• DEBUG: Szczegóły połączenia: metoda, ścieżka, wersja HTTP, kod statusu i długość odpowiedzi
• DEBUG: Ponów licznik przyrostów

Nie obejmuje to nagłówków ani treści. urllib3używa http.client.HTTPConnectionklasy do wykonywania pracy podstawowej, ale ta klasa nie obsługuje rejestrowania, normalnie można ją skonfigurować tylko do drukowania na stdout. Możesz jednak tak skonfigurować, aby wysyłał wszystkie informacje debugowania do logowania, zamiast tego wprowadzając alternatywną printnazwę do tego modułu:

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

Wywołanie httpclient_logging_patch()powoduje, że http.clientpołączenia przekazują wszystkie informacje debugowania do standardowego programu rejestrującego, a więc są odbierane przez 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

Musisz włączyć debugowanie na httplibpoziomie ( requests→ urllib3→ httplib).

Oto kilka funkcji, które można włączać ( ..._on()i ..._off()) lub tymczasowo włączać :

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

Użycie demonstracyjne:

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

Zobaczysz ŻĄDANIE, w tym NAGŁÓWKI i DANE, oraz ODPOWIEDŹ z NAGŁÓWKAMI, ale bez DANYCH. Brakuje tylko odpowiedzi.body, która nie jest zarejestrowana.

Źródło

Dla tych, którzy używają Pythona 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

Kiedy próbowałem zmusić system logowania Pythona ( import logging) do emitowania komunikatów dziennika debugowania niskiego poziomu, zdziwiłem się, że odkryłem, że:

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

który urllib3faktycznie używa tylko loggingsystemu Python :

• requests Nie
• http.client.HTTPConnection Nie
• urllib3 tak

Oczywiście, możesz wyodrębnić komunikaty debugowania HTTPConnection, ustawiając:

HTTPConnection.debuglevel = 1

ale te dane wyjściowe są po prostu emitowane za pośrednictwem printinstrukcji. Aby to udowodnić, po prostu grep client.pykod źródłowy Pythona 3.7 i sam przejrzyj instrukcje print (dzięki @Yohann):

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

Przypuszczalnie przekierowanie stdout w jakiś sposób może zadziałać na standardowe wyjście buta do systemu logowania i potencjalnie przechwycić np. Do pliku dziennika.

Wybierz opcję urllib3„rejestrator nie requests.packages.urllib3”

Aby przechwycić urllib3informacje debugowania za pośrednictwem systemu Python 3 logging, w przeciwieństwie do wielu porad w Internecie i jak wskazuje @MikeSmith, nie będziesz miał dużo szczęścia w przechwytywaniu:

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

zamiast tego musisz:

log = logging.getLogger('urllib3')

Debugowanie urllib3do pliku dziennika

Oto kod, który rejestruje urllib3działania w pliku dziennika za pomocą loggingsystemu 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/')

wynik:

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

Włączanie instrukcji HTTPConnection.debuglevelprint ()

Jeśli ustawisz HTTPConnection.debuglevel = 1

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

otrzymasz wyjście instrukcji print z dodatkowymi, soczystymi informacjami niskiego poziomu:

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

Pamiętaj, że to wyjście używa, printa nie loggingsystemu Python , i dlatego nie może być przechwycone przy użyciu tradycyjnego loggingprogramu obsługi strumienia lub pliku (chociaż może być możliwe przechwycenie danych wyjściowych do pliku przez przekierowanie standardowego wyjścia) .

Połącz dwa powyższe - zmaksymalizuj wszystkie możliwe logowanie do konsoli

Aby zmaksymalizować wszystkie możliwe rejestrowanie, musisz zadowolić się wyjściem konsoli / stdout za pomocą tego:

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

dając pełny zakres mocy:

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

Mając skrypt lub nawet podsystem aplikacji do debugowania protokołu sieciowego, pożądane jest, aby zobaczyć, jakie dokładnie są pary żądanie-odpowiedź, w tym skuteczne adresy URL, nagłówki, ładunki i status. I zazwyczaj niepraktyczne jest nagrywanie indywidualnych żądań w każdym miejscu. Jednocześnie istnieją rozważania dotyczące wydajności, które sugerują użycie pojedynczego (lub kilku specjalistycznych) requests.Session, więc poniżej założono, że sugestia jest przestrzegana.

requestsobsługuje tak zwane podpięcia zdarzeń (od 2.23 jest właściwie tylko responsepodpięcie). Jest to w zasadzie detektor zdarzeń, a zdarzenie jest emitowane przed zwróceniem kontroli z requests.request. W tym momencie zarówno żądanie, jak i odpowiedź są w pełni zdefiniowane, dzięki czemu można je zarejestrować.

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)

To w zasadzie sposób rejestrowania wszystkich obiegów HTTP sesji.

Formatowanie rekordów protokołu HTTP w obie strony

Aby powyższe rejestrowanie było przydatne, może istnieć wyspecjalizowany program formatujący rejestrowanie, który rozumie reqi resdodatkowe informacje dotyczące rejestrowania rekordów. Może to wyglądać tak:

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

Teraz, jeśli wykonasz kilka żądań za pomocą session, takich jak:

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

Dane wyjściowe do stderrbędą wyglądać następująco.

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

Sposób GUI

Gdy masz dużo zapytań, przydatny jest prosty interfejs użytkownika i sposób filtrowania rekordów. Pokażę, że do tego celu użyję Chronologera (którego jestem autorem).

Po pierwsze, hak został przepisany w celu utworzenia rekordów, które loggingmogą być serializowane podczas przesyłania przez przewód. Może to wyglądać tak:

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)

Po drugie, konfiguracja logowania musi być dostosowana do użycia logging.handlers.HTTPHandler(co Chronologer rozumie).

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)

Na koniec uruchom instancję Chronologer. np. używając Dockera:

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

I ponownie uruchom żądania:

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

Procedura obsługi strumienia wygeneruje:

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

Teraz, jeśli otworzysz http: // localhost: 8080 / (użyj „logger” jako nazwy użytkownika i pustego hasła dla podstawowego okna autoryzacji) i klikniesz przycisk „Otwórz”, powinieneś zobaczyć coś takiego:

Używam Pythona 3.4, żądania 2.19.1:

„urllib3” to rejestrator do pobrania (już nie „request.packages.urllib3”). Rejestrowanie podstawowe będzie nadal odbywać się bez ustawiania http.client.HTTPConnection.debuglevel

Używam logger_config.yamlpliku do skonfigurowania mojego logowania i aby te dzienniki się pojawiły, wszystko, co musiałem zrobić, to dodać disable_existing_loggers: Falsena końcu.

Moja konfiguracja logowania jest dość obszerna i myląca, więc nawet nie znam dobrego sposobu, aby to tutaj wyjaśnić, ale jeśli ktoś używa również pliku YAML do konfigurowania logowania, może to pomóc.

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

Poprawiam tę odpowiedź

Tak to działało u mnie:

import logging
import sys    
import requests
import textwrap
    
root = logging.getLogger('httplogger')


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

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(sys.stdout)
handler.setFormatter(formatter)
root.addHandler(handler)
root.setLevel(logging.DEBUG)


session = requests.Session()
session.hooks['response'].append(logRoundtrip)
session.get('http://httpbin.org')