kv/kvserver: TestStrictGCEnforcement failed #139072

github-actions · 2025-01-14T21:24:24Z

kv/kvserver.TestStrictGCEnforcement failed on master @ 244d979b3de227882067a1a8f56fc53bffd1604f:

=== RUN   TestStrictGCEnforcement
    test_log_scope.go:165: test logs captured to: outputs.zip/logTestStrictGCEnforcement391369898
    test_log_scope.go:76: use -show-logs to present logs inline
    client_replica_test.go:4409: -- test log scope end --
test logs left over in: outputs.zip/logTestStrictGCEnforcement391369898
--- FAIL: TestStrictGCEnforcement (33.81s)
=== RUN   TestStrictGCEnforcement/protected_timestamps_are_respected
    client_replica_test.go:4400: 
        	Error Trace:	pkg/kv/kvserver/client_replica_test.go:4400
        	Error:      	Received unexpected error:
        	            	no valid lease
        	            	(1) attached stack trace
        	            	  -- stack trace:
        	            	  | github.com/cockroachdb/cockroach/pkg/testutils/testcluster.(*TestCluster).FindRangeLeaseHolder
        	            	  | 	pkg/testutils/testcluster/testcluster.go:1456
        	            	  | github.com/cockroachdb/cockroach/pkg/kv/kvserver_test.TestStrictGCEnforcement.func20
        	            	  | 	pkg/kv/kvserver/client_replica_test.go:4399
        	            	  | testing.tRunner
        	            	  | 	GOROOT/src/testing/testing.go:1689
        	            	  | runtime.goexit
        	            	  | 	src/runtime/asm_amd64.s:1695
        	            	Wraps: (2) no valid lease
        	            	Error types: (1) *withstack.withStack (2) *errutil.leafError
        	Test:       	TestStrictGCEnforcement/protected_timestamps_are_respected
    --- FAIL: TestStrictGCEnforcement/protected_timestamps_are_respected (3.09s)

Parameters:

attempt=1
run=1
shard=22

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-46491

The text was updated successfully, but these errors were encountered:

github-actions · 2025-01-15T00:12:42Z

kv/kvserver.TestStrictGCEnforcement failed on master @ fb98afef5901b2f496a4cc99bb02c1b95ed0ddcb:

=== RUN   TestStrictGCEnforcement
    test_log_scope.go:165: test logs captured to: outputs.zip/logTestStrictGCEnforcement1518530062
    test_log_scope.go:76: use -show-logs to present logs inline
    client_replica_test.go:4409: -- test log scope end --
test logs left over in: outputs.zip/logTestStrictGCEnforcement1518530062
--- FAIL: TestStrictGCEnforcement (33.76s)
=== RUN   TestStrictGCEnforcement/protected_timestamps_are_respected
    client_replica_test.go:4400: 
        	Error Trace:	pkg/kv/kvserver/client_replica_test.go:4400
        	Error:      	Received unexpected error:
        	            	no valid lease
        	            	(1) attached stack trace
        	            	  -- stack trace:
        	            	  | github.com/cockroachdb/cockroach/pkg/testutils/testcluster.(*TestCluster).FindRangeLeaseHolder
        	            	  | 	pkg/testutils/testcluster/testcluster.go:1456
        	            	  | github.com/cockroachdb/cockroach/pkg/kv/kvserver_test.TestStrictGCEnforcement.func20
        	            	  | 	pkg/kv/kvserver/client_replica_test.go:4399
        	            	  | testing.tRunner
        	            	  | 	GOROOT/src/testing/testing.go:1689
        	            	  | runtime.goexit
        	            	  | 	src/runtime/asm_amd64.s:1695
        	            	Wraps: (2) no valid lease
        	            	Error types: (1) *withstack.withStack (2) *errutil.leafError
        	Test:       	TestStrictGCEnforcement/protected_timestamps_are_respected
    --- FAIL: TestStrictGCEnforcement/protected_timestamps_are_respected (3.09s)

Parameters:

attempt=1
run=1
shard=22

Help

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

_{This test on roachdash | Improve this report!}

cockroach-teamcity · 2025-01-15T04:40:03Z

kv/kvserver.TestStrictGCEnforcement failed with artifacts on master @ f1a746cf3e2eb39b6cc68c036a6e2a24d15b70e1:

=== RUN   TestStrictGCEnforcement
    test_log_scope.go:165: test logs captured to: /artifacts/tmp/_tmp/ac3e4004160555c7c575e1264d1b8f5f/logTestStrictGCEnforcement510737454
    test_log_scope.go:76: use -show-logs to present logs inline
    client_replica_test.go:4409: -- test log scope end --
