From d96fa9fcff8e0fe049b145d2a87903e247cd8522 Mon Sep 17 00:00:00 2001 From: Mark Bidewell Date: Thu, 20 Apr 2023 22:45:35 -0400 Subject: [PATCH 1/5] Convert Access Log Generator to use Python logging --- daphne/access.py | 58 +++++++++++++++++++++++++++++------------------- daphne/cli.py | 8 ++++--- 2 files changed, 40 insertions(+), 26 deletions(-) diff --git a/daphne/access.py b/daphne/access.py index e18138ad..f0c48df0 100644 --- a/daphne/access.py +++ b/daphne/access.py @@ -1,5 +1,7 @@ import datetime +import logging +logger = logging.getLogger(__name__) class AccessLogGenerator: """ @@ -8,7 +10,16 @@ class AccessLogGenerator: """ def __init__(self, stream): - self.stream = stream + if stream: + logger.propagate = False + handler = logging.StreamHandler(stream) + formatter = logging.Formatter('%(host)s %(ident)s %(user)s [%(asctime)s] "%{request} %(message)s" ' + '%(status)s %(length)s' + "%d/%b/%Y:%H:%M:%S") + handler.setFormatter(fmt=formatter) + logger.addHandler(handler) + else: + logger.addHandler(logging.NullHandler) def __call__(self, protocol, action, details): """ @@ -18,8 +29,8 @@ def __call__(self, protocol, action, details): if protocol == "http" and action == "complete": self.write_entry( host=details["client"], - date=datetime.datetime.now(), - request="%(method)s %(path)s" % details, + request="%(method)s", + details="%(path)s" % details, status=details["status"], length=details["size"], ) @@ -27,44 +38,45 @@ def __call__(self, protocol, action, details): elif protocol == "websocket" and action == "connecting": self.write_entry( host=details["client"], - date=datetime.datetime.now(), - request="WSCONNECTING %(path)s" % details, + request="WSCONNECTING", + details="%(path)s" % details, ) elif protocol == "websocket" and action == "rejected": self.write_entry( host=details["client"], - date=datetime.datetime.now(), - request="WSREJECT %(path)s" % details, + request="WSREJECT", + details="%(path)s" % details, ) elif protocol == "websocket" and action == "connected": self.write_entry( host=details["client"], - date=datetime.datetime.now(), - request="WSCONNECT %(path)s" % details, + request="WSCONNECT", + details="%(path)s" % details, ) elif protocol == "websocket" and action == "disconnected": self.write_entry( host=details["client"], - date=datetime.datetime.now(), - request="WSDISCONNECT %(path)s" % details, + request="WSDISCONNECT", + details="%(path)s" % details, ) def write_entry( - self, host, date, request, status=None, length=None, ident=None, user=None + self, host, request, details, status=None, length=None, ident=None, user=None ): """ Writes an NCSA-style entry to the log file (some liberty is taken with what the entries are for non-HTTP) """ - self.stream.write( - '%s %s %s [%s] "%s" %s %s\n' - % ( - host, - ident or "-", - user or "-", - date.strftime("%d/%b/%Y:%H:%M:%S"), - request, - status or "-", - length or "-", - ) + + logger.info( + f"{request} {details}", + extra={ + "host": host, + "request": request, + "details": details, + "ident": ident or "-", + "user": user or "-", + "status": status or "-", + "length": length or "-", + } ) diff --git a/daphne/cli.py b/daphne/cli.py index a036821c..72a9d4f1 100755 --- a/daphne/cli.py +++ b/daphne/cli.py @@ -228,6 +228,8 @@ def run(self, args): elif args.verbosity >= 1: access_log_stream = sys.stdout + access_logger = AccessLogGenerator(access_log_stream) if access_log_stream else None + # Import application sys.path.insert(0, ".") application = import_by_path(args.application) @@ -270,9 +272,9 @@ def run(self, args): websocket_connect_timeout=args.websocket_connect_timeout, websocket_handshake_timeout=args.websocket_connect_timeout, application_close_timeout=args.application_close_timeout, - action_logger=( - AccessLogGenerator(access_log_stream) if access_log_stream else None - ), + action_logger=access_logger + if access_log_stream + else None, root_path=args.root_path, verbosity=args.verbosity, proxy_forwarded_address_header=self._get_forwarded_host(args=args), From a1ae539fc17f8ffd3ae244a4512018fb83d2008c Mon Sep 17 00:00:00 2001 From: "pre-commit-ci[bot]" <66853113+pre-commit-ci[bot]@users.noreply.github.com> Date: Mon, 24 Apr 2023 01:25:18 +0000 Subject: [PATCH 2/5] [pre-commit.ci] auto fixes from pre-commit.com hooks for more information, see https://pre-commit.ci --- daphne/access.py | 11 +++++++---- daphne/cli.py | 8 ++++---- 2 files changed, 11 insertions(+), 8 deletions(-) diff --git a/daphne/access.py b/daphne/access.py index f0c48df0..5aea5bb5 100644 --- a/daphne/access.py +++ b/daphne/access.py @@ -3,6 +3,7 @@ logger = logging.getLogger(__name__) + class AccessLogGenerator: """ Object that implements the Daphne "action logger" internal interface in @@ -13,9 +14,11 @@ def __init__(self, stream): if stream: logger.propagate = False handler = logging.StreamHandler(stream) - formatter = logging.Formatter('%(host)s %(ident)s %(user)s [%(asctime)s] "%{request} %(message)s" ' - '%(status)s %(length)s' - "%d/%b/%Y:%H:%M:%S") + formatter = logging.Formatter( + '%(host)s %(ident)s %(user)s [%(asctime)s] "%{request} %(message)s" ' + "%(status)s %(length)s" + "%d/%b/%Y:%H:%M:%S" + ) handler.setFormatter(fmt=formatter) logger.addHandler(handler) else: @@ -78,5 +81,5 @@ def write_entry( "user": user or "-", "status": status or "-", "length": length or "-", - } + }, ) diff --git a/daphne/cli.py b/daphne/cli.py index 72a9d4f1..652a9724 100755 --- a/daphne/cli.py +++ b/daphne/cli.py @@ -228,7 +228,9 @@ def run(self, args): elif args.verbosity >= 1: access_log_stream = sys.stdout - access_logger = AccessLogGenerator(access_log_stream) if access_log_stream else None + access_logger = ( + AccessLogGenerator(access_log_stream) if access_log_stream else None + ) # Import application sys.path.insert(0, ".") @@ -272,9 +274,7 @@ def run(self, args): websocket_connect_timeout=args.websocket_connect_timeout, websocket_handshake_timeout=args.websocket_connect_timeout, application_close_timeout=args.application_close_timeout, - action_logger=access_logger - if access_log_stream - else None, + action_logger=access_logger if access_log_stream else None, root_path=args.root_path, verbosity=args.verbosity, proxy_forwarded_address_header=self._get_forwarded_host(args=args), From c741811deb76cc73dc31a8995bb5b248e51a16b6 Mon Sep 17 00:00:00 2001 From: Mark Bidewell Date: Sun, 23 Apr 2023 21:40:08 -0400 Subject: [PATCH 3/5] Linting and warning fixes --- daphne/access.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/daphne/access.py b/daphne/access.py index 5aea5bb5..8377ad50 100644 --- a/daphne/access.py +++ b/daphne/access.py @@ -1,4 +1,3 @@ -import datetime import logging logger = logging.getLogger(__name__) @@ -72,7 +71,9 @@ def write_entry( """ logger.info( - f"{request} {details}", + "%s %s", + request, + details, extra={ "host": host, "request": request, From eb820e3fed7de7e32c0041c3f13da8b0619a5e5f Mon Sep 17 00:00:00 2001 From: mbidewell Date: Sun, 5 Jan 2025 21:50:21 -0500 Subject: [PATCH 4/5] Fix logging formmatting bugs and syntax errors --- daphne/access.py | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/daphne/access.py b/daphne/access.py index 8377ad50..9f6122ff 100644 --- a/daphne/access.py +++ b/daphne/access.py @@ -14,14 +14,13 @@ def __init__(self, stream): logger.propagate = False handler = logging.StreamHandler(stream) formatter = logging.Formatter( - '%(host)s %(ident)s %(user)s [%(asctime)s] "%{request} %(message)s" ' - "%(status)s %(length)s" + '%(host)s %(ident)s %(user)s [%(asctime)s] "%(message)s" ' + "%(status)s %(length)s", "%d/%b/%Y:%H:%M:%S" ) handler.setFormatter(fmt=formatter) logger.addHandler(handler) - else: - logger.addHandler(logging.NullHandler) + def __call__(self, protocol, action, details): """ @@ -31,7 +30,7 @@ def __call__(self, protocol, action, details): if protocol == "http" and action == "complete": self.write_entry( host=details["client"], - request="%(method)s", + request="%(method)s" % details, details="%(path)s" % details, status=details["status"], length=details["size"], @@ -66,8 +65,9 @@ def write_entry( self, host, request, details, status=None, length=None, ident=None, user=None ): """ - Writes an NCSA-style entry to the log file (some liberty is taken with - what the entries are for non-HTTP) + Writes an access log. If a file is specified, an NCSA-style entry to the log file + (some liberty is taken with what the entries are for non-HTTP). The format can be + overriden with logging configuration for 'daphne.access' """ logger.info( From 8cb79b421701e949f255237c53da3a11970bb1d3 Mon Sep 17 00:00:00 2001 From: "pre-commit-ci[bot]" <66853113+pre-commit-ci[bot]@users.noreply.github.com> Date: Mon, 6 Jan 2025 02:50:32 +0000 Subject: [PATCH 5/5] [pre-commit.ci] auto fixes from pre-commit.com hooks for more information, see https://pre-commit.ci --- daphne/access.py | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) diff --git a/daphne/access.py b/daphne/access.py index 9f6122ff..7e730ca6 100644 --- a/daphne/access.py +++ b/daphne/access.py @@ -16,12 +16,11 @@ def __init__(self, stream): formatter = logging.Formatter( '%(host)s %(ident)s %(user)s [%(asctime)s] "%(message)s" ' "%(status)s %(length)s", - "%d/%b/%Y:%H:%M:%S" + "%d/%b/%Y:%H:%M:%S", ) handler.setFormatter(fmt=formatter) logger.addHandler(handler) - def __call__(self, protocol, action, details): """ Called when an action happens; use it to generate log entries. @@ -65,8 +64,8 @@ def write_entry( self, host, request, details, status=None, length=None, ident=None, user=None ): """ - Writes an access log. If a file is specified, an NCSA-style entry to the log file - (some liberty is taken with what the entries are for non-HTTP). The format can be + Writes an access log. If a file is specified, an NCSA-style entry to the log file + (some liberty is taken with what the entries are for non-HTTP). The format can be overriden with logging configuration for 'daphne.access' """