def log(monkeypatch, request):
"""Fixture providing access to captured structlog events. Interesting attributes:
``log.events`` a list of dicts, contains any events logged during the test
``log.has`` a helper method, return a bool for making simple assertions
Example usage: ``assert log.has("some message", var1="extra context")``
"""
# save settings for later
original_processors = structlog.get_config().get("processors", [])
# redirect logging to log capture
cap = StructuredLogCapture()
for processor in original_processors:
if isinstance(processor,
structlog.stdlib.PositionalArgumentsFormatter):
# if there was a positional argument formatter in there, keep it there
# see https://github.com/wimglenn/pytest-structlog/issues/18
new_processors = [processor, cap.process]
break
else:
new_processors = [cap.process]
structlog.configure(processors=new_processors,
cache_logger_on_first_use=False)
cap.original_configure = configure = structlog.configure
cap.configure_once = structlog.configure_once
monkeypatch.setattr("structlog.configure", no_op)
monkeypatch.setattr("structlog.configure_once", no_op)
request.node.structlog_events = cap.events
yield cap
# back to original behavior
configure(processors=original_processors)
def inject_request_id_header(headers):
try:
headers[constants.REQUEST_HEADER] = str(
structlog.get_config()["context_class"]._tl.dict_["request_id"]
)
except Exception as e:
headers[constants.REQUEST_HEADER] = str(uuid.uuid4())
def filter(self, record):
try:
record.request_id = str(
structlog.get_config()["context_class"]._tl.dict_["request_id"]
)
except :
record.request_id=str(uuid.uuid4())
return True
def inject_context(logger, method_name, event_dict):
# inject current structlog context to stdlib logger calls from dependencies
context_class = structlog.get_config().get("context_class")
if context_class:
context = context_class()
# context object is not always subscriptable, so create list of kv pairs instead
kv_pairs = [(k, context.get(k)) for k in context.keys()]
event_dict.update(kv_pairs)
return event_dict
def test_flask_corelation_middleware():
envoirn = {}
envoirn[HTTP_REQUEST_HEADER] = '12345'
start_reposne = Mock()
mocked_app = Mock()
mocked_app.__call__ = mocked_fucntion.__call__
flask_middleware = FlaskCorelationMiddleWare(mocked_app)
flask_middleware(envoirn, start_reposne)
request_id = structlog.get_config()["context_class"]._tl.dict_["request_id"]
assert request_id == '12345'
def get_structlog_captured_logs(
) -> Union[List[MutableMapping[str, Any]], List[LogType]]:
structlog_caplog = structlog.testing.LogCapture()
orig_processors = structlog.get_config()["processors"]
patched_procs = orig_processors.copy()
patched_procs.insert(-1, structlog_caplog)
structlog.configure(processors=patched_procs)
for log_msg in random_log_msgs:
structlog_sentry_logger.get_logger().debug(log_msg)
structlog.configure(processors=orig_processors)
captured_logs = structlog_caplog.entries
assert captured_logs
return captured_logs
def setup_logging(args):
"""Set up logging."""
cfg = structlog.get_config()
cfg['processors'].append(render_logs)
logging.basicConfig(
stream=sys.stdout,
level=(logging.DEBUG
if hasattr(args, 'debug') and args.debug else logging.INFO),
format='%(message)s',
)
# silence 'asyncio' logging
logging.getLogger('asyncio').propagate = False
def test_get_config_is_configured(self):
"""
Return value of structlog.get_config() works as input for
structlog.configure(). is_configured() reflects the state of
configuration.
"""
assert False is structlog.is_configured()
structlog.configure(**structlog.get_config())
assert True is structlog.is_configured()
structlog.reset_defaults()
assert False is structlog.is_configured()
def test_get_config_is_configured(self):
"""
Return value of structlog.get_config() works as input for
structlog.configure(). is_configured() reflects the state of
configuration.
"""
assert False is structlog.is_configured()
structlog.configure(**structlog.get_config())
assert True is structlog.is_configured()
structlog.reset_defaults()
assert False is structlog.is_configured()
def _inject_header(wrapped, instance, args, kwargs):
if "type" in args[0] and args[0]["type"] == "worker-heartbeat":
return wrapped(*args, **kwargs)
if "headers" in kwargs:
headers = kwargs["headers"]
else:
headers = {}
try:
headers[constants.REQUEST_HEADER] = str(
structlog.get_config()["context_class"]._tl.dict_["request_id"])
except Exception as e:
headers[constants.REQUEST_HEADER] = str(uuid.uuid4())
kwargs["headers"] = headers
return wrapped(*args, **kwargs)
def disable_logging():
"""
Turn off logging within the if-block
Used for repetitive environment setup that makes test errors too verbose.
"""
original_processors = structlog.get_config()["processors"]
def swallow_log(_logger, _log_method, _event_dict):
raise DropEvent
structlog.configure(processors=[swallow_log])
try:
yield
finally:
structlog.configure(processors=original_processors)
def fixture_logger():
"""Modify `capture_logs` to keep reference to `processors` list intact,
in order to also modify bound loggers which get the list assigned by reference.
See https://github.com/hynek/structlog/issues/408
"""
cap = structlog.testing.LogCapture()
# Modify `_Configuration.default_processors` set via `configure` but always keep
# the list instance intact to not break references held by bound loggers.
processors = structlog.get_config()["processors"]
old_processors = processors[:] # copy original processors
try:
processors.clear() # clear processors list
processors.append(cap) # append the LogCapture processor for testing
structlog.configure(processors=processors)
yield cap
finally:
processors.clear() # remove LogCapture
processors.extend(old_processors) # restore original processors
structlog.configure(processors=processors)
def log(monkeypatch):
"""Fixture providing access to captured structlog events. Interesting attributes:
``log.events`` a list of dicts, contains any events logged during the test
``log.has`` a helper method, return a bool for making simple assertions
Example usage: ``assert log.has("some message", var1="extra context")``
"""
# save settings for later
processors = structlog.get_config().get("processors", [])
configure = structlog.configure
# redirect logging to log capture
cap = StructuredLogCapture()
structlog.configure(processors=[cap.process],
cache_logger_on_first_use=False)
monkeypatch.setattr("structlog.configure", no_op)
monkeypatch.setattr("structlog.configure_once", no_op)
yield cap
# back to normal behavior
configure(processors=processors)
def test_flask_corelation_middleware():
request = Mock()
request.headers = {}
request.META = {
HTTP_REQUEST_HEADER: "12345",
"HTTP_PROFILE_ID": "123",
"REQUEST_METHOD": "POST",
"HTTP_OPERATING_SYSTEM_VERSION": "ICE CREAM",
"HTTP_PLATFORM": "ANDROID",
"HTTP_APP_VERSION": "1.0.0",
"HTTP_USER_AGENT": "AUTOMATED TEST"
}
request.path = '/testURL/'
request.session = {}
mocked_self_resposne = Mock()
mocked_self_resposne.__call__ = mocked_fucntion.__call__
django_middleware = DjangoCorelationMiddleware(mocked_self_resposne)
django_middleware(request)
request_id = structlog.get_config(
)["context_class"]._tl.dict_["request_id"]
assert request_id == '12345'
def test_bind_request_id_on_message_receive(mocker):
wrapped = Mock()
instance = Mock()
wrapped.__call__ = mocked_function.__call__
args0 = {}
kwargs = {}
args = [args0]
mocker.patch("uuid.uuid4", return_value="12345")
structlog.configure(
processors=[
structlog.processors.TimeStamper(fmt="ISO"),
structlog.processors.JSONRenderer(),
],
context_class=structlog.threadlocal.wrap_dict(dict),
wrapper_class=structlog.stdlib.BoundLogger,
cache_logger_on_first_use=True,
)
_bind_request_id_on_message_receive(wrapped, instance, args, kwargs)
request_id = structlog.get_config(
)["context_class"]._tl.dict_["request_id"]
assert request_id == '12345'
def test_auto_ecs_logging(elasticapm_client_log_file):
logger = logging.getLogger()
assert isinstance(logger.handlers[0].formatter, ecs_logging.StdlibFormatter)
assert isinstance(structlog.get_config()["processors"][-1], ecs_logging.StructlogFormatter)
def fix_arsenic_log():
processors = structlog.get_config().get("processors", [])
processors.insert(0, DictTrimmerProcessor())
structlog.configure(processors=processors)
def get_active_procs(self):
return get_config()["processors"]
def inject_context_dict(_, __, event_dict):
"""Add the structlog context dict to log events generated by the stdlib logging library.
>>> import structlog
>>> from django_structlog.processors import inject_context_dict
>>>
>>> LOGGING = {
... "version": 1,
... "disable_existing_loggers": False,
... "formatters": {
... "json_formatter": {
... "()": structlog.stdlib.ProcessorFormatter,
... "processor": structlog.processors.JSONRenderer(),
... # ADD THIS SECTION
... "foreign_pre_chain": [
... inject_context_dict,
... structlog.processors.TimeStamper(fmt="iso"),
... structlog.stdlib.add_logger_name,
... structlog.stdlib.add_log_level,
... structlog.stdlib.PositionalArgumentsFormatter(),
... ],
... },
... },
... "handlers": {
... "json_file": {
... "class": "logging.handlers.WatchedFileHandler",
... "filename": "logs/json.log",
... "formatter": "json_formatter",
... }
... },
... "loggers": {
... "django_structlog": {
... "handlers": ["json_file"],
... "level": "INFO",
... },
... # ADD THE STANDARD LOGGERS NAMES
... "foreign_logger": {
... "handlers": ["json_file"],
... "level": "INFO",
... },
... },
... }
>>>
Logging with a standard logger:
>>> import logging
>>> logging.getLogger("foreign_logger").info("This is a standard logger")
Results::
{
"event": "This is a standard logger",
"request_id": "da006c53-abdc-4b26-961d-e45f85152029",
"user_id": null,
"ip": "0.0.0.0",
"timestamp": "2020-11-27T03:06:37.335676Z",
"logger": "foreign_logger",
"level": "info"
}
"""
context_class = structlog.get_config().get("context_class")
if context_class:
for key, value in context_class().items():
if key not in event_dict:
event_dict[key] = value
return event_dict