test logs left over in: /artifacts/tmp/_tmp/ac3e4004160555c7c575e1264d1b8f5f/logTestStrictGCEnforcement510737454
--- FAIL: TestStrictGCEnforcement (33.84s)
=== RUN   TestStrictGCEnforcement/protected_timestamps_are_respected
    client_replica_test.go:4400: 
        	Error Trace:	pkg/kv/kvserver/client_replica_test.go:4400
        	Error:      	Received unexpected error:
        	            	no valid lease
        	            	(1) attached stack trace
        	            	  -- stack trace:
        	            	  | github.com/cockroachdb/cockroach/pkg/testutils/testcluster.(*TestCluster).FindRangeLeaseHolder
        	            	  | 	pkg/testutils/testcluster/testcluster.go:1456
        	            	  | github.com/cockroachdb/cockroach/pkg/kv/kvserver_test.TestStrictGCEnforcement.func20
        	            	  | 	pkg/kv/kvserver/client_replica_test.go:4399
        	            	  | testing.tRunner
        	            	  | 	GOROOT/src/testing/testing.go:1689
        	            	  | runtime.goexit
        	            	  | 	src/runtime/asm_arm64.s:1222
        	            	Wraps: (2) no valid lease
        	            	Error types: (1) *withstack.withStack (2) *errutil.leafError
        	Test:       	TestStrictGCEnforcement/protected_timestamps_are_respected
    --- FAIL: TestStrictGCEnforcement/protected_timestamps_are_respected (3.09s)

Help

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

_{This test on roachdash | Improve this report!}

andrewbaptist · 2025-01-15T14:30:53Z

This is easy to reproduce by running

./dev test pkg/kv/kvserver -f TestStrictGCEnforcement --stress

on master. I'll try and bisect to see why this started failing recently.

andrewbaptist · 2025-01-15T15:08:02Z

@iskettaneh This appears to be caused by your recent changes for LeadSupportStatus specifically d056d59. I didn't delve into whether this is a problem with the test or this is unexpected behavior. Specifically I'm not sure why we are hitting the no valid lease case. As part of this fix, it would be good to update FindRangeLeaseHolder to wrap the underlying error when it hits an invalid lease. This would make debugging easier.

arulajmani · 2025-01-15T15:28:08Z

I didn't delve into whether this is a problem with the test or this is unexpected behavior. Specifically I'm not sure why we are hitting the no valid lease case.

@iskettaneh we should get to the bottom of this, in particular why your change caused a behaviour difference in FindRangeLeaseHolder.

Briefly looking at the test though, it seems like this step fails during setup; as such, I'll remove the release blocker label and replace it with a ga-blocker label instead. However, we should understand this behaviour better before 25.1 goes out the door.

cockroach-teamcity · 2025-01-15T15:37:34Z

kv/kvserver.TestStrictGCEnforcement failed on master @ 0b4d620740733ec61cf50ca26d19814299d91f8e:

=== RUN   TestStrictGCEnforcement
    test_log_scope.go:165: test logs captured to: outputs.zip/logTestStrictGCEnforcement2300721638
    test_log_scope.go:76: use -show-logs to present logs inline
    client_replica_test.go:4409: -- test log scope end --
test logs left over in: outputs.zip/logTestStrictGCEnforcement2300721638
--- FAIL: TestStrictGCEnforcement (33.83s)
=== RUN   TestStrictGCEnforcement/protected_timestamps_are_respected
    client_replica_test.go:4400: 
        	Error Trace:	pkg/kv/kvserver/client_replica_test.go:4400
        	Error:      	Received unexpected error:
        	            	no valid lease
        	            	(1) attached stack trace
        	            	  -- stack trace:
        	            	  | github.com/cockroachdb/cockroach/pkg/testutils/testcluster.(*TestCluster).FindRangeLeaseHolder
        	            	  | 	pkg/testutils/testcluster/testcluster.go:1456
        	            	  | github.com/cockroachdb/cockroach/pkg/kv/kvserver_test.TestStrictGCEnforcement.func20
        	            	  | 	pkg/kv/kvserver/client_replica_test.go:4399
        	            	  | testing.tRunner
        	            	  | 	GOROOT/src/testing/testing.go:1689
        	            	  | runtime.goexit
        	            	  | 	src/runtime/asm_amd64.s:1695
        	            	Wraps: (2) no valid lease
        	            	Error types: (1) *withstack.withStack (2) *errutil.leafError
        	Test:       	TestStrictGCEnforcement/protected_timestamps_are_respected
    --- FAIL: TestStrictGCEnforcement/protected_timestamps_are_respected (3.09s)

Parameters:

attempt=1
run=10
shard=22

Help

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

_{This test on roachdash | Improve this report!}

iskettaneh · 2025-01-15T16:48:12Z

Some notes that might help us understand what's happening

This only seems to be happening with the subtest: protected timestamps are respected which blocks and then unblocks KVSubscriber rangefeed from progressing.
This is the replica and the lease that throws a problem:

replica: [n1,s1,r75/1:/{Table/104-Max}]

