release-26.2.1-rc: kv/kvnemesis: TestKVNemesisMultiNode_Partition_Safety failed

[cockroach-teamcity]

kv/kvnemesis.TestKVNemesisMultiNode_Partition_Safety failed with artifacts on release-26.2.1-rc @ 7797103d26398f23c60599f86df401d6454dadb0:

=== RUN   TestKVNemesisMultiNode_Partition_Safety
    test_log_scope.go:172: test logs captured to: /artifacts/tmp/_tmp/4aeb9c412c16a003ed8ddc43788d2bba/logTestKVNemesisMultiNode_Partition_Safety3678608590
    test_log_scope.go:82: use -show-logs to present logs inline
    kvnemesis_test.go:690: seed: 7628234005623186896
    kvnemesis_test.go:292: n1 using clock[offset=-286.409µs,amp=3.213591ms]
    kvnemesis_test.go:292: n2 using clock[offset=-293.647µs,amp=3.206353ms]
    kvnemesis_test.go:292: n3 using clock[offset=-219.5µs,amp=3.2805ms]
    kvnemesis_test.go:292: n4 using clock[offset=304.911µs,amp=3.195089ms]
    test_server_shim.go:146: using test tenant configuration from testserver factory defaults
    kvnemesis_test.go:704: error executing query="SET CLUSTER SETTING kv.rangefeed.enabled = true" args=[]: pq: setting updated but timed out waiting to read new value
    panic.go:615: -- test log scope end --
test logs left over in: /artifacts/tmp/_tmp/4aeb9c412c16a003ed8ddc43788d2bba/logTestKVNemesisMultiNode_Partition_Safety3678608590
--- FAIL: TestKVNemesisMultiNode_Partition_Safety (17.76s)

Help

See also: How To Investigate a Go Test Failure (internal)

/cc @cockroachdb/kv-triage

This test on roachdash | Improve this report!

Jira issue: CRDB-64113

[pav-kv]

/investiagate

[cockroach-teamcity]

kv/kvnemesis.TestKVNemesisMultiNode_Partition_Safety failed with artifacts on release-26.2.1-rc @ 268bf787cfff7c90049094fe2de87724f0c5f388:

=== RUN   TestKVNemesisMultiNode_Partition_Safety
    test_log_scope.go:172: test logs captured to: /artifacts/tmp/_tmp/4aeb9c412c16a003ed8ddc43788d2bba/logTestKVNemesisMultiNode_Partition_Safety3983305926
    test_log_scope.go:82: use -show-logs to present logs inline
    kvnemesis_test.go:690: seed: 5897566969651547304
    kvnemesis_test.go:292: n1 using clock[offset=-215.685µs,amp=3.284315ms]
    kvnemesis_test.go:292: n2 using clock[offset=-148.868µs,amp=3.351132ms]
    kvnemesis_test.go:292: n3 using clock[offset=-11.709µs,amp=3.488291ms]
    kvnemesis_test.go:292: n4 using clock[offset=-61.419µs,amp=3.438581ms]
    test_server_shim.go:146: using test tenant configuration from testserver factory defaults
    kvnemesis_test.go:367: kvnemesis logging to /artifacts/tmp/_tmp/4aeb9c412c16a003ed8ddc43788d2bba/kvnemesis3765184775
    kvnemesis.go:241: committed txn overwritten key had write: [d][/Table/100/"00af6c6b545b9bd8",/Table/100/"023b19059b8b918f"):1779375475.590528475,0-><nil>@s21 [d][/Table/100/"00af6c6b545b9bd8",/Table/100/"023b19059b8b918f"):1779375475.079281160,0-><nil>@s21 [s]/Table/100/"0{0af6c6b545b9bd8"-23b19059b8b918f"}:{gap:}->[]
    kvnemesis.go:282: failures(verbose): /artifacts/tmp/_tmp/4aeb9c412c16a003ed8ddc43788d2bba/kvnemesis3765184775/failures
        repro steps: /artifacts/tmp/_tmp/4aeb9c412c16a003ed8ddc43788d2bba/kvnemesis3765184775/repro.go
        rangefeed KVs: /artifacts/tmp/_tmp/4aeb9c412c16a003ed8ddc43788d2bba/kvnemesis3765184775/kvs-rangefeed.txt
        scan KVs: /artifacts/tmp/_tmp/4aeb9c412c16a003ed8ddc43788d2bba/kvnemesis3765184775/kvs-scan.txt
    kvnemesis_test.go:807: Metric                              | Node 1                         | Node 2                         | Node 3                         | Node 4                        
    kvnemesis_test.go:813: ------------------------------------+--------------------------------+--------------------------------+--------------------------------+-------------------------------
    kvnemesis_test.go:820: follower_reads.success_count        | 2                              | 11                             | 9                              | 0                             
    kvnemesis_test.go:820: raft.commands.proposed              | 3922                           | 256                            | 354                            | 136                           
    kvnemesis_test.go:820: raft.commands.reproposed.new-lai    | 0                              | 2                              | 0                              | 0                             
    kvnemesis_test.go:820: raft.commands.reproposed.unchanged  | 120                            | 7                              | 4                              | 117                           
    kvnemesis_test.go:820: txn.aborts                          | 7                              | 4                              | 8                              | 15                            
    kvnemesis_test.go:820: txn.durations                       | μ=43ms p50=10ms p99=239ms      | μ=826ms p50=25ms p99=14.818s   | μ=562ms p50=30ms p99=10.201s   | μ=386ms p50=12ms p99=5.906s   
    kvnemesis_test.go:820: txn.restarts.writetooold            | 14                             | 0                              | 1                              | 0                             
    kvnemesis_test.go:820: txn.restarts.serializable           | 1                              | 0                              | 0                              | 0                             
    kvnemesis_test.go:820: txn.restarts.readwithinuncertainty  | 0                              | 0                              | 0                              | 0                             
    kvnemesis_test.go:820: txn.server_side.1PC.success         | 107                            | 0                              | 2                              | 4                             
    kvnemesis_test.go:820: txnrecovery.failures                | 0                              | 0                              | 0                              | 0                             
    kvnemesis_test.go:820: txnrecovery.successes.aborted       | 0                              | 0                              | 0                              | 0                             
    kvnemesis_test.go:820: txnrecovery.successes.committed     | 0                              | 0                              | 0                              | 0                             
    kvnemesis_test.go:820: txnwaitqueue.deadlocks_total        | 0                              | 3                              | 0                              | 2                             
    kvnemesis_test.go:741: 
        	Error Trace:	pkg/kv/kvnemesis/kvnemesis_test.go:741
        	            				pkg/kv/kvnemesis/kvnemesis_test.go:501
        	Error:      	Should be zero, but was 1
        	Test:       	TestKVNemesisMultiNode_Partition_Safety
        	Messages:   	kvnemesis detected failures
    dump_raft_logs.go:32: dumping raft logs to /artifacts/tmp/_tmp/4aeb9c412c16a003ed8ddc43788d2bba/kvnemesis3765184775/raftlogs
    panic.go:615: -- test log scope end --
test logs left over in: /artifacts/tmp/_tmp/4aeb9c412c16a003ed8ddc43788d2bba/logTestKVNemesisMultiNode_Partition_Safety3983305926
--- FAIL: TestKVNemesisMultiNode_Partition_Safety (67.51s)

Help

See also: How To Investigate a Go Test Failure (internal)

This test on roachdash | Improve this report!

[stevendanna]

/investigate

[github-actions]

Investigation: TestKVNemesisMultiNode_Partition_Safety

Investigated failure: #issuecomment-4510373047
Failure SHA: 268bf787cfff7c90049094fe2de87724f0c5f388
Confidence: high

What This Test Does

TestKVNemesisMultiNode_Partition_Safety runs a randomized KV workload on a 4-node cluster with network partitions, fault injection (invalid lease applied index at 20% probability, reproposal error injection at 20%), and clock skew. It generates random KV operations (puts, deletes, scans, delete ranges, AddSSTable, etc.) concurrently, then validates that all observed MVCC writes are consistent with the operations' outcomes.

Where the Failure Occurs

The validator detects that a DeleteRangeUsingTombstone operation produced MVCC range tombstones at two different timestamps for the same sequence number (@s21):

committed txn overwritten key had write:
  [d][/Table/100/"00af6c6b545b9bd8",/Table/100/"023b19059b8b918f"):1779375475.590528475,0-><nil>@s21
  [d][/Table/100/"00af6c6b545b9bd8",/Table/100/"023b19059b8b918f"):1779375475.079281160,0-><nil>@s21
  [s]/Table/100/"0{0af6c6b545b9bd8"-23b19059b8b918f"}:{gap:}->[]

The failure fires at validator.go:1306 in checkAtomicCommitted, which verifies that only the most recent write for each key materializes in MVCC.

Analysis

Hypothesis: Non-transactional DeleteRangeUsingTombstone double-evaluated due to DistSender retry after ambiguous RPC error (likely cause, high confidence)

This is the same known issue as #160653: kv: non-transactional requests can double evaluate.

The mechanism:

1. A non-transactional DeleteRangeUsingTombstone request is sent to a replica.
2. The request evaluates and applies, writing range key tombstones at timestamp 1779375475.079281160,0.
3. A network partition (injected by the test) causes the RPC response to be lost.
4. The DistSender sees a transport-level error. Since NonTransactionalWritesNotIdempotent is false (the default), it treats the non-transactional write as idempotent and retries.
5. The retry evaluates and applies the same operation at a new timestamp 1779375475.590528475,0.
6. Both sets of range tombstones exist in MVCC. The rangefeed observes both, and the validator detects two materializations of the same write (same seq s21 at two timestamps).

The AmbiguousReplayProtection mechanism that prevents double evaluation for transactional requests does not apply to non-transactional writes. Issue #160653 remains open with no fix merged.

First failure (TC build 21354325) is a different failure mode: The first failure in the issue body (SHA 7797103d26398f23c60599f86df401d6454dadb0) failed with pq: setting updated but timed out waiting to read new value when setting kv.rangefeed.enabled. This is a transient infrastructure/timing issue unrelated to the double-evaluation bug — the cluster setting propagation timed out during test setup, likely due to resource contention on the CI machine.

Related Issues and PRs

• #160653 — Root cause tracking issue: "kv: non-transactional requests can double evaluate". Open, no fix merged, no assignee.
• #166017 — Same test on master, same failure signature. Confirmed dup of kv: non-transactional requests can double evaluate #160653. Has a thorough prior /investigate analysis with identical conclusions.
• #168616 — Same test on release-26.1.4-rc (different failure mode: stack trace/goroutine dump).
• #169483 — Same test on release-26.2, closed as dup of kv: non-transactional requests can double evaluate #160653. Failed with a tryConsumeWrite panic (expected exactly one element) — a different manifestation of the same double-evaluation bug where the validator panics instead of reporting a validation failure.
• #167085 — Same test on release-26.1, closed.
• #159730 — Original detailed analysis by @miraradeva identifying the double-evaluation mechanism.

Timeline

• 2025-12-17: First reported occurrence in kv/kvnemesis: TestKVNemesisMultiNode_Partition_Safety failed #159730.
• 2026-01-02: @miraradeva's detailed analysis identifying double-evaluation of AddSSTable and DeleteRangeUsingTombstone.
• 2026-01-07: kv: non-transactional requests can double evaluate #160653 filed as root cause tracking issue.
• 2026-03-18: kv/kvnemesis: TestKVNemesisMultiNode_Partition_Safety failed #166017 on master, confirmed dup. @miraradeva offered to work on a fix.
• 2026-05-04: release-26.2: kv/kvnemesis: TestKVNemesisMultiNode_Partition_Safety failed #169483 on release-26.2, closed as dup.
• 2026-05-20: This issue (release-26.2.1-rc: kv/kvnemesis: TestKVNemesisMultiNode_Partition_Safety failed #170678) opened on release-26.2.1-rc.
• 2026-05-21: Second failure in this issue with the committed txn overwritten key had write validation error.

The root cause issue #160653 has been open for ~5 months with no merged fix.

Detailed evidence and investigation notes

Log Excerpts

From test.log (TC build 21355574, line 5485):

kvnemesis.go:241: committed txn overwritten key had write:
  [d][/Table/100/"00af6c6b545b9bd8",/Table/100/"023b19059b8b918f"):1779375475.590528475,0-><nil>@s21
  [d][/Table/100/"00af6c6b545b9bd8",/Table/100/"023b19059b8b918f"):1779375475.079281160,0-><nil>@s21
  [s]/Table/100/"0{0af6c6b545b9bd8"-23b19059b8b918f"}:{gap:}->[]

Key observations:

• Both [d] entries share seq @s21 — same operation wrote both.
• Two distinct timestamps: .079281160,0 (first eval) and .590528475,0 (second eval).
• The [s] scan shows the range is empty afterward (expected for a DeleteRange).
• [d] prefix with range span notation confirms these are MVCC range tombstones from DeleteRangeUsingTombstone.

Code References

The validator check at validator.go:1304-1307:

_, isLastWrite := lastWritesByIdx[idx]
if !isLastWrite && o.Timestamp.IsSet() {
    failure = `committed txn overwritten key had write`
    break
}

The DistSender non-idempotent write handling at dist_sender.go:2605-2607:

nonIdempotentWrite :=
    ba.Txn == nil && ba.IsWrite() && NonTransactionalWritesNotIdempotent.Get(&ds.st.SV)
nonIdempotent := withCommit || nonIdempotentWrite

With the default setting false, nonIdempotentWrite is always false for non-transactional writes, allowing retries after ambiguous errors.

Things Ruled Out

• Transactional double-commit: The [d] entries are range key tombstones from DeleteRangeUsingTombstone, which is non-transactional. "committed txn" in the error message refers to the atomic unit being committed, not a SQL transaction.
• Validator bug: The same pattern has been confirmed across multiple independent occurrences on different branches with different seeds. The root cause is confirmed in the KV layer, not the validator.
• First failure being the same root cause: The first failure (TC build 21354325) timed out during SET CLUSTER SETTING, which is a different issue (transient CI flake).

Other Failure Occurrences

All committed txn overwritten key had write occurrences across the issue threads for this test show the same pattern:

• Range key deletes ([d]) at two different timestamps for the same sequence number.
• Always involves DeleteRangeUsingTombstone (non-transactional).
• Always in partition mode (network partitions trigger the ambiguous RPC errors that lead to retries).

The #169483 occurrence on release-26.2 manifested as a panic in tryConsumeWrite (expected exactly one element) rather than a validation failure, but the root cause is identical — two MVCC entries for the same seq.

Tooling Feedback

No tooling limitations encountered during this investigation.

---

Workflow run

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

[pav-kv]

Dup of #160653