diff --git a/CHANGELOG.md b/CHANGELOG.md index 3c9c67be4b..9c8cd177ba 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -41,6 +41,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - `opentelemetry-instrumentation-boto`: Remove instrumentation ([#4303](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/4303)) +- `opentelemetry-instrumentation-logging`: Use `LogRecord.getMessage()` to format and extract each log record's body text to more closely match the expected usage of the logging system. As a result, all OTel log record bodies are now always strings. + Previously, if `LogRecord.msg` (which contains the format string) was set to a non-string object (e.g. `logger.warning(some_dict)`), the object was exported as-is to the OTLP body field. Now, `LogRecord.getMessage()` will convert it to to a string. + If you are passing in non-strings as the format string argument and your backend is expecting them as-is, you will need to update accordingly. + ([#4372](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/4372)) ## Version 1.40.0/0.61b0 (2026-03-04) diff --git a/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/handler.py b/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/handler.py index aa8a319fd2..8e1d8bffa9 100644 --- a/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/handler.py +++ b/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/handler.py @@ -30,7 +30,6 @@ get_logger, get_logger_provider, ) -from opentelemetry.attributes import _VALID_ANY_VALUE_TYPES from opentelemetry.context import get_current from opentelemetry.semconv._incubating.attributes import code_attributes from opentelemetry.semconv.attributes import exception_attributes @@ -168,25 +167,7 @@ def _translate(self, record: logging.LogRecord) -> LogRecord: if self.formatter: body = self.format(record) else: - # `record.getMessage()` uses `record.msg` as a template to format - # `record.args` into. There is a special case in `record.getMessage()` - # where it will only attempt formatting if args are provided, - # otherwise, it just stringifies `record.msg`. - # - # Since the OTLP body field has a type of 'any' and the logging module - # is sometimes used in such a way that objects incorrectly end up - # set as record.msg, in those cases we would like to bypass - # `record.getMessage()` completely and set the body to the object - # itself instead of its string representation. - # For more background, see: https://github.com/open-telemetry/opentelemetry-python/pull/4216 - if not record.args and not isinstance(record.msg, str): - # if record.msg is not a value we can export, cast it to string - if not isinstance(record.msg, _VALID_ANY_VALUE_TYPES): - body = str(record.msg) - else: - body = record.msg - else: - body = record.getMessage() + body = record.getMessage() # related to https://github.com/open-telemetry/opentelemetry-python/issues/3548 # Severity Text = WARN as defined in https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/logs/data-model.md#displaying-severity. diff --git a/instrumentation/opentelemetry-instrumentation-logging/tests/test_handler.py b/instrumentation/opentelemetry-instrumentation-logging/tests/test_handler.py index 68c8daaa24..ef11c93cc6 100644 --- a/instrumentation/opentelemetry-instrumentation-logging/tests/test_handler.py +++ b/instrumentation/opentelemetry-instrumentation-logging/tests/test_handler.py @@ -451,6 +451,43 @@ def test_log_body_is_always_string_with_formatter(self): logger.removeHandler(handler) + def test_simple_log_record_processor_custom_single_obj(self): + """ + Tests that logging a single non-string object uses getMessage + """ + processor, logger, handler = set_up_test_logging(logging.WARNING) + + # NOTE: the behaviour of `record.getMessage` is detailed in the + # `logging.Logger.debug` documentation: + # > The msg is the message format string, and the args are the arguments + # > which are merged into msg using the string formatting operator. [...] + # > No % formatting operation is performed on msg when no args are supplied. + + # This test uses the presence of '%s' in the first arg to determine if + # formatting was applied + + # string msg with no args - getMessage bypasses formatting and sets the string directly + logger.warning("a string with a percent-s: %s") + # string msg with args - getMessage formats args into the msg + logger.warning("a string with a percent-s: %s", "and arg") + # non-string msg with args - getMessage stringifies msg and formats args into it + logger.warning(["a non-string with a percent-s", "%s"], "and arg") + # non-string msg with no args - getMessage stringifies the object and bypasses formatting + logger.warning(["a non-string with a percent-s", "%s"]) + + logger.removeHandler(handler) + + assert processor.emit_count() == 4 + expected = [ + ("a string with a percent-s: %s"), + ("a string with a percent-s: and arg"), + ("['a non-string with a percent-s', 'and arg']"), + ("['a non-string with a percent-s', '%s']"), + ] + for index, msg in enumerate(expected): + record = processor.get_log_record(index) + self.assertEqual(record.log_record.body, msg) + @patch.dict(os.environ, {"OTEL_SDK_DISABLED": "true"}) def test_handler_root_logger_with_disabled_sdk_does_not_go_into_recursion_error( self,