The state of the TiDB CDC task is normal, but it fails to insert data into Kafka properly

Translated
1

Note:
This topic has been translated from a Chinese forum by GPT and might contain errors.

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

| username: withseid

Background: tiup version 5.3.0

When using TiDB CDC, I encountered an issue: the state of the CDC task is normal, but it fails to insert data into 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 KB

You can see that the checkpoint time stays at 12:49, and the CDC task cannot insert data into Kafka. When the monitored table data changes, there is no corresponding data in the topic. Usually, the checkpoint time does not update in real-time, but it does not affect the normal operation of the CDC task.

According to a colleague, he performed a database deletion operation this morning, and he suspects it is related to this operation.

Additionally, one of the monitored databases inserted around 10 million records today, and it’s unclear if this data volume is related.

The following error was found in the CDC logs:

[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.\"}"]

The log attachment is as follows:

The command to create the CDC task is as follows:

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

The changefeed_xxx.toml configuration is as follows:

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
| username: withseid | Original post link

It seems that the log file is too large to upload.

3
| username: Meditator | Original post link

Adjust the message size of the downstream Kafka cluster.

4
| username: Meditator | Original post link

image
image724×340 21.2 KB

5
| username: withseid | Original post link

After adjusting the Kafka parameters, I executed a pause on the CDC task and then resumed it. Some of the logs are as follows:

[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
6
| username: withseid | Original post link

The changefeed stop here should be because I executed the pause operation. After executing the resume operation, the state of prod_da_sm became normal, but it still did not send data to Kafka.

7
| username: withseid | Original post link

When I modify the monitored data, there is no new data in the 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 92.5 KB

8
| username: withseid | Original post link

cdc latest log cdc_10000.log (2.9 MB)

9
| username: withseid | Original post link

I found that one of the CDC nodes keeps reporting
[WARN] [pd.go:152] ["get timestamp too slow"] ["cost time"=67.311146ms]

10
| username: Meditator | Original post link

This is a warning. You need to check the network situation between CDC and PD, as well as the load situation of the PD leader.

11
| username: Meditator | Original post link

This means that the table in TiDB does not have a primary key (PK) or unique key (UK), and therefore does not meet the synchronization conditions.

12
| username: system | Original post link

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.