how to get "body" to use what's specified in logging setformatters?

[jesumyip]

Using these python modules:

opentelemetry-instrumentation-fastapi==0.39b0
opentelemetry-api==1.18.0
opentelemetry-sdk==1.18.0
opentelemetry-exporter-otlp==1.18.0
opentelemetry-exporter-otlp-proto-grpc==1.18.0
opentelemetry-exporter-otlp-proto-http==1.18.0
opentelemetry-instrumentation==0.39b0
opentelemetry-proto==1.18.0
opentelemetry-semantic-conventions==0.39b0
opentelemetry-util-http==0.39b0
opentelemetry-instrumentation-logging==0.39b0

I have the following code snippet:

console_log_exporter = ConsoleLogExporter()
logger_provider = LoggerProvider(
    resource=Resource.create({})
)

set_logger_provider(logger_provider)
logger_provider.add_log_record_processor(SimpleLogRecordProcessor(console_log_exporter))
otel_log_handler = LoggingHandler(logger_provider=logger_provider)
LoggingInstrumentor().instrument()
logging.getLogger().addHandler(otel_log_handler)

I have the following env vars set:

OTEL_PYTHON_LOG_CORRELATION=true
OTEL_PYTHON_LOG_FORMAT=%(pathname)s:%(funcName)s:%(lineno)d:%(levelname)s:%(message)s
OTEL_PYTHON_LOG_LEVEL=info

Whenever I do something like logging.info("Hi there, Mr. Pineapple!"), I see that the output JSON has something that looks like this:

{
    "body": "Hi there, Mr. Pineapple!",
    "severity_number": "<SeverityNumber.INFO: 9>",
    "severity_text": "INFO",
    "attributes": {
        "otelSpanID": "2e94f2400eb2f2c9",
        "otelTraceID": "1b63d84a5a4faec3b1dd77477d1d52df",
        "otelTraceSampled": true,
        "otelServiceName": "my-fruit-service"
    },
    "timestamp": "2023-06-19T06:48:28.605903Z",
    "trace_id": "0x1b63d84a5a4faec3b1dd77477d1d52df",
    "span_id": "0x2e94f2400eb2f2c9",
    "trace_flags": 1,
    "resource": "BoundedAttributes({'telemetry.sdk.language': 'python', 'telemetry.sdk.name': 'opentelemetry', 'telemetry.sdk.version': '1.18.0', 'service.instance.id': 'dev', 'service.name': 'my-fruit-service'}, maxlen=None)"
}

I am expecting "body" to have the format dictated by OTEL_PYTHON_LOG_FORMAT, but it does not. How can I get "body" to also contain for example lineno, pathname, etc? @srikanthccv

[jesumyip]

I guess the problem is in

opentelemetry-python/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py

Line 474 in 6b9f389

def _translate(self, record: logging.LogRecord) -> LogRecord:

it is only doing body=record.getMessage(). So, it is completely ignoring any formatters that has been configured.

so a possible fix would be to change https://github.com/open-telemetry/opentelemetry-python/blob/6b9f389940ec0123d5dafc7cb400fc23c6f691c6/opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py#LL497C9-L497C51 to:

msg = self.format(record)
record.msg = msg
self._logger.emit(self._translate(record))

For those who can't wait for the update, you can easily create a new class and use it instead of LoggingHandler.

class FormattedLoggingHandler(LoggingHandler):
    def emit(self, record: logging.LogRecord) -> None:
        """
        Emit a record.

        The record is translated to OTel format, and then sent across the pipeline.
        """
        msg = self.format(record)
        record.msg = msg
        self._logger.emit(self._translate(record))

.
.
.
.
    # Something along these lines (but with better error handling!!)
    otel_log_handler = FormattedLoggingHandler(logger_provider=logger_provider)
    LoggingInstrumentor().instrument()
    logFormatter = logging.Formatter(fmt=os.getenv("OTEL_PYTHON_LOG_FORMAT", None))
    otel_log_handler.setFormatter(logFormatter)
    logging.getLogger().addHandler(otel_log_handler)

[jesumyip]

small update, since I don't use args, this code:

       msg = self.format(record)
       record.msg = msg
       self._logger.emit(self._translate(record))

should be changed to:

       msg = self.format(record)
       record.msg = msg
       record.args = None
       self._logger.emit(self._translate(record))

or you will hit this error:

  File "/usr/local/lib/python3.11/logging/__init__.py", line 377, in getMessage
    msg = msg % self.args
          ~~~~^~~~~~~~~~~
TypeError: not all arguments converted during string formatting

[aabmass]

@jesumyip thanks for reporting this, would you mind submitting a PR?

[lzchen]

I believe this pr would address this issue

[jeremydvoss]

This should be solved by #4166 . @jesumyip can you confirm?

[lzchen]

Closing due to inactivity.