Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ccl/multiregionccl: TestMultiRegionDataDriven failed #111158

Closed
cockroach-teamcity opened this issue Sep 23, 2023 · 1 comment
Closed

ccl/multiregionccl: TestMultiRegionDataDriven failed #111158

cockroach-teamcity opened this issue Sep 23, 2023 · 1 comment
Labels
A-testing Testing tools and infrastructure C-bug Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior. C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot. release-blocker Indicates a release-blocker. Use with branch-release-2x.x label to denote which branch is blocked. T-kv KV Team X-duplicate Closed as a duplicate of another issue.
Milestone

Comments

@cockroach-teamcity
Copy link
Member

cockroach-teamcity commented Sep 23, 2023

ccl/multiregionccl.TestMultiRegionDataDriven failed with artifacts on release-23.1.11-rc @ 62ad175cbc0e9041d993ea1cc911e07d279671f5:

             0.692ms      0.000ms            [dist sender send: {count: 1, duration 616µs}]
             0.692ms      0.000ms            [/cockroach.roachpb.Internal/Batch: {count: 1, duration 300µs}]
             0.696ms      0.004ms                === operation:colbatchscan _unfinished:1 _verbose:1 node:1 client:127.0.0.1:50638 hostssl: user:root cockroach.flowid:3ccbab62-9a39-46dc-953d-c1b34aa5a568 cockroach.processorid:0
             0.696ms      0.000ms                [txn coordinator send: {count: 1, duration 667µs}]
             0.696ms      0.000ms                [dist sender send: {count: 1, duration 616µs}]
             0.696ms      0.000ms                [/cockroach.roachpb.Internal/Batch: {count: 1, duration 300µs}]
             0.724ms      0.028ms                event:sql/row/kv_batch_fetcher.go:560 [n1,client=127.0.0.1:50638,hostssl,user=root] Scan /Table/108/1/1/0
             0.727ms      0.003ms                    === operation:txn coordinator send _verbose:1 node:1 client:127.0.0.1:50638 hostssl: user:root txnID:2bf11303-d243-4a64-9385-cde87bcaa81f
             0.727ms      0.000ms                    [dist sender send: {count: 1, duration 616µs}]
             0.727ms      0.000ms                    [/cockroach.roachpb.Internal/Batch: {count: 1, duration 300µs}]
             0.735ms      0.008ms                        === operation:dist sender send _verbose:1 node:1 client:127.0.0.1:50638 hostssl: user:root txn:2bf11303
             0.735ms      0.000ms                        [/cockroach.roachpb.Internal/Batch: {count: 1, duration 300µs}]
             0.755ms      0.020ms                        event:kv/kvclient/kvcoord/range_iter.go:188 [n1,client=127.0.0.1:50638,hostssl,user=root,txn=2bf11303] querying next range at /Table/108/1/1/0
             0.800ms      0.044ms                        event:kv/kvclient/kvcoord/range_iter.go:225 [n1,client=127.0.0.1:50638,hostssl,user=root,txn=2bf11303] key: /Table/108/1/1/0, desc: r64:/{Table/108-Max} [(n1,s1):1, (n2,s2):8, (n3,s3):5, (n5,s5):6NON_VOTER, (n4,s4):9NON_VOTER, next=10, gen=23]
             0.822ms      0.023ms                        event:kv/kvclient/kvcoord/dist_sender.go:2088 [n1,client=127.0.0.1:50638,hostssl,user=root,txn=2bf11303] routing to nearest replica; leaseholder not required
             0.857ms      0.035ms                        event:kv/kvclient/kvcoord/dist_sender.go:2146 [n1,client=127.0.0.1:50638,hostssl,user=root,txn=2bf11303] r64: sending batch 1 Get to (n1,s1):1
             0.866ms      0.009ms                        event:rpc/nodedialer/nodedialer.go:157 [n1,client=127.0.0.1:50638,hostssl,user=root,txn=2bf11303] sending request to local client
             0.874ms      0.007ms                            === operation:/cockroach.roachpb.Internal/Batch _verbose:1 node:1 span.kind:server request:Get [/Table/108/1/1/0,/Min), [txn: 2bf11303], [can-forward-ts]
             0.882ms      0.008ms                            event:server/node.go:1187 [n1] node received request: 1 Get
             0.910ms      0.029ms                            event:kv/kvserver/store_send.go:167 [n1,s1] executing Get [/Table/108/1/1/0,/Min), [txn: 2bf11303], [can-forward-ts]
             0.923ms      0.013ms                            event:kv/kvserver/replica_send.go:179 [n1,s1,r64/1:/{Table/108-Max}] read-only path
             0.934ms      0.010ms                            event:kv/kvserver/concurrency/concurrency_manager.go:208 [n1,s1,r64/1:/{Table/108-Max}] sequencing request
             0.940ms      0.006ms                            event:kv/kvserver/concurrency/concurrency_manager.go:289 [n1,s1,r64/1:/{Table/108-Max}] acquiring latches
             0.948ms      0.008ms                            event:kv/kvserver/concurrency/concurrency_manager.go:333 [n1,s1,r64/1:/{Table/108-Max}] scanning lock table for conflicting locks
             0.964ms      0.016ms                            event:kv/kvserver/replica_follower_read.go:127 [n1,s1,r64/1:/{Table/108-Max}] serving via follower read; query timestamp below closed timestamp by 258.546142ms
             0.992ms      0.028ms                            event:kv/kvserver/replica_read.go:296 [n1,s1,r64/1:/{Table/108-Max}] can drop latches early for batch (Get [/Table/108/1/1/0,/Min), [txn: 2bf11303], [can-forward-ts]); scanning lock table first to detect conflicts
             1.022ms      0.030ms                            event:kv/kvserver/replica_read.go:113 [n1,s1,r64/1:/{Table/108-Max}] lock table scan complete without conflicts; dropping latches early
             1.031ms      0.008ms                            event:kv/kvserver/replica_read.go:408 [n1,s1,r64/1:/{Table/108-Max}] executing read-only batch
             1.115ms      0.084ms                            event:kv/kvserver/replica_evaluate.go:550 [n1,s1,r64/1:/{Table/108-Max}] evaluated Get command header:<key:"\364\211\211\210" > , txn="sql txn" meta={id=2bf11303 key=/Min pri=0.02718838 epo=0 ts=1695454176.759332260,0 min=1695454176.759332260,0 seq=0} lock=false stat=PENDING rts=1695454176.759332260,0 wto=false gul=1695454177.259332260,0 : resp=header:<num_keys:1 num_bytes:7 > value:<raw_bytes:"\375\311[\010\n#\002" timestamp:<wall_time:1695454165628977143 > > , err=<nil>
             1.146ms      0.031ms                            event:scan stats: stepped 0 times (0 internal); seeked 1 times (1 internal); block-bytes: (total 4.8 KiB, cached 4.8 KiB); points: (count 1 , key-bytes 14 B, value-bytes 7 B, tombstoned: 0 ) ranges: (count 0 ), (contained-points 0 , skipped-points 0 ) evaluated requests: 1 gets, 0 scans, 0 reverse scans
             1.156ms      0.009ms                            event:kv/kvserver/replica_read.go:221 [n1,s1,r64/1:/{Table/108-Max}] read completed
             1.167ms      0.012ms                            event:kv/kvserver/replica_send.go:327 [n1,s1,r64/1:/{Table/108-Max}] client had stale range info; returning an update
             1.120ms     -0.047ms                            structured:{"@type":"type.googleapis.com/cockroach.roachpb.ScanStats","numInterfaceSeeks":"1","numInternalSeeks":"1","numInterfaceSteps":"0","numInternalSteps":"0","blockBytes":"4892","blockBytesInCache":"4892","keyBytes":"14","valueBytes":"7","pointCount":"1","pointsCoveredByRangeTombstones":"0","rangeKeyCount":"0","rangeKeyContainedPoints":"0","rangeKeySkippedPoints":"0","separatedPointCount":"0","separatedPointValueBytes":"0","separatedPointValueBytesFetched":"0","numGets":"1","numScans":"0","numReverseScans":"0"}
             1.245ms      0.379ms                        event:kv/kvclient/kvcoord/dist_sender.go:2275 [n1,client=127.0.0.1:50638,hostssl,user=root,txn=2bf11303] received updated range info: [desc: r64:/{Table/108-Max} [(n1,s1):1, (n2,s2):8, (n3,s3):5, (n5,s5):6NON_VOTER, (n4,s4):9NON_VOTER, next=10, gen=23], lease: repl=(n3,s3):5 seq=7 start=1695454176.747523201,0 epo=1 pro=1695454176.748735221,0, closed_timestamp_policy: LEAD_FOR_GLOBAL_READS]
             1.284ms      0.039ms                        event:kv/kvclient/rangecache/range_cache.go:1083 [n1,client=127.0.0.1:50638,hostssl,user=root,txn=2bf11303] evict cached descriptor: desc=desc:r64:/{Table/108-Max} [(n1,s1):1, (n2,s2):8, (n3,s3):5, (n5,s5):6NON_VOTER, (n4,s4):9NON_VOTER, next=10, gen=23], lease:repl=(n3,s3):5 seq=6 start=1695454176.747523201,0 exp=1695454182.747394342,0 pro=1695454176.747394342,0
             1.298ms      0.013ms                        event:kv/kvclient/rangecache/range_cache.go:594 [n1,client=127.0.0.1:50638,hostssl,user=root,txn=2bf11303] evicting cached range descriptor with 1 replacements
             1.344ms      0.047ms                        event:kv/kvclient/rangecache/range_cache.go:1252 [n1,client=127.0.0.1:50638,hostssl,user=root,txn=2bf11303] clearing entries overlapping r64:/{Table/108-Max} [(n1,s1):1, (n2,s2):8, (n3,s3):5, (n5,s5):6NON_VOTER, (n4,s4):9NON_VOTER, next=10, gen=23]
             1.391ms      0.664ms                    event:kv/kvclient/kvcoord/txn_interceptor_span_refresher.go:576 [n1,client=127.0.0.1:50638,hostssl,user=root,txn=2bf11303] recording span to refresh: /Table/108/1/1/0
             1.464ms      0.772ms            event:ComponentStats{ID: {3ccbab62-9a39-46dc-953d-c1b34aa5a568 PROCESSOR 0 1 }, KV time: 719µs, KV contention time: 0µs, KV rows read: 1, KV bytes read: 11 B, KV gRPC calls: 1, MVCC step count (ext/int): 0/0, MVCC seek count (ext/int): 1/1, max memory allocated: 20 KiB, sql cpu time: 15µs, batches output: 1, rows output: 1}
             1.476ms      0.012ms            event:ComponentStats{ID: {00000000-0000-0000-0000-000000000000 UNSET 0 ? }}
             1.423ms     -0.053ms            structured:{"@type":"type.googleapis.com/cockroach.sql.distsqlrun.ComponentStats","component":{"flowId":"3ccbab62-9a39-46dc-953d-c1b34aa5a568","type":"PROCESSOR","id":0,"sqlInstanceId":1,"region":""},"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.000718501s"},"contentionTime":{"valuePlusOne":"0.000000001s"},"numInterfaceSteps":{"valuePlusOne":"1"},"numInternalSteps":{"valuePlusOne":"1"},"numInterfaceSeeks":{"valuePlusOne":"2"},"numInternalSeeks":{"valuePlusOne":"2"},"blockBytes":{"valuePlusOne":"4893"},"blockBytesInCache":{"valuePlusOne":"4893"},"keyBytes":{"valuePlusOne":"15"},"valueBytes":{"valuePlusOne":"8"},"pointCount":{"valuePlusOne":"2"},"pointsCoveredByRangeTombstones":{"valuePlusOne":"1"},"rangeKeyCount":{"valuePlusOne":"1"},"rangeKeyContainedPoints":{"valuePlusOne":"1"},"rangeKeySkippedPoints":{"valuePlusOne":"1"},"kvCpuTime":{"valuePlusOne":"0s"},"numGets":{"valuePlusOne":"2"},"numScans":{"valuePlusOne":"1"},"numReverseScans":{"valuePlusOne":"1"},"usedStreamer":false},"exec":{"execTime":{"valuePlusOne":"0s"},"maxAllocatedMem":{"valuePlusOne":"20481"},"maxAllocatedDisk":{"valuePlusOne":"0"},"consumedRu":{"valuePlusOne":"1"},"cpuTime":{"valuePlusOne":"0.000015011s"}},"output":{"numBatches":{"valuePlusOne":"2"},"numTuples":{"valuePlusOne":"2"}},"inputs":[],"flowStats":{"maxMemUsage":{"valuePlusOne":"0"},"maxDiskUsage":{"valuePlusOne":"0"},"consumedRu":{"valuePlusOne":"0"}}}
             1.466ms      0.043ms            structured:{"@type":"type.googleapis.com/cockroach.sql.distsqlrun.ComponentStats","component":{"flowId":"00000000-0000-0000-0000-000000000000","type":"UNSET","id":0,"sqlInstanceId":0,"region":""},"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"},"kvCpuTime":{"valuePlusOne":"0s"},"numGets":{"valuePlusOne":"0"},"numScans":{"valuePlusOne":"0"},"numReverseScans":{"valuePlusOne":"0"},"usedStreamer":false},"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"}}}
             1.505ms      0.814ms        event:ComponentStats{ID: {3ccbab62-9a39-46dc-953d-c1b34aa5a568 FLOW 0 1 us-east-1}}
             1.496ms     -0.009ms        structured:{"@type":"type.googleapis.com/cockroach.sql.distsqlrun.ComponentStats","component":{"flowId":"3ccbab62-9a39-46dc-953d-c1b34aa5a568","type":"FLOW","id":0,"sqlInstanceId":1,"region":"us-east-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"},"kvCpuTime":{"valuePlusOne":"0s"},"numGets":{"valuePlusOne":"0"},"numScans":{"valuePlusOne":"0"},"numReverseScans":{"valuePlusOne":"0"},"usedStreamer":false},"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"}}}
             1.570ms      0.948ms    event:sql/conn_executor_exec.go:1036 [n1,client=127.0.0.1:50638,hostssl,user=root] execution ends
             1.588ms      0.018ms    event:sql/conn_executor_exec.go:1036 [n1,client=127.0.0.1:50638,hostssl,user=root] rows affected: 1
             1.686ms      0.098ms        === operation:commit sql txn _verbose:1 node:1 client:127.0.0.1:50638 hostssl: user:root
             1.729ms      0.141ms    event:sql/conn_executor_exec.go:2830 [n1,client=127.0.0.1:50638,hostssl,user=root] AutoCommit. err: <nil>
        
    --- FAIL: TestMultiRegionDataDriven/global_tables (24.52s)

