Uploaded image for project: 'MariaDB Connector/J'
  1. MariaDB Connector/J
  2. CONJ-503

MariaDB Driver Uses Read Replicas for non-Read-Only Connections

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 2.0.2, 2.0.3
    • Fix Version/s: 2.1.0, 1.6.3
    • Component/s: Failover
    • Labels:
      None
    • Environment:
      Amazon Linux
      Oracle Java 8
      Aurora (with read replicas and over SSL)
      Jetty
      Tomcat Pool
      Hibernate
      Spring Boot
      Spring

      Description

      We have been struggling this for a couple of weeks, and I'm thinking we may have found an issue. We've tried to do everything we can to narrow it down to the driver.

      Our context is that we are running an application in AWS against Aurora (and using Aurora failover mode) using Spring and Hibernate to manage transactions. Within writable transactions, we are seeing errors stating "The MySQL server is running with the --read-only option so it cannot execute this statement".

      Throughout this report, I have omitted or modified the full names of our classes, packages, and hostnames (we don't really use single letters to name things), except where they may be useful.

      Our connection string looks like this:
      jdbc:mariadb:aurora://d-p-m-q.cluster-abcdefg1h2ij.us-east-1.rds.amazonaws.com:3306/d?useSSL=true&log=true&profileSql=true

      Steps we have taken to troubleshoot:

      • Wrapped the DataSource with logging. After each call to getConnection, we call "isReadOnly" and log out the result.
      • Wrapped the Connection object itself with logging. For each call to "setReadOnly" we log out the value being passed in.

      What we see in our log below is that we pulled a connection, our logging code called "isReadOnly", and got false. There was no line showing a call to setReadOnly. It then shows our connection going down trough a read replica (S) connection and not a Master (M) connection, which I believe it would have to in order to write successfully, right?

      Behavior was observed in 2.0.2, and we upgrade to 2.0.3 to verify that the recent release wouldn't resolve the issue. We are unsure about recent versions prior to 2.0.2 (due to issues with SSL and Aurora failover in a few of the recent versions, we are upgrading to 2.0.2/2.0.3 from 1.4.6).

      15:22:47.145 c.t.l.p.m.aurora.util.InstrumentedDataSource Connection pulled from pool. Read-only: false
      15:22:47.147 org.mariadb.jdbc.internal.logging.ProtocolLoggingProxy Query - conn:3568(S) - 1.446 ms - "use `d`"
      15:22:47.148 org.mariadb.jdbc.internal.logging.ProtocolLoggingProxy Query - conn:3568(S) - 1.138 ms - "set autocommit=0"
      15:22:47.225 org.hibernate.engine.jdbc.spi.SqlExceptionHelper (conn:3568) The MySQL server is running with the --read-only option so it cannot execute this statement
      15:22:47.225 org.mariadb.jdbc.MariaDbStatement error executing query
      java.sql.SQLException: (conn:3568) The MySQL server is running with the --read-only option so it cannot execute this statement
      	at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:179)
      	at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:118)
      	at org.mariadb.jdbc.MariaDbStatement.executeExceptionEpilogue(MariaDbStatement.java:245)
      	at org.mariadb.jdbc.MariaDbPreparedStatementClient.executeInternal(MariaDbPreparedStatementClient.java:218)
      	at org.mariadb.jdbc.MariaDbPreparedStatementClient.execute(MariaDbPreparedStatementClient.java:153)
      	at org.mariadb.jdbc.MariaDbPreparedStatementClient.executeUpdate(MariaDbPreparedStatementClient.java:186)
      	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:204)
      	at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:45)
      	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2949)
      	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3449)
      	at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:89)
      	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:582)
      	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:456)
      	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337)
      	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
      	at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1282)
      	at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:465)
      	at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:2963)
      	at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2339)
      	at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:485)
      	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:147)
      	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$100(JdbcResourceLocalTransactionCoordinatorImpl.java:38)
      	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:231)
      	at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:65)
      	at org.hibernate.jpa.internal.TransactionImpl.commit(TransactionImpl.java:61)
      	at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:517)
      	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:761)
      	at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:730)
      	at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:504)
      	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:292)
      	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
      	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:656)
      	at c.t.l.p.m.s.M$$EnhancerBySpringCGLIB$$8b81bfe2.pushLocalMessage(<generated>)
      	at c.t.l.p.m.s.M$pushLocalMessage$2.call(Unknown Source)
      	at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:48)
      	at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:113)
      	at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:125)
      	at c.t.l.p.m.s.M.p(M.groovy:44)
          ... (additional frames omitted here) ...
      Caused by: java.sql.SQLException: The MySQL server is running with the --read-only option so it cannot execute this statement
      Query is: insert into m (c) values (?), parameters ['2017-07-06 20:22:47.186']
      	at org.mariadb.jdbc.internal.util.LogQueryTool.exceptionWithQuery(LogQueryTool.java:146)
      	at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:223)
      	at sun.reflect.GeneratedMethodAccessor178.invoke(Unknown Source)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:498)
      	at org.mariadb.jdbc.internal.failover.AbstractMastersListener.invoke(AbstractMastersListener.java:368)
      	at org.mariadb.jdbc.internal.failover.FailoverProxy.executeInvocation(FailoverProxy.java:222)
      	at org.mariadb.jdbc.internal.failover.FailoverProxy.invoke(FailoverProxy.java:215)
      	at com.sun.proxy.$Proxy131.executeQuery(Unknown Source)
      	at sun.reflect.GeneratedMethodAccessor178.invoke(Unknown Source)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:498)
      	at org.mariadb.jdbc.internal.logging.ProtocolLoggingProxy.invoke(ProtocolLoggingProxy.java:104)
      	at com.sun.proxy.$Proxy131.executeQuery(Unknown Source)
      	at org.mariadb.jdbc.MariaDbPreparedStatementClient.executeInternal(MariaDbPreparedStatementClient.java:212)
      	... 120 common frames omitted
      15:22:47.225 org.hibernate.engine.jdbc.spi.SqlExceptionHelper SQL Error: 1290, SQLState: HY000
      15:22:47.228 org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl HHH000010: On release of batch it still contained JDBC statements
      15:22:47.231 org.mariadb.jdbc.internal.logging.ProtocolLoggingProxy Query - conn:3568(S) - 2.109 ms - "ROLLBACK"
      15:22:47.233 org.mariadb.jdbc.internal.logging.ProtocolLoggingProxy Query - conn:3568(S) - 1.32 ms - "set autocommit=1"
      15:22:47.266 java.lang.Class ExceptionId: 5c925bc1-d670-4e0b-a2bc-2285de64929c - Message: An unexpected error has occurred
      org.springframework.orm.jpa.JpaSystemException: could not execute statement; nested exception is org.hibernate.exception.GenericJDBCException: could not execute statement
      	at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:333)
      	at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:244)
      	at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:521)
      	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:761)
      	at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:730)
      	at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:504)
      	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:292)
      	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
      	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:656)
      	at c.t.l.p.m.s.M$$EnhancerBySpringCGLIB$$8b81bfe2.pushLocalMessage(<generated>)
      	at c.t.l.p.m.s.M$pushLocalMessage$2.call(Unknown Source)
      	at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:48)
      	at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:113)
      	at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:125)
      	at c.t.l.p.m.s.M.p(M.groovy:44)
          ... (additional frames omitted here) ...
      Caused by: org.hibernate.exception.GenericJDBCException: could not execute statement
      	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:47)
      	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:109)
      	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:95)
      	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:207)
      	at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:45)
      	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2949)
      	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3449)
      	at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:89)
      	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:582)
      	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:456)
      	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337)
      	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
      	at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1282)
      	at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:465)
      	at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:2963)
      	at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2339)
      	at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:485)
      	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:147)
      	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$100(JdbcResourceLocalTransactionCoordinatorImpl.java:38)
      	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:231)
      	at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:65)
      	at org.hibernate.jpa.internal.TransactionImpl.commit(TransactionImpl.java:61)
      	at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:517)
      	... 98 common frames omitted
      Caused by: java.sql.SQLException: (conn:3568) The MySQL server is running with the --read-only option so it cannot execute this statement
      	at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:179)
      	at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:118)
      	at org.mariadb.jdbc.MariaDbStatement.executeExceptionEpilogue(MariaDbStatement.java:245)
      	at org.mariadb.jdbc.MariaDbPreparedStatementClient.executeInternal(MariaDbPreparedStatementClient.java:218)
      	at org.mariadb.jdbc.MariaDbPreparedStatementClient.execute(MariaDbPreparedStatementClient.java:153)
      	at org.mariadb.jdbc.MariaDbPreparedStatementClient.executeUpdate(MariaDbPreparedStatementClient.java:186)
      	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:204)
      	... 117 common frames omitted
      Caused by: java.sql.SQLException: The MySQL server is running with the --read-only option so it cannot execute this statement
      Query is: insert into m (c) values (?), parameters ['2017-07-06 20:22:47.186']
      	at org.mariadb.jdbc.internal.util.LogQueryTool.exceptionWithQuery(LogQueryTool.java:146)
      	at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:223)
      	at sun.reflect.GeneratedMethodAccessor178.invoke(Unknown Source)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:498)
      	at org.mariadb.jdbc.internal.failover.AbstractMastersListener.invoke(AbstractMastersListener.java:368)
      	at org.mariadb.jdbc.internal.failover.FailoverProxy.executeInvocation(FailoverProxy.java:222)
      	at org.mariadb.jdbc.internal.failover.FailoverProxy.invoke(FailoverProxy.java:215)
      	at com.sun.proxy.$Proxy131.executeQuery(Unknown Source)
      	at sun.reflect.GeneratedMethodAccessor178.invoke(Unknown Source)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:498)
      	at org.mariadb.jdbc.internal.logging.ProtocolLoggingProxy.invoke(ProtocolLoggingProxy.java:104)
      	at com.sun.proxy.$Proxy131.executeQuery(Unknown Source)
      	at org.mariadb.jdbc.MariaDbPreparedStatementClient.executeInternal(MariaDbPreparedStatementClient.java:212)
      	... 120 common frames omitted
      

        Attachments

          Activity

            People

            • Assignee:
              diego dupin Diego Dupin
              Reporter:
              joseph.witthuhn Joseph Witthuhn
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: