客户端启动异常，错误信息： deserializer failed ... should subsc

环境信息

canal 1.1.4 阿里云RDS 5.7 只读库

问题描述

客户端启动异常，错误信息： deserializer failed ... should subscribe first

之前一直正常运行，今日改了MySql参数binlog_rows_query_log_events=ON，然后尝试修改conf/canal.properties中的canal.instance.filter.query.dml = false参数，之后java client端下面代码报异常： Message message = connector.getWithoutAck(batchSize);

之后尝试改回binlog_rows_query_log_events=ON，恢复canal.properties参数为初始配置，重新部署canal服务等，均没有解决上面错误信息。

If there is an exception, please attach the exception trace:

com.alibaba.otter.canal.protocol.exception.CanalClientException: deserializer failed at com.alibaba.otter.canal.client.CanalMessageDeserializer.deserializer(CanalMessageDeserializer.java:54) ~[canal.client-1.1.4.jar!/:na] at com.alibaba.otter.canal.client.impl.SimpleCanalConnector.receiveMessages(SimpleCanalConnector.java:331) ~[canal.client-1.1.4.jar!/:na] at com.alibaba.otter.canal.client.impl.SimpleCanalConnector.getWithoutAck(SimpleCanalConnector.java:323) ~[canal.client-1.1.4.jar!/:na] at com.alibaba.otter.canal.client.impl.SimpleCanalConnector.getWithoutAck(SimpleCanalConnector.java:295) ~[canal.client-1.1.4.jar!/:na] at cn.lefull.canal.client.aspect.SyncLogRunner.sync(SyncLogRunner.java:76) [classes!/:0.0.1-SNAPSHOT] at cn.lefull.canal.client.aspect.SyncLogRunner.run(SyncLogRunner.java:38) [classes!/:0.0.1-SNAPSHOT] at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:786) [spring-boot-2.3.4.RELEASE.jar!/:2.3.4.RELEASE] at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:776) [spring-boot-2.3.4.RELEASE.jar!/:2.3.4.RELEASE] at org.springframework.boot.SpringApplication.run(SpringApplication.java:322) [spring-boot-2.3.4.RELEASE.jar!/:2.3.4.RELEASE] at org.springframework.boot.SpringApplication.run(SpringApplication.java:1237) [spring-boot-2.3.4.RELEASE.jar!/:2.3.4.RELEASE] at org.springframework.boot.SpringApplication.run(SpringApplication.java:1226) [spring-boot-2.3.4.RELEASE.jar!/:2.3.4.RELEASE] at cn.lefull.canal.client.CanalClientApplication.main(CanalClientApplication.java:13) [classes!/:0.0.1-SNAPSHOT] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_232] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_232] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_232] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_232] at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49) [canal-client.jar:0.0.1-SNAPSHOT] at org.springframework.boot.loader.Launcher.launch(Launcher.java:107) [canal-client.jar:0.0.1-SNAPSHOT] at org.springframework.boot.loader.Launcher.launch(Launcher.java:58) [canal-client.jar:0.0.1-SNAPSHOT] at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88) [canal-client.jar:0.0.1-SNAPSHOT] Caused by: com.alibaba.otter.canal.protocol.exception.CanalClientException: something goes wrong with reason: something goes wrong with channel:[id: 0x77eab32c, /127.0.0.1:49890 => /127.0.0.1:11111], exception=com.alibaba.otter.canal.server.exception.CanalServerException: ClientIdentity:ClientIdentity[destination=example,clientId=1001,filter=] should subscribe first

    at com.alibaba.otter.canal.client.CanalMessageDeserializer.deserializer(CanalMessageDeserializer.java:46) ~[canal.client-1.1.4.jar!/:na]
    ... 19 common frames omitted

服务端启动日志：

[root@test-node2 bin]# tail -f ../logs/canal/canal.log 2020-10-19 19:13:22.690 [main] INFO com.alibaba.otter.canal.deployer.CanalLauncher - ## set default uncaught exception handler 2020-10-19 19:13:22.726 [main] INFO com.alibaba.otter.canal.deployer.CanalLauncher - ## load canal configurations 2020-10-19 19:13:22.750 [main] INFO com.alibaba.otter.canal.deployer.CanalStarter - ## start the canal server. 2020-10-19 19:13:22.823 [main] INFO com.alibaba.otter.canal.deployer.CanalController - ## start the canal server[……:11111] 2020-10-19 19:13:24.270 [main] INFO com.alibaba.otter.canal.deployer.CanalStarter - ## the canal server is running now ...... ^C [root@test-node2 bin]# tail -f ../logs/example/example.log 2020-10-19 19:13:23.534 [main] WARN o.s.beans.GenericTypeAwarePropertyDescriptor - Invalid JavaBean property 'connectionCharset' being accessed! Ambiguous write methods found next to actually used [public void com.alibaba.otter.canal.parse.inbound.mysql.AbstractMysqlEventParser.setConnectionCharset(java.nio.charset.Charset)]: [public void com.alibaba.otter.canal.parse.inbound.mysql.AbstractMysqlEventParser.setConnectionCharset(java.lang.String)] 2020-10-19 19:13:23.605 [main] INFO c.a.o.c.i.spring.support.PropertyPlaceholderConfigurer - Loading properties file from class path resource [canal.properties] 2020-10-19 19:13:23.606 [main] INFO c.a.o.c.i.spring.support.PropertyPlaceholderConfigurer - Loading properties file from class path resource [example/instance.properties] 2020-10-19 19:13:24.186 [main] INFO c.a.otter.canal.instance.spring.CanalInstanceWithSpring - start CannalInstance for 1-example 2020-10-19 19:13:24.200 [main] WARN c.a.o.canal.parse.inbound.mysql.dbsync.LogEventConvert - --> init table filter : ^...$ 2020-10-19 19:13:24.200 [main] WARN c.a.o.canal.parse.inbound.mysql.dbsync.LogEventConvert - --> init table black filter : …… 2020-10-19 19:13:24.217 [main] INFO c.a.otter.canal.instance.core.AbstractCanalInstance - start successful.... 2020-10-19 19:13:24.331 [destination = example , address = ……: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 2020-10-19 19:13:24.331 [destination = example , address……3306 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - prepare to find start position just show master status 2020-10-19 19:13:25.653 [destination = example , address =……3306 , EventParser] WARN c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - ---> find start position successfully, EntryPosition[included=false,journalName=mysql-bin.000266,position=259409660,serverId=1548089768,gtid=,timestamp=1603106004000] cost : 1308ms , the next step is binlog dump ^C

原提问者GitHub用户hiling