backupccl: TestBackupRestoreJobTagAndLabel fails under race when running in a tenant #107336
Description
Describe the problem
This test was recently enable for tenant testing. It has since occasionally failed under race with an assertion failure:
I230721 09:57:17.481189 134873 1@kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2151 the server is terminating due to a fatal error (see the DEV channel for details)
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 observed raft log position less than per-stream lower bound (log-position=0/0 <= log-position=6/3189)
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !goroutine 134873 [running]:
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !runtime/debug.Stack()
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! GOROOT/src/runtime/debug/stack.go:24 +0x72
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/util/log.(*loggerT).outputLogEntry(0xc015df4f60, {{{0xc00cc48690, 0x24}, {0x968dfdd, 0x1}, {0x968dfdd, 0x1}, {0x968dfdd, 0x1}}, 0x1773d981fb22f376, ...})
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/util/log/clog.go:261 +0xb7
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/util/log.logfDepthInternal({0xd76a340, 0xc00a858fc0}, 0x2, 0x4, 0x0, 0x0, {0x97c2cf1, 0x46}, {0xc034597700, 0x2, ...})
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/util/log/channels.go:106 +0x6e6
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/util/log.logfDepth(...)
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/util/log/channels.go:39
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/util/log.Fatalf({0xd76a340, 0xc00a858fc0}, {0x97c2cf1, 0x46}, {0xc034597700, 0x2, 0x2})
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/bazel-out/k8-fastbuild/bin/pkg/util/log/log_channels_generated.go:848 +0x9d
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/kv/kvserver/kvflowcontrol/kvflowtokentracker.(*Tracker).Track(0xc003ce3110, {0xd76a340, 0xc00a858fc0}, 0x0, 0x331, {0xc014808e50?, 0x4?})
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 +0x85b
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/kv/kvserver/kvflowcontrol/kvflowhandle.(*Handle).deductTokensForInner(0xc009a744d0, {0xd76a340, 0xc00a858fc0}, 0x0?, {0x13860320?, 0xc018493380?}, 0x331)
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/kv/kvserver/kvflowcontrol/kvflowhandle/kvflowhandle.go:162 +0x394
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/kv/kvserver/kvflowcontrol/kvflowhandle.(*Handle).DeductTokensFor(0xc009a744d0, {0xd76a340, 0xc00a858fc0}, 0x77?, {0x2c?, 0xc014808f30?}, 0x1?)
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/kv/kvserver/kvflowcontrol/kvflowhandle/kvflowhandle.go:141 +0x72
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/kv/kvserver.maybeDeductFlowTokens({0xd76a340, 0xc008f8fcb0}, {0xd7b08c0, 0xc009a744d0}, {0xc0252d2700, 0x12, 0x12}, {0xc01e231880, 0x12, 0x12})
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_proposal_buf.go:1049 +0x2e5
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/kv/kvserver.proposeBatch({0xd76a340, 0xc008f8fcb0}, {0x7f52e49b2b00, 0xc004f12d80}, {0xd78a0f0, 0xc00cb32870}, {0xc01e231880, 0x12, 0x12}, {0xc0252d2700, ...}, ...)
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_proposal_buf.go:1026 +0x24f
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*propBuf).FlushLockedWithRaftGroup(0xc004f135d0, {0xd76a340, 0xc008f8fcb0}, {0xd78a0f0, 0xc00cb32870})
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_proposal_buf.go:619 +0x1c97
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).handleRaftReadyRaftMuLocked.func2(0xc00ccbacb8?)
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_raft.go:775 +0xfd
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).withRaftGroupLocked(0xc004f12d80, 0xc01480a760)
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_raft.go:1988 +0xae
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).handleRaftReadyRaftMuLocked(_, {_, _}, {{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...}, ...})
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_raft.go:772 +0x39b
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).handleRaftReady(_, {_, _}, {{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...}, ...})
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_raft.go:728 +0x210
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Store).processReady(0xc009758000, 0xd76a340?)
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/store_raft.go:670 +0x1d0
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*raftSchedulerShard).worker(0xc008285500, {0xd76a340, 0xc01be7f1a0}, {0xd74d9b0, 0xc009758000}, 0xc0096df500)
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/scheduler.go:418 +0x2f6
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*raftScheduler).Start.func2({0xd76a340, 0xc01be7f1a0})
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/scheduler.go:321 +0x9b
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunAsyncTaskEx.func2()
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:484 +0x1f7
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunAsyncTaskEx
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:475 +0x61a
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !For more context, check log files in: /artifacts/tmp/_tmp/95e138e66d69292427dfb9528cf06d04/logTestBackupRestoreJobTagAndLabel1075111918
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !****************************************************************************
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !This node experienced a fatal error (printed above), and as a result the
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !process is terminating.
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !Fatal errors can occur due to faulty hardware (disks, memory, clocks) or a
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !problem in CockroachDB. With your help, the support team at Cockroach Labs
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !will try to determine the root cause, recommend next steps, and we can
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !improve CockroachDB based on your report.
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !Please submit a crash report by following the instructions here:
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! https://github.com/cockroachdb/cockroach/issues/new/choose
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !If you would rather not post publicly, please contact us directly at:
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 ! support@cockroachlabs.com
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !
F230721 09:57:17.481448 134873 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [T1,n1,tenant=10,s1,r64/1:‹/Tenant/1{0-1}›] 2152 !The Cockroach Labs team appreciates your feedback.
Jira issue: CRDB-29995