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/gcjob_test: TestSchemaChangeGCJob failed #46767

Closed
cockroach-teamcity opened this issue Mar 31, 2020 · 1 comment · Fixed by #46792
Closed

sql/gcjob_test: TestSchemaChangeGCJob failed #46767

cockroach-teamcity opened this issue Mar 31, 2020 · 1 comment · Fixed by #46792
Assignees
@pbardea
Labels
C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.
Milestone
20.1

Comments

@cockroach-teamcity
Copy link
Member

(sql/gcjob_test).TestSchemaChangeGCJob failed on release-20.1@6a7ca722a135e21ad04daec3895535969ba5b02c:

I200331 03:45:42.359123 7390 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (raftlog): node unavailable; try another peer
I200331 03:45:42.359134 7390 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (raftsnapshot): node unavailable; try another peer
I200331 03:45:42.359145 7390 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (consistencyChecker): node unavailable; try another peer
I200331 03:45:42.359164 7390 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (timeSeriesMaintenance): node unavailable; try another peer
W200331 03:45:42.365735 7485 jobs/registry.go:1215  job 542493562108411905: canceling due to liveness failure
E200331 03:45:42.365822 10787 jobs/registry.go:946  [n1] job 542493562108411905: adoption completed with error job 542493562108411905: node liveness error: restarting in background
W200331 03:45:42.365871 10787 kv/txn.go:603  [n1] failure aborting transaction: node unavailable; try another peer; abort caused by: context canceled
E200331 03:45:42.365885 10787 jobs/registry.go:950  [n1] job 542493562108411905: failed querying status: context canceled
I200331 03:45:42.369980 85 util/stop/stopper.go:539  quiescing
I200331 03:45:42.377131 85 util/stop/stopper.go:539  quiescing
E200331 03:45:42.463945 4041 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
E200331 03:45:42.566664 4041 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
E200331 03:45:42.667451 4041 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
E200331 03:45:42.768244 4041 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
W200331 03:45:42.772205 4039 jobs/registry.go:1215  job 542493504132284417: canceling due to liveness failure
E200331 03:45:42.772632 5264 jobs/registry.go:946  [n1] job 542493504132284417: adoption completed with error job 542493504132284417: node liveness error: restarting in background
W200331 03:45:42.773281 5264 kv/txn.go:603  [n1] failure aborting transaction: node unavailable; try another peer; abort caused by: context canceled
E200331 03:45:42.773313 5264 jobs/registry.go:950  [n1] job 542493504132284417: failed querying status: context canceled
I200331 03:45:42.793620 4009 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (gc): node unavailable; try another peer
I200331 03:45:42.793707 4009 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (merge): node unavailable; try another peer
I200331 03:45:42.793722 4009 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (split): node unavailable; try another peer
I200331 03:45:42.793734 4009 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (replicate): node unavailable; try another peer
I200331 03:45:42.793745 4009 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (replicaGC): node unavailable; try another peer
I200331 03:45:42.793755 4009 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (raftlog): node unavailable; try another peer
I200331 03:45:42.793767 4009 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (raftsnapshot): node unavailable; try another peer
I200331 03:45:42.793777 4009 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (consistencyChecker): node unavailable; try another peer
I200331 03:45:42.793798 4009 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (timeSeriesMaintenance): node unavailable; try another peer
I200331 03:45:42.799274 85 util/stop/stopper.go:539  quiescing
I200331 03:45:42.847032 85 util/stop/stopper.go:539  quiescing
--- FAIL: TestSchemaChangeGCJob (66.04s)
    gc_job_test.go:196: condition failed to evaluate within 45s: query 'SELECT status FROM [SHOW JOBS] WHERE job_id = 542493562108411905': expected:
        succeeded
        
        got:
        running
        
        
        goroutine 85 [running]:
        runtime/debug.Stack(0xc00557b7d8, 0x4203e20, 0xc002766080)
        	/usr/local/go/src/runtime/debug/stack.go:24 +0x9d
        github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x42e8380, 0xc000111400, 0xc00557b7d8)
        	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x6b
        github.com/cockroachdb/cockroach/pkg/testutils/sqlutils.(*SQLRunner).CheckQueryResultsRetry(0xc00557bc48, 0x42e8380, 0xc000111400, 0xc004b63180, 0x40, 0xc004fe6400, 0x1, 0x1)
        	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/sqlutils/sql_runner.go:199 +0xde
        github.com/cockroachdb/cockroach/pkg/sql/gcjob_test_test.TestSchemaChangeGCJob(0xc000111400)
        	/go/src/github.com/cockroachdb/cockroach/pkg/sql/gcjob_test/gc_job_test.go:196 +0xfa8
        testing.tRunner(0xc000111400, 0x3c14368)
        	/usr/local/go/src/testing/testing.go:909 +0xc9
        created by testing.(*T).Run
        	/usr/local/go/src/testing/testing.go:960 +0x350
More

Parameters:

  • GOFLAGS=-json
make stressrace TESTS=TestSchemaChangeGCJob PKG=./pkg/sql/gcjob_test TESTTIMEOUT=5m STRESSFLAGS='-timeout 5m' 2>&1

See this test on roachdash
powered by pkg/cmd/internal/issues
@cockroach-teamcity cockroach-teamcity added C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot. branch-release-20.1 labels Mar 31, 2020
@cockroach-teamcity cockroach-teamcity added this to the 20.1 milestone Mar 31, 2020
@cockroach-teamcity
Copy link
Member Author

