From b00d6892b451bd05c24d62be405fb1e311e5e6cf Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Mon, 13 Apr 2026 13:26:00 +0800 Subject: [PATCH 01/17] revert tow stage syncpoint Signed-off-by: dongmen <414110582@qq.com> --- .gitignore | 2 +- .../dispatcher/basic_dispatcher.go | 14 +- downstreamadapter/dispatcher/helper.go | 3 +- downstreamadapter/dispatchermanager/task.go | 32 +- pkg/eventservice/dispatcher_stat.go | 118 ----- pkg/eventservice/dispatcher_stat_test.go | 26 - pkg/eventservice/event_broker.go | 443 ++--------------- pkg/eventservice/event_broker_test.go | 457 +----------------- tests/integration_tests/bdr_mode/run.sh | 1 + 9 files changed, 65 insertions(+), 1031 deletions(-) diff --git a/.gitignore b/.gitignore index 9a2367b233..f0555def26 100644 --- a/.gitignore +++ b/.gitignore @@ -4,8 +4,8 @@ tools/bin tools/include tools/workload/bin -.codex .design +.codex .issue .vscode .idea diff --git a/downstreamadapter/dispatcher/basic_dispatcher.go b/downstreamadapter/dispatcher/basic_dispatcher.go index 0c31275a4c..6771e343b3 100644 --- a/downstreamadapter/dispatcher/basic_dispatcher.go +++ b/downstreamadapter/dispatcher/basic_dispatcher.go @@ -463,12 +463,12 @@ func (d *BasicDispatcher) ensureTableModeCompatibility(tableInfo *common.TableIn func (d *BasicDispatcher) isFirstEvent(event commonEvent.Event) bool { if d.componentStatus.Get() == heartbeatpb.ComponentState_Initializing { switch event.GetType() { - case commonEvent.TypeDMLEvent, commonEvent.TypeDDLEvent: + case commonEvent.TypeResolvedEvent, commonEvent.TypeDMLEvent, commonEvent.TypeDDLEvent: if event.GetCommitTs() > d.startTs { return true } // the first syncpoint event can be same as startTs - case commonEvent.TypeResolvedEvent, commonEvent.TypeSyncPointEvent: + case commonEvent.TypeSyncPointEvent: if event.GetCommitTs() >= d.startTs { return true } @@ -749,11 +749,11 @@ func (d *BasicDispatcher) handleEvents(dispatcherEvents []DispatcherEvent, wakeC // and return await=true. // The status path will be waked up after the action finishes. func (d *BasicDispatcher) HandleDispatcherStatus(dispatcherStatus *heartbeatpb.DispatcherStatus) (await bool) { - // log.Debug("dispatcher handle dispatcher status", - // zap.String("dispatcherStatus", common.FormatDispatcherStatus(dispatcherStatus)), - // zap.Stringer("dispatcher", d.id), - // zap.Any("action", dispatcherStatus.GetAction()), - // zap.Any("ack", dispatcherStatus.GetAck())) + log.Debug("dispatcher handle dispatcher status", + zap.String("dispatcherStatus", common.FormatDispatcherStatus(dispatcherStatus)), + zap.Stringer("dispatcher", d.id), + zap.Any("action", dispatcherStatus.GetAction()), + zap.Any("ack", dispatcherStatus.GetAck())) // Step1: deal with the ack info ack := dispatcherStatus.GetAck() diff --git a/downstreamadapter/dispatcher/helper.go b/downstreamadapter/dispatcher/helper.go index d50137a95b..177eab4ffa 100644 --- a/downstreamadapter/dispatcher/helper.go +++ b/downstreamadapter/dispatcher/helper.go @@ -139,8 +139,7 @@ func (b *BlockEventStatus) actionMatchs(action *heartbeatpb.DispatcherAction) bo return false } - pendingIsSyncPoint := b.blockPendingEvent.GetType() == commonEvent.TypeSyncPointEvent - return b.blockCommitTs == action.CommitTs && pendingIsSyncPoint == action.IsSyncPoint + return b.blockCommitTs == action.CommitTs } func (b *BlockEventStatus) getEventCommitTs() (uint64, bool) { diff --git a/downstreamadapter/dispatchermanager/task.go b/downstreamadapter/dispatchermanager/task.go index c129c8a29a..d212822149 100644 --- a/downstreamadapter/dispatchermanager/task.go +++ b/downstreamadapter/dispatchermanager/task.go @@ -28,15 +28,6 @@ import ( "go.uber.org/zap" ) -const ( - heartbeatTaskExecuteInterval = 200 * time.Millisecond - - defaultCompleteStatusInterval = 10 * time.Second - // syncPointCompleteStatusInterval is shorter so eventBroker can receive dispatcher-level - // checkpointTs progress faster when two-phase syncpoint commit is enabled. - syncPointCompleteStatusInterval = 1 * time.Second -) - // HeartbeatTask is a perioic task to collect the heartbeat status from event dispatcher manager and push to heartbeatRequestQueue type HeartBeatTask struct { taskHandle *threadpool.TaskHandle @@ -55,30 +46,15 @@ func newHeartBeatTask(manager *DispatcherManager) *HeartBeatTask { return t } -func getCompleteStatusInterval(enableSyncPoint bool) time.Duration { - if enableSyncPoint { - return syncPointCompleteStatusInterval - } - return defaultCompleteStatusInterval -} - -func getIntervalTicks(interval, executeInterval time.Duration) int { - ticks := int(interval / executeInterval) - if ticks <= 0 { - return 1 - } - return ticks -} - func (t *HeartBeatTask) Execute() time.Time { if t.manager.closed.Load() { return time.Time{} } - executeInterval := heartbeatTaskExecuteInterval - enableSyncPoint := t.manager.config != nil && t.manager.config.EnableSyncPoint - completeStatusInterval := getIntervalTicks(getCompleteStatusInterval(enableSyncPoint), executeInterval) + executeInterval := time.Millisecond * 200 + // 10s / 200ms = 50 + completeStatusInterval := int(time.Second * 10 / executeInterval) t.statusTick++ - needCompleteStatus := t.statusTick%completeStatusInterval == 0 + needCompleteStatus := (t.statusTick)%completeStatusInterval == 0 message := t.manager.aggregateDispatcherHeartbeats(needCompleteStatus) t.manager.heartbeatRequestQueue.Enqueue(&HeartBeatRequestWithTargetID{TargetID: t.manager.GetMaintainerID(), Request: message}) return time.Now().Add(executeInterval) diff --git a/pkg/eventservice/dispatcher_stat.go b/pkg/eventservice/dispatcher_stat.go index 982fd9d916..a99767a704 100644 --- a/pkg/eventservice/dispatcher_stat.go +++ b/pkg/eventservice/dispatcher_stat.go @@ -434,16 +434,6 @@ type changefeedStatus struct { lastTrendAdjustTime atomic.Time usageWindow *memoryUsageWindow syncPointInterval time.Duration - // syncPointPreparingTs is the globally selected syncpoint ts in prepare stage. - // 0 means there is no pending syncpoint preparation. - syncPointPreparingTs atomic.Uint64 - // syncPointInFlightTs tracks the commit-stage syncpoint ts that is waiting for all - // active dispatchers to advance nextSyncPoint beyond it. - // 0 means there is no in-flight syncpoint in commit stage. - syncPointInFlightTs atomic.Uint64 - // syncPointStateMu serializes transitions between prepare/commit stages so - // syncPointPreparingTs and syncPointInFlightTs stay consistent. - syncPointStateMu sync.Mutex } func newChangefeedStatus(changefeedID common.ChangeFeedID, syncPointInterval time.Duration) *changefeedStatus { @@ -479,111 +469,3 @@ func (c *changefeedStatus) isEmpty() bool { func (c *changefeedStatus) isSyncpointEnabled() bool { return c.syncPointInterval > 0 } - -func (c *changefeedStatus) getSyncPointPreparingTs() uint64 { - return c.syncPointPreparingTs.Load() -} - -// tryEnterSyncPointPrepare tries to enter syncpoint prepare stage for candidateTs. -// If a prepare ts already exists, the same ts is accepted, and a smaller ts can -// replace it before commit stage starts. -func (c *changefeedStatus) tryEnterSyncPointPrepare(candidateTs uint64) bool { - if candidateTs == 0 { - return false - } - c.syncPointStateMu.Lock() - defer c.syncPointStateMu.Unlock() - - preparingTs := c.syncPointPreparingTs.Load() - switch { - case preparingTs == 0: - c.syncPointPreparingTs.Store(candidateTs) - return true - case preparingTs == candidateTs: - return true - case c.syncPointInFlightTs.Load() != 0: - return false - case candidateTs < preparingTs: - c.syncPointPreparingTs.Store(candidateTs) - return true - default: - return false - } -} - -// isSyncPointInCommitStage returns whether commitTs is in commit stage and can be emitted now. -func (c *changefeedStatus) isSyncPointInCommitStage(commitTs uint64) bool { - return commitTs > 0 && - c.syncPointPreparingTs.Load() == commitTs && - c.syncPointInFlightTs.Load() == commitTs -} - -// tryPromoteSyncPointToCommitIfReady promotes prepare stage to commit stage when all active -// dispatchers have sentResolvedTs >= preparingTs. -func (c *changefeedStatus) tryPromoteSyncPointToCommitIfReady() { - c.syncPointStateMu.Lock() - defer c.syncPointStateMu.Unlock() - - preparingTs := c.syncPointPreparingTs.Load() - if preparingTs == 0 || c.syncPointInFlightTs.Load() != 0 { - return - } - - hasEligible := false - ready := true - c.dispatchers.Range(func(_ any, value any) bool { - dispatcher := value.(*atomic.Pointer[dispatcherStat]).Load() - if dispatcher == nil || dispatcher.isRemoved.Load() || dispatcher.seq.Load() == 0 { - return true - } - hasEligible = true - if dispatcher.sentResolvedTs.Load() < preparingTs { - ready = false - return false - } - return true - }) - if !hasEligible || !ready { - return - } - - c.syncPointInFlightTs.Store(preparingTs) -} - -// tryFinishSyncPointCommitIfAllEmitted finishes current commit stage when all active dispatchers -// have advanced nextSyncPoint beyond inFlightTs and checkpointTs beyond inFlightTs. -// nextSyncPoint progression only proves event-broker emission, while checkpoint progression -// confirms downstream has moved past the in-flight syncpoint barrier. -func (c *changefeedStatus) tryFinishSyncPointCommitIfAllEmitted() { - c.syncPointStateMu.Lock() - defer c.syncPointStateMu.Unlock() - - inFlightTs := c.syncPointInFlightTs.Load() - if inFlightTs == 0 { - return - } - - canAdvance := true - c.dispatchers.Range(func(_ any, value any) bool { - dispatcher := value.(*atomic.Pointer[dispatcherStat]).Load() - if dispatcher == nil || dispatcher.isRemoved.Load() || dispatcher.seq.Load() == 0 { - return true - } - if dispatcher.nextSyncPoint.Load() <= inFlightTs { - canAdvance = false - return false - } - if dispatcher.checkpointTs.Load() <= inFlightTs { - canAdvance = false - return false - } - return true - }) - - if canAdvance { - c.syncPointInFlightTs.Store(0) - if c.syncPointPreparingTs.Load() == inFlightTs { - c.syncPointPreparingTs.Store(0) - } - } -} diff --git a/pkg/eventservice/dispatcher_stat_test.go b/pkg/eventservice/dispatcher_stat_test.go index 0b9230fd5c..0be560ab78 100644 --- a/pkg/eventservice/dispatcher_stat_test.go +++ b/pkg/eventservice/dispatcher_stat_test.go @@ -23,7 +23,6 @@ import ( pevent "github.com/pingcap/ticdc/pkg/common/event" "github.com/stretchr/testify/require" "github.com/tikv/client-go/v2/oracle" - "go.uber.org/atomic" ) func TestNewDispatcherStat(t *testing.T) { @@ -179,28 +178,3 @@ func TestResolvedTsCache(t *testing.T) { require.Equal(t, uint64(109), res[9].ResolvedTs) require.False(t, rc.isFull()) } - -func TestSyncPointPrepareCannotLowerAfterPromote(t *testing.T) { - status := newChangefeedStatus(common.NewChangefeedID4Test("default", "syncpoint-race"), 10*time.Second) - - const ( - preparingTs = uint64(50) - loweredTarget = uint64(40) - ) - - readyDispatcher := &dispatcherStat{} - readyDispatcher.seq.Store(1) - readyDispatcher.sentResolvedTs.Store(preparingTs) - dispatcherPtr := &atomic.Pointer[dispatcherStat]{} - dispatcherPtr.Store(readyDispatcher) - status.addDispatcher(common.DispatcherID{Low: 1, High: 1}, dispatcherPtr) - - status.syncPointPreparingTs.Store(preparingTs) - status.tryPromoteSyncPointToCommitIfReady() - require.True(t, status.isSyncPointInCommitStage(preparingTs)) - - lowered := status.tryEnterSyncPointPrepare(loweredTarget) - require.False(t, lowered) - require.Equal(t, preparingTs, status.syncPointPreparingTs.Load()) - require.Equal(t, preparingTs, status.syncPointInFlightTs.Load()) -} diff --git a/pkg/eventservice/event_broker.go b/pkg/eventservice/event_broker.go index ecd03fb3bf..49e14d395f 100644 --- a/pkg/eventservice/event_broker.go +++ b/pkg/eventservice/event_broker.go @@ -52,7 +52,6 @@ const ( // defaultSendResolvedTsInterval use to control whether to send a resolvedTs event to the dispatcher when its scan is skipped. defaultSendResolvedTsInterval = time.Second * 2 defaultRefreshMinSentResolvedTsInterval = time.Second * 1 - defaultLogSyncPointStageInterval = time.Minute ) // eventBroker get event from the eventStore, and send the event to the dispatchers. @@ -114,11 +113,10 @@ func newEventBroker( sendMessageWorkerCount := config.DefaultBasicEventHandlerConcurrency scanWorkerCount := config.DefaultBasicEventHandlerConcurrency * 4 - eventServiceConfig := config.GetGlobalServerConfig().Debug.EventService - scanTaskQueueSize := eventServiceConfig.ScanTaskQueueSize / scanWorkerCount + scanTaskQueueSize := config.GetGlobalServerConfig().Debug.EventService.ScanTaskQueueSize / scanWorkerCount sendMessageQueueSize := basicChannelSize * 4 - scanLimitInBytes := eventServiceConfig.ScanLimitInBytes + scanLimitInBytes := config.GetGlobalServerConfig().Debug.EventService.ScanLimitInBytes g, ctx := errgroup.WithContext(ctx) ctx, cancel := context.WithCancel(ctx) @@ -187,169 +185,10 @@ func newEventBroker( return c.refreshMinSentResolvedTs(ctx) }) - g.Go(func() error { - return c.logSyncPointStage(ctx, defaultLogSyncPointStageInterval) - }) - - log.Info("new event broker created", - zap.Uint64("id", id), - zap.Uint64("scanLimitInBytes", c.scanLimitInBytes)) + log.Info("new event broker created", zap.Uint64("id", id), zap.Uint64("scanLimitInBytes", c.scanLimitInBytes)) return c } -func (c *eventBroker) logSyncPointStage(ctx context.Context, interval time.Duration) error { - ticker := time.NewTicker(interval) - defer ticker.Stop() - - for { - select { - case <-ctx.Done(): - return context.Cause(ctx) - case <-ticker.C: - c.changefeedMap.Range(func(_, value interface{}) bool { - status := value.(*changefeedStatus) - if !status.isSyncpointEnabled() { - return true - } - - preparingTs := status.getSyncPointPreparingTs() - inFlightTs := status.syncPointInFlightTs.Load() - commitReady := preparingTs > 0 && inFlightTs == preparingTs - stage := "idle" - switch { - case preparingTs == 0 && inFlightTs == 0: - stage = "idle" - case preparingTs > 0 && !commitReady: - stage = "prepare" - case preparingTs > 0 && commitReady: - stage = "commit" - default: - stage = "unknown" - } - - var ( - totalDispatcherCount int - activeDispatcherCount int - prepareReadyCount int - prepareWaitingCount int - commitDoneCount int - commitWaitingCount int - commitEmitPendingCount int - minSentResolvedTs = ^uint64(0) - minCheckpointTs = ^uint64(0) - minNextSyncPointTs = ^uint64(0) - prepareBlockingFound bool - commitBlockingFound bool - prepareBlockingDispID common.DispatcherID - prepareBlockingSentTs uint64 - commitBlockingDispID common.DispatcherID - commitBlockingCkptTs uint64 - commitBlockingNextSPTs uint64 - ) - - status.dispatchers.Range(func(_, dispatcherValue any) bool { - dispatcher := dispatcherValue.(*atomic.Pointer[dispatcherStat]).Load() - if dispatcher == nil || dispatcher.isRemoved.Load() { - return true - } - - totalDispatcherCount++ - if dispatcher.seq.Load() == 0 { - return true - } - - activeDispatcherCount++ - sentResolvedTs := dispatcher.sentResolvedTs.Load() - checkpointTs := dispatcher.checkpointTs.Load() - nextSyncPointTs := dispatcher.nextSyncPoint.Load() - if sentResolvedTs < minSentResolvedTs { - minSentResolvedTs = sentResolvedTs - } - if checkpointTs < minCheckpointTs { - minCheckpointTs = checkpointTs - } - if nextSyncPointTs > 0 && nextSyncPointTs < minNextSyncPointTs { - minNextSyncPointTs = nextSyncPointTs - } - - if preparingTs > 0 { - if sentResolvedTs >= preparingTs { - prepareReadyCount++ - } else { - prepareWaitingCount++ - if !prepareBlockingFound { - prepareBlockingFound = true - prepareBlockingDispID = dispatcher.id - prepareBlockingSentTs = sentResolvedTs - } - } - } - if inFlightTs > 0 { - if nextSyncPointTs == inFlightTs && sentResolvedTs >= inFlightTs { - commitEmitPendingCount++ - } - if nextSyncPointTs > inFlightTs { - commitDoneCount++ - } else { - commitWaitingCount++ - if !commitBlockingFound { - commitBlockingFound = true - commitBlockingDispID = dispatcher.id - commitBlockingCkptTs = checkpointTs - commitBlockingNextSPTs = nextSyncPointTs - } - } - } - return true - }) - - if minSentResolvedTs == ^uint64(0) { - minSentResolvedTs = 0 - } - if minCheckpointTs == ^uint64(0) { - minCheckpointTs = 0 - } - if minNextSyncPointTs == ^uint64(0) { - minNextSyncPointTs = 0 - } - - fields := []zap.Field{ - zap.Stringer("changefeedID", status.changefeedID), - zap.String("stage", stage), - zap.Uint64("preparingTs", preparingTs), - zap.Bool("commitReady", commitReady), - zap.Uint64("inFlightTs", inFlightTs), - zap.Int("dispatchersTotal", totalDispatcherCount), - zap.Int("dispatchersActive", activeDispatcherCount), - zap.Int("prepareReadyCount", prepareReadyCount), - zap.Int("prepareWaitingCount", prepareWaitingCount), - zap.Int("commitDoneCount", commitDoneCount), - zap.Int("commitWaitingCount", commitWaitingCount), - zap.Int("commitEmitPendingCount", commitEmitPendingCount), - zap.Uint64("minSentResolvedTs", minSentResolvedTs), - zap.Uint64("minCheckpointTs", minCheckpointTs), - zap.Uint64("minNextSyncPointTs", minNextSyncPointTs), - } - if prepareBlockingFound { - fields = append(fields, - zap.Stringer("prepareBlockingDispatcher", prepareBlockingDispID), - zap.Uint64("prepareBlockingSentResolvedTs", prepareBlockingSentTs), - ) - } - if commitBlockingFound { - fields = append(fields, - zap.Stringer("commitBlockingDispatcher", commitBlockingDispID), - zap.Uint64("commitBlockingCheckpointTs", commitBlockingCkptTs), - zap.Uint64("commitBlockingNextSyncPointTs", commitBlockingNextSPTs), - ) - } - log.Debug("syncpoint stage snapshot", fields...) - return true - }) - } - } -} - func (c *eventBroker) sendDML(remoteID node.ID, batchEvent *event.BatchDMLEvent, d *dispatcherStat) { doSendDML := func(e *event.BatchDMLEvent) { // Send the DML event @@ -374,7 +213,7 @@ func (c *eventBroker) sendDML(remoteID node.ID, batchEvent *event.BatchDMLEvent, doSendDML(events) // Reset the index to 1 to process the next event after `dml` in next loop idx = 1 - // Emit sync point event if needed. + // Emit sync point event if needed c.emitSyncPointEventIfNeeded(dml.GetCommitTs(), d, remoteID) } else { idx++ @@ -398,42 +237,26 @@ func (c *eventBroker) sendDML(remoteID node.ID, batchEvent *event.BatchDMLEvent, } func (c *eventBroker) sendDDL(ctx context.Context, remoteID node.ID, e *event.DDLEvent, d *dispatcherStat) { - sendDDLEvent := func() bool { - e.DispatcherID = d.id - e.Seq = d.seq.Add(1) - e.Epoch = d.epoch - ddlEvent := newWrapDDLEvent(remoteID, e) - select { - case <-ctx.Done(): - log.Error("send ddl event failed", zap.Error(ctx.Err())) - return false - case c.getMessageCh(d.messageWorkerIndex, common.IsRedoMode(d.info.GetMode())) <- ddlEvent: - updateMetricEventServiceSendDDLCount(d.info.GetMode()) - } - - log.Info("send ddl event to dispatcher", - zap.Stringer("changefeedID", d.changefeedStat.changefeedID), - zap.Stringer("dispatcherID", d.id), - zap.Int64("tableID", d.info.GetTableSpan().TableID), - zap.Int64("ddlEventTableID", e.GetTableID()), - zap.String("query", e.Query), zap.Uint64("commitTs", e.FinishedTs), - zap.Uint64("seq", e.Seq), zap.Int64("mode", d.info.GetMode())) - return true - } - - // Keep same-ts barrier order as (commitTs, isSyncPoint): DDL before syncpoint. - // This matches maintainer/dispatcher assumptions when DDL and syncpoint share commitTs. - c.fastForwardSyncPointIfNeeded(d) - if d.enableSyncPoint && d.nextSyncPoint.Load() == e.FinishedTs { - if !sendDDLEvent() { - return - } - c.emitSyncPointEventIfNeeded(e.FinishedTs, d, remoteID) + c.emitSyncPointEventIfNeeded(e.FinishedTs, d, remoteID) + e.DispatcherID = d.id + e.Seq = d.seq.Add(1) + e.Epoch = d.epoch + ddlEvent := newWrapDDLEvent(remoteID, e) + select { + case <-ctx.Done(): + log.Error("send ddl event failed", zap.Error(ctx.Err())) return + case c.getMessageCh(d.messageWorkerIndex, common.IsRedoMode(d.info.GetMode())) <- ddlEvent: + updateMetricEventServiceSendDDLCount(d.info.GetMode()) } - c.emitSyncPointEventIfNeeded(e.FinishedTs, d, remoteID) - _ = sendDDLEvent() + log.Info("send ddl event to dispatcher", + zap.Stringer("changefeedID", d.changefeedStat.changefeedID), + zap.Stringer("dispatcherID", d.id), + zap.Int64("DDLSpanTableID", d.info.GetTableSpan().TableID), + zap.Int64("EventTableID", e.GetTableID()), + zap.String("query", e.Query), zap.Uint64("commitTs", e.FinishedTs), + zap.Uint64("seq", e.Seq), zap.Int64("mode", d.info.GetMode())) } func (c *eventBroker) refreshMinSentResolvedTs(ctx context.Context) error { @@ -447,62 +270,12 @@ func (c *eventBroker) refreshMinSentResolvedTs(ctx context.Context) error { c.changefeedMap.Range(func(key, value interface{}) bool { status := value.(*changefeedStatus) status.refreshMinSentResolvedTs() - c.advanceSyncPointState(status) - c.nudgeSyncPointCommitDispatchers(status) return true }) } } } -func (c *eventBroker) advanceSyncPointState(status *changefeedStatus) { - status.tryPromoteSyncPointToCommitIfReady() - status.tryFinishSyncPointCommitIfAllEmitted() -} - -func (c *eventBroker) nudgeSyncPointCommitDispatchers(status *changefeedStatus) { - inFlightTs := status.syncPointInFlightTs.Load() - if inFlightTs == 0 { - return - } - - c.dispatchers.Range(func(_, value interface{}) bool { - dispatcher := value.(*atomic.Pointer[dispatcherStat]).Load() - if dispatcher == nil || dispatcher.changefeedStat != status { - return true - } - if !c.shouldNudgeSyncPointCommit(dispatcher) { - return true - } - c.pushTask(dispatcher, false) - return true - }) -} - -func (c *eventBroker) shouldNudgeSyncPointCommit(d *dispatcherStat) bool { - if d == nil || d.isRemoved.Load() || !d.enableSyncPoint || d.seq.Load() == 0 { - return false - } - c.fastForwardSyncPointIfNeeded(d) - - commitTs := d.nextSyncPoint.Load() - if commitTs == 0 || d.sentResolvedTs.Load() < commitTs { - return false - } - - return d.changefeedStat.isSyncPointInCommitStage(commitTs) -} - -func (c *eventBroker) nudgeSyncPointCommitIfNeeded(d *dispatcherStat) bool { - if !c.shouldNudgeSyncPointCommit(d) { - return false - } - // Resend resolved-ts at current watermark to trigger syncpoint emission in commit stage, - // even when there is no fresh upstream event to drive a new scan. - c.sendResolvedTs(d, d.sentResolvedTs.Load()) - return true -} - func (c *eventBroker) sendSignalResolvedTs(d *dispatcherStat) { // Can't send resolvedTs if there was a interrupted scan task happened before. // d.lastScannedStartTs.Load() != 0 indicates that there was a interrupted scan task happened before. @@ -566,55 +339,36 @@ func (c *eventBroker) tickTableTriggerDispatchers(ctx context.Context) error { case <-ticker.C: c.tableTriggerDispatchers.Range(func(key, value interface{}) bool { stat := value.(*atomic.Pointer[dispatcherStat]).Load() - c.processTableTriggerDispatcher(ctx, key.(common.DispatcherID), stat) + if !c.checkAndSendReady(stat) { + return true + } + c.sendHandshakeIfNeed(stat) + startTs := stat.sentResolvedTs.Load() + remoteID := node.ID(stat.info.GetServerID()) + keyspaceMeta := common.KeyspaceMeta{ + ID: stat.info.GetTableSpan().KeyspaceID, + Name: stat.info.GetChangefeedID().Keyspace(), + } + ddlEvents, endTs, err := c.schemaStore.FetchTableTriggerDDLEvents(keyspaceMeta, key.(common.DispatcherID), stat.filter, startTs, 100) + if err != nil { + log.Error("table trigger ddl events fetch failed", zap.Uint32("keyspaceID", stat.info.GetTableSpan().KeyspaceID), zap.Stringer("dispatcherID", stat.id), zap.Error(err)) + return true + } + stat.receivedResolvedTs.Store(endTs) + for _, e := range ddlEvents { + ep := &e + c.sendDDL(ctx, remoteID, ep, stat) + } + if endTs > startTs { + // After all the events are sent, we send the watermark to the dispatcher. + c.sendResolvedTs(stat, endTs) + } return true }) } } } -func (c *eventBroker) processTableTriggerDispatcher(ctx context.Context, dispatcherID common.DispatcherID, stat *dispatcherStat) { - if !c.checkAndSendReady(stat) { - return - } - c.sendHandshakeIfNeed(stat) - - startTs := stat.sentResolvedTs.Load() - remoteID := node.ID(stat.info.GetServerID()) - keyspaceMeta := common.KeyspaceMeta{ - ID: stat.info.GetTableSpan().KeyspaceID, - Name: stat.info.GetChangefeedID().Keyspace(), - } - - ddlEvents, endTs, err := c.schemaStore.FetchTableTriggerDDLEvents(keyspaceMeta, dispatcherID, stat.filter, startTs, 100) - if err != nil { - log.Error("table trigger ddl events fetch failed", zap.Uint32("keyspaceID", stat.info.GetTableSpan().KeyspaceID), - zap.Stringer("dispatcherID", stat.id), zap.Uint64("startTs", startTs), zap.Error(err)) - return - } - // Keep the raw resolved-ts from schema store for scan readiness/lag visibility. - stat.receivedResolvedTs.Store(endTs) - - boundedEndTs := c.capCommitTsEndBySyncPoint(stat, endTs) - - for _, e := range ddlEvents { - if e.FinishedTs > boundedEndTs { - break - } - ep := &e - c.sendDDL(ctx, remoteID, ep, stat) - } - - if boundedEndTs > startTs { - // After all the events are sent, we send the watermark to the dispatcher. - c.sendResolvedTs(stat, boundedEndTs) - } else { - if !c.nudgeSyncPointCommitIfNeeded(stat) { - c.sendSignalResolvedTs(stat) - } - } -} - func (c *eventBroker) logUninitializedDispatchers(ctx context.Context) error { ticker := time.NewTicker(1 * time.Minute) defer ticker.Stop() @@ -656,7 +410,6 @@ func (c *eventBroker) getScanTaskDataRange(task scanTask) (bool, common.DataRang // 1. Get the data range of the dispatcher. dataRange, needScan := task.getDataRange() if !needScan { - c.nudgeSyncPointCommitIfNeeded(task) updateMetricEventServiceSkipResolvedTsCount(task.info.GetMode()) return false, common.DataRange{} } @@ -693,7 +446,6 @@ func (c *eventBroker) getScanTaskDataRange(task scanTask) (bool, common.DataRang ) } } - dataRange.CommitTsEnd = c.capCommitTsEndBySyncPoint(task, dataRange.CommitTsEnd) if dataRange.CommitTsEnd <= dataRange.CommitTsStart && hasPendingDDLEventInCurrentRange { // Global scan window base can be pinned by other lagging dispatchers. @@ -705,9 +457,6 @@ func (c *eventBroker) getScanTaskDataRange(task scanTask) (bool, common.DataRang } localScanMaxTs := oracle.GoTimeToTS(oracle.GetTimeFromTS(dataRange.CommitTsStart).Add(interval)) dataRange.CommitTsEnd = min(commitTsEndBeforeWindow, localScanMaxTs) - // Local pending-DDL advance is allowed to bypass scan window, but must still obey - // syncpoint prepare/commit boundary. - dataRange.CommitTsEnd = c.capCommitTsEndBySyncPoint(task, dataRange.CommitTsEnd) if dataRange.CommitTsEnd > dataRange.CommitTsStart { log.Info("scan window local advance due to pending ddl", zap.Stringer("changefeedID", task.changefeedStat.changefeedID), @@ -722,9 +471,6 @@ func (c *eventBroker) getScanTaskDataRange(task scanTask) (bool, common.DataRang if dataRange.CommitTsEnd <= dataRange.CommitTsStart { updateMetricEventServiceSkipResolvedTsCount(task.info.GetMode()) - if c.nudgeSyncPointCommitIfNeeded(task) { - return false, common.DataRange{} - } // Scan range can become empty after applying capping (for example, scan window). // Send a signal resolved-ts event (rate limited) to keep downstream responsive, // but do not advance the watermark here. @@ -749,26 +495,6 @@ func (c *eventBroker) getScanTaskDataRange(task scanTask) (bool, common.DataRang return true, dataRange } -// capCommitTsEndBySyncPoint enforces two-stage syncpoint boundary on scan range: -// 1. Always cap by next syncpoint boundary. -// 2. In prepare stage, cap by global preparing ts until commit stage is ready. -func (c *eventBroker) capCommitTsEndBySyncPoint(task scanTask, commitTsEnd uint64) uint64 { - if !task.enableSyncPoint { - return commitTsEnd - } - c.fastForwardSyncPointIfNeeded(task) - nextSyncPoint := task.nextSyncPoint.Load() - if nextSyncPoint > 0 && commitTsEnd > nextSyncPoint { - task.changefeedStat.tryEnterSyncPointPrepare(nextSyncPoint) - commitTsEnd = nextSyncPoint - } - preparingTs := task.changefeedStat.getSyncPointPreparingTs() - if preparingTs > 0 && !task.changefeedStat.isSyncPointInCommitStage(preparingTs) { - commitTsEnd = min(commitTsEnd, preparingTs) - } - return commitTsEnd -} - // scanReady checks if the dispatcher needs to scan the event store/schema store. // If the dispatcher needs to scan the event store/schema store, it returns true. // If the dispatcher does not need to scan the event store, it send the watermark to the dispatcher. @@ -854,43 +580,16 @@ func (c *eventBroker) sendHandshakeIfNeed(task scanTask) { // hasSyncPointEventBeforeTs checks if there is any sync point events before the given ts. func (c *eventBroker) hasSyncPointEventsBeforeTs(ts uint64, d *dispatcherStat) bool { - c.fastForwardSyncPointIfNeeded(d) - if !d.enableSyncPoint { - return false - } - nextSyncPoint := d.nextSyncPoint.Load() - if ts <= nextSyncPoint { - return false - } - d.changefeedStat.tryEnterSyncPointPrepare(nextSyncPoint) - return d.changefeedStat.isSyncPointInCommitStage(nextSyncPoint) + return d.enableSyncPoint && ts > d.nextSyncPoint.Load() } // emitSyncPointEventIfNeeded emits a sync point event if the current ts is greater than the next sync point, and updates the next sync point. // We need call this function every time we send a event(whether dml/ddl/resolvedTs), // thus to ensure the sync point event is in correct order for each dispatcher. func (c *eventBroker) emitSyncPointEventIfNeeded(ts uint64, d *dispatcherStat, remoteID node.ID) { - c.fastForwardSyncPointIfNeeded(d) - for d.enableSyncPoint { + for d.enableSyncPoint && ts > d.nextSyncPoint.Load() { commitTs := d.nextSyncPoint.Load() - if !d.changefeedStat.isSyncPointInCommitStage(commitTs) { - if ts <= commitTs { - return - } - d.changefeedStat.tryEnterSyncPointPrepare(commitTs) - if !d.changefeedStat.isSyncPointInCommitStage(commitTs) { - return - } - } else if ts < commitTs { - return - } - - nextSyncPoint := oracle.GoTimeToTS(oracle.GetTimeFromTS(commitTs).Add(d.syncPointInterval)) - // Advance nextSyncPoint with CAS so concurrent send paths cannot emit the same - // syncpoint twice or move nextSyncPoint backward. - if !d.nextSyncPoint.CompareAndSwap(commitTs, nextSyncPoint) { - continue - } + d.nextSyncPoint.Store(oracle.GoTimeToTS(oracle.GetTimeFromTS(commitTs).Add(d.syncPointInterval))) e := event.NewSyncPointEvent(d.id, commitTs, d.seq.Add(1), d.epoch) log.Debug("send syncpoint event to dispatcher", @@ -903,48 +602,6 @@ func (c *eventBroker) emitSyncPointEventIfNeeded(ts uint64, d *dispatcherStat, r } } -func (c *eventBroker) fastForwardSyncPointIfNeeded(d *dispatcherStat) { - c.fastForwardSyncPointToInFlightIfNeeded(d) -} - -type uint64Value interface { - Load() uint64 - CompareAndSwap(old, new uint64) bool -} - -// setUint64Floor makes v >= floor by CAS retry, and never decreases v. -func setUint64Floor(v uint64Value, floor uint64) (uint64, bool) { - for { - current := v.Load() - if current == 0 || current >= floor { - return current, false - } - if v.CompareAndSwap(current, floor) { - return current, true - } - } -} - -func (c *eventBroker) fastForwardSyncPointToInFlightIfNeeded(d *dispatcherStat) { - if d == nil || !d.enableSyncPoint { - return - } - inFlightTs := d.changefeedStat.syncPointInFlightTs.Load() - if inFlightTs == 0 { - return - } - oldSyncPointTs, updated := setUint64Floor(&d.nextSyncPoint, inFlightTs) - if !updated { - return - } - log.Debug("fast forward stale syncpoint to in flight syncpoint", - zap.Stringer("changefeedID", d.changefeedStat.changefeedID), - zap.Stringer("dispatcherID", d.id), - zap.Int64("tableID", d.info.GetTableSpan().GetTableID()), - zap.Uint64("oldSyncPointTs", oldSyncPointTs), - zap.Uint64("inFlightSyncPointTs", inFlightTs)) -} - func (c *eventBroker) calculateScanLimit(task scanTask) scanLimit { return scanLimit{ maxDMLBytes: task.getCurrentScanLimitInBytes(), @@ -1473,7 +1130,6 @@ func (c *eventBroker) removeDispatcher(dispatcherInfo DispatcherInfo) { Name: changefeedID.Keyspace(), } c.schemaStore.UnregisterTable(keyspaceMeta, span.TableID) - c.advanceSyncPointState(stat.changefeedStat) log.Info("remove dispatcher", zap.Uint64("clusterID", c.tidbClusterID), zap.Stringer("changefeedID", changefeedID), @@ -1628,9 +1284,6 @@ func (c *eventBroker) handleDispatcherHeartbeat(heartbeat *DispatcherHeartBeatWi } } c.sendDispatcherResponse(responseMap) - for changefeed := range changedChangefeeds { - c.advanceSyncPointState(changefeed) - } } func (c *eventBroker) handleCongestionControl(from node.ID, m *event.CongestionControl) { diff --git a/pkg/eventservice/event_broker_test.go b/pkg/eventservice/event_broker_test.go index 637bee5ec2..39069c1209 100644 --- a/pkg/eventservice/event_broker_test.go +++ b/pkg/eventservice/event_broker_test.go @@ -25,7 +25,6 @@ import ( "github.com/pingcap/ticdc/pkg/common" appcontext "github.com/pingcap/ticdc/pkg/common/context" "github.com/pingcap/ticdc/pkg/common/event" - "github.com/pingcap/ticdc/pkg/filter" "github.com/pingcap/ticdc/pkg/integrity" "github.com/pingcap/ticdc/pkg/messaging" "github.com/pingcap/ticdc/pkg/node" @@ -62,49 +61,6 @@ type notifyMsg struct { latestCommitTs uint64 } -type floorRetryMockUint64 struct { - value atomic.Uint64 - failFirstCASWithValue uint64 - failFirstCASDone atomic.Bool -} - -func (m *floorRetryMockUint64) Load() uint64 { - return m.value.Load() -} - -func (m *floorRetryMockUint64) CompareAndSwap(old, new uint64) bool { - if m.failFirstCASWithValue > 0 && m.failFirstCASDone.CompareAndSwap(false, true) { - // Simulate concurrent advance between load and CAS. - m.value.Store(m.failFirstCASWithValue) - return false - } - return m.value.CompareAndSwap(old, new) -} - -func TestSetUint64Floor(t *testing.T) { - t.Parallel() - - t.Run("update stale value", func(t *testing.T) { - var v atomic.Uint64 - v.Store(10) - old, updated := setUint64Floor(&v, 20) - require.True(t, updated) - require.Equal(t, uint64(10), old) - require.Equal(t, uint64(20), v.Load()) - }) - - t.Run("retry without fallback after concurrent advance", func(t *testing.T) { - mock := &floorRetryMockUint64{ - failFirstCASWithValue: 30, - } - mock.value.Store(10) - old, updated := setUint64Floor(mock, 20) - require.False(t, updated) - require.Equal(t, uint64(30), old) - require.Equal(t, uint64(30), mock.Load()) - }) -} - func TestCheckNeedScan(t *testing.T) { broker, _, _, _ := newEventBrokerForTest() // Close the broker, so we can catch all message in the test. @@ -261,200 +217,6 @@ func TestScanRangeCappedByScanWindow(t *testing.T) { require.Equal(t, oracle.GoTimeToTS(baseTime.Add(defaultScanInterval)), dataRange.CommitTsEnd) } -func TestScanRangeCappedByNextSyncPoint(t *testing.T) { - broker, _, _, _ := newEventBrokerForTest() - // Close the broker, so we can catch all message in the test. - broker.close() - - info := newMockDispatcherInfoForTest(t) - info.epoch = 1 - info.enableSyncPoint = true - info.syncPointInterval = 10 * time.Second - info.startTs = oracle.GoTimeToTS(time.Unix(0, 0).Add(5 * time.Second)) - info.nextSyncPoint = oracle.GoTimeToTS(time.Unix(0, 0).Add(10 * time.Second)) - - changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) - disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) - disp.seq.Store(1) - - dispPtr := &atomic.Pointer[dispatcherStat]{} - dispPtr.Store(disp) - changefeedStatus.addDispatcher(disp.id, dispPtr) - - // Make scan window wide enough so capping is determined by syncpoint boundary. - changefeedStatus.minSentTs.Store(info.startTs) - changefeedStatus.scanInterval.Store(int64(time.Hour)) - - // Current syncpoint is already in commit stage. - changefeedStatus.syncPointPreparingTs.Store(info.nextSyncPoint) - changefeedStatus.syncPointInFlightTs.Store(info.nextSyncPoint) - - disp.sentResolvedTs.Store(info.startTs) - disp.receivedResolvedTs.Store(oracle.GoTimeToTS(time.Unix(0, 0).Add(40 * time.Second))) - disp.eventStoreCommitTs.Store(oracle.GoTimeToTS(time.Unix(0, 0).Add(40 * time.Second))) - - needScan, dataRange := broker.getScanTaskDataRange(disp) - require.True(t, needScan) - require.Equal(t, info.nextSyncPoint, dataRange.CommitTsEnd) -} - -func TestGetScanTaskDataRangeCommitStageFastForwardsStaleSyncPoint(t *testing.T) { - broker, _, _, _ := newEventBrokerForTest() - // Close the broker, so we can catch all message in the test. - broker.close() - - info := newMockDispatcherInfoForTest(t) - info.epoch = 1 - info.enableSyncPoint = true - info.syncPointInterval = 10 * time.Second - - ts5 := oracle.GoTimeToTS(time.Unix(0, 0).Add(5 * time.Second)) - ts10 := oracle.GoTimeToTS(time.Unix(0, 0).Add(10 * time.Second)) - ts20 := oracle.GoTimeToTS(time.Unix(0, 0).Add(20 * time.Second)) - ts40 := oracle.GoTimeToTS(time.Unix(0, 0).Add(40 * time.Second)) - - info.startTs = ts5 - info.nextSyncPoint = ts10 - - changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) - disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) - disp.setHandshaked() - - dispPtr := &atomic.Pointer[dispatcherStat]{} - dispPtr.Store(disp) - changefeedStatus.addDispatcher(disp.id, dispPtr) - - changefeedStatus.minSentTs.Store(ts5) - changefeedStatus.scanInterval.Store(int64(time.Hour)) - changefeedStatus.syncPointPreparingTs.Store(ts20) - changefeedStatus.syncPointInFlightTs.Store(ts20) - - disp.sentResolvedTs.Store(ts5) - disp.receivedResolvedTs.Store(ts40) - disp.eventStoreCommitTs.Store(ts40) - - needScan, dataRange := broker.getScanTaskDataRange(disp) - require.True(t, needScan) - require.Equal(t, ts20, dataRange.CommitTsEnd) - require.Equal(t, ts20, disp.nextSyncPoint.Load()) -} - -func TestGetScanTaskDataRangeNudgesSyncPointInCommitStageWithoutNewData(t *testing.T) { - broker, _, _, _ := newEventBrokerForTest() - // Close the broker, so we can catch all message in the test. - broker.close() - - info := newMockDispatcherInfoForTest(t) - info.epoch = 1 - info.enableSyncPoint = true - info.syncPointInterval = 10 * time.Second - info.startTs = oracle.GoTimeToTS(time.Unix(0, 0).Add(5 * time.Second)) - info.nextSyncPoint = oracle.GoTimeToTS(time.Unix(0, 0).Add(10 * time.Second)) - - changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) - disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) - disp.setHandshaked() - - dispPtr := &atomic.Pointer[dispatcherStat]{} - dispPtr.Store(disp) - changefeedStatus.addDispatcher(disp.id, dispPtr) - - syncTs := info.nextSyncPoint - disp.updateSentResolvedTs(syncTs) - disp.receivedResolvedTs.Store(syncTs) - disp.eventStoreCommitTs.Store(syncTs) - - changefeedStatus.syncPointPreparingTs.Store(syncTs) - changefeedStatus.syncPointInFlightTs.Store(syncTs) - - needScan, _ := broker.getScanTaskDataRange(disp) - require.False(t, needScan) - - first := <-broker.messageCh[disp.messageWorkerIndex] - require.Equal(t, event.TypeSyncPointEvent, first.msgType) - second := <-broker.messageCh[disp.messageWorkerIndex] - require.Equal(t, event.TypeResolvedEvent, second.msgType) - require.Equal(t, oracle.GoTimeToTS(time.Unix(0, 0).Add(20*time.Second)), disp.nextSyncPoint.Load()) -} - -func TestNudgeSyncPointCommitIfNeededFastForwardsStaleSyncPoint(t *testing.T) { - broker, _, _, _ := newEventBrokerForTest() - // Close the broker, so we can catch all message in the test. - broker.close() - - info := newMockDispatcherInfoForTest(t) - info.epoch = 1 - info.enableSyncPoint = true - info.syncPointInterval = 10 * time.Second - - ts5 := oracle.GoTimeToTS(time.Unix(0, 0).Add(5 * time.Second)) - ts10 := oracle.GoTimeToTS(time.Unix(0, 0).Add(10 * time.Second)) - ts20 := oracle.GoTimeToTS(time.Unix(0, 0).Add(20 * time.Second)) - ts30 := oracle.GoTimeToTS(time.Unix(0, 0).Add(30 * time.Second)) - - info.startTs = ts5 - info.nextSyncPoint = ts10 - - changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) - disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) - disp.setHandshaked() - - changefeedStatus.syncPointPreparingTs.Store(ts20) - changefeedStatus.syncPointInFlightTs.Store(ts20) - - disp.sentResolvedTs.Store(ts20) - disp.receivedResolvedTs.Store(ts20) - disp.eventStoreCommitTs.Store(ts20) - - needNudge := broker.nudgeSyncPointCommitIfNeeded(disp) - require.True(t, needNudge) - - first := <-broker.messageCh[disp.messageWorkerIndex] - require.Equal(t, event.TypeSyncPointEvent, first.msgType) - syncPointEvent, ok := first.e.(*event.SyncPointEvent) - require.True(t, ok) - require.Equal(t, ts20, syncPointEvent.GetCommitTs()) - - second := <-broker.messageCh[disp.messageWorkerIndex] - require.Equal(t, event.TypeResolvedEvent, second.msgType) - require.Equal(t, ts30, disp.nextSyncPoint.Load()) -} - -func TestNudgeSyncPointCommitDispatchersPushesTask(t *testing.T) { - broker, _, _, _ := newEventBrokerForTest() - // Close the broker, so we can inspect task queue. - broker.close() - - info := newMockDispatcherInfoForTest(t) - info.epoch = 1 - info.enableSyncPoint = true - info.syncPointInterval = 10 * time.Second - info.startTs = oracle.GoTimeToTS(time.Unix(0, 0).Add(5 * time.Second)) - info.nextSyncPoint = oracle.GoTimeToTS(time.Unix(0, 0).Add(10 * time.Second)) - - changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) - disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) - disp.setHandshaked() - disp.sentResolvedTs.Store(info.nextSyncPoint) - - dispPtr := &atomic.Pointer[dispatcherStat]{} - dispPtr.Store(disp) - changefeedStatus.addDispatcher(disp.id, dispPtr) - broker.dispatchers.Store(disp.id, dispPtr) - - changefeedStatus.syncPointPreparingTs.Store(info.nextSyncPoint) - changefeedStatus.syncPointInFlightTs.Store(info.nextSyncPoint) - - broker.nudgeSyncPointCommitDispatchers(changefeedStatus) - - select { - case task := <-broker.taskChan[disp.scanWorkerIndex]: - require.Equal(t, disp.id, task.id) - case <-time.After(100 * time.Millisecond): - require.Fail(t, "expected syncpoint commit nudge task") - } -} - func TestGetScanTaskDataRangeEmptyAfterCappingDoesNotResetScanRange(t *testing.T) { broker, _, _, _ := newEventBrokerForTest() // Close the broker, so we can catch all message in the test. @@ -523,55 +285,6 @@ func TestGetScanTaskDataRangeEmptyAfterCappingWithPendingDDLEventUsesLocalWindow require.Equal(t, oracle.GoTimeToTS(oracle.GetTimeFromTS(commitStart).Add(defaultScanInterval)), dataRange.CommitTsEnd) } -func TestGetScanTaskDataRangePendingDDLLocalAdvanceRespectsSyncPointBoundary(t *testing.T) { - broker, _, ss, _ := newEventBrokerForTest() - // Close the broker, so we can catch all message in the test. - broker.close() - - info := newMockDispatcherInfoForTest(t) - info.epoch = 1 - info.enableSyncPoint = true - info.syncPointInterval = 10 * time.Second - - baseTime := time.Now() - baseTs := oracle.GoTimeToTS(baseTime) - commitStart := oracle.GoTimeToTS(baseTime.Add(20 * time.Second)) - nextSyncPoint := oracle.GoTimeToTS(baseTime.Add(22 * time.Second)) - ddlCommitTs := oracle.GoTimeToTS(baseTime.Add(23 * time.Second)) - resolvedTs := oracle.GoTimeToTS(baseTime.Add(40 * time.Second)) - - info.startTs = baseTs - info.nextSyncPoint = nextSyncPoint - - changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) - disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) - disp.seq.Store(1) - - dispPtr := &atomic.Pointer[dispatcherStat]{} - dispPtr.Store(disp) - changefeedStatus.addDispatcher(disp.id, dispPtr) - - disp.sentResolvedTs.Store(baseTs) - disp.receivedResolvedTs.Store(resolvedTs) - disp.eventStoreCommitTs.Store(commitStart) - disp.lastScannedCommitTs.Store(commitStart) - disp.lastScannedStartTs.Store(commitStart - 1) - - // Keep global scan window capped at commitStart so pending-DDL local advance path is triggered. - changefeedStatus.minSentTs.Store(oracle.GoTimeToTS(baseTime.Add(15 * time.Second))) - changefeedStatus.scanInterval.Store(int64(defaultScanInterval)) - - ss.resolvedTs = resolvedTs - ss.maxDDLCommitTs = ddlCommitTs - - needScan, dataRange := broker.getScanTaskDataRange(disp) - require.True(t, needScan) - require.Equal(t, commitStart, dataRange.CommitTsStart) - require.Equal(t, nextSyncPoint, dataRange.CommitTsEnd) - require.Equal(t, nextSyncPoint, changefeedStatus.getSyncPointPreparingTs()) - require.False(t, changefeedStatus.isSyncPointInCommitStage(nextSyncPoint)) -} - func TestGetScanTaskDataRangeRingWaitWithThreeDispatchersCanAdvancePendingDDL(t *testing.T) { broker, _, ss, _ := newEventBrokerForTest() // Close the broker, so we can catch all message in the test. @@ -712,173 +425,6 @@ func TestDoScanSkipWhenChangefeedStatusNotFound(t *testing.T) { require.False(t, disp.isTaskScanning.Load()) } -func TestSyncPointTwoStagePrepareThenCommit(t *testing.T) { - broker, _, _, _ := newEventBrokerForTest() - broker.close() - - info1 := newMockDispatcherInfoForTest(t) - info1.enableSyncPoint = true - info1.syncPointInterval = 10 * time.Second - info1.nextSyncPoint = oracle.GoTimeToTS(time.Unix(0, 0).Add(10 * time.Second)) - - info2 := newMockDispatcherInfoForTest(t) - info2.enableSyncPoint = true - info2.syncPointInterval = 10 * time.Second - info2.nextSyncPoint = oracle.GoTimeToTS(time.Unix(0, 0).Add(10 * time.Second)) - info2.changefeedID = info1.changefeedID - - changefeedStatus := broker.getOrSetChangefeedStatus(info1.GetChangefeedID(), info1.GetSyncPointInterval()) - disp1 := newDispatcherStat(info1, 1, 1, nil, changefeedStatus) - disp2 := newDispatcherStat(info2, 1, 1, nil, changefeedStatus) - disp1.setHandshaked() - disp2.setHandshaked() - - disp1Ptr := &atomic.Pointer[dispatcherStat]{} - disp1Ptr.Store(disp1) - disp2Ptr := &atomic.Pointer[dispatcherStat]{} - disp2Ptr.Store(disp2) - changefeedStatus.addDispatcher(info1.GetID(), disp1Ptr) - changefeedStatus.addDispatcher(info2.GetID(), disp2Ptr) - - // Crossing the syncpoint starts prepare stage, but no dispatcher can emit syncpoint yet. - require.False(t, broker.hasSyncPointEventsBeforeTs(oracle.GoTimeToTS(time.Unix(0, 0).Add(11*time.Second)), disp1)) - require.Equal(t, oracle.GoTimeToTS(time.Unix(0, 0).Add(10*time.Second)), changefeedStatus.getSyncPointPreparingTs()) - require.Equal(t, uint64(0), changefeedStatus.syncPointInFlightTs.Load()) - broker.emitSyncPointEventIfNeeded(oracle.GoTimeToTS(time.Unix(0, 0).Add(11*time.Second)), disp1, node.ID("server1")) - require.Len(t, broker.messageCh[disp1.messageWorkerIndex], 0) - - // Commit stage is reached only after all active dispatchers sent resolved-ts >= preparing ts. - disp1.sentResolvedTs.Store(oracle.GoTimeToTS(time.Unix(0, 0).Add(10 * time.Second))) - disp2.sentResolvedTs.Store(oracle.GoTimeToTS(time.Unix(0, 0).Add(9 * time.Second))) - changefeedStatus.tryPromoteSyncPointToCommitIfReady() - require.Equal(t, uint64(0), changefeedStatus.syncPointInFlightTs.Load()) - - disp2.sentResolvedTs.Store(oracle.GoTimeToTS(time.Unix(0, 0).Add(10 * time.Second))) - changefeedStatus.tryPromoteSyncPointToCommitIfReady() - require.True(t, changefeedStatus.isSyncPointInCommitStage(oracle.GoTimeToTS(time.Unix(0, 0).Add(10*time.Second)))) - require.Equal(t, oracle.GoTimeToTS(time.Unix(0, 0).Add(10*time.Second)), changefeedStatus.syncPointInFlightTs.Load()) - require.True(t, broker.hasSyncPointEventsBeforeTs(oracle.GoTimeToTS(time.Unix(0, 0).Add(11*time.Second)), disp1)) - - // In commit stage, dispatcher can emit syncpoint even when ts == commitTs. - broker.emitSyncPointEventIfNeeded(oracle.GoTimeToTS(time.Unix(0, 0).Add(10*time.Second)), disp1, node.ID("server1")) - msg := <-broker.messageCh[disp1.messageWorkerIndex] - require.Equal(t, event.TypeSyncPointEvent, msg.msgType) - syncPointEvent, ok := msg.e.(*event.SyncPointEvent) - require.True(t, ok) - require.Equal(t, oracle.GoTimeToTS(time.Unix(0, 0).Add(10*time.Second)), syncPointEvent.GetCommitTs()) - - broker.emitSyncPointEventIfNeeded(oracle.GoTimeToTS(time.Unix(0, 0).Add(10*time.Second)), disp2, node.ID("server1")) - msg = <-broker.messageCh[disp2.messageWorkerIndex] - require.Equal(t, event.TypeSyncPointEvent, msg.msgType) - - // Syncpoint lifecycle is not finished until checkpoint also moves beyond in-flight ts. - disp1.checkpointTs.Store(oracle.GoTimeToTS(time.Unix(0, 0).Add(9 * time.Second))) - disp2.checkpointTs.Store(oracle.GoTimeToTS(time.Unix(0, 0).Add(9 * time.Second))) - changefeedStatus.tryFinishSyncPointCommitIfAllEmitted() - require.Equal(t, oracle.GoTimeToTS(time.Unix(0, 0).Add(10*time.Second)), changefeedStatus.syncPointInFlightTs.Load()) - require.Equal(t, oracle.GoTimeToTS(time.Unix(0, 0).Add(10*time.Second)), changefeedStatus.getSyncPointPreparingTs()) - - disp1.checkpointTs.Store(oracle.GoTimeToTS(time.Unix(0, 0).Add(11 * time.Second))) - disp2.checkpointTs.Store(oracle.GoTimeToTS(time.Unix(0, 0).Add(11 * time.Second))) - changefeedStatus.tryFinishSyncPointCommitIfAllEmitted() - require.Equal(t, uint64(0), changefeedStatus.syncPointInFlightTs.Load()) - require.Equal(t, uint64(0), changefeedStatus.getSyncPointPreparingTs()) - require.False(t, changefeedStatus.isSyncPointInCommitStage(oracle.GoTimeToTS(time.Unix(0, 0).Add(10*time.Second)))) -} - -func TestSendDDLSameCommitTsAsSyncPointKeepsDDLPriority(t *testing.T) { - broker, _, _, _ := newEventBrokerForTest() - // Stop background workers so we can deterministically inspect broker.messageCh. - broker.close() - - info := newMockDispatcherInfoForTest(t) - info.epoch = 1 - info.enableSyncPoint = true - info.syncPointInterval = 10 * time.Second - - ts5 := oracle.GoTimeToTS(time.Unix(0, 0).Add(5 * time.Second)) - ts10 := oracle.GoTimeToTS(time.Unix(0, 0).Add(10 * time.Second)) - ts20 := oracle.GoTimeToTS(time.Unix(0, 0).Add(20 * time.Second)) - - info.startTs = ts5 - info.nextSyncPoint = ts10 - - changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) - disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) - disp.setHandshaked() - changefeedStatus.syncPointPreparingTs.Store(ts10) - changefeedStatus.syncPointInFlightTs.Store(ts10) - - ddl := &event.DDLEvent{ - FinishedTs: ts10, - Query: "alter table t add column c int", - } - broker.sendDDL(context.Background(), node.ID(info.GetServerID()), ddl, disp) - - first := <-broker.messageCh[disp.messageWorkerIndex] - second := <-broker.messageCh[disp.messageWorkerIndex] - - require.Equal(t, event.TypeDDLEvent, first.msgType) - firstDDL, ok := first.e.(*event.DDLEvent) - require.True(t, ok) - require.Equal(t, ts10, firstDDL.FinishedTs) - - require.Equal(t, event.TypeSyncPointEvent, second.msgType) - secondSyncPoint, ok := second.e.(*event.SyncPointEvent) - require.True(t, ok) - require.Equal(t, ts10, secondSyncPoint.GetCommitTs()) - - require.Less(t, firstDDL.Seq, secondSyncPoint.Seq) - require.Equal(t, ts20, disp.nextSyncPoint.Load()) -} - -func TestSendDDLWithLargerCommitTsStillEmitsSyncPointFirst(t *testing.T) { - broker, _, _, _ := newEventBrokerForTest() - // Stop background workers so we can deterministically inspect broker.messageCh. - broker.close() - - info := newMockDispatcherInfoForTest(t) - info.epoch = 1 - info.enableSyncPoint = true - info.syncPointInterval = 10 * time.Second - - ts5 := oracle.GoTimeToTS(time.Unix(0, 0).Add(5 * time.Second)) - ts10 := oracle.GoTimeToTS(time.Unix(0, 0).Add(10 * time.Second)) - ts15 := oracle.GoTimeToTS(time.Unix(0, 0).Add(15 * time.Second)) - ts20 := oracle.GoTimeToTS(time.Unix(0, 0).Add(20 * time.Second)) - - info.startTs = ts5 - info.nextSyncPoint = ts10 - - changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) - disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) - disp.setHandshaked() - changefeedStatus.syncPointPreparingTs.Store(ts10) - changefeedStatus.syncPointInFlightTs.Store(ts10) - - ddl := &event.DDLEvent{ - FinishedTs: ts15, - Query: "alter table t add column c int", - } - broker.sendDDL(context.Background(), node.ID(info.GetServerID()), ddl, disp) - - first := <-broker.messageCh[disp.messageWorkerIndex] - second := <-broker.messageCh[disp.messageWorkerIndex] - - require.Equal(t, event.TypeSyncPointEvent, first.msgType) - firstSyncPoint, ok := first.e.(*event.SyncPointEvent) - require.True(t, ok) - require.Equal(t, ts10, firstSyncPoint.GetCommitTs()) - - require.Equal(t, event.TypeDDLEvent, second.msgType) - secondDDL, ok := second.e.(*event.DDLEvent) - require.True(t, ok) - require.Equal(t, ts15, secondDDL.FinishedTs) - - require.Less(t, firstSyncPoint.Seq, secondDDL.Seq) - require.Equal(t, ts20, disp.nextSyncPoint.Load()) -} - func TestCURDDispatcher(t *testing.T) { broker, _, _, _ := newEventBrokerForTest() defer broker.close() @@ -1358,6 +904,7 @@ func TestAddDispatcherFailure(t *testing.T) { _, ok := broker.changefeedMap.Load(dispInfo.GetChangefeedID()) require.False(t, ok, "changefeedStatus should be removed after failed registration") } +<<<<<<< HEAD type tableTriggerSchemaStore struct { *mockSchemaStore @@ -1662,3 +1209,5 @@ func TestResetDispatcherCopiesRuntimeStatistics(t *testing.T) { require.Equal(t, int64(8192), newStat.maxScanLimitInBytes.Load()) require.Equal(t, int64(2048), newStat.lastScanBytes.Load()) } +======= +>>>>>>> parent of fa1e59cb0 (eventBroker: implement two stage syncpoint (#4429)) diff --git a/tests/integration_tests/bdr_mode/run.sh b/tests/integration_tests/bdr_mode/run.sh index 91c4366262..d161ba5dbe 100755 --- a/tests/integration_tests/bdr_mode/run.sh +++ b/tests/integration_tests/bdr_mode/run.sh @@ -37,6 +37,7 @@ function run() { run_sql_file $CUR/data/finished.sql ${UP_TIDB_HOST} ${UP_TIDB_PORT} + # syncpoint table should exists in secondary tidb, but does not exists in primary cluster check_table_exists "tidb_cdc.syncpoint_v1" ${DOWN_TIDB_HOST} ${DOWN_TIDB_PORT} 60 check_table_exists "tidb_cdc.syncpoint_v1" ${UP_TIDB_HOST} ${UP_TIDB_PORT} 60 From 1600a5c6a10d3e494123c7aff25ec75c7137889d Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Mon, 13 Apr 2026 13:33:22 +0800 Subject: [PATCH 02/17] eventBroker: sent signal resolvedTs for table trigger dispatcher Signed-off-by: dongmen <414110582@qq.com> --- pkg/eventservice/event_broker.go | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/pkg/eventservice/event_broker.go b/pkg/eventservice/event_broker.go index 49e14d395f..691fc674a1 100644 --- a/pkg/eventservice/event_broker.go +++ b/pkg/eventservice/event_broker.go @@ -362,6 +362,10 @@ func (c *eventBroker) tickTableTriggerDispatchers(ctx context.Context) error { if endTs > startTs { // After all the events are sent, we send the watermark to the dispatcher. c.sendResolvedTs(stat, endTs) + } else { + // If there is no new ddl event, we still need to send a signal resolved-ts event to keep downstream responsive, + // but do not advance the watermark here. + c.sendSignalResolvedTs(stat) } return true }) From e38bc9def98db7b62edc265e9c383d961e081bee Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Mon, 13 Apr 2026 14:37:40 +0800 Subject: [PATCH 03/17] eventservice: simplify syncpoint handling with checkpoint bounds - cap scan upper bound by checkpointTs + 2*syncPointInterval when syncpoint is enabled - suppress syncpoint emission when dispatcher lag exceeds threshold, while still advancing nextSyncPoint - resume syncpoint emission with hysteresis to avoid flapping - apply checkpoint cap to normal scan path, pending-DDL local advance, and table-trigger DDL path - add metrics for syncpoint lag, suppression count, and checkpoint-cap hits - add unit tests for checkpoint cap and suppress/resume behavior Signed-off-by: dongmen <414110582@qq.com> --- pkg/config/debug.go | 21 +- pkg/eventservice/dispatcher_stat.go | 4 +- pkg/eventservice/event_broker.go | 167 +++++++-- pkg/eventservice/event_broker_test.go | 484 ++++++++++---------------- pkg/metrics/event_service.go | 24 ++ 5 files changed, 361 insertions(+), 339 deletions(-) diff --git a/pkg/config/debug.go b/pkg/config/debug.go index 148e927430..5f724d1a62 100644 --- a/pkg/config/debug.go +++ b/pkg/config/debug.go @@ -118,6 +118,14 @@ type EventServiceConfig struct { ScanTaskQueueSize int `toml:"scan-task-queue-size" json:"scan_task_queue_size"` ScanLimitInBytes int `toml:"scan-limit-in-bytes" json:"scan_limit_in_bytes"` + // SyncPointCheckpointCapMultiplier controls how far scan can lead checkpoint when syncpoint is enabled. + // The scan upper bound is capped by checkpointTs + multiplier*syncPointInterval. + SyncPointCheckpointCapMultiplier int `toml:"sync-point-checkpoint-cap-multiplier" json:"sync_point_checkpoint_cap_multiplier"` + // SyncPointLagSuppressThreshold controls when to suppress syncpoint emission for lagging dispatchers. + SyncPointLagSuppressThreshold time.Duration `toml:"sync-point-lag-suppress-threshold" json:"sync_point_lag_suppress_threshold"` + // SyncPointLagResumeThreshold controls when to resume syncpoint emission after suppression. + SyncPointLagResumeThreshold time.Duration `toml:"sync-point-lag-resume-threshold" json:"sync_point_lag_resume_threshold"` + // DMLEventMaxRows is the maximum number of rows in a DML event when split txn is enabled. DMLEventMaxRows int32 `toml:"dml-event-max-rows" json:"dml_event_max_rows"` // DMLEventMaxBytes is the maximum size of a DML event in bytes when split txn is enabled. @@ -133,10 +141,13 @@ type EventServiceConfig struct { // NewDefaultEventServiceConfig return the default event service configuration func NewDefaultEventServiceConfig() *EventServiceConfig { return &EventServiceConfig{ - ScanTaskQueueSize: 1024 * 8, - ScanLimitInBytes: 1024 * 1024 * 256, // 256MB - DMLEventMaxRows: 256, - DMLEventMaxBytes: 1024 * 1024 * 1, // 1MB - EnableRemoteEventService: true, + ScanTaskQueueSize: 1024 * 8, + ScanLimitInBytes: 1024 * 1024 * 256, // 256MB + SyncPointCheckpointCapMultiplier: 2, + SyncPointLagSuppressThreshold: 20 * time.Minute, + SyncPointLagResumeThreshold: 15 * time.Minute, + DMLEventMaxRows: 256, + DMLEventMaxBytes: 1024 * 1024 * 1, // 1MB + EnableRemoteEventService: true, } } diff --git a/pkg/eventservice/dispatcher_stat.go b/pkg/eventservice/dispatcher_stat.go index a99767a704..9cfe374618 100644 --- a/pkg/eventservice/dispatcher_stat.go +++ b/pkg/eventservice/dispatcher_stat.go @@ -70,7 +70,9 @@ type dispatcherStat struct { enableSyncPoint bool nextSyncPoint atomic.Uint64 syncPointInterval time.Duration - txnAtomicity config.AtomicityLevel + // syncPointSendSuppressed tracks whether syncpoint emission is temporarily suppressed due to lag. + syncPointSendSuppressed atomic.Bool + txnAtomicity config.AtomicityLevel // ============================================================================= // ================== below are fields need copied when reset ================== diff --git a/pkg/eventservice/event_broker.go b/pkg/eventservice/event_broker.go index 691fc674a1..d8c6eb7b0b 100644 --- a/pkg/eventservice/event_broker.go +++ b/pkg/eventservice/event_broker.go @@ -52,6 +52,9 @@ const ( // defaultSendResolvedTsInterval use to control whether to send a resolvedTs event to the dispatcher when its scan is skipped. defaultSendResolvedTsInterval = time.Second * 2 defaultRefreshMinSentResolvedTsInterval = time.Second * 1 + defaultSyncPointCheckpointCapMultiplier = 2 + defaultSyncPointLagSuppressThreshold = 20 * time.Minute + defaultSyncPointLagResumeThreshold = 15 * time.Minute ) // eventBroker get event from the eventStore, and send the event to the dispatchers. @@ -92,8 +95,11 @@ type eventBroker struct { // metricsCollector handles all metrics collection and reporting metricsCollector *metricsCollector - scanRateLimiter *rate.Limiter - scanLimitInBytes uint64 + scanRateLimiter *rate.Limiter + scanLimitInBytes uint64 + syncPointCheckpointCapMultiplier uint64 + syncPointLagSuppressThreshold time.Duration + syncPointLagResumeThreshold time.Duration } func newEventBroker( @@ -113,10 +119,26 @@ func newEventBroker( sendMessageWorkerCount := config.DefaultBasicEventHandlerConcurrency scanWorkerCount := config.DefaultBasicEventHandlerConcurrency * 4 - scanTaskQueueSize := config.GetGlobalServerConfig().Debug.EventService.ScanTaskQueueSize / scanWorkerCount + eventServiceConfig := config.GetGlobalServerConfig().Debug.EventService + scanTaskQueueSize := eventServiceConfig.ScanTaskQueueSize / scanWorkerCount sendMessageQueueSize := basicChannelSize * 4 - scanLimitInBytes := config.GetGlobalServerConfig().Debug.EventService.ScanLimitInBytes + scanLimitInBytes := eventServiceConfig.ScanLimitInBytes + syncPointCheckpointCapMultiplier := eventServiceConfig.SyncPointCheckpointCapMultiplier + if syncPointCheckpointCapMultiplier <= 0 { + syncPointCheckpointCapMultiplier = defaultSyncPointCheckpointCapMultiplier + } + syncPointLagSuppressThreshold := eventServiceConfig.SyncPointLagSuppressThreshold + if syncPointLagSuppressThreshold <= 0 { + syncPointLagSuppressThreshold = defaultSyncPointLagSuppressThreshold + } + syncPointLagResumeThreshold := eventServiceConfig.SyncPointLagResumeThreshold + if syncPointLagResumeThreshold <= 0 { + syncPointLagResumeThreshold = defaultSyncPointLagResumeThreshold + } + if syncPointLagResumeThreshold > syncPointLagSuppressThreshold { + syncPointLagResumeThreshold = syncPointLagSuppressThreshold + } g, ctx := errgroup.WithContext(ctx) ctx, cancel := context.WithCancel(ctx) @@ -125,22 +147,25 @@ func newEventBroker( // For now, since there is only one upstream, using the default pdClock is sufficient. pdClock := appcontext.GetService[pdutil.Clock](appcontext.DefaultPDClock) c := &eventBroker{ - tidbClusterID: id, - eventStore: eventStore, - pdClock: pdClock, - mounter: event.NewMounter(tz, integrity), - schemaStore: schemaStore, - changefeedMap: sync.Map{}, - dispatchers: sync.Map{}, - tableTriggerDispatchers: sync.Map{}, - msgSender: mc, - taskChan: make([]chan scanTask, scanWorkerCount), - messageCh: make([]chan *wrapEvent, sendMessageWorkerCount), - redoMessageCh: make([]chan *wrapEvent, sendMessageWorkerCount), - cancel: cancel, - g: g, - scanRateLimiter: rate.NewLimiter(rate.Limit(scanLimitInBytes), scanLimitInBytes), - scanLimitInBytes: uint64(scanLimitInBytes), + tidbClusterID: id, + eventStore: eventStore, + pdClock: pdClock, + mounter: event.NewMounter(tz, integrity), + schemaStore: schemaStore, + changefeedMap: sync.Map{}, + dispatchers: sync.Map{}, + tableTriggerDispatchers: sync.Map{}, + msgSender: mc, + taskChan: make([]chan scanTask, scanWorkerCount), + messageCh: make([]chan *wrapEvent, sendMessageWorkerCount), + redoMessageCh: make([]chan *wrapEvent, sendMessageWorkerCount), + cancel: cancel, + g: g, + scanRateLimiter: rate.NewLimiter(rate.Limit(scanLimitInBytes), scanLimitInBytes), + scanLimitInBytes: uint64(scanLimitInBytes), + syncPointCheckpointCapMultiplier: uint64(syncPointCheckpointCapMultiplier), + syncPointLagSuppressThreshold: syncPointLagSuppressThreshold, + syncPointLagResumeThreshold: syncPointLagResumeThreshold, } // Initialize metrics collector @@ -185,7 +210,12 @@ func newEventBroker( return c.refreshMinSentResolvedTs(ctx) }) - log.Info("new event broker created", zap.Uint64("id", id), zap.Uint64("scanLimitInBytes", c.scanLimitInBytes)) + log.Info("new event broker created", + zap.Uint64("id", id), + zap.Uint64("scanLimitInBytes", c.scanLimitInBytes), + zap.Uint64("syncPointCheckpointCapMultiplier", c.syncPointCheckpointCapMultiplier), + zap.Duration("syncPointLagSuppressThreshold", c.syncPointLagSuppressThreshold), + zap.Duration("syncPointLagResumeThreshold", c.syncPointLagResumeThreshold)) return c } @@ -355,13 +385,17 @@ func (c *eventBroker) tickTableTriggerDispatchers(ctx context.Context) error { return true } stat.receivedResolvedTs.Store(endTs) + boundedEndTs := c.capCommitTsEndByCheckpoint(stat, endTs) for _, e := range ddlEvents { + if e.FinishedTs > boundedEndTs { + break + } ep := &e c.sendDDL(ctx, remoteID, ep, stat) } - if endTs > startTs { + if boundedEndTs > startTs { // After all the events are sent, we send the watermark to the dispatcher. - c.sendResolvedTs(stat, endTs) + c.sendResolvedTs(stat, boundedEndTs) } else { // If there is no new ddl event, we still need to send a signal resolved-ts event to keep downstream responsive, // but do not advance the watermark here. @@ -406,6 +440,33 @@ func (c *eventBroker) logUninitializedDispatchers(ctx context.Context) error { } } +func (c *eventBroker) capCommitTsEndByCheckpoint(task scanTask, commitTsEnd uint64) uint64 { + if !task.enableSyncPoint || task.syncPointInterval <= 0 || c.syncPointCheckpointCapMultiplier == 0 { + return commitTsEnd + } + checkpointTs := task.checkpointTs.Load() + if checkpointTs == 0 { + return commitTsEnd + } + + capDuration := time.Duration(c.syncPointCheckpointCapMultiplier) * task.syncPointInterval + checkpointCapTs := oracle.GoTimeToTS(oracle.GetTimeFromTS(checkpointTs).Add(capDuration)) + if checkpointCapTs >= commitTsEnd { + return commitTsEnd + } + + log.Debug("scan range commitTsEnd capped by checkpoint bound", + zap.Stringer("changefeedID", task.changefeedStat.changefeedID), + zap.Stringer("dispatcherID", task.id), + zap.Uint64("oldCommitTsEnd", commitTsEnd), + zap.Uint64("newCommitTsEnd", checkpointCapTs), + zap.Uint64("checkpointTs", checkpointTs), + zap.Duration("syncPointInterval", task.syncPointInterval), + zap.Uint64("multiplier", c.syncPointCheckpointCapMultiplier)) + metrics.EventServiceScanCappedByCheckpointCount.WithLabelValues(task.changefeedStat.changefeedID.String()).Inc() + return checkpointCapTs +} + // getScanTaskDataRange determines the valid data range for scanning a given task. // It checks various conditions (dispatcher status, DDL state, max commit ts of dml event) // to decide whether scanning is needed and returns the appropriate time range. @@ -450,6 +511,7 @@ func (c *eventBroker) getScanTaskDataRange(task scanTask) (bool, common.DataRang ) } } + dataRange.CommitTsEnd = c.capCommitTsEndByCheckpoint(task, dataRange.CommitTsEnd) if dataRange.CommitTsEnd <= dataRange.CommitTsStart && hasPendingDDLEventInCurrentRange { // Global scan window base can be pinned by other lagging dispatchers. @@ -461,6 +523,7 @@ func (c *eventBroker) getScanTaskDataRange(task scanTask) (bool, common.DataRang } localScanMaxTs := oracle.GoTimeToTS(oracle.GetTimeFromTS(dataRange.CommitTsStart).Add(interval)) dataRange.CommitTsEnd = min(commitTsEndBeforeWindow, localScanMaxTs) + dataRange.CommitTsEnd = c.capCommitTsEndByCheckpoint(task, dataRange.CommitTsEnd) if dataRange.CommitTsEnd > dataRange.CommitTsStart { log.Info("scan window local advance due to pending ddl", zap.Stringer("changefeedID", task.changefeedStat.changefeedID), @@ -587,6 +650,55 @@ func (c *eventBroker) hasSyncPointEventsBeforeTs(ts uint64, d *dispatcherStat) b return d.enableSyncPoint && ts > d.nextSyncPoint.Load() } +func syncPointLagDuration(sentResolvedTs, checkpointTs uint64) time.Duration { + if sentResolvedTs <= checkpointTs { + return 0 + } + return oracle.GetTimeFromTS(sentResolvedTs).Sub(oracle.GetTimeFromTS(checkpointTs)) +} + +func (c *eventBroker) shouldSuppressSyncPointEmission(d *dispatcherStat) bool { + if d == nil || c.syncPointLagSuppressThreshold <= 0 { + return false + } + + sentResolvedTs := d.sentResolvedTs.Load() + checkpointTs := d.checkpointTs.Load() + lag := syncPointLagDuration(sentResolvedTs, checkpointTs) + metrics.EventServiceSyncPointLagGaugeVec.WithLabelValues(d.changefeedStat.changefeedID.String()).Set(lag.Seconds()) + + if d.syncPointSendSuppressed.Load() { + if lag <= c.syncPointLagResumeThreshold { + if d.syncPointSendSuppressed.CompareAndSwap(true, false) { + log.Info("syncpoint emission resumed", + zap.Stringer("changefeedID", d.changefeedStat.changefeedID), + zap.Stringer("dispatcherID", d.id), + zap.Uint64("sentResolvedTs", sentResolvedTs), + zap.Uint64("checkpointTs", checkpointTs), + zap.Duration("lag", lag), + zap.Duration("resumeThreshold", c.syncPointLagResumeThreshold)) + } + return false + } + return true + } + + if lag > c.syncPointLagSuppressThreshold { + if d.syncPointSendSuppressed.CompareAndSwap(false, true) { + log.Info("syncpoint emission suppressed due to lag", + zap.Stringer("changefeedID", d.changefeedStat.changefeedID), + zap.Stringer("dispatcherID", d.id), + zap.Uint64("sentResolvedTs", sentResolvedTs), + zap.Uint64("checkpointTs", checkpointTs), + zap.Duration("lag", lag), + zap.Duration("suppressThreshold", c.syncPointLagSuppressThreshold), + zap.Duration("resumeThreshold", c.syncPointLagResumeThreshold)) + } + return true + } + return false +} + // emitSyncPointEventIfNeeded emits a sync point event if the current ts is greater than the next sync point, and updates the next sync point. // We need call this function every time we send a event(whether dml/ddl/resolvedTs), // thus to ensure the sync point event is in correct order for each dispatcher. @@ -594,15 +706,18 @@ func (c *eventBroker) emitSyncPointEventIfNeeded(ts uint64, d *dispatcherStat, r for d.enableSyncPoint && ts > d.nextSyncPoint.Load() { commitTs := d.nextSyncPoint.Load() d.nextSyncPoint.Store(oracle.GoTimeToTS(oracle.GetTimeFromTS(commitTs).Add(d.syncPointInterval))) + if c.shouldSuppressSyncPointEmission(d) { + metrics.EventServiceSyncPointSuppressedCount.WithLabelValues(d.changefeedStat.changefeedID.String()).Inc() + continue + } e := event.NewSyncPointEvent(d.id, commitTs, d.seq.Add(1), d.epoch) + syncPointEvent := newWrapSyncPointEvent(remoteID, e) + c.getMessageCh(d.messageWorkerIndex, common.IsRedoMode(d.info.GetMode())) <- syncPointEvent log.Debug("send syncpoint event to dispatcher", zap.Stringer("changefeedID", d.changefeedStat.changefeedID), zap.Stringer("dispatcherID", d.id), zap.Int64("tableID", d.info.GetTableSpan().GetTableID()), zap.Uint64("commitTs", e.GetCommitTs()), zap.Uint64("seq", e.GetSeq())) - - syncPointEvent := newWrapSyncPointEvent(remoteID, e) - c.getMessageCh(d.messageWorkerIndex, common.IsRedoMode(d.info.GetMode())) <- syncPointEvent } } diff --git a/pkg/eventservice/event_broker_test.go b/pkg/eventservice/event_broker_test.go index 39069c1209..95e483f57a 100644 --- a/pkg/eventservice/event_broker_test.go +++ b/pkg/eventservice/event_broker_test.go @@ -349,6 +349,183 @@ func TestGetScanTaskDataRangeRingWaitWithThreeDispatchersCanAdvancePendingDDL(t require.Equal(t, ts103, dataRange.CommitTsEnd) } +func TestGetScanTaskDataRangeCappedByCheckpointWithSyncPoint(t *testing.T) { + broker, _, ss, _ := newEventBrokerForTest() + broker.close() + + base := time.Unix(0, 0) + ts100 := oracle.GoTimeToTS(base.Add(100 * time.Second)) + ts120 := oracle.GoTimeToTS(base.Add(120 * time.Second)) + ts200 := oracle.GoTimeToTS(base.Add(200 * time.Second)) + + info := newMockDispatcherInfoForTest(t) + info.epoch = 1 + info.enableSyncPoint = true + info.syncPointInterval = 10 * time.Second + info.nextSyncPoint = ts120 + + changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) + changefeedStatus.scanInterval.Store(int64(5 * time.Minute)) + changefeedStatus.minSentTs.Store(ts100) + + disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) + disp.seq.Store(1) + disp.checkpointTs.Store(ts100) + disp.sentResolvedTs.Store(ts100) + disp.lastScannedCommitTs.Store(ts100) + disp.lastScannedStartTs.Store(0) + disp.receivedResolvedTs.Store(ts200) + disp.eventStoreCommitTs.Store(ts200) + + ss.resolvedTs = ts200 + ss.maxDDLCommitTs = ts200 + + needScan, dataRange := broker.getScanTaskDataRange(disp) + require.True(t, needScan) + require.Equal(t, ts100, dataRange.CommitTsStart) + require.Equal(t, ts120, dataRange.CommitTsEnd) +} + +func TestGetScanTaskDataRangePendingDDLWithCheckpointCapCanAdvance(t *testing.T) { + broker, _, ss, _ := newEventBrokerForTest() + broker.close() + + base := time.Unix(0, 0) + ts100 := oracle.GoTimeToTS(base.Add(100 * time.Second)) + ts101 := oracle.GoTimeToTS(base.Add(101 * time.Second)) + ts102 := oracle.GoTimeToTS(base.Add(102 * time.Second)) + ts103 := oracle.GoTimeToTS(base.Add(103 * time.Second)) + ts110 := oracle.GoTimeToTS(base.Add(110 * time.Second)) + + info := newMockDispatcherInfoForTest(t) + info.epoch = 1 + info.enableSyncPoint = true + info.syncPointInterval = time.Second + info.nextSyncPoint = ts110 + + changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) + changefeedStatus.scanInterval.Store(int64(time.Second)) + changefeedStatus.minSentTs.Store(ts100) + + disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) + disp.seq.Store(1) + disp.checkpointTs.Store(ts100) + disp.sentResolvedTs.Store(ts101) + disp.lastScannedCommitTs.Store(ts101) + disp.lastScannedStartTs.Store(ts101 - 1) + disp.receivedResolvedTs.Store(ts110) + disp.eventStoreCommitTs.Store(ts103) + + ss.resolvedTs = ts110 + ss.maxDDLCommitTs = ts103 + + needScan, dataRange := broker.getScanTaskDataRange(disp) + require.True(t, needScan) + require.Equal(t, ts101, dataRange.CommitTsStart) + require.Equal(t, ts102, dataRange.CommitTsEnd) +} + +func TestEmitSyncPointEventIfNeededSuppressesWhenLagging(t *testing.T) { + broker, _, _, _ := newEventBrokerForTest() + broker.close() + broker.syncPointLagSuppressThreshold = 20 * time.Second + broker.syncPointLagResumeThreshold = 10 * time.Second + + base := time.Unix(0, 0) + ts100 := oracle.GoTimeToTS(base.Add(100 * time.Second)) + ts110 := oracle.GoTimeToTS(base.Add(110 * time.Second)) + ts130 := oracle.GoTimeToTS(base.Add(130 * time.Second)) + ts180 := oracle.GoTimeToTS(base.Add(180 * time.Second)) + + info := newMockDispatcherInfoForTest(t) + info.epoch = 1 + info.enableSyncPoint = true + info.syncPointInterval = 10 * time.Second + info.nextSyncPoint = ts110 + + changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) + disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) + disp.seq.Store(1) + disp.checkpointTs.Store(ts100) + disp.sentResolvedTs.Store(ts180) + + broker.emitSyncPointEventIfNeeded(ts130, disp, node.ID(info.GetServerID())) + + require.True(t, disp.syncPointSendSuppressed.Load()) + require.Equal(t, ts130, disp.nextSyncPoint.Load()) + require.Equal(t, 0, len(broker.messageCh[disp.messageWorkerIndex])) +} + +func TestEmitSyncPointEventIfNeededResumesAfterLagRecovers(t *testing.T) { + broker, _, _, _ := newEventBrokerForTest() + broker.close() + broker.syncPointLagSuppressThreshold = 20 * time.Second + broker.syncPointLagResumeThreshold = 10 * time.Second + + base := time.Unix(0, 0) + ts110 := oracle.GoTimeToTS(base.Add(110 * time.Second)) + ts115 := oracle.GoTimeToTS(base.Add(115 * time.Second)) + ts120 := oracle.GoTimeToTS(base.Add(120 * time.Second)) + ts125 := oracle.GoTimeToTS(base.Add(125 * time.Second)) + ts130 := oracle.GoTimeToTS(base.Add(130 * time.Second)) + + info := newMockDispatcherInfoForTest(t) + info.epoch = 1 + info.enableSyncPoint = true + info.syncPointInterval = 10 * time.Second + info.nextSyncPoint = ts110 + + changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) + disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) + disp.seq.Store(1) + disp.syncPointSendSuppressed.Store(true) + disp.sentResolvedTs.Store(ts130) + disp.checkpointTs.Store(ts125) + + broker.emitSyncPointEventIfNeeded(ts115, disp, node.ID(info.GetServerID())) + + require.False(t, disp.syncPointSendSuppressed.Load()) + require.Equal(t, ts120, disp.nextSyncPoint.Load()) + require.Equal(t, 1, len(broker.messageCh[disp.messageWorkerIndex])) + + msg := <-broker.messageCh[disp.messageWorkerIndex] + require.Equal(t, event.TypeSyncPointEvent, msg.msgType) + syncPointEvent, ok := msg.e.(*event.SyncPointEvent) + require.True(t, ok) + require.Equal(t, ts110, syncPointEvent.GetCommitTs()) +} + +func TestEmitSyncPointEventIfNeededNoSuppressWhenCheckpointAhead(t *testing.T) { + broker, _, _, _ := newEventBrokerForTest() + broker.close() + broker.syncPointLagSuppressThreshold = time.Second + broker.syncPointLagResumeThreshold = time.Second + + base := time.Unix(0, 0) + ts100 := oracle.GoTimeToTS(base.Add(100 * time.Second)) + ts110 := oracle.GoTimeToTS(base.Add(110 * time.Second)) + ts115 := oracle.GoTimeToTS(base.Add(115 * time.Second)) + ts120 := oracle.GoTimeToTS(base.Add(120 * time.Second)) + + info := newMockDispatcherInfoForTest(t) + info.epoch = 1 + info.enableSyncPoint = true + info.syncPointInterval = 10 * time.Second + info.nextSyncPoint = ts110 + + changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) + disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) + disp.seq.Store(1) + disp.sentResolvedTs.Store(ts100) + disp.checkpointTs.Store(ts120) + + broker.emitSyncPointEventIfNeeded(ts115, disp, node.ID(info.GetServerID())) + + require.False(t, disp.syncPointSendSuppressed.Load()) + require.Equal(t, ts120, disp.nextSyncPoint.Load()) + require.Equal(t, 1, len(broker.messageCh[disp.messageWorkerIndex])) +} + func TestHandleCongestionControlV2AdjustsScanInterval(t *testing.T) { broker, _, _, _ := newEventBrokerForTest() defer broker.close() @@ -904,310 +1081,3 @@ func TestAddDispatcherFailure(t *testing.T) { _, ok := broker.changefeedMap.Load(dispInfo.GetChangefeedID()) require.False(t, ok, "changefeedStatus should be removed after failed registration") } -<<<<<<< HEAD - -type tableTriggerSchemaStore struct { - *mockSchemaStore - events []event.DDLEvent - endTs uint64 - once atomic.Bool -} - -func (s *tableTriggerSchemaStore) FetchTableTriggerDDLEvents(keyspaceMeta common.KeyspaceMeta, dispatcherID common.DispatcherID, tableFilter filter.Filter, start uint64, limit int) ([]event.DDLEvent, uint64, error) { - if s.once.CompareAndSwap(false, true) { - return s.events, s.endTs, nil - } - return nil, start, nil -} - -func TestProcessTableTriggerDispatcherRespectsSyncPointBoundary(t *testing.T) { - broker, _, _, _ := newEventBrokerForTest() - // Stop background workers so we can deterministically inspect broker.messageCh. - broker.close() - - base := time.Unix(0, 0) - ts5 := oracle.GoTimeToTS(base.Add(5 * time.Second)) - ts10 := oracle.GoTimeToTS(base.Add(10 * time.Second)) - ts15 := oracle.GoTimeToTS(base.Add(15 * time.Second)) - ts40 := oracle.GoTimeToTS(base.Add(40 * time.Second)) - - info := newMockDispatcherInfo(t, ts5, common.NewDispatcherID(), 0, eventpb.ActionType_ACTION_TYPE_REGISTER) - info.epoch = 1 - // Next Gen rejects DefaultKeyspaceID, so table-trigger tests need a real keyspace ID. - info.span = common.KeyspaceDDLSpan(testTableTriggerKeyspaceID) - info.enableSyncPoint = true - info.syncPointInterval = 10 * time.Second - info.nextSyncPoint = ts10 - - changefeed := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) - dispatcher := newDispatcherStat(info, 1, 1, nil, changefeed) - dispatcher.seq.Store(1) - - dispatcherPtr := &atomic.Pointer[dispatcherStat]{} - dispatcherPtr.Store(dispatcher) - changefeed.addDispatcher(dispatcher.id, dispatcherPtr) - - broker.schemaStore = &tableTriggerSchemaStore{ - mockSchemaStore: NewMockSchemaStore(), - events: []event.DDLEvent{ - {FinishedTs: ts15, Query: "alter table t add column c int"}, - }, - endTs: ts40, - } - - broker.processTableTriggerDispatcher(context.Background(), dispatcher.id, dispatcher) - - // DDL above the syncpoint boundary must be deferred, and resolved-ts must not cross the boundary. - require.Equal(t, ts10, dispatcher.sentResolvedTs.Load()) - require.Equal(t, ts10, changefeed.getSyncPointPreparingTs()) - require.Equal(t, 1, len(broker.messageCh[dispatcher.messageWorkerIndex])) - - msg := <-broker.messageCh[dispatcher.messageWorkerIndex] - require.Equal(t, event.TypeResolvedEvent, msg.msgType) - require.Equal(t, ts10, msg.resolvedTsEvent.ResolvedTs) -} - -func TestProcessTableTriggerDispatcherNudgesCommitStageWhenNoForwardRange(t *testing.T) { - broker, _, _, _ := newEventBrokerForTest() - // Stop background workers so we can deterministically inspect broker.messageCh. - broker.close() - - base := time.Unix(0, 0) - ts10 := oracle.GoTimeToTS(base.Add(10 * time.Second)) - ts20 := oracle.GoTimeToTS(base.Add(20 * time.Second)) - - info := newMockDispatcherInfo(t, ts10, common.NewDispatcherID(), 0, eventpb.ActionType_ACTION_TYPE_REGISTER) - info.epoch = 1 - info.span = common.KeyspaceDDLSpan(testTableTriggerKeyspaceID) - info.enableSyncPoint = true - info.syncPointInterval = 10 * time.Second - info.nextSyncPoint = ts10 - - changefeed := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) - dispatcher := newDispatcherStat(info, 1, 1, nil, changefeed) - dispatcher.seq.Store(1) - changefeed.syncPointPreparingTs.Store(ts10) - changefeed.syncPointInFlightTs.Store(ts10) - - dispatcherPtr := &atomic.Pointer[dispatcherStat]{} - dispatcherPtr.Store(dispatcher) - changefeed.addDispatcher(dispatcher.id, dispatcherPtr) - - broker.schemaStore = &tableTriggerSchemaStore{ - mockSchemaStore: NewMockSchemaStore(), - endTs: ts10, - } - - broker.processTableTriggerDispatcher(context.Background(), dispatcher.id, dispatcher) - - require.Equal(t, 2, len(broker.messageCh[dispatcher.messageWorkerIndex])) - first := <-broker.messageCh[dispatcher.messageWorkerIndex] - second := <-broker.messageCh[dispatcher.messageWorkerIndex] - require.Equal(t, event.TypeSyncPointEvent, first.msgType) - require.Equal(t, event.TypeResolvedEvent, second.msgType) - - syncPointEvent, ok := first.e.(*event.SyncPointEvent) - require.True(t, ok) - require.Equal(t, ts10, syncPointEvent.GetCommitTs()) - require.Equal(t, ts10, second.resolvedTsEvent.ResolvedTs) - require.Equal(t, ts20, dispatcher.nextSyncPoint.Load()) -} - -func TestProcessTableTriggerDispatcherSendsSignalResolvedWhenNoForwardRangeAndNotInCommitStage(t *testing.T) { - broker, _, _, _ := newEventBrokerForTest() - // Stop background workers so we can deterministically inspect broker.messageCh. - broker.close() - - base := time.Unix(0, 0) - ts10 := oracle.GoTimeToTS(base.Add(10 * time.Second)) - ts20 := oracle.GoTimeToTS(base.Add(20 * time.Second)) - - info := newMockDispatcherInfo(t, ts10, common.NewDispatcherID(), 0, eventpb.ActionType_ACTION_TYPE_REGISTER) - info.epoch = 1 - info.span = common.KeyspaceDDLSpan(testTableTriggerKeyspaceID) - info.enableSyncPoint = true - info.syncPointInterval = 10 * time.Second - info.nextSyncPoint = ts20 - - changefeed := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) - dispatcher := newDispatcherStat(info, 1, 1, nil, changefeed) - dispatcher.lastSentResolvedTsTime.Store(time.Now().Add(-defaultSendResolvedTsInterval - time.Second)) - - dispatcherPtr := &atomic.Pointer[dispatcherStat]{} - dispatcherPtr.Store(dispatcher) - changefeed.addDispatcher(dispatcher.id, dispatcherPtr) - - broker.schemaStore = &tableTriggerSchemaStore{ - mockSchemaStore: NewMockSchemaStore(), - endTs: ts10, - } - - broker.processTableTriggerDispatcher(context.Background(), dispatcher.id, dispatcher) - - require.Equal(t, 2, len(broker.messageCh[dispatcher.messageWorkerIndex])) - first := <-broker.messageCh[dispatcher.messageWorkerIndex] - second := <-broker.messageCh[dispatcher.messageWorkerIndex] - require.Equal(t, event.TypeHandshakeEvent, first.msgType) - require.Equal(t, event.TypeResolvedEvent, second.msgType) - require.Equal(t, ts10, second.resolvedTsEvent.ResolvedTs) - require.Equal(t, ts10, dispatcher.sentResolvedTs.Load()) - require.Equal(t, ts20, dispatcher.nextSyncPoint.Load()) -} - -func TestGetScanTaskDataRangeLocalAdvanceForPendingDDL(t *testing.T) { - broker, _, schemaStore, _ := newEventBrokerForTest() - defer broker.close() - - info := newMockDispatcherInfoForTest(t) - info.epoch = 1 - changefeed := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) - - dispatcher := newDispatcherStat(info, 1, 1, nil, changefeed) - dispatcher.seq.Store(1) - - base := time.Unix(0, 0) - ts9 := oracle.GoTimeToTS(base.Add(9 * time.Second)) - ts10 := oracle.GoTimeToTS(base.Add(10 * time.Second)) - ts11 := oracle.GoTimeToTS(base.Add(11 * time.Second)) - ts12 := oracle.GoTimeToTS(base.Add(12 * time.Second)) - ts40 := oracle.GoTimeToTS(base.Add(40 * time.Second)) - - dispatcher.sentResolvedTs.Store(ts10) - dispatcher.receivedResolvedTs.Store(ts40) - dispatcher.eventStoreCommitTs.Store(ts40) - dispatcher.lastScannedCommitTs.Store(ts10) - dispatcher.lastScannedStartTs.Store(0) - - dispatcherPtr := &atomic.Pointer[dispatcherStat]{} - dispatcherPtr.Store(dispatcher) - changefeed.addDispatcher(dispatcher.id, dispatcherPtr) - changefeed.minSentTs.Store(ts9) - changefeed.scanInterval.Store(int64(time.Second)) - - schemaStore.resolvedTs = ts40 - schemaStore.maxDDLCommitTs = ts12 - - needScan, dataRange := broker.getScanTaskDataRange(dispatcher) - require.True(t, needScan) - require.Equal(t, ts10, dataRange.CommitTsStart) - require.Equal(t, ts11, dataRange.CommitTsEnd) -} - -func TestGetScanTaskDataRangeNudgesSyncPointCommitWhenNoNewRange(t *testing.T) { - broker, _, _, _ := newEventBrokerForTest() - // Stop background workers so we can deterministically inspect broker.messageCh. - broker.close() - - info := newMockDispatcherInfoForTest(t) - info.epoch = 1 - info.enableSyncPoint = true - info.syncPointInterval = 10 * time.Second - info.startTs = oracle.GoTimeToTS(time.Unix(0, 0).Add(10 * time.Second)) - info.nextSyncPoint = oracle.GoTimeToTS(time.Unix(0, 0).Add(20 * time.Second)) - - changefeed := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) - dispatcher := newDispatcherStat(info, 1, 1, nil, changefeed) - dispatcher.seq.Store(1) - dispatcher.sentResolvedTs.Store(info.nextSyncPoint) - dispatcher.receivedResolvedTs.Store(info.nextSyncPoint) - dispatcher.lastScannedCommitTs.Store(info.nextSyncPoint) - dispatcher.lastScannedStartTs.Store(0) - changefeed.syncPointPreparingTs.Store(info.nextSyncPoint) - changefeed.syncPointInFlightTs.Store(info.nextSyncPoint) - - needScan, dataRange := broker.getScanTaskDataRange(dispatcher) - require.False(t, needScan) - require.Equal(t, common.DataRange{}, dataRange) - - first := <-broker.messageCh[dispatcher.messageWorkerIndex] - second := <-broker.messageCh[dispatcher.messageWorkerIndex] - require.Equal(t, event.TypeSyncPointEvent, first.msgType) - require.Equal(t, event.TypeResolvedEvent, second.msgType) -} - -func TestTickTableTriggerDispatchersSendsDDLEventAndResolved(t *testing.T) { - mockPDClock := pdutil.NewClock4Test() - appcontext.SetService(appcontext.DefaultPDClock, mockPDClock) - eventStore := newMockEventStore(100) - baseSchemaStore := NewMockSchemaStore() - - nextTs := uint64(310) - tableTriggerDDL := event.DDLEvent{FinishedTs: nextTs, Query: "alter table t add column c int"} - schemaStore := &tableTriggerSchemaStore{ - mockSchemaStore: baseSchemaStore, - events: []event.DDLEvent{tableTriggerDDL}, - endTs: nextTs, - } - messageCenter := messaging.NewMockMessageCenter() - messageCh := messageCenter.GetMessageChannel() - - broker := newEventBroker(context.Background(), 1, eventStore, schemaStore, messageCenter, time.UTC, &integrity.Config{ - IntegrityCheckLevel: util.AddressOf(integrity.CheckLevelNone), - CorruptionHandleLevel: util.AddressOf(integrity.CorruptionHandleLevelWarn), - }) - defer broker.close() - - info := newMockDispatcherInfo(t, 300, common.NewDispatcherID(), 0, eventpb.ActionType_ACTION_TYPE_REGISTER) - info.span = common.KeyspaceDDLSpan(testTableTriggerKeyspaceID) - err := broker.addDispatcher(info) - require.NoError(t, err) - - resetInfo := newMockDispatcherInfo(t, 300, info.GetID(), 0, eventpb.ActionType_ACTION_TYPE_RESET) - resetInfo.span = common.KeyspaceDDLSpan(testTableTriggerKeyspaceID) - resetInfo.epoch = 1 - err = broker.resetDispatcher(resetInfo) - require.NoError(t, err) - - foundDDL := false - foundResolved := false - require.Eventually(t, func() bool { - for i := 0; i < len(messageCh); i++ { - msg := <-messageCh - if msg.Type == messaging.TypeDDLEvent { - foundDDL = true - } - if msg.Type == messaging.TypeBatchResolvedTs { - foundResolved = true - } - } - return foundDDL && foundResolved - }, 5*time.Second, 20*time.Millisecond) -} - -func TestResetDispatcherCopiesRuntimeStatistics(t *testing.T) { - broker, _, _, _ := newEventBrokerForTest() - defer broker.close() - - info := newMockDispatcherInfoForTest(t) - err := broker.addDispatcher(info) - require.NoError(t, err) - - statPtr := broker.getDispatcher(info.GetID()) - require.NotNil(t, statPtr) - oldStat := statPtr.Load() - - oldStat.receivedResolvedTs.Store(180) - oldStat.eventStoreCommitTs.Store(170) - oldStat.checkpointTs.Store(160) - oldStat.currentScanLimitInBytes.Store(4096) - oldStat.maxScanLimitInBytes.Store(8192) - oldStat.lastScanBytes.Store(2048) - - resetInfo := newMockDispatcherInfo(t, 150, info.GetID(), info.GetTableSpan().TableID, eventpb.ActionType_ACTION_TYPE_RESET) - resetInfo.epoch = 2 - err = broker.resetDispatcher(resetInfo) - require.NoError(t, err) - - newStat := statPtr.Load() - require.NotEqual(t, oldStat, newStat) - require.True(t, oldStat.isRemoved.Load()) - require.Equal(t, uint64(2), newStat.epoch) - require.Equal(t, uint64(180), newStat.receivedResolvedTs.Load()) - require.Equal(t, uint64(170), newStat.eventStoreCommitTs.Load()) - require.Equal(t, uint64(160), newStat.checkpointTs.Load()) - require.Equal(t, int64(4096), newStat.currentScanLimitInBytes.Load()) - require.Equal(t, int64(8192), newStat.maxScanLimitInBytes.Load()) - require.Equal(t, int64(2048), newStat.lastScanBytes.Load()) -} -======= ->>>>>>> parent of fa1e59cb0 (eventBroker: implement two stage syncpoint (#4429)) diff --git a/pkg/metrics/event_service.go b/pkg/metrics/event_service.go index e6ed10cc90..45c10a298f 100644 --- a/pkg/metrics/event_service.go +++ b/pkg/metrics/event_service.go @@ -69,6 +69,27 @@ var ( Name: "scan_window_interval", Help: "The scan window interval in seconds for each changefeed", }, []string{"changefeed"}) + EventServiceSyncPointLagGaugeVec = prometheus.NewGaugeVec( + prometheus.GaugeOpts{ + Namespace: "ticdc", + Subsystem: "event_service", + Name: "syncpoint_lag_seconds", + Help: "The lag between sent resolved ts and checkpoint ts in seconds for each changefeed", + }, []string{"changefeed"}) + EventServiceSyncPointSuppressedCount = prometheus.NewCounterVec( + prometheus.CounterOpts{ + Namespace: "ticdc", + Subsystem: "event_service", + Name: "syncpoint_suppressed_count", + Help: "The number of syncpoint events suppressed due to lagging checkpoint", + }, []string{"changefeed"}) + EventServiceScanCappedByCheckpointCount = prometheus.NewCounterVec( + prometheus.CounterOpts{ + Namespace: "ticdc", + Subsystem: "event_service", + Name: "scan_capped_by_checkpoint_count", + Help: "The number of scan ranges capped by checkpoint based bound", + }, []string{"changefeed"}) EventServiceScanDuration = prometheus.NewHistogram( prometheus.HistogramOpts{ Namespace: "ticdc", @@ -201,6 +222,9 @@ func initEventServiceMetrics(registry *prometheus.Registry) { registry.MustRegister(EventServiceResolvedTsLagGauge) registry.MustRegister(EventServiceScanWindowBaseTsGaugeVec) registry.MustRegister(EventServiceScanWindowIntervalGaugeVec) + registry.MustRegister(EventServiceSyncPointLagGaugeVec) + registry.MustRegister(EventServiceSyncPointSuppressedCount) + registry.MustRegister(EventServiceScanCappedByCheckpointCount) registry.MustRegister(EventServiceScanDuration) registry.MustRegister(EventServiceScannedCount) registry.MustRegister(EventServiceDispatcherGauge) From 89a702d5f774c27e0168869747d886cc1f95b5d6 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Tue, 14 Apr 2026 03:02:35 +0800 Subject: [PATCH 04/17] dispatcher,dispatchermanager: deduplicate pending done statuses --- .../dispatcher/basic_dispatcher.go | 28 +-- .../basic_dispatcher_active_active_test.go | 3 +- .../dispatcher/basic_dispatcher_info.go | 57 +++++- .../dispatcher/block_status_buffer.go | 157 +++++++++++++++++ .../dispatcher/block_status_buffer_test.go | 107 ++++++++++++ .../dispatcher/event_dispatcher_test.go | 87 ++++----- downstreamadapter/dispatcher/helper.go | 2 +- .../dispatcher/redo_dispatcher_test.go | 2 +- .../dispatchermanager/dispatcher_manager.go | 54 +++--- .../dispatcher_manager_test.go | 4 +- .../dispatchermanager/heartbeat_collector.go | 1 + .../dispatchermanager/heartbeat_queue.go | 97 +++++++++- .../dispatchermanager/heartbeat_queue_test.go | 165 ++++++++++++++++++ 13 files changed, 644 insertions(+), 120 deletions(-) create mode 100644 downstreamadapter/dispatcher/block_status_buffer.go create mode 100644 downstreamadapter/dispatcher/block_status_buffer_test.go create mode 100644 downstreamadapter/dispatchermanager/heartbeat_queue_test.go diff --git a/downstreamadapter/dispatcher/basic_dispatcher.go b/downstreamadapter/dispatcher/basic_dispatcher.go index 0c31275a4c..53db1e85c8 100644 --- a/downstreamadapter/dispatcher/basic_dispatcher.go +++ b/downstreamadapter/dispatcher/basic_dispatcher.go @@ -76,7 +76,7 @@ type Dispatcher interface { GetHeartBeatInfo(h *HeartBeatInfo) GetComponentStatus() heartbeatpb.ComponentState GetBlockEventStatus() *heartbeatpb.State - GetBlockStatusesChan() chan *heartbeatpb.TableSpanBlockStatus + OfferBlockStatus(status *heartbeatpb.TableSpanBlockStatus) GetEventSizePerSecond() float32 IsTableTriggerDispatcher() bool DealWithBlockEvent(event commonEvent.BlockEvent) @@ -836,16 +836,7 @@ func (d *BasicDispatcher) HandleDispatcherStatus(dispatcherStatus *heartbeatpb.D } // Step3: whether the outdate message or not, we need to return message show we have finished the event. - d.sharedInfo.blockStatusesChan <- &heartbeatpb.TableSpanBlockStatus{ - ID: d.id.ToPB(), - State: &heartbeatpb.State{ - IsBlocked: true, - BlockTs: action.CommitTs, - IsSyncPoint: action.IsSyncPoint, - Stage: heartbeatpb.BlockStage_DONE, - }, - Mode: d.GetMode(), - } + d.OfferDoneBlockStatus(action.CommitTs, action.IsSyncPoint) } return false } @@ -881,16 +872,7 @@ func (d *BasicDispatcher) reportBlockedEventDone( actionCommitTs uint64, actionIsSyncPoint bool, ) { - d.sharedInfo.blockStatusesChan <- &heartbeatpb.TableSpanBlockStatus{ - ID: d.id.ToPB(), - State: &heartbeatpb.State{ - IsBlocked: true, - BlockTs: actionCommitTs, - IsSyncPoint: actionIsSyncPoint, - Stage: heartbeatpb.BlockStage_DONE, - }, - Mode: d.GetMode(), - } + d.OfferDoneBlockStatus(actionCommitTs, actionIsSyncPoint) GetDispatcherStatusDynamicStream().Wake(d.id) } @@ -1042,7 +1024,7 @@ func (d *BasicDispatcher) DealWithBlockEvent(event commonEvent.BlockEvent) { } else { d.resendTaskMap.Set(identifier, newResendTask(message, d, nil)) } - d.sharedInfo.blockStatusesChan <- message + d.OfferBlockStatus(message) }) // dealing with events which update schema ids @@ -1166,7 +1148,7 @@ func (d *BasicDispatcher) reportBlockedEventToMaintainer(event commonEvent.Block IsSyncPoint: event.GetType() == commonEvent.TypeSyncPointEvent, } d.resendTaskMap.Set(identifier, newResendTask(message, d, nil)) - d.sharedInfo.blockStatusesChan <- message + d.OfferBlockStatus(message) } func (d *BasicDispatcher) flushBlockedEventAndReportToMaintainer(event commonEvent.BlockEvent) { diff --git a/downstreamadapter/dispatcher/basic_dispatcher_active_active_test.go b/downstreamadapter/dispatcher/basic_dispatcher_active_active_test.go index 8f95a93b5b..882da1fe1b 100644 --- a/downstreamadapter/dispatcher/basic_dispatcher_active_active_test.go +++ b/downstreamadapter/dispatcher/basic_dispatcher_active_active_test.go @@ -129,7 +129,6 @@ func TestDDLEventsAlwaysValidateActiveActive(t *testing.T) { func newTestBasicDispatcher(t *testing.T, sinkType common.SinkType, enableActiveActive bool) *BasicDispatcher { t.Helper() statuses := make(chan TableSpanStatusWithSeq, 2) - blockStatuses := make(chan *heartbeatpb.TableSpanBlockStatus, 1) errCh := make(chan error, 1) sharedInfo := NewSharedInfo( common.NewChangefeedID("test"), @@ -143,7 +142,7 @@ func newTestBasicDispatcher(t *testing.T, sinkType common.SinkType, enableActive nil, false, statuses, - blockStatuses, + 1, errCh, ) dispatcherSink := newDispatcherTestSink(t, sinkType) diff --git a/downstreamadapter/dispatcher/basic_dispatcher_info.go b/downstreamadapter/dispatcher/basic_dispatcher_info.go index 19a0980461..161d3eb58c 100644 --- a/downstreamadapter/dispatcher/basic_dispatcher_info.go +++ b/downstreamadapter/dispatcher/basic_dispatcher_info.go @@ -14,6 +14,7 @@ package dispatcher import ( + "context" "sync/atomic" "time" @@ -58,9 +59,9 @@ type SharedInfo struct { // statusesChan is used to store the status of dispatchers when status changed // and push to heartbeatRequestQueue statusesChan chan TableSpanStatusWithSeq - // blockStatusesChan use to collector block status of ddl/sync point event to Maintainer - // shared by the event dispatcher manager - blockStatusesChan chan *heartbeatpb.TableSpanBlockStatus + // blockStatusBuffer keeps block statuses for the dispatcher manager. + // Identical DONE statuses are coalesced while pending to reduce local memory amplification. + blockStatusBuffer *BlockStatusBuffer // blockExecutor is used to execute block events such as DDL and sync point events asynchronously // to avoid callback() called in handleEvents, causing deadlock in ds @@ -88,7 +89,7 @@ func NewSharedInfo( txnAtomicity *config.AtomicityLevel, enableSplittableCheck bool, statusesChan chan TableSpanStatusWithSeq, - blockStatusesChan chan *heartbeatpb.TableSpanBlockStatus, + blockStatusBufferSize int, errCh chan error, ) *SharedInfo { sharedInfo := &SharedInfo{ @@ -102,7 +103,7 @@ func NewSharedInfo( syncPointConfig: syncPointConfig, enableSplittableCheck: enableSplittableCheck, statusesChan: statusesChan, - blockStatusesChan: blockStatusesChan, + blockStatusBuffer: NewBlockStatusBuffer(blockStatusBufferSize), blockExecutor: newBlockEventExecutor(), errCh: errCh, metricHandleDDLHis: metrics.HandleDDLHistogram.WithLabelValues(changefeedID.Keyspace(), changefeedID.Name()), @@ -219,8 +220,20 @@ func (d *BasicDispatcher) GetTxnAtomicity() config.AtomicityLevel { return d.sharedInfo.txnAtomicity } -func (d *BasicDispatcher) GetBlockStatusesChan() chan *heartbeatpb.TableSpanBlockStatus { - return d.sharedInfo.blockStatusesChan +func (d *BasicDispatcher) OfferBlockStatus(status *heartbeatpb.TableSpanBlockStatus) { + d.sharedInfo.OfferBlockStatus(status) +} + +func (d *BasicDispatcher) OfferDoneBlockStatus(blockTs uint64, isSyncPoint bool) { + d.sharedInfo.OfferDoneBlockStatus(d.id, blockTs, isSyncPoint, d.GetMode()) +} + +func (d *BasicDispatcher) TakeBlockStatus(ctx context.Context) *heartbeatpb.TableSpanBlockStatus { + return d.sharedInfo.TakeBlockStatus(ctx) +} + +func (d *BasicDispatcher) TakeBlockStatusWithTimeout(timeout time.Duration) (*heartbeatpb.TableSpanBlockStatus, bool) { + return d.sharedInfo.TakeBlockStatusWithTimeout(timeout) } func (d *BasicDispatcher) GetEventSizePerSecond() float32 { @@ -254,8 +267,34 @@ func (s *SharedInfo) EnableActiveActive() bool { return s.enableActiveActive } -func (s *SharedInfo) GetBlockStatusesChan() chan *heartbeatpb.TableSpanBlockStatus { - return s.blockStatusesChan +func (s *SharedInfo) OfferBlockStatus(status *heartbeatpb.TableSpanBlockStatus) { + s.blockStatusBuffer.Offer(status) +} + +func (s *SharedInfo) OfferDoneBlockStatus(dispatcherID common.DispatcherID, blockTs uint64, isSyncPoint bool, mode int64) { + s.blockStatusBuffer.OfferDone(dispatcherID, blockTs, isSyncPoint, mode) +} + +func (s *SharedInfo) TakeBlockStatus(ctx context.Context) *heartbeatpb.TableSpanBlockStatus { + return s.blockStatusBuffer.Take(ctx) +} + +func (s *SharedInfo) TakeBlockStatusWithTimeout(timeout time.Duration) (*heartbeatpb.TableSpanBlockStatus, bool) { + ctx, cancel := context.WithTimeout(context.Background(), timeout) + defer cancel() + status := s.TakeBlockStatus(ctx) + if status == nil { + return nil, false + } + return status, true +} + +func (s *SharedInfo) TryTakeBlockStatus() (*heartbeatpb.TableSpanBlockStatus, bool) { + return s.blockStatusBuffer.TryTake() +} + +func (s *SharedInfo) BlockStatusLen() int { + return s.blockStatusBuffer.Len() } func (s *SharedInfo) GetErrCh() chan error { diff --git a/downstreamadapter/dispatcher/block_status_buffer.go b/downstreamadapter/dispatcher/block_status_buffer.go new file mode 100644 index 0000000000..894e4dc193 --- /dev/null +++ b/downstreamadapter/dispatcher/block_status_buffer.go @@ -0,0 +1,157 @@ +// Copyright 2026 PingCAP, Inc. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// See the License for the specific language governing permissions and +// limitations under the License. + +package dispatcher + +import ( + "context" + "sync" + + "github.com/pingcap/ticdc/heartbeatpb" + "github.com/pingcap/ticdc/pkg/common" +) + +type doneBlockStatusKey struct { + dispatcherID common.DispatcherID + blockTs uint64 + mode int64 + isSyncPoint bool +} + +type blockStatusQueueEntry struct { + status *heartbeatpb.TableSpanBlockStatus + doneKey *doneBlockStatusKey +} + +// BlockStatusBuffer keeps block statuses ordered while coalescing identical DONE +// statuses that are still pending locally. Non-DONE statuses keep the original +// protobuf object and ordering. +type BlockStatusBuffer struct { + queue chan blockStatusQueueEntry + + mu sync.Mutex + pendingDone map[doneBlockStatusKey]struct{} +} + +// NewBlockStatusBuffer creates a bounded local mailbox for dispatcher block +// statuses. The buffer keeps enqueue order while coalescing identical pending +// DONE statuses before protobuf materialization. +func NewBlockStatusBuffer(size int) *BlockStatusBuffer { + if size <= 0 { + size = 1 + } + return &BlockStatusBuffer{ + queue: make(chan blockStatusQueueEntry, size), + pendingDone: make(map[doneBlockStatusKey]struct{}), + } +} + +func (b *BlockStatusBuffer) Offer(status *heartbeatpb.TableSpanBlockStatus) { + if status == nil { + return + } + if !isDoneBlockStatus(status) { + b.queue <- blockStatusQueueEntry{status: status} + return + } + + key := doneBlockStatusKey{ + dispatcherID: common.NewDispatcherIDFromPB(status.ID), + blockTs: status.State.BlockTs, + mode: status.Mode, + isSyncPoint: status.State.IsSyncPoint, + } + if !b.reserveDone(key) { + return + } + b.queue <- blockStatusQueueEntry{doneKey: &key} +} + +func (b *BlockStatusBuffer) OfferDone( + dispatcherID common.DispatcherID, + blockTs uint64, + isSyncPoint bool, + mode int64, +) { + key := doneBlockStatusKey{ + dispatcherID: dispatcherID, + blockTs: blockTs, + mode: mode, + isSyncPoint: isSyncPoint, + } + if !b.reserveDone(key) { + return + } + b.queue <- blockStatusQueueEntry{doneKey: &key} +} + +func (b *BlockStatusBuffer) Take(ctx context.Context) *heartbeatpb.TableSpanBlockStatus { + select { + case <-ctx.Done(): + return nil + case entry := <-b.queue: + return b.materialize(entry) + } +} + +func (b *BlockStatusBuffer) TryTake() (*heartbeatpb.TableSpanBlockStatus, bool) { + select { + case entry := <-b.queue: + return b.materialize(entry), true + default: + return nil, false + } +} + +func (b *BlockStatusBuffer) Len() int { + return len(b.queue) +} + +func (b *BlockStatusBuffer) reserveDone(key doneBlockStatusKey) bool { + b.mu.Lock() + defer b.mu.Unlock() + if _, ok := b.pendingDone[key]; ok { + return false + } + b.pendingDone[key] = struct{}{} + return true +} + +func (b *BlockStatusBuffer) materialize(entry blockStatusQueueEntry) *heartbeatpb.TableSpanBlockStatus { + if entry.status != nil { + return entry.status + } + + key := *entry.doneKey + b.mu.Lock() + delete(b.pendingDone, key) + b.mu.Unlock() + + return &heartbeatpb.TableSpanBlockStatus{ + ID: key.dispatcherID.ToPB(), + State: &heartbeatpb.State{ + IsBlocked: true, + BlockTs: key.blockTs, + IsSyncPoint: key.isSyncPoint, + Stage: heartbeatpb.BlockStage_DONE, + }, + Mode: key.mode, + } +} + +func isDoneBlockStatus(status *heartbeatpb.TableSpanBlockStatus) bool { + return status != nil && + status.State != nil && + status.State.IsBlocked && + status.State.Stage == heartbeatpb.BlockStage_DONE +} diff --git a/downstreamadapter/dispatcher/block_status_buffer_test.go b/downstreamadapter/dispatcher/block_status_buffer_test.go new file mode 100644 index 0000000000..4dcce37d2e --- /dev/null +++ b/downstreamadapter/dispatcher/block_status_buffer_test.go @@ -0,0 +1,107 @@ +// Copyright 2026 PingCAP, Inc. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// See the License for the specific language governing permissions and +// limitations under the License. + +package dispatcher + +import ( + "context" + "testing" + "time" + + "github.com/pingcap/ticdc/heartbeatpb" + "github.com/pingcap/ticdc/pkg/common" + "github.com/stretchr/testify/require" +) + +func TestBlockStatusBufferDeduplicatesPendingDone(t *testing.T) { + buffer := NewBlockStatusBuffer(4) + dispatcherID := common.NewDispatcherID() + + buffer.OfferDone(dispatcherID, 100, false, common.DefaultMode) + buffer.OfferDone(dispatcherID, 100, false, common.DefaultMode) + + require.Equal(t, 1, buffer.Len()) + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + msg := buffer.Take(ctx) + require.NotNil(t, msg) + require.Equal(t, dispatcherID, common.NewDispatcherIDFromPB(msg.ID)) + require.Equal(t, uint64(100), msg.State.BlockTs) + require.Equal(t, heartbeatpb.BlockStage_DONE, msg.State.Stage) + require.False(t, msg.State.IsSyncPoint) + require.Equal(t, common.DefaultMode, msg.Mode) + + _, ok := buffer.TryTake() + require.False(t, ok) +} + +func TestBlockStatusBufferKeepsWaitingBeforeDone(t *testing.T) { + buffer := NewBlockStatusBuffer(4) + dispatcherID := common.NewDispatcherID() + + buffer.Offer(&heartbeatpb.TableSpanBlockStatus{ + ID: dispatcherID.ToPB(), + State: &heartbeatpb.State{ + IsBlocked: true, + BlockTs: 200, + Stage: heartbeatpb.BlockStage_WAITING, + }, + Mode: common.DefaultMode, + }) + buffer.OfferDone(dispatcherID, 200, false, common.DefaultMode) + buffer.OfferDone(dispatcherID, 200, false, common.DefaultMode) + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + first := buffer.Take(ctx) + require.NotNil(t, first) + require.Equal(t, heartbeatpb.BlockStage_WAITING, first.State.Stage) + + second := buffer.Take(ctx) + require.NotNil(t, second) + require.Equal(t, heartbeatpb.BlockStage_DONE, second.State.Stage) + + _, ok := buffer.TryTake() + require.False(t, ok) +} + +func TestBlockStatusBufferKeepsDistinctDoneKeys(t *testing.T) { + buffer := NewBlockStatusBuffer(4) + dispatcherID := common.NewDispatcherID() + + buffer.OfferDone(dispatcherID, 300, false, common.DefaultMode) + buffer.OfferDone(dispatcherID, 300, true, common.DefaultMode) + buffer.OfferDone(dispatcherID, 300, false, common.RedoMode) + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + + first := buffer.Take(ctx) + require.NotNil(t, first) + require.False(t, first.State.IsSyncPoint) + require.Equal(t, common.DefaultMode, first.Mode) + + second := buffer.Take(ctx) + require.NotNil(t, second) + require.True(t, second.State.IsSyncPoint) + require.Equal(t, common.DefaultMode, second.Mode) + + third := buffer.Take(ctx) + require.NotNil(t, third) + require.False(t, third.State.IsSyncPoint) + require.Equal(t, common.RedoMode, third.Mode) + + _, ok := buffer.TryTake() + require.False(t, ok) +} diff --git a/downstreamadapter/dispatcher/event_dispatcher_test.go b/downstreamadapter/dispatcher/event_dispatcher_test.go index 29b8ace3e2..0ce694d02e 100644 --- a/downstreamadapter/dispatcher/event_dispatcher_test.go +++ b/downstreamadapter/dispatcher/event_dispatcher_test.go @@ -83,7 +83,7 @@ func newDispatcherForTest(sink sink.Sink, tableSpan *heartbeatpb.TableSpan) *Eve &defaultAtomicity, false, // enableSplittableCheck make(chan TableSpanStatusWithSeq, 128), - make(chan *heartbeatpb.TableSpanBlockStatus, 128), + 128, make(chan error, 1), ) return NewEventDispatcher( @@ -476,22 +476,16 @@ func TestBlockingDDLFlushBeforeWaitingAndWriteDoesNotFlushAgain(t *testing.T) { require.Nil(t, pendingEvent) require.Equal(t, heartbeatpb.BlockStage_NONE, blockStage) - select { - case msg := <-dispatcher.GetBlockStatusesChan(): - require.FailNow(t, "unexpected block status before local flush finishes", "received=%v", msg) - case <-time.After(200 * time.Millisecond): - } + msg, ok := dispatcher.TakeBlockStatusWithTimeout(200 * time.Millisecond) + require.False(t, ok, "unexpected block status before local flush finishes: %v", msg) close(flushRelease) - select { - case msg := <-dispatcher.GetBlockStatusesChan(): - require.True(t, msg.State.IsBlocked) - require.Equal(t, uint64(10), msg.State.BlockTs) - require.Equal(t, heartbeatpb.BlockStage_WAITING, msg.State.Stage) - case <-time.After(time.Second): - require.FailNow(t, "expected blocking DDL to enter WAITING after local flush") - } + msg, ok = dispatcher.TakeBlockStatusWithTimeout(time.Second) + require.True(t, ok, "expected blocking DDL to enter WAITING after local flush") + require.True(t, msg.State.IsBlocked) + require.Equal(t, uint64(10), msg.State.BlockTs) + require.Equal(t, heartbeatpb.BlockStage_WAITING, msg.State.Stage) pendingEvent, blockStage = dispatcher.blockEventStatus.getEventAndStage() require.Same(t, ddlEvent, pendingEvent) @@ -507,14 +501,11 @@ func TestBlockingDDLFlushBeforeWaitingAndWriteDoesNotFlushAgain(t *testing.T) { }) require.True(t, await) - select { - case msg := <-dispatcher.GetBlockStatusesChan(): - require.True(t, msg.State.IsBlocked) - require.Equal(t, uint64(10), msg.State.BlockTs) - require.Equal(t, heartbeatpb.BlockStage_DONE, msg.State.Stage) - case <-time.After(time.Second): - require.FailNow(t, "expected DONE after write action") - } + msg, ok = dispatcher.TakeBlockStatusWithTimeout(time.Second) + require.True(t, ok, "expected DONE after write action") + require.True(t, msg.State.IsBlocked) + require.Equal(t, uint64(10), msg.State.BlockTs) + require.Equal(t, heartbeatpb.BlockStage_DONE, msg.State.Stage) require.Eventually(t, func() bool { pendingEvent, blockStage = dispatcher.blockEventStatus.getEventAndStage() @@ -1004,7 +995,7 @@ func TestDispatcherSplittableCheck(t *testing.T) { &defaultAtomicity, true, // enableSplittableCheck = true make(chan TableSpanStatusWithSeq, 128), - make(chan *heartbeatpb.TableSpanBlockStatus, 128), + 128, make(chan error, 1), ) @@ -1114,7 +1105,7 @@ func TestDispatcher_SkipDMLAsStartTs_FilterCorrectly(t *testing.T) { &defaultAtomicity, false, make(chan TableSpanStatusWithSeq, 128), - make(chan *heartbeatpb.TableSpanBlockStatus, 128), + 128, make(chan error, 1), ) @@ -1194,7 +1185,7 @@ func TestDispatcher_SkipDMLAsStartTs_Disabled(t *testing.T) { &defaultAtomicity, false, make(chan TableSpanStatusWithSeq, 128), - make(chan *heartbeatpb.TableSpanBlockStatus, 128), + 128, make(chan error, 1), ) @@ -1258,14 +1249,11 @@ func TestHoldBlockEventUntilNoResendTasks(t *testing.T) { block := dispatcher.HandleEvents([]DispatcherEvent{NewDispatcherEvent(&nodeID, createTableDDL)}, func() {}) require.True(t, block) - select { - case msg := <-dispatcher.GetBlockStatusesChan(): - require.False(t, msg.State.IsBlocked) - require.False(t, msg.State.IsSyncPoint) - require.Equal(t, uint64(10), msg.State.BlockTs) - case <-time.After(time.Second): - require.FailNow(t, "expected add-table block status") - } + msg, ok := dispatcher.TakeBlockStatusWithTimeout(time.Second) + require.True(t, ok, "expected add-table block status") + require.False(t, msg.State.IsBlocked) + require.False(t, msg.State.IsSyncPoint) + require.Equal(t, uint64(10), msg.State.BlockTs) require.Equal(t, 1, dispatcher.resendTaskMap.Len()) // A DB/All block event must be deferred until resendTaskMap becomes empty, @@ -1281,11 +1269,8 @@ func TestHoldBlockEventUntilNoResendTasks(t *testing.T) { block = dispatcher.HandleEvents([]DispatcherEvent{NewDispatcherEvent(&nodeID, dropDBDDL)}, func() {}) require.True(t, block) - select { - case msg := <-dispatcher.GetBlockStatusesChan(): - require.FailNow(t, "unexpected block status", "received=%v", msg) - case <-time.After(200 * time.Millisecond): - } + msg, ok = dispatcher.TakeBlockStatusWithTimeout(200 * time.Millisecond) + require.False(t, ok, "unexpected block status: %v", msg) // Simulate maintainer ACK for the create table scheduling message. dispatcher.HandleDispatcherStatus(&heartbeatpb.DispatcherStatus{ @@ -1301,23 +1286,17 @@ func TestHoldBlockEventUntilNoResendTasks(t *testing.T) { require.FailNow(t, "expected deferred DB-level flush to start") } - select { - case msg := <-dispatcher.GetBlockStatusesChan(): - require.FailNow(t, "unexpected block status before local flush finishes", "received=%v", msg) - case <-time.After(200 * time.Millisecond): - } + msg, ok = dispatcher.TakeBlockStatusWithTimeout(200 * time.Millisecond) + require.False(t, ok, "unexpected block status before local flush finishes: %v", msg) close(flushRelease) - select { - case msg := <-dispatcher.GetBlockStatusesChan(): - require.True(t, msg.State.IsBlocked) - require.False(t, msg.State.IsSyncPoint) - require.Equal(t, uint64(20), msg.State.BlockTs) - require.Equal(t, heartbeatpb.InfluenceType_DB, msg.State.BlockTables.InfluenceType) - require.Equal(t, int64(1), msg.State.BlockTables.SchemaID) - require.Equal(t, heartbeatpb.BlockStage_WAITING, msg.State.Stage) - case <-time.After(time.Second): - require.FailNow(t, "expected deferred DB-level block status") - } + msg, ok = dispatcher.TakeBlockStatusWithTimeout(time.Second) + require.True(t, ok, "expected deferred DB-level block status") + require.True(t, msg.State.IsBlocked) + require.False(t, msg.State.IsSyncPoint) + require.Equal(t, uint64(20), msg.State.BlockTs) + require.Equal(t, heartbeatpb.InfluenceType_DB, msg.State.BlockTables.InfluenceType) + require.Equal(t, int64(1), msg.State.BlockTables.SchemaID) + require.Equal(t, heartbeatpb.BlockStage_WAITING, msg.State.Stage) } diff --git a/downstreamadapter/dispatcher/helper.go b/downstreamadapter/dispatcher/helper.go index d50137a95b..30983c1d50 100644 --- a/downstreamadapter/dispatcher/helper.go +++ b/downstreamadapter/dispatcher/helper.go @@ -270,7 +270,7 @@ func newResendTask(message *heartbeatpb.TableSpanBlockStatus, dispatcher Dispatc func (t *ResendTask) Execute() time.Time { log.Debug("resend task", zap.Any("message", t.message), zap.Any("dispatcherID", t.dispatcher.GetId())) - t.dispatcher.GetBlockStatusesChan() <- t.message + t.dispatcher.OfferBlockStatus(t.message) executeCount := atomic.AddUint64(&t.executeCount, 1) if executeCount%10 == 0 { diff --git a/downstreamadapter/dispatcher/redo_dispatcher_test.go b/downstreamadapter/dispatcher/redo_dispatcher_test.go index 68f97016b7..bdd906eebc 100644 --- a/downstreamadapter/dispatcher/redo_dispatcher_test.go +++ b/downstreamadapter/dispatcher/redo_dispatcher_test.go @@ -48,7 +48,7 @@ func newRedoDispatcherForTest(sink sink.Sink, tableSpan *heartbeatpb.TableSpan) &defaultAtomicity, false, // enableSplittableCheck make(chan TableSpanStatusWithSeq, 128), - make(chan *heartbeatpb.TableSpanBlockStatus, 128), + 128, make(chan error, 1), ) return NewRedoDispatcher( diff --git a/downstreamadapter/dispatchermanager/dispatcher_manager.go b/downstreamadapter/dispatchermanager/dispatcher_manager.go index 128f8cbe1e..7446889b52 100644 --- a/downstreamadapter/dispatchermanager/dispatcher_manager.go +++ b/downstreamadapter/dispatchermanager/dispatcher_manager.go @@ -258,7 +258,7 @@ func NewDispatcherManager( manager.config.SinkConfig.TxnAtomicity, manager.config.EnableSplittableCheck, make(chan dispatcher.TableSpanStatusWithSeq, 8192), - make(chan *heartbeatpb.TableSpanBlockStatus, 1024*1024), + 1024*1024, make(chan error, 1), ) @@ -565,8 +565,6 @@ func (e *DispatcherManager) collectErrors(ctx context.Context) { // collectBlockStatusRequest collect the block status from the block status channel and report to the maintainer. func (e *DispatcherManager) collectBlockStatusRequest(ctx context.Context) { - delay := time.NewTimer(0) - defer delay.Stop() enqueueBlockStatus := func(blockStatusMessage []*heartbeatpb.TableSpanBlockStatus, mode int64) { var message heartbeatpb.BlockStatusRequest message.ChangefeedID = e.changefeedID.ToPB() @@ -577,37 +575,39 @@ func (e *DispatcherManager) collectBlockStatusRequest(ctx context.Context) { for { blockStatusMessage := make([]*heartbeatpb.TableSpanBlockStatus, 0) redoBlockStatusMessage := make([]*heartbeatpb.TableSpanBlockStatus, 0) - select { - case <-ctx.Done(): + blockStatus := e.sharedInfo.TakeBlockStatus(ctx) + if blockStatus == nil { return - case blockStatus := <-e.sharedInfo.GetBlockStatusesChan(): + } + if common.IsDefaultMode(blockStatus.Mode) { + blockStatusMessage = append(blockStatusMessage, blockStatus) + } else { + redoBlockStatusMessage = append(redoBlockStatusMessage, blockStatus) + } + + batchCtx, cancel := context.WithTimeout(ctx, 10*time.Millisecond) + for { + blockStatus = e.sharedInfo.TakeBlockStatus(batchCtx) + if blockStatus == nil { + break + } if common.IsDefaultMode(blockStatus.Mode) { blockStatusMessage = append(blockStatusMessage, blockStatus) } else { redoBlockStatusMessage = append(redoBlockStatusMessage, blockStatus) } - delay.Reset(10 * time.Millisecond) - loop: - for { - select { - case blockStatus := <-e.sharedInfo.GetBlockStatusesChan(): - if common.IsDefaultMode(blockStatus.Mode) { - blockStatusMessage = append(blockStatusMessage, blockStatus) - } else { - redoBlockStatusMessage = append(redoBlockStatusMessage, blockStatus) - } - case <-delay.C: - break loop - } - } + } + cancel() + if ctx.Err() != nil { + return + } - e.metricBlockStatusesChanLen.Set(float64(len(e.sharedInfo.GetBlockStatusesChan()))) - if len(blockStatusMessage) != 0 { - enqueueBlockStatus(blockStatusMessage, common.DefaultMode) - } - if len(redoBlockStatusMessage) != 0 { - enqueueBlockStatus(redoBlockStatusMessage, common.RedoMode) - } + e.metricBlockStatusesChanLen.Set(float64(e.sharedInfo.BlockStatusLen())) + if len(blockStatusMessage) != 0 { + enqueueBlockStatus(blockStatusMessage, common.DefaultMode) + } + if len(redoBlockStatusMessage) != 0 { + enqueueBlockStatus(redoBlockStatusMessage, common.RedoMode) } } } diff --git a/downstreamadapter/dispatchermanager/dispatcher_manager_test.go b/downstreamadapter/dispatchermanager/dispatcher_manager_test.go index d26a6193d8..f48d52df21 100644 --- a/downstreamadapter/dispatchermanager/dispatcher_manager_test.go +++ b/downstreamadapter/dispatchermanager/dispatcher_manager_test.go @@ -80,7 +80,7 @@ func createTestDispatcher(t *testing.T, manager *DispatcherManager, id common.Di &defaultAtomicity, false, make(chan dispatcher.TableSpanStatusWithSeq, 1), - make(chan *heartbeatpb.TableSpanBlockStatus, 1), + 1, make(chan error, 1), ) d := dispatcher.NewEventDispatcher( @@ -141,7 +141,7 @@ func createTestManager(t *testing.T) *DispatcherManager { &defaultAtomicity, false, make(chan dispatcher.TableSpanStatusWithSeq, 8192), - make(chan *heartbeatpb.TableSpanBlockStatus, 1024*1024), + 1024*1024, make(chan error, 1), ) nodeID := node.NewID() diff --git a/downstreamadapter/dispatchermanager/heartbeat_collector.go b/downstreamadapter/dispatchermanager/heartbeat_collector.go index 99ef678b14..67417face8 100644 --- a/downstreamadapter/dispatchermanager/heartbeat_collector.go +++ b/downstreamadapter/dispatchermanager/heartbeat_collector.go @@ -248,6 +248,7 @@ func (c *HeartBeatCollector) sendBlockStatusMessages(ctx context.Context) error messaging.MaintainerManagerTopic, blockStatusRequestWithTargetID.Request, )) + c.blockStatusReqQueue.OnSendComplete(blockStatusRequestWithTargetID) if err != nil { log.Error("failed to send block status request message", zap.Error(err)) } diff --git a/downstreamadapter/dispatchermanager/heartbeat_queue.go b/downstreamadapter/dispatchermanager/heartbeat_queue.go index e93b59f401..6ceae27f48 100644 --- a/downstreamadapter/dispatchermanager/heartbeat_queue.go +++ b/downstreamadapter/dispatchermanager/heartbeat_queue.go @@ -15,8 +15,10 @@ package dispatchermanager import ( "context" + "sync" "github.com/pingcap/ticdc/heartbeatpb" + "github.com/pingcap/ticdc/pkg/common" "github.com/pingcap/ticdc/pkg/metrics" "github.com/pingcap/ticdc/pkg/node" ) @@ -62,15 +64,30 @@ type BlockStatusRequestWithTargetID struct { // BlockStatusRequestQueue is a channel for all event dispatcher managers to send block status requests to HeartBeatCollector type BlockStatusRequestQueue struct { queue chan *BlockStatusRequestWithTargetID + + mu sync.Mutex + requestDoneKeys map[*BlockStatusRequestWithTargetID][]blockStatusRequestDedupeKey + queuedDone map[blockStatusRequestDedupeKey]struct{} + inFlightDone map[blockStatusRequestDedupeKey]struct{} } func NewBlockStatusRequestQueue() *BlockStatusRequestQueue { return &BlockStatusRequestQueue{ - queue: make(chan *BlockStatusRequestWithTargetID, 10000), + queue: make(chan *BlockStatusRequestWithTargetID, 10000), + requestDoneKeys: make(map[*BlockStatusRequestWithTargetID][]blockStatusRequestDedupeKey), + queuedDone: make(map[blockStatusRequestDedupeKey]struct{}), + inFlightDone: make(map[blockStatusRequestDedupeKey]struct{}), } } func (q *BlockStatusRequestQueue) Enqueue(request *BlockStatusRequestWithTargetID) { + if request == nil || request.Request == nil { + return + } + if !q.trackPendingDone(request) { + metrics.HeartbeatCollectorBlockStatusRequestQueueLenGauge.Set(float64(len(q.queue))) + return + } q.queue <- request metrics.HeartbeatCollectorBlockStatusRequestQueueLenGauge.Set(float64(len(q.queue))) } @@ -80,11 +97,89 @@ func (q *BlockStatusRequestQueue) Dequeue(ctx context.Context) *BlockStatusReque case <-ctx.Done(): return nil case request := <-q.queue: + q.markInFlight(request) metrics.HeartbeatCollectorBlockStatusRequestQueueLenGauge.Set(float64(len(q.queue))) return request } } +func (q *BlockStatusRequestQueue) OnSendComplete(request *BlockStatusRequestWithTargetID) { + if request == nil { + return + } + + q.mu.Lock() + defer q.mu.Unlock() + for _, key := range q.requestDoneKeys[request] { + delete(q.inFlightDone, key) + } + delete(q.requestDoneKeys, request) +} + func (q *BlockStatusRequestQueue) Close() { close(q.queue) } + +type blockStatusRequestDedupeKey struct { + targetID node.ID + dispatcherID common.DispatcherID + blockTs uint64 + mode int64 + isSyncPoint bool +} + +func (q *BlockStatusRequestQueue) trackPendingDone(request *BlockStatusRequestWithTargetID) bool { + statuses := request.Request.BlockStatuses + filtered := statuses[:0] + doneKeys := make([]blockStatusRequestDedupeKey, 0) + + q.mu.Lock() + defer q.mu.Unlock() + + for _, status := range statuses { + if !isDoneRequestStatus(status) { + filtered = append(filtered, status) + continue + } + + key := blockStatusRequestDedupeKey{ + targetID: request.TargetID, + dispatcherID: common.NewDispatcherIDFromPB(status.ID), + blockTs: status.State.BlockTs, + mode: status.Mode, + isSyncPoint: status.State.IsSyncPoint, + } + if _, ok := q.queuedDone[key]; ok { + continue + } + if _, ok := q.inFlightDone[key]; ok { + continue + } + + filtered = append(filtered, status) + q.queuedDone[key] = struct{}{} + doneKeys = append(doneKeys, key) + } + + request.Request.BlockStatuses = filtered + if len(doneKeys) > 0 { + q.requestDoneKeys[request] = doneKeys + } + return len(filtered) > 0 +} + +func (q *BlockStatusRequestQueue) markInFlight(request *BlockStatusRequestWithTargetID) { + q.mu.Lock() + defer q.mu.Unlock() + for _, key := range q.requestDoneKeys[request] { + delete(q.queuedDone, key) + q.inFlightDone[key] = struct{}{} + } +} + +func isDoneRequestStatus(status *heartbeatpb.TableSpanBlockStatus) bool { + return status != nil && + status.State != nil && + status.State.IsBlocked && + status.State.Stage == heartbeatpb.BlockStage_DONE +} diff --git a/downstreamadapter/dispatchermanager/heartbeat_queue_test.go b/downstreamadapter/dispatchermanager/heartbeat_queue_test.go new file mode 100644 index 0000000000..942ceb1c33 --- /dev/null +++ b/downstreamadapter/dispatchermanager/heartbeat_queue_test.go @@ -0,0 +1,165 @@ +// Copyright 2026 PingCAP, Inc. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// See the License for the specific language governing permissions and +// limitations under the License. + +package dispatchermanager + +import ( + "context" + "testing" + "time" + + "github.com/pingcap/ticdc/heartbeatpb" + "github.com/pingcap/ticdc/pkg/common" + "github.com/pingcap/ticdc/pkg/node" + "github.com/stretchr/testify/require" +) + +func TestBlockStatusRequestQueueDeduplicatesQueuedAndInFlightDone(t *testing.T) { + queue := NewBlockStatusRequestQueue() + targetID := node.NewID() + dispatcherID := common.NewDispatcherID() + + first := newDoneBlockStatusRequest(targetID, dispatcherID, 100) + second := newDoneBlockStatusRequest(targetID, dispatcherID, 100) + + queue.Enqueue(first) + queue.Enqueue(second) + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + dequeued := queue.Dequeue(ctx) + require.Same(t, first, dequeued) + + shortCtx, shortCancel := context.WithTimeout(context.Background(), 20*time.Millisecond) + defer shortCancel() + require.Nil(t, queue.Dequeue(shortCtx)) + + third := newDoneBlockStatusRequest(targetID, dispatcherID, 100) + queue.Enqueue(third) + + shortCtx2, shortCancel2 := context.WithTimeout(context.Background(), 20*time.Millisecond) + defer shortCancel2() + require.Nil(t, queue.Dequeue(shortCtx2)) + + queue.OnSendComplete(dequeued) + + fourth := newDoneBlockStatusRequest(targetID, dispatcherID, 100) + queue.Enqueue(fourth) + + ctx2, cancel2 := context.WithTimeout(context.Background(), time.Second) + defer cancel2() + require.Same(t, fourth, queue.Dequeue(ctx2)) +} + +func TestBlockStatusRequestQueueDoesNotDeduplicateWaiting(t *testing.T) { + queue := NewBlockStatusRequestQueue() + targetID := node.NewID() + dispatcherID := common.NewDispatcherID() + + first := &BlockStatusRequestWithTargetID{ + TargetID: targetID, + Request: &heartbeatpb.BlockStatusRequest{ + BlockStatuses: []*heartbeatpb.TableSpanBlockStatus{ + { + ID: dispatcherID.ToPB(), + State: &heartbeatpb.State{ + IsBlocked: true, + BlockTs: 101, + Stage: heartbeatpb.BlockStage_WAITING, + }, + Mode: common.DefaultMode, + }, + }, + Mode: common.DefaultMode, + }, + } + second := &BlockStatusRequestWithTargetID{ + TargetID: targetID, + Request: &heartbeatpb.BlockStatusRequest{ + BlockStatuses: []*heartbeatpb.TableSpanBlockStatus{ + { + ID: dispatcherID.ToPB(), + State: &heartbeatpb.State{ + IsBlocked: true, + BlockTs: 101, + Stage: heartbeatpb.BlockStage_WAITING, + }, + Mode: common.DefaultMode, + }, + }, + Mode: common.DefaultMode, + }, + } + + queue.Enqueue(first) + queue.Enqueue(second) + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + require.Same(t, first, queue.Dequeue(ctx)) + + ctx2, cancel2 := context.WithTimeout(context.Background(), time.Second) + defer cancel2() + require.Same(t, second, queue.Dequeue(ctx2)) +} + +func TestBlockStatusRequestQueueKeepsDistinctDoneKeys(t *testing.T) { + queue := NewBlockStatusRequestQueue() + targetID := node.NewID() + dispatcherID := common.NewDispatcherID() + + defaultDone := newDoneBlockStatusRequest(targetID, dispatcherID, 200) + syncPointDone := newDoneBlockStatusRequest(targetID, dispatcherID, 200) + syncPointDone.Request.BlockStatuses[0].State.IsSyncPoint = true + redoDone := newDoneBlockStatusRequest(targetID, dispatcherID, 200) + redoDone.Request.BlockStatuses[0].Mode = common.RedoMode + redoDone.Request.Mode = common.RedoMode + + queue.Enqueue(defaultDone) + queue.Enqueue(syncPointDone) + queue.Enqueue(redoDone) + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + require.Same(t, defaultDone, queue.Dequeue(ctx)) + queue.OnSendComplete(defaultDone) + + ctx2, cancel2 := context.WithTimeout(context.Background(), time.Second) + defer cancel2() + require.Same(t, syncPointDone, queue.Dequeue(ctx2)) + queue.OnSendComplete(syncPointDone) + + ctx3, cancel3 := context.WithTimeout(context.Background(), time.Second) + defer cancel3() + require.Same(t, redoDone, queue.Dequeue(ctx3)) +} + +func newDoneBlockStatusRequest(targetID node.ID, dispatcherID common.DispatcherID, blockTs uint64) *BlockStatusRequestWithTargetID { + return &BlockStatusRequestWithTargetID{ + TargetID: targetID, + Request: &heartbeatpb.BlockStatusRequest{ + BlockStatuses: []*heartbeatpb.TableSpanBlockStatus{ + { + ID: dispatcherID.ToPB(), + State: &heartbeatpb.State{ + IsBlocked: true, + BlockTs: blockTs, + Stage: heartbeatpb.BlockStage_DONE, + }, + Mode: common.DefaultMode, + }, + }, + Mode: common.DefaultMode, + }, + } +} From f17b2c332263f71c2ec57c92efe16b504dc5444a Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Tue, 14 Apr 2026 09:13:49 +0800 Subject: [PATCH 05/17] remove verbose log Signed-off-by: dongmen <414110582@qq.com> --- downstreamadapter/dispatcher/basic_dispatcher.go | 12 +++++++----- 1 file changed, 7 insertions(+), 5 deletions(-) diff --git a/downstreamadapter/dispatcher/basic_dispatcher.go b/downstreamadapter/dispatcher/basic_dispatcher.go index 6771e343b3..04f05e16cd 100644 --- a/downstreamadapter/dispatcher/basic_dispatcher.go +++ b/downstreamadapter/dispatcher/basic_dispatcher.go @@ -749,11 +749,13 @@ func (d *BasicDispatcher) handleEvents(dispatcherEvents []DispatcherEvent, wakeC // and return await=true. // The status path will be waked up after the action finishes. func (d *BasicDispatcher) HandleDispatcherStatus(dispatcherStatus *heartbeatpb.DispatcherStatus) (await bool) { - log.Debug("dispatcher handle dispatcher status", - zap.String("dispatcherStatus", common.FormatDispatcherStatus(dispatcherStatus)), - zap.Stringer("dispatcher", d.id), - zap.Any("action", dispatcherStatus.GetAction()), - zap.Any("ack", dispatcherStatus.GetAck())) + if log.GetLevel() <= zapcore.DebugLevel { + log.Debug("dispatcher handle dispatcher status", + zap.String("dispatcherStatus", common.FormatDispatcherStatus(dispatcherStatus)), + zap.Stringer("dispatcher", d.id), + zap.Any("action", dispatcherStatus.GetAction()), + zap.Any("ack", dispatcherStatus.GetAck())) + } // Step1: deal with the ack info ack := dispatcherStatus.GetAck() From 0a9d4e8051f12835200b9a52e4596d8db48372dd Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Tue, 14 Apr 2026 11:02:58 +0800 Subject: [PATCH 06/17] dispatahcer: fix stuck Signed-off-by: dongmen <414110582@qq.com> --- downstreamadapter/dispatcher/basic_dispatcher.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/downstreamadapter/dispatcher/basic_dispatcher.go b/downstreamadapter/dispatcher/basic_dispatcher.go index c4fd329996..51cf5b32cb 100644 --- a/downstreamadapter/dispatcher/basic_dispatcher.go +++ b/downstreamadapter/dispatcher/basic_dispatcher.go @@ -463,12 +463,12 @@ func (d *BasicDispatcher) ensureTableModeCompatibility(tableInfo *common.TableIn func (d *BasicDispatcher) isFirstEvent(event commonEvent.Event) bool { if d.componentStatus.Get() == heartbeatpb.ComponentState_Initializing { switch event.GetType() { - case commonEvent.TypeResolvedEvent, commonEvent.TypeDMLEvent, commonEvent.TypeDDLEvent: + case commonEvent.TypeDMLEvent, commonEvent.TypeDDLEvent: if event.GetCommitTs() > d.startTs { return true } // the first syncpoint event can be same as startTs - case commonEvent.TypeSyncPointEvent: + case commonEvent.TypeResolvedEvent, commonEvent.TypeSyncPointEvent: if event.GetCommitTs() >= d.startTs { return true } From afcf43fc87973e06863c11ccdd7968a66019891d Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Tue, 14 Apr 2026 14:29:17 +0800 Subject: [PATCH 07/17] dispatahcer: fix stuck 2 Signed-off-by: dongmen <414110582@qq.com> --- pkg/eventservice/event_broker.go | 14 ++++++++++ pkg/eventservice/event_broker_test.go | 38 +++++++++++++++++++++++++++ 2 files changed, 52 insertions(+) diff --git a/pkg/eventservice/event_broker.go b/pkg/eventservice/event_broker.go index d8c6eb7b0b..0130d8ce18 100644 --- a/pkg/eventservice/event_broker.go +++ b/pkg/eventservice/event_broker.go @@ -524,6 +524,20 @@ func (c *eventBroker) getScanTaskDataRange(task scanTask) (bool, common.DataRang localScanMaxTs := oracle.GoTimeToTS(oracle.GetTimeFromTS(dataRange.CommitTsStart).Add(interval)) dataRange.CommitTsEnd = min(commitTsEndBeforeWindow, localScanMaxTs) dataRange.CommitTsEnd = c.capCommitTsEndByCheckpoint(task, dataRange.CommitTsEnd) + if dataRange.CommitTsEnd <= dataRange.CommitTsStart { + bypassEndTs := min(commitTsEndBeforeWindow, localScanMaxTs) + bypassEndTs = min(bypassEndTs, ddlState.MaxEventCommitTs) + if bypassEndTs > dataRange.CommitTsStart { + dataRange.CommitTsEnd = bypassEndTs + log.Info("scan window local advance bypass checkpoint cap due to pending ddl", + zap.Stringer("changefeedID", task.changefeedStat.changefeedID), + zap.Stringer("dispatcherID", task.id), + zap.Uint64("startTs", dataRange.CommitTsStart), + zap.Uint64("checkpointTs", task.checkpointTs.Load()), + zap.Uint64("ddlCommitTs", ddlState.MaxEventCommitTs), + zap.Uint64("newEndTs", dataRange.CommitTsEnd)) + } + } if dataRange.CommitTsEnd > dataRange.CommitTsStart { log.Info("scan window local advance due to pending ddl", zap.Stringer("changefeedID", task.changefeedStat.changefeedID), diff --git a/pkg/eventservice/event_broker_test.go b/pkg/eventservice/event_broker_test.go index 95e483f57a..1c1a139a9b 100644 --- a/pkg/eventservice/event_broker_test.go +++ b/pkg/eventservice/event_broker_test.go @@ -425,6 +425,44 @@ func TestGetScanTaskDataRangePendingDDLWithCheckpointCapCanAdvance(t *testing.T) require.Equal(t, ts102, dataRange.CommitTsEnd) } +func TestGetScanTaskDataRangePendingDDLBypassesCheckpointCapLock(t *testing.T) { + broker, _, ss, _ := newEventBrokerForTest() + broker.close() + + base := time.Unix(0, 0) + ts100 := oracle.GoTimeToTS(base.Add(100 * time.Second)) + ts102 := oracle.GoTimeToTS(base.Add(102 * time.Second)) + ts103 := oracle.GoTimeToTS(base.Add(103 * time.Second)) + ts110 := oracle.GoTimeToTS(base.Add(110 * time.Second)) + + info := newMockDispatcherInfoForTest(t) + info.epoch = 1 + info.enableSyncPoint = true + info.syncPointInterval = time.Second + info.nextSyncPoint = ts110 + + changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) + changefeedStatus.scanInterval.Store(int64(time.Second)) + changefeedStatus.minSentTs.Store(ts100) + + disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) + disp.seq.Store(1) + disp.checkpointTs.Store(ts100) + disp.sentResolvedTs.Store(ts102) + disp.lastScannedCommitTs.Store(ts102) + disp.lastScannedStartTs.Store(ts102 - 1) + disp.receivedResolvedTs.Store(ts110) + disp.eventStoreCommitTs.Store(ts103) + + ss.resolvedTs = ts110 + ss.maxDDLCommitTs = ts103 + + needScan, dataRange := broker.getScanTaskDataRange(disp) + require.True(t, needScan) + require.Equal(t, ts102, dataRange.CommitTsStart) + require.Equal(t, ts103, dataRange.CommitTsEnd) +} + func TestEmitSyncPointEventIfNeededSuppressesWhenLagging(t *testing.T) { broker, _, _, _ := newEventBrokerForTest() broker.close() From 956d0fe0589bba893ed38b3a950f1fd0d3598b57 Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Tue, 14 Apr 2026 15:34:00 +0800 Subject: [PATCH 08/17] eventBroker: use received resolvedTs Signed-off-by: dongmen <414110582@qq.com> --- pkg/eventservice/event_broker.go | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/pkg/eventservice/event_broker.go b/pkg/eventservice/event_broker.go index 0130d8ce18..bda65ee5ac 100644 --- a/pkg/eventservice/event_broker.go +++ b/pkg/eventservice/event_broker.go @@ -676,9 +676,9 @@ func (c *eventBroker) shouldSuppressSyncPointEmission(d *dispatcherStat) bool { return false } - sentResolvedTs := d.sentResolvedTs.Load() + receivedResolvedTs := d.receivedResolvedTs.Load() checkpointTs := d.checkpointTs.Load() - lag := syncPointLagDuration(sentResolvedTs, checkpointTs) + lag := syncPointLagDuration(receivedResolvedTs, checkpointTs) metrics.EventServiceSyncPointLagGaugeVec.WithLabelValues(d.changefeedStat.changefeedID.String()).Set(lag.Seconds()) if d.syncPointSendSuppressed.Load() { @@ -687,7 +687,7 @@ func (c *eventBroker) shouldSuppressSyncPointEmission(d *dispatcherStat) bool { log.Info("syncpoint emission resumed", zap.Stringer("changefeedID", d.changefeedStat.changefeedID), zap.Stringer("dispatcherID", d.id), - zap.Uint64("sentResolvedTs", sentResolvedTs), + zap.Uint64("receivedResolvedTs", receivedResolvedTs), zap.Uint64("checkpointTs", checkpointTs), zap.Duration("lag", lag), zap.Duration("resumeThreshold", c.syncPointLagResumeThreshold)) @@ -702,7 +702,7 @@ func (c *eventBroker) shouldSuppressSyncPointEmission(d *dispatcherStat) bool { log.Info("syncpoint emission suppressed due to lag", zap.Stringer("changefeedID", d.changefeedStat.changefeedID), zap.Stringer("dispatcherID", d.id), - zap.Uint64("sentResolvedTs", sentResolvedTs), + zap.Uint64("sentResolvedTs", receivedResolvedTs), zap.Uint64("checkpointTs", checkpointTs), zap.Duration("lag", lag), zap.Duration("suppressThreshold", c.syncPointLagSuppressThreshold), From cd4c09ff9e31522be8e2d892c9932ee8288ad07a Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Tue, 14 Apr 2026 18:58:13 +0800 Subject: [PATCH 09/17] eventBroker: add debug log Signed-off-by: dongmen <414110582@qq.com> --- pkg/eventservice/metrics_collector.go | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-) diff --git a/pkg/eventservice/metrics_collector.go b/pkg/eventservice/metrics_collector.go index 0952ed9260..47d27215ad 100644 --- a/pkg/eventservice/metrics_collector.go +++ b/pkg/eventservice/metrics_collector.go @@ -132,6 +132,8 @@ func (d *dispatcherHeapItem) LessThan(other *dispatcherHeapItem) bool { type metricsSnapshot struct { receivedMinResolvedTs uint64 sentMinResolvedTs uint64 + receivedMinDispatcher *dispatcherStat + sentMinDispatcher *dispatcherStat dispatcherCount int pendingTaskCount int slowestDispatchers []*dispatcherStat // top 10 dispatchers with slowest checkpointTs @@ -222,11 +224,13 @@ func (mc *metricsCollector) collectDispatcherMetrics(snapshot *metricsSnapshot) resolvedTs := dispatcher.receivedResolvedTs.Load() if resolvedTs < snapshot.receivedMinResolvedTs { snapshot.receivedMinResolvedTs = resolvedTs + snapshot.receivedMinDispatcher = dispatcher } watermark := dispatcher.sentResolvedTs.Load() if watermark < snapshot.sentMinResolvedTs { snapshot.sentMinResolvedTs = watermark + snapshot.sentMinDispatcher = dispatcher } // Maintain a min-heap of size 10 for the slowest dispatchers @@ -301,7 +305,9 @@ func (mc *metricsCollector) updateMetricsFromSnapshot(snapshot *metricsSnapshot) // logSlowDispatchers logs warnings for dispatchers that are too slow func (mc *metricsCollector) logSlowDispatchers(snapshot *metricsSnapshot) { - if len(snapshot.slowestDispatchers) == 0 { + if len(snapshot.slowestDispatchers) == 0 && + snapshot.receivedMinDispatcher == nil && + snapshot.sentMinDispatcher == nil { return } @@ -311,6 +317,16 @@ func (mc *metricsCollector) logSlowDispatchers(snapshot *metricsSnapshot) { mc.lastLogSlowDispatchersTime = time.Now() + if snapshot.receivedMinDispatcher != nil && snapshot.sentMinDispatcher != nil { + log.Warn("event service min resolved ts snapshot", + zap.Stringer("receivedMinDispatcherID", snapshot.receivedMinDispatcher.id), + zap.Stringer("receivedMinChangefeedID", snapshot.receivedMinDispatcher.changefeedStat.changefeedID), + zap.Uint64("receivedMinResolvedTs", snapshot.receivedMinResolvedTs), + zap.Stringer("sentMinDispatcherID", snapshot.sentMinDispatcher.id), + zap.Stringer("sentMinChangefeedID", snapshot.sentMinDispatcher.changefeedStat.changefeedID), + zap.Uint64("sentMinResolvedTs", snapshot.sentMinResolvedTs)) + } + for _, dispatcher := range snapshot.slowestDispatchers { checkpointTs := dispatcher.checkpointTs.Load() lag := time.Since(oracle.GetTimeFromTS(checkpointTs)) From 55d6b26ca75f1b89927de8f8f1af1e46568c4cf2 Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Wed, 15 Apr 2026 11:50:56 +0800 Subject: [PATCH 10/17] eventBroker: allow dispatcher advence when there is a ddl Signed-off-by: dongmen <414110582@qq.com> --- pkg/eventservice/event_broker.go | 40 ++++++++++++++++++-------------- 1 file changed, 22 insertions(+), 18 deletions(-) diff --git a/pkg/eventservice/event_broker.go b/pkg/eventservice/event_broker.go index bda65ee5ac..25b1f747f2 100644 --- a/pkg/eventservice/event_broker.go +++ b/pkg/eventservice/event_broker.go @@ -385,7 +385,7 @@ func (c *eventBroker) tickTableTriggerDispatchers(ctx context.Context) error { return true } stat.receivedResolvedTs.Store(endTs) - boundedEndTs := c.capCommitTsEndByCheckpoint(stat, endTs) + boundedEndTs := c.capCommitTsEndBySyncPoint(stat, endTs) for _, e := range ddlEvents { if e.FinishedTs > boundedEndTs { break @@ -440,7 +440,8 @@ func (c *eventBroker) logUninitializedDispatchers(ctx context.Context) error { } } -func (c *eventBroker) capCommitTsEndByCheckpoint(task scanTask, commitTsEnd uint64) uint64 { +// capCommitTsEndBySyncPoint caps the commitTsEnd by the checkpoint bound determined by the sync point configuration. +func (c *eventBroker) capCommitTsEndBySyncPoint(task scanTask, commitTsEnd uint64) uint64 { if !task.enableSyncPoint || task.syncPointInterval <= 0 || c.syncPointCheckpointCapMultiplier == 0 { return commitTsEnd } @@ -511,7 +512,7 @@ func (c *eventBroker) getScanTaskDataRange(task scanTask) (bool, common.DataRang ) } } - dataRange.CommitTsEnd = c.capCommitTsEndByCheckpoint(task, dataRange.CommitTsEnd) + dataRange.CommitTsEnd = c.capCommitTsEndBySyncPoint(task, dataRange.CommitTsEnd) if dataRange.CommitTsEnd <= dataRange.CommitTsStart && hasPendingDDLEventInCurrentRange { // Global scan window base can be pinned by other lagging dispatchers. @@ -523,21 +524,24 @@ func (c *eventBroker) getScanTaskDataRange(task scanTask) (bool, common.DataRang } localScanMaxTs := oracle.GoTimeToTS(oracle.GetTimeFromTS(dataRange.CommitTsStart).Add(interval)) dataRange.CommitTsEnd = min(commitTsEndBeforeWindow, localScanMaxTs) - dataRange.CommitTsEnd = c.capCommitTsEndByCheckpoint(task, dataRange.CommitTsEnd) - if dataRange.CommitTsEnd <= dataRange.CommitTsStart { - bypassEndTs := min(commitTsEndBeforeWindow, localScanMaxTs) - bypassEndTs = min(bypassEndTs, ddlState.MaxEventCommitTs) - if bypassEndTs > dataRange.CommitTsStart { - dataRange.CommitTsEnd = bypassEndTs - log.Info("scan window local advance bypass checkpoint cap due to pending ddl", - zap.Stringer("changefeedID", task.changefeedStat.changefeedID), - zap.Stringer("dispatcherID", task.id), - zap.Uint64("startTs", dataRange.CommitTsStart), - zap.Uint64("checkpointTs", task.checkpointTs.Load()), - zap.Uint64("ddlCommitTs", ddlState.MaxEventCommitTs), - zap.Uint64("newEndTs", dataRange.CommitTsEnd)) - } - } + + // Don't cap by syncpoint again when in comes to local advance. + //dataRange.CommitTsEnd = c.capCommitTsEndBySyncPoint(task, dataRange.CommitTsEnd) + // if dataRange.CommitTsEnd <= dataRange.CommitTsStart { + // bypassEndTs := min(commitTsEndBeforeWindow, localScanMaxTs) + // bypassEndTs = min(bypassEndTs, ddlState.MaxEventCommitTs) + // if bypassEndTs > dataRange.CommitTsStart { + // dataRange.CommitTsEnd = bypassEndTs + // log.Info("scan window local advance bypass checkpoint cap due to pending ddl", + // zap.Stringer("changefeedID", task.changefeedStat.changefeedID), + // zap.Stringer("dispatcherID", task.id), + // zap.Uint64("startTs", dataRange.CommitTsStart), + // zap.Uint64("checkpointTs", task.checkpointTs.Load()), + // zap.Uint64("ddlCommitTs", ddlState.MaxEventCommitTs), + // zap.Uint64("newEndTs", dataRange.CommitTsEnd)) + // } + // } + if dataRange.CommitTsEnd > dataRange.CommitTsStart { log.Info("scan window local advance due to pending ddl", zap.Stringer("changefeedID", task.changefeedStat.changefeedID), From d5f8123cae396c0a10188b098d61b94c797a54ec Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Wed, 15 Apr 2026 13:43:16 +0800 Subject: [PATCH 11/17] eventBroker: add log Signed-off-by: dongmen <414110582@qq.com> --- pkg/eventservice/event_broker.go | 14 ++++++++------ 1 file changed, 8 insertions(+), 6 deletions(-) diff --git a/pkg/eventservice/event_broker.go b/pkg/eventservice/event_broker.go index 25b1f747f2..00e19be1fe 100644 --- a/pkg/eventservice/event_broker.go +++ b/pkg/eventservice/event_broker.go @@ -324,6 +324,7 @@ func (c *eventBroker) sendResolvedTs(d *dispatcherStat, watermark uint64) { resolvedEvent := newWrapResolvedEvent(remoteID, re) c.getMessageCh(d.messageWorkerIndex, common.IsRedoMode(d.info.GetMode())) <- resolvedEvent d.updateSentResolvedTs(watermark) + log.Debug("send resolvedTs", zap.Uint64("resolvedTs", watermark), zap.String("dispatcher", d.id.String())) updateMetricEventServiceSendResolvedTsCount(d.info.GetMode()) } @@ -385,17 +386,15 @@ func (c *eventBroker) tickTableTriggerDispatchers(ctx context.Context) error { return true } stat.receivedResolvedTs.Store(endTs) - boundedEndTs := c.capCommitTsEndBySyncPoint(stat, endTs) + //boundedEndTs := c.capCommitTsEndBySyncPoint(stat, endTs) for _, e := range ddlEvents { - if e.FinishedTs > boundedEndTs { - break - } ep := &e c.sendDDL(ctx, remoteID, ep, stat) } - if boundedEndTs > startTs { + + if endTs > startTs { // After all the events are sent, we send the watermark to the dispatcher. - c.sendResolvedTs(stat, boundedEndTs) + c.sendResolvedTs(stat, endTs) } else { // If there is no new ddl event, we still need to send a signal resolved-ts event to keep downstream responsive, // but do not advance the watermark here. @@ -442,6 +441,9 @@ func (c *eventBroker) logUninitializedDispatchers(ctx context.Context) error { // capCommitTsEndBySyncPoint caps the commitTsEnd by the checkpoint bound determined by the sync point configuration. func (c *eventBroker) capCommitTsEndBySyncPoint(task scanTask, commitTsEnd uint64) uint64 { + + return commitTsEnd + if !task.enableSyncPoint || task.syncPointInterval <= 0 || c.syncPointCheckpointCapMultiplier == 0 { return commitTsEnd } From e4432d916924b777584aa4f0dbdecf8127888f91 Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Thu, 16 Apr 2026 14:56:04 +0800 Subject: [PATCH 12/17] dedupe waitting Signed-off-by: dongmen <414110582@qq.com> --- .../dispatcher/basic_dispatcher_info.go | 2 +- .../dispatcher/block_status_buffer.go | 73 +++++++++++---- .../dispatcher/block_status_buffer_test.go | 61 +++++++++++++ .../dispatchermanager/heartbeat_queue.go | 61 ++++++++----- .../dispatchermanager/heartbeat_queue_test.go | 91 ++++++++++++++++++- 5 files changed, 242 insertions(+), 46 deletions(-) diff --git a/downstreamadapter/dispatcher/basic_dispatcher_info.go b/downstreamadapter/dispatcher/basic_dispatcher_info.go index 161d3eb58c..ee71078891 100644 --- a/downstreamadapter/dispatcher/basic_dispatcher_info.go +++ b/downstreamadapter/dispatcher/basic_dispatcher_info.go @@ -60,7 +60,7 @@ type SharedInfo struct { // and push to heartbeatRequestQueue statusesChan chan TableSpanStatusWithSeq // blockStatusBuffer keeps block statuses for the dispatcher manager. - // Identical DONE statuses are coalesced while pending to reduce local memory amplification. + // Identical WAITING and DONE statuses are coalesced while pending to reduce local memory amplification. blockStatusBuffer *BlockStatusBuffer // blockExecutor is used to execute block events such as DDL and sync point events asynchronously diff --git a/downstreamadapter/dispatcher/block_status_buffer.go b/downstreamadapter/dispatcher/block_status_buffer.go index 894e4dc193..434ada5484 100644 --- a/downstreamadapter/dispatcher/block_status_buffer.go +++ b/downstreamadapter/dispatcher/block_status_buffer.go @@ -21,7 +21,7 @@ import ( "github.com/pingcap/ticdc/pkg/common" ) -type doneBlockStatusKey struct { +type blockStatusKey struct { dispatcherID common.DispatcherID blockTs uint64 mode int64 @@ -30,29 +30,31 @@ type doneBlockStatusKey struct { type blockStatusQueueEntry struct { status *heartbeatpb.TableSpanBlockStatus - doneKey *doneBlockStatusKey + doneKey *blockStatusKey } -// BlockStatusBuffer keeps block statuses ordered while coalescing identical DONE -// statuses that are still pending locally. Non-DONE statuses keep the original -// protobuf object and ordering. +// BlockStatusBuffer keeps block statuses ordered while coalescing identical +// WAITING and DONE statuses that are still pending locally. Other statuses keep +// the original protobuf object and ordering. type BlockStatusBuffer struct { queue chan blockStatusQueueEntry - mu sync.Mutex - pendingDone map[doneBlockStatusKey]struct{} + mu sync.Mutex + pendingDone map[blockStatusKey]struct{} + pendingWaiting map[blockStatusKey]struct{} } // NewBlockStatusBuffer creates a bounded local mailbox for dispatcher block // statuses. The buffer keeps enqueue order while coalescing identical pending -// DONE statuses before protobuf materialization. +// WAITING and DONE statuses before protobuf materialization. func NewBlockStatusBuffer(size int) *BlockStatusBuffer { if size <= 0 { size = 1 } return &BlockStatusBuffer{ - queue: make(chan blockStatusQueueEntry, size), - pendingDone: make(map[doneBlockStatusKey]struct{}), + queue: make(chan blockStatusQueueEntry, size), + pendingDone: make(map[blockStatusKey]struct{}), + pendingWaiting: make(map[blockStatusKey]struct{}), } } @@ -60,17 +62,20 @@ func (b *BlockStatusBuffer) Offer(status *heartbeatpb.TableSpanBlockStatus) { if status == nil { return } + if isWaitingBlockStatus(status) { + key := newBlockStatusKey(status) + if !b.reserveWaiting(key) { + return + } + b.queue <- blockStatusQueueEntry{status: status} + return + } if !isDoneBlockStatus(status) { b.queue <- blockStatusQueueEntry{status: status} return } - key := doneBlockStatusKey{ - dispatcherID: common.NewDispatcherIDFromPB(status.ID), - blockTs: status.State.BlockTs, - mode: status.Mode, - isSyncPoint: status.State.IsSyncPoint, - } + key := newBlockStatusKey(status) if !b.reserveDone(key) { return } @@ -83,7 +88,7 @@ func (b *BlockStatusBuffer) OfferDone( isSyncPoint bool, mode int64, ) { - key := doneBlockStatusKey{ + key := blockStatusKey{ dispatcherID: dispatcherID, blockTs: blockTs, mode: mode, @@ -117,7 +122,17 @@ func (b *BlockStatusBuffer) Len() int { return len(b.queue) } -func (b *BlockStatusBuffer) reserveDone(key doneBlockStatusKey) bool { +func (b *BlockStatusBuffer) reserveWaiting(key blockStatusKey) bool { + b.mu.Lock() + defer b.mu.Unlock() + if _, ok := b.pendingWaiting[key]; ok { + return false + } + b.pendingWaiting[key] = struct{}{} + return true +} + +func (b *BlockStatusBuffer) reserveDone(key blockStatusKey) bool { b.mu.Lock() defer b.mu.Unlock() if _, ok := b.pendingDone[key]; ok { @@ -129,6 +144,12 @@ func (b *BlockStatusBuffer) reserveDone(key doneBlockStatusKey) bool { func (b *BlockStatusBuffer) materialize(entry blockStatusQueueEntry) *heartbeatpb.TableSpanBlockStatus { if entry.status != nil { + if isWaitingBlockStatus(entry.status) { + key := newBlockStatusKey(entry.status) + b.mu.Lock() + delete(b.pendingWaiting, key) + b.mu.Unlock() + } return entry.status } @@ -149,6 +170,22 @@ func (b *BlockStatusBuffer) materialize(entry blockStatusQueueEntry) *heartbeatp } } +func newBlockStatusKey(status *heartbeatpb.TableSpanBlockStatus) blockStatusKey { + return blockStatusKey{ + dispatcherID: common.NewDispatcherIDFromPB(status.ID), + blockTs: status.State.BlockTs, + mode: status.Mode, + isSyncPoint: status.State.IsSyncPoint, + } +} + +func isWaitingBlockStatus(status *heartbeatpb.TableSpanBlockStatus) bool { + return status != nil && + status.State != nil && + status.State.IsBlocked && + status.State.Stage == heartbeatpb.BlockStage_WAITING +} + func isDoneBlockStatus(status *heartbeatpb.TableSpanBlockStatus) bool { return status != nil && status.State != nil && diff --git a/downstreamadapter/dispatcher/block_status_buffer_test.go b/downstreamadapter/dispatcher/block_status_buffer_test.go index 4dcce37d2e..021039bb81 100644 --- a/downstreamadapter/dispatcher/block_status_buffer_test.go +++ b/downstreamadapter/dispatcher/block_status_buffer_test.go @@ -46,6 +46,67 @@ func TestBlockStatusBufferDeduplicatesPendingDone(t *testing.T) { require.False(t, ok) } +func TestBlockStatusBufferDeduplicatesPendingWaiting(t *testing.T) { + buffer := NewBlockStatusBuffer(4) + dispatcherID := common.NewDispatcherID() + + waiting := &heartbeatpb.TableSpanBlockStatus{ + ID: dispatcherID.ToPB(), + State: &heartbeatpb.State{ + IsBlocked: true, + BlockTs: 150, + Stage: heartbeatpb.BlockStage_WAITING, + }, + Mode: common.DefaultMode, + } + + buffer.Offer(waiting) + buffer.Offer(waiting) + + require.Equal(t, 1, buffer.Len()) + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + msg := buffer.Take(ctx) + require.NotNil(t, msg) + require.Equal(t, heartbeatpb.BlockStage_WAITING, msg.State.Stage) + + _, ok := buffer.TryTake() + require.False(t, ok) +} + +func TestBlockStatusBufferAllowsWaitingAgainAfterTake(t *testing.T) { + buffer := NewBlockStatusBuffer(4) + dispatcherID := common.NewDispatcherID() + + waiting := &heartbeatpb.TableSpanBlockStatus{ + ID: dispatcherID.ToPB(), + State: &heartbeatpb.State{ + IsBlocked: true, + BlockTs: 180, + Stage: heartbeatpb.BlockStage_WAITING, + }, + Mode: common.DefaultMode, + } + + buffer.Offer(waiting) + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + first := buffer.Take(ctx) + require.NotNil(t, first) + require.Equal(t, heartbeatpb.BlockStage_WAITING, first.State.Stage) + + buffer.Offer(waiting) + + second := buffer.Take(ctx) + require.NotNil(t, second) + require.Equal(t, heartbeatpb.BlockStage_WAITING, second.State.Stage) + + _, ok := buffer.TryTake() + require.False(t, ok) +} + func TestBlockStatusBufferKeepsWaitingBeforeDone(t *testing.T) { buffer := NewBlockStatusBuffer(4) dispatcherID := common.NewDispatcherID() diff --git a/downstreamadapter/dispatchermanager/heartbeat_queue.go b/downstreamadapter/dispatchermanager/heartbeat_queue.go index 6ceae27f48..af4fe6b7c6 100644 --- a/downstreamadapter/dispatchermanager/heartbeat_queue.go +++ b/downstreamadapter/dispatchermanager/heartbeat_queue.go @@ -65,18 +65,18 @@ type BlockStatusRequestWithTargetID struct { type BlockStatusRequestQueue struct { queue chan *BlockStatusRequestWithTargetID - mu sync.Mutex - requestDoneKeys map[*BlockStatusRequestWithTargetID][]blockStatusRequestDedupeKey - queuedDone map[blockStatusRequestDedupeKey]struct{} - inFlightDone map[blockStatusRequestDedupeKey]struct{} + mu sync.Mutex + requestStatusKeys map[*BlockStatusRequestWithTargetID][]blockStatusRequestDedupeKey + queuedStatuses map[blockStatusRequestDedupeKey]struct{} + inFlightStatuses map[blockStatusRequestDedupeKey]struct{} } func NewBlockStatusRequestQueue() *BlockStatusRequestQueue { return &BlockStatusRequestQueue{ - queue: make(chan *BlockStatusRequestWithTargetID, 10000), - requestDoneKeys: make(map[*BlockStatusRequestWithTargetID][]blockStatusRequestDedupeKey), - queuedDone: make(map[blockStatusRequestDedupeKey]struct{}), - inFlightDone: make(map[blockStatusRequestDedupeKey]struct{}), + queue: make(chan *BlockStatusRequestWithTargetID, 10000), + requestStatusKeys: make(map[*BlockStatusRequestWithTargetID][]blockStatusRequestDedupeKey), + queuedStatuses: make(map[blockStatusRequestDedupeKey]struct{}), + inFlightStatuses: make(map[blockStatusRequestDedupeKey]struct{}), } } @@ -84,7 +84,7 @@ func (q *BlockStatusRequestQueue) Enqueue(request *BlockStatusRequestWithTargetI if request == nil || request.Request == nil { return } - if !q.trackPendingDone(request) { + if !q.trackPendingStatuses(request) { metrics.HeartbeatCollectorBlockStatusRequestQueueLenGauge.Set(float64(len(q.queue))) return } @@ -110,10 +110,10 @@ func (q *BlockStatusRequestQueue) OnSendComplete(request *BlockStatusRequestWith q.mu.Lock() defer q.mu.Unlock() - for _, key := range q.requestDoneKeys[request] { - delete(q.inFlightDone, key) + for _, key := range q.requestStatusKeys[request] { + delete(q.inFlightStatuses, key) } - delete(q.requestDoneKeys, request) + delete(q.requestStatusKeys, request) } func (q *BlockStatusRequestQueue) Close() { @@ -126,18 +126,19 @@ type blockStatusRequestDedupeKey struct { blockTs uint64 mode int64 isSyncPoint bool + stage heartbeatpb.BlockStage } -func (q *BlockStatusRequestQueue) trackPendingDone(request *BlockStatusRequestWithTargetID) bool { +func (q *BlockStatusRequestQueue) trackPendingStatuses(request *BlockStatusRequestWithTargetID) bool { statuses := request.Request.BlockStatuses filtered := statuses[:0] - doneKeys := make([]blockStatusRequestDedupeKey, 0) + statusKeys := make([]blockStatusRequestDedupeKey, 0) q.mu.Lock() defer q.mu.Unlock() for _, status := range statuses { - if !isDoneRequestStatus(status) { + if !shouldDeduplicateRequestStatus(status) { filtered = append(filtered, status) continue } @@ -148,22 +149,23 @@ func (q *BlockStatusRequestQueue) trackPendingDone(request *BlockStatusRequestWi blockTs: status.State.BlockTs, mode: status.Mode, isSyncPoint: status.State.IsSyncPoint, + stage: status.State.Stage, } - if _, ok := q.queuedDone[key]; ok { + if _, ok := q.queuedStatuses[key]; ok { continue } - if _, ok := q.inFlightDone[key]; ok { + if _, ok := q.inFlightStatuses[key]; ok { continue } filtered = append(filtered, status) - q.queuedDone[key] = struct{}{} - doneKeys = append(doneKeys, key) + q.queuedStatuses[key] = struct{}{} + statusKeys = append(statusKeys, key) } request.Request.BlockStatuses = filtered - if len(doneKeys) > 0 { - q.requestDoneKeys[request] = doneKeys + if len(statusKeys) > 0 { + q.requestStatusKeys[request] = statusKeys } return len(filtered) > 0 } @@ -171,12 +173,23 @@ func (q *BlockStatusRequestQueue) trackPendingDone(request *BlockStatusRequestWi func (q *BlockStatusRequestQueue) markInFlight(request *BlockStatusRequestWithTargetID) { q.mu.Lock() defer q.mu.Unlock() - for _, key := range q.requestDoneKeys[request] { - delete(q.queuedDone, key) - q.inFlightDone[key] = struct{}{} + for _, key := range q.requestStatusKeys[request] { + delete(q.queuedStatuses, key) + q.inFlightStatuses[key] = struct{}{} } } +func isWaitingRequestStatus(status *heartbeatpb.TableSpanBlockStatus) bool { + return status != nil && + status.State != nil && + status.State.IsBlocked && + status.State.Stage == heartbeatpb.BlockStage_WAITING +} + +func shouldDeduplicateRequestStatus(status *heartbeatpb.TableSpanBlockStatus) bool { + return isDoneRequestStatus(status) || isWaitingRequestStatus(status) +} + func isDoneRequestStatus(status *heartbeatpb.TableSpanBlockStatus) bool { return status != nil && status.State != nil && diff --git a/downstreamadapter/dispatchermanager/heartbeat_queue_test.go b/downstreamadapter/dispatchermanager/heartbeat_queue_test.go index 942ceb1c33..e639bb9216 100644 --- a/downstreamadapter/dispatchermanager/heartbeat_queue_test.go +++ b/downstreamadapter/dispatchermanager/heartbeat_queue_test.go @@ -61,7 +61,7 @@ func TestBlockStatusRequestQueueDeduplicatesQueuedAndInFlightDone(t *testing.T) require.Same(t, fourth, queue.Dequeue(ctx2)) } -func TestBlockStatusRequestQueueDoesNotDeduplicateWaiting(t *testing.T) { +func TestBlockStatusRequestQueueDeduplicatesQueuedAndInFlightWaiting(t *testing.T) { queue := NewBlockStatusRequestQueue() targetID := node.NewID() dispatcherID := common.NewDispatcherID() @@ -106,11 +106,60 @@ func TestBlockStatusRequestQueueDoesNotDeduplicateWaiting(t *testing.T) { ctx, cancel := context.WithTimeout(context.Background(), time.Second) defer cancel() - require.Same(t, first, queue.Dequeue(ctx)) + dequeued := queue.Dequeue(ctx) + require.Same(t, first, dequeued) + + shortCtx, shortCancel := context.WithTimeout(context.Background(), 20*time.Millisecond) + defer shortCancel() + require.Nil(t, queue.Dequeue(shortCtx)) + + third := &BlockStatusRequestWithTargetID{ + TargetID: targetID, + Request: &heartbeatpb.BlockStatusRequest{ + BlockStatuses: []*heartbeatpb.TableSpanBlockStatus{ + { + ID: dispatcherID.ToPB(), + State: &heartbeatpb.State{ + IsBlocked: true, + BlockTs: 101, + Stage: heartbeatpb.BlockStage_WAITING, + }, + Mode: common.DefaultMode, + }, + }, + Mode: common.DefaultMode, + }, + } + queue.Enqueue(third) + + shortCtx2, shortCancel2 := context.WithTimeout(context.Background(), 20*time.Millisecond) + defer shortCancel2() + require.Nil(t, queue.Dequeue(shortCtx2)) + + queue.OnSendComplete(dequeued) + + fourth := &BlockStatusRequestWithTargetID{ + TargetID: targetID, + Request: &heartbeatpb.BlockStatusRequest{ + BlockStatuses: []*heartbeatpb.TableSpanBlockStatus{ + { + ID: dispatcherID.ToPB(), + State: &heartbeatpb.State{ + IsBlocked: true, + BlockTs: 101, + Stage: heartbeatpb.BlockStage_WAITING, + }, + Mode: common.DefaultMode, + }, + }, + Mode: common.DefaultMode, + }, + } + queue.Enqueue(fourth) ctx2, cancel2 := context.WithTimeout(context.Background(), time.Second) defer cancel2() - require.Same(t, second, queue.Dequeue(ctx2)) + require.Same(t, fourth, queue.Dequeue(ctx2)) } func TestBlockStatusRequestQueueKeepsDistinctDoneKeys(t *testing.T) { @@ -144,6 +193,42 @@ func TestBlockStatusRequestQueueKeepsDistinctDoneKeys(t *testing.T) { require.Same(t, redoDone, queue.Dequeue(ctx3)) } +func TestBlockStatusRequestQueueKeepsWaitingAndDoneDistinct(t *testing.T) { + queue := NewBlockStatusRequestQueue() + targetID := node.NewID() + dispatcherID := common.NewDispatcherID() + + waiting := &BlockStatusRequestWithTargetID{ + TargetID: targetID, + Request: &heartbeatpb.BlockStatusRequest{ + BlockStatuses: []*heartbeatpb.TableSpanBlockStatus{ + { + ID: dispatcherID.ToPB(), + State: &heartbeatpb.State{ + IsBlocked: true, + BlockTs: 300, + Stage: heartbeatpb.BlockStage_WAITING, + }, + Mode: common.DefaultMode, + }, + }, + Mode: common.DefaultMode, + }, + } + done := newDoneBlockStatusRequest(targetID, dispatcherID, 300) + + queue.Enqueue(waiting) + queue.Enqueue(done) + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + require.Same(t, waiting, queue.Dequeue(ctx)) + + ctx2, cancel2 := context.WithTimeout(context.Background(), time.Second) + defer cancel2() + require.Same(t, done, queue.Dequeue(ctx2)) +} + func newDoneBlockStatusRequest(targetID node.ID, dispatcherID common.DispatcherID, blockTs uint64) *BlockStatusRequestWithTargetID { return &BlockStatusRequestWithTargetID{ TargetID: targetID, From baabb3015e792e3bd852ec7fb8b5c20d64951b3d Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Fri, 17 Apr 2026 11:45:40 +0800 Subject: [PATCH 13/17] maintainer: refine Signed-off-by: dongmen <414110582@qq.com> --- maintainer/maintainer.go | 49 +++++++-- maintainer/maintainer_test.go | 184 ++++++++++++++++++++++++++++++++++ 2 files changed, 226 insertions(+), 7 deletions(-) diff --git a/maintainer/maintainer.go b/maintainer/maintainer.go index 15a16cd984..e8cfff5d73 100644 --- a/maintainer/maintainer.go +++ b/maintainer/maintainer.go @@ -69,8 +69,9 @@ type Maintainer struct { selfNode *node.Info controller *Controller - pdClock pdutil.Clock - eventCh *chann.DrainableChann[*Event] + pdClock pdutil.Clock + eventCh *chann.DrainableChann[*Event] + statusRequestNotifyCh chan struct{} mc messaging.MessageCenter @@ -163,6 +164,14 @@ type Maintainer struct { redoScheduledTaskGauge prometheus.Gauge redoSpanCountGauge prometheus.Gauge redoTableCountGauge prometheus.Gauge + + bufferedStatusRequests bufferedStatusRequestBuffer + + droppedStatusRequests struct { + sync.Mutex + count uint64 + lastLogTime time.Time + } } // NewMaintainer create the maintainer for the changefeed @@ -196,10 +205,11 @@ func NewMaintainer(cfID common.ChangeFeedID, Name: keyspaceName, } m := &Maintainer{ - changefeedID: cfID, - selfNode: selfNode, - eventCh: chann.NewAutoDrainChann[*Event](), - startCheckpointTs: checkpointTs, + changefeedID: cfID, + selfNode: selfNode, + eventCh: chann.NewAutoDrainChann[*Event](), + statusRequestNotifyCh: make(chan struct{}, 1), + startCheckpointTs: checkpointTs, controller: NewController(cfID, checkpointTs, taskScheduler, info.Config, ddlSpan, redoDDLSpan, conf.AddTableBatchSize, time.Duration(conf.CheckBalanceInterval), refresher, keyspaceMeta, enableRedo), mc: mc, @@ -1157,6 +1167,8 @@ func (m *Maintainer) runHandleEvents(ctx context.Context) { return case event := <-m.eventCh.Out(): m.HandleEvent(event) + case <-m.statusRequestNotifyCh: + m.handleBufferedStatusRequests() case <-ticker.C: m.HandleEvent(&Event{ changefeedID: m.changefeedID, @@ -1168,8 +1180,31 @@ func (m *Maintainer) runHandleEvents(ctx context.Context) { // pushEvent is used to push event to maintainer's event channel // event will be handled by maintainer's main loop -func (m *Maintainer) pushEvent(event *Event) { +func (m *Maintainer) pushEvent(event *Event) bool { + if handled, accepted := m.tryBufferStatusRequestEvent(event); handled { + return accepted + } m.eventCh.In() <- event + return true +} + +func (m *Maintainer) recordDroppedStatusRequest(msgType messaging.IOType, reason string) { + m.droppedStatusRequests.Lock() + defer m.droppedStatusRequests.Unlock() + + m.droppedStatusRequests.count++ + now := time.Now() + if !m.droppedStatusRequests.lastLogTime.IsZero() && now.Sub(m.droppedStatusRequests.lastLogTime) < 5*time.Second { + return + } + m.droppedStatusRequests.lastLogTime = now + + log.Warn("drop maintainer status request", + zap.Stringer("changefeedID", m.changefeedID), + zap.String("type", msgType.String()), + zap.String("reason", reason), + zap.Int("eventChLen", m.eventCh.Len()), + zap.Uint64("droppedCount", m.droppedStatusRequests.count)) } func (m *Maintainer) getWatermark() heartbeatpb.Watermark { diff --git a/maintainer/maintainer_test.go b/maintainer/maintainer_test.go index 8c06121e47..84b452c1a1 100644 --- a/maintainer/maintainer_test.go +++ b/maintainer/maintainer_test.go @@ -33,6 +33,7 @@ import ( "github.com/pingcap/ticdc/pkg/node" "github.com/pingcap/ticdc/pkg/pdutil" "github.com/pingcap/ticdc/server/watcher" + "github.com/pingcap/ticdc/utils/chann" "github.com/pingcap/ticdc/utils/threadpool" "github.com/stretchr/testify/require" "go.uber.org/atomic" @@ -256,6 +257,189 @@ func (m *mockDispatcherManager) sendHeartbeat() { } } +func TestMaintainerPushEventDropsStatusRequestBeforeInitialized(t *testing.T) { + m := &Maintainer{ + changefeedID: common.NewChangeFeedIDWithName("test", common.DefaultKeyspaceName), + eventCh: chann.NewAutoDrainChann[*Event](chann.Cap(8)), + statusRequestNotifyCh: make(chan struct{}, 1), + removed: atomic.NewBool(false), + } + + pushed := m.pushEvent(&Event{ + changefeedID: m.changefeedID, + eventType: EventMessage, + message: &messaging.TargetMessage{Type: messaging.TypeBlockStatusRequest}, + }) + + require.False(t, pushed) + require.Equal(t, 0, m.eventCh.Len()) +} + +func TestMaintainerPushEventBuffersBlockStatusRequest(t *testing.T) { + dispatcherID := common.NewDispatcherID() + from := node.ID("node-1") + m := &Maintainer{ + changefeedID: common.NewChangeFeedIDWithName("test", common.DefaultKeyspaceName), + eventCh: chann.NewAutoDrainChann[*Event](chann.Cap(8)), + statusRequestNotifyCh: make(chan struct{}, 1), + removed: atomic.NewBool(false), + } + m.initialized.Store(true) + + req := &heartbeatpb.BlockStatusRequest{ + ChangefeedID: m.changefeedID.ToPB(), + Mode: common.DefaultMode, + BlockStatuses: []*heartbeatpb.TableSpanBlockStatus{ + { + ID: dispatcherID.ToPB(), + State: &heartbeatpb.State{ + IsBlocked: true, + BlockTs: 100, + IsSyncPoint: true, + Stage: heartbeatpb.BlockStage_WAITING, + }, + Mode: common.DefaultMode, + }, + }, + } + + require.True(t, m.pushEvent(&Event{ + changefeedID: m.changefeedID, + eventType: EventMessage, + message: &messaging.TargetMessage{ + From: from, + Type: messaging.TypeBlockStatusRequest, + Message: []messaging.IOTypeT{req}, + }, + })) + require.True(t, m.pushEvent(&Event{ + changefeedID: m.changefeedID, + eventType: EventMessage, + message: &messaging.TargetMessage{ + From: from, + Type: messaging.TypeBlockStatusRequest, + Message: []messaging.IOTypeT{req}, + }, + })) + + require.Equal(t, 0, m.eventCh.Len()) + require.Equal(t, 1, len(m.statusRequestNotifyCh)) + + events := m.takeBufferedStatusRequestEvents() + require.Len(t, events, 1) + bufferedReq := events[0].message.Message[0].(*heartbeatpb.BlockStatusRequest) + require.Len(t, bufferedReq.BlockStatuses, 1) + require.Equal(t, from, events[0].message.From) +} + +func TestMaintainerPushEventBuffersBlockStatusRequestByModeAndBlockTs(t *testing.T) { + from := node.ID("node-1") + changefeedID := common.NewChangeFeedIDWithName("test", common.DefaultKeyspaceName) + defaultDispatcherID := common.NewDispatcherID() + redoDispatcherID := common.NewDispatcherID() + + newBlockStatus := func(dispatcherID common.DispatcherID, blockTs uint64, mode int64) *heartbeatpb.TableSpanBlockStatus { + return &heartbeatpb.TableSpanBlockStatus{ + ID: dispatcherID.ToPB(), + State: &heartbeatpb.State{ + IsBlocked: true, + BlockTs: blockTs, + IsSyncPoint: true, + Stage: heartbeatpb.BlockStage_WAITING, + }, + Mode: mode, + } + } + + m := &Maintainer{ + changefeedID: changefeedID, + eventCh: chann.NewAutoDrainChann[*Event](chann.Cap(8)), + statusRequestNotifyCh: make(chan struct{}, 1), + removed: atomic.NewBool(false), + } + m.initialized.Store(true) + + newBlockStatusRequest := func(mode int64, statuses ...*heartbeatpb.TableSpanBlockStatus) *heartbeatpb.BlockStatusRequest { + return &heartbeatpb.BlockStatusRequest{ + ChangefeedID: changefeedID.ToPB(), + Mode: mode, + BlockStatuses: statuses, + } + } + + require.True(t, m.pushEvent(&Event{ + changefeedID: m.changefeedID, + eventType: EventMessage, + message: &messaging.TargetMessage{ + From: from, + Type: messaging.TypeBlockStatusRequest, + Message: []messaging.IOTypeT{ + newBlockStatusRequest(common.DefaultMode, + newBlockStatus(defaultDispatcherID, 100, common.DefaultMode)), + }, + }, + })) + require.True(t, m.pushEvent(&Event{ + changefeedID: m.changefeedID, + eventType: EventMessage, + message: &messaging.TargetMessage{ + From: from, + Type: messaging.TypeBlockStatusRequest, + Message: []messaging.IOTypeT{ + newBlockStatusRequest(common.DefaultMode, + newBlockStatus(defaultDispatcherID, 200, common.DefaultMode)), + }, + }, + })) + require.True(t, m.pushEvent(&Event{ + changefeedID: m.changefeedID, + eventType: EventMessage, + message: &messaging.TargetMessage{ + From: from, + Type: messaging.TypeBlockStatusRequest, + Message: []messaging.IOTypeT{ + newBlockStatusRequest(common.RedoMode, + newBlockStatus(redoDispatcherID, 300, common.RedoMode)), + }, + }, + })) + + events := m.takeBufferedStatusRequestEvents() + require.Len(t, events, 2) + + blockTsByMode := make(map[int64][]uint64, 2) + for _, event := range events { + require.Equal(t, from, event.message.From) + req := event.message.Message[0].(*heartbeatpb.BlockStatusRequest) + for _, status := range req.BlockStatuses { + blockTsByMode[req.Mode] = append(blockTsByMode[req.Mode], status.State.BlockTs) + } + } + + require.ElementsMatch(t, []uint64{100, 200}, blockTsByMode[common.DefaultMode]) + require.ElementsMatch(t, []uint64{300}, blockTsByMode[common.RedoMode]) +} + +func TestMaintainerPushEventKeepsBootstrapResponseOutsideStatusBuffer(t *testing.T) { + m := &Maintainer{ + changefeedID: common.NewChangeFeedIDWithName("test", common.DefaultKeyspaceName), + eventCh: chann.NewAutoDrainChann[*Event](chann.Cap(8)), + statusRequestNotifyCh: make(chan struct{}, 1), + removed: atomic.NewBool(false), + } + m.initialized.Store(true) + + pushed := m.pushEvent(&Event{ + changefeedID: m.changefeedID, + eventType: EventMessage, + message: &messaging.TargetMessage{Type: messaging.TypeMaintainerBootstrapResponse}, + }) + + require.True(t, pushed) + require.Equal(t, 1, m.eventCh.Len()) + require.Equal(t, 0, len(m.statusRequestNotifyCh)) +} + func TestMaintainerSchedule(t *testing.T) { // This test exercises a single-node maintainer lifecycle: // 1) Bootstrap a changefeed via the dispatcher manager mock. From 73c97af851e7313da8152dca39607fecca08a678 Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Fri, 17 Apr 2026 11:45:47 +0800 Subject: [PATCH 14/17] maintainer: refine Signed-off-by: dongmen <414110582@qq.com> --- maintainer/status_request_buffer.go | 299 ++++++++++++++++++++++++++++ 1 file changed, 299 insertions(+) create mode 100644 maintainer/status_request_buffer.go diff --git a/maintainer/status_request_buffer.go b/maintainer/status_request_buffer.go new file mode 100644 index 0000000000..ab2849c670 --- /dev/null +++ b/maintainer/status_request_buffer.go @@ -0,0 +1,299 @@ +package maintainer + +import ( + "sync" + + "github.com/pingcap/ticdc/heartbeatpb" + "github.com/pingcap/ticdc/pkg/common" + "github.com/pingcap/ticdc/pkg/messaging" + "github.com/pingcap/ticdc/pkg/node" +) + +type bufferedStatusRequestBuffer struct { + sync.Mutex + + heartbeats map[node.ID]*bufferedHeartbeatRequest + blockStatuses map[bufferedBlockStatusSourceKey]*bufferedBlockStatusRequest + redoResolvedTs map[node.ID]*heartbeatpb.RedoResolvedTsProgressMessage +} + +type bufferedHeartbeatRequest struct { + changefeedID *heartbeatpb.ChangefeedID + watermark *heartbeatpb.Watermark + redoWatermark *heartbeatpb.Watermark + statuses map[heartbeatStatusKey]*heartbeatpb.TableSpanStatus + order []heartbeatStatusKey + err *heartbeatpb.RunningError + completeStatus bool +} + +type heartbeatStatusKey struct { + dispatcherID common.DispatcherID + mode int64 +} + +type bufferedBlockStatusRequest struct { + changefeedID *heartbeatpb.ChangefeedID + from node.ID + mode int64 + statuses map[blockStatusKey]*heartbeatpb.TableSpanBlockStatus + order []blockStatusKey +} + +type bufferedBlockStatusSourceKey struct { + from node.ID + mode int64 +} + +type blockStatusKey struct { + dispatcherID common.DispatcherID + blockTs uint64 + mode int64 + isSyncPoint bool + stage heartbeatpb.BlockStage +} + +func isBufferableStatusRequest(msgType messaging.IOType) bool { + switch msgType { + case messaging.TypeHeartBeatRequest, + messaging.TypeBlockStatusRequest, + messaging.TypeRedoResolvedTsProgressMessage: + return true + default: + return false + } +} + +func (m *Maintainer) tryBufferStatusRequestEvent(event *Event) (bool, bool) { + if event == nil || event.eventType != EventMessage || event.message == nil { + return false, false + } + if !isBufferableStatusRequest(event.message.Type) { + return false, false + } + if !m.initialized.Load() { + m.recordDroppedStatusRequest(event.message.Type, "maintainer not initialized") + return true, false + } + if m.removing.Load() || (m.removed != nil && m.removed.Load()) { + m.recordDroppedStatusRequest(event.message.Type, "maintainer is closing") + return true, false + } + + m.bufferStatusRequest(event.message) + select { + case m.statusRequestNotifyCh <- struct{}{}: + default: + } + return true, true +} + +func (m *Maintainer) bufferStatusRequest(msg *messaging.TargetMessage) { + switch msg.Type { + case messaging.TypeHeartBeatRequest: + req := msg.Message[0].(*heartbeatpb.HeartBeatRequest) + m.bufferedStatusRequests.mergeHeartbeat(msg.From, req) + case messaging.TypeBlockStatusRequest: + req := msg.Message[0].(*heartbeatpb.BlockStatusRequest) + m.bufferedStatusRequests.mergeBlockStatus(msg.From, req) + case messaging.TypeRedoResolvedTsProgressMessage: + req := msg.Message[0].(*heartbeatpb.RedoResolvedTsProgressMessage) + m.bufferedStatusRequests.mergeRedoResolvedTs(msg.From, req) + } +} + +func (m *Maintainer) handleBufferedStatusRequests() { + for _, event := range m.takeBufferedStatusRequestEvents() { + m.HandleEvent(event) + } +} + +func (m *Maintainer) takeBufferedStatusRequestEvents() []*Event { + return m.bufferedStatusRequests.drain(m.changefeedID) +} + +func (b *bufferedStatusRequestBuffer) mergeHeartbeat(from node.ID, req *heartbeatpb.HeartBeatRequest) { + if req == nil { + return + } + b.Lock() + defer b.Unlock() + if b.heartbeats == nil { + b.heartbeats = make(map[node.ID]*bufferedHeartbeatRequest) + } + entry, ok := b.heartbeats[from] + if !ok { + entry = &bufferedHeartbeatRequest{ + changefeedID: req.ChangefeedID, + statuses: make(map[heartbeatStatusKey]*heartbeatpb.TableSpanStatus), + } + b.heartbeats[from] = entry + } + entry.changefeedID = req.ChangefeedID + entry.completeStatus = entry.completeStatus || req.CompeleteStatus + entry.err = pickRunningError(entry.err, req.Err) + entry.watermark = pickWatermark(entry.watermark, req.Watermark) + entry.redoWatermark = pickWatermark(entry.redoWatermark, req.RedoWatermark) + for _, status := range req.Statuses { + if status == nil || status.ID == nil { + continue + } + key := heartbeatStatusKey{ + dispatcherID: common.NewDispatcherIDFromPB(status.ID), + mode: status.Mode, + } + if _, exists := entry.statuses[key]; !exists { + entry.order = append(entry.order, key) + } + entry.statuses[key] = status + } +} + +func (b *bufferedStatusRequestBuffer) mergeBlockStatus(from node.ID, req *heartbeatpb.BlockStatusRequest) { + if req == nil { + return + } + b.Lock() + defer b.Unlock() + if b.blockStatuses == nil { + b.blockStatuses = make(map[bufferedBlockStatusSourceKey]*bufferedBlockStatusRequest) + } + sourceKey := bufferedBlockStatusSourceKey{ + from: from, + mode: req.Mode, + } + entry, ok := b.blockStatuses[sourceKey] + if !ok { + entry = &bufferedBlockStatusRequest{ + changefeedID: req.ChangefeedID, + from: from, + mode: req.Mode, + statuses: make(map[blockStatusKey]*heartbeatpb.TableSpanBlockStatus), + } + b.blockStatuses[sourceKey] = entry + } + entry.changefeedID = req.ChangefeedID + entry.mode = req.Mode + for _, status := range req.BlockStatuses { + if status == nil || status.ID == nil || status.State == nil { + continue + } + key := blockStatusKey{ + dispatcherID: common.NewDispatcherIDFromPB(status.ID), + blockTs: status.State.BlockTs, + mode: status.Mode, + isSyncPoint: status.State.IsSyncPoint, + stage: status.State.Stage, + } + if _, exists := entry.statuses[key]; !exists { + entry.order = append(entry.order, key) + } + entry.statuses[key] = status + } +} + +func (b *bufferedStatusRequestBuffer) mergeRedoResolvedTs(from node.ID, req *heartbeatpb.RedoResolvedTsProgressMessage) { + if req == nil { + return + } + b.Lock() + defer b.Unlock() + if b.redoResolvedTs == nil { + b.redoResolvedTs = make(map[node.ID]*heartbeatpb.RedoResolvedTsProgressMessage) + } + current, ok := b.redoResolvedTs[from] + if !ok || req.ResolvedTs > current.ResolvedTs { + b.redoResolvedTs[from] = req + } +} + +func (b *bufferedStatusRequestBuffer) drain(changefeedID common.ChangeFeedID) []*Event { + var events []*Event + b.Lock() + defer b.Unlock() + + for _, entry := range b.blockStatuses { + req := &heartbeatpb.BlockStatusRequest{ + ChangefeedID: entry.changefeedID, + Mode: entry.mode, + BlockStatuses: make([]*heartbeatpb.TableSpanBlockStatus, 0, len(entry.order)), + } + for _, key := range entry.order { + if status, ok := entry.statuses[key]; ok { + req.BlockStatuses = append(req.BlockStatuses, status) + } + } + if len(req.BlockStatuses) > 0 { + events = append(events, newBufferedStatusEvent(changefeedID, entry.from, messaging.TypeBlockStatusRequest, req)) + } + } + b.blockStatuses = nil + + for from, entry := range b.heartbeats { + req := &heartbeatpb.HeartBeatRequest{ + ChangefeedID: entry.changefeedID, + Statuses: make([]*heartbeatpb.TableSpanStatus, 0, len(entry.order)), + Watermark: entry.watermark, + RedoWatermark: entry.redoWatermark, + Err: entry.err, + CompeleteStatus: entry.completeStatus, + } + for _, key := range entry.order { + if status, ok := entry.statuses[key]; ok { + req.Statuses = append(req.Statuses, status) + } + } + if len(req.Statuses) > 0 || req.Watermark != nil || req.RedoWatermark != nil || req.Err != nil { + events = append(events, newBufferedStatusEvent(changefeedID, from, messaging.TypeHeartBeatRequest, req)) + } + } + b.heartbeats = nil + + for from, req := range b.redoResolvedTs { + events = append(events, newBufferedStatusEvent(changefeedID, from, messaging.TypeRedoResolvedTsProgressMessage, req)) + } + b.redoResolvedTs = nil + + return events +} + +func newBufferedStatusEvent( + changefeedID common.ChangeFeedID, + from node.ID, + msgType messaging.IOType, + msg messaging.IOTypeT, +) *Event { + return &Event{ + changefeedID: changefeedID, + eventType: EventMessage, + message: &messaging.TargetMessage{ + From: from, + To: "", + Type: msgType, + Message: []messaging.IOTypeT{msg}, + }, + } +} + +func pickRunningError(current, candidate *heartbeatpb.RunningError) *heartbeatpb.RunningError { + if candidate != nil { + return candidate + } + return current +} + +func pickWatermark(current, candidate *heartbeatpb.Watermark) *heartbeatpb.Watermark { + if candidate == nil { + return current + } + if current == nil { + return candidate + } + if candidate.Seq > current.Seq || (candidate.Seq == current.Seq && candidate.CheckpointTs >= current.CheckpointTs) { + current = candidate + } + if candidate.LastSyncedTs > current.LastSyncedTs { + current.LastSyncedTs = candidate.LastSyncedTs + } + return current +} From 6d02d5b7bfcb8e8b00c07d25d67d894ce3e9caeb Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Fri, 17 Apr 2026 12:01:19 +0800 Subject: [PATCH 15/17] fix make Signed-off-by: dongmen <414110582@qq.com> --- pkg/eventservice/event_broker.go | 2 ++ 1 file changed, 2 insertions(+) diff --git a/pkg/eventservice/event_broker.go b/pkg/eventservice/event_broker.go index 0d138410e5..ea442afe8a 100644 --- a/pkg/eventservice/event_broker.go +++ b/pkg/eventservice/event_broker.go @@ -122,6 +122,8 @@ func newEventBroker( scanTaskQueueSize := config.GetGlobalServerConfig().Debug.EventService.ScanTaskQueueSize / scanWorkerCount sendMessageQueueSize := basicChannelSize * 4 + eventServiceConfig := config.GetGlobalServerConfig().Debug.EventService + scanLimitInBytes := eventServiceConfig.ScanLimitInBytes syncPointCheckpointCapMultiplier := eventServiceConfig.SyncPointCheckpointCapMultiplier if syncPointCheckpointCapMultiplier <= 0 { From 330eda5fcf90a05bf953c13c77c5a6f86b73f8aa Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Fri, 17 Apr 2026 17:51:32 +0800 Subject: [PATCH 16/17] eventBroker: refine syncpoint produce logic Signed-off-by: dongmen <414110582@qq.com> --- pkg/eventservice/dispatcher_stat.go | 12 +++ pkg/eventservice/event_broker.go | 27 +++++- pkg/eventservice/event_broker_test.go | 127 +++++++++++++++++++++++++- pkg/eventservice/scan_window.go | 31 ++++++- pkg/eventservice/scan_window_test.go | 14 +++ 5 files changed, 202 insertions(+), 9 deletions(-) diff --git a/pkg/eventservice/dispatcher_stat.go b/pkg/eventservice/dispatcher_stat.go index 9cfe374618..424caab604 100644 --- a/pkg/eventservice/dispatcher_stat.go +++ b/pkg/eventservice/dispatcher_stat.go @@ -430,6 +430,7 @@ type changefeedStatus struct { availableMemoryQuota sync.Map // nodeID -> atomic.Uint64 (memory quota in bytes) minSentTs atomic.Uint64 + minCheckpointTs atomic.Uint64 scanInterval atomic.Int64 lastAdjustTime atomic.Time @@ -438,6 +439,8 @@ type changefeedStatus struct { syncPointInterval time.Duration } +const invalidMinCheckpointTs = ^uint64(0) + func newChangefeedStatus(changefeedID common.ChangeFeedID, syncPointInterval time.Duration) *changefeedStatus { status := &changefeedStatus{ changefeedID: changefeedID, @@ -445,6 +448,7 @@ func newChangefeedStatus(changefeedID common.ChangeFeedID, syncPointInterval tim syncPointInterval: syncPointInterval, } status.scanInterval.Store(int64(defaultScanInterval)) + status.minCheckpointTs.Store(invalidMinCheckpointTs) status.lastAdjustTime.Store(time.Now()) status.lastTrendAdjustTime.Store(time.Now()) @@ -471,3 +475,11 @@ func (c *changefeedStatus) isEmpty() bool { func (c *changefeedStatus) isSyncpointEnabled() bool { return c.syncPointInterval > 0 } + +func (c *changefeedStatus) getMinCheckpointTs() (uint64, bool) { + minCheckpointTs := c.minCheckpointTs.Load() + if minCheckpointTs == invalidMinCheckpointTs { + return 0, false + } + return minCheckpointTs, true +} diff --git a/pkg/eventservice/event_broker.go b/pkg/eventservice/event_broker.go index ea442afe8a..c9b31d917f 100644 --- a/pkg/eventservice/event_broker.go +++ b/pkg/eventservice/event_broker.go @@ -683,7 +683,20 @@ func (c *eventBroker) shouldSuppressSyncPointEmission(d *dispatcherStat) bool { } receivedResolvedTs := d.receivedResolvedTs.Load() - checkpointTs := d.checkpointTs.Load() + checkpointTs, ok := d.changefeedStat.getMinCheckpointTs() + if !ok { + metrics.EventServiceSyncPointLagGaugeVec.WithLabelValues(d.changefeedStat.changefeedID.String()).Set(0) + if d.syncPointSendSuppressed.Load() { + if d.syncPointSendSuppressed.CompareAndSwap(true, false) { + log.Info("syncpoint emission resumed", + zap.Stringer("changefeedID", d.changefeedStat.changefeedID), + zap.Stringer("dispatcherID", d.id), + zap.Uint64("receivedResolvedTs", receivedResolvedTs), + zap.Duration("resumeThreshold", c.syncPointLagResumeThreshold)) + } + } + return false + } lag := syncPointLagDuration(receivedResolvedTs, checkpointTs) metrics.EventServiceSyncPointLagGaugeVec.WithLabelValues(d.changefeedStat.changefeedID.String()).Set(lag.Seconds()) @@ -694,7 +707,7 @@ func (c *eventBroker) shouldSuppressSyncPointEmission(d *dispatcherStat) bool { zap.Stringer("changefeedID", d.changefeedStat.changefeedID), zap.Stringer("dispatcherID", d.id), zap.Uint64("receivedResolvedTs", receivedResolvedTs), - zap.Uint64("checkpointTs", checkpointTs), + zap.Uint64("minCheckpointTs", checkpointTs), zap.Duration("lag", lag), zap.Duration("resumeThreshold", c.syncPointLagResumeThreshold)) } @@ -709,7 +722,7 @@ func (c *eventBroker) shouldSuppressSyncPointEmission(d *dispatcherStat) bool { zap.Stringer("changefeedID", d.changefeedStat.changefeedID), zap.Stringer("dispatcherID", d.id), zap.Uint64("sentResolvedTs", receivedResolvedTs), - zap.Uint64("checkpointTs", checkpointTs), + zap.Uint64("minCheckpointTs", checkpointTs), zap.Duration("lag", lag), zap.Duration("suppressThreshold", c.syncPointLagSuppressThreshold), zap.Duration("resumeThreshold", c.syncPointLagResumeThreshold)) @@ -1141,6 +1154,7 @@ func (c *eventBroker) addDispatcher(info DispatcherInfo) error { status.addDispatcher(id, dispatcherPtr) if span.Equal(common.KeyspaceDDLSpan(span.KeyspaceID)) { c.tableTriggerDispatchers.Store(id, dispatcherPtr) + status.refreshMinSentResolvedTs() log.Info("table trigger dispatcher register dispatcher", zap.Uint64("clusterID", c.tidbClusterID), zap.Stringer("changefeedID", changefeedID), @@ -1211,6 +1225,7 @@ func (c *eventBroker) addDispatcher(info DispatcherInfo) error { return err } c.dispatchers.Store(id, dispatcherPtr) + status.refreshMinSentResolvedTs() c.metricsCollector.metricDispatcherCount.Inc() log.Info("register dispatcher", zap.Uint64("clusterID", c.tidbClusterID), @@ -1259,6 +1274,8 @@ func (c *eventBroker) removeDispatcher(dispatcherInfo DispatcherInfo) { metrics.EventServiceAvailableMemoryQuotaGaugeVec.DeleteLabelValues(changefeedID.String()) metrics.EventServiceScanWindowBaseTsGaugeVec.DeleteLabelValues(changefeedID.String()) metrics.EventServiceScanWindowIntervalGaugeVec.DeleteLabelValues(changefeedID.String()) + } else { + stat.changefeedStat.refreshMinSentResolvedTs() } c.eventStore.UnregisterDispatcher(changefeedID, id) @@ -1335,6 +1352,7 @@ func (c *eventBroker) resetDispatcher(dispatcherInfo DispatcherInfo) error { for { if statPtr.CompareAndSwap(oldStat, newStat) { status.addDispatcher(dispatcherID, statPtr) + status.refreshMinSentResolvedTs() break } log.Warn("reset dispatcher failed since the dispatcher is changed concurrently", @@ -1422,6 +1440,9 @@ func (c *eventBroker) handleDispatcherHeartbeat(heartbeat *DispatcherHeartBeatWi handleProgress(dp.DispatcherID, dp.CheckpointTs, 0, false) } } + for changefeed := range changedChangefeeds { + changefeed.refreshMinSentResolvedTs() + } c.sendDispatcherResponse(responseMap) } diff --git a/pkg/eventservice/event_broker_test.go b/pkg/eventservice/event_broker_test.go index 1c1a139a9b..fdc90edab9 100644 --- a/pkg/eventservice/event_broker_test.go +++ b/pkg/eventservice/event_broker_test.go @@ -485,7 +485,13 @@ func TestEmitSyncPointEventIfNeededSuppressesWhenLagging(t *testing.T) { disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) disp.seq.Store(1) disp.checkpointTs.Store(ts100) - disp.sentResolvedTs.Store(ts180) + disp.receivedResolvedTs.Store(ts180) + disp.lastReceivedHeartbeatTime.Store(time.Now().Unix()) + + dispPtr := &atomic.Pointer[dispatcherStat]{} + dispPtr.Store(disp) + changefeedStatus.addDispatcher(disp.id, dispPtr) + changefeedStatus.refreshMinSentResolvedTs() broker.emitSyncPointEventIfNeeded(ts130, disp, node.ID(info.GetServerID())) @@ -494,6 +500,54 @@ func TestEmitSyncPointEventIfNeededSuppressesWhenLagging(t *testing.T) { require.Equal(t, 0, len(broker.messageCh[disp.messageWorkerIndex])) } +func TestEmitSyncPointEventIfNeededSuppressesByMinChangefeedCheckpoint(t *testing.T) { + broker, _, _, _ := newEventBrokerForTest() + broker.close() + broker.syncPointLagSuppressThreshold = 20 * time.Second + broker.syncPointLagResumeThreshold = 10 * time.Second + + base := time.Unix(0, 0) + ts100 := oracle.GoTimeToTS(base.Add(100 * time.Second)) + ts110 := oracle.GoTimeToTS(base.Add(110 * time.Second)) + ts115 := oracle.GoTimeToTS(base.Add(115 * time.Second)) + ts120 := oracle.GoTimeToTS(base.Add(120 * time.Second)) + ts125 := oracle.GoTimeToTS(base.Add(125 * time.Second)) + ts130 := oracle.GoTimeToTS(base.Add(130 * time.Second)) + + info := newMockDispatcherInfoForTest(t) + info.epoch = 1 + info.enableSyncPoint = true + info.syncPointInterval = 10 * time.Second + info.nextSyncPoint = ts110 + + changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) + disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) + disp.seq.Store(1) + disp.receivedResolvedTs.Store(ts130) + disp.checkpointTs.Store(ts125) + disp.lastReceivedHeartbeatTime.Store(time.Now().Unix()) + + dispPtr := &atomic.Pointer[dispatcherStat]{} + dispPtr.Store(disp) + changefeedStatus.addDispatcher(disp.id, dispPtr) + + lagging := newDispatcherStat(newMockDispatcherInfoForTest(t), 1, 1, nil, changefeedStatus) + lagging.seq.Store(1) + lagging.checkpointTs.Store(ts100) + lagging.lastReceivedHeartbeatTime.Store(time.Now().Unix()) + + laggingPtr := &atomic.Pointer[dispatcherStat]{} + laggingPtr.Store(lagging) + changefeedStatus.addDispatcher(lagging.id, laggingPtr) + changefeedStatus.refreshMinSentResolvedTs() + + broker.emitSyncPointEventIfNeeded(ts115, disp, node.ID(info.GetServerID())) + + require.True(t, disp.syncPointSendSuppressed.Load()) + require.Equal(t, ts120, disp.nextSyncPoint.Load()) + require.Equal(t, 0, len(broker.messageCh[disp.messageWorkerIndex])) +} + func TestEmitSyncPointEventIfNeededResumesAfterLagRecovers(t *testing.T) { broker, _, _, _ := newEventBrokerForTest() broker.close() @@ -517,8 +571,69 @@ func TestEmitSyncPointEventIfNeededResumesAfterLagRecovers(t *testing.T) { disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) disp.seq.Store(1) disp.syncPointSendSuppressed.Store(true) - disp.sentResolvedTs.Store(ts130) + disp.receivedResolvedTs.Store(ts130) disp.checkpointTs.Store(ts125) + disp.lastReceivedHeartbeatTime.Store(time.Now().Unix()) + + dispPtr := &atomic.Pointer[dispatcherStat]{} + dispPtr.Store(disp) + changefeedStatus.addDispatcher(disp.id, dispPtr) + changefeedStatus.refreshMinSentResolvedTs() + + broker.emitSyncPointEventIfNeeded(ts115, disp, node.ID(info.GetServerID())) + + require.False(t, disp.syncPointSendSuppressed.Load()) + require.Equal(t, ts120, disp.nextSyncPoint.Load()) + require.Equal(t, 1, len(broker.messageCh[disp.messageWorkerIndex])) + + msg := <-broker.messageCh[disp.messageWorkerIndex] + require.Equal(t, event.TypeSyncPointEvent, msg.msgType) + syncPointEvent, ok := msg.e.(*event.SyncPointEvent) + require.True(t, ok) + require.Equal(t, ts110, syncPointEvent.GetCommitTs()) +} + +func TestEmitSyncPointEventIfNeededResumesWhenStaleCheckpointIsIgnored(t *testing.T) { + broker, _, _, _ := newEventBrokerForTest() + broker.close() + broker.syncPointLagSuppressThreshold = 20 * time.Second + broker.syncPointLagResumeThreshold = 10 * time.Second + + base := time.Unix(0, 0) + ts100 := oracle.GoTimeToTS(base.Add(100 * time.Second)) + ts110 := oracle.GoTimeToTS(base.Add(110 * time.Second)) + ts115 := oracle.GoTimeToTS(base.Add(115 * time.Second)) + ts120 := oracle.GoTimeToTS(base.Add(120 * time.Second)) + ts125 := oracle.GoTimeToTS(base.Add(125 * time.Second)) + ts130 := oracle.GoTimeToTS(base.Add(130 * time.Second)) + + info := newMockDispatcherInfoForTest(t) + info.epoch = 1 + info.enableSyncPoint = true + info.syncPointInterval = 10 * time.Second + info.nextSyncPoint = ts110 + + changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) + disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) + disp.seq.Store(1) + disp.syncPointSendSuppressed.Store(true) + disp.receivedResolvedTs.Store(ts130) + disp.checkpointTs.Store(ts125) + disp.lastReceivedHeartbeatTime.Store(time.Now().Unix()) + + dispPtr := &atomic.Pointer[dispatcherStat]{} + dispPtr.Store(disp) + changefeedStatus.addDispatcher(disp.id, dispPtr) + + stale := newDispatcherStat(newMockDispatcherInfoForTest(t), 1, 1, nil, changefeedStatus) + stale.seq.Store(1) + stale.checkpointTs.Store(ts100) + stale.lastReceivedHeartbeatTime.Store(time.Now().Add(-scanWindowStaleDispatcherHeartbeatThreshold - time.Second).Unix()) + + stalePtr := &atomic.Pointer[dispatcherStat]{} + stalePtr.Store(stale) + changefeedStatus.addDispatcher(stale.id, stalePtr) + changefeedStatus.refreshMinSentResolvedTs() broker.emitSyncPointEventIfNeeded(ts115, disp, node.ID(info.GetServerID())) @@ -554,8 +669,14 @@ func TestEmitSyncPointEventIfNeededNoSuppressWhenCheckpointAhead(t *testing.T) { changefeedStatus := broker.getOrSetChangefeedStatus(info.GetChangefeedID(), info.GetSyncPointInterval()) disp := newDispatcherStat(info, 1, 1, nil, changefeedStatus) disp.seq.Store(1) - disp.sentResolvedTs.Store(ts100) + disp.receivedResolvedTs.Store(ts100) disp.checkpointTs.Store(ts120) + disp.lastReceivedHeartbeatTime.Store(time.Now().Unix()) + + dispPtr := &atomic.Pointer[dispatcherStat]{} + dispPtr.Store(disp) + changefeedStatus.addDispatcher(disp.id, dispPtr) + changefeedStatus.refreshMinSentResolvedTs() broker.emitSyncPointEventIfNeeded(ts115, disp, node.ID(info.GetServerID())) diff --git a/pkg/eventservice/scan_window.go b/pkg/eventservice/scan_window.go index 46cb9cffb3..a5d1a8a3e4 100644 --- a/pkg/eventservice/scan_window.go +++ b/pkg/eventservice/scan_window.go @@ -82,6 +82,11 @@ const ( scanWindowStaleDispatcherHeartbeatThreshold = 1 * time.Minute ) +func isDispatcherStale(lastHeartbeatTime int64, now time.Time) bool { + return lastHeartbeatTime > 0 && + now.Sub(time.Unix(lastHeartbeatTime, 0)) > scanWindowStaleDispatcherHeartbeatThreshold +} + type memoryUsageSample struct { ts time.Time ratio float64 @@ -332,8 +337,10 @@ func (c *changefeedStatus) refreshMinSentResolvedTs() { now := time.Now() minSentResolvedTs := ^uint64(0) minSentResolvedTsWithStale := ^uint64(0) + minCheckpointTs := uint64(0) hasEligible := false hasNonStale := false + hasMinCheckpointTs := false c.dispatchers.Range(func(_ any, value any) bool { dispatcher := value.(*atomic.Pointer[dispatcherStat]).Load() if dispatcher == nil || dispatcher.isRemoved.Load() || dispatcher.seq.Load() == 0 { @@ -346,9 +353,7 @@ func (c *changefeedStatus) refreshMinSentResolvedTs() { minSentResolvedTsWithStale = sentResolvedTs } - lastHeartbeatTime := dispatcher.lastReceivedHeartbeatTime.Load() - if lastHeartbeatTime > 0 && - now.Sub(time.Unix(lastHeartbeatTime, 0)) > scanWindowStaleDispatcherHeartbeatThreshold { + if isDispatcherStale(dispatcher.lastReceivedHeartbeatTime.Load(), now) { log.Info("dispatcher is stale, skip it's sent resolved ts", zap.Stringer("changefeedID", c.changefeedID), zap.Stringer("dispatcherID", dispatcher.id)) return true } @@ -357,18 +362,30 @@ func (c *changefeedStatus) refreshMinSentResolvedTs() { if sentResolvedTs < minSentResolvedTs { minSentResolvedTs = sentResolvedTs } + checkpointTs := dispatcher.checkpointTs.Load() + if !hasMinCheckpointTs || checkpointTs < minCheckpointTs { + minCheckpointTs = checkpointTs + hasMinCheckpointTs = true + } return true }) if !hasEligible { c.storeMinSentTs(0) + c.storeMinCheckpointTs(invalidMinCheckpointTs) return } if !hasNonStale { c.storeMinSentTs(minSentResolvedTsWithStale) + c.storeMinCheckpointTs(invalidMinCheckpointTs) return } c.storeMinSentTs(minSentResolvedTs) + if hasMinCheckpointTs { + c.storeMinCheckpointTs(minCheckpointTs) + } else { + c.storeMinCheckpointTs(invalidMinCheckpointTs) + } } func (c *changefeedStatus) getScanMaxTs() uint64 { @@ -393,6 +410,14 @@ func (c *changefeedStatus) storeMinSentTs(value uint64) { metrics.EventServiceScanWindowBaseTsGaugeVec.WithLabelValues(c.changefeedID.String()).Set(float64(value)) } +func (c *changefeedStatus) storeMinCheckpointTs(value uint64) { + prev := c.minCheckpointTs.Load() + if prev == value { + return + } + c.minCheckpointTs.Store(value) +} + func scaleDuration(d time.Duration, numerator int64, denominator int64) time.Duration { if numerator <= 0 || denominator <= 0 { return d diff --git a/pkg/eventservice/scan_window_test.go b/pkg/eventservice/scan_window_test.go index 01ee458e70..e6400b69a0 100644 --- a/pkg/eventservice/scan_window_test.go +++ b/pkg/eventservice/scan_window_test.go @@ -153,6 +153,7 @@ func TestRefreshMinSentResolvedTsMinAndSkipRules(t *testing.T) { stale := &dispatcherStat{} stale.seq.Store(1) stale.sentResolvedTs.Store(10) + stale.checkpointTs.Store(10) stale.lastReceivedHeartbeatTime.Store(time.Now().Add(-scanWindowStaleDispatcherHeartbeatThreshold - time.Second).Unix()) removed := &dispatcherStat{} @@ -167,10 +168,12 @@ func TestRefreshMinSentResolvedTsMinAndSkipRules(t *testing.T) { first := &dispatcherStat{} first.seq.Store(1) first.sentResolvedTs.Store(200) + first.checkpointTs.Store(200) second := &dispatcherStat{} second.seq.Store(1) second.sentResolvedTs.Store(50) + second.checkpointTs.Store(50) stalePtr := &atomic.Pointer[dispatcherStat]{} stalePtr.Store(stale) @@ -194,15 +197,23 @@ func TestRefreshMinSentResolvedTsMinAndSkipRules(t *testing.T) { status.refreshMinSentResolvedTs() require.Equal(t, uint64(50), status.minSentTs.Load()) + minCheckpointTs, ok := status.getMinCheckpointTs() + require.True(t, ok) + require.Equal(t, uint64(50), minCheckpointTs) second.isRemoved.Store(true) status.refreshMinSentResolvedTs() require.Equal(t, uint64(200), status.minSentTs.Load()) + minCheckpointTs, ok = status.getMinCheckpointTs() + require.True(t, ok) + require.Equal(t, uint64(200), minCheckpointTs) stale.isRemoved.Store(true) first.seq.Store(0) status.refreshMinSentResolvedTs() require.Equal(t, uint64(0), status.minSentTs.Load()) + _, ok = status.getMinCheckpointTs() + require.False(t, ok) } func TestRefreshMinSentResolvedTsStaleFallback(t *testing.T) { @@ -213,6 +224,7 @@ func TestRefreshMinSentResolvedTsStaleFallback(t *testing.T) { stale := &dispatcherStat{} stale.seq.Store(1) stale.sentResolvedTs.Store(123) + stale.checkpointTs.Store(123) stale.lastReceivedHeartbeatTime.Store(time.Now().Add(-scanWindowStaleDispatcherHeartbeatThreshold - time.Second).Unix()) stalePtr := &atomic.Pointer[dispatcherStat]{} @@ -221,6 +233,8 @@ func TestRefreshMinSentResolvedTsStaleFallback(t *testing.T) { status.refreshMinSentResolvedTs() require.Equal(t, uint64(123), status.minSentTs.Load()) + _, ok := status.getMinCheckpointTs() + require.False(t, ok) } func TestGetScanMaxTsFallbackInterval(t *testing.T) { From 531f764104eb3530305a0872b17dd445636cb097 Mon Sep 17 00:00:00 2001 From: dongmen <414110582@qq.com> Date: Fri, 17 Apr 2026 18:11:49 +0800 Subject: [PATCH 17/17] eventBroker: refine syncpoint produce logic 2 Signed-off-by: dongmen <414110582@qq.com> --- pkg/eventservice/event_broker.go | 5 ----- 1 file changed, 5 deletions(-) diff --git a/pkg/eventservice/event_broker.go b/pkg/eventservice/event_broker.go index c9b31d917f..a88e8976d5 100644 --- a/pkg/eventservice/event_broker.go +++ b/pkg/eventservice/event_broker.go @@ -1154,7 +1154,6 @@ func (c *eventBroker) addDispatcher(info DispatcherInfo) error { status.addDispatcher(id, dispatcherPtr) if span.Equal(common.KeyspaceDDLSpan(span.KeyspaceID)) { c.tableTriggerDispatchers.Store(id, dispatcherPtr) - status.refreshMinSentResolvedTs() log.Info("table trigger dispatcher register dispatcher", zap.Uint64("clusterID", c.tidbClusterID), zap.Stringer("changefeedID", changefeedID), @@ -1225,7 +1224,6 @@ func (c *eventBroker) addDispatcher(info DispatcherInfo) error { return err } c.dispatchers.Store(id, dispatcherPtr) - status.refreshMinSentResolvedTs() c.metricsCollector.metricDispatcherCount.Inc() log.Info("register dispatcher", zap.Uint64("clusterID", c.tidbClusterID), @@ -1274,8 +1272,6 @@ func (c *eventBroker) removeDispatcher(dispatcherInfo DispatcherInfo) { metrics.EventServiceAvailableMemoryQuotaGaugeVec.DeleteLabelValues(changefeedID.String()) metrics.EventServiceScanWindowBaseTsGaugeVec.DeleteLabelValues(changefeedID.String()) metrics.EventServiceScanWindowIntervalGaugeVec.DeleteLabelValues(changefeedID.String()) - } else { - stat.changefeedStat.refreshMinSentResolvedTs() } c.eventStore.UnregisterDispatcher(changefeedID, id) @@ -1352,7 +1348,6 @@ func (c *eventBroker) resetDispatcher(dispatcherInfo DispatcherInfo) error { for { if statPtr.CompareAndSwap(oldStat, newStat) { status.addDispatcher(dispatcherID, statPtr) - status.refreshMinSentResolvedTs() break } log.Warn("reset dispatcher failed since the dispatcher is changed concurrently",