开发者社区> 问答> 正文

关于mysql与canal 25s超时设置心跳的问题

2019-09-12 11:12:31.463 [destination = example2 , address = /60.205.164.108:3307 , EventParser] ERROR c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - dump address 60.205.164.108/60.205.164.108:3307 has an error, retrying. caused by java.net.SocketTimeoutException: Timeout occurred, failed to read total 4 bytes in 25000 milliseconds, actual read only 0 bytes at com.alibaba.otter.canal.parse.driver.mysql.socket.BioSocketChannel.read(BioSocketChannel.java:124) ~[canal.parse.driver-1.1.4.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch0(DirectLogFetcher.java:174) ~[canal.parse-1.1.4.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:77) ~[canal.parse-1.1.4.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:235) ~[canal.parse-1.1.4.jar:na] at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:265) ~[canal.parse-1.1.4.jar:na] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_191] 2019-09-12 11:12:31.463 [destination = example2 , address = /60.205.164.108:3307 , EventParser] ERROR com.alibaba.otter.canal.common.alarm.LogAlarmHandler - destination:example2[java.net.SocketTimeoutException: Timeout occurred, failed to read total 4 bytes in 25000 milliseconds, actual read only 0 bytes at com.alibaba.otter.canal.parse.driver.mysql.socket.BioSocketChannel.read(BioSocketChannel.java:124) at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch0(DirectLogFetcher.java:174) at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:77) at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:235) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:265) at java.lang.Thread.run(Thread.java:748)

2019-09-12 14:22:46.858 [destination = example2 , address = /60.205.164.108:3307 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - ---> begin to find start position, it will be long time for reset or first position 2019-09-12 14:22:46.859 [destination = example2 , address = /60.205.164.108:3307 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - prepare to find start position just last position {"identity":{"slaveId":-1,"sourceAddress":{"address":"60.205.164.108","port":3307}},"postion":{"gtid":"","included":false,"journalName":"mysql-bin.000008","position":1851264,"serverId":3307,"timestamp":1568269294000}} 2019-09-12 14:22:46.877 [destination = example2 , address = /60.205.164.108:3307 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - ---> find start position successfully, EntryPosition[included=false,journalName=mysql-bin.000008,position=1851264,serverId=3307,gtid=,timestamp=1568269294000] cost : 19ms , the next step is binlog dump

查询之前issue有提到这个问题的根源是mysql在25秒内都没有任何binlog事件,canal等了25秒没有任何消息就会出现类似的错误。目前已添加了mysql定时事件每10s更新一次数据,下面是meta.log中的记录:

`2019-09-12 11:10:57.519 - clientId:1001 cursor:[mysql-bin.000008,1665932,1568257856000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:11:07.519 - clientId:1001 cursor:[mysql-bin.000008,1666143,1568257866000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:11:14.520 - clientId:1001 cursor:[mysql-bin.000008,1666411,1568257873000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:11:15.520 - clientId:1001 cursor:[mysql-bin.000008,1666679,1568257873000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:11:17.520 - clientId:1001 cursor:[mysql-bin.000008,1666890,1568257876000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:11:27.520 - clientId:1001 cursor:[mysql-bin.000008,1667101,1568257886000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:11:37.520 - clientId:1001 cursor:[mysql-bin.000008,1667312,1568257896000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:11:47.520 - clientId:1001 cursor:[mysql-bin.000008,1667523,1568257906000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:11:57.520 - clientId:1001 cursor:[mysql-bin.000008,1667734,1568257916000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:12:07.520 - clientId:1001 cursor:[mysql-bin.000008,1667945,1568257926000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:12:45.521 - clientId:1001 cursor:[mysql-bin.000008,1668156,1568257956000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:12:47.521 - clientId:1001 cursor:[mysql-bin.000008,1668367,1568257966000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:12:57.521 - clientId:1001 cursor:[mysql-bin.000008,1668578,1568257976000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:13:07.520 - clientId:1001 cursor:[mysql-bin.000008,1668789,1568257986000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:13:17.520 - clientId:1001 cursor:[mysql-bin.000008,1669000,1568257996000,3307,] address[60.205.164.108/60.205.164.108:3307]

2019-09-12 11:13:27.520 - clientId:1001 cursor:[mysql-bin.000008,1669211,1568258006000,3307,] address[60.205.164.108/60.205.164.108:3307]`

可以看到在11点12分07秒至45秒处确实有超时25s的情况,请问是否还有其他方法可以根除此问题?

canal版本1.1.4 mysql版本5.6

原提问者GitHub用户enclairfarron

展开
收起
数据大拿 2023-05-04 10:55:11 165 0
1 条回答
写回答
取消 提交回答
  • 开启心跳SQL,让mysql定时产生binlog

    原回答者GitHub用户agapple

    2023-05-05 10:06:28
    赞同 展开评论 打赏
问答排行榜
最热
最新

相关电子书

更多
One Box: 解读事务与分析一体化数据库 HybridDB for MySQL 立即下载
One Box:解读事务与分析一体化数据库HybridDB for MySQL 立即下载
如何支撑HTAP场景-HybridDB for MySQL系统架构和技术演进 立即下载

相关镜像