gh-ost icon indicating copy to clipboard operation
gh-ost copied to clipboard

_ghc table has been dropped before copying ends

Open pznamensky opened this issue 8 years ago • 4 comments

Hi, Something strange happened. _ghc table has been dropped before copying ends. Is this expected behaviour?

2017-09-14 10:27:53 INFO Droppping table `test`.`_table_ghc`
2017-09-14 10:27:53 INFO Table dropped
2017-09-14 10:27:53 INFO Droppping table `test`.`_table_del`
2017-09-14 10:27:53 ERROR Error 1146: Table 'test._table_ghc' doesn't exist
Copy: 22417847/22417847 100.0%; Applied: 352; Backlog: 0/1000; Time: 9m15s(total), 9m12s(copy); streamer: mysql-bin.002906:714245194; State: throttled, max-load Threads_running=68 >= 20; ETA: due

Full log:

~ $ gh-ost \
> --max-load=Threads_running=20 \
> --critical-load=Threads_running=1000 \
> --chunk-size=1000 \
> --heartbeat-interval-millis=100 \
> --max-lag-millis=500 \
> --host=127.0.0.1 \
> --allow-on-master \
> --verbose \
> --allow-master-master \
> --cut-over=default \
> --exact-rowcount \
> --concurrent-rowcount \
> --default-retries=60 \
> --panic-flag-file=/tmp/ghost.panic.flag \
> --postpone-cut-over-flag-file=/tmp/ghost.postpone.flag \
> --ok-to-drop-table \
> --user="user" \
> --password="password" \
> --database="test" \
> --table="table" \
> --initially-drop-ghost-table \
> --execute \
> --alter="ADD INDEX index_table_on_created_at (created_at)" \
> --throttle-control-replicas="mysql-slave"

2017-09-14 10:18:39 INFO starting gh-ost 1.0.40
2017-09-14 10:18:39 INFO Migrating `test`.`table`
2017-09-14 10:18:39 INFO connection validated on 127.0.0.1:3306
2017-09-14 10:18:39 INFO User has ALL privileges
2017-09-14 10:18:39 INFO binary logs validated on 127.0.0.1:3306
2017-09-14 10:18:39 INFO Restarting replication on 127.0.0.1:3306 to make sure binlog settings apply to replication thread
2017-09-14 10:18:39 INFO Inspector initiated on mysql-master:3306, version 10.1.20-MariaDB
2017-09-14 10:18:39 INFO Table found. Engine=InnoDB
2017-09-14 10:18:39 INFO Estimated number of rows via EXPLAIN: 20959399
2017-09-14 10:18:39 INFO Recursively searching for replication master
2017-09-14 10:18:39 INFO Master found to be mysql-master:3306
2017-09-14 10:18:39 WARNING log_slave_updates not found on 127.0.0.1:3306, but executing directly on master, so I'm proceeeding
2017-09-14 10:18:39 INFO connection validated on 127.0.0.1:3306
2017/09/14 10:18:39 binlogsyncer.go:75: [info] create BinlogSyncer with config &{99999 mysql 127.0.0.1 3306 perconauser Cri846WvFg  false false <nil>}
2017-09-14 10:18:39 INFO Connecting binlog streamer at mysql-bin.002903:154564212
2017/09/14 10:18:39 binlogsyncer.go:241: [info] begin to sync binlog from position (mysql-bin.002903, 154564212)
2017/09/14 10:18:39 binlogsyncer.go:134: [info] register slave for master server 127.0.0.1:3306
2017-09-14 10:18:39 INFO connection validated on 127.0.0.1:3306
2017-09-14 10:18:39 INFO connection validated on 127.0.0.1:3306
2017-09-14 10:18:39 INFO will use time_zone='SYSTEM' on applier
2017/09/14 10:18:39 binlogsyncer.go:568: [info] rotate to (mysql-bin.002903, 154564212)
2017-09-14 10:18:39 INFO rotate to next log name: mysql-bin.002903
2017-09-14 10:18:39 INFO Examining table structure on applier
2017-09-14 10:18:39 INFO Applier initiated on mysql-master:3306, version 10.1.20-MariaDB
2017-09-14 10:18:39 INFO Droppping table `test`.`_table_gho`
2017-09-14 10:18:39 INFO Table dropped
2017-09-14 10:18:39 INFO Droppping table `test`.`_table_ghc`
2017-09-14 10:18:39 INFO Table dropped
2017-09-14 10:18:39 INFO Creating changelog table `test`.`_table_ghc`
2017-09-14 10:18:39 INFO Changelog table created
2017-09-14 10:18:39 INFO Creating ghost table `test`.`_table_gho`
2017-09-14 10:18:39 INFO Ghost table created
2017-09-14 10:18:39 INFO Altering ghost table `test`.`_table_gho`
2017-09-14 10:18:39 INFO Ghost table altered
2017-09-14 10:18:39 INFO Intercepted changelog state GhostTableMigrated
2017-09-14 10:18:39 INFO Waiting for ghost table to be migrated. Current lag is 0s
2017-09-14 10:18:39 INFO Handled changelog state GhostTableMigrated
2017-09-14 10:18:39 INFO Chosen shared unique key is PRIMARY
2017-09-14 10:18:39 INFO Shared columns are ...
2017-09-14 10:18:39 INFO Listening on unix socket file: /tmp/gh-ost.test.table.sock
2017-09-14 10:18:39 INFO As instructed, counting rows in the background; meanwhile I will use an estimated count, and will update it later on
2017-09-14 10:18:39 INFO As instructed, I'm issuing a SELECT COUNT(*) on the table. This may take a while
2017-09-14 10:18:39 INFO Migration min values: [5712]
2017-09-14 10:18:39 INFO Migration max values: [22459727]
2017-09-14 10:18:39 INFO Waiting for first throttle metrics to be collected
2017-09-14 10:18:39 INFO First throttle metrics collected
# Migrating `test`.`table`; Ghost table is `test`.`_table_gho`
# Migrating mysql-master:3306; inspecting mysql-master:3306; executing on mysql-master
# Migration started at Thu Sep 14 10:18:39 +0300 2017
# chunk-size: 1000; max-lag-millis: 500ms; dml-batch-size: 10; max-load: Threads_running=20; critical-load: Threads_running=1000; nice-ratio: 0.000000
# throttle-additional-flag-file: /tmp/gh-ost.throttle
# throttle-control-replicas count: 1
# postpone-cut-over-flag-file: /tmp/ghost.postpone.flag
# panic-flag-file: /tmp/ghost.panic.flag
# Serving on unix socket: /tmp/gh-ost.test.table.sock
Copy: 0/20959399 0.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.002903:154571816; State: migrating; ETA: N/A
Copy: 0/20959399 0.0%; Applied: 0; Backlog: 0/1000; Time: 1s(total), 1s(copy); streamer: mysql-bin.002903:154829132; State: migrating; ETA: N/A
Copy: 27000/20959399 0.1%; Applied: 0; Backlog: 0/1000; Time: 2s(total), 2s(copy); streamer: mysql-bin.002903:162717827; State: migrating; ETA: N/A
Copy: 59000/20959399 0.3%; Applied: 0; Backlog: 0/1000; Time: 3s(total), 3s(copy); streamer: mysql-bin.002903:173483307; State: migrating; ETA: N/A
Copy: 89000/20959400 0.4%; Applied: 1; Backlog: 0/1000; Time: 4s(total), 4s(copy); streamer: mysql-bin.002903:190755821; State: migrating; ETA: N/A
2017-09-14 10:18:43 INFO Exact number of rows via COUNT: 22417847
Copy: 122000/22417848 0.5%; Applied: 3; Backlog: 0/1000; Time: 5s(total), 5s(copy); streamer: mysql-bin.002903:209835106; State: migrating; ETA: N/A
Copy: 156000/22417848 0.7%; Applied: 3; Backlog: 0/1000; Time: 6s(total), 6s(copy); streamer: mysql-bin.002903:229251103; State: migrating; ETA: N/A
Copy: 192000/22417848 0.9%; Applied: 3; Backlog: 0/1000; Time: 7s(total), 7s(copy); streamer: mysql-bin.002903:250276927; State: migrating; ETA: N/A
Copy: 233000/22417848 1.0%; Applied: 3; Backlog: 0/1000; Time: 8s(total), 8s(copy); streamer: mysql-bin.002903:262960281; State: migrating; ETA: 12m41s
Copy: 279000/22417848 1.2%; Applied: 3; Backlog: 0/1000; Time: 9s(total), 9s(copy); streamer: mysql-bin.002903:275155492; State: migrating; ETA: 11m54s
Copy: 324000/22417848 1.4%; Applied: 3; Backlog: 0/1000; Time: 10s(total), 10s(copy); streamer: mysql-bin.002903:286982394; State: migrating; ETA: 11m21s
Copy: 370000/22417848 1.7%; Applied: 3; Backlog: 0/1000; Time: 11s(total), 11s(copy); streamer: mysql-bin.002903:297767161; State: migrating; ETA: 10m55s
Copy: 421000/22417848 1.9%; Applied: 3; Backlog: 0/1000; Time: 12s(total), 12s(copy); streamer: mysql-bin.002903:302436164; State: migrating; ETA: 10m27s
Copy: 475000/22417848 2.1%; Applied: 3; Backlog: 0/1000; Time: 13s(total), 13s(copy); streamer: mysql-bin.002903:307296707; State: migrating; ETA: 10m0s
Copy: 528000/22417848 2.4%; Applied: 3; Backlog: 0/1000; Time: 14s(total), 14s(copy); streamer: mysql-bin.002903:312080755; State: migrating; ETA: 9m40s
Copy: 576000/22417848 2.6%; Applied: 3; Backlog: 0/1000; Time: 15s(total), 15s(copy); streamer: mysql-bin.002903:318554424; State: migrating; ETA: 9m28s
Copy: 619000/22417848 2.8%; Applied: 3; Backlog: 0/1000; Time: 16s(total), 16s(copy); streamer: mysql-bin.002903:325560449; State: migrating; ETA: 9m23s
Copy: 666000/22417848 3.0%; Applied: 3; Backlog: 0/1000; Time: 17s(total), 17s(copy); streamer: mysql-bin.002903:332882197; State: migrating; ETA: 9m15s
Copy: 709000/22417848 3.2%; Applied: 3; Backlog: 0/1000; Time: 18s(total), 18s(copy); streamer: mysql-bin.002903:339451908; State: migrating; ETA: 9m11s
Copy: 754000/22417848 3.4%; Applied: 3; Backlog: 0/1000; Time: 19s(total), 19s(copy); streamer: mysql-bin.002903:346292453; State: migrating; ETA: 9m5s
Copy: 767000/22417848 3.4%; Applied: 3; Backlog: 0/1000; Time: 20s(total), 20s(copy); streamer: mysql-bin.002903:348279177; State: migrating; ETA: 9m24s
Copy: 779000/22417848 3.5%; Applied: 3; Backlog: 0/1000; Time: 21s(total), 21s(copy); streamer: mysql-bin.002903:350079394; State: migrating; ETA: 9m43s
Copy: 786000/22417848 3.5%; Applied: 3; Backlog: 0/1000; Time: 22s(total), 22s(copy); streamer: mysql-bin.002903:351003357; State: migrating; ETA: 10m5s
Copy: 805000/22417848 3.6%; Applied: 3; Backlog: 0/1000; Time: 23s(total), 23s(copy); streamer: mysql-bin.002903:353898359; State: migrating; ETA: 10m17s
Copy: 821000/22417848 3.7%; Applied: 3; Backlog: 0/1000; Time: 24s(total), 24s(copy); streamer: mysql-bin.002903:356201121; State: migrating; ETA: 10m31s
Copy: 839000/22417848 3.7%; Applied: 3; Backlog: 0/1000; Time: 25s(total), 25s(copy); streamer: mysql-bin.002903:358940100; State: migrating; ETA: 10m43s
Copy: 856000/22417848 3.8%; Applied: 3; Backlog: 0/1000; Time: 26s(total), 26s(copy); streamer: mysql-bin.002903:361455981; State: migrating; ETA: 10m54s
Copy: 871000/22417848 3.9%; Applied: 3; Backlog: 0/1000; Time: 27s(total), 27s(copy); streamer: mysql-bin.002903:363861694; State: migrating; ETA: 11m7s
Copy: 892000/22417848 4.0%; Applied: 3; Backlog: 0/1000; Time: 28s(total), 28s(copy); streamer: mysql-bin.002903:366907842; State: migrating; ETA: 11m15s
Copy: 919000/22417848 4.1%; Applied: 3; Backlog: 0/1000; Time: 29s(total), 29s(copy); streamer: mysql-bin.002903:370928717; State: migrating; ETA: 11m18s
Copy: 926000/22417848 4.1%; Applied: 3; Backlog: 0/1000; Time: 30s(total), 30s(copy); streamer: mysql-bin.002903:371948391; State: migrating; ETA: 11m36s
Copy: 927000/22417848 4.1%; Applied: 3; Backlog: 1/1000; Time: 31s(total), 31s(copy); streamer: mysql-bin.002903:372206251; State: throttled, max-load Threads_running=35 >= 20; ETA: 11m58s
Copy: 959000/22417849 4.3%; Applied: 6; Backlog: 0/1000; Time: 32s(total), 32s(copy); streamer: mysql-bin.002903:377131491; State: migrating; ETA: 11m56s
Copy: 1003000/22417849 4.5%; Applied: 6; Backlog: 0/1000; Time: 33s(total), 33s(copy); streamer: mysql-bin.002903:383344877; State: migrating; ETA: 11m44s
Copy: 1045000/22417849 4.7%; Applied: 6; Backlog: 0/1000; Time: 34s(total), 34s(copy); streamer: mysql-bin.002903:389656622; State: migrating; ETA: 11m35s
Copy: 1088000/22417849 4.9%; Applied: 6; Backlog: 0/1000; Time: 35s(total), 35s(copy); streamer: mysql-bin.002903:395948842; State: migrating; ETA: 11m26s
Copy: 1131000/22417849 5.0%; Applied: 6; Backlog: 0/1000; Time: 36s(total), 36s(copy); streamer: mysql-bin.002903:402663972; State: migrating; ETA: 11m17s
Copy: 1173000/22417849 5.2%; Applied: 6; Backlog: 0/1000; Time: 37s(total), 37s(copy); streamer: mysql-bin.002903:409258327; State: migrating; ETA: 11m10s
Copy: 1217000/22417849 5.4%; Applied: 6; Backlog: 0/1000; Time: 38s(total), 38s(copy); streamer: mysql-bin.002903:415903475; State: migrating; ETA: 11m1s
Copy: 1260000/22417849 5.6%; Applied: 6; Backlog: 0/1000; Time: 39s(total), 39s(copy); streamer: mysql-bin.002903:422318651; State: migrating; ETA: 10m54s
Copy: 1301000/22417849 5.8%; Applied: 6; Backlog: 0/1000; Time: 40s(total), 40s(copy); streamer: mysql-bin.002903:428730120; State: migrating; ETA: 10m49s
Copy: 1346000/22417849 6.0%; Applied: 7; Backlog: 0/1000; Time: 41s(total), 41s(copy); streamer: mysql-bin.002903:435691899; State: migrating; ETA: 10m41s
Copy: 1389000/22417849 6.2%; Applied: 19; Backlog: 0/1000; Time: 42s(total), 42s(copy); streamer: mysql-bin.002903:442366912; State: migrating; ETA: 10m35s
Copy: 1431000/22417849 6.4%; Applied: 20; Backlog: 0/1000; Time: 43s(total), 43s(copy); streamer: mysql-bin.002903:448822306; State: migrating; ETA: 10m30s
Copy: 1475000/22417849 6.6%; Applied: 20; Backlog: 0/1000; Time: 44s(total), 44s(copy); streamer: mysql-bin.002903:455435468; State: migrating; ETA: 10m24s
Copy: 1520000/22417849 6.8%; Applied: 20; Backlog: 0/1000; Time: 45s(total), 45s(copy); streamer: mysql-bin.002903:461447820; State: migrating; ETA: 10m18s
Copy: 1562000/22417850 7.0%; Applied: 21; Backlog: 0/1000; Time: 46s(total), 46s(copy); streamer: mysql-bin.002903:466670894; State: migrating; ETA: 10m14s
Copy: 1602000/22417850 7.1%; Applied: 21; Backlog: 0/1000; Time: 47s(total), 47s(copy); streamer: mysql-bin.002903:472530866; State: migrating; ETA: 10m10s
Copy: 1641000/22417850 7.3%; Applied: 21; Backlog: 0/1000; Time: 48s(total), 48s(copy); streamer: mysql-bin.002903:478481598; State: migrating; ETA: 10m7s
Copy: 1681000/22417850 7.5%; Applied: 21; Backlog: 0/1000; Time: 49s(total), 49s(copy); streamer: mysql-bin.002903:484642893; State: migrating; ETA: 10m4s
Copy: 1723000/22417850 7.7%; Applied: 21; Backlog: 0/1000; Time: 50s(total), 50s(copy); streamer: mysql-bin.002903:490634910; State: migrating; ETA: 10m0s
Copy: 1765000/22417850 7.9%; Applied: 21; Backlog: 0/1000; Time: 51s(total), 51s(copy); streamer: mysql-bin.002903:496598459; State: migrating; ETA: 9m56s
Copy: 1808000/22417850 8.1%; Applied: 21; Backlog: 0/1000; Time: 52s(total), 52s(copy); streamer: mysql-bin.002903:504100791; State: migrating; ETA: 9m52s
Copy: 1850000/22417850 8.3%; Applied: 21; Backlog: 0/1000; Time: 53s(total), 53s(copy); streamer: mysql-bin.002903:512052776; State: migrating; ETA: 9m49s
Copy: 1892000/22417850 8.4%; Applied: 21; Backlog: 0/1000; Time: 54s(total), 54s(copy); streamer: mysql-bin.002903:520442737; State: migrating; ETA: 9m45s
Copy: 1930000/22417850 8.6%; Applied: 21; Backlog: 0/1000; Time: 55s(total), 55s(copy); streamer: mysql-bin.002903:527785192; State: migrating; ETA: 9m43s
Copy: 1971000/22417850 8.8%; Applied: 21; Backlog: 0/1000; Time: 56s(total), 56s(copy); streamer: mysql-bin.002903:536209752; State: migrating; ETA: 9m40s
Copy: 2013000/22417850 9.0%; Applied: 21; Backlog: 0/1000; Time: 57s(total), 57s(copy); streamer: mysql-bin.002903:544370591; State: migrating; ETA: 9m37s
Copy: 2056000/22417850 9.2%; Applied: 21; Backlog: 0/1000; Time: 58s(total), 58s(copy); streamer: mysql-bin.002903:552625479; State: migrating; ETA: 9m34s
Copy: 2099000/22417850 9.4%; Applied: 21; Backlog: 0/1000; Time: 59s(total), 59s(copy); streamer: mysql-bin.002903:561437077; State: migrating; ETA: 9m31s
Copy: 2140000/22417850 9.5%; Applied: 21; Backlog: 0/1000; Time: 1m0s(total), 1m0s(copy); streamer: mysql-bin.002903:569736135; State: migrating; ETA: 9m28s
Copy: 2349000/22417850 10.5%; Applied: 25; Backlog: 0/1000; Time: 1m5s(total), 1m5s(copy); streamer: mysql-bin.002903:610637067; State: migrating; ETA: 9m15s
Copy: 2545000/22417850 11.4%; Applied: 29; Backlog: 0/1000; Time: 1m10s(total), 1m10s(copy); streamer: mysql-bin.002903:649246081; State: migrating; ETA: 9m6s
Copy: 2758000/22417854 12.3%; Applied: 35; Backlog: 0/1000; Time: 1m15s(total), 1m15s(copy); streamer: mysql-bin.002903:687579008; State: migrating; ETA: 8m54s
Copy: 2973000/22417854 13.3%; Applied: 35; Backlog: 0/1000; Time: 1m20s(total), 1m20s(copy); streamer: mysql-bin.002903:726316897; State: migrating; ETA: 8m43s
Copy: 3190000/22417854 14.2%; Applied: 35; Backlog: 0/1000; Time: 1m25s(total), 1m25s(copy); streamer: mysql-bin.002903:766308196; State: migrating; ETA: 8m32s
Copy: 3400000/22417854 15.2%; Applied: 35; Backlog: 0/1000; Time: 1m30s(total), 1m30s(copy); streamer: mysql-bin.002903:804284095; State: migrating; ETA: 8m23s
Copy: 3607000/22417854 16.1%; Applied: 35; Backlog: 0/1000; Time: 1m35s(total), 1m35s(copy); streamer: mysql-bin.002903:841979014; State: migrating; ETA: 8m15s
Copy: 3795000/22417854 16.9%; Applied: 35; Backlog: 0/1000; Time: 1m40s(total), 1m40s(copy); streamer: mysql-bin.002903:877410814; State: migrating; ETA: 8m10s
Copy: 4009000/22417854 17.9%; Applied: 35; Backlog: 0/1000; Time: 1m45s(total), 1m45s(copy); streamer: mysql-bin.002903:917144271; State: migrating; ETA: 8m2s
Copy: 4213000/22417854 18.8%; Applied: 35; Backlog: 0/1000; Time: 1m50s(total), 1m50s(copy); streamer: mysql-bin.002903:956846840; State: migrating; ETA: 7m55s
Copy: 4421000/22417854 19.7%; Applied: 45; Backlog: 0/1000; Time: 1m55s(total), 1m55s(copy); streamer: mysql-bin.002903:995390456; State: migrating; ETA: 7m48s
Copy: 4631000/22417854 20.7%; Applied: 45; Backlog: 0/1000; Time: 2m0s(total), 2m0s(copy); streamer: mysql-bin.002903:1032239036; State: migrating; ETA: 7m40s
Copy: 4841000/22417854 21.6%; Applied: 45; Backlog: 0/1000; Time: 2m5s(total), 2m5s(copy); streamer: mysql-bin.002903:1071141988; State: migrating; ETA: 7m33s
2017/09/14 10:20:45 binlogsyncer.go:568: [info] rotate to (mysql-bin.002904, 4)
2017/09/14 10:20:45 binlogsyncer.go:568: [info] rotate to (mysql-bin.002904, 4)
2017-09-14 10:20:45 INFO rotate to next log name: mysql-bin.002904
2017-09-14 10:20:45 INFO rotate to next log name: mysql-bin.002904
Copy: 5018000/22417854 22.4%; Applied: 45; Backlog: 0/1000; Time: 2m10s(total), 2m10s(copy); streamer: mysql-bin.002904:26896719; State: migrating; ETA: 7m30s
Copy: 5233000/22417856 23.3%; Applied: 51; Backlog: 0/1000; Time: 2m15s(total), 2m15s(copy); streamer: mysql-bin.002904:64966036; State: migrating; ETA: 7m23s
Copy: 5443000/22417857 24.3%; Applied: 61; Backlog: 0/1000; Time: 2m20s(total), 2m20s(copy); streamer: mysql-bin.002904:102507055; State: migrating; ETA: 7m16s
Copy: 5662000/22417857 25.3%; Applied: 61; Backlog: 0/1000; Time: 2m25s(total), 2m25s(copy); streamer: mysql-bin.002904:137810137; State: migrating; ETA: 7m9s
Copy: 5882000/22417858 26.2%; Applied: 62; Backlog: 0/1000; Time: 2m30s(total), 2m30s(copy); streamer: mysql-bin.002904:174585828; State: migrating; ETA: 7m1s
Copy: 6129000/22417858 27.3%; Applied: 66; Backlog: 0/1000; Time: 2m35s(total), 2m35s(copy); streamer: mysql-bin.002904:202300857; State: migrating; ETA: 6m51s
Copy: 6389000/22417858 28.5%; Applied: 66; Backlog: 0/1000; Time: 2m40s(total), 2m40s(copy); streamer: mysql-bin.002904:231057884; State: migrating; ETA: 6m41s
Copy: 6616000/22417858 29.5%; Applied: 66; Backlog: 0/1000; Time: 2m45s(total), 2m45s(copy); streamer: mysql-bin.002904:256131798; State: migrating; ETA: 6m34s
Copy: 6862000/22417859 30.6%; Applied: 67; Backlog: 0/1000; Time: 2m50s(total), 2m50s(copy); streamer: mysql-bin.002904:283876844; State: migrating; ETA: 6m25s
Copy: 7103000/22417859 31.7%; Applied: 67; Backlog: 0/1000; Time: 2m55s(total), 2m55s(copy); streamer: mysql-bin.002904:313896640; State: migrating; ETA: 6m17s
Copy: 7338000/22417859 32.7%; Applied: 67; Backlog: 0/1000; Time: 3m0s(total), 3m0s(copy); streamer: mysql-bin.002904:346141609; State: migrating; ETA: 6m9s
Copy: 8727000/22417863 38.9%; Applied: 84; Backlog: 0/1000; Time: 3m30s(total), 3m30s(copy); streamer: mysql-bin.002904:523463642; State: migrating; ETA: 5m29s
Copy: 10022000/22417865 44.7%; Applied: 101; Backlog: 0/1000; Time: 4m0s(total), 4m0s(copy); streamer: mysql-bin.002904:731418234; State: migrating; ETA: 4m56s
Copy: 11290000/22417876 50.4%; Applied: 141; Backlog: 0/1000; Time: 4m30s(total), 4m30s(copy); streamer: mysql-bin.002904:950920829; State: migrating; ETA: 4m26s
2017/09/14 10:23:27 binlogsyncer.go:568: [info] rotate to (mysql-bin.002905, 4)
2017/09/14 10:23:27 binlogsyncer.go:568: [info] rotate to (mysql-bin.002905, 4)
2017-09-14 10:23:27 INFO rotate to next log name: mysql-bin.002905
2017-09-14 10:23:27 INFO rotate to next log name: mysql-bin.002905
Copy: 12493000/22417877 55.7%; Applied: 144; Backlog: 0/1000; Time: 5m0s(total), 5m0s(copy); streamer: mysql-bin.002905:86123865; State: migrating; ETA: 3m58s
Copy: 13701000/22417879 61.1%; Applied: 167; Backlog: 0/1000; Time: 5m30s(total), 5m30s(copy); streamer: mysql-bin.002905:290105405; State: migrating; ETA: 3m29s
Copy: 14891000/22417882 66.4%; Applied: 188; Backlog: 0/1000; Time: 6m0s(total), 6m0s(copy); streamer: mysql-bin.002905:497909965; State: migrating; ETA: 3m1s
Copy: 15085000/22417883 67.3%; Applied: 191; Backlog: 0/1000; Time: 6m5s(total), 6m5s(copy); streamer: mysql-bin.002905:531698615; State: migrating; ETA: 2m57s
Copy: 15272000/22417884 68.1%; Applied: 195; Backlog: 0/1000; Time: 6m10s(total), 6m10s(copy); streamer: mysql-bin.002905:566415428; State: migrating; ETA: 2m53s
Copy: 15481000/22417884 69.1%; Applied: 196; Backlog: 0/1000; Time: 6m15s(total), 6m15s(copy); streamer: mysql-bin.002905:601845692; State: migrating; ETA: 2m48s
Copy: 15674000/22417884 69.9%; Applied: 198; Backlog: 0/1000; Time: 6m20s(total), 6m20s(copy); streamer: mysql-bin.002905:635411692; State: migrating; ETA: 2m43s
Copy: 15843000/22417885 70.7%; Applied: 199; Backlog: 0/1000; Time: 6m25s(total), 6m25s(copy); streamer: mysql-bin.002905:665405144; State: migrating; ETA: 2m39s
Copy: 16041000/22417885 71.6%; Applied: 199; Backlog: 0/1000; Time: 6m30s(total), 6m30s(copy); streamer: mysql-bin.002905:697593101; State: migrating; ETA: 2m35s
Copy: 16240000/22417886 72.4%; Applied: 201; Backlog: 0/1000; Time: 6m35s(total), 6m35s(copy); streamer: mysql-bin.002905:733350586; State: migrating; ETA: 2m30s
Copy: 16435000/22417886 73.3%; Applied: 201; Backlog: 0/1000; Time: 6m40s(total), 6m40s(copy); streamer: mysql-bin.002905:768344714; State: migrating; ETA: 2m25s
Copy: 16641000/22417888 74.2%; Applied: 210; Backlog: 0/1000; Time: 6m45s(total), 6m45s(copy); streamer: mysql-bin.002905:803266286; State: migrating; ETA: 2m20s
Copy: 16841000/22417932 75.1%; Applied: 268; Backlog: 0/1000; Time: 6m50s(total), 6m50s(copy); streamer: mysql-bin.002905:838991995; State: migrating; ETA: 2m15s
Copy: 17016000/22417932 75.9%; Applied: 270; Backlog: 0/1000; Time: 6m55s(total), 6m55s(copy); streamer: mysql-bin.002905:869482074; State: migrating; ETA: 2m11s
Copy: 17221000/22417934 76.8%; Applied: 273; Backlog: 0/1000; Time: 7m0s(total), 7m0s(copy); streamer: mysql-bin.002905:901918286; State: migrating; ETA: 2m6s
Copy: 17426000/22417934 77.7%; Applied: 274; Backlog: 0/1000; Time: 7m5s(total), 7m5s(copy); streamer: mysql-bin.002905:938134183; State: migrating; ETA: 2m1s
Copy: 17633000/22417934 78.7%; Applied: 274; Backlog: 0/1000; Time: 7m10s(total), 7m10s(copy); streamer: mysql-bin.002905:974880029; State: migrating; ETA: 1m56s
Copy: 17833000/22417935 79.5%; Applied: 275; Backlog: 0/1000; Time: 7m15s(total), 7m15s(copy); streamer: mysql-bin.002905:1009238206; State: migrating; ETA: 1m51s
Copy: 18038000/22417935 80.5%; Applied: 279; Backlog: 0/1000; Time: 7m20s(total), 7m20s(copy); streamer: mysql-bin.002905:1043177473; State: migrating; ETA: 1m46s
Copy: 18209000/22417935 81.2%; Applied: 280; Backlog: 0/1000; Time: 7m25s(total), 7m25s(copy); streamer: mysql-bin.002905:1071926775; State: migrating; ETA: 1m42s
2017/09/14 10:26:05 binlogsyncer.go:568: [info] rotate to (mysql-bin.002906, 4)
2017/09/14 10:26:05 binlogsyncer.go:568: [info] rotate to (mysql-bin.002906, 4)
2017-09-14 10:26:05 INFO rotate to next log name: mysql-bin.002906
2017-09-14 10:26:05 INFO rotate to next log name: mysql-bin.002906
Copy: 18405000/22417935 82.1%; Applied: 282; Backlog: 0/1000; Time: 7m30s(total), 7m30s(copy); streamer: mysql-bin.002906:32639008; State: migrating; ETA: 1m38s
Copy: 18612000/22417938 83.0%; Applied: 294; Backlog: 0/1000; Time: 7m35s(total), 7m35s(copy); streamer: mysql-bin.002906:66306463; State: migrating; ETA: 1m33s
Copy: 18822000/22417940 84.0%; Applied: 298; Backlog: 0/1000; Time: 7m40s(total), 7m40s(copy); streamer: mysql-bin.002906:101801650; State: migrating; ETA: 1m27s
Copy: 19022000/22417940 84.9%; Applied: 300; Backlog: 0/1000; Time: 7m45s(total), 7m45s(copy); streamer: mysql-bin.002906:136572812; State: migrating; ETA: 1m23s
Copy: 19232000/22417940 85.8%; Applied: 300; Backlog: 0/1000; Time: 7m50s(total), 7m50s(copy); streamer: mysql-bin.002906:174141169; State: migrating; ETA: 1m17s
Copy: 19433000/22417941 86.7%; Applied: 301; Backlog: 0/1000; Time: 7m55s(total), 7m55s(copy); streamer: mysql-bin.002906:208186200; State: migrating; ETA: 1m12s
Copy: 19614000/22417941 87.5%; Applied: 301; Backlog: 0/1000; Time: 8m0s(total), 8m0s(copy); streamer: mysql-bin.002906:239195238; State: migrating; ETA: 1m8s
Copy: 19817000/22417941 88.4%; Applied: 301; Backlog: 0/1000; Time: 8m5s(total), 8m5s(copy); streamer: mysql-bin.002906:274342144; State: migrating; ETA: 1m3s
Copy: 19987000/22417941 89.2%; Applied: 303; Backlog: 0/1000; Time: 8m9s(total), 8m9s(copy); streamer: mysql-bin.002906:301355380; State: migrating; ETA: 59s
Copy: 20025000/22417941 89.3%; Applied: 303; Backlog: 0/1000; Time: 8m10s(total), 8m10s(copy); streamer: mysql-bin.002906:308254870; State: migrating; ETA: 58s
Copy: 20067000/22417941 89.5%; Applied: 303; Backlog: 0/1000; Time: 8m11s(total), 8m11s(copy); streamer: mysql-bin.002906:315195248; State: migrating; ETA: 57s
Copy: 20104000/22417941 89.7%; Applied: 303; Backlog: 0/1000; Time: 8m12s(total), 8m12s(copy); streamer: mysql-bin.002906:322256977; State: migrating; ETA: 56s
Copy: 20145000/22417941 89.9%; Applied: 303; Backlog: 0/1000; Time: 8m13s(total), 8m13s(copy); streamer: mysql-bin.002906:329699832; State: migrating; ETA: 55s
Copy: 20182000/22417941 90.0%; Applied: 303; Backlog: 0/1000; Time: 8m14s(total), 8m14s(copy); streamer: mysql-bin.002906:336882099; State: migrating; ETA: 54s
Copy: 20222000/22417941 90.2%; Applied: 303; Backlog: 0/1000; Time: 8m15s(total), 8m15s(copy); streamer: mysql-bin.002906:343353342; State: migrating; ETA: 53s
Copy: 20270000/22417941 90.4%; Applied: 303; Backlog: 0/1000; Time: 8m16s(total), 8m16s(copy); streamer: mysql-bin.002906:350231498; State: migrating; ETA: 52s
Copy: 20306000/22417941 90.6%; Applied: 303; Backlog: 0/1000; Time: 8m17s(total), 8m17s(copy); streamer: mysql-bin.002906:356779900; State: migrating; ETA: 51s
Copy: 20343000/22417941 90.7%; Applied: 303; Backlog: 0/1000; Time: 8m18s(total), 8m18s(copy); streamer: mysql-bin.002906:363510433; State: migrating; ETA: 50s
Copy: 20384000/22417941 90.9%; Applied: 303; Backlog: 0/1000; Time: 8m19s(total), 8m19s(copy); streamer: mysql-bin.002906:370654037; State: migrating; ETA: 49s
Copy: 20423000/22417941 91.1%; Applied: 303; Backlog: 0/1000; Time: 8m20s(total), 8m20s(copy); streamer: mysql-bin.002906:377992690; State: migrating; ETA: 48s
Copy: 20463000/22417941 91.3%; Applied: 303; Backlog: 0/1000; Time: 8m21s(total), 8m21s(copy); streamer: mysql-bin.002906:385268669; State: migrating; ETA: 47s
Copy: 20504000/22417942 91.5%; Applied: 304; Backlog: 0/1000; Time: 8m22s(total), 8m22s(copy); streamer: mysql-bin.002906:390985352; State: migrating; ETA: 46s
Copy: 20546000/22417942 91.6%; Applied: 304; Backlog: 0/1000; Time: 8m23s(total), 8m23s(copy); streamer: mysql-bin.002906:396900800; State: migrating; ETA: 45s
Copy: 20586000/22417943 91.8%; Applied: 305; Backlog: 0/1000; Time: 8m24s(total), 8m24s(copy); streamer: mysql-bin.002906:403692767; State: migrating; ETA: 44s
Copy: 20622000/22417943 92.0%; Applied: 305; Backlog: 0/1000; Time: 8m25s(total), 8m25s(copy); streamer: mysql-bin.002906:409798586; State: migrating; ETA: 43s
Copy: 20657000/22417943 92.1%; Applied: 305; Backlog: 0/1000; Time: 8m26s(total), 8m26s(copy); streamer: mysql-bin.002906:415952366; State: migrating; ETA: 43s
Copy: 20697000/22417943 92.3%; Applied: 305; Backlog: 0/1000; Time: 8m27s(total), 8m27s(copy); streamer: mysql-bin.002906:423385209; State: migrating; ETA: 42s
Copy: 20736000/22417943 92.5%; Applied: 305; Backlog: 0/1000; Time: 8m28s(total), 8m28s(copy); streamer: mysql-bin.002906:429916710; State: migrating; ETA: 41s
Copy: 20772000/22417943 92.7%; Applied: 305; Backlog: 0/1000; Time: 8m29s(total), 8m29s(copy); streamer: mysql-bin.002906:435207694; State: migrating; ETA: 40s
Copy: 20804000/22417943 92.8%; Applied: 305; Backlog: 0/1000; Time: 8m30s(total), 8m30s(copy); streamer: mysql-bin.002906:440348506; State: migrating; ETA: 39s
Copy: 20835000/22417943 92.9%; Applied: 305; Backlog: 0/1000; Time: 8m31s(total), 8m31s(copy); streamer: mysql-bin.002906:445890561; State: migrating; ETA: 38s
Copy: 20876000/22417944 93.1%; Applied: 306; Backlog: 0/1000; Time: 8m32s(total), 8m32s(copy); streamer: mysql-bin.002906:452758646; State: migrating; ETA: 37s
Copy: 20914000/22417944 93.3%; Applied: 308; Backlog: 0/1000; Time: 8m33s(total), 8m33s(copy); streamer: mysql-bin.002906:459273185; State: migrating; ETA: 36s
Copy: 20952000/22417945 93.5%; Applied: 309; Backlog: 0/1000; Time: 8m34s(total), 8m34s(copy); streamer: mysql-bin.002906:466271943; State: migrating; ETA: 35s
Copy: 20990000/22417945 93.6%; Applied: 309; Backlog: 0/1000; Time: 8m35s(total), 8m35s(copy); streamer: mysql-bin.002906:472859033; State: migrating; ETA: 35s
Copy: 21031000/22417945 93.8%; Applied: 309; Backlog: 0/1000; Time: 8m36s(total), 8m36s(copy); streamer: mysql-bin.002906:480142549; State: migrating; ETA: 34s
Copy: 21071000/22417945 94.0%; Applied: 309; Backlog: 0/1000; Time: 8m37s(total), 8m37s(copy); streamer: mysql-bin.002906:487238218; State: migrating; ETA: 33s
Copy: 21108000/22417945 94.2%; Applied: 309; Backlog: 0/1000; Time: 8m38s(total), 8m38s(copy); streamer: mysql-bin.002906:493923934; State: migrating; ETA: 32s
Copy: 21148000/22417945 94.3%; Applied: 309; Backlog: 0/1000; Time: 8m39s(total), 8m39s(copy); streamer: mysql-bin.002906:501355617; State: migrating; ETA: 31s
Copy: 21195000/22417945 94.5%; Applied: 309; Backlog: 0/1000; Time: 8m40s(total), 8m40s(copy); streamer: mysql-bin.002906:507439320; State: migrating; ETA: 30s
Copy: 21237000/22417945 94.7%; Applied: 309; Backlog: 0/1000; Time: 8m41s(total), 8m41s(copy); streamer: mysql-bin.002906:513548610; State: migrating; ETA: 28s
Copy: 21280000/22417945 94.9%; Applied: 309; Backlog: 0/1000; Time: 8m42s(total), 8m42s(copy); streamer: mysql-bin.002906:521388020; State: migrating; ETA: 27s
Copy: 21319000/22417945 95.1%; Applied: 309; Backlog: 0/1000; Time: 8m43s(total), 8m43s(copy); streamer: mysql-bin.002906:527553859; State: migrating; ETA: 26s
Copy: 21357000/22417945 95.3%; Applied: 309; Backlog: 0/1000; Time: 8m44s(total), 8m44s(copy); streamer: mysql-bin.002906:534263015; State: migrating; ETA: 26s
Copy: 21402000/22417945 95.5%; Applied: 309; Backlog: 0/1000; Time: 8m45s(total), 8m45s(copy); streamer: mysql-bin.002906:541235776; State: migrating; ETA: 24s
Copy: 21448000/22417945 95.7%; Applied: 324; Backlog: 0/1000; Time: 8m46s(total), 8m46s(copy); streamer: mysql-bin.002906:547100182; State: migrating; ETA: 23s
Copy: 21489000/22417945 95.9%; Applied: 325; Backlog: 0/1000; Time: 8m47s(total), 8m47s(copy); streamer: mysql-bin.002906:553835930; State: migrating; ETA: 22s
Copy: 21531000/22417945 96.0%; Applied: 325; Backlog: 0/1000; Time: 8m48s(total), 8m48s(copy); streamer: mysql-bin.002906:561441986; State: migrating; ETA: 21s
Copy: 21568000/22417945 96.2%; Applied: 325; Backlog: 0/1000; Time: 8m49s(total), 8m49s(copy); streamer: mysql-bin.002906:567922104; State: migrating; ETA: 20s
Copy: 21609000/22417945 96.4%; Applied: 325; Backlog: 0/1000; Time: 8m50s(total), 8m50s(copy); streamer: mysql-bin.002906:575482740; State: migrating; ETA: 19s
Copy: 21648000/22417945 96.6%; Applied: 325; Backlog: 0/1000; Time: 8m51s(total), 8m51s(copy); streamer: mysql-bin.002906:582662275; State: migrating; ETA: 18s
Copy: 21695000/22417946 96.8%; Applied: 326; Backlog: 0/1000; Time: 8m52s(total), 8m52s(copy); streamer: mysql-bin.002906:589418018; State: migrating; ETA: 17s
Copy: 21739000/22417946 97.0%; Applied: 326; Backlog: 0/1000; Time: 8m53s(total), 8m53s(copy); streamer: mysql-bin.002906:595417921; State: migrating; ETA: 16s
Copy: 21775000/22417947 97.1%; Applied: 327; Backlog: 0/1000; Time: 8m54s(total), 8m54s(copy); streamer: mysql-bin.002906:601559482; State: migrating; ETA: 15s
Copy: 21818000/22417947 97.3%; Applied: 329; Backlog: 0/1000; Time: 8m55s(total), 8m55s(copy); streamer: mysql-bin.002906:609618959; State: migrating; ETA: 14s
Copy: 21860000/22417947 97.5%; Applied: 330; Backlog: 0/1000; Time: 8m56s(total), 8m56s(copy); streamer: mysql-bin.002906:617209026; State: migrating; ETA: 13s
Copy: 21899000/22417947 97.7%; Applied: 330; Backlog: 0/1000; Time: 8m57s(total), 8m57s(copy); streamer: mysql-bin.002906:624124738; State: migrating; ETA: 12s
Copy: 21940000/22417947 97.9%; Applied: 330; Backlog: 0/1000; Time: 8m58s(total), 8m58s(copy); streamer: mysql-bin.002906:630478406; State: migrating; ETA: 11s
Copy: 21974000/22417947 98.0%; Applied: 330; Backlog: 0/1000; Time: 8m59s(total), 8m59s(copy); streamer: mysql-bin.002906:636131136; State: migrating; ETA: 10s
Copy: 21977000/22417947 98.0%; Applied: 330; Backlog: 0/1000; Time: 9m0s(total), 9m0s(copy); streamer: mysql-bin.002906:636664994; State: migrating; ETA: 10s
Copy: 22011000/22417947 98.2%; Applied: 330; Backlog: 0/1000; Time: 9m1s(total), 9m1s(copy); streamer: mysql-bin.002906:642933908; State: migrating; ETA: 10s
Copy: 22044000/22417947 98.3%; Applied: 330; Backlog: 0/1000; Time: 9m2s(total), 9m2s(copy); streamer: mysql-bin.002906:648974938; State: migrating; ETA: 9s
Copy: 22079000/22417947 98.5%; Applied: 330; Backlog: 0/1000; Time: 9m3s(total), 9m3s(copy); streamer: mysql-bin.002906:654970219; State: migrating; ETA: 8s
Copy: 22117000/22417947 98.7%; Applied: 330; Backlog: 0/1000; Time: 9m4s(total), 9m4s(copy); streamer: mysql-bin.002906:661466169; State: migrating; ETA: 7s
Copy: 22146000/22417947 98.8%; Applied: 330; Backlog: 0/1000; Time: 9m5s(total), 9m5s(copy); streamer: mysql-bin.002906:666703146; State: migrating; ETA: 6s
Copy: 22187000/22417947 99.0%; Applied: 330; Backlog: 0/1000; Time: 9m6s(total), 9m6s(copy); streamer: mysql-bin.002906:672833972; State: migrating; ETA: 5s
Copy: 22226000/22417947 99.1%; Applied: 348; Backlog: 0/1000; Time: 9m7s(total), 9m7s(copy); streamer: mysql-bin.002906:678772715; State: migrating; ETA: 4s
Copy: 22259000/22417947 99.3%; Applied: 352; Backlog: 0/1000; Time: 9m8s(total), 9m8s(copy); streamer: mysql-bin.002906:685390458; State: migrating; ETA: 3s
Copy: 22293000/22417947 99.4%; Applied: 352; Backlog: 0/1000; Time: 9m9s(total), 9m9s(copy); streamer: mysql-bin.002906:691603588; State: migrating; ETA: 3s
Copy: 22329000/22417947 99.6%; Applied: 352; Backlog: 0/1000; Time: 9m10s(total), 9m10s(copy); streamer: mysql-bin.002906:698392727; State: migrating; ETA: 2s
Copy: 22369000/22417947 99.8%; Applied: 352; Backlog: 0/1000; Time: 9m11s(total), 9m11s(copy); streamer: mysql-bin.002906:705803021; State: migrating; ETA: 1s
Copy: 22406000/22417947 99.9%; Applied: 352; Backlog: 0/1000; Time: 9m12s(total), 9m12s(copy); streamer: mysql-bin.002906:712171935; State: migrating; ETA: 0s
2017-09-14 10:27:52 INFO Row copy complete
Copy: 22417847/22417847 100.0%; Applied: 352; Backlog: 0/1000; Time: 9m12s(total), 9m12s(copy); streamer: mysql-bin.002906:714048541; State: migrating; ETA: due
2017-09-14 10:27:52 INFO Grabbing voluntary lock: gh-ost.3013365.lock
2017-09-14 10:27:52 INFO Setting LOCK timeout as 6 seconds
2017-09-14 10:27:52 INFO Looking for magic cut-over table
2017-09-14 10:27:52 INFO Creating magic cut-over table `test`.`_table_del`
2017-09-14 10:27:52 INFO Magic cut-over table created
2017-09-14 10:27:52 INFO Locking `test`.`table`, `test`.`_table_del`
2017-09-14 10:27:52 INFO Tables locked
2017-09-14 10:27:52 INFO Session locking original & magic tables is 3013365
2017-09-14 10:27:52 INFO Writing changelog state: AllEventsUpToLockProcessed:1505374072074323462
2017-09-14 10:27:52 INFO Intercepted changelog state AllEventsUpToLockProcessed
2017-09-14 10:27:52 INFO Handled changelog state AllEventsUpToLockProcessed
2017-09-14 10:27:52 INFO Waiting for events up to lock
2017-09-14 10:27:53 INFO Waiting for events up to lock: got AllEventsUpToLockProcessed:1505374072074323462
2017-09-14 10:27:53 INFO Done waiting for events up to lock; duration=981.463089ms
# Migrating `test`.`table`; Ghost table is `test`.`_table_gho`
# Migrating mysql-master:3306; inspecting mysql-master:3306; executing on mysql-master
# Migration started at Thu Sep 14 10:18:39 +0300 2017
# chunk-size: 1000; max-lag-millis: 500ms; dml-batch-size: 10; max-load: Threads_running=20; critical-load: Threads_running=1000; nice-ratio: 0.000000
# throttle-additional-flag-file: /tmp/gh-ost.throttle
# throttle-control-replicas count: 1
# postpone-cut-over-flag-file: /tmp/ghost.postpone.flag
# panic-flag-file: /tmp/ghost.panic.flag
# Serving on unix socket: /tmp/gh-ost.test.table.sock
Copy: 22417847/22417847 100.0%; Applied: 352; Backlog: 0/1000; Time: 9m13s(total), 9m12s(copy); streamer: mysql-bin.002906:714238809; State: migrating; ETA: due
2017-09-14 10:27:53 INFO Setting RENAME timeout as 3 seconds
2017-09-14 10:27:53 INFO Session renaming tables is 3013324
2017-09-14 10:27:53 INFO Issuing and expecting this to block: rename /* gh-ost */ table `test`.`table` to `test`.`_table_del`, `test`.`_table_gho` to `test`.`table`
2017-09-14 10:27:53 INFO Found atomic RENAME to be blocking, as expected. Double checking the lock is still in place (though I don't strictly have to)
2017-09-14 10:27:53 INFO Checking session lock: gh-ost.3013365.lock
2017-09-14 10:27:53 INFO Connection holding lock on original table still exists
2017-09-14 10:27:53 INFO Will now proceed to drop magic table and unlock tables
2017-09-14 10:27:53 INFO Dropping magic cut-over table
2017-09-14 10:27:53 INFO Releasing lock from `test`.`table`, `test`.`_table_del`
2017-09-14 10:27:53 INFO Tables unlocked
2017-09-14 10:27:53 INFO Tables renamed
2017-09-14 10:27:53 INFO Lock & rename duration: 1.080335371s. During this time, queries on `table` were blocked
2017-09-14 10:27:53 INFO Looking for magic cut-over table
2017-09-14 10:27:53 INFO Closed streamer connection. err=<nil>
2017-09-14 10:27:53 INFO Droppping table `test`.`_table_ghc`
2017-09-14 10:27:53 INFO Table dropped
2017-09-14 10:27:53 INFO Droppping table `test`.`_table_del`
2017-09-14 10:27:53 ERROR Error 1146: Table 'test._table_ghc' doesn't exist
Copy: 22417847/22417847 100.0%; Applied: 352; Backlog: 0/1000; Time: 9m15s(total), 9m12s(copy); streamer: mysql-bin.002906:714245194; State: throttled, max-load Threads_running=68 >= 20; ETA: due
2017-09-14 10:27:59 ERROR Error 1146: Table 'test._table_ghc' doesn't exist
Copy: 22417847/22417847 100.0%; Applied: 352; Backlog: 0/1000; Time: 9m20s(total), 9m12s(copy); streamer: mysql-bin.002906:714245194; State: throttled, max-load Threads_running=133 >= 20; ETA: due
Copy: 22417847/22417847 100.0%; Applied: 352; Backlog: 0/1000; Time: 9m25s(total), 9m12s(copy); streamer: mysql-bin.002906:714245194; State: throttled, max-load Threads_running=132 >= 20; ETA: due
2017-09-14 10:28:04 INFO Table dropped
2017-09-14 10:28:04 INFO Done migrating `test`.`table`
2017-09-14 10:28:04 INFO Removing socket file: /tmp/gh-ost.test.table.sock
# Done

pznamensky avatar Sep 14 '17 08:09 pznamensky

duplicate of https://github.com/github/gh-ost/issues/377 related https://github.com/github/gh-ost/issues/442

The tables are dropped after the complete data has been copied. A race condition leads to gh-ost attempting to apply data written after cut-over ; the race condition was recently mitigated but not solved.

There is no data integrity issue, though I wholeheartedly agree the log is not nice. FWIW this happens rarely (at least on our side?).

shlomi-noach avatar Sep 14 '17 08:09 shlomi-noach

Thanks for the explaition. We faced with this in the first time.

pznamensky avatar Sep 14 '17 08:09 pznamensky

Sorry for the inconvenience.

shlomi-noach avatar Sep 14 '17 08:09 shlomi-noach

it seems this problem has been solved in v1.1.1.

roodkcab avatar May 20 '21 04:05 roodkcab