gh-ost completed success but print Errors

[hunterhuang8810]

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

[quanllong]

I meet the save question. go-ost completed, but still print log

[quanllong]

2025-09-17 14:36:05 INFO Copy: 106/106 100.0%; Applied: 0; Backlog: 0/1000; Time: 30m4s(total), 1s(copy); streamer: mysql-bin.005980:153126099; Lag: 0.10s, HeartbeatLag: 1152.13s, State: migrating; ETA: due [] Copy: 106/106 100.0%; Applied: 0; Backlog: 0/1000; Time: 30m5s(total), 1s(copy); streamer: mysql-bin.005980:153126099; Lag: 0.10s, HeartbeatLag: 1153.13s, State: migrating; ETA: due 2025-09-17 14:36:06 INFO Copy: 106/106 100.0%; Applied: 0; Backlog: 0/1000; Time: 30m5s(total), 1s(copy); streamer: mysql-bin.005980:153126099; Lag: 0.10s, HeartbeatLag: 1153.13s, State: migrating; ETA: due []