javasqlmariadbtransactional

TransactionException on mariadb get


Apologies for bit-misleading title.

I have a device-id application, which basically saves any new deviceId sent to system or return details of any deviceId as per request.

This issue is not very frequent but it does pop up now-and-then and google is not helping solve it!

Datastore is on MariaDB-10.1.35. Service has a QPS activity of ~2.5k, couple of google links suggested to increase wait_timeout but given the QPS, a wait_timeout of 600seconds is a safe bet.

prod config has:

validationQuery: "/* Health Check */ SELECT 1"
wait_timeout: 600

standard function ( built around hystrix wrapper is as below )

public Optional<DeviceId> get(final String token) throws DeviceIdException {
    try {
        return CommandFactory.<Optional<DeviceId>>create("DeviceId", "Get")
                .executor(() -> DaoRegistry.getDeviceIdLookupDao().get(token))
                .toObservable()
                .toBlocking()
                .single();
    } catch (Exception e) {
        log.error("Get error {}", e);
        throw DeviceIdException.builder()
                .code(Response.Status.INTERNAL_SERVER_ERROR.getStatusCode())
                .errorCode("DI000")
                .message("Oops! Something went wrong!")
                .build();
    }
}

Stack dump as below

Caused by: org.hibernate.TransactionException: JDBC begin transaction failed:
    at org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor.begin(AbstractLogicalConnectionImplementor.java:73)
    at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:263)
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
    at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:56)
    at org.hibernate.internal.AbstractSharedSessionContract.beginTransaction(AbstractSharedSessionContract.java:409)
    at io.dropwizard.sharding.utils.TransactionHandler.beginTransaction(TransactionHandler.java:96)
    at io.dropwizard.sharding.utils.TransactionHandler.beforeStart(TransactionHandler.java:48)
    at io.dropwizard.sharding.utils.Transactions.execute(Transactions.java:52)
    at io.dropwizard.sharding.utils.Transactions.execute(Transactions.java:46)
    at io.dropwizard.sharding.dao.LookupDao.get(LookupDao.java:192)
    at io.dropwizard.sharding.dao.LookupDao.get(LookupDao.java:176)
    at com.myOrganisation.MyCustomService.commands.DeviceIdCommands.lambda$get$1(DeviceIdCommands.java:73)
    at io.appform.core.hystrix.GenericHystrixCommand$1.run(GenericHystrixCommand.java:43)
    at com.netflix.hystrix.HystrixCommand$2.call(HystrixCommand.java:302)
    at com.netflix.hystrix.HystrixCommand$2.call(HystrixCommand.java:298)
    at rx.internal.operators.OnSubscribeDefer.call(OnSubscribeDefer.java:46)
    ... 26 common frames omitted
Caused by: java.sql.SQLNonTransientConnectionException: (conn=2997305) unexpected end of stream, read 0 bytes from 4 (socket was closed by server)
    at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:234)
    at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:165)
    at org.mariadb.jdbc.MariaDbStatement.executeExceptionEpilogue(MariaDbStatement.java:238)
    at org.mariadb.jdbc.MariaDbStatement.executeInternal(MariaDbStatement.java:356)
    at org.mariadb.jdbc.MariaDbStatement.executeUpdate(MariaDbStatement.java:545)
    at org.mariadb.jdbc.MariaDbConnection.setAutoCommit(MariaDbConnection.java:751)
    at sun.reflect.GeneratedMethodAccessor39.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.apache.tomcat.jdbc.pool.ProxyConnection.invoke(ProxyConnection.java:126)
    at org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(JdbcInterceptor.java:108)
    at org.apache.tomcat.jdbc.pool.interceptor.AbstractCreateStatementInterceptor.invoke(AbstractCreateStatementInterceptor.java:79)
    at org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(JdbcInterceptor.java:108)
    at org.apache.tomcat.jdbc.pool.DisposableConnectionFacade.invoke(DisposableConnectionFacade.java:81)
    at com.sun.proxy.$Proxy53.setAutoCommit(Unknown Source)
    at org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor.begin(AbstractLogicalConnectionImplementor.java:67)
    ... 41 common frames omitted
Caused by: java.sql.SQLException: unexpected end of stream, read 0 bytes from 4 (socket was closed by server)
Query is: set autocommit=0
java thread: hystrix-DeviceId.Get-4
    at org.mariadb.jdbc.internal.util.LogQueryTool.exceptionWithQuery(LogQueryTool.java:126)
    at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:222)
    at org.mariadb.jdbc.MariaDbStatement.executeInternal(MariaDbStatement.java:350)
    ... 53 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:238)
    at org.mariadb.jdbc.internal.io.input.StandardPacketInputStream.getPacket(StandardPacketInputStream.java:207)
    at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.readPacket(AbstractQueryProtocol.java:1427)
    at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.getResult(AbstractQueryProtocol.java:1407)
    at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:219)
    ... 54 common frames omitted

Can some one help with right direction here as to what might be broken / missing?


Solution

  • Looks like a wait_timeout issue. If the value is set to be in hours; reduce it to a reasonable time; say 600 seconds. It would be overoptimistic to expect the connection to be kept alive for hours. Hope this helps.