简单做一下线上问题排查的记录。使用的Mysql引擎是 InnoDB 5.7。
###排查log
通过排查应用日志(只有其中一台机器),可以马上定位到问题是数据库连接池满了。具体日志如下:
2018-05-10 10:42:16.824 WARN 5 [xec-3303] SqlExceptionHelper SQL Error: 0, SQLState: null
2018-05-10 10:42:16.824 ERROR 5 [xec-3303] SqlExceptionHelper wait millis 5000, active 80, maxActive 80
2018-05-10 10:42:16.864 ERROR 5 [xec-3303] StorageOutputService Error Storage output create,createDTO:StorageOutputCreateDTO{...}.
org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction; nested exception is javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:431)
###排查db
通过查看DB的TPS以及连接池占用情况发现,DB的连接数并没有被占满,其他服务可以正常获取DB连接并正常运行。于是在排查具体问题之前,做的第一件事就是调整负载均衡,关闭该服务的流量,如果线上QPS以及其他机器负载不大的话,最好保留问题现场。同时对日志进行进核对(因为当时该微服务没有重要级写数据场景,所以没有再做数据核对,否则要进行数据校准)。
进一步排查。当时首先想到的是是否会存在死锁,导致大多数线程都对锁资源进行竞争。
查看innodb status(以下为展示用的测试环境数据):
$show engine innodb status
....
Per second averages calculated from the last 29 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 387668 srv_active, 0 srv_shutdown, 21764038 srv_idle
srv_master_thre