又发现了数组下标越界异常，新的

[listen-zhou]

java.lang.ArrayIndexOutOfBoundsException: null
#011at java.lang.System.arraycopy(Native Method)
#011at java.util.Arrays.copyOfRange(Arrays.java:3521)
#011at com.hiriver.unbiz.mysql.lib.protocol.datautils.MysqlStringUtils.readFixString(MysqlStringUtils.java:55)
#011at com.hiriver.unbiz.mysql.lib.protocol.binlog.event.BaseRowEvent.readRowColumnNullBitmap(BaseRowEvent.java:253)
#011at com.hiriver.unbiz.mysql.lib.protocol.binlog.event.BaseRowEvent.parseRow(BaseRowEvent.java:172)
#011at com.hiriver.unbiz.mysql.lib.protocol.binlog.event.RowEventV1.parseVerRowForUpdate(RowEventV1.java:37)
#011at com.hiriver.unbiz.mysql.lib.protocol.binlog.event.BaseRowEvent.parse(BaseRowEvent.java:148)
#011at com.hiriver.unbiz.mysql.lib.BinlogStreamBlockingTransportImpl.readEvent(BinlogStreamBlockingTransportImpl.java:363)
#011at com.hiriver.unbiz.mysql.lib.BinlogStreamBlockingTransportImpl.getBinlogOutputImmediately(BinlogStreamBlockingTransportImpl.java:256)
#011at com.hiriver.streamsource.impl.MysqlStreamSource.readValidInfo(MysqlStreamSource.java:52)
#011at com.hiriver.channel.stream.impl.DefaultChannelStream.providerThreadCore(DefaultChannelStream.java:263)
#011at com.hiriver.channel.stream.impl.DefaultChannelStream.access$000(DefaultChannelStream.java:45)
#011at com.hiriver.channel.stream.impl.DefaultChannelStream$2.run(DefaultChannelStream.java:232)
#011at java.lang.Thread.run(Thread.java:745)

我看了是数组拷贝的时候下标越界，我手动判断一下是否越界，如果越界，end下标就设置为length-1，保证不出现下标越界异常，看看效果怎么样。
顺便说下，这个异常出自新闻类的数据，中文字符居多，别的数据暂时没有这个异常

[rolandhe]

能重现吗？从协议上分析，不应该有这个问题

[listen-zhou]

这个是我为了规避这个异常导致的线程退出，所以加了这个打印和判断，结果是这样，还是跳不过去，下面是截图是打印的日志结果

供你参考一下，我觉得应该是字符串字段解析导致的吧，你看看，这个数据处理的太快，没法定位是哪个表哪个数据出问题，况且也无法定位到是哪个字段哪种类型出问题，因为在解析的时候就异常了，就无法看出解析后的数据是什么样的。现在还依然存在这个问题，我还没发解决，我能提供的是：这个现象是发生在新闻资讯数据解析的时候报的错。我再详细描述一下，仿真环境既有新闻资讯的数据，也有普通的其他金融数据，而生产只处理新闻资讯的数据，目前发现生产会报这个错，仿真反而没有报错。不知道什么原因。

[listen-zhou]

能重现吗？从协议上分析，不应该有这个问题

详细的信息我只能提供这么多了

[rolandhe]

1. 发一下表结构
2. 根据binlog pos，使用mysql binlog工具找一下对应的数据，根据数据我分析一下

[listen-zhou]

感觉是这个表的数据解析异常了，因为到这个地方就不能往后面走了，一直卡在这，我只能手动跳过，然后再把缺的数据重新触发一下，然后就正常进行了。下面是表结构和部分数据
CREATE TABLE binlog_pos_record (
id INT(11) NOT NULL AUTO_INCREMENT,
source_dbname VARCHAR(200) NULL DEFAULT NULL,
log_name VARCHAR(100) NULL DEFAULT NULL,
log_pos BIGINT(20) NULL DEFAULT NULL,
insert_time TIMESTAMP NULL DEFAULT CURRENT_TIMESTAMP,
modify_time DATETIME NULL DEFAULT NULL ON UPDATE CURRENT_TIMESTAMP,
complete_time TIMESTAMP NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
PRIMARY KEY (id),
UNIQUE INDEX source_dbname_log_name (source_dbname, log_name)
)
COLLATE='utf8_general_ci'
ENGINE=InnoDB
AUTO_INCREMENT=7852874
;

INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6327157, 'tdxdb', 'mysql-bin.000358', 172732668, '2020-03-23 10:17:56', '2020-03-23 16:04:32', '2020-03-23 16:17:59');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6373870, 'tdxdb', 'mysql-bin.000359', 159949049, '2020-03-23 16:18:00', '2020-03-23 22:03:42', '2020-03-23 22:18:02');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6422030, 'tdxdb', 'mysql-bin.000360', 183141192, '2020-03-23 22:18:02', '2020-03-24 01:05:59', '2020-03-24 04:18:04');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6467531, 'tdxdb', 'mysql-bin.000361', 226913691, '2020-03-24 04:18:04', '2020-03-24 10:03:35', '2020-03-24 10:18:08');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6513605, 'tdxdb', 'mysql-bin.000362', 197694032, '2020-03-24 10:18:08', '2020-03-24 16:04:17', '2020-03-24 16:18:10');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6558714, 'tdxdb', 'mysql-bin.000363', 166925688, '2020-03-24 16:18:11', '2020-03-24 22:02:08', '2020-03-24 22:18:12');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6606259, 'tdxdb', 'mysql-bin.000364', 178005471, '2020-03-24 22:18:13', '2020-03-25 01:33:28', '2020-03-25 04:18:15');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6651847, 'tdxdb', 'mysql-bin.000365', 323592997, '2020-03-25 04:18:15', '2020-03-25 10:03:58', '2020-03-25 10:18:18');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6697870, 'tdxdb', 'mysql-bin.000366', 177338897, '2020-03-25 10:18:18', '2020-03-25 16:04:05', '2020-03-25 16:18:20');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6743898, 'tdxdb', 'mysql-bin.000367', 156734469, '2020-03-25 16:18:20', '2020-03-25 22:03:49', '2020-03-25 22:18:22');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6791571, 'tdxdb', 'mysql-bin.000368', 222986406, '2020-03-25 22:18:22', '2020-03-26 01:34:39', '2020-03-26 04:18:24');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6838724, 'tdxdb', 'mysql-bin.000369', 178444214, '2020-03-26 04:18:24', '2020-03-26 10:03:58', '2020-03-26 10:18:25');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6884964, 'tdxdb', 'mysql-bin.000370', 185461419, '2020-03-26 10:18:26', '2020-03-26 16:03:42', '2020-03-26 16:18:29');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6931919, 'tdxdb', 'mysql-bin.000371', 171807824, '2020-03-26 16:18:30', '2020-03-26 22:02:09', '2020-03-26 22:18:31');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (6979376, 'tdxdb', 'mysql-bin.000372', 260526426, '2020-03-26 22:18:32', '2020-03-27 01:30:13', '2020-03-27 04:18:33');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7026503, 'tdxdb', 'mysql-bin.000373', 180193148, '2020-03-27 04:18:34', '2020-03-27 10:05:59', '2020-03-27 10:18:35');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7073207, 'tdxdb', 'mysql-bin.000374', 190337302, '2020-03-27 10:18:36', '2020-03-27 16:04:10', '2020-03-27 16:18:36');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7103846, 'tdxdb', 'mysql-bin.000375', 189603686, '2020-03-27 16:18:37', '2020-03-27 22:04:40', '2020-03-27 22:18:38');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7151536, 'tdxdb', 'mysql-bin.000376', 243081372, '2020-03-27 22:18:38', '2020-03-28 02:30:56', '2020-03-28 04:18:40');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7198597, 'tdxdb', 'mysql-bin.000377', 139267583, '2020-03-28 04:18:40', '2020-03-28 10:02:09', '2020-03-28 10:18:41');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7244860, 'tdxdb', 'mysql-bin.000378', 76767752, '2020-03-28 10:18:42', '2020-03-28 16:02:19', '2020-03-28 16:18:42');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7291576, 'tdxdb', 'mysql-bin.000379', 59381199, '2020-03-28 16:18:42', '2020-03-28 21:32:04', '2020-03-28 22:18:44');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7338890, 'tdxdb', 'mysql-bin.000380', 313736078, '2020-03-28 22:18:45', '2020-03-29 01:00:09', '2020-03-29 07:16:31');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7408816, 'tdxdb', 'mysql-bin.000381', 136358749, '2020-03-29 07:16:32', '2020-03-29 01:00:09', '2020-03-29 10:18:47');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7429271, 'tdxdb', 'mysql-bin.000382', 59763039, '2020-03-29 10:18:50', '2020-03-29 16:02:00', '2020-03-29 16:18:51');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7465486, 'tdxdb', 'mysql-bin.000383', 73327838, '2020-03-29 16:18:52', '2020-03-29 22:02:08', '2020-03-29 22:18:53');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7512741, 'tdxdb', 'mysql-bin.000384', 183053284, '2020-03-29 22:18:54', '2020-03-30 01:31:54', '2020-03-30 04:18:55');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7560071, 'tdxdb', 'mysql-bin.000385', 167748037, '2020-03-30 04:18:56', '2020-03-30 10:03:31', '2020-03-30 10:18:57');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7606591, 'tdxdb', 'mysql-bin.000386', 188873765, '2020-03-30 10:18:57', '2020-03-30 16:04:12', '2020-03-30 16:18:59');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7655336, 'tdxdb', 'mysql-bin.000387', 206233663, '2020-03-30 16:18:59', '2020-03-30 22:03:34', '2020-03-30 22:19:00');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7707437, 'tdxdb', 'mysql-bin.000388', 237397231, '2020-03-30 22:19:01', '2020-03-31 04:01:13', '2020-03-31 04:19:03');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7758944, 'tdxdb', 'mysql-bin.000389', 212741350, '2020-03-31 04:19:03', '2020-03-31 10:03:48', '2020-03-31 10:19:00');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7808430, 'tdxdb', 'mysql-bin.000390', 219554850, '2020-03-31 10:19:04', '2020-03-31 16:04:51', '2020-03-31 16:19:04');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7813997, 'winddb', 'mysql-bin.002801', 422503242, '2020-03-31 11:27:44', '2020-03-31 13:13:12', '2020-03-31 13:13:12');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7820522, 'winddb', 'mysql-bin.002802', 524261390, '2020-03-31 13:13:30', '2020-03-31 14:04:01', '2020-03-31 14:04:02');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7825077, 'winddb', 'mysql-bin.002803', 495461648, '2020-03-31 14:04:05', '2020-03-31 15:19:29', '2020-03-31 15:19:29');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7835438, 'winddb', 'mysql-bin.002804', 523499353, '2020-03-31 15:19:40', '2020-03-31 15:36:13', '2020-03-31 15:36:17');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7837734, 'winddb', 'mysql-bin.002805', 524431355, '2020-03-31 15:36:17', '2020-03-31 16:14:50', '2020-03-31 16:14:51');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7843246, 'winddb', 'mysql-bin.002806', 433264814, '2020-03-31 16:14:53', '2020-03-31 16:24:42', '2020-03-31 16:24:45');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7843897, 'tdxdb', 'mysql-bin.000391', 28355501, '2020-03-31 16:19:04', '2020-03-31 17:07:34', '2020-03-31 17:25:51');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7844784, 'winddb', 'mysql-bin.002807', 527081750, '2020-03-31 16:25:04', '2020-03-31 17:19:10', '2020-03-31 17:19:11');
INSERT INTO binlog_pos_record (id, source_dbname, log_name, log_pos, insert_time, modify_time, complete_time) VALUES (7852262, 'winddb', 'mysql-bin.002808', 288427109, '2020-03-31 17:19:12', '2020-03-31 17:25:51', '2020-03-31 17:25:51');

