diff --git a/CHANGELOG.md b/CHANGELOG.md index 3332b41cbe2..48962e95439 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -14,6 +14,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - `opentelemetry-sdk`: Add `service` resource detector support to declarative file configuration via `detection_development.detectors[].service` ([#5003](https://github.com/open-telemetry/opentelemetry-python/pull/5003)) +- logs: add exception support to Logger emit and LogRecord attributes + ([#4907](https://github.com/open-telemetry/opentelemetry-python/issues/4907)) - Drop Python 3.9 support ([#5076](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/5076)) diff --git a/opentelemetry-api/src/opentelemetry/_logs/_internal/__init__.py b/opentelemetry-api/src/opentelemetry/_logs/_internal/__init__.py index 780bcb4843d..12a8cc08f88 100644 --- a/opentelemetry-api/src/opentelemetry/_logs/_internal/__init__.py +++ b/opentelemetry-api/src/opentelemetry/_logs/_internal/__init__.py @@ -76,6 +76,7 @@ def __init__( body: AnyValue = None, attributes: Optional[_ExtendedAttributes] = None, event_name: Optional[str] = None, + exception: Optional[BaseException] = None, ) -> None: ... @overload @@ -110,6 +111,7 @@ def __init__( body: AnyValue = None, attributes: Optional[_ExtendedAttributes] = None, event_name: Optional[str] = None, + exception: Optional[BaseException] = None, ) -> None: if not context: context = get_current() @@ -127,6 +129,7 @@ def __init__( self.body = body self.attributes = attributes self.event_name = event_name + self.exception = exception class Logger(ABC): @@ -157,6 +160,7 @@ def emit( body: AnyValue | None = None, attributes: _ExtendedAttributes | None = None, event_name: str | None = None, + exception: BaseException | None = None, ) -> None: ... @overload @@ -178,6 +182,7 @@ def emit( body: AnyValue | None = None, attributes: _ExtendedAttributes | None = None, event_name: str | None = None, + exception: BaseException | None = None, ) -> None: """Emits a :class:`LogRecord` representing a log to the processing pipeline.""" @@ -200,6 +205,7 @@ def emit( body: AnyValue | None = None, attributes: _ExtendedAttributes | None = None, event_name: str | None = None, + exception: BaseException | None = None, ) -> None: ... @overload @@ -220,6 +226,7 @@ def emit( body: AnyValue | None = None, attributes: _ExtendedAttributes | None = None, event_name: str | None = None, + exception: BaseException | None = None, ) -> None: pass @@ -266,6 +273,7 @@ def emit( body: AnyValue | None = None, attributes: _ExtendedAttributes | None = None, event_name: str | None = None, + exception: BaseException | None = None, ) -> None: ... @overload @@ -286,6 +294,7 @@ def emit( body: AnyValue | None = None, attributes: _ExtendedAttributes | None = None, event_name: str | None = None, + exception: BaseException | None = None, ) -> None: if record: self._logger.emit(record) @@ -299,6 +308,7 @@ def emit( body=body, attributes=attributes, event_name=event_name, + exception=exception, ) diff --git a/opentelemetry-api/tests/logs/test_log_record.py b/opentelemetry-api/tests/logs/test_log_record.py index a06ed8dabfc..da0f41e3b6b 100644 --- a/opentelemetry-api/tests/logs/test_log_record.py +++ b/opentelemetry-api/tests/logs/test_log_record.py @@ -25,3 +25,8 @@ class TestLogRecord(unittest.TestCase): def test_log_record_observed_timestamp_default(self, time_ns_mock): # type: ignore time_ns_mock.return_value = OBSERVED_TIMESTAMP self.assertEqual(LogRecord().observed_timestamp, OBSERVED_TIMESTAMP) + + def test_log_record_exception(self): + exc = ValueError("boom") + log_record = LogRecord(exception=exc) + self.assertIs(log_record.exception, exc) diff --git a/opentelemetry-api/tests/logs/test_proxy.py b/opentelemetry-api/tests/logs/test_proxy.py index d72ccc7c6b2..1b5d0c22ce1 100644 --- a/opentelemetry-api/tests/logs/test_proxy.py +++ b/opentelemetry-api/tests/logs/test_proxy.py @@ -15,6 +15,7 @@ # pylint: disable=W0212,W0222,W0221 import typing import unittest +from unittest.mock import Mock import opentelemetry._logs._internal as _logs_internal from opentelemetry import _logs @@ -46,6 +47,7 @@ def emit( body=None, attributes=None, event_name=None, + exception: typing.Optional[BaseException] = None, ) -> None: pass @@ -74,3 +76,13 @@ def test_proxy_logger(self): # references to the old provider still work but return real logger now real_logger = provider.get_logger("proxy-test") self.assertIsInstance(real_logger, LoggerTest) + + def test_proxy_logger_forwards_record_with_exception(self): + logger = _logs_internal.ProxyLogger("proxy-test") + logger._real_logger = Mock(spec=LoggerTest("proxy-test")) + record = _logs.LogRecord(exception=ValueError("boom")) + + self.assertIsNotNone(logger._real_logger) + logger.emit(record) + + logger._real_logger.emit.assert_called_once_with(record) diff --git a/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py b/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py index fa5399742a9..956d9f28bd7 100644 --- a/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py +++ b/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py @@ -52,6 +52,11 @@ from opentelemetry.context import get_current from opentelemetry.context.context import Context from opentelemetry.metrics import MeterProvider, get_meter_provider +from opentelemetry.sdk._logs._internal._exceptions import ( + _copy_log_record_with_exception, + _create_log_record_with_exception, + _set_log_record_exception_attributes, +) from opentelemetry.sdk._logs._internal._logger_metrics import LoggerMetrics from opentelemetry.sdk.environment_variables import ( OTEL_ATTRIBUTE_COUNT_LIMIT, @@ -712,6 +717,7 @@ def emit( body: AnyValue | None = None, attributes: _ExtendedAttributes | None = None, event_name: str | None = None, + exception: BaseException | None = None, ) -> None: """Emits the :class:`ReadWriteLogRecord` by setting instrumentation scope and forwarding to the processor. @@ -721,6 +727,8 @@ def emit( # If a record is provided, use it directly if record is not None: if not isinstance(record, ReadWriteLogRecord): + if record.exception is not None: + record = _copy_log_record_with_exception(record) # pylint:disable=protected-access writable_record = ReadWriteLogRecord._from_api_log_record( record=record, @@ -728,10 +736,11 @@ def emit( instrumentation_scope=self._instrumentation_scope, ) else: + _set_log_record_exception_attributes(record.log_record) writable_record = record else: # Create a record from individual parameters - log_record = LogRecord( + log_record = _create_log_record_with_exception( timestamp=timestamp, observed_timestamp=observed_timestamp, context=context, @@ -740,6 +749,7 @@ def emit( body=body, attributes=attributes, event_name=event_name, + exception=exception, ) # pylint:disable=protected-access writable_record = ReadWriteLogRecord._from_api_log_record( diff --git a/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/_exceptions.py b/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/_exceptions.py new file mode 100644 index 00000000000..4f3fdabec41 --- /dev/null +++ b/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/_exceptions.py @@ -0,0 +1,132 @@ +# Copyright The OpenTelemetry Authors +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +from __future__ import annotations + +import traceback + +from opentelemetry._logs import LogRecord +from opentelemetry.attributes import BoundedAttributes +from opentelemetry.semconv.attributes import exception_attributes +from opentelemetry.util.types import AnyValue, _ExtendedAttributes + + +def _get_exception_attributes( + exception: BaseException, +) -> dict[str, AnyValue]: + stacktrace = "".join( + traceback.format_exception( + type(exception), value=exception, tb=exception.__traceback__ + ) + ) + module = type(exception).__module__ + qualname = type(exception).__qualname__ + exception_type = ( + f"{module}.{qualname}" if module and module != "builtins" else qualname + ) + return { + exception_attributes.EXCEPTION_TYPE: exception_type, + exception_attributes.EXCEPTION_MESSAGE: str(exception), + exception_attributes.EXCEPTION_STACKTRACE: stacktrace, + } + + +def _get_attributes_with_exception( + attributes: _ExtendedAttributes | None, + exception: BaseException | None, +) -> _ExtendedAttributes | None: + if exception is None: + return attributes + + exception_attributes_map = _get_exception_attributes(exception) + if attributes is None: + attributes_map: _ExtendedAttributes = {} + else: + attributes_map = attributes + + if isinstance(attributes_map, BoundedAttributes): + bounded_attributes = attributes_map + merged = BoundedAttributes( + maxlen=bounded_attributes.maxlen, + attributes=bounded_attributes, + immutable=False, + max_value_len=bounded_attributes.max_value_len, + extended_attributes=bounded_attributes._extended_attributes, # pylint: disable=protected-access + ) + merged.dropped = bounded_attributes.dropped + for key, value in exception_attributes_map.items(): + if key not in merged: + merged[key] = value + return merged + + return exception_attributes_map | dict(attributes_map.items()) + + +def _copy_log_record( + record: LogRecord, + attributes: _ExtendedAttributes | None, +) -> LogRecord: + copied_record = LogRecord( + timestamp=record.timestamp, + observed_timestamp=record.observed_timestamp, + context=record.context, + severity_text=record.severity_text, + severity_number=record.severity_number, + body=record.body, + attributes=attributes, + event_name=record.event_name, + exception=getattr(record, "exception", None), + ) + copied_record.trace_id = record.trace_id + copied_record.span_id = record.span_id + copied_record.trace_flags = record.trace_flags + return copied_record + + +def _copy_log_record_with_exception(record: LogRecord) -> LogRecord: + return _copy_log_record( + record, + _get_attributes_with_exception(record.attributes, record.exception), + ) + + +def _set_log_record_exception_attributes(record: LogRecord) -> None: + record.attributes = _get_attributes_with_exception( + record.attributes, + record.exception, + ) + + +def _create_log_record_with_exception( + *, + timestamp: int | None = None, + observed_timestamp: int | None = None, + context=None, + severity_number=None, + severity_text: str | None = None, + body: AnyValue | None = None, + attributes: _ExtendedAttributes | None = None, + event_name: str | None = None, + exception: BaseException | None = None, +) -> LogRecord: + return LogRecord( + timestamp=timestamp, + observed_timestamp=observed_timestamp, + context=context, + severity_number=severity_number, + severity_text=severity_text, + body=body, + attributes=_get_attributes_with_exception(attributes, exception), + event_name=event_name, + exception=exception, + ) diff --git a/opentelemetry-sdk/tests/logs/test_logs.py b/opentelemetry-sdk/tests/logs/test_logs.py index d96c0cd63f0..deb242f4a11 100644 --- a/opentelemetry-sdk/tests/logs/test_logs.py +++ b/opentelemetry-sdk/tests/logs/test_logs.py @@ -18,12 +18,14 @@ from unittest.mock import Mock, patch from opentelemetry._logs import LogRecord, SeverityNumber +from opentelemetry.attributes import BoundedAttributes from opentelemetry.context import get_current from opentelemetry.metrics import NoOpMeterProvider from opentelemetry.sdk._logs import ( Logger, LoggerProvider, ReadableLogRecord, + ReadWriteLogRecord, ) from opentelemetry.sdk._logs._internal import ( LoggerMetrics, @@ -39,6 +41,7 @@ InstrumentationScope, _scope_name_matches_glob, ) +from opentelemetry.semconv.attributes import exception_attributes class TestLoggerProvider(unittest.TestCase): @@ -354,3 +357,109 @@ def test_can_emit_with_keywords_arguments(self): self.assertEqual(result_log_record.attributes, {"some": "attributes"}) self.assertEqual(result_log_record.event_name, "event_name") self.assertEqual(log_data.resource, logger.resource) + + def test_emit_with_exception_adds_attributes(self): + logger, log_record_processor_mock = self._get_logger() + exc = ValueError("boom") + + logger.emit(body="a log line", exception=exc) + log_record_processor_mock.on_emit.assert_called_once() + log_data = log_record_processor_mock.on_emit.call_args.args[0] + attributes = dict(log_data.log_record.attributes) + self.assertEqual( + attributes[exception_attributes.EXCEPTION_TYPE], "ValueError" + ) + self.assertEqual( + attributes[exception_attributes.EXCEPTION_MESSAGE], "boom" + ) + self.assertIn( + "ValueError: boom", + attributes[exception_attributes.EXCEPTION_STACKTRACE], + ) + + def test_emit_with_raised_exception_has_stacktrace(self): + logger, log_record_processor_mock = self._get_logger() + + try: + raise ValueError("boom") + except ValueError as exc: + logger.emit(body="error", exception=exc) + + log_record_processor_mock.on_emit.assert_called_once() + log_data = log_record_processor_mock.on_emit.call_args.args[0] + stacktrace = dict(log_data.log_record.attributes)[ + exception_attributes.EXCEPTION_STACKTRACE + ] + self.assertIn("Traceback (most recent call last)", stacktrace) + self.assertIn("raise ValueError", stacktrace) + + def test_emit_logrecord_exception_preserves_user_attributes(self): + logger, log_record_processor_mock = self._get_logger() + exc = ValueError("boom") + log_record = LogRecord( + observed_timestamp=0, + body="a log line", + attributes={exception_attributes.EXCEPTION_TYPE: "custom"}, + exception=exc, + ) + + logger.emit(log_record) + log_record_processor_mock.on_emit.assert_called_once() + log_data = log_record_processor_mock.on_emit.call_args.args[0] + attributes = dict(log_data.log_record.attributes) + self.assertEqual( + attributes[exception_attributes.EXCEPTION_TYPE], "custom" + ) + self.assertEqual( + attributes[exception_attributes.EXCEPTION_MESSAGE], "boom" + ) + + def test_emit_logrecord_exception_with_immutable_attributes(self): + logger, log_record_processor_mock = self._get_logger() + exc = ValueError("boom") + original_attributes = BoundedAttributes( + attributes={"custom": "value"}, + immutable=True, + extended_attributes=True, + ) + log_record = LogRecord( + observed_timestamp=0, + body="a log line", + attributes=original_attributes, + exception=exc, + ) + + logger.emit(log_record) + + self.assertNotIn( + exception_attributes.EXCEPTION_TYPE, log_record.attributes + ) + log_record_processor_mock.on_emit.assert_called_once() + log_data = log_record_processor_mock.on_emit.call_args.args[0] + attributes = dict(log_data.log_record.attributes) + self.assertEqual(attributes["custom"], "value") + self.assertEqual( + attributes[exception_attributes.EXCEPTION_TYPE], "ValueError" + ) + + def test_emit_readwrite_logrecord_uses_exception(self): + logger, log_record_processor_mock = self._get_logger() + exc = RuntimeError("kaput") + log_record = LogRecord( + observed_timestamp=0, + body="a log line", + exception=exc, + ) + readwrite = ReadWriteLogRecord( + log_record=log_record, + resource=Resource.create({}), + instrumentation_scope=logger._instrumentation_scope, + ) + + logger.emit(readwrite) + log_record_processor_mock.on_emit.assert_called_once() + log_data = log_record_processor_mock.on_emit.call_args.args[0] + attributes = dict(log_data.log_record.attributes) + self.assertEqual( + attributes[exception_attributes.EXCEPTION_TYPE], "RuntimeError" + )