Bug Report: VReplication vplayer stall detector fires while the workflow is throttled, terminally failing resumable Online DDL migrations

[mcrauwel]

Overview of the Issue

The vplayer stall detector ("relay log I/O stalled: progress stalled; vplayer was unable to replicate the transaction in a timely manner") can be triggered purely by throttling. While the vplayer's throttler check is denied, it never calls relay.Fetch(), so the relay log is never drained — but the vstreamer keeps filling it (including injected heartbeats). Once the relay log is full for vplayerProgressDeadline (hardcoded 5 minutes), relayLog.Send() returns the stall error. The stall timer has no awareness of throttle state.

When --vreplication-max-time-to-retry-on-error is set to a non-zero value (operators set this to bound genuinely-dead streams; default is 0 = retry forever), a sustained throttling window longer than that value converts the recurring stall error into a terminal error (last_error: "the same error was encountered continuously … assumed to be unrecoverable"). For a vrepl Online DDL migration, the executor then cancels the migration on that shard and marks it failed.

The failure is a false positive: the stream is healthy and fully resumable. In our incidents, the _vt.vreplication row and _vt.copy_state checkpoints were intact, and issuing Workflow start on the stream (before any RETRY, which deletes the stream and starts a new shadow table) resumes the copy phase from the stored lastpk. A "failed" migration that a plain Workflow start un-fails was not failed — it was throttled, which is backpressure working as designed. The practical cost is severe: multi-day, multi-shard Online DDL migrations lose days of row-copy work to a routine, transient infrastructure event, and most operators will re-run the whole migration from scratch.

Where the pieces live (on main, unchanged from v22):

• Stall timer: go/vt/vttablet/tabletmanager/vreplication/relaylog.go — Send() blocks on canAccept.Wait() when full; startSendTimer fires after vplayerProgressDeadline (hardcoded 5m in vplayer.go), producing relayLogIOStalledMsg + errVPlayerStalled.
• Throttled applier: go/vt/vttablet/tabletmanager/vreplication/vplayer.go, applyEvents() — on throttler denial the vplayer skips relay.Fetch() and loops (recording component_throttled), so the relay log is never drained while denied.
• Producer keeps filling: go/vt/vttablet/tabletserver/vstreamer/vstreamer.go injects heartbeats ~900ms even when the vstreamer itself is throttled.
• Terminal conversion: go/vt/vterrors/last_error.go (ShouldRetry), wired via controller.go with --vreplication-max-time-to-retry-on-error. errVPlayerStalled carries no vterrors code, so it is not intrinsically unrecoverable — only the same-error window makes it terminal.
• Online DDL consequence: go/vt/vttablet/onlineddl/executor.go — reviewRunningMigrations sees vreplication state Error on a running migration and cancels/fails it.

Related prior work: #15797 introduced the stall detector (a real problem worth keeping for genuinely wedged vplayers); #16575 / #16577 fixed lag reporting while throttled, but not stall detection.

Proposed fix directions (any or several):

1. Make the stall deadline throttle-aware (preferred): pause or reset the relay log Send() deadline while the vplayer is in a throttler-denied state; only un-throttled time without progress should count toward the stall verdict. The vplayer already tracks its throttled state in-process.
2. Exempt stall-while-throttled from the LastError terminal window: reset the same-error window whenever a throttled interval overlaps it, so --vreplication-max-time-to-retry-on-error still bounds genuinely dead streams without converting legitimate sustained throttling into a terminal failure.
3. Online DDL executor: classify before failing. On vreplication Error, distinguish resumable error classes (stall/throttle) from unrecoverable ones (FAILED_PRECONDITION, the listed MySQL errnos) and keep the migration in a stuck/retrying state with a descriptive message instead of failed.

Adjacent (possibly its own issue): a catch-up grace period before a freshly restored replica (RESTORE→REPLICA transition) is included in shard-scope throttler lag aggregation — currently a single rejoining replica throttles all lag-gated apps for its entire catch-up, which is what produces the sustained denial in the reproduction below.

