11 flink-sql 中基于 mysql-cdc 连接 mysql-pxc 集群无法获取增量数据问题

前言

问题是来自于群友, 2024.03.29, 也是花了一些时间来排查这个问题

大致的问题是用 mysql-cdc 连接了一个 mysql-pxc 集群, 然后创建了一个 test_user 表

使用 "select * from test_user" 获取数据表的数据, 可以拿到查询时的快照, 但是无法获取到后续对于 test_user 表的增量操作的数据, 比如新增的数据

正常连接一个普通的单点 mysql 是可以正常进行数据同步的

flink-sql 中基于 mysql-cdc 的 select * from test_user 的具体实现也是衍生自此问题

然后可以先了解一下这个查询的过程

问题的排查思路

当然这里介绍的仅仅是一个思路, 一个排查方向, 未必能够解决问题

1. 查看正常同步, 异常同步的 mysql 的 bin-log 相关配置, 然后更新异常同步 mysql 的这边的配置, 查看是否能够正常工作

2. 日志级别的排查, 查看 taskmanager 这边的日志, 查看一下 BinaryLogClinet, BinlogReader 等等相关日志, 切换日志级别为 DEBUG, 查看是否有具体的信息, 结合日志信息和代码进行一个抽象的分析

3. 如果能够访问数据库的话, 可以本地部署一个简单的 flink-1.13.6, 然后本地模拟, 来调试 taskmanager, 当然在这里这个问题, 我们是不具备条件的, 别人的机器

4. 使用 mysqlbinlog 等等工具, 向 mysql 集群这边发送请求, 获取 binlog 相关信息, 查看是否正常

处理过程

1. 查看正常同步, 异常同步的 mysql 的 bin-log 相关配置, 然后更新异常同步 mysql 的这边的配置, 查看是否能够正常工作

2. 日志级别的排查, 查看 taskmanager 这边的日志, 查看一下 BinaryLogClinet, BinlogReader 等等相关日志, 切换日志级别为 DEBUG, 查看是否有具体的信息, 结合日志信息和代码进行一个抽象的分析

INFO 级别的日志信息如下, 可以得出的大致的现象是 "看这个情况有点像 task_manager 触发连接 mysql binlog 服务这边怎么出问题了, 然后 blc-keepalive 线程, 每隔一分钟在重试 "


2024-04-01 09:19:32,482 INFO  io.debezium.util.Threads                                     [] - Creating thread debezium-mysqlconnector-mysql_binlog_source-binlog-client
2024-04-01 09:19:32,492 INFO  io.debezium.connector.mysql.BinlogReader                     [] - Connected to MySQL binlog at 172.16.5.58:3306, starting at binlog file 'bin.000051', pos=387473470, skipping 0 events plus 0 rows
2024-04-01 09:19:32,493 INFO  io.debezium.connector.mysql.BinlogReader                     [] - Stopped reading binlog after 0 events, no new offset was recorded
2024-04-01 09:19:52,622 INFO  io.debezium.util.Threads                                     [] - Creating thread debezium-mysqlconnector-mysql_binlog_source-binlog-client
2024-04-01 09:19:52,635 INFO  io.debezium.connector.mysql.BinlogReader                     [] - Connected to MySQL binlog at 172.16.5.58:3306, starting at binlog file 'bin.000051', pos=382848711, skipping 0 events plus 0 rows
2024-04-01 09:19:52,636 INFO  io.debezium.connector.mysql.BinlogReader                     [] - Stopped reading binlog after 0 events, no new offset was recorded
2024-04-01 09:20:32,494 INFO  io.debezium.util.Threads                                     [] - Creating thread debezium-mysqlconnector-mysql_binlog_source-binlog-client
2024-04-01 09:20:32,504 INFO  io.debezium.connector.mysql.BinlogReader                     [] - Connected to MySQL binlog at 172.16.5.58:3306, starting at binlog file 'bin.000051', pos=387473470, skipping 0 events plus 0 rows
2024-04-01 09:20:32,504 INFO  io.debezium.connector.mysql.BinlogReader                     [] - Stopped reading binlog after 0 events, no new offset was recorded
2024-04-01 09:20:52,636 INFO  io.debezium.util.Threads                                     [] - Creating thread debezium-mysqlconnector-mysql_binlog_source-binlog-client
2024-04-01 09:20:52,647 INFO  io.debezium.connector.mysql.BinlogReader                     [] - Connected to MySQL binlog at 172.16.5.58:3306, starting at binlog file 'bin.000051', pos=382848711, skipping 0 events plus 0 rows
2024-04-01 09:20:52,647 INFO  io.debezium.connector.mysql.BinlogReader                     [] - Stopped reading binlog after 0 events, no new offset was recorded
2024-04-01 09:21:32,506 INFO  io.debezium.util.Threads                                     [] - Creating thread debezium-mysqlconnector-mysql_binlog_source-binlog-client
2024-04-01 09:21:32,515 INFO  io.debezium.connector.mysql.BinlogReader                     [] - Connected to MySQL binlog at 172.16.5.58:3306, starting at binlog file 'bin.000051', pos=387473470, skipping 0 events plus 0 rows
2024-04-01 09:21:32,515 INFO  io.debezium.connector.mysql.BinlogReader                     [] - Stopped reading binlog after 0 events, no new offset was recorded
2024-04-01 09:21:52,648 INFO  io.debezium.util.Threads                                     [] - Creating thread debezium-mysqlconnector-mysql_binlog_source-binlog-client
2024-04-01 09:21:52,660 INFO  io.debezium.connector.mysql.BinlogReader                     [] - Connected to MySQL binlog at 172.16.5.58:3306, starting at binlog file 'bin.000051', pos=382848711, skipping 0 events plus 0 rows
2024-04-01 09:21:52,660 INFO  io.debezium.connector.mysql.BinlogReader                     [] - Stopped reading binlog after 0 events, no new offset was recorded

日志修改为 DEBUG 级别, 可以看到和 mysql 这边建立了获取 binlog 的链接之后, 马上就断开了

日志映射到代码这边的话

"Connected to MySQL binlog at 172.16.5.58:3306, starting at binlog file 'bin.000061', pos=161824289, skipping 0 events plus 0 rows" 是在 onConnect 中进行输出的

"Stopped reading binlog after 0 events, no new offset was recorded" 是在 onConnect 中进行输出的

然后 requestBinaryLogStream 是向 mysql 这边发送 dump binlog 命令

然后正常的话这个线程会阻塞在 listenForEventPackets, 进而处理 mysql 服务器这边传递过来的各个 binlog 事件, 进而反馈给 flink sql-client, 实现了数据的实时同步更新

那么问题可能就在是向 mysql 这边发送 dump binlog 命令哪里出现问题了

因此, 我们使用 mysqlbinlog 工具来进行模拟一下