Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
2.7.4
-
None
Description
We recently upgraded our setup from 2.7.2 of MariaDB JDBC driver to 2.7.4 to bring in certain fixes in that driver. Ever since this upgrade, our usage of this driver in the product has started seeing very frequent connection usage failures which look something like:
ERROR org.mariadb.jdbc.MariaDbStatement - error executing query
java.sql.SQLTransientConnectionException: (conn=72408) unexpected end of stream, read 0 bytes from 4 (socket was closed by server)
at org.mariadb.jdbc.internal.util.exceptions.ExceptionFactory.createException(ExceptionFactory.java:79)
at org.mariadb.jdbc.internal.util.exceptions.ExceptionFactory.create(ExceptionFactory.java:158)
at org.mariadb.jdbc.MariaDbStatement.executeExceptionEpilogue(MariaDbStatement.java:266)
at org.mariadb.jdbc.ClientSidePreparedStatement.executeInternal(ClientSidePreparedStatement.java:229)
at org.mariadb.jdbc.ClientSidePreparedStatement.execute(ClientSidePreparedStatement.java:149)
at org.mariadb.jdbc.ClientSidePreparedStatement.executeQuery(ClientSidePreparedStatement.java:163)
at org.myapp.SQL.executeQuery(SQL.java:1234)
at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
Caused by: org.mariadb.jdbc.internal.util.exceptions.MariaDbSqlException: unexpected end of stream, read 0 bytes from 4 (socket was closed by server)
at org.mariadb.jdbc.internal.util.exceptions.MariaDbSqlException.of(MariaDbSqlException.java:34)
at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.exceptionWithQuery(AbstractQueryProtocol.java:194)
at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.exceptionWithQuery(AbstractQueryProtocol.java:177)
at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:321)
at org.mariadb.jdbc.ClientSidePreparedStatement.executeInternal(ClientSidePreparedStatement.java:220)
... 12 common frames omitted
Caused by: java.sql.SQLTransientConnectionException: unexpected end of stream, read 0 bytes from 4 (socket was closed by server)
at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.handleIoException(AbstractQueryProtocol.java:2073)
at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.readPacket(AbstractQueryProtocol.java:1542)
at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.getResult(AbstractQueryProtocol.java:1521)
at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:318)
... 13 common frames omitted
Caused by: java.io.EOFException: unexpected end of stream, read 0 bytes from 4 (socket was closed by server)
at org.mariadb.jdbc.internal.io.input.StandardPacketInputStream.getPacketArray(StandardPacketInputStream.java:249)
at org.mariadb.jdbc.internal.io.input.StandardPacketInputStream.getPacket(StandardPacketInputStream.java:218)
at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.readPacket(AbstractQueryProtocol.java:1540)
... 15 common frames omitted
We hadn't seen this before in the older version. Enabling DEBUG logs of MariaDB driver did provide some hints but it still wasn't clear what was going on. It looked like a "stale" (as in a connection that is no longer valid) was being handed out to the callers of the pool.
After going through the MariaDB driver code, I think it's a recent regression that got introduced as part of the fix for https://jira.mariadb.org/browse/CONJ-884. Looking at that fix, I think there's a typo in the code here https://github.com/mariadb-corporation/mariadb-connector-j/commit/cb652bb4c054558f9b14a2d4e78e8fa33a9ae0d9#diff-8d7b4d2af627987dd65db5582bfe117ab5c7662b76441eec10262ea80e06a62dR231
That code I think should instead look like:
diff --git a/src/main/java/org/mariadb/jdbc/internal/util/pool/Pool.java b/src/main/java/org/mariadb/jdbc/internal/util/pool/Pool.java
index 92ad6b31..8d1c304f 100644
— a/src/main/java/org/mariadb/jdbc/internal/util/pool/Pool.java
+++ b/src/main/java/org/mariadb/jdbc/internal/util/pool/Pool.java
@@ -375,7 +375,7 @@ public class Pool implements AutoCloseable, PoolMBean {
// ensure that other connection will be validated before being use
// since one connection failed, better to assume the other might as well
- idleConnections.stream().forEach(c -> c.lastUsedToNow());
+ idleConnections.stream().forEach(c -> c.ensureValidation());
addConnectionRequest();
logger.debug(
I think what's happening because of this change is that the validation is being skipped for items that are already in the pool, instead of doing the opposite, i.e. forcing a validation.