tidb cdc 任务的 state 正常，但是没能正常往 kafka 插入数据

🪐 TiDB 技术问题 备份&数据迁移
1

背景： tiup version 5.3.0

使用 tidb cdc 时遇到这么一个问题： cdc 任务的 state 正常，但是没能往kafka 中插入数据

2022-09-23%2016-46-23%E5%B1%8F%E5%B9%95%E6%88%AA%E5%9B%BE
2022-09-23%2016-46-23%E5%B1%8F%E5%B9%95%E6%88%AA%E5%9B%BE1028×773 57.1 KB

可以看到 checkpoint 的时间停留在 12：49 ,且 cdc task 不能将数据插入到 kafka 中，当受监控的表数据变更时，topic 中没有相应的数据。 往常 checkpoint 的时间也不会事实更新，但不影响 cdc task 的正常工作。

据同事描述，他今天早上做了一个数据库删除的操作，他怀疑与该操作有关。

另外，今天其中一个受监听的数据库插入了 1000万 左右的数据，不知道跟这个数据量有没有关系。

cdc 日志中发现一下 Error

[2022/09/23 09:57:32.339 +08:00] [ERROR] [feed_state_manager.go:253] ["processor report an error"] [changefeedID=prod-da-sm] [captureID=c4128f23-0154-471b-8b4f-737ed49f36cc] [error="{\"addr\":\"10.20.70.38:8300\",\"code\":\"CDC:ErrProcessorUnknown\",\"message\":\"[CDC:ErrKafkaAsyncSendMessage]kafka: Failed to produce message to topic prod_da_sm: kafka server: Message was too large, server rejected it to avoid allocation error.: kafka: Failed to produce message to topic prod_da_sm: kafka server: Message was too large, server rejected it to avoid allocation error.\"}"]

日志附件如下：

cdc 创建任务的命令如下：

tiup cdc:v5.3.0 cli changefeed create --pd=host:port --sink-uri="kafka://host:port/topic?kafka-version=2.6.0&partition-num=1&max-message-bytes=67108864&replication-factor=1" --config changefeed_xxx.toml -c xxxx

changefeed_xxx.toml 配置如下

case-sensitive = true

enable-old-value = true

[filter]
ignore-txn-start-ts = [1, 2]

rules = ['database.*']


[mounter]
worker-num = 16

[sink]
dispatchers = [
    {matcher = ['database.*'], dispatcher = "rowid"},
]
protocol = "maxwell"
2

貌似日志文件太大了，上传不上来

3

调整下下游kakfa集群的消息大小

4

https://docs.pingcap.com/tidb/v5.0/troubleshoot-ticdc

image
image724×340 22.9 KB

5

调整了 kafka 的参数后，我对 cdc task 执行了 pause 后，再 resume 操作，部分日志如下：

[2022/09/23 18:03:24.908 +08:00] [INFO] [changefeed.go:292] ["close changefeed"] [changefeed=prod-da-sm] [info="{\"sink-uri\":\"***\",\"opts\":{\"max-message-bytes\":\"67108864\"},\"create-time\":\"2022-08-25T17:25:46.073399911+08:00\",\"start-ts\":435531161239814145,\"target-ts\":0,\"admin-job-type\":0,\"sort-engine\":\"unified\",\"sort-dir\":\"\",\"config\":{\"case-sensitive\":true,\"enable-old-value\":true,\"force-replicate\":false,\"check-gc-safe-point\":true,\"filter\":{\"rules\":[\"prod_da_sm.*\",\"!prod_da_sm.market_data\"],\"ignore-txn-start-ts\":[1,2]},\"mounter\":{\"worker-num\":16},\"sink\":{\"dispatchers\":[{\"matcher\":[\"prod_da_sm.*\"],\"dispatcher\":\"rowid\"}],\"protocol\":\"maxwell\"},\"cyclic-replication\":{\"enable\":false,\"replica-id\":0,\"filter-replica-ids\":null,\"id-buckets\":0,\"sync-ddl\":false},\"scheduler\":{\"type\":\"table-number\",\"polling-time\":-1},\"consistent\":{\"level\":\"none\",\"max-log-size\":64,\"flush-interval\":1000,\"storage\":\"\"}},\"state\":\"normal\",\"history\":[],\"error\":{\"addr\":\"10.20.70.38:8300\",\"code\":\"CDC:ErrProcessorUnknown\",\"message\":\"[CDC:ErrKafkaAsyncSendMessage]kafka: Failed to produce message to topic prod_da_sm: kafka server: Message was too large, server rejected it to avoid allocation error.: kafka: Failed to produce message to topic prod_da_sm: kafka server: Message was too large, server rejected it to avoid allocation error.\"},\"sync-point-enabled\":false,\"sync-point-interval\":600000000000,\"creator-version\":\"v5.3.0\"}"] [isRemoved=false]
[2022/09/23 18:03:24.980 +08:00] [INFO] [sorter.go:163] ["flow control cancelled for table"] [tableID=2117] [tableName=`prod_da_sm`.`prospectus_issuing_related_institutions_from_a_shares`]
[2022/09/23 18:03:24.980 +08:00] [INFO] [sorter.go:163] ["flow control cancelled for table"] [tableID=2520] [tableName=`prod_da_sm`.`listing_fusions`]
[2022/09/23 18:03:24.980 +08:00] [INFO] [sorter.go:163] ["flow control cancelled for table"] [tableID=2163] [tableName=`prod_da_sm`.`income_statement_summary_from_a_shares`]
[2022/09/23 18:03:36.817 +08:00] [INFO] [changefeed.go:208] ["initialize changefeed"] [changefeed=prod-da-sm] [info="{\"sink-uri\":\"***\",\"opts\":{\"max-message-bytes\":\"67108864\"},\"create-time\":\"2022-08-25T17:25:46.073399911+08:00\",\"start-ts\":435531161239814145,\"target-ts\":0,\"admin-job-type\":0,\"sort-engine\":\"unified\",\"sort-dir\":\"\",\"config\":{\"case-sensitive\":true,\"enable-old-value\":true,\"force-replicate\":false,\"check-gc-safe-point\":true,\"filter\":{\"rules\":[\"prod_da_sm.*\",\"!prod_da_sm.market_data\"],\"ignore-txn-start-ts\":[1,2]},\"mounter\":{\"worker-num\":16},\"sink\":{\"dispatchers\":[{\"matcher\":[\"prod_da_sm.*\"],\"dispatcher\":\"rowid\"}],\"protocol\":\"maxwell\"},\"cyclic-replication\":{\"enable\":false,\"replica-id\":0,\"filter-replica-ids\":null,\"id-buckets\":0,\"sync-ddl\":false},\"scheduler\":{\"type\":\"table-number\",\"polling-time\":-1},\"consistent\":{\"level\":\"none\",\"max-log-size\":64,\"flush-interval\":1000,\"storage\":\"\"}},\"state\":\"normal\",\"history\":null,\"error\":null,\"sync-point-enabled\":false,\"sync-point-interval\":600000000000,\"creator-version\":\"v5.3.0\"}"] ["checkpoint ts"=436182723364126727]
[2022/09/23 18:03:41.066 +08:00] [INFO] [kafka.go:402] ["get partition number of topic"] [topic=prod_da_sm] [partition_num=1]
[2022/09/23 18:03:41.066 +08:00] [WARN] [schema.go:160] ["skip ineligible table"] [tid=3845] [table=prod_da_sm.industry_classification_from_strategic_emergings]
[2022/09/23 18:03:41.067 +08:00] [WARN] [schema.go:160] ["skip ineligible table"] [tid=3833] [table=prod_da_sm.industry_classification_from_investments]
[2022/09/23 18:03:41.067 +08:00] [WARN] [schema.go:160] ["skip ineligible table"] [tid=3839] [table=prod_da_sm.industry_classification_from_managements]
[2022/09/23 18:03:57.540 +08:00] [WARN] [schema.go:160] ["skip ineligible table"] [tid=3833] [table=prod_da_sm.industry_classification_from_investments]
[2022/09/23 18:03:57.540 +08:00] [WARN] [schema.go:160] ["skip ineligible table"] [tid=3839] [table=prod_da_sm.industry_classification_from_managements]
[2022/09/23 18:03:57.541 +08:00] [WARN] [schema.go:160] ["skip ineligible table"] [tid=3845] [table=prod_da_sm.industry_classification_from_strategic_emergings]
[2022/09/23 18:04:01.924 +08:00] [INFO] [kafka.go:402] ["get partition number of topic"] [topic=prod_da_sm] [partition_num=1]
[2022/09/23 18:04:01.924 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=3857] [changefeed=prod-da-sm] [name=`prod_da_sm`.`market_data_from_neeqs`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"][globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.924 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2138] [changefeed=prod-da-sm] [name=`prod_da_sm`.`financial_summary_from_hk_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.924 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2146] [changefeed=prod-da-sm] [name=`prod_da_sm`.`prospectus_issuer_info_from_hk_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.924 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2166] [changefeed=prod-da-sm] [name=`prod_da_sm`.`enterprise_industry_from_shenwans`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.924 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2168] [changefeed=prod-da-sm] [name=`prod_da_sm`.`industry_classification_from_hs`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.924 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=3859] [changefeed=prod-da-sm] [name=`prod_da_sm`.`latest_top_shareholders_from_neeqs`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.924 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2136] [changefeed=prod-da-sm] [name=`prod_da_sm`.`main_board_listing_processes_from_a_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2204] [changefeed=prod-da-sm] [name=`prod_da_sm`.`prospectus_issuance_manager_from_hk_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2220] [changefeed=prod-da-sm] [name=`prod_da_sm`.`enterprise_industry_from_gics`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2222] [changefeed=prod-da-sm] [name=`prod_da_sm`.`key_ratio_from_a_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2073] [changefeed=prod-da-sm] [name=`prod_da_sm`.`enterprise_industry_from_winds`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=3487] [changefeed=prod-da-sm] [name=`prod_da_sm`.`latest_top_shareholders_from_a_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=3843] [changefeed=prod-da-sm] [name=`prod_da_sm`.`enterprise_industry_from_managements`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2194] [changefeed=prod-da-sm] [name=`prod_da_sm`.`industry_classification_from_shenwans`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2064] [changefeed=prod-da-sm] [name=`prod_da_sm`.`security_associated_companies_from_a_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2116] [changefeed=prod-da-sm] [name=`prod_da_sm`.`roadshow_from_a_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"][globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2122] [changefeed=prod-da-sm] [name=`prod_da_sm`.`enterprise_industry_from_citics`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2140] [changefeed=prod-da-sm] [name=`prod_da_sm`.`listing_announcements_from_a_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2218] [changefeed=prod-da-sm] [name=`prod_da_sm`.`latest_market_data_from_us_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2223] [changefeed=prod-da-sm] [name=`prod_da_sm`.`prospectus_issuer_info_from_us_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=3791] [changefeed=prod-da-sm] [name=`prod_da_sm`.`prospectus_issuer_infos_from_a_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=3847] [changefeed=prod-da-sm] [name=`prod_da_sm`.`industry_hierarchy_from_strategic_emergings`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2067] [changefeed=prod-da-sm] [name=`prod_da_sm`.`prospectus_issuing_related_agency_from_us_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2108] [changefeed=prod-da-sm] [name=`prod_da_sm`.`industry_classification_from_winds`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.925 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2114] [changefeed=prod-da-sm] [name=`prod_da_sm`.`listing_processes_from_us_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.926 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2154] [changefeed=prod-da-sm] [name=`prod_da_sm`.`industry_hierarchy_from_gics`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.926 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=5254] [changefeed=prod-da-sm] [name=`prod_da_sm`.`listed_companies_key_personnel_from_a_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.926 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=3855] [changefeed=prod-da-sm] [name=`prod_da_sm`.`audit_status_from_neeqs`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.926 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2096] [changefeed=prod-da-sm] [name=`prod_da_sm`.`market_data_from_hk_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.926 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2110] [changefeed=prod-da-sm] [name=`prod_da_sm`.`main_board_audit_status_from_a_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.926 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2124] [changefeed=prod-da-sm] [name=`prod_da_sm`.`securities`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.926 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2148] [changefeed=prod-da-sm] [name=`prod_da_sm`.`prospectus_issuance_managers_from_a_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.926 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2178] [changefeed=prod-da-sm] [name=`prod_da_sm`.`security_associated_companies_deriveds`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.926 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=2188] [changefeed=prod-da-sm] [name=`prod_da_sm`.`prospectus_issued_shares_overview_from_us_shares`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]
[2022/09/23 18:04:01.926 +08:00] [INFO] [processor.go:747] ["Add table pipeline"] [tableID=3861] [changefeed=prod-da-sm] [name=`prod_da_sm`.`latest_market_data_from_neeqs`] [replicaInfo="{\"start-ts\":436182723364126727,\"mark-table-id\":0}"] [globalResolvedTs=436182723364126727]```
这边日志第一行显示 changefeed close ,
6

这边的 changefeed stop 应该是因为我执行了 pause 操作，后面执行 resume 操作后，prod_da_sm state 为正常了，但还是没有往 kafka 发送数据

7

当我修改被监听的数据的的数据时，topic 中没有新增的数据

2022-09-23%2018-18-03%E5%B1%8F%E5%B9%95%E6%88%AA%E5%9B%BE
2022-09-23%2018-18-03%E5%B1%8F%E5%B9%95%E6%88%AA%E5%9B%BE1040×841 99.1 KB

8

cdc 最新日志 cdc_10000.log (2.9 MB)

9

发现其中一个 cdc 节点一直报
[WARN] [pd.go:152] ["get timestamp too slow"] ["cost time"=67.311146ms]

10

这个是warn，需要看看cdc到pd的网路情况和pd leader的负载情况

11

这种是tidb中表没有PK或者UK，不符合同步条件。

12

此话题已在最后回复的 60 天后被自动关闭。不再允许新回复。