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

Flaky test: data race found in TestRevisionNotFallBack #4549

Closed
Tracked by #2246
CharlesCheung96 opened this issue Feb 10, 2022 · 1 comment · Fixed by #4551
Closed
Tracked by #2246

Flaky test: data race found in TestRevisionNotFallBack #4549

CharlesCheung96 opened this issue Feb 10, 2022 · 1 comment · Fixed by #4551
Assignees
@asddongmen
Labels
affects-5.4 This bug affects the 5.4.x(LTS) versions. area/ticdc Issues or PRs related to TiCDC. component/test Unit tests and integration tests component. severity/minor type/bug The issue is confirmed as a bug.

Comments

@CharlesCheung96
Copy link
Contributor

Which jobs are flaking?

unit_test_in_verify_ci

Which test(s) are flaking?

pkg/etcd TestRevisionNotFallBack

Jenkins logs or GitHub Actions link

[2022-02-09T16:24:53.494Z] === Failed

[2022-02-09T16:24:53.494Z] === FAIL: pkg/etcd TestRevisionNotFallBack (0.04s)

[2022-02-09T16:24:53.494Z] [2022/02/10 00:22:44.145 +08:00] [WARN] [client.go:262] ["etcd client watchCh blocking too long, reset the watchCh"] [duration=10s] [stack="github.com/pingcap/tiflow/pkg/etcd.(*Client).WatchWithChan\n\t/home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client.go:264\ngithub.com/pingcap/tiflow/pkg/etcd.TestRevisionNotFallBack.func2\n\t/home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client_test.go:297"] [role=]

[2022-02-09T16:24:53.494Z] [2022/02/10 00:22:44.156 +08:00] [WARN] [client.go:262] ["etcd client watchCh blocking too long, reset the watchCh"] [duration=10s] [stack="github.com/pingcap/tiflow/pkg/etcd.(*Client).WatchWithChan\n\t/home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client.go:264\ngithub.com/pingcap/tiflow/pkg/etcd.TestRevisionNotFallBack.func2\n\t/home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client_test.go:297"] [role=]

[2022-02-09T16:24:53.494Z] [2022/02/10 00:22:44.167 +08:00] [WARN] [client.go:262] ["etcd client watchCh blocking too long, reset the watchCh"] [duration=10s] [stack="github.com/pingcap/tiflow/pkg/etcd.(*Client).WatchWithChan\n\t/home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client.go:264\ngithub.com/pingcap/tiflow/pkg/etcd.TestRevisionNotFallBack.func2\n\t/home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client_test.go:297"] [role=]

[2022-02-09T16:24:53.494Z] ==================

[2022-02-09T16:24:53.494Z] WARNING: DATA RACE

[2022-02-09T16:24:53.494Z] Read at 0x00c000c1f0b8 by goroutine 67:

[2022-02-09T16:24:53.494Z]   github.com/pingcap/tiflow/pkg/etcd.TestRevisionNotFallBack()

[2022-02-09T16:24:53.494Z]       /home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client_test.go:304 +0x70b

[2022-02-09T16:24:53.494Z]   testing.tRunner()

[2022-02-09T16:24:53.494Z]       /usr/local/go/src/testing/testing.go:1193 +0x202

[2022-02-09T16:24:53.494Z] 

[2022-02-09T16:24:53.494Z] Previous write at 0x00c000c1f0b8 by goroutine 69:

[2022-02-09T16:24:53.494Z]   github.com/pingcap/tiflow/pkg/etcd.mockWatcher.Watch()

[2022-02-09T16:24:53.494Z]       /home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client_test.go:60 +0x72

[2022-02-09T16:24:53.494Z]   github.com/pingcap/tiflow/pkg/etcd.(*mockWatcher).Watch()

[2022-02-09T16:24:53.494Z]       <autogenerated>:1 +0x124

[2022-02-09T16:24:53.495Z]   github.com/pingcap/tiflow/pkg/etcd.(*Client).WatchWithChan()

[2022-02-09T16:24:53.495Z]       /home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client.go:270 +0x12e1

[2022-02-09T16:24:53.495Z]   github.com/pingcap/tiflow/pkg/etcd.TestRevisionNotFallBack.func2()

[2022-02-09T16:24:53.495Z]       /home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client_test.go:297 +0x135

[2022-02-09T16:24:53.495Z] 

[2022-02-09T16:24:53.495Z] Goroutine 67 (running) created at:

[2022-02-09T16:24:53.495Z]   testing.(*T).Run()

[2022-02-09T16:24:53.495Z]       /usr/local/go/src/testing/testing.go:1238 +0x5d7

