问题描述

收到error日志告警,出现多条下列错误日志

[2021-02-03 16:55:32.469][ERROR][http-nio-8249-exec-44][com.jiu.common.online.exception.GlobalExceptionHandler][127.0.0.1][[]请求异常：/merchant/cashierArea/listCashiierAreaorg.mybatis.spring.MyBatisSystemException: nested exception is org.apache.ibatis.exceptions.PersistenceException: ### Error querying database. 
Cause: java.lang.IndexOutOfBoundsException: Index: 1, Size: 0 ### The error may exist in class path resource [mapper/zx_business_machine/HsyCashierAreaMapper.xml] ### The error may involve defaultParameterMap ### The error occurred while setting parameters ### SQL: select F_id, F_cashier_area_no, F_cashier_area_name, F_merchant_id, F_create_time, F_update_time from t_hsy_cashier_area where f_merchant_id = ? order by f_create_time desc limit ?,? ### 
Cause: java.lang.IndexOutOfBoundsException: Index: 1, Size: 0 
    at org.mybatis.spring.MyBatisExceptionTranslator.translateExceptionIfPossible(MyBatisExceptionTranslator.java:77) 
    at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:446) 
    at com.sun.proxy.$Proxy142.selectList(Unknown Source) 
    at org.mybatis.spring.SqlSessionTemplate.selectList(SqlSessionTemplate.java:230) 
    at org.apache.ibatis.binding.MapperMethod.executeForMany(MapperMethod.java:144) 
    at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:77) 
    at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:58) 
    at com.sun.proxy.$Proxy173.listCashierAreaByMerchantId(Unknown Source) 
    at com.jiu.online.machine.hsy.service.impl.CashierAreaServiceImpl.listCashierArea(CashierAreaServiceImpl.java:310) 
    at com.jiu.online.machine.hsy.service.impl.CashierAreaServiceImpl$$FastClassBySpringCGLIB$$4cc36c10.invoke() 
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) 
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:684) 
    at com.jiu.online.machine.hsy.service.impl.CashierAreaServiceImpl$$EnhancerBySpringCGLIB$$f7bc53d8.listCashierArea() 
    at com.jiu.online.machine.hsy.controller.CashierAreaController.listCashierArea(CashierAreaController.java:114) 
    at sun.reflect.GeneratedMethodAccessor513.invoke(Unknown Source) 
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) 
    at java.lang.reflect.Method.invoke(Method.java:498) 
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:209) 
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136) 
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:102) 
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:877) 
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:783) 
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) 
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:991) 
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:925) 
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:974) 
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:877) 
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:661) 
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:851) 
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) 
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) 
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) 
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) 
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) 
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) 
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:158) 
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:126) 
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:111) 
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) 
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) 
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) 
    at com.jiu.online.machine.hsy.filter.SessionFilter.doFilter(SessionFilter.java:49) 
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) 
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) 
    at org.springframework.boot.actuate.web.trace.servlet.HttpTraceFilter.doFilterInternal(HttpTraceFilter.java:90) 
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) 
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) 
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) 
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) 
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) 
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) 
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) 
    at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:109) 
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) 
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) 
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) 
    at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93) 
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) 
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) 
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) 
    at org.springframework.cloud.sleuth.instrument.web.ExceptionLoggingFilter.doFilter(ExceptionLoggingFilter.java:48) 
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) 
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) 
    at brave.servlet.TracingFilter.doFilter(TracingFilter.java:86) 
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) 
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) 
    at com.jiu.common.online.filter.MonitorFilter.doFilter(MonitorFilter.java:54) 
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) 
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) 
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200) 
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) 
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) 
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) 
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) 
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) 
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:496) 
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) 
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) 
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) 
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) 
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:803) 
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) 
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:790) 
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1468) 
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) 
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) 
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) 
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) 
    at java.lang.Thread.run(Thread.java:748) 
Caused by: org.apache.ibatis.exceptions.PersistenceException: ### Error querying database. 
Cause: java.lang.IndexOutOfBoundsException: Index: 1, Size: 0 ### The error may exist in class path resource [mapper/zx_business_machine/HsyCashierAreaMapper.xml] ### The error may involve defaultParameterMap ### The error occurred while setting parameters ### SQL: select F_id, F_cashier_area_no, F_cashier_area_name, F_merchant_id, F_create_time, F_update_time from t_hsy_cashier_area where f_merchant_id = ? order by f_create_time desc limit ?,? ### 
Cause: java.lang.IndexOutOfBoundsException: Index: 1, Size: 0 
    at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30) 
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:150) 
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:141) 
    at sun.reflect.GeneratedMethodAccessor373.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) ... 87 common frames omitted 
