Open wuwei0727 opened 1 week ago
可以查一下deployer的 ${instance}的日志
我的deployer日志只有这些。我看了里面没有报错信息
example就是instance,进example目录看看
example.log我看了,我没看见有什么报错
2024-07-30 15:28:09.305 [main] INFO c.a.otter.canal.instance.spring.CanalInstanceWithSpring - start CannalInstance for 1-example 2024-07-30 15:28:09.323 [main] WARN c.a.o.canal.parse.inbound.mysql.dbsync.LogEventConvert - --> init table filter : ^park1.parking_elevator_binding$|^park1.parking_company$|^park1.parking_place$|^park1.parking_exit$|^park1.map_build$|^park1.shangjia$|^park1.map_wc$ 2024-07-30 15:28:09.324 [main] WARN c.a.o.canal.parse.inbound.mysql.dbsync.LogEventConvert - --> init table black filter : ^mysql\.slave_.*$ 2024-07-30 15:28:09.368 [destination = example , address = /192.168.1.95:3306 , 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 2024-07-30 15:28:09.439 [main] INFO c.a.otter.canal.instance.core.AbstractCanalInstance - start successful.... 2024-07-30 15:28:09.467 [destination = example , address = /192.168.1.95:3306 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - prepare to find start position just last position {"identity":{"slaveId":-1,"sourceAddress":{"address":"192.168.1.95","port":3306}},"postion":{"gtid":"","included":false,"journalName":"mysql-bin.007076","position":27619077,"serverId":1,"timestamp":1722324313000}} 2024-07-30 15:28:09.480 [destination = example , address = /192.168.1.95:3306 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - ---> find start position successfully, EntryPosition[included=false,journalName=mysql-bin.007076,position=27619077,serverId=1,gtid=,timestamp=1722324313000] cost : 99ms , the next step is binlog dump
meta.log:
是怎么运行的,确认这服务还正常跑着么?
直接运行bin目录下的sh文件。线上环境跑了很久之前没问题。测试发现问题,我去看日志发现只有9.24的,后面的就没了,也没发现任何报错信息。
ps
命令 查下java进程是否还在运行中呢,这个启动后&推倒后台了
## server
ps aux | grep CanalLauncher |grep -v grep
## adapter
ps aux | grep CanalAdapterApplication|grep -v grep
都没有。我不知道是什么原因导致停止了。有日志可以看原因?
这种情况只能查查系统日志了,比如/var/log下的
好的谢谢。我重启canal服务。会读取之前的binlog没同步的数据?
为了避免java崩溃,可以采取以下措施
systemd unitfile
把进程启动管理起来,并配置开机启动以及崩溃重启好的谢谢。我重启canal服务。会读取之前的binlog没同步的数据?
按道理,预期是得接着读啊
大佬这是什么问题?
2024-10-23 15:16:40.697 [destination = example , address = /192.168.1.95:3306 , EventParser] ERROR com.alibaba.otter.canal.common.alarm.LogAlarmHandler - destination:example[java.io.IOException: Received error packet: errno = 1236, sqlstate = HY000 errmsg = bogus data in log event; the first event 'mysql-bin.007826' at 61676899, the last event read from '/var/lib/mysql/mysql-bin.007826' at 61676926, the last byte read from '/var/lib/mysql/mysql-bin.007826' at 61676945. at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:102) at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:238) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$1.run(AbstractEventParser.java:262) at java.lang.Thread.run(Thread.java:748)
读取不到binlog文件?
上数据库查1查show master status;
看看master的binlog日志有没有保留到mysql-bin.007826
之前?
看你日志 mysql-bin.007815 没有的,直接跳到007826了?
你的example/目录下没有持久化的meta.data吗?
我看了是有的,为什么会报错?
example.log里面全是这样的报错。
其他节点是不是还有实例也再跑?有没有连zookeeper?
我这个是单机,没有其他机器跑
canal.instance.master.journal.name=mysql-bin.007815
canal.instance.master.position=0
把这个配置更新到 example/instance.properties, 重启看看行不
example/meta.data 有没有这个文件?
meta.data有
是把这删掉?
meta.data有
打开看看,不能删除呀呀,这个文件非常重要啊,记录的是同步到哪里了
meta.data: {"clientDatas":[{"clientIdentity":{"clientId":1001,"destination":"example","filter":""},"cursor":{"identity":{"slaveId":-1,"sourceAddress":{"address":"192.168.1.95","port":3306}},"postion":{"gtid":"","included":false,"journalName":"mysql-bin.007826","position":61676899,"serverId":1,"timestamp":1727157518000}}}],"destination":"example"}
日志中断是mysql-bin.007815
,meta.data记录是mysql-bin.007826,所以example会从mysql-bin.007826这里再继续
1727157518000=2024-09-24 13:58:38 说明程序后来又启动了
我可以把完整的example.log发送给你吗?
把meta.data中的61676899改为61676926,重启试试
好的我试试
这个还需要改吗
不用
2024-10-23 15:52:19.769 [New I/O server worker #1-1] ERROR c.a.otter.canal.server.netty.handler.SessionHandler - something goes wrong with channel:[id: 0x6483e299, /127.0.0.1:57812 :> /127.0.0.1:11111], exception=java.nio.channels.ClosedChannelException at org.jboss.netty.channel.socket.nio.NioWorker.cleanUpWriteBuffer(NioWorker.java:649) at org.jboss.netty.channel.socket.nio.NioWorker.writeFromUserCode(NioWorker.java:370) at org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink.handleAcceptedSocket(NioServerSocketPipelineSink.java:137) at org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink.eventSunk(NioServerSocketPipelineSink.java:76) at org.jboss.netty.channel.Channels.write(Channels.java:611) at org.jboss.netty.channel.Channels.write(Channels.java:578) at com.alibaba.otter.canal.server.netty.NettyUtils.write(NettyUtils.java:49) at com.alibaba.otter.canal.server.netty.handler.SessionHandler.messageReceived(SessionHandler.java:333) at org.jboss.netty.handler.timeout.IdleStateAwareChannelHandler.handleUpstream(IdleStateAwareChannelHandler.java:48) at org.jboss.netty.handler.timeout.IdleStateHandler.messageReceived(IdleStateHandler.java:276) at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:302) at org.jboss.netty.handler.codec.replay.ReplayingDecoder.unfoldAndfireMessageReceived(ReplayingDecoder.java:526) at org.jboss.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:507) at org.jboss.netty.handler.codec.replay.ReplayingDecoder.messageReceived(ReplayingDecoder.java:444) at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:274) at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:261) at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:350) at org.jboss.netty.channel.socket.nio.NioWorker.processSelectedKeys(NioWorker.java:281) at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:201) at org.jboss.netty.util.internal.IoWorkerRunnable.run(IoWorkerRunnable.java:46) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)
2024-10-23 15:52:19.866 [Thread-5] INFO c.a.otter.canal.instance.core.AbstractCanalInstance - stop CannalInstance for null-example 2024-10-23 15:52:19.870 [Thread-5] INFO c.a.otter.canal.instance.core.AbstractCanalInstance - stop successful.... 2024-10-23 15:52:27.284 [main] INFO c.a.otter.canal.instance.spring.CanalInstanceWithSpring - start CannalInstance for 1-example 2024-10-23 15:52:27.297 [main] WARN c.a.o.canal.parse.inbound.mysql.dbsync.LogEventConvert - --> init table filter : ^park1.parking_elevator_binding$|^park1.parking_company$|^park1.parking_place$|^park1.parking_exit$|^park1.map_build$|^park1.shangjia$|^park1.mapwc$ 2024-10-23 15:52:27.297 [main] WARN c.a.o.canal.parse.inbound.mysql.dbsync.LogEventConvert - --> init table black filter : ^mysql.slave.*$ 2024-10-23 15:52:27.345 [destination = example , address = /192.168.1.95:3306 , 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 2024-10-23 15:52:27.403 [main] INFO c.a.otter.canal.instance.core.AbstractCanalInstance - start successful.... 2024-10-23 15:52:30.438 [destination = example , address = /192.168.1.95:3306 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - prepare to find start position just last position {"identity":{"slaveId":-1,"sourceAddress":{"address":"192.168.1.95","port":3306}},"postion":{"gtid":"","included":false,"journalName":"mysql-bin.007826","position":61676899,"serverId":1,"timestamp":1727157518000}} 2024-10-23 15:52:30.454 [destination = example , address = /192.168.1.95:3306 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - ---> find start position successfully, EntryPosition[included=false,journalName=mysql-bin.007826,position=61676899,serverId=1,gtid=,timestamp=1727157518000] cost : 3094ms , the next step is binlog dump 2024-10-23 15:52:30.510 [destination = example , address = /192.168.1.95:3306 , EventParser] ERROR c.a.o.canal.parse.inbound.mysql.dbsync.DirectLogFetcher - I/O error while reading from client socket java.io.IOException: Received error packet: errno = 1236, sqlstate = HY000 errmsg = bogus data in log event; the first event 'mysql-bin.007826' at 61676899, the last event read from '/var/lib/mysql/mysql-bin.007826' at 61676926, the last byte read from '/var/lib/mysql/mysql-bin.007826' at 61676945. at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:102) ~[canal.parse-1.1.5.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:238) [canal.parse-1.1.5.jar:na] at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$1.run(AbstractEventParser.java:262) [canal.parse-1.1.5.jar:na] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_312] 2024-10-23 15:52:30.511 [destination = example , address = /192.168.1.95:3306 , EventParser] ERROR c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - dump address /192.168.1.95:3306 has an error, retrying. caused by java.io.IOException: Received error packet: errno = 1236, sqlstate = HY000 errmsg = bogus data in log event; the first event 'mysql-bin.007826' at 61676899, the last event read from '/var/lib/mysql/mysql-bin.007826' at 61676926, the last byte read from '/var/lib/mysql/mysql-bin.007826' at 61676945. at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:102) ~[canal.parse-1.1.5.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:238) ~[canal.parse-1.1.5.jar:na] at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$1.run(AbstractEventParser.java:262) ~[canal.parse-1.1.5.jar:na] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_312] 2024-10-23 15:52:30.515 [destination = example , address = /192.168.1.95:3306 , EventParser] ERROR com.alibaba.otter.canal.common.alarm.LogAlarmHandler - destination:example[java.io.IOException: Received error packet: errno = 1236, sqlstate = HY000 errmsg = bogus data in log event; the first event 'mysql-bin.007826' at 61676899, the last event read from '/var/lib/mysql/mysql-bin.007826' at 61676926, the last byte read from '/var/lib/mysql/mysql-bin.007826' at 61676945. at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:102) at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:238) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$1.run(AbstractEventParser.java:262) at java.lang.Thread.run(Thread.java:748) ]
我按您说的修改了。
还有个方法 1,删除mate.data(做好备份) 2、修改example/instance.properties
canal.instance.master.journal.name=mysql-bin.007815
canal.instance.master.position=0
3、重启
但要确认是从哪个mysql-bin.xxxx 哪个文件开始
meta.dat文件为什么每次修改后有变回去了
没变回,看日志又有个61676945
2024-10-23 16:06:19.135 [destination = example , address = /192.168.1.95:3306 , 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 2024-10-23 16:06:19.137 [destination = example , address = /192.168.1.95:3306 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - prepare to find start position just last position {"identity":{"slaveId":-1,"sourceAddress":{"address":"192.168.1.95","port":3306}},"postion":{"gtid":"","included":false,"journalName":"mysql-bin.007826","position":61676899,"serverId":1,"timestamp":1727157518000}} 2024-10-23 16:06:19.137 [destination = example , address = /192.168.1.95:3306 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - ---> find start position successfully, EntryPosition[included=false,journalName=mysql-bin.007826,position=61676899,serverId=1,gtid=,timestamp=1727157518000] cost : 2ms , the next step is binlog dump 2024-10-23 16:06:19.153 [destination = example , address = /192.168.1.95:3306 , EventParser] ERROR c.a.o.canal.parse.inbound.mysql.dbsync.DirectLogFetcher - I/O error while reading from client socket java.io.IOException: Received error packet: errno = 1236, sqlstate = HY000 errmsg = bogus data in log event; the first event 'mysql-bin.007826' at 61676899, the last event read from '/var/lib/mysql/mysql-bin.007826' at 61676926, the last byte read from '/var/lib/mysql/mysql-bin.007826' at 61676945. at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:102) ~[canal.parse-1.1.5.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:238) [canal.parse-1.1.5.jar:na] at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$1.run(AbstractEventParser.java:262) [canal.parse-1.1.5.jar:na] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_312] 2024-10-23 16:06:19.153 [destination = example , address = /192.168.1.95:3306 , EventParser] ERROR c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - dump address /192.168.1.95:3306 has an error, retrying. caused by java.io.IOException: Received error packet: errno = 1236, sqlstate = HY000 errmsg = bogus data in log event; the first event 'mysql-bin.007826' at 61676899, the last event read from '/var/lib/mysql/mysql-bin.007826' at 61676926, the last byte read from '/var/lib/mysql/mysql-bin.007826' at 61676945. at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:102) ~[canal.parse-1.1.5.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:238) ~[canal.parse-1.1.5.jar:na] at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$1.run(AbstractEventParser.java:262) ~[canal.parse-1.1.5.jar:na] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_312] 2024-10-23 16:06:19.154 [destination = example , address = /192.168.1.95:3306 , EventParser] ERROR com.alibaba.otter.canal.common.alarm.LogAlarmHandler - destination:example[java.io.IOException: Received error packet: errno = 1236, sqlstate = HY000 errmsg = bogus data in log event; the first event 'mysql-bin.007826' at 61676899, the last event read from '/var/lib/mysql/mysql-bin.007826' at 61676926, the last byte read from '/var/lib/mysql/mysql-bin.007826' at 61676945. at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:102) at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:238) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$1.run(AbstractEventParser.java:262) at java.lang.Thread.run(Thread.java:748) ] 2024-10-23 16:06:21.801 [Thread-5] INFO c.a.otter.canal.instance.core.AbstractCanalInstance - stop CannalInstance for null-example 2024-10-23 16:06:21.814 [Thread-5] INFO c.a.otter.canal.instance.core.AbstractCanalInstance - stop successful.... 2024-10-23 16:08:19.705 [main] INFO c.a.otter.canal.instance.spring.CanalInstanceWithSpring - start CannalInstance for 1-example 2024-10-23 16:08:19.721 [main] WARN c.a.o.canal.parse.inbound.mysql.dbsync.LogEventConvert - --> init table filter : ^park1.parking_elevator_binding$|^park1.parking_company$|^park1.parking_place$|^park1.parking_exit$|^park1.map_build$|^park1.shangjia$|^park1.mapwc$ 2024-10-23 16:08:19.721 [main] WARN c.a.o.canal.parse.inbound.mysql.dbsync.LogEventConvert - --> init table black filter : ^mysql.slave.*$ 2024-10-23 16:08:19.766 [destination = example , address = /192.168.1.95:3306 , 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 2024-10-23 16:08:19.832 [main] INFO c.a.otter.canal.instance.core.AbstractCanalInstance - start successful.... 2024-10-23 16:08:22.869 [destination = example , address = /192.168.1.95:3306 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - prepare to find start position just last position {"identity":{"slaveId":-1,"sourceAddress":{"address":"192.168.1.95","port":3306}},"postion":{"gtid":"","included":false,"journalName":"mysql-bin.007826","position":61676926,"serverId":1,"timestamp":1727157518000}} 2024-10-23 16:08:22.884 [destination = example , address = /192.168.1.95:3306 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - ---> find start position successfully, EntryPosition[included=false,journalName=mysql-bin.007826,position=61676926,serverId=1,gtid=,timestamp=1727157518000] cost : 3103ms , the next step is binlog dump 2024-10-23 16:08:22.940 [destination = example , address = /192.168.1.95:3306 , EventParser] ERROR c.a.o.canal.parse.inbound.mysql.dbsync.DirectLogFetcher - I/O error while reading from client socket java.io.IOException: Received error packet: errno = 1236, sqlstate = HY000 errmsg = bogus data in log event; the first event 'mysql-bin.007826' at 61676926, the last event read from '/var/lib/mysql/mysql-bin.007826' at 61676926, the last byte read from '/var/lib/mysql/mysql-bin.007826' at 61676945. at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:102) ~[canal.parse-1.1.5.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:238) [canal.parse-1.1.5.jar:na] at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$1.run(AbstractEventParser.java:262) [canal.parse-1.1.5.jar:na] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_312] 2024-10-23 16:08:22.941 [destination = example , address = /192.168.1.95:3306 , EventParser] ERROR c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - dump address /192.168.1.95:3306 has an error, retrying. caused by java.io.IOException: Received error packet: errno = 1236, sqlstate = HY000 errmsg = bogus data in log event; the first event 'mysql-bin.007826' at 61676926, the last event read from '/var/lib/mysql/mysql-bin.007826' at 61676926, the last byte read from '/var/lib/mysql/mysql-bin.007826' at 61676945. at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:102) ~[canal.parse-1.1.5.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:238) ~[canal.parse-1.1.5.jar:na] at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$1.run(AbstractEventParser.java:262) ~[canal.parse-1.1.5.jar:na] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_312] 2024-10-23 16:08:22.943 [destination = example , address = /192.168.1.95:3306 , EventParser] ERROR com.alibaba.otter.canal.common.alarm.LogAlarmHandler - destination:example[java.io.IOException: Received error packet: errno = 1236, sqlstate = HY000 errmsg = bogus data in log event; the first event 'mysql-bin.007826' at 61676926, the last event read from '/var/lib/mysql/mysql-bin.007826' at 61676926, the last byte read from '/var/lib/mysql/mysql-bin.007826' at 61676945. at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:102) at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:238) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$1.run(AbstractEventParser.java:262) at java.lang.Thread.run(Thread.java:748)
journalName的这个需要改?我看了meta.dat已经改成61676926
journalName
mate.data的 journalName?
是的
现在报错。读取不到binlog文件。不知道哪里问题。改成了61676926。还是不行
是需要把mate.data删除重新读?
是需要把mate.data删除重新读?
这个是不得已的办法
非常感谢!您的耐心帮助
environment
Issue Description
线上环境使用了很久,今天看日志突然同步不了。看了日志是9月24的,后面就没有日志了。没看到有什么报错.
需要我提供什么日志排查?
adapter: deployer:Steps to reproduce
Expected behaviour
Actual behaviour
If there is an exception, please attach the exception trace: