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.

Sign up for GitHub

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

Jump to bottom

sql/catalog/lease: TestTxnObeysTableModificationTime failed [liveness failure caused jobs failure] #107159

Closed
cockroach-teamcity opened this issue Jul 19, 2023 · 9 comments · Fixed by #107993
Closed

sql/catalog/lease: TestTxnObeysTableModificationTime failed [liveness failure caused jobs failure] #107159

cockroach-teamcity opened this issue Jul 19, 2023 · 9 comments · Fixed by #107993
Assignees
@Xiang-Gu
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-robot Originated from a bot. T-sql-foundations SQL Foundations Team (formerly SQL Schema + SQL Sessions)
Milestone
23.1

Comments

@cockroach-teamcity
Copy link
Member

cockroach-teamcity commented Jul 19, 2023 •
edited by cockroach-jira-scripts
Loading

sql/catalog/lease.TestTxnObeysTableModificationTime failed with artifacts on release-23.1 @ 207e4959d30012b2887f31f32d3fdaea630496b9:

W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	github.com/cockroachdb/cockroach/pkg/kv/db.go:927
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | github.com/cockroachdb/cockroach/pkg/kv.(*DB).Txn
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	github.com/cockroachdb/cockroach/pkg/kv/db.go:902
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | github.com/cockroachdb/cockroach/pkg/sql.(*InternalDB).txn
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	github.com/cockroachdb/cockroach/pkg/sql/internal.go:1686
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | github.com/cockroachdb/cockroach/pkg/sql.(*InternalDB).Txn
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	github.com/cockroachdb/cockroach/pkg/sql/internal.go:1621
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | github.com/cockroachdb/cockroach/pkg/sql/gcjob.persistProgress
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	github.com/cockroachdb/cockroach/pkg/sql/gcjob/gc_job_utils.go:281
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | github.com/cockroachdb/cockroach/pkg/sql/gcjob.schemaChangeGCResumer.deleteDataAndWaitForGC
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	github.com/cockroachdb/cockroach/pkg/sql/gcjob/gc_job.go:333
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | github.com/cockroachdb/cockroach/pkg/sql/gcjob.schemaChangeGCResumer.Resume
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	github.com/cockroachdb/cockroach/pkg/sql/gcjob/gc_job.go:314
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | github.com/cockroachdb/cockroach/pkg/jobs.(*Registry).stepThroughStateMachine.func2
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	github.com/cockroachdb/cockroach/pkg/jobs/registry.go:1628
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | github.com/cockroachdb/cockroach/pkg/jobs.(*Registry).stepThroughStateMachine
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	github.com/cockroachdb/cockroach/pkg/jobs/registry.go:1629
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | github.com/cockroachdb/cockroach/pkg/jobs.(*Registry).runJob
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	github.com/cockroachdb/cockroach/pkg/jobs/adopt.go:474
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | github.com/cockroachdb/cockroach/pkg/jobs.(*Registry).resumeJob.func2
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	github.com/cockroachdb/cockroach/pkg/jobs/adopt.go:388
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | [...repeated from below...]
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +Wraps: (6) failed to read query result
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +Wraps: (7) candidate pg code: 57014
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +Wraps: (8) attached stack trace
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  -- stack trace:
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | github.com/cockroachdb/cockroach/pkg/util/cancelchecker.init
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	github.com/cockroachdb/cockroach/pkg/util/cancelchecker/cancel_checker.go:80
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | runtime.doInit
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	GOROOT/src/runtime/proc.go:6349
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | runtime.doInit
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	GOROOT/src/runtime/proc.go:6326
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | runtime.doInit
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	GOROOT/src/runtime/proc.go:6326
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | runtime.doInit
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	GOROOT/src/runtime/proc.go:6326
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | runtime.doInit
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	GOROOT/src/runtime/proc.go:6326
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | runtime.doInit
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	GOROOT/src/runtime/proc.go:6326
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | runtime.main
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	GOROOT/src/runtime/proc.go:233
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | runtime.goexit
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +  | 	GOROOT/src/runtime/asm_amd64.s:1594
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +Wraps: (9) query execution canceled
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433 +Error types: (1) *withstack.withStack (2) *errutil.withPrefix (3) *withstack.withStack (4) *errutil.withPrefix (5) *withstack.withStack (6) *errutil.withPrefix (7) *pgerror.withCandidateCode (8) *withstack.withStack (9) *errutil.leafError
I230719 09:54:18.446704 81233 server/server_controller_orchestration.go:263  [T1,n1] 5434  server controller shutting down ungracefully
I230719 09:54:18.446745 81233 server/server_controller_orchestration.go:274  [T1,n1] 5435  waiting for tenant servers to report stopped
W230719 09:54:18.446814 81233 server/server_sql.go:1704  [T1,n1] 5436  server shutdown without a prior graceful drain
--- FAIL: TestTxnObeysTableModificationTime (1.79s)

