roachtest: transfer-leases/drain-other-node failed

[cockroach-teamcity]

Note: This build has runtime assertions enabled. If the same failure was hit in a run without assertions enabled, there should be a similar failure without this message. If there isn't one, then this failure is likely due to an assertion violation or (assertion) timeout.

roachtest.transfer-leases/drain-other-node failed with artifacts on release-25.4 @ f224345f5c16ce7e17a0d9203a98ca45599c4742:

(cluster.go:2436).Stop: cluster.StopE: one or more parallel execution failure(s): context deadline exceeded
test artifacts and logs in: /artifacts/transfer-leases/drain-other-node/run_1

Parameters:

• arch=amd64
• cloud=gce
• coverageBuild=false
• cpu=4
• encrypted=false
• metamorphicBufferedSender=true
• metamorphicLeases=leader
• metamorphicWriteBuffering=true
• runtimeAssertionsBuild=true
• ssd=0

Help

See: roachtest README

See: How To Investigate (internal)

See: Grafana

/cc @cockroachdb/kv-triage

This test on roachdash | Improve this report!

Jira issue: CRDB-61595

[pav-kv]

/investigate

[github-actions]

Investigation: transfer-leases/drain-other-node

Investigated failure: #165792 (issue body)
Failure SHA: f224345f5c16ce7e17a0d9203a98ca45599c4742
Confidence: moderate

What This Test Does

The transfer-leases/drain-other-node roachtest verifies that draining a node from a different node (exercising the drain RPC redirect) successfully transfers all leases before the node shuts down. It creates 500 ranges on a 3-node cluster, then iterates through each node three times: draining it, verifying no leases remain, and restarting it.

Where the Failure Occurs

The test fails at quit.go:458 when calling c.Stop (SIGKILL with wait) on Node 1 during the first iteration (iteration 0, node 1). The error is context deadline exceeded — the 1-minute timeout from runWithTimeout expires before the stop command completes.

The SSH command that should have sent kill -9 to the cockroach process produced <no output>, indicating the roachprod kill script never executed or never completed on the remote node before the context was cancelled.

Analysis

Hypothesis 1: The SIGKILL stop SSH command failed to reach the remote node in time (moderate confidence)

The timeline from the test log and journalctl on Node 1:

1. 08:50:02 — runWithTimeout starts (1-minute deadline: 08:51:02)
2. 08:50:02 — cockroach node drain begins from Node 2 targeting Node 1
3. 08:50:03 — Drain completes successfully ("remaining: 0 (complete)")
4. 08:50:04 — SIGHUP stop (c.Stop with sig=1, no wait) — SSH session 473 connects and disconnects quickly. Node 1 receives SIGHUP and reloads certificates but stays alive
5. 08:50:04 — SIGKILL stop (c.Stop with sig=9, wait=true) should begin
6. 08:50:14 — systemd tears down the user@1000.service after 10-second linger timeout (no active SSH sessions for the ubuntu user)
7. 08:50:14 – 08:51:02 — No SSH sessions to Node 1 appear in journalctl
8. 08:51:02 — Context deadline expires. The SIGKILL stop returns context deadline exceeded
9. 08:51:02 — Post-failure artifact collection SSH sessions begin

The critical gap: between 08:50:04 (SIGHUP session closes) and 08:51:02 (timeout), no SSH session for the SIGKILL stop appears in Node 1's journalctl. Yet the test framework reports it tried to run the kill script but got <no output>. This means either:

• The SSH connection attempt hung (unlikely given ConnectTimeout=5)
• The SSH session was established but not logged by systemd-logind (unlikely)
• There was a transient networking issue or SSH authentication delay

Supporting evidence: The cockroach process was still alive after the SIGHUP, as confirmed by continued "cannot acquire lease when draining" log messages in the cockroach log through 08:50:58. The SIGKILL was never delivered.

