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

roachtest: copyfrom/crdb-atomic/sf=1/nodes=1 failed #106142

Closed
cockroach-teamcity opened this issue Jul 5, 2023 · 2 comments
Closed

roachtest: copyfrom/crdb-atomic/sf=1/nodes=1 failed #106142

cockroach-teamcity opened this issue Jul 5, 2023 · 2 comments
Labels
branch-release-23.1 Used to mark GA and release blockers, technical advisories, and bugs for 23.1 C-test-failure Broken test (automatically or manually discovered). O-roachtest 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-queries SQL Queries Team
Milestone

Comments

@cockroach-teamcity
Copy link
Member

cockroach-teamcity commented Jul 5, 2023

roachtest.copyfrom/crdb-atomic/sf=1/nodes=1 failed with artifacts on release-23.1 @ f1108313b2b51ffab176b6b230bcc15b0259f170:

(copyfrom.go:92).runTest: COMMAND_PROBLEM: exit status 1
(monitor.go:137).Wait: monitor failure: monitor task failed: t.Fatal() was called
test artifacts and logs in: /artifacts/copyfrom/crdb-atomic/sf=1/nodes=1/run_1

Parameters: ROACHTEST_arch=amd64 , ROACHTEST_cloud=gce , ROACHTEST_cpu=4 , ROACHTEST_encrypted=false , ROACHTEST_ssd=0

Help

See: roachtest README

See: How To Investigate (internal)

/cc @cockroachdb/sql-queries

This test on roachdash | Improve this report!

Jira issue: CRDB-29425

@cockroach-teamcity cockroach-teamcity added branch-release-23.1 Used to mark GA and release blockers, technical advisories, and bugs for 23.1 C-test-failure Broken test (automatically or manually discovered). O-roachtest 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. labels Jul 5, 2023
@cockroach-teamcity cockroach-teamcity added this to the 23.1 milestone Jul 5, 2023
@blathers-crl blathers-crl bot added the T-sql-queries SQL Queries Team label Jul 5, 2023
@msirek
Copy link
Contributor

msirek commented Jul 5, 2023

Is this a possible interaction issue between COPY and autostats?

