This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

Author joukewitteveen
Recipients joukewitteveen
Date 2021-09-11.13:17:18
SpamBayes Score -1.0
Marked as misclassified Yes
Message-id <1631366238.78.0.687157218809.issue45171@roundup.psfhosted.org>
In-reply-to
Content
Handling of `stacklevel` in the logging module makes a few unwarranted assumptions, for instance on the depth of the stack due to internal logging module calls. This can be seen for instance when using the shortcut call `logging.warning` to the root logger, instead of using `root_logger.warning`. Consider the following `stacklevel.py` file:

```
import logging
import warnings

root_logger = logging.getLogger()
root_logger.handle = print

def test(**kwargs):
    warnings.warn("warning-module", **kwargs)
    logging.warning("on-module", **kwargs)
    root_logger.warning("on-logger", **kwargs)

for stacklevel in range(5):
    print(f"{stacklevel=}")
    test(stacklevel=stacklevel)
```

The output of running `PYTHONWARNINGS=always python stacklevel.py` is:

```
stacklevel=0
stacklevel.py:8: UserWarning: warning-module
  warnings.warn("warning-module", **kwargs)
<LogRecord: root, 30, stacklevel.py, 9, "on-module">
<LogRecord: root, 30, stacklevel.py, 10, "on-logger">
stacklevel=1
stacklevel.py:8: UserWarning: warning-module
  warnings.warn("warning-module", **kwargs)
<LogRecord: root, 30, stacklevel.py, 9, "on-module">
<LogRecord: root, 30, stacklevel.py, 10, "on-logger">
stacklevel=2
stacklevel.py:14: UserWarning: warning-module
  test(stacklevel=stacklevel)
<LogRecord: root, 30, stacklevel.py, 9, "on-module">
<LogRecord: root, 30, stacklevel.py, 14, "on-logger">
stacklevel=3
sys:1: UserWarning: warning-module
<LogRecord: root, 30, stacklevel.py, 14, "on-module">
<LogRecord: root, 30, stacklevel.py, 10, "on-logger">
stacklevel=4
sys:1: UserWarning: warning-module
<LogRecord: root, 30, stacklevel.py, 9, "on-module">
<LogRecord: root, 30, stacklevel.py, 10, "on-logger">
```

Looking at the line numbers, we get:
stacklevel 0: lines 8, 9, 10.
stacklevel 1: lines 8, 9, 10.
stacklevel 2: lines 14, 9, 14.
stacklevel 3: lines sys:1, 14, 10.
stacklevel 4: lines sys:1, 9, 10.

As can be seen, the stacklevel for the on-module (shortcut) calls lags one level of unwinding behind.
History
Date User Action Args
2021-09-11 13:17:18joukewitteveensetrecipients: + joukewitteveen
2021-09-11 13:17:18joukewitteveensetmessageid: <1631366238.78.0.687157218809.issue45171@roundup.psfhosted.org>
2021-09-11 13:17:18joukewitteveenlinkissue45171 messages
2021-09-11 13:17:18joukewitteveencreate