AS61 Startup is slow

[thammoud]

Hello,

With 6.1, we have noticed that it is much slower to deploy our ear than with 4.x (50% slower). Upon startup, we noticed a good 30 second hang after the message:

16:10:16,444 DEBUG [EarLibExcludeDeployer] Excluding ear's lib directory: "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/FinancialDataServer.ear/lib before our ear is loaded.

Having trace on, we noticed that many classes are being scanned for annotations as expected. We would like to reduce the set of classes that the scanner will look at and hope that it will address our problem.

Our ear structure:

  - ejb.jar

  - a.rar

  - lib/*

We added a jboss-scanning.xml to the ear's META-INF to control scanning of ejb.jar and that helped greatly. However, the rar (and its embedded jars) are always scanned. We added an empty jboss-scanning.xml to the rar META-INF and an entry in the ear's jboss-scanning but the TRACE still shows scanning taking place.

<scanning xmlns="urn:jboss:scanning:1.0">

  <path name="ejb.jar">

    <exclude name="com.foo.bar" recurse="true"/>

  </path> 

  <path name="a.rar">

    <exclude name="org" recurse="true"/>

  </path>   

</scanning>

Any ideas?  Thank you.

[alesj]

We added an empty jboss-scanning.xml to the rar META-INF

This should do it.

How do you see that the scanning is taking place for .rar?

[thammoud]

Ales,

I turned on the boot trace and can see many of these messages in the boot.log file:

06:14:43,538 TRACE [GenericAnnotationVisitor] Scanning class org.apache.derby.iapi.services.compiler.MethodBuilder for annotations

06:14:40,222 TRACE [GenericAnnotationVisitor] Scanning class org.apache.activemq.network.DemandForwardingBridgeSupport$10 for annotations

06:14:47,710 TRACE [GenericAnnotationVisitor] Scanning class org.springframework.osgi.bundle.BundleAction for annotations

These are all jars that are embedded in the rar file.

[alesj]

Hmm, I see.

Can you perhaps debug the actual ScanningDeployer,

and perhaps see why it's not picking up jboss-scanning.xml / ScanningMetaData?

I recently added two new inputs to ScanningDeployer:

* http://anonsvn.jboss.org/repos/jbossas/trunk/server/src/etc/deployers/scanning-deployers-jboss-beans.xml

<install method="addInput" state="Instantiated">

       <parameter class="java.lang.String">org.jboss.classloading.spi.visitor.ResourceFilter.recurse</parameter>

    </install>

    <install method="addInput" state="Instantiated">

       <parameter class="java.lang.String">org.jboss.classloading.spi.visitor.ResourceFilter.resource</parameter>

    </install>

Perhaps this is what's missing?

[thammoud]

Ales,

I do have those entries in my scanning-deployers-jboss-beans.xml. To simply the problem, I simply deployed the a standalone rar (attached) and removed all but one of the embedded jar files. The scanning still takes place. I am attaching the log where it starts the deployment of the rar and stops at the first scan of an embedded class. Again, thanks for all your help.

[alesj]

I do have those entries in my scanning-deployers-jboss-beans.xml. To simply the problem, I simply deployed the a standalone rar (attached) and removed all but one of the embedded jar files.

Embedded jar, as in x.rar/y.jar?

Then this jar is treated as a sub-deployment, and you should put the jboss-scanning.xml to its META-INF.

[thammoud]

Yes. That's what I thought. The real rar file (Third party) contains about 30 jars and it will be a pain to open each one and rejar. Is there any other setting to disable the scanning for the parent deployment (in this case the .rar).

[alesj]

What you could do is make .rar a single deployment, w/o sub-deployments, by using jboss-structure.xml.

Where those jars would simply be classpath entries then.

Then you could have .rar/META-INF/jboss-scanning.xml exclude them all.

[thammoud]

Ales,

I created the jboss-structure.xml. While it does seem to stop the scanning, I am getting CNFE all over the place. Must be doing something stupid. The content of the rar are as follows:

M Filemode      Length  Date         Time      File

- ----------  --------  -----------  --------  -----------------------------------------------

  -rw-r--r--      2818  27-May-2011  08:27:36  broker-config.xml

  drwxr-xr-x         0  13-Jun-2011  11:34:56  lib/

  -rw-r--r--     35859  14-Mar-2011  14:53:48  lib/spring-osgi-io-1.2.1.jar

  -rw-r--r--    102631  14-Mar-2011  14:53:48  lib/activeio-core-3.1.2.jar

  -rw-r--r--    320317  14-Mar-2011  14:53:48  lib/spring-aop-3.0.1.RELEASE.jar

  -rw-r--r--     85617  14-Mar-2011  14:53:48  lib/activemq-ra-5.4-SNAPSHOT.jar

  -rw-r--r--   3214041  16-May-2011  10:32:36  lib/activemq-core-5.4-SNAPSHOT.jar

  -rw-r--r--     53082  14-Mar-2011  14:53:48  lib/spring-asm-3.0.1.RELEASE.jar

  -rw-r--r--     44598  14-Mar-2011  14:53:48  lib/commons-logging-api-1.1.jar

  -rw-r--r--    362889  14-Mar-2011  14:53:48  lib/spring-osgi-core-1.2.1.jar

  -rw-r--r--    130519  14-Mar-2011  14:53:48  lib/xbean-spring-3.6.jar

  -rw-r--r--    163485  14-Mar-2011  14:53:48  lib/org.osgi.core-4.1.0.jar

  -rw-r--r--    355608  14-Mar-2011  14:53:48  lib/spring-core-3.0.1.RELEASE.jar

  -rw-r--r--     52915  14-Mar-2011  14:53:48  lib/commons-logging-1.1.jar

  -rw-r--r--    197067  14-Mar-2011  14:53:48  lib/commons-net-2.0.jar

  -rw-r--r--     20220  14-Mar-2011  14:53:48  lib/geronimo-j2ee-management_1.1_spec-1.0.1.jar

  -rw-r--r--    656988  14-Mar-2011  14:53:48  lib/spring-context-3.0.1.RELEASE.jar

  -rw-r--r--    547839  14-Mar-2011  14:53:48  lib/spring-beans-3.0.1.RELEASE.jar

  -rw-r--r--   2141382  14-Mar-2011  14:53:48  lib/derby-10.1.3.1.jar

  -rw-r--r--    153198  14-Mar-2011  14:53:48  lib/kahadb-5.4-SNAPSHOT.jar

  -rw-r--r--     16030  14-Mar-2011  14:53:48  lib/geronimo-j2ee-management_1.0_spec-1.0.jar

  -rw-r--r--    147909  14-Mar-2011  14:53:48  lib/activemq-protobuf-1.1-SNAPSHOT.jar

  -rw-r--r--      4467  14-Mar-2011  14:53:48  lib/aopalliance-1.0.jar

  -rw-r--r--    156128  14-Mar-2011  14:53:48  lib/spring-expression-3.0.1.RELEASE.jar

  drwxr-xr-x         0  13-Jun-2011  11:34:42  META-INF/

  -rw-r--r--       130  26-May-2011  13:16:22  META-INF/jboss-scanning.xml

  -rw-r--r--     10011  14-Mar-2011  14:53:48  META-INF/ra.xml

  -rw-r--r--     13768  14-Mar-2011  14:53:48  META-INF/LICENSE

  -rw-r--r--       289  13-Jun-2011  11:34:42  META-INF/jboss-structure.xml

  -rw-r--r--      2053  14-Mar-2011  14:53:48  META-INF/NOTICE

and the jboss-structure.xml:

<?xml version="1.0" encoding="UTF-8"?>

<structure>

    <context>

        <path name=""/>

        <metaDataPath>

            <path name="META-INF"/>

        </metaDataPath>

        <classpath>

            <path name="lib/" suffixes=".jar" />

        </classpath>

    </context>

</structure>

Is there any doucmention to jboss-strucutre.xml?

[alesj]

Is there any doucmention to jboss-strucutre.xml?

* http://community.jboss.org/wiki/JBoss5custommetadatafiles

And Deployers tests.

Although your jboss-structure.xml looks OK ...

[thammoud]

Thanks Ales. What is strange, if I deploy the rar standalone in the deploy directory, I see the following (Notice how the embedded Jars are being processed):

14:35:11,384 TRACE [structure] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar" isJBossStructure: true

14:35:11,384 TRACE [DeclaredStructure] Recognised: activemq-ra.rar

14:35:11,384 TRACE [VFSStructuralDeployersImpl] activemq-ra.rar recognised by org.jboss.deployers.vfs.plugins.structure.explicit.DeclaredStructure@34be8216

14:35:11,384 TRACE [VFSStructureBuilder] Populating deployment vfs:///opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar metaData=StructureMetaDataImpl{contexts=[ContextInfoImpl{path= metaData=[META-INF - DEFAULT] classPath=[ClassPathEntryImpl{path=lib/ suffixes=.jar}]}]}

14:35:11,384 TRACE [VFSStructureBuilder] Apply context: vfs:///opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar ContextInfoImpl{path= metaData=[META-INF - DEFAULT] classPath=[ClassPathEntryImpl{path=lib/ suffixes=.jar}]}

14:35:11,384 TRACE [VFSStructureBuilder] Resolving classpath entry ClassPathEntryImpl{path=lib/ suffixes=.jar} for vfs:///opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar

14:35:11,384 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/derby-10.1.3.1.jar" accepted: true

14:35:11,384 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/activemq-core-5.4-SNAPSHOT.jar" accepted: true

14:35:11,384 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/org.osgi.core-4.1.0.jar" accepted: true

14:35:11,384 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-core-3.0.1.RELEASE.jar" accepted: true

14:35:11,384 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-beans-3.0.1.RELEASE.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/activeio-core-3.1.2.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/xbean-spring-3.6.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/commons-net-2.0.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-aop-3.0.1.RELEASE.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-osgi-core-1.2.1.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/commons-logging-1.1.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/commons-logging-api-1.1.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-expression-3.0.1.RELEASE.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-osgi-io-1.2.1.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/aopalliance-1.0.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-context-3.0.1.RELEASE.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/activemq-ra-5.4-SNAPSHOT.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/activemq-protobuf-1.1-SNAPSHOT.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/geronimo-j2ee-management_1.0_spec-1.0.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/kahadb-5.4-SNAPSHOT.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-asm-3.0.1.RELEASE.jar" accepted: true

14:35:11,385 TRACE [SuffixMatchFilter] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/geronimo-j2ee-management_1.1_spec-1.0.1.jar" accepted: true

14:35:11,385 TRACE [VFSStructureBuilder] Added classpath matches: ["/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/derby-10.1.3.1.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/activemq-core-5.4-SNAPSHOT.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/org.osgi.core-4.1.0.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-core-3.0.1.RELEASE.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-beans-3.0.1.RELEASE.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/activeio-core-3.1.2.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/xbean-spring-3.6.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/commons-net-2.0.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-aop-3.0.1.RELEASE.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-osgi-core-1.2.1.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/commons-logging-1.1.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/commons-logging-api-1.1.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-expression-3.0.1.RELEASE.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-osgi-io-1.2.1.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/aopalliance-1.0.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-context-3.0.1.RELEASE.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/activemq-ra-5.4-SNAPSHOT.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/activemq-protobuf-1.1-SNAPSHOT.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/geronimo-j2ee-management_1.0_spec-1.0.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/kahadb-5.4-SNAPSHOT.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/spring-asm-3.0.1.RELEASE.jar", "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/activemq-ra.rar/lib/geronimo-j2ee-management_1.1_spec-1.0.1.jar"]

When deployed inside an ear, I get:

14:41:12,483 TRACE [structure] "/opt/jboss/jboss61_src/trunk/build/target/jboss-6.1.0-SNAPSHOT/server/us/deploy/FinancialDataServer.ear/activemq-ra.rar" isJBossStructure: true

14:41:12,483 TRACE [DeclaredStructure] Recognised: activemq-ra.rar

14:41:12,483 TRACE [VFSStructuralDeployersImpl] activemq-ra.rar recognised by org.jboss.deployers.vfs.plugins.structure.explicit.DeclaredStructure@34be8216

and it jumps to the next deployment unit from inside the ear (in this case a sar). No reference whatsoever about the embedded jars in this case and then the storm of CNFE.

Tarek

[alesj]

Strange.

Although Structure deployers should only recognize structure == ContextInfo.

Where the processing of this info is done later, when the whole deployment has been recognized.

And this is where this .jar suffix gets used -- see VFSStructureBuilder.

[alesj]

Strange.

I think I know what the problem is. ;-)

Let me mock this tomorrow and fix it.

And I think you should be able to simply change the Deployers with the latest trunk -- as it will be all backcompatible.

[alesj]

I think I know what the problem is. ;-)

Let me mock this tomorrow and fix it.

And I think you should be able to simply change the Deployers with the latest trunk -- as it will be all backcompatible.

Can you try the latest Deployers trunk if it works for you?

* http://anonsvn.jboss.org/repos/jbossas/projects/jboss-deployers/trunk/

(you might also need the latest Classloading trunk as well ...)

* http://anonsvn.jboss.org/repos/jbossas/projects/jboss-cl/trunk/

The problem is that declarative structure was only implemented to work for top level deployment.

Hence the paths are not relative aka wrong, but unfortunately no code checks for correctness == no error msg.

e.g. this should probably fix your problem:

<classpath>

   <path name="my.rar/lib/" suffixes=".jar" />

</classpath>

[thammoud]

Thanks a lot. Let me get this straight. In addition to using the latest deployer code, you also want me to change the class path or changing the class path with the old code will work?

Tarek