Reproduction Steps

1. Run a large vrepl Online DDL migration (ddl_strategy=vitess) mid row-copy on a sharded keyspace, with the tablet throttler enabled (default lag threshold 5s) and --vreplication-max-time-to-retry-on-error=15m on the vttablets.
2. Restore a replica of the same shard from a backup taken N hours ago (N ≥ 1) and let it rejoin — e.g. routine node replacement. The moment it transitions RESTORE→REPLICA it is included in shard-scope lag aggregation with no catch-up grace, so the shard lag metric jumps to ~N hours (we measured 0.2s → 92,886s within one probe interval).
3. Every lag-gated throttler check is now denied for the duration of the catch-up. The vplayer stops draining the relay log; the vstreamer keeps filling it.
4. After 5 minutes, the stall error fires; the stream retries every 5s and stalls again after 5 minutes, always restarting from the identical GTID position (see logs).
5. After 15 minutes of the same error: stream state Error with a terminal-error message → the Online DDL executor cancels the migration on that shard → migration_status='failed' — while SELECT COUNT(*) FROM _vt.copy_state WHERE vrepl_id=<id> still shows the intact checkpoint and Workflow start resumes the copy.

We hit this twice in one week on the same shard, each time triggered by a routine node replacement whose restored replica joined ~20–26h behind.

Binary Version

vttablet version 22.0 (also verified the relevant code paths are unchanged on current main)
MySQL 8.4.6

Operating System and Environment details

Linux x86_64, Kubernetes-based deployment (vitess-operator-style), 32-shard keyspace
tablet throttler enabled, default threshold (5s replica lag)
--vreplication-max-time-to-retry-on-error=15m
vreplication relay log defaults (--vreplication_relay_log_max_size=250000, --vreplication_relay_log_max_items=5000)

Log Fragments

E0819 11:00:55.666607 dbclient.go:139] error in stream 3, will retry after 5s: relay log I/O stalled: progress stalled; vplayer was unable to replicate the transaction in a timely manner; examine the target mysqld instance health and the replicated queries' EXPLAIN output to see why queries are taking unusually long
I0819 11:01:00.720910 vplayer.go:129] Starting VReplication player id: 3, startPos: <identical GTID set on every restart — no progress across retries>
E0819 11:06:01.074720 dbclient.go:139] error in stream 3, will retry after 5s: relay log I/O stalled: progress stalled; ...
E0819 11:11:06.467434 dbclient.go:139] error in stream 3, will retry after 5s: relay log I/O stalled: progress stalled; ...
E0819 11:16:11.859199 last_error.go:85] VReplication controller 3 for workflow "0bb8d2ef_afdb_5a3f_8767_8ef3d110f58e": the same error was encountered continuously since 2026-08-19 11:00:55.666421604 +0000 UTC, it is now assumed to be unrecoverable; any affected operations will need to be manually restarted once error 'relay log I/O stalled: ...' has been addressed
E0819 11:16:11.860652 controller.go:317] vreplication stream 3 going into error state due to progress stalled; vplayer was unable to replicate the transaction in a timely manner; ...
I0819 11:16:46.498284 executor.go:3462] migration 0bb8d2ef_afdb_5a3f_8767_8ef3d110f58e in 'running' state but vreplication state is 'Error'
I0819 11:16:46.498310 executor.go:1753] cancelMigrations: cancelling 0bb8d2ef_afdb_5a3f_8767_8ef3d110f58e; reason: vreplication: terminal error: relay log I/O stalled: ...

Corresponding throttler metric on the shard primary (vttablet_throttler_aggregated_shard_lag): 0.2s at 10:50, 92,886s at 11:00 (= exactly the age of the backup the rejoining replica restored from), decaying as the replica caught up — throughout which the vplayer made zero progress.