Skip to content

Migration fails with "ghc table does not exist" #1622

Description

@ajm188

This was running off of master against an 8.4.6 database.

+ ./gh-ost -allow-on-master -attempt-instant-ddl -dml-batch-size 50 -exact-rowcount -force-named-cut-over -force-named-panic -postpone-cut-over-flag-file /tmp/queries/bb2d953d-431d-4bf0-
b6b2-d7ed1a2ae9d0/postpone-cutover -throttle-additional-flag-file /tmp/queries/bb2d953d-431d-4bf0-b6b2-d7ed1a2ae9d0/throttle -timestamp-old-table --skip-metadata-lock-check -database test -alter 'add index idx_user_start_time_end_time (user_id, start_time, end_time)' -table queries -host $hostname -user root -ask-pass
[2026/01/30 17:57:10] [info] binlogsyncer.go:191 create BinlogSyncer with config {ServerID:99999 Flavor:mysql Host:[redacted] Port:3306 User:root Password: Localhost: Charset: SemiSyncEnabled:false RawModeEnabled:false TLSConfig:<nil> ParseTime:false TimestampStringLocation:UTC UseDecimal:true RecvB
ufferSize:0 HeartbeatPeriod:0s ReadTimeout:0s MaxReconnectAttempts:0 DisableRetrySync:false VerifyChecksum:false DumpCommandFlag:0 Option:<nil> Logger:0x40004c23c0 Dialer:0x329d40 RowsEv
entDecodeFunc:<nil> TableMapOptionalMetaDecodeFunc:<nil> DiscardGTIDSet:false EventCacheCount:10240 SynchronousEventHandler:<nil>}
[2026/01/30 17:57:10] [info] binlogsyncer.go:443 begin to sync binlog from position (mysql-bin-changelog.027237, 3002)
[2026/01/30 17:57:10] [info] binlogsyncer.go:409 Connected to mysql 8.4.6 server
[2026/01/30 17:57:10] [info] binlogsyncer.go:868 rotate to (mysql-bin-changelog.027237, 3002)
# Migrating `test`.`queries`; Ghost table is `test`.`_queries_gho`
# Migrating `test`.`queries`; Ghost table is `test`.`_queries_gho`
# Migrating ip-172-17-5-122:3306; inspecting ip-172-17-5-122:3306; executing on bastion-0
# Migration started at Fri Jan 30 17:57:10 +0000 2026
# chunk-size: 1000; max-lag-millis: 1500ms; dml-batch-size: 50; max-load: ; critical-load: ; nice-ratio: 0.000000
# throttle-additional-flag-file: /tmp/queries/bb2d953d-431d-4bf0-b6b2-d7ed1a2ae9d0/throttle
# postpone-cut-over-flag-file: /tmp/queries/bb2d953d-431d-4bf0-b6b2-d7ed1a2ae9d0/postpone-cutover [set]
# Serving on unix socket: /tmp/gh-ost.test.queries.sock
# Migrating ip-172-17-5-122:3306; inspecting ip-172-17-5-122:3306; executing on bastion-0
# Migration started at Fri Jan 30 17:57:10 +0000 2026
# chunk-size: 1000; max-lag-millis: 1500ms; dml-batch-size: 50; max-load: ; critical-load: ; nice-ratio: 0.000000
# throttle-additional-flag-file: /tmp/queries/bb2d953d-431d-4bf0-b6b2-d7ed1a2ae9d0/throttle
# postpone-cut-over-flag-file: /tmp/queries/bb2d953d-431d-4bf0-b6b2-d7ed1a2ae9d0/postpone-cutover [set]
# Serving on unix socket: /tmp/gh-ost.honeycomb_prod.queries.sock
Copy: 0/0 100.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin-changelog.027237:7368; Lag: 0.07s, HeartbeatLag: 0.07s, State: migrating; ETA: due
Copy: 0/426432577 0.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin-changelog.027237:7368; Lag: 0.07s, HeartbeatLag: 0.07s, State: migrating; ETA: N/A
CREATE TABLE `_queries_gho` (
  `id` int NOT NULL AUTO_INCREMENT,
  ...
  PRIMARY KEY (`id`),
) ENGINE=InnoDB AUTO_INCREMENT=404517417 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin
[2026/01/30 17:57:10] [info] binlogsyncer.go:225 syncer is closing...
[2026/01/30 17:57:10] [info] binlogsyncer.go:988 kill last connection id 109
[2026/01/30 17:57:10] [info] binlogsyncer.go:255 syncer is closed
2026-01-30 17:57:10 ERROR Error 1146 (42S02): Table 'test._queries_ghc' doesn't exist

Interestingly, I was not running in either "revert" or "resume" mode, so I have no idea why gh-ost didn't actually try to create the changelog table. After the gh-ost process exited, there were no gh-ost tables on the database at all:

(MySQL):test>show tables like '%gh%';
+---------------------------------+
| Tables_in_test (%gh%) |
+---------------------------------+
+---------------------------------+

Activity

  1. saimitta-looker commented on Feb 21, 2026

    @saimitta-looker

    Ran into the same exact issue today, was there any investigation into the root cause? Thanks!

    +1 to " not running in either "revert" or "resume" mode"

  2. meiji163 commented on Mar 9, 2026

    @meiji163
    Contributor

    @ajm188 @saimitta-looker what gh-ost version are you using? I couldn't reproduce this. Does it also error with --execute?

  3. ajm188 commented on Apr 5, 2026

    @ajm188
    ContributorAuthor

    I was using the 1.18 release candidate. If I get some time this week I can try with 1.18 GA to see if it is happening there as well.

    Unfortunately I don't remember if this also errored with --execute but I will try to remember to grab that info next time around

  4. NoskyOrg commented on Aug 3, 2026

    @NoskyOrg

    Has this issue been fixed?
    #1664

  5. ajm188 commented on Sep 18, 2026

    @ajm188
    ContributorAuthor

    this happened again yesterday, version 1.1.11. i'm going to poke around a bit at logs to see if i can find anything useful and will report back!

  6. ajm188 commented on Sep 18, 2026

    @ajm188
    ContributorAuthor

    i'm back, and i think this is an intermittent but ultimately harmless error log noise. it's a race between the cleanup and the throttler's lag collection goroutine.

    The race between Throttler.collectReplicationLag and Migrator.finalCleanup:

    1. collectReplicationLag's ticker (default 100ms) spawns go collectFunc() on every tick,
      gated only on thlr.finishedMigrating — which is set in Throttler.Teardown(), called from
      Migrator.teardown() after finalCleanup() (and the _ghc drop) has already run.
    2. collectFunc() does check CleanupImminentFlag before querying, but it's a check-then-act
      race: if the goroutine reads the flag as 0 a moment before finalCleanup sets it, it
      proceeds anyway.
    3. That query (readChangelogState("heartbeat")) runs on the inspector connection, i.e. the
      read replica — not the primary where DROP TABLE _ghc actually executes. So the race window
      is the full replication lag needed for the drop to propagate to the replica.
    4. In my most recent example, HeartbeatLag spikes from 0.06s to 1.07s at the exact moment of the
      error, and that spike gave the stale in-flight SELECT enough time to land on the replica
      after the drop had already replicated there.

    it's pretty rare since it needs a collectFunc() goroutine spawned in the small window right before CleanupImminentFlag is set, and enough replica lag for the drop to beat it there.

    Planning to look at a fix (tighter check in the collection loop, and/or having finalCleanup wait out in-flight throttler queries before dropping _ghc).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions