Skip to content

perf(cutover): drop two 1s sleeps from the locked cut-over window - #1772

Open
conf wants to merge 1 commit into
github:masterfrom
conf:optimize-cutover-lock-time-1630
Open

conf wants to merge 1 commit into
github:masterfrom
conf:optimize-cutover-lock-time-1630

Conversation

@conf

@conf conf commented Sep 19, 2026

Copy link
Copy Markdown
Contributor

A Pull Request should be associated with an Issue.

Related issue: #1630

Description

This PR removes two fixed 1-second sleeps that run while the original table is write-locked, i.e. while every query on it is blocked.

1. The idle sleep in executeWriteFuncs (the one reported in #1630)

When both the events queue and the row-copy queue are empty, the loop slept a flat second. Once row copy is done that is the steady state, so the AllEventsUpToLockProcessed sentinel — which arrives on applyEventsQueue after the tables are locked — had to wait out the remainder of that sleep:

Done waiting for events up to lock; duration=990.976125ms

It now blocks on both queues with a 1s timeout instead, which is the shape executeDMLWriteFuncs already uses a few lines below. Same log line after:

Done waiting for events up to lock; duration=1.314334ms

2. The retryOperation backoff in waitForRename, one step later

With #1 fixed the cut-over still took ~1s, and the remaining second is in the next phase. After issuing the atomic RENAME in a goroutine, gh-ost polls SHOW PROCESSLIST for it through retryOperation, whose backoff is a flat 1 second. The first poll usually loses the race against the RENAME registering its metadata-lock wait, so it paid that full second — again, with the table locked:

22:36:39 Done waiting for events up to lock; duration=1.314334ms
22:36:39 Issuing and expecting this to block: rename ...
22:36:40 Found atomic RENAME to be blocking, as expected.
22:36:40 Lock & rename duration: 1.019256291s

Across the full localtests suite this hit 6 of the 73 cases that reach cut-over (~8%), which is why it does not show on every run.

It now polls every 10ms, for a budget of twice the RENAME's own lock_wait_timeout — past that the RENAME has errored out and set tableRenameKnownToHaveFailed, so waitForRename returns immediately and the attempt count never runs out.

Both call sites go through a new retryOperationWithInterval, which is the existing retryOperation body with the attempt count and wait made explicit; retryOperation now delegates to it with its previous MaxRetries()/1s values. No behaviour change for its other callers.

Results

Lock & rename duration over the 73 localtests cases that reach cut-over. Before, it was ~1s on essentially every cut-over:

p50 p90 p99 max
mariadb:11.8 9ms 21ms 90ms 90ms
mysql:8.4.3 23ms 31ms 96ms 96ms

The remaining tail is not this code path. It is waitForEventsUpToLock: on both flavours the same four cases, which happen to see no DML during the migration, spend 54–77ms waiting for the sentinel to come back through an otherwise idle binlog stream. No case with concurrent DML exceeds 50ms on either flavour (0/60 and 0/59). That delay reproduces with a plain mariadb-binlog --read-from-remote-server client, so it is in binlog delivery rather than in gh-ost, and it predates this change.

Test change

TestCutOverLossDataCaseLockGhostBeforeRename took its lock on the ghost table one second after removing the postpone flag, relying on cut-over still being in flight. With cut-over now ~10ms the ghost table was already renamed, giving Table 'test._testing_gho' doesn't exist. It now takes the lock before un-postponing, which is what the test name describes anyway and no longer depends on cut-over being slow.

Verification

  • script/cibuild — clean (gofmt, build, go test -race ./go/...).
  • script/docker-gh-ost-replica-tests run — full suite passes on mariadb:11.4, mariadb:11.8, mysql:8.0.41 and mysql:8.4.3.
  • Per-case Lock & rename duration measured on mariadb:11.8 and mysql:8.4.3 for the table above.

In case this PR introduced Go code changes:

  • contributed code is using same conventions as original code
  • script/cibuild returns with no formatting errors, build errors or unit test errors.

Both sleeps happened while the original table was write-locked, so they
were pure table downtime:

- executeWriteFuncs slept 1s whenever both queues were empty, which is the
  steady state once row copy is done. The cut-over sentinel arrives on
  applyEventsQueue and had to wait that sleep out. It now blocks on both
  queues with a 1s timeout instead.

- waitForRename watched for the blocking RENAME through retryOperation,
  which backs off a flat 1s. The first check usually runs before the RENAME
  shows up. It now checks every 10ms, via a new retryOperationWithInterval
  (retryOperation with the attempt count and wait made explicit).

"Lock & rename duration" over the 73 localtests that reach cut-over. Before,
it was ~1s on essentially every cut-over:

  mariadb:11.8   p50  9ms   p90 21ms   p99 90ms   max 90ms
  mysql:8.4.3    p50 23ms   p90 31ms   p99 96ms   max 96ms

The tail is not this code path. It is waitForEventsUpToLock: on both
flavours the same four cases, which happen to see no DML during the
migration, spend 54-77ms waiting for the sentinel to come back through an
otherwise idle binlog stream. No case with concurrent DML exceeds 50ms.
That delay reproduces with a plain binlog reader, so it is in binlog
delivery, not in gh-ost.

TestCutOverLossDataCaseLockGhostBeforeRename now locks the ghost table
before un-postponing, instead of relying on cut-over being slow.

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

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant