Activity

1. vallsv

   changed the title [-]pytest 9.1.0[/-] [+]pytest 9.1.0 ask wrong formatting on logging module[/+] on Jun 15, 2026
2. The-Compiler commented on Jun 15, 2026

   

   The-Compiler

   on Jun 15, 2026

   Member

   More actions

   Not much we can do without a reproducer unfortunately. For starters it would be good to see the full traceback, your output seems to be cut off.

   I suggest the next thing you do is a git bisect with pytest's sources, you can roughly do this (untested):

   In a first terminal:

   cd /tmp
   git clone https://github.com/pytest-dev/pytest.git
   git checkout 9.1.0
   

   In a second terminal:

   cd /nobackup/lvalls1/valls/workspace/bliss.git/flint
   python -m venv .venv-bisect
   source .venv-bisect/bin/activate
   pip install .
   pip install -e /tmp/pytest
   pytest   # this should fail
   

   Then in the first terminal with the pytest repo, do:

   git bisect start
   git bisect bad
   git checkout 9.0.3
   

   then repeat the following steps:

   • In your project folder terminal, run pytest again
   • In the pytest terminal, run either git bisect bad or git bisect good
   • Repeat it some <10 times until it tells you the offending commit

   With that, we should be able to find the offending commit which will narrow things down considerably.

   👍React with 👍1Reacted by Valentin Valls
3. The-Compiler

   added

   status: needs informationreporter needs to provide more information; can be closed after 2 or more weeks of inactivityreporter needs to provide more information; can be closed after 2 or more weeks of inactivity

   on Jun 15, 2026
4. vallsv commented on Jun 15, 2026

   

   vallsv

   on Jun 15, 2026

   Last edited by vallsv

   Author

   More actions

   I have checked with a fresh independent env, independent code

   It sounds like it is not related to pytest. At least the behavior is the same between pytest versions. But in a way i have not expected. It always fails.

   Maybe the problem is related to the why we setup the handlers in our project and the way it is done in pytest or plugins. Ill dig a bit more.

   # test_log.py
   import logging
   
   def test_logging_error():
       logging.error("%s", 1, 3, 1, 2)
   

   pytest 9.1.0

   conda create -n test-py python=3.11
   pip install "pytest==9.1.0"
   pytest test_log.py
   

   >           msg = msg % self.args
                     ^^^^^^^^^^^^^^^
   E           TypeError: not all arguments converted during string formatting
   
   ../../Software/micromamba/envs/test-py/lib/python3.11/logging/__init__.py:377: TypeError
   

   pytest < 9.1.0

   I have tested pytest-6.2.5, pytest-7.4.4, pytest-8.4.2, pytest-9.0.3.

   Got always the same result.

   conda create -n test-py python=3.11
   pip install "pytest<9.1.0"
   pytest test_log.py
   

   >           msg = msg % self.args
                     ^^^^^^^^^^^^^^^
   E           TypeError: not all arguments converted during string formatting
   
   ../../Software/micromamba/envs/test-py/lib/python3.11/logging/__init__.py:377: TypeError
   

   Python interpreter

   But with a python interpreter it's fine.

   (test-py) $ python -c "import logging; logging.error('%s')"
   ERROR:root:%s
   
5. vallsv commented on Jun 15, 2026

   

   vallsv

   on Jun 15, 2026

   Author

   More actions

   Sorry, i have to recheck everything from the start.

   The pytest and python behavior looks to be consistent. I was just not testing the exact same thing.

   This is fine

   (test-py) $ python -c "import logging; logging.error('%s')"
   ERROR:root:%s
   

   But this is not

   (test-py) $ python -c "import logging; logging.error('%s', 1, 3, 1, 2)"
   logging.error('%s', 1, 3, 1, 2)"
   --- Logging error ---
   Traceback (most recent call last):
     File "micromamba/envs/test-py/lib/python3.11/logging/__init__.py", line 1110, in emit
       msg = self.format(record)
             ^^^^^^^^^^^^^^^^^^^
     File "micromamba/envs/test-py/lib/python3.11/logging/__init__.py", line 953, in format
       return fmt.format(record)
              ^^^^^^^^^^^^^^^^^^
     File "micromamba/envs/test-py/lib/python3.11/logging/__init__.py", line 687, in format
       record.message = record.getMessage()
                        ^^^^^^^^^^^^^^^^^^^
     File "micromamba/envs/test-py/lib/python3.11/logging/__init__.py", line 377, in getMessage
       msg = msg % self.args
             ~~~~^~~~~~~~~~~
   TypeError: not all arguments converted during string formatting
   Call stack:
     File "<string>", line 1, in <module>
   Message: '%s'
   Arguments: (1, 3, 1, 2)
   