Hypothesis 2: The 1-minute timeout is too tight for runtime-assertions builds (moderate confidence)

The test uses runWithTimeout with a hard-coded 1-minute timeout for the entire drain + SIGHUP stop + SIGKILL stop sequence. While the drain completed quickly (~1 second), the SSH-based stop commands need to establish connections, run scripts, and wait for process exit. On a runtime-assertions-enabled build (which is slower) on GCE infrastructure, this sequence can be tight.

The prior issue #160870 showed the same context deadline exceeded failure pattern across multiple cloud providers (GCE and Azure), both with and without runtime assertions. That issue was closed after PR #161195 ("kvserver: do not use StoreLiveness as a signal to mark stores as dead") was merged, but that fix addressed a different failure mode (StoreLiveness causing incorrect store-dead marking) and is not present in the release-25.4 branch at this failure SHA.

Related Issues and PRs

Issue/PR	Status	Relevance
#160870	Closed	Same test, same error signature (context deadline exceeded in c.Stop). Closed after PR #161195, but that fix is not in release-25.4.
#160823	Closed	transfer-leases/drain (not drain-other-node) with similar timeout failure
PR #161195	Merged	"kvserver: do not use StoreLiveness as a signal to mark stores as dead" — NOT backported to release-25.4
#74691	Open	Drained nodes can re-acquire + retain leases (long-standing known issue)

Timeline

• 2026-01-10 – 2026-01-15: Multiple drain-other-node failures on master tracked in #160870, all with the same context deadline exceeded error
• 2026-01-16: PR kvserver: do not use StoreLiveness as a signal to mark stores as dead  #161195 merged on master; issue roachtest: transfer-leases/drain-other-node failed #160870 closed
• 2026-03-15: This failure on release-25.4 at SHA f224345f5c16ce7e17a0d9203a98ca45599c4742

Detailed evidence and investigation notes

Log Excerpts

test.log — drain completes, stop hangs:

2026/03/15 08:50:02 cluster.go:2595: running cmd `./cockroach node drain --lo...` on nodes [:2]
2026/03/15 08:50:03 quit.go:445: cockroach node drain:
drain ok
node is draining... remaining: 610
node is draining... remaining: 0 (complete)

2026/03/15 08:50:03 cluster.go:722: test status: stopping nodes :1
teamcity-...: stopping
2026/03/15 08:50:04 cluster.go:722: test status: stopping nodes :1
teamcity-...: stopping and waiting
2026/03/15 08:51:02 cluster_synced.go:2503: 1: context deadline exceeded

cockroach.log Node 1 — SIGHUP received, process stays alive:

I260315 08:50:03.716678  drain request completed without server shutdown
I260315 08:50:04.260818  received signal "hangup", triggering certificate reload
W260315 08:50:08.037980  error polling for transaction diagnostics requests: cannot acquire lease when draining
W260315 08:50:18.039374  error polling for transaction diagnostics requests: cannot acquire lease when draining
[... continues every 10s through 08:50:58 ...]

roachprod.log Node 1 — only one stop entry (SIGHUP), no SIGKILL entry:

>>> roachprod stop: Sun Mar 15 08:50:04 UTC 2026
[process listing showing cockroach PID 41579 with ROACHPROD=1]

No second >>> roachprod stop entry exists, confirming the SIGKILL kill script never executed on the remote node.

journalctl Node 1 — user manager teardown in the gap:

Mar 15 08:50:04  Session 473 logged out.
Mar 15 08:50:14  Stopping User Manager for UID 1000...
Mar 15 08:50:14  Stopped User Manager for UID 1000.
Mar 15 08:50:14  Stopped User Runtime Directory /run/user/1000.
Mar 15 08:50:14  Removed slice User Slice of UID 1000.
[no SSH sessions until 08:51:02]
Mar 15 08:51:02  New session 474 of user ubuntu.  [post-failure artifact collection]

Code References

