Python 3.12.0 test failure on log entry assert in `test_session_command_queue_not_implemented`

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