一、好言
熬得住就出眾,熬不住就出局关串，相信糟糕得日志熬過去了拧廊，剩下得就是好運氣 。
二晋修、背景
上周一晚上十點多吧碾，就開始MQ消息累積然后報警，運維早上找我看墓卦，那些消息累積了倦春，然后運維重啟服務(wù)后消息就消費了，然后過一會又累積了落剪，到上午十一點多的時候睁本，開始報內(nèi)存過高，然后發(fā)現(xiàn)已經(jīng)又兩臺服務(wù)已經(jīng)掛了忠怖，看了日志呢堰，有錯誤，但是沒有很多可用的錯誤凡泣。所以重啟枉疼，吃完飯服務(wù)又掛了，jconsole看到結(jié)果如下圖：
jconsole-1.png
然后下午的時候內(nèi)存的爆發(fā)簡直更加頻繁了
jsonsole-2
三：解決
3.1鞋拟、內(nèi)容
出現(xiàn)內(nèi)存溢出問題骂维，所以肯定首要需要dump內(nèi)存溢出文件，所以先讓運維導(dǎo)出*.hprof 文件贺纲，然后我也查看日志文件航闺，我們使用kibana進行日志統(tǒng)計了，所以查看其中錯誤日志猴誊，的確又很多錯誤的信息潦刃，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
如上兩個認(rèn)為是內(nèi)存溢出了萝毛，造成沒有內(nèi)存可使用沒法開線程處理项阴。
看看下面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(<generated>)
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(<generated>)
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(<generated>)
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)
這個地方的錯誤我在網(wǎng)上也搜過，其實基本是鎖等待超時問題，這個一個同事之前遇到過环揽，跟他交流了下略荡，這個錯誤說明我的事物太大了，造成事物等待超時歉胶，并且有查處和更新相同數(shù)據(jù)造成的汛兜。這個現(xiàn)在想想這里代碼的業(yè)務(wù)邏輯的確是存在這種問題，由于數(shù)據(jù)量大通今，如果按照現(xiàn)在的查詢條件粥谬，地區(qū)會查詢出相同數(shù)據(jù)，并且由于事物放在servicec層辫塌，在for循環(huán)中update數(shù)據(jù)的時候漏策，會造成事物最后一起提交，所以造成鎖等待超時問題臼氨。所以最后更新代碼業(yè)務(wù)如下
1:對查詢代碼順序做優(yōu)化
List list = ...
if(符合條件){
list = ...(select ...where)
}
由于數(shù)據(jù)庫數(shù)據(jù)量有4500w左右掺喻，上述代碼先查詢，然后再判斷條件储矩，所以有可能會查詢兩次數(shù)據(jù)庫感耙，所以代碼優(yōu)化，處理代碼順序持隧，先判斷條件即硼。
2:對加在service的事物移動到dao層，每次更新一次提交一次屡拨，把事物縮小谦絮。
3:對于一些處理可以做異步處理
4:做限流操作(使用hystrix做限流)
5:<a href ="http://www.reibang.com/p/82c27c58e0b6">對消費做消費速度限制</a>
3.2:dump文件分析
由于之前系統(tǒng)是假死狀態(tài)，每次沖上去之后洁仗，過十幾分鐘或者半小時后层皱，可能又會慢慢回收。所以每次爆的時候并沒有dump文件赠潦，<a href="http://www.reibang.com/p/05e9f46e3f09">腳本</a>
每次沒dump,最后我們在內(nèi)存上升期間叫胖，只用使用
#查看內(nèi)存
jmap -heap pid
jmap -dump:format=b,file=$dumpfile pid
圖片.png
導(dǎo)出文件，查看如下
圖1.png
上圖是在沒有處理完sql錯誤時倒出的hprof文件她奥。
下圖是處理完sql異常導(dǎo)出的文件
圖2.png
圖二我們可以看到一個很大的對象瓮增，就是我畫紅色的部分，點進去看哩俭，有三百多萬個對象绷跑，占用內(nèi)存三百多兆，并且我們看到老年代使用的量特別大凡资，基本沒回收樣砸捏。怎么會有這么大的對象了，根據(jù)對象我們找到代碼位置，確定是查詢問題垦藏，造成大量對象產(chǎn)生梆暖，并且也是之前大量更新，并且數(shù)據(jù)有重復(fù)的概率掂骏，所以造成占用大量內(nèi)存轰驳。其實這種發(fā)生也是要有數(shù)據(jù)量的情況下才會出現(xiàn)，發(fā)生溢出.
下面幾張是檢測到的日志信息數(shù)據(jù)：
log-1.png
log-2.png
log-3.png
最后簡單總結(jié)下處理的過程弟灼，首先需要排除所有可能造成該問題的問題级解，也就是先解決掉看到的錯誤，然后查看導(dǎo)出dump文件中的大對象田绑，根據(jù)大對象查看代碼蠕趁，進一步分析問題。其實在這個中間辛馆，做了很多各種處理看效果俺陋，比如MQ限流消費處理等。但是現(xiàn)在看來昙篙，最終原因應(yīng)該還是出在數(shù)據(jù)庫層面腊状。
四：感觸
其實之前沒怎么解決過內(nèi)存溢出問題，這算是自己第一次全程經(jīng)歷此次內(nèi)存溢出并解決苔可，不過首先說缴挖，這代碼并不是我寫的代碼，是我被按排接手的項目焚辅，所以還的感謝這之前寫這代碼的人映屋，才使得我有這么一次經(jīng)歷，通過這次經(jīng)歷同蜻，也會讓自己對于一個內(nèi)存溢出問題的解決思路更佳清晰棚点，思考問題更佳全面，處理問題更佳穩(wěn)重湾蔓，并且對于一些工具的使用瘫析，比如MAT，Jprofile有了接觸默责。所以有些經(jīng)歷真的是不可求的贬循。因此才有了經(jīng)驗之說。努力吧桃序，騷年杖虾。
