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

最后，logging.basicConfig()也会配置根记录器，但如果根记录器上已经没有处理程序，则也将配置 .如果使用force=True，则basicConfig()将删除所有现有的处理程序，然后在根目录上配置这些处理程序.它将始终创建一个Formatter()实例并将其设置在所有处理程序上.您可以将basicConfig()用于您的根记录器所需的 all :import http.clientimport loggingimport os.pathimport sysfrom logging.handlers import TimedRotatingFileHandlerdef 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() global:import http.clientimport logginghttp_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 implementationhttp.client.print = print_to_log应用上述http.client技巧和setup_logging(logging.DEBUG)后，当我使用requests.get("https://stackoverflow.com/a/58769712/100297")时，我看到以下日志同时出现在stdout和文件中: 2019-11-08 16:17:26 [MainThread ] [DEBUG] Starting new HTTPS connection (1): stackoverflow.com:4432019-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: private2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Content-Type: text/html; charset=utf-82019-11-08 16:17:27 [MainThread ] [DEBUG] header: Location: /questions/58738195/python-http-request-and-debug-level-logging-to-the-log-file/58769712#587697122019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Frame-Options: SAMEORIGIN2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Request-Guid: 761bd2f8-3e5c-453a-ab46-d012849405412019-11-08 16:17:27 [MainThread ] [DEBUG] header: Strict-Transport-Security: max-age=155520002019-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.com2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Accept-Ranges: bytes2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Age: 02019-11-08 16:17:27 [MainThread ] [DEBUG] header: Content-Length: 2142019-11-08 16:17:27 [MainThread ] [DEBUG] header: Accept-Ranges: bytes2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Date: Fri, 08 Nov 2019 16:17:27 GMT2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Via: 1.1 varnish2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Age: 02019-11-08 16:17:27 [MainThread ] [DEBUG] header: Connection: keep-alive2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Served-By: cache-lhr7324-LHR2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Cache: MISS2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Cache-Hits: 02019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Timer: S1573229847.069848,VS0,VE802019-11-08 16:17:27 [MainThread ] [DEBUG] header: Vary: Fastly-SSL2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-DNS-Prefetch-Control: off2019-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=/; HttpOnly2019-11-08 16:17:27 [MainThread ] [DEBUG] https://stackoverflow.com:443 "GET /a/58769712/100297 HTTP/1.1" 302 2142019-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: private2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Content-Type: text/html; charset=utf-82019-11-08 16:17:27 [MainThread ] [DEBUG] header: Content-Encoding: gzip2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Last-Modified: Fri, 08 Nov 2019 16:16:07 GMT2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Frame-Options: SAMEORIGIN2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Request-Guid: 5e48399e-a91c-44aa-aad6-00a96014131f2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Strict-Transport-Security: max-age=155520002019-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.com2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Accept-Ranges: bytes2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Age: 02019-11-08 16:17:27 [MainThread ] [DEBUG] header: Content-Length: 426252019-11-08 16:17:27 [MainThread ] [DEBUG] header: Accept-Ranges: bytes2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Date: Fri, 08 Nov 2019 16:17:27 GMT2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Via: 1.1 varnish2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Age: 02019-11-08 16:17:27 [MainThread ] [DEBUG] header: Connection: keep-alive2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Served-By: cache-lhr7324-LHR2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Cache: MISS2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Cache-Hits: 02019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Timer: S1573229847.189349,VS0,VE952019-11-08 16:17:27 [MainThread ] [DEBUG] header: Vary: Accept-Encoding,Fastly-SSL2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-DNS-Prefetch-Control: off2019-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 requestsimport syslogPath, logFileName = "/tmp", "demo"level = logging.DEBUG if "-v" in sys.argv else Nonesetup_logging(level)requests.get("https://stackoverflow.com/a/58769712/100297")在上面的代码之外添加了.然后，您可以使用python <script.py> -v将级别设置为详细，并将其与python <script.py>进行比较，而完全没有设置级别.I have a hard time to get DEBUG level logs in a log file for HTTP request like those from console like:DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): URI:443DEBUG:urllib3.connectionpool:URL:443 "POST /endpoint HTTP/1.1" 200 Nonefor the code below:import loggingfrom 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)When I will call it with logging.DEBUG log file will only contains whatever I will specify in the code as _logger.info or _logger.debug nothing similar like for the console log output.PS.Example code how do I call it:def main(args): args = parse_args(args) cfg = config(args.env) setup_logging(logging.DEBUG, cfg) requests.get("https://stackoverflow.com/a/58769712/100297") 解决方案 You are adding your handlers and level changes in the wrong place.The Python logging module treats logger objects as existing in a hierarchy, based on their name and the presence of . delimiters in those names. The name "foo.bar.baz" for a logger is logically placed as child of foo.bar and of foo, should they exist. At the base of the hierarchy is the root logger, which has no name. You access it with logging.getLogger() (no arguments, although '' and None also would work).Now, when logging messages, first the message has to pass the effective level of the logger. If they passed that the messages are passed to the handlers on every logger from the current logger down to the root, provided they clear the level of each handler found.To find the effective level, the hierarchy is traversed to find the nearest logger object with a level set; if there are none then messages always pass. When traversing the hierarchy to find handlers, a log object can block propagation (propagate is set to False), at which point traversing stops.When you are trying to handle messages for urllib3.connectionpool(), you need to put a handler on one of three locations: the logger for urllib3.connectionpool, for urllib3 or the root logger. Your code doesn't do that.You instead set up your handlers on your own logger with a different name:_logger = logging.getLogger(__name__)That is guaranteed to not match the root logger (__name__ would need to be empty, that's never the case) nor the urllib3 or urllib3.connectionpool loggers (which would mean your module is also called urllib3 or urllib3.connectionpool).Because it is not in the path that urllib3.connectionpool log messages would follow, your handlers are never going to be given those messages.Instead, you want to configure the root logger: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)You could just set the log level of each handler to a log level you want to see on that handler, rather than on the root logger (or in addition to the root logger). Remember that the level set on the root logger is used to determine the effective level of other loggers in the hierarchy that don't have a level set directly and that the effective level works as a 'high water mark' for all messages. If the root logger is set to INFO, and no other handlers are configured, then your handlers will never see DEBUG messages. The default level for the root logger is WARNING.You usually only ever want to use named loggers in your modules to produce log messages, and put all your handlers on the root. Anything else is specialised, 'advanced' use of the logger module (e.g. a dedicated, separate handler just for the urllib3 log messages, or silencing a whole package by setting their lowest-level logger object to propagate = False).Finally, logging.basicConfig() configures the root logger too, but only if there are no handlers on the root logger already. If you use force=True then basicConfig() will remove all existing handlers, then configure the handlers on the root. It'll always create a Formatter() instance and set it on all handlers.You could use basicConfig() for all your root logger needs:import http.clientimport loggingimport os.pathimport sysfrom logging.handlers import TimedRotatingFileHandlerdef 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 )Side note: the http.client library does not use logging to output debug messages; it will always use print() to output those. If you want to see those messages appear in your logs, you'll need to monkey-patch the library, adding in an alternative print() global:import http.clientimport logginghttp_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 implementationhttp.client.print = print_to_logWith the above http.client trick applied and setup_logging(logging.DEBUG), I see the following logs appear both on stdout and in the file when I use requests.get("https://stackoverflow.com/a/58769712/100297"):2019-11-08 16:17:26 [MainThread ] [DEBUG] Starting new HTTPS connection (1): stackoverflow.com:4432019-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: private2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Content-Type: text/html; charset=utf-82019-11-08 16:17:27 [MainThread ] [DEBUG] header: Location: /questions/58738195/python-http-request-and-debug-level-logging-to-the-log-file/58769712#587697122019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Frame-Options: SAMEORIGIN2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Request-Guid: 761bd2f8-3e5c-453a-ab46-d012849405412019-11-08 16:17:27 [MainThread ] [DEBUG] header: Strict-Transport-Security: max-age=155520002019-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.com2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Accept-Ranges: bytes2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Age: 02019-11-08 16:17:27 [MainThread ] [DEBUG] header: Content-Length: 2142019-11-08 16:17:27 [MainThread ] [DEBUG] header: Accept-Ranges: bytes2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Date: Fri, 08 Nov 2019 16:17:27 GMT2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Via: 1.1 varnish2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Age: 02019-11-08 16:17:27 [MainThread ] [DEBUG] header: Connection: keep-alive2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Served-By: cache-lhr7324-LHR2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Cache: MISS2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Cache-Hits: 02019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Timer: S1573229847.069848,VS0,VE802019-11-08 16:17:27 [MainThread ] [DEBUG] header: Vary: Fastly-SSL2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-DNS-Prefetch-Control: off2019-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=/; HttpOnly2019-11-08 16:17:27 [MainThread ] [DEBUG] https://stackoverflow.com:443 "GET /a/58769712/100297 HTTP/1.1" 302 2142019-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: private2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Content-Type: text/html; charset=utf-82019-11-08 16:17:27 [MainThread ] [DEBUG] header: Content-Encoding: gzip2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Last-Modified: Fri, 08 Nov 2019 16:16:07 GMT2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Frame-Options: SAMEORIGIN2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Request-Guid: 5e48399e-a91c-44aa-aad6-00a96014131f2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Strict-Transport-Security: max-age=155520002019-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.com2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Accept-Ranges: bytes2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Age: 02019-11-08 16:17:27 [MainThread ] [DEBUG] header: Content-Length: 426252019-11-08 16:17:27 [MainThread ] [DEBUG] header: Accept-Ranges: bytes2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Date: Fri, 08 Nov 2019 16:17:27 GMT2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Via: 1.1 varnish2019-11-08 16:17:27 [MainThread ] [DEBUG] header: Age: 02019-11-08 16:17:27 [MainThread ] [DEBUG] header: Connection: keep-alive2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Served-By: cache-lhr7324-LHR2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Cache: MISS2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Cache-Hits: 02019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-Timer: S1573229847.189349,VS0,VE952019-11-08 16:17:27 [MainThread ] [DEBUG] header: Vary: Accept-Encoding,Fastly-SSL2019-11-08 16:17:27 [MainThread ] [DEBUG] header: X-DNS-Prefetch-Control: off2019-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 42625You can reproduce this with a file with:import requestsimport syslogPath, logFileName = "/tmp", "demo"level = logging.DEBUG if "-v" in sys.argv else Nonesetup_logging(level)requests.get("https://stackoverflow.com/a/58769712/100297")added in addition to the code above. You can then use python <script.py> -v to set the level to verbose and compare that to python <script.py> with the level not set at all. 这篇关于Python HTTP请求和调试级别日志记录到日志文件的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持！ 1403页，肝出来的..