DeploymentException: CDI deployment failure:null with Payara 412_173

[Dave Hubbard]

Hi

I have inherited an application which we have had deploying and running in 411_162.  It is using Sun Jersey RESTful web services and Google Guice injector. 

I am attempting to get a new version of Payara rolled out - using 412_173 - but when I attempt to deploy via asadmin I get the following in the server.log

[2017-10-04T17:12:31.161+0100] [Payara 4.1] [INFO] [] [org.jboss.weld.Version] [tid: _ThreadID=22 _ThreadName=RunLevelControllerThread-1507133541037] [timeMillis: 1507133551161] [levelValue: 800] [[
  WELD-000900: 2.4.2 (SP1)]]

[2017-10-04T17:12:32.711+0100] [Payara 4.1] [SEVERE] [NCLS-CORE-00026] [javax.enterprise.system.core] [tid: _ThreadID=22 _ThreadName=RunLevelControllerThread-1507133541037] [timeMillis: 1507133552711] [levelValue: 1000] [[
  Exception during lifecycle processing
org.glassfish.deployment.common.DeploymentException: CDI deployment failure:null
        at org.glassfish.weld.WeldDeployer.event(WeldDeployer.java:263)
        at org.glassfish.kernel.event.EventsImpl.send(EventsImpl.java:131)
        at org.glassfish.internal.data.ApplicationInfo.load(ApplicationInfo.java:333)
        at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:497)
        at com.sun.enterprise.v3.server.ApplicationLoaderService.processApplication(ApplicationLoaderService.java:406)
        at com.sun.enterprise.v3.server.ApplicationLoaderService.postConstruct(ApplicationLoaderService.java:243)
        at org.jvnet.hk2.internal.ClazzCreator.postConstructMe(ClazzCreator.java:327)
        at org.jvnet.hk2.internal.ClazzCreator.create(ClazzCreator.java:375)
        at org.jvnet.hk2.internal.SystemDescriptor.create(SystemDescriptor.java:487)
        at org.glassfish.hk2.runlevel.internal.AsyncRunLevelContext.findOrCreate(AsyncRunLevelContext.java:305)
        at org.glassfish.hk2.runlevel.RunLevelContext.findOrCreate(RunLevelContext.java:85)
        at org.jvnet.hk2.internal.Utilities.createService(Utilities.java:2126)
        at org.jvnet.hk2.internal.ServiceHandleImpl.getService(ServiceHandleImpl.java:116)
        at org.jvnet.hk2.internal.ServiceHandleImpl.getService(ServiceHandleImpl.java:90)
        at org.glassfish.hk2.runlevel.internal.CurrentTaskFuture$QueueRunner.oneJob(CurrentTaskFuture.java:1237)
        at org.glassfish.hk2.runlevel.internal.CurrentTaskFuture$QueueRunner.run(CurrentTaskFuture.java:1168)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.UnsupportedOperationException
        at java.util.AbstractList.add(AbstractList.java:148)
        at java.util.AbstractList.add(AbstractList.java:108)
        at org.glassfish.weld.DeploymentImpl.loadBeanDeploymentArchive(DeploymentImpl.java:445)
        at org.jboss.weld.util.DeploymentStructures.getOrCreateBeanDeployment(DeploymentStructures.java:37)
        at org.jboss.weld.bootstrap.ExtensionBeanDeployer.deployBean(ExtensionBeanDeployer.java:79)
        at org.jboss.weld.bootstrap.ExtensionBeanDeployer.deployBeans(ExtensionBeanDeployer.java:72)
        at org.jboss.weld.bootstrap.WeldStartup.startInitialization(WeldStartup.java:366)
        at org.jboss.weld.bootstrap.WeldBootstrap.startInitialization(WeldBootstrap.java:76)
        at org.glassfish.weld.WeldDeployer.event(WeldDeployer.java:249)
        ... 18 more
]]

[2017-10-04T17:12:32.712+0100] [Payara 4.1] [SEVERE] [] [javax.enterprise.system.core] [tid: _ThreadID=22 _ThreadName=RunLevelControllerThread-1507133541037] [timeMillis: 1507133552712] [levelValue: 1000] [[

  Exception while loading the app]]

