roachtest: perturbation/full/backfill failed

[cockroach-teamcity]

roachtest.perturbation/full/backfill failed with artifacts on master @ 3dc59b8f9bbac2f0b97eb530eba8bd588d3bc289:

Failed with:

(assertions.go:387).Fail: 
	Error Trace:	pkg/cmd/roachtest/tests/perturbation/framework.go:857
	            				pkg/cmd/roachtest/test_runner.go:1550
	            				src/runtime/asm_amd64.s:1771
	Error:      	FAILURE: follower-read  : throughput ratio 8455500000000.00x exceeds limit 1.2x (baseline: 8456 ops/s, measured: 0 ops/s)
	            	FAILURE: read           : throughput ratio 8452500000000.00x exceeds limit 1.2x (baseline: 8452 ops/s, measured: 0 ops/s)
	            	FAILURE: write          : throughput ratio 16921900000000.00x exceeds limit 1.2x (baseline: 16922 ops/s, measured: 0 ops/s)
	            	FAILURE: follower-read  : throughput ratio 8455500000000.00x exceeds limit 1.2x (baseline: 8456 ops/s, measured: 0 ops/s)
	            	FAILURE: read           : throughput ratio 8452500000000.00x exceeds limit 1.2x (baseline: 8452 ops/s, measured: 0 ops/s)
	            	FAILURE: write          : throughput ratio 16921900000000.00x exceeds limit 1.2x (baseline: 16922 ops/s, measured: 0 ops/s)
	Test:       	perturbation/full/backfill
(require.go:522).Fail: FailNow called
test artifacts and logs in: /artifacts/perturbation/full/backfill/run_1

Cluster Node to Ip Mapping:

Node	Public IP	Private IP
teamcity-21340200-1778135524-204-n13cpu16sm-0001	34.74.107.217	10.142.1.123
teamcity-21340200-1778135524-204-n13cpu16sm-0002	34.148.250.32	10.142.1.160
teamcity-21340200-1778135524-204-n13cpu16sm-0003	34.148.26.142	10.142.1.157
teamcity-21340200-1778135524-204-n13cpu16sm-0004	34.24.58.147	10.142.1.128
teamcity-21340200-1778135524-204-n13cpu16sm-0005	34.139.15.101	10.142.1.159
teamcity-21340200-1778135524-204-n13cpu16sm-0006	35.196.247.113	10.142.1.117
teamcity-21340200-1778135524-204-n13cpu16sm-0007	104.196.17.159	10.142.1.109
teamcity-21340200-1778135524-204-n13cpu16sm-0008	34.138.195.207	10.142.1.154
teamcity-21340200-1778135524-204-n13cpu16sm-0009	34.73.230.140	10.142.0.46
teamcity-21340200-1778135524-204-n13cpu16sm-0010	34.23.26.89	10.142.1.130
teamcity-21340200-1778135524-204-n13cpu16sm-0011	35.231.232.20	10.142.0.190
teamcity-21340200-1778135524-204-n13cpu16sm-0012	34.139.181.78	10.142.1.147
teamcity-21340200-1778135524-204-n13cpu16sm-0013	35.231.187.238	10.142.1.136

Parameters:

• acMode=defaultOption
• arch=amd64
• blockSize=4096
• cloud=gce
• coverageBuild=false
• cpu=16
• diskBandwidthLimit=0
• diskCount=2
• disks=2
• encrypted=false
• fillDuration=10m0s
• fs=ext4
• leaseType=leader
• localSSD=true
• mem=standard
• numNodes=12
• numWorkloadNodes=1
• perturbationDuration=10m0s
• ratioOfMax=0.5
• runtimeAssertionsBuild=false
• seed=0
• splits=10000
• validationDuration=5m0s
• vcpu=16

Help

See: roachtest README

See: How To Investigate (internal)

See: Grafana

See: Datadog Logs

/cc @cockroachdb/kv-triage

This test on roachdash | Improve this report!

Jira issue: CRDB-63711

[angeladietz]

/investigate

[github-actions]

Investigation: perturbation/full/backfill

Investigated failure: Issue body
Failure SHA: 3dc59b8f9bbac2f0b97eb530eba8bd588d3bc289
Confidence: high

What This Test Does

The perturbation/full/backfill test exercises CockroachDB's foreground workload stability during an index backfill. It starts a 12-node cluster, pre-fills a backfill database with replicas pinned to a target node (node 8), then runs a steady-state KV workload on a separate target database. During the "perturbation" phase it runs CREATE INDEX on the backfill data, and validates that foreground throughput doesn't drop more than 20% below baseline.

