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

redo apply panic: "insert events should be emitted after other kinds of events in the same transaction" #11096

Closed
fubinzh opened this issue May 14, 2024 · 5 comments · Fixed by #11117
Closed

redo apply panic: "insert events should be emitted after other kinds of events in the same transaction" #11096

fubinzh opened this issue May 14, 2024 · 5 comments · Fixed by #11117
Assignees
@hongyunyan
Labels
affects-6.5 affects-7.1 affects-7.5 affects-8.1 area/ticdc Issues or PRs related to TiCDC. severity/major type/bug The issue is confirmed as a bug.

Comments

@fubinzh
Copy link

fubinzh commented May 14, 2024

What did you do?

  1. create mysql sink changefeed with redo log on
  2. run gotpc workload
  3. After 30m, pause changefeed and run redo apply

What did you expect to see?

redo apply should succeed.

What did you see instead?

redo apply failed with panic:

[2024/05/13 04:58:14.678 +00:00] [INFO] [worker.go:94] [\"Transaction dmlSink worker exits as canceled\"] [changefeedID=.] [workerID=11], stderr: panic: insert events should be emitted after other kinds of events in the same transaction\n\ngoroutine 434 [running]:\ngo.uber.org/zap/zapcore.CheckWriteAction.OnWrite(0x0?, 0x0?, {0x0?, 0x0?, 0xc00015af00?})\n\tgo.uber.org/zap@v1.27.0/zapcore/entry.go:196 +0x54\ngo.uber.org/zap/zapcore.(*CheckedEntry).Write(0xc0018fe1a0, {0x0, 0x0, 0x0})\n\tgo.uber.org/zap@v1.27.0/zapcore/entry.go:262 +0x3ec\ngo.uber.org/zap.(*Logger).Panic(0xc006eda630?, {0x525a3c8?, 0x40c9a74?}, {0x0, 0x0, 0x0})\n\tgo.uber.org/zap@v1.27.0/logger.go:285 +0x51\ngithub.com/pingcap/log.Panic({0x525a3c8?, 0xc00006b7a0?}, {0x0?, 0xc0017e46c0?, 0x0?})\n\tgithub.com/pingcap/log@v1.1.1-0.20240314023424-862ccc32f18d/global.go:54 +0x85\ngithub.com/pingcap/tiflow/pkg/applier.(*updateEventSplitter).checkEventOrder(0xc0010ad180?, 0x5d61178?)\n\tgithub.com/pingcap/tiflow/pkg/applier/redo.go:654 +0x4f\ngithub.com/pingcap/tiflow/pkg/applier.(*updateEventSplitter).readNextRow(0xc003558200, {0x5d61178, 0xc001046f00})\n\tgithub.com/pingcap/tiflow/pkg/applier/redo.go:694 +0xa8\ngithub.com/pingcap/tiflow/pkg/applier.(*RedoApplier).consumeLogs(0xc0013d2120, {0x5d61178, 0xc001046f00})\n\tgithub.com/pingcap/tiflow/pkg/applier/redo.go:210 +0x42a\ngithub.com/pingcap/tiflow/pkg/applier.(*RedoApplier).Apply.func3()\n\tgithub.com/pingcap/tiflow/pkg/applier/redo.go:741 +0x1f\ngolang.org/x/sync/errgroup.(*Group).Go.func1()\n\tgolang.org/x/sync@v0.7.0/errgroup/errgroup.go:78 +0x56\ncreated by golang.org/x/sync/errgroup.(*Group).Go in goroutine 1\n\tgolang.org/x/sync@v0.7.0/errgroup/errgroup.go:75 +0x96, ExitCode: 2"] [stack="github.com/pingcap/test-infra/caselib/pkg/host.(*TiCDCHost).Redo\n\tgithub.com/pingcap/test-infra/caselib/pkg/host/ticdc.go:107\ngithub.com/pingcap/test-infra/caselib/pkg/steps.(*redo).Execute\n\tgithub.com/pingcap/test-infra/caselib/pkg/steps/redo.go:28\ngithub.com/pingcap/test-infra/caselib/pkg/steps.withRecover\n\tgithub.com/pingcap/test-infra/caselib/pkg/steps/step.go:24\ngithub.com/pingcap/test-infra/caselib/pkg/steps.(*Serial).Execute\n\tgithub.com/pingcap/test-infra/caselib/pkg/steps/step.go:45\nmain.main\n\ttest-infra/caselib/ticdc/main.go:112\nruntime.main\n\truntime/proc.go:267"]

