Sporadic lookup failure for @Singleton @Startup EJB on JDK8 /FISH-745

[chrjohn]

Description

---

This is probably related to #1279 and I've copied some of the description here. However, the problem seems to manifest a little differently, although the outcome is the same (unsuccessful deployment on startup of Payara).

However, now the problem seems only to occur when using JDK8 and not on JDK11 (other JDKs in between not tested)

The Singleton bean is part of a WAB (web application bundle, OSGi), so it is a WAR file. I heard somewhere that WARs are deployed differently from JARs (even concurrently?), so maybe this is the basic problem.

I have condensed a minimal test case which exhibits the problem. Please see #1279 for the reproducer.

Expected Outcome

I would expect that Payara handles the deployment in a way that it should deploy dependent EJBs first. When starting up the the Singleton bean, the needed EJBs need to be available.

Current Outcome

In most of the cases the startup of the bundle which contains the Singleton bean fails. It might be happening more frequently when clearing the osgi-cache folder before startup of Payara. But this might have been coincidental.

Steps to reproduce (Only for bug reports)

1 - setup a new domain 2 - start the domain 3 - deploy bundles (rename to have JAR/WAR ending) - payarabug-singletonstartup-0.0.1-SNAPSHOT needs WAR ending, the others JAR ending

asadmin --terse deploy --force --type osgi payarabug-singletonstartup-interface-0.0.1-SNAPSHOT.jar
asadmin --terse deploy --force --type osgi payarabug-singletonstartup-implementation-0.0.1-SNAPSHOT.jar
asadmin --terse deploy --force --type osgi payarabug-singletonstartup-0.0.1-SNAPSHOT.war

4- restart Payara a few times and wait for an error like this:

[2020-10-03T23:27:43.390+0200] [Payara 5.2020.4] [WARNING] [] [org.glassfish.osgijavaeebase] [tid: _ThreadID=143 _ThreadName=Thread-21] [timeMillis: 1601760463390] [levelValue: 900] [[
  Failed to deploy bundle com.macd.payarabug-singletonstartup [398]
org.glassfish.osgijavaeebase.DeploymentException: Deployment of com.macd.payarabug-singletonstartup [398] failed because of following reason: Failed while deploying bundle com.macd.payarabug-singletonstartup [398] : java.lang.RuntimeException: Failed to deploy bundle [ com.macd.payarabug-singletonstartup [398] ], root
 cause: JNDI lookup failed for the resource: Name: [java:module/env/payarabug.bean.PayaraBugSingleton/payaraBug], Lookup: [java:global/PayaraBugInterface], Type: [Session]
        at org.glassfish.osgijavaeebase.AbstractOSGiDeployer.deploy(AbstractOSGiDeployer.java:103)
        at org.glassfish.osgijavaeebase.OSGiContainer.deploy(OSGiContainer.java:130)
        at org.glassfish.osgijavaeebase.OSGiContainer.redeploy(OSGiContainer.java:89)
        at org.glassfish.osgijavaeebase.OSGiContainer.access$500(OSGiContainer.java:37)
        at org.glassfish.osgijavaeebase.OSGiContainer$DeployerAddedThread.run(OSGiContainer.java:281)
Caused by: java.lang.RuntimeException: Failed to deploy bundle [ com.macd.payarabug-singletonstartup [398] ], root cause: JNDI lookup failed for the resource: Name: [java:module/env/payarabug.bean.PayaraBugSingleton/payaraBug], Lookup: [java:global/PayaraBugInterface], Type: [Session]
        at org.glassfish.osgijavaeebase.OSGiDeploymentRequest.deploy(OSGiDeploymentRequest.java:174)
        at org.glassfish.osgijavaeebase.OSGiDeploymentRequest.execute(OSGiDeploymentRequest.java:96)
        at org.glassfish.osgijavaeebase.AbstractOSGiDeployer.deploy(AbstractOSGiDeployer.java:99)
        ... 4 more
]]

point of interest

Now the real strange thing is that this error seems to manifest differently in our full deployment. There we have several OSGi bundles, MDBs, session beans, etc. When we startup the server there (with JDK8) we get exceptions like these:

1. com.sun.enterprise.module.ResolveError: Failed to start OSGiModuleImpl:: Bundle = [fish.payara.server.internal.orb.iiop [215]], State = [NEW]
2. java.lang.IllegalStateException: Could not load descriptor SystemDescriptor(
        implementation=org.glassfish.enterprise.iiop.impl.GlassFishORBFactoryImpl
        contracts={org.glassfish.enterprise.iiop.impl.GlassFishORBFactoryImpl,org.glassfish.enterprise.iiop.api.GlassFishORBFactory}
        scope=javax.inject.Singleton
        qualifiers={}
        descriptorType=CLASS
        descriptorVisibility=NORMAL
        metadata=Bundle-SymbolicName={fish.payara.server.internal.orb.iiop},Bundle-Version={5.2020.4}
        rank=0
        loader=OsgiPopulatorPostProcessor.HK2Loader(OSGiModuleImpl:: Bundle = [fish.payara.server.internal.orb.iiop [215]], State = [NEW],753829631)
        proxiable=null
        proxyForSameScope=null
        analysisName=null
        id=261
        locatorId=0
        identityHashCode=261792760
        reified=false)
3. java.lang.IllegalStateException: Unable to perform operation: post construct on org.glassfish.enterprise.iiop.api.GlassFishORBHelper
4. java.lang.IllegalArgumentException: While attempting to resolve the dependencies of com.sun.ejb.containers.EjbContainerUtilImpl errors were found
5. java.lang.IllegalStateException: Unable to perform operation: resolve on com.sun.ejb.containers.EjbContainerUtilImpl
6. java.lang.IllegalArgumentException: While attempting to resolve the dependencies of org.glassfish.ejb.startup.EjbContainerStarter errors were found
7. java.lang.IllegalStateException: Unable to perform operation: resolve on org.glassfish.ejb.startup.EjbContainerStarter

Environment

• Payara Version: 5.2020.4
• Edition: Full
• JDK Version: Oracle JDK 8 (not working), OpenJDK 11 (working)
• Operating System: Debian 10, Ubuntu 20.04

[AlanRoth]

Hi @chrjohn, I've been able to reproduce this issue on the latest version, Community 5.2020.5. I have created an internal issue FISH-745

[AlanRoth]

Hi @chrjohn, Upon investigation by our developers, it appears that there is a flaw in the design of the reproducer, as the deployment order when specifying @Singleton and @Startup cannot be guaranteed.

You can combine the OSGi CDI extension and the timer service to inject the dependent EJB and delay the call on the same EJB, this helps guarantee the EJB is available.

I have attached the files used to confirm this finding, if you wish to confirm the findings yourself - the steps to reproduce are the same as detailed above.

osgi-test-interface.zip osgi-test-implementation-ejb.zip osgi-test-web-osgi-module.zip

The development team has decided there is no further action required - I will be closing the issue but feel free to add any extra detail which you feel is missing.

Thank you, Alan