You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@aurora.apache.org by "Zameer Manji (JIRA)" <ji...@apache.org> on 2016/02/03 01:12:39 UTC
[jira] [Updated] (AURORA-1607) Persistent "Error accessing
PooledConnection. Connection is invalid" exceptions with DbTaskStore
enabled
[ 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)