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

unstable test etcdSuite.TestClientErrNoPendingRegion #2688

Closed
Rustin170506 opened this issue Aug 31, 2021 · 13 comments · Fixed by #3663
Closed

unstable test etcdSuite.TestClientErrNoPendingRegion #2688

Rustin170506 opened this issue Aug 31, 2021 · 13 comments · Fixed by #3663
Assignees
Labels
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

@Rustin170506
Copy link
Member

Bug Report

Please answer these questions before submitting your issue. Thanks!

  1. What did you do? If possible, provide a recipe for reproducing the error.

Run unit tests.

  1. What did you expect to see?

CI passed.

  1. What did you see instead?
[2021-08-31T06:28:51.459Z] ----------------------------------------------------------------------

[2021-08-31T06:28:51.459Z] FAIL: client_test.go:2807: etcdSuite.TestClientErrNoPendingRegion

[2021-08-31T06:28:51.459Z] 

[2021-08-31T06:28:51.459Z] client_test.go:2815:

[2021-08-31T06:28:51.459Z]     // test for client v1

[2021-08-31T06:28:51.459Z]     s.testClientErrNoPendingRegion(c)

[2021-08-31T06:28:51.459Z] client_test.go:302:

[2021-08-31T06:28:51.459Z]     c.Assert(err, check.IsNil)

[2021-08-31T06:28:51.459Z] ... value *errors.Error = &errors.Error{code:0, codeText:"CDC:ErrReachMaxTry", message:"reach maximum try: %d", redactArgsPos:[]int(nil), cause:(*errors.fundamental)(0xc0006ca3c0), args:[]interface {}{20}, file:"/home/jenkins/agent/workspace/cdc_ghpr_test/go/src/github.com/pingcap/ticdc/pkg/retry/retry_with_opt.go", line:65} ("[CDC:ErrReachMaxTry]reach maximum try: 20")

[2021-08-31T06:28:51.459Z] 

[2021-08-31T06:28:51.459Z] [2021/08/31 14:25:18.613 +08:00] [ERROR] [region_worker.go:695] ["The CommitTs must be greater than the resolvedTs"] ["Event Type"=COMMIT] [CommitTs=98] [resolvedTs=100] [regionID=3] [stack="github.com/pingcap/ticdc/cdc/kv.(*regionWorker).handleEventEntry\n\t/home/jenkins/agent/workspace/cdc_ghpr_test/go/src/github.com/pingcap/ticdc/cdc/kv/region_worker.go:695\ngit.luolix.top/pingcap/ticdc/cdc/kv.(*regionWorker).processEvent\n\t/home/jenkins/agent/workspace/cdc_ghpr_test/go/src/github.com/pingcap/ticdc/cdc/kv/region_worker.go:406\ngit.luolix.top/pingcap/ticdc/cdc/kv.(*regionWorker).eventHandler\n\t/home/jenkins/agent/workspace/cdc_ghpr_test/go/src/github.com/pingcap/ticdc/cdc/kv/region_worker.go:499\ngit.luolix.top/pingcap/ticdc/cdc/kv.(*regionWorker).run.func3\n\t/home/jenkins/agent/workspace/cdc_ghpr_test/go/src/github.com/pingcap/ticdc/cdc/kv/region_worker.go:614\ngolang.org/x/sync/errgroup.(*Group).Go.func1\n\t/nfs/cache/mod/golang.org/x/sync@v0.0.0-20210220032951-036812b2e83c/errgroup/errgroup.go:57"]
@Rustin170506 Rustin170506 added type/bug The issue is confirmed as a bug. component/test Unit tests and integration tests component. labels Aug 31, 2021
@Rustin170506
Copy link
Member Author

@Rustin170506
Copy link
Member Author

another case: https://ci2.pingcap.net/blue/organizations/jenkins/cdc_ghpr_test/detail/cdc_ghpr_test/7592/pipeline

[2021-09-14T08:09:30.278Z] ----------------------------------------------------------------------

[2021-09-14T08:09:30.278Z] FAIL: client_test.go:2806: etcdSuite.TestClientErrNoPendingRegion

[2021-09-14T08:09:30.278Z] 

[2021-09-14T08:09:30.278Z] client_test.go:2818:

