cockroachdb / cockroachdb/cockroach
kvserver: slow intent resolution causes backups to fail
- Dominant language
- Go
- Stars
- 32.5k
- Forks
- 4.1k
- PR merge metrics
- PR metrics pending
Description
### Background
Each ExportRequest issued by a backup is given 5 minutes to complete before the sender context is canceled and the job is failed. The first few ExportRequests for a span are sent with `WaitPolicy: Error` and default `UserPriority`. If those requests encounter a `WriteIntentError` then a final attempt is made with `WaitPolicy: Block` and high `UserPriority`. Thanks to @kevinkokomani we now have a reliable reproduction where we can get an ExportRequest to take longer than 5 minutes thereby causing the backup to fails:
### Reproduction
```
roachprod create kokomani-16442-reproduction -n 6 --gce-zones 'us-east4-a' --gce-machine-type 'n1-standard-16'
roachprod stage kokomani-16442-reproduction release v22.2.6
roachprod start kokomani-16442-reproduction
```
```
CREATE DATABASE testing;
USE TESTING;
CREATE TABLE public.table_name (
....
);
```
```
roachprod put kokomani-16442-reproduction:1 randomSample.csv /mnt/data1/cockroach/extern
import into table_name (name, message_id, data, created_at, updated_at) csv data ('nodelocal://1/randomSample.csv');
// backup will run every 5 minutes
create schedule if not exists schedule1 for backup into 'nodelocal://1/test_backup' WITH revision_history = true, detached RECURRING '*/5 * * * *' FULL BACKUP ALWAYS WITH SCHEDULE OPTIONS first_run = 'now';
// delete query without predicate
delete from table_name';
```
The backup kicked off while the delete is running will very likely end up failing with `failed to run backup: exporting 44 ranges: export request timeout: operation "ExportRequest for span <> timed out after 5m0s (given timeout 5m0s): context deadline exceeded
`
Occasionally, the backup won't fail but will slow down to a complete crawl, presumably because the ExportRequests are just managing to stay under the 5mins timeout.
### Initial findings:
The first step in triaging this issue was to grab stacks of the slow ExportRequest:
I patched https://github.com/cockroachdb/cockroach/pull/100316 to add some more information to the stacks that we dump for slow KV requests. Let us walk through one such request that takes us close to the backup imposed timeout of 300s to complete. I believe that this is representative of a request that is causing the backup to topple over:
In a snapshot captured 278s ago we see the ExportRequest waiting on the concurrent export request limiter. This limiter, by default, permits 3 ExportRequests to be executing concurrently per-store.
278s
```
I230404 19:00:41.657525 552366 ccl/backupccl/backup_processor.go:177 ⋮ [T1,n4,f‹802faa0d›,job=853816377872449542,distsql.gateway=‹2›] 402 slow request stack during backup: ‹Op:Export [/Table/106/3/2020-11-27T04:10:43Z/"\x1e_\xe9һ\xef@\x00\x8f/\xf4\xe9]\xf7\x80\x02",/Table/106/4), [wait-policy: Block], NodeID: 4, RecordedAt: 2023-04-04 19:00:30.772469322 +0000 UTC›
‹stack as of 278.7s ago: goroutine 552402 [select]:›
‹github.com/cockroachdb/cockroach/pkg/util/quotapool.(*AbstractPool).Acquire(0xc00b0cc2c0, {0x7017380, 0xc009747bf0}, {0x6fed420, 0xc007d221a0})›
‹ github.com/cockroachdb/cockroach/pkg/util/quotapool/quotapool.go:281 +0x75c›
‹github.com/cockroachdb/cockroach/pkg/util/quotapool.(*IntPool).acquireMaybeWait(0xc001dd2420, {0x7017380, 0xc009747bf0}, 0x1, 0x1)›
‹ github.com/cockroachdb/cockroach/pkg/util/quotapool/intpool.go:178 +0x13f›
‹github.com/cockroachdb/cockroach/pkg/util/quotapool.(*IntPool).Acquire(...)›
‹ github.com/cockroachdb/cockroach/pkg/util/quotapool/intpool.go:147›
‹github.com/cockroachdb/cockroach/pkg/util/limit.(*ConcurrentRequestLimiter).Begin(0xc00b0aa6f0, {0x7017380, 0xc009747bc0})›
‹ github.com/cockroachdb/cockroach/pkg/util/limit/limiter.go:58 +0x22a›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Store).maybeThrottleBatch(0xc00b0aa000, {0x7017380, 0xc009747bc0}, 0xc008717028?)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/store_send.go:370 +0x11b›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Store).SendWithWriteBytes(0xc00b0aa000, {0x7017380?, 0xc009747b90?}, 0xc00f87ec00)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/store_send.go:73 +0xc9›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Stores).SendWithWriteBytes(0x7017380?, {0x7017380, 0xc009747b90}, 0xc00f87ec00)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/stores.go:203 +0x10f›
‹github.com/cockroachdb/cockroach/pkg/server.(*Node).batchInternal(0xc000f9c000, {0x7017380?, 0xc009747b30?}, {0x10000007e?}, 0xc00f87ec00)›
‹ github.com/cockroachdb/cockroach/pkg/server/node.go:1188 +0x4f7›
‹github.com/cockroachdb/cockroach/pkg/server.(*Node).Batch(0xc000f9c000, {0x7017380, 0xc009747ad0}, 0xc00f87ec00)›
‹ github.com/cockroachdb/cockroach/pkg/server/node.go:1268 +0x192›
‹github.com/cockroachdb/cockroach/pkg/rpc.makeInternalClientAdapter.func1({0x7017380?, 0xc009747ad0?}, {0x5a292a0?, 0xc00f87ec00?})›
‹ github.com/cockroachdb/cockroach/pkg/rpc/pkg/rpc/context.go:835 +0x4b›
‹github.com/cockroachdb/cockroach/pkg/util/tracing/grpcinterceptor.ServerInterceptor.func1({0x7017380, 0xc009747ad0}, {0x5a292a0, 0xc00f87ec00}, 0xc00aced660, 0xc00aceb980)›
‹ github.com/cockroachdb/cockroach/pkg/util/tracing/grpcinterceptor/grpc_interceptor.go:96 +0x254›
‹github.com/cockroachdb/cockroach/pkg/rpc.bindUnaryServerInterceptorToHandler.func1({0x7017380?, 0xc009747ad0?}, {0x5a292a0?, 0xc00f87ec00?})›
‹ github.com/cockroachdb/cockroach/pkg/rpc/pkg/rpc/context.go:946 +0x3a›
‹github.com/cockroachdb/cockroach/pkg/rpc.NewServerEx.func3({0x7017380, 0xc009747ad0}, {0x5a292a0, 0xc00f87ec00}, 0xc0029871d0?, 0xc00aced680)›
‹ github.com/cockroachdb/cockroach/pkg/rpc/pkg/rpc/context.go:276 +0x83›
‹github.com/cockroachdb/cockroach/pkg/rpc.bindUnaryServerInterceptorToHandler.func1({0x7017380?, 0xc009747ad0?}, {0x5a292a0?, 0xc00f87ec00?})›
‹ github.com/cockroachdb/cockroach/pkg/rpc/pkg/rpc/context.go:946 +0x3a›
‹github.com/cockroachdb/cockroach/pkg/rpc.NewServerEx.func1.1({0x7017380?, 0xc009747ad0?})›
‹ github.com/cockroachdb/cockroach/pkg/rpc/pkg/rpc/context.go:243 +0x39›
‹github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunTaskWithErr(0xc000fa2800, {0x7017380, 0xc009747ad0}, {0x0?, 0x0?}, 0xc002987298)›
‹ github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:322 +0xd1›
‹github.com/cockroachdb/cockroach/pkg/rpc.NewServerEx.func1({0x7017380?, 0xc009747ad0?}, {0x5a292a0?, 0xc00f87ec00?}, 0x127c8ae?, 0x0?)›
‹ github.com/cockroachdb/cockroach/pkg/rpc/pkg/rpc/context.go:241 +0x95›
‹github.com/cockroachdb/cockroach/pkg/rpc.bindUnaryServerInterceptorToHandler.func1({0x7017380?, 0xc009747ad0?}, {0x5a292a0?, 0xc00f87ec00?})›
‹ github.com/cockroachdb/cockroach/pkg/rpc/pkg/rpc/context.go:946 +0x3a›
‹github.com/cockroachdb/cockroach/pkg/rpc.makeInternalClientAdapter.func2({0x7017380?, 0xc009747ad0?}, {0xc009747ad0?, 0x4?}, {0x5a292a0?, 0xc00f87ec00?}, {0x58d92c0?, 0xc001615a80}, 0x203002?, {0x0, ...})›
‹ github.com/cockroachdb/cockroach/pkg/rpc/pkg/rpc/context.go:845 +0x54›
‹github.com/cockroachdb/cockroach/pkg/util/tracing/grpcinterceptor.ClientInterceptor.func2({0x7017380, 0xc009747ad0}, {0x5b33648, 0x21}, {0x5a292a0, 0xc00f87ec00}, {0x58d92c0, 0xc001615a80}, 0x522f2c0?, 0xc00ad50880, ...)›
‹ github.com/cockroachdb/cockroach/pkg/util/tracing/grpcinterceptor/grpc_interceptor.go:227 +0x155›
‹github.com/cockroachdb/cockroach/pkg/rpc.getChainUnaryInvoker.func1({0x7017380, 0xc009747ad0}, {0x5b33648, 0x21}, {0x5a292a0, 0xc00f87ec00}, {0x58d92c0, 0xc001615a80}, 0x0?, {0x0, ...})›
‹ github.com/cockroachdb/cockroach/pkg/rpc/pkg/rpc/context.go:1030 +0x13e›
‹github.com/cockroachdb/cockroach/pkg/rpc.makeInternalClientAdapter.func3({0x7017380, 0xc009747a40}, 0xc00f87eb00, {0x0, 0x0, 0x0})›
‹ github.com/cockroachdb/cockroach/pkg/rpc/pkg/rpc/context.go:915 +0x349›
‹github.com/cockroachdb/cockroach/pkg/rpc.internalClientAdapter.Batch(...)›
‹ github.com/cockroachdb/cockroach/pkg/rpc/pkg/rpc/context.go:1038›
‹github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord.(*grpcTransport).sendBatch(0xc008f82840, {0x7017380, 0xc009747a40}, 0xcdbe52?, {0x7014c60, 0xc00ad58e40?}, 0xc00f87eb00)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/transport.go:210 +0x103›
‹github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord.(*grpcTransport).SendNext(0xc008f82840, {0x7017380, 0xc009747a40}, 0xc008f82840?)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/transport.go:189 +0x92›
‹github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord.(*DistSender).sendToReplicas(0xc00072b400, {0x7017380, 0xc009747a40}, 0xc00f87e900?, {0xc000f46370, 0xc0029b4820, 0xc0029b4890, 0x0, 0x0}, 0x0)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/dist_sender.go:2153 +0x11a3›
‹github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord.(*DistSender).sendPartialBatch(0xc00072b400, {0x7017380?, 0xc009747a40}, 0xc00f87e900, {{0xc014c1c580, 0x1d, 0x20}, {0xc008717028, 0x2, 0x8}}, ...)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/dist_sender.go:1679 +0x845›
‹github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord.(*DistSender).divideAndSendBatchToRanges(0xc00072b400, {0x7017380, 0xc009747a40}, 0xc00f87e900, {{0xc014c1c580, 0x1d, 0x20}, {0xc008717028, 0x2, 0x8}}, ...)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/dist_sender.go:1250 +0x3e8›
‹github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord.(*DistSender).Send(0xc00072b400, {0x7017348, 0xc007cca960}, 0xc00f87e900)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/dist_sender.go:871 +0x675›
‹github.com/cockroachdb/cockroach/pkg/kv.(*CrossRangeTxnWrapperSender).Send(0xc001347a48, {0x7017348, 0xc007cca960}, 0xc00f87e900)›
‹ github.com/cockroachdb/cockroach/pkg/kv/db.go:223 +0xa6›
‹github.com/cockroachdb/cockroach/pkg/kv.SendWrappedWithAdmission({0x7017348, 0xc007cca960}, {0x6fd0460, 0xc001347a48}, {{0x1752d0278419c680, 0x0, 0x0}, 0x0, {0x0, 0x0, ...}, ...}, ...)›
‹ github.com/cockroachdb/cockroach/pkg/kv/sender.go:441 +0x150›
‹github.com/cockroachdb/cockroach/pkg/ccl/backupccl.runBackupProcessor.func1.2({0x7017348, 0xc007cca960})›
‹ github.com/cockroachdb/cockroach/pkg/ccl/backupccl/backup_processor.go:483 +0x10e›
‹github.com/cockroachdb/cockroach/pkg/util/contextutil.RunWithTimeout({0x70172d8?, 0xc008a5f180?}, {0xc00a537b20, 0x6d}, 0x45d964b800, 0xc002989890)›
‹ github.com/cockroachdb/cockroach/pkg/util/contextutil/context.go:91 +0xed›
‹github.com/cockroachdb/cockroach/pkg/ccl/backupccl.runBackupProcessor.func1({0x70172d8, 0xc008a5f180?}, 0x70700c00390df58?)›
‹ github.com/cockroachdb/cockroach/pkg/ccl/backupccl/backup_processor.go:480 +0xddd›
‹github.com/cockroachdb/cockroach/pkg/util/ctxgroup.GroupWorkers.func1({0x70172d8?, 0xc008a5f180?})›
‹ github.com/cockroachdb/cockroach/pkg/util/ctxgroup/ctxgroup.go:177 +0x2b›
‹github.com/cockroachdb/cockroach/pkg/util/ctxgroup.Group.GoCtx.func1()›
‹ github.com/cockroachdb/cockroach/pkg/util/ctxgroup/ctxgroup.go:168 +0x25›
‹golang.org/x/sync/errgroup.(*Group).Go.func1()›
‹ golang.org/x/sync/errgroup/external/org_golang_x_sync/errgroup/errgroup.go:75 +0x64›
‹created by golang.org/x/sync/errgroup.(*Group).Go›
‹ golang.org/x/sync/errgroup/external/org_golang_x_sync/errgroup/errgroup.go:72 +0xa5›
```
We see the ExportRequest stuck in this same place until the snapshot that is taken at 238s i.e for ~40 seconds of its allotted 300s. This is just the ExportRequest waiting for other concurrent requests to complete execution so that it can start executing itself.
In the snapshot taken at the 218s mark we see the goroutine move to resolving intents - https://github.com/cockroachdb/cockroach/blob/master/pkg/kv/kvserver/replica_send.go#L447:
218s
```
I230404 19:00:41.657925 552366 ccl/backupccl/backup_processor.go:177 ⋮ [T1,n4,f‹802faa0d›,job=853816377872449542,distsql.gateway=‹2›] 405 slow request stack during backup: ‹Op:Export [/Table/106/3/2020-11-27T04:10:43Z/"\x1e_\xe9һ\xef@\x00\x8f/\xf4\xe9]\xf7\x80\x02",/Table/106/4), [wait-policy: Block], NodeID: 4, RecordedAt: 2023-04-04 19:00:30.772469322 +0000 UTC›
‹stack as of 218.7s ago: goroutine 552402 [select]:›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).resolveIntents(0xc00b0e5400, {0x7017380, 0xc008e517d0}, {0x6feac20, 0xc00c7f8048}, {0x0?, {0x0?, 0x0?, 0x0?}})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:975 +0x909›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).ResolveIntents(...)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:915›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).ResolveIntent(0x7017380?, {0x7017380, 0xc008e517d0}, {{{0xc00c89cd60, 0x1e, 0x20}, {0x0, 0x0, 0x0}}, {{0xbf, ...}, ...}, ...}, ...)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:908 +0x115›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*lockTableWaiterImpl).pushLockTxn(0xc002b1eaa0, {0x7017380, 0xc008e517d0}, {0x0, {0x1752d0278419c680, 0x0, 0x0}, 0x408f400000000000, 0x0, 0x0, ...}, ...)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/lock_table_waiter.go:656 +0x814›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*lockTableWaiterImpl).WaitOn.func3({0x7017380?, 0xc008e517d0?})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/lock_table_waiter.go:379 +0x2bc›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*lockTableWaiterImpl).WaitOn(0xc002b1eaa0, {0x7017380, 0xc008e517d0}, {0x0, {0x1752d0278419c680, 0x0, 0x0}, 0x408f400000000000, 0x0, 0x0, ...}, ...)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/lock_table_waiter.go:430 +0x4e6›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*managerImpl).sequenceReqWithGuard(0xc002b1e5f0, {0x7017380, 0xc008e517d0}, 0xc01a3a21e0, 0xc013def778?)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/concurrency_manager.go:330 +0x98f›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*managerImpl).SequenceReq(0x0?, {0x7017380, 0xc008e517d0}, 0xc008cff520?, {0x0, {0x1752d0278419c680, 0x0, 0x0}, 0x408f400000000000, 0x0, ...}, ...)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/concurrency_manager.go:224 +0x2cc›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).executeBatchWithConcurrencyRetries(0xc002ef4580, {0x7017380, 0xc008e517d0}, 0xc00f87ec00, 0x5e402e0)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_send.go:447 +0x310›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).SendWithWriteBytes(0xc002ef4580, {0x7017380?, 0xc009747bc0?}, 0xc00f87ec00)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_send.go:181 +0x6b1›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Store).SendWithWriteBytes(0xc00b0aa000, {0x7017380?, 0xc009747b90?}, 0xc00f87ec00)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/store_send.go:206 +0x74a›
‹ ...+64 lines matching previous stack›
```
At the 198s snapshot we are still resolving intents:
198s
```
I230404 19:00:41.658038 552366 ccl/backupccl/backup_processor.go:177 ⋮ [T1,n4,f‹802faa0d›,job=853816377872449542,distsql.gateway=‹2›] 406 slow request stack during backup: ‹Op:Export [/Table/106/3/2020-11-27T04:10:43Z/"\x1e_\xe9һ\xef@\x00\x8f/\xf4\xe9]\xf7\x80\x02",/Table/106/4), [wait-policy: Block], NodeID: 4, RecordedAt: 2023-04-04 19:00:30.772469322 +0000 UTC›
‹stack as of 198.7s ago: goroutine 552402 [select]:›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).resolveIntents(0xc00b0e5400, {0x7017380, 0xc008e517d0}, {0x6feac20, 0xc010196db0}, {0x0?, {0x0?, 0x0?, 0x0?}})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:975 +0x909›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).ResolveIntents(...)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:915›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).ResolveIntent(0x7017380?, {0x7017380, 0xc008e517d0}, {{{0xc00e3ed3e›
‹ ...+81 lines matching previous stack›
```
At the 178s snapshot we are still resolving intents but the stack has moved on to handle a write intent error and resolve deferred intents - https://github.com/cockroachdb/cockroach/blob/master/pkg/kv/kvserver/replica_send.go#L525
178s
```
‹stack as of 178.7s ago: goroutine 552402 [select]:›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).resolveIntents(0xc00b0e5400, {0x7017380, 0xc008e517d0}, {0x6feac20, 0xc00c1563f0}, {0x0?, {0x1?, 0x0?, 0x0?}})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:975 +0x909›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).ResolveIntents(0xc002d66b40?, {0x7017380, 0xc008e517d0}, {0xc01e3a4000, 0x1388, 0x175c}, {0x1, {0x0, 0x0, 0x0}})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:915 +0xce›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*lockTableWaiterImpl).ResolveDeferredIntents(0xc001f52c60?, {0x7017380?, 0xc008e517d0?}, {0xc01e3a4000?, 0x7048ea0?, 0xc019174a00?})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/lock_table_waiter.go:844 +0x5c›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*managerImpl).HandleWriterIntentError(0xc002b1e5f0, {0x7017380, 0xc008e517d0}, 0xc01a3a21e0, 0xc00c6b8930?, 0xc0036d7050)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/concurrency_manager.go:490 +0x3e8›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).handleWriteIntentError(0xc01a3a21e0?, {0x7017380?, 0xc008e517d0?}, 0x7017380?, 0xc008e517d0?, 0x1?, 0x1?)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_send.go:732 +0x5c›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).executeBatchWithConcurrencyRetries(0xc002ef4580, {0x7017380, 0xc008e517d0}, 0xc00f87ec00, 0x5e402e0)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_send.go:525 +0x788›
‹ ...+68 lines matching previous stack›
```
In the 158s snapshot we are still resolving deferred intents.
In the 138s snapshot we seem to have looped around after handling our WriteIntent error and are retrying the batch because we find a runnable goroutine in https://github.com/cockroachdb/cockroach/blob/master/pkg/kv/kvserver/replica_send.go#L483.
138s
```
‹stack as of 138.7s ago: goroutine 552402 [runnable]:›
‹github.com/cockroachdb/cockroach/pkg/storage.EngineKeyEqual({0xc014dd5aa0?, 0x37?, 0x60?}, {0xc0175f67d0?, 0x37?, 0x37?})›
‹ github.com/cockroachdb/cockroach/pkg/storage/pebble.go:169 +0x334›
‹github.com/cockroachdb/pebble.(*Iterator).equal(...)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:333›
‹github.com/cockroachdb/pebble.(*Iterator).nextUserKey(0xc00ea26000)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:723 +0x253›
‹github.com/cockroachdb/pebble.(*Iterator).findNextEntry(0xc00ea26000, {0x0, 0x0, 0x0})›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:573 +0x3f0›
‹github.com/cockroachdb/pebble.(*Iterator).nextWithLimit(0xc00ea26000, {0x0, 0x0, 0x0})›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:1841 +0x2fe›
‹github.com/cockroachdb/pebble.(*Iterator).Next(...)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:1591›
‹github.com/cockroachdb/cockroach/pkg/storage.(*pebbleIterator).NextEngineKey(0xc01215aa40)›
‹ github.com/cockroachdb/cockroach/pkg/storage/pebble_iterator.go:440 +0x2b›
‹github.com/cockroachdb/cockroach/pkg/storage.ScanConflictingIntentsForDroppingLatchesEarly({0x7017380, 0xc008e517d0}, {0x7057100, 0xc01215a600}, {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...}, ...)›
‹ github.com/cockroachdb/cockroach/pkg/storage/engine.go:1825 +0x3ce›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).canDropLatchesBeforeEval(0xc002ef4580, {0x7017380, 0xc008e517d0}, {0x709ca88?, 0xc01215a600}, _, _, {{{0x1752cd9bf3121f61, 0x0, 0x0}, ...}, ...})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_read.go:311 +0x466›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).executeReadOnlyBatch(0xc002ef4580, {0x7017380, 0xc008e517d0}, 0xc00f87ec00, 0xc01a3a21e0)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_read.go:96 +0x4f2›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).executeBatchWithConcurrencyRetries(0xc002ef4580, {0x7017380, 0xc008e517d0}, 0xc00f87ec00, 0x5e402e0)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_send.go:483 +0x383›
‹ ...+68 lines matching previous stack›
I230404 19:00:41.658243 552366 ccl/backupccl/backup_processor.go:177 ⋮ [T1,n4,f‹802faa0d›,job=853816377872449542,distsql.gateway=‹2›] 410 slow request stack during backup: ‹Op:Export [/Table/106/3/2020-11-27T04:10:43Z/"\x1e_\xe9һ\xef@\x00\x8f/\xf4\xe9]\xf7\x80\x02",/Table/106/4), [wait-policy: Block], NodeID: 4, RecordedAt: 2023-04-04 19:00:30.772469322 +0000 UTC›
‹stack as of 118.7s ago: goroutine 552402 [runnable]:›
‹github.com/cockroachdb/pebble.(*mergingIter).isNextEntryDeleted(0xc000282ac0, 0xc000282df8)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/merging_iter.go:650 +0x745›
‹github.com/cockroachdb/pebble.(*mergingIter).findNextEntry(0xc000282ac0)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/merging_iter.go:810 +0xf9›
‹github.com/cockroachdb/pebble.(*mergingIter).Next(0xc000282ac0)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/merging_iter.go:1251 +0x65›
‹github.com/cockroachdb/pebble.(*Iterator).nextUserKey(0xc000282500)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:709 +0x18f›
‹github.com/cockroachdb/pebble.(*Iterator).findNextEntry(0xc000282500, {0x0, 0x0, 0x0})›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:573 +0x3f0›
‹github.com/cockroachdb/pebble.(*Iterator).nextWithLimit(0xc000282500, {0x0, 0x0, 0x0})›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:1841 +0x2fe›
‹github.com/cockroachdb/pebble.(*Iterator).Next(...)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:1591›
‹github.com/cockroachdb/cockroach/pkg/storage.(*pebbleIterator).NextEngineKey(0xc001c6f640)›
‹ github.com/cockroachdb/cockroach/pkg/storage/pebble_iterator.go:440 +0x2b›
‹github.com/cockroachdb/cockroach/pkg/storage.ScanConflictingIntentsForDroppingLatchesEarly({0x7017380, 0xc008e517d0}, {0x7057100, 0xc001c6f200}, {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...}, ...)›
‹ github.com/cockroachdb/cockroach/pkg/storage/engine.go:1825 +0x3ce›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).canDropLatchesBeforeEval(0xc002ef4580, {0x7017380, 0xc008e517d0}, {0x709ca88?, 0xc001c6f2›
‹ ...+73 lines matching previous stack›
```
From the 118s to 58s snapshots we once again see the ExportRequest resolving deffered intents
118s - 58s
```
I230404 19:00:41.658304 552366 ccl/backupccl/backup_processor.go:177 ⋮ [T1,n4,f‹802faa0d›,job=853816377872449542,distsql.gateway=‹2›] 411 slow request stack during backup: ‹Op:Export [/Table/106/3/2020-11-27T04:10:43Z/"\x1e_\xe9һ\xef@\x00\x8f/\xf4\xe9]\xf7\x80\x02",/Table/106/4), [wait-policy: Block], NodeID: 4, RecordedAt: 2023-04-04 19:00:30.772469322 +0000 UTC›
‹stack as of 98.7s ago: goroutine 552402 [select]:›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).resolveIntents(0xc00b0e5400, {0x7017380, 0xc008e517d0}, {0x6feac20, 0xc007353f80}, {0x0?, {0x1?, 0x0?, 0x0?}})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:975 +0x909›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).ResolveIntents(0xc002d66b40?, {0x7017380, 0xc008e517d0}, {0xc01e3a4000, 0x1388, 0x175c}, {0x1, {0x0, 0x0, 0x0}})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:915 +0xce›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*lockTableWaiterImpl).ResolveDeferredIntents(0xc001f52c60?, {0x7017380?, 0xc008e517d0?}, {0xc01e3a4000?, 0x7048ea0?, 0xc019174a00?})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/lock_table_waiter.go:844 +0x5c›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*managerImpl).HandleWriterIntentError(0xc002b1e5f0, {0x7017380, 0xc008e517d0}, 0xc01a3a21e0, 0xc00c6b8930?, 0xc0101f6ea0)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/concurrency_manager.go:490 +0x3e8›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).handleWriteIntentError(0xc01a3a21e0?, {0x7017380?, 0xc008e517d0?}, 0x7017380?, 0xc008e517d0?, 0x1?, 0x1?)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_send.go:732 +0x5c›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).executeBatchWithConcurrencyRetries(0xc002ef4580, {0x7017380, 0xc008e517d0}, 0xc00f87ec00, 0x5e402e0)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_send.go:525 +0x788›
‹ ...+68 lines matching previous stack›
I230404 19:00:41.658358 552366 ccl/backupccl/backup_processor.go:177 ⋮ [T1,n4,f‹802faa0d›,job=853816377872449542,distsql.gateway=‹2›] 412 slow request stack during backup: ‹Op:Export [/Table/106/3/2020-11-27T04:10:43Z/"\x1e_\xe9һ\xef@\x00\x8f/\xf4\xe9]\xf7\x80\x02",/Table/106/4), [wait-policy: Block], NodeID: 4, RecordedAt: 2023-04-04 19:00:30.772469322 +0000 UTC›
‹stack as of 78.7s ago: goroutine 552402 [select]:›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).resolveIntents(0xc00b0e5400, {0x7017380, 0xc008e517d0}, {0x6feac20, 0xc012ef8eb8}, {0x0?, {0x1?, 0x0?, 0x0?}})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:975 +0x909›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).ResolveIntents(0xc002d66b40?, {0x7017380, 0xc008e517d0}, {0xc01e3a4000, 0x1388, 0x175c}, {0x1, {0x0, 0x0, 0x0}})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:915 +0xce›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*lockTableWaiterImpl).ResolveDeferredIntents(0xc001f52c60?, {0x7017380?, 0xc008e517d0?}, {0xc01e3a4000?, 0x7048ea0?, 0xc019174a00?})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/lock_table_waiter.go:844 +0x5c›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*managerImpl).HandleWriterIntentError(0xc002b1e5f0, {0x7017380, 0xc008e517d0}, 0xc01a3a21e0, 0xc00c6b8930?, 0xc0106d1d›
‹ ...+73 lines matching previous stack›
I230404 19:00:41.658407 552366 ccl/backupccl/backup_processor.go:177 ⋮ [T1,n4,f‹802faa0d›,job=853816377872449542,distsql.gateway=‹2›] 413 slow request stack during backup: ‹Op:Export [/Table/106/3/2020-11-27T04:10:43Z/"\x1e_\xe9һ\xef@\x00\x8f/\xf4\xe9]\xf7\x80\x02",/Table/106/4), [wait-policy: Block], NodeID: 4, RecordedAt: 2023-04-04 19:00:30.772469322 +0000 UTC›
‹stack as of 58.7s ago: goroutine 552402 [select]:›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).resolveIntents(0xc00b0e5400, {0x7017380, 0xc008e517d0}, {0x6feac20, 0xc00f1f2420}, {0x0?, {0x1?, 0x0?, 0x0?}})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:975 +0x909›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).ResolveIntents(0xc002d66b40?, {0x7017380, 0xc008e517d0}, {0xc01e3a4000, 0x1388, 0x175c}, {0x1, {0x0, 0x0, 0x0}})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:915 +0xce›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*lockTableWaiterImpl).ResolveDeferredIntents(0xc001f52c60?, {0x7017380?, 0xc008e517d0?}, {0xc01e3a4000?, 0x7048ea0?, 0xc019174a00?})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/lock_table_waiter.go:844 +0x5c›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*managerImpl).HandleWriterIntentError(0xc002b1e5f0, {0x7017380, 0xc008e517d0}, 0xc01a3a21e0, 0xc00c6b8930?, 0xc008320ab›
‹ ...+73 lines matching previous stack›
```
The snapshots from 38s - 18s show the batch being retried after which the request presumably completes or times out causing it to return to the client:
38s - 18s
```
I230404 19:00:41.658449 552366 ccl/backupccl/backup_processor.go:177 ⋮ [T1,n4,f‹802faa0d›,job=853816377872449542,distsql.gateway=‹2›] 414 slow request stack during backup: ‹Op:Export [/Table/106/3/2020-11-27T04:10:43Z/"\x1e_\xe9һ\xef@\x00\x8f/\xf4\xe9]\xf7\x80\x02",/Table/106/4), [wait-policy: Block], NodeID: 4, RecordedAt: 2023-04-04 19:00:30.772469322 +0000 UTC›
‹stack as of 38.7s ago: goroutine 552402 [runnable]:›
‹github.com/cockroachdb/pebble/internal/base.InternalCompare(0x5e46538?, {{0xc0087d03c0?, 0x39?, 0x39?}, 0xffffffffffffff16?}, {{0x7f22b4845275?, 0x2?, 0x2?}, 0x74d20f00f?})›
‹ github.com/cockroachdb/pebble/internal/base/external/com_github_cockroachdb_pebble/internal/base/internal.go:262 +0xc5›
‹github.com/cockroachdb/pebble/sstable.(*blockIter).SeekLT(0xc00ee81b00, {0xc0087d03c0, 0x39, 0x39}, 0x39?)›
‹ github.com/cockroachdb/pebble/sstable/external/com_github_cockroachdb_pebble/sstable/block.go:845 +0x291›
‹github.com/cockroachdb/pebble/sstable.(*fragmentBlockIter).SeekLT(0xc00ee81b00, {0xc0087d03c0?, 0xc003a16028?, 0x12f13d8?})›
‹ github.com/cockroachdb/pebble/sstable/external/com_github_cockroachdb_pebble/sstable/block.go:1706 +0x2c›
‹github.com/cockroachdb/pebble/sstable.(*fragmentBlockIter).SeekGE(0xc00ee81b00, {0xc0087d03c0, 0x39, 0x39})›
‹ github.com/cockroachdb/pebble/sstable/external/com_github_cockroachdb_pebble/sstable/block.go:1694 +0x31›
‹github.com/cockroachdb/pebble.(*mergingIter).initMinRangeDelIters(0xc0165c8ac0, 0xc0165c8ac0?)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/merging_iter.go:361 +0x9d›
‹github.com/cockroachdb/pebble.(*mergingIter).nextEntry(0xc0165c8ac0, 0xc0165c8cd8, {0x0?, 0x0?, 0x0?})›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/merging_iter.go:640 +0x1e5›
‹github.com/cockroachdb/pebble.(*mergingIter).Next(0xc0165c8ac0)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/merging_iter.go:1250 +0x5a›
‹github.com/cockroachdb/pebble.(*Iterator).nextUserKey(0xc0165c8500)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:709 +0x18f›
‹github.com/cockroachdb/pebble.(*Iterator).findNextEntry(0xc0165c8500, {0x0, 0x0, 0x0})›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:573 +0x3f0›
‹github.com/cockroachdb/pebble.(*Iterator).nextWithLimit(0xc0165c8500, {0x0, 0x0, 0x0})›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:1841 +0x2fe›
‹github.com/cockroachdb/pebble.(*Iterator).Next(...)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:1591›
‹github.com/cockroachdb/cockroach/pkg/storage.(*pebbleIterator).NextEngineKey(0xc01092d640)›
‹ github.com/cockroachdb/cockroach/pkg/storage/pebble_iterator.go:440 +0x2b›
‹github.com/cockroachdb/cockroach/pkg/storage.ScanConflictingIntentsForDroppingLatchesEarly({0x7017380, 0xc008e517d0}, {0x7057100, 0xc01092d200}, {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...}, ...)›
‹ github.com/cockroachdb/cockroach/pkg/storage/engine.go:1825 +0x3ce›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).canDropLatchesBeforeEval(0xc002ef4580, {0x7017380, 0xc008e517d0}, {0x709ca88?, 0xc01092d200}, _, _, {{{0x1752cd9bf3121f61, 0x0, 0x0}, ...}, ...})›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_read.go:311 +0x466›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).executeReadOnlyBatch(0xc002ef4580, {0x7017380, 0xc008e517d0}, 0xc00f87ec00, 0xc01a3a21e0)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_read.go:96 +0x4f2›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).executeBatchWithConcurrencyRetries(0xc002ef4580, {0x7017380, 0xc008e517d0}, 0xc00f87ec00, 0x5e402e0)›
‹ github.com/cockroachdb/cockroach/pkg/kv/kvserver/pkg/kv/kvserver/replica_send.go:483 +0x383›
‹ ...+68 lines matching previous stack›
I230404 19:00:41.658546 552366 ccl/backupccl/backup_processor.go:177 ⋮ [T1,n4,f‹802faa0d›,job=853816377872449542,distsql.gateway=‹2›] 415 slow request stack during backup: ‹Op:Export [/Table/106/3/2020-11-27T04:10:43Z/"\x1e_\xe9һ\xef@\x00\x8f/\xf4\xe9]\xf7\x80\x02",/Table/106/4), [wait-policy: Block], NodeID: 4, RecordedAt: 2023-04-04 19:00:30.772469322 +0000 UTC›
‹stack as of 18.7s ago: goroutine 552402 [runnable]:›
‹github.com/cockroachdb/cockroach/pkg/storage.EngineKeyEqual({0xc011926c00?, 0x39?, 0x80?}, {0xc0021f0b40?, 0x39?, 0x39?})›
‹ github.com/cockroachdb/cockroach/pkg/storage/pebble.go:169 +0x334›
‹github.com/cockroachdb/pebble.(*Iterator).equal(...)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:333›
‹github.com/cockroachdb/pebble.(*Iterator).nextUserKey(0xc00ed2aa00)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:723 +0x253›
‹github.com/cockroachdb/pebble.(*Iterator).findNextEntry(0xc00ed2aa00, {0x0, 0x0, 0x0})›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:573 +0x3f0›
‹github.com/cockroachdb/pebble.(*Iterator).nextWithLimit(0xc00ed2aa00, {0x0, 0x0, 0x0})›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:1841 +0x2fe›
‹github.com/cockroachdb/pebble.(*Iterator).Next(...)›
‹ github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/iterator.go:1591›
‹github.com/cockroachdb/cockroach/pkg/storage.(*pebbleIterator).NextEngineKey(0xc0161baa40)›
‹ github.com/cockroachdb/cockroach/pkg/storage/pebble_iterator.go:440 +0x2b›
‹github.com/cockroachdb/cockroach/pkg/storage.ScanConflictingIntentsForDroppingLatchesEarly({0x7017380, 0xc008e517d0}, {0x7057100, 0xc0161ba600}, {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...}, ...)›
‹ github.com/cockroachdb/cockroach/pkg/storage/engine.go:1825 +0x3ce›
‹github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).canDropLatchesBeforeEval(0xc002ef4580, {0x7017380, 0xc008e517d0}, {0x709ca88?, 0xc0161ba6›
‹ ...+73 lines matching previous stack›
```
This is just one example of what we are seeing in ExportRequests across all nodes. The above stacks correlate with the spike in the metric that tracks how many intents are sent/recvd:

Though we don't see very many range intents in that same time window:

Another interesting thing to point out is that each ExportRequest goes through a concurrent request limiter. This limiter permits 3 requests per store. We have a metric called `exportrequest.delay.total` that calculates the time spent across all ExportRequests in that limiter and it did not appear to spike anywhere close to 300s (our timeout). This implies that the ExportRequests are probably timing out while actively resolving intents server-side.
### Next steps
- One suggestion was to add a metric to track how long we're spending in the intent resolver loop - https://github.com/cockroachdb/cockroach/blob/master/pkg/kv/kvserver/intentresolver/intent_resolver.go#L943-L986 as this could be useful to confirm that we are indeed tipping over the 300s mark because of intent resolution.
- More steps to follow.
### Additional context:
There was a mention in an internal slack channel about a similar behaviour observed by `SELECTs` - https://cockroachlabs.slack.com/archives/C01RX2G8LT1/p1677554404681329
Jira issue: CRDB-27039
Jira issue: CRDB-27089
Contributor guide
Research direction
Reproduce the issue with the roachprod setup and SQL workload, then trace the slow ExportRequest through pkg/kv/kvserver/store_send.go and pkg/kv/kvserver/replica_send.go#L447, including the limiter in pkg/util/limit/limiter.go. Use ccl/backupccl/backup_processor.go around the five-minute context as the completion boundary; done means the reproduced backup no longer times out during intent resolution.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go
- Domain
- backend, databases, distributed-systems
- Issue type
- Bug
- Difficulty
- 5/5
- Estimated time
- Over a week
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 25/100