[listen-zhou]

1. 发一下表结构
2. 根据binlog pos，使用mysql binlog工具找一下对应的数据，根据数据我分析一下

这个表主要记录处理binlog的进度，这个是源表，在白名单和黑名单中都没有设置这个表或者正则，遇到这个表，程序会解析出表名，当然字段也解析，报错应该是在遇到这个数据解析的时候异常了。

[listen-zhou]

我感觉不是新闻资讯数据导致的解析失败异常，因为我手动跳过之后，又重新触发新闻资讯表的binglog数据，可以正常解析，也就是说是这个表的解析卡住了

[listen-zhou]

1. 发一下表结构
2. 根据binlog pos，使用mysql binlog工具找一下对应的数据，根据数据我分析一下

#################################
2020-04-01 19:41:27.074 [Consumer-channel_000022] INFO h.a.f.b.BinlogAnalysisFieldsConsumer - ----------------------------------------------------------------
2020-04-01 19:41:27.217 [Provider-channel_000021] ERROR c.h.u.m.l.p.b.event.BaseRowEvent - parse column value error, maybe you add new column in middle of all columns
2020-04-01 19:41:27.217 [Consumer-channel_000022] INFO h.a.f.b.BinlogAnalysisFieldsConsumer - [hiriver-sample-fbdb-Prod][[START]]event prePosName[mysql-bin.000372:11794835] newPosName[mysql-bin.000372:11795341] [STD_NEWS_TRIGGER_LOG][2020-04-01 19:33:27]
2020-04-01 19:41:27.217 [Provider-channel_000021] ERROR c.h.u.m.l.p.d.MysqlStringUtils - 数组经过修正还是-拷贝下标越界异常start[170]end[165]len[-5]buf.length[165]
2020-04-01 19:41:27.217 [Provider-channel_000021] ERROR c.h.u.m.l.p.d.MysqlStringUtils - 数组经过修正还是-只能返回最后一个字符buf.length[165]error start[164]error end[165]
2020-04-01 19:41:27.217 [Provider-channel_000021] ERROR c.h.u.m.l.p.b.event.BaseRowEvent - parse column value error, maybe you add new column in middle of all columns
2020-04-01 19:41:27.217 [Provider-channel_000021] ERROR c.h.u.m.l.p.b.event.BaseRowEvent - parse column value error, maybe you add new column in middle of all columns
2020-04-01 19:41:27.220 [Provider-channel_000021] INFO c.h.c.s.impl.DefaultChannelStream - channelId is channel_0000,meet unknown error.
java.lang.ArrayIndexOutOfBoundsException: 1
#011at com.hiriver.unbiz.mysql.lib.protocol.binlog.event.BaseRowEvent.isNullInRow(BaseRowEvent.java:240)
#011at com.hiriver.unbiz.mysql.lib.protocol.binlog.event.BaseRowEvent.parseRow(BaseRowEvent.java:187)
#011at com.hiriver.unbiz.mysql.lib.protocol.binlog.event.RowEventV1.parseVerRowForUpdate(RowEventV1.java:37)
#011at com.hiriver.unbiz.mysql.lib.protocol.binlog.event.BaseRowEvent.parse(BaseRowEvent.java:148)
#011at com.hiriver.unbiz.mysql.lib.BinlogStreamBlockingTransportImpl.readEvent(BinlogStreamBlockingTransportImpl.java:363)
#011at com.hiriver.unbiz.mysql.lib.BinlogStreamBlockingTransportImpl.getBinlogOutputImmediately(BinlogStreamBlockingTransportImpl.java:256)
#011at com.hiriver.streamsource.impl.MysqlStreamSource.readValidInfo(MysqlStreamSource.java:52)
#011at com.hiriver.channel.stream.impl.DefaultChannelStream.providerThreadCore(DefaultChannelStream.java:263)
#011at com.hiriver.channel.stream.impl.DefaultChannelStream.access$000(DefaultChannelStream.java:45)
#011at com.hiriver.channel.stream.impl.DefaultChannelStream$2.run(DefaultChannelStream.java:232)
#011at java.lang.Thread.run(Thread.java:745)
2020-04-01 19:41:27.221 [Provider-channel_000021] INFO c.h.c.s.impl.DefaultChannelStream - load binlog position mysql-bin.000372:11795221 from mem,channelId is channel_0000.
2020-04-01 19:41:27.229 [Provider-channel_000021] INFO c.h.u.m.l.BinlogStreamBlockingTransportImpl - handshake success.
2020-04-01 19:41:27.236 [Provider-channel_000021] INFO c.h.u.m.l.TextProtocolBlockingTransportImpl - handshake success.
2020-04-01 19:41:27.236 [Provider-channel_000021] INFO c.h.u.m.l.TextProtocolBlockingTransportImpl - init SQL:SET AUTOCOMMIT=1
2020-04-01 19:41:27.241 [Provider-channel_000021] INFO c.h.u.m.l.BinlogStreamBlockingTransportImpl - read checksum CRC32 from db rds4886zqurmhz85pj9a.mysql.rds.aliyuncs.com:3306.
2020-04-01 19:41:27.243 [Provider-channel_000021] INFO c.h.u.m.l.BinlogStreamBlockingTransportImpl - set checkSum, result is 0.
2020-04-01 19:41:27.249 [Consumer-channel_000022] INFO h.a.f.b.BinlogAnalysisFieldsConsumer - [hiriver-sample-fbdb-Prod][[START]]event prePosName[mysql-bin.000372:11795341] newPosName[mysql-bin.000372:11795341]
###################################

