Skip to content

Logging API accepts optional Context with priority over trace_id etc, and LoggingHandler passes current Context #4597

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 10 commits into
base: main
Choose a base branch
from
3 changes: 3 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
([#4593](https://github.com/open-telemetry/opentelemetry-python/pull/4593))
- opentelemetry-test-utils: assert explicit bucket boundaries in histogram metrics
([#4595](https://github.com/open-telemetry/opentelemetry-python/pull/4595))
- Logging API accepts optional Context with precedence over `trace_id`, `span_id`,
`trace_flags` if provided with valid span. LoggingHandler passes current Context.
([#4597](https://github.com/open-telemetry/opentelemetry-python/pull/4597))

## Version 1.33.0/0.54b0 (2025-05-09)

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,7 @@
from typing import Optional, cast

from opentelemetry._logs.severity import SeverityNumber
from opentelemetry.context.context import Context
from opentelemetry.environment_variables import _OTEL_PYTHON_LOGGER_PROVIDER
from opentelemetry.trace.span import TraceFlags
from opentelemetry.util._once import Once
Expand All @@ -61,6 +62,7 @@ def __init__(
self,
timestamp: Optional[int] = None,
observed_timestamp: Optional[int] = None,
context: Optional[Context] = None,
trace_id: Optional[int] = None,
span_id: Optional[int] = None,
trace_flags: Optional["TraceFlags"] = None,
Expand All @@ -73,6 +75,7 @@ def __init__(
if observed_timestamp is None:
observed_timestamp = time_ns()
self.observed_timestamp = observed_timestamp
self.context = context
self.trace_id = trace_id
self.span_id = span_id
self.trace_flags = trace_flags
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -37,6 +37,8 @@
std_to_otel,
)
from opentelemetry.attributes import _VALID_ANY_VALUE_TYPES, BoundedAttributes
from opentelemetry.context import get_current
from opentelemetry.context.context import Context
from opentelemetry.sdk.environment_variables import (
OTEL_ATTRIBUTE_COUNT_LIMIT,
OTEL_ATTRIBUTE_VALUE_LENGTH_LIMIT,
Expand Down Expand Up @@ -176,6 +178,7 @@ def __init__(
self,
timestamp: int | None = None,
observed_timestamp: int | None = None,
context: Context | None = None,
trace_id: int | None = None,
span_id: int | None = None,
trace_flags: TraceFlags | None = None,
Expand All @@ -186,10 +189,22 @@ def __init__(
attributes: _ExtendedAttributes | None = None,
limits: LogLimits | None = _UnsetLogLimits,
):
# Prioritizes context over trace_id / span_id / trace_flags.
# If context provided and its current span valid, then uses that span info.
# Otherwise, uses provided trace_id etc for backwards compatibility.
if context is not None:
span = get_current_span(context)
span_context = span.get_span_context()
if span_context.is_valid:
trace_id = span_context.trace_id
span_id = span_context.span_id
trace_flags = span_context.trace_flags

super().__init__(
**{
"timestamp": timestamp,
"observed_timestamp": observed_timestamp,
"context": context,
"trace_id": trace_id,
"span_id": span_id,
"trace_flags": trace_flags,
Expand Down Expand Up @@ -220,6 +235,19 @@ def __eq__(self, other: object) -> bool:
return NotImplemented
return self.__dict__ == other.__dict__

def serialized_context(self) -> dict:
"""Returns JSON-serializable copy of stored Context"""
context_dict = {}
if self.context is not None:
for key, value in self.context.items():
try:
json.dumps(value)
context_dict[key] = value
except TypeError:
# If not JSON-serializable, use string representation
context_dict[key] = str(value)
return context_dict

def to_json(self, indent: int | None = 4) -> str:
return json.dumps(
{
Expand All @@ -234,6 +262,7 @@ def to_json(self, indent: int | None = 4) -> str:
"dropped_attributes": self.dropped_attributes,
"timestamp": ns_to_iso_str(self.timestamp),
"observed_timestamp": ns_to_iso_str(self.observed_timestamp),
"context": self.serialized_context(),
"trace_id": (
f"0x{format_trace_id(self.trace_id)}"
if self.trace_id is not None
Expand Down Expand Up @@ -548,6 +577,7 @@ def _translate(self, record: logging.LogRecord) -> LogRecord:
return LogRecord(
timestamp=timestamp,
observed_timestamp=observered_timestamp,
context=get_current(),
trace_id=span_context.trace_id,
span_id=span_context.span_id,
trace_flags=span_context.trace_flags,
Expand Down
98 changes: 76 additions & 22 deletions opentelemetry-sdk/tests/logs/test_handler.py
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@
from opentelemetry._logs import NoOpLoggerProvider, SeverityNumber
from opentelemetry._logs import get_logger as APIGetLogger
from opentelemetry.attributes import BoundedAttributes
from opentelemetry.context.context import Context
from opentelemetry.sdk import trace
from opentelemetry.sdk._logs import (
LogData,
Expand All @@ -29,7 +30,10 @@
)
from opentelemetry.semconv._incubating.attributes import code_attributes
from opentelemetry.semconv.attributes import exception_attributes
from opentelemetry.trace import INVALID_SPAN_CONTEXT
from opentelemetry.trace import (
INVALID_SPAN_CONTEXT,
set_span_in_context,
)


class TestLoggingHandler(unittest.TestCase):
Expand Down Expand Up @@ -91,19 +95,26 @@ def test_log_flush_noop(self):

def test_log_record_no_span_context(self):
processor, logger = set_up_test_logging(logging.WARNING)
mock_context = Context()

# Assert emit gets called for warning message
with self.assertLogs(level=logging.WARNING):
logger.warning("Warning message")
with patch(
"opentelemetry.sdk._logs._internal.get_current",
return_value=mock_context,
):
# Assert emit gets called for warning message
with self.assertLogs(level=logging.WARNING):
logger.warning("Warning message")

log_record = processor.get_log_record(0)
log_record = processor.get_log_record(0)

self.assertIsNotNone(log_record)
self.assertEqual(log_record.trace_id, INVALID_SPAN_CONTEXT.trace_id)
self.assertEqual(log_record.span_id, INVALID_SPAN_CONTEXT.span_id)
self.assertEqual(
log_record.trace_flags, INVALID_SPAN_CONTEXT.trace_flags
)
self.assertIsNotNone(log_record)
self.assertEqual(
log_record.trace_id, INVALID_SPAN_CONTEXT.trace_id
)
self.assertEqual(log_record.span_id, INVALID_SPAN_CONTEXT.span_id)
self.assertEqual(
log_record.trace_flags, INVALID_SPAN_CONTEXT.trace_flags
)

def test_log_record_observed_timestamp(self):
processor, logger = set_up_test_logging(logging.WARNING)
Expand Down Expand Up @@ -271,18 +282,61 @@ def test_log_record_trace_correlation(self):

tracer = trace.TracerProvider().get_tracer(__name__)
with tracer.start_as_current_span("test") as span:
with self.assertLogs(level=logging.CRITICAL):
logger.critical("Critical message within span")

log_record = processor.get_log_record(0)
mock_context = set_span_in_context(span)

with patch(
"opentelemetry.sdk._logs._internal.get_current",
return_value=mock_context,
):
with self.assertLogs(level=logging.CRITICAL):
logger.critical("Critical message within span")

log_record = processor.get_log_record(0)

self.assertEqual(
log_record.body, "Critical message within span"
)
self.assertEqual(log_record.severity_text, "CRITICAL")
self.assertEqual(
log_record.severity_number, SeverityNumber.FATAL
)
self.assertEqual(log_record.context, mock_context)
span_context = span.get_span_context()
self.assertEqual(log_record.trace_id, span_context.trace_id)
self.assertEqual(log_record.span_id, span_context.span_id)
self.assertEqual(
log_record.trace_flags, span_context.trace_flags
)

def test_log_record_trace_correlation_backwards_compatibility(self):
processor, logger = set_up_test_logging(logging.WARNING)
mock_context = Context() # no span in context

self.assertEqual(log_record.body, "Critical message within span")
self.assertEqual(log_record.severity_text, "CRITICAL")
self.assertEqual(log_record.severity_number, SeverityNumber.FATAL)
span_context = span.get_span_context()
self.assertEqual(log_record.trace_id, span_context.trace_id)
self.assertEqual(log_record.span_id, span_context.span_id)
self.assertEqual(log_record.trace_flags, span_context.trace_flags)
tracer = trace.TracerProvider().get_tracer(__name__)
with tracer.start_as_current_span("test") as span:
with patch(
"opentelemetry.sdk._logs._internal.get_current",
return_value=mock_context,
):
with self.assertLogs(level=logging.CRITICAL):
logger.critical("Critical message within span")

log_record = processor.get_log_record(0)

self.assertEqual(
log_record.body, "Critical message within span"
)
self.assertEqual(log_record.severity_text, "CRITICAL")
self.assertEqual(
log_record.severity_number, SeverityNumber.FATAL
)
self.assertEqual(log_record.context, mock_context)
span_context = span.get_span_context()
self.assertEqual(log_record.trace_id, span_context.trace_id)
self.assertEqual(log_record.span_id, span_context.span_id)
self.assertEqual(
log_record.trace_flags, span_context.trace_flags
)

def test_warning_without_formatter(self):
processor, logger = set_up_test_logging(logging.WARNING)
Expand Down
Loading