[jboss-dev] Bootstrap times

[Adrian Brock]

After Sacha's "the AS is hanging" thread
last week, I've created some simple stats
to show the times spent in deployers
and the microcontainer state transfers.

See attached for the full stats
(this is the default configuration).

DEPLOYERS

For the deployers you can see
the big hits are in the expected
bean and jmx deployers which do
most of the work.

Other hits include annotation scanning,
classloader creation and surprisingly
the ejb3 deployer (there are no ejb3 deployments? :-).

ANNOTATION DEPLOYER

Drilling down in the annotation scanning,
you can see most time is spent in
jbossweb.sar, console-mgr.sar and jbossws.sar
Making these metadata complete would knock
something like 7-8 seconds off the bootstrap time.

CLASSLOADER DEPLOYER

Most of the time in the classloader bucket
is spent processing conf/jboss-service.xml
so this is a function of the number of jars
in server/default/lib, i.e. determining
what packages they contain.

EJB3 DEPLOYER

A lot of time in the EJB3 bucket is taken on
jbossweb.sar (nearly a second?), but
there are others where it is taking upto
a quarter of second.

RAR PARSER DEPLOYER

Although, it doesn't take much time,
this looks less efficient than the other
parsers. I'd guess there is some inefficiency
due it using the old ObjectModelFactory
instead of annotations? e.g. maybe it
is reconstructing the schema binding on
every request or parsing the schema?

KERNEL

The kernel reports show more details
of the stages for beans/jmx and more
of a summary for the deployers (i.e.
it shows the deployment stages rather
than individual deployers).

A quick guide to the states:

Real = Real deployers
PostClassLoader = annotation scanning
Start = bean/jmx.start()
Described = bean/jmx metadata analysis
Instantiated = object construction
Parse = Parsing deployers
ClassLoader = ClassLoading deployers
Create = bean/jmx.create()
etc.

REAL

The biggest hit is the Real stage.

But there will be some double
counting here. e.g. the real stage
of a bean/jmx will also show up in
Instantiated/Create/Start/etc.

Also, the times will include dependencies.
e.g. the starting of the transaction
manager will start a lot of other services.

Creating some of the deployers is showing
more time than I would expect?

jboss-jca is obviously slow since it is the
only one using JAXB instead of JBossXB,
so it has to load all those classes,
but why does aop, ejb3, web take more than
one second to just create the deployers?

POSTCLASSLOADER

This is the annotation scanning again

START

This is obviously where a lot of
services do things, but again the
WARDeployer is showing as quite high up?

DESCRIBED

There is nothing in here that is
very big, but it does include
the aop annotation scanning for beans,
so there are lots of small bits
that add up.

TODO

I'll let you look at the numbers
yourselves, in particular the parts
you are responsible for and see
whether you can explain it,
you're happy with it or there
is something strange going on.

-- 
xxxxxxxxxxxxxxxxxxxxxxxxxxxx
Adrian Brock
Chief Scientist
JBoss, a division of Red Hat
xxxxxxxxxxxxxxxxxxxxxxxxxxxx
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.jboss.org/pipermail/jboss-development/attachments/20080909/cc841577/attachment.html 
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.jboss.org/pipermail/jboss-development/attachments/20080909/cc841577/attachment-0001.html 
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.jboss.org/pipermail/jboss-development/attachments/20080909/cc841577/attachment-0002.html 
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.jboss.org/pipermail/jboss-development/attachments/20080909/cc841577/attachment-0003.html