canal问题二则

最近打开了大数据项目与生产数据的实时同步，过程中canal有了点问题，下面稍微总结下。

问题一

报错

开启同步后，rocketmq的生产消费速度巨慢，大概只有2-5，查看应用日志后，并未发现报错。数据库检查后也未发现死锁影响同步。

后来查看canal日志，发现以下报错：

2019-06-03 16:32:38.785 [destination = example , address = 172.16.153.119: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
2019-06-03 16:32:38.829 [destination = example , address = 172.16.153.119:3306 , EventParser] WARN  c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - ---> find start position successfully, EntryPosition[included=false,journalName=mysql-bin.000018,position=519081757,serverId=41,gtid=9e3c7999-2477-11e9-90a7-7cd30a552d31:1-2,18c68cdb-0f19-11e5-aff9-40a8f028ee6c:1-1821462442,ae8ade8c-6b4d-11e9-9e90-506b8d463235:1-133,584ebf5a-22c5-11e8-8042-1402ec31dfb0:1-2,29b70c86-7e5e-11e8-958c-7ed30a552ce7:1-837803407,bcfbba5d-ae65-11e7-8968-1402ec31dfb0:1,timestamp=1557876969000] cost : 44ms , the next step is binlog dump
2019-06-03 16:32:39.731 [destination = example , address = 172.16.153.119:3306 , EventParser] ERROR c.a.o.c.p.inbound.mysql.rds.RdsBinlogEventParserProxy - dump address bigdata-mha/172.16.153.119:3306 has an error, retrying. caused by 
com.alibaba.otter.canal.parse.exception.CanalParseException: com.alibaba.otter.canal.parse.exception.CanalParseException: parse row data failed.
Caused by: com.alibaba.otter.canal.parse.exception.CanalParseException: parse row data failed.
Caused by: com.alibaba.otter.canal.parse.exception.CanalParseException: column size is not match for table:cif.cif_user_we_chat,16 vs 15
2019-06-03 16:32:39.731 [destination = example , address = 172.16.153.119:3306 , EventParser] ERROR com.alibaba.otter.canal.common.alarm.LogAlarmHandler - destination:example[com.alibaba.otter.canal.parse.exception.CanalParseException: com.alibaba.otter.canal.parse.exception.CanalParseException: parse row data failed.
Caused by: com.alibaba.otter.canal.parse.exception.CanalParseException: parse row data failed.
Caused by: com.alibaba.otter.canal.parse.exception.CanalParseException: column size is not match for table:cif.cif_user_we_chat,16 vs 15]
复制

重点：

原因

网上找了下相关报错，最后在github的canal issue里找到了答案。这问题主要是由于tsdb引起的，canal tsdb设计理念：https://github.com/alibaba/canal/wiki/TableMetaTSDB。

因为同步库与生产库有1个月未同步了，期间对同步库和生产库的cif_user_we_chat表进行了加列操作（由15列加到16列），所以canal的tsdb里缓存了一份最新的表结构。当重新打开同步后，canal发现一个月前的生产数据库只有15个字段，于是抛出了这个错误。

解决方案

最简单的方法就是清空canal tsdb里的表结构信息，让它重新加载一份。所有的缓存表结构都存在canal/conf/example目录下的h2.mv.db文件里，删除它即可。

需要特别注意的是，删除h2.mv.db，重启canal后，meta.dat的节点信息也会被一并清空，需要重新重新指定节点信息。

处理时一定要做好备份工作！

问题二

报错

开发说有张表功共18个字段，canal取了18个字段，但是其中cur_credit字段重复取了两次，然后抛弃了最后个字段modify_time，我第一反应是代码问题，但是看下来其他环境相同代码都没问题。然后检查了下表结构，也都正常。

最后又看了canal的explame日志，发现了藏得很好的一条信息：

2019-05-31 17:09:13.068 [[scheduler-table-meta-snapshot]] ERROR c.a.o.canal.parse.inbound.mysql.tsdb.DatabaseTableMeta - pls submit github issue, show create table ddl:CREATE TABLE `crius_u
ser_task` (
  `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT COMMENT '自增主键',
  `user_task_id` varchar(25) NOT NULL COMMENT '用户任务id',
  `user_id` varchar(32) NOT NULL COMMENT '用户id',
  `task_config_id` varchar(7) NOT NULL COMMENT '任务配置id',
  `tag_no` varchar(32) NOT NULL COMMENT '标签编号',
  `tag_value` varchar(200) DEFAULT NULL COMMENT '标签值',
  `activity_id` varchar(32) DEFAULT NULL COMMENT '活动id',
  `credit` decimal(16,0) NOT NULL COMMENT '积分，不同用户可能不一样',
  `cur_credit` decimal(16,0) NOT NULL DEFAULT '0' COMMENT '当前积分',
  `freq_cycle_num` int(4) NOT NULL COMMENT '周期循环类任务，已经循环的次数',
  `issue_time` varchar(14) NOT NULL COMMENT '下发日期',
  `check_time` varchar(14) DEFAULT NULL COMMENT '领取日期（点击去完成）',
  `finish_time` varchar(14) DEFAULT NULL COMMENT '完成日期',
  `expire_time` varchar(14) DEFAULT NULL COMMENT '有效日期。',
  `task_status` varchar(1) NOT NULL COMMENT '任务状态',
  `issue_status` varchar(1) NOT NULL COMMENT '发奖励状态',
  `create_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP COMMENT '新增时间',
  `modify_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP COMMENT '修改时间',
  PRIMARY KEY (`id`),
  UNIQUE KEY `uniq_user_task_id` (`user_task_id`),
  KEY `idx_user_id` (`user_id`),
  KEY `idx_task_config_id` (`task_config_id`)
) ENGINE=InnoDB AUTO_INCREMENT=6339 DEFAULT CHARSET=utf8 COMMENT='用户任务表' , compare failed . 
 db : TableMeta [schema=crius, table=crius_user_task, fileds=
	FieldMeta [columnName=id, columnType=bigint(20) unsigned, nullable=false, key=true, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=user_task_id, columnType=varchar(25), nullable=false, key=false, defaultValue=null, extra=null, unique=true]
	FieldMeta [columnName=user_id, columnType=varchar(32), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=task_config_id, columnType=varchar(7), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=tag_no, columnType=varchar(32), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=tag_value, columnType=varchar(200), nullable=true, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=activity_id, columnType=varchar(32), nullable=true, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=credit, columnType=decimal(16,0), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=cur_credit, columnType=decimal(16,0), nullable=false, key=false, defaultValue=0, extra=null, unique=false]
	FieldMeta [columnName=freq_cycle_num, columnType=int(4), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=issue_time, columnType=varchar(14), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=check_time, columnType=varchar(14), nullable=true, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=finish_time, columnType=varchar(14), nullable=true, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=expire_time, columnType=varchar(14), nullable=true, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=task_status, columnType=varchar(1), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=issue_status, columnType=varchar(1), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=create_time, columnType=timestamp, nullable=false, key=false, defaultValue=CURRENT_TIMESTAMP, extra=null, unique=false]
	FieldMeta [columnName=modify_time, columnType=timestamp, nullable=false, key=false, defaultValue=CURRENT_TIMESTAMP, extra=null, unique=false]
] 
 mem : TableMeta [schema=crius, table=crius_user_task, fileds=
	FieldMeta [columnName=id, columnType=bigint(20) unsigned, nullable=false, key=true, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=user_task_id, columnType=varchar(25), nullable=false, key=false, defaultValue=null, extra=null, unique=true]
	FieldMeta [columnName=user_id, columnType=varchar(32), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=task_config_id, columnType=varchar(7), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=tag_no, columnType=VARCHAR(32), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=tag_value, columnType=VARCHAR(200), nullable=true, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=activity_id, columnType=varchar(32), nullable=true, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=credit, columnType=DECIMAL(16,0), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=cur_credit, columnType=DECIMAL(16,0), nullable=true, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=cur_credit, columnType=DECIMAL(16,0), nullable=false, key=false, defaultValue=0, extra=null, unique=false]
	FieldMeta [columnName=freq_cycle_num, columnType=int(4), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=issue_time, columnType=varchar(14), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=check_time, columnType=varchar(14), nullable=true, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=finish_time, columnType=varchar(14), nullable=true, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=expire_time, columnType=varchar(14), nullable=true, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=issue_status, columnType=varchar(1), nullable=false, key=false, defaultValue=null, extra=null, unique=false]
	FieldMeta [columnName=create_time, columnType=timestamp, nullable=false, key=false, defaultValue=CURRENT_TIMESTAMP, extra=null, unique=false]
	FieldMeta [columnName=modify_time, columnType=timestamp, nullable=false, key=false, defaultValue=CURRENT_TIMESTAMP, extra=null, unique=false]
复制

关键信息：

原因

第二张图显示canal mem的表结构中cur_credit字段存了两份，这与开发的描述一致。

第一张图尽然让我去github上提个issue，好吧~网上查了下没有找到这个问题相应描述。

解决方案

找不到原因，那就先解决呗。这次是通过删除原表crius_user_task，再原模原样重建一张（字段、类型、名字全都与原表一致），然后导入备份的数据。重启canal后，发现binlog解析正常了。

遇到这问题时，并未搞清canal tsdb的概念，下次再遇到此类问题，应该也可以通过清空tsdb里的缓存表结构解决。