diff --git a/CHANGELOG.md b/CHANGELOG.md index 1ee1ab20693..71468a8ceea 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -26,6 +26,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ([#4637](https://github.com/open-telemetry/opentelemetry-python/pull/4637)) - Logging API accepts optional `context`; deprecates `trace_id`, `span_id`, `trace_flags`. ([#4597](https://github.com/open-telemetry/opentelemetry-python/pull/4597)) +- sdk: use context instead of trace_id,span_id for initializing LogRecord + ([#4653](https://github.com/open-telemetry/opentelemetry-python/pull/4653)) - Rename LogRecordProcessor.emit to on_emit ([#4648](https://github.com/open-telemetry/opentelemetry-python/pull/4648)) - Logging API hide std_to_otel function to convert python logging severity to otel severity diff --git a/exporter/opentelemetry-exporter-otlp-proto-common/tests/test_log_encoder.py b/exporter/opentelemetry-exporter-otlp-proto-common/tests/test_log_encoder.py index 4c2b54aad2b..5407d9f1bca 100644 --- a/exporter/opentelemetry-exporter-otlp-proto-common/tests/test_log_encoder.py +++ b/exporter/opentelemetry-exporter-otlp-proto-common/tests/test_log_encoder.py @@ -49,7 +49,12 @@ from opentelemetry.sdk._logs import LogRecord as SDKLogRecord from opentelemetry.sdk.resources import Resource as SDKResource from opentelemetry.sdk.util.instrumentation import InstrumentationScope -from opentelemetry.trace import TraceFlags +from opentelemetry.trace import ( + NonRecordingSpan, + SpanContext, + TraceFlags, + set_span_in_context, +) class TestOTLPLogEncoder(unittest.TestCase): @@ -84,13 +89,21 @@ def test_dropped_attributes_count(self): @staticmethod def _get_sdk_log_data() -> List[LogData]: + ctx_log1 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 89564621134313219400156819398935297684, + 1312458408527513268, + False, + TraceFlags(0x01), + ) + ) + ) log1 = LogData( log_record=SDKLogRecord( timestamp=1644650195189786880, observed_timestamp=1644650195189786881, - trace_id=89564621134313219400156819398935297684, - span_id=1312458408527513268, - trace_flags=TraceFlags(0x01), + context=ctx_log1, severity_text="WARN", severity_number=SeverityNumber.WARN, body="Do not go gentle into that good night. Rage, rage against the dying of the light", @@ -109,9 +122,6 @@ def _get_sdk_log_data() -> List[LogData]: log_record=SDKLogRecord( timestamp=1644650249738562048, observed_timestamp=1644650249738562049, - trace_id=0, - span_id=0, - trace_flags=TraceFlags.DEFAULT, severity_text="WARN", severity_number=SeverityNumber.WARN, body="Cooper, this is no time for caution!", @@ -123,13 +133,21 @@ def _get_sdk_log_data() -> List[LogData]: ), ) + ctx_log3 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 271615924622795969659406376515024083555, + 4242561578944770265, + False, + TraceFlags(0x01), + ) + ) + ) log3 = LogData( log_record=SDKLogRecord( timestamp=1644650427658989056, observed_timestamp=1644650427658989057, - trace_id=271615924622795969659406376515024083555, - span_id=4242561578944770265, - trace_flags=TraceFlags(0x01), + context=ctx_log3, severity_text="DEBUG", severity_number=SeverityNumber.DEBUG, body="To our galaxy", @@ -139,13 +157,21 @@ def _get_sdk_log_data() -> List[LogData]: instrumentation_scope=None, ) + ctx_log4 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 212592107417388365804938480559624925555, + 6077757853989569223, + False, + TraceFlags(0x01), + ) + ) + ) log4 = LogData( log_record=SDKLogRecord( timestamp=1644650584292683008, observed_timestamp=1644650584292683009, - trace_id=212592107417388365804938480559624925555, - span_id=6077757853989569223, - trace_flags=TraceFlags(0x01), + context=ctx_log4, severity_text="INFO", severity_number=SeverityNumber.INFO, body="Love is the one thing that transcends time and space", @@ -160,13 +186,21 @@ def _get_sdk_log_data() -> List[LogData]: ), ) + ctx_log5 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 212592107417388365804938480559624925555, + 6077757853989569445, + False, + TraceFlags(0x01), + ) + ) + ) log5 = LogData( log_record=SDKLogRecord( timestamp=1644650584292683009, observed_timestamp=1644650584292683010, - trace_id=212592107417388365804938480559624925555, - span_id=6077757853989569445, - trace_flags=TraceFlags(0x01), + context=ctx_log5, severity_text="INFO", severity_number=SeverityNumber.INFO, body={"error": None, "array_with_nones": [1, None, 2]}, @@ -178,13 +212,21 @@ def _get_sdk_log_data() -> List[LogData]: ), ) + ctx_log6 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 212592107417388365804938480559624925522, + 6077757853989569222, + False, + TraceFlags(0x01), + ) + ) + ) log6 = LogData( log_record=SDKLogRecord( timestamp=1644650584292683022, observed_timestamp=1644650584292683022, - trace_id=212592107417388365804938480559624925522, - span_id=6077757853989569222, - trace_flags=TraceFlags(0x01), + context=ctx_log6, severity_text="ERROR", severity_number=SeverityNumber.ERROR, body="This instrumentation scope has a schema url", @@ -201,13 +243,21 @@ def _get_sdk_log_data() -> List[LogData]: ), ) + ctx_log7 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 212592107417388365804938480559624925533, + 6077757853989569233, + False, + TraceFlags(0x01), + ) + ) + ) log7 = LogData( log_record=SDKLogRecord( timestamp=1644650584292683033, observed_timestamp=1644650584292683033, - trace_id=212592107417388365804938480559624925533, - span_id=6077757853989569233, - trace_flags=TraceFlags(0x01), + context=ctx_log7, severity_text="FATAL", severity_number=SeverityNumber.FATAL, body="This instrumentation scope has a schema url and attributes", @@ -225,13 +275,21 @@ def _get_sdk_log_data() -> List[LogData]: ), ) + ctx_log8 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 212592107417388365804938480559624925566, + 6077757853989569466, + False, + TraceFlags(0x01), + ) + ) + ) log8 = LogData( log_record=SDKLogRecord( timestamp=1644650584292683044, observed_timestamp=1644650584292683044, - trace_id=212592107417388365804938480559624925566, - span_id=6077757853989569466, - trace_flags=TraceFlags(0x01), + context=ctx_log8, severity_text="INFO", severity_number=SeverityNumber.INFO, body="Test export of extended attributes", @@ -544,12 +602,20 @@ def get_test_logs( @staticmethod def _get_test_logs_dropped_attributes() -> List[LogData]: + ctx_log1 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 89564621134313219400156819398935297684, + 1312458408527513268, + False, + TraceFlags(0x01), + ) + ) + ) log1 = LogData( log_record=SDKLogRecord( timestamp=1644650195189786880, - trace_id=89564621134313219400156819398935297684, - span_id=1312458408527513268, - trace_flags=TraceFlags(0x01), + context=ctx_log1, severity_text="WARN", severity_number=SeverityNumber.WARN, body="Do not go gentle into that good night. Rage, rage against the dying of the light", @@ -561,13 +627,13 @@ def _get_test_logs_dropped_attributes() -> List[LogData]: "first_name", "first_version" ), ) - + ctx_log2 = set_span_in_context( + NonRecordingSpan(SpanContext(0, 0, False)) + ) log2 = LogData( log_record=SDKLogRecord( timestamp=1644650249738562048, - trace_id=0, - span_id=0, - trace_flags=TraceFlags.DEFAULT, + context=ctx_log2, severity_text="WARN", severity_number=SeverityNumber.WARN, body="Cooper, this is no time for caution!", diff --git a/exporter/opentelemetry-exporter-otlp-proto-grpc/tests/logs/test_otlp_logs_exporter.py b/exporter/opentelemetry-exporter-otlp-proto-grpc/tests/logs/test_otlp_logs_exporter.py index 8f3677784b1..d4407649b2f 100644 --- a/exporter/opentelemetry-exporter-otlp-proto-grpc/tests/logs/test_otlp_logs_exporter.py +++ b/exporter/opentelemetry-exporter-otlp-proto-grpc/tests/logs/test_otlp_logs_exporter.py @@ -51,7 +51,12 @@ ) from opentelemetry.sdk.resources import Resource as SDKResource from opentelemetry.sdk.util.instrumentation import InstrumentationScope -from opentelemetry.trace import TraceFlags +from opentelemetry.trace import ( + NonRecordingSpan, + SpanContext, + TraceFlags, + set_span_in_context, +) THIS_DIR = dirname(__file__) @@ -59,12 +64,20 @@ class TestOTLPLogExporter(TestCase): def setUp(self): self.exporter = OTLPLogExporter() + ctx_log_data_1 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 2604504634922341076776623263868986797, + 5213367945872657620, + False, + TraceFlags(0x01), + ) + ) + ) self.log_data_1 = LogData( log_record=LogRecord( timestamp=int(time.time() * 1e9), - trace_id=2604504634922341076776623263868986797, - span_id=5213367945872657620, - trace_flags=TraceFlags(0x01), + context=ctx_log_data_1, severity_text="WARNING", severity_number=SeverityNumber.WARN, body="Zhengzhou, We have a heaviest rains in 1000 years", @@ -75,12 +88,20 @@ def setUp(self): "first_name", "first_version" ), ) + ctx_log_data_2 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 2604504634922341076776623263868986799, + 5213367945872657623, + False, + TraceFlags(0x01), + ) + ) + ) self.log_data_2 = LogData( log_record=LogRecord( timestamp=int(time.time() * 1e9), - trace_id=2604504634922341076776623263868986799, - span_id=5213367945872657623, - trace_flags=TraceFlags(0x01), + context=ctx_log_data_2, severity_text="INFO", severity_number=SeverityNumber.INFO2, body="Sydney, Opera House is closed", @@ -91,12 +112,20 @@ def setUp(self): "second_name", "second_version" ), ) + ctx_log_data_3 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 2604504634922341076776623263868986800, + 5213367945872657628, + False, + TraceFlags(0x01), + ) + ) + ) self.log_data_3 = LogData( log_record=LogRecord( timestamp=int(time.time() * 1e9), - trace_id=2604504634922341076776623263868986800, - span_id=5213367945872657628, - trace_flags=TraceFlags(0x01), + context=ctx_log_data_3, severity_text="ERROR", severity_number=SeverityNumber.WARN, body="Mumbai, Boil water before drinking", @@ -106,12 +135,15 @@ def setUp(self): "third_name", "third_version" ), ) + ctx_log_data_4 = set_span_in_context( + NonRecordingSpan( + SpanContext(0, 5213367945872657629, False, TraceFlags(0x01)) + ) + ) self.log_data_4 = LogData( log_record=LogRecord( timestamp=int(time.time() * 1e9), - trace_id=0, - span_id=5213367945872657629, - trace_flags=TraceFlags(0x01), + context=ctx_log_data_4, severity_text="ERROR", severity_number=SeverityNumber.WARN, body="Invalid trace id check", @@ -121,12 +153,20 @@ def setUp(self): "fourth_name", "fourth_version" ), ) + ctx_log_data_5 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 2604504634922341076776623263868986801, + 0, + False, + TraceFlags(0x01), + ) + ) + ) self.log_data_5 = LogData( log_record=LogRecord( timestamp=int(time.time() * 1e9), - trace_id=2604504634922341076776623263868986801, - span_id=0, - trace_flags=TraceFlags(0x01), + context=ctx_log_data_5, severity_text="ERROR", severity_number=SeverityNumber.WARN, body="Invalid span id check", diff --git a/exporter/opentelemetry-exporter-otlp-proto-http/tests/test_proto_log_exporter.py b/exporter/opentelemetry-exporter-otlp-proto-http/tests/test_proto_log_exporter.py index 04c37743860..024015d0fa5 100644 --- a/exporter/opentelemetry-exporter-otlp-proto-http/tests/test_proto_log_exporter.py +++ b/exporter/opentelemetry-exporter-otlp-proto-http/tests/test_proto_log_exporter.py @@ -59,7 +59,12 @@ ) from opentelemetry.sdk.resources import Resource as SDKResource from opentelemetry.sdk.util.instrumentation import InstrumentationScope -from opentelemetry.trace import TraceFlags +from opentelemetry.trace import ( + NonRecordingSpan, + SpanContext, + TraceFlags, + set_span_in_context, +) ENV_ENDPOINT = "http://localhost.env:8080/" ENV_CERTIFICATE = "/etc/base.crt" @@ -217,12 +222,20 @@ def export_log_and_deserialize(log): return log_records def test_exported_log_without_trace_id(self): + ctx = set_span_in_context( + NonRecordingSpan( + SpanContext( + 0, + 1312458408527513292, + False, + TraceFlags(0x01), + ) + ) + ) log = LogData( log_record=SDKLogRecord( timestamp=1644650195189786182, - trace_id=0, - span_id=1312458408527513292, - trace_flags=TraceFlags(0x01), + context=ctx, severity_text="WARN", severity_number=SeverityNumber.WARN, body="Invalid trace id check", @@ -244,12 +257,21 @@ def test_exported_log_without_trace_id(self): self.fail("No log records found") def test_exported_log_without_span_id(self): + ctx = set_span_in_context( + NonRecordingSpan( + SpanContext( + 89564621134313219400156819398935297696, + 0, + False, + TraceFlags(0x01), + ) + ) + ) + log = LogData( log_record=SDKLogRecord( timestamp=1644650195189786360, - trace_id=89564621134313219400156819398935297696, - span_id=0, - trace_flags=TraceFlags(0x01), + context=ctx, severity_text="WARN", severity_number=SeverityNumber.WARN, body="Invalid span id check", @@ -272,12 +294,20 @@ def test_exported_log_without_span_id(self): @staticmethod def _get_sdk_log_data() -> List[LogData]: + ctx_log1 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 89564621134313219400156819398935297684, + 1312458408527513268, + False, + TraceFlags(0x01), + ) + ) + ) log1 = LogData( log_record=SDKLogRecord( timestamp=1644650195189786880, - trace_id=89564621134313219400156819398935297684, - span_id=1312458408527513268, - trace_flags=TraceFlags(0x01), + context=ctx_log1, severity_text="WARN", severity_number=SeverityNumber.WARN, body="Do not go gentle into that good night. Rage, rage against the dying of the light", @@ -289,12 +319,19 @@ def _get_sdk_log_data() -> List[LogData]: ), ) + ctx_log2 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 0, + 0, + False, + ) + ) + ) log2 = LogData( log_record=SDKLogRecord( timestamp=1644650249738562048, - trace_id=0, - span_id=0, - trace_flags=TraceFlags.DEFAULT, + context=ctx_log2, severity_text="WARN", severity_number=SeverityNumber.WARN, body="Cooper, this is no time for caution!", @@ -305,13 +342,20 @@ def _get_sdk_log_data() -> List[LogData]: "second_name", "second_version" ), ) - + ctx_log3 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 271615924622795969659406376515024083555, + 4242561578944770265, + False, + TraceFlags(0x01), + ) + ) + ) log3 = LogData( log_record=SDKLogRecord( timestamp=1644650427658989056, - trace_id=271615924622795969659406376515024083555, - span_id=4242561578944770265, - trace_flags=TraceFlags(0x01), + context=ctx_log3, severity_text="DEBUG", severity_number=SeverityNumber.DEBUG, body="To our galaxy", @@ -320,13 +364,20 @@ def _get_sdk_log_data() -> List[LogData]: ), instrumentation_scope=None, ) - + ctx_log4 = set_span_in_context( + NonRecordingSpan( + SpanContext( + 212592107417388365804938480559624925555, + 6077757853989569223, + False, + TraceFlags(0x01), + ) + ) + ) log4 = LogData( log_record=SDKLogRecord( timestamp=1644650584292683008, - trace_id=212592107417388365804938480559624925555, - span_id=6077757853989569223, - trace_flags=TraceFlags(0x01), + context=ctx_log4, severity_text="INFO", severity_number=SeverityNumber.INFO, body="Love is the one thing that transcends time and space", diff --git a/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py b/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py index 791b15b26c6..2afe4805353 100644 --- a/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py +++ b/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py @@ -250,22 +250,17 @@ def __init__( # pylint:disable=too-many-locals if not context: context = get_current() - 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 + span = get_current_span(context) + span_context = span.get_span_context() super().__init__( **{ "timestamp": timestamp, "observed_timestamp": observed_timestamp, "context": context, - "trace_id": trace_id, - "span_id": span_id, - "trace_flags": trace_flags, + "trace_id": trace_id or span_context.trace_id, + "span_id": span_id or span_context.span_id, + "trace_flags": trace_flags or span_context.trace_flags, "severity_text": severity_text, "severity_number": severity_number, "body": body, @@ -588,7 +583,6 @@ def _get_attributes(record: logging.LogRecord) -> _ExtendedAttributes: def _translate(self, record: logging.LogRecord) -> LogRecord: timestamp = int(record.created * 1e9) observered_timestamp = time_ns() - span_context = get_current_span().get_span_context() attributes = self._get_attributes(record) severity_number = std_to_otel(record.levelno) if self.formatter: @@ -624,9 +618,7 @@ def _translate(self, record: logging.LogRecord) -> LogRecord: return LogRecord( timestamp=timestamp, observed_timestamp=observered_timestamp, - trace_id=span_context.trace_id, - span_id=span_context.span_id, - trace_flags=span_context.trace_flags, + context=get_current() or None, severity_text=level_name, severity_number=severity_number, body=body, diff --git a/opentelemetry-sdk/tests/logs/test_export.py b/opentelemetry-sdk/tests/logs/test_export.py index 27165665569..4b8d98693c5 100644 --- a/opentelemetry-sdk/tests/logs/test_export.py +++ b/opentelemetry-sdk/tests/logs/test_export.py @@ -46,7 +46,12 @@ ) from opentelemetry.sdk.resources import Resource as SDKResource from opentelemetry.sdk.util.instrumentation import InstrumentationScope -from opentelemetry.trace import TraceFlags +from opentelemetry.trace import ( + NonRecordingSpan, + SpanContext, + TraceFlags, + set_span_in_context, +) from opentelemetry.trace.span import INVALID_SPAN_CONTEXT EMPTY_LOG = LogData( @@ -593,12 +598,20 @@ def test_validation_negative_max_queue_size(self): class TestConsoleLogExporter(unittest.TestCase): def test_export(self): # pylint: disable=no-self-use """Check that the console exporter prints log records.""" + ctx = set_span_in_context( + NonRecordingSpan( + SpanContext( + 2604504634922341076776623263868986797, + 5213367945872657620, + False, + TraceFlags(0x01), + ) + ) + ) log_data = LogData( log_record=LogRecord( timestamp=int(time.time() * 1e9), - trace_id=2604504634922341076776623263868986797, - span_id=5213367945872657620, - trace_flags=TraceFlags(0x01), + context=ctx, severity_text="WARN", severity_number=SeverityNumber.WARN, body="Zhengzhou, We have a heaviest rains in 1000 years", diff --git a/opentelemetry-sdk/tests/logs/test_log_record.py b/opentelemetry-sdk/tests/logs/test_log_record.py index 5175cb8c860..ed341baa3fc 100644 --- a/opentelemetry-sdk/tests/logs/test_log_record.py +++ b/opentelemetry-sdk/tests/logs/test_log_record.py @@ -47,7 +47,7 @@ def test_log_record_to_json(self): self.assertEqual( log_record.to_json(indent=None), - '{"body": {"key": "logLine", "bytes": "MTIz"}, "severity_number": null, "severity_text": null, "attributes": {"mapping": {"key": "value"}, "none": null, "sequence": [1, 2], "str": "string"}, "dropped_attributes": 0, "timestamp": "1970-01-01T00:00:00.000000Z", "observed_timestamp": "1970-01-01T00:00:00.000000Z", "trace_id": "", "span_id": "", "trace_flags": null, "resource": {"attributes": {"service.name": "foo"}, "schema_url": ""}, "event_name": "a.event"}', + '{"body": {"key": "logLine", "bytes": "MTIz"}, "severity_number": null, "severity_text": null, "attributes": {"mapping": {"key": "value"}, "none": null, "sequence": [1, 2], "str": "string"}, "dropped_attributes": 0, "timestamp": "1970-01-01T00:00:00.000000Z", "observed_timestamp": "1970-01-01T00:00:00.000000Z", "trace_id": "0x00000000000000000000000000000000", "span_id": "0x0000000000000000", "trace_flags": 0, "resource": {"attributes": {"service.name": "foo"}, "schema_url": ""}, "event_name": "a.event"}', ) def test_log_record_to_json_serializes_severity_number_as_int(self):