Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -326,6 +326,13 @@ def _init_logging(
set_event_logger_provider(event_logger_provider)

if setup_logging_handler:
warnings.warn(
"Setting the OTel Logging handler from the SDK and the "
"`OTEL_PYTHON_LOGGING_AUTO_INSTRUMENTATION_ENABLED` are deprecated. "
"You should install the opentelemetry-instrumentation-logging",
Comment on lines +330 to +332
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

"The `OTEL_PYTHON_LOGGING_AUTO_INSTRUMENTATION_ENABLED` environment"
" variable and the `LoggingHandler` in `opentelemetry-sdk` that it controls are"
" deprecated. Install the `opentelemetry-instrumentation-logging`"
" package instead.",

DeprecationWarning,
)

# Add OTel handler
handler = LoggingHandler(
level=logging.NOTSET, logger_provider=provider
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -496,6 +496,11 @@ def __init__(
super().__init__(level=level)
self._logger_provider = logger_provider or get_logger_provider()

warnings.warn(
"This is deprecated you should use the one in opentelemetry-instrumentation-logging",
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

"`LoggingHandler` in `opentelemetry-sdk` is deprecated. Use the"
" handler from `opentelemetry-instrumentation-logging` instead.",

DeprecationWarning,
)

@staticmethod
def _get_attributes(record: logging.LogRecord) -> _ExtendedAttributes:
attributes = {
Expand Down
89 changes: 68 additions & 21 deletions opentelemetry-sdk/tests/logs/test_handler.py
Original file line number Diff line number Diff line change
Expand Up @@ -39,7 +39,7 @@
# pylint: disable=too-many-public-methods
class TestLoggingHandler(unittest.TestCase):
def test_handler_default_log_level(self):
processor, logger = set_up_test_logging(logging.NOTSET)
processor, logger, handler = set_up_test_logging(logging.NOTSET)

# Make sure debug messages are ignored by default
logger.debug("Debug message")
Expand All @@ -50,8 +50,10 @@ def test_handler_default_log_level(self):
logger.warning("Warning message")
self.assertEqual(processor.emit_count(), 1)

logger.removeHandler(handler)

def test_handler_custom_log_level(self):
processor, logger = set_up_test_logging(logging.ERROR)
processor, logger, handler = set_up_test_logging(logging.ERROR)

with self.assertLogs(level=logging.WARNING):
logger.warning("Warning message test custom log level")
Expand All @@ -64,6 +66,8 @@ def test_handler_custom_log_level(self):
logger.critical("No Time For Caution")
self.assertEqual(processor.emit_count(), 2)

logger.removeHandler(handler)

# pylint: disable=protected-access
def test_log_record_emit_noop(self):
noop_logger_provder = NoOpLoggerProvider()
Expand All @@ -78,9 +82,10 @@ def test_log_record_emit_noop(self):
with self.assertLogs(level=logging.WARNING):
logger.warning("Warning message")

logger.removeHandler(handler_mock)

def test_log_flush_noop(self):
no_op_logger_provider = NoOpLoggerProvider()
no_op_logger_provider.force_flush = Mock()

logger = logging.getLogger("foo")
handler = LoggingHandler(
Expand All @@ -91,11 +96,19 @@ def test_log_flush_noop(self):
with self.assertLogs(level=logging.WARNING):
logger.warning("Warning message")

logger.handlers[0].flush()
no_op_logger_provider.force_flush.assert_not_called()
# the LoggingHandler flush method will call the force_flush method of LoggerProvider in
# a separate thread if present. NoOpLoggerProvider is not supposed to have that
with patch(
"opentelemetry.sdk._logs._internal.threading"
) as threading_mock:
logger.handlers[0].flush()

threading_mock.Thread.assert_not_called()

logger.removeHandler(handler)

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

# Assert emit gets called for warning message
with self.assertLogs(level=logging.WARNING):
Expand All @@ -115,18 +128,22 @@ def test_log_record_no_span_context(self):
INVALID_SPAN_CONTEXT.trace_flags,
)

logger.removeHandler(handler)

def test_log_record_observed_timestamp(self):
processor, logger = set_up_test_logging(logging.WARNING)
processor, logger, handler = set_up_test_logging(logging.WARNING)

with self.assertLogs(level=logging.WARNING):
logger.warning("Warning message")

record = processor.get_log_record(0)
self.assertIsNotNone(record.log_record.observed_timestamp)

logger.removeHandler(handler)

def test_log_record_user_attributes(self):
"""Attributes can be injected into logs by adding them to the ReadWriteLogRecord"""
processor, logger = set_up_test_logging(logging.WARNING)
processor, logger, handler = set_up_test_logging(logging.WARNING)

# Assert emit gets called for warning message
with self.assertLogs(level=logging.WARNING):
Expand Down Expand Up @@ -155,9 +172,11 @@ def test_log_record_user_attributes(self):
isinstance(record.log_record.attributes, BoundedAttributes)
)

logger.removeHandler(handler)

def test_log_record_exception(self):
"""Exception information will be included in attributes"""
processor, logger = set_up_test_logging(logging.ERROR)
processor, logger, handler = set_up_test_logging(logging.ERROR)

try:
raise ZeroDivisionError("division by zero")
Expand Down Expand Up @@ -189,9 +208,11 @@ def test_log_record_exception(self):
self.assertTrue("division by zero" in stack_trace)
self.assertTrue(__file__ in stack_trace)

logger.removeHandler(handler)

def test_log_record_recursive_exception(self):
"""Exception information will be included in attributes even though it is recursive"""
processor, logger = set_up_test_logging(logging.ERROR)
processor, logger, handler = set_up_test_logging(logging.ERROR)

try:
raise ZeroDivisionError(
Expand Down Expand Up @@ -224,9 +245,11 @@ def test_log_record_recursive_exception(self):
self.assertTrue("division by zero" in stack_trace)
self.assertTrue(__file__ in stack_trace)

logger.removeHandler(handler)

def test_log_exc_info_false(self):
"""Exception information will not be included in attributes"""
processor, logger = set_up_test_logging(logging.NOTSET)
processor, logger, handler = set_up_test_logging(logging.NOTSET)

try:
raise ZeroDivisionError("division by zero")
Expand All @@ -251,8 +274,10 @@ def test_log_exc_info_false(self):
record.log_record.attributes,
)

logger.removeHandler(handler)

def test_log_record_exception_with_object_payload(self):
processor, logger = set_up_test_logging(logging.ERROR)
processor, logger, handler = set_up_test_logging(logging.ERROR)

class CustomException(Exception):
def __str__(self):
Expand Down Expand Up @@ -287,8 +312,10 @@ def __str__(self):
self.assertTrue("CustomException" in stack_trace)
self.assertTrue(__file__ in stack_trace)

logger.removeHandler(handler)

def test_log_record_trace_correlation(self):
processor, logger = set_up_test_logging(logging.WARNING)
processor, logger, handler = set_up_test_logging(logging.WARNING)

tracer = trace.TracerProvider().get_tracer(__name__)
with tracer.start_as_current_span("test") as span:
Expand Down Expand Up @@ -325,8 +352,10 @@ def test_log_record_trace_correlation(self):
span_context.trace_flags,
)

logger.removeHandler(handler)

def test_log_record_trace_correlation_deprecated(self):
processor, logger = set_up_test_logging(logging.WARNING)
processor, logger, handler = set_up_test_logging(logging.WARNING)

tracer = trace.TracerProvider().get_tracer(__name__)
with tracer.start_as_current_span("test") as span:
Expand All @@ -349,22 +378,28 @@ def test_log_record_trace_correlation_deprecated(self):
record.log_record.trace_flags, span_context.trace_flags
)

logger.removeHandler(handler)

def test_warning_without_formatter(self):
processor, logger = set_up_test_logging(logging.WARNING)
processor, logger, handler = set_up_test_logging(logging.WARNING)
logger.warning("Test message")

record = processor.get_log_record(0)
self.assertEqual(record.log_record.body, "Test message")

logger.removeHandler(handler)

def test_exception_without_formatter(self):
processor, logger = set_up_test_logging(logging.WARNING)
processor, logger, handler = set_up_test_logging(logging.WARNING)
logger.exception("Test exception")

record = processor.get_log_record(0)
self.assertEqual(record.log_record.body, "Test exception")

logger.removeHandler(handler)

def test_warning_with_formatter(self):
processor, logger = set_up_test_logging(
processor, logger, handler = set_up_test_logging(
logging.WARNING,
formatter=logging.Formatter(
"%(name)s - %(levelname)s - %(message)s"
Expand All @@ -377,8 +412,10 @@ def test_warning_with_formatter(self):
record.log_record.body, "foo - WARNING - Test message"
)

logger.removeHandler(handler)

def test_log_body_is_always_string_with_formatter(self):
processor, logger = set_up_test_logging(
processor, logger, handler = set_up_test_logging(
logging.WARNING,
formatter=logging.Formatter(
"%(name)s - %(levelname)s - %(message)s"
Expand All @@ -389,17 +426,21 @@ def test_log_body_is_always_string_with_formatter(self):
record = processor.get_log_record(0)
self.assertIsInstance(record.log_record.body, str)

logger.removeHandler(handler)

@patch.dict(os.environ, {"OTEL_SDK_DISABLED": "true"})
def test_handler_root_logger_with_disabled_sdk_does_not_go_into_recursion_error(
self,
):
processor, logger = set_up_test_logging(
processor, logger, handler = set_up_test_logging(
logging.NOTSET, root_logger=True
)
logger.warning("hello")

self.assertEqual(processor.emit_count(), 0)

logger.removeHandler(handler)

@patch.dict(os.environ, {OTEL_ATTRIBUTE_COUNT_LIMIT: "3"})
def test_otel_attribute_count_limit_respected_in_logging_handler(self):
"""Test that OTEL_ATTRIBUTE_COUNT_LIMIT is properly respected by LoggingHandler."""
Expand Down Expand Up @@ -439,6 +480,8 @@ def test_otel_attribute_count_limit_respected_in_logging_handler(self):
f"Should have 10 dropped attributes, got {record.dropped_attributes}",
)

logger.removeHandler(handler)

@patch.dict(os.environ, {OTEL_ATTRIBUTE_COUNT_LIMIT: "5"})
def test_otel_attribute_count_limit_includes_code_attributes(self):
"""Test that OTEL_ATTRIBUTE_COUNT_LIMIT applies to all attributes including code attributes."""
Expand Down Expand Up @@ -476,9 +519,11 @@ def test_otel_attribute_count_limit_includes_code_attributes(self):
f"Should have 6 dropped attributes, got {record.dropped_attributes}",
)

logger.removeHandler(handler)

def test_logging_handler_without_env_var_uses_default_limit(self):
"""Test that without OTEL_ATTRIBUTE_COUNT_LIMIT, default limit (128) should apply."""
processor, logger = set_up_test_logging(logging.WARNING)
processor, logger, handler = set_up_test_logging(logging.WARNING)

# Create a log record with many attributes (more than default limit of 128)
extra_attrs = {f"attr_{i}": f"value_{i}" for i in range(150)}
Expand All @@ -505,6 +550,8 @@ def test_logging_handler_without_env_var_uses_default_limit(self):
f"Should have 25 dropped attributes, got {record.dropped_attributes}",
)

logger.removeHandler(handler)


def set_up_test_logging(level, formatter=None, root_logger=False):
logger_provider = LoggerProvider()
Expand All @@ -515,7 +562,7 @@ def set_up_test_logging(level, formatter=None, root_logger=False):
if formatter:
handler.setFormatter(formatter)
logger.addHandler(handler)
return processor, logger
return processor, logger, handler


class FakeProcessor(LogRecordProcessor):
Expand Down
Loading