我有一个反复出现的间歇性问题,我的 Spring JPA/Hibernate 应用程序(在 Tomcat 8 上运行)在 setAutoCommit 阶段尝试从 MySQL 读取时会挂起 5-30 秒。这发生在我们运行 MySQL 5.0 时,并且在升级到最新的 MariaDB 后仍然存在。
问题可能几天或几周都不会出现,但一旦出现,通常是在下午,也就是周一到周四,也就是我们的“高峰”时段。 (这里的“峰值”真的很轻,每秒可能有 10 个请求。)奇怪的是,问题经常发生在 14:50,尽管我找不到任何会导致此问题的 cronjobs 或其他重复性任务。
该应用程序集群在两台服务器上,两台服务器在尝试连接到共享数据库服务器时同时挂起,所以它似乎是数据库方面的问题。数据库允许 1000 个 max_connections,但使用的数量远没有那么多。在 Tomcat 方面,我使用的是最大连接数为 100 的 C3P0。似乎没有任何特定的 SQL 会触发该问题,所有查询都会在该问题发生时挂起。
这是挂起线程的堆栈跟踪:
"ajp-nio-8010-exec-26" Id=1355 RUNNABLE (in native)
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:100)
at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:143)
at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:173)
- locked com.mysql.jdbc.util.ReadAheadInputStream@33d807d4
at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2911)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3332)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3322)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3762)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2435)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2582)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2531)
- locked com.mysql.jdbc.JDBC4Connection@178ec6c
at com.mysql.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:4852)
- locked com.mysql.jdbc.JDBC4Connection@178ec6c
at com.intergral.fusionreactor.jdbc.ConnectionSurrogate.setAutoCommit(ConnectionSurrogate.java:368)
at com.mchange.v2.c3p0.impl.NewProxyConnection.setAutoCommit(NewProxyConnection.java:1059)
etc.....
同时,在MySQL的慢查询日志中:
# Time: 160128 14:50:38
# User@Host: user @ server1
# Thread_id: 77244 Schema: db_live QC_hit: No
# Query_time: 7.621437 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 0
# Rows_affected: 0
SET timestamp=1454010638;
commit;
# User@Host: user @ server2
# Thread_id: 81339 Schema: db_live QC_hit: No
# Query_time: 7.556022 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 0
# Rows_affected: 0
SET timestamp=1454010638;
commit;
我不太确定慢速日志的原因 - 这里没有实际的 SQL,但它对应于此时在 Tomcat 上观察到的 7 秒挂起。与两台服务器同时尝试连接并相互阻塞有关吗?两个 SET timestamp
语句完全相同。请注意,两个 Tomcat 实例使用相同的用户凭据登录,只是来自两个不同的 IP。日志中附近没有其他慢查询,之前或之后。
有什么想法可能导致此问题或下一步要看哪里?
编辑:
其他可能值得注意的细节:表是 InnoDB,我们正在使用 transaction-isolation = READ-COMMITTED
。所有挂起的线程都在等待 setAutoCommit。
最佳答案
事实并非如此。堆栈跟踪显示它被阻止试图从数据库服务器读取,这意味着它已经连接,并且它正在做的是设置autoCommit
,在连接阶段没有任何东西。
关于java - 为什么 Tomcat 在尝试对 MySQL 设置自动提交时挂起?,我们在Stack Overflow上找到一个类似的问题: https://stackoverflow.com/questions/35072929/