warnings raised by test_peg_generator when setuptools_scm is installed

Bug report

Bug description:

Hi, since #131802, we see test_peg_generator failing with the following warning:

Warning -- logging._handlerList was modified by test_peg_generator
Warning --   Before: (140617884985088, [<weakref at 0x7fe4271c8720; to 'logging._StderrHandler' at 0x7fe427ceb620>, <weakref at 0x7fe421d4d350; to 'setuptools_scm._log.AlwaysStdErrHandler' at 0x7fe420b25fd0>], [<weakref at 0x7fe4271c8720; to 'logging._StderrHandler' at 0x7fe427ceb620>])
Warning --   After:  (140617884985088, [<weakref at 0x7fe4271c8720; to 'logging._StderrHandler' at 0x7fe427ceb620>, <weakref at 0x7fe421d4d350; to 'setuptools_scm._log.AlwaysStdErrHandler' at 0x7fe420b25fd0>], [<weakref at 0x7fe4271c8720; to 'logging._StderrHandler' at 0x7fe427ceb620>, <weakref at 0x7fe421d4d350; to 'setuptools_scm._log.AlwaysStdErrHandler' at 0x7fe420b25fd0>])

For some reason, during the execution, second reference to the same 'setuptools_scm._log.AlwaysStdErrHandler' appears in the _handlerList.

When I remove setuptools_scm, the issue is gone.

Interestingly (at least to me), when I revert changes done in #131802 in lib/test/support/__init__.py and os_helper.py (commenting out import logging is enough), the issue is gone as well, so it seems like some weird side effect of the import?

I tried to track the issue and got through setuptools all the way to ep.load() in finalize_options() which triggers the issue (see trace below).

I added some debug prints to _addHandlerRef function, and it's apparently called only once with this handler. Though I also see a single call for the logging._StderrHandler' and it's there twice as well, so I am probably overlooking something...

Here is the trace from when the handler ref is being added during the test execution:

