Skip to content

Handle "LogRecord.exc_info" being a string #4699

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.

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

Open
wants to merge 6 commits into
base: main
Choose a base branch
from
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
2 changes: 2 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0

## Unreleased

- Fix logic to deal with `LoggingHandler.exc_info` occasionally being a string ([#4699](https://github.com/open-telemetry/opentelemetry-python/pull/4699))

## Version 1.36.0/0.57b0 (2025-07-29)

- Add missing Prometheus exporter documentation
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@
import concurrent.futures
import json
import logging
import sys
import threading
import traceback
import warnings
Expand Down Expand Up @@ -568,6 +569,9 @@ def _get_attributes(record: logging.LogRecord) -> _ExtendedAttributes:
attributes[code_attributes.CODE_FUNCTION_NAME] = record.funcName
attributes[code_attributes.CODE_LINE_NUMBER] = record.lineno

if isinstance(record.exc_info, str):
Copy link
Member

Choose a reason for hiding this comment

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

Should we add a comment here to explain the motivation?

Copy link
Author

@jourdanrodrigues jourdanrodrigues Jul 28, 2025

Choose a reason for hiding this comment

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

I wasn't able to track down why nor how this happens (I tried as hard as I could), like if this was some misconfiguration in my work's project or some lib doing this, and I left such comment in the test that preserves this behavior.

Unfortunately, the only thing I know is that it can be a string and this fixed it in my case.

Copy link
Member

Choose a reason for hiding this comment

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

Perhaps a line explaining the motivation would help readers? Doesn't have to be specific, just that the check and overwrite are defensive, preventing errors in some implementations.

Copy link
Member

Choose a reason for hiding this comment

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

@jourdanrodrigues are you setting any kind of logging.Filter in the LoggingHandler?

record.exc_info = sys.exc_info()

if record.exc_info:
exctype, value, tb = record.exc_info
if exctype is not None:
Expand Down
35 changes: 35 additions & 0 deletions opentelemetry-sdk/tests/logs/test_handler.py
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,8 @@

import logging
import os
import sys
import traceback
import unittest
from unittest.mock import Mock, patch

Expand Down Expand Up @@ -48,6 +50,39 @@ def test_handler_default_log_level(self):
logger.warning("Warning message")
self.assertEqual(processor.emit_count(), 1)

def test_handler_error_exc_info(self):
processor, logger = set_up_test_logging(logging.NOTSET)

class CustomException(Exception):
pass

try:
raise CustomException("Custom exception")
except CustomException as exception:
exc_info = (type(exception), exception, exception.__traceback__)
else:
exc_info = "Second stringified exception"

exc_info_values = [
# Don't know what caused it in my context, so I'm relying on mocks to replicate the behavior.
# First the `record.exc_info` becomes a string somehow, then `sys.exc_info` brings the tuple.
"First stringified exception",
exc_info,
]

with patch.object(sys, "exc_info", side_effect=exc_info_values):
logger.exception("Exception message") # Should not raise exception

assert processor.emit_count() == 1

attributes = processor.log_data_emitted[0].log_record.attributes._dict
assert attributes["exception.type"] == "CustomException"
assert attributes["exception.message"] == str(exc_info[1])
assert isinstance(exc_info, tuple)
assert attributes["exception.stacktrace"] == "".join(
traceback.format_exception(*exc_info)
)

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

Expand Down
Loading