[2021-09-14T08:09:30.278Z]     // test for client v2

[2021-09-14T08:09:30.278Z]     s.testClientErrNoPendingRegion(c)

[2021-09-14T08:09:30.278Z] client_test.go:301:

[2021-09-14T08:09:30.278Z]     c.Assert(err, check.IsNil)

[2021-09-14T08:09:30.278Z] ... value *errors.Error = &errors.Error{code:0, codeText:"CDC:ErrReachMaxTry", message:"reach maximum try: %d", redactArgsPos:[]int(nil), cause:(*errors.fundamental)(0xc0015b2168), args:[]interface {}{20}, file:"/home/jenkins/agent/workspace/cdc_ghpr_test/go/src/github.com/pingcap/ticdc/pkg/retry/retry_with_opt.go", line:65} ("[CDC:ErrReachMaxTry]reach maximum try: 20: request id 6 is not larger than 7")

@overvenus
Copy link
Member

Another failed case https://ci2.pingcap.net/blue/organizations/jenkins/cdc_ghpr_test/detail/cdc_ghpr_test/7687/pipeline#step-49-log-16

[2021-09-16T02:27:36.391Z] FAIL: client_test.go:2807: etcdSuite.TestClientErrNoPendingRegion

[2021-09-16T02:27:36.391Z] 

[2021-09-16T02:27:36.391Z] client_test.go:2819:

[2021-09-16T02:27:36.391Z]     // test for client v2

[2021-09-16T02:27:36.391Z]     s.testClientErrNoPendingRegion(c)

[2021-09-16T02:27:36.391Z] client_test.go:302:

[2021-09-16T02:27:36.391Z]     c.Assert(err, check.IsNil)

[2021-09-16T02:27:36.391Z] ... value *errors.Error = &errors.Error{code:0, codeText:"CDC:ErrReachMaxTry", message:"reach maximum try: %d", redactArgsPos:[]int(nil), cause:(*errors.fundamental)(0xc00000e2b8), args:[]interface {}{20}, file:"/home/jenkins/agent/workspace/cdc_ghpr_test/go/src/github.com/pingcap/ticdc/pkg/retry/retry_with_opt.go", line:65} ("[CDC:ErrReachMaxTry]reach maximum try: 20")

@asddongmen
Copy link
Contributor

FAIL: client_test.go:2807: etcdSuite.TestClientErrNoPendingRegion

[2021-09-24T09:42:00.418Z] 

[2021-09-24T09:42:00.418Z] client_test.go:2819:

[2021-09-24T09:42:00.418Z]     // test for client v2

[2021-09-24T09:42:00.418Z]     s.testClientErrNoPendingRegion(c)

[2021-09-24T09:42:00.418Z] client_test.go:302:

[2021-09-24T09:42:00.418Z]     c.Assert(err, check.IsNil)

[2021-09-24T09:42:00.418Z] ... value *errors.Error = &errors.Error{code:0, codeText:"CDC:ErrReachMaxTry", message:"reach maximum try: %d", redactArgsPos:[]int(nil), cause:(*errors.fundamental)(0xc00143a0a8), args:[]interface {}{20}, file:"/home/jenkins/agent/workspace/cdc_ghpr_integration_test/go/src/github.com/pingcap/ticdc/pkg/retry/retry_with_opt.go", line:65} ("[CDC:ErrReachMaxTry]reach maximum try: 20")

[2021-09-24T09:42:00.418Z] 

[2021-09-24T09:42:00.418Z] [2021/09/24 17:40:28.751 +08:00] [ERROR] [region_worker.go:698] ["The CommitTs must be greater than the resolvedTs"] ["Event Type"=COMMIT] [CommitTs=98] [resolvedTs=100] [regionID=3] [stack="github.com/pingcap/ticdc/cdc/kv.(*regionWorker).handleEventEntry\n\t/home/jenkins/agent/workspace/cdc_ghpr_integration_test/go/src/github.com/pingcap/ticdc/cdc/kv/region_worker.go:698\ngit.luolix.top/pingcap/ticdc/cdc/kv.(*regionWorker).processEvent\n\t/home/jenkins/agent/workspace/cdc_ghpr_integration_test/go/src/github.com/pingcap/ticdc/cdc/kv/region_worker.go:408\ngit.luolix.top/pingcap/ticdc/cdc/kv.(*regionWorker).eventHandler\n\t/home/jenkins/agent/workspace/cdc_ghpr_integration_test/go/src/github.com/pingcap/ticdc/cdc/kv/region_worker.go:501\ngit.luolix.top/pingcap/ticdc/cdc/kv.(*regionWorker).run.func3\n\t/home/jenkins/agent/workspace/cdc_ghpr_integration_test/go/src/github.com/pingcap/ticdc/cdc/kv/region_worker.go:616\ngolang.org/x/sync/errgroup.(*Group).Go.func1\n\t/nfs/cache/mod/golang.org/x/sync@v0.0.0-20201020160332-67f06af15bc9/errgroup/errgroup.go:57"]

