Description

VTAdmin Workflow Details View

The max_v_replication_lag value returned in the workflow's show vtctldclient command output (e.g. MoveTables) is a liveness metric that reflects how long ago we last processed an event from the source across all of the streams and not what a VTAdmin user is ultimately interested in when trying to understand if a vreplication workflow is caught up, lagging, etc. The liveness value can be 0 while the workflow is really lagging by hours, which is reflected in the returned max_v_replication_transaction_lag value which is built by comparing the timestamp of the last transaction that we applied from the source with the current timestamp on the target across all of the streams. See the test case in the issue for a demonstration of this.

On this PR branch you can see the max vreplication transaction lag (across all streams) value returned from the workflow show command now used in the workflow detail view when using the manual test in #18804:

VReplication Timings Loss

In #13824 we started closing the binlogplayer stats aggressively everywhere. That was generally correct, but for workflows we should only close them when the controller is deleted. There are various scenarios where the controller and/or binlogplayer stats are re-used. Once you close the binlogplayer stats you cannot re-start the goroutines which operate the timings. So e.g. if you updated a workflow to change the state from Copying to Running — which is what happens automatically when you create a new workflow and it finishes catching up — you would no longer have any stats for VReplicationLags or VReplicationQPS. You can actually see that if you run the manual test in #18804 and look at the metrics:

curl -s http://localhost:15$(vtctldclient GetTablets --keyspace customer --tablet-type primary --shard "0" | awk '{print $1}' | cut -d- -f2 | bc)/debug/vars | grep -E 'VReplicationLag|VReplicationQPS'

They are forever empty. So we change how these stats are managed and we only close the binlogplayer stats when we know that they will no longer be used (primarily when we remove the controller).

VReplicationLag* Metrics

This metric was really measuring how long the target vplayer was lagging behind the source vstreamer as it was comparing the time the event was created on the vstreamer with the current time on the vplayer when it was processed. That means that whenever the stream is healthy and running the lag will always be very low, whether the workflow is not actually lagging or if it's lagging by hours or even days. This is wrong. We were already calculating the "transaction lag" as described above when we estimated the lag due to being throttled, now we also calculate the lag when we're processing transactions as "transaction lag".

But still... the VReplicationQPS and VReplicationLag metric values were exactly the same! For example:

"VReplicationLag": {"1":[110.5,93,109.25,85.4],"All":[110.5,93,109.25,85.4]},
"VReplicationQPS": {"All":[110.5,93,109.25,85.4],"BatchTransaction":[110.5,93,109.25,85.4],"Query":[0,0,0,0],"Transaction":[0,0,0,0]},

That was because we were using a timeseries of Rates, and we were updating the lag value on every event which was a batched transaction. This means that the rate of lag values being added was equal to the rate of batched transactions. So we move VReplicationLag to use a timeseries of Gauges, which is what we really want here for the lag — a sampling of the actual lag values added rather than the rate at which they were added. In a manual test that ensures workflow lag, we can now see that the lag metrics all line up now (see the tail end of the VReplicationLag list):

