basalt-26.3: pkg/kv/followerreads/followerreads_test: TestFollowerReadsWithStaleDescriptor failed

pkg/kv/followerreads/followerreads_test.TestFollowerReadsWithStaleDescriptor [failed](https://mesolite.cluster.engflow.com/invocations/default/f7fa05d2-f7ed-4423-b932-342e560e818b?testReportRun=2&testReportShard=1&testReportAttempt=1#targets-Ly9wa2cva3YvZm9sbG93ZXJyZWFkczpmb2xsb3dlcnJlYWRzX3Rlc3Q=) on basalt-26.3 @ [fafc66a354bc3374b5e38f8c3789047d52859fee](https://github.com/cockroachdb/cockroach/commits/fafc66a354bc3374b5e38f8c3789047d52859fee):

```
939.870ms -2.330ms structured:{"@type":"type.googleapis.com/cockroach.roachpb.UsedFollowerRead"}
942.010ms 2.141ms structured:{"@type":"type.googleapis.com/cockroach.roachpb.ScanStats","numInterfaceSeeks":"1","numInternalSeeks":"1","numGets":"1","nodeId":3,"region":"test"}
942.519ms 4.505ms event:kv/kvclient/kvcoord/transport.go:231 [n3,f2a381338,distsql.stmt=SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp(),distsql.gateway=4,distsql.txn=6077dc0b-91d9-4f87-8f70-42fbaed4f66c,txn=6077dc0b] received batch response
942.897ms 6.378ms event:kv/kvclient/kvcoord/txn_interceptor_span_refresher.go:620 [n3,f2a381338,distsql.stmt=SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp(),distsql.gateway=4,distsql.txn=6077dc0b-91d9-4f87-8f70-42fbaed4f66c,txn=6077dc0b] recording span to refresh: /Tenant/10/Table/106/1/2/0
936.091ms -6.805ms === operation:colbatchscan gid:38746 _unfinished:1 _verbose:1 node:3 f:2a381338 distsql.stmt:SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp() distsql.gateway:4 distsql.txn:6077dc0b-91d9-4f87-8f70-42fbaed4f66c cockroach.flowid:2a381338-c35b-40a6-815b-5a42c28e4db1 cockroach.processorid:1
936.091ms 0.000ms [txn coordinator send: {count: 1, duration 5ms}]
936.091ms 0.000ms [dist sender send: {count: 1, duration 5ms}]
936.091ms 0.000ms [/cockroach.roachpb.Internal/Batch: {count: 1, duration 3ms}]
943.212ms 7.121ms event:sql/row/kv_batch_fetcher.go:665 [n3,f2a381338,distsql.stmt=SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp(),distsql.gateway=4,distsql.txn=6077dc0b-91d9-4f87-8f70-42fbaed4f66c] Scan /Tenant/10/Table/106/1/3/0
943.369ms 0.156ms event:sql/row/kv_batch_fetcher.go:310 [n3,f2a381338,distsql.stmt=SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp(),distsql.gateway=4,distsql.txn=6077dc0b-91d9-4f87-8f70-42fbaed4f66c] kv fetcher: sending a batch with 1 requests
943.383ms 0.014ms === operation:txn coordinator send gid:38746 _verbose:1 node:3 f:2a381338 distsql.stmt:SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp() distsql.gateway:4 distsql.txn:6077dc0b-91d9-4f87-8f70-42fbaed4f66c txnID:6077dc0b-91d9-4f87-8f70-42fbaed4f66c
943.383ms 0.000ms [dist sender send: {count: 1, duration 5ms}]
943.383ms 0.000ms [/cockroach.roachpb.Internal/Batch: {count: 1, duration 3ms}]
943.424ms 0.041ms === operation:dist sender send gid:38746 _verbose:1 node:3 f:2a381338 distsql.stmt:SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp() distsql.gateway:4 distsql.txn:6077dc0b-91d9-4f87-8f70-42fbaed4f66c txn:6077dc0b
943.424ms 0.000ms [/cockroach.roachpb.Internal/Batch: {count: 1, duration 3ms}]
943.676ms 0.252ms event:kv/kvclient/kvcoord/range_iter.go:183 [n3,f2a381338,distsql.stmt=SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp(),distsql.gateway=4,distsql.txn=6077dc0b-91d9-4f87-8f70-42fbaed4f66c,txn=6077dc0b] querying next range at /Tenant/10/Table/106/1/3/0
944.041ms 0.365ms event:kv/kvclient/kvcoord/range_iter.go:220 [n3,f2a381338,distsql.stmt=SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp(),distsql.gateway=4,distsql.txn=6077dc0b-91d9-4f87-8f70-42fbaed4f66c,txn=6077dc0b] key: /Tenant/10/Table/106/1/3/0, desc: r90:/Tenant/1{0/Table/106-1} [(n1,s1):1, (n3,s3):3NON_VOTER, next=4, gen=9, sticky=9223372036.854775807,2147483647]
944.303ms 0.262ms event:kv/kvclient/kvcoord/dist_sender.go:2747 [n3,f2a381338,distsql.stmt=SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp(),distsql.gateway=4,distsql.txn=6077dc0b-91d9-4f87-8f70-42fbaed4f66c,txn=6077dc0b] routing to nearest replica; leaseholder not required order=[(n3,s3):3NON_VOTER(health=false match=2 latency=0µs),(n1,s1):1(health=false match=1 latency=381ms)]
944.483ms 0.180ms event:kv/kvclient/kvcoord/dist_sender.go:2806 [n3,f2a381338,distsql.stmt=SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp(),distsql.gateway=4,distsql.txn=6077dc0b-91d9-4f87-8f70-42fbaed4f66c,txn=6077dc0b] r90: sending batch 1 Get to (n3,s3):3NON_VOTER
944.670ms 0.186ms event:rpc/nodedialer/nodedialer.go:167 [n3,f2a381338,distsql.stmt=SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp(),distsql.gateway=4,distsql.txn=6077dc0b-91d9-4f87-8f70-42fbaed4f66c,txn=6077dc0b] sending request to local client
944.869ms 0.200ms event:kv/kvclient/kvcoord/transport.go:228 [n3,f2a381338,distsql.stmt=SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp(),distsql.gateway=4,distsql.txn=6077dc0b-91d9-4f87-8f70-42fbaed4f66c,txn=6077dc0b] sending batch request
944.970ms 0.101ms === operation:/cockroach.roachpb.Internal/Batch gid:38746 _verbose:1 node:3 tenant:10 span.kind:server request:Get [/Tenant/10/Table/106/1/3/0], [txn: 6077dc0b], [max_span_request_keys: 0], [target_bytes: 45801]
945.095ms 0.125ms event:server/node.go:1672 [n3,tenant=10] node received request: 1 Get
945.306ms 0.212ms event:kv/kvserver/store_send.go:203 [n3,tenant=10,s3] executing Get [/Tenant/10/Table/106/1/3/0], [txn: 6077dc0b], [max_span_request_keys: 0], [target_bytes: 45801]
945.408ms 0.102ms event:kv/kvserver/replica_send.go:190 [n3,tenant=10,s3,r90/3:/Tenant/1{0/Table/…-1}] read-only path
945.512ms 0.104ms event:kv/kvserver/concurrency/concurrency_manager.go:299 [n3,tenant=10,s3,r90/3:/Tenant/1{0/Table/…-1}] sequencing request
945.594ms 0.082ms event:kv/kvserver/concurrency/concurrency_manager.go:380 [n3,tenant=10,s3,r90/3:/Tenant/1{0/Table/…-1}] acquiring latches
945.689ms 0.095ms event:kv/kvserver/concurrency/concurrency_manager.go:424 [n3,tenant=10,s3,r90/3:/Tenant/1{0/Table/…-1}] scanning lock table for conflicting locks
945.830ms 0.141ms event:kv/kvserver/replica_follower_read.go:75 [n3,tenant=10,s3,r90/3:/Tenant/1{0/Table/…-1}] serving via follower read; query timestamp below closed timestamp by 1.96354947s
946.290ms 0.461ms event:
946.499ms 0.209ms event:kv/kvserver/replica_read.go:516 [n3,tenant=10,s3,r90/3:/Tenant/1{0/Table/…-1}] can drop latches early for batch (Get [/Tenant/10/Table/106/1/3/0], [txn: 6077dc0b], [max_span_request_keys: 0], [target_bytes: 45801]); scanning lock table first to detect conflicts
946.869ms 0.370ms event:storage/engine.go:2147 [n3,tenant=10,s3,r90/3:/Tenant/1{0/Table/…-1}] lock table scan stats: seeked 1 times (1 internal); stepped 0 times (0 internal); blocks: 67B cached; points: 0 (0B keys, 0B values)
946.974ms 0.105ms event:kv/kvserver/replica_read.go:319 [n3,tenant=10,s3,r90/3:/Tenant/1{0/Table/…-1}] lock table scan complete without conflicts; dropping latches early
947.067ms 0.093ms event:kv/kvserver/replica_read.go:636 [n3,tenant=10,s3,r90/3:/Tenant/1{0/Table/…-1}] executing read-only batch
947.826ms 0.759ms event:kv/kvserver/replica_evaluate.go:565 [n3,tenant=10,s3,r90/3:/Tenant/1{0/Table/…-1}] evaluated Get command header: expect_exclusion_since:<> , txn="sql txn" meta={id=6077dc0b key=/Min iso=Serializable pri=0.02945829 epo=0 ts=1788693395.902040000,0 min=1788693395.902040000,0 seq=0} lock=false stat=PENDING rts=1788693395.902040000,0 gul=1788693395.902040000,0 obs={n3@1788693401.040508576,0 n4@1788693400.101598383,0} : resp=header:<> , err=
947.926ms 0.100ms event:kv/kvserver/replica_read.go:441 [n3,tenant=10,s3,r90/3:/Tenant/1{0/Table/…-1}] read completed
948.142ms 0.216ms event:n3 scan stats: stepped 0 times (0 internal); seeked 1 times (1 internal); block-bytes: (total 0 B, cached 0 B, duration 0s); points: (count 0, key-bytes 0 B, value-bytes 0 B, tombstoned: 0) ranges: (count 0), (contained-points 0, skipped-points 0) evaluated requests: 1 gets, 0 scans, 0 reverse scans
948.209ms 0.068ms event:server/node.go:1797 [n3,tenant=10] node sending response
946.268ms -1.941ms structured:{"@type":"type.googleapis.com/cockroach.roachpb.UsedFollowerRead"}
948.027ms 1.759ms structured:{"@type":"type.googleapis.com/cockroach.roachpb.ScanStats","numInterfaceSeeks":"1","numInternalSeeks":"1","numGets":"1","nodeId":3,"region":"test"}
948.547ms 3.678ms event:kv/kvclient/kvcoord/transport.go:231 [n3,f2a381338,distsql.stmt=SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp(),distsql.gateway=4,distsql.txn=6077dc0b-91d9-4f87-8f70-42fbaed4f66c,txn=6077dc0b] received batch response
948.858ms 5.475ms event:kv/kvclient/kvcoord/txn_interceptor_span_refresher.go:620 [n3,f2a381338,distsql.stmt=SELECT * FROM [SELECT * FROM test WHERE k = _ UNION ALL SELECT * FROM test WHERE k = _] AS OF SYSTEM TIME follower_read_timestamp(),distsql.gateway=4,distsql.txn=6077dc0b-91d9-4f87-8f70-42fbaed4f66c,txn=6077dc0b] recording span to refresh: /Tenant/10/Table/106/1/3/0
1058.038ms 1049.237ms event:sql/conn_executor_exec.go:1161 [n4,client=127.0.0.1:51352,hostssl,user=root] execution ends
1058.125ms 0.087ms event:sql/conn_executor_exec.go:1161 [n4,client=127.0.0.1:51352,hostssl,user=root] rows affected: 0
1058.798ms 0.673ms === operation:commit sql txn gid:33548 _verbose:1 node:4 client:127.0.0.1:51352 hostssl: user:root
1058.972ms 0.847ms event:sql/conn_executor_exec.go:4627 [n4,client=127.0.0.1:51352,hostssl,user=root] AutoCommit. err:
1058.988ms 0.016ms event:in instrumenationHelper.Finish
panic.go:694: -- test log scope end --
test logs left over in: outputs.zip/logTestFollowerReadsWithStaleDescriptor3549429459
--- FAIL: TestFollowerReadsWithStaleDescriptor (244.52s)
```

Parameters:
- attempt=1
- race=true
- run=2
- shard=1
Help

See also: [How To Investigate a Go Test Failure \(internal\)](https://cockroachlabs.atlassian.net/l/c/HgfXfJgM)

/cc @cockroachlabs/unowned

[This test on roachdash](https://roachdash.crdb.dev/?filter=status:open%20t:.*TestFollowerReadsWithStaleDescriptor.*&sort=title+created&display=lastcommented+project) | [Improve this report!](https://github.com/cockroachdb/cockroach/tree/master/pkg/cmd/bazci/githubpost/issues)

Jira issue: CRDB-67984

Start by rerunning pkg/kv/followerreads/followerreads_test.TestFollowerReadsWithStaleDescriptor at commit fafc66a354bc3374b5e38f8c3789047d52859fee and compare the failure with the linked test report. Read pkg/kv/followerreads/followerreads_test and the reported follower-read trace; done means the test reliably passes and the failure is explained or fixed.

Written by the indexing model from the issue text.