2

I am using Python 3.8.8 with the included logging library. To have a common string format in Python, I wanted to use also for logging the new format string variant with {}. I also want to use lazy evaluation of the logging string (so no "{}".format(var) or f"{var}").

According to this Stack Overflow post about pylint (so pylint logging-format-style=new), the following variant should work. However, there is an exception at logging.info.

import logging

logging.basicConfig(level=logging.INFO)
logger = logging.getLogger()

var1 = "foo"
var2 = "blub"

logger.info("var1 {}, var2 {}", var1, var2) # Exception thrown!

The exception in the last line is as follows:

--- Logging error ---
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/logging/__init__.py", line 1081, in emit
    msg = self.format(record)
  File "/usr/local/lib/python3.8/logging/__init__.py", line 925, in format
    return fmt.format(record)
  File "/usr/local/lib/python3.8/logging/__init__.py", line 664, in format
    record.message = record.getMessage()
  File "/usr/local/lib/python3.8/logging/__init__.py", line 369, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting

I infered from the exception message that logging still expects the old style formatting with %s.

How can I use the new format string variant with {} at logging in Python 3.8.8 without using any additional wrapper function (as suggested by some other posts on Stack Overflow)? Although possible to define in pylint, is this maybe even not possible without any wrapper function?

Improve this question
6
  • Does this answer your question? Logging variable data with new format string Commented Mar 31, 2021 at 14:57
  • 1
    Fundamentally this is still true: "There would no changing this while preserving backward compatibility, since all logging calls which are out there in existing code will be using %-format strings." Commented Mar 31, 2021 at 15:03
  • @jonrsharpe Thanks for the suggestion of that post. Before asking this question, I have already looked at that but this does not answer my question because first, it's Python 2.7, and second, it is using some wrapper function and by using already Python 3.8 I hope that's no more needed. Commented Mar 31, 2021 at 17:51
  • The quote I posted is from the 3.latest docs, it hasn't somehow suddenly become the case that the logging calls in existence aren't using %. The fact that you don't like those answers doesn't make them not the answers. Commented Mar 31, 2021 at 18:25
  • @jonrsharpe My first comment was an answer to your first comment. Until now I didn't have time to look more detailed on your quote from the logging docs but I checked it now. It is true that I would have liked that there are already some changes from 2.7 to 3.8 but for me knowing that this still does not work, is also a totally valid and acceptable answer. Feel free to write this as an answer to the question and I will accept that. Otherwise I will write the answer to my question by myself. Commented Apr 1, 2021 at 11:47

2 Answers 2

Reset to default
0

I infered from the exception message that logging still expects the old style formatting with %s. How can I use the new format string variant with {}

You should define the formatter either when you are explicitly creating formatter or implicitly using BasicConfig.

using BasicConfig


logging.basicConfig(
    filename="example.log",
    encoding="utf-8",
    level=logging.DEBUG,
    style="{", # <-----------------
    format="{levelname} logger={name}, {message}", # <-----------------
)

using Formatter class

new_format = logging.Formatter(
    fmt="{levelname} logger={name}, {message}",
    style="{",
)

file_handler = logging.FileHandler(
    "example.log",
    encoding="utf-8",
)

file_handler.setFormatter(new_format)

Regarding style="{"

[It] only applies to fmt and datefmt (e.g. '%(message)s' versus '{message}'), not to the actual log messages passed to the logging methods. link

It is not meant to be used the way you intended, logger.info("var1 {}, var2 {}", var1, var2).

So, even after you set style to {, string formatter operator remains %.

The msg is the message format string, and the args are the arguments which are merged into msg using the string formatting operator. (Note that this means that you can use keywords in the format string, together with a single dictionary argument.) No % formatting operation is performed on msg when no args are supplied. link

logger.debug("debug info %s %s", 'variable1', 'variable2')
logger.debug("debug info %(var1)s %(var2)s", {'var1':"some variable", 'var2':"some variable 2"})

If you want to use curly braces, {}.

You can use LogRecord factories by subclassing LogRecord. However, you mentioned you don't want "any additional wrapper function".

Another way of passing arguments to format message is by using custom fields and extra keyword argument in logging calls.

logger.debug("debug info 2", extra={'var': 'some value'})

This extra dictionary is used to populate the dict of the LogRecord. So, It means you can access its fields in other stages such as during filtering.

They can also be incorporated into logged messages.

import logging

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
new_format = logging.Formatter(
    fmt="{levelname} logger={name}, {message}, variable: {var}", 
    style="{", 
    defaults={"var": "default value"} # < default value can be empty string
)

file_handler = logging.FileHandler(
    "example.log",
    encoding="utf-8",
)

file_handler.setFormatter(new_format)
logger.addHandler(file_handler)

logger.debug("debug info" )
# DEBUG logger=__main__, debug info, variable: default value

logger.debug("debug info 2", extra={'var': 'some value'})
# DEBUG logger=__main__, debug info 2, variable: some value

Note: If defaults is not set in logging.Formatter and you don't pass keyword arguments to the custom field like first debug call, it raises a KeyError.

Improve this answer
Sign up to request clarification or add additional context in comments.

Comments

-1

I think Python string interpolation is easier to work with:

logger.info(f"var1 {var1}, var2 {var2}")

To achieve lazy evaluation,

if logger.isEnabledFor(logging.INFO):
    logger.info(f"var1 {var1}, var2 {var2}")
Improve this answer

5 Comments

This misses the entire point of the question. Passing an uninterpolated string to logger.X will interpolate the string only if it will be emitted
No. The next best thing is to keep using %s or creating a custom style: stackoverflow.com/questions/13131400/…
A need for lazy evaluation was not mentioned by the OP
@MikeSlinn Thank you for the suggestion. You are right, lazy evaluation was not mentionend from my side but it is something that I would like to have. I have updated my question. About your answer, yes, it works but for me using logger.isEnabledFor doesn't sound like an elegant solution but more like a workaround (especially if there is not just one log message but likely quite many)
@Fabian, you could cache the enabled state in a var e = logger.isEnabledFor(logging.INFO) and then use boolean shortcut logic like this e and logger.info(f"var1 {var1}, var2 {var2}"). If e is false, the rest won't be evaluated.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.