bin/rails test stopped printing and never finished.
Not a failure. Not a stack trace. The log just froze mid-run, and the parent process sat at 0% CPU:
Running 2014 tests in parallel using 10 processes
# Running:
CalculatorsControllerTest#test_each_tool_page_has_a_markdown_twin = 0.04 s = .
CompanyIssue::AccountResultSyncTest#test_names_an_application_it_can_already_identify_without_asking_twice = 0.01 s = .
ConfirmModalFormsTest#test_each_destructive_action_renders_a_hidden_form_the_controller_can_submit = 0.25 s = .
SocialImageGeneratorTest#test_all_templates_produce_images_of_similar_size = 13.75 s = .
SocialImageGeneratorTest#test_renders_valid_PNG_for_each_template = 15.49 s = .
Wait. Nothing else.
Those last tests render social cards in a headless browser, so they take 7–15 seconds — the slowest in the suite. Of course I went looking at that commit.
They were fine. All 2014 tests passed once the real problem was cleared.
If your parallel suite is stuck right now, skip ahead to Clearing a wedged machine . The rest is how I found it, why the log lied, and why Ctrl-C made it permanent.
Do not trust the last line printed
My expensive mistake was reading the log and deciding the slowest test was the hang.
Minitest shuffles the suite and deals tests out to workers as it goes. A stuck worker reports nothing, so whatever it happened to be holding is the last thing you see. Slow tests show up there more often because they are still running when everything else is done. Output order is a sampling artifact, not a timeline.
Ask the OS where the processes are before you invent a theory.
Step 1: Find the workers (they are not named ruby)
ps -eo pid,ppid,etime,stat,args | grep -i "rails test worker"
Rails renames each parallel worker with Process.setproctitle, so ps | grep ruby misses them. That one fact is half the diagnosis.
In a healthy run I saw one master and no workers under that filter, and briefly thought parallelism never started. It had. My filter was wrong.
1103 834 03:07 Rails test worker 2 - BlogsControllerTest#test_blog_post_serves_markdown_twin_at_.md_format
1110 834 03:07 Rails test worker 9 - BlogsControllerTest#test_non-blog_article_redirects_from_/blog_to_/news_with_301
Two workers still alive. The other eight were gone. Rails’ coordinator only prints when a worker reports back, so a worker wedged mid-test looks exactly like a worker that finished.
Step 2: Sample a stuck worker
On macOS, sample gives a native call graph without attaching a debugger:
sample 1103 2 -f /tmp/worker2.txt
Ruby’s frames are opaque in a release build. The leaf of the stack is not. Both stuck workers had the same leaf:
monitor_synchronize (monitor.c:276)
rb_hash_fetch_m ×2
??? (pg_ext.bundle) ← Postgres
rb_io_wait
__select ← blocked on the socket
Not a browser. Not an image encoder. A PostgreSQL query the server had stopped answering. The social card tests were the last line printed; the workers were waiting on the database.
Step 3: Ask Postgres what is blocking
pg_stat_activity shows what each session is doing. pg_blocking_pids names who is holding it up:
SELECT pid, state, wait_event_type, wait_event,
now() - xact_start AS age,
cardinality(pg_blocking_pids(pid)) AS blockers,
pg_blocking_pids(pid) AS blocking_pids,
left(query, 70) AS query
FROM pg_stat_activity
WHERE datname LIKE 'myapp_test%'
AND (cardinality(pg_blocking_pids(pid)) > 0 OR state = 'idle in transaction')
ORDER BY xact_start;
Swap myapp_test% for your test database prefix. The result was a chain that had been sitting there for fifteen and a half hours:
pid | state | age | blockers | query
------+---------------------+------------+----------+-------------------
69337 | idle in transaction | 15:33:12 | {} | SELECT "company_issues".* WHERE id = $1
69339 | idle in transaction | 15:33:12 | {} | SELECT "company_issues".* WHERE id = $1
75768 | active Lock/relation | 15:32:46 | {69337} | TRUNCATE TABLE "companies", ...
75773 | active Lock/relation | 15:32:46 | {69339} | TRUNCATE TABLE "company_issues", ...
77321 | active Lock/relation | 00:04:17 | {75773} | SELECT a.attname, format_type(...)
77322 | active Lock/relation | 00:04:17 | {75768} | SELECT a.attname, format_type(...)
Read it top to bottom. Two sessions went idle in transaction — opened a transaction, ran a query, then stopped talking without commit or rollback. Two TRUNCATEs sat behind them. Everything else, including plain ActiveRecord schema introspection, sat behind the TRUNCATEs.
Why TRUNCATE turns one stuck session into a total outage
Before the suite starts, Rails truncates every table in each parallel worker’s database:
# activerecord/lib/active_record/test_databases.rb
ActiveSupport::Testing::Parallelization.after_fork_hook do |i|
create_and_load_schema(i, env_name: ...)
end
# activerecord/lib/active_record/tasks/database_tasks.rb:419
def reconstruct_from_schema(db_config, file = nil)
# ...
if schema_up_to_date?(db_config, nil, file)
truncate_tables(db_config) unless ENV["SKIP_TEST_DATABASE_TRUNCATE"]
# ...
end
Three things about that TRUNCATE matter:
- It runs in an
after_fork_hook, so ten workers do it at once, each against its own database. TRUNCATEneedsACCESS EXCLUSIVEon every table, so it blocks behind any open transaction.- It takes locks one relation at a time. Stuck halfway, it still holds
ACCESS EXCLUSIVEon everything it already got.
So the waiting TRUNCATE is not only waiting. It is a huge lock holder. Anything that needs a table it already locked queues up behind it — including schema queries at boot. One idle transaction is enough to take the whole run down.
And it never recovers. Postgres detects deadlocks by walking the lock graph for a loop. Session 69337 is idle, not waiting on anyone, so the graph is a chain. deadlock_timeout never fires. Postgres will wait forever.
That is what “hangs with no error” means. A deadlock reports itself. This is not a deadlock.
Why it kept coming back: Ctrl-C orphans the workers
The first wedge was mundane: I interrupted a run.
Rails’ parallel worker looks like this:
# activesupport/lib/active_support/testing/parallelization/worker.rb
def start
fork do
# ...
work_from_queue
ensure
set_process_title("(stopping)")
run_cleanup
@queue.stop_worker(@id, Process.pid) # DRb call to the master
end
end
stop_worker is a DRb call to the coordinator. Ctrl-C kills the coordinator, so that call never returns. The worker parks in its ensure forever, reparented to init, still holding its transaction open. Transactional tests only roll back when the worker unwinds, so the transaction stays open with it.
Once you know the signature, it is hard to miss:
69203 1 15:35:22 Rails test worker 2 - (stopping)
69212 1 15:35:22 Rails test worker 9 - (stopping)
75756 1 15:34:39 Rails test worker 2 - (stopping)
75763 1 15:34:39 Rails test worker 9 - (stopping)
ppid of 1, title ending in (stopping). Six of them, from three earlier runs, each poisoning every run after. The master makes it stick:
# activesupport/lib/active_support/testing/parallelization/server.rb
def shutdown
@queue.close
while active_workers? # polls the DRb worker map, never reaps
sleep 0.1
end
end
One interrupted afternoon, and the machine could not run its test suite at all — with nothing on screen to say why.
The fix
Skip the truncate:
# config/environments/test.rb
ENV["SKIP_TEST_DATABASE_TRUNCATE"] ||= "1"
If your tests are transactional (Rails’ default — use_transactional_tests defaults to true), this costs nothing. Every test already runs inside a transaction that rolls back, so there is nothing to truncate. An out-of-date schema is still rebuilt; only the truncate of an already-current schema is skipped.
Check you are not opting out somewhere:
grep -rn "use_transactional_tests" config/ test/
If anything sets use_transactional_tests = false and leaves rows behind, you still need truncate (or another cleanup strategy) for those cases. For a normal Rails suite, you do not.
Two gotchas:
- Set it in the test environment, not in application config or a container env allow-list.
ActiveRecord::TestDatabasesis loaded byrails/test_help.rb, so this path never runs in production. - Rails treats the variable as truthy.
SKIP_TEST_DATABASE_TRUNCATE=0still skips. Unset it if you want truncate back.
Optional safety net on local Postgres (kills abandoned transactions before they live for 15 hours):
ALTER DATABASE myapp_test SET idle_in_transaction_session_timeout = '5min';
Apply per parallel DB (myapp_test_0 … myapp_test_9) if you use suffixes, or set it in postgresql.conf for your local cluster.
Verify the fix — and that your reproduction actually reproduces
A concurrency fix needs more than “the suite passed.” I reproduced the wedge on purpose: open a transaction, touch a table, leave it open.
BEGIN; SELECT id FROM myapp_test_2 LIMIT 1; SELECT pg_sleep(150);
Use the full suite. Rails only goes parallel above 50 tests. A single-file run says “in a single process”, uses the unsuffixed database, and never hits any of this.
With the variable unset, the suite wedges immediately — TRUNCATE stuck in pg_stat_activity, no output. With it set:
2014 runs, 11688 assertions, 0 failures, 0 errors, 0 skips
Finished in 18.037418s
The negative control is the part that matters. My first attempt passed with the fix still disabled. Tempting conclusion: the fix was unnecessary. Wrong. I had locked myapp_test, while parallel workers use myapp_test_0 through myapp_test_9. I had proved nothing.
Had I skipped that check, I would have shipped an unverified fix for a hang — and the next person to Ctrl-C a run would get the same dead machine under a confident commit message.
When you verify a hang fix, confirm the reproduction actually reproduces. A test that passes before the fix is broken, not reassuring.
Clearing a wedged machine
Interrupt first so nothing new joins in. Then find sessions holding a transaction open — anything listed is a leaked worker:
bin/rails runner -e test 'ActiveRecord::Base.connection.select_all(%q{SELECT pid, datname, state, now() - xact_start AS age, left(query, 60) AS query FROM pg_stat_activity WHERE datname LIKE $$myapp%test%$$ AND xact_start IS NOT NULL AND pid <> pg_backend_pid() ORDER BY xact_start}).each { |r| puts r.values.join(" | ") }'
ps -eo pid,ppid,etime,args | grep "Rails test worker" | grep -v grep
Kill the processes; Postgres rolls the transaction back when the client dies:
pkill -f "Rails test worker"
To unblock a run already in progress without restarting it, terminate the blocking sessions:
bin/rails runner -e test 'ActiveRecord::Base.connection.select_all(%q{SELECT pid, pg_terminate_backend(pid) AS terminated FROM pg_stat_activity WHERE datname LIKE $$myapp%test%$$ AND xact_start IS NOT NULL AND pid <> pg_backend_pid()}).each { |r| puts r.values.join(" | ") }'
A worker that loses its session mid-test fails with PG::ObjectInUse or ActiveRecord::StatementInvalid instead of hanging. That is the trade: an error you can read beats a hang you cannot.
Takeaway
A parallel suite that stops printing is not naming the slow test. Some worker stopped reporting, and the last line is just the last thing it managed to say.
| Step | Command | Answers |
|---|---|---|
| Which processes are alive | ps … | grep "rails test worker" |
Workers are renamed; grep ruby misses them |
| What a worker is doing | sample <pid> 2 |
The leaf frame, when Ruby frames are opaque |
| What the database is doing | pg_stat_activity, pg_blocking_pids |
The lock chain, and how old it is |
| Is it a deadlock | Look for a cycle | No cycle → Postgres waits forever |
What generalizes past this hang:
idle in transactionis a time bomb. A client that opens a transaction and stops talking holds locks indefinitely, and nothing warns you.TRUNCATEis the most dangerous statement in a test suite. It wants the strongest lock on every table at once, and while waiting it still holds everything it already locked.- A hang can outlive the run that caused it. Leftover workers turn one bad Ctrl-C into a permanently broken machine — clean up before the next run.
If your parallel suite hangs at 0% CPU, check pg_stat_activity before you check anything else. And if you have not already, read the other way a parallel Rails suite hangs on macOS
— same symptom, a segfault in pg instead of a lock, and worth ruling out.