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

Python 3.12.0 test failure on log entry assert in test_session_command_queue_not_implemented #12

Open
gertvdijk opened this issue Oct 10, 2023 · 0 comments
Labels
bug Something isn't working

Comments

@gertvdijk
Copy link
Owner

test_session_command_queue_not_implemented fails on 3.12.0 only, on an assert that an error message must have been logged.

fake_session_should_fail = FakeMtaMilterSession(_socket_connection=FakeSocketConnection(app_factory=<function fake_app_factory.<locals>.app_facto...tions_sent=False, _closed=False, logger=<_LoggerAdapter purepythonmilter.server.session (DEBUG)>, responses_written=[])
caplog = <_pytest.logging.LogCaptureFixture object at 0x7f5368fe2b70>

    async def test_session_command_queue_not_implemented(
        fake_session_should_fail: FakeMtaMilterSession,
        caplog: pytest.LogCaptureFixture,
    ) -> None:
        class NonExistingCommand(commands.BaseCommand):
            pass
    
        done_event = fake_session_should_fail.queue_command(NonExistingCommand())
        await asyncio.wait_for(done_event.wait(), 1)
        assert fake_session_should_fail._commands_consumer_task.done()
        assert isinstance(
            fake_session_should_fail._commands_consumer_task.exception(),
            NotImplementedError,
        )
        errors_logged = [rec for rec in caplog.records if rec.levelno >= logging.ERROR]
>       assert len(errors_logged) == 1
E       assert 0 == 1
E        +  where 0 = len([])

tests/server/test_session.py:160: AssertionError

It is actually logged just fine, but just later on and it seems to be like a race condition. Confirmed by this work-around:

diff --git tests/server/test_session.py tests/server/test_session.py
index e8082fb..d271615 100644
--- tests/server/test_session.py
+++ tests/server/test_session.py
@@ -156,6 +156,7 @@ async def test_session_command_queue_not_implemented(
         fake_session_should_fail._commands_consumer_task.exception(),
         NotImplementedError,
     )
+    await asyncio.sleep(0.1)
     errors_logged = [rec for rec in caplog.records if rec.levelno >= logging.ERROR]
     assert len(errors_logged) == 1
     assert ("Got an exception in the commands consumer task.") in errors_logged[0].msg

But it's really awaiting the done event in the consumer, and it should really have been logged before that event is set. Unsure what's going on and whether the test is just not right or something else is not set up correctly.

@gertvdijk gertvdijk added the bug Something isn't working label Oct 10, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

1 participant