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

[sequence_sharding_optimistic] check diff failed at last #5731

Closed
Tracked by #2246
lance6716 opened this issue Jun 2, 2022 · 4 comments · Fixed by #6572
Closed
Tracked by #2246

[sequence_sharding_optimistic] check diff failed at last #5731

lance6716 opened this issue Jun 2, 2022 · 4 comments · Fixed by #6572
Labels
affects-5.3 affects-5.4 affects-6.1 affects-6.2 area/dm Issues or PRs related to DM. component/test Unit tests and integration tests component. severity/minor type/bug The issue is confirmed as a bug.

Comments

@lance6716
Copy link
Contributor

Which jobs are flaking?

sequence_sharding_optimistic

Which test(s) are flaking?

DM-IT
release-6.1

Jenkins logs or GitHub Actions link

https://ci2.pingcap.net/blue/organizations/jenkins/dm_ghpr_integration_test/detail/dm_ghpr_integration_test/6421/pipeline/

["column num not equal"] ["upstream table"=t1] ["column num"=3] ["downstream table"=t_target] ["column num"=4] 

Anything else we need to know

  • Does this test exist for other branches as well?

  • Has there been a high frequency of failure lately?

@lance6716 lance6716 added component/test Unit tests and integration tests component. area/dm Issues or PRs related to DM. labels Jun 2, 2022
@buchuitoudegou
Copy link
Contributor

buchuitoudegou commented Jun 24, 2022

@lance6716
Copy link
Contributor Author

[2022-07-21T08:41:19.914Z] [2022/07/21 16:40:38.047 +08:00] [ERROR] [subtask.go:377] ["unit process error"] [subtask=sequence_sharding_optimistic] [unit=Sync] ["error information"="ErrCode:36069 ErrClass:\"sync-unit\" ErrScope:\"upstream\" ErrLevel:\"high\" Message:\"get binlog event error: [code=11038:class=functional:scope=internal:level=high], Message: parse relay log file dm-integration-test-go1180-8032-psp31-w99ls-bin.000001 from offset 4 in dir /tmp/dm_test/sequence_sharding_optimistic/worker2/relay_log/368cb627-08d0-11ed-95f6-9682e7a57465.000001: parse relay log file dm-integration-test-go1180-8032-psp31-w99ls-bin.000001 from offset 3681 in dir /tmp/dm_test/sequence_sharding_optimistic/worker2/relay_log/368cb627-08d0-11ed-95f6-9682e7a57465.000001: parse relay log file /tmp/dm_test/sequence_sharding_optimistic/worker2/relay_log/368cb627-08d0-11ed-95f6-9682e7a57465.000001/dm-integration-test-go1180-8032-psp31-w99ls-bin.000001, RawCause: Header &replication.EventHeader{Timestamp:0x62d910f7, EventType:0x1e, ServerID:0x1, EventSize:0x3a, LogPos:0xe61, Flags:0x0}, Data \\\"[\\\\x01\\\\x00\\\\x00\\\\x00\\\\x00\\\\x01\\\\x00\\\\x02\\\\x00\\\\x03\\\\xff\\\\x00\\\\x84\\\\x1a\\\\x06\\\\x00\\\\x00\\\\x00\\\\x00\\\\x00\\\\x06410004\\\\x06420004\\\", Err: table id 347: invalid table id, no corresponding table map event\" Workaround:\"Please check if the binlog file could be parsed by `mysqlbinlog`.\" "]

@lance6716
Copy link
Contributor Author

lance6716 commented Jul 21, 2022

there is a table map event

[2022-07-21T08:41:19.858Z] [2022/07/21 16:40:23.884 +08:00] [DEBUG] [relay.go:614] ["receive binlog event with header"] [component="relay log"] [header="{\"Timestamp\":1658392823,\"EventType\":19,\"ServerID\":1,\"EventSize\":69,\"LogPos\":3623,\"Flags\":0}"]
[2022-07-21T08:41:19.858Z] [2022/07/21 16:40:23.884 +08:00] [DEBUG] [relay.go:662] ["writing binlog event"] [component="relay log"] [header="{\"Timestamp\":1658392823,\"EventType\":19,\"ServerID\":1,\"EventSize\":69,\"LogPos\":3623,\"Flags\":0}"]
[2022-07-21T08:41:19.858Z] [2022/07/21 16:40:23.885 +08:00] [DEBUG] [relay.go:614] ["receive binlog event with header"] [component="relay log"] [header="{\"Timestamp\":1658392823,\"EventType\":30,\"ServerID\":1,\"EventSize\":58,\"LogPos\":3681,\"Flags\":0}"]
[2022-07-21T08:41:19.858Z] [2022/07/21 16:40:23.885 +08:00] [DEBUG] [relay.go:662] ["writing binlog event"] [component="relay log"] [header="{\"Timestamp\":1658392823,\"EventType\":30,\"ServerID\":1,\"EventSize\":58,\"LogPos\":3681,\"Flags\":0}"]

we should not re-parse in the middle of (table map event, rows events). But I'm not sure why old code before the relay refacor can work

Header &replication.EventHeader{Timestamp:0x62d910f7, EventType:0x1e, ServerID:0x1, EventSize:0x3a, LogPos:0xe61, Flags:0x0}, Data "[���������410004�420004", Err: table id 347: invalid table id, no corresponding table map event
github.com/pingcap/errors.AddStack
        /go/pkg/mod/github.com/pingcap/[email protected]/errors.go:174
github.com/pingcap/errors.Trace
        /go/pkg/mod/github.com/pingcap/[email protected]/juju_adaptor.go:15
github.com/go-mysql-org/go-mysql/replication.(*BinlogParser).parseSingleEvent
        /go/pkg/mod/github.com/go-mysql-org/[email protected]/replication/parser.go:155
github.com/go-mysql-org/go-mysql/replication.(*BinlogParser).ParseReader
        /go/pkg/mod/github.com/go-mysql-org/[email protected]/replication/parser.go:171
github.com/pingcap/tiflow/dm/relay.(*BinlogReader).parseFile
        /home/jenkins/agent/workspace/dm_ghpr_integration_test/go/src/github.com/pingcap/tiflow/dm/relay/local_reader.go:653
github.com/pingcap/tiflow/dm/relay.(*BinlogReader).parseFileAsPossible
        /home/jenkins/agent/workspace/dm_ghpr_integration_test/go/src/github.com/pingcap/tiflow/dm/relay/local_reader.go:487
github.com/pingcap/tiflow/dm/relay.(*BinlogReader).parseDirAsPossible
        /home/jenkins/agent/workspace/dm_ghpr_integration_test/go/src/github.com/pingcap/tiflow/dm/relay/local_reader.go:427
github.com/pingcap/tiflow/dm/relay.(*BinlogReader).parseRelay
        /home/jenkins/agent/workspace/dm_ghpr_integration_test/go/src/github.com/pingcap/tiflow/dm/relay/local_reader.go:317
github.com/pingcap/tiflow/dm/relay.(*BinlogReader).StartSyncByGTID.func1
        /home/jenkins/agent/workspace/dm_ghpr_integration_test/go/src/github.com/pingcap/tiflow/dm/relay/local_reader.go:286
runtime.goexit
        /usr/local/go/src/runtime/asm_amd64.s:1571

cc @D3Hunter

@lance6716 lance6716 added the type/bug The issue is confirmed as a bug. label Jul 21, 2022
ti-chi-bot pushed a commit that referenced this issue Aug 3, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
affects-5.3 affects-5.4 affects-6.1 affects-6.2 area/dm Issues or PRs related to DM. 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.

2 participants