时间戳

首页 > 解决方案 > Python HTTP 请求和调试级别记录到日志文件

python - Python HTTP 请求和调试级别记录到日志文件

问题描述

我很难在 HTTP 请求的日志文件中获取 DEBUG 级别日志，例如来自控制台的请求，例如：

DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): URI:443
DEBUG:urllib3.connectionpool:URL:443 "POST /endpoint HTTP/1.1" 200 None

对于下面的代码：

import logging
from logging.handlers import TimedRotatingFileHandler
_logger = logging.getLogger(__name__)

    def setup_logging(loglevel):
        logFormatter = logging.Formatter("%(asctime)s [%(threadName)-12.12s] [%(levelname)-5.5s]  %(message)s")

        if loglevel is not None:
            if loglevel == 10:
                  http.client.HTTPConnection.debuglevel = 1
            logformat = "%(asctime)s [%(threadName)-12.12s] [%(levelname)-5.5s]  %(message)s"
            logging.basicConfig(level=loglevel, stream=sys.stdout, format=logformat, datefmt="%Y-%m-%d %H:%M:%S")

        fileHandler = logging.handlers.TimedRotatingFileHandler("{0}/{1}.log".format(logPath, logFileName), when="midnight")
        fileHandler.setFormatter(logFormatter)
        _logger.setLevel(logging.DEBUG)
        _logger.addHandler(fileHandler)

当我用logging.DEBUG日志文件调用它时，它将只包含我在代码中指定的任何内容_logger.info或_logger.debug与控制台日志输出类似的内容。

PS。示例代码如何调用它：

def main(args):
    args = parse_args(args)
    cfg = config(args.env)
    setup_logging(logging.DEBUG, cfg)
    requests.get("https://stackoverflow.com/a/58769712/100297")

标签： pythonpython-3.xlogging

解决方案

您在错误的位置添加处理程序和级别更改。

Python logging 模块将 logger 对象视为存在于层次结构中，基于它们的名称和.这些名称中分隔符的存在。记录器的名称"foo.bar.baz"在逻辑上被放置为foo.bar和 的子级foo，如果它们存在的话。层次结构的基础是根记录器，它没有名称。您可以使用logging.getLogger()（没有参数，尽管''也None可以）访问它。

现在，在记录消息时，首先消息必须通过记录器的有效级别。如果他们通过了，则消息将传递给从当前记录器到根的每个记录器上的处理程序，前提是他们清除找到的每个处理程序的级别。

为了找到有效级别，遍历层次结构以找到最近的具有级别集的记录器对象；如果没有，则消息总是通过。当遍历层次结构以查找处理程序时，日志对象可以阻止传播（propagate设置为False），此时遍历停止。

当您尝试为 处理消息时urllib3.connectionpool()，您需要将处理程序放置在三个位置之一：for 的记录器urllib3.connectionpool、forurllib3或根记录器。您的代码没有这样做。

相反，您可以在自己的记录器上使用不同的名称设置处理程序：

_logger = logging.getLogger(__name__)

这保证不匹配根记录器（__name__需要为空，绝不是这种情况）也不匹配urllib3orurllib3.connectionpool记录器（这意味着您的模块也被称为urllib3or urllib3.connectionpool)。

因为它不在urllib3.connectionpool日志消息将遵循的路径中，所以您的处理程序永远不会收到这些消息。

相反，您要配置根记录器：

fileHandler = logging.handlers.TimedRotatingFileHandler("{0}/{1}.log".format(logPath, logFileName), when="midnight")
fileHandler.setFormatter(logFormatter)
root = logging.getLogger()
root.setLevel(logging.DEBUG)
root.addHandler(fileHandler)

您可以将每个处理程序的日志级别设置为您希望在该处理程序上看到的日志级别，而不是在根记录器上（或除了根记录器之外）。请记住，根记录器上设置的级别用于确定层次结构中没有直接设置级别的其他记录器的有效级别，并且有效级别用作所有消息的“高水位标记”。如果根记录器设置为INFO，并且没有配置其他处理程序，那么您的处理程序将永远不会看到DEBUG消息。根记录器的默认级别是WARNING.

您通常只想在模块中使用命名记录器来生成日志消息，并将所有处理程序放在根目录上。其他任何东西都是专门的，“高级”使用记录器模块（例如，专用的，单独的处理程序只用于urllib3日志消息，或者通过将其最低级别的记录器对象设置为来使整个包静音propagate = False）。

最后，logging.basicConfig()也配置根记录器，但前提是根记录器上已经没有处理程序。如果使用force=TruethenbasicConfig()将删除所有现有的处理程序，然后在根上配置处理程序。它总是会创建一个Formatter()实例并将其设置在所有处理程序上。

您可以使用basicConfig()所有根记录器需求：

import http.client
import logging
import os.path
import sys
from logging.handlers import TimedRotatingFileHandler

