1 Reply Latest reply on Feb 13, 2008 5:18 AM by jaikiran

    EntityManagerFactory does not shutdown cleanly on JBoss-5.0B

    jaikiran

      I am trying out a simple EJB3 application on JBoss-5.0 Beta3, Java 1.5. The application includes a StatelessSessionBean, a few entities and a persistence unit. The application deploys properly and works as per expectations. However, when i shutdown JBoss, i see the following exceptions in the logs:

      2008-02-12 12:58:34,208 INFO [org.jboss.ejb3.entity.PersistenceUnitDeployment] Stopping persistence unit persistence.units:ear=EJB3Persistence.ear,jar=myapp_ejb3.jar,unitName=EJB3Persistence
      2008-02-12 12:58:37,896 INFO [org.hibernate.impl.SessionFactoryImpl] closing
      2008-02-12 12:58:37,896 INFO [org.hibernate.impl.SessionFactoryObjectFactory] Unbinding factory from JNDI name: persistence.units:ear=EJB3Persistence.ear,jar=myapp_ejb3.jar,unitName=EJB3Persistence
      2008-02-12 12:58:37,896 INFO [org.hibernate.util.NamingHelper] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
      2008-02-12 12:59:37,710 ERROR [org.hibernate.util.NamingHelper] Could not obtain initial context
      javax.naming.NoInitialContextException: Cannot instantiate class: org.jnp.interfaces.NamingContextFactory [Root exception is java.lang.ClassNotFoundException: org.jnp.interfaces.NamingContextFactory]
       at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:657)
       at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:247)
       at javax.naming.InitialContext.init(InitialContext.java:223)
       at javax.naming.InitialContext.<init>(InitialContext.java:197)
       at org.hibernate.util.NamingHelper.getInitialContext(NamingHelper.java:28)
       at org.hibernate.impl.SessionFactoryObjectFactory.removeInstance(SessionFactoryObjectFactory.java:115)
       at org.hibernate.impl.SessionFactoryImpl.close(SessionFactoryImpl.java:806)
       at org.hibernate.ejb.EntityManagerFactoryImpl.close(EntityManagerFactoryImpl.java:43)
       at org.jboss.ejb3.entity.ManagedEntityManagerFactory.destroy(ManagedEntityManagerFactory.java:95)
       at org.jboss.ejb3.entity.PersistenceUnitDeployment.stop(PersistenceUnitDeployment.java:292)
       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:585)
       at org.jboss.reflect.plugins.introspection.ReflectionUtils.invoke(ReflectionUtils.java:56)
       at org.jboss.reflect.plugins.introspection.ReflectMethodInfoImpl.invoke(ReflectMethodInfoImpl.java:110)
       at org.jboss.joinpoint.plugins.BasicMethodJoinPoint.dispatch(BasicMethodJoinPoint.java:66)
       at org.jboss.kernel.plugins.dependency.KernelControllerContextAction$JoinpointDispatchWrapper.execute(KernelControllerContextAction.java:214)
       at org.jboss.kernel.plugins.dependency.ExecutionWrapper.execute(ExecutionWrapper.java:45)
       at org.jboss.kernel.plugins.dependency.KernelControllerContextAction.dispatchExecutionWrapper(KernelControllerContextAction.java:108)
       at org.jboss.kernel.plugins.dependency.KernelControllerContextAction.dispatchJoinPoint(KernelControllerContextAction.java:69)
       at org.jboss.kernel.plugins.dependency.LifecycleAction.uninstallActionInternal(LifecycleAction.java:249)
       at org.jboss.kernel.plugins.dependency.KernelControllerContextAction.uninstallAction(KernelControllerContextAction.java:167)
       at org.jboss.kernel.plugins.dependency.KernelControllerContextAction.uninstallAction(KernelControllerContextAction.java:46)
       at org.jboss.dependency.plugins.action.SimpleControllerContextAction.simpleUninstallAction(SimpleControllerContextAction.java:79)
       at org.jboss.dependency.plugins.action.AccessControllerContextAction.uninstall(AccessControllerContextAction.java:131)
       at org.jboss.dependency.plugins.AbstractControllerContextActions.uninstall(AbstractControllerContextActions.java:58)
       at org.jboss.dependency.plugins.AbstractControllerContext.uninstall(AbstractControllerContext.java:333)
       at org.jboss.dependency.plugins.AbstractController.uninstall(AbstractController.java:1323)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:1009)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:936)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:986)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:936)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:986)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:936)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:986)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:936)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:986)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:936)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:986)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:936)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:986)
       at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:627)
       at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:411)
       at org.jboss.system.ServiceController.doChange(ServiceController.java:659)
       at org.jboss.system.ServiceController.stop(ServiceController.java:481)
       at org.jboss.system.deployers.ServiceDeployer.stop(ServiceDeployer.java:156)
       at org.jboss.system.deployers.ServiceDeployer.undeploy(ServiceDeployer.java:136)
       at org.jboss.system.deployers.ServiceDeployer.undeploy(ServiceDeployer.java:46)
       at org.jboss.deployers.spi.deployer.helpers.AbstractSimpleRealDeployer.internalUndeploy(AbstractSimpleRealDeployer.java:73)
       at org.jboss.deployers.spi.deployer.helpers.AbstractRealDeployer.undeploy(AbstractRealDeployer.java:112)
       at org.jboss.deployers.plugins.deployers.DeployerWrapper.undeploy(DeployerWrapper.java:187)
       at org.jboss.deployers.plugins.deployers.DeployersImpl.doUninstallParentLast(DeployersImpl.java:1072)
       at org.jboss.deployers.plugins.deployers.DeployersImpl.doUninstallParentLast(DeployersImpl.java:1065)
       at org.jboss.deployers.plugins.deployers.DeployersImpl.uninstall(DeployersImpl.java:1027)
       at org.jboss.dependency.plugins.AbstractControllerContext.uninstall(AbstractControllerContext.java:333)
       at org.jboss.dependency.plugins.AbstractController.uninstall(AbstractController.java:1323)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:1009)
       at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:627)
       at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:411)
       at org.jboss.deployers.plugins.deployers.DeployersImpl.process(DeployersImpl.java:423)
       at org.jboss.deployers.plugins.main.MainDeployerImpl.process(MainDeployerImpl.java:506)
       at org.jboss.deployers.plugins.main.MainDeployerImpl.shutdown(MainDeployerImpl.java:543)
       at org.jboss.system.server.profileservice.ProfileServiceBootstrap.shutdown(ProfileServiceBootstrap.java:151)
       at org.jboss.bootstrap.AbstractServerImpl.shutdownServer(AbstractServerImpl.java:505)
       at org.jboss.bootstrap.AbstractServerImpl$ShutdownHook.run(AbstractServerImpl.java:824)
      Caused by: java.lang.ClassNotFoundException: org.jnp.interfaces.NamingContextFactory
       at java.net.URLClassLoader$1.run(URLClassLoader.java:200)
       at java.security.AccessController.doPrivileged(Native Method)
       at java.net.URLClassLoader.findClass(URLClassLoader.java:188)
       at java.lang.ClassLoader.loadClass(ClassLoader.java:306)
       at java.lang.ClassLoader.loadClass(ClassLoader.java:251)
       at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:319)
       at java.lang.Class.forName0(Native Method)
       at java.lang.Class.forName(Class.java:242)
       at com.sun.naming.internal.VersionHelper12.loadClass(VersionHelper12.java:42)
       at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:654)
       ... 65 more
      2008-02-12 12:59:37,726 WARN [org.hibernate.impl.SessionFactoryObjectFactory] Could not unbind factory from JNDI
      javax.naming.NoInitialContextException: Cannot instantiate class: org.jnp.interfaces.NamingContextFactory [Root exception is java.lang.ClassNotFoundException: org.jnp.interfaces.NamingContextFactory]
       at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:657)
       at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:247)
       at javax.naming.InitialContext.init(InitialContext.java:223)
       at javax.naming.InitialContext.<init>(InitialContext.java:197)
       at org.hibernate.util.NamingHelper.getInitialContext(NamingHelper.java:28)
       at org.hibernate.impl.SessionFactoryObjectFactory.removeInstance(SessionFactoryObjectFactory.java:115)
       at org.hibernate.impl.SessionFactoryImpl.close(SessionFactoryImpl.java:806)
       at org.hibernate.ejb.EntityManagerFactoryImpl.close(EntityManagerFactoryImpl.java:43)
       at org.jboss.ejb3.entity.ManagedEntityManagerFactory.destroy(ManagedEntityManagerFactory.java:95)
       at org.jboss.ejb3.entity.PersistenceUnitDeployment.stop(PersistenceUnitDeployment.java:292)
       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:585)
       at org.jboss.reflect.plugins.introspection.ReflectionUtils.invoke(ReflectionUtils.java:56)
       at org.jboss.reflect.plugins.introspection.ReflectMethodInfoImpl.invoke(ReflectMethodInfoImpl.java:110)
       at org.jboss.joinpoint.plugins.BasicMethodJoinPoint.dispatch(BasicMethodJoinPoint.java:66)
       at org.jboss.kernel.plugins.dependency.KernelControllerContextAction$JoinpointDispatchWrapper.execute(KernelControllerContextAction.java:214)
       at org.jboss.kernel.plugins.dependency.ExecutionWrapper.execute(ExecutionWrapper.java:45)
       at org.jboss.kernel.plugins.dependency.KernelControllerContextAction.dispatchExecutionWrapper(KernelControllerContextAction.java:108)
       at org.jboss.kernel.plugins.dependency.KernelControllerContextAction.dispatchJoinPoint(KernelControllerContextAction.java:69)
       at org.jboss.kernel.plugins.dependency.LifecycleAction.uninstallActionInternal(LifecycleAction.java:249)
       at org.jboss.kernel.plugins.dependency.KernelControllerContextAction.uninstallAction(KernelControllerContextAction.java:167)
       at org.jboss.kernel.plugins.dependency.KernelControllerContextAction.uninstallAction(KernelControllerContextAction.java:46)
       at org.jboss.dependency.plugins.action.SimpleControllerContextAction.simpleUninstallAction(SimpleControllerContextAction.java:79)
       at org.jboss.dependency.plugins.action.AccessControllerContextAction.uninstall(AccessControllerContextAction.java:131)
       at org.jboss.dependency.plugins.AbstractControllerContextActions.uninstall(AbstractControllerContextActions.java:58)
       at org.jboss.dependency.plugins.AbstractControllerContext.uninstall(AbstractControllerContext.java:333)
       at org.jboss.dependency.plugins.AbstractController.uninstall(AbstractController.java:1323)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:1009)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:936)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:986)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:936)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:986)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:936)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:986)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:936)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:986)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:936)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:986)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:936)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:986)
       at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:627)
       at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:411)
       at org.jboss.system.ServiceController.doChange(ServiceController.java:659)
       at org.jboss.system.ServiceController.stop(ServiceController.java:481)
       at org.jboss.system.deployers.ServiceDeployer.stop(ServiceDeployer.java:156)
       at org.jboss.system.deployers.ServiceDeployer.undeploy(ServiceDeployer.java:136)
       at org.jboss.system.deployers.ServiceDeployer.undeploy(ServiceDeployer.java:46)
       at org.jboss.deployers.spi.deployer.helpers.AbstractSimpleRealDeployer.internalUndeploy(AbstractSimpleRealDeployer.java:73)
       at org.jboss.deployers.spi.deployer.helpers.AbstractRealDeployer.undeploy(AbstractRealDeployer.java:112)
       at org.jboss.deployers.plugins.deployers.DeployerWrapper.undeploy(DeployerWrapper.java:187)
       at org.jboss.deployers.plugins.deployers.DeployersImpl.doUninstallParentLast(DeployersImpl.java:1072)
       at org.jboss.deployers.plugins.deployers.DeployersImpl.doUninstallParentLast(DeployersImpl.java:1065)
       at org.jboss.deployers.plugins.deployers.DeployersImpl.uninstall(DeployersImpl.java:1027)
       at org.jboss.dependency.plugins.AbstractControllerContext.uninstall(AbstractControllerContext.java:333)
       at org.jboss.dependency.plugins.AbstractController.uninstall(AbstractController.java:1323)
       at org.jboss.dependency.plugins.AbstractController.uninstallContext(AbstractController.java:1009)
       at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:627)
       at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:411)
       at org.jboss.deployers.plugins.deployers.DeployersImpl.process(DeployersImpl.java:423)
       at org.jboss.deployers.plugins.main.MainDeployerImpl.process(MainDeployerImpl.java:506)
       at org.jboss.deployers.plugins.main.MainDeployerImpl.shutdown(MainDeployerImpl.java:543)
       at org.jboss.system.server.profileservice.ProfileServiceBootstrap.shutdown(ProfileServiceBootstrap.java:151)
       at org.jboss.bootstrap.AbstractServerImpl.shutdownServer(AbstractServerImpl.java:505)
       at org.jboss.bootstrap.AbstractServerImpl$ShutdownHook.run(AbstractServerImpl.java:824)
      Caused by: java.lang.ClassNotFoundException: org.jnp.interfaces.NamingContextFactory
       at java.net.URLClassLoader$1.run(URLClassLoader.java:200)
       at java.security.AccessController.doPrivileged(Native Method)
       at java.net.URLClassLoader.findClass(URLClassLoader.java:188)
       at java.lang.ClassLoader.loadClass(ClassLoader.java:306)
       at java.lang.ClassLoader.loadClass(ClassLoader.java:251)
       at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:319)
       at java.lang.Class.forName0(Native Method)
       at java.lang.Class.forName(Class.java:242)
       at com.sun.naming.internal.VersionHelper12.loadClass(VersionHelper12.java:42)
       at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:654)
       ... 65 more
      
      
      


      A bit of debugging showed that the Shutdown hook thread which triggers the close of the EntityManagerFactory sets the context classloader of the thread to org.jboss.system.NoAnnotationURLClassLoader because of which the org.jnp.interfaces.NamingContextFactory class is not found by the classloader or its parent classloader.

      Just for the sake of testing, i changed the code in the destroy method of the org.jboss.ejb3.entity.ManagedEntityManagerFactory to set the context classloader before invoking the close method of the entitymanager factory as follows:

      public void destroy()
       {
       System.out.println("Classloader of entity manager factory is : " + entityManagerFactory.getClass().getClassLoader());
      
       ClassLoader origClassloader = Thread.currentThread().getContextClassLoader();
       try {
       System.out.println("Setting the context classloader of " + Thread.currentThread() + " to " + entityManagerFactory.getClass().getClassLoader());
       Thread.currentThread().setContextClassLoader(entityManagerFactory.getClass().getClassLoader());
       entityManagerFactory.close();
       } finally {
       Thread.currentThread().setContextClassLoader(origClassloader);
       System.out.println("Reset classloader of thread : " + Thread.currentThread() + " to " + origClassloader);
       }
       }
      


      This worked and i no longer see the exception. Here's the logs on JBoss shutdown:

      2008-02-12 15:38:51,956 INFO [org.jboss.ejb3.entity.PersistenceUnitDeployment] Stopping persistence unit persistence.units:ear=EJB3Persistence.ear,jar=myapp_ejb3.jar,unitName=EJB3Persistence
      2008-02-12 15:38:51,971 INFO [STDOUT] Classloader of entity manager factory is : org.jboss.mx.loading.UnifiedClassLoader3@1cefde4{ url=vfsfile:/D:/jboss-5.0.0.Beta3/server/jaikiran/conf/jboss-service.xml ,addedOrder=2}
      2008-02-12 15:38:51,971 INFO [STDOUT] Setting the context classloader of Thread[JBoss Shutdown Hook,5,jboss] to org.jboss.mx.loading.UnifiedClassLoader3@1cefde4{ url=vfsfile:/D:/jboss-5.0.0.Beta3/server/jaikiran/conf/jboss-service.xml ,addedOrder=2}
      2008-02-12 15:38:51,987 INFO [org.hibernate.impl.SessionFactoryImpl] closing
      2008-02-12 15:38:51,987 INFO [org.hibernate.impl.SessionFactoryObjectFactory] Unbinding factory from JNDI name: persistence.units:ear=EJB3Persistence.ear,jar=myapp_ejb3.jar,unitName=EJB3Persistence
      2008-02-12 15:38:52,003 INFO [org.hibernate.util.NamingHelper] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
      2008-02-12 15:38:52,018 INFO [org.hibernate.impl.SessionFactoryObjectFactory] Unbound factory from JNDI name: persistence.units:ear=EJB3Persistence.ear,jar=myapp_ejb3.jar,unitName=EJB3Persistence
      2008-02-12 15:38:52,018 TRACE [org.jboss.mx.loading.RepositoryClassLoader] getResourceLocally(org.jboss.mx.loading.UnifiedClassLoader3@142c63f{ url=vfsfile:/D:/jboss-5.0.0.Beta3/server/jaikiran/deployers/bsh.deployer/ ,addedOrder=3}), name=org/apache/tomcat/util/buf/ByteChunk$ByteOutputChannel.class, resURL:null
      2008-02-12 15:38:52,018 INFO [STDOUT] Reset classloader of thread : Thread[JBoss Shutdown Hook,5,jboss] to org.jboss.system.NoAnnotationURLClassLoader@1bbdd48
      
      


      The code change that i did was just for testing and there might be a better way to achieve this. I searched the JIRA to see if this has been reported before, but could not find any. Do i open a new issue (i can add my sample application and the classloader logs, if that's required) for this or did i miss a already reported issue in the JIRA?


        • 1. Re: EntityManagerFactory does not shutdown cleanly on JBoss-
          jaikiran

          Downloaded JBoss-5.0 Beta 4, which was released yesterday. This issue is not present on Beta 4. Everything works fine during shutdown:

          15:41:35,556 INFO [PersistenceUnitDeployment] Stopping persistence unit persistence.units:ear=EJB3Persistence.ear,jar=myapp_ejb3.jar,unitName=EJB3Persistence
          15:41:35,571 INFO [SessionFactoryImpl] closing
          15:41:35,571 INFO [SessionFactoryObjectFactory] Unbinding factory from JNDI name: persistence.units:ear=EJB3Persistence.ear,jar=myapp_ejb3.jar,unitName=EJB3Persistence
          15:41:35,587 INFO [NamingHelper] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          15:41:35,587 INFO [SessionFactoryObjectFactory] Unbound factory from JNDI name: persistence.units:ear=EJB3Persistence.ear,jar=myapp_ejb3.jar,unitName=EJB3Persistence
          


          I'll move to Beta 4 and wont open a issue in JIRA.