From 43986ba6defb80f8bef8db56f099aed2796c1f84 Mon Sep 17 00:00:00 2001 From: Pablo Collins Date: Tue, 11 Mar 2025 14:30:18 -0400 Subject: [PATCH 1/7] Add ClearLoggingHandlers test helper --- opentelemetry-sdk/tests/test_configurator.py | 55 ++++++++++++++++++-- 1 file changed, 52 insertions(+), 3 deletions(-) diff --git a/opentelemetry-sdk/tests/test_configurator.py b/opentelemetry-sdk/tests/test_configurator.py index 12cfd5c1d2e..d3d22c3e435 100644 --- a/opentelemetry-sdk/tests/test_configurator.py +++ b/opentelemetry-sdk/tests/test_configurator.py @@ -15,10 +15,11 @@ # pylint: skip-file from __future__ import annotations -from logging import WARNING, getLogger +import logging +from logging import getLogger, WARNING from os import environ from typing import Iterable, Optional, Sequence -from unittest import TestCase, mock +from unittest import mock, TestCase from unittest.mock import Mock, patch from pytest import raises @@ -58,7 +59,7 @@ MetricReader, ) from opentelemetry.sdk.metrics.view import Aggregation -from opentelemetry.sdk.resources import SERVICE_NAME, Resource +from opentelemetry.sdk.resources import Resource, SERVICE_NAME from opentelemetry.sdk.trace.export import ConsoleSpanExporter from opentelemetry.sdk.trace.id_generator import IdGenerator, RandomIdGenerator from opentelemetry.sdk.trace.sampling import ( @@ -1076,3 +1077,51 @@ def test_custom_configurator(self, mock_init_comp): "sampler": "TEST_SAMPLER", } mock_init_comp.assert_called_once_with(**kwargs) + + +class ClearLoggingHandlers: + def __init__(self): + self.root_logger = getLogger() + self.original_handlers = None + + def __enter__(self): + # Save original state + self.original_handlers = self.root_logger.handlers[:] + # Remove all handlers + self.root_logger.handlers = [] + return self + + def __exit__(self, exc_type, exc_val, exc_tb): + # Restore original state + self.root_logger.handlers = [] + for handler in self.original_handlers: + self.root_logger.addHandler(handler) + + +class TestClearLoggingHandlers(TestCase): + def test_preserves_handlers(self): + root_logger = getLogger() # Get the root logger + initial_handlers = root_logger.handlers[ + : + ] # Save initial test environment handlers + + # Add our test handler + test_handler = logging.StreamHandler() + root_logger.addHandler(test_handler) + expected_handlers = initial_handlers + [test_handler] + + with ClearLoggingHandlers(): + # Should have no handlers during the test + self.assertEqual(len(root_logger.handlers), 0) + + # Add a temporary handler that should get cleaned up + temp_handler = logging.StreamHandler() + root_logger.addHandler(temp_handler) + + # After the test, should be back to initial handlers plus our test handler + self.assertEqual(len(root_logger.handlers), len(expected_handlers)) + for h1, h2 in zip(root_logger.handlers, expected_handlers): + self.assertIs(h1, h2) + + # Cleanup our test handler + root_logger.removeHandler(test_handler) From 97014576f2e9e96ecc22f7e2ad3e755786c91270 Mon Sep 17 00:00:00 2001 From: Pablo Collins Date: Tue, 11 Mar 2025 15:50:24 -0400 Subject: [PATCH 2/7] Monkeypatch basicConfig --- .../sdk/_configuration/__init__.py | 31 +++++++++++++++++++ opentelemetry-sdk/tests/test_configurator.py | 26 ++++++++++++++++ 2 files changed, 57 insertions(+) diff --git a/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py b/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py index c1852edd957..6f207c5e694 100644 --- a/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py +++ b/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py @@ -253,6 +253,37 @@ def _init_logging( set_event_logger_provider(event_logger_provider) if setup_logging_handler: + # noinspection PyPep8Naming + original_basicConfig = logging.basicConfig + + # noinspection PyPep8Naming + def patched_basicConfig(*args, **kwargs): + # Get the root logger + root = logging.getLogger() + + # Check if the only handler is our OTel handler + has_only_otel = len(root.handlers) == 1 and isinstance( + root.handlers[0], LoggingHandler + ) + + if has_only_otel: + # Temporarily remove OTel handler + otel_handler = root.handlers[0] + root.handlers = [] + + # Call original basicConfig + original_basicConfig(*args, **kwargs) + + # Add OTel handler back + root.addHandler(otel_handler) + else: + # Normal behavior + original_basicConfig(*args, **kwargs) + + # Apply the monkey patch + logging.basicConfig = patched_basicConfig + + # Add OTel handler handler = LoggingHandler( level=logging.NOTSET, logger_provider=provider ) diff --git a/opentelemetry-sdk/tests/test_configurator.py b/opentelemetry-sdk/tests/test_configurator.py index d3d22c3e435..24d744fa5ef 100644 --- a/opentelemetry-sdk/tests/test_configurator.py +++ b/opentelemetry-sdk/tests/test_configurator.py @@ -842,6 +842,32 @@ def test_initialize_components_kwargs( True, ) + def test_basicConfig_works_with_otel_handler(self): + with ClearLoggingHandlers(): + # Initialize auto-instrumentation with logging enabled + _init_logging( + {"otlp": DummyOTLPLogExporter}, + Resource.create({}), + setup_logging_handler=True, + ) + + # Call basicConfig - this should work despite OTel handler being present + logging.basicConfig(level=logging.INFO) + + # Verify a StreamHandler was added + root_logger = logging.getLogger() + stream_handlers = [ + h + for h in root_logger.handlers + if isinstance(h, logging.StreamHandler) + and not isinstance(h, LoggingHandler) + ] + self.assertEqual( + len(stream_handlers), + 1, + "basicConfig should add a StreamHandler even when OTel handler exists", + ) + class TestMetricsInit(TestCase): def setUp(self): From 856171ab06ef2b9c7c594a7ba8d712bdc382d6e5 Mon Sep 17 00:00:00 2001 From: Pablo Collins Date: Tue, 11 Mar 2025 16:02:25 -0400 Subject: [PATCH 3/7] Make DummyOTLPLogExporter subclass LogExporter --- opentelemetry-sdk/tests/test_configurator.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/opentelemetry-sdk/tests/test_configurator.py b/opentelemetry-sdk/tests/test_configurator.py index 24d744fa5ef..1715227a5b4 100644 --- a/opentelemetry-sdk/tests/test_configurator.py +++ b/opentelemetry-sdk/tests/test_configurator.py @@ -45,6 +45,7 @@ _OTelSDKConfigurator, ) from opentelemetry.sdk._logs import LoggingHandler +from opentelemetry.sdk._logs._internal.export import LogExporter from opentelemetry.sdk._logs.export import ConsoleLogExporter from opentelemetry.sdk.environment_variables import ( OTEL_TRACES_SAMPLER, @@ -204,7 +205,7 @@ class OTLPSpanExporter: pass -class DummyOTLPLogExporter: +class DummyOTLPLogExporter(LogExporter): def __init__(self, *args, **kwargs): self.export_called = False From f2babd3419c17ebef401d701a4bd65622b30d25a Mon Sep 17 00:00:00 2001 From: Pablo Collins Date: Tue, 11 Mar 2025 18:17:44 -0400 Subject: [PATCH 4/7] Minor refactor of basic config patch --- .../sdk/_configuration/__init__.py | 58 ++++++++++--------- 1 file changed, 30 insertions(+), 28 deletions(-) diff --git a/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py b/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py index 6f207c5e694..57154112c93 100644 --- a/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py +++ b/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py @@ -253,41 +253,43 @@ def _init_logging( set_event_logger_provider(event_logger_provider) if setup_logging_handler: - # noinspection PyPep8Naming - original_basicConfig = logging.basicConfig + _patch_basic_config() - # noinspection PyPep8Naming - def patched_basicConfig(*args, **kwargs): - # Get the root logger - root = logging.getLogger() + # Add OTel handler + handler = LoggingHandler( + level=logging.NOTSET, logger_provider=provider + ) + logging.getLogger().addHandler(handler) - # Check if the only handler is our OTel handler - has_only_otel = len(root.handlers) == 1 and isinstance( - root.handlers[0], LoggingHandler - ) - if has_only_otel: - # Temporarily remove OTel handler - otel_handler = root.handlers[0] - root.handlers = [] +def _patch_basic_config(): + original_basic_config = logging.basicConfig - # Call original basicConfig - original_basicConfig(*args, **kwargs) + def patched_basic_config(*args, **kwargs): + # Get the root logger + root = logging.getLogger() - # Add OTel handler back - root.addHandler(otel_handler) - else: - # Normal behavior - original_basicConfig(*args, **kwargs) + # Check if the only handler is our OTel handler + has_only_otel = len(root.handlers) == 1 and isinstance( + root.handlers[0], LoggingHandler + ) - # Apply the monkey patch - logging.basicConfig = patched_basicConfig + if has_only_otel: + # Temporarily remove OTel handler + otel_handler = root.handlers[0] + root.handlers = [] - # Add OTel handler - handler = LoggingHandler( - level=logging.NOTSET, logger_provider=provider - ) - logging.getLogger().addHandler(handler) + # Call original basicConfig + original_basic_config(*args, **kwargs) + + # Add OTel handler back + root.addHandler(otel_handler) + else: + # Normal behavior + original_basic_config(*args, **kwargs) + + # Apply the monkey patch + logging.basicConfig = patched_basic_config def _import_exporters( From 93d924228c169f447c62d7aab225a6cfa8e59584 Mon Sep 17 00:00:00 2001 From: Pablo Collins Date: Wed, 12 Mar 2025 13:12:11 -0400 Subject: [PATCH 5/7] Add unit test --- .../sdk/_configuration/__init__.py | 11 ---- opentelemetry-sdk/tests/test_configurator.py | 57 ++++++++++++------- 2 files changed, 37 insertions(+), 31 deletions(-) diff --git a/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py b/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py index 57154112c93..f064bc49196 100644 --- a/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py +++ b/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py @@ -266,29 +266,18 @@ def _patch_basic_config(): original_basic_config = logging.basicConfig def patched_basic_config(*args, **kwargs): - # Get the root logger root = logging.getLogger() - - # Check if the only handler is our OTel handler has_only_otel = len(root.handlers) == 1 and isinstance( root.handlers[0], LoggingHandler ) - if has_only_otel: - # Temporarily remove OTel handler otel_handler = root.handlers[0] root.handlers = [] - - # Call original basicConfig original_basic_config(*args, **kwargs) - - # Add OTel handler back root.addHandler(otel_handler) else: - # Normal behavior original_basic_config(*args, **kwargs) - # Apply the monkey patch logging.basicConfig = patched_basic_config diff --git a/opentelemetry-sdk/tests/test_configurator.py b/opentelemetry-sdk/tests/test_configurator.py index 1715227a5b4..9fda75b66f0 100644 --- a/opentelemetry-sdk/tests/test_configurator.py +++ b/opentelemetry-sdk/tests/test_configurator.py @@ -16,10 +16,10 @@ from __future__ import annotations import logging -from logging import getLogger, WARNING +from logging import WARNING, getLogger from os import environ from typing import Iterable, Optional, Sequence -from unittest import mock, TestCase +from unittest import TestCase, mock from unittest.mock import Mock, patch from pytest import raises @@ -60,7 +60,7 @@ MetricReader, ) from opentelemetry.sdk.metrics.view import Aggregation -from opentelemetry.sdk.resources import Resource, SERVICE_NAME +from opentelemetry.sdk.resources import SERVICE_NAME, Resource from opentelemetry.sdk.trace.export import ConsoleSpanExporter from opentelemetry.sdk.trace.id_generator import IdGenerator, RandomIdGenerator from opentelemetry.sdk.trace.sampling import ( @@ -845,23 +845,19 @@ def test_initialize_components_kwargs( def test_basicConfig_works_with_otel_handler(self): with ClearLoggingHandlers(): - # Initialize auto-instrumentation with logging enabled _init_logging( {"otlp": DummyOTLPLogExporter}, Resource.create({}), setup_logging_handler=True, ) - # Call basicConfig - this should work despite OTel handler being present logging.basicConfig(level=logging.INFO) - # Verify a StreamHandler was added root_logger = logging.getLogger() stream_handlers = [ h for h in root_logger.handlers if isinstance(h, logging.StreamHandler) - and not isinstance(h, LoggingHandler) ] self.assertEqual( len(stream_handlers), @@ -869,6 +865,38 @@ def test_basicConfig_works_with_otel_handler(self): "basicConfig should add a StreamHandler even when OTel handler exists", ) + def test_basicConfig_preserves_otel_handler(self): + with ClearLoggingHandlers(): + _init_logging( + {"otlp": DummyOTLPLogExporter}, + Resource.create({}), + setup_logging_handler=True, + ) + + root_logger = logging.getLogger() + self.assertEqual( + len(root_logger.handlers), + 1, + "Should be exactly one OpenTelemetry LoggingHandler", + ) + handler = root_logger.handlers[0] + self.assertIsInstance(handler, LoggingHandler) + + logging.basicConfig() + + self.assertGreater(len(root_logger.handlers), 1) + + logging_handlers = [ + h + for h in root_logger.handlers + if isinstance(h, LoggingHandler) + ] + self.assertEqual( + len(logging_handlers), + 1, + "Should still have exactly one OpenTelemetry LoggingHandler", + ) + class TestMetricsInit(TestCase): def setUp(self): @@ -1112,14 +1140,11 @@ def __init__(self): self.original_handlers = None def __enter__(self): - # Save original state self.original_handlers = self.root_logger.handlers[:] - # Remove all handlers self.root_logger.handlers = [] return self def __exit__(self, exc_type, exc_val, exc_tb): - # Restore original state self.root_logger.handlers = [] for handler in self.original_handlers: self.root_logger.addHandler(handler) @@ -1127,28 +1152,20 @@ def __exit__(self, exc_type, exc_val, exc_tb): class TestClearLoggingHandlers(TestCase): def test_preserves_handlers(self): - root_logger = getLogger() # Get the root logger - initial_handlers = root_logger.handlers[ - : - ] # Save initial test environment handlers + root_logger = getLogger() + initial_handlers = root_logger.handlers[:] - # Add our test handler test_handler = logging.StreamHandler() root_logger.addHandler(test_handler) expected_handlers = initial_handlers + [test_handler] with ClearLoggingHandlers(): - # Should have no handlers during the test self.assertEqual(len(root_logger.handlers), 0) - - # Add a temporary handler that should get cleaned up temp_handler = logging.StreamHandler() root_logger.addHandler(temp_handler) - # After the test, should be back to initial handlers plus our test handler self.assertEqual(len(root_logger.handlers), len(expected_handlers)) for h1, h2 in zip(root_logger.handlers, expected_handlers): self.assertIs(h1, h2) - # Cleanup our test handler root_logger.removeHandler(test_handler) From e3f42c111f642ac3a43d96cb092500b659abb058 Mon Sep 17 00:00:00 2001 From: Pablo Collins Date: Mon, 17 Mar 2025 11:22:14 -0400 Subject: [PATCH 6/7] Add changelog entry --- CHANGELOG.md | 2 ++ 1 file changed, 2 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 07d3121668e..5f4fe166624 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -17,6 +17,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ([#4494](https://github.com/open-telemetry/opentelemetry-python/pull/4494)) - Improve CI by cancelling stale runs and setting timeouts ([#4498](https://github.com/open-telemetry/opentelemetry-python/pull/4498)) +- Patch logging.basicConfig so OTel logs don't cause console logs to disappear + ([#4436](https://github.com/open-telemetry/opentelemetry-python/pull/4436)) ## Version 1.31.0/0.52b0 (2025-03-12) From b70516cbaf77a659dda9ec9ea74debb48dfbec7c Mon Sep 17 00:00:00 2001 From: Pablo Collins Date: Mon, 31 Mar 2025 10:57:41 -0400 Subject: [PATCH 7/7] Address PR feedback --- .../src/opentelemetry/sdk/_configuration/__init__.py | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py b/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py index f064bc49196..745a83385f9 100644 --- a/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py +++ b/opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py @@ -271,8 +271,7 @@ def patched_basic_config(*args, **kwargs): root.handlers[0], LoggingHandler ) if has_only_otel: - otel_handler = root.handlers[0] - root.handlers = [] + otel_handler = root.handlers.pop() original_basic_config(*args, **kwargs) root.addHandler(otel_handler) else: