From 225856ef3e6c5e4f234ede1dd118b57f6e8f6d0e Mon Sep 17 00:00:00 2001 From: Serhiy Storchaka Date: Mon, 12 Feb 2024 20:29:48 +0200 Subject: [PATCH] [3.12] gh-115233: Fix an example in the Logging Cookbook (GH-115325) (GH-115355) Also add more tests for LoggerAdapter. Also support stacklevel in LoggerAdapter._log(). (cherry picked from commit 91822018eeba12a6c9eabbc748363b2fd4291b30) --- Doc/howto/logging-cookbook.rst | 10 +- Lib/logging/__init__.py | 11 +- Lib/test/test_logging.py | 107 ++++++++++++++++-- ...-02-12-12-26-17.gh-issue-115233.aug6r9.rst | 1 + 4 files changed, 106 insertions(+), 23 deletions(-) create mode 100644 Misc/NEWS.d/next/Documentation/2024-02-12-12-26-17.gh-issue-115233.aug6r9.rst diff --git a/Doc/howto/logging-cookbook.rst b/Doc/howto/logging-cookbook.rst index 33c57ae73473e3..466e1e21cbd187 100644 --- a/Doc/howto/logging-cookbook.rst +++ b/Doc/howto/logging-cookbook.rst @@ -1744,13 +1744,11 @@ to the above, as in the following example:: 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): + def log(self, level, msg, /, *args, stacklevel=1, **kwargs): if self.isEnabledFor(level): msg, kwargs = self.process(msg, kwargs) - self.logger._log(level, Message(msg, args), (), **kwargs) + self.logger.log(level, Message(msg, args), **kwargs, + stacklevel=stacklevel+1) logger = StyleAdapter(logging.getLogger(__name__)) @@ -1762,7 +1760,7 @@ to the above, as in the following example:: main() The above script should log the message ``Hello, world!`` when run with -Python 3.2 or later. +Python 3.8 or later. .. currentmodule:: logging diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 056380fb2287af..4f89fdccf675bf 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -1985,18 +1985,11 @@ def hasHandlers(self): """ return self.logger.hasHandlers() - def _log(self, level, msg, args, exc_info=None, extra=None, stack_info=False): + def _log(self, level, msg, args, **kwargs): """ Low-level log implementation, proxied to allow nested logger adapters. """ - return self.logger._log( - level, - msg, - args, - exc_info=exc_info, - extra=extra, - stack_info=stack_info, - ) + return self.logger._log(level, msg, args, **kwargs) @property def manager(self): diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index d1ec2d6cf7a7d2..5bfdddc0b70621 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -5447,6 +5447,7 @@ def test_critical(self): self.assertEqual(record.levelno, logging.CRITICAL) self.assertEqual(record.msg, msg) self.assertEqual(record.args, (self.recording,)) + self.assertEqual(record.funcName, 'test_critical') def test_is_enabled_for(self): old_disable = self.adapter.logger.manager.disable @@ -5465,15 +5466,9 @@ def test_has_handlers(self): self.assertFalse(self.adapter.hasHandlers()) def test_nested(self): - class Adapter(logging.LoggerAdapter): - prefix = 'Adapter' - - def process(self, msg, kwargs): - return f"{self.prefix} {msg}", kwargs - msg = 'Adapters can be nested, yo.' - adapter = Adapter(logger=self.logger, extra=None) - adapter_adapter = Adapter(logger=adapter, extra=None) + adapter = PrefixAdapter(logger=self.logger, extra=None) + adapter_adapter = PrefixAdapter(logger=adapter, extra=None) adapter_adapter.prefix = 'AdapterAdapter' self.assertEqual(repr(adapter), repr(adapter_adapter)) adapter_adapter.log(logging.CRITICAL, msg, self.recording) @@ -5482,6 +5477,7 @@ def process(self, msg, kwargs): self.assertEqual(record.levelno, logging.CRITICAL) self.assertEqual(record.msg, f"Adapter AdapterAdapter {msg}") self.assertEqual(record.args, (self.recording,)) + self.assertEqual(record.funcName, 'test_nested') orig_manager = adapter_adapter.manager self.assertIs(adapter.manager, orig_manager) self.assertIs(self.logger.manager, orig_manager) @@ -5497,6 +5493,101 @@ def process(self, msg, kwargs): self.assertIs(adapter.manager, orig_manager) self.assertIs(self.logger.manager, orig_manager) + def test_styled_adapter(self): + # Test an example from the Cookbook. + records = self.recording.records + adapter = StyleAdapter(self.logger) + adapter.warning('Hello, {}!', 'world') + self.assertEqual(str(records[-1].msg), 'Hello, world!') + self.assertEqual(records[-1].funcName, 'test_styled_adapter') + adapter.log(logging.WARNING, 'Goodbye {}.', 'world') + self.assertEqual(str(records[-1].msg), 'Goodbye world.') + self.assertEqual(records[-1].funcName, 'test_styled_adapter') + + def test_nested_styled_adapter(self): + records = self.recording.records + adapter = PrefixAdapter(self.logger) + adapter.prefix = '{}' + adapter2 = StyleAdapter(adapter) + adapter2.warning('Hello, {}!', 'world') + self.assertEqual(str(records[-1].msg), '{} Hello, world!') + self.assertEqual(records[-1].funcName, 'test_nested_styled_adapter') + adapter2.log(logging.WARNING, 'Goodbye {}.', 'world') + self.assertEqual(str(records[-1].msg), '{} Goodbye world.') + self.assertEqual(records[-1].funcName, 'test_nested_styled_adapter') + + def test_find_caller_with_stacklevel(self): + the_level = 1 + trigger = self.adapter.warning + + def innermost(): + trigger('test', stacklevel=the_level) + + def inner(): + innermost() + + def outer(): + inner() + + records = self.recording.records + outer() + self.assertEqual(records[-1].funcName, 'innermost') + lineno = records[-1].lineno + the_level += 1 + outer() + self.assertEqual(records[-1].funcName, 'inner') + self.assertGreater(records[-1].lineno, lineno) + lineno = records[-1].lineno + the_level += 1 + outer() + self.assertEqual(records[-1].funcName, 'outer') + self.assertGreater(records[-1].lineno, lineno) + lineno = records[-1].lineno + the_level += 1 + outer() + self.assertEqual(records[-1].funcName, 'test_find_caller_with_stacklevel') + self.assertGreater(records[-1].lineno, lineno) + + def test_extra_in_records(self): + self.adapter = logging.LoggerAdapter(logger=self.logger, + extra={'foo': '1'}) + + self.adapter.critical('foo should be here') + self.assertEqual(len(self.recording.records), 1) + record = self.recording.records[0] + self.assertTrue(hasattr(record, 'foo')) + self.assertEqual(record.foo, '1') + + def test_extra_not_merged_by_default(self): + self.adapter.critical('foo should NOT be here', extra={'foo': 'nope'}) + self.assertEqual(len(self.recording.records), 1) + record = self.recording.records[0] + self.assertFalse(hasattr(record, 'foo')) + + +class PrefixAdapter(logging.LoggerAdapter): + prefix = 'Adapter' + + def process(self, msg, kwargs): + return f"{self.prefix} {msg}", kwargs + + +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 log(self, level, msg, /, *args, stacklevel=1, **kwargs): + if self.isEnabledFor(level): + msg, kwargs = self.process(msg, kwargs) + self.logger.log(level, Message(msg, args), **kwargs, + stacklevel=stacklevel+1) + class LoggerTest(BaseTest, AssertErrorMessage): diff --git a/Misc/NEWS.d/next/Documentation/2024-02-12-12-26-17.gh-issue-115233.aug6r9.rst b/Misc/NEWS.d/next/Documentation/2024-02-12-12-26-17.gh-issue-115233.aug6r9.rst new file mode 100644 index 00000000000000..f37f94d12d4cf1 --- /dev/null +++ b/Misc/NEWS.d/next/Documentation/2024-02-12-12-26-17.gh-issue-115233.aug6r9.rst @@ -0,0 +1 @@ +Fix an example for :class:`~logging.LoggerAdapter` in the Logging Cookbook.