❯ curl -s http://localhost:15$(vtctldclient GetTablets --keyspace customer --tablet-type primary --shard "0" | awk '{print $1}' | cut -d- -f2 | bc)/debug/vars | grep -E 'VReplicationLag|VReplicationQPS'
"VReplicationLag": {"1":[9223372036854776000,188,124,127,132,136,140,145,149,154,158,162,167,171,176,180,184,189,193,198,202,206,211,215,220,225,229,232,237,241,246,251,254,259,264,268,271,277,281,285,290,293,297,302,306,312,316,320,323,329,333,337,341,345,349,354,358,362,367,370,375,379,384,389,393,396,401,406,409,415,418,422,427,432,435,440,444,448,452,458,461,465,470,475,478,482,487,492,495,500,505,509,513,517,522,525,530,535,538,542,546,552,556,560,564,568,573,578,581,585,591,594,598,604,607,611,617,620,625,628,634,638,642,647,651,654,659,663,668,672,676,680,684,688,693,698,702,707,712,716,721,725,729,734,738,743,748,753,757,761,766,770,775,779,784,788,793,798,802,807,811,816,820,825,829,835,838,843,848,853,856,862,865,871,875,880,885,889,894,898,903]},
"VReplicationLagSeconds": {"commerce.0.commerce2customer.1": 904},
"VReplicationLagSecondsMax": 904,
"VReplicationLagSecondsTotal": 904,
"VReplicationQPS": {"All":[3.4,2.2,2.8,3.5,3.75,3.75,2.6,3.5,3.5,2.6,3,3.5,3.75,2.6,2.8,3,3.5,2.8,3.5,3.25,2.8,3.5,3.5,3.75,3.2,4.25,3.75,3.2,3.75,3.2,3.2,3.75,4.25,3.2,3.2,4,3.2,4,3.2,4,3.2,3.2,3,4,4.25,4.5,4.25,3,3.4,4.25,3.2,4,3.4,4,4.25,3,3.75,4.25,3,4,3.2,4,4.25,3.2,2.8,3.2,4,4.25,4.25,3.2,3,3.75,3.4,4,3.4,3,3.4,4.25,4.25,3.2,4,4.25,3.2,3,3.2,4,4.5,3.4,4.25,3.4,3.4,3.2,4.25,4.25,3.2,4.25,3.4,4,4.25,3.2,3.2,3.4,4,3.75,2.8,4,3.4,3.2,2.8,4.25,3.2,3.4,3.4,3,4,3.4,3.75,3.4,2,3.5,4.5,3.2,3.6,4.25,3.75,3.4,4,4.5,3.8,3,3.2,2.8,2.2,1.8,2.2,2.2,2.25,1.8,2,2.2,2.2,2,2.5,2.25,2,2.25,2.2,2,2,2.2,1.8,2.25,2.25,2.4,1.6,2.75,2.5,1.8,2,2.5,2.75,1.8,2.75,1.8,2.75,2.25,2.2,2,2.75,2,2.2,1.6,3,1.8,3,1.8,2.5,2.4,2.5,2.2],"BatchTransaction":[0.6,2.2,2.8,3.5,3.75,3.75,2.6,3.5,3.5,2.6,3,3.5,3.75,2.6,2.8,3,3.5,2.8,3.5,3.25,2.8,3.5,3.5,3.75,3.2,4.25,3.75,3.2,3.75,3.2,3.2,3.75,4.25,3.2,3.2,4,3.2,4,3.2,4,3.2,3.2,3,4,4.25,4.5,4.25,3,3.4,4.25,3.2,4,3.4,4,4.25,3,3.75,4.25,3,4,3.2,4,4.25,3.2,2.8,3.2,4,4.25,4.25,3.2,3,3.75,3.4,4,3.4,3,3.4,4.25,4.25,3.2,4,4.25,3.2,3,3.2,4,4.5,3.4,4.25,3.4,3.4,3.2,4.25,4.25,3.2,4.25,3.4,4,4.25,3.2,3.2,3.4,4,3.75,2.8,4,3.4,3.2,2.8,4.25,3.2,3.4,3.4,3,4,3.4,3.75,3.4,2,3.5,4.5,3.2,3.6,4.25,3.75,3.4,4,4.5,3.8,3,3.2,2.8,2.2,1.8,2.2,2.2,2.25,1.8,2,2.2,2.2,2,2.5,2.25,2,2.25,2.2,2,2,2.2,1.8,2.25,2.25,2.4,1.6,2.75,2.5,1.8,2,2.5,2.75,1.8,2.75,1.8,2.75,2.25,2.2,2,2.75,2,2.2,1.6,3,1.8,3,1.8,2.5,2.4,2.5,2.2],"Query":[2.8,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"Transaction":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0]},

And the lag metrics line up with what we see for the max_v_replication_transaction_lag output in the vtctldclient MoveTables show command while the test runs. And because of these changes, the VTAdmin stream lag graph looks correct now too:

Related Issue(s)

• Fixes: Bug Report: VTAdmin workflow detail page uses max_v_replication_lag value which can be misleading #18804

Checklist

• "Backport to:" labels have been added if this change should be back-ported to release branches
• If this change is to be back-ported to previous releases, a justification is included in the PR description
• Tests were added or are not required
• Did the new or modified tests pass consistently locally and on CI?
• Documentation was added: Add VReplicationLag metric to docs website#2013

AI Disclosure

h/t to Claude Code for doing all of the vtadmin code changes!