Jackenmen commented 2 years ago

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:

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

<!-- gh-linked-prs -->
### Linked PRs
* gh-111451
<!-- /gh-linked-prs -->

mmerickel commented 1 year ago

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 commented 10 months ago

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 commented 2 months ago

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)

python / cpython

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

Bug report