Caused by: java.lang.IndexOutOfBoundsException: Index: 1, Size: 0 
    at java.util.ArrayList.rangeCheck(ArrayList.java:653) 
    at java.util.ArrayList.get(ArrayList.java:429) 
    at com.dangdang.ddframe.rdb.sharding.jdbc.util.ParameterList.set(ParameterList.java:82) 
    at com.dangdang.ddframe.rdb.sharding.parser.result.merger.Limit.replaceParameters(Limit.java:71) 
    at com.dangdang.ddframe.rdb.sharding.router.SQLRouteEngine.routeSQL(SQLRouteEngine.java:105) 
    at com.dangdang.ddframe.rdb.sharding.router.PreparedSQLRouter.route(PreparedSQLRouter.java:56) 
    at com.dangdang.ddframe.rdb.sharding.jdbc.ShardingPreparedStatement.routeSQL(ShardingPreparedStatement.java:162) 
    at com.dangdang.ddframe.rdb.sharding.jdbc.ShardingPreparedStatement.execute(ShardingPreparedStatement.java:112) 
    at sun.reflect.GeneratedMethodAccessor242.invoke(Unknown Source) 
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) 
    at java.lang.reflect.Method.invoke(Method.java:498) 
    at org.apache.ibatis.logging.jdbc.PreparedStatementLogger.invoke(PreparedStatementLogger.java:59) 
    at com.sun.proxy.$Proxy256.execute(Unknown Source) 
    at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:64) 
    at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:79) 
    at sun.reflect.GeneratedMethodAccessor241.invoke(Unknown Source) 
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) 
    at java.lang.reflect.Method.invoke(Method.java:498) 
    at org.apache.ibatis.plugin.Invocation.proceed(Invocation.java:49) 
    at com.jiu.online.machine.hsy.filter.SqlExecuteTimeCountInterceptor.intercept(SqlExecuteTimeCountInterceptor.java:53) 
    at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61) 
    at com.sun.proxy.$Proxy254.query(Unknown Source) 
    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.BaseExecutor.query(BaseExecutor.java:136) 
    at sun.reflect.GeneratedMethodAccessor236.invoke(Unknown Source) 
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) 
    at java.lang.reflect.Method.invoke(Method.java:498) 
    at org.apache.ibatis.plugin.Invocation.proceed(Invocation.java:49) 
    at com.jiu.common.core.persistence.interceptor.PaginationInterceptor.intercept(PaginationInterceptor.java:74) 
    at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61) 
    at com.sun.proxy.$Proxy253.query(Unknown Source) 
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:148) ... 92 common frames omitted ]

原因分析

根据异常栈信息,初步定为是sharding框架代码抛的下标越界异常

image.png

Cause: java.lang.IndexOutOfBoundsException: Index: 1, Size: 0
说明此时jdbcMethodInvocations这个list为空,但参数index传了1
初步判断是由于并发导致的

经过一番折腾,最终确定是由于并发情况下,框架出现了线程安全问题.且复现出现概率也蛮高的
复现演示图如下:

sharding1bug.gif

原因分析:

• testThread-0线程和testThread-1线程对应的jdbcMethodInvocations对象竟然是同一个(但未定位到该原因,初步判断是由于本地缓存的原因)

• 在执行完语句后,有个clearRouteContext的方法会clear这个list

  
  
  image.png

• 在并发情况下,由于ArrayList非线程安全,可能导致上述问题

解决方案

• 目前由于历史原因,用了sharding-jdbc1.3.3这一早期的版本,框架出现了问题,优先考虑升级,考虑升级至4.0.0-RC3版本
• 经过测试以及查阅资料,该版本未出现问题
• 线上采取灰度升级版本.逐步将部门所有项目的sharding-jdbc框架进行了升级

另外,sharding-jdbc 1.x这一古老版本和4.x版本存在很多不同,包括包名,分片接口,命名空间方式对应的标签等,着实也折腾得够呛(估计和被apache收购有关).具体的一些不同也可以参考我的另一篇文档
https://www.jianshu.com/p/39830e1ccf9b

总结

对于技术选型以及版本的选择真的要重视,一定是经过相关调研才敲定.像项目中竟然采用这么古老的版本实在不应该