Skip to content

Wait for polling queries in logging tests instead of sleeping - #775

Open
wintan1418 wants to merge 2 commits into
rails:mainfrom
wintan1418:wait-for-polling-queries-in-logging-tests
Open

Wait for polling queries in logging tests instead of sleeping#775
wintan1418 wants to merge 2 commits into
rails:mainfrom
wintan1418:wait-for-polling-queries-in-logging-tests

Conversation

@wintan1418

Copy link
Copy Markdown
Contributor

Related to #602

Problem

The "polling queries are logged" tests in WorkerTest and DispatcherTest start a worker/dispatcher and sleep for a fixed window (0.2s / 0.5s) before asserting that the polling SELECT shows up in the captured log. On a slow CI runner, process boot (DB registration, pool startup) can eat the whole window before the first poll executes, so the log only contains the process INSERT and the assertion fails.

Example failure from a recent CI run (MySQL job):

Failure:
WorkerTest#test_polling_queries_are_logged [test/unit/worker_test.rb:156]:
Expected /SELECT .* FROM .solid_queue_ready_executions. .../ to match
"  TRANSACTION (0.2ms)  BEGIN\n  SolidQueue::Process Create (0.5ms)  INSERT INTO `solid_queue_processes` ..."

Fix

Poll the captured log for the expected query with wait_while_with_timeout (3 seconds) instead of a flat sleep. The tests remain as fast as before in the common case — the wait returns as soon as the query appears — and become robust when the runner is slow. On timeout, the existing assertion still runs and reports the log contents.

@wintan1418
wintan1418 force-pushed the wait-for-polling-queries-in-logging-tests branch from fd082c3 to 9951627 Compare July 30, 2026 11:47
The "polling queries are logged" tests started a worker/dispatcher and
slept for a fixed window before asserting the polling SELECT showed up
in the log. On a slow CI runner, process boot (registration, pool
startup) can eat the whole window before the first poll runs, failing
the test.

Poll the captured log for the expected query with a timeout instead:
as fast as before in the common case, and robust when the runner is
slow.

Related to rails#602
@wintan1418
wintan1418 force-pushed the wait-for-polling-queries-in-logging-tests branch from 9951627 to 8b5f383 Compare July 30, 2026 11:59
"sleeps 0.seconds between polls" started the dispatcher and waited only
1 second (without raising) for all three scheduled jobs to be
dispatched. On a slow CI runner the dispatcher thread may not have
booted and polled within that window, so the test failed on the
scheduled executions count with all three jobs still there.

Wait up to 5 seconds instead; the wait returns as soon as the jobs are
dispatched, so the test's runtime is unchanged in the common case.
@wintan1418
wintan1418 force-pushed the wait-for-polling-queries-in-logging-tests branch from 58d49be to 521644b Compare July 31, 2026 13:53
@wintan1418

Copy link
Copy Markdown
Contributor Author

For review context: the failure on the previous run (AsyncProcessesLifecycleTest#test_term_supervisor_exceeding_timeout) is a different pre-existing flake, addressed in #782 — this branch predates that fix, so it can still surface here. Same applies across #775/#776/#782: each fixes a different subset of the suite's known flakes, so until they land, any of them can still go red on one of the others' tests. Re-triggered CI here.

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

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant