mysql jdbc内存溢出_20170718一次内存溢出排查经历

一、好言

熬得住就出众,熬不住就出局，相信糟糕得日志熬过去了，剩下得就是好运气 。

二、背景

上周一晚上十点多，就开始MQ消息累积然后报警，运维早上找我看，那些消息累积了，然后运维重启服务后消息就消费了，然后过一会又累积了，到上午十一点多的时候，开始报内存过高，然后发现已经又两台服务已经挂了，看了日志，有错误，但是没有很多可用的错误。所以重启，吃完饭服务又挂了，jconsole看到结果如下图：

jconsole-1.png

然后下午的时候内存的爆发简直更加频繁了

jsonsole-2

三：解决

3.1、内容

出现内存溢出问题，所以肯定首要需要dump内存溢出文件，所以先让运维导出*.hprof 文件，然后我也查看日志文件，我们使用kibana进行日志统计了，所以查看其中错误日志，的确又很多错误的信息，redis错误，MQ错误，还有mysql错误。

org.springframework.dao.QueryTimeoutException: Redis command timed out; nested exception is com.lambdaworks.redis.RedisCommandTimeoutException: Command timed out

at org.springframework.data.redis.connection.lettuce.LettuceExceptionC

onverter.convert(LettuceExceptionConverter.java:66)

at org.springframework.data.redis.connection.lettuce.LettuceExceptionC

onverter.convert(LettuceExceptionConverter.java:41)

at org.springframework.data.redis.PassThroughExceptionTranslationStr

ategy.translate(PassThroughExceptionTranslationStrategy.java:37)

[ActiveMQ Transport: tcp://mqtest.com/10.10.10.10:6161@123] org.apache.activemq.transport.failover.FailoverTransport - Transport (tcp://mqtest.com/10.10.10.10:6161) failed, attempting to automatically reconnect

java.io.IOException: Unexpected error occurred: java.lang.OutOfMemoryError: Java heap space

at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:222)

at java.lang.Thread.run(Thread.java:745)

Caused by: java.lang.OutOfMemoryError: Java heap space

如上两个认为是内存溢出了，造成没有内存可使用没法开线程处理。

看看下面mysql错误

### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackExceptio

n: Lock wait timeout exceeded; try restarting transaction

; SQL []; Lock wait timeout exceeded; try restarting transaction;

nested exception is

com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackExceptio

n: Lock wait timeout exceeded; try restarting transaction

at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTransl

ator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:259)

at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTran

slator.translate(AbstractFallbackSQLExceptionTranslator.java:73)

at org.mybatis.spring.MyBatisExceptionTranslator.translateExceptionIfP

ossible(MyBatisExceptionTranslator.java:74)

at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke

(SqlSessionTemplate.java:421)

at com.sun.proxy.$Proxy31.update(Unknown Source)

at org.mybatis.spring.SqlSessionTemplate.update(SqlSessionTemplate.j

ava:270)

at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:55)

at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:53)

at com.sun.proxy.$Proxy55.updateByPrimaryKey(Unknown

Source)

at com.mouse.moon.app.service.Userervice.update(

UserService.java:26)

at com.mouse.moon.app.service.Userervice$$FastClassBySpringCGLIB$$3eb1bfc8.invoke()

at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)

at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)

at org.springframework.transaction.interceptor.TransactionInterceptor$1.

proceedWithInvocation(TransactionInterceptor.java:99)

at org.springframework.transaction.interceptor.TransactionAspectSuppor

t.invokeWithinTransaction(TransactionAspectSupport.java:281)

at org.springframework.transaction.interceptor.TransactionInterceptor.inv

oke(TransactionInterceptor.java:96)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proc

eed(ReflectiveMethodInvocation.java:179)

at org.springframework.aop.framework.CglibAopProxy$DynamicAdvised

Interceptor.intercept(CglibAopProxy.java:655)

at com.mouse.moon.app.service.UserService$$EnhancerBySpringCGLIB$$31a8197.update()

at com.mouse.moon.app.service.userService.dealUser(MobileAppRegisterService.java:154)

at com.mouse.moon.app.service.UserService.(userService.java:104)

at com.mouse.moon.app.service.UserService$$FastClassBySpringCGLIB$$a99b8cf4.invoke()

at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)

at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)

at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)

at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)

at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)

at org.springframework.aop.interceptor.AsyncExecutionInterceptor$1.call(AsyncExecutionInterceptor.java:115)