(sql/gcjob_test).TestSchemaChangeGCJob failed on release-20.1@98b80c3fa4c3105ac0ba1b2a0cb42c0d805bd873:

I200331 14:52:59.267139 9749 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (replicaGC): node unavailable; try another peer
I200331 14:52:59.267150 9749 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (raftlog): node unavailable; try another peer
I200331 14:52:59.267161 9749 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (raftsnapshot): node unavailable; try another peer
I200331 14:52:59.267171 9749 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (consistencyChecker): node unavailable; try another peer
I200331 14:52:59.267181 9749 kv/kvserver/queue.go:578  [n1,s1] rate limited in MaybeAdd (timeSeriesMaintenance): node unavailable; try another peer
E200331 14:52:59.326410 9799 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
W200331 14:52:59.334663 9797 jobs/registry.go:1215  job 542624745788342273: canceling due to liveness failure
E200331 14:52:59.334743 11196 jobs/registry.go:946  [n1] job 542624745788342273: adoption completed with error job 542624745788342273: node liveness error: restarting in background
W200331 14:52:59.334785 11196 kv/txn.go:603  [n1] failure aborting transaction: node unavailable; try another peer; abort caused by: context canceled
E200331 14:52:59.334794 11196 jobs/registry.go:950  [n1] job 542624745788342273: failed querying status: context canceled
I200331 14:52:59.343701 9 util/stop/stopper.go:539  quiescing
I200331 14:52:59.367775 9 util/stop/stopper.go:539  quiescing
I200331 14:52:59.440550 9 util/stop/stopper.go:539  quiescing
E200331 14:52:59.491979 4021 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
E200331 14:52:59.593754 4021 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
E200331 14:52:59.694578 4021 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
E200331 14:52:59.795327 4021 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
E200331 14:52:59.896200 4021 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
E200331 14:52:59.997666 4021 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
E200331 14:53:00.098408 4021 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
E200331 14:53:00.199259 4021 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
E200331 14:53:00.300274 4021 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
E200331 14:53:00.401215 4021 jobs/registry.go:500  error while adopting jobs: failed querying for jobs: adopt-job: node unavailable; try another peer
W200331 14:53:00.403331 4019 jobs/registry.go:1215  job 542624729495109633: canceling due to liveness failure
E200331 14:53:00.403416 5438 jobs/registry.go:946  [n1] job 542624729495109633: adoption completed with error job 542624729495109633: node liveness error: restarting in background
W200331 14:53:00.403466 5438 kv/txn.go:603  [n1] failure aborting transaction: node unavailable; try another peer; abort caused by: context canceled
E200331 14:53:00.403478 5438 jobs/registry.go:950  [n1] job 542624729495109633: failed querying status: context canceled
I200331 14:53:00.409201 9 util/stop/stopper.go:539  quiescing
I200331 14:53:00.417877 9 util/stop/stopper.go:539  quiescing
--- FAIL: TestSchemaChangeGCJob (57.50s)
    gc_job_test.go:196: condition failed to evaluate within 45s: query 'SELECT status FROM [SHOW JOBS] WHERE job_id = 542624755132432385': expected:
        succeeded
        
        got:
        running
        
        
        goroutine 9 [running]:
        runtime/debug.Stack(0xc0022d37d8, 0x4203e20, 0xc0071dcf80)
        	/usr/local/go/src/runtime/debug/stack.go:24 +0x9d
        github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x42e8380, 0xc000637400, 0xc0022d37d8)
        	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x6b
        github.com/cockroachdb/cockroach/pkg/testutils/sqlutils.(*SQLRunner).CheckQueryResultsRetry(0xc0022d3c48, 0x42e8380, 0xc000637400, 0xc0015dae40, 0x40, 0xc001afbea0, 0x1, 0x1)
        	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/sqlutils/sql_runner.go:199 +0xde
        github.com/cockroachdb/cockroach/pkg/sql/gcjob_test_test.TestSchemaChangeGCJob(0xc000637400)
        	/go/src/github.com/cockroachdb/cockroach/pkg/sql/gcjob_test/gc_job_test.go:196 +0xfa8
        testing.tRunner(0xc000637400, 0x3c14368)
        	/usr/local/go/src/testing/testing.go:909 +0xc9
        created by testing.(*T).Run
        	/usr/local/go/src/testing/testing.go:960 +0x350
More

Parameters:

  • GOFLAGS=-json
make stressrace TESTS=TestSchemaChangeGCJob PKG=./pkg/sql/gcjob_test TESTTIMEOUT=5m STRESSFLAGS='-timeout 5m' 2>&1

See this test on roachdash
powered by pkg/cmd/internal/issues

@pbardea pbardea mentioned this issue Mar 31, 2020
Merged
@cockroach-teamcity cockroach-teamcity mentioned this issue Mar 31, 2020
Closed
@pbardea pbardea mentioned this issue Mar 31, 2020
Merged
@craig craig bot closed this as completed in 10a05b5 Mar 31, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@pbardea pbardea

Labels
C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.
Projects
None yet
Milestone
20.1
Development

Successfully merging a pull request may close this issue.

gcjob: fix race in gc job test pbardea/cockroach
2 participants
@pbardea @cockroach-teamcity