table not loaded after all nodes bootstrapped
Open
Nobody has claimed this yet.
type/bug
- Dominant language
- Go
- Stars
- 56
- Forks
- 63
- Avg merge
- 2d 20h
- Merged PRs (30d)
- 34
Description
What did you do?
start a changefeed
What did you expect to see?
the dispatcher load immediately
What did you see instead?
Resume 2 changefeeds at the same time, one changefeed load tables immediately, another changefeeds load tables around 15 minutes later.
2025-11-25 15:16:55.052info[2025/11/25 07:16:55.051 +00:00] [INFO] [changefeed_db.go:267] ["move a changefeed to scheduling queue, it will be scheduled later"] [changefeed=aqua/kafka-test] [checkpointTs=462416825662833076] [overwriteCheckpointTs=false] [nextScheduleTime=0001/01/01 00:00:00.000 +00:00]
2025-11-25 15:16:55.227info[2025/11/25 07:16:55.227 +00:00] [INFO] [operator_controller.go:277] ["add operator to running queue"] [role=coordinator] [operator="add maintainer operator: aqua/kafka-test, dest:194f8274-b162-4f77-b50d-c1725a2aa45b"]
2025-11-25 15:16:55.227info[2025/11/25 07:16:55.227 +00:00] [INFO] [changefeed_db.go:197] ["bind changefeed to node"] [changefeed=aqua/kafka-test] [oldNode=] [node=194f8274-b162-4f77-b50d-c1725a2aa45b]
2025-11-25 15:16:55.227info[2025/11/25 07:16:55.227 +00:00] [INFO] [replication_group.go:136] ["scheduler: bind replica to node"] [schedulerID=coordinator-435986] [group=default] [replica=aqua/kafka-test] [oldNode=] [node=194f8274-b162-4f77-b50d-c1725a2aa45b]
2025-11-25 15:16:55.296info[2025/11/25 07:16:55.296 +00:00] [INFO] [operator_controller.go:90] ["send command to maintainer"] [role=coordinator] [operator="add maintainer operator: aqua/kafka-test, dest:194f8274-b162-4f77-b50d-c1725a2aa45b"]
2025-11-25 15:16:55.297info[2025/11/25 07:16:55.297 +00:00] [INFO] [replication_span.go:90] ["new working span replication created"] [keyspaceID=1] [changefeedID=kafka-test] [id=585638751957086401214657789405386685618] [nodeID=194f8274-b162-4f77-b50d-c1725a2aa45b] [checkpointTs=462416825662833076] [componentStatus=Working] [schemaID=0] [keyspaceID=1] [tableID=0] [groupID=0] [start=7800000174800000ff00000000005f7200fe] [end=7800000174800000ff00000000005f7300fe]
2025-11-25 15:16:55.297info[2025/11/25 07:16:55.297 +00:00] [INFO] [maintainer.go:253] ["changefeed maintainer is created"] [id=aqua/kafka-test] [state=normal] [checkpointTs=462416825662833076] [ddlDispatcherID=585638751957086401214657789405386685618] [redoTs="changefeedID:<high:14049700043824605829 low:14720730946243377716 name:\"kafka-test\" keyspace:\"aqua\" > resolvedTs:462416825662833076 checkpointTs:462416825662833076 "] [newChangefeed=false]
2025-11-25 15:16:55.297info[2025/11/25 07:16:55.297 +00:00] [INFO] [maintainer.go:372] ["start to initialize changefeed maintainer"] [changefeed=aqua/kafka-test]
2025-11-25 15:16:55.297info[2025/11/25 07:16:55.297 +00:00] [INFO] [maintainer.go:388] ["changefeed bootstrap initial nodes"] [selfNodeID=194f8274-b162-4f77-b50d-c1725a2aa45b] [changefeedID=aqua/kafka-test] [nodeCount=3]
2025-11-25 15:16:55.297info[2025/11/25 07:16:55.297 +00:00] [INFO] [bootstrap.go:71] ["find a new node"] [changefeed=kafka-test] [nodeAddr=cdc-test-ticdc-bloedw.cdc-test-ticdc-peer.default:8300] [nodeID=194f8274-b162-4f77-b50d-c1725a2aa45b]
2025-11-25 15:16:55.297info[2025/11/25 07:16:55.297 +00:00] [INFO] [maintainer.go:1051] ["create table event trigger dispatcher bootstrap message"] [changefeed=aqua/kafka-test] [server=194f8274-b162-4f77-b50d-c1725a2aa45b] [dispatcherID=585638751957086401214657789405386685618] [startTs=462416825662833076]
2025-11-25 15:16:55.297info[2025/11/25 07:16:55.297 +00:00] [INFO] [maintainer.go:1064] ["New maintainer bootstrap message to dispatcher manager"] [changefeed=aqua/kafka-test] [server=194f8274-b162-4f77-b50d-c1725a2aa45b] [startTs=462416825662833076]
2025-11-25 15:16:55.297info[2025/11/25 07:16:55.297 +00:00] [INFO] [bootstrap.go:71] ["find a new node"] [changefeed=kafka-test] [nodeAddr=cdc-test-ticdc-uahygj.cdc-test-ticdc-peer.default:8300] [nodeID=6205e757-ca3e-41f8-83c5-34f239403ecc]
2025-11-25 15:16:55.297info[2025/11/25 07:16:55.297 +00:00] [INFO] [maintainer.go:1064] ["New maintainer bootstrap message to dispatcher manager"] [changefeed=aqua/kafka-test] [server=6205e757-ca3e-41f8-83c5-34f239403ecc] [startTs=462416825662833076]
2025-11-25 15:16:55.297info[2025/11/25 07:16:55.297 +00:00] [INFO] [bootstrap.go:71] ["find a new node"] [changefeed=kafka-test] [nodeAddr=cdc-test-ticdc-8zt7w5.cdc-test-ticdc-peer.default:8300] [nodeID=6c99009f-ad6b-4245-a036-f8e29df4c7c7]
2025-11-25 15:16:55.297info[2025/11/25 07:16:55.297 +00:00] [INFO] [maintainer.go:1064] ["New maintainer bootstrap message to dispatcher manager"] [changefeed=aqua/kafka-test] [server=6c99009f-ad6b-4245-a036-f8e29df4c7c7] [startTs=462416825662833076]
2025-11-25 15:16:55.298info[2025/11/25 07:16:55.298 +00:00] [INFO] [maintainer.go:399] ["changefeed maintainer initialized"]...
2025-11-25 15:16:55.302info[2025/11/25 07:16:55.302 +00:00] [INFO] [operator_add.go:59] ["maintainer report working status"] [changefeed=aqua/kafka-test]
2025-11-25 15:16:55.319info[2025/11/25 07:16:55.319 +00:00] [INFO] [dispatcher_manager.go:293] ["event dispatcher manager created"] [changefeedID=aqua/kafka-test] [maintainerID=194f8274-b162-4f77-b50d-c1725a2aa45b] [startTs=462416825662833076] [tableTriggerStartTs=0] [sinkQuota=1073741824] [redoQuota=0] [redoEnable=false] [outputRawChangeEvent=false]
2025-11-25 15:16:55.320info[2025/11/25 07:16:55.320 +00:00] [INFO] [maintainer.go:822] ["received maintainer bootstrap response"] [changefeed=kafka-test] [sourceNodeID=6205e757-ca3e-41f8-83c5-34f239403ecc]
2025-11-25 15:16:55.325info[2025/11/25 07:16:55.325 +00:00] [INFO] [dispatcher_manager.go:472] ["new dispatcher created"] [changefeedID=aqua/kafka-test] [dispatcherID=585638751957086401214657789405386685618] [tableSpan="tableID: 0, startKey: 7800000174800000ff00000000005f7200fe, endKey: 7800000174800000ff00000000005f7300fe, keyspaceID: 1\n"] [startTs=462416825662833076]
2025-11-25 15:16:55.325info[2025/11/25 07:16:55.325 +00:00] [INFO] [dispatcher_manager.go:479] ["batch create new dispatchers"] [changefeedID=aqua/kafka-test] [count=1] [duration=32.225µs]
2025-11-25 15:16:55.325info[2025/11/25 07:16:55.325 +00:00] [INFO] [dispatcher_manager.go:322] ["table trigger event dispatcher created"] [changefeedID=aqua/kafka-test] [dispatcherID=585638751957086401214657789405386685618] [startTs=462416825662833076]
2025-11-25 15:16:55.325info[2025/11/25 07:16:55.325 +00:00] [INFO] [dispatcher_manager.go:293] ["event dispatcher manager created"] [changefeedID=aqua/kafka-test] [maintainerID=194f8274-b162-4f77-b50d-c1725a2aa45b] [startTs=462416825662833076] [tableTriggerStartTs=462416825662833076] [sinkQuota=1073741824] [redoQuota=0] [redoEnable=false] [outputRawChangeEvent=false]
2025-11-25 15:16:55.325info[2025/11/25 07:16:55.325 +00:00] [INFO] [maintainer.go:822] ["received maintainer bootstrap response"] [changefeed=kafka-test] [sourceNodeID=194f8274-b162-4f77-b50d-c1725a2aa45b]
2025-11-25 15:16:55.334info[2025/11/25 07:16:55.334 +00:00] [INFO] [dispatcher_manager.go:293] ["event dispatcher manager created"] [changefeedID=aqua/kafka-test] [maintainerID=194f8274-b162-4f77-b50d-c1725a2aa45b] [startTs=462416825662833076] [tableTriggerStartTs=0] [sinkQuota=1073741824] [redoQuota=0] [redoEnable=false] [outputRawChangeEvent=false]
2025-11-25 15:16:55.334info[2025/11/25 07:16:55.334 +00:00] [INFO] [maintainer.go:822] ["received maintainer bootstrap response"] [changefeed=kafka-test] [sourceNodeID=6c99009f-ad6b-4245-a036-f8e29df4c7c7]
2025-11-25 15:16:55.334info[2025/11/25 07:16:55.334 +00:00] [INFO] [maintainer_controller_bootstrap.go:83] ["all nodes have sent bootstrap response, start to handle them"] [changefeed=aqua/kafka-test] [nodeCount=3]
2025-11-25 15:16:55.334info[2025/11/25 07:16:55.334 +00:00] [INFO] [maintainer_controller_bootstrap.go:127] ["handle bootstrap response"] [changefeed=aqua/kafka-test] [nodeID=194f8274-b162-4f77-b50d-c1725a2aa45b] [checkpointTs=462416825662833076] [spanCount=1]
2025-11-25 15:16:55.334info[2025/11/25 07:16:55.334 +00:00] [INFO] [maintainer_controller_bootstrap.go:127] ["handle bootstrap response"] [changefeed=aqua/kafka-test] [nodeID=6205e757-ca3e-41f8-83c5-34f239403ecc] [checkpointTs=0] [spanCount=0]
2025-11-25 15:16:55.334info[2025/11/25 07:16:55.334 +00:00] [INFO] [maintainer_controller_bootstrap.go:127] ["handle bootstrap response"] [changefeed=aqua/kafka-test] [nodeID=6c99009f-ad6b-4245-a036-f8e29df4c7c7] [checkpointTs=0] [spanCount=0]
2025-11-25 15:16:55.398warn[2025/11/25 07:16:55.398 +00:00] [WARN] [maintainer.go:619] ["can not advance checkpointTs since not bootstrapped"] [changefeed=kafka-test] [checkpointTs=462416825662833076] [resolvedTs=462416825662833076]
2025-11-25 15:16:55.496info[2025/11/25 07:16:55.496 +00:00] [INFO] [changefeed_db.go:209] ["marking changefeed replicating"] [changefeed=aqua/kafka-test]
2025-11-25 15:16:55.497info[2025/11/25 07:16:55.496 +00:00] [INFO] [replication_group.go:110] ["scheduler: marking replica replicating"] [schedulerID=coordinator-435986] [group=default] [replica=aqua/kafka-test]
2025-11-25 15:16:55.497info[2025/11/25 07:16:55.496 +00:00] [INFO] [operator_controller.go:257] ["operator finished"] [role=coordinator] [operator=aqua/kafka-test] [operator="add maintainer operator: aqua/kafka-test, dest:194f8274-b162-4f77-b50d-c1725a2aa45b"]
2025-11-25 15:16:55.498warn[2025/11/25 07:16:55.498 +00:00] [WARN] [maintainer.go:619] ["can not advance checkpointTs since not bootstrapped"] [changefeed=kafka-test] [checkpointTs=462416825662833076] [resolvedTs=462416825662833076]
2025-11-25 15:16:55.598warn[2025/11/25 07:16:55.598 +00:00] [WARN] [maintainer.go:619] ["can not advance checkpointTs since not bootstrapped"] [changefeed=kafka-test] [checkpointTs=462416825662833076] [resolvedTs=462416825662833076]
2025-11-25 15:16:55.697warn[2025/11/25 07:16:55.697 +00:00] [WARN] [maintainer.go:619] ["can not advance checkpointTs since not bootstrapped"] [changefeed=kafka-test] [checkpointTs=462416825662833076] [resolvedTs=462416825662833076]
...
2025-11-25 15:25:30.630info[2025/11/25 07:25:30.630 +00:00] [INFO] [region_count_splitter.go:83] ["skip split span because region count is less than region threshold or region threshold is 0"] [changefeed=kafka-test] [span="TableID:3808 StartKey:\"x\\000\\000\\001t\\200\\000\\000\\377\\000\\000\\000\\016\\340_r\\000\\376\" EndKey:\"x\\000\\000\\001t\\200\\000\\000\\377\\000\\000\\000\\016\\340_s\\000\\376\" KeyspaceID:1 "] [regionCount=1] [regionThreshold=1000]
2025-11-25 15:25:30.630info[2025/11/25 07:25:30.630 +00:00] [INFO] [replication_span.go:65] ["new span replication created"] [keyspaceID=1] [changefeedID=kafka-test] [id=43428046065463378077654748621050933632] [schemaID=5] [tableID=3808] [groupID=default] [checkpointTs=462416825662833076] [start=7800000174800000ff0000000ee05f7200fe] [end=7800000174800000ff0000000ee05f7300fe]
Versions of the cluster
Upstream TiDB cluster version (execute SELECT tidb_version(); in a MySQL client):
(paste TiDB cluster version here)
Upstream TiKV version (execute tikv-server --version):
(paste TiKV version here)
TiCDC version (execute cdc version):
(paste TiCDC version here)
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start with the bootstrap flow in maintainer_controller_bootstrap.go and maintainer.go, then follow the dispatcher creation logs in dispatcher_manager.go. Reproduce two changefeeds being resumed together and compare the bootstrap responses, checkpoint warnings, and delayed span creation. Done means both changefeeds load their tables without the reported delay, with regression coverage if an existing test area applies.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go
- Domain
- backend, distributed-systems
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 32/100