Repository navigation
TestServerTLSLoopback hung for 1h20m on macOS, taking the lane's whole 90m budget: a GVL hand-off deadlock, not a slow suite #695
Description
TestServerTLSLoopback (internal/vm/socket_test.go:782) hung for 1h20m on
test (macos-latest) and took the whole lane down with it:
panic: test timed out after 1h30m0s
running tests:
TestServerTLSLoopback (1h20m14s)
One test, no assertion failure anywhere in the job — --- FAIL: appears
nowhere. This is a deadlock, not a slow suite, and it is worth separating from the
budget-exhaustion story of #623: that one was the whole binary running out of 50
minutes, this is a single test blocking for 80 of the 90.
The test names the invariant it depends on, and that invariant is the suspect
Its own comment:
The client (a Thread) runs the connect handshake — which hands the GVL back to
the spawner while it blocks, letting the server (main) run its accept handshake
concurrently — then writes and closes. The server reads the buffered request
afterwards, so no two Threads ever block on a read at once.
So the test passes only if a blocking socket operation inside a Ruby Thread
releases the GVL. srv.accept on the main thread and ssl.connect in the spawned
thread must interleave; if the hand-off does not happen, both block forever,
which is exactly the observed shape.
Hypothesis, with independent support from today — stated as a hypothesis
Two separately measured defects in the same area were routed today from the
mspec-shim work (#692), both in internal/vm/thread.go:
Thread#joinnever returns for a thread killed while blocked inMutex#lockor
Queue#pop(core/mutex/synchronize_spec.rb2→0,core/thread/value_spec.rb
3→0, with MRI 2→5 and 3→4 respectively);Thread#abort_on_exception=does not interrupt the main thread — the spec's bare
sleepnever returns.
Both are "a blocking operation that does not yield control as MRI's does". This
TLS hang has the same signature. I have not shown they are the same defect —
that is the thing to test.
What is known and what is not
- The test was added in feat(socket): UDPSocket + UNIXSocket/UNIXServer + server-side TLS #192 and has been green for a long time, including on six
other pull requests today. - It is not in PR internal/vm, ci: fix the js/wasm build, and make the guard that caught it reachable #684's diff. internal/vm, ci: fix the js/wasm build, and make the guard that caught it reachable #684 does touch
socket_test.go, but only to
turn at.Skipf("cannot build cmd/rbgo")intot.Fatalf(Two tests report a build failure as a PASS (t.Skipf on 'cannot build cmd/rbgo'), plus the full env-var-gate inventory #687); when the build
succeeds — as it does — that path is identical either way. - This is one occurrence. One sample from a possibly-flaky population proves
nothing about a rate, so the failed job has been re-run to discriminate
"deterministic on this branch" from "intermittent". Until that comes back, the
rate is unknown and should not be quoted. -raceslows execution by a large factor and shifts exactly the timing this
test depends on, which is a plausible reason it surfaces on a-racelane and
not locally.
Worth doing regardless of the cause
The test has no deadline of its own. A Ruby-level concurrency test that can
deadlock should bound itself, so that it fails in seconds naming the blocked side
instead of consuming the binary's entire budget and reporting as a timeout with no
failing assertion. A hang that presents as "the lane took 90 minutes" costs far
more to diagnose than one that presents as "accept did not return within 10s".
Activity
fix(vm): release the GVL around blocking socket calls (#695)
tannevaled commentedon Sep 26, 2026
The discriminator came back: intermittent, not deterministic on that branch.
I re-ran only the failed macOS job on the same commit. It passed, and the PR is
now 9/9 and merged. So:
That is enough to say the hang is not caused by PR #684 — which is what the
re-run was for — and not enough to quote a rate. Two runs on one commit is a
sample of two. What can be said honestly: it is reachable and it is rare.
Why this still matters at a rate that low. The cost of an occurrence is not one
red tick — it consumed 80 of the lane's 90 minutes and reported as
panic: test timed outwith no failing assertion anywhere in the job, which is themost expensive shape a failure can take here. A 1-in-N hang in a 70-minute lane is
worse than a 1-in-N assertion failure by a wide margin.
So the two follow-ups stand independently of the rate:
blocked side —
srv.acceptdid not return, orssl.connectdid not — insteadof consuming the binary's budget. That is a test-side change and costs nothing
in fidelity: a deadline in a test is an assertion about liveness; a timeout in
the VM where MRI blocks indefinitely would be a divergence, and is not what is
being proposed.
working
internal/vm/thread.goagainst the two defects routed from fix(conformance): repair the mspec shim — 530 examples MRI itself could not score #692(
Thread#joinnot returning from a killedMutex#lock/Queue#pop,Thread#abort_on_exception=not interrupting the main thread) plus a third foundsince — an uncaught
SystemExitin a non-main thread not reaching the mainthread's blocking
sleep, worth 24 examples across three spec files thatcurrently TIME OUT rather than fail. Four candidates, one suspected cause; that
brief asks for the question to be settled by measurement, with "these are
four separate defects" accepted as a good answer.
Keeping this open until the thread work reports, since if the common cause is real
this is its cheapest reproducer.
fix(vm): a dying thread releases its mutexes and honours abort_on_exc…
tannevaled commentedon Sep 26, 2026
Diagnosed, reproduced deterministically, and fixed in #698.
The hypothesis in this issue was right about the shape and wrong about the
unification. The three routed defects and this hang are not one defect: they
are four of five, with five distinct mechanisms. The ablation matrix is in #698 —
each fix built alone and run against every witness, and no single change fixes two
of them.
What #695 actually is
The test does release the GVL for both TLS handshakes, so the peers complete the
handshake. Then both race for the GVL — the client to reach
ssl.write, theserver to reach
conn.gets:getsis satisfied from thebuffer, green;
getsholding the GVL the client needs to write,and both stop forever.
TCPServer#acceptand the socket reads never released the GVL at all. Whichwaiter a
sync.Mutexhands to is unspecified and-raceshifts exactly thattiming — hence green on six PRs the same day and 1h20m on one macOS
-racelane.The test's own comment names the invariant it depends on, as this issue said, but
the second half of that comment — "the server reads the buffered request
afterwards, so no two Threads ever block on a read at once" — describes the
lucky interleaving as if it were guaranteed. It is the ordering, not the
buffering, that was never guaranteed.
The
-race-only condition was removableThe interleaving no longer needs a timing shift to appear: one placed
sleepforces the losing order, so the witness fails without
-raceonmainandpasses without it on the branch. Four of them (
accept,gets,read,recv)plus an AF_UNIX dual.
The deadline
TestServerTLSLoopbacknow has its own, as this issue asked. Measured effect: thewhole set of new hangs reports in 107 seconds on unmodified
mainwhere oneunbounded hang cost 80 minutes of a 90-minute lane and reported as
panic: test timed outwith no failing assertion anywhere in the job. The deadlineis the test's, never the VM's — MRI's
acceptand read block indefinitely, so atimeout inside the primitive would be a divergence rather than a fix.
fix(vm): thread blocking and the GVL hand-off — five defects, one sub…
tannevaled commentedon Sep 26, 2026
Fixed and confirmed on the lane that produced it. Closing.
The hang is resolved by #698 (merged), and the confirmation is specific: the
macOS
-racelane — the lane this hung on for 1h20m — is green. That was the onecondition no local run could reproduce, since this host cannot run
-raceat all(
CGO_ENABLED=0is required here).What it actually was
Not a flake, and not the GVL hand-off failing to happen. The test does release
the GVL for both TLS handshakes. Then both peers race for it — the client to
ssl.write, the server toconn.gets. Client first: the write is buffered andeverything proceeds, which is why it was green for months and on six PRs in one day.
Server first: it blocks in
getsholding the GVL the client needs in order towrite, and both stop for ever.
The test's own comment described the lucky interleaving as though it were
guaranteed.
sync.Mutexhand-off order is unspecified, and-raceshifts exactlythat timing.
Two things worth keeping
The
-race-only condition turned out to be removable. One placedsleepforcesthe losing order, so the witness now fails without
-raceon the old code andpasses without it on the new — a flake converted into a deterministic test. That is
the shape to aim for whenever a bug is "only reproducible under
-race": the raceis usually a scheduler hint, not a requirement.
TestServerTLSLoopbacknow carries its own deadline. A recurrence reports in~30s naming the blocked side instead of consuming the binary's 90-minute budget and
presenting as
panic: test timed outwith no failing assertion. A Ruby-levelconcurrency test that can deadlock should bound itself; a deadline in a test is an
assertion about liveness, which is not the same thing as a timeout in the VM where
MRI blocks indefinitely — that would be a divergence.
And the common-cause hypothesis was wrong, which is worth recording
I routed this alongside three other symptoms as "one suspected family: a blocking
operation that does not yield control as MRI's does", and asked for the question to
be settled by measurement with "these are separate defects" accepted as a good
answer. It was five defects, five mechanisms, established by an ablation matrix —
each fix built alone against all seven witnesses. The GVL-release fix and the
interrupt fix repair disjoint sets, and a third witness resists both. They shared
a description and nothing else.