Where the Failure Occurs

The test fails at framework.go:857 because measured throughput during both the perturbation and recovery intervals was 0 ops/s against baselines of ~8,452–16,922 ops/s. The throughput ratios are astronomically high (e.g. 8455500000000.00x) because the denominator (p5(tput/s)) is zero.

The recovery stats are entirely zero:

Recovery stats
follower-read  : median(tput/s): 0 ops/s
read           : median(tput/s): 0 ops/s
write          : median(tput/s): 0 ops/s

Analysis

Hypothesis 1 (likely cause): Node 8 stall during backfill caused total workload stoppage — a known class of issue for this test, now caught by the recently-added throughput threshold.

Evidence:

1. Node 8 became unresponsive at ~17:21:06. All other nodes simultaneously lost gRPC connectivity to node 8 (10.142.1.154) at 17:21:12, with heartbeat timeouts of 6s across all connection classes (raft, system, default, rangefeed). The stall started ~6s earlier at 17:21:06.

2. Workload throughput dropped to 0 at 17:21:07, precisely when node 8 stalled. From the workload log, write throughput halved at 17:21:06 (from ~19,500 to ~9,900 ops/s), then dropped to 0 at 17:21:07 with no data ticks until 17:21:12. At 17:21:12, 51 errors appeared, growing to 81, after which throughput stayed at 0 permanently.

3. The workload error at 17:21:12 was: RPC error: grpc: error reading from server: read tcp 10.142.0.46:49186->10.142.1.154:26257: use of closed network connection with a TransactionAbortedError(ABORT_REASON_NEW_LEASE_PREVENTS_TXN). This confirms node 8's unresponsiveness caused cascading failures.

4. Node 8 was the backfill target node. The backfill database was configured with constraints='{"+node8":1}', meaning node 8 held replicas of all backfill data. At 17:17:21, node 8 showed a 5s latch wait for a GC request on the backfill table (Table 106), and a pebble compaction was cancelled. The heavy index backfill (validating 11M rows at 17:21:11) likely caused a severe storage stall.

5. Node 8 did NOT OOM or crash — no OOM kills in dmesg/journalctl. The node recovered eventually (other nodes reconnected), but the workload's --tolerate-errors mode didn't help because all 500 concurrent workers were stuck/erroring, resulting in permanent 0 throughput for the rest of the test.

6. The throughput threshold was recently added. Commit 9dda3aec545 (May 4, 2026 — 3 days before this failure) changed maxThroughputImpact from +Inf (never fail) to 1.25 (fail if throughput drops below 80% of baseline). This is the first time this test could fail on throughput. Prior runs with the same node-stall behavior would have passed silently.

Confidence: high — The failure mechanism is clear: backfill-induced storage pressure on node 8 caused a ~6s+ stall, making the node unreachable, which killed the foreground workload. The test now correctly catches this because of the new throughput threshold.

Root cause context: This is the same fundamental issue tracked in #139262 (index backfill causes large impact on foreground latency) and related to the WAL failover / admission control bypass documented in #165780 and #166476. The fix in PR #166731 addressed the WAL-failover-bypasses-admission-control variant, but storage stalls from heavy backfill IO on the target node remain a known problem.

Recommendation: This failure confirms the backfill perturbation test is working as intended with the new threshold — it's catching real throughput regressions. The underlying issue is the impact of index backfill on co-located storage. Options:

• Investigate whether the node 8 stall is an admission control gap (backfill writes not being throttled enough to prevent storage stalls).
• Consider whether perturbation/full/backfill should tolerate temporary workload stalls (e.g., use a higher threshold or exclude extreme outlier intervals) vs. treating any complete throughput loss as a failure.
• Track progress via #139262.

Related Issues and PRs

Issue	Relation
#139262	Root cause: index backfill causes large foreground latency impact (open)
#168249	Meta issue: re-introduce thresholds for perturbation tests (open)
#165780	Prior perturbation/full/backfill failure — WAL stalls on target node (closed, fixed in #166731)
#166476	Related: WAL failover disabling admission control → OOM (closed, fixed in #166731)
#162151	Prior perturbation/full/backfill failure — replica unavailable / circuit breaker (closed)
#169625	Recent perturbation/full/backup failure (open, different test)

Timeline

