A troubleshooting process for an online MySQL connection exception

MySQL as a common database, in the Internet system applications a lot. Some faults are their own bugs, others are not, examples of problems encountered in the previous period.

Problem

The symptoms that were encountered were this, our application on-line test environment, during the JMeter testing process, it was found that each stress test started with a low access to the previous HTTP request request will time out, and subsequent requests are not in continuous testing. The last point is that Tomcat's log did not report any errors.

The content of the test is the 200 thread constantly send the request to this HTTP page, this page logic is also relatively simple, will be in the back end to the database insert a data, connection pool using Ali's Druid (this pit first left here), Tomcat is running a regular web App app, The maximum number of JDBC Connection pool connections per app is set at 30, which means that even if 4 tomcat is connected to the database, there is not much connection.

Try to troubleshoot

Since Tomcat's log is nothing wrong, start trying to reproduce the error first. It is not easy to reproduce the error, because it seems to be more random, and later, after summing up, found that every time the problem is applied to the night after the test staff came in the morning to start the stress test, and began to doubt the idle related, so the back of the replay is in this way, idle for half an hour to try to reproduce.

Find Log

Without log, you should look at the stack information of the JVM. Reproduce the failure, on the machine with jstack directly grasp the problem Tomcat JVM information.

JPs
List the Java process number of the machine
Jstack Javaid
Dump stack information for this Java process

Something useful was found in the stack message that was received:

"http-bio-8081-exec-4975" daemon prio=10 tid=0x00007f9d4c127000 nid=0x65db runnable [0x00007f9cc4544000]
Java.lang.Thread.State:RUNNABLE
At java.net.SocketInputStream.socketRead0 (Native Method)
At Java.net.SocketInputStream.read (socketinputstream.java:129)
At Com.mysql.jdbc.util.ReadAheadInputStream.fill (readaheadinputstream.java:114)
At Com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary (readaheadinputstream.java:161)
At **com.mysql.jdbc.util.readaheadinputstream.read (readaheadinputstream.java:189)
-Locked <0x0000000684d608c8> (a com.mysql.jdbc.util.ReadAheadInputStream) * *
At Com.mysql.jdbc.MysqlIO.readFully (mysqlio.java:3014)
At Com.mysql.jdbc.MysqlIO.reuseAndReadPacket (mysqlio.java:3467)
At Com.mysql.jdbc.MysqlIO.reuseAndReadPacket (mysqlio.java:3456)
At Com.mysql.jdbc.MysqlIO.checkErrorPacket (mysqlio.java:3997)
At Com.mysql.jdbc.MysqlIO.sendCommand (mysqlio.java:2468)
At Com.mysql.jdbc.ConnectionImpl.pingInternal (connectionimpl.java:4092)
At Com.mysql.jdbc.ConnectionImpl.ping (connectionimpl.java:4069)
At Sun.reflect.GeneratedMethodAccessor94.invoke (Unknown Source)
At Sun.reflect.DelegatingMethodAccessorImpl.invoke (delegatingmethodaccessorimpl.java:25)
At Java.lang.reflect.Method.invoke (method.java:597)
At Com.alibaba.druid.pool.vendor.MySqlValidConnectionChecker.isValidConnection (Mysqlvalidconnectionchecker.java : 98)
At Com.alibaba.druid.pool.DruidAbstractDataSource.testConnectionInternal (druidabstractdatasource.java:1235)
At Com.alibaba.druid.pool.DruidDataSource.getConnectionDirect (druiddatasource.java:928)
At Com.alibaba.druid.pool.DruidDataSource.getConnection (druiddatasource.java:882)
At Com.alibaba.druid.pool.DruidDataSource.getConnection (druiddatasource.java:872)
At Com.alibaba.druid.pool.DruidDataSource.getConnection (druiddatasource.java:97)
At Org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin (Datasourcetransactionmanager.java : 202)
At Org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction ( abstractplatformtransactionmanager.java:372)
At Org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary ( transactionaspectsupport.java:417)
At Org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction ( transactionaspectsupport.java:255)
At Org.springframework.transaction.interceptor.TransactionInterceptor.invoke (transactioninterceptor.java:94)
At Org.springframework.aop.framework.ReflectiveMethodInvocation.proceed (reflectivemethodinvocation.java:179)
At Org.springframework.aop.framework.JdkDynamicAopProxy.invoke (jdkdynamicaopproxy.java:207)
At Com.sun.proxy. $Proxy 27.insert (Unknown Source)

The HTTP request can be seen from the front-end container until the database is read, stuck in the database where it was read, and not in the JDBC driver code, but in the socket where it was read:

Com.mysql.jdbc.util.ReadAheadInputStream.read (readaheadinputstream.java:189)
-Locked <0x0000000684d608c8> (a com.mysql.jdbc.util.ReadAheadInputStream) *

According to this error search, the only value is n years ago, MySQL official online reported a bug, the same error, but the solution is not the root of the problem. As mentioned, change the JDBC connection string to:

Usereadaheadinput=false&useunbufferedinput=false

This just allows the socket to not read the network buffer, but in fact this time the MySQL connection has been disconnected, do not know whether the Web application is broken or MySQL.

Find Connection Pool Timeout

Since the client that appears to be an app on the socket does not read anything on it, it must be that the application is disconnected from the MySQL TCP connection, so start troubleshooting the connection timeout settings for the app connection pool settings and MySQL.

Apply connection Pooling Settings

Name= "maxwait" value= "60000"
Get connection maximum wait 60 seconds
Name= "Testwhileidle" value= "true"
Test idle connections
Name= "Minevictableidletimemillis" value= "300000"
Name= "Timebetweenevictionrunsmillis" value= "60000"
Destroy thread detects the time interval of the connection

The connection pool settings on the application side do not have an active disconnect setting.

MySQL Connection timeout setting

Show global variables like '%timeout% '

See MySQL maintain connection timeout time is 28800, that is, 8 hours, the database side will not disconnect this connection.

At this point, the problem of troubleshooting into a dead end, both sides will not actively disconnect, why the client after a few minutes of inactivity will be broken off?

There is also a doubt that the same code, the database has not changed, in another pure test environment completely without this problem.

Finding network problems

The focus of the problem now is on the online environment network problem. Then looking for operations colleagues to see the next database Machine Linux There is no abnormal configuration, the result is not.

During the period, I also wondered why Ali Druid's connection pool was now set up to detect connections in the connection pool every minute, or if there was an invalid connection at the time of getting the connection.

Solve

Intermittent tossing for 2 days, holding a dead horse when live horse doctor to consult other departments of colleagues, the result that brother said is not idle after the card on the socketread? Then asked the application and the database is not on different network segments, it is immediately recommended to find the network of the firewall to the TCP long connection timeout setting.

This is basically a firewall setup problem, after the troubleshooting found that two network segments of the Huawei Switch long connection timeout set 3 minutes, because the Java application Connection pool is as long as possible to maintain the connection (a few hours, less than the maximum 8 hours of the database settings), and the firewall think more than 3 minutes of connectivity is problematic, The application and MySQL did not know that the TCP connection was broken.

This fault also exposes Ali Druid Open source connection pool to the connection processing logic problem, the connection pool does not use a separate thread to detect all connections are disconnected, check the code to find that it is only in the connection when the test connection is valid, processing logic is not established C3P0 rigorous, The Application connection pool implementation is then replaced with C3P0.

The article comes from the platform "malt bread". Reprint please specify.

A troubleshooting process for an online MySQL connection exception