The beans.xml (that works in 411_162) looks like this

<beans
        xmlns="http://xmlns.jcp.org/xml/ns/javaee"
        xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
        xmlns:weld="http://jboss.org/schema/weld/beans"
        xsi:schemaLocation="http://xmlns.jcp.org/xml/ns/javaee
                            http://xmlns.jcp.org/xml/ns/javaee/beans_1_1.xsd
                            http://jboss.org/schema/weld/beans
                            http://jboss.org/schema/weld/beans_1_1.xsd"

        bean-discovery-mode="none">

</beans>

I have tried with ( bean-discovery-mode="annotated" ) and with certain exlusions based on various advise to do with problems with Google Guice e.g.

    <scan>
        <exclude name="com.sun.jersey.guice.spi.container.servlet.GuiceContainer" />
    </scan>-->
       
    <weld:scan>
        <weld:exclude name="com.google.**"/>
    </weld:scan>
   
   

I'm wondering if there is better advise from Payara community based on updates to Payara between these versions e.g. a migration guide?

Thanks

[Ondrej Mihályi]

Hi Dave,

Looking at the code the piece of code that throws the exception shouldn't be executed if CDI is disabled in beans.xml with bean-discovery-mode=none.

In WAR, beans.xml should be placed the WEB-INF folder and not in the META-INF folder - can you check where you placed it?

If nothing works, you may try to disable CDI scanning of all JAR libraries in glassfish-web.xml file, as per documentation here: https://docs.payara.fish/documentation/extended-documentation/app-deployment/descriptor-elements.html#scanning-exclude-and-scanning-include

Regards,

Ondro

--
You received this message because you are subscribed to the Google Groups "Payara Forum" group.
To unsubscribe from this group and stop receiving emails from it, send an email to payara-forum+unsubscribe@googlegroups.com.
To view this discussion on the web, visit https://groups.google.com/d/msgid/payara-forum/4c8189ca-fba4-4561-a23f-dd27dbc11ed5%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Dave Hubbard]

Ondro hi

Thanks for your input

I can confirm that the beans.xml is in the WEB-INF folder alongside web.xml. 

I also tried your suggestion on "<scanning-exclude>*</scanning-exclude>" in "glassfish-web.xml" but got the same error. 

Of course it may be that I've not specified these quite correctly so would ideally like to see a log of glassfish deploy steps indicating it was recognising this config, I tried to set log level for the CLI to "DEBUG" i.e. "com.sun.enterprise.admin.cli.level=DEBUG" but no more info came out.


.

To unsubscribe from this group and stop receiving emails from it, send an email to payara-forum...@googlegroups.com.

[Ondrej Mihályi]

Hi,

To receive information from the CDI subsystem, you need to configure the logger named "javax.enterprise.inject.spi". Ideally set it to FINE level.

This type of problem is a candidate for debugging. If you can, try to isolate the code that causes this problem into a separate application that could be used to reproduce it and submit it with a bug report in github issues. 

Or you can download Payara sources and debug yourself - it would be interesting to find out what happens before the line 445 of the loadBeanDeploymentArchive method is executed and the UnsupportedOperationException is thrown. I don't understand why if condition allows this code to execute when you set bean discovery to none in beans.xml. I would be particularly interested which bean archive is processed and causes the exception - the information in the newBda variable.

Ondro

To unsubscribe from this group and stop receiving emails from it, send an email to payara-forum+unsubscribe@googlegroups.com.
To view this discussion on the web, visit https://groups.google.com/d/msgid/payara-forum/aaa59fd6-a395-4e6f-a79e-1e0528d42756%40googlegroups.com.

[Dave Hubbard]

Hi

So I have set "javax.enterprise.inject.spi.level=FINE" I get

[2017-10-24T10:33:49.962+0100] [Payara 4.1] [FINE] [AS-CDI-00019] [javax.enterprise.inject.spi] [tid: _ThreadID=44 _ThreadName=admin-thread-pool::admin-listener(1)] [timeMillis: 1508837629962] [levelValue: 500] [CLASSNAME: org.glassfish.weld.DeploymentImpl] [METHODNAME: getBeanDeploymentArchives] [[
  getBeanDeploymentArchives returning [].]]

