项目场景:
多线程处理数据推送:有A和B两张表,A表是MySQL连接,B表是Mycat连接,各有200张分表,A和B联查拼接数据推送其他系统使用。当前方案是A表1-200分表逐个分页读取数据,拿到id集合去B表的逻辑表查询,拼接数据。
问题描述
将分页大小调整为1000,程序跑了一段时间后报错,具体报错如下,后来又将分页大小调小,没有报错,然后调整为5000,程序运行时间大大减少并报错。
[2022-07-20 16:36:30.723] [公共区数据查询线程781294] [WARN ] com.zaxxer.hikari.pool.ProxyConnection - HikariPool-1 - Connection com.mysql.cj.jdbc.ConnectionImpl@552074cf marked as broken because of SQLSTATE(08S01), ErrorCode(0)
com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure
The last packet successfully received from the server was 1,882 milliseconds ago. The last packet sent successfully to the server was 1,883 milliseconds ago.
at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:174)
at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64)
at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:953)
at com.mysql.cj.jdbc.ClientPreparedStatement.execute(ClientPreparedStatement.java:370)
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:325)
at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)
at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109)
at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:83)
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:148)
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:141)
at sun.reflect.GeneratedMethodAccessor34.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:434)
at com.sun.proxy.$Proxy54.selectList(Unknown Source)
at org.mybatis.spring.SqlSessionTemplate.selectList(SqlSessionTemplate.java:231)
at org.apache.ibatis.binding.MapperMethod.executeForMany(MapperMethod.java:128)
at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:68)
at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:53)
at com.sun.proxy.$Proxy58.querySource(Unknown Source)
at gov.zwfw.iam.datacutover.service.impl.NaturalServiceImpl.moveData(NaturalServiceImpl.java:63)
at gov.zwfw.iam.datacutover.thread.NaturalDataThread.run(NaturalDataThread.java:43)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: com.mysql.cj.exceptions.CJCommunicationsException: Communications link failure
原因分析:
开始出现这个问题,我从navicat查询了一下sql的状态,SHOW FULL PROCESSLIST;
发现大部分sql的state为Waiting for query cache lock
,
于是搜索这个问题,发现是查询缓存的问题,然后根据show status like '%Qcache%';
查询缓存的相关信息,如下
根据show variables like '%query_cache%';
查询缓存设置
查询相关文档后,关闭了查询缓存,进入mysql的my.cnf文件,设置下面两个属性
一通操作下来,重新启动程序,sql状态倒是没问题了,但是,过了一段时间后还是报错,只不过这个时间长了一点,于是,再次查询这个问题,有些文档说是空闲连接的超时时间超过了mysql连接的时间,于是,查询mysql的连接超时时间,show global variables like "wait_timeout";
最开始是3000,然后我又设置了超时时间为默认的8小时,即28800,set global wait_timeout=28800;
注意这个操作一定要在MySQL连接下进行,或者直接修改my.cnf文件
同时,在程序配置上设置了如下配置
validationQuery: SELECT 1
testWhileIdle: true
timeBetweenEvictionRunsMillis: 28000
然后重启程序,过了一段时间,报错。。。。。。。。。。。。。
这通操作下来,已经浪费了我一天的时间了,再搞不好就要被骂了,痛定思痛,忽然想到,这里一直是mycat连接报错啊,然后看了下日志,发现console.log日志会在程序报错后报oom,是不是mycat的设置有问题,于是,打开了mycat的配置,查看wrapper.conf文件,发现有一个直接内存配置为2g,然后突发奇想把这个加大试试呢,改成了8g,这次,程序运行的时间更长了,但是最终依然报错
然后我看了一下mycat的日志,运行日志一直在刷sql,这时,凭借我的火眼金睛发现了问题
在逻辑表执行一条sql,是要到每个分片表去执行一次的,好死不死的我这里用了in去查询,这时我心里大概明白了,由于数据量加大,查询变慢,没有连接造成了mycat假死,这也是为什么分页大小调小就没事,而且报错后重启mycat还能正常运行。
解决方案:
将mycat查询时候的in范围查询改成了等值查询,这样,虽然每次都要去循环查库,但是好歹程序跑起来了,循环查询的性能也比之前的in范围查询快了很多,同时,分页大小也可以设置较大的值,问题解决。