Skip to content

io_uring: TransplantDoubleClaim=1 in TestHandoffHasNothingInFlight/async: rerunHandOff hands off a conn whose goroutine's claim is not yet queued, and the claim is then counted as a second one (pre-existing since #681) #758

Description

@FumingPower3925

What failed

celeris main 698bed6, push CI run 36341302731, Unit job 108681805572 (attempt 1), step engine/iouring — race tests at the runner's memlock (ubuntu-24.04 x86_64, kernel 6.17.0-1022-azure, 4 vCPU, memlock 8192 KiB, so one io_uring worker):

=== RUN   TestHandoffHasNothingInFlight/async
fd_lifetime_engine_test.go:393: celeris657 load conns=128 ok=74479 errs=0 classes=[] W1T=0 W1U=0 W1C=0 W2=0 held=0 reaps=213 misses=85 rescued=0 doubleclaim=1 detached=128 claimdeferred=0 reapfailed=0 reapunsupported=0
fd_lifetime_engine_test.go:393: TransplantDoubleClaim = 1, want 0 (a hand-off counter that must stay 0)
--- FAIL: TestHandoffHasNothingInFlight/async (1.99s)

The sync and async_without_cancel_flags arms passed in the same process, and the next step of the same job ran the test again and passed (doubleclaim=0). No client error, no stale recv data, all 128 connections handed off. The re-run of the failed job (attempt 2, job 108689465519) passed: the async arm passed in both steps and every load line reads doubleclaim=0.

Not a regression from today's merges

History

