getpelican / pelican

Static site generator that supports Markdown and reST syntax. Powered by Python.
https://getpelican.com
GNU Affero General Public License v3.0
12.53k stars 1.81k forks source link

test_log.py failed during `LimitFilter` #3382

Closed egberts closed 2 months ago

egberts commented 2 months ago

Issue

In my egberts/pelican at master-egbert branch, latest everything, in the test_log is all of a sudden now failing the LimitFilter portion of test_log.py.

Despite the test_log properly inserting the LimitFilter (and unchanged for the last 4 years, @avaris ), yet our Pelican lone solitary test_log.py unit test is now failing.

Something have gotten changed (might be me and my massive PR smash-together).

pytest

$ pytest tests/test_log.py 
Test session starts (platform: linux, Python 3.11.2, pytest 8.2.2, pytest-sugar 1.0.0)
rootdir: /home/wolfe/admin/websites/egbert.net/pelican
configfile: tox.ini
plugins: xdist-3.6.1, anyio-4.4.0, sugar-1.0.0
6 workers [1 item]      collecting ... 

――――――――――――――――――――――――――― TestLog.test_log_filter ――――――――――――――――――――――――――――
[gw0] linux -- Python 3.11.2 /home/wolfe/virtualenvs/pelican/bin/python

self = <pelican.tests.test_log.TestLog testMethod=test_log_filter>

    def test_log_filter(self):
        def do_logging():
            for i in range(5):
                self.logger.warning("Log %s", i)
                self.logger.warning("Another log %s", i)

        # no filter
        with self.reset_logger():
            do_logging()
            self.assertEqual(self.handler.count_logs("Log \\d", logging.WARNING), 5)
            self.assertEqual(
                self.handler.count_logs("Another log \\d", logging.WARNING), 5
            )

        # filter by template
        with self.reset_logger():
            log.LimitFilter._ignore.add((logging.WARNING, "Log %s"))
            do_logging()
>           self.assertEqual(self.handler.count_logs("Log \\d", logging.WARNING), 0)
E           AssertionError: 5 != 0

tests/test_log.py:53: AssertionError
----------------------------- Captured stdout call -----------------------------
[13:43:02] WARNING  Log 0                                         test_log.py:38
           WARNING  Another log 0                                 test_log.py:39
           WARNING  Log 1                                         test_log.py:38
           WARNING  Another log 1                                 test_log.py:39
           WARNING  Log 2                                         test_log.py:38
           WARNING  Another log 2                                 test_log.py:39
           WARNING  Log 3                                         test_log.py:38
           WARNING  Another log 3                                 test_log.py:39
           WARNING  Log 4                                         test_log.py:38
           WARNING  Another log 4                                 test_log.py:39
           WARNING  Log 0                                         test_log.py:38
           WARNING  Another log 0                                 test_log.py:39
           WARNING  Log 1                                         test_log.py:38
           WARNING  Another log 1                                 test_log.py:39
           WARNING  Log 2                                         test_log.py:38
           WARNING  Another log 2                                 test_log.py:39
           WARNING  Log 3                                         test_log.py:38
           WARNING  Another log 3                                 test_log.py:39
           WARNING  Log 4                                         test_log.py:38
           WARNING  Another log 4                                 test_log.py:39
------------------------------ Captured log call -------------------------------
WARNING  pelican.tests.test_log:test_log.py:38 Log 0
WARNING  pelican.tests.test_log:test_log.py:39 Another log 0
WARNING  pelican.tests.test_log:test_log.py:38 Log 1
WARNING  pelican.tests.test_log:test_log.py:39 Another log 1
WARNING  pelican.tests.test_log:test_log.py:38 Log 2
WARNING  pelican.tests.test_log:test_log.py:39 Another log 2
WARNING  pelican.tests.test_log:test_log.py:38 Log 3
WARNING  pelican.tests.test_log:test_log.py:39 Another log 3
WARNING  pelican.tests.test_log:test_log.py:38 Log 4
WARNING  pelican.tests.test_log:test_log.py:39 Another log 4
WARNING  pelican.tests.test_log:test_log.py:38 Log 0
WARNING  pelican.tests.test_log:test_log.py:39 Another log 0
WARNING  pelican.tests.test_log:test_log.py:38 Log 1
WARNING  pelican.tests.test_log:test_log.py:39 Another log 1
WARNING  pelican.tests.test_log:test_log.py:38 Log 2
WARNING  pelican.tests.test_log:test_log.py:39 Another log 2
WARNING  pelican.tests.test_log:test_log.py:38 Log 3
WARNING  pelican.tests.test_log:test_log.py:39 Another log 3
WARNING  pelican.tests.test_log:test_log.py:38 Log 4
WARNING  pelican.tests.test_log:test_log.py:39 Another log 4

 pelican/tests/test_log.py ⨯                                     100% ██████████
=========================== short test summary info ============================
FAILED tests/test_log.py::TestLog::test_log_filter - AssertionError: 5 != 0

Results (0.89s):
       1 failed
         - pelican/tests/test_log.py:35 TestLog.test_log_filter

logging.addFilter works and properly added:

self.filters[0].LOGS_DEDUP_MIN_LEVEL = 30
self.filters[0].name = ""
self.filters[0].nlen = 0

Pelican's log.LimitFilter._ignore has the correct value:

{
    ( 
        30,
        'Log %s'
    )
}

But the _ignore field seems to be ignored.

Platform

egberts commented 2 months ago

Found it.... My introduction of pelican/pelican/tests/conftest.py caused the logger to have dual-personality (despite no logging import statement inside conftest.py): as a result, the logger.getLevel() produces two different values between Pelican __init__.py and log.py.

Very interesting....