[
https://issues.apache.org/jira/browse/AURORA-1607?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Zameer Manji updated AURORA-1607:
---------------------------------
Description:
Even after the resolution of AURORA-1596 (adding a ping query), I still see
exceptions like this in the log:
{noformat}
Feb 02, 2016 11:24:01 PM
com.google.common.util.concurrent.ServiceManager$ServiceListener failed
SEVERE: Service PreemptorService [FAILED] has failed in the RUNNING state.
org.apache.ibatis.exceptions.PersistenceException:
### Error rolling back transaction. Cause: java.sql.SQLException: Error
accessing PooledConnection. Connection is invalid.
### Cause: java.sql.SQLException: Error accessing PooledConnection. Connection
is invalid.
at
org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
at
org.apache.ibatis.session.defaults.DefaultSqlSession.rollback(DefaultSqlSession.java:216)
at
org.apache.ibatis.session.SqlSessionManager.rollback(SqlSessionManager.java:299)
at
org.mybatis.guice.transactional.TransactionalMethodInterceptor.invoke(TransactionalMethodInterceptor.java:116)
at
org.apache.aurora.common.inject.TimedInterceptor.invoke(TimedInterceptor.java:83)
at
org.apache.aurora.scheduler.storage.log.LogStorage.read(LogStorage.java:570)
at
org.apache.aurora.scheduler.storage.CallOrderEnforcingStorage.read(CallOrderEnforcingStorage.java:113)
at
org.apache.aurora.scheduler.preemptor.PendingTaskProcessor.run(PendingTaskProcessor.java:119)
at
org.apache.aurora.scheduler.preemptor.PreemptorModule$PreemptorService.runOneIteration(PreemptorModule.java:145)
at
com.google.common.util.concurrent.AbstractScheduledService$ServiceDelegate$Task.run(AbstractScheduledService.java:189)
at com.google.common.util.concurrent.Callables$3.run(Callables.java:100)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.sql.SQLException: Error accessing PooledConnection. Connection
is invalid.
at
org.apache.ibatis.datasource.pooled.PooledConnection.checkConnection(PooledConnection.java:254)
at
org.apache.ibatis.datasource.pooled.PooledConnection.invoke(PooledConnection.java:243)
at com.sun.proxy.$Proxy130.getAutoCommit(Unknown Source)
at
org.apache.ibatis.transaction.jdbc.JdbcTransaction.rollback(JdbcTransaction.java:79)
at
org.apache.ibatis.executor.BaseExecutor.rollback(BaseExecutor.java:249)
at
org.apache.ibatis.executor.CachingExecutor.rollback(CachingExecutor.java:119)
at
org.apache.ibatis.session.defaults.DefaultSqlSession.rollback(DefaultSqlSession.java:213)
... 16 more
E0202 23:24:01.414 [PreemptorService RUNNING,
GuavaUtils$LifecycleShutdownListener:53] Service: PreemptorService [FAILED]
failed unexpectedly. Triggering shutdown.
I0202 23:24:01.414 [PreemptorService RUNNING, Lifecycle:84] Shutting down
application
{noformat}
To me this signals a problem in the mybatis connection pool implementation.
Enabling verbose logging in all database related code does not show anything
obvious in the logs.
was:
Even after the resolution of AURORA-1596 (adding a ping query), I still see
exceptions like this in the log:
{noformat}
Feb 02, 2016 11:24:01 PM
com.google.common.util.concurrent.ServiceManager$ServiceListener failed
SEVERE: Service PreemptorService [FAILED] has failed in the RUNNING state.
org.apache.ibatis.exceptions.PersistenceException:
### Error rolling back transaction. Cause: java.sql.SQLException: Error
accessing PooledConnection. Connection is invalid.
### Cause: java.sql.SQLException: Error accessing PooledConnection. Connection
is invalid.
at
org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
at
org.apache.ibatis.session.defaults.DefaultSqlSession.rollback(DefaultSqlSession.java:216)
at
org.apache.ibatis.session.SqlSessionManager.rollback(SqlSessionManager.java:299)
at
org.mybatis.guice.transactional.TransactionalMethodInterceptor.invoke(TransactionalMethodInterceptor.java:116)
at
org.apache.aurora.common.inject.TimedInterceptor.invoke(TimedInterceptor.java:83)
at
org.apache.aurora.scheduler.storage.log.LogStorage.read(LogStorage.java:570)
at
org.apache.aurora.scheduler.storage.CallOrderEnforcingStorage.read(CallOrderEnforcingStorage.java:113)
at
org.apache.aurora.scheduler.preemptor.PendingTaskProcessor.run(PendingTaskProcessor.java:119)
at
org.apache.aurora.scheduler.preemptor.PreemptorModule$PreemptorService.runOneIteration(PreemptorModule.java:145)
at
com.google.common.util.concurrent.AbstractScheduledService$ServiceDelegate$Task.run(AbstractScheduledService.java:189)
at com.google.common.util.concurrent.Callables$3.run(Callables.java:100)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.sql.SQLException: Error accessing PooledConnection. Connection
is invalid.
at
org.apache.ibatis.datasource.pooled.PooledConnection.checkConnection(PooledConnection.java:254)
at
org.apache.ibatis.datasource.pooled.PooledConnection.invoke(PooledConnection.java:243)
at com.sun.proxy.$Proxy130.getAutoCommit(Unknown Source)
at
org.apache.ibatis.transaction.jdbc.JdbcTransaction.rollback(JdbcTransaction.java:79)
at
org.apache.ibatis.executor.BaseExecutor.rollback(BaseExecutor.java:249)
at
org.apache.ibatis.executor.CachingExecutor.rollback(CachingExecutor.java:119)
at
org.apache.ibatis.session.defaults.DefaultSqlSession.rollback(DefaultSqlSession.java:213)
... 16 more
E0202 23:24:01.414 [PreemptorService RUNNING,
GuavaUtils$LifecycleShutdownListener:53] Service: PreemptorService [FAILED]
failed unexpectedly. Triggering shutdown.
I0202 23:24:01.414 [PreemptorService RUNNING, Lifecycle:84] Shutting down
application
{noformat}
To me this signals a problem in the mybatis connection pool implementation.
Enabling verbose logging in all database related code does not show anything
obvious in the logs.
We already depend on the c3p0 library and I suggest we swap out our pooled
connection implementation for that.
> Persistent "Error accessing PooledConnection. Connection is invalid"
> exceptions with DbTaskStore enabled
> --------------------------------------------------------------------------------------------------------
>
> Key: AURORA-1607
> URL: https://issues.apache.org/jira/browse/AURORA-1607
> Project: Aurora
> Issue Type: Bug
> Reporter: Zameer Manji
> Assignee: Zameer Manji
>
> Even after the resolution of AURORA-1596 (adding a ping query), I still see
> exceptions like this in the log:
> {noformat}
> Feb 02, 2016 11:24:01 PM
> com.google.common.util.concurrent.ServiceManager$ServiceListener failed
> SEVERE: Service PreemptorService [FAILED] has failed in the RUNNING state.
> org.apache.ibatis.exceptions.PersistenceException:
> ### Error rolling back transaction. Cause: java.sql.SQLException: Error
> accessing PooledConnection. Connection is invalid.
> ### Cause: java.sql.SQLException: Error accessing PooledConnection.
> Connection is invalid.
> at
> org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
> at
> org.apache.ibatis.session.defaults.DefaultSqlSession.rollback(DefaultSqlSession.java:216)
> at
> org.apache.ibatis.session.SqlSessionManager.rollback(SqlSessionManager.java:299)
> at
> org.mybatis.guice.transactional.TransactionalMethodInterceptor.invoke(TransactionalMethodInterceptor.java:116)
> at
> org.apache.aurora.common.inject.TimedInterceptor.invoke(TimedInterceptor.java:83)
> at
> org.apache.aurora.scheduler.storage.log.LogStorage.read(LogStorage.java:570)
> at
> org.apache.aurora.scheduler.storage.CallOrderEnforcingStorage.read(CallOrderEnforcingStorage.java:113)
> at
> org.apache.aurora.scheduler.preemptor.PendingTaskProcessor.run(PendingTaskProcessor.java:119)
> at
> org.apache.aurora.scheduler.preemptor.PreemptorModule$PreemptorService.runOneIteration(PreemptorModule.java:145)
> at
> com.google.common.util.concurrent.AbstractScheduledService$ServiceDelegate$Task.run(AbstractScheduledService.java:189)
> at com.google.common.util.concurrent.Callables$3.run(Callables.java:100)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: java.sql.SQLException: Error accessing PooledConnection.
> Connection is invalid.
> at
> org.apache.ibatis.datasource.pooled.PooledConnection.checkConnection(PooledConnection.java:254)
> at
> org.apache.ibatis.datasource.pooled.PooledConnection.invoke(PooledConnection.java:243)
> at com.sun.proxy.$Proxy130.getAutoCommit(Unknown Source)
> at
> org.apache.ibatis.transaction.jdbc.JdbcTransaction.rollback(JdbcTransaction.java:79)
> at
> org.apache.ibatis.executor.BaseExecutor.rollback(BaseExecutor.java:249)
> at
> org.apache.ibatis.executor.CachingExecutor.rollback(CachingExecutor.java:119)
> at
> org.apache.ibatis.session.defaults.DefaultSqlSession.rollback(DefaultSqlSession.java:213)
> ... 16 more
> E0202 23:24:01.414 [PreemptorService RUNNING,
> GuavaUtils$LifecycleShutdownListener:53] Service: PreemptorService [FAILED]
> failed unexpectedly. Triggering shutdown.
> I0202 23:24:01.414 [PreemptorService RUNNING, Lifecycle:84] Shutting down
> application
> {noformat}
> To me this signals a problem in the mybatis connection pool implementation.
> Enabling verbose logging in all database related code does not show anything
> obvious in the logs.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