TestHandoffHasNothingInFlight was added in 4770d07 (#681) (git log -S). I searched every CI and Coverage workflow run created since 2026-09-13: 339 runs and 369 Unit/Coverage jobs across all attempts, with 368 logs fetched. The two workflows were queried separately, and each run's created_at was checked.

Mechanism

noteDoubleClaim has one call site: the slot check in finishAsyncTransplant (transplant_source.go:316). finishAsyncTransplant has two callers:

  1. drainDetachQueue runs it for a claim entry. It clears transplantPending first.
  2. rerunHandOff (fd_lifetime.go:200) runs it from retryReaps and from reapOutcome, whenever asyncRun reads false. It neither checks nor clears transplantPending.

The dispatch goroutine claims its own hand-off like this (worker.go:4283-4286): set transplantPending=true and asyncRun=false under asyncInMu, unlock, and only then call enqueueDetach. For that span the worker sees a claimed conn that is not on the detach queue yet.

A6 ("one owner per hand-off") makes tryTransplant leave such a conn to its claim (TransplantClaimDeferred). rerunHandOff has no such rule. The sequence:

  1. An earlier reap missed while a recv was armed, so a retry is owed (queueReapRetry).
  2. The goroutine publishes its claim, and its enqueueDetach lands after the loop's drainDetachQueue has run retryReaps and checked or swapped the queue.
  3. retryReaps → rerunHandOff: asyncRun is false, so finishAsyncTransplant places a reap on the recv the feed path armed.
  4. The reap cancels that recv before the client's next request arrives. At the -ECANCELED, reapOutcome → rerunHandOff → finishAsyncTransplant → handOff, with transplantPending still true.
  5. The claim's entry is drained. transplantPending is set, so finishAsyncTransplant runs, finds w.conns[cs.fd] != cs (the slot was vacated by step 4) and counts TransplantDoubleClaim.

One hand-off, counted as two claims. The slot check does its job: nothing is dup'd twice, and a reused fd number is never touched. The counter's premise does not hold, though. Its doc says what else vacates the slot "is another hand-off of the same conn", and here that other hand-off is the same claim, served by the rerun path. Detached releases skip releaseConnState, so the stale entry still has transplantPending set and the old fd when it is drained.

Impact beyond this flake: TransplantDoubleClaim is a must-stay-0 counter. The adaptive flap test (S0T4 DOUBLECLAIM) and goceleris/probatorium's validation checker (engine_transplant_double_claim, which a release gate can require) both treat nonzero as a defect. So this ordering can fail those gates too.

What is proven

1. Deterministic reproduction (test only, no engine change). The test is engine/iouring/doubleclaim_repro_test.go (attached below) and uses the existing fdlFixture. It builds the exact interleaving: claim published, retry owed, retry drain, reap -ECANCELED, then enqueue and drain. Laptop container (golang:1.27, arm64, kernel 7.0.12-linuxkit, memlock 8 MiB):

commit TestDCRepro/claim_enqueued_after_the_retry_drain control: enqueue before the retry drain TestDCReproOutcome
698bed6 FAIL: adopted=1, TransplantDoubleClaim=1 PASS (0) FAIL (1)
9f4d89b FAIL: adopted=1, TransplantDoubleClaim=1 PASS (0) FAIL (1)
4770d07 FAIL: adopted=1, TransplantDoubleClaim=1 PASS (0) FAIL (1)
698bed6 + candidate fix PASS: adopted=1, TransplantDoubleClaim=0, ClaimDeferred=1

2. Engine-level fault injection (RULE 50). TestHandoffHasNothingInFlight/async ran with a sleep in the claim window (after the asyncInMu unlock, before enqueueDetach), plus counters on rerunHandOff. Same container, 4 CPUs, memlock 8 MiB, -race:

arm iterations with doubleclaim>0 notes
sleep 2 ms in the claim window 12 / 80 184 double claims in total
same 2 ms sleep AFTER enqueueDetach (control) 0 / 40 rerun on a pending claim still happens (154+89), but the claim is already queued
no sleep (instrumentation only) 0 / 40
candidate fix + 2 ms claim-window sleep 0 / 30 128/128 handed off, 0 client errors
candidate fix, no sleep, whole test (sync, async, async_without_cancel_flags) 10 / 10 PASS
  • Attribution is exact. Every counted double claim followed a reapOutcome → rerunHandOff hand-off made while that conn's claim was set: doubleclaim_after_pending_handoff == TransplantDoubleClaim in every iteration, and doubleclaim_other = 0.
  • Significance. 2 ms window vs the after-enqueue control: one-sided Fisher p = 0.006. Vs the candidate fix: p = 0.017.
  • Longer windows do not help. A 20 ms window gave 0/5: the client's next request then arrives inside the window, and the respawn aborts the claim.

Not proven

  • That the CI failure took exactly this path. CI has no per-path counters. What matches: the async arm only; misses at the history maximum (retries come from misses); one hand-off per conn (detached=128 for 128 conns); zero errors.
  • The CI-shape rate on current main vs 9f4d89b. See the rates below. Stress shards with -count=200 in one process do not keep the CI conditions: the async arm's throughput falls from about 80k to about 30k requests after the second iteration, and misses fall to about 0. CI's own history, one process per run, is therefore the better rate estimate.

Rates

Iterations of TestHandoffHasNothingInFlight/async with TransplantDoubleClaim > 0, counted from --- PASS/FAIL/SKIP lines only:

where shape 698bed6 9f4d89b
goceleris/probatorium celeris-stress, target=github, runs 36344368270 / 36344373358 x86 ubuntu-24.04, kernel 6.17.0-1022-azure, -race, memlock 8 MiB, -run '^TestHandoffHasNothingInFlight$', 4 shards × -count=200 0 / 800 (0/4 processes) 0 / 800 (0/4 processes)
same runs arm64 ubuntu-24.04-arm, same kernel 0 / 800 (0/4) 0 / 800 (0/4)
laptop container, one fresh process per iteration (count=1, the CI per-process shape) arm64, kernel 7.0.12-linuxkit, -race, memlock 8 MiB, 4 CPUs 0 / 300 0 / 294 (6 SKIP, "io_uring not available": not counted)
CI history (Unit and Coverage jobs, one process per run) x86 GitHub-hosted 1 / ~260 in total, all commits since 4770d07
  • Intervals. 0/1600 per commit bounds the stress-shape rate at ≤ 0.23% (exact 95%). The CI history's 1/~260 is 0.38% (exact 95% interval 0.01% to 2.1%).
  • No sample separates the two commits, which is expected: the code paths are identical, and the deterministic reproduction fails on both. So I did not bracket further (a842109, 49d2726).
  • The stress shape undersamples the precondition. With -count=200 in one -race process, the async arm serves ~80k requests in iterations 1-2 and ~30k from then on, and its misses drop from CI's p90 = 26 to p90 = 0-1. The mechanism starts from a miss. The fresh-process laptop loop keeps CI-like misses (p90 37 and 49) and still shows 0/300, consistent with a rate well under 1% there.

Candidate fix (not a PR; verified only as above)

In rerunHandOff's async branch, apply A6 the way tryTransplant does:

cs.asyncInMu.Lock()
running := cs.asyncRun
claimed := cs.transplantPending.Load()
cs.asyncInMu.Unlock()
if !running && claimed {
	w.handoffLoss.noteClaimDeferred() // the claim's drain entry runs finishAsyncTransplant itself
	return
}
  • Retry case. The reap is left to the claim's own finishAsyncTransplant. In the fix arm, the deferral fired: TransplantClaimDeferred summed 484 over 30 iterations, against 21 and 31 in the two unfixed 30-iteration arms. TransplantDoubleClaim stayed 0, and 128/128 conns were handed off in every iteration.
  • Reap-landing case (a reap already out when a claim appears). It should become unreachable: the only reap that can be out under a pending claim is one rerunHandOff placed. If it did happen, reapOutcome re-arms the recv (the conn still owns its slot), and the claim's drain reaps it again: one extra cycle, and nothing is stranded if the drain stops first. This branch was not exercised in the runs above. The other route would be to have rerunHandOff consume the claim (clear transplantPending). That lets the late entry fall through drainDetachQueue to markDirty on a handed-off connState, so I would not take it without also skipping entries whose slot is vacated.
The reproduction test (drop into engine/iouring; uses the existing fdlFixture)
//go:build linux

package iouring

// Deterministic reproduction for the TransplantDoubleClaim=1 seen in
// TestHandoffHasNothingInFlight/async (celeris main 698bed6, CI run
// 36341302731). Test-only: no engine code is changed. It drives, on one
// worker, the interleaving the triage names:
//
//   1. the dispatch goroutine publishes its claim under asyncInMu
//      (transplantPending=true, asyncRun=false) and has NOT yet enqueued it
//      (runAsyncHandler: Unlock, then enqueueDetach);
//   2. a reap retry is owed for the conn (an earlier reap missed while its
//      recv was armed); the loop's drainDetachQueue runs retryReaps first,
//      and rerunHandOff -> finishAsyncTransplant places a reap, because
//      asyncRun reads false; the queue itself is still empty;
//   3. the reap lands: the recv's -ECANCELED -> reapOutcome -> rerunHandOff
//      -> finishAsyncTransplant -> handOff. transplantPending is never
//      cleared on this path;
//   4. the goroutine's enqueue lands; the next drain finds the claim, still
//      marked, calls finishAsyncTransplant, and the slot check counts a
//      double claim for a conn that was handed off ONCE.

import (
	"testing"

	"golang.org/x/sys/unix"
)

func TestDCRepro(t *testing.T) {
	setup := func(t *testing.T) *fdlFixture {
		t.Helper()
		f := newFDLFixture(t, true)
		f.armFirstRecv() // the recv the feed path armed after the last request
		f.cs.asyncPromoted.Store(true)
		f.startDrain()
		// Step 1: the claim is published, not enqueued.
		f.cs.asyncInMu.Lock()
		f.cs.transplantPending.Store(true)
		f.cs.asyncRun = false
		f.cs.asyncInMu.Unlock()
		// Step 2's precondition: a retry owed from an earlier miss.
		f.w.queueReapRetry(f.cs)
		return f
	}

	t.Run("claim_enqueued_after_the_retry_drain", func(t *testing.T) {
		f := setup(t)
		f.w.drainDetachQueue() // retryReaps runs; the detach queue is empty
		sqes := takeSQEs(f.w.ring)
		if len(sqes) != 1 || !f.isReap(sqes[0]) {
			t.Fatalf("the retry placed %v, want one reap", sqes)
		}
		f.process(f.recvCQE(-int32(unix.ECANCELED))) // step 3
		if n := f.tgt.adopted.Load(); n != 1 {
			t.Fatalf("the reap's -ECANCELED made %d hand-offs, want 1", n)
		}
		t.Logf("after the reap: transplantPending=%v conns[fd]==cs=%v", f.cs.transplantPending.Load(), f.w.conns[f.fd] == f.cs)
		f.w.enqueueDetach(f.cs) // step 4
		f.w.drainDetachQueue()
		dc := metric(t, f.e, "TransplantDoubleClaim")
		t.Logf("DCREPRO adopted=%d TransplantDoubleClaim=%d", f.tgt.adopted.Load(), dc)
		if n := f.tgt.adopted.Load(); n != 1 {
			t.Fatalf("handed off %d times, want exactly once", n)
		}
		if dc != 0 {
			t.Errorf("TransplantDoubleClaim = %d with exactly one hand-off: the queued claim was served by "+
				"rerunHandOff and then counted as a second claim", dc)
		}
	})

	// Control: the same state, but the goroutine's enqueue lands before the
	// drain that runs the retry (the common order). No double claim.
	t.Run("claim_enqueued_before_the_retry_drain", func(t *testing.T) {
		f := setup(t)
		f.w.enqueueDetach(f.cs)
		f.w.drainDetachQueue() // retryReaps places the reap, then the claim finds it out
		sqes := takeSQEs(f.w.ring)
		if len(sqes) != 1 || !f.isReap(sqes[0]) {
			t.Fatalf("the drain placed %v, want one reap", sqes)
		}
		f.process(f.recvCQE(-int32(unix.ECANCELED)))
		f.w.drainDetachQueue()
		dc := metric(t, f.e, "TransplantDoubleClaim")
		t.Logf("DCREPRO-CONTROL adopted=%d TransplantDoubleClaim=%d", f.tgt.adopted.Load(), dc)
		if n := f.tgt.adopted.Load(); n != 1 {
			t.Fatalf("handed off %d times, want exactly once", n)
		}
		if dc != 0 {
			t.Errorf("TransplantDoubleClaim = %d, want 0", dc)
		}
	})
}

// TestDCReproOutcome is the same interleaving judged by outcome only, so it
// runs unchanged on a tree that fixes it: whatever the retry drain does, the
// claim's enqueue lands after it, every reap placed lands as -ECANCELED, and
// the conn must be handed off exactly once with TransplantDoubleClaim 0.
func TestDCReproOutcome(t *testing.T) {
	f := newFDLFixture(t, true)
	f.armFirstRecv()
	f.cs.asyncPromoted.Store(true)
	f.startDrain()
	f.cs.asyncInMu.Lock()
	f.cs.transplantPending.Store(true)
	f.cs.asyncRun = false
	f.cs.asyncInMu.Unlock()
	f.w.queueReapRetry(f.cs)
	land := func(stage string) {
		sqes := takeSQEs(f.w.ring)
		reaps := 0
		for _, s := range sqes {
			if f.isReap(s) {
				reaps++
			}
		}
		t.Logf("%s placed %d SQEs, %d reaps", stage, len(sqes), reaps)
		if reaps > 0 && f.w.conns[f.fd] == f.cs {
			f.process(f.recvCQE(-int32(unix.ECANCELED)))
		}
	}
	f.w.drainDetachQueue() // the retry, before the claim is on the queue
	land("retry drain")
	f.w.enqueueDetach(f.cs)
	f.w.drainDetachQueue() // the claim
	land("claim drain")
	dc := metric(t, f.e, "TransplantDoubleClaim")
	t.Logf("DCREPRO-OUTCOME adopted=%d TransplantDoubleClaim=%d ClaimDeferred=%d", f.tgt.adopted.Load(), dc,
		metric(t, f.e, "TransplantClaimDeferred"))
	if n := f.tgt.adopted.Load(); n != 1 {
		t.Errorf("handed off %d times, want exactly once", n)
	}
	if dc != 0 {
		t.Errorf("TransplantDoubleClaim = %d, want 0", dc)
	}
}
Where the engine-level injection sleeps (the rest of the patch is counters)
if w.transplant.Load() != nil && w.asyncTransplantEligible(cs) {
	cs.transplantPending.Store(true)
	cs.asyncRun = false
	cs.asyncInMu.Unlock()
	dcInject(dcInjectClaimGap)     // CELERIS_DC_INJECT=claimgap: sleep here (the window)
	w.enqueueDetach(cs)
	dcInject(dcInjectAfterEnqueue) // CELERIS_DC_INJECT=afterenqueue: sleep here (control)
	return
}

Logs, the history tally and the full injection patch are in the triage lane's local evidence directory (evidence/celeris-doubleclaim-20260927/); ask if you want any of them attached.

Activity

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingengine/iouringio_uring engine specifics

    Type

    No type

    Projects

    No projects

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions