Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
31 changes: 20 additions & 11 deletions src/aignostics_foundry_core/otel.py
Original file line number Diff line number Diff line change
Expand Up @@ -145,6 +145,13 @@
"CRITICAL": logging.CRITICAL,
}

# Attribute names the stdlib logging framework owns on every LogRecord, plus the two it
# fills in later (``message`` via ``getMessage()``, ``asctime`` via a formatter). Computed
# from a real LogRecord so it tracks whatever this Python version actually populates.
_RESERVED_LOG_RECORD_ATTRS = frozenset(
logging.LogRecord(name="", level=0, pathname="", lineno=0, msg="", args=None, exc_info=None).__dict__
) | {"message", "asctime"}


class OTelSettings(OpaqueSettings):
"""Configuration settings for OpenTelemetry integration.
Expand Down Expand Up @@ -589,18 +596,20 @@ def sink(message: Message) -> None:
if record["exception"] is not None:
exc = record["exception"]
exc_info = (exc.type, exc.value, exc.traceback)
handler.emit(
logging.LogRecord(
name=record["name"] or "",
level=_LOGURU_TO_STDLIB_LEVEL.get(record["level"].name, logging.INFO),
pathname=record["file"].path,
lineno=record["line"],
msg=record["message"],
args=None,
exc_info=exc_info, # pyright: ignore[reportArgumentType]
func=record["function"],
)
log_record = logging.LogRecord(
name=record["name"] or "",
level=_LOGURU_TO_STDLIB_LEVEL.get(record["level"].name, logging.INFO),
pathname=record["file"].path,
lineno=record["line"],
msg=record["message"],
args=None,
exc_info=exc_info, # pyright: ignore[reportArgumentType]
func=record["function"],
)
log_record.__dict__.update({
key: value for key, value in record["extra"].items() if key not in _RESERVED_LOG_RECORD_ATTRS
})
handler.emit(log_record)

return sink

Expand Down
68 changes: 67 additions & 1 deletion tests/aignostics_foundry_core/otel_test.py
Original file line number Diff line number Diff line change
Expand Up @@ -434,8 +434,13 @@ def _make_loguru_message(
level_name: str = "INFO",
message: str = "hello",
exception: object = None,
extra: dict[str, object] | None = None,
) -> MagicMock:
"""Build a minimal fake loguru Message with a `.record` dict for sink tests."""
"""Build a minimal fake loguru Message with a `.record` dict for sink tests.

Real loguru records always carry an ``extra`` dict (empty unless fields are
bound via ``logger.bind(...)``), so it is always present here too.
"""
level = MagicMock()
level.name = level_name
file_ = MagicMock()
Expand All @@ -449,10 +454,26 @@ def _make_loguru_message(
"message": message,
"function": "my_func",
"exception": exception,
"extra": extra if extra is not None else {},
}
return msg


_BOUND_FIELD_KEY = "job_id"
_BOUND_FIELD_VALUE = "abc"


def _make_wired_otel_log_handler() -> tuple[object, object]:
"""Build a real OTel LoggingHandler wired to an in-memory exporter."""
from opentelemetry.sdk._logs import LoggerProvider, LoggingHandler
from opentelemetry.sdk._logs.export import InMemoryLogRecordExporter, SimpleLogRecordProcessor

exporter = InMemoryLogRecordExporter()
provider = LoggerProvider()
provider.add_log_record_processor(SimpleLogRecordProcessor(exporter))
return LoggingHandler(level=logging.NOTSET, logger_provider=provider), exporter


@pytest.mark.unit
class TestMakeOtelLogSink:
"""Behavioural tests for _make_otel_log_sink()."""
Expand Down Expand Up @@ -502,6 +523,51 @@ def test_sink_includes_exc_info_when_exception_present(self) -> None:
assert record.exc_info is not None
assert record.exc_info[1] is exc_value

def test_otel_log_sink_forwards_bound_extras(self) -> None:
"""A field bound via logger.bind() lands as its own top-level OTLP attribute."""
handler, exporter = _make_wired_otel_log_handler()
sink = _make_otel_log_sink(handler) # pyright: ignore[reportArgumentType]

sink(_make_loguru_message(extra={_BOUND_FIELD_KEY: _BOUND_FIELD_VALUE}))

finished = exporter.get_finished_logs() # pyright: ignore[reportAttributeAccessIssue]
assert len(finished) == 1
attributes = finished[0].log_record.attributes
assert attributes[_BOUND_FIELD_KEY] == _BOUND_FIELD_VALUE
assert "extra" not in attributes

def test_otel_log_sink_without_extras_still_emits(self) -> None:
"""A record with no bound extras emits cleanly with its standard fields intact."""
handler, exporter = _make_wired_otel_log_handler()
sink = _make_otel_log_sink(handler) # pyright: ignore[reportArgumentType]

sink(_make_loguru_message(message="no bound fields"))

finished = exporter.get_finished_logs() # pyright: ignore[reportAttributeAccessIssue]
assert len(finished) == 1
assert finished[0].log_record.body == "no bound fields"

def test_otel_log_sink_extra_does_not_clobber_reserved_fields(self) -> None:
"""A bound key colliding with a reserved LogRecord attribute is ignored, not applied."""
handler, exporter = _make_wired_otel_log_handler()
sink = _make_otel_log_sink(handler) # pyright: ignore[reportArgumentType]

sink(
_make_loguru_message(
level_name="WARNING",
message="real message",
extra={"message": "hijacked", "levelname": "BOGUS"},
)
)

finished = exporter.get_finished_logs() # pyright: ignore[reportAttributeAccessIssue]
assert len(finished) == 1
log_record = finished[0].log_record
assert log_record.body == "real message"
# OTel maps stdlib "WARNING" to the shortened "WARN"; had the bound "levelname"
# been applied, severity_text would read "BOGUS" instead.
assert log_record.severity_text == "WARN"


@pytest.mark.unit
class TestOtelLogSinkFilter:
Expand Down
Loading