def setup_logging(loglevel):
    # the file handler receives all messages from level DEBUG on up, regardless
    fileHandler = TimedRotatingFileHandler(
        os.path.join(logPath, logFileName + ".log"),
        when="midnight"
    )
    fileHandler.setLevel(logging.DEBUG)
    handlers = [fileHandler]

    if loglevel is not None:
        # if a log level is configured, use that for logging to the console
        stream_handler = logging.StreamHandler(sys.stdout)
        stream_handler.setLevel(loglevel)
        handlers.append(stream_handler)

    if loglevel == logging.DEBUG:
        # when logging at debug level, make http.client extra chatty too
        # http.client *uses `print()` calls*, not logging.
        http.client.HTTPConnection.debuglevel = 1

    # finally, configure the root logger with our choice of handlers
    # the logging level of the root set to DEBUG (defaults to WARNING otherwise).
    logformat = "%(asctime)s [%(threadName)-12.12s] [%(levelname)-5.5s]  %(message)s"
    logging.basicConfig(
        format=logformat, datefmt="%Y-%m-%d %H:%M:%S",
        handlers=handlers, level=logging.DEBUG
    )

旁注：该http.client库不logging用于输出调试消息；它总是print()用来输出那些。如果你想看到这些消息出现在你的日志中，你需要对库进行猴子补丁，添加一个替代的print()全局：

import http.client
import logging

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

def print_to_log(*args):
    http_client_logger.debug(" ".join(args)) 

# monkey-patch a `print` global into the http.client module; all calls to
# print() in that module will then use our print_to_log implementation
http.client.print = print_to_log

应用上述http.client技巧后，当我使用时setup_logging(logging.DEBUG)，我看到文件中和文件中都出现了以下日志：stdoutrequests.get("https://stackoverflow.com/a/58769712/100297")

2019-11-08 16:17:26 [MainThread  ] [DEBUG]  Starting new HTTPS connection (1): stackoverflow.com:443
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  send: b'GET /a/58769712/100297 HTTP/1.1\r\nHost: stackoverflow.com\r\nUser-Agent: python-requests/2.22.0\r\nAccept-Encoding: gzip, deflate\r\nAccept: */*\r\nConnection: keep-alive\r\n\r\n'
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  reply: 'HTTP/1.1 302 Found\r\n'
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Cache-Control: private
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Content-Type: text/html; charset=utf-8
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Location: /questions/58738195/python-http-request-and-debug-level-logging-to-the-log-file/58769712#58769712
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: X-Frame-Options: SAMEORIGIN
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: X-Request-Guid: 761bd2f8-3e5c-453a-ab46-d01284940541
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Strict-Transport-Security: max-age=15552000
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Feature-Policy: microphone 'none'; speaker 'none'
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Content-Security-Policy: upgrade-insecure-requests; frame-ancestors 'self' https://stackexchange.com
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Accept-Ranges: bytes
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Age: 0
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Content-Length: 214
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Accept-Ranges: bytes
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Date: Fri, 08 Nov 2019 16:17:27 GMT
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Via: 1.1 varnish
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Age: 0
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Connection: keep-alive
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: X-Served-By: cache-lhr7324-LHR
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: X-Cache: MISS
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: X-Cache-Hits: 0
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: X-Timer: S1573229847.069848,VS0,VE80
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Vary: Fastly-SSL
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: X-DNS-Prefetch-Control: off
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Set-Cookie: prov=0e92634f-abce-9f8e-1865-0d35ebecc595; domain=.stackoverflow.com; expires=Fri, 01-Jan-2055 00:00:00 GMT; path=/; HttpOnly
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  https://stackoverflow.com:443 "GET /a/58769712/100297 HTTP/1.1" 302 214
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  send: b'GET /questions/58738195/python-http-request-and-debug-level-logging-to-the-log-file/58769712 HTTP/1.1\r\nHost: stackoverflow.com\r\nUser-Agent: python-requests/2.22.0\r\nAccept-Encoding: gzip, deflate\r\nAccept: */*\r\nConnection: keep-alive\r\nCookie: prov=0e92634f-abce-9f8e-1865-0d35ebecc595\r\n\r\n'
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  reply: 'HTTP/1.1 200 OK\r\n'
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Cache-Control: private
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Content-Type: text/html; charset=utf-8
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Content-Encoding: gzip
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Last-Modified: Fri, 08 Nov 2019 16:16:07 GMT
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: X-Frame-Options: SAMEORIGIN
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: X-Request-Guid: 5e48399e-a91c-44aa-aad6-00a96014131f
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Strict-Transport-Security: max-age=15552000
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Feature-Policy: microphone 'none'; speaker 'none'
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Content-Security-Policy: upgrade-insecure-requests; frame-ancestors 'self' https://stackexchange.com
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Accept-Ranges: bytes
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Age: 0
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Content-Length: 42625
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Accept-Ranges: bytes
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Date: Fri, 08 Nov 2019 16:17:27 GMT
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Via: 1.1 varnish
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Age: 0
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Connection: keep-alive
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: X-Served-By: cache-lhr7324-LHR
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: X-Cache: MISS
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: X-Cache-Hits: 0
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: X-Timer: S1573229847.189349,VS0,VE95
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: Vary: Accept-Encoding,Fastly-SSL
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  header: X-DNS-Prefetch-Control: off
2019-11-08 16:17:27 [MainThread  ] [DEBUG]  https://stackoverflow.com:443 "GET /questions/58738195/python-http-request-and-debug-level-logging-to-the-log-file/58769712 HTTP/1.1" 200 42625

您可以使用以下文件重现此内容：

import requests
import sys

logPath, logFileName = "/tmp", "demo"
level = logging.DEBUG if "-v" in sys.argv else None
setup_logging(level)

requests.get("https://stackoverflow.com/a/58769712/100297")

除了上面的代码之外还添加了。然后，您可以使用python <script.py> -v将级别设置为详细，并将其python <script.py>与根本未设置的级别进行比较。

推荐阅读