开发者社区> 问答> 正文

canal v 1.1.1版本,修改某一任务配置时,导致canal-instance-scan 线程

任务日志

2019-07-24 14:31:50.504 [canal-instance-scan-0] INFO c.a.o.c.i.spring.support.PropertyPlaceholderConfigurer - Loading properties file from class path resource [canal.properties] 2019-07-24 14:31:50.505 [canal-instance-scan-0] INFO c.a.o.c.i.spring.support.PropertyPlaceholderConfigurer - Loading properties file from class path resource [ods_dts/instance.properties] 2019-07-24 14:31:50.511 [canal-instance-scan-0] INFO c.a.otter.canal.instance.spring.CanalInstanceWithSpring - start CannalInstance for 1-ods_dts 2019-07-24 14:31:50.513 [canal-instance-scan-0] INFO c.a.otter.canal.instance.core.AbstractCanalInstance - subscribe filter change to dts.dts_loan 2019-07-24 14:31:50.513 [canal-instance-scan-0] INFO c.a.otter.canal.instance.core.AbstractCanalInstance - start successful.... 2019-07-24 14:31:50.547 [destination = ods_dts , address = /10.203.150.20:3306 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - prepare to find start position ::1563939102000 2019-07-24 14:31:54.589 [New I/O server worker #1-3] INFO c.a.otter.canal.instance.core.AbstractCanalInstance - subscribe filter change to dts.dts_loan 2019-07-24 16:18:42.044 [canal-instance-scan-0] INFO c.a.otter.canal.instance.core.AbstractCanalInstance - stop CannalInstance for null-ods_dts 2019-07-24 16:18:42.487 [destination = ods_dts , address = /10.203.150.20:3306 , EventParser] ERROR c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - ERROR ## findAsPerTimestampInSpecificLogFile has an error java.nio.channels.ClosedByInterruptException: null at com.alibaba.otter.canal.parse.driver.mysql.socket.BioSocketChannel.read(BioSocketChannel.java:116) ~[canal.parse.driver-1.1.1.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch0(DirectLogFetcher.java:174) ~[canal.parse-1.1.1.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:77) ~[canal.parse-1.1.1.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.seek(MysqlConnection.java:131) ~[canal.parse-1.1.1.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.MysqlEventParser.findAsPerTimestampInSpecificLogFile(MysqlEventParser.java:731) [canal.parse-1.1.1.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.MysqlEventParser.findByStartTimeStamp(MysqlEventParser.java:569) [canal.parse-1.1.1.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.MysqlEventParser.findStartPositionInternal(MysqlEventParser.java:438) [canal.parse-1.1.1.jar:na] at com.alibaba.otter.canal.parse.inbound.mysql.MysqlEventParser.findStartPosition(MysqlEventParser.java:360) [canal.parse-1.1.1.jar:na] at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:184) [canal.parse-1.1.1.jar:na] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181] 2019-07-24 16:18:42.491 [destination = ods_dts , address = /10.203.150.20:3306 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - find start position : EntryPosition[included=false,journalName=log.000004,position=47963465,serverId=1,gtid=,timestamp=1563897673000]

堆栈日志 定位到 canal-instance-scan 线程

"canal-instance-scan-0" #16 daemon prio=5 os_prio=0 tid=0x00007fbd34713800 nid=0x3e71 in Object.wait() [0x00007fbd09dc1000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.lang.Thread.join(Thread.java:1252) - locked <0x0000000620e80fa0> (a java.lang.Thread) at java.lang.Thread.join(Thread.java:1326) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser.stop(AbstractEventParser.java:360) at com.alibaba.otter.canal.parse.inbound.mysql.AbstractMysqlEventParser.stop(AbstractMysqlEventParser.java:118) at com.alibaba.otter.canal.parse.inbound.mysql.MysqlEventParser.stop(MysqlEventParser.java:172) at com.alibaba.otter.canal.parse.inbound.mysql.rds.RdsBinlogEventParserProxy.stop(RdsBinlogEventParserProxy.java:134) at com.alibaba.otter.canal.instance.core.AbstractCanalInstance.stop(AbstractCanalInstance.java:102) at com.alibaba.otter.canal.server.embedded.CanalServerWithEmbedded.stop(CanalServerWithEmbedded.java:131) at com.alibaba.otter.canal.deployer.CanalController$3.stop(CanalController.java:231) at com.alibaba.otter.canal.deployer.CanalController$3.reload(CanalController.java:241) at com.alibaba.otter.canal.deployer.monitor.SpringInstanceConfigMonitor.notifyReload(SpringInstanceConfigMonitor.java:208) at com.alibaba.otter.canal.deployer.monitor.SpringInstanceConfigMonitor.scan(SpringInstanceConfigMonitor.java:144) at com.alibaba.otter.canal.deployer.monitor.SpringInstanceConfigMonitor.access$000(SpringInstanceConfigMonitor.java:34) at com.alibaba.otter.canal.deployer.monitor.SpringInstanceConfigMonitor$2.run(SpringInstanceConfigMonitor.java:61) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)

parseThread 线程堆栈

"destination = ods_dts , address = /10.203.150.20:3306 , EventParser" #982 daemon prio=5 os_prio=0 tid=0x00007fbcb8302800 nid=0x4235 runnable [0x00007fbc973ce000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:171) at java.net.SocketInputStream.read(SocketInputStream.java:141) at java.io.BufferedInputStream.fill(BufferedInputStream.java:246) at java.io.BufferedInputStream.read1(BufferedInputStream.java:286) at java.io.BufferedInputStream.read(BufferedInputStream.java:345) - locked <0x0000000620e89188> (a java.io.BufferedInputStream) at com.alibaba.otter.canal.parse.driver.mysql.socket.BioSocketChannel.read(BioSocketChannel.java:108) 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:216) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:252) at java.lang.Thread.run(Thread.java:748)

问题原因:

在加载启动任务时候,AbstractEventParser 类中执行start方法,parseThread线程就也会启动,但是parserThread 需要先找到start Position 后才能dump日志。如果parseThread长时间处于查找start点时,此时如果有配置变更,配置文件扫描线程instance-scan,就会触发stop任务。但是AbstractEventParser执行stop时,在将parseThread线程关闭时,至少interrupt而已,最终停止需要本身线程执行完,才能正在停止。但是此时 multiStageCoprocessor 这个对象还没有处于start状态,所以说没有办法执行stop。这个时候parseThread,找到了start点后,

// 4. 开始dump数据 if (parallel) { // build stage processor multiStageCoprocessor = buildMultiStageCoprocessor(); if (isGTIDMode()) { // 判断所属instance是否启用GTID模式,是的话调用ErosaConnection中GTID对应方法dump数据 GTIDSet gtidSet = MysqlGTIDSet.parse(startPosition.getGtid()); ((MysqlMultiStageCoprocessor) multiStageCoprocessor).setGtidSet(gtidSet); multiStageCoprocessor.start(); erosaConnection.dump(gtidSet, multiStageCoprocessor); } else { multiStageCoprocessor.start(); if (StringUtils.isEmpty(startPosition.getJournalName()) && startPosition.getTimestamp() != null) { erosaConnection.dump(startPosition.getTimestamp(), multiStageCoprocessor); } else { erosaConnection.dump(startPosition.getJournalName(), startPosition.getPosition(), multiStageCoprocessor); } } } else { 才将multiStageCoprocessor执行start方法,然后parserThread线程就一直处于dump中,导致了instance-scan线程无法真正停止任务,重启任务。

**解决方法: **

是否可以在找到点的过程中,判断AbstractEventParser 是否处于stop状态,从而决定parserThread是否继续往下执行?

原提问者GitHub用户happyzhouhuan

展开
收起
数据大拿 2023-05-04 11:40:19 82 0
1 条回答
写回答
取消 提交回答
  • 尝试一下最新版本吧,印象中修复过资源停止的问题

    原回答者GitHub用户agapple

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

相关电子书

更多
多IO线程优化版 立即下载
低代码开发师(初级)实战教程 立即下载
阿里巴巴DevOps 最佳实践手册 立即下载