MySQL Connection Constantly Re-opened
theoilie opened this issue ยท 8 comments
I noticed on my server that when using craftconomy3, a ton of MySQL connections are being opened. Aside from the cost of opening so many connections, this sometimes leads to not being able to connect to the MySQL server (due to error 1040 - too many connections) and the need for a forced restart of the MySQL server. Proof:
MariaDB [(none)]> SHOW STATUS LIKE '%onn%';
+-----------------------------------------------+-------+
| Variable_name | Value |
+-----------------------------------------------+-------+
| Aborted_connects | 341 |
| Connection_errors_accept | 0 |
| Connection_errors_internal | 0 |
| Connection_errors_max_connections | 0 |
| Connection_errors_peer_address | 0 |
| Connection_errors_select | 0 |
| Connection_errors_tcpwrap | 0 |
| Connections | 11767 |
| Max_used_connections | 25 |
| Performance_schema_session_connect_attrs_lost | 0 |
| Ssl_client_connects | 0 |
| Ssl_connect_renegotiates | 0 |
| Ssl_finished_connects | 0 |
| Threads_connected | 20 |
+-----------------------------------------------+-------+
14 rows in set (0.00 sec)
MariaDB [(none)]> SHOW processlist;
+-------+-----------+--------------------------------------------------------+--------------------+---------+-------+-------+------------------+----------+
| Id | User | Host | db | Command | Time | State | Info | Progress |
+-------+-----------+--------------------------------------------------------+--------------------+---------+-------+-------+------------------+----------+
| 2 | pex | [redacted]:41615 | hub_permissions | Sleep | 142 | | NULL | 0.000 |
| 14 | root | localhost:59850 | prison_permissions | Sleep | 4 | | NULL | 0.000 |
| 15 | root | localhost:59851 | multicraft_daemon | Sleep | 4 | | NULL | 0.000 |
| 16 | root | localhost:59852 | GANGS | Sleep | 17 | | NULL | 0.000 |
| 18 | eximstats | localhost | eximstats | Sleep | 126 | | NULL | 0.000 |
| 19 | pex | [redacted]:42142 | hub_permissions | Sleep | 1 | | NULL | 0.000 |
| 337 | root | localhost:60410 | multicraft_daemon | Sleep | 15301 | | NULL | 0.000 |
| 1013 | root | localhost:32914 | killsDatabase | Sleep | 17 | | NULL | 0.000 |
| 1620 | root | [redacted]:60260 | prison_plotz | Sleep | 1048 | | NULL | 0.000 |
| 11211 | root | localhost:44341 | prison_economy | Sleep | 1 | | NULL | 0.000 |
| 11651 | root | localhost:44844 | prison_economy | Sleep | 16 | | NULL | 0.000 |
| 11652 | root | localhost:44845 | prison_economy | Sleep | 16 | | NULL | 0.000 |
| 11653 | root | localhost:44846 | prison_economy | Sleep | 16 | | NULL | 0.000 |
| 11654 | root | localhost:44847 | prison_economy | Sleep | 16 | | NULL | 0.000 |
| 11655 | root | localhost:44848 | prison_economy | Sleep | 16 | | NULL | 0.000 |
| 11656 | root | localhost:44849 | prison_economy | Sleep | 16 | | NULL | 0.000 |
| 11657 | root | localhost:44850 | prison_economy | Sleep | 16 | | NULL | 0.000 |
| 11658 | root | localhost:44851 | prison_economy | Sleep | 16 | | NULL | 0.000 |
| 11659 | root | localhost:44852 | prison_economy | Sleep | 16 | | NULL | 0.000 |
| 11764 | root | localhost | NULL | Query | 0 | init | SHOW processlist | 0.000 |
+-------+-----------+--------------------------------------------------------+--------------------+---------+-------+-------+------------------+----------+
Notice that connections is at nearly 12000. It continues increasing. This should be a pretty easy fix. The problem appears to be in https://github.com/greatman/craftconomy3/blob/master/src/main/java/com/greatmancode/craftconomy3/storage/sql/SQLStorageEngine.java. The problem is that the connection is closed after every call, so it has to be opened again the next time that call is made.
The connection is not closed as in The TCP-Connection to the MySQL-Server is closed. CraftConomy3 uses HikariCP which is a connection-pool, so the close puts the connection you got from getConnection() back into the pool of available connections.
The error you get is odd since | Max_used_connections | 25 | is so low it shoudn't be a issue. Craftconomy have a config variable to set the maximum amount of connection it can use. The maximum is set by default to 10. It can be set in the config.yml.
I understand it's a pool (although I've never used HikariCP), but I notice Tools.closeJDBCConnection(connection); whenever commitConnection is null. I found the Tools class and the method that it calls, which appears to close the connection as one normally closes a MySQL connection in Java, meaning it needs to be opened again next time (and the cycle goes on...).
As you can see in my query dump, the connections with the highest ids (meaning newest, most recently-connected) are from CraftConomy3. I just checked again, and the connection count is over 60,000 with ids in the 60,000s being to the prison_economy database.
Obviously it's not using all these connections since max_user_connections is set to 25 like you pointed out, but it seems like they're just being created and then closed. Regarding the config variable you mentioned, I haven't touched that. The config still shows Poolsize: 10.
Ill check if there's a update to HikariCP. Maybe it's a bug in it that creates a boatload of connections or the keepalive being too low. When I close the connection in Tools.closeJDBCConnection, I just tell HikariCP that the connection I just used is free, it then decides if it keeps it or not. Looks like it just decides to scrap it, which is odd since connecting is one of the most expensive stuff to do.
@greatman I don't see anything having to do with HikariCP in Tools.closeJDBCConnection (https://github.com/greatman/GreatmancodeTools/blob/master/src/main/java/com/greatmancode/tools/utils/Tools.java#L123-L128). That's how one normally closes a connection, so I don't think HikariCP even has any choice but to open it again (or use a different connection) next time CC3 tries to get a connection from its pool.
It's normal, I still use normal JDBC stuff when working with HikariCP. It gives me a "proxy" of the actual JDBC connection.
To see, https://github.com/greatman/craftconomy3/blob/master/src/main/java/com/greatmancode/craftconomy3/storage/sql/MySQLEngine.java#L34-L44 creates the HikariCP connection. https://github.com/greatman/craftconomy3/blob/master/src/main/java/com/greatmancode/craftconomy3/storage/sql/MySQLEngine.java#L57 gives me a HikariCP JDBC connection.
Could it be a problem that you set the connection timeout to 5000 ms in the above link? Timing out every 5 seconds seems way too soon. The default connection timeout set by HikariCP is 30 seconds (https://github.com/brettwooldridge/HikariCP/blob/dev/src/main/java/com/zaxxer/hikari/HikariConfig.java#L51). Is there a reason you change it to 5?
The connection timeout is for the initial connect, it prevent JDBC stalling trying to get a connection so if after 5s it didn't connect to MySQL, it just drops. The value for waiting before closing is the idle timeout which is set to 10 minutes.
I just updated HikariCP to the latest version and i'm seeing my connections being 1000s in sleep so it looks fine I think.
You can try that version if you want, it is here: https://oss.sonatype.org/content/repositories/snapshots/com/greatmancode/craftconomy3/3.3.1-SNAPSHOT/craftconomy3-3.3.1-20160106.045307-9.jar