github / github/gh-ost

Failed Gh-ost hook Not Propagating to Gh-ost script

Open
#801 0 comments 0 reactions 0 assignees View on GitHub
Dominant language
Go
Stars
13.6k
Forks
1.4k
Avg merge
2h 31m
Merged PRs (30d)
4

Description

Summary: when the gh-ost-on-begin-postponed hook returns an error, I expect gh-ost to abort the entire migration. But this is not happening in this case.

The gh-ost-on-begin-postponed looks like this which intentionally has a syntax error:
```
$ cat /tmp/ghost_hooks/gh-ost-on-begin-postponed
#!/bin/sh

xcurl
```

This is the command that is executed:
```
[root@16-04 gh-ost]$ bin/gh-ost \
--user=root \
--password=root \
--database=jcua \
--table=hello \
--alter='add column boo int' \
--verbose \
--allow-on-master \
--initially-drop-old-table \
--initially-drop-ghost-table \
--initially-drop-socket-file \
--postpone-cut-over-flag-file=/tmp/ghost.postpone.flag \
--hooks-path=/tmp/ghost_hooks \
--execute
```

The relevant log lines are these:
```
2019-11-18 15:54:19 INFO Row copy complete
# Migrating `jcua`.`hello`; Ghost table is `jcua`.`_hello_gho`
# Migrating 16-04:3306; inspecting 16-04:3306; executing on 16-04
# Migration started at Mon Nov 18 15:54:19 -0800 2019
# chunk-size: 1000; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000
# throttle-additional-flag-file: /tmp/gh-ost.throttle
# postpone-cut-over-flag-file: /tmp/ghost.postpone.flag [set]
# Serving on unix socket: /tmp/gh-ost.jcua.hello.sock
Copy: 0/1 0.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000029:63775115; Lag: 0.00s, State: migrating; ETA: N/A
Copy: 0/0 100.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000029:63775115; Lag: 0.00s, State: migrating; ETA: due
2019-11-18 15:54:19 INFO executing gh-ost-on-begin-postponed hook: /tmp/ghost_hooks/gh-ost-on-begin-postponed
/tmp/ghost_hooks/gh-ost-on-begin-postponed: 3: /tmp/ghost_hooks/gh-ost-on-begin-postponed: xcurl: not found

2019-11-18 15:54:19 ERROR exit status 127
2019-11-18 15:54:19 INFO Grabbing voluntary lock: gh-ost.97478.lock
2019-11-18 15:54:19 INFO Setting LOCK timeout as 6 seconds
2019-11-18 15:54:19 INFO Looking for magic cut-over table
2019-11-18 15:54:19 INFO Creating magic cut-over table `jcua`.`_hello_del`
2019-11-18 15:54:19 INFO Magic cut-over table created
2019-11-18 15:54:19 INFO Locking `jcua`.`hello`, `jcua`.`_hello_del`
2019-11-18 15:54:19 INFO Tables locked
2019-11-18 15:54:19 INFO Session locking original & magic tables is 97478
2019-11-18 15:54:19 INFO Writing changelog state: AllEventsUpToLockProcessed:1574121259137364883
```
Notice that the gh-ost-on-begin-postponed hook gave an error, and yet gh-ost continued with the cutover even though there was a postpone flag that was set.

According to the documentation:
```
A hook returning with error code will propagate the error in gh-ost. Thus, you are able to force gh-ost to fail migration on your conditions.
Make sure to only return an error code when you do indeed wish to fail the rest of the migration
```

In the above case, gh-ost should have stopped when it encountered an error with the gh-ost-on-begin-postponed hook, right?

When I changed the code to this:
```
diff --git a/go/logic/migrator.go b/go/logic/migrator.go
index b1a238f..5371cf8 100644
--- a/go/logic/migrator.go
+++ b/go/logic/migrator.go
@@ -475,7 +475,7 @@ func (this *Migrator) cutOver() (err error) {

this.migrationContext.MarkPointOfInterest()
log.Debugf("checking for cut-over postpone")
- this.sleepWhileTrue(
+ sleepErr := this.sleepWhileTrue(
func() (bool, error) {
if this.migrationContext.PostponeCutOverFlagFile == "" {
return false, nil
@@ -497,6 +497,10 @@ func (this *Migrator) cutOver() (err error) {
return false, nil
},
)
+
+ if sleepErr != nil {
+ this.migrationContext.PanicAbort <- err
+ }
atomic.StoreInt64(&this.migrationContext.IsPostponingCutOver, 0)
this.migrationContext.MarkPointOfInterest()
log.Debugf("checking for cut-over postpone: complete")
```

and re-ran gh-ost, this is what I got
```
# chunk-size: 1000; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000
# throttle-additional-flag-file: /tmp/gh-ost.throttle
# postpone-cut-over-flag-file: /tmp/ghost.postpone.flag [set]
# Serving on unix socket: /tmp/gh-ost.jcua.hello.sock
Copy: 0/0 100.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000029:63798968; Lag: 0.01s, State: migrating; ETA: due
2019-11-18 16:01:09 INFO executing gh-ost-on-begin-postponed hook: /tmp/ghost_hooks/gh-ost-on-begin-postponed
Copy: 0/1 0.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000029:63798968; Lag: 0.01s, State: migrating; ETA: N/A
/tmp/ghost_hooks/gh-ost-on-begin-postponed: 3: /tmp/ghost_hooks/gh-ost-on-begin-postponed: xcurl: not found

2019-11-18 16:01:09 ERROR exit status 127
```

gh-ost stopped and this is what I expected. Am I mis-reading the documentation on this?

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.