Parameters: TAGS=bazel,gss

Help

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

/cc @cockroachdb/sql-foundations

This test on roachdash | Improve this report!

Jira issue: CRDB-29922
@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-robot Originated from a bot. T-sql-foundations SQL Foundations Team (formerly SQL Schema + SQL Sessions) labels Jul 19, 2023
@cockroach-teamcity cockroach-teamcity added this to the 23.1 milestone Jul 19, 2023
@rafiss
Copy link
Collaborator

rafiss commented Jul 20, 2023 

W230719 09:54:18.441643 93802 kv/kvserver/intentresolver/intent_resolver.go:826  [-] 5423  failed to gc transaction record: could not GC completed transaction anchored at /Table/53/1/883720383116476417/"legacy_progress": node unavailable; try another peer
W230719 09:54:18.441777 93868 1@sql/event_log.go:659  [T1,n1,client=127.0.0.1:39146,hostssl,user=root] 5424  unable to save 1 entries to system.eventlog: log-event: failed to read query result: query execution canceled
W230719 09:54:18.442254 81855 sql/sqlliveness/slinstance/slinstance.go:334  [T1,n1] 5425  exiting heartbeat loop
W230719 09:54:18.442342 81855 sql/sqlliveness/slinstance/slinstance.go:321  [T1,n1] 5426  exiting heartbeat loop with error: node unavailable; try another peer
E230719 09:54:18.442375 81855 server/server_sql.go:509  [T1,n1] 5427  failed to run update of instance with new session ID: node unavailable; try another peer
E230719 09:54:18.442443 88761 jobs/registry.go:989  [T1,n1] 5428  error getting live session: node unavailable; try another peer
I230719 09:54:18.442494 81795 rpc/context.go:2318  [T1,n1,rnode=1,raddr=127.0.0.1:45015,class=default,rpc] 5429  connection heartbeat loop ended with err: <nil>
I230719 09:54:18.442845 82036 sql/stats/automatic_stats.go:612  [T1,n1] 5430  quiescing stats garbage collector
I230719 09:54:18.442896 82835 jobs/registry.go:1588  [T1,n1] 5431  AUTO SPAN CONFIG RECONCILIATION job 883720378150125569: stepping through state succeeded
I230719 09:54:18.443106 81584 server/start_listen.go:103  [T1,n1] 5432  server shutting down: instructing cmux to stop accepting
W230719 09:54:18.444261 93470 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=883720383116476417] 5433  failed to update job's progress payload or running status err: job 883720383116476417: select-job: failed to read query result: query execution canceled

I'm moving this to the KV team since they have been working on liveness related failures.

@rafiss rafiss changed the title sql/catalog/lease: TestTxnObeysTableModificationTime failed sql/catalog/lease: TestTxnObeysTableModificationTime failed [liveness failure caused jobs failure] Jul 20, 2023
@rafiss rafiss added T-kv KV Team and removed T-sql-foundations SQL Foundations Team (formerly SQL Schema + SQL Sessions) labels Jul 20, 2023
@knz
Copy link
Contributor

