Fix resumable binlog position after interrupt by fjordan · Pull Request #168 · Shopify/ghostferry

fjordan · 2020-04-08T17:55:57Z

Alternative to #160 (and also makes use of the same added test with slight modifications).

As described in the other PR, attempting to resume Ghostferry from an invalid binlog position will result in an error as the preceding TableMapEvent is required to properly translate RowsEvents.

This adds a resumable position and interface to the DMLEvent that the InlineVerifier and BinlogWriter persist during interruption to be reused during resume.

The last resumable position is stored as a member of the BinlogStreamer and is periodically updated as the BinlogStreamer sees new resumable events (GTIDEvents and XIDEvents). This position is then sent along with the corresponding DMLEvent. The resumable position is made available on the DMLEvents using a new interface method - ResumableBinlogPosition.

/cc @Shopify/pods

hkdsun

Love how simply you solved this ❤️ couple comments and then good-to-go I think

And excellent test case by @kolbitsch-lastline, thank you for the contribution!

hkdsun · 2020-04-13T18:36:00Z

 	}

-	dmlEvs, err := NewBinlogDMLEvents(table, ev, pos)
+	s.lastResumableBinlogPosition.Name = s.lastStreamedBinlogPosition.Name


Wait, what? I don't think this should be legal 😄 jokes aside, mutating any binlog position sounds like a recipe for bugs down the line.. it's a bit like randomizing the coordinates you put in a GPS.. you might end up in middle of nowhere!

Would a test fail if I removed this line?

I wouldn't recommend removing it 😄.

Instead of just duplicating all the places where lastStreamedBinlogPosition is set to also set this value, we just reuse the value like is already being done for the pos value in line 262.

Do you think it makes more sense to put it closer to the pos assignment? I don't think it would make much difference.

Oh I see what's going on. This could use some cleanup, I'll PR something based off your branch.

Ended up moving this assignment to the RotateEvent and in the initial connect further up. That allows us to remove it from this line here.

hkdsun · 2020-04-13T18:36:55Z

 			// so there's no way to handle this for us.
 			continue
+		case *replication.XIDEvent, *replication.GTIDEvent:
+			s.lastResumableBinlogPosition.Pos = uint32(ev.Header.LogPos)


Let's document in code comments what got us to this? 🙏

can do 👍

…ition

hkdsun

LGTM. Let's get Shuhao's +1 and 🚢

hkdsun · 2020-04-13T20:31:17Z

+			//
+			// As a result, the following case will set the last resumable position for
+			// interruption to EITHER the start (if using GTIDs) or the end of the
+			// last transaction


Succinct explanation. Thank you!

shuhaowu · 2020-04-13T20:36:10Z

+	binlogStreamer              *replication.BinlogStreamer
+	lastStreamedBinlogPosition  mysql.Position
+	lastResumableBinlogPosition mysql.Position
+	targetBinlogPosition        mysql.Position


We don't have to do this now, but this was brought up the other day: Since we will eventually start streaming binlog from the target for verification, maybe we should rename this to "stopAtBinlogPosition", or something to that effect.

I just wanted to mention this so we don't forget about it.

shuhaowu · 2020-04-13T21:09:11Z

+
+    ghostferry.on_status(Ghostferry::Status::AFTER_BINLOG_APPLY) do
+      # while we are emitting events in the loop above, try to inject a shutdown
+      # signal, hoping to interrupt between applying an INSERT and receiving the


So this test will be known to racy? Will it make CI more flaky?

It has been consistently passing in my experience and hasn’t been flaky

shuhaowu · 2020-04-13T21:10:30Z


 	logrus.SetLevel(logrus.DebugLevel)
+	if os.Getenv("CI") == "true" {
+		logrus.SetLevel(logrus.ErrorLevel)


Can you remind me what this is for? I don't recall anymore.

The log output from the binlog events is seemingly causing CI to truncate the output. This just lowers the logging level unless needed for the tests

shuhaowu · 2020-04-13T21:11:51Z

 		case *replication.RotateEvent:
 			// This event is needed because we need to update the last successful
 			// binlog position.
+			s.lastResumableBinlogPosition.Pos = uint32(e.Position)


Shouldn't we need to set the .Name here as well? This is a RotateEvent so the file should change, right? That would get rid of the slightly cryptic s.lastResumableBinlogPosition.Name line below?

Following up on our conversation, we decided to set the name here and in the ConnectBinlogStreamerToMysqlFrom above 👍

hkdsun · 2020-04-14T11:30:43Z

 			// This event is needed because we need to update the last successful
 			// binlog position.
+			s.lastResumableBinlogPosition.Pos = uint32(e.Position)
+			s.lastResumableBinlogPosition.Name = string(e.NextLogName)


Wait, I thought we agreed we can't resume from a RotateEvent's position?

This is the only place where MySQL replication gives us the file name of the binlog. This value is therefore cached until the next Rotate event, which would give us the next file name. So we have to set this filename here?

well, why can't we use a separate currentFilename variable to cache the current filename?

the current filename needs a clear separation from the resumable position.

fix resumable binlog position after interrupt

fe43779

fjordan mentioned this pull request Apr 8, 2020

Fix resuming binlog streaming #156 #160

Open

fjordan requested review from hkdsun and shuhaowu April 8, 2020 17:56

Decrease log level and increase open file limit for CI

b3cd656

fjordan force-pushed the feature/fix-resuming-binlog-position branch 2 times, most recently from 2f562cb to b3cd656 Compare April 8, 2020 20:36

hkdsun reviewed Apr 9, 2020

View reviewed changes

Comment thread binlog_streamer.go

hkdsun reviewed Apr 13, 2020

View reviewed changes

fjordan force-pushed the feature/fix-resuming-binlog-position branch from 2bb8be2 to 2df4712 Compare April 13, 2020 19:53

explicitly set last resumable binlog position on XID and GTID events

38f9c93

fjordan force-pushed the feature/fix-resuming-binlog-position branch from 2df4712 to 38f9c93 Compare April 13, 2020 19:54

Add explanation of using GTID and XIDEvents to set last resumable pos…

9bf9684

…ition

hkdsun approved these changes Apr 13, 2020

View reviewed changes

shuhaowu reviewed Apr 13, 2020

View reviewed changes

set initial last resumable position during connect

d2dc8cc

fjordan force-pushed the feature/fix-resuming-binlog-position branch from c2a79fd to d2dc8cc Compare April 13, 2020 22:18

hkdsun approved these changes Apr 14, 2020

View reviewed changes

hkdsun reviewed Apr 14, 2020

View reviewed changes

shuhaowu approved these changes Apr 14, 2020

View reviewed changes

fjordan merged commit 509aeda into master Apr 14, 2020

fjordan deleted the feature/fix-resuming-binlog-position branch April 14, 2020 14:14

shuhaowu mentioned this pull request Jun 23, 2020

Resuming ghostferry-copydb after interrupt fails due to missed TableMapEvent #156

Open

Conversation

fjordan commented Apr 8, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Uh oh!

hkdsun left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

fjordan Apr 13, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

hkdsun left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

fjordan commented Apr 8, 2020 •

edited

Loading

fjordan Apr 13, 2020 •

edited

Loading