[CONJ-896] Ensure pool connections validation when a socket fail Created: 2021-08-24  Updated: 2021-08-31  Resolved: 2021-08-30

Status: Closed
Project: MariaDB Connector/J
Component/s: pooling
Affects Version/s: 2.7.4
Fix Version/s: 2.7.5, 3.0.2-rc

Type: Bug Priority: Major
Reporter: Jaikiran Pai Assignee: Diego Dupin
Resolution: Fixed Votes: 0
Labels: 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.



 Comments   
Comment by Jaikiran Pai [ 2021-08-24 ]

I've opened PR https://github.com/mariadb-corporation/mariadb-connector-j/pull/173 as a fix.

Comment by Diego Dupin [ 2021-08-30 ]

thanks for your contribution, reported in 3.0.2-rc as well

Generated at Thu Feb 08 03:19:06 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.