at java.util.concurrent.FutureTask.run(FutureTask.java:262)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

at java.lang.Thread.run(Thread.java:745)

Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction

at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)

at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)

at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)

at java.lang.reflect.Constructor.newInstance(Constructor.java:526)

at com.mysql.jdbc.Util.handleNewInstance(Util.java:404)

at com.mysql.jdbc.Util.getInstance(Util.java:387)

at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:946)

at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3878)

at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3814)

at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2478)

at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2625)

at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2551)

at com.mysql.jdbc.MultiHostMySQLConnection.execSQL(MultiHostMySQLConnection.java:157)

at sun.reflect.GeneratedMethodAccessor306.invoke(Unknown Source)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:606)

at com.mysql.jdbc.LoadBalancedConnectionProxy.invokeMore(LoadBalancedConnectionProxy.java:484)

at com.mysql.jdbc.MultiHostConnectionProxy.invoke(MultiHostConnectionProxy.java:452)

at com.sun.proxy.$Proxy63.execSQL(Unknown Source)

at com.mysql.jdbc.MultiHostMySQLConnection.execSQL(MultiHostMySQLConnection.java:157)

at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861)

at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:1192)

at sun.reflect.GeneratedMethodAccessor314.invoke(Unknown Source)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:606)

at com.mysql.jdbc.MultiHostConnectionProxy$JdbcInterfaceProxy.invoke(MultiHostConnectionProxy.java:103)

at com.sun.proxy.$Proxy68.execute(Unknown Source)

这个地方的错误我在网上也搜过，其实基本是锁等待超时问题，这个一个同事之前遇到过，跟他交流了下，这个错误说明我的事物太大了，造成事物等待超时，并且有查处和更新相同数据造成的。这个现在想想这里代码的业务逻辑的确是存在这种问题，由于数据量大，如果按照现在的查询条件，地区会查询出相同数据，并且由于事物放在servicec层，在for循环中update数据的时候，会造成事物最后一起提交，所以造成锁等待超时问题。所以最后更新代码业务如下

1:对查询代码顺序做优化

List list = ...

if(符合条件){

list = ...(select ...where)

}

由于数据库数据量有4500w左右，上述代码先查询，然后再判断条件，所以有可能会查询两次数据库，所以代码优化，处理代码顺序，先判断条件。

2:对加在service的事物移动到dao层，每次更新一次提交一次，把事物缩小。

3:对于一些处理可以做异步处理

4:做限流操作(使用hystrix做限流)

5:对消费做消费速度限制

3.2:dump文件分析

由于之前系统是假死状态，每次冲上去之后，过十几分钟或者半小时后，可能又会慢慢回收。所以每次爆的时候并没有dump文件，脚本

每次没dump,最后我们在内存上升期间，只用使用

#查看内存

jmap -heap pid

jmap -dump:format=b,file=$dumpfile pid

图片.png

导出文件，查看如下

图1.png

上图是在没有处理完sql错误时倒出的hprof文件。

下图是处理完sql异常导出的文件

图2.png

图二我们可以看到一个很大的对象，就是我画红色的部分，点进去看，有三百多万个对象，占用内存三百多兆，并且我们看到老年代使用的量特别大，基本没回收样。怎么会有这么大的对象了，根据对象我们找到代码位置，确定是查询问题，造成大量对象产生，并且也是之前大量更新，并且数据有重复的概率，所以造成占用大量内存。其实这种发生也是要有数据量的情况下才会出现，发生溢出.

下面几张是检测到的日志信息数据：

log-1.png

log-2.png

log-3.png

最后简单总结下处理的过程，首先需要排除所有可能造成该问题的问题，也就是先解决掉看到的错误，然后查看导出dump文件中的大对象，根据大对象查看代码，进一步分析问题。其实在这个中间，做了很多各种处理看效果，比如MQ限流消费处理等。但是现在看来，最终原因应该还是出在数据库层面。

四：感触

其实之前没怎么解决过内存溢出问题，这算是自己第一次全程经历此次内存溢出并解决，不过首先说，这代码并不是我写的代码，是我被按排接手的项目，所以还的感谢这之前写这代码的人，才使得我有这么一次经历，通过这次经历，也会让自己对于一个内存溢出问题的解决思路更佳清晰，思考问题更佳全面，处理问题更佳稳重，并且对于一些工具的使用，比如MAT，Jprofile有了接触。所以有些经历真的是不可求的。因此才有了经验之说。努力吧，骚年。