logging.captureWarnings(True) doesn't show object allocation (-X tracemalloc)

[Jackenmen]

Bug report

When using logging.captureWarnings(True), the information about object allocation that you should get with -X tracemalloc gets lost.

It appears to be a discrepancy between Python and C implementation of the warnings module? source isn't passed to the created WarningMessage object in the Lib/warnings.py: https://github.com/python/cpython/blob/a17cd47b614f8bc660788647a009a25e121221d7/Lib/warnings.py#L12 https://github.com/python/cpython/blob/a17cd47b614f8bc660788647a009a25e121221d7/Lib/warnings.py#L17 https://github.com/python/cpython/blob/a17cd47b614f8bc660788647a009a25e121221d7/Lib/warnings.py#L394 while it is in Python/_warnings.c: https://github.com/python/cpython/blob/a17cd47b614f8bc660788647a009a25e121221d7/Python/_warnings.c#L593-L605

Reproduction steps:

1. Create a file repro.py with contents:

import logging
import tempfile
import warnings

warnings.simplefilter("default", category=ResourceWarning)
logging.basicConfig()


print("--- UNCAPTURED WARNING ---")
file = tempfile.SpooledTemporaryFile(1)
file.write(b"foo")
file = None

print("\n--- CAPTURED WARNING ---")
logging.captureWarnings(True)
file = tempfile.SpooledTemporaryFile(1)
file.write(b"foo")
file = None

2. Run python -X tracemalloc=5
3. See that output only contains object allocation traceback for uncaptured warning:

--- UNCAPTURED WARNING ---
/tmp/test_tracemallo/repro.py:12: ResourceWarning: unclosed file <_io.BufferedRandom name=3>
  file = None
Object allocated at (most recent call last):
  File "/tmp/test_tracemallo/repro.py", lineno 11
    file.write(b"foo")
  File "/usr/lib/python3.10/tempfile.py", lineno 911
    self._check(file)
  File "/usr/lib/python3.10/tempfile.py", lineno 807
    self.rollover()
  File "/usr/lib/python3.10/tempfile.py", lineno 812
    newfile = self._file = TemporaryFile(**self._TemporaryFileArgs)
  File "/usr/lib/python3.10/tempfile.py", lineno 760
    return _io.open(fd, mode, buffering=buffering,

--- CAPTURED WARNING ---
WARNING:py.warnings:/tmp/test_tracemallo/repro.py:18: ResourceWarning: unclosed file <_io.BufferedRandom name=3>
  file = None

Your environment

• CPython versions tested on: 3.7.13, 3.8.13, 3.9.13 (installed from deadsnakes ppa), 3.10.4 (system Python)
• Operating system and architecture: Ubuntu 22.04

Linked PRs

• gh-111451

[mmerickel]

Just ran into this while trying to track down resource warnings from our logging system. logging.captureWarnings overrides the warning.showwarning hook.

The issue is that warning.formatwarning and warning.showwarning are public apis that don't accept the source arg that was added later so the warnings module is jumping through some hoops to keep the old signature if you override those hooks.

The only way I've found to override things correctly is to override the impl under the hood and handle it yourself:

warnings._showwarnmsg_impl = showwarning_msg_impl


def showwarning_msg_impl(msg):
    str = warnings._formatwarnmsg(msg)
    wlog = logging.getLogger('py.warnings')
    wlog.warning(str)

[P6rguVyrst]

Stumbled upon this issue during PyCON APAC sprints, when looking for things to work on.

Have a POC fix for this that I've raised as a draft PR. Would like to know if the fix is complete, and would probably need some help to get it upstream.

cc @corona10

[P6rguVyrst]

On my mac, I'm not able to reproduce this with python.exe -X tracemalloc=5, however I can reproduce it on main branch using the environment variable.

➜  cpython git:(main) ✗ PYTHONTRACEMALLOC=5 ./python.exe repro.py
--- UNCAPTURED WARNING ---
/opt/github/p6rguvyrst/cpython/repro.py:12: ResourceWarning: Unclosed file <tempfile.SpooledTemporaryFile object at 0x105ac77a0>
  file = None
Object allocated at (most recent call last):
  File "/opt/github/p6rguvyrst/cpython/repro.py", lineno 10
    file = tempfile.SpooledTemporaryFile(1)

--- CAPTURED WARNING ---
WARNING:py.warnings:/opt/github/p6rguvyrst/cpython/repro.py:18: ResourceWarning: Unclosed file <tempfile.SpooledTemporaryFile object at 0x105ac77a0>
  file = None

When on my branch, the test script seems to produce the desired output:

➜  cpython git:(gh-95748) ✗ PYTHONTRACEMALLOC=5 ./python.exe repro.py
--- UNCAPTURED WARNING ---
/opt/github/p6rguvyrst/cpython/repro.py:12: ResourceWarning: Unclosed file <tempfile.SpooledTemporaryFile object at 0x10382b7a0>
  file = None
Object allocated at (most recent call last):
  File "/opt/github/p6rguvyrst/cpython/repro.py", lineno 10
    file = tempfile.SpooledTemporaryFile(1)

--- CAPTURED WARNING ---
WARNING:py.warnings:/opt/github/p6rguvyrst/cpython/repro.py:18: ResourceWarning: Unclosed file <tempfile.SpooledTemporaryFile object at 0x10382b7a0>
  file = None
Object allocated at (most recent call last):
  File "/opt/github/p6rguvyrst/cpython/repro.py", lineno 16
    file = tempfile.SpooledTemporaryFile(1)