From 6a74393f95d27a80850dd0963ed3fa600332995f Mon Sep 17 00:00:00 2001
From: Matt Riedemann <mriedem@ibm.com>
Date: Fri, 9 Oct 2020 15:09:54 -0500
Subject: [PATCH] Pass NotebookApp logger to log_request

In order to use the same logger from the notebook app we
need to pass it through to the log_request function. To
do that we need to use a partial function so the `log` kwarg
is available. If not provided the default logger is the same
as before, the tornado web access logger.

This is necessary for the `log_json` settings to be used for
both the notebook app logs and the web app request logging.

There is still a todo needed here so that the individual
request fields get formatted separately rather than dumped
into the `msg` field.
---
 notebook/log.py         | 27 ++++++++++-----------------
 notebook/notebookapp.py |  5 ++++-
 2 files changed, 14 insertions(+), 18 deletions(-)

diff --git a/notebook/log.py b/notebook/log.py
index d81a8ea66..46cd93585 100644
--- a/notebook/log.py
+++ b/notebook/log.py
@@ -9,12 +9,8 @@ import json
 from tornado.log import access_log
 from .prometheus.log_functions import prometheus_log_method
 
-from .utils import enable_json_logs
 
-_enable_json_logs = enable_json_logs()
-
-
-def log_request(handler):
+def log_request(handler, log=access_log):
     """log a bit more information about each request than tornado's default
     
     - move static file get success to debug-level (reduces noise)
@@ -26,15 +22,15 @@ def log_request(handler):
     request = handler.request
     if status < 300 or status == 304:
         # Successes (or 304 FOUND) are debug-level
-        log_method = access_log.debug
+        log_method = log.debug
     elif status < 400:
-        log_method = access_log.info
+        log_method = log.info
     elif status < 500:
-        log_method = access_log.warning
+        log_method = log.warning
     else:
-        log_method = access_log.error
+        log_method = log.error
     
-    request_time = 1000.0 * handler.request.request_time()
+    request_time = 1000.0 * request.request_time()
     ns = dict(
         status=status,
         method=request.method,
@@ -50,11 +46,8 @@ def log_request(handler):
     if status >= 500 and status != 502:
         # log all headers if it caused an error
         log_method(json.dumps(dict(request.headers), indent=2))
-    if _enable_json_logs:
-        # FIXME: this still logs the msg as a serialized json string,
-        # presumably because it's using tornado's access_log rather than
-        # the logger setup in notebook app with _log_formatter_cls.
-        log_method(ns)
-    else:
-        log_method(msg.format(**ns))
+    # if _enable_json_logs:
+    #     log_method(ns)
+    # else:
+    log_method(msg.format(**ns))
     prometheus_log_method(handler)
diff --git a/notebook/notebookapp.py b/notebook/notebookapp.py
index 7359f23ad..6920866be 100755
--- a/notebook/notebookapp.py
+++ b/notebook/notebookapp.py
@@ -11,6 +11,7 @@ import asyncio
 import binascii
 import datetime
 import errno
+import functools
 import gettext
 import hashlib
 import hmac
@@ -251,9 +252,11 @@ class NotebookWebApplication(web.Application):
             # collapse $HOME to ~
             root_dir = '~' + root_dir[len(home):]
 
+        # Use the NotebookApp logger and its formatting for tornado request logging.
+        log_function = functools.partial(log_request, log=log)
         settings = dict(
             # basics
-            log_function=log_request,
+            log_function=log_function,
             base_url=base_url,
             default_url=default_url,
             template_path=template_path,