Skip to content

Commit 29dcbc0

Browse files
committed
feat(logger): add OpenTelemetry-compatible log emission
Add `Logger.emit_log()` so applications can emit independent `type="log"` rows without constructing spans manually. Correlate rows with the active Braintrust or OpenTelemetry context when available. Seed each logger with a baseline trace ID for unscoped logs. This keeps consecutive logs from one logger together while preserving unique row and span IDs, and avoids grouping logs emitted by separate logger instances. Map the six base OpenTelemetry severities into `context.otel.log` and add `trace()`, `debug()`, `info()`, `warn()`, `error()`, and `fatal()` helpers. logger.error("Payment failed", metadata={"payment_id": "pay_123"}) helper -> emit_log -> `type="log"` row |-- active span: reuse trace/span IDs `-- no span: reuse logger trace, generate span ID
1 parent 53b1a18 commit 29dcbc0

5 files changed

Lines changed: 217 additions & 0 deletions

File tree

py/src/braintrust/logger.py

Lines changed: 89 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -131,6 +131,16 @@
131131
# 6 MB for the AWS lambda gateway (from our own testing).
132132
DEFAULT_MAX_REQUEST_SIZE = 6 * 1024 * 1024
133133

134+
LogLevel = Literal["trace", "debug", "info", "warn", "error", "fatal"]
135+
_OTEL_LOG_LEVELS: dict[LogLevel, int] = {
136+
"trace": 1,
137+
"debug": 5,
138+
"info": 9,
139+
"warn": 13,
140+
"error": 17,
141+
"fatal": 21,
142+
}
143+
134144

135145
@dataclasses.dataclass
136146
class Logs3OverflowInputRow:
@@ -5854,6 +5864,7 @@ def __init__(
58545864
# fallbacks when generating links
58555865
self._link_args = link_args
58565866
self.state = state or _state
5867+
self._baseline_trace_id = self.state.id_generator.get_trace_id()
58575868

58585869
@property
58595870
def org_id(self) -> str:
@@ -5932,6 +5943,84 @@ def log(
59325943

59335944
return span.id
59345945

5946+
def emit_log(
5947+
self,
5948+
body: Any,
5949+
level: LogLevel,
5950+
metadata: Metadata | None = None,
5951+
) -> str:
5952+
"""Capture a log record, associating it with the active span when one exists.
5953+
5954+
The log is stored as an independent row. If a Braintrust or OpenTelemetry
5955+
span is active, the row reuses its span and trace IDs for correlation.
5956+
Otherwise, the row uses this logger's baseline trace ID.
5957+
5958+
:param body: The log body. May be any JSON-serializable value.
5959+
:param level: The OpenTelemetry log severity: ``trace``, ``debug``,
5960+
``info``, ``warn``, ``error``, or ``fatal``.
5961+
:param metadata: Optional JSON-serializable attributes for the log.
5962+
:returns: The unique ID of the captured log row.
5963+
"""
5964+
if level not in _OTEL_LOG_LEVELS:
5965+
valid_levels = ", ".join(_OTEL_LOG_LEVELS)
5966+
raise ValueError(f"Invalid log level {level!r}. Expected one of: {valid_levels}")
5967+
5968+
captured_at = time.time()
5969+
span_info = self.state.context_manager.get_current_span_info()
5970+
severity_number = _OTEL_LOG_LEVELS[level]
5971+
span = self._start_span_impl(
5972+
name="Log",
5973+
type=SpanTypeAttribute.LOG,
5974+
start_time=captured_at,
5975+
set_current=False,
5976+
span_id=span_info.span_id if span_info else None,
5977+
root_span_id=span_info.trace_id if span_info else self._baseline_trace_id,
5978+
lookup_span_parent=False,
5979+
output=body,
5980+
error=body if severity_number >= _OTEL_LOG_LEVELS["error"] and isinstance(body, str) else None,
5981+
metadata=metadata,
5982+
context={
5983+
"otel": {
5984+
"signal": "logs",
5985+
"log": {
5986+
"time_unix_nano": str(round(captured_at * 1_000_000_000)),
5987+
"severity_number": severity_number,
5988+
"severity_text": level.upper(),
5989+
},
5990+
}
5991+
},
5992+
)
5993+
span.end(end_time=captured_at)
5994+
5995+
if not self.async_flush:
5996+
self.flush()
5997+
5998+
return span.id
5999+
6000+
def trace(self, body: Any, metadata: Metadata | None = None) -> str:
6001+
"""Capture a log at OpenTelemetry TRACE severity."""
6002+
return self.emit_log(body=body, level="trace", metadata=metadata)
6003+
6004+
def debug(self, body: Any, metadata: Metadata | None = None) -> str:
6005+
"""Capture a log at OpenTelemetry DEBUG severity."""
6006+
return self.emit_log(body=body, level="debug", metadata=metadata)
6007+
6008+
def info(self, body: Any, metadata: Metadata | None = None) -> str:
6009+
"""Capture a log at OpenTelemetry INFO severity."""
6010+
return self.emit_log(body=body, level="info", metadata=metadata)
6011+
6012+
def warn(self, body: Any, metadata: Metadata | None = None) -> str:
6013+
"""Capture a log at OpenTelemetry WARN severity."""
6014+
return self.emit_log(body=body, level="warn", metadata=metadata)
6015+
6016+
def error(self, body: Any, metadata: Metadata | None = None) -> str:
6017+
"""Capture a log at OpenTelemetry ERROR severity."""
6018+
return self.emit_log(body=body, level="error", metadata=metadata)
6019+
6020+
def fatal(self, body: Any, metadata: Metadata | None = None) -> str:
6021+
"""Capture a log at OpenTelemetry FATAL severity."""
6022+
return self.emit_log(body=body, level="fatal", metadata=metadata)
6023+
59356024
def log_feedback(
59366025
self,
59376026
id: str,

py/src/braintrust/otel/test_otel_bt_integration.py

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -122,6 +122,22 @@ def test_mixed_otel_bt_tracing_with_bt_logger_first(otel_fixture):
122122
assert s2_span_id in s3["span_parents"]
123123

124124

125+
def test_emit_log_uses_active_otel_span(otel_fixture):
126+
logger = init_test_logger(__name__)
127+
tracer = otel_fixture.tracer
128+
memory_logger = otel_fixture.memory_logger
129+
130+
with tracer.start_as_current_span("owner") as owner:
131+
log_id = logger.emit_log(body="Inside OTel span", level="info")
132+
owner_context = owner.get_span_context()
133+
134+
[log_row] = memory_logger.pop()
135+
assert log_row["id"] == log_id
136+
assert log_row["span_id"] == format(owner_context.span_id, "016x")
137+
assert log_row["root_span_id"] == format(owner_context.trace_id, "032x")
138+
assert not log_row.get("span_parents")
139+
140+
125141
def test_mixed_otel_bt_tracing_with_experiment_parent(otel_fixture):
126142
experiment = init_test_exp("otel-bt-mixed", "test-mixed-tracing-experiment")
127143
tracer = otel_fixture.tracer

py/src/braintrust/span_types.py

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@ class SpanTypeAttribute(str, Enum):
1818
PREPROCESSOR = "preprocessor"
1919
CLASSIFIER = "classifier"
2020
REVIEW = "review"
21+
LOG = "log"
2122

2223

2324
class SpanPurpose(str, Enum):

py/src/braintrust/test_logger.py

Lines changed: 101 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1396,6 +1396,107 @@ def test_logger_log_accepts_model_dump_metadata(with_memory_logger):
13961396
assert logs[0]["metadata"] == {"foo": "bar"}
13971397

13981398

1399+
def test_logger_emit_log_without_active_span(with_memory_logger):
1400+
test_logger = init_test_logger(__name__)
1401+
1402+
first_id = test_logger.emit_log(
1403+
body="Payment failed",
1404+
level="error",
1405+
metadata={"payment_id": "pay_123"},
1406+
)
1407+
second_id = test_logger.emit_log(body="Retrying payment", level="info")
1408+
1409+
logs = with_memory_logger.pop()
1410+
assert len(logs) == 2
1411+
first, second = logs
1412+
assert first_id == first["id"]
1413+
assert second_id == second["id"]
1414+
assert first["id"] != second["id"]
1415+
assert first["span_id"] != second["span_id"]
1416+
assert first["root_span_id"] == second["root_span_id"]
1417+
assert not first.get("span_parents")
1418+
assert first["output"] == "Payment failed"
1419+
assert first["error"] == "Payment failed"
1420+
assert first["metadata"] == {"payment_id": "pay_123"}
1421+
assert first["span_attributes"]["name"] == "Log"
1422+
assert first["span_attributes"]["type"] == "log"
1423+
assert first["metrics"]["start"] == first["metrics"]["end"]
1424+
assert first["context"]["otel"]["signal"] == "logs"
1425+
assert first["context"]["otel"]["log"] == {
1426+
"time_unix_nano": str(round(first["metrics"]["start"] * 1_000_000_000)),
1427+
"severity_number": 17,
1428+
"severity_text": "ERROR",
1429+
}
1430+
assert "error" not in second
1431+
assert second["context"]["otel"]["log"]["severity_number"] == 9
1432+
1433+
1434+
def test_logger_emit_log_uses_distinct_baseline_trace_per_logger(with_memory_logger):
1435+
first_logger = init_test_logger(f"{__name__}-first")
1436+
second_logger = init_test_logger(f"{__name__}-second")
1437+
1438+
first_logger.info("first")
1439+
second_logger.info("second")
1440+
1441+
first, second = with_memory_logger.pop()
1442+
assert first["root_span_id"] != second["root_span_id"]
1443+
1444+
1445+
def test_logger_emit_log_uses_active_span(with_memory_logger):
1446+
test_logger = init_test_logger(__name__)
1447+
1448+
with test_logger.start_span(name="owner") as owner:
1449+
log_id = test_logger.emit_log(body="Inside span", level="debug", metadata={"attempt": 1})
1450+
1451+
rows = with_memory_logger.pop()
1452+
log_row = next(row for row in rows if row["id"] == log_id)
1453+
owner_row = next(row for row in rows if row["span_attributes"]["name"] == "owner")
1454+
assert log_row["id"] != owner_row["id"]
1455+
assert log_row["span_id"] == owner_row["span_id"]
1456+
assert log_row["root_span_id"] == owner_row["root_span_id"]
1457+
assert not log_row.get("span_parents")
1458+
assert log_row["context"]["otel"]["log"]["severity_number"] == 5
1459+
1460+
1461+
@pytest.mark.parametrize(
1462+
("level", "severity_number"),
1463+
[("trace", 1), ("debug", 5), ("info", 9), ("warn", 13), ("error", 17), ("fatal", 21)],
1464+
)
1465+
def test_logger_emit_log_maps_otel_log_levels(with_memory_logger, level, severity_number):
1466+
test_logger = init_test_logger(__name__)
1467+
1468+
test_logger.emit_log(body="message", level=level)
1469+
1470+
[row] = with_memory_logger.pop()
1471+
assert row["context"]["otel"]["log"]["severity_number"] == severity_number
1472+
assert row["context"]["otel"]["log"]["severity_text"] == level.upper()
1473+
1474+
1475+
@pytest.mark.parametrize(
1476+
("method_name", "severity_number"),
1477+
[("trace", 1), ("debug", 5), ("info", 9), ("warn", 13), ("error", 17), ("fatal", 21)],
1478+
)
1479+
def test_logger_log_level_helpers(with_memory_logger, method_name, severity_number):
1480+
test_logger = init_test_logger(__name__)
1481+
1482+
log_id = getattr(test_logger, method_name)("message", metadata={"source": method_name})
1483+
1484+
[row] = with_memory_logger.pop()
1485+
assert row["id"] == log_id
1486+
assert row["output"] == "message"
1487+
assert row["metadata"] == {"source": method_name}
1488+
assert row["context"]["otel"]["log"]["severity_number"] == severity_number
1489+
1490+
1491+
def test_logger_emit_log_rejects_invalid_level(with_memory_logger):
1492+
test_logger = init_test_logger(__name__)
1493+
1494+
with pytest.raises(ValueError, match="Invalid log level"):
1495+
test_logger.emit_log(body="message", level="warning")
1496+
1497+
assert with_memory_logger.pop() == []
1498+
1499+
13991500
def test_experiment_log_accepts_model_dump_metadata(with_memory_logger):
14001501
experiment = init_test_exp("test-experiment", "test-project")
14011502

py/src/braintrust/type_tests/test_metadata_types.py

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,16 @@ def accepts_logger_metadata(logger: Logger) -> None:
2323
logger.log(metadata=PydanticV2Metadata())
2424
logger.log(metadata=PydanticV1Metadata())
2525

26+
logger.emit_log(body="message", level="info", metadata=mapping_metadata)
27+
logger.emit_log(body="message", level="info", metadata=PydanticV2Metadata())
28+
logger.emit_log(body="message", level="info", metadata=PydanticV1Metadata())
29+
logger.trace("message", metadata=mapping_metadata)
30+
logger.debug("message", metadata=PydanticV2Metadata())
31+
logger.info("message", metadata=PydanticV1Metadata())
32+
logger.warn("message", metadata=mapping_metadata)
33+
logger.error("message", metadata=PydanticV2Metadata())
34+
logger.fatal("message", metadata=PydanticV1Metadata())
35+
2636
logger.log_feedback(id="event-id", metadata=mapping_metadata)
2737
logger.log_feedback(id="event-id", metadata=PydanticV2Metadata())
2838
logger.log_feedback(id="event-id", metadata=PydanticV1Metadata())

0 commit comments

Comments
 (0)