[2017-10-24T10:33:49.962+0100] [Payara 4.1] [FINE] [AS-CDI-00020] [javax.enterprise.inject.spi] [tid: _ThreadID=44 _ThreadName=admin-thread-pool::admin-listener(1)] [timeMillis: 1508837629962] [levelValue: 500] [CLASSNAME: org.glassfish.weld.DeploymentImpl] [METHODNAME: loadBeanDeploymentArchive] [[
  loadBeanDeploymentArchive for beanClass class org.jboss.weld.bootstrap.WeldExtension]]

[2017-10-24T10:33:49.962+0100] [Payara 4.1] [FINE] [AS-CDI-00019] [javax.enterprise.inject.spi] [tid: _ThreadID=44 _ThreadName=admin-thread-pool::admin-listener(1)] [timeMillis: 1508837629962] [levelValue: 500] [CLASSNAME: org.glassfish.weld.DeploymentImpl] [METHODNAME: getBeanDeploymentArchives] [[
  getBeanDeploymentArchives returning [].]]

[2017-10-24T10:33:49.963+0100] [Payara 4.1] [FINE] [AS-CDI-00024] [javax.enterprise.inject.spi] [tid: _ThreadID=44 _ThreadName=admin-thread-pool::admin-listener(1)] [timeMillis: 1508837629963] [levelValue: 500] [CLASSNAME: org.glassfish.weld.DeploymentImpl] [METHODNAME: loadBeanDeploymentArchive] [[
  loadBeanDeploymentArchive beanClass class org.jboss.weld.bootstrap.WeldExtension not found in the BDAs of this deployment. Creating a new BDA.]]

[2017-10-24T10:33:49.963+0100] [Payara 4.1] [FINE] [AS-CDI-00025] [javax.enterprise.inject.spi] [tid: _ThreadID=44 _ThreadName=admin-thread-pool::admin-listener(1)] [timeMillis: 1508837629963] [levelValue: 500] [CLASSNAME: org.glassfish.weld.DeploymentImpl] [METHODNAME: loadBeanDeploymentArchive] [[
  loadBeanDeploymentArchive new BDA {0} created. Adding new BDA to all root BDAs of this deployment.]]

[2017-10-24T10:33:49.963+0100] [Payara 4.1] [FINE] [AS-CDI-00026] [javax.enterprise.inject.spi] [tid: _ThreadID=44 _ThreadName=admin-thread-pool::admin-listener(1)] [timeMillis: 1508837629963] [levelValue: 500] [CLASSNAME: org.glassfish.weld.DeploymentImpl] [METHODNAME: loadBeanDeploymentArchive] [[
  loadBeanDeploymentArchive for beanClass class org.jboss.weld.bootstrap.WeldExtension returning the newly created BDA |ID: org.jboss.weld.bootstrap.WeldExtension, bdaType= UNKNOWN, accessibleBDAs #:0, [], Bean Classes #: 1,[org.jboss.weld.bootstrap.WeldExtension], ejbs=[]
]]

[2017-10-24T10:33:49.964+0100] [Payara 4.1] [FINE] [AS-CDI-00019] [javax.enterprise.inject.spi] [tid: _ThreadID=44 _ThreadName=admin-thread-pool::admin-listener(1)] [timeMillis: 1508837629964] [levelValue: 500] [CLASSNAME: org.glassfish.weld.DeploymentImpl] [METHODNAME: getBeanDeploymentArchives] [[
  getBeanDeploymentArchives returning [].]]

