Раис Юсупалиев
131 lines
3.7 KiB
Python
131 lines
3.7 KiB
Python
import json
|
|
import logging
|
|
from io import StringIO
|
|
|
|
import structlog
|
|
from opentelemetry import trace
|
|
from opentelemetry.trace import NonRecordingSpan, SpanContext, TraceFlags
|
|
|
|
from app.runtime.logging import configure_logging
|
|
|
|
|
|
def test_application_log_is_serialized_as_json() -> None:
|
|
stream = StringIO()
|
|
|
|
configure_logging(stream=stream)
|
|
|
|
logging.getLogger("app.test").info("application_event")
|
|
|
|
payload = json.loads(stream.getvalue().splitlines()[0])
|
|
|
|
assert payload["event"] == "application_event"
|
|
assert payload["level"] == "info"
|
|
assert payload["logger"] == "app.test"
|
|
assert isinstance(payload["timestamp"], str)
|
|
assert "trace_id" not in payload
|
|
assert "span_id" not in payload
|
|
|
|
_reset_logging()
|
|
|
|
|
|
def test_structured_context_is_preserved_and_rendered_in_event() -> None:
|
|
stream = StringIO()
|
|
|
|
configure_logging(stream=stream)
|
|
|
|
structlog.get_logger("app.test").warning(
|
|
"application_event",
|
|
order_uuid="order-1",
|
|
attempt=2,
|
|
retryable=True,
|
|
details={"code": "invalid"},
|
|
)
|
|
|
|
payload = json.loads(stream.getvalue().splitlines()[0])
|
|
|
|
assert payload["event"] == (
|
|
'application_event attempt=2 details={"code":"invalid"} '
|
|
'order_uuid="order-1" retryable=true'
|
|
)
|
|
assert payload["order_uuid"] == "order-1"
|
|
assert payload["attempt"] == 2
|
|
assert payload["retryable"] is True
|
|
assert payload["details"] == {"code": "invalid"}
|
|
|
|
_reset_logging()
|
|
|
|
|
|
def test_uvicorn_loggers_use_shared_json_logging_setup() -> None:
|
|
stream = StringIO()
|
|
|
|
configure_logging(stream=stream)
|
|
|
|
logging.getLogger("uvicorn.error").error("uvicorn_error_event")
|
|
logging.getLogger("uvicorn.access").info("uvicorn_access_event")
|
|
|
|
records = [json.loads(line) for line in stream.getvalue().splitlines()]
|
|
|
|
assert [record["event"] for record in records] == [
|
|
"uvicorn_error_event",
|
|
"uvicorn_access_event",
|
|
]
|
|
assert [record["logger"] for record in records] == [
|
|
"uvicorn.error",
|
|
"uvicorn.access",
|
|
]
|
|
assert all(record["level"] in {"error", "info"} for record in records)
|
|
assert all(isinstance(record["timestamp"], str) for record in records)
|
|
|
|
_reset_logging()
|
|
|
|
|
|
def test_active_trace_context_is_added_to_structlog_and_standard_logs() -> None:
|
|
stream = StringIO()
|
|
trace_id = 0x1234567890ABCDEF1234567890ABCDEF
|
|
span_id = 0x1234567890ABCDEF
|
|
span = NonRecordingSpan(
|
|
SpanContext(
|
|
trace_id=trace_id,
|
|
span_id=span_id,
|
|
is_remote=False,
|
|
trace_flags=TraceFlags.SAMPLED,
|
|
)
|
|
)
|
|
|
|
configure_logging(stream=stream)
|
|
|
|
with trace.use_span(span, end_on_exit=False):
|
|
structlog.get_logger("app.test").info("structured_event")
|
|
logging.getLogger("app.test").info("standard_event")
|
|
|
|
records = [json.loads(line) for line in stream.getvalue().splitlines()]
|
|
expected_trace_id = "1234567890abcdef1234567890abcdef"
|
|
expected_span_id = "1234567890abcdef"
|
|
|
|
assert [record["trace_id"] for record in records] == [
|
|
expected_trace_id,
|
|
expected_trace_id,
|
|
]
|
|
assert [record["span_id"] for record in records] == [
|
|
expected_span_id,
|
|
expected_span_id,
|
|
]
|
|
assert records[0]["event"] == (
|
|
f'structured_event span_id="{expected_span_id}" '
|
|
f'trace_id="{expected_trace_id}"'
|
|
)
|
|
assert records[1]["event"] == (
|
|
f'standard_event span_id="{expected_span_id}" '
|
|
f'trace_id="{expected_trace_id}"'
|
|
)
|
|
|
|
_reset_logging()
|
|
|
|
|
|
def _reset_logging() -> None:
|
|
structlog.reset_defaults()
|
|
root_logger = logging.getLogger()
|
|
root_logger.handlers = []
|
|
for logger_name in ("uvicorn", "uvicorn.error", "uvicorn.access"):
|
|
logging.getLogger(logger_name).handlers = []
|