glassfish
  1. glassfish
  2. GLASSFISH-17221

Cluster hangs during startup when timer app is deployed

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 3.1.1
    • Fix Version/s: 3.1.2_b15
    • Component/s: jts
    • Labels:
      None
    • Environment:

      Glassfish 3.1.1 open source release. Java version 1.6.0_26 64 bit. SLES 11.

      Description

      I can deploy an application that uses timers while the cluster is running and everything seems fine. However, once I stop the cluster and then try to start it again it hangs. The point that it hangs in the logs is with this message:

      [#|2011-08-22T15:16:25.136-0400|INFO|glassfish3.1.1|javax.enterprise.resource.resourceadapter.com.sun.enterprise.connectors.inbound|_ThreadID=18;_ThreadName=Thread-2;|Recovery of Inbound Transactions started.|#]

      After some trial and error I found that this is a problem even when there are not actually any timers in existence. It happens as long as a bean is deployed that might use a timer, even if it is not actually using one. It only takes a single bean in an ejb jar to reproduce the problem. I will attach the source for that bean.

      I have run in to this before (see GLASSFISH-16072) and then had trouble reproducing it with a basic install so I think there might be some relation to my specific configuration (datasource used for the timer, database vendor, the fact that it is a cluster and not a standalone instance, I don't know). I'm not doing anything exotic, just an Oracle database and XA datasource for the timer and a 2 node cluster, but it's more than a vanilla install. So I will also tar and attach my domain config directory.

      I have a stack dump that shows where things are hanging up. It involves two threads, shown below:

      "Recovery Helper Thread" daemon prio=10 tid=0x00007f20f07d7000 nid=0x2bf1 waiting for monitor entry [0x00007f20e6fed000]
      java.lang.Thread.State: BLOCKED (on object monitor)
      at com.sun.hk2.component.SingletonInhabitant.get(SingletonInhabitant.java:63)

      • waiting to lock <0x00000000c0c9e368> (a com.sun.hk2.component.SingletonInhabitant)
        at com.sun.hk2.component.EventPublishingInhabitant.get(EventPublishingInhabitant.java:139)
        at com.sun.hk2.component.AbstractInhabitantImpl.get(AbstractInhabitantImpl.java:76)
        at org.jvnet.hk2.component.Habitat.getComponent(Habitat.java:796)
        at com.sun.enterprise.resource.recovery.ConnectorsRecoveryResourceHandler.loadXAResourcesAndItsConnections(ConnectorsRecoveryResourceHandler.java:217)
        at com.sun.enterprise.transaction.jts.ResourceRecoveryManagerImpl.getAllRecoverableResources(ResourceRecoveryManagerImpl.java:210)
        at com.sun.enterprise.transaction.jts.ResourceRecoveryManagerImpl.recoverXAResources(ResourceRecoveryManagerImpl.java:234)
        at com.sun.enterprise.transaction.jts.ResourceRecoveryManagerImpl.recoverXAResources(ResourceRecoveryManagerImpl.java:331)
        at com.sun.enterprise.transaction.jts.ResourceRecoveryManagerImpl.postConstruct(ResourceRecoveryManagerImpl.java:106)
        at com.sun.hk2.component.AbstractCreatorImpl.inject(AbstractCreatorImpl.java:131)
        at com.sun.hk2.component.ConstructorCreator.initialize(ConstructorCreator.java:91)
        at com.sun.hk2.component.AbstractCreatorImpl.get(AbstractCreatorImpl.java:82)
        at com.sun.hk2.component.SingletonInhabitant.get(SingletonInhabitant.java:67)
      • locked <0x00000000eb716f10> (a com.sun.hk2.component.SingletonInhabitant)
        at com.sun.hk2.component.EventPublishingInhabitant.get(EventPublishingInhabitant.java:139)
        at com.sun.hk2.component.AbstractInhabitantImpl.get(AbstractInhabitantImpl.java:76)
        at org.jvnet.hk2.component.Habitat.getByContract(Habitat.java:1042)
        at com.sun.jts.jta.TransactionServiceProperties$RecoveryHelperThread.run(TransactionServiceProperties.java:355)

      "main" prio=10 tid=0x0000000040114800 nid=0x2b55 in Object.wait() [0x00007f20fa83c000]
      java.lang.Thread.State: WAITING (on object monitor)
      at java.lang.Object.wait(Native Method)

      • waiting on <0x00000000c0658f20> (a com.sun.jts.CosTransactions.EventSemaphore)
        at java.lang.Object.wait(Object.java:485)
        at com.sun.jts.CosTransactions.EventSemaphore.waitEvent(EventSemaphore.java:133)
      • locked <0x00000000c0658f20> (a com.sun.jts.CosTransactions.EventSemaphore)
        at com.sun.jts.CosTransactions.RecoveryManager.waitForResync(RecoveryManager.java:1452)
        at com.sun.jts.CosTransactions.TransactionFactoryImpl.localCreate(TransactionFactoryImpl.java:180)
        at com.sun.jts.CosTransactions.CurrentImpl.begin(CurrentImpl.java:431)
        at com.sun.jts.jta.TransactionManagerImpl.begin(TransactionManagerImpl.java:288)
        at com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.beginJTS(JavaEETransactionManagerJTSDelegate.java:499)
        at com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.startJTSTx(JavaEETransactionManagerJTSDelegate.java:402)
        at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.startJTSTx(JavaEETransactionManagerSimplified.java:413)
        at com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.enlistLAOResource(JavaEETransactionManagerJTSDelegate.java:319)
        at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.enlistResource(JavaEETransactionManagerSimplified.java:345)
        at com.sun.enterprise.resource.rm.SystemResourceManagerImpl.enlistResource(SystemResourceManagerImpl.java:103)
        at com.sun.enterprise.resource.pool.PoolManagerImpl.getResource(PoolManagerImpl.java:208)
        at com.sun.enterprise.connectors.ConnectionManagerImpl.getResource(ConnectionManagerImpl.java:332)
        at com.sun.enterprise.connectors.ConnectionManagerImpl.internalGetConnection(ConnectionManagerImpl.java:301)
        at com.sun.enterprise.connectors.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:190)
        at com.sun.enterprise.connectors.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:165)
        at com.sun.enterprise.connectors.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:160)
        at com.sun.gjc.spi.base.DataSource.getConnection(DataSource.java:113)
        at org.eclipse.persistence.sessions.JNDIConnector.connect(JNDIConnector.java:123)
        at org.eclipse.persistence.sessions.DatasourceLogin.connectToDatasource(DatasourceLogin.java:162)
        at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.connectInternal(DatasourceAccessor.java:330)
        at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.connectInternal(DatabaseAccessor.java:293)
        at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.connect(DatasourceAccessor.java:418)
        at org.eclipse.persistence.sessions.server.ConnectionPool.buildConnection(ConnectionPool.java:216)
        at org.eclipse.persistence.sessions.server.ExternalConnectionPool.startUp(ExternalConnectionPool.java:146)
      • locked <0x00000000eb397270> (a org.eclipse.persistence.sessions.server.ExternalConnectionPool)
        at org.eclipse.persistence.sessions.server.ServerSession.connect(ServerSession.java:489)
        at org.eclipse.persistence.internal.sessions.DatabaseSessionImpl.loginAndDetectDatasource(DatabaseSessionImpl.java:617)
        at org.eclipse.persistence.internal.jpa.EntityManagerFactoryProvider.login(EntityManagerFactoryProvider.java:206)
        at org.eclipse.persistence.internal.jpa.EntityManagerSetupImpl.deploy(EntityManagerSetupImpl.java:472)
      • locked <0x00000000fc73a688> (a org.eclipse.persistence.sessions.server.ServerSession)
        at org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate.getDatabaseSession(EntityManagerFactoryDelegate.java:188)
      • locked <0x00000000fc67cd90> (a org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate)
        at org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate.createEntityManagerImpl(EntityManagerFactoryDelegate.java:277)
        at org.eclipse.persistence.internal.jpa.EntityManagerFactoryImpl.createEntityManagerImpl(EntityManagerFactoryImpl.java:290)
        at org.eclipse.persistence.internal.jpa.EntityManagerFactoryImpl.createEntityManager(EntityManagerFactoryImpl.java:275)
        at com.sun.enterprise.container.common.impl.EntityManagerWrapper._getDelegate(EntityManagerWrapper.java:208)
        at com.sun.enterprise.container.common.impl.EntityManagerWrapper.createNamedQuery(EntityManagerWrapper.java:532)
        at com.sun.ejb.containers.TimerBean.findTimersByOwnerAndState(TimerBean.java:201)
        at com.sun.ejb.containers.TimerBean.findActiveTimersOwnedByThisServer(TimerBean.java:518)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1052)
        at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1124)
        at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:5366)
        at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:619)
        at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:800)
        at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:571)
        at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doAround(SystemInterceptorProxy.java:162)
        at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundInvoke(SystemInterceptorProxy.java:144)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:861)
        at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:800)
        at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:370)
        at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:5338)
        at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:5326)
        at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:214)
        at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:88)
        at $Proxy133.findActiveTimersOwnedByThisServer(Unknown Source)
        at com.sun.ejb.containers.EJBTimerService.restoreEJBTimers(EJBTimerService.java:486)
        at com.sun.ejb.containers.EjbContainerUtilImpl.getEJBTimerService(EjbContainerUtilImpl.java:307)
        at com.sun.ejb.containers.EjbContainerUtilImpl.getEJBTimerService(EjbContainerUtilImpl.java:289)
        at com.sun.ejb.containers.EjbContainerUtilImpl.getEJBTimerService(EjbContainerUtilImpl.java:274)
        at com.sun.ejb.containers.BaseContainer.<init>(BaseContainer.java:755)
        at com.sun.ejb.containers.AbstractSingletonContainer.<init>(AbstractSingletonContainer.java:141)
        at com.sun.ejb.containers.CMCSingletonContainer.<init>(CMCSingletonContainer.java:77)
        at com.sun.ejb.containers.ContainerFactoryImpl.createContainer(ContainerFactoryImpl.java:115)
        at org.glassfish.ejb.startup.EjbApplication.loadContainers(EjbApplication.java:230)
        at org.glassfish.ejb.startup.EjbDeployer.load(EjbDeployer.java:290)
        at org.glassfish.ejb.startup.EjbDeployer.load(EjbDeployer.java:101)
        at org.glassfish.internal.data.ModuleInfo.load(ModuleInfo.java:186)
        at org.glassfish.internal.data.ApplicationInfo.load(ApplicationInfo.java:257)
        at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:461)
        at com.sun.enterprise.v3.server.ApplicationLoaderService.processApplication(ApplicationLoaderService.java:375)
        at com.sun.enterprise.v3.server.ApplicationLoaderService.postConstruct(ApplicationLoaderService.java:219)
        at com.sun.hk2.component.AbstractCreatorImpl.inject(AbstractCreatorImpl.java:131)
        at com.sun.hk2.component.ConstructorCreator.initialize(ConstructorCreator.java:91)
        at com.sun.hk2.component.AbstractCreatorImpl.get(AbstractCreatorImpl.java:82)
        at com.sun.hk2.component.SingletonInhabitant.get(SingletonInhabitant.java:67)
      • locked <0x00000000c0c9e368> (a com.sun.hk2.component.SingletonInhabitant)
        at com.sun.hk2.component.EventPublishingInhabitant.get(EventPublishingInhabitant.java:139)
        at com.sun.hk2.component.AbstractInhabitantImpl.get(AbstractInhabitantImpl.java:76)
        at com.sun.enterprise.v3.server.AppServerStartup.run(AppServerStartup.java:253)
        at com.sun.enterprise.v3.server.AppServerStartup.doStart(AppServerStartup.java:145)
        at com.sun.enterprise.v3.server.AppServerStartup.start(AppServerStartup.java:136)
      • locked <0x00000000fc50a878> (a com.sun.enterprise.v3.server.AppServerStartup)
        at com.sun.enterprise.glassfish.bootstrap.GlassFishImpl.start(GlassFishImpl.java:79)
      • locked <0x00000000fc50a860> (a com.sun.enterprise.glassfish.bootstrap.GlassFishImpl)
        at com.sun.enterprise.glassfish.bootstrap.GlassFishDecorator.start(GlassFishDecorator.java:63)
        at com.sun.enterprise.glassfish.bootstrap.osgi.OSGiGlassFishImpl.start(OSGiGlassFishImpl.java:69)
        at com.sun.enterprise.glassfish.bootstrap.GlassFishMain$Launcher.launch(GlassFishMain.java:117)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at com.sun.enterprise.glassfish.bootstrap.GlassFishMain.main(GlassFishMain.java:97)
        at com.sun.enterprise.glassfish.bootstrap.ASMain.main(ASMain.java:55)
      1. config.tgz
        87 kB
        sarnoth
      2. TimerSingletonBean.java
        1 kB
        sarnoth

        Activity

        Hide
        sarnoth added a comment -

        I tried with 3.1.2 b15 and it seems to be fixed.

        Show
        sarnoth added a comment - I tried with 3.1.2 b15 and it seems to be fixed.
        Hide
        marina vatkina added a comment -

        Thank you for confirming!

        Show
        marina vatkina added a comment - Thank you for confirming!
        Hide
        gray added a comment -

        This same bug appears on 4.0

        Show
        gray added a comment - This same bug appears on 4.0
        Hide
        magadan4ester added a comment -

        And 4.0.1-b03

        Show
        magadan4ester added a comment - And 4.0.1-b03
        Hide
        davidwinters1980 added a comment -

        This same issue occurs on the latest GF build. I raised another defect for this issue on 4.0.x: https://java.net/jira/browse/GLASSFISH-21175?filter=-2

        Show
        davidwinters1980 added a comment - This same issue occurs on the latest GF build. I raised another defect for this issue on 4.0.x: https://java.net/jira/browse/GLASSFISH-21175?filter=-2

          People

          • Assignee:
            marina vatkina
            Reporter:
            sarnoth
          • Votes:
            1 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: