kv/kvnemesis: TestKVNemesisMultiNode failed

[cockroach-teamcity]

kv/kvnemesis.TestKVNemesisMultiNode failed with artifacts on release-23.1 @ 5d02fdf2851038279f7544e6271a08e1036a2966:

=== RUN   TestKVNemesisMultiNode
    test_log_scope.go:161: test logs captured to: /artifacts/tmp/_tmp/1f42cf5be2fc021646bf9b2daf5eaef3/logTestKVNemesisMultiNode681426315
    test_log_scope.go:79: use -show-logs to present logs inline
    kvnemesis_test.go:180: seed: 8246618713428840787
    kvnemesis_test.go:124: kvnemesis logging to /artifacts/tmp/_tmp/1f42cf5be2fc021646bf9b2daf5eaef3/kvnemesis2506896689
    kvnemesis.go:165: error applying x.ScanForUpdate(ctx, tk(7627554184111334918), tk(11297944047384909700), 0) // WriteTooOldError: write for key /Table/100/"83f343408bfd2cf2" at timestamp 1709031554.741791117,0 too old; wrote at 1709031554.784361740,1: {<nil> 0 {0xc002fbb670} <nil> 1709031554.919155299,0}
    kvnemesis.go:185: failures(verbose): /artifacts/tmp/_tmp/1f42cf5be2fc021646bf9b2daf5eaef3/kvnemesis2506896689/failures
        repro steps: /artifacts/tmp/_tmp/1f42cf5be2fc021646bf9b2daf5eaef3/kvnemesis2506896689/repro.go
        rangefeed KVs: /artifacts/tmp/_tmp/1f42cf5be2fc021646bf9b2daf5eaef3/kvnemesis2506896689/kvs-rangefeed.txt
        scan KVs: /artifacts/tmp/_tmp/1f42cf5be2fc021646bf9b2daf5eaef3/kvnemesis2506896689/kvs-scan.txt
    kvnemesis_test.go:207: 
        	Error Trace:	github.com/cockroachdb/cockroach/pkg/kv/kvnemesis/pkg/kv/kvnemesis/kvnemesis_test.go:207
        	            				github.com/cockroachdb/cockroach/pkg/kv/kvnemesis/pkg/kv/kvnemesis/kvnemesis_test.go:160
        	Error:      	Should be zero, but was 1
        	Test:       	TestKVNemesisMultiNode
        	Messages:   	kvnemesis detected failures
    panic.go:522: -- test log scope end --
test logs left over in: /artifacts/tmp/_tmp/1f42cf5be2fc021646bf9b2daf5eaef3/logTestKVNemesisMultiNode681426315
--- FAIL: TestKVNemesisMultiNode (19.24s)

Parameters:

• TAGS=bazel,gss

Help

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

Same failure on other branches

• kv/kvnemesis: TestKVNemesisMultiNode failed #118471 kv/kvnemesis: TestKVNemesisMultiNode failed [C-test-failure O-robot P-2 T-kv X-duplicate branch-release-23.2]
• kv/kvnemesis: TestKVNemesisMultiNode failed #118017 kv/kvnemesis: TestKVNemesisMultiNode failed [A-testing C-bug C-test-failure O-robot P-2 T-kv branch-master]

/cc @cockroachdb/kv

This test on roachdash | Improve this report!

Jira issue: CRDB-36279

[arulajmani]

The failed operation was:

  before: 1709031554.731652557,0
  3 OP  db1.ScanForUpdate(ctx, tk(7627554184111334918), tk(11297944047384909700), 0) // WriteTooOldError: write for key /Table/100/"83f343408bfd2cf2" at timestamp 1709031554.741791117,0 too old; wrote at 1709031554.784361740,1
  after: 1709031554.919480615,0

and the trace is:

w3_step17_trace.txt

[arulajmani]

Slack discussion here:

https://cockroachlabs.slack.com/archives/C04AFSL6E3C/p1709219305351869

[arulajmani]

It looks like we're getting an unexpected RetryWithUncertaintyIntervalError for a locking request. I think this is coming from range keys, as the only path where RetryWithUncertaintyIntervalErrors are possible for locking requests is:

cockroach/pkg/storage/pebble_mvcc_scanner.go

Lines 1531 to 1552 in bac5c82

	// Check if any of the range keys are in the uncertainty interval.
	if p.checkUncertainty {
	for _, version := range p.curRangeKeys.Versions {
	if version.Timestamp.LessEq(p.ts) {
	break
	}
	var value MVCCValue
	var simple bool
	value, simple, p.err = tryDecodeSimpleMVCCValue(version.Value)
	if !simple && p.err == nil {
	value, p.err = decodeExtendedMVCCValue(version.Value)
	}
	if p.err != nil {
	return false
	}
	localTS := value.GetLocalTimestamp(version.Timestamp)
	if p.uncertainty.IsUncertain(version.Timestamp, localTS) {
	return p.uncertaintyError(version.Timestamp, localTS)
	}
	}
	}
	}

We only attempt a server side retry while holding latches once. Server side retries can happen for both RetryWithUncertaintyIntervalErrors and WriteTooOldErrors. We used up our one and only retry for the (unexpected) RetryWithUncertaintyIntervalError. As a result, the second WriteTooOldError was bubbled back up to the client.

We seem to be breaking the invariants described in:

cockroach/pkg/kv/kvserver/replica_send.go

Line 640 in 338aa9c

// retrying.

However, for this specific case, we're just missing a potential opportunity to perform a server side refresh. I don't think this qualifies as a release blocker as a result. That being said, let's discuss this a bit more once you're back @nvanbenschoten, as you've got the most context here.

[arulajmani]

Thanks for helping debug this btw @miraradeva!

[nvanbenschoten]

More discussion in https://cockroachlabs.slack.com/archives/C04AFSL6E3C/p1709595293019079?thread_ts=1709219305.351869&cid=C04AFSL6E3C.

[github-actions]

We have marked this test failure issue as stale because it has been
inactive for 1 month. If this failure is still relevant, removing the
stale label or adding a comment will keep it active. Otherwise,
we'll close it in 5 days to keep the test failure queue tidy.

[blathers-crl]

Based on the specified backports for linked PR #131093, I applied the following new label(s) to this issue: branch-release-24.2. Please adjust the labels as needed to match the branches actually affected by this issue, including adding any known older branches.

_{🦉 Hoot! I am a Blathers, a bot for CockroachDB. My owner is dev-inf.}

[blathers-crl]

Based on the specified backports for linked PR #131093, I applied the following new label(s) to this issue: branch-release-24.1. Please adjust the labels as needed to match the branches actually affected by this issue, including adding any known older branches.

_{🦉 Hoot! I am a Blathers, a bot for CockroachDB. My owner is dev-inf.}

[blathers-crl]

Based on the specified backports for linked PR #131093, I applied the following new label(s) to this issue: branch-release-23.2. Please adjust the labels as needed to match the branches actually affected by this issue, including adding any known older branches.

_{🦉 Hoot! I am a Blathers, a bot for CockroachDB. My owner is dev-inf.}