Log format "printf-style" provocates encoding issues

[Tobias Flühmann]

Hi everyone

Currently most of the logging entries use the "printf-stlye" format for log lines with variables. Like that a custom format could probably not be applied correctly to the log line since the variable is not passed to the formatter.
Example:

I want to format all the log lines as json in my app.

import logging
import logging.handlers
import json
JSON_LOG_FORMAT = '{"severity": "%(levelname)s", "message":"%(message)s"}'
logging.basicConfig(
    level=logging.INFO,
    format=JSON_LOG_FORMAT
)

class DefaultLoggerAdapter(logging.LoggerAdapter):
    def process(self, msg, kwargs):
        msg = json.dumps(str(msg))[1:-1] # escape the message as json and cut the last and the first character since it's a quote
        return msg, kwargs

log = logging.getLogger("my-app")

log = DefaultLoggerAdapter(log, {})

log.info(' %s', ' "this is my message" ')

With the example code above the output is something like:
{"severity": "INFO", "message": " "this is my message" "}
It does not produce a valid json format in that case, because the log formatter only sees %s instead of "this is my message". Therefore it cannot replace the quotes with \". So the json is expected to look like: {"severity": "INFO", "message": " \"this is my message\" "}

In my case I have to create exceptions of my log-based metrics for pika.

Would you agree to change the log format to something like:

log.info(f'{"this is my message"}')
log.info("{}"format("this is my message"))
log.info("%s" % "this is my message")

It is the simplest way to circumvent this issue, or do you have an other idea how to fix this?

[Luke Bakken]

Hello,

The Pika project won't be changing how we use the logging module since using printf formatting is a standard, accepted way of using the module.

I think the logging module should provide a means for you to intercept the arguments and format the data yourself:

https://docs.python.org/3/howto/logging-cookbook.html#formatting-styles

Thanks,

Luke

[Vitaly Krug]

You should be able to implement and install your own logging handler in your app that would output the logs using json lines format, for example

--
You received this message because you are subscribed to the Google Groups "Pika" group.
To unsubscribe from this group and stop receiving emails from it, send an email to pika-python...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/pika-python/48f87b61-8af3-4564-8e6a-90a527d60863n%40googlegroups.com.

[Tobias Flühmann]

Hi all,

Thanks for your replies. I tried to implement it as suggested with the logging handler. Sadly the issue stays the same, the printf-style logging gets replaced after the

logging handler modification takes place.

Here my example code:

import sys
import logging
from logging import Formatter
import json
import datetime


class CustomFormatter(Formatter):
    def __init__(self, task_name=None):
        self.task_name = task_name

        super(CustomFormatter, self).__init__()

    def format(self, record):
        data = {'message': record.msg,
                'timestamp': datetime.datetime.utcnow().strftime('%Y-%m-%dT%H:%M:%S.%fZ')}
        return json.dumps(data)


logger = logging.getLogger("example-logging-handler")
logger.setLevel(logging.DEBUG)
handler = logging.StreamHandler(sys.stdout)
formatter = CustomFormatter("example-logging-handler")
handler.setFormatter(formatter)
logger.addHandler(handler)

logger.info("example-logging-handler %s", '"{}"')

It generates the following output:

{"message": "example-logging-handler %s", "timestamp": "2021-02-12T11:01:13.047235Z"}
 instead of the expected output:

{"message": '"example-logging-handler \\"{}\\""', "timestamp": "2021-02-12T11:01:13.047235Z"}

Regards,

Tobias