Parameters: TAGS=bazel,gss

Help

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

Same failure on other branches

/cc @cockroachdb/sql-foundations

This test on roachdash | Improve this report!

Jira issue: CRDB-31793

@cockroach-teamcity cockroach-teamcity added branch-release-23.1.11-rc C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot. release-blocker Indicates a release-blocker. Use with branch-release-2x.x label to denote which branch is blocked. T-sql-foundations SQL Foundations Team (formerly SQL Schema + SQL Sessions) labels Sep 23, 2023
@cockroach-teamcity cockroach-teamcity added this to the 23.1 milestone Sep 23, 2023
@rafiss rafiss added T-kv KV Team and removed T-sql-foundations SQL Foundations Team (formerly SQL Schema + SQL Sessions) labels Sep 24, 2023
@rafiss
Copy link
Collaborator

rafiss commented Sep 24, 2023

closing as per #110631 (comment)

@rafiss rafiss closed this as completed Sep 24, 2023
@kvoli kvoli added C-bug Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior. A-testing Testing tools and infrastructure labels Sep 25, 2023
@shralex shralex added the X-duplicate Closed as a duplicate of another issue. label Nov 30, 2023
@github-project-automation github-project-automation bot moved this to Closed in KV Aug 28, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-testing Testing tools and infrastructure C-bug Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior. C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot. release-blocker Indicates a release-blocker. Use with branch-release-2x.x label to denote which branch is blocked. T-kv KV Team X-duplicate Closed as a duplicate of another issue.
Projects
No open projects
Archived in project
Archived in project
Development

No branches or pull requests

4 participants