• quit.go:430-459 — drain-other-node test method: drain → SIGHUP stop → SIGKILL stop
• quit.go:147-155 — runWithTimeout with 1-minute deadline
• cluster_synced.go:557-646 — kill function that generates the remote kill script
• session.go:110-131 — SSH session setup with ConnectTimeout=5

Things Ruled Out

• Drain failure: The drain completed successfully ("remaining: 0 (complete)") in ~1 second
• Uninterruptible process (D state): No kernel-level issues in dmesg — the process never received SIGKILL, so it wasn't stuck in D state
• Coverage mode interference: coverageBuild=false, so the SIGUSR1 pre-stop path in cluster.go:2412 is not triggered
• Process monitor interference: ExpectProcessDead is just metadata tracking, non-blocking
• CockroachDB bug causing slow drain: The drain itself was fast. The issue is purely in the stop/kill mechanism

Other Failure Occurrences

The prior issue #160870 had 5 failures of the same test across multiple SHAs, all on master, with the same error signature: context deadline exceeded in c.Stop. Some were on GCE, some on Azure. Some had runtime assertions, some did not. The error was consistently (quit.go:447).func4: context deadline exceeded — note this is the same function at a different line number (likely a version difference).

Tooling Feedback

• The SSH verbose logs (-vvv -E <logfile>) for the SIGKILL stop command would have been extremely valuable to determine whether the SSH connection was attempted, established, or rejected. These logs are written to the roachtest artifacts directory but were not included in the artifacts.zip. Including SSH debug logs for failed commands in the artifact bundle would significantly aid debugging.
• Access to the roachprod controller logs (showing all SSH commands issued and their results) would help determine whether the SIGKILL stop's SSH command was even dispatched.

---

Workflow run

---

Was this investigation helpful? Leave a 👍 or 👎 on this comment.

[pav-kv]

Verified Hypothesis 1, the node 1 indeed stays alive and hasn't received the sigkill.

We can close as an infra flake, and try to figure out why SIGKILL got lost on the way if this happens again. It's sent by this code:

cockroach/pkg/roachprod/install/cluster_synced.go

Lines 575 to 598 in b6ba26a

	if wait {
	waitCmd = fmt.Sprintf(`
	for pid in ${pids}; do
	echo "${pid}: checking" >> %[1]s/roachprod.log
	waitcnt=0
	while kill -0 ${pid}; do
	if [ %[2]d -gt 0 -a $waitcnt -gt %[2]d ]; then
	echo "${pid}: max %[2]d attempts reached, aborting wait" >>%[1]s/roachprod.log
	echo "%[3]s"
	break
	fi
	kill -0 ${pid} >> %[1]s/roachprod.log 2>&1
	echo "${pid}: still alive [$?]" >> %[1]s/roachprod.log
	ps axeww -o pid -o command >> %[1]s/roachprod.log
	sleep 1
	waitcnt=$(expr $waitcnt + 1)
	done
	echo "${pid}: dead" >> %[1]s/roachprod.log
	done`,
	c.LogDir(node, "", 0), // [1]
	gracePeriod, // [2]
	timedOutMessage, // [3]
	)
	}

Some fixes suggested by Claude:

1. (preferred) Enable loginctl enable-linger ubuntu on roachprod VMs — this prevents systemd from tearing down the user manager when no sessions are active. The startup scripts already configure LoginGraceTime but don't set linger.

2. Don't send SIGHUP and SIGKILL as separate SSH sessions — the test at quit.go:452-458 sends SIGHUP (sig=1, no wait) then SIGKILL (sig=9, wait=true) as two separate c.Stop calls. The SIGHUP session disconnects immediately (no wait), creating the window for systemd teardown. Combining them into a single SSH session, or at least waiting on the SIGHUP session, would avoid the gap.

3. Increase the linger timeout on the VMs (default is 10s, which is clearly too short for back-to-back SSH operations).