Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add support for JSON formatted logs #5799

Merged
merged 13 commits into from
Oct 14, 2020
Merged
12 changes: 11 additions & 1 deletion notebook/log.py
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,10 @@
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):
"""log a bit more information about each request than tornado's default
Expand Down Expand Up @@ -46,5 +50,11 @@ 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))
mriedem marked this conversation as resolved.
Show resolved Hide resolved
log_method(msg.format(**ns))
if _enable_json_logs:
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just because this is true doesn't mean that json-logging is installed. If it's not, the request log line ends up looking like this:

[W 17:04:57.097 NotebookApp] {'status': 404, 'method': 'GET', 'ip': '127.0.0.1', 'uri': '/nbextensions/widgets/notebook/js/extension.js', 'request_time': 6.743431091308594, 'referer': 'http://localhost:8888/notebooks/Untitled.ipynb?kernel_name=python3'}

Also note that with the json logging we're not formatting the request time to 2 decimal places:

'request_time': 6.743431091308594

# FIXME: this still logs the msg as a serialized json string,
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wonder if we could use a partial to pass log in here:

log_function=log_request,

Because that'd be the NotebookApp logger which is using our json log formatter.

# 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))
prometheus_log_method(handler)
18 changes: 17 additions & 1 deletion notebook/notebookapp.py
Original file line number Diff line number Diff line change
Expand Up @@ -113,6 +113,7 @@
from ._tz import utcnow, utcfromtimestamp
from .utils import (
check_pid,
enable_json_logs,
mriedem marked this conversation as resolved.
Show resolved Hide resolved
pathname2url,
run_sync,
unix_socket_in_use,
Expand All @@ -138,6 +139,19 @@
except ImportError:
terminado_available = False

# Tolerate missing json_logging package.
_enable_json_logs = enable_json_logs()
try:
import json_logging
except ImportError:
# If configured for json logs and we can't do it, log a hint.
if _enable_json_logs:
logging.getLogger(__name__).exception(
'Unable to use json logging due to missing packages. '
'Run "pip install notebook[json-logging]" to fix.'
)
_enable_json_logs = False

#-----------------------------------------------------------------------------
# Module globals
#-----------------------------------------------------------------------------
Expand Down Expand Up @@ -702,7 +716,9 @@ class NotebookApp(JupyterApp):
password=(NotebookPasswordApp, NotebookPasswordApp.description.splitlines()[0]),
)

_log_formatter_cls = LogFormatter
# Unless there is a way to re-initialize the log formatter (like with _log_format_changed?)
# we need to load the json logging formatter early here otherwise traitlets complains.
_log_formatter_cls = json_logging.JSONLogFormatter if _enable_json_logs else LogFormatter

@default('log_level')
def _default_log_level(self):
Expand Down
4 changes: 4 additions & 0 deletions notebook/utils.py
Original file line number Diff line number Diff line change
Expand Up @@ -401,3 +401,7 @@ def unix_socket_in_use(socket_path):
return True
finally:
sock.close()


def enable_json_logs():
return os.getenv('ENABLE_JSON_LOGGING', 'false').lower() == 'true'
1 change: 1 addition & 0 deletions setup.py
Original file line number Diff line number Diff line change
Expand Up @@ -120,6 +120,7 @@
'nbval', 'nose-exclude', 'selenium', 'pytest', 'pytest-cov'],
'docs': ['sphinx', 'nbsphinx', 'sphinxcontrib_github_alt', 'sphinx_rtd_theme'],
'test:sys_platform != "win32"': ['requests-unixsocket'],
'json-logging': ['json-logging']
},
python_requires = '>=3.5',
entry_points = {
Expand Down