.....
  File "/build/cpython-3.13/Lib/test/test_peg_generator/test_c_parser.py", line 131, in build_extension
    generate_parser_c_extension(grammar, Path('.'), library_dir=self.library_dir)
  File "/build/cpython-3.13/Tools/peg_generator/pegen/testutil.py", line 107, in generate_parser_c_extension
    compile_c_extension(
  File "/build/cpython-3.13/Tools/peg_generator/pegen/build.py", line 160, in compile_c_extension
    dist = Distribution({"name": extension_name, "ext_modules": [extension]})
  File "/usr/lib/python3.13/vendor-packages/setuptools/dist.py", line 323, in __init__
    _Distribution.__init__(self, dist_attrs)
  File "/usr/lib/python3.13/vendor-packages/setuptools/_distutils/dist.py", line 309, in __init__
    self.finalize_options()
  File "/usr/lib/python3.13/vendor-packages/setuptools/dist.py", line 787, in finalize_options
    for ep in sorted(loaded, key=by_order):
  File "/usr/lib/python3.13/vendor-packages/setuptools/dist.py", line 786, in <lambda>
    loaded = map(lambda e: e.load(), filtered)
  File "/build/cpython-3.13/Lib/importlib/metadata/__init__.py", line 179, in load
    module = import_module(match.group('module'))
  File "/build/cpython-3.13/Lib/importlib/__init__.py", line 88, in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
  File "<frozen importlib._bootstrap>", line 1387, in _gcd_import
  File "<frozen importlib._bootstrap>", line 1360, in _find_and_load
  File "<frozen importlib._bootstrap>", line 1310, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 488, in _call_with_frames_removed
  File "<frozen importlib._bootstrap>", line 1387, in _gcd_import
  File "<frozen importlib._bootstrap>", line 1360, in _find_and_load
  File "<frozen importlib._bootstrap>", line 1310, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 488, in _call_with_frames_removed
  File "<frozen importlib._bootstrap>", line 1387, in _gcd_import
  File "<frozen importlib._bootstrap>", line 1360, in _find_and_load
  File "<frozen importlib._bootstrap>", line 1331, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 935, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 1026, in exec_module
  File "<frozen importlib._bootstrap>", line 488, in _call_with_frames_removed
  File "/usr/lib/python3.13/vendor-packages/setuptools_scm/__init__.py", line 8, in <module>
    from ._config import DEFAULT_LOCAL_SCHEME
  File "<frozen importlib._bootstrap>", line 1360, in _find_and_load
  File "<frozen importlib._bootstrap>", line 1331, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 935, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 1026, in exec_module
  File "<frozen importlib._bootstrap>", line 488, in _call_with_frames_removed
  File "/usr/lib/python3.13/vendor-packages/setuptools_scm/_config.py", line 15, in <module>
    from . import _log
  File "<frozen importlib._bootstrap>", line 1415, in _handle_fromlist
  File "<frozen importlib._bootstrap>", line 488, in _call_with_frames_removed
  File "<frozen importlib._bootstrap>", line 1360, in _find_and_load
  File "<frozen importlib._bootstrap>", line 1331, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 935, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 1026, in exec_module
  File "<frozen importlib._bootstrap>", line 488, in _call_with_frames_removed
  File "/usr/lib/python3.13/vendor-packages/setuptools_scm/_log.py", line 48, in <module>
    _default_handler = make_default_handler()
  File "/usr/lib/python3.13/vendor-packages/setuptools_scm/_log.py", line 43, in make_default_handler
    handler = AlwaysStdErrHandler()
  File "/usr/lib/python3.13/vendor-packages/setuptools_scm/_log.py", line 23, in __init__
    super().__init__(sys.stderr)
  File "/build/cpython-3.13/Lib/logging/__init__.py", line 1128, in __init__
    Handler.__init__(self)
  File "/build/cpython-3.13/Lib/logging/__init__.py", line 941, in __init__
    _addHandlerRef(self)

All this is with Python 3.13 (latest changes), setuptools 80.3.1, setuptools_scm 8.3.1, and on Oracle Solaris, but I don't think this is necessarily platform dependent.

I also reproduced this with older setuptools 73.0.1 and setuptools_scm 8.1.0.

CPython versions tested on:

3.13

Operating systems tested on:

Other

I just reproduced this with latest main, with just setuptools 80.3.1 and setuptools_scm 8.3.1 available in site-packages.

The test is failing because the test suite doesn't like it when logging handlers are added by tests, which setuptools_scm is seemingly doing. Doing so causes a warning, which causes tests to fail since #131802, so I don't think this is actually a new issue. I don't think there's much we can do if setuptools_scm automatically adds some logging handlers.

I don't think that #131802 just uncovered something that was always the case.

As I mentioned above, when I remove logging imports from lib/test/support/__init__.py and os_helper.py (added in that change), the issue is gone. And when I turn warnings into errors in older 3.13.1 (with python_opts.extend(('-W', 'error'))), there is no environment change warning - only when I add import logging to lib/test/support/__init__.py, it appears.

That seems like there's more going on than just setuptools_scm adding a new logging handler.

Also, it doesn't really explain (at least to me) how does the same exact handler (it's the same weakref to the same handler) appear for the second time in the _handlerList.

And when I turn warnings into errors in older 3.13.1 (with python_opts.extend(('-W', 'error'))),

To be clear--I don't think there's a bug, on our end or on setuptools_scm. The tests just don't like it when state changes between tests. You can see something similar if you change an environment variable in a test. It's not a bug to set an environment variable, but it fails under our test suite.

It's not immediately obvious why removing import logging "fixes" it, but I don't think it matters much. If you can find an easy fix, then go for it! But otherwise, I don't think tracking this down is worthwhile.

Well, the main issue I am trying to solve is that the test suite is failing. I can live with the warning, but we'd really like to have the test suite pass, and there doesn't seem to be a simple way to ignore this warning-turned-to-error.

BTW, I just reproduced this on Fedora with 3.13.3 as well, so it's not a platform diff.

I will ask in setuptools_scm issues; maybe somebody will have some more insight there.

In general, running the tests with third-party packages installed is not a supported (or supportable) configuration. There's no limit to what such packages can change.

I can live with the warning, but we'd really like to have the test suite pass

The whole point is that warnings won't freely pass in tests anymore, hopefully catching bugs.

What's the use case here, anyway? I can't think of many reasons why you'd need to run the CPython test suite with packages installed.

In general, running the tests with third-party packages installed is not a supported (or support_able_) configuration. There's no limit to what such packages can change.

That makes sense. But it would still be nice if it worked with at least a subset of packages known to be installed on machine used to build python stuff ;).