knz commented Jul 20, 2023

here too https://teamcity.cockroachdb.com/buildConfiguration/Cockroach_BazelEssentialCi/10990286?hideProblemsFromDependencies=false&hideTestsFromDependencies=false&expandBuildChangesSection=true&expandBuildTestsSection=true

@andrewbaptist andrewbaptist self-assigned this Jul 20, 2023
@joshimhoff
Copy link
Collaborator

https://teamcity.cockroachdb.com/viewLog.html?buildId=10998614&buildTypeId=Cockroach_BazelEssentialCi

@rafiss rafiss mentioned this issue Jul 21, 2023
Closed
@nvanbenschoten
Copy link
Member

I'm moving this to the KV team since they have been working on liveness related failures.

@rafiss isn't this a reference to sqlliveness, not node liveness?

@nvanbenschoten
Copy link
Member

Yes, it is. This error comes from descs.deadlineExpiredError.

None of the node unavailable or context canceled errors come before the t.Fatalf from the test, so I think they're just server shutdown artifacts.

I'm going to move this test failure and #107337 back to SQL Foundations, as there doesn't appear to be anything KV related. Please let us know if you find something in these failures that you'd like us to take a look at.

@blathers-crl blathers-crl bot added the T-sql-foundations SQL Foundations Team (formerly SQL Schema + SQL Sessions) label Jul 24, 2023
@nvanbenschoten nvanbenschoten removed the T-kv KV Team label Jul 24, 2023
@rafiss
Copy link
Collaborator

rafiss commented Jul 24, 2023

I see - sorry for the noise.

@chengxiong-ruan chengxiong-ruan mentioned this issue Jul 25, 2023
Closed
@rafiss rafiss mentioned this issue Jul 27, 2023
Merged
@rafiss
Copy link
Collaborator

rafiss commented Jul 27, 2023

failed here: https://teamcity.cockroachdb.com/buildConfiguration/Cockroach_BazelEssentialCi/11088934?hideProblemsFromDependencies=false&hideTestsFromDependencies=false&expandBuildChangesSection=true&expandBuildProblemsSection=true&expandBuildTestsSection=true

@cockroach-teamcity cockroach-teamcity mentioned this issue Jul 27, 2023
Closed
@cockroach-teamcity
Copy link
Member Author

sql/catalog/lease.TestTxnObeysTableModificationTime failed with artifacts on release-23.1 @ 4a64824134c25d6623e15ad8b3bf7627a26a65d5:

