github / gh-ost

GitHub's Online Schema-migration Tool for MySQL
MIT License
12.28k stars 1.25k forks source link

why "ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist" ? #657

Open boomballa opened 5 years ago

boomballa commented 5 years ago

My gh-ost version is 1.0.46.

gh-ost --max-load=Threads_running=500 --critical-load=Threads_running=1000 --chunk-size=1000 --throttle-control-replicas="192.168.1.25:3307" --port=3307 --max-lag-millis=1500 --user="root" --password='123456' --host=192.168.1.24 --port=3307 --allow-on-master --database="account_proxy" --table="sms_validate_code" --verbose --alter="ADD COLUMN verify_channel tinyint NULL DEFAULT 0' AFTER sms_param" --switch-to-rbr --allow-master-master --cut-over=default --exact-rowcount --concurrent-rowcount --timestamp-old-table --default-retries=120 --panic-flag-file=./ghost.panic.flag --skip-foreign-key-checks --ok-to-drop-table --execute --initially-drop-ghost-table

Copy: 14521000/14721232 98.6%; Applied: 3416; Backlog: 0/1000; Time: 16m40s(total), 16m40s(copy); streamer: binlog.010454:333650497; State: throttled, 192.168.1.25:3307 replica-lag=1.550521s; ETA: 13s
Copy: 14521000/14721232 98.6%; Applied: 3416; Backlog: 0/1000; Time: 16m41s(total), 16m41s(copy); streamer: binlog.010454:333701327; State: throttled, 192.168.1.25:3307 replica-lag=2.150548s; ETA: 13s
Copy: 14521000/14721232 98.6%; Applied: 3416; Backlog: 5/1000; Time: 16m42s(total), 16m42s(copy); streamer: binlog.010454:333741293; State: throttled, 192.168.1.25:3307 replica-lag=2.450541s; ETA: 13s
Copy: 14521000/14721232 98.6%; Applied: 3416; Backlog: 7/1000; Time: 16m43s(total), 16m43s(copy); streamer: binlog.010454:334124358; State: throttled, 192.168.1.25:3307 replica-lag=2.850286s; ETA: 13s
Copy: 14540000/14721238 98.8%; Applied: 3426; Backlog: 0/1000; Time: 16m44s(total), 16m44s(copy); streamer: binlog.010454:339088688; State: migrating; ETA: 12s
Copy: 14562000/14721239 98.9%; Applied: 3428; Backlog: 0/1000; Time: 16m45s(total), 16m45s(copy); streamer: binlog.010454:344519285; State: migrating; ETA: 10s
Copy: 14579000/14721239 99.0%; Applied: 3429; Backlog: 0/1000; Time: 16m46s(total), 16m46s(copy); streamer: binlog.010454:348673963; State: migrating; ETA: 9s
Copy: 14592000/14721240 99.1%; Applied: 3431; Backlog: 1/1000; Time: 16m47s(total), 16m47s(copy); streamer: binlog.010454:351847125; State: migrating; ETA: 8s
Copy: 14602000/14721241 99.2%; Applied: 3434; Backlog: 0/1000; Time: 16m48s(total), 16m48s(copy); streamer: binlog.010454:354555425; State: migrating; ETA: 8s
Copy: 14608000/14721241 99.2%; Applied: 3435; Backlog: 0/1000; Time: 16m49s(total), 16m49s(copy); streamer: binlog.010454:356395444; State: migrating; ETA: 7s
Copy: 14626000/14721243 99.4%; Applied: 3438; Backlog: 0/1000; Time: 16m50s(total), 16m50s(copy); streamer: binlog.010454:360793216; State: migrating; ETA: 6s
Copy: 14640000/14721243 99.4%; Applied: 3439; Backlog: 0/1000; Time: 16m51s(total), 16m51s(copy); streamer: binlog.010454:364218454; State: migrating; ETA: 5s
Copy: 14654000/14721244 99.5%; Applied: 3440; Backlog: 0/1000; Time: 16m52s(total), 16m52s(copy); streamer: binlog.010454:367624058; State: migrating; ETA: 4s
Copy: 14660000/14721245 99.6%; Applied: 3442; Backlog: 1/1000; Time: 16m53s(total), 16m53s(copy); streamer: binlog.010454:369426977; State: migrating; ETA: 4s
Copy: 14669000/14721246 99.6%; Applied: 3444; Backlog: 0/1000; Time: 16m54s(total), 16m54s(copy); streamer: binlog.010454:371853560; State: migrating; ETA: 3s
Copy: 14685000/14721247 99.8%; Applied: 3446; Backlog: 0/1000; Time: 16m55s(total), 16m55s(copy); streamer: binlog.010454:375939245; State: migrating; ETA: 2s
Copy: 14704000/14721247 99.9%; Applied: 3447; Backlog: 0/1000; Time: 16m56s(total), 16m56s(copy); streamer: binlog.010454:380768918; State: migrating; ETA: 1s
2018-11-01 16:18:10 INFO Row copy complete
Copy: 14719578/14719578 100.0%; Applied: 3450; Backlog: 0/1000; Time: 16m57s(total), 16m56s(copy); streamer: binlog.010454:384733635; State: migrating; ETA: due
2018-11-01 16:18:10 INFO Grabbing voluntary lock: gh-ost.59126619.lock
2018-11-01 16:18:10 INFO Setting LOCK timeout as 6 seconds
2018-11-01 16:18:10 INFO Looking for magic cut-over table
2018-11-01 16:18:10 INFO Creating magic cut-over table `account_proxy`.`_sms_validate_code_20181101160113_del`
2018-11-01 16:18:10 INFO Magic cut-over table created
2018-11-01 16:18:10 INFO Locking `account_proxy`.`sms_validate_code`, `account_proxy`.`_sms_validate_code_20181101160113_del`
2018-11-01 16:18:10 INFO Tables locked
2018-11-01 16:18:10 INFO Session locking original & magic tables is 59126619
2018-11-01 16:18:10 INFO Writing changelog state: AllEventsUpToLockProcessed:1541060290984561941
2018-11-01 16:18:10 INFO Intercepted changelog state AllEventsUpToLockProcessed
2018-11-01 16:18:10 INFO Handled changelog state AllEventsUpToLockProcessed
2018-11-01 16:18:10 INFO Waiting for events up to lock
2018-11-01 16:18:11 INFO Waiting for events up to lock: got AllEventsUpToLockProcessed:1541060290984561941
2018-11-01 16:18:11 INFO Done waiting for events up to lock; duration=974.068345ms
Migrating `account_proxy`.`sms_validate_code`; Ghost table is `account_proxy`.`_sms_validate_code_gho`
Migrating 1_24-HLG_H08-Account-Mysql-Master2:3307; inspecting 1_24-HLG_H08-Account-Mysql-Master2:3307; executing on 1_24-HLG_H08-Account-Mysql-Master1
Migration started at Thu Nov 01 16:01:13 +0800 2018
chunk-size: 1000; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: Threads_running=500; critical-load: Threads_running=1000; nice-ratio: 0.000000
throttle-additional-flag-file: /tmp/gh-ost.throttle 
throttle-control-replicas count: 1
panic-flag-file: ./ghost.panic.flag
Serving on unix socket: /tmp/gh-ost.account_proxy.sms_validate_code.sock
Copy: 14719578/14719578 100.0%; Applied: 3450; Backlog: 0/1000; Time: 16m58s(total), 16m56s(copy); streamer: binlog.010454:385117897; State: migrating; ETA: due
2018-11-01 16:18:11 INFO Setting RENAME timeout as 3 seconds
2018-11-01 16:18:11 INFO Session renaming tables is 59126618
2018-11-01 16:18:11 INFO Issuing and expecting this to block: rename /* gh-ost */ table `account_proxy`.`sms_validate_code` to `account_proxy`.`_sms_validate_code_20181101160113_del`, `account_proxy`.`_sms_validate_code_gho` to `account_proxy`.`sms_validate_code`
2018-11-01 16:18:12 INFO Found atomic RENAME to be blocking, as expected. Double checking the lock is still in place (though I don't strictly have to)
2018-11-01 16:18:12 INFO Checking session lock: gh-ost.59126619.lock
2018-11-01 16:18:12 INFO Connection holding lock on original table still exists
2018-11-01 16:18:12 INFO Will now proceed to drop magic table and unlock tables
2018-11-01 16:18:12 INFO Dropping magic cut-over table
2018-11-01 16:18:12 INFO Releasing lock from `account_proxy`.`sms_validate_code`, `account_proxy`.`_sms_validate_code_20181101160113_del`
2018-11-01 16:18:12 INFO Tables unlocked
2018-11-01 16:18:12 INFO Tables renamed
2018-11-01 16:18:12 INFO Lock & rename duration: 1.085854334s. During this time, queries on `sms_validate_code` were blocked
2018-11-01 16:18:12 INFO Looking for magic cut-over table
2018/11/01 16:18:12 binlogsyncer.go:107: [info] syncer is closing... 
2018/11/01 16:18:12 binlogstreamer.go:47: [error] close sync with err: sync is been closing...
2018/11/01 16:18:12 binlogsyncer.go:122: [info] syncer is closed 
2018-11-01 16:18:12 INFO Closed streamer connection. err=<nil>
2018-11-01 16:18:12 INFO Dropping table `account_proxy`.`_sms_validate_code_ghc`
2018-11-01 16:18:12 INFO Table dropped
2018-11-01 16:18:12 INFO Dropping table `account_proxy`.`_sms_validate_code_20181101160113_del`
2018-11-01 16:18:12 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:12 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:12 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:12 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:12 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:12 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:12 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:12 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:12 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:12 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:12 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:13 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:13 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:13 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:13 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:13 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:13 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:13 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:13 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:13 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:13 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:14 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:14 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:14 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
Copy: 14719578/14719578 100.0%; Applied: 3450; Backlog: 0/1000; Time: 17m0s(total), 16m56s(copy); streamer: binlog.010454:385142843; State: throttled, 192.168.1.25:3307 Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist; ETA: due
2018-11-01 16:18:14 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:14 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:14 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:14 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:14 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:14 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:14 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:14 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:15 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:15 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:15 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:15 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:15 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:15 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:15 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:15 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:15 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:15 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:16 ERROR Error 1146: Table 'account_proxy._sms_validate_code_ghc' doesn't exist
2018-11-01 16:18:16 INFO Table dropped
2018-11-01 16:18:16 INFO Done migrating `account_proxy`.`sms_validate_code`
2018-11-01 16:18:16 INFO Removing socket file: /tmp/gh-ost.account_proxy.sms_validate_code.sock
2018-11-01 16:18:16 INFO Tearing down inspector
2018-11-01 16:18:16 INFO Tearing down applier
2018-11-01 16:18:16 INFO Tearing down streamer
2018-11-01 16:18:16 INFO Tearing down throttler
Done

Hi, I saw someone mention issue before. But this problem still exists in the latest version of gh-ost. It has been verified that this error has no effect on data, and DDL has been executed. But the feeling experience is not good enough, it always makes people feel very down-to-earth. I wonder if I can try to fix it in the new version. thanks.

shlomi-noach commented 5 years ago

Thank you. I agree the messages are disturbing. I'll try looking into it.

1iuyunpeng commented 5 years ago

I also encountered this problem today, and I did not affect the DDL changes, but I don’t know if it really didn’t affect.

GPF199541 commented 1 year ago

I often encounter this kind of situation this is the gh-ost log ....

Done

2022-10-27 15:37:08 ERROR Error 1146: Table 'd1._rs_order_cancel_91_ghc' doesn't exist Copy: 1116424/1116424 100.0%; Applied: 2; Backlog: 0/1000; Time: 37s(total), 30s(copy); streamer: mysql-bin.009700:227129799; Lag: 0.09s, HeartbeatLag: 0.09s, State: migrating; ETA: due

niushaoda commented 1 year ago

I also encountered this situation. Looking at the log, the gh-ost tool still uses or detects the xx_ghc table after deleting the xx_ghc table. This error does not seem to affect the data.

boomballa commented 1 year ago

I also encountered this situation. Looking at the log, the gh-ost tool still uses or detects the xx_ghc table after deleting the xx_ghc table. This error does not seem to affect the data.

@niushaoda Yes, it does not affect the data, but the Error field will be output at the end of command execution, which is not very comfortable. 🤣 This problem should still exist in the current version, and it seems that it has not been fixed.

Can official friends try to fix it?