[logging] parsing dictConfig for formatters: key name "format" does not correspond to constructor parameter name "fmt"

[Xezarior]

Bug report

Creating a new formatter in a dictConfig requires the format string to be specified with the key "format" instead of "fmt". This is inconsistent with the syntax for the class constructor.

Furthermore, the result is that the resulting formatter quietly drops the specified format string replacing it with {message} for no apparent reason.

While the documentation states "format" as key name, all other keys are identically named to the constructor and this causes an unnecessary risk for confusion and errors. Especially since "fmt" and "format" do read very similarly.

I believe it would be a good addition to allow the key "fmt" to be read equivalently to "format" since this may be unwanted behaviour.

MWE:

import logging
config = {
    "version": 1,
    "formatters": {
        "default": { "fmt": "%(levelname)s %(message)s" }
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "default"
        }
    },
    "loggers": {
        "log": { "handlers": ["console"] }
    }
}
logging.config.dictConfig(config)
logging.info("test")

Causes the log record to drop the levelname.

Your environment

Python 3.11.2 (tags/v3.11.2:878ead1, Feb 7 2023, 16:38:35) [MSC v.1934 64 bit (AMD64)] on win32 Windows 11 64 bit

P.S.: This is my first bug report in a project of such size, please kindly help me improving if needed. EDIT: added link to documentation of Dictionary Schema Details.

Linked PRs

• gh-103013

[gaogaotiantian]

Hi, @Xezarior !

I believe the No.1 rule for a bug report is to make SURE your MWE works. Unfortunately yours does not, which will unnecessarily increase the difficulty to triage your issue.

Your original code has a couple of issues:

1. config is not part of the exports of logging. You need to explicitly import logging.config (Actually if you have executed your code, you'd notice that :))
2. The default logging level is WARNING so logging.info won't output any data.
3. You are using the default logger, instead of your defined logger log. So the customized configuration is not used :(

A better demo would be:

import logging
import logging.config
config = {
    "version": 1,
    "formatters": {
        "default": { "fmt": "%(levelname)s %(message)s" }
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "default"
        }
    },
    "loggers": {
        "log": { "handlers": ["console"] }
    }
}
logging.config.dictConfig(config)
logger = logging.getLogger("log")
logger.warning("test")

As for your actual issue. I believe using format instead of fmt is because that's what logging.basicConfig uses. I do agree that unifying all the usages would be a good idea, but at this point, that would mean breaking backward compatibility, which I doubt the devs are willing to do.

Treating fmt as format is a backward compatible way, it's useful in a lot of cases, but it also introduces a bit confusion. I think that's one way to go, but that's for the component owners to decide.

In the meantime, I believe a harmless improvement is to check the dictionary for invalid keys and raise an exception for that(of course, only when it's for non-customize class).

I'll work on a PR for that, and the component owners will probably answer the questions left.

[AlexWaygood]

Thanks @gaogaotiantian, that's excellent triage work -- really helpful! :)

[gaogaotiantian]

Thank you @AlexWaygood . Let me know if there's extra code work needed on this issue or if my improvement has negative impacts that I did not think of.

[Xezarior]

Oh well, that is embarrassing... I thought I was in a clean interpreter session but that was obviously not the case. I am sorry for the botched MWE, it was a long day for me. I am glad the Issue could add something.

Thank you very much for the very fast response and the PR, I also see the ValueError as a good solution that would have avoided the situation. Let's see how it's proceeded. :)

[serhiy-storchaka]

A new key was added for formatter config less than a month after creating #103013. Dictionaries with such key are not compatible with the current validator, and tests fail.

It is very likely that more optional keys will be added in future. The code of the validator can be updated to accept new keys, but not in already released versions. Therefore, configs will be incompatible between Python versions.

[gaogaotiantian]

That's true. So should we simply accept a "no-op" config for lower version logging without letting users know? When they try to pass a config to the lower version that does not support it. Would a warning be a more appropriate option? What's the direction here?

[serhiy-storchaka]

Warnings can be annoying and almost so bad as errors, especially if the program practices zero tolerance to warnings. Silent ignoring the new options can be even worse if the new options radically change the behavior, but it is acceptable if they only slightly tweak it.

Perhaps the safest way is to add an option to control validation. But note that dictConfig() is only one way to configure logging. If implement such feature for dictConfig(), you should also implement it for fileConfig().

Although I am not sure that this feature should be in the stdlib rather in a third-party program. Usually, unconsumed configuration options are ignored, it allows to use the same source to configure several subsystems and include platform-specific or program-specific options.

[gaogaotiantian]

So here's what I think - backward compatibility is to ensure the old code work with the new method, not the other way around. I think it's reasonable to have an optional argument validate_config=True for dictConfig and fileConfig. And while I check the code for fileConfig, I found another reason why we should do this: the validate argument is not implemented in fileConfig, while it's listed in the documentation. The example given in the documentation has the validate=True field while the code does nothing about it - we would've caught that if we have some kind of validation mechanism for the configuration.

I don't fully agree that the unknown configuration should just be ignored. Sure it's helpful in certain cases, but it also creates issues. Think of that as a function argument - they are not entirely the same but very similar. Should we ignore unknown function arguments? Or we should report an error about it? I'm a supporter for "allowlist" - you should only be allowed to do things on the list, not that you could do anything but some of them might be no-op - because you don't know which would be.

After spotting the missing validate implementation (since what, 3.8?), I'm now leaning toward to do this validation and enable it by default, but giving the user an option to disable.

[vsajip]

Creating a new formatter in a dictConfig requires the format string to be specified with the key "format" instead of "fmt". This is inconsistent with the syntax for the class constructor.

There is no reason why they have to be the same. Configuration is often read and written by non-developers, and IMO "format" is nicer for them than "fmt". If I had my time again I might have named the constructor parameters "format" and "date_format" rather than "fmt", and "datefmt", but it's too late for that now. It's IMO not a bug.

There is purposeful configuration code which caters for "format" and maps to "fmt" as needed.