Time (UTC)	Event
16:26:43	Test starts, 12-node cluster initialized
16:52:54	Backfill data fill complete, IO overload subsides
17:05:34	Stable-rate workload starts at ~39,179 ops/s per node
17:08:05	Baseline measurement begins (2.5 min)
17:10:35	Perturbation starts: CREATE INDEX backfill_index ON backfill.kv (k, v)
17:17:21	Node 8: 5s latch wait on GC for backfill table
17:20:19	Node 8: pebble compaction cancelled
17:21:06	Node 8 stalls — workload throughput drops to 0
17:21:12	All nodes detect node 8 gRPC timeout; workload errors spike to 81
17:21:46	Perturbation ends, recovery interval begins
17:26:46	Recovery interval ends — all stats remain 0
17:26:51	Test fails: throughput ratio exceeds 1.2x threshold

• The throughput threshold of 1.25x was added on May 4 in 9dda3aec545.

Detailed evidence and investigation notes

Log Excerpts

Workload — last non-zero throughput (17:21:06) and first errors (17:21:12):

{"time":"2026-05-07T17:21:06.814897856Z","errs":0,"avgt":9908.4,"avgl":19509.6,"p50l":2.0,"type":"write"}
// 6-second gap — no ticks
{"time":"2026-05-07T17:21:12.815394806Z","errs":51,"avgt":415.8,"avgl":19385.1,"type":"write"}
{"time":"2026-05-07T17:21:13.815025255Z","errs":81,"avgt":418.2,"avgl":19364.9,"type":"write"}
{"time":"2026-05-07T17:21:14.815194515Z","errs":81,"avgt":0.0,"avgl":19344.2,"type":"write"}

Workload error:

ERROR: result is ambiguous: error=ba: Put [...], EndTxn(parallel commit) [...] RPC error: grpc: error reading from server: read tcp 10.142.0.46:49186->10.142.1.154:26257: use of closed network connection [code 14/Unavailable]
(last error: TransactionAbortedError(ABORT_REASON_NEW_LEASE_PREVENTS_TXN))

Node 1 — detecting node 8 failure:

E260507 17:21:12.464365 [...] disconnected (was healthy for 53m36.959s): operation "conn heartbeat" timed out after 6s: context deadline exceeded
W260507 17:21:12.237269 [...] closed timestamps side-transport connection dropped from node: 8

Node 2 — health alerts:

W260507 17:21:14.595191 [...] health alerts detected: ranges.underreplicated@s3=155, ranges.underreplicated@s4=167

Node 8 — latch wait during backfill:

W260507 17:17:21.884967 [...] have been waiting 5s to acquire write latch [...] for request GC [/Table/106/2/...]

Node 8 — pebble compaction cancelled:

E260507 17:20:19.673026 [...] background error: pebble: compaction cancelled by a concurrent operation, will retry compaction

Code References

• Threshold enforcement: framework.go:920-946 — isAcceptableChange() computes base.throughput/nonZero(stats.throughput) and compares to limits.maxThroughputImpact (1.25).
• Default thresholds: framework.go:276-281 — maxThroughputImpact: 1.25.
• Backfill perturbation: index_backfill.go:94-101 — CREATE INDEX backfill_index ON backfill.kv (k, v).

Things Ruled Out

• OOM kill: No OOM kills found in dmesg or journalctl for any node.
• Node crash: Node 8 did not crash — it stalled temporarily and recovered. Other nodes reconnected to it after the stall.
• WAL failover bypass (the release-25.2: perturbation: rate-limit backfill pre-fill to avoid OOM on target node #166731 fix): Node 8's IO admission controller showed [status] admitting all with healthy L0 metrics at 17:21:05, suggesting the WAL failover/AC bypass was not the primary issue here. The stall appears to be a direct storage pressure issue from the backfill rather than an admission control bypass.
• Test infrastructure issue: The workload node (13) and all other nodes were healthy. Only node 8 stalled.

Other Failure Occurrences

This is the first occurrence filed under this issue. However, comparing with prior failures of the same test:

• roachtest: perturbation/full/backfill failed #165780 (March 2026): Different failure — workload init failed with replica unavailable / slow proposal during split. Root cause was WAL failover disabling admission control.
• roachtest: perturbation/full/backfill failed #162151 (Feb 2026): Different failure — replica unavailable error during workload run, also related to node 8 stall during backfill.
• All prior failures share the common theme of node 8 (the backfill target) becoming overloaded during the index backfill, but the specific failure mode varies (WAL stall, OOM, storage stall). This occurrence is the first to fail via the throughput threshold, which was only added on May 4.

Workflow run

---

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

[tbg]

yep definitely workload tanked, see roachperf here: