記一次網絡緣由致使的mysql鏈接中斷問題(druid)

時間  2019-12-11
標籤 一次 網絡 緣由 致使 mysql 鏈接 中斷 問題 druid 欄目 系統網絡 简体版
原文   原文鏈接
  • date: 2018-04-19 21:00
  • tag: java,mysql,exception,mat,調試,jvm
  • 工具: gceasy.io, MAT

線上系統出現一個詭異的bug，經過heap dump分析java

  • 分析:
  1. 經過日誌確認系統在一天前就已經中止運行
  2. 代碼較簡單應該不存在DB寫入操做死鎖
  3. mysql操做不是特別頻繁
  • 定位:
  1. 使用jmap -dump導出線上的應用的heap dump
  2. jstack 導出堆棧信息
  3. 分析jstack發現多個Thread在DB寫入時在等待同一把鎖
  4. 經過MAT分析dump
  5. 經過OQL在MAT中定位上面出現的鎖住多個Thread的鎖對象
  6. 經過分析發現鎖對象的全部者是阿里druid線程池的com.alibaba.druid.pool.DruidDataSource
  7. 在IDE中查看DruidDataSource的源碼發現幾個關鍵屬性: poolingCount, errorCount, destroyCount, lastError
  8. google搜索lastError的描述Communications link failure, 獲得多是網絡緣由致使的mysql鏈接關閉
  9. 在MAT中查看poolingCount, errorCount, destroyCount屬性的值發現與上述結論一致
  10. 重啓應用，問題消失
  • 思考:
  1. 爲何Druid線程池沒有嘗試從新鏈接?
  2. 須要優化日誌，提升排查效率
  3. 增長必要的Metric和預警規則
  • 程序假死時的heap dump:
OQL:
 SELECT s.poolingCount,
 s.errorCount.toString() AS errorCount,
 s.destroyCount.toString() AS destroyCount,
 s.createCount.toString() AS createCount,
 s.lastError.exceptionMessage.toString()
 FROM com.alibaba.druid.pool.DruidDataSource s 
結果:
 s.poolingCount |errorCount|destroyCount|createCount|s.lastError.exceptionMessage.toString()
---------------------------------------------------------------------------------------------------------------------------------------------
              0 |10        |7           |17         |Communications link failure\u000a\u000aLast packet sent to the server was 180289 ms ago.
---------------------------------------------------------------------------------------------------------------------------------------------

s.connections:
結果:
Type|Name|Value
---------------
ref |[0] |null
ref |[1] |null
ref |[2] |null
ref |[3] |null
ref |[4] |null
ref |[5] |null
ref |[6] |null
ref |[7] |null
---------------
  • 正常運行時候的core dump:
OQL:
 SELECT s.poolingCount,
 s.errorCount.toString() AS errorCount,
 s.destroyCount.toString() AS destroyCount,
 s.createCount.toString() AS createCount,
 s.lastError.exceptionMessage.toString()
 FROM com.alibaba.druid.pool.DruidDataSource s 
結果:
 s.poolingCount |errorCount|destroyCount|createCount|s.lastError.exceptionMessage.toString()
--------------------------------------------------------------------------------------------
              1 |1         |0           |4          |
--------------------------------------------------------------------------------------------

s.connections:
結果:
Type|Name|Value
-------------------------------------------------------------------
ref |[0] |com.alibaba.druid.pool.DruidConnectionHolder @ 0xc5fb1958
ref |[1] |null
ref |[2] |null
ref |[3] |null
ref |[4] |null
ref |[5] |null
ref |[6] |null
ref |[7] |null
-------------------------------------------------------------------
  • 日誌文件中的異常堆棧:
org.springframework.dao.RecoverableDataAccessException: 
### Error querying database.  Cause: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

Last packet sent to the server was 655505 ms ago.
### The error may exist in class path resource [mapper/ConfigMapper.xml]
### The error may involve com.myserver1.crawler.dao.ConfigDao.selectAllByType-Inline
### The error occurred while setting parameters
### SQL: select           id, type, props, content, status, create_time, update_time         from config     where     type = ?     and status = 1
### Cause: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

Last packet sent to the server was 655505 ms ago.
; SQL []; Communications link failure

Last packet sent to the server was 655505 ms ago.; nested exception is com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

Last packet sent to the server was 655505 ms ago.
        at org.springframework.jdbc.support.SQLExceptionSubclassTranslator.doTranslate(SQLExceptionSubclassTranslator.java:98) ~[spring-jdbc-4.3.6.RELEASE.jar!/:4.3.6.RELEASE]
        at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:73) ~[spring-jdbc-4.3.6.RELEASE.jar!/:4.3.6.RELEASE]
        at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:81) ~[spring-jdbc-4.3.6.RELEASE.jar!/:4.3.6.RELEASE]
        at org.mybatis.spring.MyBatisExceptionTranslator.translateExceptionIfPossible(MyBatisExceptionTranslator.java:74) ~[mybatis-spring-1.2.3.jar!/:1.2.3]
        at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:399) ~[mybatis-spring-1.2.3.jar!/:1.2.3]
        at com.sun.proxy.$Proxy60.selectList(Unknown Source) ~[?:?]
        at org.mybatis.spring.SqlSessionTemplate.selectList(SqlSessionTemplate.java:205) ~[mybatis-spring-1.2.3.jar!/:1.2.3]
        at com.myserver1.crawler.dao.ConfigDao.selectAllByType(ConfigDao.java:27) ~[classes!/:1.0-SNAPSHOT]
        at com.myserver1.crawler.dao.ConfigDao$$FastClassBySpringCGLIB$$98d41dde.invoke(<generated>) ~[classes!/:1.0-SNAPSHOT]
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[spring-core-4.3.6.RELEASE.jar!/:4.3.6.RELEASE]
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:721) ~[spring-aop-4.3.6.RELEASE.jar!/:4.3.6.RELEASE]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) ~[spring-aop-4.3.6.RELEASE.jar!/:4.3.6.RELEASE]
        at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:136) ~[spring-tx-4.3.6.RELEASE.jar!/:4.3.6.RELEAS
E]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.3.6.RELEASE.jar!/:4.3.6.RELEASE]
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:656) ~[spring-aop-4.3.6.RELEASE.jar!/:4.3.6.RELEASE]
        at com.myserver1.crawler.dao.ConfigDao$$EnhancerBySpringCGLIB$$c890af99.selectAllByType(<generated>) ~[classes!/:1.0-SNAPSHOT]
        at com.myserver1.event.VideoItemListener.post(VideoItemListener.java:32) ~[classes!/:1.0-SNAPSHOT]
        at com.myserver1.event.EventBus.push(EventBus.java:28) [classes!/:1.0-SNAPSHOT]
        at com.myserver1.crawler.site.ABreadthCrawler.start(ABreadthCrawler.java:97) [classes!/:1.0-SNAPSHOT]
        at com.myserver1.event.QueueThread.run(QueueThread.java:41) [classes!/:1.0-SNAPSHOT]
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

Last packet sent to the server was 655505 ms ago.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:1.8.0_101]
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[?:1.8.0_101]
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:1.8.0_101]
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[?:1.8.0_101]
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:406) ~[mysql-connector-java-5.1.6.jar!/:?]
        at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1074) ~[mysql-connector-java-5.1.6.jar!/:?]
        at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3246) ~[mysql-connector-java-5.1.6.jar!/:?]
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1917) ~[mysql-connector-java-5.1.6.jar!/:?]
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2060) ~[mysql-connector-java-5.1.6.jar!/:?]
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2542) ~[mysql-connector-java-5.1.6.jar!/:?]
        at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1734) ~[mysql-connector-java-5.1.6.jar!/:?]
        at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:995) ~[mysql-connector-java-5.1.6.jar!/:?]
        at com.alibaba.druid.pool.DruidPooledPreparedStatement.execute(DruidPooledPreparedStatement.java:477) ~[druid-0.2.9.jar!/:0.2.9]
        at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:62) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:78) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:62) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:303) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:154) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:102) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:82) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:120) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:113) ~[mybatis-3.3.0.jar!/:3.3.0]
        at sun.reflect.GeneratedMethodAccessor81.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_101]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_101]
        at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:386) ~[mybatis-spring-1.2.3.jar!/:1.2.3]
        ... 15 more
Caused by: java.net.SocketException: Connection reset
        at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113) ~[?:1.8.0_101]
        at java.net.SocketOutputStream.write(SocketOutputStream.java:153) ~[?:1.8.0_101]
        at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82) ~[?:1.8.0_101]
        at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140) ~[?:1.8.0_101]
        at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3227) ~[mysql-connector-java-5.1.6.jar!/:?]
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1917) ~[mysql-connector-java-5.1.6.jar!/:?]
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2060) ~[mysql-connector-java-5.1.6.jar!/:?]
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2542) ~[mysql-connector-java-5.1.6.jar!/:?]
        at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1734) ~[mysql-connector-java-5.1.6.jar!/:?]
        at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:995) ~[mysql-connector-java-5.1.6.jar!/:?]
        at com.alibaba.druid.pool.DruidPooledPreparedStatement.execute(DruidPooledPreparedStatement.java:477) ~[druid-0.2.9.jar!/:0.2.9]
        at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:62) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:78) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:62) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:303) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:154) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:102) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:82) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:120) ~[mybatis-3.3.0.jar!/:3.3.0]
        at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:113) ~[mybatis-3.3.0.jar!/:3.3.0]
        at sun.reflect.GeneratedMethodAccessor81.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_101]
相關文章
相關標籤/搜索
每日一句
    每一个你不满意的现在，都有一个你没有努力的曾经。
本站公眾號
   歡迎關注本站公眾號,獲取更多信息
聯繫我們 最近搜索 最新文章 沪ICP备13005482号-10 MyBatis教程 SQL 教程 MySQL教程 Java 教程 Thymeleaf 教程 Hibernate教程 Spring教程 Redis教程