W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | github.com/cockroachdb/cockroach/pkg/kv.(*DB).TxnWithAdmissionControl
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	github.com/cockroachdb/cockroach/pkg/kv/db.go:927
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | github.com/cockroachdb/cockroach/pkg/kv.(*DB).Txn
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	github.com/cockroachdb/cockroach/pkg/kv/db.go:902
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | github.com/cockroachdb/cockroach/pkg/sql.(*InternalDB).txn
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	github.com/cockroachdb/cockroach/pkg/sql/internal.go:1686
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | github.com/cockroachdb/cockroach/pkg/sql.(*InternalDB).Txn
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	github.com/cockroachdb/cockroach/pkg/sql/internal.go:1621
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | github.com/cockroachdb/cockroach/pkg/sql/gcjob.persistProgress
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	github.com/cockroachdb/cockroach/pkg/sql/gcjob/gc_job_utils.go:281
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | github.com/cockroachdb/cockroach/pkg/sql/gcjob.schemaChangeGCResumer.deleteDataAndWaitForGC
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	github.com/cockroachdb/cockroach/pkg/sql/gcjob/gc_job.go:333
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | github.com/cockroachdb/cockroach/pkg/sql/gcjob.schemaChangeGCResumer.Resume
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	github.com/cockroachdb/cockroach/pkg/sql/gcjob/gc_job.go:314
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | github.com/cockroachdb/cockroach/pkg/jobs.(*Registry).stepThroughStateMachine.func2
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	github.com/cockroachdb/cockroach/pkg/jobs/registry.go:1628
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | github.com/cockroachdb/cockroach/pkg/jobs.(*Registry).stepThroughStateMachine
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	github.com/cockroachdb/cockroach/pkg/jobs/registry.go:1629
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | github.com/cockroachdb/cockroach/pkg/jobs.(*Registry).runJob
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	github.com/cockroachdb/cockroach/pkg/jobs/adopt.go:474
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | github.com/cockroachdb/cockroach/pkg/jobs.(*Registry).resumeJob.func2
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	github.com/cockroachdb/cockroach/pkg/jobs/adopt.go:388
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +Wraps: (6) failed to read query result
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +Wraps: (7) candidate pg code: 57014
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +Wraps: (8) attached stack trace
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  -- stack trace:
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | github.com/cockroachdb/cockroach/pkg/util/cancelchecker.init
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	github.com/cockroachdb/cockroach/pkg/util/cancelchecker/cancel_checker.go:80
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | runtime.doInit
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	GOROOT/src/runtime/proc.go:6349
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | runtime.doInit
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	GOROOT/src/runtime/proc.go:6326
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | runtime.doInit
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	GOROOT/src/runtime/proc.go:6326
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | runtime.doInit
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	GOROOT/src/runtime/proc.go:6326
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | runtime.doInit
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	GOROOT/src/runtime/proc.go:6326
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | runtime.doInit
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	GOROOT/src/runtime/proc.go:6326
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | runtime.main
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	GOROOT/src/runtime/proc.go:233
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | runtime.goexit
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +  | 	GOROOT/src/runtime/asm_arm64.s:1172
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +Wraps: (9) query execution canceled
W230728 23:57:53.543753 114084 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886434278224691201] 5596 +Error types: (1) *withstack.withStack (2) *errutil.withPrefix (3) *withstack.withStack (4) *errutil.withPrefix (5) *withstack.withStack (6) *errutil.withPrefix (7) *pgerror.withCandidateCode (8) *withstack.withStack (9) *errutil.leafError
I230728 23:57:53.547921 93516 server/server_controller_orchestration.go:268  [T1,n1] 5597  server controller shutting down ungracefully
I230728 23:57:53.547961 93516 server/server_controller_orchestration.go:279  [T1,n1] 5598  waiting for tenant servers to report stopped
W230728 23:57:53.548017 93516 server/server_sql.go:1704  [T1,n1] 5599  server shutdown without a prior graceful drain
--- FAIL: TestTxnObeysTableModificationTime (3.74s)
Help

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

Same failure on other branches

This test on roachdash | Improve this report!

@cockroach-teamcity
Copy link
Member Author

sql/catalog/lease.TestTxnObeysTableModificationTime failed with artifacts on release-23.1 @ 8b970683af4630cbb30b4c92f0be86cfadd97993:

