From d8c9ef3ec4eb37616fd8d998b8df2bc2fa9daff6 Mon Sep 17 00:00:00 2001 From: Gaurav Dubey Date: Tue, 27 Oct 2026 06:17:25 +0000 Subject: [PATCH 1/2] feat(log): add trace_id/span_id to JSON log records inside a span When OpenTelemetry tracing is enabled, JsonHandler now adds the current span's W3C trace_id (32 hex) and span_id (16 hex) to each record, so a log line can be looked up in the tracing backend and vice versa. The ids come from a new reflex_base.otel.trace_fields() helper, which returns None while tracing is off or no valid span is current. It uses the API module bound by enable(), so the disabled path still imports nothing from opentelemetry. Closes #6903 --- docs/api-reference/observability.md | 14 +++++++ .../news/+json-log-trace-ids.feature.md | 1 + packages/reflex-base/src/reflex_base/otel.py | 19 ++++++++++ .../reflex-base/src/reflex_base/utils/log.py | 4 ++ tests/units/reflex_base/test_otel.py | 19 ++++++++++ tests/units/reflex_base/utils/test_log.py | 38 +++++++++++++++++++ 6 files changed, 95 insertions(+) create mode 100644 packages/reflex-base/news/+json-log-trace-ids.feature.md diff --git a/docs/api-reference/observability.md b/docs/api-reference/observability.md index 6d21b8c60cb..c19425fa762 100644 --- a/docs/api-reference/observability.md +++ b/docs/api-reference/observability.md @@ -86,6 +86,20 @@ attributes. Event payloads and state are never recorded. Pass `meter_provider=` to `instrument()` to export them (defaults to the global meter provider). +### Logs + +With JSON logging on (`REFLEX_LOG_JSON=true` or `--json`), every Reflex log +record emitted inside a span carries that span's W3C ids, so a log line can be +looked up in your tracing backend and vice versa: + +```json +{"level": "error", "message": "...", "trace_id": "4bf92f3577b34da6a3ce929d0e0e4736", "span_id": "00f067aa0ba902b7"} +``` + +Records emitted outside a span, or while the instrumentation is off, have no +`trace_id`/`span_id` fields. For your own application loggers, use +[`opentelemetry-instrumentation-logging`](https://opentelemetry-python-contrib.readthedocs.io/en/latest/instrumentation/logging/logging.html). + ## Frontend: browser traces Add the plugin to your config to trace the browser as well: diff --git a/packages/reflex-base/news/+json-log-trace-ids.feature.md b/packages/reflex-base/news/+json-log-trace-ids.feature.md new file mode 100644 index 00000000000..9eb6b66da41 --- /dev/null +++ b/packages/reflex-base/news/+json-log-trace-ids.feature.md @@ -0,0 +1 @@ +With OpenTelemetry tracing enabled, JSON log records (`REFLEX_LOG_JSON=true`) emitted inside a span now include its `trace_id` and `span_id`, so logs can be correlated with traces. diff --git a/packages/reflex-base/src/reflex_base/otel.py b/packages/reflex-base/src/reflex_base/otel.py index 6acd96fb50f..be5728eb24d 100644 --- a/packages/reflex-base/src/reflex_base/otel.py +++ b/packages/reflex-base/src/reflex_base/otel.py @@ -269,6 +269,24 @@ def capture_context() -> Context | None: return context_api.get_current() +def trace_fields() -> dict[str, str] | None: + """W3C ids of the current span, for correlating a log record with its trace. + + Returns: + ``trace_id`` (32 hex digits) and ``span_id`` (16 hex digits) of the + current span, or None when tracing is off or no valid span is current. + """ + if not enabled: + return None + span_context = trace.get_current_span().get_span_context() + if not span_context.is_valid: + return None + return { + "trace_id": trace.format_trace_id(span_context.trace_id), + "span_id": trace.format_span_id(span_context.span_id), + } + + def attach_context(context: Context | None) -> None: """Make a captured context current for the rest of the running task. @@ -524,4 +542,5 @@ def record_connection(delta: int) -> None: "record_message_size", "record_state_acquired", "remote_context", + "trace_fields", ] diff --git a/packages/reflex-base/src/reflex_base/utils/log.py b/packages/reflex-base/src/reflex_base/utils/log.py index 725313fe889..9d80a082d8d 100644 --- a/packages/reflex-base/src/reflex_base/utils/log.py +++ b/packages/reflex-base/src/reflex_base/utils/log.py @@ -42,6 +42,7 @@ from rich.errors import MarkupError from rich.text import Text +from reflex_base import otel from reflex_base.constants import LogLevel from reflex_base.constants.base import Reflex from reflex_base.utils.decorator import once @@ -571,6 +572,9 @@ def emit(self, record: logging.LogRecord): value = getattr(record, field, None) if value is not None: payload[field] = value + # Correlate the record with the span it was emitted under. + if (ids := otel.trace_fields()) is not None: + payload.update(ids) if record.exc_info and record.exc_info[0] is not None: payload["exception"] = _EXC_FORMATTER.formatException( record.exc_info # pyright: ignore[reportArgumentType] diff --git a/tests/units/reflex_base/test_otel.py b/tests/units/reflex_base/test_otel.py index 944e82c2a0c..2b4f25f9c02 100644 --- a/tests/units/reflex_base/test_otel.py +++ b/tests/units/reflex_base/test_otel.py @@ -63,6 +63,7 @@ def test_trace_points_carry_no_import_statement(): otel.record_state_acquired, otel.record_message_size, otel.record_connection, + otel.trace_fields, ) for trace_point in trace_points: opnames = {inst.opname for inst in dis.get_instructions(trace_point)} @@ -114,6 +115,24 @@ def test_capture_context_returns_current(otel_exporter: InMemorySpanExporter): assert otel_context.get_current() is not captured +def test_trace_fields_disabled(): + assert otel.trace_fields() is None + + +def test_trace_fields_without_current_span(otel_exporter: InMemorySpanExporter): + assert otel.trace_fields() is None + + +def test_trace_fields_inside_span(otel_exporter: InMemorySpanExporter): + with active_tracer().start_as_current_span("outer") as span: + fields = otel.trace_fields() + span_context = span.get_span_context() + assert fields == { + "trace_id": f"{span_context.trace_id:032x}", + "span_id": f"{span_context.span_id:016x}", + } + + def test_event_span_attributes(otel_exporter: InMemorySpanExporter): ctx = _ctx(parent_txid="parent123") event = Event(name="state.sub.handler") diff --git a/tests/units/reflex_base/utils/test_log.py b/tests/units/reflex_base/utils/test_log.py index dfdf620957e..2a76f03e67f 100644 --- a/tests/units/reflex_base/utils/test_log.py +++ b/tests/units/reflex_base/utils/test_log.py @@ -12,10 +12,13 @@ from unittest import mock import pytest +from reflex_base import otel from reflex_base.constants import LogLevel from reflex_base.utils import console, log from rich.console import Console +from tests.units.conftest import active_tracer + logger = logging.getLogger("reflex_base.tests.logs") @@ -159,6 +162,41 @@ def test_json_mode_success_level(monkeypatch, capsys): assert json.loads(out)["level"] == "success" +def test_json_mode_adds_trace_ids(monkeypatch, capsys, otel_sdk): + """Records emitted inside a span carry the span's W3C trace and span ids.""" + monkeypatch.setenv("REFLEX_LOG_JSON", "true") + log.configure() + with active_tracer().start_as_current_span("outer") as span: + logger.info("inside") + logger.error("failed inside") + span_context = span.get_span_context() + out, err = capsys.readouterr() + for record in (json.loads(out), json.loads(err)): + assert record["trace_id"] == f"{span_context.trace_id:032x}" + assert record["span_id"] == f"{span_context.span_id:016x}" + + +def test_json_mode_omits_trace_ids_outside_span(monkeypatch, capsys, otel_sdk): + """With tracing on but no current span, records carry no trace ids.""" + monkeypatch.setenv("REFLEX_LOG_JSON", "true") + log.configure() + logger.info("outside") + record = json.loads(capsys.readouterr().out) + assert "trace_id" not in record + assert "span_id" not in record + + +def test_json_mode_omits_trace_ids_when_tracing_disabled(monkeypatch, capsys): + """With tracing off, records carry no trace ids.""" + monkeypatch.setenv("REFLEX_LOG_JSON", "true") + log.configure() + assert otel.enabled is False + logger.info("untraced") + record = json.loads(capsys.readouterr().out) + assert "trace_id" not in record + assert "span_id" not in record + + def test_configure_idempotent(): """Repeated configure calls never stack handlers.""" log.configure() From a20f3cc327b1e077ce4acd550263a1442ead3d40 Mon Sep 17 00:00:00 2001 From: Gaurav Dubey Date: Tue, 27 Oct 2026 06:30:51 +0000 Subject: [PATCH 2/2] Add trace ids to console output in JSON mode too console.print() in JSON mode writes through emit_json_print(), which bypasses JsonHandler, so its records lacked trace_id/span_id. Merge the ids in _write_json(), the one writer both paths share. --- docs/api-reference/observability.md | 7 ++++--- packages/reflex-base/src/reflex_base/utils/log.py | 8 +++++--- tests/units/reflex_base/utils/test_log.py | 13 +++++++++++++ 3 files changed, 22 insertions(+), 6 deletions(-) diff --git a/docs/api-reference/observability.md b/docs/api-reference/observability.md index c19425fa762..458c52e3525 100644 --- a/docs/api-reference/observability.md +++ b/docs/api-reference/observability.md @@ -88,9 +88,10 @@ meter provider). ### Logs -With JSON logging on (`REFLEX_LOG_JSON=true` or `--json`), every Reflex log -record emitted inside a span carries that span's W3C ids, so a log line can be -looked up in your tracing backend and vice versa: +With JSON logging on (`REFLEX_LOG_JSON=true` or `--json`), every JSON record +Reflex writes inside a span (log records and plain console output alike) +carries that span's W3C ids, so a log line can be looked up in your tracing +backend and vice versa: ```json {"level": "error", "message": "...", "trace_id": "4bf92f3577b34da6a3ce929d0e0e4736", "span_id": "00f067aa0ba902b7"} diff --git a/packages/reflex-base/src/reflex_base/utils/log.py b/packages/reflex-base/src/reflex_base/utils/log.py index 9d80a082d8d..80f8e531b63 100644 --- a/packages/reflex-base/src/reflex_base/utils/log.py +++ b/packages/reflex-base/src/reflex_base/utils/log.py @@ -256,10 +256,15 @@ def format_exception(self, record: logging.LogRecord) -> str: def _write_json(payload: dict, *, stderr: bool): """Write one JSON record to the output stream. + A record written inside an OpenTelemetry span also carries the span's + ``trace_id`` and ``span_id``. + Args: payload: The record fields. stderr: Whether the record targets stderr. """ + if (ids := otel.trace_fields()) is not None: + payload.update(ids) stream = sys.stderr if stderr or _stdout_reserved else sys.stdout stream.write(json.dumps(payload, default=str) + "\n") stream.flush() @@ -572,9 +577,6 @@ def emit(self, record: logging.LogRecord): value = getattr(record, field, None) if value is not None: payload[field] = value - # Correlate the record with the span it was emitted under. - if (ids := otel.trace_fields()) is not None: - payload.update(ids) if record.exc_info and record.exc_info[0] is not None: payload["exception"] = _EXC_FORMATTER.formatException( record.exc_info # pyright: ignore[reportArgumentType] diff --git a/tests/units/reflex_base/utils/test_log.py b/tests/units/reflex_base/utils/test_log.py index 2a76f03e67f..5ed4b649dfb 100644 --- a/tests/units/reflex_base/utils/test_log.py +++ b/tests/units/reflex_base/utils/test_log.py @@ -176,6 +176,19 @@ def test_json_mode_adds_trace_ids(monkeypatch, capsys, otel_sdk): assert record["span_id"] == f"{span_context.span_id:016x}" +def test_console_print_json_mode_adds_trace_ids(monkeypatch, capsys, otel_sdk): + """Plain console output in JSON mode carries the current span's ids too.""" + monkeypatch.setenv("REFLEX_LOG_JSON", "true") + log.configure() + with active_tracer().start_as_current_span("outer") as span: + console.print("printed inside") + span_context = span.get_span_context() + record = json.loads(capsys.readouterr().out) + assert record["message"] == "printed inside" + assert record["trace_id"] == f"{span_context.trace_id:032x}" + assert record["span_id"] == f"{span_context.span_id:016x}" + + def test_json_mode_omits_trace_ids_outside_span(monkeypatch, capsys, otel_sdk): """With tracing on but no current span, records carry no trace ids.""" monkeypatch.setenv("REFLEX_LOG_JSON", "true")