gh-ost completed success but print Errors

まず、レポートに示されている cut-over のクリーンアップシーケンスを、特に _game_player_10_ghc と _game_player_10_20250722144233_del の削除を中心に追跡します。提供された gh-ost コマンドまたは同等の MySQL テーブルを使ってマイグレーションを再現し、その後、マイグレーションが成功した後にテーブルが存在しないという条件がログに記録される理由を調査します。このシーケンスをカバレッジに含め、クリーンアップが成功したときに誤解を招く ERROR が出力されなければ完了です。

I used below command to add column to table:

gh-ost --chunk-size=200000 --host=x.x.x.x --verbose --timestamp-old-table --ask-pass --port=xxx--user=dbauser --database=game_usercenter_01 --table=game_player_10 --allow-on-master --ok-to-drop-table --max-lag-millis=100 --alter="add column game_mode tinyint(4) DEFAULT '0' COMMENT 'xxx'" --execute

gh-ost will completed successfully , and the resutl is as expected, but I'm confused is it will print Error message in the log, as below:

2025-07-22 14:50:06 INFO Copy: 11900000/11710096 101.6%; Applied: 0; Backlog: 0/1000; Time: 7m33s(total), 7m33s(copy); streamer: mysql-bin.000027:793269783; Lag: 0.01s, HeartbeatLag: 0.01s, State: migrating; ETA: due []
2025-07-22 14:50:07 INFO Row copy complete
Copy: 12002122/12002122 100.0%; Applied: 0; Backlog: 0/1000; Time: 7m34s(total), 7m33s(copy); streamer: mysql-bin.000027:815218176; Lag: 0.01s, HeartbeatLag: 0.04s, State: migrating; ETA: due
2025-07-22 14:50:07 INFO Copy: 12002122/12002122 100.0%; Applied: 0; Backlog: 0/1000; Time: 7m34s(total), 7m33s(copy); streamer: mysql-bin.000027:815218176; Lag: 0.01s, HeartbeatLag: 0.04s, State: migrating; ETA: due []
2025-07-22 14:50:07 INFO Grabbing voluntary lock: gh-ost.395.lock
2025-07-22 14:50:07 INFO Setting LOCK timeout as 6 seconds
2025-07-22 14:50:07 INFO Looking for magic cut-over table
2025-07-22 14:50:07 INFO Creating magic cut-over table game_usercenter_01._game_player_10_20250722144233_del
2025-07-22 14:50:07 INFO Magic cut-over table created
2025-07-22 14:50:07 INFO Setting cut-over idle timeout as 9 seconds
2025-07-22 14:50:07 INFO Locking game_usercenter_01.game_player_10, game_usercenter_01._game_player_10_20250722144233_del
2025-07-22 14:50:07 INFO Tables locked
2025-07-22 14:50:07 INFO Session locking original & magic tables is 395
2025-07-22 14:50:07 INFO Writing changelog state: AllEventsUpToLockProcessed:1753167007393436520
2025-07-22 14:50:07 INFO Intercepted changelog state AllEventsUpToLockProcessed
2025-07-22 14:50:07 INFO Handled changelog state AllEventsUpToLockProcessed
2025-07-22 14:50:07 INFO Waiting for events up to lock
Copy: 12002122/12002122 100.0%; Applied: 0; Backlog: 1/1000; Time: 7m34s(total), 7m33s(copy); streamer: mysql-bin.000027:815220562; Lag: 0.01s, HeartbeatLag: 0.01s, State: migrating; ETA: due
2025-07-22 14:50:07 INFO Copy: 12002122/12002122 100.0%; Applied: 0; Backlog: 1/1000; Time: 7m34s(total), 7m33s(copy); streamer: mysql-bin.000027:815220562; Lag: 0.01s, HeartbeatLag: 0.01s, State: migrating; ETA: due []
2025-07-22 14:50:08 INFO Waiting for events up to lock: got AllEventsUpToLockProcessed:1753167007393436520
2025-07-22 14:50:08 INFO Done waiting for events up to lock; duration=988.348385ms

Migrating game_usercenter_01.game_player_10; Ghost table is game_usercenter_01._game_player_10_gho

Migrating xx-xx-xx-xx.rds-fatpod-game-union.bjht:33xx; inspecting xx-xx-xxx-xx.rds-fatpod-game-union.bjht:33xx; executing on xx-xx-xxx-xxx.rdsrestore.bjht

Migration started at Tue Jul 22 14:42:33 +0800 2025

chunk-size: 100000; max-lag-millis: 100ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000

throttle-additional-flag-file: /tmp/gh-ost.throttle

Serving on unix socket: /tmp/gh-ost.game_usercenter_01.game_player_10.sock

Copy: 12002122/12002122 100.0%; Applied: 0; Backlog: 0/1000; Time: 7m35s(total), 7m33s(copy); streamer: mysql-bin.000027:815224002; Lag: 0.01s, HeartbeatLag: 0.04s, State: migrating; ETA: due
2025-07-22 14:50:08 INFO Copy: 12002122/12002122 100.0%; Applied: 0; Backlog: 0/1000; Time: 7m35s(total), 7m33s(copy); streamer: mysql-bin.000027:815224002; Lag: 0.01s, HeartbeatLag: 0.04s, State: migrating; ETA: due []
2025-07-22 14:50:08 INFO Setting RENAME timeout as 3 seconds
2025-07-22 14:50:08 INFO Session renaming tables is 391
2025-07-22 14:50:08 INFO Issuing and expecting this to block: rename /* gh-ost */ table game_usercenter_01.game_player_10 to game_usercenter_01._game_player_10_20250722144233_del, game_usercenter_01._game_player_10_gho to game_usercenter_01.game_player_10
2025-07-22 14:50:08 INFO Found atomic RENAME to be blocking, as expected. Double checking the lock is still in place (though I don't strictly have to)
2025-07-22 14:50:08 INFO Checking session lock: gh-ost.395.lock
2025-07-22 14:50:08 INFO Connection holding lock on original table still exists
2025-07-22 14:50:08 INFO Will now proceed to drop magic table and unlock tables
2025-07-22 14:50:08 INFO Dropping magic cut-over table
2025-07-22 14:50:08 INFO Releasing lock from game_usercenter_01.game_player_10, game_usercenter_01._game_player_10_20250722144233_del
2025-07-22 14:50:08 INFO Tables unlocked
2025-07-22 14:50:08 INFO Reverting cut-over idle timeout to 28800 seconds
2025-07-22 14:50:08 INFO Looking for magic cut-over table
2025-07-22 14:50:08 INFO Tables renamed
2025-07-22 14:50:08 INFO Lock & rename duration: 1.057990808s. During this time, queries on game_player_10 were blocked
2025-07-22 14:50:08 INFO Writing changelog state: Migrated
[2025/07/22 14:50:08] [info] binlogsyncer.go:206 syncer is closing...
[2025/07/22 14:50:08] [info] binlogsyncer.go:906 kill last connection id 390
[2025/07/22 14:50:08] [info] binlogsyncer.go:236 syncer is closed
2025-07-22 14:50:08 INFO Closed streamer connection. err=
2025-07-22 14:50:08 INFO Dropping table game_usercenter_01._game_player_10_ghc
2025-07-22 14:50:08 INFO Table dropped
2025-07-22 14:50:08 INFO Dropping table game_usercenter_01._game_player_10_20250722144233_del
_2025-07-22 14:50:08 ERROR Error 1146 (42S02): Table 'game_usercenter_01._game_player_10_ghc' doesn't exist
2025-07-22 14:50:08 ERROR Error 1146 (42S02): Table 'game_usercenter_01.game_player_10_ghc' doesn't exist
Copy: 12002122/12002122 100.0%; Applied: 0; Backlog: 0/1000; Time: 7m35s(total), 7m33s(copy); streamer: mysql-bin.000027:815225489; Lag: 0.01s, HeartbeatLag: 0.11s, State: migrating; ETA: due
2025-07-22 14:50:08 INFO Copy: 12002122/12002122 100.0%; Applied: 0; Backlog: 0/1000; Time: 7m35s(total), 7m33s(copy); streamer: mysql-bin.000027:815225489; Lag: 0.01s, HeartbeatLag: 0.11s, State: migrating; ETA: due []
2025-07-22 14:50:08 ERROR Error 1146 (42S02): Table 'game_usercenter_01._game_player_10_ghc' doesn't exist
2025-07-22 14:50:08 ERROR Error 1146 (42S02): Table 'game_usercenter_01._game_player_10_ghc' doesn't exist
2025-07-22 14:50:08 INFO Table dropped
2025-07-22 14:50:08 INFO Done migrating game_usercenter_01.game_player_10
2025-07-22 14:50:08 INFO Removing socket file: /tmp/gh-ost.game_usercenter_01.game_player_10.sock
2025-07-22 14:50:08 INFO Tearing down inspector
2025-07-22 14:50:08 INFO Tearing down applier
2025-07-22 14:50:08 INFO Tearing down streamer
2025-07-22 14:50:08 INFO Tearing down throttler

Done

In our platform code, we will check if gh-ost run success by checking the log, if there are ERROR messages our code will treat the gh-ost job run failed.

please have a look and check why above job printed Error messages, and how to avoid print the error message , thanks a lot