test_a_dropped_report_is_logged_at_debug_with_its_name fails intermittently under load #34

tests/test_trace_client.py test_a_dropped_report_is_logged_at_debug_with_its_name can fail with:

AssertionError: 1 != 0 : a drop names the event it dropped: ['[trace] queue full, dropped filler']

The test was seen failing on unmodified main (986505e) in 2 of 7 full-suite runs on Python 3.8.10, and in 0 of 300 runs of the test alone, so the failure depends on load.

Cause. The test sends QUEUE_CAPACITY + 1 fillers and then overflow-event, and its comment states that the next report has nowhere to go whatever the sender has picked up. That holds only if the sender wakes before the fillers finish. If the queue fills while the sender is still waking, the last filler is the one dropped. The sender then takes one report, which frees a slot, and overflow-event is queued instead of dropped, so the expected log line is never written.

This was confirmed by forcing that interleaving: with the sender held until just before overflow-event, the test fails with the message above on every run.

Suggested fix. Wait for the sender to take the first report before filling the queue, as test_close_on_a_full_queue_drops_the_oldest_report_and_still_stops_the_sender already does. The client itself is not at fault.

This issue was drafted during a Gardener session (https://github.com/Stephenson-Software/gardener).

drafted by Claude on behalf of Daniel Stephenson