From a1207a57c38e6542f8958095dd4b5b69acc1bbea Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Tue, 23 Jun 2026 10:24:32 +0800 Subject: [PATCH 01/21] logpuller: send cdc scan priority --- go.mod | 2 +- go.sum | 4 +- logservice/logpuller/priority_task.go | 26 ++++++++ logservice/logpuller/priority_task_test.go | 10 +++ logservice/logpuller/region_request_worker.go | 1 + .../logpuller/region_request_worker_test.go | 36 +++++++++++ logservice/logpuller/region_state.go | 5 ++ logservice/logpuller/subscription_client.go | 5 +- .../logpuller/subscription_client_test.go | 64 +++++++++++++++++++ 9 files changed, 148 insertions(+), 5 deletions(-) diff --git a/go.mod b/go.mod index 3264e2b11b..ca663b9a21 100644 --- a/go.mod +++ b/go.mod @@ -51,7 +51,7 @@ require ( github.com/pierrec/lz4/v4 v4.1.21 github.com/pingcap/errors v0.11.5-0.20250523034308-74f78ae071ee github.com/pingcap/failpoint v0.0.0-20240528011301-b51a646c7c86 - github.com/pingcap/kvproto v0.0.0-20251109100001-1907922fbd18 + github.com/pingcap/kvproto v0.0.0-20260622153037-f3bb7de680cd github.com/pingcap/log v1.1.1-0.20250917021125-19901e015dc9 github.com/pingcap/sysutil v1.0.1-0.20240311050922-ae81ee01f3a5 github.com/pingcap/tidb v1.1.0-beta.0.20251121075944-8f2630e53d5d diff --git a/go.sum b/go.sum index 1cf2cfe1ce..c49192a9e5 100644 --- a/go.sum +++ b/go.sum @@ -2143,8 +2143,8 @@ github.com/pingcap/fn v1.0.0/go.mod h1:u9WZ1ZiOD1RpNhcI42RucFh/lBuzTu6rw88a+oF2Z github.com/pingcap/goleveldb v0.0.0-20191226122134-f82aafb29989 h1:surzm05a8C9dN8dIUmo4Be2+pMRb6f55i+UIYrluu2E= github.com/pingcap/goleveldb v0.0.0-20191226122134-f82aafb29989/go.mod h1:O17XtbryoCJhkKGbT62+L2OlrniwqiGLSqrmdHCMzZw= github.com/pingcap/kvproto v0.0.0-20191211054548-3c6b38ea5107/go.mod h1:WWLmULLO7l8IOcQG+t+ItJ3fEcrL5FxF0Wu+HrMy26w= -github.com/pingcap/kvproto v0.0.0-20251109100001-1907922fbd18 h1:ZgebBNwgma8INCfexAX8dfqZo7TWQrvMXHGABEmAY2Y= -github.com/pingcap/kvproto v0.0.0-20251109100001-1907922fbd18/go.mod h1:rXxWk2UnwfUhLXha1jxRWPADw9eMZGWEWCg92Tgmb/8= +github.com/pingcap/kvproto v0.0.0-20260622153037-f3bb7de680cd h1:PYIS5Hp5df4fSrSJ+76yjJnQGdt4ODmE9EHMNX2K+R8= +github.com/pingcap/kvproto v0.0.0-20260622153037-f3bb7de680cd/go.mod h1:rXxWk2UnwfUhLXha1jxRWPADw9eMZGWEWCg92Tgmb/8= github.com/pingcap/log v0.0.0-20191012051959-b742a5d432e9/go.mod h1:4rbK1p9ILyIfb6hU7OG2CiWSqMXnp3JMbiaVJ6mvoY8= github.com/pingcap/log v0.0.0-20210625125904-98ed8e2eb1c7/go.mod h1:8AanEdAHATuRurdGxZXBz0At+9avep+ub7U1AGYLIMM= github.com/pingcap/log v1.1.0/go.mod h1:DWQW5jICDR7UJh4HtxXSM20Churx4CQL0fwL/SoOSA4= diff --git a/logservice/logpuller/priority_task.go b/logservice/logpuller/priority_task.go index 68ef9e885d..5dcbd02faf 100644 --- a/logservice/logpuller/priority_task.go +++ b/logservice/logpuller/priority_task.go @@ -17,6 +17,7 @@ import ( "fmt" "time" + "github.com/pingcap/kvproto/pkg/cdcpb" "github.com/tikv/client-go/v2/oracle" ) @@ -42,6 +43,31 @@ func (t TaskType) String() string { return fmt.Sprintf("%d", t) } +func (t TaskType) scanPriority() cdcpb.ScanPriority { + switch t { + case TaskHighPrior: + return cdcpb.ScanPriority_SCAN_PRIORITY_HIGH + case TaskLowPrior: + return cdcpb.ScanPriority_SCAN_PRIORITY_LOW + default: + return cdcpb.ScanPriority_SCAN_PRIORITY_LOW + } +} + +func taskTypeFromScanPriority(priority cdcpb.ScanPriority) TaskType { + if priority == cdcpb.ScanPriority_SCAN_PRIORITY_HIGH { + return TaskHighPrior + } + return TaskLowPrior +} + +func normalizeScanPriority(priority cdcpb.ScanPriority) cdcpb.ScanPriority { + if priority == cdcpb.ScanPriority_SCAN_PRIORITY_HIGH { + return cdcpb.ScanPriority_SCAN_PRIORITY_HIGH + } + return cdcpb.ScanPriority_SCAN_PRIORITY_LOW +} + // PriorityTask is the interface for priority-based tasks // It implements heap.Item interface type PriorityTask interface { diff --git a/logservice/logpuller/priority_task_test.go b/logservice/logpuller/priority_task_test.go index 5b1b373afb..2b8e3cde11 100644 --- a/logservice/logpuller/priority_task_test.go +++ b/logservice/logpuller/priority_task_test.go @@ -17,10 +17,20 @@ import ( "testing" "time" + "github.com/pingcap/kvproto/pkg/cdcpb" "github.com/stretchr/testify/require" "github.com/tikv/client-go/v2/oracle" ) +func TestTaskTypeScanPriorityMapping(t *testing.T) { + require.Equal(t, cdcpb.ScanPriority_SCAN_PRIORITY_HIGH, TaskHighPrior.scanPriority()) + require.Equal(t, cdcpb.ScanPriority_SCAN_PRIORITY_LOW, TaskLowPrior.scanPriority()) + require.Equal(t, TaskHighPrior, taskTypeFromScanPriority(cdcpb.ScanPriority_SCAN_PRIORITY_HIGH)) + require.Equal(t, TaskLowPrior, taskTypeFromScanPriority(cdcpb.ScanPriority_SCAN_PRIORITY_LOW)) + require.Equal(t, TaskLowPrior, taskTypeFromScanPriority(cdcpb.ScanPriority_SCAN_PRIORITY_UNKNOWN)) + require.Equal(t, cdcpb.ScanPriority_SCAN_PRIORITY_LOW, normalizeScanPriority(cdcpb.ScanPriority_SCAN_PRIORITY_UNKNOWN)) +} + // TestPriorityCalculationLogic tests the priority calculation logic in isolation func TestPriorityCalculationLogic(t *testing.T) { currentTime := time.Now() diff --git a/logservice/logpuller/region_request_worker.go b/logservice/logpuller/region_request_worker.go index 2049335446..309a732522 100644 --- a/logservice/logpuller/region_request_worker.go +++ b/logservice/logpuller/region_request_worker.go @@ -458,6 +458,7 @@ func (s *regionRequestWorker) createRegionRequest(region regionInfo) *cdcpb.Chan EndKey: region.span.EndKey, ExtraOp: kvrpcpb.ExtraOp_ReadOldValue, FilterLoop: region.filterLoop, + ScanPriority: normalizeScanPriority(region.scanPriority), } } diff --git a/logservice/logpuller/region_request_worker_test.go b/logservice/logpuller/region_request_worker_test.go index f9752a0eb3..a7231da794 100644 --- a/logservice/logpuller/region_request_worker_test.go +++ b/logservice/logpuller/region_request_worker_test.go @@ -57,6 +57,42 @@ func prepareRegionForSendTest(region regionInfo) regionInfo { return region } +func TestCreateRegionRequestScanPriority(t *testing.T) { + worker := ®ionRequestWorker{ + client: &subscriptionClient{clusterID: 1}, + } + + for _, tc := range []struct { + name string + priority cdcpb.ScanPriority + expected cdcpb.ScanPriority + }{ + { + name: "high", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_HIGH, + expected: cdcpb.ScanPriority_SCAN_PRIORITY_HIGH, + }, + { + name: "low", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_LOW, + expected: cdcpb.ScanPriority_SCAN_PRIORITY_LOW, + }, + { + name: "unknown defaults to low", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_UNKNOWN, + expected: cdcpb.ScanPriority_SCAN_PRIORITY_LOW, + }, + } { + t.Run(tc.name, func(t *testing.T) { + region := prepareRegionForSendTest(createTestRegionInfo(1, 1)) + region.scanPriority = tc.priority + + req := worker.createRegionRequest(region) + require.Equal(t, tc.expected, req.GetScanPriority()) + }) + } +} + func TestRegionStatesOperation(t *testing.T) { worker := ®ionRequestWorker{} worker.requestedRegions.subscriptions = make(map[SubscriptionID]regionFeedStates) diff --git a/logservice/logpuller/region_state.go b/logservice/logpuller/region_state.go index e9c21a7aad..40e98bdb26 100644 --- a/logservice/logpuller/region_state.go +++ b/logservice/logpuller/region_state.go @@ -16,6 +16,7 @@ package logpuller import ( "sync" + "github.com/pingcap/kvproto/pkg/cdcpb" "github.com/pingcap/ticdc/heartbeatpb" "github.com/pingcap/ticdc/logservice/logpuller/regionlock" "github.com/tikv/client-go/v2/tikv" @@ -46,6 +47,9 @@ type regionInfo struct { // Whether to filter out the value write by cdc itself. // It should be `true` in BDR mode filterLoop bool + // scanPriority is sent to TiKV/CSE so remote incremental scan admission can + // preserve TiCDC's business priority across retries. + scanPriority cdcpb.ScanPriority } func (s *regionInfo) isStopped() bool { @@ -66,6 +70,7 @@ func newRegionInfo( rpcCtx: rpcCtx, subscribedSpan: subscribedSpan, filterLoop: filterLoop, + scanPriority: TaskLowPrior.scanPriority(), } } diff --git a/logservice/logpuller/subscription_client.go b/logservice/logpuller/subscription_client.go index 1aa199bc9a..ad7bea6a5c 100644 --- a/logservice/logpuller/subscription_client.go +++ b/logservice/logpuller/subscription_client.go @@ -796,6 +796,7 @@ func (s *subscriptionClient) divideSpanAndScheduleRegionRequests( // scheduleRegionRequest locks the region's range and send the region to regionTaskQueue, // which will be handled by handleRegions. func (s *subscriptionClient) scheduleRegionRequest(ctx context.Context, region regionInfo, priority TaskType) { + region.scanPriority = priority.scanPriority() lockRangeResult := region.subscribedSpan.rangeLock.LockRange( ctx, region.span.StartKey, region.span.EndKey, region.verID.GetID(), region.verID.GetVer()) @@ -872,12 +873,12 @@ func (s *subscriptionClient) doHandleError(ctx context.Context, errInfo regionEr } if innerErr.GetCongested() != nil { metricKvCongestedCounter.Inc() - s.scheduleRegionRequest(ctx, errInfo.regionInfo, TaskLowPrior) + s.scheduleRegionRequest(ctx, errInfo.regionInfo, taskTypeFromScanPriority(errInfo.scanPriority)) return nil } if innerErr.GetServerIsBusy() != nil { metricKvIsBusyCounter.Inc() - s.scheduleRegionRequest(ctx, errInfo.regionInfo, TaskLowPrior) + s.scheduleRegionRequest(ctx, errInfo.regionInfo, taskTypeFromScanPriority(errInfo.scanPriority)) return nil } if duplicated := innerErr.GetDuplicateRequest(); duplicated != nil { diff --git a/logservice/logpuller/subscription_client_test.go b/logservice/logpuller/subscription_client_test.go index be5ff52675..495a50dbc1 100644 --- a/logservice/logpuller/subscription_client_test.go +++ b/logservice/logpuller/subscription_client_test.go @@ -21,6 +21,7 @@ import ( "github.com/pingcap/errors" "github.com/pingcap/kvproto/pkg/cdcpb" + "github.com/pingcap/kvproto/pkg/errorpb" "github.com/pingcap/ticdc/heartbeatpb" "github.com/pingcap/ticdc/logservice/logpuller/regionlock" "github.com/pingcap/ticdc/pkg/common" @@ -226,6 +227,69 @@ func TestOnRegionFailQueuesCanceledErrorCache(t *testing.T) { require.NotContains(t, client.totalSpans.spanMap, span.subID) } +func TestBusyRetryPreservesScanPriority(t *testing.T) { + for _, tc := range []struct { + name string + priority cdcpb.ScanPriority + cdcErr *cdcpb.Error + expected TaskType + }{ + { + name: "server is busy high", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_HIGH, + cdcErr: &cdcpb.Error{ServerIsBusy: &errorpb.ServerIsBusy{}}, + expected: TaskHighPrior, + }, + { + name: "server is busy low", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_LOW, + cdcErr: &cdcpb.Error{ServerIsBusy: &errorpb.ServerIsBusy{}}, + expected: TaskLowPrior, + }, + { + name: "congested high", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_HIGH, + cdcErr: &cdcpb.Error{Congested: &cdcpb.Congested{}}, + expected: TaskHighPrior, + }, + { + name: "congested low", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_LOW, + cdcErr: &cdcpb.Error{Congested: &cdcpb.Congested{}}, + expected: TaskLowPrior, + }, + } { + t.Run(tc.name, func(t *testing.T) { + client := &subscriptionClient{ + regionTaskQueue: NewPriorityQueue(), + } + client.pdClock = pdutil.NewClock4Test() + rawSpan := heartbeatpb.TableSpan{ + TableID: 1, + StartKey: []byte("a"), + EndKey: []byte("z"), + } + span := &subscribedSpan{ + subID: SubscriptionID(1), + span: rawSpan, + rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), + } + region := newRegionInfo(tikv.NewRegionVerID(1, 1, 1), rawSpan, nil, span, false) + region.scanPriority = tc.priority + + err := client.doHandleError(context.Background(), newRegionErrorInfo(region, &eventError{err: tc.cdcErr})) + require.NoError(t, err) + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + task, err := client.regionTaskQueue.Pop(ctx) + require.NoError(t, err) + require.Equal(t, tc.expected, task.(*regionPriorityTask).taskType) + require.Equal(t, tc.priority, task.GetRegionInfo().scanPriority) + }) + } +} + type mockDynamicStream struct{} func (s *mockDynamicStream) Start() {} From 638d564c90239c73d5ba912ab093582400aa79c2 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Fri, 26 Jun 2026 16:14:53 +0800 Subject: [PATCH 02/21] logpuller: preserve scan priority for retries --- logservice/logpuller/subscription_client.go | 19 ++-- .../logpuller/subscription_client_test.go | 87 +++++++++++++++++++ 2 files changed, 97 insertions(+), 9 deletions(-) diff --git a/logservice/logpuller/subscription_client.go b/logservice/logpuller/subscription_client.go index ad7bea6a5c..8ffb83585a 100644 --- a/logservice/logpuller/subscription_client.go +++ b/logservice/logpuller/subscription_client.go @@ -845,6 +845,7 @@ func (s *subscriptionClient) handleErrors(ctx context.Context) error { func (s *subscriptionClient) doHandleError(ctx context.Context, errInfo regionErrorInfo) error { err := errors.Cause(errInfo.err) + retryPriority := taskTypeFromScanPriority(errInfo.scanPriority) if _, requestCancelled := err.(*requestCancelledErr); !requestCancelled { log.Debug("cdc region error", zap.Uint64("subscriptionID", uint64(errInfo.subscribedSpan.subID)), @@ -858,27 +859,27 @@ func (s *subscriptionClient) doHandleError(ctx context.Context, errInfo regionEr if notLeader := innerErr.GetNotLeader(); notLeader != nil { metricFeedNotLeaderCounter.Inc() s.regionCache.UpdateLeader(errInfo.verID, notLeader.GetLeader(), errInfo.rpcCtx.AccessIdx) - s.scheduleRegionRequest(ctx, errInfo.regionInfo, TaskHighPrior) + s.scheduleRegionRequest(ctx, errInfo.regionInfo, retryPriority) return nil } if innerErr.GetEpochNotMatch() != nil { metricFeedEpochNotMatchCounter.Inc() - s.scheduleRangeRequest(ctx, errInfo.span, errInfo.subscribedSpan, errInfo.filterLoop, TaskHighPrior) + s.scheduleRangeRequest(ctx, errInfo.span, errInfo.subscribedSpan, errInfo.filterLoop, retryPriority) return nil } if innerErr.GetRegionNotFound() != nil { metricFeedRegionNotFoundCounter.Inc() - s.scheduleRangeRequest(ctx, errInfo.span, errInfo.subscribedSpan, errInfo.filterLoop, TaskHighPrior) + s.scheduleRangeRequest(ctx, errInfo.span, errInfo.subscribedSpan, errInfo.filterLoop, retryPriority) return nil } if innerErr.GetCongested() != nil { metricKvCongestedCounter.Inc() - s.scheduleRegionRequest(ctx, errInfo.regionInfo, taskTypeFromScanPriority(errInfo.scanPriority)) + s.scheduleRegionRequest(ctx, errInfo.regionInfo, retryPriority) return nil } if innerErr.GetServerIsBusy() != nil { metricKvIsBusyCounter.Inc() - s.scheduleRegionRequest(ctx, errInfo.regionInfo, taskTypeFromScanPriority(errInfo.scanPriority)) + s.scheduleRegionRequest(ctx, errInfo.regionInfo, retryPriority) return nil } if duplicated := innerErr.GetDuplicateRequest(); duplicated != nil { @@ -897,24 +898,24 @@ func (s *subscriptionClient) doHandleError(ctx context.Context, errInfo regionEr zap.Uint64("subscriptionID", uint64(errInfo.subscribedSpan.subID)), zap.Stringer("error", innerErr)) metricFeedUnknownErrorCounter.Inc() - s.scheduleRegionRequest(ctx, errInfo.regionInfo, TaskHighPrior) + s.scheduleRegionRequest(ctx, errInfo.regionInfo, retryPriority) return nil case *rpcCtxUnavailableErr: metricFeedRPCCtxUnavailable.Inc() - s.scheduleRangeRequest(ctx, errInfo.span, errInfo.subscribedSpan, errInfo.filterLoop, TaskHighPrior) + s.scheduleRangeRequest(ctx, errInfo.span, errInfo.subscribedSpan, errInfo.filterLoop, retryPriority) return nil case *getStoreErr: metricGetStoreErr.Inc() bo := tikv.NewBackoffer(ctx, tikvRequestMaxBackoff) // cannot get the store the region belongs to, so we need to reload the region. s.regionCache.OnSendFail(bo, errInfo.rpcCtx, true, err) - s.scheduleRangeRequest(ctx, errInfo.span, errInfo.subscribedSpan, errInfo.filterLoop, TaskHighPrior) + s.scheduleRangeRequest(ctx, errInfo.span, errInfo.subscribedSpan, errInfo.filterLoop, retryPriority) return nil case *storeStreamErr: metricStoreSendRequestErr.Inc() bo := tikv.NewBackoffer(ctx, tikvRequestMaxBackoff) s.regionCache.OnSendFail(bo, errInfo.rpcCtx, regionScheduleReload, err) - s.scheduleRegionRequest(ctx, errInfo.regionInfo, TaskHighPrior) + s.scheduleRegionRequest(ctx, errInfo.regionInfo, retryPriority) return nil case *requestCancelledErr: // the corresponding subscription has been unsubscribed, just ignore. diff --git a/logservice/logpuller/subscription_client_test.go b/logservice/logpuller/subscription_client_test.go index 495a50dbc1..c3e899625e 100644 --- a/logservice/logpuller/subscription_client_test.go +++ b/logservice/logpuller/subscription_client_test.go @@ -258,6 +258,18 @@ func TestBusyRetryPreservesScanPriority(t *testing.T) { cdcErr: &cdcpb.Error{Congested: &cdcpb.Congested{}}, expected: TaskLowPrior, }, + { + name: "unknown retry high", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_HIGH, + cdcErr: &cdcpb.Error{}, + expected: TaskHighPrior, + }, + { + name: "unknown retry low", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_LOW, + cdcErr: &cdcpb.Error{}, + expected: TaskLowPrior, + }, } { t.Run(tc.name, func(t *testing.T) { client := &subscriptionClient{ @@ -290,6 +302,81 @@ func TestBusyRetryPreservesScanPriority(t *testing.T) { } } +func TestRangeRetryPreservesScanPriority(t *testing.T) { + for _, tc := range []struct { + name string + priority cdcpb.ScanPriority + err error + expected TaskType + }{ + { + name: "epoch not match high", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_HIGH, + err: &eventError{err: &cdcpb.Error{EpochNotMatch: &errorpb.EpochNotMatch{}}}, + expected: TaskHighPrior, + }, + { + name: "epoch not match low", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_LOW, + err: &eventError{err: &cdcpb.Error{EpochNotMatch: &errorpb.EpochNotMatch{}}}, + expected: TaskLowPrior, + }, + { + name: "region not found high", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_HIGH, + err: &eventError{err: &cdcpb.Error{RegionNotFound: &errorpb.RegionNotFound{}}}, + expected: TaskHighPrior, + }, + { + name: "region not found low", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_LOW, + err: &eventError{err: &cdcpb.Error{RegionNotFound: &errorpb.RegionNotFound{}}}, + expected: TaskLowPrior, + }, + { + name: "rpc context unavailable high", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_HIGH, + err: &rpcCtxUnavailableErr{verID: tikv.NewRegionVerID(1, 1, 1)}, + expected: TaskHighPrior, + }, + { + name: "rpc context unavailable low", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_LOW, + err: &rpcCtxUnavailableErr{verID: tikv.NewRegionVerID(1, 1, 1)}, + expected: TaskLowPrior, + }, + } { + t.Run(tc.name, func(t *testing.T) { + client := &subscriptionClient{ + rangeTaskCh: make(chan rangeTask, 1), + } + rawSpan := heartbeatpb.TableSpan{ + TableID: 1, + StartKey: []byte("a"), + EndKey: []byte("z"), + } + span := &subscribedSpan{ + subID: SubscriptionID(1), + span: rawSpan, + rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), + } + region := newRegionInfo(tikv.NewRegionVerID(1, 1, 1), rawSpan, nil, span, false) + region.scanPriority = tc.priority + + err := client.doHandleError(context.Background(), newRegionErrorInfo(region, tc.err)) + require.NoError(t, err) + + select { + case task := <-client.rangeTaskCh: + require.Equal(t, tc.expected, task.priority) + require.Equal(t, rawSpan, task.span) + case <-time.After(time.Second): + require.Fail(t, "expected range retry task") + } + }) + } +} + type mockDynamicStream struct{} func (s *mockDynamicStream) Start() {} From 4e95247cd276ba4a3344a552b2891bdb94351459 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Fri, 26 Jun 2026 18:39:15 +0800 Subject: [PATCH 03/21] logservice: add changefeed scan task logs Signed-off-by: hongyunyan <649330952@qq.com> --- logservice/eventstore/event_store.go | 9 ++++- logservice/eventstore/event_store_test.go | 1 + logservice/logpuller/priority_task.go | 11 ++++++ logservice/logpuller/region_req_cache_test.go | 7 ++-- logservice/logpuller/region_request_worker.go | 2 ++ .../logpuller/region_request_worker_test.go | 1 + logservice/logpuller/subscription_client.go | 36 ++++++++++++++----- .../logpuller/subscription_client_test.go | 8 ++--- logservice/schemastore/ddl_job_fetcher.go | 12 ++++++- 9 files changed, 69 insertions(+), 18 deletions(-) diff --git a/logservice/eventstore/event_store.go b/logservice/eventstore/event_store.go index 4605fab8f3..81d6354214 100644 --- a/logservice/eventstore/event_store.go +++ b/logservice/eventstore/event_store.go @@ -463,12 +463,14 @@ func (e *eventStore) RegisterDispatcher( metrics.EventStoreRegisterDispatcherStartTsLagHist.Observe(lag.Seconds()) if lag >= 10*time.Second { log.Warn("register dispatcher with large startTs lag", + zap.Stringer("changefeedID", changefeedID), zap.Stringer("dispatcherID", dispatcherID), zap.String("span", common.FormatTableSpan(dispatcherSpan)), zap.Uint64("startTs", startTs), zap.Duration("lag", lag)) } else { log.Info("register dispatcher", + zap.Stringer("changefeedID", changefeedID), zap.Stringer("dispatcherID", dispatcherID), zap.String("span", common.FormatTableSpan(dispatcherSpan)), zap.Uint64("startTs", startTs)) @@ -478,6 +480,7 @@ func (e *eventStore) RegisterDispatcher( defer func() { if success { log.Info("register dispatcher success", + zap.Stringer("changefeedID", changefeedID), zap.Stringer("dispatcherID", dispatcherID), zap.String("span", common.FormatTableSpan(dispatcherSpan)), zap.Uint64("startTs", startTs), @@ -486,6 +489,7 @@ func (e *eventStore) RegisterDispatcher( zap.Duration("duration", time.Since(start))) } else { log.Info("register dispatcher failed", + zap.Stringer("changefeedID", changefeedID), zap.Stringer("dispatcherID", dispatcherID), zap.String("span", common.FormatTableSpan(dispatcherSpan)), zap.Uint64("startTs", startTs), @@ -533,6 +537,7 @@ func (e *eventStore) RegisterDispatcher( e.addSubscriberToSubStat(subStat, dispatcherID, &Subscriber{notifyFunc: wrappedNotifier}) e.dispatcherMeta.Unlock() log.Info("reuse existing subscription with exact span match", + zap.Stringer("changefeedID", changefeedID), zap.Stringer("dispatcherID", dispatcherID), zap.String("dispatcherSpan", common.FormatTableSpan(dispatcherSpan)), zap.Uint64("startTs", startTs), @@ -559,6 +564,7 @@ func (e *eventStore) RegisterDispatcher( e.dispatcherMeta.dispatcherStats[dispatcherID] = stat e.addSubscriberToSubStat(bestMatch, dispatcherID, &Subscriber{notifyFunc: wrappedNotifier}) log.Info("reuse existing subscription with smallest containing span", + zap.Stringer("changefeedID", changefeedID), zap.Stringer("dispatcherID", dispatcherID), zap.String("dispatcherSpan", common.FormatTableSpan(dispatcherSpan)), zap.Uint64("startTs", startTs), @@ -661,8 +667,9 @@ func (e *eventStore) RegisterDispatcher( serverConfig := config.GetGlobalServerConfig() resolvedTsAdvanceInterval := int64(serverConfig.KVClient.AdvanceIntervalInMs) // Note: don't hold any lock when call Subscribe - e.subClient.Subscribe(subStat.subID, *dispatcherSpan, startTs, consumeKVEvents, advanceResolvedTs, resolvedTsAdvanceInterval, bdrMode) + e.subClient.Subscribe(changefeedID.String(), subStat.subID, *dispatcherSpan, startTs, consumeKVEvents, advanceResolvedTs, resolvedTsAdvanceInterval, bdrMode) log.Info("new subscription created", + zap.Stringer("changefeedID", changefeedID), zap.Stringer("dispatcherID", dispatcherID), zap.Uint64("startTs", startTs), zap.Uint64("subscriptionID", uint64(subStat.subID)), diff --git a/logservice/eventstore/event_store_test.go b/logservice/eventstore/event_store_test.go index eb92c90715..6de83f9cbd 100644 --- a/logservice/eventstore/event_store_test.go +++ b/logservice/eventstore/event_store_test.go @@ -72,6 +72,7 @@ func (s *mockSubscriptionClient) AllocSubscriptionID() logpuller.SubscriptionID } func (s *mockSubscriptionClient) Subscribe( + changefeedID string, subID logpuller.SubscriptionID, span heartbeatpb.TableSpan, startTs uint64, diff --git a/logservice/logpuller/priority_task.go b/logservice/logpuller/priority_task.go index 5dcbd02faf..208812a62e 100644 --- a/logservice/logpuller/priority_task.go +++ b/logservice/logpuller/priority_task.go @@ -43,6 +43,17 @@ func (t TaskType) String() string { return fmt.Sprintf("%d", t) } +func taskTypeLogName(t TaskType) string { + switch t { + case TaskHighPrior: + return "high" + case TaskLowPrior: + return "low" + default: + return "unknown" + } +} + func (t TaskType) scanPriority() cdcpb.ScanPriority { switch t { case TaskHighPrior: diff --git a/logservice/logpuller/region_req_cache_test.go b/logservice/logpuller/region_req_cache_test.go index 62706a8542..c4f223033d 100644 --- a/logservice/logpuller/region_req_cache_test.go +++ b/logservice/logpuller/region_req_cache_test.go @@ -33,9 +33,10 @@ func createTestRegionInfo(subID SubscriptionID, regionID uint64) regionInfo { } subscribedSpan := &subscribedSpan{ - subID: subID, - startTs: 100, - span: span, + subID: subID, + changefeedID: "test/test-changefeed", + startTs: 100, + span: span, } return newRegionInfo(verID, span, nil, subscribedSpan, false) diff --git a/logservice/logpuller/region_request_worker.go b/logservice/logpuller/region_request_worker.go index 309a732522..2331cfff25 100644 --- a/logservice/logpuller/region_request_worker.go +++ b/logservice/logpuller/region_request_worker.go @@ -384,6 +384,7 @@ func (s *regionRequestWorker) processRegionSendTask( subID := region.subscribedSpan.subID log.Debug("region request worker gets a singleRegionInfo", zap.Uint64("workerID", s.workerID), + zap.String("changefeedID", region.subscribedSpan.changefeedID), zap.Uint64("subscriptionID", uint64(subID)), zap.Uint64("regionID", region.verID.GetID()), zap.String("addr", s.store.storeAddr), @@ -452,6 +453,7 @@ func (s *regionRequestWorker) createRegionRequest(region regionInfo) *cdcpb.Chan Header: &cdcpb.Header{ClusterId: s.client.clusterID, TicdcVersion: version.ReleaseSemver()}, RegionId: region.verID.GetID(), RequestId: uint64(region.subscribedSpan.subID), + ChangefeedId: region.subscribedSpan.changefeedID, RegionEpoch: region.rpcCtx.Meta.RegionEpoch, CheckpointTs: region.resolvedTs(), StartKey: region.span.StartKey, diff --git a/logservice/logpuller/region_request_worker_test.go b/logservice/logpuller/region_request_worker_test.go index a7231da794..7b742ae2bb 100644 --- a/logservice/logpuller/region_request_worker_test.go +++ b/logservice/logpuller/region_request_worker_test.go @@ -89,6 +89,7 @@ func TestCreateRegionRequestScanPriority(t *testing.T) { req := worker.createRegionRequest(region) require.Equal(t, tc.expected, req.GetScanPriority()) + require.Equal(t, "test/test-changefeed", req.GetChangefeedId()) }) } } diff --git a/logservice/logpuller/subscription_client.go b/logservice/logpuller/subscription_client.go index 8ffb83585a..56c16c808b 100644 --- a/logservice/logpuller/subscription_client.go +++ b/logservice/logpuller/subscription_client.go @@ -110,8 +110,9 @@ const kvEventsCacheMaxSize = 32 // It contains a sub span of a table(or the total span of a table), // the startTs of the table, and the output event channel. type subscribedSpan struct { - subID SubscriptionID - startTs uint64 + subID SubscriptionID + changefeedID string + startTs uint64 // Whether to filter out the value written by TiCDC itself. // It should be `true` in BDR mode. filterLoop bool @@ -170,6 +171,7 @@ type SubscriptionClient interface { AllocSubscriptionID() SubscriptionID // subscribe a table span Subscribe( + changefeedID string, subID SubscriptionID, span heartbeatpb.TableSpan, startTs uint64, @@ -349,6 +351,7 @@ func (s *subscriptionClient) updateMetrics(ctx context.Context) error { // and send a rangeTask to `s.rangeTaskCh`. // The rangeTask will be handled in `handleRangeTasks` goroutine. func (s *subscriptionClient) Subscribe( + changefeedID string, subID SubscriptionID, span heartbeatpb.TableSpan, startTs uint64, @@ -362,7 +365,7 @@ func (s *subscriptionClient) Subscribe( return } - rt := s.newSubscribedSpan(subID, span, startTs, consumeKVEvents, advanceResolvedTs, advanceInterval, bdrMode) + rt := s.newSubscribedSpan(changefeedID, subID, span, startTs, consumeKVEvents, advanceResolvedTs, advanceInterval, bdrMode) s.totalSpans.Lock() s.totalSpans.spanMap[subID] = rt s.totalSpans.Unlock() @@ -374,7 +377,9 @@ func (s *subscriptionClient) Subscribe( case <-s.ctx.Done(): log.Warn("subscribes span failed, the subscription client has closed") case s.rangeTaskCh <- rangeTask{span: span, subscribedSpan: rt, filterLoop: rt.filterLoop, priority: TaskLowPrior}: - log.Info("subscribes span done", zap.Uint64("subscriptionID", uint64(subID)), + log.Info("subscribes span done", + zap.String("changefeedID", changefeedID), + zap.Uint64("subscriptionID", uint64(subID)), zap.Int64("tableID", span.TableID), zap.Uint64("startTs", startTs), zap.String("startKey", spanz.HexKey(span.StartKey)), zap.String("endKey", spanz.HexKey(span.EndKey))) } @@ -808,6 +813,17 @@ func (s *subscriptionClient) scheduleRegionRequest(ctx context.Context, region r case regionlock.LockRangeStatusSuccess: region.lockedRangeState = lockRangeResult.LockedRangeState s.regionTaskQueue.Push(NewRegionPriorityTask(priority, region, s.pdClock.CurrentTS())) + log.Info("cdc region scan task enqueued", + zap.String("changefeedID", region.subscribedSpan.changefeedID), + zap.Uint64("subscriptionID", uint64(region.subscribedSpan.subID)), + zap.Int64("tableID", region.subscribedSpan.span.TableID), + zap.Uint64("startTs", region.subscribedSpan.startTs), + zap.Uint64("regionID", region.verID.GetID()), + zap.Uint64("regionEpochVersion", region.verID.GetVer()), + zap.Uint64("regionEpochConfVer", region.verID.GetConfVer()), + zap.String("priority", taskTypeLogName(priority)), + zap.String("scanPriority", region.scanPriority.String()), + zap.String("span", common.FormatTableSpan(®ion.span))) case regionlock.LockRangeStatusStale: for _, r := range lockRangeResult.RetryRanges { s.scheduleRangeRequest(ctx, r, region.subscribedSpan, region.filterLoop, priority) @@ -1081,6 +1097,7 @@ func (s *subscriptionClient) logSlowRegions(ctx context.Context) error { } func (s *subscriptionClient) newSubscribedSpan( + changefeedID string, subID SubscriptionID, span heartbeatpb.TableSpan, startTs uint64, @@ -1092,11 +1109,12 @@ func (s *subscriptionClient) newSubscribedSpan( rangeLock := regionlock.NewRangeLock(uint64(subID), span.StartKey, span.EndKey, startTs) rt := &subscribedSpan{ - subID: subID, - span: span, - startTs: startTs, - filterLoop: filterLoop, - rangeLock: rangeLock, + subID: subID, + changefeedID: changefeedID, + span: span, + startTs: startTs, + filterLoop: filterLoop, + rangeLock: rangeLock, consumeKVEvents: consumeKVEvents, advanceResolvedTs: advanceResolvedTs, diff --git a/logservice/logpuller/subscription_client_test.go b/logservice/logpuller/subscription_client_test.go index c3e899625e..d8806c747b 100644 --- a/logservice/logpuller/subscription_client_test.go +++ b/logservice/logpuller/subscription_client_test.go @@ -50,7 +50,7 @@ func TestGenerateResolveLockTask(t *testing.T) { } consumeKVEvents := func(_ []common.RawKVEntry, _ func()) bool { return false } advanceResolvedTs := func(ts uint64) {} - span := client.newSubscribedSpan(SubscriptionID(1), rawSpan, 100, consumeKVEvents, advanceResolvedTs, 0, false) + span := client.newSubscribedSpan("test/test-changefeed", SubscriptionID(1), rawSpan, 100, consumeKVEvents, advanceResolvedTs, 0, false) client.totalSpans.spanMap = make(map[SubscriptionID]*subscribedSpan) client.totalSpans.spanMap[SubscriptionID(1)] = span client.pdClock = pdutil.NewClock4Test() @@ -119,7 +119,7 @@ func TestResolveLockTaskDroppedWhenChannelFull(t *testing.T) { } consumeKVEvents := func(_ []common.RawKVEntry, _ func()) bool { return false } advanceResolvedTs := func(ts uint64) {} - span := client.newSubscribedSpan(SubscriptionID(1), rawSpan, 100, consumeKVEvents, advanceResolvedTs, 0, false) + span := client.newSubscribedSpan("test/test-changefeed", SubscriptionID(1), rawSpan, 100, consumeKVEvents, advanceResolvedTs, 0, false) res := span.rangeLock.LockRange(context.Background(), []byte{'b'}, []byte{'c'}, 1, 100) require.Equal(t, regionlock.LockRangeStatusSuccess, res.Status) @@ -167,7 +167,7 @@ func TestStopTaskUsesSubscribedSpanFilterLoop(t *testing.T) { } consumeKVEvents := func(_ []common.RawKVEntry, _ func()) bool { return false } advanceResolvedTs := func(ts uint64) {} - span := client.newSubscribedSpan(SubscriptionID(1), rawSpan, 100, consumeKVEvents, advanceResolvedTs, 0, true) + span := client.newSubscribedSpan("test/test-changefeed", SubscriptionID(1), rawSpan, 100, consumeKVEvents, advanceResolvedTs, 0, true) res := span.rangeLock.LockRange(context.Background(), rawSpan.StartKey, rawSpan.EndKey, 1, 1) require.Equal(t, regionlock.LockRangeStatusSuccess, res.Status) @@ -546,7 +546,7 @@ func TestSubscriptionWithFailedTiKV(t *testing.T) { case tsCh <- ts: } } - client.Subscribe(subID, span, 1, consumeKVEvents, advanceResolvedTs, 0, false) + client.Subscribe("test/test-changefeed", subID, span, 1, consumeKVEvents, advanceResolvedTs, 0, false) eventsCh1 <- mockInitializedEvent(11, uint64(subID)) targetTs := oracle.GoTimeToTS(pdClock.CurrentTime()) diff --git a/logservice/schemastore/ddl_job_fetcher.go b/logservice/schemastore/ddl_job_fetcher.go index 16e079e290..018d17f545 100644 --- a/logservice/schemastore/ddl_job_fetcher.go +++ b/logservice/schemastore/ddl_job_fetcher.go @@ -15,6 +15,7 @@ package schemastore import ( "context" + "fmt" "math" "sync" @@ -96,7 +97,16 @@ func (p *ddlJobFetcher) run(startTs uint64) error { advanceSubSpanResolvedTs := func(ts uint64) { p.tryAdvanceResolvedTs(subID, ts) } - p.subClient.Subscribe(subID, span, startTs, p.input, advanceSubSpanResolvedTs, 0, ddlPullerFilterLoop) + p.subClient.Subscribe( + fmt.Sprintf("schema-store/ddl-job-fetcher-%d", p.keyspaceID), + subID, + span, + startTs, + p.input, + advanceSubSpanResolvedTs, + 0, + ddlPullerFilterLoop, + ) } return nil } From 367bf9ce1787b9da44a1a756b396e9bcfa43710d Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Sat, 27 Jun 2026 10:27:16 +0800 Subject: [PATCH 04/21] logpuller: classify initial scan priority by start ts Signed-off-by: hongyunyan <649330952@qq.com> --- logservice/logpuller/subscription_client.go | 21 +++- .../logpuller/subscription_client_test.go | 107 ++++++++++++++++++ pkg/config/debug.go | 19 ++++ 3 files changed, 146 insertions(+), 1 deletion(-) diff --git a/logservice/logpuller/subscription_client.go b/logservice/logpuller/subscription_client.go index 56c16c808b..686bf16886 100644 --- a/logservice/logpuller/subscription_client.go +++ b/logservice/logpuller/subscription_client.go @@ -373,18 +373,37 @@ func (s *subscriptionClient) Subscribe( areaSetting := dynstream.NewAreaSettingsWithMaxPendingSize(1*1024*1024*1024, dynstream.MemoryControlForPuller, "logPuller") // 1GB s.ds.AddPath(rt.subID, rt, areaSetting) + initialPriority := s.initialScanTaskPriority(startTs) select { case <-s.ctx.Done(): log.Warn("subscribes span failed, the subscription client has closed") - case s.rangeTaskCh <- rangeTask{span: span, subscribedSpan: rt, filterLoop: rt.filterLoop, priority: TaskLowPrior}: + case s.rangeTaskCh <- rangeTask{span: span, subscribedSpan: rt, filterLoop: rt.filterLoop, priority: initialPriority}: log.Info("subscribes span done", zap.String("changefeedID", changefeedID), zap.Uint64("subscriptionID", uint64(subID)), zap.Int64("tableID", span.TableID), zap.Uint64("startTs", startTs), + zap.String("initialScanPriority", taskTypeLogName(initialPriority)), zap.String("startKey", spanz.HexKey(span.StartKey)), zap.String("endKey", spanz.HexKey(span.EndKey))) } } +func (s *subscriptionClient) initialScanTaskPriority(startTs uint64) TaskType { + if startTs == 0 { + return TaskLowPrior + } + + threshold := time.Duration(config.GetGlobalServerConfig().Debug.Puller.OldStartTsScanLowPriorityThreshold) + if threshold <= 0 { + threshold = config.DefaultOldStartTsScanLowPriorityThreshold + } + + startTime := oracle.GetTimeFromTS(startTs) + if s.pdClock.CurrentTime().Sub(startTime) > threshold { + return TaskLowPrior + } + return TaskHighPrior +} + // Unsubscribe the given table span. All covered regions will be deregistered asynchronously. // NOTE: `span.TableID` must be set correctly. func (s *subscriptionClient) Unsubscribe(subID SubscriptionID) { diff --git a/logservice/logpuller/subscription_client_test.go b/logservice/logpuller/subscription_client_test.go index d8806c747b..4eb587eda3 100644 --- a/logservice/logpuller/subscription_client_test.go +++ b/logservice/logpuller/subscription_client_test.go @@ -26,6 +26,7 @@ import ( "github.com/pingcap/ticdc/logservice/logpuller/regionlock" "github.com/pingcap/ticdc/pkg/common" appcontext "github.com/pingcap/ticdc/pkg/common/context" + "github.com/pingcap/ticdc/pkg/config" "github.com/pingcap/ticdc/pkg/metrics" "github.com/pingcap/ticdc/pkg/pdutil" "github.com/pingcap/ticdc/pkg/security" @@ -407,6 +408,112 @@ func (s *mockDynamicStream) GetMetrics() dynstream.Metrics[int, SubscriptionID] return dynstream.Metrics[int, SubscriptionID]{} } +func TestInitialScanTaskPriority(t *testing.T) { + restore := setInitialScanLowPriorityThresholdForTest(t, 30*time.Minute) + defer restore() + + currentTime := time.Date(2026, time.June, 27, 12, 0, 0, 0, time.UTC) + pdClock := pdutil.NewClock4Test() + pdClock.(*pdutil.Clock4Test).SetTS(oracle.GoTimeToTS(currentTime)) + client := &subscriptionClient{ + pdClock: pdClock, + } + + for _, tc := range []struct { + name string + startTs uint64 + expected TaskType + }{ + { + name: "zero start ts", + startTs: 0, + expected: TaskLowPrior, + }, + { + name: "recent start ts", + startTs: oracle.GoTimeToTS(currentTime.Add(-29 * time.Minute)), + expected: TaskHighPrior, + }, + { + name: "threshold boundary", + startTs: oracle.GoTimeToTS(currentTime.Add(-30 * time.Minute)), + expected: TaskHighPrior, + }, + { + name: "old start ts", + startTs: oracle.GoTimeToTS(currentTime.Add(-31 * time.Minute)), + expected: TaskLowPrior, + }, + { + name: "future start ts", + startTs: oracle.GoTimeToTS(currentTime.Add(time.Minute)), + expected: TaskHighPrior, + }, + } { + t.Run(tc.name, func(t *testing.T) { + require.Equal(t, tc.expected, client.initialScanTaskPriority(tc.startTs)) + }) + } +} + +func TestSubscribeUsesInitialScanTaskPriority(t *testing.T) { + restore := setInitialScanLowPriorityThresholdForTest(t, 30*time.Minute) + defer restore() + + ctx, cancel := context.WithCancel(context.Background()) + defer cancel() + + currentTime := time.Date(2026, time.June, 27, 12, 0, 0, 0, time.UTC) + pdClock := pdutil.NewClock4Test() + pdClock.(*pdutil.Clock4Test).SetTS(oracle.GoTimeToTS(currentTime)) + client := &subscriptionClient{ + ctx: ctx, + ds: &mockDynamicStream{}, + rangeTaskCh: make(chan rangeTask, 2), + pdClock: pdClock, + } + client.totalSpans.spanMap = make(map[SubscriptionID]*subscribedSpan) + + span := heartbeatpb.TableSpan{TableID: 1, StartKey: []byte("a"), EndKey: []byte("z")} + consumeKVEvents := func(_ []common.RawKVEntry, _ func()) bool { return false } + advanceResolvedTs := func(uint64) {} + + client.Subscribe( + "test/recent-changefeed", + SubscriptionID(1), + span, + oracle.GoTimeToTS(currentTime.Add(-time.Minute)), + consumeKVEvents, + advanceResolvedTs, + 0, + false, + ) + client.Subscribe( + "test/old-changefeed", + SubscriptionID(2), + span, + oracle.GoTimeToTS(currentTime.Add(-31*time.Minute)), + consumeKVEvents, + advanceResolvedTs, + 0, + false, + ) + + require.Equal(t, TaskHighPrior, (<-client.rangeTaskCh).priority) + require.Equal(t, TaskLowPrior, (<-client.rangeTaskCh).priority) +} + +func setInitialScanLowPriorityThresholdForTest(t *testing.T, threshold time.Duration) func() { + t.Helper() + oldConfig := config.GetGlobalServerConfig() + testConfig := oldConfig.Clone() + testConfig.Debug.Puller.OldStartTsScanLowPriorityThreshold = config.TomlDuration(threshold) + config.StoreGlobalServerConfig(testConfig) + return func() { + config.StoreGlobalServerConfig(oldConfig) + } +} + func TestPushRegionEventToDSUnblocksOnClose(t *testing.T) { client := &subscriptionClient{ ds: &mockDynamicStream{}, diff --git a/pkg/config/debug.go b/pkg/config/debug.go index 148e927430..236711800f 100644 --- a/pkg/config/debug.go +++ b/pkg/config/debug.go @@ -19,6 +19,12 @@ import ( "github.com/pingcap/errors" ) +const ( + // DefaultOldStartTsScanLowPriorityThreshold is the default age threshold for + // classifying initial scan tasks as low priority. + DefaultOldStartTsScanLowPriorityThreshold = 30 * time.Minute +) + // DebugConfig represents config for ticdc unexposed feature configurations type DebugConfig struct { DB *DBConfig `toml:"db" json:"db"` @@ -49,6 +55,7 @@ func (c *DebugConfig) ValidateAndAdjust() error { if err := c.Scheduler.ValidateAndAdjust(); err != nil { return errors.Trace(err) } + c.Puller.ValidateAndAdjust() return nil } @@ -67,6 +74,9 @@ type PullerConfig struct { // For example, if PendingRegionRequestQueueSize is 32 and there are 8 workers connecting to the same store, // each worker's queue size will be 32 / 8 = 4. PendingRegionRequestQueueSize int `toml:"pending-region-request-queue-size" json:"pending_region_request_queue_size"` + // OldStartTsScanLowPriorityThreshold is the startTs age threshold for initial scans. + // Initial scans older than this threshold are scheduled as low priority. + OldStartTsScanLowPriorityThreshold TomlDuration `toml:"old-start-ts-scan-low-priority-threshold" json:"old_start_ts_scan_low_priority_threshold"` } // NewDefaultPullerConfig return the default puller configuration @@ -76,6 +86,15 @@ func NewDefaultPullerConfig() *PullerConfig { ResolvedTsStuckInterval: TomlDuration(5 * time.Minute), LogRegionDetails: false, PendingRegionRequestQueueSize: 32, // This value is chosen to reduce the impact of new changefeeds on existing ones. + OldStartTsScanLowPriorityThreshold: TomlDuration( + DefaultOldStartTsScanLowPriorityThreshold), + } +} + +// ValidateAndAdjust validates and adjusts puller configuration. +func (c *PullerConfig) ValidateAndAdjust() { + if c.OldStartTsScanLowPriorityThreshold <= 0 { + c.OldStartTsScanLowPriorityThreshold = TomlDuration(DefaultOldStartTsScanLowPriorityThreshold) } } From d59155761c63346e04e57e93ad66d5691b08788b Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Mon, 29 Jun 2026 11:09:00 +0800 Subject: [PATCH 05/21] logpuller: protect realtime recovery scans Signed-off-by: hongyunyan <649330952@qq.com> --- logservice/logpuller/region_event_handler.go | 3 + logservice/logpuller/subscription_client.go | 50 +++++++++-- .../logpuller/subscription_client_test.go | 90 +++++++++++++++++++ 3 files changed, 135 insertions(+), 8 deletions(-) diff --git a/logservice/logpuller/region_event_handler.go b/logservice/logpuller/region_event_handler.go index 0de2306c47..1930f6d93e 100644 --- a/logservice/logpuller/region_event_handler.go +++ b/logservice/logpuller/region_event_handler.go @@ -128,6 +128,9 @@ func (h *regionEventHandler) Handle(span *subscribedSpan, events ...regionEvent) if resolvedTs > newResolvedTs { newResolvedTs = resolvedTs } + if resolvedTs > 0 && h.subClient != nil { + h.subClient.maybeEnableRealtimeScanPriority(span, resolvedTs) + } } } else { log.Panic("should not reach", zap.Any("event", event), zap.Any("events", events)) diff --git a/logservice/logpuller/subscription_client.go b/logservice/logpuller/subscription_client.go index 686bf16886..8437305b27 100644 --- a/logservice/logpuller/subscription_client.go +++ b/logservice/logpuller/subscription_client.go @@ -144,6 +144,10 @@ type subscribedSpan struct { initialized atomic.Bool resolvedTsUpdated atomic.Int64 resolvedTs atomic.Uint64 + // realtimeScanPriority is set after this subscription catches up once. + // It is sticky so later recovery scans can protect realtime changefeeds + // even if historical catch-up scans temporarily push their lag up again. + realtimeScanPriority atomic.Bool } func (span *subscribedSpan) clearKVEventsCache() { @@ -388,20 +392,48 @@ func (s *subscriptionClient) Subscribe( } func (s *subscriptionClient) initialScanTaskPriority(startTs uint64) TaskType { - if startTs == 0 { - return TaskLowPrior + if s.isTsCloseToCurrent(startTs) { + return TaskHighPrior } + return TaskLowPrior +} +func (s *subscriptionClient) oldStartTsScanLowPriorityThreshold() time.Duration { threshold := time.Duration(config.GetGlobalServerConfig().Debug.Puller.OldStartTsScanLowPriorityThreshold) - if threshold <= 0 { - threshold = config.DefaultOldStartTsScanLowPriorityThreshold + if threshold > 0 { + return threshold + } + return config.DefaultOldStartTsScanLowPriorityThreshold +} + +func (s *subscriptionClient) isTsCloseToCurrent(ts uint64) bool { + if ts == 0 { + return false + } + return s.pdClock.CurrentTime().Sub(oracle.GetTimeFromTS(ts)) <= s.oldStartTsScanLowPriorityThreshold() +} + +func (s *subscriptionClient) maybeEnableRealtimeScanPriority(span *subscribedSpan, resolvedTs uint64) { + if span == nil || !span.initialized.Load() || span.realtimeScanPriority.Load() { + return + } + if !s.isTsCloseToCurrent(resolvedTs) { + return + } + if span.realtimeScanPriority.CompareAndSwap(false, true) { + log.Info("subscription client enables realtime scan priority", + zap.String("changefeedID", span.changefeedID), + zap.Uint64("subscriptionID", uint64(span.subID)), + zap.Uint64("resolvedTs", resolvedTs), + zap.Duration("threshold", s.oldStartTsScanLowPriorityThreshold())) } +} - startTime := oracle.GetTimeFromTS(startTs) - if s.pdClock.CurrentTime().Sub(startTime) > threshold { - return TaskLowPrior +func (s *subscriptionClient) effectiveScanTaskPriority(subscribedSpan *subscribedSpan, priority TaskType) TaskType { + if subscribedSpan != nil && subscribedSpan.realtimeScanPriority.Load() { + return TaskHighPrior } - return TaskHighPrior + return priority } // Unsubscribe the given table span. All covered regions will be deregistered asynchronously. @@ -820,6 +852,7 @@ func (s *subscriptionClient) divideSpanAndScheduleRegionRequests( // scheduleRegionRequest locks the region's range and send the region to regionTaskQueue, // which will be handled by handleRegions. func (s *subscriptionClient) scheduleRegionRequest(ctx context.Context, region regionInfo, priority TaskType) { + priority = s.effectiveScanTaskPriority(region.subscribedSpan, priority) region.scanPriority = priority.scanPriority() lockRangeResult := region.subscribedSpan.rangeLock.LockRange( ctx, region.span.StartKey, region.span.EndKey, region.verID.GetID(), region.verID.GetVer()) @@ -858,6 +891,7 @@ func (s *subscriptionClient) scheduleRangeRequest( filterLoop bool, priority TaskType, ) { + priority = s.effectiveScanTaskPriority(subscribedSpan, priority) select { case <-ctx.Done(): case s.rangeTaskCh <- rangeTask{span: span, subscribedSpan: subscribedSpan, filterLoop: filterLoop, priority: priority}: diff --git a/logservice/logpuller/subscription_client_test.go b/logservice/logpuller/subscription_client_test.go index 4eb587eda3..d31f54c766 100644 --- a/logservice/logpuller/subscription_client_test.go +++ b/logservice/logpuller/subscription_client_test.go @@ -503,6 +503,96 @@ func TestSubscribeUsesInitialScanTaskPriority(t *testing.T) { require.Equal(t, TaskLowPrior, (<-client.rangeTaskCh).priority) } +func TestRealtimeScanPriorityEnabledAfterSubscriptionCatchesUp(t *testing.T) { + restore := setInitialScanLowPriorityThresholdForTest(t, 30*time.Minute) + defer restore() + + currentTime := time.Date(2026, time.June, 27, 12, 0, 0, 0, time.UTC) + pdClock := pdutil.NewClock4Test() + pdClock.(*pdutil.Clock4Test).SetTS(oracle.GoTimeToTS(currentTime)) + client := &subscriptionClient{ + pdClock: pdClock, + } + + rawSpan := heartbeatpb.TableSpan{TableID: 1, StartKey: []byte("a"), EndKey: []byte("z")} + span := &subscribedSpan{ + subID: SubscriptionID(1), + span: rawSpan, + rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), + } + + client.maybeEnableRealtimeScanPriority(span, oracle.GoTimeToTS(currentTime.Add(-time.Minute))) + require.False(t, span.realtimeScanPriority.Load()) + + span.initialized.Store(true) + client.maybeEnableRealtimeScanPriority(span, oracle.GoTimeToTS(currentTime.Add(-31*time.Minute))) + require.False(t, span.realtimeScanPriority.Load()) + + client.maybeEnableRealtimeScanPriority(span, oracle.GoTimeToTS(currentTime.Add(-time.Minute))) + require.True(t, span.realtimeScanPriority.Load()) + require.Equal(t, TaskHighPrior, client.effectiveScanTaskPriority(span, TaskLowPrior)) +} + +func TestRealtimeScanPriorityUpgradesRegionRetry(t *testing.T) { + client := &subscriptionClient{ + regionTaskQueue: NewPriorityQueue(), + } + client.pdClock = pdutil.NewClock4Test() + rawSpan := heartbeatpb.TableSpan{ + TableID: 1, + StartKey: []byte("a"), + EndKey: []byte("z"), + } + span := &subscribedSpan{ + subID: SubscriptionID(1), + span: rawSpan, + rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), + } + span.realtimeScanPriority.Store(true) + region := newRegionInfo(tikv.NewRegionVerID(1, 1, 1), rawSpan, nil, span, false) + region.scanPriority = cdcpb.ScanPriority_SCAN_PRIORITY_LOW + + err := client.doHandleError(context.Background(), newRegionErrorInfo(region, &eventError{err: &cdcpb.Error{ServerIsBusy: &errorpb.ServerIsBusy{}}})) + require.NoError(t, err) + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + task, err := client.regionTaskQueue.Pop(ctx) + require.NoError(t, err) + require.Equal(t, TaskHighPrior, task.(*regionPriorityTask).taskType) + require.Equal(t, cdcpb.ScanPriority_SCAN_PRIORITY_HIGH, task.GetRegionInfo().scanPriority) +} + +func TestRealtimeScanPriorityUpgradesRangeRetry(t *testing.T) { + client := &subscriptionClient{ + rangeTaskCh: make(chan rangeTask, 1), + } + rawSpan := heartbeatpb.TableSpan{ + TableID: 1, + StartKey: []byte("a"), + EndKey: []byte("z"), + } + span := &subscribedSpan{ + subID: SubscriptionID(1), + span: rawSpan, + rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), + } + span.realtimeScanPriority.Store(true) + region := newRegionInfo(tikv.NewRegionVerID(1, 1, 1), rawSpan, nil, span, false) + region.scanPriority = cdcpb.ScanPriority_SCAN_PRIORITY_LOW + + err := client.doHandleError(context.Background(), newRegionErrorInfo(region, &eventError{err: &cdcpb.Error{EpochNotMatch: &errorpb.EpochNotMatch{}}})) + require.NoError(t, err) + + select { + case task := <-client.rangeTaskCh: + require.Equal(t, TaskHighPrior, task.priority) + require.Equal(t, rawSpan, task.span) + case <-time.After(time.Second): + require.Fail(t, "expected range retry task") + } +} + func setInitialScanLowPriorityThresholdForTest(t *testing.T, threshold time.Duration) func() { t.Helper() oldConfig := config.GetGlobalServerConfig() From 871a7ff0d1deeec6b626370d17e2e22c4847df78 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Tue, 7 Jul 2026 13:52:26 +0800 Subject: [PATCH 06/21] logservice: keep changefeed id in event store merge Signed-off-by: hongyunyan <649330952@qq.com> --- logservice/eventstore/event_store.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/logservice/eventstore/event_store.go b/logservice/eventstore/event_store.go index 1a2766c92f..e68bba3ef6 100644 --- a/logservice/eventstore/event_store.go +++ b/logservice/eventstore/event_store.go @@ -460,7 +460,7 @@ func (e *eventStore) Close(_ context.Context) error { } func (e *eventStore) RegisterDispatcher( - _ common.ChangeFeedID, + changefeedID common.ChangeFeedID, dispatcherID common.DispatcherID, dispatcherSpan *heartbeatpb.TableSpan, startTs uint64, From 3a26268f6cb27284bfb173e59fed60b0db1d5118 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Tue, 7 Jul 2026 14:11:15 +0800 Subject: [PATCH 07/21] logservice: modernize priority scan tests Signed-off-by: hongyunyan <649330952@qq.com> --- logservice/logpuller/subscription_client_test.go | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/logservice/logpuller/subscription_client_test.go b/logservice/logpuller/subscription_client_test.go index 015c2b212a..5ad6a90459 100644 --- a/logservice/logpuller/subscription_client_test.go +++ b/logservice/logpuller/subscription_client_test.go @@ -173,7 +173,7 @@ func TestResolveLockTaskDeduplicatedAcrossSubscribedSpans(t *testing.T) { } func TestHandleResolveLockTasksMetrics(t *testing.T) { - ctx, cancel := context.WithCancel(context.Background()) + ctx, cancel := context.WithCancel(t.Context()) defer cancel() resolver := &mockLockResolver{} @@ -586,8 +586,7 @@ func TestSubscribeUsesInitialScanTaskPriority(t *testing.T) { restore := setInitialScanLowPriorityThresholdForTest(t, 30*time.Minute) defer restore() - ctx, cancel := context.WithCancel(context.Background()) - defer cancel() + ctx := t.Context() currentTime := time.Date(2026, time.June, 27, 12, 0, 0, 0, time.UTC) pdClock := pdutil.NewClock4Test() From 51619e1c40dda6c247ab7ea5e6e9f469e8ef383b Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Tue, 7 Jul 2026 16:05:32 +0800 Subject: [PATCH 08/21] logpuller: simplify scan priority scheduling Signed-off-by: hongyunyan <649330952@qq.com> --- logservice/logpuller/priority_task.go | 5 +- logservice/logpuller/region_event_handler.go | 6 +-- logservice/logpuller/subscription_client.go | 2 +- .../logpuller/subscription_client_test.go | 52 +++++++++---------- 4 files changed, 29 insertions(+), 36 deletions(-) diff --git a/logservice/logpuller/priority_task.go b/logservice/logpuller/priority_task.go index 208812a62e..8f896ec058 100644 --- a/logservice/logpuller/priority_task.go +++ b/logservice/logpuller/priority_task.go @@ -73,10 +73,7 @@ func taskTypeFromScanPriority(priority cdcpb.ScanPriority) TaskType { } func normalizeScanPriority(priority cdcpb.ScanPriority) cdcpb.ScanPriority { - if priority == cdcpb.ScanPriority_SCAN_PRIORITY_HIGH { - return cdcpb.ScanPriority_SCAN_PRIORITY_HIGH - } - return cdcpb.ScanPriority_SCAN_PRIORITY_LOW + return taskTypeFromScanPriority(priority).scanPriority() } // PriorityTask is the interface for priority-based tasks diff --git a/logservice/logpuller/region_event_handler.go b/logservice/logpuller/region_event_handler.go index f788530ef4..d8feaae8cb 100644 --- a/logservice/logpuller/region_event_handler.go +++ b/logservice/logpuller/region_event_handler.go @@ -137,14 +137,14 @@ func (h *regionEventHandler) Handle(span *subscribedSpan, events ...regionEvent) if resolvedTs > newResolvedTs { newResolvedTs = resolvedTs } - if resolvedTs > 0 && h.subClient != nil { - h.subClient.maybeEnableRealtimeScanPriority(span, resolvedTs) - } } } else { log.Panic("should not reach", zap.Any("event", event), zap.Any("events", events)) } } + if newResolvedTs > 0 && h.subClient != nil { + h.subClient.maybeEnableRealtimeScanPriority(span, newResolvedTs) + } tryAdvanceResolvedTs := func() { if newResolvedTs != 0 { span.advanceResolvedTs(newResolvedTs) diff --git a/logservice/logpuller/subscription_client.go b/logservice/logpuller/subscription_client.go index 9b49f0ecfb..6dd725d893 100644 --- a/logservice/logpuller/subscription_client.go +++ b/logservice/logpuller/subscription_client.go @@ -872,7 +872,7 @@ func (s *subscriptionClient) scheduleRegionRequest(ctx context.Context, region r case regionlock.LockRangeStatusSuccess: region.lockedRangeState = lockRangeResult.LockedRangeState s.regionTaskQueue.Push(NewRegionPriorityTask(priority, region, s.pdClock.CurrentTS())) - log.Info("cdc region scan task enqueued", + log.Debug("cdc region scan task enqueued", zap.String("changefeedID", region.subscribedSpan.changefeedID), zap.Uint64("subscriptionID", uint64(region.subscribedSpan.subID)), zap.Int64("tableID", region.subscribedSpan.span.TableID), diff --git a/logservice/logpuller/subscription_client_test.go b/logservice/logpuller/subscription_client_test.go index 5ad6a90459..7c5ba758ae 100644 --- a/logservice/logpuller/subscription_client_test.go +++ b/logservice/logpuller/subscription_client_test.go @@ -639,12 +639,7 @@ func TestRealtimeScanPriorityEnabledAfterSubscriptionCatchesUp(t *testing.T) { pdClock: pdClock, } - rawSpan := heartbeatpb.TableSpan{TableID: 1, StartKey: []byte("a"), EndKey: []byte("z")} - span := &subscribedSpan{ - subID: SubscriptionID(1), - span: rawSpan, - rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), - } + _, span := newRealtimePriorityTestSpan() client.maybeEnableRealtimeScanPriority(span, oracle.GoTimeToTS(currentTime.Add(-time.Minute))) require.False(t, span.realtimeScanPriority.Load()) @@ -663,18 +658,9 @@ func TestRealtimeScanPriorityUpgradesRegionRetry(t *testing.T) { regionTaskQueue: priorityqueue.New[PriorityTask](), } client.pdClock = pdutil.NewClock4Test() - rawSpan := heartbeatpb.TableSpan{ - TableID: 1, - StartKey: []byte("a"), - EndKey: []byte("z"), - } - span := &subscribedSpan{ - subID: SubscriptionID(1), - span: rawSpan, - rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), - } + _, span := newRealtimePriorityTestSpan() span.realtimeScanPriority.Store(true) - region := newRegionInfo(tikv.NewRegionVerID(1, 1, 1), rawSpan, nil, span, false) + region := newRealtimePriorityTestRegion(span) region.scanPriority = cdcpb.ScanPriority_SCAN_PRIORITY_LOW err := client.doHandleError(context.Background(), newRegionErrorInfo(region, &eventError{err: &cdcpb.Error{ServerIsBusy: &errorpb.ServerIsBusy{}}})) @@ -692,18 +678,9 @@ func TestRealtimeScanPriorityUpgradesRangeRetry(t *testing.T) { client := &subscriptionClient{ rangeTaskCh: make(chan rangeTask, 1), } - rawSpan := heartbeatpb.TableSpan{ - TableID: 1, - StartKey: []byte("a"), - EndKey: []byte("z"), - } - span := &subscribedSpan{ - subID: SubscriptionID(1), - span: rawSpan, - rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), - } + rawSpan, span := newRealtimePriorityTestSpan() span.realtimeScanPriority.Store(true) - region := newRegionInfo(tikv.NewRegionVerID(1, 1, 1), rawSpan, nil, span, false) + region := newRealtimePriorityTestRegion(span) region.scanPriority = cdcpb.ScanPriority_SCAN_PRIORITY_LOW err := client.doHandleError(context.Background(), newRegionErrorInfo(region, &eventError{err: &cdcpb.Error{EpochNotMatch: &errorpb.EpochNotMatch{}}})) @@ -718,6 +695,25 @@ func TestRealtimeScanPriorityUpgradesRangeRetry(t *testing.T) { } } +func newRealtimePriorityTestSpan() (heartbeatpb.TableSpan, *subscribedSpan) { + rawSpan := heartbeatpb.TableSpan{ + TableID: 1, + StartKey: []byte("a"), + EndKey: []byte("z"), + } + span := &subscribedSpan{ + subID: SubscriptionID(1), + changefeedID: "test/test-changefeed", + span: rawSpan, + rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), + } + return rawSpan, span +} + +func newRealtimePriorityTestRegion(span *subscribedSpan) regionInfo { + return newRegionInfo(tikv.NewRegionVerID(1, 1, 1), span.span, nil, span, false) +} + func setInitialScanLowPriorityThresholdForTest(t *testing.T, threshold time.Duration) func() { t.Helper() oldConfig := config.GetGlobalServerConfig() From da6b17a3a974cfbc0ec4c71845b6e896b9185e18 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Tue, 7 Jul 2026 17:16:05 +0800 Subject: [PATCH 09/21] logpuller: simplify priority scan diagnostics Signed-off-by: hongyunyan <649330952@qq.com> --- logservice/logpuller/subscription_client.go | 25 +++++++----- .../logpuller/subscription_client_test.go | 40 +++++-------------- 2 files changed, 25 insertions(+), 40 deletions(-) diff --git a/logservice/logpuller/subscription_client.go b/logservice/logpuller/subscription_client.go index 6dd725d893..b6b9cf403b 100644 --- a/logservice/logpuller/subscription_client.go +++ b/logservice/logpuller/subscription_client.go @@ -41,6 +41,7 @@ import ( "github.com/tikv/client-go/v2/tikv" pd "github.com/tikv/pd/client" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "golang.org/x/sync/errgroup" ) @@ -872,17 +873,19 @@ func (s *subscriptionClient) scheduleRegionRequest(ctx context.Context, region r case regionlock.LockRangeStatusSuccess: region.lockedRangeState = lockRangeResult.LockedRangeState s.regionTaskQueue.Push(NewRegionPriorityTask(priority, region, s.pdClock.CurrentTS())) - log.Debug("cdc region scan task enqueued", - zap.String("changefeedID", region.subscribedSpan.changefeedID), - zap.Uint64("subscriptionID", uint64(region.subscribedSpan.subID)), - zap.Int64("tableID", region.subscribedSpan.span.TableID), - zap.Uint64("startTs", region.subscribedSpan.startTs), - zap.Uint64("regionID", region.verID.GetID()), - zap.Uint64("regionEpochVersion", region.verID.GetVer()), - zap.Uint64("regionEpochConfVer", region.verID.GetConfVer()), - zap.String("priority", taskTypeLogName(priority)), - zap.String("scanPriority", region.scanPriority.String()), - zap.String("span", common.FormatTableSpan(®ion.span))) + if log.GetLevel() <= zapcore.DebugLevel { + log.Debug("cdc region scan task enqueued", + zap.String("changefeedID", region.subscribedSpan.changefeedID), + zap.Uint64("subscriptionID", uint64(region.subscribedSpan.subID)), + zap.Int64("tableID", region.subscribedSpan.span.TableID), + zap.Uint64("startTs", region.subscribedSpan.startTs), + zap.Uint64("regionID", region.verID.GetID()), + zap.Uint64("regionEpochVersion", region.verID.GetVer()), + zap.Uint64("regionEpochConfVer", region.verID.GetConfVer()), + zap.String("priority", taskTypeLogName(priority)), + zap.String("scanPriority", region.scanPriority.String()), + zap.String("span", common.FormatTableSpan(®ion.span))) + } case regionlock.LockRangeStatusStale: for _, r := range lockRangeResult.RetryRanges { s.scheduleRangeRequest(ctx, r, region.subscribedSpan, region.filterLoop, priority) diff --git a/logservice/logpuller/subscription_client_test.go b/logservice/logpuller/subscription_client_test.go index 7c5ba758ae..f0aa83eeec 100644 --- a/logservice/logpuller/subscription_client_test.go +++ b/logservice/logpuller/subscription_client_test.go @@ -403,17 +403,8 @@ func TestBusyRetryPreservesScanPriority(t *testing.T) { regionTaskQueue: priorityqueue.New[PriorityTask](), } client.pdClock = pdutil.NewClock4Test() - rawSpan := heartbeatpb.TableSpan{ - TableID: 1, - StartKey: []byte("a"), - EndKey: []byte("z"), - } - span := &subscribedSpan{ - subID: SubscriptionID(1), - span: rawSpan, - rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), - } - region := newRegionInfo(tikv.NewRegionVerID(1, 1, 1), rawSpan, nil, span, false) + _, span := newScanPriorityTestSpan() + region := newScanPriorityTestRegion(span) region.scanPriority = tc.priority err := client.doHandleError(context.Background(), newRegionErrorInfo(region, &eventError{err: tc.cdcErr})) @@ -477,17 +468,8 @@ func TestRangeRetryPreservesScanPriority(t *testing.T) { client := &subscriptionClient{ rangeTaskCh: make(chan rangeTask, 1), } - rawSpan := heartbeatpb.TableSpan{ - TableID: 1, - StartKey: []byte("a"), - EndKey: []byte("z"), - } - span := &subscribedSpan{ - subID: SubscriptionID(1), - span: rawSpan, - rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), - } - region := newRegionInfo(tikv.NewRegionVerID(1, 1, 1), rawSpan, nil, span, false) + rawSpan, span := newScanPriorityTestSpan() + region := newScanPriorityTestRegion(span) region.scanPriority = tc.priority err := client.doHandleError(context.Background(), newRegionErrorInfo(region, tc.err)) @@ -639,7 +621,7 @@ func TestRealtimeScanPriorityEnabledAfterSubscriptionCatchesUp(t *testing.T) { pdClock: pdClock, } - _, span := newRealtimePriorityTestSpan() + _, span := newScanPriorityTestSpan() client.maybeEnableRealtimeScanPriority(span, oracle.GoTimeToTS(currentTime.Add(-time.Minute))) require.False(t, span.realtimeScanPriority.Load()) @@ -658,9 +640,9 @@ func TestRealtimeScanPriorityUpgradesRegionRetry(t *testing.T) { regionTaskQueue: priorityqueue.New[PriorityTask](), } client.pdClock = pdutil.NewClock4Test() - _, span := newRealtimePriorityTestSpan() + _, span := newScanPriorityTestSpan() span.realtimeScanPriority.Store(true) - region := newRealtimePriorityTestRegion(span) + region := newScanPriorityTestRegion(span) region.scanPriority = cdcpb.ScanPriority_SCAN_PRIORITY_LOW err := client.doHandleError(context.Background(), newRegionErrorInfo(region, &eventError{err: &cdcpb.Error{ServerIsBusy: &errorpb.ServerIsBusy{}}})) @@ -678,9 +660,9 @@ func TestRealtimeScanPriorityUpgradesRangeRetry(t *testing.T) { client := &subscriptionClient{ rangeTaskCh: make(chan rangeTask, 1), } - rawSpan, span := newRealtimePriorityTestSpan() + rawSpan, span := newScanPriorityTestSpan() span.realtimeScanPriority.Store(true) - region := newRealtimePriorityTestRegion(span) + region := newScanPriorityTestRegion(span) region.scanPriority = cdcpb.ScanPriority_SCAN_PRIORITY_LOW err := client.doHandleError(context.Background(), newRegionErrorInfo(region, &eventError{err: &cdcpb.Error{EpochNotMatch: &errorpb.EpochNotMatch{}}})) @@ -695,7 +677,7 @@ func TestRealtimeScanPriorityUpgradesRangeRetry(t *testing.T) { } } -func newRealtimePriorityTestSpan() (heartbeatpb.TableSpan, *subscribedSpan) { +func newScanPriorityTestSpan() (heartbeatpb.TableSpan, *subscribedSpan) { rawSpan := heartbeatpb.TableSpan{ TableID: 1, StartKey: []byte("a"), @@ -710,7 +692,7 @@ func newRealtimePriorityTestSpan() (heartbeatpb.TableSpan, *subscribedSpan) { return rawSpan, span } -func newRealtimePriorityTestRegion(span *subscribedSpan) regionInfo { +func newScanPriorityTestRegion(span *subscribedSpan) regionInfo { return newRegionInfo(tikv.NewRegionVerID(1, 1, 1), span.span, nil, span, false) } From ab05078039b2a64065f47b17c8bbaa054010e5d5 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Tue, 7 Jul 2026 19:01:46 +0800 Subject: [PATCH 10/21] logpuller: simplify task priority logging Signed-off-by: hongyunyan <649330952@qq.com> --- logservice/logpuller/priority_task.go | 5 ----- logservice/logpuller/subscription_client.go | 4 ++-- 2 files changed, 2 insertions(+), 7 deletions(-) diff --git a/logservice/logpuller/priority_task.go b/logservice/logpuller/priority_task.go index 8f896ec058..56bc7f72cc 100644 --- a/logservice/logpuller/priority_task.go +++ b/logservice/logpuller/priority_task.go @@ -14,7 +14,6 @@ package logpuller import ( - "fmt" "time" "github.com/pingcap/kvproto/pkg/cdcpb" @@ -40,10 +39,6 @@ const ( ) func (t TaskType) String() string { - return fmt.Sprintf("%d", t) -} - -func taskTypeLogName(t TaskType) string { switch t { case TaskHighPrior: return "high" diff --git a/logservice/logpuller/subscription_client.go b/logservice/logpuller/subscription_client.go index b6b9cf403b..3a6fb98445 100644 --- a/logservice/logpuller/subscription_client.go +++ b/logservice/logpuller/subscription_client.go @@ -387,7 +387,7 @@ func (s *subscriptionClient) Subscribe( zap.String("changefeedID", changefeedID), zap.Uint64("subscriptionID", uint64(subID)), zap.Int64("tableID", span.TableID), zap.Uint64("startTs", startTs), - zap.String("initialScanPriority", taskTypeLogName(initialPriority)), + zap.String("initialScanPriority", initialPriority.String()), zap.String("startKey", spanz.HexKey(span.StartKey)), zap.String("endKey", spanz.HexKey(span.EndKey))) } } @@ -882,7 +882,7 @@ func (s *subscriptionClient) scheduleRegionRequest(ctx context.Context, region r zap.Uint64("regionID", region.verID.GetID()), zap.Uint64("regionEpochVersion", region.verID.GetVer()), zap.Uint64("regionEpochConfVer", region.verID.GetConfVer()), - zap.String("priority", taskTypeLogName(priority)), + zap.String("priority", priority.String()), zap.String("scanPriority", region.scanPriority.String()), zap.String("span", common.FormatTableSpan(®ion.span))) } From 945e05bc778292b24f403f99758ebcb71cb42b20 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Wed, 8 Jul 2026 14:36:45 +0800 Subject: [PATCH 11/21] logpuller,grafana: remove cse changefeed id Signed-off-by: hongyunyan <649330952@qq.com> --- logservice/logpuller/region_request_worker.go | 1 - .../logpuller/region_request_worker_test.go | 1 - metrics/grafana/ticdc_new_arch.json | 357 +++++++++++++++++- .../ticdc_new_arch_next_gen.json | 357 +++++++++++++++++- 4 files changed, 686 insertions(+), 30 deletions(-) diff --git a/logservice/logpuller/region_request_worker.go b/logservice/logpuller/region_request_worker.go index 534d864cd5..130be03097 100644 --- a/logservice/logpuller/region_request_worker.go +++ b/logservice/logpuller/region_request_worker.go @@ -443,7 +443,6 @@ func (s *regionRequestWorker) createRegionRequest(region regionInfo) *cdcpb.Chan Header: &cdcpb.Header{ClusterId: s.client.clusterID, TicdcVersion: version.ReleaseSemver()}, RegionId: region.verID.GetID(), RequestId: uint64(region.subscribedSpan.subID), - ChangefeedId: region.subscribedSpan.changefeedID, RegionEpoch: region.rpcCtx.Meta.RegionEpoch, CheckpointTs: region.resolvedTs(), StartKey: region.span.StartKey, diff --git a/logservice/logpuller/region_request_worker_test.go b/logservice/logpuller/region_request_worker_test.go index 7b742ae2bb..a7231da794 100644 --- a/logservice/logpuller/region_request_worker_test.go +++ b/logservice/logpuller/region_request_worker_test.go @@ -89,7 +89,6 @@ func TestCreateRegionRequestScanPriority(t *testing.T) { req := worker.createRegionRequest(region) require.Equal(t, tc.expected, req.GetScanPriority()) - require.Equal(t, "test/test-changefeed", req.GetChangefeedId()) }) } } diff --git a/metrics/grafana/ticdc_new_arch.json b/metrics/grafana/ticdc_new_arch.json index 5b6a19db31..9cdd8af284 100644 --- a/metrics/grafana/ticdc_new_arch.json +++ b/metrics/grafana/ticdc_new_arch.json @@ -22644,7 +22644,7 @@ "dashes": false, "datasource": "${DS_TEST-CLUSTER}", "decimals": 1, - "description": "", + "description": "Queued CDC incremental scan jobs by priority per TiKV instance.", "fieldConfig": { "defaults": {}, "overrides": [] @@ -22658,6 +22658,335 @@ "y": 41 }, "hiddenSeries": false, + "id": 62042, + "legend": { + "alignAsTable": true, + "avg": false, + "current": true, + "hideEmpty": false, + "hideZero": true, + "max": true, + "min": false, + "rightSide": false, + "show": true, + "sideWidth": null, + "sort": "current", + "sortDesc": true, + "total": false, + "values": true + }, + "lines": true, + "linewidth": 1, + "links": [], + "nullPointMode": "null", + "options": { + "alertThreshold": true + }, + "paceLength": 10, + "percentage": false, + "pluginVersion": "7.5.17", + "pointradius": 5, + "points": false, + "renderer": "flot", + "seriesOverrides": [], + "spaceLength": 10, + "stack": false, + "steppedLine": false, + "targets": [ + { + "expr": "sum(tikv_cdc_scan_scheduler_queue_length{k8s_cluster=\"$k8s_cluster\", tidb_cluster=\"$tidb_cluster\", instance=~\"$tikv_instance\"}) by (instance, priority)", + "format": "time_series", + "hide": false, + "intervalFactor": 1, + "legendFormat": "{{instance}}-{{priority}}", + "refId": "A" + } + ], + "thresholds": [], + "timeFrom": null, + "timeRegions": [], + "timeShift": null, + "title": "CDC Scan Scheduler Queue Length", + "tooltip": { + "shared": true, + "sort": 0, + "value_type": "individual" + }, + "type": "graph", + "xaxis": { + "buckets": null, + "mode": "time", + "name": null, + "show": true, + "values": [] + }, + "yaxes": [ + { + "format": "none", + "label": null, + "logBase": 1, + "max": null, + "min": "0", + "show": true + }, + { + "format": "short", + "label": null, + "logBase": 1, + "max": null, + "min": null, + "show": false + } + ], + "yaxis": { + "align": false, + "alignLevel": null + } + }, + { + "aliasColors": {}, + "bars": false, + "dashLength": 10, + "dashes": false, + "datasource": "${DS_TEST-CLUSTER}", + "decimals": 1, + "description": "Running CDC incremental scan jobs by slot kind per TiKV instance.", + "fieldConfig": { + "defaults": {}, + "overrides": [] + }, + "fill": 1, + "fillGradient": 0, + "gridPos": { + "h": 7, + "w": 12, + "x": 12, + "y": 41 + }, + "hiddenSeries": false, + "id": 62043, + "legend": { + "alignAsTable": true, + "avg": false, + "current": true, + "hideEmpty": false, + "hideZero": true, + "max": true, + "min": false, + "rightSide": false, + "show": true, + "sideWidth": null, + "sort": "current", + "sortDesc": true, + "total": false, + "values": true + }, + "lines": true, + "linewidth": 1, + "links": [], + "nullPointMode": "null", + "options": { + "alertThreshold": true + }, + "paceLength": 10, + "percentage": false, + "pluginVersion": "7.5.17", + "pointradius": 5, + "points": false, + "renderer": "flot", + "seriesOverrides": [], + "spaceLength": 10, + "stack": false, + "steppedLine": false, + "targets": [ + { + "expr": "sum(tikv_cdc_scan_scheduler_running{k8s_cluster=\"$k8s_cluster\", tidb_cluster=\"$tidb_cluster\", instance=~\"$tikv_instance\"}) by (instance, slot)", + "format": "time_series", + "hide": false, + "intervalFactor": 1, + "legendFormat": "{{instance}}-{{slot}}", + "refId": "A" + } + ], + "thresholds": [], + "timeFrom": null, + "timeRegions": [], + "timeShift": null, + "title": "CDC Scan Scheduler Running", + "tooltip": { + "shared": true, + "sort": 0, + "value_type": "individual" + }, + "type": "graph", + "xaxis": { + "buckets": null, + "mode": "time", + "name": null, + "show": true, + "values": [] + }, + "yaxes": [ + { + "format": "none", + "label": null, + "logBase": 1, + "max": null, + "min": "0", + "show": true + }, + { + "format": "short", + "label": null, + "logBase": 1, + "max": null, + "min": null, + "show": false + } + ], + "yaxis": { + "align": false, + "alignLevel": null + } + }, + { + "aliasColors": {}, + "bars": false, + "dashLength": 10, + "dashes": false, + "datasource": "${DS_TEST-CLUSTER}", + "decimals": 1, + "description": "Time spent waiting in the CDC scan scheduler before dispatch.", + "fieldConfig": { + "defaults": {}, + "overrides": [] + }, + "fill": 1, + "fillGradient": 0, + "gridPos": { + "h": 7, + "w": 24, + "x": 0, + "y": 48 + }, + "hiddenSeries": false, + "id": 62044, + "legend": { + "alignAsTable": true, + "avg": false, + "current": true, + "hideEmpty": false, + "hideZero": true, + "max": true, + "min": false, + "rightSide": false, + "show": true, + "sideWidth": null, + "sort": "current", + "sortDesc": true, + "total": false, + "values": true + }, + "lines": true, + "linewidth": 1, + "links": [], + "nullPointMode": "null", + "options": { + "alertThreshold": true + }, + "paceLength": 10, + "percentage": false, + "pluginVersion": "7.5.17", + "pointradius": 5, + "points": false, + "renderer": "flot", + "seriesOverrides": [], + "spaceLength": 10, + "stack": false, + "steppedLine": false, + "targets": [ + { + "exemplar": true, + "expr": "histogram_quantile(0.99, sum(rate(tikv_cdc_scan_scheduler_dispatch_latency_seconds_bucket{k8s_cluster=\"$k8s_cluster\", tidb_cluster=\"$tidb_cluster\", instance=~\"$tikv_instance\"}[1m])) by (le, instance, priority, slot))", + "format": "time_series", + "hide": false, + "interval": "", + "intervalFactor": 1, + "legendFormat": "{{instance}}-{{priority}}-{{slot}}-p99", + "refId": "A" + }, + { + "exemplar": true, + "expr": "sum(rate(tikv_cdc_scan_scheduler_dispatch_latency_seconds_sum{k8s_cluster=\"$k8s_cluster\", tidb_cluster=\"$tidb_cluster\", instance=~\"$tikv_instance\"}[1m])) by (instance, priority, slot) / sum(rate(tikv_cdc_scan_scheduler_dispatch_latency_seconds_count{k8s_cluster=\"$k8s_cluster\", tidb_cluster=\"$tidb_cluster\", instance=~\"$tikv_instance\"}[1m])) by (instance, priority, slot)", + "format": "time_series", + "hide": false, + "interval": "", + "legendFormat": "{{instance}}-{{priority}}-{{slot}}-avg", + "refId": "B" + } + ], + "thresholds": [], + "timeFrom": null, + "timeRegions": [], + "timeShift": null, + "title": "CDC Scan Scheduler Dispatch Latency", + "tooltip": { + "shared": true, + "sort": 0, + "value_type": "individual" + }, + "type": "graph", + "xaxis": { + "buckets": null, + "mode": "time", + "name": null, + "show": true, + "values": [] + }, + "yaxes": [ + { + "format": "s", + "label": null, + "logBase": 1, + "max": null, + "min": "0", + "show": true + }, + { + "format": "short", + "label": null, + "logBase": 1, + "max": null, + "min": null, + "show": false + } + ], + "yaxis": { + "align": false, + "alignLevel": null + } + }, + { + "aliasColors": {}, + "bars": false, + "dashLength": 10, + "dashes": false, + "datasource": "${DS_TEST-CLUSTER}", + "decimals": 1, + "description": "", + "fieldConfig": { + "defaults": {}, + "overrides": [] + }, + "fill": 1, + "fillGradient": 0, + "gridPos": { + "h": 7, + "w": 12, + "x": 0, + "y": 55 + }, + "hiddenSeries": false, "id": 72, "legend": { "alignAsTable": true, @@ -22776,7 +23105,7 @@ "h": 7, "w": 12, "x": 12, - "y": 41 + "y": 55 }, "heatmap": {}, "hideZeroBuckets": true, @@ -22853,7 +23182,7 @@ "h": 7, "w": 12, "x": 0, - "y": 48 + "y": 62 }, "hiddenSeries": false, "id": 22297, @@ -22971,7 +23300,7 @@ "h": 7, "w": 12, "x": 12, - "y": 48 + "y": 62 }, "hiddenSeries": false, "id": 139, @@ -23082,7 +23411,7 @@ "h": 7, "w": 12, "x": 0, - "y": 55 + "y": 69 }, "hiddenSeries": false, "id": 76, @@ -23193,7 +23522,7 @@ "h": 7, "w": 12, "x": 12, - "y": 55 + "y": 69 }, "hiddenSeries": false, "id": 22298, @@ -23306,7 +23635,7 @@ "h": 7, "w": 12, "x": 0, - "y": 62 + "y": 76 }, "hiddenSeries": false, "id": 152, @@ -23444,7 +23773,7 @@ "h": 7, "w": 12, "x": 12, - "y": 62 + "y": 76 }, "hiddenSeries": false, "id": 70, @@ -23549,7 +23878,7 @@ "h": 7, "w": 12, "x": 0, - "y": 69 + "y": 83 }, "hiddenSeries": false, "id": 143, @@ -23674,7 +24003,7 @@ "h": 7, "w": 12, "x": 12, - "y": 69 + "y": 83 }, "hiddenSeries": false, "id": 153, @@ -23788,7 +24117,7 @@ "h": 7, "w": 12, "x": 0, - "y": 76 + "y": 90 }, "heatmap": {}, "hideZeroBuckets": true, @@ -23864,7 +24193,7 @@ "h": 7, "w": 12, "x": 12, - "y": 76 + "y": 90 }, "hiddenSeries": false, "id": 145, @@ -24002,7 +24331,7 @@ "h": 7, "w": 12, "x": 0, - "y": 83 + "y": 97 }, "hiddenSeries": false, "id": 142, @@ -24119,7 +24448,7 @@ "h": 7, "w": 12, "x": 12, - "y": 83 + "y": 97 }, "hiddenSeries": false, "id": 141, diff --git a/metrics/nextgengrafana/ticdc_new_arch_next_gen.json b/metrics/nextgengrafana/ticdc_new_arch_next_gen.json index 77a3a6a48a..ea0c2cb2bf 100644 --- a/metrics/nextgengrafana/ticdc_new_arch_next_gen.json +++ b/metrics/nextgengrafana/ticdc_new_arch_next_gen.json @@ -22644,7 +22644,7 @@ "dashes": false, "datasource": "${DS_TEST-CLUSTER}", "decimals": 1, - "description": "", + "description": "Queued CDC incremental scan jobs by priority per TiKV instance.", "fieldConfig": { "defaults": {}, "overrides": [] @@ -22658,6 +22658,335 @@ "y": 41 }, "hiddenSeries": false, + "id": 62042, + "legend": { + "alignAsTable": true, + "avg": false, + "current": true, + "hideEmpty": false, + "hideZero": true, + "max": true, + "min": false, + "rightSide": false, + "show": true, + "sideWidth": null, + "sort": "current", + "sortDesc": true, + "total": false, + "values": true + }, + "lines": true, + "linewidth": 1, + "links": [], + "nullPointMode": "null", + "options": { + "alertThreshold": true + }, + "paceLength": 10, + "percentage": false, + "pluginVersion": "7.5.17", + "pointradius": 5, + "points": false, + "renderer": "flot", + "seriesOverrides": [], + "spaceLength": 10, + "stack": false, + "steppedLine": false, + "targets": [ + { + "expr": "sum(tikv_cdc_scan_scheduler_queue_length{k8s_cluster=\"$k8s_cluster\", sharedpool_id=\"$tidb_cluster\", instance=~\"$tikv_instance\"}) by (instance, priority)", + "format": "time_series", + "hide": false, + "intervalFactor": 1, + "legendFormat": "{{instance}}-{{priority}}", + "refId": "A" + } + ], + "thresholds": [], + "timeFrom": null, + "timeRegions": [], + "timeShift": null, + "title": "CDC Scan Scheduler Queue Length", + "tooltip": { + "shared": true, + "sort": 0, + "value_type": "individual" + }, + "type": "graph", + "xaxis": { + "buckets": null, + "mode": "time", + "name": null, + "show": true, + "values": [] + }, + "yaxes": [ + { + "format": "none", + "label": null, + "logBase": 1, + "max": null, + "min": "0", + "show": true + }, + { + "format": "short", + "label": null, + "logBase": 1, + "max": null, + "min": null, + "show": false + } + ], + "yaxis": { + "align": false, + "alignLevel": null + } + }, + { + "aliasColors": {}, + "bars": false, + "dashLength": 10, + "dashes": false, + "datasource": "${DS_TEST-CLUSTER}", + "decimals": 1, + "description": "Running CDC incremental scan jobs by slot kind per TiKV instance.", + "fieldConfig": { + "defaults": {}, + "overrides": [] + }, + "fill": 1, + "fillGradient": 0, + "gridPos": { + "h": 7, + "w": 12, + "x": 12, + "y": 41 + }, + "hiddenSeries": false, + "id": 62043, + "legend": { + "alignAsTable": true, + "avg": false, + "current": true, + "hideEmpty": false, + "hideZero": true, + "max": true, + "min": false, + "rightSide": false, + "show": true, + "sideWidth": null, + "sort": "current", + "sortDesc": true, + "total": false, + "values": true + }, + "lines": true, + "linewidth": 1, + "links": [], + "nullPointMode": "null", + "options": { + "alertThreshold": true + }, + "paceLength": 10, + "percentage": false, + "pluginVersion": "7.5.17", + "pointradius": 5, + "points": false, + "renderer": "flot", + "seriesOverrides": [], + "spaceLength": 10, + "stack": false, + "steppedLine": false, + "targets": [ + { + "expr": "sum(tikv_cdc_scan_scheduler_running{k8s_cluster=\"$k8s_cluster\", sharedpool_id=\"$tidb_cluster\", instance=~\"$tikv_instance\"}) by (instance, slot)", + "format": "time_series", + "hide": false, + "intervalFactor": 1, + "legendFormat": "{{instance}}-{{slot}}", + "refId": "A" + } + ], + "thresholds": [], + "timeFrom": null, + "timeRegions": [], + "timeShift": null, + "title": "CDC Scan Scheduler Running", + "tooltip": { + "shared": true, + "sort": 0, + "value_type": "individual" + }, + "type": "graph", + "xaxis": { + "buckets": null, + "mode": "time", + "name": null, + "show": true, + "values": [] + }, + "yaxes": [ + { + "format": "none", + "label": null, + "logBase": 1, + "max": null, + "min": "0", + "show": true + }, + { + "format": "short", + "label": null, + "logBase": 1, + "max": null, + "min": null, + "show": false + } + ], + "yaxis": { + "align": false, + "alignLevel": null + } + }, + { + "aliasColors": {}, + "bars": false, + "dashLength": 10, + "dashes": false, + "datasource": "${DS_TEST-CLUSTER}", + "decimals": 1, + "description": "Time spent waiting in the CDC scan scheduler before dispatch.", + "fieldConfig": { + "defaults": {}, + "overrides": [] + }, + "fill": 1, + "fillGradient": 0, + "gridPos": { + "h": 7, + "w": 24, + "x": 0, + "y": 48 + }, + "hiddenSeries": false, + "id": 62044, + "legend": { + "alignAsTable": true, + "avg": false, + "current": true, + "hideEmpty": false, + "hideZero": true, + "max": true, + "min": false, + "rightSide": false, + "show": true, + "sideWidth": null, + "sort": "current", + "sortDesc": true, + "total": false, + "values": true + }, + "lines": true, + "linewidth": 1, + "links": [], + "nullPointMode": "null", + "options": { + "alertThreshold": true + }, + "paceLength": 10, + "percentage": false, + "pluginVersion": "7.5.17", + "pointradius": 5, + "points": false, + "renderer": "flot", + "seriesOverrides": [], + "spaceLength": 10, + "stack": false, + "steppedLine": false, + "targets": [ + { + "exemplar": true, + "expr": "histogram_quantile(0.99, sum(rate(tikv_cdc_scan_scheduler_dispatch_latency_seconds_bucket{k8s_cluster=\"$k8s_cluster\", sharedpool_id=\"$tidb_cluster\", instance=~\"$tikv_instance\"}[1m])) by (le, instance, priority, slot))", + "format": "time_series", + "hide": false, + "interval": "", + "intervalFactor": 1, + "legendFormat": "{{instance}}-{{priority}}-{{slot}}-p99", + "refId": "A" + }, + { + "exemplar": true, + "expr": "sum(rate(tikv_cdc_scan_scheduler_dispatch_latency_seconds_sum{k8s_cluster=\"$k8s_cluster\", sharedpool_id=\"$tidb_cluster\", instance=~\"$tikv_instance\"}[1m])) by (instance, priority, slot) / sum(rate(tikv_cdc_scan_scheduler_dispatch_latency_seconds_count{k8s_cluster=\"$k8s_cluster\", sharedpool_id=\"$tidb_cluster\", instance=~\"$tikv_instance\"}[1m])) by (instance, priority, slot)", + "format": "time_series", + "hide": false, + "interval": "", + "legendFormat": "{{instance}}-{{priority}}-{{slot}}-avg", + "refId": "B" + } + ], + "thresholds": [], + "timeFrom": null, + "timeRegions": [], + "timeShift": null, + "title": "CDC Scan Scheduler Dispatch Latency", + "tooltip": { + "shared": true, + "sort": 0, + "value_type": "individual" + }, + "type": "graph", + "xaxis": { + "buckets": null, + "mode": "time", + "name": null, + "show": true, + "values": [] + }, + "yaxes": [ + { + "format": "s", + "label": null, + "logBase": 1, + "max": null, + "min": "0", + "show": true + }, + { + "format": "short", + "label": null, + "logBase": 1, + "max": null, + "min": null, + "show": false + } + ], + "yaxis": { + "align": false, + "alignLevel": null + } + }, + { + "aliasColors": {}, + "bars": false, + "dashLength": 10, + "dashes": false, + "datasource": "${DS_TEST-CLUSTER}", + "decimals": 1, + "description": "", + "fieldConfig": { + "defaults": {}, + "overrides": [] + }, + "fill": 1, + "fillGradient": 0, + "gridPos": { + "h": 7, + "w": 12, + "x": 0, + "y": 55 + }, + "hiddenSeries": false, "id": 72, "legend": { "alignAsTable": true, @@ -22776,7 +23105,7 @@ "h": 7, "w": 12, "x": 12, - "y": 41 + "y": 55 }, "heatmap": {}, "hideZeroBuckets": true, @@ -22853,7 +23182,7 @@ "h": 7, "w": 12, "x": 0, - "y": 48 + "y": 62 }, "hiddenSeries": false, "id": 22297, @@ -22971,7 +23300,7 @@ "h": 7, "w": 12, "x": 12, - "y": 48 + "y": 62 }, "hiddenSeries": false, "id": 139, @@ -23082,7 +23411,7 @@ "h": 7, "w": 12, "x": 0, - "y": 55 + "y": 69 }, "hiddenSeries": false, "id": 76, @@ -23193,7 +23522,7 @@ "h": 7, "w": 12, "x": 12, - "y": 55 + "y": 69 }, "hiddenSeries": false, "id": 22298, @@ -23306,7 +23635,7 @@ "h": 7, "w": 12, "x": 0, - "y": 62 + "y": 76 }, "hiddenSeries": false, "id": 152, @@ -23444,7 +23773,7 @@ "h": 7, "w": 12, "x": 12, - "y": 62 + "y": 76 }, "hiddenSeries": false, "id": 70, @@ -23549,7 +23878,7 @@ "h": 7, "w": 12, "x": 0, - "y": 69 + "y": 83 }, "hiddenSeries": false, "id": 143, @@ -23674,7 +24003,7 @@ "h": 7, "w": 12, "x": 12, - "y": 69 + "y": 83 }, "hiddenSeries": false, "id": 153, @@ -23788,7 +24117,7 @@ "h": 7, "w": 12, "x": 0, - "y": 76 + "y": 90 }, "heatmap": {}, "hideZeroBuckets": true, @@ -23864,7 +24193,7 @@ "h": 7, "w": 12, "x": 12, - "y": 76 + "y": 90 }, "hiddenSeries": false, "id": 145, @@ -24002,7 +24331,7 @@ "h": 7, "w": 12, "x": 0, - "y": 83 + "y": 97 }, "hiddenSeries": false, "id": 142, @@ -24119,7 +24448,7 @@ "h": 7, "w": 12, "x": 12, - "y": 83 + "y": 97 }, "hiddenSeries": false, "id": 141, From 0d7ab0b5a5e43d692c518ac70aad8de56cfa651f Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Wed, 8 Jul 2026 14:41:21 +0800 Subject: [PATCH 12/21] grafana: fix duplicate scan scheduler panel ids Signed-off-by: hongyunyan <649330952@qq.com> --- metrics/grafana/ticdc_new_arch.json | 6 +++--- metrics/nextgengrafana/ticdc_new_arch_next_gen.json | 6 +++--- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/metrics/grafana/ticdc_new_arch.json b/metrics/grafana/ticdc_new_arch.json index 9cdd8af284..d90057fb1f 100644 --- a/metrics/grafana/ticdc_new_arch.json +++ b/metrics/grafana/ticdc_new_arch.json @@ -22658,7 +22658,7 @@ "y": 41 }, "hiddenSeries": false, - "id": 62042, + "id": 62047, "legend": { "alignAsTable": true, "avg": false, @@ -22764,7 +22764,7 @@ "y": 41 }, "hiddenSeries": false, - "id": 62043, + "id": 62048, "legend": { "alignAsTable": true, "avg": false, @@ -22870,7 +22870,7 @@ "y": 48 }, "hiddenSeries": false, - "id": 62044, + "id": 62049, "legend": { "alignAsTable": true, "avg": false, diff --git a/metrics/nextgengrafana/ticdc_new_arch_next_gen.json b/metrics/nextgengrafana/ticdc_new_arch_next_gen.json index ea0c2cb2bf..50027729e6 100644 --- a/metrics/nextgengrafana/ticdc_new_arch_next_gen.json +++ b/metrics/nextgengrafana/ticdc_new_arch_next_gen.json @@ -22658,7 +22658,7 @@ "y": 41 }, "hiddenSeries": false, - "id": 62042, + "id": 62047, "legend": { "alignAsTable": true, "avg": false, @@ -22764,7 +22764,7 @@ "y": 41 }, "hiddenSeries": false, - "id": 62043, + "id": 62048, "legend": { "alignAsTable": true, "avg": false, @@ -22870,7 +22870,7 @@ "y": 48 }, "hiddenSeries": false, - "id": 62044, + "id": 62049, "legend": { "alignAsTable": true, "avg": false, From 90ada3a878610300b508c9530b3c28f75d73ec4e Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Wed, 8 Jul 2026 15:11:21 +0800 Subject: [PATCH 13/21] logservice: drop redundant changefeed ID plumbing Signed-off-by: hongyunyan <649330952@qq.com> --- logservice/eventstore/event_store.go | 9 +------ logservice/eventstore/event_store_test.go | 1 - logservice/logpuller/region_req_cache_test.go | 7 +++--- logservice/logpuller/region_request_worker.go | 1 - logservice/logpuller/subscription_client.go | 24 +++++++------------ .../logpuller/subscription_client_test.go | 23 ++++++++---------- logservice/schemastore/ddl_job_fetcher.go | 2 -- 7 files changed, 22 insertions(+), 45 deletions(-) diff --git a/logservice/eventstore/event_store.go b/logservice/eventstore/event_store.go index e68bba3ef6..17f9bf3e20 100644 --- a/logservice/eventstore/event_store.go +++ b/logservice/eventstore/event_store.go @@ -478,14 +478,12 @@ func (e *eventStore) RegisterDispatcher( metrics.EventStoreRegisterDispatcherStartTsLagHist.Observe(lag.Seconds()) if lag >= 10*time.Second { log.Warn("register dispatcher with large startTs lag", - zap.Stringer("changefeedID", changefeedID), zap.Stringer("dispatcherID", dispatcherID), zap.String("span", common.FormatTableSpan(dispatcherSpan)), zap.Uint64("startTs", startTs), zap.Duration("lag", lag)) } else { log.Info("register dispatcher", - zap.Stringer("changefeedID", changefeedID), zap.Stringer("dispatcherID", dispatcherID), zap.String("span", common.FormatTableSpan(dispatcherSpan)), zap.Uint64("startTs", startTs)) @@ -495,7 +493,6 @@ func (e *eventStore) RegisterDispatcher( defer func() { if success { log.Info("register dispatcher success", - zap.Stringer("changefeedID", changefeedID), zap.Stringer("dispatcherID", dispatcherID), zap.String("span", common.FormatTableSpan(dispatcherSpan)), zap.Uint64("startTs", startTs), @@ -504,7 +501,6 @@ func (e *eventStore) RegisterDispatcher( zap.Duration("duration", time.Since(start))) } else { log.Info("register dispatcher failed", - zap.Stringer("changefeedID", changefeedID), zap.Stringer("dispatcherID", dispatcherID), zap.String("span", common.FormatTableSpan(dispatcherSpan)), zap.Uint64("startTs", startTs), @@ -553,7 +549,6 @@ func (e *eventStore) RegisterDispatcher( e.addSubscriberToSubStat(subStat, dispatcherID, &Subscriber{notifyFunc: wrappedNotifier}) e.dispatcherMeta.Unlock() log.Info("reuse existing subscription with exact span match", - zap.Stringer("changefeedID", changefeedID), zap.Stringer("dispatcherID", dispatcherID), zap.String("dispatcherSpan", common.FormatTableSpan(dispatcherSpan)), zap.Uint64("startTs", startTs), @@ -580,7 +575,6 @@ func (e *eventStore) RegisterDispatcher( e.dispatcherMeta.dispatcherStats[dispatcherID] = stat e.addSubscriberToSubStat(bestMatch, dispatcherID, &Subscriber{notifyFunc: wrappedNotifier}) log.Info("reuse existing subscription with smallest containing span", - zap.Stringer("changefeedID", changefeedID), zap.Stringer("dispatcherID", dispatcherID), zap.String("dispatcherSpan", common.FormatTableSpan(dispatcherSpan)), zap.Uint64("startTs", startTs), @@ -684,9 +678,8 @@ func (e *eventStore) RegisterDispatcher( serverConfig := config.GetGlobalServerConfig() resolvedTsAdvanceInterval := int64(serverConfig.KVClient.AdvanceIntervalInMs) // Note: don't hold any lock when call Subscribe - e.subClient.Subscribe(changefeedID.String(), subStat.subID, *dispatcherSpan, startTs, consumeKVEvents, advanceResolvedTs, resolvedTsAdvanceInterval, bdrMode) + e.subClient.Subscribe(subStat.subID, *dispatcherSpan, startTs, consumeKVEvents, advanceResolvedTs, resolvedTsAdvanceInterval, bdrMode) log.Info("new subscription created", - zap.Stringer("changefeedID", changefeedID), zap.Stringer("dispatcherID", dispatcherID), zap.Uint64("startTs", startTs), zap.Uint64("subscriptionID", uint64(subStat.subID)), diff --git a/logservice/eventstore/event_store_test.go b/logservice/eventstore/event_store_test.go index e1f356cf15..4ac22e504d 100644 --- a/logservice/eventstore/event_store_test.go +++ b/logservice/eventstore/event_store_test.go @@ -120,7 +120,6 @@ func (s *mockSubscriptionClient) AllocSubscriptionID() logpuller.SubscriptionID } func (s *mockSubscriptionClient) Subscribe( - changefeedID string, subID logpuller.SubscriptionID, span heartbeatpb.TableSpan, startTs uint64, diff --git a/logservice/logpuller/region_req_cache_test.go b/logservice/logpuller/region_req_cache_test.go index c4f223033d..62706a8542 100644 --- a/logservice/logpuller/region_req_cache_test.go +++ b/logservice/logpuller/region_req_cache_test.go @@ -33,10 +33,9 @@ func createTestRegionInfo(subID SubscriptionID, regionID uint64) regionInfo { } subscribedSpan := &subscribedSpan{ - subID: subID, - changefeedID: "test/test-changefeed", - startTs: 100, - span: span, + subID: subID, + startTs: 100, + span: span, } return newRegionInfo(verID, span, nil, subscribedSpan, false) diff --git a/logservice/logpuller/region_request_worker.go b/logservice/logpuller/region_request_worker.go index 130be03097..367ddc2561 100644 --- a/logservice/logpuller/region_request_worker.go +++ b/logservice/logpuller/region_request_worker.go @@ -373,7 +373,6 @@ func (s *regionRequestWorker) processRegionSendTask( subID := region.subscribedSpan.subID log.Debug("region request worker gets a singleRegionInfo", zap.Uint64("workerID", s.workerID), - zap.String("changefeedID", region.subscribedSpan.changefeedID), zap.Uint64("subscriptionID", uint64(subID)), zap.Uint64("regionID", region.verID.GetID()), zap.String("addr", s.store.storeAddr), diff --git a/logservice/logpuller/subscription_client.go b/logservice/logpuller/subscription_client.go index 3a6fb98445..107da949d0 100644 --- a/logservice/logpuller/subscription_client.go +++ b/logservice/logpuller/subscription_client.go @@ -109,9 +109,8 @@ const kvEventsCacheMaxSize = 32 // It contains a sub span of a table(or the total span of a table), // the startTs of the table, and the output event channel. type subscribedSpan struct { - subID SubscriptionID - changefeedID string - startTs uint64 + subID SubscriptionID + startTs uint64 // Whether to filter out the value written by TiCDC itself. // It should be `true` in BDR mode. filterLoop bool @@ -174,7 +173,6 @@ type SubscriptionClient interface { AllocSubscriptionID() SubscriptionID // subscribe a table span Subscribe( - changefeedID string, subID SubscriptionID, span heartbeatpb.TableSpan, startTs uint64, @@ -356,7 +354,6 @@ func (s *subscriptionClient) updateMetrics(ctx context.Context) error { // and send a rangeTask to `s.rangeTaskCh`. // The rangeTask will be handled in `handleRangeTasks` goroutine. func (s *subscriptionClient) Subscribe( - changefeedID string, subID SubscriptionID, span heartbeatpb.TableSpan, startTs uint64, @@ -370,7 +367,7 @@ func (s *subscriptionClient) Subscribe( return } - rt := s.newSubscribedSpan(changefeedID, subID, span, startTs, consumeKVEvents, advanceResolvedTs, advanceInterval, bdrMode) + rt := s.newSubscribedSpan(subID, span, startTs, consumeKVEvents, advanceResolvedTs, advanceInterval, bdrMode) s.totalSpans.Lock() s.totalSpans.spanMap[subID] = rt s.totalSpans.Unlock() @@ -384,7 +381,6 @@ func (s *subscriptionClient) Subscribe( log.Warn("subscribes span failed, the subscription client has closed") case s.rangeTaskCh <- rangeTask{span: span, subscribedSpan: rt, filterLoop: rt.filterLoop, priority: initialPriority}: log.Info("subscribes span done", - zap.String("changefeedID", changefeedID), zap.Uint64("subscriptionID", uint64(subID)), zap.Int64("tableID", span.TableID), zap.Uint64("startTs", startTs), zap.String("initialScanPriority", initialPriority.String()), @@ -423,7 +419,6 @@ func (s *subscriptionClient) maybeEnableRealtimeScanPriority(span *subscribedSpa } if span.realtimeScanPriority.CompareAndSwap(false, true) { log.Info("subscription client enables realtime scan priority", - zap.String("changefeedID", span.changefeedID), zap.Uint64("subscriptionID", uint64(span.subID)), zap.Uint64("resolvedTs", resolvedTs), zap.Duration("threshold", s.oldStartTsScanLowPriorityThreshold())) @@ -875,7 +870,6 @@ func (s *subscriptionClient) scheduleRegionRequest(ctx context.Context, region r s.regionTaskQueue.Push(NewRegionPriorityTask(priority, region, s.pdClock.CurrentTS())) if log.GetLevel() <= zapcore.DebugLevel { log.Debug("cdc region scan task enqueued", - zap.String("changefeedID", region.subscribedSpan.changefeedID), zap.Uint64("subscriptionID", uint64(region.subscribedSpan.subID)), zap.Int64("tableID", region.subscribedSpan.span.TableID), zap.Uint64("startTs", region.subscribedSpan.startTs), @@ -1151,7 +1145,6 @@ func (s *subscriptionClient) logSlowRegions(ctx context.Context) error { } func (s *subscriptionClient) newSubscribedSpan( - changefeedID string, subID SubscriptionID, span heartbeatpb.TableSpan, startTs uint64, @@ -1163,12 +1156,11 @@ func (s *subscriptionClient) newSubscribedSpan( rangeLock := regionlock.NewRangeLock(uint64(subID), span.StartKey, span.EndKey, startTs) rt := &subscribedSpan{ - subID: subID, - changefeedID: changefeedID, - span: span, - startTs: startTs, - filterLoop: filterLoop, - rangeLock: rangeLock, + subID: subID, + span: span, + startTs: startTs, + filterLoop: filterLoop, + rangeLock: rangeLock, consumeKVEvents: consumeKVEvents, advanceResolvedTs: advanceResolvedTs, diff --git a/logservice/logpuller/subscription_client_test.go b/logservice/logpuller/subscription_client_test.go index f0aa83eeec..e093b5a637 100644 --- a/logservice/logpuller/subscription_client_test.go +++ b/logservice/logpuller/subscription_client_test.go @@ -68,7 +68,7 @@ func TestGenerateResolveLockTask(t *testing.T) { } consumeKVEvents := func(_ []common.RawKVEntry, _ func()) bool { return false } advanceResolvedTs := func(ts uint64) {} - span := client.newSubscribedSpan("test/test-changefeed", SubscriptionID(1), rawSpan, 100, consumeKVEvents, advanceResolvedTs, 0, false) + span := client.newSubscribedSpan(SubscriptionID(1), rawSpan, 100, consumeKVEvents, advanceResolvedTs, 0, false) client.totalSpans.spanMap = make(map[SubscriptionID]*subscribedSpan) client.totalSpans.spanMap[SubscriptionID(1)] = span client.pdClock = pdutil.NewClock4Test() @@ -138,12 +138,12 @@ func TestResolveLockTaskDeduplicatedAcrossSubscribedSpans(t *testing.T) { consumeKVEvents := func(_ []common.RawKVEntry, _ func()) bool { return false } advanceResolvedTs := func(ts uint64) {} - span1 := client.newSubscribedSpan("test/test-changefeed", SubscriptionID(1), heartbeatpb.TableSpan{ + span1 := client.newSubscribedSpan(SubscriptionID(1), heartbeatpb.TableSpan{ TableID: 1, StartKey: []byte{'a'}, EndKey: []byte{'z'}, }, 100, consumeKVEvents, advanceResolvedTs, 0, false) - span2 := client.newSubscribedSpan("test/test-changefeed", SubscriptionID(2), heartbeatpb.TableSpan{ + span2 := client.newSubscribedSpan(SubscriptionID(2), heartbeatpb.TableSpan{ TableID: 2, StartKey: []byte{'a'}, EndKey: []byte{'z'}, @@ -246,7 +246,7 @@ func TestResolveLockTaskDroppedWhenChannelFull(t *testing.T) { } consumeKVEvents := func(_ []common.RawKVEntry, _ func()) bool { return false } advanceResolvedTs := func(ts uint64) {} - span := client.newSubscribedSpan("test/test-changefeed", SubscriptionID(1), rawSpan, 100, consumeKVEvents, advanceResolvedTs, 0, false) + span := client.newSubscribedSpan(SubscriptionID(1), rawSpan, 100, consumeKVEvents, advanceResolvedTs, 0, false) res := span.rangeLock.LockRange(context.Background(), []byte{'b'}, []byte{'c'}, 1, 100) require.Equal(t, regionlock.LockRangeStatusSuccess, res.Status) @@ -294,7 +294,7 @@ func TestStopTaskUsesSubscribedSpanFilterLoop(t *testing.T) { } consumeKVEvents := func(_ []common.RawKVEntry, _ func()) bool { return false } advanceResolvedTs := func(ts uint64) {} - span := client.newSubscribedSpan("test/test-changefeed", SubscriptionID(1), rawSpan, 100, consumeKVEvents, advanceResolvedTs, 0, true) + span := client.newSubscribedSpan(SubscriptionID(1), rawSpan, 100, consumeKVEvents, advanceResolvedTs, 0, true) res := span.rangeLock.LockRange(context.Background(), rawSpan.StartKey, rawSpan.EndKey, 1, 1) require.Equal(t, regionlock.LockRangeStatusSuccess, res.Status) @@ -586,7 +586,6 @@ func TestSubscribeUsesInitialScanTaskPriority(t *testing.T) { advanceResolvedTs := func(uint64) {} client.Subscribe( - "test/recent-changefeed", SubscriptionID(1), span, oracle.GoTimeToTS(currentTime.Add(-time.Minute)), @@ -596,7 +595,6 @@ func TestSubscribeUsesInitialScanTaskPriority(t *testing.T) { false, ) client.Subscribe( - "test/old-changefeed", SubscriptionID(2), span, oracle.GoTimeToTS(currentTime.Add(-31*time.Minute)), @@ -684,10 +682,9 @@ func newScanPriorityTestSpan() (heartbeatpb.TableSpan, *subscribedSpan) { EndKey: []byte("z"), } span := &subscribedSpan{ - subID: SubscriptionID(1), - changefeedID: "test/test-changefeed", - span: rawSpan, - rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), + subID: SubscriptionID(1), + span: rawSpan, + rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), } return rawSpan, span } @@ -846,7 +843,7 @@ func TestSubscriptionWithFailedTiKV(t *testing.T) { case tsCh <- ts: } } - client.Subscribe("test/test-changefeed", subID, span, 1, consumeKVEvents, advanceResolvedTs, 0, false) + client.Subscribe(subID, span, 1, consumeKVEvents, advanceResolvedTs, 0, false) eventsCh1 <- mockInitializedEvent(11, uint64(subID)) targetTs := oracle.GoTimeToTS(pdClock.CurrentTime()) @@ -1029,7 +1026,7 @@ func TestGetResolvedTargetTs(t *testing.T) { consumeKVEvents := func(_ []common.RawKVEntry, _ func()) bool { return false } advanceResolvedTs := func(ts uint64) {} - span := client.newSubscribedSpan("test/test-changefeed", SubscriptionID(1), heartbeatpb.TableSpan{ + span := client.newSubscribedSpan(SubscriptionID(1), heartbeatpb.TableSpan{ TableID: 1, StartKey: []byte{'a'}, EndKey: []byte{'z'}, diff --git a/logservice/schemastore/ddl_job_fetcher.go b/logservice/schemastore/ddl_job_fetcher.go index 018d17f545..0e943be723 100644 --- a/logservice/schemastore/ddl_job_fetcher.go +++ b/logservice/schemastore/ddl_job_fetcher.go @@ -15,7 +15,6 @@ package schemastore import ( "context" - "fmt" "math" "sync" @@ -98,7 +97,6 @@ func (p *ddlJobFetcher) run(startTs uint64) error { p.tryAdvanceResolvedTs(subID, ts) } p.subClient.Subscribe( - fmt.Sprintf("schema-store/ddl-job-fetcher-%d", p.keyspaceID), subID, span, startTs, From 343e555bc6b2afae8f6ee04d5b4c98c19f09870f Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Wed, 8 Jul 2026 15:33:15 +0800 Subject: [PATCH 14/21] eventstore: drop redundant register changefeed id Signed-off-by: hongyunyan <649330952@qq.com> --- logservice/eventstore/event_store.go | 3 - logservice/eventstore/event_store_test.go | 85 ++++++++++------------- pkg/eventservice/event_broker.go | 1 - pkg/eventservice/event_service_test.go | 1 - 4 files changed, 35 insertions(+), 55 deletions(-) diff --git a/logservice/eventstore/event_store.go b/logservice/eventstore/event_store.go index 17f9bf3e20..1ac83f26df 100644 --- a/logservice/eventstore/event_store.go +++ b/logservice/eventstore/event_store.go @@ -78,9 +78,7 @@ type Subscriber struct { type EventStore interface { common.SubModule - // Note: changefeedID is just a tag for dispatcher, avoid abuse it RegisterDispatcher( - changefeedID common.ChangeFeedID, dispatcherID common.DispatcherID, span *heartbeatpb.TableSpan, startTS uint64, @@ -460,7 +458,6 @@ func (e *eventStore) Close(_ context.Context) error { } func (e *eventStore) RegisterDispatcher( - changefeedID common.ChangeFeedID, dispatcherID common.DispatcherID, dispatcherSpan *heartbeatpb.TableSpan, startTs uint64, diff --git a/logservice/eventstore/event_store_test.go b/logservice/eventstore/event_store_test.go index 4ac22e504d..e324de858f 100644 --- a/logservice/eventstore/event_store_test.go +++ b/logservice/eventstore/event_store_test.go @@ -191,7 +191,6 @@ func TestEventStoreInteractionWithSubClient(t *testing.T) { dispatcherID1 := common.NewDispatcherID() dispatcherID2 := common.NewDispatcherID() dispatcherID3 := common.NewDispatcherID() - cfID := common.NewChangefeedID4Test("default", "test-cf") { span := &heartbeatpb.TableSpan{ @@ -199,7 +198,7 @@ func TestEventStoreInteractionWithSubClient(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("e"), } - ok := store.RegisterDispatcher(cfID, dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // add a dispatcher with the same span @@ -209,7 +208,7 @@ func TestEventStoreInteractionWithSubClient(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("e"), } - ok := store.RegisterDispatcher(cfID, dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // check there is only one subscription in subClient @@ -226,7 +225,7 @@ func TestEventStoreInteractionWithSubClient(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("b"), } - ok := store.RegisterDispatcher(cfID, dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // check a new subscription is created in subClient @@ -247,14 +246,13 @@ func TestEventStoreUsesKeyspaceIDForEncryption(t *testing.T) { es.encryptionManager = spy dispatcherID := common.NewDispatcherID() - cfID := common.NewChangefeedID4Test("default", "test-cf") span := &heartbeatpb.TableSpan{ TableID: 1, StartKey: []byte("a"), EndKey: []byte("z"), KeyspaceID: 42, } - ok := store.RegisterDispatcher(cfID, dispatcherID, span, 0, func(uint64, uint64) {}, false, false) + ok := store.RegisterDispatcher(dispatcherID, span, 0, func(uint64, uint64) {}, false, false) require.True(t, ok) es.dispatcherMeta.RLock() @@ -341,14 +339,13 @@ func TestEventStoreHandlesUnencryptedValuesFromEncryptionLayer(t *testing.T) { es.encryptionManager = encryption.NewEncryptionManager(&unencryptedMetaManager{}) dispatcherID := common.NewDispatcherID() - cfID := common.NewChangefeedID4Test("default", "test-cf") span := &heartbeatpb.TableSpan{ TableID: 1, StartKey: []byte("a"), EndKey: []byte("z"), KeyspaceID: 42, } - ok := store.RegisterDispatcher(cfID, dispatcherID, span, 0, func(uint64, uint64) {}, false, false) + ok := store.RegisterDispatcher(dispatcherID, span, 0, func(uint64, uint64) {}, false, false) require.True(t, ok) es.dispatcherMeta.RLock() @@ -437,7 +434,6 @@ func TestEventStoreOnlyReuseDispatcher(t *testing.T) { dispatcherID2 := common.NewDispatcherID() dispatcherID3 := common.NewDispatcherID() tableID := int64(1) - cfID := common.NewChangefeedID4Test("default", "test-cf") // add a dispatcher to create a subscription { span := &heartbeatpb.TableSpan{ @@ -445,7 +441,7 @@ func TestEventStoreOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(cfID, dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // add a dispatcher(onlyReuse=true) with a non-containing span which should fail @@ -455,7 +451,7 @@ func TestEventStoreOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("b"), EndKey: []byte("i"), } - ok := store.RegisterDispatcher(cfID, dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) + ok := store.RegisterDispatcher(dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) require.False(t, ok) } // when the existing subscription is not initialized, add a dispatcher(onlyReuse=true) should fail @@ -465,7 +461,7 @@ func TestEventStoreOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("b"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(cfID, dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) + ok := store.RegisterDispatcher(dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) require.False(t, ok) } // mark existing subscription as initialized @@ -477,11 +473,11 @@ func TestEventStoreOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("b"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(cfID, dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) + ok := store.RegisterDispatcher(dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) require.True(t, ok) } { - store.UnregisterDispatcher(cfID, dispatcherID1) + store.UnregisterDispatcher(common.NewChangefeedID4Test("default", "test-cf"), dispatcherID1) subStats := store.(*eventStore).dispatcherMeta.tableStats[tableID] require.Equal(t, 1, len(subStats)) // because there is only one subStat, we know its subID is 1 @@ -491,7 +487,7 @@ func TestEventStoreOnlyReuseDispatcher(t *testing.T) { require.NotNil(t, subData) require.Equal(t, 1, len(subData.subscribers)) require.Equal(t, int64(0), subData.idleTime) - store.UnregisterDispatcher(cfID, dispatcherID3) + store.UnregisterDispatcher(common.NewChangefeedID4Test("default", "test-cf"), dispatcherID3) subData = subStat.subscribers.Load() require.NotNil(t, subData) require.Equal(t, 0, len(subData.subscribers)) @@ -510,7 +506,6 @@ func TestEventStoreOnlyReuseDispatcherSuccess(t *testing.T) { dispatcherID2 := common.NewDispatcherID() dispatcherID3 := common.NewDispatcherID() tableID := int64(1) - cfID := common.NewChangefeedID4Test("default", "test-cf") // 1. Register a dispatcher to create a large subscription. { @@ -519,7 +514,7 @@ func TestEventStoreOnlyReuseDispatcherSuccess(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("z"), } - ok := es.RegisterDispatcher(cfID, dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := es.RegisterDispatcher(dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } markSubStatsInitializedForTest(store, tableID) @@ -532,7 +527,7 @@ func TestEventStoreOnlyReuseDispatcherSuccess(t *testing.T) { StartKey: []byte("b"), EndKey: []byte("y"), } - ok := es.RegisterDispatcher(cfID, dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) + ok := es.RegisterDispatcher(dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) require.True(t, ok) } @@ -544,7 +539,7 @@ func TestEventStoreOnlyReuseDispatcherSuccess(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("z"), } - ok := es.RegisterDispatcher(cfID, dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) + ok := es.RegisterDispatcher(dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) require.True(t, ok) } } @@ -560,7 +555,6 @@ func TestEventStoreNonOnlyReuseDispatcher(t *testing.T) { dispatcherID3 := common.NewDispatcherID() dispatcherID4 := common.NewDispatcherID() tableID := int64(1) - cfID := common.NewChangefeedID4Test("default", "test-cf") // add a subscription to create a subscription { span := &heartbeatpb.TableSpan{ @@ -568,7 +562,7 @@ func TestEventStoreNonOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(cfID, dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // add a dispatcher(onlyReuse=false) with a non-containing span @@ -578,7 +572,7 @@ func TestEventStoreNonOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("c"), EndKey: []byte("i"), } - ok := store.RegisterDispatcher(cfID, dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // do some check @@ -594,7 +588,7 @@ func TestEventStoreNonOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("b"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(cfID, dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // do some check @@ -616,7 +610,7 @@ func TestEventStoreNonOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(cfID, dispatcherID4, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(dispatcherID4, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) subStats := store.(*eventStore).dispatcherMeta.tableStats[tableID] require.Equal(t, 3, len(subStats)) @@ -629,7 +623,7 @@ func TestEventStoreNonOnlyReuseDispatcher(t *testing.T) { } // test unregister dispatcherID3 can remove its dependency on two subscriptions { - store.UnregisterDispatcher(cfID, dispatcherID3) + store.UnregisterDispatcher(common.NewChangefeedID4Test("default", "test-cf"), dispatcherID3) subStats := store.(*eventStore).dispatcherMeta.tableStats[tableID] require.Equal(t, 3, len(subStats)) { @@ -657,7 +651,6 @@ func TestEventStoreRegisterDispatcherWithoutDataSharing(t *testing.T) { es := store.(*eventStore) tableID := int64(1) - cfID := common.NewChangefeedID4Test("default", "test-cf") dispatcherID1 := common.NewDispatcherID() dispatcherID2 := common.NewDispatcherID() dispatcherID3 := common.NewDispatcherID() @@ -668,16 +661,16 @@ func TestEventStoreRegisterDispatcherWithoutDataSharing(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("h"), } - require.True(t, store.RegisterDispatcher(cfID, dispatcherID1, spanFull, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(dispatcherID1, spanFull, 100, func(uint64, uint64) {}, false, false)) - require.True(t, store.RegisterDispatcher(cfID, dispatcherID2, spanFull, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(dispatcherID2, spanFull, 100, func(uint64, uint64) {}, false, false)) spanSubset := &heartbeatpb.TableSpan{ TableID: tableID, StartKey: []byte("b"), EndKey: []byte("g"), } - require.True(t, store.RegisterDispatcher(cfID, dispatcherID3, spanSubset, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(dispatcherID3, spanSubset, 100, func(uint64, uint64) {}, false, false)) mockSubClient := subClient.(*mockSubscriptionClient) mockSubClient.mu.Lock() @@ -691,7 +684,7 @@ func TestEventStoreRegisterDispatcherWithoutDataSharing(t *testing.T) { require.Nil(t, es.dispatcherMeta.dispatcherStats[dispatcherID3].pendingSubStat) es.dispatcherMeta.RUnlock() - ok := store.RegisterDispatcher(cfID, dispatcherID4, spanFull, 100, func(uint64, uint64) {}, true, false) + ok := store.RegisterDispatcher(dispatcherID4, spanFull, 100, func(uint64, uint64) {}, true, false) require.False(t, ok) es.dispatcherMeta.RLock() @@ -711,8 +704,6 @@ func TestGetIteratorPanicWhenStartLessThanCheckpoint(t *testing.T) { defer func() { require.NoError(t, store.Close(context.Background())) }() - - cfID := common.NewChangefeedID4Test("default", "test") dispatcherID := common.NewDispatcherID() span := &heartbeatpb.TableSpan{ TableID: 1, @@ -720,7 +711,7 @@ func TestGetIteratorPanicWhenStartLessThanCheckpoint(t *testing.T) { EndKey: []byte("z"), } - require.True(t, store.RegisterDispatcher(cfID, dispatcherID, span, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(dispatcherID, span, 100, func(uint64, uint64) {}, false, false)) stat := store.dispatcherMeta.dispatcherStats[dispatcherID] require.NotNil(t, stat) @@ -746,21 +737,20 @@ func TestEventStoreUnregisterDispatcherWithoutDataSharingRemovesSubscription(t * es := store.(*eventStore) tableID := int64(1) - cfID := common.NewChangefeedID4Test("default", "test-cf") dispatcherID := common.NewDispatcherID() span := &heartbeatpb.TableSpan{ TableID: tableID, StartKey: []byte("a"), EndKey: []byte("h"), } - require.True(t, store.RegisterDispatcher(cfID, dispatcherID, span, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(dispatcherID, span, 100, func(uint64, uint64) {}, false, false)) mockSubClient := subClient.(*mockSubscriptionClient) mockSubClient.mu.Lock() require.Equal(t, 1, len(mockSubClient.subscriptions)) mockSubClient.mu.Unlock() - store.UnregisterDispatcher(cfID, dispatcherID) + store.UnregisterDispatcher(common.NewChangefeedID4Test("default", "test-cf"), dispatcherID) mockSubClient.mu.Lock() require.Equal(t, 1, len(mockSubClient.subscriptions)) @@ -788,16 +778,15 @@ func TestEventStoreUnregisterDispatcherWithDataSharingKeepsSubscriptionForTTL(t es := store.(*eventStore) tableID := int64(1) - cfID := common.NewChangefeedID4Test("default", "test-cf") dispatcherID := common.NewDispatcherID() span := &heartbeatpb.TableSpan{ TableID: tableID, StartKey: []byte("a"), EndKey: []byte("h"), } - require.True(t, store.RegisterDispatcher(cfID, dispatcherID, span, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(dispatcherID, span, 100, func(uint64, uint64) {}, false, false)) - store.UnregisterDispatcher(cfID, dispatcherID) + store.UnregisterDispatcher(common.NewChangefeedID4Test("default", "test-cf"), dispatcherID) mockSubClient := subClient.(*mockSubscriptionClient) mockSubClient.mu.Lock() @@ -833,7 +822,6 @@ func TestEventStoreUpdateCheckpointTs(t *testing.T) { dispatcherID1 := common.NewDispatcherID() dispatcherID2 := common.NewDispatcherID() tableID := int64(1) - cfID := common.NewChangefeedID4Test("default", "test-cf") // add first dispatcher { span := &heartbeatpb.TableSpan{ @@ -841,7 +829,7 @@ func TestEventStoreUpdateCheckpointTs(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(cfID, dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // add a dispatcher(onlyReuse=false) with a containing span @@ -851,7 +839,7 @@ func TestEventStoreUpdateCheckpointTs(t *testing.T) { StartKey: []byte("b"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(cfID, dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // check subStat checkpointTs cannot advance when their resolved ts is not advanced @@ -920,15 +908,14 @@ func TestEventStoreUpdateCheckpointTsConcurrentStaleUpdates(t *testing.T) { dispatcherID1 := common.NewDispatcherID() dispatcherID2 := common.NewDispatcherID() tableID := int64(1) - cfID := common.NewChangefeedID4Test("default", "test-cf") span := &heartbeatpb.TableSpan{ TableID: tableID, StartKey: []byte("a"), EndKey: []byte("h"), } - require.True(t, store.RegisterDispatcher(cfID, dispatcherID1, span, 100, func(uint64, uint64) {}, false, false)) - require.True(t, store.RegisterDispatcher(cfID, dispatcherID2, span, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(dispatcherID1, span, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(dispatcherID2, span, 100, func(uint64, uint64) {}, false, false)) es.dispatcherMeta.RLock() stat1 := es.dispatcherMeta.dispatcherStats[dispatcherID1] @@ -975,7 +962,6 @@ func TestEventStoreSwitchSubStat(t *testing.T) { dispatcherID1 := common.NewDispatcherID() dispatcherID2 := common.NewDispatcherID() tableID := int64(1) - cfID := common.NewChangefeedID4Test("default", "test-cf") updateSubStatResolvedTs := func(subID logpuller.SubscriptionID, ts uint64) { subStats := store.(*eventStore).dispatcherMeta.tableStats[tableID] @@ -1007,7 +993,7 @@ func TestEventStoreSwitchSubStat(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(cfID, dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // add a dispatcher(onlyReuse=false) with a containing span @@ -1018,7 +1004,7 @@ func TestEventStoreSwitchSubStat(t *testing.T) { StartKey: []byte("b"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(cfID, dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } @@ -1528,12 +1514,11 @@ func TestEventStoreGetIteratorConcurrently(t *testing.T) { // 1. Register a dispatcher. dispatcherID := common.NewDispatcherID() - cfID := common.NewChangefeedID4Test("default", "test-cf") span := &heartbeatpb.TableSpan{TableID: 1, StartKey: []byte("a"), EndKey: []byte("z")} startTs := uint64(100) var resolvedTs atomic.Uint64 resolvedTs.Store(startTs) - ok := store.RegisterDispatcher(cfID, dispatcherID, span, startTs, func(watermark, latestCommitTs uint64) { + ok := store.RegisterDispatcher(dispatcherID, span, startTs, func(watermark, latestCommitTs uint64) { resolvedTs.Store(watermark) }, false, false) require.True(t, ok) diff --git a/pkg/eventservice/event_broker.go b/pkg/eventservice/event_broker.go index 8acc8d9232..48e6233808 100644 --- a/pkg/eventservice/event_broker.go +++ b/pkg/eventservice/event_broker.go @@ -1023,7 +1023,6 @@ func (c *eventBroker) addDispatcher(info DispatcherInfo) error { start := time.Now() success := c.eventStore.RegisterDispatcher( - changefeedID, id, span, info.GetStartTs(), diff --git a/pkg/eventservice/event_service_test.go b/pkg/eventservice/event_service_test.go index 166df9429e..d9090a7b38 100644 --- a/pkg/eventservice/event_service_test.go +++ b/pkg/eventservice/event_service_test.go @@ -287,7 +287,6 @@ func (m *mockEventStore) GetLogCoordinatorNodeID() node.ID { } func (m *mockEventStore) RegisterDispatcher( - changefeedID common.ChangeFeedID, dispatcherID common.DispatcherID, span *heartbeatpb.TableSpan, startTS common.Ts, From 73f1c2f5ed07536e18cc4c078abce00fa563fb9c Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Tue, 14 Jul 2026 14:42:23 +0800 Subject: [PATCH 15/21] eventstore: restore changefeed ID in registration Signed-off-by: hongyunyan <649330952@qq.com> --- logservice/eventstore/event_store.go | 3 + logservice/eventstore/event_store_test.go | 85 +++++++++++++---------- pkg/eventservice/event_broker.go | 1 + pkg/eventservice/event_service_test.go | 1 + 4 files changed, 55 insertions(+), 35 deletions(-) diff --git a/logservice/eventstore/event_store.go b/logservice/eventstore/event_store.go index 1ac83f26df..f5b3e78986 100644 --- a/logservice/eventstore/event_store.go +++ b/logservice/eventstore/event_store.go @@ -78,7 +78,9 @@ type Subscriber struct { type EventStore interface { common.SubModule + // Note: changefeedID is just a tag for dispatcher, avoid abuse it RegisterDispatcher( + changefeedID common.ChangeFeedID, dispatcherID common.DispatcherID, span *heartbeatpb.TableSpan, startTS uint64, @@ -458,6 +460,7 @@ func (e *eventStore) Close(_ context.Context) error { } func (e *eventStore) RegisterDispatcher( + _ common.ChangeFeedID, dispatcherID common.DispatcherID, dispatcherSpan *heartbeatpb.TableSpan, startTs uint64, diff --git a/logservice/eventstore/event_store_test.go b/logservice/eventstore/event_store_test.go index e324de858f..4ac22e504d 100644 --- a/logservice/eventstore/event_store_test.go +++ b/logservice/eventstore/event_store_test.go @@ -191,6 +191,7 @@ func TestEventStoreInteractionWithSubClient(t *testing.T) { dispatcherID1 := common.NewDispatcherID() dispatcherID2 := common.NewDispatcherID() dispatcherID3 := common.NewDispatcherID() + cfID := common.NewChangefeedID4Test("default", "test-cf") { span := &heartbeatpb.TableSpan{ @@ -198,7 +199,7 @@ func TestEventStoreInteractionWithSubClient(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("e"), } - ok := store.RegisterDispatcher(dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(cfID, dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // add a dispatcher with the same span @@ -208,7 +209,7 @@ func TestEventStoreInteractionWithSubClient(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("e"), } - ok := store.RegisterDispatcher(dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(cfID, dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // check there is only one subscription in subClient @@ -225,7 +226,7 @@ func TestEventStoreInteractionWithSubClient(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("b"), } - ok := store.RegisterDispatcher(dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(cfID, dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // check a new subscription is created in subClient @@ -246,13 +247,14 @@ func TestEventStoreUsesKeyspaceIDForEncryption(t *testing.T) { es.encryptionManager = spy dispatcherID := common.NewDispatcherID() + cfID := common.NewChangefeedID4Test("default", "test-cf") span := &heartbeatpb.TableSpan{ TableID: 1, StartKey: []byte("a"), EndKey: []byte("z"), KeyspaceID: 42, } - ok := store.RegisterDispatcher(dispatcherID, span, 0, func(uint64, uint64) {}, false, false) + ok := store.RegisterDispatcher(cfID, dispatcherID, span, 0, func(uint64, uint64) {}, false, false) require.True(t, ok) es.dispatcherMeta.RLock() @@ -339,13 +341,14 @@ func TestEventStoreHandlesUnencryptedValuesFromEncryptionLayer(t *testing.T) { es.encryptionManager = encryption.NewEncryptionManager(&unencryptedMetaManager{}) dispatcherID := common.NewDispatcherID() + cfID := common.NewChangefeedID4Test("default", "test-cf") span := &heartbeatpb.TableSpan{ TableID: 1, StartKey: []byte("a"), EndKey: []byte("z"), KeyspaceID: 42, } - ok := store.RegisterDispatcher(dispatcherID, span, 0, func(uint64, uint64) {}, false, false) + ok := store.RegisterDispatcher(cfID, dispatcherID, span, 0, func(uint64, uint64) {}, false, false) require.True(t, ok) es.dispatcherMeta.RLock() @@ -434,6 +437,7 @@ func TestEventStoreOnlyReuseDispatcher(t *testing.T) { dispatcherID2 := common.NewDispatcherID() dispatcherID3 := common.NewDispatcherID() tableID := int64(1) + cfID := common.NewChangefeedID4Test("default", "test-cf") // add a dispatcher to create a subscription { span := &heartbeatpb.TableSpan{ @@ -441,7 +445,7 @@ func TestEventStoreOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(cfID, dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // add a dispatcher(onlyReuse=true) with a non-containing span which should fail @@ -451,7 +455,7 @@ func TestEventStoreOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("b"), EndKey: []byte("i"), } - ok := store.RegisterDispatcher(dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) + ok := store.RegisterDispatcher(cfID, dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) require.False(t, ok) } // when the existing subscription is not initialized, add a dispatcher(onlyReuse=true) should fail @@ -461,7 +465,7 @@ func TestEventStoreOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("b"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) + ok := store.RegisterDispatcher(cfID, dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) require.False(t, ok) } // mark existing subscription as initialized @@ -473,11 +477,11 @@ func TestEventStoreOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("b"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) + ok := store.RegisterDispatcher(cfID, dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) require.True(t, ok) } { - store.UnregisterDispatcher(common.NewChangefeedID4Test("default", "test-cf"), dispatcherID1) + store.UnregisterDispatcher(cfID, dispatcherID1) subStats := store.(*eventStore).dispatcherMeta.tableStats[tableID] require.Equal(t, 1, len(subStats)) // because there is only one subStat, we know its subID is 1 @@ -487,7 +491,7 @@ func TestEventStoreOnlyReuseDispatcher(t *testing.T) { require.NotNil(t, subData) require.Equal(t, 1, len(subData.subscribers)) require.Equal(t, int64(0), subData.idleTime) - store.UnregisterDispatcher(common.NewChangefeedID4Test("default", "test-cf"), dispatcherID3) + store.UnregisterDispatcher(cfID, dispatcherID3) subData = subStat.subscribers.Load() require.NotNil(t, subData) require.Equal(t, 0, len(subData.subscribers)) @@ -506,6 +510,7 @@ func TestEventStoreOnlyReuseDispatcherSuccess(t *testing.T) { dispatcherID2 := common.NewDispatcherID() dispatcherID3 := common.NewDispatcherID() tableID := int64(1) + cfID := common.NewChangefeedID4Test("default", "test-cf") // 1. Register a dispatcher to create a large subscription. { @@ -514,7 +519,7 @@ func TestEventStoreOnlyReuseDispatcherSuccess(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("z"), } - ok := es.RegisterDispatcher(dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := es.RegisterDispatcher(cfID, dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } markSubStatsInitializedForTest(store, tableID) @@ -527,7 +532,7 @@ func TestEventStoreOnlyReuseDispatcherSuccess(t *testing.T) { StartKey: []byte("b"), EndKey: []byte("y"), } - ok := es.RegisterDispatcher(dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) + ok := es.RegisterDispatcher(cfID, dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) require.True(t, ok) } @@ -539,7 +544,7 @@ func TestEventStoreOnlyReuseDispatcherSuccess(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("z"), } - ok := es.RegisterDispatcher(dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) + ok := es.RegisterDispatcher(cfID, dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, true, false) require.True(t, ok) } } @@ -555,6 +560,7 @@ func TestEventStoreNonOnlyReuseDispatcher(t *testing.T) { dispatcherID3 := common.NewDispatcherID() dispatcherID4 := common.NewDispatcherID() tableID := int64(1) + cfID := common.NewChangefeedID4Test("default", "test-cf") // add a subscription to create a subscription { span := &heartbeatpb.TableSpan{ @@ -562,7 +568,7 @@ func TestEventStoreNonOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(cfID, dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // add a dispatcher(onlyReuse=false) with a non-containing span @@ -572,7 +578,7 @@ func TestEventStoreNonOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("c"), EndKey: []byte("i"), } - ok := store.RegisterDispatcher(dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(cfID, dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // do some check @@ -588,7 +594,7 @@ func TestEventStoreNonOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("b"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(cfID, dispatcherID3, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // do some check @@ -610,7 +616,7 @@ func TestEventStoreNonOnlyReuseDispatcher(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(dispatcherID4, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(cfID, dispatcherID4, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) subStats := store.(*eventStore).dispatcherMeta.tableStats[tableID] require.Equal(t, 3, len(subStats)) @@ -623,7 +629,7 @@ func TestEventStoreNonOnlyReuseDispatcher(t *testing.T) { } // test unregister dispatcherID3 can remove its dependency on two subscriptions { - store.UnregisterDispatcher(common.NewChangefeedID4Test("default", "test-cf"), dispatcherID3) + store.UnregisterDispatcher(cfID, dispatcherID3) subStats := store.(*eventStore).dispatcherMeta.tableStats[tableID] require.Equal(t, 3, len(subStats)) { @@ -651,6 +657,7 @@ func TestEventStoreRegisterDispatcherWithoutDataSharing(t *testing.T) { es := store.(*eventStore) tableID := int64(1) + cfID := common.NewChangefeedID4Test("default", "test-cf") dispatcherID1 := common.NewDispatcherID() dispatcherID2 := common.NewDispatcherID() dispatcherID3 := common.NewDispatcherID() @@ -661,16 +668,16 @@ func TestEventStoreRegisterDispatcherWithoutDataSharing(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("h"), } - require.True(t, store.RegisterDispatcher(dispatcherID1, spanFull, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(cfID, dispatcherID1, spanFull, 100, func(uint64, uint64) {}, false, false)) - require.True(t, store.RegisterDispatcher(dispatcherID2, spanFull, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(cfID, dispatcherID2, spanFull, 100, func(uint64, uint64) {}, false, false)) spanSubset := &heartbeatpb.TableSpan{ TableID: tableID, StartKey: []byte("b"), EndKey: []byte("g"), } - require.True(t, store.RegisterDispatcher(dispatcherID3, spanSubset, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(cfID, dispatcherID3, spanSubset, 100, func(uint64, uint64) {}, false, false)) mockSubClient := subClient.(*mockSubscriptionClient) mockSubClient.mu.Lock() @@ -684,7 +691,7 @@ func TestEventStoreRegisterDispatcherWithoutDataSharing(t *testing.T) { require.Nil(t, es.dispatcherMeta.dispatcherStats[dispatcherID3].pendingSubStat) es.dispatcherMeta.RUnlock() - ok := store.RegisterDispatcher(dispatcherID4, spanFull, 100, func(uint64, uint64) {}, true, false) + ok := store.RegisterDispatcher(cfID, dispatcherID4, spanFull, 100, func(uint64, uint64) {}, true, false) require.False(t, ok) es.dispatcherMeta.RLock() @@ -704,6 +711,8 @@ func TestGetIteratorPanicWhenStartLessThanCheckpoint(t *testing.T) { defer func() { require.NoError(t, store.Close(context.Background())) }() + + cfID := common.NewChangefeedID4Test("default", "test") dispatcherID := common.NewDispatcherID() span := &heartbeatpb.TableSpan{ TableID: 1, @@ -711,7 +720,7 @@ func TestGetIteratorPanicWhenStartLessThanCheckpoint(t *testing.T) { EndKey: []byte("z"), } - require.True(t, store.RegisterDispatcher(dispatcherID, span, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(cfID, dispatcherID, span, 100, func(uint64, uint64) {}, false, false)) stat := store.dispatcherMeta.dispatcherStats[dispatcherID] require.NotNil(t, stat) @@ -737,20 +746,21 @@ func TestEventStoreUnregisterDispatcherWithoutDataSharingRemovesSubscription(t * es := store.(*eventStore) tableID := int64(1) + cfID := common.NewChangefeedID4Test("default", "test-cf") dispatcherID := common.NewDispatcherID() span := &heartbeatpb.TableSpan{ TableID: tableID, StartKey: []byte("a"), EndKey: []byte("h"), } - require.True(t, store.RegisterDispatcher(dispatcherID, span, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(cfID, dispatcherID, span, 100, func(uint64, uint64) {}, false, false)) mockSubClient := subClient.(*mockSubscriptionClient) mockSubClient.mu.Lock() require.Equal(t, 1, len(mockSubClient.subscriptions)) mockSubClient.mu.Unlock() - store.UnregisterDispatcher(common.NewChangefeedID4Test("default", "test-cf"), dispatcherID) + store.UnregisterDispatcher(cfID, dispatcherID) mockSubClient.mu.Lock() require.Equal(t, 1, len(mockSubClient.subscriptions)) @@ -778,15 +788,16 @@ func TestEventStoreUnregisterDispatcherWithDataSharingKeepsSubscriptionForTTL(t es := store.(*eventStore) tableID := int64(1) + cfID := common.NewChangefeedID4Test("default", "test-cf") dispatcherID := common.NewDispatcherID() span := &heartbeatpb.TableSpan{ TableID: tableID, StartKey: []byte("a"), EndKey: []byte("h"), } - require.True(t, store.RegisterDispatcher(dispatcherID, span, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(cfID, dispatcherID, span, 100, func(uint64, uint64) {}, false, false)) - store.UnregisterDispatcher(common.NewChangefeedID4Test("default", "test-cf"), dispatcherID) + store.UnregisterDispatcher(cfID, dispatcherID) mockSubClient := subClient.(*mockSubscriptionClient) mockSubClient.mu.Lock() @@ -822,6 +833,7 @@ func TestEventStoreUpdateCheckpointTs(t *testing.T) { dispatcherID1 := common.NewDispatcherID() dispatcherID2 := common.NewDispatcherID() tableID := int64(1) + cfID := common.NewChangefeedID4Test("default", "test-cf") // add first dispatcher { span := &heartbeatpb.TableSpan{ @@ -829,7 +841,7 @@ func TestEventStoreUpdateCheckpointTs(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(cfID, dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // add a dispatcher(onlyReuse=false) with a containing span @@ -839,7 +851,7 @@ func TestEventStoreUpdateCheckpointTs(t *testing.T) { StartKey: []byte("b"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(cfID, dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // check subStat checkpointTs cannot advance when their resolved ts is not advanced @@ -908,14 +920,15 @@ func TestEventStoreUpdateCheckpointTsConcurrentStaleUpdates(t *testing.T) { dispatcherID1 := common.NewDispatcherID() dispatcherID2 := common.NewDispatcherID() tableID := int64(1) + cfID := common.NewChangefeedID4Test("default", "test-cf") span := &heartbeatpb.TableSpan{ TableID: tableID, StartKey: []byte("a"), EndKey: []byte("h"), } - require.True(t, store.RegisterDispatcher(dispatcherID1, span, 100, func(uint64, uint64) {}, false, false)) - require.True(t, store.RegisterDispatcher(dispatcherID2, span, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(cfID, dispatcherID1, span, 100, func(uint64, uint64) {}, false, false)) + require.True(t, store.RegisterDispatcher(cfID, dispatcherID2, span, 100, func(uint64, uint64) {}, false, false)) es.dispatcherMeta.RLock() stat1 := es.dispatcherMeta.dispatcherStats[dispatcherID1] @@ -962,6 +975,7 @@ func TestEventStoreSwitchSubStat(t *testing.T) { dispatcherID1 := common.NewDispatcherID() dispatcherID2 := common.NewDispatcherID() tableID := int64(1) + cfID := common.NewChangefeedID4Test("default", "test-cf") updateSubStatResolvedTs := func(subID logpuller.SubscriptionID, ts uint64) { subStats := store.(*eventStore).dispatcherMeta.tableStats[tableID] @@ -993,7 +1007,7 @@ func TestEventStoreSwitchSubStat(t *testing.T) { StartKey: []byte("a"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(cfID, dispatcherID1, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } // add a dispatcher(onlyReuse=false) with a containing span @@ -1004,7 +1018,7 @@ func TestEventStoreSwitchSubStat(t *testing.T) { StartKey: []byte("b"), EndKey: []byte("h"), } - ok := store.RegisterDispatcher(dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) + ok := store.RegisterDispatcher(cfID, dispatcherID2, span, 100, func(watermark uint64, latestCommitTs uint64) {}, false, false) require.True(t, ok) } @@ -1514,11 +1528,12 @@ func TestEventStoreGetIteratorConcurrently(t *testing.T) { // 1. Register a dispatcher. dispatcherID := common.NewDispatcherID() + cfID := common.NewChangefeedID4Test("default", "test-cf") span := &heartbeatpb.TableSpan{TableID: 1, StartKey: []byte("a"), EndKey: []byte("z")} startTs := uint64(100) var resolvedTs atomic.Uint64 resolvedTs.Store(startTs) - ok := store.RegisterDispatcher(dispatcherID, span, startTs, func(watermark, latestCommitTs uint64) { + ok := store.RegisterDispatcher(cfID, dispatcherID, span, startTs, func(watermark, latestCommitTs uint64) { resolvedTs.Store(watermark) }, false, false) require.True(t, ok) diff --git a/pkg/eventservice/event_broker.go b/pkg/eventservice/event_broker.go index 6ee9ca91db..4e0a659f05 100644 --- a/pkg/eventservice/event_broker.go +++ b/pkg/eventservice/event_broker.go @@ -1028,6 +1028,7 @@ func (c *eventBroker) addDispatcher(info DispatcherInfo) error { start := time.Now() success := c.eventStore.RegisterDispatcher( + changefeedID, id, span, info.GetStartTs(), diff --git a/pkg/eventservice/event_service_test.go b/pkg/eventservice/event_service_test.go index d9090a7b38..166df9429e 100644 --- a/pkg/eventservice/event_service_test.go +++ b/pkg/eventservice/event_service_test.go @@ -287,6 +287,7 @@ func (m *mockEventStore) GetLogCoordinatorNodeID() node.ID { } func (m *mockEventStore) RegisterDispatcher( + changefeedID common.ChangeFeedID, dispatcherID common.DispatcherID, span *heartbeatpb.TableSpan, startTS common.Ts, From e281c0e03c102787a5995610f813604fa73e5e76 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Wed, 15 Jul 2026 20:36:21 +0800 Subject: [PATCH 16/21] logpuller: simplify scan priority state handling --- logservice/logpuller/region_event_handler.go | 6 ++- .../logpuller/region_event_handler_test.go | 13 ++++-- logservice/logpuller/region_event_sink.go | 9 +++- logservice/logpuller/span_registry.go | 24 +++++++++-- logservice/logpuller/subscription_client.go | 43 +++---------------- .../logpuller/subscription_client_test.go | 21 +++------ 6 files changed, 55 insertions(+), 61 deletions(-) diff --git a/logservice/logpuller/region_event_handler.go b/logservice/logpuller/region_event_handler.go index 1f148665bd..1b274ecf9a 100644 --- a/logservice/logpuller/region_event_handler.go +++ b/logservice/logpuller/region_event_handler.go @@ -21,6 +21,7 @@ import ( "github.com/pingcap/log" "github.com/pingcap/ticdc/pkg/common" "github.com/pingcap/ticdc/pkg/metrics" + "github.com/pingcap/ticdc/pkg/pdutil" "github.com/pingcap/ticdc/pkg/spanz" "github.com/pingcap/ticdc/pkg/util" "github.com/pingcap/ticdc/utils/dynstream" @@ -89,6 +90,7 @@ func (event regionEvent) mustFirstState() *regionFeedState { type regionEventHandler struct { eventSink *regionEventSink failureHandler *regionFailureHandler + pdClock pdutil.Clock } func (h *regionEventHandler) Path(event regionEvent) SubscriptionID { @@ -143,8 +145,8 @@ func (h *regionEventHandler) Handle(span *subscribedSpan, events ...regionEvent) log.Panic("should not reach", zap.Any("event", event), zap.Any("events", events)) } } - if newResolvedTs > 0 && h.failureHandler != nil && h.failureHandler.client != nil { - h.failureHandler.client.maybeEnableRealtimeScanPriority(span, newResolvedTs) + if newResolvedTs > 0 { + span.maybeMarkCaughtUp(h.pdClock, newResolvedTs) } tryAdvanceResolvedTs := func() { if newResolvedTs != 0 { diff --git a/logservice/logpuller/region_event_handler_test.go b/logservice/logpuller/region_event_handler_test.go index e94d176ed0..79c534b407 100644 --- a/logservice/logpuller/region_event_handler_test.go +++ b/logservice/logpuller/region_event_handler_test.go @@ -23,6 +23,7 @@ import ( "github.com/pingcap/ticdc/heartbeatpb" "github.com/pingcap/ticdc/logservice/logpuller/regionlock" "github.com/pingcap/ticdc/pkg/common" + "github.com/pingcap/ticdc/pkg/pdutil" "github.com/pingcap/ticdc/utils/dynstream" "github.com/stretchr/testify/require" "github.com/tikv/client-go/v2/tikv" @@ -206,7 +207,9 @@ func TestHandleEventEntryEventOutOfOrder(t *testing.T) { func TestHandleResolvedTs(t *testing.T) { // initialize option := dynstream.NewOption() - ds := dynstream.NewParallelDynamicStream("test", ®ionEventHandler{}, option) + pdClock := pdutil.NewClock4Test() + pdClock.(*pdutil.Clock4Test).SetTS(10) + ds := dynstream.NewParallelDynamicStream("test", ®ionEventHandler{pdClock: pdClock}, option) ds.Start() consumeKVEvents := func(events []common.RawKVEntry, _ func()) bool { return false } // not used @@ -221,13 +224,14 @@ func TestHandleResolvedTs(t *testing.T) { } state1 := newRegionFeedState(regionInfo{verID: tikv.NewRegionVerID(1, 1, 1)}, uint64(subID1), worker) state1.start() + var subSpan1 *subscribedSpan { span := heartbeatpb.TableSpan{ TableID: 100, StartKey: common.ToComparableKey([]byte{}), // TODO: remove spanz dependency EndKey: common.ToComparableKey(common.UpperBoundKey), } - subSpan := &subscribedSpan{ + subSpan1 = &subscribedSpan{ subID: subID1, span: heartbeatpb.TableSpan{}, rangeLock: regionlock.NewRangeLock(uint64(subID1), span.StartKey, span.EndKey, 1), @@ -235,8 +239,8 @@ func TestHandleResolvedTs(t *testing.T) { advanceResolvedTs: advanceResolvedTs, advanceInterval: 0, } - ds.AddPath(subID1, subSpan, dynstream.AreaSettings{}) - state1.region.subscribedSpan = subSpan + ds.AddPath(subID1, subSpan1, dynstream.AreaSettings{}) + state1.region.subscribedSpan = subSpan1 state1.region.lockedRangeState = ®ionlock.LockedRangeState{} state1.setInitialized() state1.updateResolvedTs(9) @@ -330,6 +334,7 @@ func TestHandleResolvedTs(t *testing.T) { require.Equal(t, uint64(10), state1.getLastResolvedTs()) require.Equal(t, uint64(11), state2.getLastResolvedTs()) require.Equal(t, uint64(8), state3.getLastResolvedTs()) + require.True(t, subSpan1.everCaughtUp.Load()) } func TestHandleResolvedTsThrottled(t *testing.T) { diff --git a/logservice/logpuller/region_event_sink.go b/logservice/logpuller/region_event_sink.go index 3fb1771461..50af5a7da2 100644 --- a/logservice/logpuller/region_event_sink.go +++ b/logservice/logpuller/region_event_sink.go @@ -20,6 +20,7 @@ import ( "github.com/pingcap/log" "github.com/pingcap/ticdc/pkg/metrics" + "github.com/pingcap/ticdc/pkg/pdutil" "github.com/pingcap/ticdc/utils/dynstream" "go.uber.org/zap" ) @@ -34,7 +35,11 @@ type regionEventSink struct { paused atomic.Bool } -func newRegionEventSink(ctx context.Context, failureHandler *regionFailureHandler) *regionEventSink { +func newRegionEventSink( + ctx context.Context, + failureHandler *regionFailureHandler, + pdClock pdutil.Clock, +) *regionEventSink { sink := ®ionEventSink{ctx: ctx} option := dynstream.NewOption() @@ -46,7 +51,7 @@ func newRegionEventSink(ctx context.Context, failureHandler *regionFailureHandle option.EnableMemoryControl = true ds := dynstream.NewParallelDynamicStream( "log-puller", - ®ionEventHandler{eventSink: sink, failureHandler: failureHandler}, + ®ionEventHandler{eventSink: sink, failureHandler: failureHandler, pdClock: pdClock}, option, ) ds.Start() diff --git a/logservice/logpuller/span_registry.go b/logservice/logpuller/span_registry.go index 35b2b0c864..e3eb4a8f61 100644 --- a/logservice/logpuller/span_registry.go +++ b/logservice/logpuller/span_registry.go @@ -71,10 +71,10 @@ type subscribedSpan struct { initialized atomic.Bool resolvedTsUpdated atomic.Int64 resolvedTs atomic.Uint64 - // realtimeScanPriority is set after this subscription catches up once. - // It is sticky so later recovery scans can protect realtime changefeeds + // everCaughtUp is sticky after this subscription catches up for the first time, + // so later recovery scans can protect realtime changefeeds // even if historical catch-up scans temporarily push their lag up again. - realtimeScanPriority atomic.Bool + everCaughtUp atomic.Bool } // spanRegistry tracks subscribed spans and owns span-level background maintenance. @@ -142,6 +142,24 @@ func newSubscribedSpan( return rt } +func (span *subscribedSpan) maybeMarkCaughtUp(pdClock pdutil.Clock, resolvedTs uint64) { + if span.everCaughtUp.Load() || !isTsCloseToCurrent(pdClock, resolvedTs) { + return + } + if span.everCaughtUp.CompareAndSwap(false, true) { + log.Info("subscription catches up for the first time", + zap.Uint64("subscriptionID", uint64(span.subID)), + zap.Uint64("resolvedTs", resolvedTs)) + } +} + +func (span *subscribedSpan) effectiveScanTaskPriority(priority TaskType) TaskType { + if priority == TaskHighPrior || span.everCaughtUp.Load() { + return TaskHighPrior + } + return priority +} + func (span *subscribedSpan) clearKVEventsCache() { if cap(span.kvEventsCache) > kvEventsCacheMaxSize { span.kvEventsCache = nil diff --git a/logservice/logpuller/subscription_client.go b/logservice/logpuller/subscription_client.go index 4d28ce4074..460fe7ae48 100644 --- a/logservice/logpuller/subscription_client.go +++ b/logservice/logpuller/subscription_client.go @@ -182,7 +182,7 @@ func NewSubscriptionClient( } subClient.ctx, subClient.cancel = context.WithCancel(context.Background()) subClient.failureHandler = newRegionFailureHandler(subClient) - subClient.eventSink = newRegionEventSink(subClient.ctx, subClient.failureHandler) + subClient.eventSink = newRegionEventSink(subClient.ctx, subClient.failureHandler, subClient.pdClock) subClient.spanRegistry = newSpanRegistry(subClient.pd, subClient.pdClock) subClient.initMetrics() @@ -278,47 +278,18 @@ func (s *subscriptionClient) Subscribe( } func (s *subscriptionClient) initialScanTaskPriority(startTs uint64) TaskType { - if s.isTsCloseToCurrent(startTs) { + if isTsCloseToCurrent(s.pdClock, startTs) { return TaskHighPrior } return TaskLowPrior } -func (s *subscriptionClient) oldStartTsScanLowPriorityThreshold() time.Duration { - threshold := time.Duration(config.GetGlobalServerConfig().Debug.Puller.OldStartTsScanLowPriorityThreshold) - if threshold > 0 { - return threshold - } - return config.DefaultOldStartTsScanLowPriorityThreshold -} - -func (s *subscriptionClient) isTsCloseToCurrent(ts uint64) bool { +func isTsCloseToCurrent(pdClock pdutil.Clock, ts uint64) bool { if ts == 0 { return false } - return s.pdClock.CurrentTime().Sub(oracle.GetTimeFromTS(ts)) <= s.oldStartTsScanLowPriorityThreshold() -} - -func (s *subscriptionClient) maybeEnableRealtimeScanPriority(span *subscribedSpan, resolvedTs uint64) { - if span == nil || !span.initialized.Load() || span.realtimeScanPriority.Load() { - return - } - if !s.isTsCloseToCurrent(resolvedTs) { - return - } - if span.realtimeScanPriority.CompareAndSwap(false, true) { - log.Info("subscription client enables realtime scan priority", - zap.Uint64("subscriptionID", uint64(span.subID)), - zap.Uint64("resolvedTs", resolvedTs), - zap.Duration("threshold", s.oldStartTsScanLowPriorityThreshold())) - } -} - -func (s *subscriptionClient) effectiveScanTaskPriority(subscribedSpan *subscribedSpan, priority TaskType) TaskType { - if subscribedSpan != nil && subscribedSpan.realtimeScanPriority.Load() { - return TaskHighPrior - } - return priority + threshold := time.Duration(config.GetGlobalServerConfig().Debug.Puller.OldStartTsScanLowPriorityThreshold) + return pdClock.CurrentTime().Sub(oracle.GetTimeFromTS(ts)) <= threshold } // Unsubscribe the given table span. All covered regions will be deregistered asynchronously. @@ -681,7 +652,7 @@ func (s *subscriptionClient) divideSpanAndScheduleRegionRequests( // scheduleRegionRequest locks the region's range and send the region to regionTaskQueue, // which will be handled by handleRegions. func (s *subscriptionClient) scheduleRegionRequest(ctx context.Context, region regionInfo, priority TaskType) { - priority = s.effectiveScanTaskPriority(region.subscribedSpan, priority) + priority = region.subscribedSpan.effectiveScanTaskPriority(priority) region.scanPriority = priority.scanPriority() lockRangeResult := region.subscribedSpan.rangeLock.LockRange( ctx, region.span.StartKey, region.span.EndKey, region.verID.GetID(), region.verID.GetVer()) @@ -721,7 +692,7 @@ func (s *subscriptionClient) scheduleRangeRequest( filterLoop bool, priority TaskType, ) { - priority = s.effectiveScanTaskPriority(subscribedSpan, priority) + priority = subscribedSpan.effectiveScanTaskPriority(priority) select { case <-ctx.Done(): case s.rangeTaskCh <- rangeTask{span: span, subscribedSpan: subscribedSpan, filterLoop: filterLoop, priority: priority}: diff --git a/logservice/logpuller/subscription_client_test.go b/logservice/logpuller/subscription_client_test.go index 6ccc4bb30b..e551ee9e52 100644 --- a/logservice/logpuller/subscription_client_test.go +++ b/logservice/logpuller/subscription_client_test.go @@ -658,22 +658,15 @@ func TestRealtimeScanPriorityEnabledAfterSubscriptionCatchesUp(t *testing.T) { currentTime := time.Date(2026, time.June, 27, 12, 0, 0, 0, time.UTC) pdClock := pdutil.NewClock4Test() pdClock.(*pdutil.Clock4Test).SetTS(oracle.GoTimeToTS(currentTime)) - client := &subscriptionClient{ - pdClock: pdClock, - } _, span := newScanPriorityTestSpan() - client.maybeEnableRealtimeScanPriority(span, oracle.GoTimeToTS(currentTime.Add(-time.Minute))) - require.False(t, span.realtimeScanPriority.Load()) - - span.initialized.Store(true) - client.maybeEnableRealtimeScanPriority(span, oracle.GoTimeToTS(currentTime.Add(-31*time.Minute))) - require.False(t, span.realtimeScanPriority.Load()) + span.maybeMarkCaughtUp(pdClock, oracle.GoTimeToTS(currentTime.Add(-31*time.Minute))) + require.False(t, span.everCaughtUp.Load()) - client.maybeEnableRealtimeScanPriority(span, oracle.GoTimeToTS(currentTime.Add(-time.Minute))) - require.True(t, span.realtimeScanPriority.Load()) - require.Equal(t, TaskHighPrior, client.effectiveScanTaskPriority(span, TaskLowPrior)) + span.maybeMarkCaughtUp(pdClock, oracle.GoTimeToTS(currentTime.Add(-time.Minute))) + require.True(t, span.everCaughtUp.Load()) + require.Equal(t, TaskHighPrior, span.effectiveScanTaskPriority(TaskLowPrior)) } func TestRealtimeScanPriorityUpgradesRegionRetry(t *testing.T) { @@ -683,7 +676,7 @@ func TestRealtimeScanPriorityUpgradesRegionRetry(t *testing.T) { client.pdClock = pdutil.NewClock4Test() client.failureHandler = newRegionFailureHandler(client) _, span := newScanPriorityTestSpan() - span.realtimeScanPriority.Store(true) + span.everCaughtUp.Store(true) region := newScanPriorityTestRegion(span) region.scanPriority = cdcpb.ScanPriority_SCAN_PRIORITY_LOW @@ -704,7 +697,7 @@ func TestRealtimeScanPriorityUpgradesRangeRetry(t *testing.T) { } client.failureHandler = newRegionFailureHandler(client) rawSpan, span := newScanPriorityTestSpan() - span.realtimeScanPriority.Store(true) + span.everCaughtUp.Store(true) region := newScanPriorityTestRegion(span) region.scanPriority = cdcpb.ScanPriority_SCAN_PRIORITY_LOW From 0d9423ab48b5cd88f91f4235a842ac5f4c90cb8f Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Wed, 15 Jul 2026 20:49:57 +0800 Subject: [PATCH 17/21] logpuller: clean up caught-up priority handling --- logservice/logpuller/span_registry.go | 5 +- logservice/logpuller/subscription_client.go | 1 - .../logpuller/subscription_client_test.go | 88 ++++++------------- 3 files changed, 28 insertions(+), 66 deletions(-) diff --git a/logservice/logpuller/span_registry.go b/logservice/logpuller/span_registry.go index e3eb4a8f61..d303a06658 100644 --- a/logservice/logpuller/span_registry.go +++ b/logservice/logpuller/span_registry.go @@ -71,9 +71,8 @@ type subscribedSpan struct { initialized atomic.Bool resolvedTsUpdated atomic.Int64 resolvedTs atomic.Uint64 - // everCaughtUp is sticky after this subscription catches up for the first time, - // so later recovery scans can protect realtime changefeeds - // even if historical catch-up scans temporarily push their lag up again. + // everCaughtUp remains true once the subscription catches up, so recovery scans + // stay high priority even if a later failure temporarily increases the lag. everCaughtUp atomic.Bool } diff --git a/logservice/logpuller/subscription_client.go b/logservice/logpuller/subscription_client.go index 1eb7ab0fe2..dc70e18dc3 100644 --- a/logservice/logpuller/subscription_client.go +++ b/logservice/logpuller/subscription_client.go @@ -692,7 +692,6 @@ func (s *subscriptionClient) scheduleRangeRequest( filterLoop bool, priority TaskType, ) { - priority = subscribedSpan.effectiveScanTaskPriority(priority) select { case <-ctx.Done(): case s.rangeTaskCh <- rangeTask{span: span, subscribedSpan: subscribedSpan, filterLoop: filterLoop, priority: priority}: diff --git a/logservice/logpuller/subscription_client_test.go b/logservice/logpuller/subscription_client_test.go index b91a352a12..0f8aa4abab 100644 --- a/logservice/logpuller/subscription_client_test.go +++ b/logservice/logpuller/subscription_client_test.go @@ -388,12 +388,13 @@ func TestOnRegionFailQueuesCanceledErrorCache(t *testing.T) { require.Nil(t, client.spanRegistry.Get(span.subID)) } -func TestBusyRetryPreservesScanPriority(t *testing.T) { +func TestRegionRetryScanPriority(t *testing.T) { for _, tc := range []struct { - name string - priority cdcpb.ScanPriority - cdcErr *cdcpb.Error - expected TaskType + name string + priority cdcpb.ScanPriority + cdcErr *cdcpb.Error + everCaughtUp bool + expected TaskType }{ { name: "server is busy high", @@ -407,6 +408,13 @@ func TestBusyRetryPreservesScanPriority(t *testing.T) { cdcErr: &cdcpb.Error{ServerIsBusy: &errorpb.ServerIsBusy{}}, expected: TaskLowPrior, }, + { + name: "server is busy low after catch up", + priority: cdcpb.ScanPriority_SCAN_PRIORITY_LOW, + cdcErr: &cdcpb.Error{ServerIsBusy: &errorpb.ServerIsBusy{}}, + everCaughtUp: true, + expected: TaskHighPrior, + }, { name: "congested high", priority: cdcpb.ScanPriority_SCAN_PRIORITY_HIGH, @@ -439,6 +447,7 @@ func TestBusyRetryPreservesScanPriority(t *testing.T) { client.pdClock = pdutil.NewClock4Test() client.failureHandler = newRegionFailureHandler(client) _, span := newScanPriorityTestSpan() + span.everCaughtUp.Store(tc.everCaughtUp) region := newScanPriorityTestRegion(span) region.scanPriority = tc.priority @@ -450,7 +459,7 @@ func TestBusyRetryPreservesScanPriority(t *testing.T) { task, err := client.regionTaskQueue.Pop(ctx) require.NoError(t, err) require.Equal(t, tc.expected, task.(*regionPriorityTask).taskType) - require.Equal(t, tc.priority, task.GetRegionInfo().scanPriority) + require.Equal(t, tc.expected.scanPriority(), task.GetRegionInfo().scanPriority) }) } } @@ -553,8 +562,7 @@ func (s *mockDynamicStream) GetMetrics() dynstream.Metrics[int, SubscriptionID] } func TestInitialScanTaskPriority(t *testing.T) { - restore := setInitialScanLowPriorityThresholdForTest(t, 30*time.Minute) - defer restore() + setInitialScanLowPriorityThresholdForTest(t, 30*time.Minute) currentTime := time.Date(2026, time.June, 27, 12, 0, 0, 0, time.UTC) pdClock := pdutil.NewClock4Test() @@ -601,8 +609,7 @@ func TestInitialScanTaskPriority(t *testing.T) { } func TestSubscribeUsesInitialScanTaskPriority(t *testing.T) { - restore := setInitialScanLowPriorityThresholdForTest(t, 30*time.Minute) - defer restore() + setInitialScanLowPriorityThresholdForTest(t, 30*time.Minute) ctx := t.Context() @@ -650,66 +657,23 @@ func TestSubscribeUsesInitialScanTaskPriority(t *testing.T) { require.Equal(t, TaskLowPrior, (<-client.rangeTaskCh).priority) } -func TestRealtimeScanPriorityEnabledAfterSubscriptionCatchesUp(t *testing.T) { - restore := setInitialScanLowPriorityThresholdForTest(t, 30*time.Minute) - defer restore() +func TestSubscribedSpanMarksCaughtUp(t *testing.T) { + setInitialScanLowPriorityThresholdForTest(t, 30*time.Minute) currentTime := time.Date(2026, time.June, 27, 12, 0, 0, 0, time.UTC) pdClock := pdutil.NewClock4Test() pdClock.(*pdutil.Clock4Test).SetTS(oracle.GoTimeToTS(currentTime)) - _, span := newScanPriorityTestSpan() - span.maybeMarkCaughtUp(pdClock, oracle.GoTimeToTS(currentTime.Add(-31*time.Minute))) + oldResolvedTs := oracle.GoTimeToTS(currentTime.Add(-31 * time.Minute)) + span.maybeMarkCaughtUp(pdClock, oldResolvedTs) require.False(t, span.everCaughtUp.Load()) span.maybeMarkCaughtUp(pdClock, oracle.GoTimeToTS(currentTime.Add(-time.Minute))) require.True(t, span.everCaughtUp.Load()) - require.Equal(t, TaskHighPrior, span.effectiveScanTaskPriority(TaskLowPrior)) -} -func TestRealtimeScanPriorityUpgradesRegionRetry(t *testing.T) { - client := &subscriptionClient{ - regionTaskQueue: priorityqueue.New[PriorityTask](), - } - client.pdClock = pdutil.NewClock4Test() - client.failureHandler = newRegionFailureHandler(client) - _, span := newScanPriorityTestSpan() - span.everCaughtUp.Store(true) - region := newScanPriorityTestRegion(span) - region.scanPriority = cdcpb.ScanPriority_SCAN_PRIORITY_LOW - - err := client.failureHandler.handleError(context.Background(), newRegionErrorInfo(region, &eventError{err: &cdcpb.Error{ServerIsBusy: &errorpb.ServerIsBusy{}}})) - require.NoError(t, err) - - ctx, cancel := context.WithTimeout(context.Background(), time.Second) - defer cancel() - task, err := client.regionTaskQueue.Pop(ctx) - require.NoError(t, err) - require.Equal(t, TaskHighPrior, task.(*regionPriorityTask).taskType) - require.Equal(t, cdcpb.ScanPriority_SCAN_PRIORITY_HIGH, task.GetRegionInfo().scanPriority) -} - -func TestRealtimeScanPriorityUpgradesRangeRetry(t *testing.T) { - client := &subscriptionClient{ - rangeTaskCh: make(chan rangeTask, 1), - } - client.failureHandler = newRegionFailureHandler(client) - rawSpan, span := newScanPriorityTestSpan() - span.everCaughtUp.Store(true) - region := newScanPriorityTestRegion(span) - region.scanPriority = cdcpb.ScanPriority_SCAN_PRIORITY_LOW - - err := client.failureHandler.handleError(context.Background(), newRegionErrorInfo(region, &eventError{err: &cdcpb.Error{EpochNotMatch: &errorpb.EpochNotMatch{}}})) - require.NoError(t, err) - - select { - case task := <-client.rangeTaskCh: - require.Equal(t, TaskHighPrior, task.priority) - require.Equal(t, rawSpan, task.span) - case <-time.After(time.Second): - require.Fail(t, "expected range retry task") - } + span.maybeMarkCaughtUp(pdClock, oldResolvedTs) + require.True(t, span.everCaughtUp.Load()) } func newScanPriorityTestSpan() (heartbeatpb.TableSpan, *subscribedSpan) { @@ -730,15 +694,15 @@ func newScanPriorityTestRegion(span *subscribedSpan) regionInfo { return newRegionInfo(tikv.NewRegionVerID(1, 1, 1), span.span, nil, span, false) } -func setInitialScanLowPriorityThresholdForTest(t *testing.T, threshold time.Duration) func() { +func setInitialScanLowPriorityThresholdForTest(t *testing.T, threshold time.Duration) { t.Helper() oldConfig := config.GetGlobalServerConfig() testConfig := oldConfig.Clone() testConfig.Debug.Puller.OldStartTsScanLowPriorityThreshold = config.TomlDuration(threshold) config.StoreGlobalServerConfig(testConfig) - return func() { + t.Cleanup(func() { config.StoreGlobalServerConfig(oldConfig) - } + }) } func TestPushRegionEventToDSUnblocksOnClose(t *testing.T) { From c7ea317e2df1942447c6e0d45a9c9761b15a6939 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Thu, 16 Jul 2026 10:31:38 +0800 Subject: [PATCH 18/21] Update logservice/logpuller/region_state.go Co-authored-by: dongmen <20351731+asddongmen@users.noreply.github.com> --- logservice/logpuller/region_state.go | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/logservice/logpuller/region_state.go b/logservice/logpuller/region_state.go index 40e98bdb26..78806b59a0 100644 --- a/logservice/logpuller/region_state.go +++ b/logservice/logpuller/region_state.go @@ -47,7 +47,8 @@ type regionInfo struct { // Whether to filter out the value write by cdc itself. // It should be `true` in BDR mode filterLoop bool - // scanPriority is sent to TiKV/CSE so remote incremental scan admission can +// scanPriority is sent to TiKV/CSE. It informs the remote incremental scan admission logic +// to schedule TiCDC region requests by priority and maintain consistent ordering across retries. // preserve TiCDC's business priority across retries. scanPriority cdcpb.ScanPriority } From de79c1bb4c66f2f47be592bd390c0ca5099f951f Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Fri, 17 Jul 2026 14:33:39 +0800 Subject: [PATCH 19/21] logpuller: centralize scan priority policy --- logservice/logpuller/region_event_handler.go | 4 +- .../logpuller/region_event_handler_test.go | 7 +- logservice/logpuller/region_event_sink.go | 5 +- logservice/logpuller/scan_priority.go | 66 ++++++++ logservice/logpuller/scan_priority_test.go | 159 ++++++++++++++++++ logservice/logpuller/span_registry.go | 27 ++- logservice/logpuller/subscription_client.go | 51 +++--- .../logpuller/subscription_client_test.go | 149 ++-------------- pkg/config/debug.go | 9 +- 9 files changed, 291 insertions(+), 186 deletions(-) create mode 100644 logservice/logpuller/scan_priority.go create mode 100644 logservice/logpuller/scan_priority_test.go diff --git a/logservice/logpuller/region_event_handler.go b/logservice/logpuller/region_event_handler.go index bc4183f813..3f7a80aa71 100644 --- a/logservice/logpuller/region_event_handler.go +++ b/logservice/logpuller/region_event_handler.go @@ -21,7 +21,6 @@ import ( "github.com/pingcap/log" "github.com/pingcap/ticdc/pkg/common" "github.com/pingcap/ticdc/pkg/metrics" - "github.com/pingcap/ticdc/pkg/pdutil" "github.com/pingcap/ticdc/pkg/spanz" "github.com/pingcap/ticdc/pkg/util" "github.com/pingcap/ticdc/utils/dynstream" @@ -90,7 +89,6 @@ func (event regionEvent) mustFirstState() *regionFeedState { type regionEventHandler struct { eventSink *regionEventSink failureHandler *regionFailureHandler - pdClock pdutil.Clock } func (h *regionEventHandler) Path(event regionEvent) SubscriptionID { @@ -146,7 +144,7 @@ func (h *regionEventHandler) Handle(span *subscribedSpan, events ...regionEvent) } } if newResolvedTs > 0 { - span.maybeMarkCaughtUp(h.pdClock, newResolvedTs) + span.observeResolvedTs(newResolvedTs) } tryAdvanceResolvedTs := func() { if newResolvedTs != 0 { diff --git a/logservice/logpuller/region_event_handler_test.go b/logservice/logpuller/region_event_handler_test.go index 4ceaaa1221..8af61ce029 100644 --- a/logservice/logpuller/region_event_handler_test.go +++ b/logservice/logpuller/region_event_handler_test.go @@ -213,7 +213,7 @@ func TestHandleResolvedTs(t *testing.T) { option := dynstream.NewOption() pdClock := pdutil.NewClock4Test() pdClock.(*pdutil.Clock4Test).SetTS(10) - ds := dynstream.NewParallelDynamicStream("test", ®ionEventHandler{pdClock: pdClock}, option) + ds := dynstream.NewParallelDynamicStream("test", ®ionEventHandler{}, option) ds.Start() consumeKVEvents := func(events []common.RawKVEntry, _ func()) bool { return false } // not used @@ -242,6 +242,7 @@ func TestHandleResolvedTs(t *testing.T) { consumeKVEvents: consumeKVEvents, advanceResolvedTs: advanceResolvedTs, advanceInterval: 0, + priorityPolicy: newScanPriorityPolicy(pdClock, 30*time.Minute), } ds.AddPath(subID1, subSpan1, dynstream.AreaSettings{}) state1.region.subscribedSpan = subSpan1 @@ -269,6 +270,7 @@ func TestHandleResolvedTs(t *testing.T) { consumeKVEvents: consumeKVEvents, advanceResolvedTs: advanceResolvedTs, advanceInterval: 0, + priorityPolicy: newScanPriorityPolicy(pdClock, 30*time.Minute), } ds.AddPath(subID2, subSpan, dynstream.AreaSettings{}) state2.region.subscribedSpan = subSpan @@ -296,6 +298,7 @@ func TestHandleResolvedTs(t *testing.T) { consumeKVEvents: consumeKVEvents, advanceResolvedTs: advanceResolvedTs, advanceInterval: 0, + priorityPolicy: newScanPriorityPolicy(pdClock, 30*time.Minute), } ds.AddPath(subID3, subSpan, dynstream.AreaSettings{}) state3.region.subscribedSpan = subSpan @@ -347,7 +350,7 @@ func TestHandleResolvedTs(t *testing.T) { require.Equal(t, uint64(10), state1.getLastResolvedTs()) require.Equal(t, uint64(11), state2.getLastResolvedTs()) require.Equal(t, uint64(8), state3.getLastResolvedTs()) - require.True(t, subSpan1.everCaughtUp.Load()) + require.True(t, subSpan1.priorityPolicy.everCaughtUp.Load()) } func TestHandleResolvedTsThrottled(t *testing.T) { diff --git a/logservice/logpuller/region_event_sink.go b/logservice/logpuller/region_event_sink.go index ae32b52ca0..a89a0555bc 100644 --- a/logservice/logpuller/region_event_sink.go +++ b/logservice/logpuller/region_event_sink.go @@ -20,7 +20,6 @@ import ( "github.com/pingcap/log" "github.com/pingcap/ticdc/pkg/metrics" - "github.com/pingcap/ticdc/pkg/pdutil" "github.com/pingcap/ticdc/utils/dynstream" "go.uber.org/zap" ) @@ -39,7 +38,7 @@ type regionEventSink struct { ds dynstream.DynamicStream[int, SubscriptionID, regionEvent, *subscribedSpan, *regionEventHandler] } -func newRegionEventSink(failureHandler *regionFailureHandler, pdClock pdutil.Clock) *regionEventSink { +func newRegionEventSink(failureHandler *regionFailureHandler) *regionEventSink { sink := ®ionEventSink{} sink.cond = sync.NewCond(&sink.mu) @@ -52,7 +51,7 @@ func newRegionEventSink(failureHandler *regionFailureHandler, pdClock pdutil.Clo option.EnableMemoryControl = true ds := dynstream.NewParallelDynamicStream( "log-puller", - ®ionEventHandler{eventSink: sink, failureHandler: failureHandler, pdClock: pdClock}, + ®ionEventHandler{eventSink: sink, failureHandler: failureHandler}, option, ) ds.Start() diff --git a/logservice/logpuller/scan_priority.go b/logservice/logpuller/scan_priority.go new file mode 100644 index 0000000000..7f8480265a --- /dev/null +++ b/logservice/logpuller/scan_priority.go @@ -0,0 +1,66 @@ +// 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, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package logpuller + +import ( + "sync/atomic" + "time" + + "github.com/pingcap/ticdc/pkg/pdutil" + "github.com/tikv/client-go/v2/oracle" +) + +// scanPriorityPolicy owns the priority rules and sticky state for one subscribed span. +type scanPriorityPolicy struct { + pdClock pdutil.Clock + lagThreshold time.Duration + everCaughtUp atomic.Bool +} + +func newScanPriorityPolicy(pdClock pdutil.Clock, lagThreshold time.Duration) scanPriorityPolicy { + return scanPriorityPolicy{ + pdClock: pdClock, + lagThreshold: lagThreshold, + } +} + +// observeSpanResolved records when the whole span first catches up. The state is +// sticky so later recovery scans remain protected even if the span falls behind. +func (p *scanPriorityPolicy) observeSpanResolved(resolvedTs uint64) bool { + if p.everCaughtUp.Load() || !p.isTsClose(resolvedTs, p.pdClock.CurrentTime()) { + return false + } + return p.everCaughtUp.CompareAndSwap(false, true) +} + +// resolve returns the effective priority after combining inherited, span, and +// region progress. A high priority decision is never downgraded. +func (p *scanPriorityPolicy) resolve( + inherited TaskType, + regionResolvedTs uint64, + currentTime time.Time, +) TaskType { + if inherited == TaskHighPrior || p.everCaughtUp.Load() || p.isTsClose(regionResolvedTs, currentTime) { + return TaskHighPrior + } + return TaskLowPrior +} + +func (p *scanPriorityPolicy) isTsClose(ts uint64, currentTime time.Time) bool { + if ts == 0 { + return false + } + return currentTime.Sub(oracle.GetTimeFromTS(ts)) <= p.lagThreshold +} diff --git a/logservice/logpuller/scan_priority_test.go b/logservice/logpuller/scan_priority_test.go new file mode 100644 index 0000000000..d5501efcd2 --- /dev/null +++ b/logservice/logpuller/scan_priority_test.go @@ -0,0 +1,159 @@ +// 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, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package logpuller + +import ( + "context" + "testing" + "time" + + "github.com/pingcap/kvproto/pkg/cdcpb" + "github.com/pingcap/ticdc/heartbeatpb" + "github.com/pingcap/ticdc/logservice/logpuller/regionlock" + "github.com/pingcap/ticdc/pkg/pdutil" + "github.com/pingcap/ticdc/utils/priorityqueue" + "github.com/stretchr/testify/require" + "github.com/tikv/client-go/v2/oracle" + "github.com/tikv/client-go/v2/tikv" +) + +func TestScanPriorityPolicyResolve(t *testing.T) { + currentTime := time.Date(2026, time.June, 27, 12, 0, 0, 0, time.UTC) + pdClock := pdutil.NewClock4Test() + pdClock.(*pdutil.Clock4Test).SetTS(oracle.GoTimeToTS(currentTime)) + policy := newScanPriorityPolicy(pdClock, 30*time.Minute) + + for _, tc := range []struct { + name string + inherited TaskType + regionResolvedTs uint64 + expected TaskType + }{ + { + name: "zero resolved ts", + inherited: TaskLowPrior, + regionResolvedTs: 0, + expected: TaskLowPrior, + }, + { + name: "recent region", + inherited: TaskLowPrior, + regionResolvedTs: oracle.GoTimeToTS(currentTime.Add(-29 * time.Minute)), + expected: TaskHighPrior, + }, + { + name: "threshold boundary", + inherited: TaskLowPrior, + regionResolvedTs: oracle.GoTimeToTS(currentTime.Add(-30 * time.Minute)), + expected: TaskHighPrior, + }, + { + name: "old region", + inherited: TaskLowPrior, + regionResolvedTs: oracle.GoTimeToTS(currentTime.Add(-31 * time.Minute)), + expected: TaskLowPrior, + }, + { + name: "future region", + inherited: TaskLowPrior, + regionResolvedTs: oracle.GoTimeToTS(currentTime.Add(time.Minute)), + expected: TaskHighPrior, + }, + { + name: "inherited high", + inherited: TaskHighPrior, + regionResolvedTs: oracle.GoTimeToTS(currentTime.Add(-time.Hour)), + expected: TaskHighPrior, + }, + } { + t.Run(tc.name, func(t *testing.T) { + require.Equal(t, tc.expected, policy.resolve(tc.inherited, tc.regionResolvedTs, currentTime)) + }) + } +} + +func TestScanPriorityPolicyRemainsHighAfterCatchUp(t *testing.T) { + currentTime := time.Date(2026, time.June, 27, 12, 0, 0, 0, time.UTC) + pdClock := pdutil.NewClock4Test() + pdClock.(*pdutil.Clock4Test).SetTS(oracle.GoTimeToTS(currentTime)) + policy := newScanPriorityPolicy(pdClock, 30*time.Minute) + + require.False(t, policy.observeSpanResolved(oracle.GoTimeToTS(currentTime.Add(-31*time.Minute)))) + require.True(t, policy.observeSpanResolved(oracle.GoTimeToTS(currentTime.Add(-time.Minute)))) + require.False(t, policy.observeSpanResolved(oracle.GoTimeToTS(currentTime))) + require.Equal(t, TaskHighPrior, policy.resolve( + TaskLowPrior, + oracle.GoTimeToTS(currentTime.Add(-time.Hour)), + currentTime, + )) +} + +func TestScanPriorityUsesRestoredRegionProgress(t *testing.T) { + currentTime := time.Date(2026, time.June, 27, 12, 0, 0, 0, time.UTC) + currentTs := oracle.GoTimeToTS(currentTime) + pdClock := pdutil.NewClock4Test() + pdClock.(*pdutil.Clock4Test).SetTS(currentTs) + client := &subscriptionClient{ + pdClock: pdClock, + regionTaskQueue: priorityqueue.New[PriorityTask](), + } + + startTs := oracle.GoTimeToTS(currentTime.Add(-time.Hour)) + rawSpan := heartbeatpb.TableSpan{ + TableID: 1, + StartKey: []byte("a"), + EndKey: []byte("z"), + } + span := &subscribedSpan{ + subID: SubscriptionID(1), + span: rawSpan, + startTs: startTs, + rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, startTs), + priorityPolicy: newScanPriorityPolicy(pdClock, 30*time.Minute), + } + region := newRegionInfo(tikv.NewRegionVerID(1, 1, 1), rawSpan, nil, span, false) + + client.scheduleRegionRequest(context.Background(), region, TaskLowPrior) + firstTask := popRegionPriorityTask(t, client.regionTaskQueue) + require.Equal(t, TaskLowPrior, firstTask.taskType) + + firstRegion := firstTask.GetRegionInfo() + firstRegion.lockedRangeState.ResolvedTs.Store(oracle.GoTimeToTS(currentTime.Add(-time.Minute))) + span.rangeLock.UnlockRange( + firstRegion.span.StartKey, + firstRegion.span.EndKey, + firstRegion.verID.GetID(), + firstRegion.verID.GetVer(), + ) + + retryRegion := newRegionInfo(tikv.NewRegionVerID(1, 1, 2), rawSpan, nil, span, false) + client.scheduleRegionRequest(context.Background(), retryRegion, TaskLowPrior) + retryTask := popRegionPriorityTask(t, client.regionTaskQueue) + require.Equal(t, TaskHighPrior, retryTask.taskType) + require.Equal(t, cdcpb.ScanPriority_SCAN_PRIORITY_HIGH, retryTask.GetRegionInfo().scanPriority) + require.False(t, span.priorityPolicy.everCaughtUp.Load()) +} + +func popRegionPriorityTask( + t *testing.T, + queue *priorityqueue.PriorityQueue[PriorityTask], +) *regionPriorityTask { + t.Helper() + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + task, err := queue.Pop(ctx) + require.NoError(t, err) + return task.(*regionPriorityTask) +} diff --git a/logservice/logpuller/span_registry.go b/logservice/logpuller/span_registry.go index 5e1391a832..02b0d04bba 100644 --- a/logservice/logpuller/span_registry.go +++ b/logservice/logpuller/span_registry.go @@ -73,9 +73,7 @@ type subscribedSpan struct { initializationTracker spanInitializationTracker resolvedTsUpdated atomic.Int64 resolvedTs atomic.Uint64 - // everCaughtUp remains true once the subscription catches up, so recovery scans - // stay high priority even if a later failure temporarily increases the lag. - everCaughtUp atomic.Bool + priorityPolicy scanPriorityPolicy } // spanRegistry tracks subscribed spans and owns span-level background maintenance. @@ -98,6 +96,8 @@ func newSubscribedSpan( advanceResolvedTs func(ts uint64), advanceInterval int64, filterLoop bool, + pdClock pdutil.Clock, + priorityLagThreshold time.Duration, ) *subscribedSpan { rangeLock := regionlock.NewRangeLock(uint64(subID), span.StartKey, span.EndKey, startTs) @@ -111,6 +111,10 @@ func newSubscribedSpan( consumeKVEvents: consumeKVEvents, advanceResolvedTs: advanceResolvedTs, advanceInterval: advanceInterval, + priorityPolicy: scanPriorityPolicy{ + pdClock: pdClock, + lagThreshold: priorityLagThreshold, + }, } rt.initialized.Store(false) rt.resolvedTsUpdated.Store(time.Now().Unix()) @@ -143,22 +147,13 @@ func newSubscribedSpan( return rt } -func (span *subscribedSpan) maybeMarkCaughtUp(pdClock pdutil.Clock, resolvedTs uint64) { - if span.everCaughtUp.Load() || !isTsCloseToCurrent(pdClock, resolvedTs) { - return - } - if span.everCaughtUp.CompareAndSwap(false, true) { +func (span *subscribedSpan) observeResolvedTs(resolvedTs uint64) { + if span.priorityPolicy.observeSpanResolved(resolvedTs) { log.Info("subscription catches up for the first time", zap.Uint64("subscriptionID", uint64(span.subID)), - zap.Uint64("resolvedTs", resolvedTs)) - } -} - -func (span *subscribedSpan) effectiveScanTaskPriority(priority TaskType) TaskType { - if priority == TaskHighPrior || span.everCaughtUp.Load() { - return TaskHighPrior + zap.Uint64("resolvedTs", resolvedTs), + zap.Duration("threshold", span.priorityPolicy.lagThreshold)) } - return priority } func (span *subscribedSpan) clearKVEventsCache() { diff --git a/logservice/logpuller/subscription_client.go b/logservice/logpuller/subscription_client.go index dc70e18dc3..fc3a0725c3 100644 --- a/logservice/logpuller/subscription_client.go +++ b/logservice/logpuller/subscription_client.go @@ -182,7 +182,7 @@ func NewSubscriptionClient( } subClient.ctx, subClient.cancel = context.WithCancel(context.Background()) subClient.failureHandler = newRegionFailureHandler(subClient) - subClient.eventSink = newRegionEventSink(subClient.failureHandler, subClient.pdClock) + subClient.eventSink = newRegionEventSink(subClient.failureHandler) subClient.spanRegistry = newSpanRegistry(subClient.pd, subClient.pdClock) subClient.initMetrics() @@ -260,38 +260,23 @@ func (s *subscriptionClient) Subscribe( advanceResolvedTs, advanceInterval, bdrMode, + s.pdClock, + time.Duration(config.GetGlobalServerConfig().Debug.Puller.OldStartTsScanLowPriorityThreshold), ) s.spanRegistry.Add(rt) s.eventSink.AddPath(rt) - initialPriority := s.initialScanTaskPriority(startTs) select { case <-s.ctx.Done(): log.Warn("subscribes span failed, the subscription client has closed") - case s.rangeTaskCh <- rangeTask{span: span, subscribedSpan: rt, filterLoop: rt.filterLoop, priority: initialPriority}: + case s.rangeTaskCh <- rangeTask{span: span, subscribedSpan: rt, filterLoop: rt.filterLoop, priority: TaskLowPrior}: log.Info("subscribes span done", zap.Uint64("subscriptionID", uint64(subID)), zap.Int64("tableID", span.TableID), zap.Uint64("startTs", startTs), - zap.String("initialScanPriority", initialPriority.String()), zap.String("startKey", spanz.HexKey(span.StartKey)), zap.String("endKey", spanz.HexKey(span.EndKey))) } } -func (s *subscriptionClient) initialScanTaskPriority(startTs uint64) TaskType { - if isTsCloseToCurrent(s.pdClock, startTs) { - return TaskHighPrior - } - return TaskLowPrior -} - -func isTsCloseToCurrent(pdClock pdutil.Clock, ts uint64) bool { - if ts == 0 { - return false - } - threshold := time.Duration(config.GetGlobalServerConfig().Debug.Puller.OldStartTsScanLowPriorityThreshold) - return pdClock.CurrentTime().Sub(oracle.GetTimeFromTS(ts)) <= threshold -} - // Unsubscribe the given table span. All covered regions will be deregistered asynchronously. // NOTE: `span.TableID` must be set correctly. func (s *subscriptionClient) Unsubscribe(subID SubscriptionID) { @@ -651,9 +636,11 @@ func (s *subscriptionClient) divideSpanAndScheduleRegionRequests( // scheduleRegionRequest locks the region's range and send the region to regionTaskQueue, // which will be handled by handleRegions. -func (s *subscriptionClient) scheduleRegionRequest(ctx context.Context, region regionInfo, priority TaskType) { - priority = region.subscribedSpan.effectiveScanTaskPriority(priority) - region.scanPriority = priority.scanPriority() +func (s *subscriptionClient) scheduleRegionRequest( + ctx context.Context, + region regionInfo, + inheritedPriority TaskType, +) { lockRangeResult := region.subscribedSpan.rangeLock.LockRange( ctx, region.span.StartKey, region.span.EndKey, region.verID.GetID(), region.verID.GetVer()) @@ -664,7 +651,14 @@ func (s *subscriptionClient) scheduleRegionRequest(ctx context.Context, region r switch lockRangeResult.Status { case regionlock.LockRangeStatusSuccess: region.lockedRangeState = lockRangeResult.LockedRangeState - s.regionTaskQueue.Push(NewRegionPriorityTask(priority, region, s.pdClock.CurrentTS())) + currentTs := s.pdClock.CurrentTS() + priority := region.subscribedSpan.priorityPolicy.resolve( + inheritedPriority, + region.resolvedTs(), + oracle.GetTimeFromTS(currentTs), + ) + region.scanPriority = priority.scanPriority() + s.regionTaskQueue.Push(NewRegionPriorityTask(priority, region, currentTs)) if log.GetLevel() <= zapcore.DebugLevel { log.Debug("cdc region scan task enqueued", zap.Uint64("subscriptionID", uint64(region.subscribedSpan.subID)), @@ -679,7 +673,7 @@ func (s *subscriptionClient) scheduleRegionRequest(ctx context.Context, region r } case regionlock.LockRangeStatusStale: for _, r := range lockRangeResult.RetryRanges { - s.scheduleRangeRequest(ctx, r, region.subscribedSpan, region.filterLoop, priority) + s.scheduleRangeRequest(ctx, r, region.subscribedSpan, region.filterLoop, inheritedPriority) } default: return @@ -690,11 +684,16 @@ func (s *subscriptionClient) scheduleRangeRequest( ctx context.Context, span heartbeatpb.TableSpan, subscribedSpan *subscribedSpan, filterLoop bool, - priority TaskType, + inheritedPriority TaskType, ) { select { case <-ctx.Done(): - case s.rangeTaskCh <- rangeTask{span: span, subscribedSpan: subscribedSpan, filterLoop: filterLoop, priority: priority}: + case s.rangeTaskCh <- rangeTask{ + span: span, + subscribedSpan: subscribedSpan, + filterLoop: filterLoop, + priority: inheritedPriority, + }: } } diff --git a/logservice/logpuller/subscription_client_test.go b/logservice/logpuller/subscription_client_test.go index 787ef9bf54..18ce5cc75f 100644 --- a/logservice/logpuller/subscription_client_test.go +++ b/logservice/logpuller/subscription_client_test.go @@ -27,7 +27,6 @@ import ( "github.com/pingcap/ticdc/logservice/logpuller/regionlock" "github.com/pingcap/ticdc/pkg/common" appcontext "github.com/pingcap/ticdc/pkg/common/context" - "github.com/pingcap/ticdc/pkg/config" "github.com/pingcap/ticdc/pkg/metrics" "github.com/pingcap/ticdc/pkg/pdutil" "github.com/pingcap/ticdc/pkg/security" @@ -81,6 +80,8 @@ func TestGenerateResolveLockTask(t *testing.T) { advanceResolvedTs, 0, false, + pdutil.NewClock4Test(), + 30*time.Minute, ) client.spanRegistry.Add(span) @@ -157,12 +158,12 @@ func TestResolveLockTaskDeduplicatedAcrossSubscribedSpans(t *testing.T) { TableID: 1, StartKey: []byte{'a'}, EndKey: []byte{'z'}, - }, 100, consumeKVEvents, advanceResolvedTs, 0, false) + }, 100, consumeKVEvents, advanceResolvedTs, 0, false, pdutil.NewClock4Test(), 30*time.Minute) span2 := newSubscribedSpan(client.ctx, client.resolveLockRateLimiter, client.resolveLockTaskCh, SubscriptionID(2), heartbeatpb.TableSpan{ TableID: 2, StartKey: []byte{'a'}, EndKey: []byte{'z'}, - }, 100, consumeKVEvents, advanceResolvedTs, 0, false) + }, 100, consumeKVEvents, advanceResolvedTs, 0, false, pdutil.NewClock4Test(), 30*time.Minute) res := span1.rangeLock.LockRange(context.Background(), []byte{'b'}, []byte{'c'}, 1, 100) require.Equal(t, regionlock.LockRangeStatusSuccess, res.Status) @@ -275,6 +276,8 @@ func TestResolveLockTaskDroppedWhenChannelFull(t *testing.T) { advanceResolvedTs, 0, false, + pdutil.NewClock4Test(), + 30*time.Minute, ) res := span.rangeLock.LockRange(context.Background(), []byte{'b'}, []byte{'c'}, 1, 100) @@ -334,6 +337,8 @@ func TestStopTaskUsesSubscribedSpanFilterLoop(t *testing.T) { advanceResolvedTs, 0, true, + pdutil.NewClock4Test(), + 30*time.Minute, ) res := span.rangeLock.LockRange(context.Background(), rawSpan.StartKey, rawSpan.EndKey, 1, 1) @@ -452,9 +457,10 @@ func TestRegionRetryScanPriority(t *testing.T) { regionTaskQueue: priorityqueue.New[PriorityTask](), } client.pdClock = pdutil.NewClock4Test() + client.pdClock.(*pdutil.Clock4Test).SetTS(oracle.GoTimeToTS(time.Now())) client.failureHandler = newRegionFailureHandler(client) _, span := newScanPriorityTestSpan() - span.everCaughtUp.Store(tc.everCaughtUp) + span.priorityPolicy.everCaughtUp.Store(tc.everCaughtUp) region := newScanPriorityTestRegion(span) region.scanPriority = tc.priority @@ -568,121 +574,6 @@ func (s *mockDynamicStream) GetMetrics() dynstream.Metrics[int, SubscriptionID] return dynstream.Metrics[int, SubscriptionID]{} } -func TestInitialScanTaskPriority(t *testing.T) { - setInitialScanLowPriorityThresholdForTest(t, 30*time.Minute) - - currentTime := time.Date(2026, time.June, 27, 12, 0, 0, 0, time.UTC) - pdClock := pdutil.NewClock4Test() - pdClock.(*pdutil.Clock4Test).SetTS(oracle.GoTimeToTS(currentTime)) - client := &subscriptionClient{ - pdClock: pdClock, - } - - for _, tc := range []struct { - name string - startTs uint64 - expected TaskType - }{ - { - name: "zero start ts", - startTs: 0, - expected: TaskLowPrior, - }, - { - name: "recent start ts", - startTs: oracle.GoTimeToTS(currentTime.Add(-29 * time.Minute)), - expected: TaskHighPrior, - }, - { - name: "threshold boundary", - startTs: oracle.GoTimeToTS(currentTime.Add(-30 * time.Minute)), - expected: TaskHighPrior, - }, - { - name: "old start ts", - startTs: oracle.GoTimeToTS(currentTime.Add(-31 * time.Minute)), - expected: TaskLowPrior, - }, - { - name: "future start ts", - startTs: oracle.GoTimeToTS(currentTime.Add(time.Minute)), - expected: TaskHighPrior, - }, - } { - t.Run(tc.name, func(t *testing.T) { - require.Equal(t, tc.expected, client.initialScanTaskPriority(tc.startTs)) - }) - } -} - -func TestSubscribeUsesInitialScanTaskPriority(t *testing.T) { - setInitialScanLowPriorityThresholdForTest(t, 30*time.Minute) - - ctx := t.Context() - - currentTime := time.Date(2026, time.June, 27, 12, 0, 0, 0, time.UTC) - pdClock := pdutil.NewClock4Test() - pdClock.(*pdutil.Clock4Test).SetTS(oracle.GoTimeToTS(currentTime)) - sink := ®ionEventSink{ - ds: &mockDynamicStream{}, - } - sink.cond = sync.NewCond(&sink.mu) - client := &subscriptionClient{ - ctx: ctx, - eventSink: sink, - rangeTaskCh: make(chan rangeTask, 2), - pdClock: pdClock, - resolveLockTaskCh: make(chan resolveLockTask, 1), - resolveLockRateLimiter: newResolveLockRateLimiter(), - } - client.spanRegistry = newSpanRegistry(nil, pdClock) - - span := heartbeatpb.TableSpan{TableID: 1, StartKey: []byte("a"), EndKey: []byte("z")} - consumeKVEvents := func(_ []common.RawKVEntry, _ func()) bool { return false } - advanceResolvedTs := func(uint64) {} - - client.Subscribe( - SubscriptionID(1), - span, - oracle.GoTimeToTS(currentTime.Add(-time.Minute)), - consumeKVEvents, - advanceResolvedTs, - 0, - false, - ) - client.Subscribe( - SubscriptionID(2), - span, - oracle.GoTimeToTS(currentTime.Add(-31*time.Minute)), - consumeKVEvents, - advanceResolvedTs, - 0, - false, - ) - - require.Equal(t, TaskHighPrior, (<-client.rangeTaskCh).priority) - require.Equal(t, TaskLowPrior, (<-client.rangeTaskCh).priority) -} - -func TestSubscribedSpanMarksCaughtUp(t *testing.T) { - setInitialScanLowPriorityThresholdForTest(t, 30*time.Minute) - - currentTime := time.Date(2026, time.June, 27, 12, 0, 0, 0, time.UTC) - pdClock := pdutil.NewClock4Test() - pdClock.(*pdutil.Clock4Test).SetTS(oracle.GoTimeToTS(currentTime)) - _, span := newScanPriorityTestSpan() - - oldResolvedTs := oracle.GoTimeToTS(currentTime.Add(-31 * time.Minute)) - span.maybeMarkCaughtUp(pdClock, oldResolvedTs) - require.False(t, span.everCaughtUp.Load()) - - span.maybeMarkCaughtUp(pdClock, oracle.GoTimeToTS(currentTime.Add(-time.Minute))) - require.True(t, span.everCaughtUp.Load()) - - span.maybeMarkCaughtUp(pdClock, oldResolvedTs) - require.True(t, span.everCaughtUp.Load()) -} - func newScanPriorityTestSpan() (heartbeatpb.TableSpan, *subscribedSpan) { rawSpan := heartbeatpb.TableSpan{ TableID: 1, @@ -690,9 +581,10 @@ func newScanPriorityTestSpan() (heartbeatpb.TableSpan, *subscribedSpan) { EndKey: []byte("z"), } span := &subscribedSpan{ - subID: SubscriptionID(1), - span: rawSpan, - rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), + subID: SubscriptionID(1), + span: rawSpan, + rangeLock: regionlock.NewRangeLock(1, rawSpan.StartKey, rawSpan.EndKey, 100), + priorityPolicy: newTestScanPriorityPolicy(), } return rawSpan, span } @@ -701,15 +593,8 @@ func newScanPriorityTestRegion(span *subscribedSpan) regionInfo { return newRegionInfo(tikv.NewRegionVerID(1, 1, 1), span.span, nil, span, false) } -func setInitialScanLowPriorityThresholdForTest(t *testing.T, threshold time.Duration) { - t.Helper() - oldConfig := config.GetGlobalServerConfig() - testConfig := oldConfig.Clone() - testConfig.Debug.Puller.OldStartTsScanLowPriorityThreshold = config.TomlDuration(threshold) - config.StoreGlobalServerConfig(testConfig) - t.Cleanup(func() { - config.StoreGlobalServerConfig(oldConfig) - }) +func newTestScanPriorityPolicy() scanPriorityPolicy { + return newScanPriorityPolicy(pdutil.NewClock4Test(), 30*time.Minute) } func TestPushRegionEventToDSUnblocksOnClose(t *testing.T) { @@ -894,7 +779,7 @@ func TestGetResolvedTargetTs(t *testing.T) { TableID: 1, StartKey: []byte{'a'}, EndKey: []byte{'z'}, - }, 100, consumeKVEvents, advanceResolvedTs, 0, false) + }, 100, consumeKVEvents, advanceResolvedTs, 0, false, pdutil.NewClock4Test(), 30*time.Minute) span.initialized.Store(true) // Replicate the getResolvedTargetTs closure from runResolveLockChecker diff --git a/pkg/config/debug.go b/pkg/config/debug.go index 5dd8b56a22..11cdef9465 100644 --- a/pkg/config/debug.go +++ b/pkg/config/debug.go @@ -20,8 +20,8 @@ import ( ) const ( - // DefaultOldStartTsScanLowPriorityThreshold is the default age threshold for - // classifying initial scan tasks as low priority. + // DefaultOldStartTsScanLowPriorityThreshold is the default lag threshold for + // classifying scan tasks as low priority. DefaultOldStartTsScanLowPriorityThreshold = 30 * time.Minute ) @@ -74,8 +74,9 @@ type PullerConfig struct { // For example, if PendingRegionRequestQueueSize is 32 and there are 8 workers connecting to the same store, // each worker's queue size will be 32 / 8 = 4. PendingRegionRequestQueueSize int `toml:"pending-region-request-queue-size" json:"pending_region_request_queue_size"` - // OldStartTsScanLowPriorityThreshold is the startTs age threshold for initial scans. - // Initial scans older than this threshold are scheduled as low priority. + // OldStartTsScanLowPriorityThreshold is the lag threshold for scan priority. + // Scans within this threshold are scheduled as high priority. Older scans + // remain low priority until their span catches up once. OldStartTsScanLowPriorityThreshold TomlDuration `toml:"old-start-ts-scan-low-priority-threshold" json:"old_start_ts_scan_low_priority_threshold"` } From 5303b4520d8a41810826f17c8e7220ba84fccf57 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Fri, 17 Jul 2026 15:03:20 +0800 Subject: [PATCH 20/21] logpuller: clean up scan priority comment --- logservice/logpuller/region_state.go | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/logservice/logpuller/region_state.go b/logservice/logpuller/region_state.go index 160bbe53c2..40e98bdb26 100644 --- a/logservice/logpuller/region_state.go +++ b/logservice/logpuller/region_state.go @@ -47,8 +47,7 @@ type regionInfo struct { // Whether to filter out the value write by cdc itself. // It should be `true` in BDR mode filterLoop bool - // scanPriority is sent to TiKV/CSE. It informs the remote incremental scan admission logic - // to schedule TiCDC region requests by priority and maintain consistent ordering across retries. + // scanPriority is sent to TiKV/CSE so remote incremental scan admission can // preserve TiCDC's business priority across retries. scanPriority cdcpb.ScanPriority } From 0bfb0253dab2a9ddf9debb28c1ecf86db1f69e6b Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Fri, 17 Jul 2026 16:35:04 +0800 Subject: [PATCH 21/21] logpuller: record scan priority with resolved ts --- logservice/logpuller/region_event_handler.go | 6 +----- logservice/logpuller/region_event_handler_test.go | 10 ++++++---- logservice/logpuller/span_registry.go | 5 ++++- 3 files changed, 11 insertions(+), 10 deletions(-) diff --git a/logservice/logpuller/region_event_handler.go b/logservice/logpuller/region_event_handler.go index 3f7a80aa71..0973b1df15 100644 --- a/logservice/logpuller/region_event_handler.go +++ b/logservice/logpuller/region_event_handler.go @@ -143,9 +143,6 @@ func (h *regionEventHandler) Handle(span *subscribedSpan, events ...regionEvent) log.Panic("should not reach", zap.Any("event", event), zap.Any("events", events)) } } - if newResolvedTs > 0 { - span.observeResolvedTs(newResolvedTs) - } tryAdvanceResolvedTs := func() { if newResolvedTs != 0 { span.advanceResolvedTs(newResolvedTs) @@ -425,8 +422,7 @@ func handleResolvedTs(span *subscribedSpan, state *regionFeedState, resolvedTs u zap.Uint64("lastResolvedTs", lastResolvedTs), zap.Float64("decreaseLag(s)", decreaseLag)) } - span.resolvedTs.Store(ts) - span.resolvedTsUpdated.Store(time.Now().Unix()) + span.recordResolvedTs(ts) return ts } } diff --git a/logservice/logpuller/region_event_handler_test.go b/logservice/logpuller/region_event_handler_test.go index 8af61ce029..3a5b250cef 100644 --- a/logservice/logpuller/region_event_handler_test.go +++ b/logservice/logpuller/region_event_handler_test.go @@ -380,6 +380,7 @@ func TestHandleResolvedTsThrottled(t *testing.T) { subID: SubscriptionID(1), rangeLock: l, advanceInterval: 100, + priorityPolicy: newScanPriorityPolicy(pdutil.NewClock4Test(), 30*time.Minute), } span.lastAdvanceTime.Store(0) state := newRegionFeedState( @@ -405,10 +406,11 @@ func TestSpanInitializedAfterAllRangesInitialized(t *testing.T) { require.Equal(t, regionlock.LockRangeStatusSuccess, secondLock.Status) span := &subscribedSpan{ - subID: SubscriptionID(1), - startTs: 100, - span: heartbeatpb.TableSpan{StartKey: []byte("a"), EndKey: []byte("z")}, - rangeLock: rangeLock, + subID: SubscriptionID(1), + startTs: 100, + span: heartbeatpb.TableSpan{StartKey: []byte("a"), EndKey: []byte("z")}, + rangeLock: rangeLock, + priorityPolicy: newScanPriorityPolicy(pdutil.NewClock4Test(), 30*time.Minute), } span.resolvedTs.Store(span.startTs) worker := ®ionRequestWorker{requestCache: newRequestCache(2)} diff --git a/logservice/logpuller/span_registry.go b/logservice/logpuller/span_registry.go index 02b0d04bba..797e42d833 100644 --- a/logservice/logpuller/span_registry.go +++ b/logservice/logpuller/span_registry.go @@ -147,7 +147,10 @@ func newSubscribedSpan( return rt } -func (span *subscribedSpan) observeResolvedTs(resolvedTs uint64) { +// recordResolvedTs updates span progress and its priority policy together. +func (span *subscribedSpan) recordResolvedTs(resolvedTs uint64) { + span.resolvedTs.Store(resolvedTs) + span.resolvedTsUpdated.Store(time.Now().Unix()) if span.priorityPolicy.observeSpanResolved(resolvedTs) { log.Info("subscription catches up for the first time", zap.Uint64("subscriptionID", uint64(span.subID)),