【发布时间】：2018-07-01 11:54:34
【问题描述】：
我们遇到了一个产品问题，需要重新启动我们的 tomcat 服务器才能修复。我们可以通过性能测试重现这一点，但我们不确定重现它所需的一系列事件。似乎如果我们在一个 tomcat 实例上抛出足够多的流量，它最终会出现以下问题：
Tomcat 有 200 个线程可用，但所有 200 个线程都在这样做：
"http-nio-8080-exec-1" #41 daemon prio=5 os_prio=0 tid=0x00007f7264a5b800 nid=0xdf9 runnable [0x00007f71e39fd000]
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:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:101)
at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:144)
at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:174)
- locked <0x000000008b9bbb60> (a com.mysql.jdbc.util.ReadAheadInputStream)
at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3008)
at com.mysql.jdbc.MysqlIO.readPacket(MysqlIO.java:567)
at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1016)
at com.mysql.jdbc.ConnectionImpl.coreConnect(ConnectionImpl.java:2188)
at com.mysql.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:2035)
at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2019)
- locked <0x000000008b9bbc88> (a com.mysql.jdbc.JDBC4Connection)
at com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:776)
at com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:47)
at sun.reflect.GeneratedConstructorAccessor69.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:386)
at com.mysql.jdbc.MultiHostConnectionProxy.createConnectionForHost(MultiHostConnectionProxy.java:346)
- eliminated <0x000000008b9bc188> (a com.mysql.jdbc.LoadBalancedConnectionProxy)
at com.mysql.jdbc.LoadBalancedConnectionProxy.createConnectionForHost(LoadBalancedConnectionProxy.java:372)
- eliminated <0x000000008b9bc188> (a com.mysql.jdbc.LoadBalancedConnectionProxy)
at com.mysql.jdbc.RandomBalanceStrategy.pickConnection(RandomBalanceStrategy.java:73)
at com.mysql.jdbc.LoadBalancedConnectionProxy.pickNewConnection(LoadBalancedConnectionProxy.java:317)
- locked <0x000000008b9bc188> (a com.mysql.jdbc.LoadBalancedConnectionProxy)
at com.mysql.jdbc.LoadBalancedConnectionProxy.<init>(LoadBalancedConnectionProxy.java:229)
at com.mysql.jdbc.LoadBalancedConnectionProxy.createProxyInstance(LoadBalancedConnectionProxy.java:105)
at com.mysql.jdbc.NonRegisteringDriver.connectLoadBalanced(NonRegisteringDriver.java:374)
at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:314)
at com.mysql.jdbc.ReplicationConnectionProxy.initializeMasterConnection(ReplicationConnectionProxy.java:415)
at com.mysql.jdbc.ReplicationConnectionProxy.<init>(ReplicationConnectionProxy.java:182)
at com.mysql.jdbc.ReplicationConnectionProxy.createProxyInstance(ReplicationConnectionProxy.java:85)
at com.mysql.jdbc.NonRegisteringDriver.connectReplicationConnection(NonRegisteringDriver.java:459)
at com.mysql.jdbc.NonRegisteringReplicationDriver.connect(NonRegisteringReplicationDriver.java:46)
at com.myapp.rest.JSONService.setUpConnection(JSONService.java:1278) ******************************************************************************
at sun.reflect.GeneratedMethodAccessor120.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:76)
at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$$Lambda$127/439202272.invoke(Unknown Source)
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:148)
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:191)
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:243)
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:103)
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:493)
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:415)
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:104)
at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:277)
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:272)
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:268)
at org.glassfish.jersey.internal.Errors.process(Errors.java:316)
at org.glassfish.jersey.internal.Errors.process(Errors.java:298)
at org.glassfish.jersey.internal.Errors.process(Errors.java:268)
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:289)
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:256)
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:703)
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:416)
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:370)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:389)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:342)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:229)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:292)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:212)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:94)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:504)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:676)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:620)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:502)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1132)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:684)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1533)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1489)
- locked <0x000000008a974068> (a org.apache.tomcat.util.net.NioChannel)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
我知道这是一大堆文字，但您可以通过在该堆栈跟踪中搜索 ****************************************************************************** 找到我们的代码。
由于所有可用线程都在等待获取连接，tomcat 变得无响应。当tomcat像这样被锁定时，mysql master上没有连接（虽然我没有检查过slave）。所以看起来 Java 代码正在等待来自数据库的连接，而数据库没有 Java 尝试连接它的记录。
这个数据库有 7k 的可用连接，通过 New Relic 我们可以看到从来没有超过 3k。所以这不是数据库连接断开的问题。
这是用于建立连接的代码：
Class.forName("com.mysql.jdbc.ReplicationDriver");
final String JDBC_CONNECTION_STRING = System.getProperty("JDBC_CONNECTION_STRING");
final String DB_USER_STRING = System.getProperty("DB_USER_STRING");
final String DB_PASSWORD_STRING = System.getProperty("DB_PASSWORD_STRING");
ReplicationDriver driver = new ReplicationDriver();
Properties props = new Properties();
// We want this for failover on the slaves
props.put("autoReconnect", "true");
// We want to load balance between the slaves
props.put("roundRobinLoadBalance", "true");
props.put("user", DB_USER_STRING);
props.put("password", DB_PASSWORD_STRING);
props.put("useLocalSessionState", "true");
props.put("useLocalTransactionState", "true");
props.put("connectTimeout", System.getProperty("MYSQL_CLIENT_CONNECT_TIMEOUT_MS"));
props.put("socketTimeout", System.getProperty("MYSQL_CLIENT_SOCKET_TIMEOUT_MS"));
if(use_utf8)
{
props.put("useUnicode", "yes");
props.put("characterEncoding", "UTF-8");
}
connect = driver.connect(JDBC_CONNECTION_STRING, props); //all threads block on this line
connect.setReadOnly(false);
作为一种解决方法，我们添加了 MYSQL_CLIENT_CONNECT_TIMEOUT_MS 和 MYSQL_CLIENT_SOCKET_TIMEOUT_MS 行。设置这些可以防止机器被锁定，但我们还没有真正解决根本问题。我想解决根本问题：为什么 Java 代码等待连接到数据库？
我们在 RDS 上使用 MySQL，版本 5.6.10。
我正在使用 Tomcat 8、JDK 8、Jersey 2.26 和
<dependency>
<groupId>mysql</groupId>
<artifactId>mysql-connector-java</artifactId>
<version>5.1.45</version>
</dependency>
可能值得注意的是，我使用这个 jdbc url 前缀连接到这个数据库：jdbc:mysql:replication://。此外，这似乎只发生在 RDS 上，而不是本地。两种环境的区别在于 RDS 有主从，而本地没有。
【问题讨论】：
-
你的Tomcat流量下做了哪些Mysql操作？只选择操作？当您的并发 UPDATE/DELETE/SELECT 请求发送到 Mysql 服务器时，是否可能发生死锁？如果出现死锁，你的线程会像上面描述的那样运行。
-
@ftb 我们正在执行各种 CRUD 操作。但是，我不确定我是否同意你的说法，因为堆栈跟踪总是显示它在等待连接，而不是等待 CRUD 操作。为什么它会因为数据库死锁而停在那里？请记住，数据库有 7k 个连接要提供，每个 tomcat 只使用 200 个。
-
做一个堆转储，看看哪些线程在 JVM 中死锁了。要求数据库为您提供有关在给定时刻可用的连接数的信息。
-
@duffymo 我的问题中已经有了这些信息。没有标记为“死锁”的线程。数据库有 1000 个可用连接。
-
" - 锁定 (a com.mysql.jdbc.util.ReadAheadInputStream)" - 这让我觉得 Java JDBC 有了连接。也许这就是问题所在——为什么 MySQL 不同意？
标签： java mysql tomcat jdbc jersey-2.0