Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

test_log.py failed during LimitFilter #3382

Closed
egberts opened this issue Jul 24, 2024 · 1 comment
Closed

test_log.py failed during LimitFilter #3382

egberts opened this issue Jul 24, 2024 · 1 comment
Labels

Comments

@egberts
Copy link
Contributor

egberts commented Jul 24, 2024

  • [ x] I have read the Filing Issues and subsequent “How to Get Help” sections of the documentation.
  • [ x ] I have searched the issues (including closed ones) and believe that this is not a duplicate.

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

  • OS version and name: Linux 6.1.0-21-amd64 SMP PREEMPT_DYNAMIC Debian 6.1.90-1 (2024-05-03) x86_64 GNU/Linux

  • Python version: 3.11.2

  • Pelican version: master-egbert branch in github.com/egberts/pelican

  • Link to theme: custom m.css

  • Links to plugins: None

  • Link to your site: N/A

  • Link to your source: https://github.com/egberts/pelican/tree/master-egbert

  • Link to a Gist with the contents of your settings file: none (DEFAULT_CONFIG)

@egberts egberts added the bug label Jul 24, 2024
@egberts
Copy link
Contributor Author

egberts commented Jul 24, 2024

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....

@egberts egberts changed the title test_log.py failed; logging upgraded? Missing _ignore field test_log.py failed during LimitFilter Jul 24, 2024
@egberts egberts closed this as not planned Won't fix, can't repro, duplicate, stale Jul 25, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

1 participant