6. vallsv commented on Jun 15, 2026

   

   vallsv

   on Jun 15, 2026

   Last edited by vallsv

   Author

   More actions

   Finally found some discrepancies between pytest versions:

   With pytest 9.1.0, some extra handlers are injected to the "non-propagated" loggers.

   Here is a test case to reproduce the problem.

   import logging
   
   test_logger = logging.getLogger(__name__)
   test_logger.propagate = False
   
   
   def test_logging_error():
       for h in test_logger.handlers:
           print(f"{type(h).__module__}.{type(h).__qualname__}", h)
   
       test_logger.error("%s", 1, 3, 1, 2)
   

   With pytest 9.1.0

   Some extra handlers are injected by pytest, and the test fails.

   _pytest.logging._LiveLoggingNullHandler <_LiveLoggingNullHandler (NOTSET)>
   _pytest.logging._FileHandler <_FileHandler /dev/null (NOTSET)>
   _pytest.logging.LogCaptureHandler <LogCaptureHandler (NOTSET)>
   _pytest.logging.LogCaptureHandler <LogCaptureHandler (NOTSET)>
   

   With pytest 9.0.3

   There is no handlers, and the test succeed.

   Now i don't know what to think about. Do you consider it as a regression? Or that's something i have to deal on my side.

   I am guessing, as it's not propagated, this should not be captured, and pytest should not be aware of it at all. But i am not quite sure about it.

   For now i think i will pin an older version of pytest and wait for some feedback.
7. vallsv

   changed the title [-]pytest 9.1.0 ask wrong formatting on logging module[/-] [+]pytest 9.1.0 add handlers to non-propagated loggers[/+] on Jun 15, 2026
8. RonnyPfannschmidt commented on Jun 15, 2026

   

   RonnyPfannschmidt

   on Jun 15, 2026

   Member

   More actions

   so pytest just uncovered a bug in your code - because those logger calls are absolutely incorrect - seems like lack of handler and propagation just hid the fact that there is a bug
9. vallsv commented on Jun 15, 2026

   

   vallsv

   on Jun 15, 2026

   Author

   More actions

   so pytest just uncovered a bug in your code - because those logger calls are absolutely incorrect - seems like lack of handler and propagation just hid the fact that there is a bug

   You are right, this is incorrect.

   But it was done in purpose to check incorrect calls. To make sure that a custom handler is resilient to any problems.

   So what the software in production will not fail because of a wrong uncovered code, or because of a wrong "user script", or because of a wrong serialization of def __str__(self) on a user object. Such things.
10. bluetech commented on Jun 16, 2026

    

    bluetech

    on Jun 16, 2026

    Member

    More actions

    Hi @vallsv,

    This is not a regression but an intentional change, see #3697 (was one of the most highly voted issues in pytest).

    Your case is rather special. I think perhaps for these particular tests, you can add a little "hack" like this to prevent the pytest handler from trying to format these messages:

        def test_buggy_logging(xvfb, silxTestUtils, loggingList, caplog):
            # Prevent pytest from interfering.
            caplog.set_level(99999)
    
            widget = loggingList
            assert widget.logCount() == 0
            test_logger.warning("Two fields expected %s %f", "foo")
11. vallsv commented on Jun 16, 2026

    

    vallsv

    on Jun 16, 2026

    Last edited by vallsv

    Author

    More actions

    Hi @bluetech

    Sure, if the pytest team think that it is an expected behavior, that's a legitimate answer.

    We can patch it on our side without problem. I have to take a look at it, but i
    will probably drop the handlers instead. Good to know there is other ways.

    Should I close this issue? Or feel free to close it.
    Regards,
12. bluetech

    closed this as not plannedon Jun 16, 2026
13. vallsv commented on Jun 16, 2026

    

    vallsv

    on Jun 16, 2026

    Last edited by vallsv

    Author

    More actions

    In case, I have filtered them this way.

    Notice that it is not possible to filter it in the fixtures. Sounds like some more handlers are added after the setup of the fixtures and just before the test.

    def test_buggy_logging(xvfb, silxTestUtils, loggingList):
        # With pytest 9.1.0, some loggers are added to the non-propagated loggers.
        # As this tests creates failing calls, we have to drop such extra handlers.
        for h in list(test_logger.handlers):
            if "pytest" in type(h).__module__:
                test_logger.handlers.remove(h)
    

    Reagrds.
14. RonnyPfannschmidt commented on Jun 17, 2026

    

    RonnyPfannschmidt

    on Jun 17, 2026

    Member

    More actions

    Ps if all you want to do is testing your handler reacting to broken log records

    Just make a unittest that hands it the pathological records