diff --git a/CHANGELOG.md b/CHANGELOG.md index e76232d5ac..c09e71a5fb 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,6 +9,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added - Add global LogEmitterProvider and convenience function get_log_emitter ([#1901](https://github.com/open-telemetry/opentelemetry-python/pull/1901)) +- Add OTLPHandler for standard library logging module + ([#1903](https://github.com/open-telemetry/opentelemetry-python/pull/1903)) ### Changed - Updated `opentelemetry-opencensus-exporter` to use `service_name` of spans instead of resource diff --git a/opentelemetry-sdk/src/opentelemetry/sdk/logs/__init__.py b/opentelemetry-sdk/src/opentelemetry/sdk/logs/__init__.py index f93987e08d..e436461e53 100644 --- a/opentelemetry-sdk/src/opentelemetry/sdk/logs/__init__.py +++ b/opentelemetry-sdk/src/opentelemetry/sdk/logs/__init__.py @@ -21,9 +21,10 @@ from opentelemetry.sdk.environment_variables import ( OTEL_PYTHON_LOG_EMITTER_PROVIDER, ) -from opentelemetry.sdk.logs.severity import SeverityNumber +from opentelemetry.sdk.logs.severity import SeverityNumber, std_to_otlp from opentelemetry.sdk.resources import Resource from opentelemetry.sdk.util.instrumentation import InstrumentationInfo +from opentelemetry.trace import get_current_span from opentelemetry.trace.span import TraceFlags from opentelemetry.util._providers import _load_provider from opentelemetry.util.types import Attributes @@ -111,6 +112,48 @@ def force_flush(self, timeout_millis: int = 30000): """ +class OTLPHandler(logging.Handler): + """A handler class which writes logging records, in OTLP format, to + a network destination or file. + """ + + def __init__(self, level=logging.NOTSET, log_emitter=None) -> None: + super().__init__(level=level) + self._log_emitter = log_emitter or get_log_emitter(__name__) + + def _translate(self, record: logging.LogRecord) -> LogRecord: + timestamp = int(record.created * 1e9) + span_context = get_current_span().get_span_context() + # TODO: attributes (or resource attributes?) from record metadata + attributes: Attributes = {} + severity_number = std_to_otlp(record.levelno) + return LogRecord( + timestamp=timestamp, + trace_id=span_context.trace_id, + span_id=span_context.span_id, + trace_flags=span_context.trace_flags, + severity_text=record.levelname, + severity_number=severity_number, + body=record.getMessage(), + resource=self._log_emitter.resource, + attributes=attributes, + ) + + def emit(self, record: logging.LogRecord) -> None: + """ + Emit a record. + + The record is translated to OTLP format, and then sent across the pipeline. + """ + self._log_emitter.emit(self._translate(record)) + + def flush(self) -> None: + """ + Flushes the logging output. + """ + self._log_emitter.flush() + + class LogEmitter: # TODO: Add multi_log_processor def __init__( @@ -121,6 +164,10 @@ def __init__( self._resource = resource self._instrumentation_info = instrumentation_info + @property + def resource(self): + return self._resource + def emit(self, record: LogRecord): # TODO: multi_log_processor.emit pass @@ -142,6 +189,10 @@ def __init__( if shutdown_on_exit: self._at_exit_handler = atexit.register(self.shutdown) + @property + def resource(self): + return self._resource + def get_log_emitter( self, instrumenting_module_name: str, diff --git a/opentelemetry-sdk/src/opentelemetry/sdk/logs/severity.py b/opentelemetry-sdk/src/opentelemetry/sdk/logs/severity.py index 13a9d4e6c3..c0509ea2c1 100644 --- a/opentelemetry-sdk/src/opentelemetry/sdk/logs/severity.py +++ b/opentelemetry-sdk/src/opentelemetry/sdk/logs/severity.py @@ -54,3 +54,63 @@ class SeverityNumber(enum.Enum): FATAL2 = 22 FATAL3 = 23 FATAL4 = 24 + + +_STD_TO_OTLP = { + 10: SeverityNumber.DEBUG, + 11: SeverityNumber.DEBUG2, + 12: SeverityNumber.DEBUG3, + 13: SeverityNumber.DEBUG4, + 14: SeverityNumber.DEBUG4, + 15: SeverityNumber.DEBUG4, + 16: SeverityNumber.DEBUG4, + 17: SeverityNumber.DEBUG4, + 18: SeverityNumber.DEBUG4, + 19: SeverityNumber.DEBUG4, + 20: SeverityNumber.INFO, + 21: SeverityNumber.INFO2, + 22: SeverityNumber.INFO3, + 23: SeverityNumber.INFO4, + 24: SeverityNumber.INFO4, + 25: SeverityNumber.INFO4, + 26: SeverityNumber.INFO4, + 27: SeverityNumber.INFO4, + 28: SeverityNumber.INFO4, + 29: SeverityNumber.INFO4, + 30: SeverityNumber.WARN, + 31: SeverityNumber.WARN2, + 32: SeverityNumber.WARN3, + 33: SeverityNumber.WARN4, + 34: SeverityNumber.WARN4, + 35: SeverityNumber.WARN4, + 36: SeverityNumber.WARN4, + 37: SeverityNumber.WARN4, + 38: SeverityNumber.WARN4, + 39: SeverityNumber.WARN4, + 40: SeverityNumber.ERROR, + 41: SeverityNumber.ERROR2, + 42: SeverityNumber.ERROR3, + 43: SeverityNumber.ERROR4, + 44: SeverityNumber.ERROR4, + 45: SeverityNumber.ERROR4, + 46: SeverityNumber.ERROR4, + 47: SeverityNumber.ERROR4, + 48: SeverityNumber.ERROR4, + 49: SeverityNumber.ERROR4, + 50: SeverityNumber.FATAL, + 51: SeverityNumber.FATAL2, + 52: SeverityNumber.FATAL3, + 53: SeverityNumber.FATAL4, +} + + +def std_to_otlp(levelno: int) -> SeverityNumber: + """ + Map python log levelno as defined in https://docs.python.org/3/library/logging.html#logging-levels + to OTLP log severity number. + """ + if levelno < 10: + return SeverityNumber.UNSPECIFIED + if levelno > 53: + return SeverityNumber.FATAL4 + return _STD_TO_OTLP[levelno] diff --git a/opentelemetry-sdk/tests/logs/test_handler.py b/opentelemetry-sdk/tests/logs/test_handler.py new file mode 100644 index 0000000000..1d1b84f0fd --- /dev/null +++ b/opentelemetry-sdk/tests/logs/test_handler.py @@ -0,0 +1,84 @@ +# 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. + +import logging +import unittest +from unittest.mock import Mock + +from opentelemetry.sdk import trace +from opentelemetry.sdk.logs import LogEmitter, OTLPHandler +from opentelemetry.sdk.logs.severity import SeverityNumber +from opentelemetry.trace import INVALID_SPAN_CONTEXT + + +def get_logger(level=logging.NOTSET, log_emitter=None): + logger = logging.getLogger(__name__) + handler = OTLPHandler(level=level, log_emitter=log_emitter) + logger.addHandler(handler) + return logger + + +class TestOTLPHandler(unittest.TestCase): + def test_handler_default_log_level(self): + emitter_mock = Mock(spec=LogEmitter) + logger = get_logger(log_emitter=emitter_mock) + # Make sure debug messages are ignored by default + logger.debug("Debug message") + self.assertEqual(emitter_mock.emit.call_count, 0) + # Assert emit gets called for warning message + logger.warning("Wanrning message") + self.assertEqual(emitter_mock.emit.call_count, 1) + + def test_handler_custom_log_level(self): + emitter_mock = Mock(spec=LogEmitter) + logger = get_logger(level=logging.ERROR, log_emitter=emitter_mock) + logger.warning("Warning message test custom log level") + # Make sure any log with level < ERROR is ignored + self.assertEqual(emitter_mock.emit.call_count, 0) + logger.error("Mumbai, we have a major problem") + logger.critical("No Time For Caution") + self.assertEqual(emitter_mock.emit.call_count, 2) + + def test_log_record_no_span_context(self): + emitter_mock = Mock(spec=LogEmitter) + logger = get_logger(log_emitter=emitter_mock) + # Assert emit gets called for warning message + logger.warning("Wanrning message") + args, _ = emitter_mock.emit.call_args_list[0] + log_record = args[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 + ) + + def test_log_record_trace_correlation(self): + emitter_mock = Mock(spec=LogEmitter) + logger = get_logger(log_emitter=emitter_mock) + + tracer = trace.TracerProvider().get_tracer(__name__) + with tracer.start_as_current_span("test") as span: + logger.critical("Critical message within span") + + args, _ = emitter_mock.emit.call_args_list[0] + log_record = args[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) + 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)