Skip to content

Backport: Fix max recursion bug by removing logging.log calls in emit (#4588) #4589

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
aabmass merged 1 commit into from
May 16, 2025
Merged

Backport: Fix max recursion bug by removing logging.log calls in emit (#4588) #4589

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
5 changes: 5 additions & 0 deletions CHANGELOG.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,11 @@ All notable changes to this project will be documented in this file.
The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/),
and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html).

## Unreleased

- Remove log messages from `BatchLogRecordProcessor.emit`, this caused the program
to crash at shutdown with a max recursion error ([#4586](https://github.com/open-telemetry/opentelemetry-python/pull/4586)).

## Version 1.33.0/0.54b0 (2025-05-09)

- Fix intermittent `Connection aborted` error when using otlp/http exporters
Expand Down
7 changes: 4 additions & 3 deletions opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/export/__init__.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -286,15 +286,16 @@ def _export(self, batch_strategy: BatchLogExportStrategy) -> None:
_logger.exception("Exception while exporting logs.")
detach(token)

# Do not add any logging.log statements to this function, they can be being routed back to this `emit` function,
# resulting in endless recursive calls that crash the program.
# See https://github.com/open-telemetry/opentelemetry-python/issues/4261
def emit(self, log_data: LogData) -> None:
if self._shutdown:
_logger.info("Shutdown called, ignoring log.")
return
if self._pid != os.getpid():
_BSP_RESET_ONCE.do_once(self._at_fork_reinit)

if len(self._queue) == self._max_queue_size:
_logger.warning("Queue full, dropping log.")
# This will drop a log from the right side if the queue is at _max_queue_length.
self._queue.appendleft(log_data)
if len(self._queue) >= self._max_export_batch_size:
self._worker_awaken.set()
Expand Down
42 changes: 36 additions & 6 deletions opentelemetry-sdk/tests/logs/test_export.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,8 +21,11 @@
import unittest
import weakref
from concurrent.futures import ThreadPoolExecutor
from sys import version_info
from unittest.mock import Mock, patch

from pytest import mark

from opentelemetry._logs import SeverityNumber
from opentelemetry.sdk import trace
from opentelemetry.sdk._logs import (
Expand Down Expand Up @@ -347,6 +350,39 @@ def test_emit_call_log_record(self):
logger.error("error")
self.assertEqual(log_record_processor.emit.call_count, 1)

@mark.skipif(
version_info < (3, 10),
reason="assertNoLogs only exists in python 3.10+.",
)
def test_logging_lib_not_invoked_in_batch_log_record_emit(self): # pylint: disable=no-self-use
# See https://github.com/open-telemetry/opentelemetry-python/issues/4261
exporter = Mock()
processor = BatchLogRecordProcessor(exporter)
logger_provider = LoggerProvider(
resource=SDKResource.create(
{
"service.name": "shoppingcart",
"service.instance.id": "instance-12",
}
),
)
logger_provider.add_log_record_processor(processor)
handler = LoggingHandler(
level=logging.INFO, logger_provider=logger_provider
)
sdk_logger = logging.getLogger("opentelemetry.sdk")
# Attach OTLP handler to SDK logger
sdk_logger.addHandler(handler)
# If `emit` calls logging.log then this test will throw a maximum recursion depth exceeded exception and fail.
try:
with self.assertNoLogs(sdk_logger, logging.NOTSET):
processor.emit(EMPTY_LOG)
processor.shutdown()
with self.assertNoLogs(sdk_logger, logging.NOTSET):
processor.emit(EMPTY_LOG)
finally:
sdk_logger.removeHandler(handler)

def test_args(self):
exporter = InMemoryLogExporter()
log_record_processor = BatchLogRecordProcessor(
Expand Down Expand Up @@ -517,12 +553,6 @@ def test_logs_flushed_before_shutdown_and_dropped_after_shutdown(self):
exporter.export.assert_called_once_with([EMPTY_LOG])
self.assertTrue(exporter._stopped)

with self.assertLogs(level="INFO") as log:
# This log should not be flushed.
log_record_processor.emit(EMPTY_LOG)
self.assertEqual(len(log.output), 1)
self.assertEqual(len(log.records), 1)
self.assertIn("Shutdown called, ignoring log.", log.output[0])
exporter.export.assert_called_once()

# pylint: disable=no-self-use
Expand Down
Loading