Issue #392 has been updated by Vicente J. Ruiz Jurado. Status changed from Closed to New % Done changed from 100 to 0 ---------------------------------------- Bug #392: Excepction with mysql connection pool and cron task http://redmine.ourproject.org/issues/392#change-507 * Author: Vicente J. Ruiz Jurado * Status: New * Priority: Normal * Assignee: * Category: Server side * Target version: * Resolution: ---------------------------------------- 2012-10-25 02:04:58 RackServletFilter [DEBUG] REQUEST: /ws/ContentService 2012-10-25 02:04:58 GWTServiceFilter [INFO] -------------------------------------------------------------------------------- 2012-10-25 02:04:58 GWTServiceFilter [DEBUG] SERVICE: /ws/ContentService - ContentService 2012-10-25 02:04:58 AuthenticatedMethodInterceptor [INFO] ----- Starting method: getContentByWaveRef- userhash: 1n9sg2jn48eld8o2ul8sg7b1r ----- 2012-10-25 02:04:58 AuthenticatedMethodInterceptor [INFO] Method: getContentByWaveRef 2012-10-25 02:04:58 AuthenticatedMethodInterceptor [INFO] Userhash received: 1n9sg2jn48eld8o2ul8sg7b1r 2012-10-25 02:04:58 LoggerMethodInterceptor [DEBUG] ContentRPC.getContentByWaveRef(1n9sg2jn48eld8o2ul8sg7b1r, kune.cc/w+75IIY14siqG, ) 2012-10-25 02:04:58 LoggerMethodInterceptor [DEBUG] ContentRPC.getContentByWaveRef => StateDTO[null], time consumed: 3ms 2012-10-25 02:04:58 AuthenticatedMethodInterceptor [INFO] ----- Ending method: getContentByWaveRef- userhash: 1n9sg2jn48eld8o2ul8sg7b1r ----- 2012-10-25 02:05:00 PendingNotificationImmediateJob [INFO] Immediate notifications cron job start, pendingNotifications: [0, 13, 5] 2012-10-25 02:05:00 PendingNotificationImmediateJob [INFO] Immediate notifications cron job end, pendingNotifications: [0, 13, 5] 2012-10-25 02:05:43 RackServletFilter [DEBUG] REQUEST: /ws/deferredjs/263731522B89AE30DF807A092AE86150/10.cache.js 2012-10-25 02:05:43 RackServletFilter [DEBUG] REQUEST: /ws/servlets/EntityLogoDownloadManager 2012-10-25 02:05:43 ServletServiceFilter [DEBUG] SERVICE: /ws/servlets/EntityLogoDownloadManager - EntityLogoDownloadManager 2012-10-25 02:05:43 RackServletFilter [DEBUG] REQUEST: /ws/servlets/EntityLogoDownloadManager 2012-10-25 02:05:43 ServletServiceFilter [DEBUG] SERVICE: /ws/servlets/EntityLogoDownloadManager - EntityLogoDownloadManager 2012-10-25 02:05:43 RackServletFilter [DEBUG] REQUEST: /ws/servlets/EntityLogoDownloadManager 2012-10-25 02:05:43 ServletServiceFilter [DEBUG] SERVICE: /ws/servlets/EntityLogoDownloadManager - EntityLogoDownloadManager 2012-10-25 02:05:43 RackServletFilter [DEBUG] REQUEST: /ws/servlets/EntityLogoDownloadManager 2012-10-25 02:05:43 ServletServiceFilter [DEBUG] SERVICE: /ws/servlets/EntityLogoDownloadManager - EntityLogoDownloadManager 2012-10-25 02:05:51 RackServletFilter [DEBUG] REQUEST: /ws/servlets/EntityLogoDownloadManager 2012-10-25 02:05:51 ServletServiceFilter [DEBUG] SERVICE: /ws/servlets/EntityLogoDownloadManager - EntityLogoDownloadManager 2012-10-25 02:06:00 PendingNotificationImmediateJob [INFO] Immediate notifications cron job start, pendingNotifications: [0, 13, 5] 2012-10-25 02:06:00 PendingNotificationImmediateJob [INFO] Immediate notifications cron job end, pendingNotifications: [0, 13, 5] 2012-10-25 02:07:00 PendingNotificationImmediateJob [INFO] Immediate notifications cron job start, pendingNotifications: [0, 13, 5] 2012-10-25 02:07:00 PendingNotificationImmediateJob [INFO] Immediate notifications cron job end, pendingNotifications: [0, 13, 5] 2012-10-25 02:08:00 PendingNotificationImmediateJob [INFO] Immediate notifications cron job start, pendingNotifications: [0, 13, 5] 2012-10-25 02:08:00 PendingNotificationImmediateJob [INFO] Immediate notifications cron job end, pendingNotifications: [0, 13, 5] 2012-10-25 02:09:00 PendingNotificationImmediateJob [INFO] Immediate notifications cron job start, pendingNotifications: [0, 13, 5] 2012-10-25 02:09:00 PendingNotificationImmediateJob [INFO] Immediate notifications cron job end, pendingNotifications: [0, 13, 5] 2012-10-25 02:09:00 nio [WARN] java.io.IOException: Broken pipe 2012-10-25 02:09:00 WaveEmailNotifier [INFO] '[email protected]' update wave 'Emite' 2012-10-25 02:09:00 SqlExceptionHelper [WARN] SQL Error: 0, SQLState: 08003 2012-10-25 02:09:00 SqlExceptionHelper [ERROR] No operations allowed after connection closed. 2012-10-25 02:09:00 NewPooledConnection [WARN] [c3p0] A PooledConnection that has already signalled a Connection error is still in use! 2012-10-25 02:09:00 NewPooledConnection [WARN] [c3p0] Another error has occurred [ com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed. ] which will not be reported to listeners! com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed. at sun.reflect.GeneratedConstructorAccessor164.newInstance(Unknown Source) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:532) at com.mysql.jdbc.Util.handleNewInstance(Util.java:409) at com.mysql.jdbc.Util.getInstance(Util.java:384) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1015) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:989) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:984) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:929) at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1193) at com.mysql.jdbc.ConnectionImpl.getMutex(ConnectionImpl.java:3035) at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:4644) at com.mchange.v2.c3p0.impl.NewProxyConnection.rollback(NewProxyConnection.java:855) at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doRollback(JdbcTransaction.java:163) at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.rollback(AbstractTransactionImpl.java:209) at org.hibernate.ejb.TransactionImpl.rollback(TransactionImpl.java:106) at com.google.inject.persist.jpa.KuneJpaLocalTxnInterceptor.rollbackIfNecessary(KuneJpaLocalTxnInterceptor.java:161) at com.google.inject.persist.jpa.KuneJpaLocalTxnInterceptor.invoke(KuneJpaLocalTxnInterceptor.java:77) at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:72) at com.google.inject.internal.InterceptorStackCallback.intercept(InterceptorStackCallback.java:52) at cc.kune.core.server.notifier.PendingNotificationHourlyJob$$EnhancerByGuice$$701a4d54.execute(<generated>) at org.quartz.core.JobRunShell.run(JobRunShell.java:213) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) 2012-10-25 02:09:00 NewPooledConnection [WARN] [c3p0] A PooledConnection that has already signalled a Connection error is still in use! 2012-10-25 02:09:00 NewPooledConnection [WARN] [c3p0] Another error has occurred [ com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed. ] which will not be reported to listeners! com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed. at sun.reflect.GeneratedConstructorAccessor164.newInstance(Unknown Source) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:532) at com.mysql.jdbc.Util.handleNewInstance(Util.java:409) at com.mysql.jdbc.Util.getInstance(Util.java:384) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1015) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:989) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:984) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:929) at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1193) at com.mysql.jdbc.ConnectionImpl.getMutex(ConnectionImpl.java:3035) at com.mysql.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:4909) at com.mchange.v2.c3p0.impl.NewProxyConnection.setAutoCommit(NewProxyConnection.java:881) at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.releaseManagedConnection(JdbcTransaction.java:127) at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doRollback(JdbcTransaction.java:170) at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.rollback(AbstractTransactionImpl.java:209) at org.hibernate.ejb.TransactionImpl.rollback(TransactionImpl.java:106) at com.google.inject.persist.jpa.KuneJpaLocalTxnInterceptor.rollbackIfNecessary(KuneJpaLocalTxnInterceptor.java:161) at com.google.inject.persist.jpa.KuneJpaLocalTxnInterceptor.invoke(KuneJpaLocalTxnInterceptor.java:77) at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:72) at com.google.inject.internal.InterceptorStackCallback.intercept(InterceptorStackCallback.java:52) at cc.kune.core.server.notifier.PendingNotificationHourlyJob$$EnhancerByGuice$$701a4d54.execute(<generated>) at org.quartz.core.JobRunShell.run(JobRunShell.java:213) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) 2012-10-25 02:09:00 JobRunShell [ERROR] Job groupdef.pendingnotifhourlyjob threw an unhandled Exception: javax.persistence.PersistenceException: unexpected error when rollbacking at org.hibernate.ejb.TransactionImpl.rollback(TransactionImpl.java:109) at com.google.inject.persist.jpa.KuneJpaLocalTxnInterceptor.rollbackIfNecessary(KuneJpaLocalTxnInterceptor.java:161) at com.google.inject.persist.jpa.KuneJpaLocalTxnInterceptor.invoke(KuneJpaLocalTxnInterceptor.java:77) at org.quartz.core.JobRunShell.run(JobRunShell.java:213) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) Caused by: org.hibernate.TransactionException: rollback failed at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.rollback(AbstractTransactionImpl.java:215) at org.hibernate.ejb.TransactionImpl.rollback(TransactionImpl.java:106) ... 4 more Caused by: org.hibernate.TransactionException: unable to rollback against JDBC connection at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doRollback(JdbcTransaction.java:167) at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.rollback(AbstractTransactionImpl.java:209) ... 5 more Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed. at sun.reflect.GeneratedConstructorAccessor164.newInstance(Unknown Source) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:532) at com.mysql.jdbc.Util.handleNewInstance(Util.java:409) at com.mysql.jdbc.Util.getInstance(Util.java:384) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1015) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:989) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:984) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:929) at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1193) at com.mysql.jdbc.ConnectionImpl.getMutex(ConnectionImpl.java:3035) at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:4644) at com.mchange.v2.c3p0.impl.NewProxyConnection.rollback(NewProxyConnection.java:855) at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doRollback(JdbcTransaction.java:163) ... 6 more 2012-10-25 02:09:00 ErrorLogger [ERROR] Job (groupdef.pendingnotifhourlyjob threw an exception. org.quartz.SchedulerException: Job threw an unhandled exception. [See nested exception: javax.persistence.PersistenceException: unexpected error when rollbacking] at org.quartz.core.JobRunShell.run(JobRunShell.java:224) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) Caused by: javax.persistence.PersistenceException: unexpected error when rollbacking at org.hibernate.ejb.TransactionImpl.rollback(TransactionImpl.java:109) at com.google.inject.persist.jpa.KuneJpaLocalTxnInterceptor.rollbackIfNecessary(KuneJpaLocalTxnInterceptor.java:161) at com.google.inject.persist.jpa.KuneJpaLocalTxnInterceptor.invoke(KuneJpaLocalTxnInterceptor.java:77) at org.quartz.core.JobRunShell.run(JobRunShell.java:213) ... 1 more Caused by: org.hibernate.TransactionException: rollback failed at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.rollback(AbstractTransactionImpl.java:215) at org.hibernate.ejb.TransactionImpl.rollback(TransactionImpl.java:106) ... 4 more Caused by: org.hibernate.TransactionException: unable to rollback against JDBC connection at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doRollback(JdbcTransaction.java:167) at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.rollback(AbstractTransactionImpl.java:209) ... 5 more Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed. at sun.reflect.GeneratedConstructorAccessor164.newInstance(Unknown Source) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:532) at com.mysql.jdbc.Util.handleNewInstance(Util.java:409) at com.mysql.jdbc.Util.getInstance(Util.java:384) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1015) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:989) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:984) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:929) at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1193) at com.mysql.jdbc.ConnectionImpl.getMutex(ConnectionImpl.java:3035) at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:4644) at com.mchange.v2.c3p0.impl.NewProxyConnection.rollback(NewProxyConnection.java:855) at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doRollback(JdbcTransaction.java:163) ... 6 more -- You have received this notification because you have either subscribed to it, or are involved in it. To change your notification preferences, please click here: http://redmine.ourproject.org/my/account