MySQL表加字段可为null导致ArrayIndexOutOfBoundsException报错问题记录

勤奋不是嘴上说说而已,而是实际的行动,在勤奋的苦度中持之以恒,永不退却。业精于勤,荒于嬉;行成于思,毁于随。在人生的仕途上,我们毫不迟疑地选择勤奋,她是几乎于世界上一切成就的催产婆。只要我们拥着勤奋去思考,拥着勤奋的手去耕耘,用抱勤奋的心去对待工作,浪迹红尘而坚韧不拔,那么,我们的生命就会绽放火花,让人生的时光更加的闪亮而精彩。

导读:本篇文章讲解 MySQL表加字段可为null导致ArrayIndexOutOfBoundsException报错问题记录,希望对大家有帮助,欢迎收藏,转发!站点地址:www.bmabk.com,来源:原文

问题爆出

企微群告警爆了,立即去看ELK报错日志,报错日志非常莫名其妙:java.lang.ArrayIndexOutOfBoundsException: 16

原因分析

事后发现共有18257次报错日志,时间跨度 19:09:24.331 – 19:19:20.332,如下截图所示:
在这里插入图片描述
这个时间点正好是让DBA操作执行DDL语句,表加字段:ALTER TABLE channel_advertiser_id ADD COLUMN stop_time timestamp default NULL COMMENT '账户关停时间' after status;

执行时间为19点9分21秒,执行耗时不过3秒,19点9分24秒就执行完成。
在这里插入图片描述
看到数据越界,思维会习惯性以为查询出重复的数据。于是查询表的总记录数为3235条,没有重复的数据。
在这里插入图片描述
可知,表的数据量非常少,但是是一个非常核心的业务主表。0.17s就有194次报错日志
在这里插入图片描述
ELK最早一条报错日志:

19:09:24.331 [SchedulerFactory_Worker-17] ERROR c.p.c.b.j.t.PutAdCreativeMaterialJob - PutAdCreativeMaterialJob error:org.springframework.dao.TransientDataAccessResourceException: 
### Error querying database.  Cause: java.sql.SQLException: java.lang.ArrayIndexOutOfBoundsException: 16
### The error may exist in URL [jar:file:/opt/app/octopus-backend.jar!/BOOT-INF/classes!/mybatisKraken/ChannelAdvertiserIdMapper.xml]
### The error may involve defaultParameterMap
### The error occurred while setting parameters
### SQL: select * from channel_advertiser_id where isactive = 1 and advertiser_id = ?
### Cause: java.sql.SQLException: java.lang.ArrayIndexOutOfBoundsException: 16
; SQL []; java.lang.ArrayIndexOutOfBoundsException: 16; nested exception is java.sql.SQLException: java.lang.ArrayIndexOutOfBoundsException: 16

至此还是莫名其妙,毫无头绪。

不过大体上的思路还是有的,无非是2个:

  1. 找日志
  2. Google

谛听(内部应用,类似于开源的SkyWalking)报错日志:
在这里插入图片描述

java.lang.ArrayIndexOutOfBoundsException: 16<MSG>16
java.sql.SQLException
	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:129)
	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97)
	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:89)
	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:63)
	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:73)
	at com.mysql.cj.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:441)
	at com.mysql.cj.jdbc.ClientPreparedStatement.execute$original$HSVORnno(ClientPreparedStatement.java:370)
	at com.mysql.cj.jdbc.ClientPreparedStatement.execute$original$HSVORnno$accessor$gSEmEInd(ClientPreparedStatement.java)
	at com.mysql.cj.jdbc.ClientPreparedStatement$auxiliary$ksqk50q8.call(Unknown Source)
	at org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.InstMethodsInter.intercept(InstMethodsInter.java:86)
	at com.mysql.cj.jdbc.ClientPreparedStatement.execute(ClientPreparedStatement.java)
	at com.mysql.cj.jdbc.ServerPreparedStatement.execute$accessor$mLgNCD2S(ServerPreparedStatement.java)
	at com.mysql.cj.jdbc.ServerPreparedStatement$auxiliary$3DrEHQTx.call(Unknown Source)
	at org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.InstMethodsInter.intercept(InstMethodsInter.java:86)
	at com.mysql.cj.jdbc.ServerPreparedStatement.execute(ServerPreparedStatement.java)
	at com.zaxxer.hikari.pool.ProxyPreparedStatement.execute(ProxyPreparedStatement.java:44)
	at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.execute(HikariProxyPreparedStatement.java)
	at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:63)
	at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:79)
	at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:63)
	at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:324)
	at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)
	at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109)
	at com.github.pagehelper.PageInterceptor.intercept(PageInterceptor.java:108)
	at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61)
	at com.sun.proxy.$Proxy437.query(Unknown Source)
	at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:148)
	at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:141)
	at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java:77)
	at sun.reflect.GeneratedMethodAccessor169.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:433)
	at com.sun.proxy.$Proxy138.selectOne(Unknown Source)
	at org.mybatis.spring.SqlSessionTemplate.selectOne(SqlSessionTemplate.java:166)
	at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:82)
	at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:59)
	at com.sun.proxy.$Proxy152.selectAdvertiserIdById(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor168.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
	at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:136)
	at org.springframework.aop.framework.ReflectiveMethodInvocation

同时也找到类似(不完全一样)的几个ArrayIndexOutOfBoundsException报错记录帖子,见参考。

看源码com.mysql.cj.jdbc.ServerPreparedStatement(有删减),简单分析:

protected <M extends Message> com.mysql.cj.jdbc.result.ResultSetInternalMethods executeInternal(int maxRowsToRetrieve, M sendPacket,
        boolean createStreamingResultSet, boolean queryIsSelectOnly, ColumnDefinition metadata, boolean isBatch) throws SQLException {
    synchronized (checkClosed().getConnectionMutex()) {
        ((PreparedQuery<?>) this.query).getQueryBindings()
                .setNumberOfExecutions(((PreparedQuery<?>) this.query).getQueryBindings().getNumberOfExecutions() + 1);

        // We defer to server-side execution
        try {
            return serverExecute(maxRowsToRetrieve, createStreamingResultSet, metadata);
        } catch (Exception ex) {
            if (this.session.getPropertySet().getBooleanProperty(PropertyKey.enablePacketDebug).getValue()) {
                this.session.dumpPacketRingBuffer();
            }
			// 报错441行
            SQLException sqlEx = SQLError.createSQLException(ex.toString(), MysqlErrorNumbers.SQL_STATE_GENERAL_ERROR, ex, this.exceptionInterceptor);

            if (this.dumpQueriesOnException.getValue()) {
                String extractedSql = toString();
                StringBuilder messageBuf = new StringBuilder(extractedSql.length() + 32);
                messageBuf.append("\n\nQuery being executed when exception was thrown:\n");
                messageBuf.append(extractedSql);
                messageBuf.append("\n\n");
                sqlEx = appendMessageToException(sqlEx, messageBuf.toString(), this.exceptionInterceptor);
            }
            throw sqlEx;
        }
    }
}

执行return serverExecute(maxRowsToRetrieve, createStreamingResultSet, metadata);时抛错,ServerPreparedStatement.serverExecute方法

protected ResultSetInternalMethods serverExecute(int maxRowsToRetrieve, boolean createStreamingResultSet, ColumnDefinition metadata) throws SQLException {
    synchronized (checkClosed().getConnectionMutex()) {
        this.results = ((ServerPreparedQuery) this.query).serverExecute(maxRowsToRetrieve, createStreamingResultSet, metadata, this.resultSetFactory);
        return this.results;
    }
}

ServerPreparedQuery.serverExecute方法

public <T extends Resultset> T serverExecute(int maxRowsToRetrieve, boolean createStreamingResultSet, ColumnDefinition metadata,
    ProtocolEntityFactory<T, NativePacketPayload> resultSetFactory) {
    if (this.session.shouldIntercept()) {
        T interceptedResults = this.session.invokeQueryInterceptorsPre(() -> {
            return getOriginalSql();
        }, this, true);

        if (interceptedResults != null) {
            return interceptedResults;
        }
    }
    String queryAsString = this.profileSQL || this.logSlowQueries || this.gatherPerfMetrics ? asSql(true) : "";

    NativePacketPayload packet = prepareExecutePacket();
    NativePacketPayload resPacket = sendExecutePacket(packet, queryAsString);
    T rs = readExecuteResult(resPacket, maxRowsToRetrieve, createStreamingResultSet, metadata, resultSetFactory, queryAsString);

    return rs;
}

执行查询时,需要使用到session。而加字段后,session信息发生变更?

另外从源码搜索反向分析,找到ArrayIndexOutOfBoundsException可能出现在NativeServerSession类里面:
在这里插入图片描述
能力有限,只能分析到这个地步。

另外,报错的数据越界的数字也是有讲究的,看一下表的定义(注释省去,字段名字母有删减):

create table channel_advertiser_id (
    id          int auto_increment primary key,
    adv_id      varchar(100)                         null,
    aer_name    varchar(100)                         null comment '',
    adve_name   varchar(100)                         null comment '',
    cha_id      text                                 null comment '',
    cor_id      int                                  null comment '',
    use_id      int                                  null comment '',
    isactive    tinyint(1)                           not null,
    insert_time timestamp  default CURRENT_TIMESTAMP not null,
    update_time timestamp  default CURRENT_TIMESTAMP not null on update CURRENT_TIMESTAMP,
    updateby    varchar(100)                         null comment '',
    isot        int(5)     default 2                 not null comment '',
    status      int(5)     default 1                 not null comment '',
    stop_time   timestamp                            null comment '账户关停时间',
    advd_id     varchar(50)                          null comment '',
    is_ew       tinyint(1) default 0                 null comment '',
    cony        varchar(100)                         null
) charset = utf8;

发布前16个字段,发布后17个字段。

注:mysql-connector-java版本为8.0.22,

反思

假使按照规范,DBA是21点(整点)执行DDL语句。虽然DBA不一定会卡整点执行。但是生产上很多跑批任务大多数都是整点或者半点执行的。19点10分有1.8w次报错。那21点多执行,虽然不是业务使用高峰期,那还是会有这个问题???

参考

版权声明:本文内容由互联网用户自发贡献,该文观点仅代表作者本人。本站仅提供信息存储空间服务,不拥有所有权,不承担相关法律责任。如发现本站有涉嫌侵权/违法违规的内容, 请发送邮件至 举报,一经查实,本站将立刻删除。

文章由极客之音整理,本文链接:https://www.bmabk.com/index.php/post/142116.html

(0)
飞熊的头像飞熊bm

相关推荐

发表回复

登录后才能评论
极客之音——专业性很强的中文编程技术网站,欢迎收藏到浏览器,订阅我们!