[2017-10-24T10:33:49.965+0100] [Payara 4.1] [SEVERE] [NCLS-CORE-00026] [javax.enterprise.system.core] [tid: _ThreadID=44 _ThreadName=admin-thread-pool::admin-listener(1)] [timeMillis: 1508837629965] [levelValue: 1000] [[

  Exception during lifecycle processing
org.glassfish.deployment.common.DeploymentException: CDI deployment failure:null

Looking at code in git (for 173 tag) my guess (without debugging)

is that "getBeanDeploymentArchives" (line 361) returns Collections.EmptyList

    @Override
    public BeanDeploymentArchive loadBeanDeploymentArchive(Class<?> beanClass) {
        if ( logger.isLoggable( FINE ) ) {
            logger.log(FINE, CDILoggerInfo.LOAD_BEAN_DEPLOYMENT_ARCHIVE, new Object[] { beanClass });
        }
        List<BeanDeploymentArchive> beanDeploymentArchives = getBeanDeploymentArchives();

Which is iterable buton the "add" call at the end (line 445) ...

               beanDeploymentArchives.add(newBda);

...the EmptyList - which doesn't implement is "public void add(int index, E element)" hits the base AbstractList method for this

 

    public void add(int index, E element) {
        throw new UnsupportedOperationException();
    }

Cheers
Dave

[Dave Hubbard]

I have now managed to get debug working on 173

I can confirm

1) "getBeanDeploymentArchives()" (line 361) returns EmptyList

2) "InjectionServices injectionServices = this.getServices().get(InjectionServices.class);" (line 426) returns null object

3) "BeansXml beansXml = newBda.getBeansXml();" (line 428) returns a "org.jboss.weld.metadata.BeansXmlImpl" object which has "discoveryMode" attribute set to "ALL"

This I think stems from (as per the comment in "BeanDeploymentArchiveImpl.getBeansXml()" )

    public BeansXml getBeansXml() {
        BeansXml result = null;

        if (beansXmlURLs.size() == 1) {
            result = weldBootstrap.parse(beansXmlURLs.get(0));
        } else {
            // This method attempts to performs a merge, but loses some
            // information (e.g., version, bean-discovery-mode)
            result = weldBootstrap.parse(beansXmlURLs);
        }

        return result;
    }

What is slightly confusing (to me) is this code does not appear to have changed from 162 - so presumably there is a different higher level condition somewhere which is different.  I will attempt to debug 162 and find the divergent path.

Regards
Dave

[Dave Hubbard]

Hi

So I have worked round the null pointer issue by changing org.glassfish.weld.DeploymentImpl.getBeanDeploymentArchives to

    @Override
    public List<BeanDeploymentArchive> getBeanDeploymentArchives() {

        if ( logger.isLoggable( FINE ) ) {

            logger.log(FINE, CDILoggerInfo.GET_BEAN_DEPLOYMENT_ARCHIVES, new Object[] {beanDeploymentArchives});
        }
        if (!beanDeploymentArchives.isEmpty()) {
            return beanDeploymentArchives;
        }
//        return Collections.emptyList();
        return beanDeploymentArchives;
    }

i.e. always return the actual list - empty or not.  

This allows war to be deployed and code appears to work ok.

I presume the assumption in this code is that, by the time it calls "loadBeanDeploymentArchive" then this will have been setup correctly i.e. not empty - but that appears to be not the case.

In terms of debugging this (I'm no CDI expert) but having done deployment in both 162 and 173

In org.glassfish.weld.WeldDeployer.event (WeldDeployer.java)

 DeploymentImpl deploymentImpl = appInfo.getTransientAppMetaData(
                        WELD_DEPLOYMENT, DeploymentImpl.class);


For 162
-  deploymentImpl.appName = "CDIApp"

Then in

   bootstrap.startInitialization();

No call is made into org.glassfish.weld.DeploymentImpl

In 173
-  deploymentImpl.appName = "api-1.2.1.war"

- org.glassfish.weld.BeanDeploymentArchiveImpl.populate

     "BeanDiscoveryMode bdMode = beansXML.getBeanDiscoveryMode();"
     shows bdMode = "NONE"   (as per setting in beans.xml)

- org.glassfish.weld.DeploymentImpl.loadBeanDeploymentArchive()

as above - getBeanDeploymentArchives() returns EmptyList - which fails on "beanDeploymentArchives.add(newBda);"

So (to me) it looks like it's ignoring this "NONE" and running

One other things of note - if I deploy with a "--name api-deploy" parameter (which is our usual method of deployment)

    deploymentImpl.appName = "api-deploy.war.war.war.war"   !! 

Is there somewhere where I should log this as a bug?

Regards
Dave

[Dave Hubbard]

Issue raised https://github.com/payara/Payara/issues/2112