[2021-09-24T09:42:00.419Z] [2021/09/24 17:40:29.504 +08:00] [ERROR] [region_worker.go:679] ["The CommitTs must be greater than the resolvedTs"] ["Event Type"=COMMITTED] [CommitTs=98] [resolvedTs=100] [regionID=3] [stack="github.com/pingcap/ticdc/cdc/kv.(*regionWorker).handleEventEntry\n\t/home/jenkins/agent/workspace/cdc_ghpr_integration_test/go/src/github.com/pingcap/ticdc/cdc/kv/region_worker.go:679\ngit.luolix.top/pingcap/ticdc/cdc/kv.(*regionWorker).processEvent\n\t/home/jenkins/agent/workspace/cdc_ghpr_integration_test/go/src/github.com/pingcap/ticdc/cdc/kv/region_worker.go:408\ngit.luolix.top/pingcap/ticdc/cdc/kv.(*regionWorker).eventHandler\n\t/home/jenkins/agent/workspace/cdc_ghpr_integration_test/go/src/github.com/pingcap/ticdc/cdc/kv/region_worker.go:501\ngit.luolix.top/pingcap/ticdc/cdc/kv.(*regionWorker).run.func3\n\t/home/jenkins/agent/workspace/cdc_ghpr_integration_test/go/src/github.com/pingcap/ticdc/cdc/kv/region_worker.go:616\ngolang.org/x/sync/errgroup.(*Group).Go.func1\n\t/nfs/cache/mod/golang.org/x/sync@v0.0.0-20201020160332-67f06af15bc9/errgroup/errgroup.go:57"]

