bobbui/json-logging-python

Using root logger + flask outside of flask request context throws RuntimeError

ex-nerd opened this issue · 4 comments

I've noticed that I get a RuntimeError: Working outside of application context. if I try to log anything after initializing Flask logs but don't yet have a flask request context.

Replication code is here:

app = Flask("my_app")

logging.basicConfig()

json_logging.init_flask(enable_json=True)
json_logging.init_request_instrument(app)
json_logging.config_root_logger()
logger = logging.getLogger()
logger.setLevel(logging.DEBUG)
logger.info("logging initialized")

This appears to be a bug in json_logging.util.get_correlation_id expecting that "no request" should have a None value but it actually comes back as an "unbound" instance of werkzeug.local.LocalProxy. This fails to match in the check for request is None and results in a call to self.request_adapter.get_correlation_id_in_request_context that triggers the exception. It appears that the unbound LocalProxy resolves to False so checking both request is None or not bool(request) would work around this issue for Flask. I just don't know how that fix would affect other frameworks.

thanks for reporting this, i put in a quick fix on 1.2.9

I updated to 1.2.9 and am still seeing the error. I'm just typing this straight into the python shell:

import logging
import json_logging
from flask import Flask

app = Flask("my_app")

logging.basicConfig()

json_logging.init_flask(enable_json=True)
json_logging.init_request_instrument(app)
json_logging.config_root_logger()
logger = logging.getLogger()
logger.setLevel(logging.DEBUG)
logger.info("logging initialized")

Which results in:

--- Logging error ---
Traceback (most recent call last):
  File "/path/to/userhome/.pyenv/versions/3.7.8/lib/python3.7/logging/__init__.py", line 1025, in emit
    msg = self.format(record)
  File "/path/to/userhome/.pyenv/versions/3.7.8/lib/python3.7/logging/__init__.py", line 869, in format
    return fmt.format(record)
  File "/path/to/venv/python-3.7.8/lib/python3.7/site-packages/json_logging/__init__.py", line 243, in format
    log_object = self._format_log_object(record, request_util=_request_util)
  File "/path/to/venv/python-3.7.8/lib/python3.7/site-packages/json_logging/__init__.py", line 341, in _format_log_object
    "correlation_id": request_util.get_correlation_id(within_formatter=True),
  File "/path/to/venv/python-3.7.8/lib/python3.7/site-packages/json_logging/util.py", line 147, in get_correlation_id
    correlation_id = self._get_correlation_id_in_request_header(self.request_adapter, request)
  File "/path/to/venv/python-3.7.8/lib/python3.7/site-packages/json_logging/util.py", line 203, in _get_correlation_id_in_request_header
    value = request_adapter.get_http_header(request, header)
  File "/path/to/venv/python-3.7.8/lib/python3.7/site-packages/json_logging/framework/flask/__init__.py", line 81, in get_http_header
    if header_name in request.headers:
  File "/path/to/venv/python-3.7.8/lib/python3.7/site-packages/werkzeug/local.py", line 347, in __getattr__
    return getattr(self._get_current_object(), name)
  File "/path/to/venv/python-3.7.8/lib/python3.7/site-packages/werkzeug/local.py", line 306, in _get_current_object
    return self.__local()
  File "/path/to/venv/python-3.7.8/lib/python3.7/site-packages/flask/globals.py", line 38, in _lookup_req_object
    raise RuntimeError(_request_ctx_err_msg)
RuntimeError: Working outside of request context.

This typically means that you attempted to use functionality that needed
an active HTTP request.  Consult the documentation on testing for
information about how to avoid this problem.
Call stack:
  File "<stdin>", line 1, in <module>
Message: 'logging initialized'
Arguments: ()

my bad, fix it again with 1.2.10

Sweet, that now works. :)