2 Replies Latest reply on Aug 17, 2011 5:22 AM by piotr.komisarski

    Jboss 6 & problem with timerService in singleton

    piotr.komisarski

      Hi

       

      I have a problem with my singleton.

      It looks like this :

       

       

      @Singleton

      @Startup

      @Local(StartupService.class)

      public class StartupServiceBean implements StartupService {

       

      (...)

      @PostConstruct

          public void init() {

       

              ScheduleExpression schexp = new ScheduleExpression();

              schexp.second("30");

              schexp.minute("*");

              schexp.hour("*");

              timerService.createCalendarTimer(schexp);

       

       

      And i have exception:

      23:49:40,500 ERROR [org.jboss.ejb3.timerservice.mk2.task.TimerTask] Error during retyring timeout for timer: [id=aff4f3f6-a604-4786-9f36-839e23b09857 timedObjectId=jboss.j2ee:ear=com.komisarski.letter.ear-1.0.ear,jar=com.komisarski.lette

      r.backend-1.0.jar,name=StartupServiceBean,service=EJB3 auto-timer?:true persistent?:true timerService=org.jboss.ejb3.timerservice.mk2.TimerServiceImpl@1f8cdaa initialExpiration=2011-08-12 00:00:00.0 intervalDuration(in milli sec)=0 nextE

      xpiration=Fri Aug 12 23:49:50 CEST 2011 timerState=RETRY_TIMEOUT: javax.ejb.EJBException: java.lang.RuntimeException: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Cannot open connection

              at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.handleExceptionInOurTx(CMTTxInterceptor.java:183) [:0.0.1]

              at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:251) [:0.0.1]

              at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.required(CMTTxInterceptor.java:349) [:0.0.1]

              at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.invoke(CMTTxInterceptor.java:209) [:0.0.1]

              at org.jboss.ejb3.tx2.aop.CMTTxInterceptorWrapper.invoke(CMTTxInterceptorWrapper.java:52) [:0.0.1]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:76) [:1.0.0.GA]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:41) [:1.7.17]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.BlockContainerShutdownInterceptor.invoke(BlockContainerShutdownInterceptor.java:67) [:1.7.17]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.core.context.CurrentInvocationContextInterceptor.invoke(CurrentInvocationContextInterceptor.java:47) [:1.7.17]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.aspects.currentinvocation.CurrentInvocationInterceptor.invoke(CurrentInvocationInterceptor.java:67) [:1.0.1]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.interceptor.EJB3TCCLInterceptor.invoke(EJB3TCCLInterceptor.java:86) [:1.7.17]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.singleton.aop.impl.AOPBasedInterceptorRegistry.intercept(AOPBasedInterceptorRegistry.java:110) [:1.0.0-alpha-28]

              at org.jboss.ejb3.singleton.impl.container.SingletonContainer.invoke(SingletonContainer.java:206) [:1.0.0-alpha-28]

              at org.jboss.ejb3.singleton.aop.impl.AOPBasedSingletonContainer.callTimeout(AOPBasedSingletonContainer.java:886) [:1.0.0-alpha-28]

              at org.jboss.ejb3.timerservice.mk2.task.CalendarTimerTask.callTimeout(CalendarTimerTask.java:80) [:1.0.0-alpha-13]

              at org.jboss.ejb3.timerservice.mk2.task.TimerTask.run(TimerTask.java:127) [:1.0.0-alpha-13]

              at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [:1.6.0_26]

              at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [:1.6.0_26]

              at java.util.concurrent.FutureTask.run(FutureTask.java:138) [:1.6.0_26]

              at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98) [:1.6.0_26]

              at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206) [:1.6.0_26]

              at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [:1.6.0_26]

              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [:1.6.0_26]

              at java.lang.Thread.run(Thread.java:662) [:1.6.0_26]

      Caused by: java.lang.RuntimeException: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Cannot open connection

              at org.jboss.ejb3.timerservice.mk2.TimerServiceImpl.persistTimer(TimerServiceImpl.java:685) [:1.0.0-alpha-13]

              at org.jboss.ejb3.timerservice.mk2.TimerServiceImpl.createCalendarTimer(TimerServiceImpl.java:452) [:1.0.0-alpha-13]

              at org.jboss.ejb3.timerservice.mk2.TimerServiceImpl.createCalendarTimer(TimerServiceImpl.java:176) [:1.0.0-alpha-13]

              at org.jboss.ejb3.timerservice.mk2.TimerServiceImpl.createCalendarTimer(TimerServiceImpl.java:164) [:1.0.0-alpha-13]

              at com.komisarski.letter.service.startup.StartupServiceBean.init(StartupServiceBean.java:65) [:]

              at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [:1.6.0_26]

              at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [:1.6.0_26]

              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [:1.6.0_26]

              at java.lang.reflect.Method.invoke(Method.java:597) [:1.6.0_26]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeTarget(MethodInvocation.java:122) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:111) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.interceptors.container.ContainerMethodInvocationWrapper.invokeNext(ContainerMethodInvocationWrapper.java:72) [:1.1.3]

              at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.invoke(InterceptorSequencer.java:76) [:1.1.3]

              at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.aroundInvoke(InterceptorSequencer.java:62) [:1.1.3]

              at sun.reflect.GeneratedMethodAccessor1377.invoke(Unknown Source) [:1.6.0_26]

              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [:1.6.0_26]

              at java.lang.reflect.Method.invoke(Method.java:597) [:1.6.0_26]

              at org.jboss.aop.advice.PerJoinpointAdvice.invoke(PerJoinpointAdvice.java:174) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor.fillMethod(InvocationContextInterceptor.java:74) [:1.1.3]

              at org.jboss.aop.advice.org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor_z_fillMethod_13868860.invoke(InvocationContextInterceptor_z_fillMethod_13868860.java) [:]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor.setup(InvocationContextInterceptor.java:90) [:1.1.3]

              at org.jboss.aop.advice.org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor_z_setup_13868860.invoke(InvocationContextInterceptor_z_setup_13868860.java) [:]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.async.impl.interceptor.AsynchronousServerInterceptor.invoke(AsynchronousServerInterceptor.java:128) [:1.7.17]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:62) [:1.7.17]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:56) [:1.7.17]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.concurrency.aop.interceptor.ContainerManagedConcurrencyInterceptor.invoke(ContainerManagedConcurrencyInterceptor.java:181) [:1.0.0-alpha-4]

              at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:86) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47) [:1.7.17]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.tx.NullInterceptor.invoke(NullInterceptor.java:42) [:1.0.3]

              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

              at org.jboss.ejb3.core.context.SessionInvocationContextAdapter.proceed(SessionInvocationContextAdapter.java:95) [:1.7.17]

              at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:247) [:0.0.1]

              ... 29 more

      Caused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Cannot open connection

              at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1214) [:3.6.0.Final]

              at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1147) [:3.6.0.Final]

              at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1153) [:3.6.0.Final]

              at org.hibernate.ejb.AbstractEntityManagerImpl.merge(AbstractEntityManagerImpl.java:695) [:3.6.0.Final]

              at org.jboss.ejb3.timerservice.mk2.TimerServiceImpl.persistTimer(TimerServiceImpl.java:675) [:1.0.0-alpha-13]

              ... 68 more

      Caused by: org.hibernate.exception.GenericJDBCException: Cannot open connection

              at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:140) [:3.6.0.Final]

              at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:128) [:3.6.0.Final]

              at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66) [:3.6.0.Final]

              at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:52) [:3.6.0.Final]

              at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:449) [:3.6.0.Final]

              at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167) [:3.6.0.Final]

              at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:161) [:3.6.0.Final]

              at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1700) [:3.6.0.Final]

              at org.hibernate.loader.Loader.doQuery(Loader.java:801) [:3.6.0.Final]

              at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:274) [:3.6.0.Final]

              at org.hibernate.loader.Loader.loadEntity(Loader.java:2037) [:3.6.0.Final]

              at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:86) [:3.6.0.Final]

              at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:76) [:3.6.0.Final]

              at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3268) [:3.6.0.Final]

              at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:496) [:3.6.0.Final]

              at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:477) [:3.6.0.Final]

              at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:227) [:3.6.0.Final]

              at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:285) [:3.6.0.Final]

              at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:152) [:3.6.0.Final]

              at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:1090) [:3.6.0.Final]

              at org.hibernate.impl.SessionImpl.get(SessionImpl.java:1005) [:3.6.0.Final]

              at org.hibernate.event.def.DefaultMergeEventListener.entityIsDetached(DefaultMergeEventListener.java:453) [:3.6.0.Final]

              at org.hibernate.event.def.DefaultMergeEventListener.onMerge(DefaultMergeEventListener.java:255) [:3.6.0.Final]

              at org.hibernate.event.def.DefaultMergeEventListener.onMerge(DefaultMergeEventListener.java:84) [:3.6.0.Final]

              at org.hibernate.impl.SessionImpl.fireMerge(SessionImpl.java:867) [:3.6.0.Final]

              at org.hibernate.impl.SessionImpl.merge(SessionImpl.java:851) [:3.6.0.Final]

              at org.hibernate.impl.SessionImpl.merge(SessionImpl.java:855) [:3.6.0.Final]

              at org.hibernate.ejb.AbstractEntityManagerImpl.merge(AbstractEntityManagerImpl.java:686) [:3.6.0.Final]

              ... 69 more

      Caused by: org.jboss.util.NestedSQLException: Could not enlist in transaction on entering meta-aware object!; - nested throwable: (javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warni

      ngs. tx=TransactionImple < ac, BasicAction: 0:ffffa9fed43b:126a:4e459236:92e status: ActionStatus.ABORT_ONLY >); - nested throwable: (org.jboss.resource.JBossResourceException: Could not enlist in transaction on entering meta-aware objec

      t!; - nested throwable: (javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: 0:ffffa9fed43b:126a:4e459236:92e status: ActionStatus.ABORT_ON

      LY >))

              at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:95) [:6.0.0.Final]

              at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:71) [:3.6.0.Final]

              at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446) [:3.6.0.Final]

              ... 92 more

      Caused by: org.jboss.resource.JBossResourceException: Could not enlist in transaction on entering meta-aware object!; - nested throwable: (javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previo

      us warnings. tx=TransactionImple < ac, BasicAction: 0:ffffa9fed43b:126a:4e459236:92e status: ActionStatus.ABORT_ONLY >)

              at org.jboss.resource.connectionmanager.TxConnectionManager.managedConnectionReconnected(TxConnectionManager.java:465) [:6.0.0.Final]

              at org.jboss.resource.connectionmanager.BaseConnectionManager2.reconnectManagedConnection(BaseConnectionManager2.java:625) [:6.0.0.Final]

              at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:499) [:6.0.0.Final]

              at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:941) [:6.0.0.Final]

              at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:89) [:6.0.0.Final]

              ... 94 more

      Caused by: javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: 0:ffffa9fed43b:126a:4e459236:92e status: ActionStatus.ABORT_ONLY >

              at org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener$TransactionSynchronization.checkEnlisted(TxConnectionManager.java:946) [:6.0.0.Final]

              at org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener.enlist(TxConnectionManager.java:742) [:6.0.0.Final]

              at org.jboss.resource.connectionmanager.TxConnectionManager.managedConnectionReconnected(TxConnectionManager.java:459) [:6.0.0.Final]

              ... 98 more

       

       

       

       

      But when i changed @PostConstruct  to @Schedule(second="*/10", minute="*",hour="*", persistent=true)

      everything is working fine. So i believe, that during startup of a singleton bean jboss is not ready yet to persist timer (it's only my theory)

      But why ?  And how i can avoid these exceptions ?