lease: {Lease:repl=(n1,s1):1 seq=1 start=0,0 term=6 min-exp=1736958390.198541000,0 pro=1736958384.198541000,0 acq=Request Now:1736958389.709972000,0 RequestTime:1736958389.709972000,0 State:UNUSABLE ErrInfo: Liveness:liveness(nid:0 epo:0 exp:0,0) MinValidObservedTimestamp:0,0 LeaderSupport:{Term:6 LeadSupportUntil:1736958386.689868000,0}}

Notice that the State:UNUSABLE, the LeadSupportUntil:1736958386.689868000,0 which is less than Request Now:1736958389.709972000,0.
Also, the Request Now:1736958389.709972000,0 is very very close to the min-exp=1736958390.198541000,0

iskettaneh · 2025-01-15T16:57:59Z

Ugh, I believe that the intention was to calculate the ComputeSupportUntil on every tick. But we currently do it on LeaderStep

cockroach/pkg/raft/raft.go

Lines 1844 to 1845 in 003a622

    
           // Compute the LeadSupportUntil on every tick. 
        
           r.fortificationTracker.ComputeLeadSupportUntil(r.state)

This commit calls ComputeLeadSupportUntil on every leader tick rather than on every leader step. If the range is idle, the leader won't have anything to step on, but it will keep ticking. References: cockroachdb#139072 Release Note: None

139151: raft: ComputeLeadSupportUntil on every leader tick r=iskettaneh a=iskettaneh This commit calls ComputeLeadSupportUntil on every leader tick rather than on every leader step. If the range is idle, the leader won't have anything to step on, but it will keep ticking. References: #139072 Release Note: None Co-authored-by: Ibrahim Kettaneh <[email protected]>

This commit calls ComputeLeadSupportUntil on every leader tick rather than on every leader step. If the range is idle, the leader won't have anything to step on, but it will keep ticking. References: #139072 Release Note: None

iskettaneh · 2025-01-15T20:29:21Z

This was fixed in #139151

I will make FindRangeLeaseHolder more verbose as part of fixing #136801

This commit calls ComputeLeadSupportUntil on every leader tick rather than on every leader step. If the range is idle, the leader won't have anything to step on, but it will keep ticking. References: cockroachdb#139072 Release Note: None

andrewbaptist assigned iskettaneh Jan 15, 2025

andrewbaptist added the C-bug Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior. label Jan 15, 2025

arulajmani added GA-blocker and removed release-blocker Indicates a release-blocker. Use with branch-release-2x.x label to denote which branch is blocked. labels Jan 15, 2025

arulajmani added release-blocker Indicates a release-blocker. Use with branch-release-2x.x label to denote which branch is blocked. and removed GA-blocker labels Jan 15, 2025

iskettaneh mentioned this issue Jan 15, 2025

raft: ComputeLeadSupportUntil on every leader tick #139151

Merged

blathers-crl bot mentioned this issue Jan 15, 2025

release-25.1: raft: ComputeLeadSupportUntil on every leader tick #139156

Merged

iskettaneh closed this as completed Jan 15, 2025

mohini-crl mentioned this issue Jan 17, 2025

[Replicated] release-25.1: raft: ComputeLeadSupportUntil on every leader tick mohini-crl/cockroach#150

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

kv/kvserver: TestStrictGCEnforcement failed #139072

kv/kvserver: TestStrictGCEnforcement failed #139072

github-actions bot commented Jan 14, 2025 •

edited by cockroach-jira-scripts

Loading

github-actions bot commented Jan 15, 2025

cockroach-teamcity commented Jan 15, 2025

andrewbaptist commented Jan 15, 2025

andrewbaptist commented Jan 15, 2025 •

edited

Loading

arulajmani commented Jan 15, 2025

cockroach-teamcity commented Jan 15, 2025

iskettaneh commented Jan 15, 2025

iskettaneh commented Jan 15, 2025

iskettaneh commented Jan 15, 2025

kv/kvserver: TestStrictGCEnforcement failed #139072

kv/kvserver: TestStrictGCEnforcement failed #139072

Comments

github-actions bot commented Jan 14, 2025 • edited by cockroach-jira-scripts Loading

github-actions bot commented Jan 15, 2025

cockroach-teamcity commented Jan 15, 2025

andrewbaptist commented Jan 15, 2025

andrewbaptist commented Jan 15, 2025 • edited Loading

arulajmani commented Jan 15, 2025

cockroach-teamcity commented Jan 15, 2025

iskettaneh commented Jan 15, 2025

Some notes that might help us understand what's happening

iskettaneh commented Jan 15, 2025

iskettaneh commented Jan 15, 2025

github-actions bot commented Jan 14, 2025 •

edited by cockroach-jira-scripts

Loading

andrewbaptist commented Jan 15, 2025 •

edited

Loading