The whole point is that warnings won't freely pass in tests anymore, hopefully catching bugs.

I understand that, but as you mentioned above, this is likely not a bug. And there doesn't seem to be a way to suppress the warning for test_peg_generator specifically (I don't want to run whole test suite with warning disabled as they are otherwise useful).

What's the use case here, anyway? I can't think of many reasons why you'd need to run the CPython test suite with packages installed.

That's the way we are building all packages for Oracle Solaris (and I wouldn't be surprised if we were alone in this). The build machine contains everything that is necessary to build the whole Userland, and since setuptools_scm is necessary to build many other things, Python tests find it.

I tried running tests isolated from the machine with TESTPYTHONOPTS=-S and that fixed this issue, but that unfortunately skips test_site, which seems like a nice test to run, so not ideal.

Maybe the simplest thing is to skip the pegen tests... Or would you have another suggestion on how to handle this? Being able to ignore the warning for this specific test would be nice, though I don't think there is a nice place to put a warning filter into.

Im happy to adjust how setuptools_scm creates its handlers

AFAICS, the problem is that it initializes handlers in a pth file, which the test suite notices. An easy fix would be to put that behavior behind an environment variable (e.g., SETUPTOOLS_SCM_NO_PTH).

There's no pth

But setuptools plugin import

Maybe setuptools itself has a pth file? There's definitely some pth file that triggers it if -S fixes it.

Its possible that setuptools tries to ensure its distutils package is getting used via a pth

Someone needs to validate

I am no expert on the import process, but I don't think that pth files are at play here. Here is much simplified what setuptools and setuptools_scm are doing in this case:

foo.py (setuptools part)

import logging
from importlib import metadata

print(logging._handlerList)

group = "foo.finalize_distribution_options"
defined = metadata.entry_points(group=group)
for ep in defined:
	func = ep.load()   # this triggers the new handler creation
	#func()

print(logging._handlerList)

local/bar.py (setuptools_scm part)

import logging

handler = logging.StreamHandler()

def infer_version():
    pass

$> cat local/bar.dist-info/entry_points.txt
[foo.finalize_distribution_options]
bar = bar:infer_version

$> PYTHONPATH=`pwd`/local python3.13 -S foo.py
[<weakref at 0x7fcb47a5b2d90; to 'logging._StderrHandler' at 0x7fcb47a5a92b0>]
[<weakref at 0x7fcb47a5b2d90; to 'logging._StderrHandler' at 0x7fcb47a5a92b0>, <weakref at 0x7fcb478411710; to 'logging.StreamHandler' at 0x7fcb47a5a96a0>]

As for the potential solutions, the issue is that the new handler is always created globally on import. Even if it was created later on demand, it would likely be necessary when infer_version is called (func() in the example above).

I am not sure what is the reason to always create the new logging handler (maybe to ensure one always exists? Though the logging._StderrHandler created by the runtime seems to always be there and do the same thing), but maybe it can be made optional in some way?

The logging details changed a number of times due to ux concerns

Im happy to drop the creation

But i have to ensure correct configuration and working logging

Its only necessary to actually configure logging if one of the entrypoints starts the machinery

Let's continue in pypa/setuptools-scm#1139 - seems that is a better place for this issue.

Navigation Menu

Repository navigation

warnings raised by test_peg_generator when setuptools_scm is installed #133509

Bug report

Bug description:

CPython versions tested on:

Operating systems tested on:

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

warnings raised by test_peg_generator when setuptools_scm is installed #133509

Description

Bug report

Bug description:

CPython versions tested on:

Operating systems tested on:

Activity

kulikjak commented on May 6, 2025

ZeroIntensity commented on May 6, 2025

kulikjak commented on May 6, 2025

ZeroIntensity commented on May 6, 2025

kulikjak commented on May 6, 2025

zware commented on May 6, 2025

ZeroIntensity commented on May 6, 2025

kulikjak commented on May 7, 2025

RonnyPfannschmidt commented on May 7, 2025

ZeroIntensity commented on May 7, 2025

RonnyPfannschmidt commented on May 7, 2025

ZeroIntensity commented on May 7, 2025

RonnyPfannschmidt commented on May 7, 2025

kulikjak commented on May 12, 2025

RonnyPfannschmidt commented on May 12, 2025

kulikjak commented on Jun 3, 2025

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions