Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
2.0.2, 2.0.3
-
None
-
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
|