[2022-02-09T16:24:53.495Z]   testing.runTests.func1()

[2022-02-09T16:24:53.495Z]       /usr/local/go/src/testing/testing.go:1511 +0xa6

[2022-02-09T16:24:53.495Z]   testing.tRunner()

[2022-02-09T16:24:53.495Z]       /usr/local/go/src/testing/testing.go:1193 +0x202

[2022-02-09T16:24:53.495Z]   testing.runTests()

[2022-02-09T16:24:53.495Z]       /usr/local/go/src/testing/testing.go:1509 +0x612

[2022-02-09T16:24:53.495Z]   testing.(*M).Run()

[2022-02-09T16:24:53.495Z]       /usr/local/go/src/testing/testing.go:1417 +0x3b3

[2022-02-09T16:24:53.495Z]   go.uber.org/goleak.VerifyTestMain()

[2022-02-09T16:24:53.495Z]       /go/pkg/mod/go.uber.org/[email protected]/testmain.go:53 +0x5e

[2022-02-09T16:24:53.495Z]   github.com/pingcap/tiflow/pkg/leakutil.SetUpLeakTest()

[2022-02-09T16:24:53.495Z]       /home/jenkins/agent/workspace/ut-check/tiflow/pkg/leakutil/leak_helper.go:32 +0x170

[2022-02-09T16:24:53.495Z]   github.com/pingcap/tiflow/pkg/etcd.TestMain()

[2022-02-09T16:24:53.495Z]       /home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/main_test.go:23 +0x384

[2022-02-09T16:24:53.495Z]   main.main()

[2022-02-09T16:24:53.495Z]       _testmain.go:135 +0x369

[2022-02-09T16:24:53.495Z] 

[2022-02-09T16:24:53.495Z] Goroutine 69 (running) created at:

[2022-02-09T16:24:53.495Z]   github.com/pingcap/tiflow/pkg/etcd.TestRevisionNotFallBack()

[2022-02-09T16:24:53.495Z]       /home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client_test.go:296 +0x6b6

[2022-02-09T16:24:53.495Z]   testing.tRunner()

[2022-02-09T16:24:53.495Z]       /usr/local/go/src/testing/testing.go:1193 +0x202

[2022-02-09T16:24:53.495Z] ==================

[2022-02-09T16:24:53.495Z] ==================

[2022-02-09T16:24:53.495Z] WARNING: DATA RACE

[2022-02-09T16:24:53.495Z] Read at 0x00c000c1f0c8 by goroutine 67:

[2022-02-09T16:24:53.495Z]   github.com/pingcap/tiflow/pkg/etcd.TestRevisionNotFallBack()

[2022-02-09T16:24:53.495Z]       /home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client_test.go:308 +0x765

[2022-02-09T16:24:53.495Z]   testing.tRunner()

[2022-02-09T16:24:53.495Z]       /usr/local/go/src/testing/testing.go:1193 +0x202

[2022-02-09T16:24:53.495Z] 

[2022-02-09T16:24:53.495Z] Previous write at 0x00c000c1f0c8 by goroutine 69:

[2022-02-09T16:24:53.495Z]   github.com/pingcap/tiflow/pkg/etcd.mockWatcher.Watch()

[2022-02-09T16:24:53.495Z]       /home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client_test.go:65 +0x1b7

[2022-02-09T16:24:53.495Z]   github.com/pingcap/tiflow/pkg/etcd.(*mockWatcher).Watch()

[2022-02-09T16:24:53.495Z]       <autogenerated>:1 +0x124

[2022-02-09T16:24:53.495Z]   github.com/pingcap/tiflow/pkg/etcd.(*Client).WatchWithChan()

[2022-02-09T16:24:53.495Z]       /home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client.go:270 +0x12e1

[2022-02-09T16:24:53.495Z]   github.com/pingcap/tiflow/pkg/etcd.TestRevisionNotFallBack.func2()

[2022-02-09T16:24:53.495Z]       /home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client_test.go:297 +0x135

[2022-02-09T16:24:53.495Z] 

[2022-02-09T16:24:53.495Z] Goroutine 67 (running) created at:

[2022-02-09T16:24:53.495Z]   testing.(*T).Run()

[2022-02-09T16:24:53.495Z]       /usr/local/go/src/testing/testing.go:1238 +0x5d7

[2022-02-09T16:24:53.495Z]   testing.runTests.func1()

[2022-02-09T16:24:53.495Z]       /usr/local/go/src/testing/testing.go:1511 +0xa6

[2022-02-09T16:24:53.495Z]   testing.tRunner()

[2022-02-09T16:24:53.495Z]       /usr/local/go/src/testing/testing.go:1193 +0x202

[2022-02-09T16:24:53.495Z]   testing.runTests()

[2022-02-09T16:24:53.495Z]       /usr/local/go/src/testing/testing.go:1509 +0x612

[2022-02-09T16:24:53.495Z]   testing.(*M).Run()

[2022-02-09T16:24:53.495Z]       /usr/local/go/src/testing/testing.go:1417 +0x3b3

[2022-02-09T16:24:53.496Z]   go.uber.org/goleak.VerifyTestMain()

[2022-02-09T16:24:53.496Z]       /go/pkg/mod/go.uber.org/[email protected]/testmain.go:53 +0x5e

[2022-02-09T16:24:53.496Z]   github.com/pingcap/tiflow/pkg/leakutil.SetUpLeakTest()

[2022-02-09T16:24:53.496Z]       /home/jenkins/agent/workspace/ut-check/tiflow/pkg/leakutil/leak_helper.go:32 +0x170

[2022-02-09T16:24:53.496Z]   github.com/pingcap/tiflow/pkg/etcd.TestMain()

[2022-02-09T16:24:53.496Z]       /home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/main_test.go:23 +0x384

[2022-02-09T16:24:53.496Z]   main.main()

[2022-02-09T16:24:53.496Z]       _testmain.go:135 +0x369

[2022-02-09T16:24:53.496Z] 

[2022-02-09T16:24:53.496Z] Goroutine 69 (running) created at:

[2022-02-09T16:24:53.496Z]   github.com/pingcap/tiflow/pkg/etcd.TestRevisionNotFallBack()

[2022-02-09T16:24:53.496Z]       /home/jenkins/agent/workspace/ut-check/tiflow/pkg/etcd/client_test.go:296 +0x6b6

[2022-02-09T16:24:53.496Z]   testing.tRunner()

[2022-02-09T16:24:53.496Z]       /usr/local/go/src/testing/testing.go:1193 +0x202

[2022-02-09T16:24:53.496Z] ==================

[2022-02-09T16:24:53.496Z]     testing.go:1092: race detected during execution of test

[2022-02-09T16:24:53.496Z] 

[2022-02-09T16:24:53.496Z] DONE 652 tests, 1 failure in 580.485s

[2022-02-09T16:24:56.024Z] make: *** [unit_test_in_verify_ci] Error 1

Details: https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/1134/pipeline/

Anything else we need to know

  • Does this test exist for other branches as well?

  • Has there been a high frequency of failure lately?
@CharlesCheung96 CharlesCheung96 added the component/test Unit tests and integration tests component. label Feb 10, 2022
@CharlesCheung96 CharlesCheung96 mentioned this issue Feb 10, 2022
Closed
@CharlesCheung96 CharlesCheung96 added the area/ticdc Issues or PRs related to TiCDC. label Feb 10, 2022
@asddongmen asddongmen mentioned this issue Feb 10, 2022
Merged
@asddongmen asddongmen added type/bug The issue is confirmed as a bug. severity/minor labels Feb 10, 2022
@overvenus overvenus mentioned this issue Feb 11, 2022
Closed
ti-chi-bot pushed a commit that referenced this issue Feb 13, 2022
@asddongmen
etcd (ticdc): fix a data race in unit test (#4551)
fc3b5ad 
close #4549
This was referenced Feb 13, 2022
Merged
Closed
Closed
Closed
Closed
zhaoxinyu pushed a commit to zhaoxinyu/ticdc that referenced this issue Feb 16, 2022
@asddongmen @zhaoxinyu
etcd (ticdc): fix a data race in unit test (pingcap#4551)
15cd2aa 
close pingcap#4549
@asddongmen asddongmen mentioned this issue Apr 13, 2022
Merged
@nongfushanquan
Copy link
Contributor

/label affects-5.4

@ti-chi-bot ti-chi-bot added the affects-5.4 This bug affects the 5.4.x(LTS) versions. label Jun 21, 2022
ti-chi-bot added a commit that referenced this issue Jun 22, 2022
@ti-chi-bot
etcd (ticdc): fix a data race in unit test (#4551) (#4576)
601781b 
close #4549
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@asddongmen asddongmen

Labels
affects-5.4 This bug affects the 5.4.x(LTS) versions. area/ticdc Issues or PRs related to TiCDC. component/test Unit tests and integration tests component. severity/minor type/bug The issue is confirmed as a bug.
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

etcd (ticdc): fix a data race in unit test asddongmen/tiflow
4 participants
@asddongmen @CharlesCheung96 @ti-chi-bot @nongfushanquan