I230705 09:21:39.525445 3849 sql/stats/automatic_stats.go:910 ⋮ [T1,n1] 334  automatically executing ‹"CREATE STATISTICS __auto__ FROM [104] WITH OPTIONS THROTTLING 0.9 AS OF SYSTEM TIME '-30s'"›
I230705 09:21:39.556870 10285 jobs/registry.go:1588 â‹® [T1,n1] 335  AUTO CREATE STATS job 879750347258757121: stepping through state running
I230705 09:21:40.246488 195 kv/kvserver/store_raft.go:656 ⋮ [T1,n1,s1,r64/1:‹/{Table/104-Max}›,raft] 336  raft ready handling: 1.26s [append=0.00s, apply=1.14s, commit-batch=0.00s, other=0.12s], wrote 49 B [apply=46 MiB (1)] pebble stats: [commit-wait 56ns sem 586ns]; node might be overloaded
I230705 09:21:43.452037 192 kv/kvserver/store_raft.go:656 ⋮ [T1,n1,s1,r64/1:‹/{Table/104-Max}›,raft] 337  raft ready handling: 1.10s [append=0.00s, apply=1.03s, commit-batch=0.00s, other=0.07s], wrote 49 B [apply=46 MiB (1)] pebble stats: [commit-wait 85ns sem 1.192µs]; node might be overloaded
I230705 09:21:46.716150 199 kv/kvserver/store_raft.go:656 ⋮ [T1,n1,s1,r64/1:‹/{Table/104-Max}›,raft] 338  raft ready handling: 1.03s [append=0.00s, apply=0.99s, commit-batch=0.00s, other=0.04s], wrote 49 B [apply=46 MiB (1)] pebble stats: [commit-wait 49ns sem 657ns]; node might be overloaded
I230705 09:21:49.661318 198 kv/kvserver/queue.go:614 ⋮ [T1,n1,s1,r48/1:‹/Table/4{6-7}›,raft] 339  rate limited in MaybeAdd (merge): throttled on async limiting semaphore
I230705 09:21:49.911770 192 kv/kvserver/store_raft.go:656 ⋮ [T1,n1,s1,r64/1:‹/{Table/104-Max}›,raft] 340  raft ready handling: 1.05s [append=0.00s, apply=0.94s, commit-batch=0.00s, other=0.11s], wrote 49 B [apply=46 MiB (1)] pebble stats: [commit-wait 72ns sem 1.072µs]; node might be overloaded
I230705 09:21:53.408200 196 kv/kvserver/store_raft.go:656 ⋮ [T1,n1,s1,r64/1:‹/{Table/104-Max}›,raft] 341  raft ready handling: 1.23s [append=0.00s, apply=1.14s, commit-batch=0.00s, other=0.09s], wrote 49 B [apply=46 MiB (1)] pebble stats: [commit-wait 62ns sem 924ns]; node might be overloaded
I230705 09:21:55.500553 11541 kv/kvserver/replica_command.go:438 ⋮ [T1,n1,split,s1,r64/1:‹/{Table/104-Max}›] 342  initiating a split of this range at key /Table/104/8/‹8359›/‹294208›/‹4› [r65] (‹515 MiB above threshold size 512 MiB›)‹›
W230705 09:21:56.255533 190 go.etcd.io/raft/v3/raft.go:767 ⋮ [T1,n1,s1,r64/1:‹/{Table/104-Max}›] 343  1 appending new entries to log would exceed uncommitted entry size limit; dropping proposal
I230705 09:21:56.291232 196 kv/kvserver/queue.go:614 ⋮ [T1,n1,s1,r12/1:‹/Table/{8-11}›,raft] 344  rate limited in MaybeAdd (merge): throttled on async limiting semaphore
I230705 09:21:57.180292 194 kv/kvserver/store_raft.go:656 ⋮ [T1,n1,s1,r64/1:‹/{Table/104-Max}›,raft] 345  raft ready handling: 0.90s [append=0.00s, apply=0.85s, commit-batch=0.00s, other=0.06s], wrote 49 B [apply=46 MiB (1)] pebble stats: [commit-wait 77ns sem 1.309µs]; node might be overloaded
I230705 09:22:00.135618 11942 kv/kvserver/replica_range_lease.go:1462 ⋮ [T1,n1,replicate,s1,r64/1:‹/Table/104{-/8/8359…}›] 346  extending lease repl=(n1,s1):1 seq=1 start=0,0 exp=1688548922.171193886,0 pro=1688548916.171193886,0 at 1688548920.135611785,0
I230705 09:22:01.769249 203 kv/kvserver/store_raft.go:656 ⋮ [T1,n1,s1,r65/1:‹/{Table/104/8/…-Max}›,raft] 347  raft ready handling: 0.54s [append=0.00s, apply=0.52s, commit-batch=0.00s, other=0.02s], wrote 49 B [apply=24 MiB (1)] pebble stats: [commit-wait 77ns sem 585ns]; node might be overloaded
E230705 09:22:02.248528 3874 9@sql/conn_executor.go:2952 ⋮ [T1,n1,client=10.142.0.30:37984,hostnossl,user=‹importer›] 348  error executing ‹CopyIn: COPY lineitem FROM STDIN WITH (FORMAT CSV, DELIMITER '|')›: TransactionRetryWithProtoRefreshError: TransactionAbortedError(ABORT_REASON_CLIENT_REJECT): "sql txn" meta={id=5897626e key=/Table/104/1/‹1›/‹1›/‹0› pri=0.03102594 epo=0 ts=1688548917.136021091,2 min=1688548866.079097776,0 seq=4891392} lock=true stat=PENDING rts=1688548910.753557859,2 wto=false gul=1688548866.579097776,0
E230705 09:22:02.248528 3874 9@sql/conn_executor.go:2952 ⋮ [T1,n1,client=10.142.0.30:37984,hostnossl,user=‹importer›] 348 +(1)
E230705 09:22:02.248528 3874 9@sql/conn_executor.go:2952 ⋮ [T1,n1,client=10.142.0.30:37984,hostnossl,user=‹importer›] 348 +Wraps: (2) TransactionRetryWithProtoRefreshError: TransactionAbortedError(ABORT_REASON_CLIENT_REJECT): "sql txn" meta={id=5897626e key=/Table/104/1/‹1›/‹1›/‹0› pri=0.03102594 epo=0 ts=1688548917.136021091,2 min=1688548866.079097776,0 seq=4891392} lock=true stat=PENDING rts=1688548910.753557859,2 wto=false gul=1688548866.579097776,0
E230705 09:22:02.248528 3874 9@sql/conn_executor.go:2952 ⋮ [T1,n1,client=10.142.0.30:37984,hostnossl,user=‹importer›] 348 +Error types: (1) *colexecerror.notInternalError (2) *kvpb.TransactionRetryWithProtoRefreshError

A range split is also occurring here:

I230705 09:21:55.500553 11541 kv/kvserver/replica_command.go:438 ⋮ [T1,n1,split,s1,r64/1:‹/{Table/104-Max}›] 342  initiating a split of this range at key /Table/104/8/‹8359›/‹294208›/‹4› [r65] (‹515 MiB above threshold size 512 MiB›)‹›

@cucaroach
Copy link
Contributor

dup of #90656

@mgartner mgartner moved this to Done in SQL Queries Jul 24, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
branch-release-23.1 Used to mark GA and release blockers, technical advisories, and bugs for 23.1 C-test-failure Broken test (automatically or manually discovered). O-roachtest 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-queries SQL Queries Team
Projects
Archived in project
Development

No branches or pull requests

3 participants