[2021-09-24T09:42:00.419Z] [2021/09/24 17:40:29.929 +08:00] [ERROR] [client.go:1089] ["tikv reported compatibility error, which is not expected"] [rpcCtx="region ID: 3, meta: id:3 peers:<id:4 store_id:1 > , peer: id:4 store_id:1 , addr: 127.0.0.1:45106, idx: 0, reqStoreType: TiKvOnly, runStoreType: tikv"] [error="required_version:\"v4.0.7\" "] [stack="github.com/pingcap/ticdc/cdc/kv.

https://ci2.pingcap.net/blue/organizations/jenkins/cdc_ghpr_integration_test/detail/cdc_ghpr_integration_test/4612/pipeline/111

@maxshuang
Copy link
Contributor

A common solution has been pr in #3612. If you find this issue happens again after this pr, pls reopen the this issue and @ me.

@asddongmen
Copy link
Contributor

asddongmen commented Dec 17, 2021

[2021-12-17T10:31:44.210Z] === Failed

[2021-12-17T10:31:44.210Z] === FAIL: cdc/kv Test (140.64s)

[2021-12-17T10:31:44.210Z]

[2021-12-17T10:31:44.210Z] ----------------------------------------------------------------------

[2021-12-17T10:31:44.210Z] FAIL: client_test.go:2868: clientSuite.TestClientErrNoPendingRegion

[2021-12-17T10:31:44.210Z]

[2021-12-17T10:31:44.210Z] client_test.go:2870:

[2021-12-17T10:31:44.210Z] s.testClientErrNoPendingRegion(c)

[2021-12-17T10:31:44.210Z] client_test.go:330:

[2021-12-17T10:31:44.210Z] c.Assert(err, check.IsNil)

[2021-12-17T10:31:44.210Z] ... value *errors.Error = &errors.Error{code:0, codeText:"CDC:ErrReachMaxTry", message:"reach maximum try: %d", redactArgsPos:[]int(nil), cause:(*errors.fundamental)(0xc000d14690), args:[]interface {}{20}, file:"/home/jenkins/agent/workspace/atom-ut/ticdc/pkg/retry/retry_with_opt.go", line:65} ("[CDC:ErrReachMaxTry]reach maximum try: 20: request id 4 is not larger than 4")

[2021-12-17T10:31:44.210Z]

@maxshuang FYI

In this PR #3935

@asddongmen asddongmen reopened this Dec 17, 2021
@jebter jebter added the area/ticdc Issues or PRs related to TiCDC. label Dec 29, 2021
@asddongmen
Copy link
Contributor


FAIL: client_test.go:2870: clientSuite.TestClientErrNoPendingRegion
client_test.go:2872:
s.testClientErrNoPendingRegion(c)
client_test.go:335:
c.Assert(err, check.IsNil)
... value *errors.Error = &errors.Error{code:0, codeText:"CDC:ErrReachMaxTry", message:"reach maximum try: %d", redactArgsPos:[]int(nil), cause:(*errors.fundamental)(0xc000940060), args:[]interface {}{20}, file:"/home/jenkins/agent/workspace/atom-ut/tiflow/pkg/retry/retry_with_opt.go", line:65} ("[CDC:ErrReachMaxTry]reach maximum try: 20: request id 4 is not larger than 4")

@asddongmen
Copy link
Contributor

@asddongmen
Copy link
Contributor

@Rustin170506
Copy link
Member Author

another case:

[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-360)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-361)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-362)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-363)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-364)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-365)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-366)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-367)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-368)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-369)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-370)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-371)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-372)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-373)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-374)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-375)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-376)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-377)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-378)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-379)[](https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/8344/pipeline/#step-49-log-380)[2022-04-07T06:00:37.001Z] === Failed

[2022-04-07T06:00:37.001Z] === FAIL: cdc/kv TestClientErrNoPendingRegion (2.57s)

[2022-04-07T06:00:37.001Z] [2022/04/07 13:54:11.487 +08:00] [INFO] [client.go:512] ["event feed started"] [span="[61, 63)"] [startTs=100] [changefeed=]

[2022-04-07T06:00:37.001Z] [2022/04/07 13:54:11.489 +08:00] [INFO] [region_range_lock.go:222] ["range locked"] [changefeed=] [lockID=24] [regionID=3] [version=1] [startKey=61] [endKey=62] [checkpointTs=100]

[2022-04-07T06:00:37.001Z] [2022/04/07 13:54:11.490 +08:00] [INFO] [region_range_lock.go:222] ["range locked"] [changefeed=] [lockID=24] [regionID=4] [version=1] [startKey=62] [endKey=63] [checkpointTs=100]

[2022-04-07T06:00:37.001Z] [2022/04/07 13:54:11.490 +08:00] [INFO] [client.go:755] ["creating new stream to store to send request"] [changefeed=] [regionID=3] [requestID=69] [storeID=1] [addr=127.0.0.1:41789]

[2022-04-07T06:00:37.001Z] [2022/04/07 13:54:11.497 +08:00] [INFO] [client.go:801] ["start new request"] [changefeed=] [request="{\"header\":{\"cluster_id\":1},\"region_id\":3,\"region_epoch\":{\"version\":1},\"checkpoint_ts\":100,\"start_key\":\"YQ==\",\"end_key\":\"Yg==\",\"request_id\":69,\"Request\":null}"] [addr=127.0.0.1:41789]

[2022-04-07T06:00:37.001Z] [2022/04/07 13:54:11.989 +08:00] [WARN] [client.go:1190] ["failed to receive from stream"] [changefeed=] [addr=127.0.0.1:41789] [storeID=1] [error="injected error"] [errorVerbose="injected error\ngit.luolix.top/pingcap/tiflow/cdc/kv.(*eventFeedSession).receiveFromStream\n\t/home/jenkins/agent/workspace/ut-check/tiflow/cdc/kv/client.go:1178\ngit.luolix.top/pingcap/tiflow/cdc/kv.(*eventFeedSession).requestRegionToStore.func1\n\t/home/jenkins/agent/workspace/ut-check/tiflow/cdc/kv/client.go:790\ngolang.org/x/sync/errgroup.(*Group).Go.func1\n\t/go/pkg/mod/golang.org/x/sync@v0.0.0-20210220032951-036812b2e83c/errgroup/errgroup.go:57\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1571"]

[2022-04-07T06:00:37.001Z] [2022/04/07 13:54:12.044 +08:00] [INFO] [region_worker.go:449] ["region worker closed by error"] [changefeed=]

[2022-04-07T06:00:37.001Z] [2022/04/07 13:54:12.046 +08:00] [INFO] [client.go:1139] ["stream to store closed"] [changefeed=] [addr=127.0.0.1:41789] [storeID=1]

[2022-04-07T06:00:37.001Z] [2022/04/07 13:54:12.498 +08:00] [INFO] [client.go:755] ["creating new stream to store to send request"] [changefeed=] [regionID=4] [requestID=70] [storeID=1] [addr=127.0.0.1:41789]

[2022-04-07T06:00:37.001Z] [2022/04/07 13:54:12.499 +08:00] [INFO] [client.go:801] ["start new request"] [changefeed=] [request="{\"header\":{\"cluster_id\":1},\"region_id\":4,\"region_epoch\":{\"version\":1},\"checkpoint_ts\":100,\"start_key\":\"Yg==\",\"end_key\":\"Yw==\",\"request_id\":70,\"Request\":null}"] [addr=127.0.0.1:41789]

[2022-04-07T06:00:37.001Z]     client_test.go:309: 

[2022-04-07T06:00:37.001Z]         	Error Trace:	client_test.go:309

[2022-04-07T06:00:37.001Z]         	            				client_test.go:2896

[2022-04-07T06:00:37.002Z]         	            				client_test.go:2838

[2022-04-07T06:00:37.002Z]         	Error:      	Expected nil, but got: &errors.Error{code:0, codeText:"CDC:ErrReachMaxTry", message:"reach maximum try: %d", redactArgsPos:[]int(nil), cause:(*errors.fundamental)(0xc007c0c180), args:[]interface {}{20}, file:"/home/jenkins/agent/workspace/ut-check/tiflow/pkg/retry/retry_with_opt.go", line:65}

[2022-04-07T06:00:37.002Z]         	Test:       	TestClientErrNoPendingRegion

[2022-04-07T06:00:37.002Z] [2022/04/07 13:54:14.046 +08:00] [INFO] [region_range_lock.go:389] ["unlocked range"] [changefeed=] [lockID=24] [regionID=3] [startKey=61] [endKey=62] [checkpointTs=100]

[2022-04-07T06:00:37.002Z] 

[2022-04-07T06:00:37.002Z] DONE 780 tests, 1 failure in 600.207s

[2022-04-07T06:00:37.002Z] make: *** [unit_test_in_verify_ci] Error 1

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

@CharlesCheung96
Copy link
Contributor

CharlesCheung96 commented May 6, 2022

another case:

[2022-05-06T04:42:57.338Z] 

[2022-05-06T04:42:57.338Z] === Failed

[2022-05-06T04:42:57.338Z] === FAIL: cdc/kv TestClientErrNoPendingRegion (2.55s)

[2022-05-06T04:42:57.338Z] [2022/05/06 12:38:03.386 +08:00] [INFO] [client.go:513] ["event feed started"] [span="[61, 63)"] [startTs=100] [namespace=default] [changefeed=]

[2022-05-06T04:42:57.338Z] [2022/05/06 12:38:03.387 +08:00] [INFO] [region_range_lock.go:222] ["range locked"] [lockID=24] [regionID=3] [version=1] [startKey=61] [endKey=62] [checkpointTs=100]

[2022-05-06T04:42:57.338Z] [2022/05/06 12:38:03.387 +08:00] [INFO] [region_range_lock.go:222] ["range locked"] [lockID=24] [regionID=4] [version=1] [startKey=62] [endKey=63] [checkpointTs=100]

[2022-05-06T04:42:57.338Z] [2022/05/06 12:38:03.388 +08:00] [INFO] [client.go:758] ["creating new stream to store to send request"] [namespace=default] [changefeed=] [regionID=3] [requestID=68] [storeID=1] [addr=127.0.0.1:40341]

[2022-05-06T04:42:57.338Z] [2022/05/06 12:38:03.391 +08:00] [INFO] [client.go:806] ["start new request"] [namespace=default] [changefeed=] [request="{\"header\":{\"cluster_id\":1},\"region_id\":3,\"region_epoch\":{\"version\":1},\"checkpoint_ts\":100,\"start_key\":\"YQ==\",\"end_key\":\"Yg==\",\"request_id\":68,\"extra_op\":1,\"Request\":null}"] [addr=127.0.0.1:40341]

[2022-05-06T04:42:57.338Z] [2022/05/06 12:38:03.887 +08:00] [WARN] [client.go:1212] ["failed to receive from stream"] [namespace=default] [changefeed=] [addr=127.0.0.1:40341] [storeID=1] [error="injected error"] [errorVerbose="injected error\ngit.luolix.top/pingcap/tiflow/cdc/kv.(*eventFeedSession).receiveFromStream\n\t/home/jenkins/agent/workspace/ut-check/tiflow/cdc/kv/client.go:1199\ngit.luolix.top/pingcap/tiflow/cdc/kv.(*eventFeedSession).requestRegionToStore.func1\n\t/home/jenkins/agent/workspace/ut-check/tiflow/cdc/kv/client.go:795\ngolang.org/x/sync/errgroup.(*Group).Go.func1\n\t/go/pkg/mod/golang.org/x/sync@v0.0.0-20210220032951-036812b2e83c/errgroup/errgroup.go:57\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1571"]

[2022-05-06T04:42:57.339Z] [2022/05/06 12:38:03.926 +08:00] [INFO] [client.go:1159] ["stream to store closed"] [namespace=default] [changefeed=] [addr=127.0.0.1:40341] [storeID=1]

[2022-05-06T04:42:57.339Z] [2022/05/06 12:38:03.926 +08:00] [INFO] [region_worker.go:462] ["region worker closed by error"] [namesapce=default] [changefeed=]

[2022-05-06T04:42:57.339Z] [2022/05/06 12:38:04.393 +08:00] [INFO] [client.go:758] ["creating new stream to store to send request"] [namespace=default] [changefeed=] [regionID=4] [requestID=69] [storeID=1] [addr=127.0.0.1:40341]

[2022-05-06T04:42:57.339Z] [2022/05/06 12:38:04.393 +08:00] [INFO] [client.go:806] ["start new request"] [namespace=default] [changefeed=] [request="{\"header\":{\"cluster_id\":1},\"region_id\":4,\"region_epoch\":{\"version\":1},\"checkpoint_ts\":100,\"start_key\":\"Yg==\",\"end_key\":\"Yw==\",\"request_id\":69,\"extra_op\":1,\"Request\":null}"] [addr=127.0.0.1:40341]

[2022-05-06T04:42:57.339Z]     client_test.go:286: 

[2022-05-06T04:42:57.339Z]         	Error Trace:	client_test.go:286

[2022-05-06T04:42:57.339Z]         	            				client_test.go:2972

[2022-05-06T04:42:57.339Z]         	            				client_test.go:2909

[2022-05-06T04:42:57.339Z]         	Error:      	Expected nil, but got: &errors.Error{code:0, codeText:"CDC:ErrReachMaxTry", message:"reach maximum try: %s, error: %s", redactArgsPos:[]int(nil), cause:(*errors.fundamental)(0xc0034bd368), args:[]interface {}{"20", (*errors.fundamental)(0xc0034bd368)}, file:"/home/jenkins/agent/workspace/ut-check/tiflow/pkg/retry/retry_with_opt.go", line:69}

[2022-05-06T04:42:57.339Z]         	Test:       	TestClientErrNoPendingRegion

[2022-05-06T04:42:57.339Z] [2022/05/06 12:38:05.927 +08:00] [INFO] [region_range_lock.go:388] ["unlocked range"] [changefeed=default-] [lockID=24] [regionID=3] [startKey=61] [endKey=62] [checkpointTs=100]

[2022-05-06T04:42:57.339Z] 

[2022-05-06T04:42:57.339Z] DONE 832 tests, 1 failure in 501.540s

https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/10289/pipeline/
https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/10556/pipeline/45/

@asddongmen
Copy link
Contributor

fixed by:tikv/migration#127

@sleepymole
Copy link
Contributor

sleepymole commented Oct 31, 2022

A new case at https://ci.pingcap.net/blue/organizations/jenkins/ut-check/detail/ut-check/41294/pipeline/.

[2022-10-31T09:26:07.395Z] === FAIL: cdc/kv TestClientErrNoPendingRegion (2.53s)

[2022-10-31T09:26:07.395Z] [2022/10/31 17:18:30.576 +08:00] [INFO] [client.go:538] ["event feed started"] [namespace=default] [changefeed=changefeed-test] [tableID=0] [tableName=] [startTs=100] [span="[61, 63)"]

[2022-10-31T09:26:07.396Z] [2022/10/31 17:18:30.580 +08:00] [INFO] [client.go:722] ["creating new stream to store to send request"] [namespace=default] [changefeed=changefeed-test] [regionID=3] [requestID=69] [storeID=1] [addr=127.0.0.1:38570]

[2022-10-31T09:26:07.396Z] [2022/10/31 17:18:31.078 +08:00] [WARN] [client.go:1146] ["failed to receive from stream"] [namespace=default] [changefeed=changefeed-test] [addr=127.0.0.1:38570] [storeID=1] [error="injected error"] [errorVerbose="injected error\ngit.luolix.top/pingcap/tiflow/cdc/kv.(*eventFeedSession).receiveFromStream\n\t/home/jenkins/agent/workspace/ut-check/tiflow/cdc/kv/client.go:1133\ngit.luolix.top/pingcap/tiflow/cdc/kv.(*eventFeedSession).requestRegionToStore.func1\n\t/home/jenkins/agent/workspace/ut-check/tiflow/cdc/kv/client.go:732\ngolang.org/x/sync/errgroup.(*Group).Go.func1\n\t/go/pkg/mod/golang.org/x/sync@v0.0.0-20220722155255-886fb9371eb4/errgroup/errgroup.go:75\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1594"]

[2022-10-31T09:26:07.396Z] [2022/10/31 17:18:31.101 +08:00] [INFO] [client.go:1092] ["stream to store closed"] [namespace=default] [changefeed=changefeed-test] [addr=127.0.0.1:38570] [storeID=1]

[2022-10-31T09:26:07.396Z] [2022/10/31 17:18:31.101 +08:00] [INFO] [region_worker.go:422] ["region worker closed by error"] [namespace=default] [changefeed=changefeed-test]

[2022-10-31T09:26:07.396Z] [2022/10/31 17:18:31.580 +08:00] [INFO] [client.go:722] ["creating new stream to store to send request"] [namespace=default] [changefeed=changefeed-test] [regionID=4] [requestID=70] [storeID=1] [addr=127.0.0.1:38570]

[2022-10-31T09:26:07.396Z]     client_test.go:285: 

[2022-10-31T09:26:07.396Z]         	Error Trace:	/home/jenkins/agent/workspace/ut-check/tiflow/cdc/kv/client_test.go:285

[2022-10-31T09:26:07.396Z]         	            				/home/jenkins/agent/workspace/ut-check/tiflow/cdc/kv/client_test.go:2932

[2022-10-31T09:26:07.396Z]         	            				/home/jenkins/agent/workspace/ut-check/tiflow/cdc/kv/client_test.go:2871

[2022-10-31T09:26:07.396Z]         	Error:      	Expected nil, but got: &errors.Error{code:0, codeText:"CDC:ErrReachMaxTry", message:"reach maximum try: %s, error: %s", redactArgsPos:[]int(nil), cause:(*errors.fundamental)(0xc000c8d080), args:[]interface {}{"20", (*errors.fundamental)(0xc000c8d080)}, file:"/home/jenkins/agent/workspace/ut-check/tiflow/pkg/retry/retry_with_opt.go", line:69}

[2022-10-31T09:26:07.396Z]         	Test:       	TestClientErrNoPendingRegion

[2022-10-31T09:26:07.396Z] [2022/10/31 17:18:33.102 +08:00] [INFO] [region_cache.go:1025] ["mark store's regions need be refill"] [store=127.0.0.1:38570]

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
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
Development

Successfully merging a pull request may close this issue.

8 participants