Versions of the cluster

[release-version=v8.1.0] [git-hash=faabbc0bae6d77ed6d8cac005bfc31fe8b075b63]
@fubinzh fubinzh added area/ticdc Issues or PRs related to TiCDC. type/bug The issue is confirmed as a bug. labels May 14, 2024
@fubinzh
Copy link
Author

fubinzh commented May 14, 2024

/label affects-8.1

@fubinzh
Copy link
Author

fubinzh commented May 15, 2024

/severity major

@hongyunyan hongyunyan mentioned this issue May 15, 2024
Closed
@lidezhu lidezhu removed their assignment May 15, 2024
@hongyunyan hongyunyan mentioned this issue May 16, 2024
Merged
@kennedy8312
Copy link

/type regression

@ti-chi-bot ti-chi-bot
Copy link
Contributor

ti-chi-bot bot commented May 17, 2024

@kennedy8312: The label(s) type/regression cannot be applied, because the repository doesn't have them.

In response to this:

/type regression

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the ti-community-infra/tichi repository.

@fubinzh
Copy link
Author

fubinzh commented May 17, 2024

Regression issue introduced by #11027

ti-chi-bot bot pushed a commit that referenced this issue May 17, 2024
@hongyunyan
(redo)ticdc: fix the event orderliness in redo log (#11117)
e75248d 
close #11096
@ti-chi-bot ti-chi-bot mentioned this issue May 17, 2024
Merged
ti-chi-bot bot pushed a commit that referenced this issue May 17, 2024
@ti-chi-bot
(redo)ticdc: fix the event orderliness in redo log (#11117) (#11130)
9a296b9 
close #11096
@ti-chi-bot ti-chi-bot mentioned this issue May 21, 2024
Merged
ti-chi-bot bot pushed a commit that referenced this issue May 22, 2024
@ti-chi-bot
(redo)ticdc: fix the event orderliness in redo log (#11117) (#11155)
7806104 
close #11096
This was referenced May 27, 2024
Merged
Merged
ti-chi-bot bot pushed a commit that referenced this issue May 29, 2024
@ti-chi-bot
(redo)ticdc: fix the event orderliness in redo log (#11117) (#11181)
6db1dc2 
close #11096
ti-chi-bot bot pushed a commit that referenced this issue May 29, 2024
@ti-chi-bot
(redo)ticdc: fix the event orderliness in redo log (#11117) (#11180)
0ba9329 
close #11096
hicqu added a commit to ti-chi-bot/tiflow that referenced this issue Jun 12, 2024
@hicqu
Squashed commit of the following:
a3d30ca 
commit c092599
Author: Ti Chi Robot <ti-community-prow-bot@tidb.io>
Date:   Wed Jun 12 00:26:59 2024 +0800

    pkg/config, sink(ticdc): support output raw change event for mq and cloud storage sink (pingcap#11226) (pingcap#11290)

    close pingcap#11211

commit 3426e46
Author: Ti Chi Robot <ti-community-prow-bot@tidb.io>
Date:   Tue Jun 11 19:40:29 2024 +0800

    puller(ticdc): fix wrong update splitting behavior after table scheduling (pingcap#11269) (pingcap#11282)

    close pingcap#11219

commit 2a28078
Author: Ti Chi Robot <ti-community-prow-bot@tidb.io>
Date:   Tue Jun 11 16:40:37 2024 +0800

    mysql(ticdc): remove error filter when check isTiDB in backend init (pingcap#11214) (pingcap#11261)

    close pingcap#11213

commit 2425d54
Author: Ti Chi Robot <ti-community-prow-bot@tidb.io>
Date:   Tue Jun 11 16:40:30 2024 +0800

    log(ticdc): Add more error query information to the returned error to facilitate users to know the cause of the failure (pingcap#10945) (pingcap#11257)

    close pingcap#11254

commit 053cdaf
Author: Ti Chi Robot <ti-community-prow-bot@tidb.io>
Date:   Tue Jun 11 15:34:30 2024 +0800

    cdc: log slow conflict detect every 60s (pingcap#11251) (pingcap#11287)

    close pingcap#11271

commit 327ba7b
Author: Ti Chi Robot <ti-community-prow-bot@tidb.io>
Date:   Tue Jun 11 11:42:00 2024 +0800

    redo(ticdc): return internal error in redo writer (pingcap#11011) (pingcap#11091)

    close pingcap#10124

commit d82ae89
Author: Ti Chi Robot <ti-community-prow-bot@tidb.io>
Date:   Mon Jun 10 22:28:29 2024 +0800

    ddl_puller (ticdc): handle dorp pk/uk ddl correctly (pingcap#10965) (pingcap#10981)

    close pingcap#10890

commit f15bec9
Author: Ti Chi Robot <ti-community-prow-bot@tidb.io>
Date:   Fri Jun 7 16:16:28 2024 +0800

    redo(ticdc): enable pprof and set memory limit for redo applier (pingcap#10904) (pingcap#10996)

    close pingcap#10900

commit ba50a0e
Author: Ti Chi Robot <ti-community-prow-bot@tidb.io>
Date:   Wed Jun 5 19:58:26 2024 +0800

    test(ticdc): enable sequence test (pingcap#11023) (pingcap#11037)

    close pingcap#11015

commit 94b9897
Author: Ti Chi Robot <ti-community-prow-bot@tidb.io>
Date:   Wed Jun 5 17:08:56 2024 +0800

    mounter(ticdc): timezone fill default value should also consider tz. (pingcap#10932) (pingcap#10946)

    close pingcap#10931

commit a912d33
Author: Ti Chi Robot <ti-community-prow-bot@tidb.io>
Date:   Wed Jun 5 10:49:25 2024 +0800

    mysql (ticdc): Improve the performance of the mysql sink by refining the transaction event batching logic (pingcap#10466) (pingcap#11242)

    close pingcap#11241

commit 6277d9a
Author: dongmen <20351731+asddongmen@users.noreply.github.com>
Date:   Wed May 29 20:13:22 2024 +0800

    kvClient (ticdc): revert e5999e3 to remove useless metrics (pingcap#11184)

    close pingcap#11073

commit 54e93ed
Author: dongmen <20351731+asddongmen@users.noreply.github.com>
Date:   Wed May 29 17:43:22 2024 +0800

    syncpoint (ticdc): make syncpoint support base64 encoded password (pingcap#11162)

    close pingcap#10516

commit 0ba9329
Author: Ti Chi Robot <ti-community-prow-bot@tidb.io>
Date:   Wed May 29 09:07:21 2024 +0800

    (redo)ticdc: fix the event orderliness in redo log (pingcap#11117) (pingcap#11180)

    close pingcap#11096

Signed-off-by: qupeng <qupeng@pingcap.com>
@hongyunyan hongyunyan mentioned this issue Jun 17, 2024
Merged
ti-chi-bot bot pushed a commit that referenced this issue Jun 17, 2024
@hongyunyan
redo(ticdc): fix orderliness of redo (#11320)
ffbe6f8 
close #11096
@hongyunyan hongyunyan mentioned this issue Jun 19, 2024
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@hongyunyan hongyunyan

Labels
affects-6.5 affects-7.1 affects-7.5 affects-8.1 area/ticdc Issues or PRs related to TiCDC. severity/major type/bug The issue is confirmed as a bug.
Projects
Question and Bug Reports
Status: Done
Milestone
No milestone
4 participants
@fubinzh @hongyunyan @lidezhu @kennedy8312