W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/sql/internal.go:1698
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/kv.runTxn.func1
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/kv/db.go:965
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/kv.(*Txn).exec
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/kv/txn.go:928
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/kv.runTxn
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/kv/db.go:964
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/kv.(*DB).TxnWithAdmissionControl
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/kv/db.go:927
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/kv.(*DB).Txn
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/kv/db.go:902
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/sql.(*InternalDB).txn
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/sql/internal.go:1686
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/sql.(*InternalDB).Txn
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/sql/internal.go:1621
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/sql/gcjob.persistProgress
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/sql/gcjob/gc_job_utils.go:281
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/sql/gcjob.schemaChangeGCResumer.deleteDataAndWaitForGC
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/sql/gcjob/gc_job.go:333
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/sql/gcjob.schemaChangeGCResumer.Resume
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/sql/gcjob/gc_job.go:314
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/jobs.(*Registry).stepThroughStateMachine.func2
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/jobs/registry.go:1628
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/jobs.(*Registry).stepThroughStateMachine
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/jobs/registry.go:1629
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/jobs.(*Registry).runJob
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/jobs/adopt.go:474
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/jobs.(*Registry).resumeJob.func2
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/jobs/adopt.go:388
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunAsyncTaskEx.func2
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:470
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | runtime.goexit
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +  | 	GOROOT/src/runtime/asm_amd64.s:1594
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +Wraps: (2) job 886590545141465089
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +Wraps: (3) context canceled
W230729 13:12:42.355951 99564 sql/gcjob/gc_job_utils.go:299  [T1,n1,job=SCHEMA CHANGE GC id=886590545141465089] 5497 +Error types: (1) *withstack.withStack (2) *errutil.withPrefix (3) *errors.errorString
I230729 13:12:42.356293 87730 server/start_listen.go:103  [T1,n1] 5499  server shutting down: instructing cmux to stop accepting
I230729 13:12:42.356377 88770 sql/stats/automatic_stats.go:612  [T1,n1] 5500  quiescing stats garbage collector
I230729 13:12:42.356687 88142 rpc/context.go:2318  [T1,n1,rnode=1,raddr=127.0.0.1:40433,class=default,rpc] 5501  connection heartbeat loop ended with err: <nil>
W230729 13:12:42.356933 88464 sql/sqlliveness/slinstance/slinstance.go:334  [T1,n1] 5502  exiting heartbeat loop
W230729 13:12:42.356959 88464 sql/sqlliveness/slinstance/slinstance.go:321  [T1,n1] 5503  exiting heartbeat loop with error: node unavailable; try another peer
E230729 13:12:42.356982 88464 server/server_sql.go:509  [T1,n1] 5504  failed to run update of instance with new session ID: node unavailable; try another peer
I230729 13:12:42.357065 89223 jobs/registry.go:1588  [T1,n1] 5505  AUTO SPAN CONFIG RECONCILIATION job 886590541109985281: stepping through state succeeded
E230729 13:12:42.357188 89223 jobs/registry.go:989  [T1,n1] 5506  error getting live session: node unavailable; try another peer
W230729 13:12:42.362003 99564 jobs/adopt.go:518  [T1,n1] 5507  could not clear job claim: clear-job-claim: failed to send RPC: sending to all replicas failed; last error: ba: Scan [/Table/15/1/886590545141465089,/Table/15/1/886590545141465090), [txn: bf2de98b], [can-forward-ts] RPC error: node unavailable; try another peer
W230729 13:12:42.362876 94965 jobs/adopt.go:518  [T1,n1] 5508  could not clear job claim: clear-job-claim: node unavailable; try another peer
I230729 13:12:42.366838 87603 server/server_controller_orchestration.go:268  [T1,n1] 5509  server controller shutting down ungracefully
I230729 13:12:42.366873 87603 server/server_controller_orchestration.go:279  [T1,n1] 5510  waiting for tenant servers to report stopped
W230729 13:12:42.366963 87603 server/server_sql.go:1704  [T1,n1] 5511  server shutdown without a prior graceful drain
--- FAIL: TestTxnObeysTableModificationTime (1.48s)

Parameters: TAGS=bazel,gss

Help

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

Same failure on other branches

This test on roachdash | Improve this report!

@rafiss rafiss mentioned this issue Aug 2, 2023
Merged
@craig craig bot closed this as completed in c3f3951 Aug 2, 2023
@blathers-crl blathers-crl bot mentioned this issue Aug 2, 2023
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@Xiang-Gu Xiang-Gu

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-robot Originated from a bot. T-sql-foundations SQL Foundations Team (formerly SQL Schema + SQL Sessions)
Projects
None yet
Milestone
23.1
Development

Successfully merging a pull request may close this issue.

sql: Deflake TestTxnObeysTableModificationTime Xiang-Gu/cockroach
7 participants
@knz @rafiss @joshimhoff @nvanbenschoten @cockroach-teamcity @Xiang-Gu @andrewbaptist