fix(exporter): convert body to str as fallback

[lukaslihotzki-f]

Description

When a message body is passed to logging which cannot be encoded directly, try to convert it to a string as a fallback. This makes sense because log bodies are commonly strings, and string is also the only supported interface that is immutable and may get large, so it might make sense to offer a way to compute log strings lazily.

Fixes #4509

Type of change

Please delete options that are not relevant.

• Bug fix (non-breaking change which fixes an issue)
• New feature (non-breaking change which adds functionality)
• Breaking change (fix or feature that would cause existing functionality to not work as expected)
• This change requires a documentation update

How Has This Been Tested?

Fixes the minimal example and the OTLP log export in synapse.

Does This PR Require a Contrib Repo Change?

• Yes.
• No.

Checklist:

• Followed the style guidelines of this project
• Changelogs have been updated
• Unit tests have been added
• Documentation has been updated (is this necessary?)

[linux-foundation-easycla]

The committers listed above are authorized under a signed CLA.

• ✅ login: lukaslihotzki-f (b0ff6dc)

[jomcgi]

Could this create unexpected behaviour when complex objects passed incorrectly?
eg. we mask an actual error by logging <MyObject instance at 0x... instead of raising an exception

[lukaslihotzki-f]

This function is executed during batch processing, and not when the complex object is passed. Therefore, the exception does not carry a useful stack trace. The exception would carry the type name, but the type name is also contained in the string representation. Also, raising an exception here impacts the whole batch (all lines in it), so not raising here also has some benefits.

More importantly, Python's native logging also converts to strings by default instead of raising an exception. Therefore, OpenTelemetry should follow this approach instead of raising surprising exceptions:

import logging

class Foo:
    pass

logging.warning(Foo())
# no exception, prints `WARNING:root:<__main__.Foo object at 0x…>`

[jomcgi]

That would expand the scope of this function from serializing to the spec to transforming data to comply with the spec.

A different approach was suggested in #3389 which I think would be more appropriate here.

They sub-classed the LoggingHandler and modified it to account for this scenario.

from twisted.logger._stdlib import StringifiableFromEvent

def create_logging_handler():
    logger_provider = LoggerProvider()
    logger_provider.add_log_record_processor(
        BatchLogRecordProcessor(OTLPLogExporter(insecure=True))
    )

    class ModifiedHandler(LoggingHandler):
        def emit(self, record):
            to_str_types = (StringifiableFromEvent)
            if isinstance(record.msg, to_str_types):
                record.msg = str(record.message)
            super().emit(record)

    otel_handler = ModifiedHandler(logger_provider=logger_provider)
    return otel_handler

The logging handler already includes a translate function (here), this would make it easy to create a Logging Handler in opentelemetry-python-contrib that handles this scenario for the third party library.

There is a contrib example that we never merged here: open-telemetry/opentelemetry-python-contrib#2492

A similar issue (support for structlog) was discussed in #2993.

[lukaslihotzki-f]

Is this about the _encode_value function specifically? If so, this could be rewritten somehow. I still think that stringification should be the default, because application developers generally don't know what some library may pass to the logging function, and these exceptions result in a bad user experience for app developers integrating OpenTelemetry. For example, I decided to modify your sample to unconditionally stringify all record.msg, because synapse including all of its dependencies is huge, and I don't want to continuously maintain a to_str_types list.

Thanks for the sample. It works for me now. I already used a custom LoggingHandler subclass, so only the emit method was missing.

[lukaslihotzki-f]

Also, this PR is useful for #4514, although it may not be ideal. This indicates that the behavior is useful for general purpose, not just for the StringifiableFromEvent from twisted.

[xrmx]

I think this is the wrong place to catch that, something more like the diff below seems to work here, please note that this is on top of another PR that adds _VALID_ANY_VALUE_TYPES:

diff --git a/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py b/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py
index 368b1d8e3..b3440cdd2 100644
--- a/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py
+++ b/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py
@@ -36,7 +36,7 @@ from opentelemetry._logs import (
     get_logger_provider,
     std_to_otel,
 )
-from opentelemetry.attributes import BoundedAttributes
+from opentelemetry.attributes import _VALID_ANY_VALUE_TYPES, BoundedAttributes
 from opentelemetry.sdk.environment_variables import (
     OTEL_ATTRIBUTE_COUNT_LIMIT,
     OTEL_ATTRIBUTE_VALUE_LENGTH_LIMIT,
@@ -524,8 +524,11 @@ class LoggingHandler(logging.Handler):
             # 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):
-                # no args are provided so it's *mostly* safe to use the message template as the body
-                body = record.msg
+                #  if record.msg is not an AnyValue 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()