pingcap / pingcap/ticdc

logpuller: dispatcher move can leave RangeLock holes and stall resolved ts

Open
#4,547 0 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

type/bug
Dominant language
Go
Stars
56
Forks
63
Avg merge
2d 20h
Merged PRs (30d)
34

Description

What did you do?
  • Deployed TiCDC v8.5.6-release.2 (c6157f2ad683388de72320ff9f7c2111f7483881) in a customer environment.
  • Observed repeated lag spikes on changefeed.
  • Analyzed sanitized node logs together with the current code. All timestamps below are from TiCDC logs and are in UTC.
What did you expect to see?
  • Dispatcher rebalance/move should not pin resolvedTs / changefeedTs for tens of seconds or minutes while DMLs are still being received.
  • During move/reset/remove, the handoff should not leave uncovered span windows that keep a subscription's resolved ts at an old value.
What did you see instead?
  • Around 2026-03-19 21:19, 21:31, and 21:43-21:46, the lag of resolvedTs / changefeedTs increased stepwise to about 2-3 minutes and then dropped abruptly.
  • During the lag window, lastReceiveDMLTime kept moving forward, so this does not look like upstream write traffic stalled.
  • At the same time, logpuller repeatedly logged subscription client holes exist.
  • When the hole was eventually covered, logpuller emitted resolved ts advance step is too large, which shows the resolved ts caught up in a single jump instead of advancing smoothly.
Evidence from logs
  • 21:19:01: maintainer emitted chooseMoveSpans found multiple move plans with moveCount=17, then many add operator to running queue logs.
  • 21:19:33: subscription client holes exist for subscriptionID=348.
  • 21:19:53 .. 21:21:23: resolved ts lag is too large for initialized subscription for subID=348 while lastReceiveDMLTime continued to advance from 21:19:53.022 to 21:21:23.047.
  • 21:21:25: resolved ts advance step is too large with decreaseLag(s)=129.85.
  • 21:31:18: another chooseMoveSpans found multiple move plans with moveCount=16.
  • 21:31:20: event service side logged send remove dispatcher request to event service together with reset dispatcher for moved dispatchers.
  • 21:31:23: resolved ts lag is too large for initialized subscription for subID=400, while lastReceiveDMLTime=21:31:23.057.
  • 21:43:31: another chooseMoveSpans found multiple move plans with moveCount=17.
  • 21:43:33: multiple subscriptions for table 245 became uninitialized; holes were logged for subscriptionID=1074 and 981.
  • 21:45:33 / 21:46:33: lag for subID=981 and 1074 kept growing to 149s+ / 200s+ while hole logs kept repeating.
  • 21:46:48 and 21:46:49: resolved ts advance step is too large with decreaseLag(s)=223.4 and 216.3.
Root cause analysis

The repeated pattern matches a temporary coverage gap in logpuller RangeLock during batch dispatcher move / reset / remove:

  1. maintainer schedules many move operators for the same table;
  2. old subscriptions/dispatchers are removed or reset;
  3. before the new coverage is fully rebuilt, RangeLock.IterAll() sees uncovered spans and records them as UnLockedRanges;
  4. RangeLock.ResolvedTs() takes the minimum of locked ranges and unlocked ranges, so the subscription resolved ts is pinned by the hole's stale ts;
  5. once the hole disappears, resolved ts jumps forward and the lag drops abruptly.

This also explains why lastReceiveDMLTime keeps advancing while resolvedTs does not.

The issue is amplified when maintainer emits many move operators in one burst.

Relevant code paths
  • logservice/logpuller/subscription_client.go:1070: logs subscription client holes exist when UnLockedRanges is not empty.
  • logservice/logpuller/regionlock/region_range_lock.go:264: ResolvedTs() includes unlockedRanges.getMinTs() in the global minimum.
  • logservice/logpuller/regionlock/region_range_lock.go:313: IterAll() turns uncovered gaps into UnLockedRanges.
  • logservice/logpuller/region_event_handler.go:404: warns when resolved ts suddenly advances by a large step.
  • logservice/eventstore/event_store.go:1204: warns when initialized subscriptions have large resolved ts lag.
  • maintainer/replica/split_span_checker.go:460: creates batch move plans.
  • maintainer/operator/operator_controller.go:347: enqueues the move operators.
Versions of the cluster

Upstream TiDB cluster version:

Not included in the sanitized customer log bundle.

Upstream TiKV version:

Not included in the sanitized customer log bundle.

TiCDC version:

v8.5.6-release.2
commit c6157f2ad683388de72320ff9f7c2111f7483881
Potential directions
  • Minimize or eliminate uncovered span windows during dispatcher move/reset/remove.
  • Revisit whether UnLockedRanges should directly pin the global ResolvedTs() during rebalance handoff, or whether the handoff path should preserve continuity differently.
  • Add focused tests for batch dispatcher move on a hot table to verify that resolved ts does not stall for the uncovered gap window.

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start with logservice/logpuller/regionlock/region_range_lock.go, especially IterAll() and ResolvedTs(), then trace the handoff through subscription_client.go and region_event_handler.go. Compare this with batch move creation in maintainer/replica/split_span_checker.go and operator enqueueing in maintainer/operator/operator_controller.go; done means focused hot-table move tests show no unresolved coverage gap stalls or abrupt resolved-ts jumps.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
distributed-systems
Issue type
Bug
Difficulty
5/5
Estimated time
Over a week
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.