Skip to content

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

Description

@gertvdijk

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.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions