LoggerAdapter and %(funcName)s prints the wrong function name

[dogbertai]

Bug report

Bug description:

Using the StyleAdapter from the Cookbook https://docs.python.org/3/howto/logging-cookbook.html
With the %(funcName)s formatter
Yields the wrong funcName in 3.11 and later.

No matter where you use the StyleAdapter logger, it always prints "log"

#!/usr/bin/env python3
import logging.handlers
import sys


class Message:
    def __init__(self, fmt, args):
        self.fmt = fmt
        self.args = args

    def __str__(self):
        return self.fmt.format(*self.args)


class StyleAdapter(logging.LoggerAdapter):
    def __init__(self, logger, extra=None):
        super().__init__(logger, extra or {})

    def log(self, level, msg, /, *args, **kwargs):
        if self.isEnabledFor(level):
            msg, kwargs = self.process(msg, kwargs)
            self.logger._log(level, Message(msg, args), (), **kwargs)


logger = StyleAdapter(logging.getLogger(__name__))


def main():
    root_logger = logging.getLogger()
    root_logger.setLevel(logging.DEBUG)

    # create formatter
    formatter = logging.Formatter(
        '%(asctime)s %(name)s %(funcName)s %(levelname)s %(message)s')

    # create console handler and set level to debug
    console_handler = logging.StreamHandler()
    console_handler.setFormatter(formatter)
    root_logger.addHandler(console_handler)
    root_logger.info('Logger initialized.')

    logger.info('test')


if __name__ == '__main__':
    sys.exit(main())

PS > py -3.10 test_log.py
2024-02-09 23:15:33,506 root main INFO Logger initialized.
2024-02-09 23:15:33,506 __main__ main INFO test
PS > py -3.12 test_log.py                                                          
2024-02-09 23:15:29,298 root main INFO Logger initialized.
2024-02-09 23:15:29,299 __main__ log INFO test

CPython versions tested on:

3.10, 3.12

Operating systems tested on:

Windows

Linked PRs

• gh-115233: Fix currentframe to get the frame of original caller #115241
• gh-115233: Fix an example in the Logging Cookbook #115325
• [3.12] gh-115233: Fix an example in the Logging Cookbook (GH-115325) #115355
• [3.11] [3.12] gh-115233: Fix an example in the Logging Cookbook (GH-115325) (GH-115355) #115357

[Agent-Hellboy]

bisected to 5ca6d74

he changed currentframe function
5ca6d74#diff-1bf0ad6d121df3948853dafdd8e5406709fe0c3911b30e3cf2def41717455c98L162

Thanks, @Eclips4 for help

[Jason-Y-Z]

Thanks all for the discussion. Issue aside, I think it would be really helpful to have some comments for 5ca6d74#diff-1bf0ad6d121df3948853dafdd8e5406709fe0c3911b30e3cf2def41717455c98L162 as sys._getframe(1) v.s. sys._getframe(3) feels equally magic :)

[Agent-Hellboy]

sys._getframe(1) is missing the caller frame if _log is called through an intermediate function , I am going to add a PR