chengxiong-ruan
commented
1 year ago the full error message:
datadriven_test.go:132:
/home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/1456/execroot/com_github_cockroachdb_cockroach/bazel-out/k8-fastbuild/bin/pkg/ccl/multiregionccl/multiregionccl_test_/multiregionccl_test.runfiles/com_github_cockroachdb_cockroach/pkg/ccl/multiregionccl/testdata/global_tables:24:
SELECT * FROM db.global WHERE k = 1
expected:
served locally: true
served via follower read: false
found:
not a match, trace:
0.000ms 0.000ms === operation:traced statement _verbose:1 node:1 client:127.0.0.1:46960 user:root
0.000ms 0.000ms [flow: {count: 1, duration 8ms}]
0.000ms 0.000ms [colbatchscan: {count: 1, duration 7ms}]
0.000ms 0.000ms [batch flow coordinator: {count: 1, duration 7ms}]
0.000ms 0.000ms [txn coordinator send: {count: 1, duration 5ms}]
0.000ms 0.000ms [dist sender send: {count: 1, duration 4ms}]
0.000ms 0.000ms [optimizer: {count: 1, duration 4ms}]
0.000ms 0.000ms [/cockroach.roachpb.Internal/Batch: {count: 1, duration 3ms}]
0.000ms 0.000ms [commit sql txn: {count: 1, duration 291µs}]
0.089ms 0.089ms === operation:optimizer _verbose:1 node:1 client:127.0.0.1:46960 user:root
0.214ms 0.125ms event:sql/plan_opt.go:389 [n1,client=127.0.0.1:46960,user=root] query cache miss
0.263ms 0.049ms event:sql/opt/optbuilder/builder.go:201 [n1,client=127.0.0.1:46960,user=root] optbuilder start
0.480ms 0.217ms event:sql/catalog/lease/descriptor_version_state.go:124 [n1,client=127.0.0.1:46960,user=root] descriptorVersionState.incRefCount: 100("defaultdb") ver=1:1681452788.512207414,0, refcount=1
0.880ms 0.400ms event:sql/catalog/descs/descriptor.go:137 [n1,client=127.0.0.1:46960,user=root] looking up descriptors for ids [100]
1.076ms 0.196ms event:sql/catalog/lease/descriptor_version_state.go:124 [n1,client=127.0.0.1:46960,user=root] descriptorVersionState.incRefCount: 104("db") ver=1:1681452797.870155005,0, refcount=1
1.933ms 0.857ms event:sql/catalog/descs/descriptor.go:137 [n1,client=127.0.0.1:46960,user=root] looking up descriptors for ids [104]
2.005ms 0.072ms event:sql/catalog/descs/descriptor.go:137 [n1,client=127.0.0.1:46960,user=root] looking up descriptors for ids [105]
2.257ms 0.252ms event:sql/catalog/lease/descriptor_version_state.go:124 [n1,client=127.0.0.1:46960,user=root] descriptorVersionState.incRefCount: 105("public") ver=1:1681452786.773546468,0, refcount=1
2.693ms 0.437ms event:sql/catalog/lease/descriptor_version_state.go:124 [n1,client=127.0.0.1:46960,user=root] descriptorVersionState.incRefCount: 108("global") ver=1:1681452800.392605536,0, refcount=1
3.190ms 0.497ms event:sql/catalog/descs/descriptor.go:137 [n1,client=127.0.0.1:46960,user=root] looking up descriptors for ids [108]
3.494ms 0.304ms event:sql/opt/optbuilder/builder.go:247 [n1,client=127.0.0.1:46960,user=root] optbuilder finish
3.547ms 0.053ms event:sql/opt/xform/optimizer.go:240 [n1,client=127.0.0.1:46960,user=root] optimize start
3.654ms 0.107ms event:sql/opt/xform/optimizer.go:289 [n1,client=127.0.0.1:46960,user=root] optimize finish
3.723ms 0.069ms event:sql/plan_opt.go:389 [n1,client=127.0.0.1:46960,user=root] query cache add
4.054ms 4.054ms event:sql/conn_executor_exec.go:963 [n1,client=127.0.0.1:46960,user=root] planning ends
4.111ms 0.057ms event:sql/conn_executor_exec.go:963 [n1,client=127.0.0.1:46960,user=root] checking distributability
4.162ms 0.050ms event:sql/conn_executor_exec.go:963 [n1,client=127.0.0.1:46960,user=root] will distribute plan: false
4.235ms 0.073ms event:sql/conn_executor_exec.go:963 [n1,client=127.0.0.1:46960,user=root] executing after 0 retries, last retry reason: <nil>
4.291ms 0.056ms event:sql/conn_executor_exec.go:963 [n1,client=127.0.0.1:46960,user=root] execution starts: distributed engine
4.354ms 0.064ms event:sql/distsql_running.go:1922 [n1,client=127.0.0.1:46960,user=root] creating DistSQL plan with isLocal=true
4.422ms 0.068ms event:sql/distsql_running.go:819 [n1,client=127.0.0.1:46960,user=root] running DistSQL plan
4.467ms 0.045ms === operation:flow _verbose:1 node:1 client:127.0.0.1:46960 user:root
4.647ms 0.180ms event:sql/colflow/vectorized_flow.go:232 [n1,client=127.0.0.1:46960,user=root] setting up vectorized flow
4.811ms 0.164ms event:sql/colflow/vectorized_flow.go:282 [n1,client=127.0.0.1:46960,user=root] vectorized flow setup succeeded
4.873ms 0.062ms event:sql/flowinfra/flow.go:442 [n1,client=127.0.0.1:46960,user=root] starting (0 processors, 0 startables) asynchronously
4.924ms 0.051ms event:sql/colflow/vectorized_flow.go:325 [n1,client=127.0.0.1:46960,user=root] running the batch flow coordinator in the flow's goroutine
12.459ms 7.535ms event:component:<flow_id:<7385a3ad-2f74-4920-9a2e-6f82cf5002a7> type:FLOW id:0 sql_instance_id:1 > net_rx:<latency:<> wait_time:<> deserialization_time:<> tuples_received:<> bytes_received:<> messages_received:<> > net_tx:<tuples_sent:<> bytes_sent:<> messages_sent:<> > kv:<bytes_read:<> tuples_read:<> batch_requests_issued:<> kv_time:<> contention_time:<> num_interface_steps:<> num_internal_steps:<> num_interface_seeks:<> num_internal_seeks:<> block_bytes:<> block_bytes_in_cache:<> key_bytes:<> value_bytes:<> point_count:<> points_covered_by_range_tombstones:<> range_key_count:<> range_key_contained_points:<> range_key_skipped_points:<> kv_cpu_time:<> num_gets:<> num_scans:<> num_reverse_scans:<> > exec:<exec_time:<> max_allocated_mem:<> max_allocated_disk:<> consumed_ru:<> cpu_time:<> > output:<num_batches:<> num_tuples:<> > flow_stats:<max_mem_usage:<value_plus_one:20481 > max_disk_usage:<value_plus_one:1 > consumed_ru:<> >
12.286ms -0.172ms structured:{"@type":"type.googleapis.com/cockroach.sql.distsqlrun.ComponentStats","component":{"flowId":"7385a3ad-2f74-4920-9a2e-6f82cf5002a7","type":"FLOW","id":0,"sqlInstanceId":1},"netRx":{"latency":{"valuePlusOne":"0s"},"waitTime":{"valuePlusOne":"0s"},"deserializationTime":{"valuePlusOne":"0s"},"tuplesReceived":{"valuePlusOne":"0"},"bytesReceived":{"valuePlusOne":"0"},"messagesReceived":{"valuePlusOne":"0"}},"netTx":{"tuplesSent":{"valuePlusOne":"0"},"bytesSent":{"valuePlusOne":"0"},"messagesSent":{"valuePlusOne":"0"}},"kv":{"bytesRead":{"valuePlusOne":"0"},"tuplesRead":{"valuePlusOne":"0"},"batchRequestsIssued":{"valuePlusOne":"0"},"kvTime":{"valuePlusOne":"0s"},"contentionTime":{"valuePlusOne":"0s"},"numInterfaceSteps":{"valuePlusOne":"0"},"numInternalSteps":{"valuePlusOne":"0"},"numInterfaceSeeks":{"valuePlusOne":"0"},"numInternalSeeks":{"valuePlusOne":"0"},"blockBytes":{"valuePlusOne":"0"},"blockBytesInCache":{"valuePlusOne":"0"},"keyBytes":{"valuePlusOne":"0"},"valueBytes":{"valuePlusOne":"0"},"pointCount":{"valuePlusOne":"0"},"pointsCoveredByRangeTombstones":{"valuePlusOne":"0"},"rangeKeyCount":{"valuePlusOne":"0"},"rangeKeyContainedPoints":{"valuePlusOne":"0"},"rangeKeySkippedPoints":{"valuePlusOne":"0"},"contentionEvents":[],"kvCpuTime":{"valuePlusOne":"0s"},"numGets":{"valuePlusOne":"0"},"numScans":{"valuePlusOne":"0"},"numReverseScans":{"valuePlusOne":"0"}},"exec":{"execTime":{"valuePlusOne":"0s"},"maxAllocatedMem":{"valuePlusOne":"0"},"maxAllocatedDisk":{"valuePlusOne":"0"},"consumedRu":{"valuePlusOne":"0"},"cpuTime":{"valuePlusOne":"0s"}},"output":{"numBatches":{"valuePlusOne":"0"},"numTuples":{"valuePlusOne":"0"}},"inputs":[],"flowStats":{"maxMemUsage":{"valuePlusOne":"20481"},"maxDiskUsage":{"valuePlusOne":"1"},"consumedRu":{"valuePlusOne":"0"}}}
4.972ms -7.314ms === operation:batch flow coordinator _unfinished:1 _verbose:1 node:1 client:127.0.0.1:46960 user:root cockroach.flowid:7385a3ad-2f74-4920-9a2e-6f82cf5002a7 cockroach.processorid:0
11.336ms 6.364ms event:component:<flow_id:<7385a3ad-2f74-4920-9a2e-6f82cf5002a7> type:PROCESSOR id:0 sql_instance_id:1 > net_rx:<latency:<> wait_time:<> deserialization_time:<> tuples_received:<> bytes_received:<> messages_received:<> > net_tx:<tuples_sent:<> bytes_sent:<> messages_sent:<> > kv:<bytes_read:<value_plus_one:12 > tuples_read:<value_plus_one:2 > batch_requests_issued:<value_plus_one:2 > kv_time:<value_plus_one:<nanos:5724270 > > contention_time:<value_plus_one:<nanos:1 > > num_interface_steps:<value_plus_one:1 > num_internal_steps:<value_plus_one:1 > num_interface_seeks:<value_plus_one:2 > num_internal_seeks:<value_plus_one:2 > block_bytes:<value_plus_one:3787 > block_bytes_in_cache:<value_plus_one:3787 > key_bytes:<value_plus_one:15 > value_bytes:<value_plus_one:15 > point_count:<value_plus_one:2 > points_covered_by_range_tombstones:<value_plus_one:1 > range_key_count:<value_plus_one:1 > range_key_contained_points:<value_plus_one:1 > range_key_skipped_points:<value_plus_one:1 > kv_cpu_time:<> num_gets:<value_plus_one:2 > num_scans:<value_plus_one:1 > num_reverse_scans:<value_plus_one:1 > > exec:<exec_time:<> max_allocated_mem:<value_plus_one:20481 > max_allocated_disk:<> consumed_ru:<value_plus_one:1 > cpu_time:<value_plus_one:<nanos:459268 > > > output:<num_batches:<value_plus_one:2 > num_tuples:<value_plus_one:2 > > flow_stats:<max_mem_usage:<> max_disk_usage:<> consumed_ru:<> >
11.597ms 0.261ms event:component:<flow_id:<00000000-0000-0000-0000-000000000000> type:UNSET id:0 sql_instance_id:0 > net_rx:<latency:<> wait_time:<> deserialization_time:<> tuples_received:<> bytes_received:<> messages_received:<> > net_tx:<tuples_sent:<> bytes_sent:<> messages_sent:<> > kv:<bytes_read:<> tuples_read:<> batch_requests_issued:<> kv_time:<> contention_time:<> num_interface_steps:<> num_internal_steps:<> num_interface_seeks:<> num_internal_seeks:<> block_bytes:<> block_bytes_in_cache:<> key_bytes:<> value_bytes:<> point_count:<> points_covered_by_range_tombstones:<> range_key_count:<> range_key_contained_points:<> range_key_skipped_points:<> kv_cpu_time:<> num_gets:<> num_scans:<> num_reverse_scans:<> > exec:<exec_time:<> max_allocated_mem:<> max_allocated_disk:<> consumed_ru:<> cpu_time:<> > output:<num_batches:<> num_tuples:<> > flow_stats:<max_mem_usage:<> max_disk_usage:<> consumed_ru:<> >
11.135ms -0.461ms structured:{"@type":"type.googleapis.com/cockroach.sql.distsqlrun.ComponentStats","component":{"flowId":"7385a3ad-2f74-4920-9a2e-6f82cf5002a7","type":"PROCESSOR","id":0,"sqlInstanceId":1},"netRx":{"latency":{"valuePlusOne":"0s"},"waitTime":{"valuePlusOne":"0s"},"deserializationTime":{"valuePlusOne":"0s"},"tuplesReceived":{"valuePlusOne":"0"},"bytesReceived":{"valuePlusOne":"0"},"messagesReceived":{"valuePlusOne":"0"}},"netTx":{"tuplesSent":{"valuePlusOne":"0"},"bytesSent":{"valuePlusOne":"0"},"messagesSent":{"valuePlusOne":"0"}},"kv":{"bytesRead":{"valuePlusOne":"12"},"tuplesRead":{"valuePlusOne":"2"},"batchRequestsIssued":{"valuePlusOne":"2"},"kvTime":{"valuePlusOne":"0.005724270s"},"contentionTime":{"valuePlusOne":"0.000000001s"},"numInterfaceSteps":{"valuePlusOne":"1"},"numInternalSteps":{"valuePlusOne":"1"},"numInterfaceSeeks":{"valuePlusOne":"2"},"numInternalSeeks":{"valuePlusOne":"2"},"blockBytes":{"valuePlusOne":"3787"},"blockBytesInCache":{"valuePlusOne":"3787"},"keyBytes":{"valuePlusOne":"15"},"valueBytes":{"valuePlusOne":"15"},"pointCount":{"valuePlusOne":"2"},"pointsCoveredByRangeTombstones":{"valuePlusOne":"1"},"rangeKeyCount":{"valuePlusOne":"1"},"rangeKeyContainedPoints":{"valuePlusOne":"1"},"rangeKeySkippedPoints":{"valuePlusOne":"1"},"contentionEvents":[],"kvCpuTime":{"valuePlusOne":"0s"},"numGets":{"valuePlusOne":"2"},"numScans":{"valuePlusOne":"1"},"numReverseScans":{"valuePlusOne":"1"}},"exec":{"execTime":{"valuePlusOne":"0s"},"maxAllocatedMem":{"valuePlusOne":"20481"},"maxAllocatedDisk":{"valuePlusOne":"0"},"consumedRu":{"valuePlusOne":"1"},"cpuTime":{"valuePlusOne":"0.000459268s"}},"output":{"numBatches":{"valuePlusOne":"2"},"numTuples":{"valuePlusOne":"2"}},"inputs":[],"flowStats":{"maxMemUsage":{"valuePlusOne":"0"},"maxDiskUsage":{"valuePlusOne":"0"},"consumedRu":{"valuePlusOne":"0"}}}
11.392ms 0.257ms structured:{"@type":"type.googleapis.com/cockroach.sql.distsqlrun.ComponentStats","component":{"flowId":"00000000-0000-0000-0000-000000000000","type":"UNSET","id":0,"sqlInstanceId":0},"netRx":{"latency":{"valuePlusOne":"0s"},"waitTime":{"valuePlusOne":"0s"},"deserializationTime":{"valuePlusOne":"0s"},"tuplesReceived":{"valuePlusOne":"0"},"bytesReceived":{"valuePlusOne":"0"},"messagesReceived":{"valuePlusOne":"0"}},"netTx":{"tuplesSent":{"valuePlusOne":"0"},"bytesSent":{"valuePlusOne":"0"},"messagesSent":{"valuePlusOne":"0"}},"kv":{"bytesRead":{"valuePlusOne":"0"},"tuplesRead":{"valuePlusOne":"0"},"batchRequestsIssued":{"valuePlusOne":"0"},"kvTime":{"valuePlusOne":"0s"},"contentionTime":{"valuePlusOne":"0s"},"numInterfaceSteps":{"valuePlusOne":"0"},"numInternalSteps":{"valuePlusOne":"0"},"numInterfaceSeeks":{"valuePlusOne":"0"},"numInternalSeeks":{"valuePlusOne":"0"},"blockBytes":{"valuePlusOne":"0"},"blockBytesInCache":{"valuePlusOne":"0"},"keyBytes":{"valuePlusOne":"0"},"valueBytes":{"valuePlusOne":"0"},"pointCount":{"valuePlusOne":"0"},"pointsCoveredByRangeTombstones":{"valuePlusOne":"0"},"rangeKeyCount":{"valuePlusOne":"0"},"rangeKeyContainedPoints":{"valuePlusOne":"0"},"rangeKeySkippedPoints":{"valuePlusOne":"0"},"contentionEvents":[],"kvCpuTime":{"valuePlusOne":"0s"},"numGets":{"valuePlusOne":"0"},"numScans":{"valuePlusOne":"0"},"numReverseScans":{"valuePlusOne":"0"}},"exec":{"execTime":{"valuePlusOne":"0s"},"maxAllocatedMem":{"valuePlusOne":"0"},"maxAllocatedDisk":{"valuePlusOne":"0"},"consumedRu":{"valuePlusOne":"0"},"cpuTime":{"valuePlusOne":"0s"}},"output":{"numBatches":{"valuePlusOne":"0"},"numTuples":{"valuePlusOne":"0"}},"inputs":[],"flowStats":{"maxMemUsage":{"valuePlusOne":"0"},"maxDiskUsage":{"valuePlusOne":"0"},"consumedRu":{"valuePlusOne":"0"}}}
5.100ms -6.292ms === operation:colbatchscan _unfinished:1 _verbose:1 node:1 client:127.0.0.1:46960 user:root
5.100ms 0.000ms [txn coordinator send: {count: 1, duration 5ms}]
5.100ms 0.000ms [dist sender send: {count: 1, duration 4ms}]
5.100ms 0.000ms [/cockroach.roachpb.Internal/Batch: {count: 1, duration 3ms}]
5.547ms 0.447ms event:sql/row/kv_batch_fetcher.go:475 [n1,client=127.0.0.1:46960,user=root] Scan /Table/108/1/1/0
5.629ms 0.081ms === operation:txn coordinator send _verbose:1 node:1 client:127.0.0.1:46960 user:root txnID:a8f00682-00a1-4053-bcff-edec6f0c9546
5.629ms 0.000ms [dist sender send: {count: 1, duration 4ms}]
5.629ms 0.000ms [/cockroach.roachpb.Internal/Batch: {count: 1, duration 3ms}]
5.781ms 0.152ms === operation:dist sender send _verbose:1 node:1 client:127.0.0.1:46960 user:root txn:a8f00682
5.781ms 0.000ms [/cockroach.roachpb.Internal/Batch: {count: 1, duration 3ms}]
5.941ms 0.160ms event:kv/kvclient/kvcoord/range_iter.go:188 [n1,client=127.0.0.1:46960,user=root,txn=a8f00682] querying next range at /Table/108/1/1/0
6.147ms 0.205ms event:kv/kvclient/kvcoord/range_iter.go:225 [n1,client=127.0.0.1:46960,user=root,txn=a8f00682] key: /Table/108/1/1/0, desc: r63:/{Table/108-Max} [(n1,s1):1, (n2,s2):5, (n3,s3):9, (n4,s4):6NON_VOTER, (n5,s5):10NON_VOTER, next=11, gen=25]
6.285ms 0.139ms event:kv/kvclient/kvcoord/dist_sender.go:2051 [n1,client=127.0.0.1:46960,user=root,txn=a8f00682] routing to nearest replica; leaseholder not required
6.887ms 0.602ms event:kv/kvclient/kvcoord/dist_sender.go:2109 [n1,client=127.0.0.1:46960,user=root,txn=a8f00682] r63: sending batch 1 Get to (n1,s1):1
6.968ms 0.081ms event:rpc/nodedialer/nodedialer.go:157 [n1,client=127.0.0.1:46960,user=root,txn=a8f00682] sending request to local client
7.030ms 0.061ms === operation:/cockroach.roachpb.Internal/Batch _verbose:1 node:1 span.kind:server request:Get [/Table/108/1/1/0,/Min), [txn: a8f00682], [can-forward-ts]
7.189ms 0.159ms event:server/node.go:1171 [n1] node received request: 1 Get
7.394ms 0.205ms event:kv/kvserver/store_send.go:167 [n1,s1] executing Get [/Table/108/1/1/0,/Min), [txn: a8f00682], [can-forward-ts]
7.573ms 0.179ms event:kv/kvserver/replica_send.go:179 [n1,s1,r63/1:/{Table/108-Max}] read-only path
7.691ms 0.119ms event:kv/kvserver/concurrency/concurrency_manager.go:194 [n1,s1,r63/1:/{Table/108-Max}] sequencing request
7.749ms 0.058ms event:kv/kvserver/concurrency/concurrency_manager.go:275 [n1,s1,r63/1:/{Table/108-Max}] acquiring latches
7.838ms 0.089ms event:kv/kvserver/concurrency/concurrency_manager.go:319 [n1,s1,r63/1:/{Table/108-Max}] scanning lock table for conflicting locks
8.109ms 0.270ms event:kv/kvserver/replica_follower_read.go:127 [n1,s1,r63/1:/{Table/108-Max}] serving via follower read; query timestamp below closed timestamp by 141.121822ms
8.292ms 0.183ms event:kv/kvserver/replica_read.go:296 [n1,s1,r63/1:/{Table/108-Max}] can drop latches early for batch (Get [/Table/108/1/1/0,/Min), [txn: a8f00682], [can-forward-ts]); scanning lock table first to detect conflicts
8.432ms 0.140ms event:kv/kvserver/replica_read.go:113 [n1,s1,r63/1:/{Table/108-Max}] lock table scan complete without conflicts; dropping latches early
8.562ms 0.130ms event:kv/kvserver/replica_read.go:408 [n1,s1,r63/1:/{Table/108-Max}] executing read-only batch
8.957ms 0.395ms event:kv/kvserver/replica_evaluate.go:550 [n1,s1,r63/1:/{Table/108-Max}] evaluated Get command header:<key:"\364\211\211\210" > , txn="sql txn" meta={id=a8f00682 key=/Min pri=0.00520204 epo=0 ts=1681452512.813048908,0 min=1681452512.813048908,0 seq=0} lock=false stat=PENDING rts=1681452512.813048908,0 wto=false gul=1681452513.313048908,0 : resp=header:<num_keys:1 num_bytes:7 > value:<raw_bytes:"\375\311[\010\n#\002" timestamp:<wall_time:1681452499775152626 > > , err=<nil>
9.078ms 0.121ms event:scan stats: stepped 0 times (0 internal); seeked 1 times (1 internal); block-bytes: (total 3.7 KiB, cached 3.7 KiB); points: (count 1 , key-bytes 14 B, value-bytes 14 B, tombstoned: 0 ) ranges: (count 0 ), (contained-points 0 , skipped-points 0 ) evaluated requests: 1 gets, 0 scans, 0 reverse scans
9.257ms 0.179ms event:kv/kvserver/replica_read.go:221 [n1,s1,r63/1:/{Table/108-Max}] read completed
9.325ms 0.068ms event:kv/kvserver/replica_send.go:321 [n1,s1,r63/1:/{Table/108-Max}] client had stale range info; returning an update
8.993ms -0.332ms structured:{"@type":"type.googleapis.com/cockroach.roachpb.ScanStats","numInterfaceSeeks":"1","numInternalSeeks":"1","numInterfaceSteps":"0","numInternalSteps":"0","blockBytes":"3786","blockBytesInCache":"3786","keyBytes":"14","valueBytes":"14","pointCount":"1","pointsCoveredByRangeTombstones":"0","rangeKeyCount":"0","rangeKeyContainedPoints":"0","rangeKeySkippedPoints":"0","separatedPointCount":"0","separatedPointValueBytes":"0","separatedPointValueBytesFetched":"0","numGets":"1","numScans":"0","numReverseScans":"0"}
9.818ms 2.849ms event:kv/kvclient/kvcoord/dist_sender.go:2238 [n1,client=127.0.0.1:46960,user=root,txn=a8f00682] received updated range info: [desc: r63:/{Table/108-Max} [(n1,s1):1, (n2,s2):5, (n3,s3):9, (n4,s4):6NON_VOTER, (n5,s5):10NON_VOTER, next=11, gen=25], lease: repl=(n2,s2):5 seq=3 start=1681452512.683300499,0 epo=1 pro=1681452512.706779630,0, closed_timestamp_policy: LEAD_FOR_GLOBAL_READS]
9.990ms 0.172ms event:kv/kvclient/rangecache/range_cache.go:1083 [n1,client=127.0.0.1:46960,user=root,txn=a8f00682] evict cached descriptor: desc=desc:r63:/{Table/108-Max} [(n1,s1):1, (n2,s2):5, (n3,s3):9, (n4,s4):6NON_VOTER, (n5,s5):10NON_VOTER, next=11, gen=25], lease:repl=(n2,s2):5 seq=2 start=1681452512.683300499,0 exp=1681452518.681706531,0 pro=1681452512.681706531,0
10.046ms 0.056ms event:kv/kvclient/rangecache/range_cache.go:594 [n1,client=127.0.0.1:46960,user=root,txn=a8f00682] evicting cached range descriptor with 1 replacements
10.123ms 0.077ms event:kv/kvclient/rangecache/range_cache.go:1252 [n1,client=127.0.0.1:46960,user=root,txn=a8f00682] clearing entries overlapping r63:/{Table/108-Max} [(n1,s1):1, (n2,s2):5, (n3,s3):9, (n4,s4):6NON_VOTER, (n5,s5):10NON_VOTER, next=11, gen=25]
10.408ms 4.779ms event:kv/kvclient/kvcoord/txn_interceptor_span_refresher.go:576 [n1,client=127.0.0.1:46960,user=root,txn=a8f00682] recording span to refresh: /Table/108/1/1/0
12.773ms 8.352ms event:sql/conn_executor_exec.go:963 [n1,client=127.0.0.1:46960,user=root] execution ends
12.824ms 0.050ms event:sql/conn_executor_exec.go:963 [n1,client=127.0.0.1:46960,user=root] rows affected: 1
14.269ms 1.445ms === operation:commit sql txn _verbose:1 node:1 client:127.0.0.1:46960 user:root
14.697ms 1.873ms event:sql/conn_executor_exec.go:2724 [n1,client=127.0.0.1:46960,user=root] AutoCommit. err: <nil>
ccl/multiregionccl.TestMultiRegionDataDriven failed with artifacts on release-23.1.0 @ 5e9f0c062e6b166b76148f7a6e10c2f509658d37:
Parameters:
TAGS=bazel,gss,deadlockHelp
See also: [How To Investigate a Go Test Failure \(internal\)](https://cockroachlabs.atlassian.net/l/c/HgfXfJgM)
Same failure on other branches
- #99563 ccl/multiregionccl: TestMultiRegionDataDriven failed [C-test-failure O-robot T-sql-schema branch-release-23.1] - #98020 ccl/multiregionccl: TestMultiRegionDataDriven failed [C-test-failure O-robot T-cluster-observability branch-master skipped-test] - #92235 ccl/multiregionccl: TestMultiRegionDataDriven failed [C-test-failure O-robot T-sql-sessions branch-release-22.2 skipped-test]
/cc @cockroachdb/sql-schema
This test on roachdash | Improve this report!
Jira issue: CRDB-26987