CREATE TABLE std_news_trigger_log (
id BIGINT(20) NOT NULL AUTO_INCREMENT COMMENT '主键id',
table_name VARCHAR(100) NOT NULL COMMENT '表名',
data_id BIGINT(20) NOT NULL COMMENT '数据id',
trig_type VARCHAR(50) NOT NULL COMMENT '触发类型',
table_priority INT(11) NULL DEFAULT '1000' COMMENT '表处理优先级',
last_modified_dt TIMESTAMP NOT NULL DEFAULT CURRENT_TIMESTAMP COMMENT '记录时间戳',
PRIMARY KEY (id),
INDEX last_modified_dt (last_modified_dt),
INDEX table_priority (table_priority)
)
COMMENT='wind新闻数据触发器日志记录表'
COLLATE='utf8_general_ci'
ENGINE=InnoDB
AUTO_INCREMENT=67378044
;

我看了下，这个表目前没有数据，但是报了这个异常，目前统计的情况来看，导致异常出现的表，都不是我的业务表，在黑名单中没有加这个表，为了规避这个问题，我只能在黑名单中加入这些会导致异常的表。

[rolandhe]

找dba把出问题的binlog文件copy到你本地，使用LocalBinlogReader工具本地调试一下，找到出问题的binlog pos，没有数据很难定位问题