JBoss 5 starts slowly

Posted Thu, 26/02/2009 - 11:02 by mark
, , ,

JBoss 5 starts very slowly.

As we can see from the part of log - it takes about 1 min to pass these four lines.

Sometimes 1 min can grow to several minutes.

09:50:43,819 INFO  [ProfileServiceImpl] Loaded profile: ProfileImpl@17035c6{key=org.jboss.profileservice.spi.ProfileKey@f9d9dd27[domain=default,server=defa
ult,name=worklight]}
09:50:52,413 INFO  [WebService] Using RMI server codebase: http://nimrod-desk:8083/
09:51:10,758 INFO  [NativeServerConfig] JBoss Web Services - Stack Native Core
09:51:10,758 INFO  [NativeServerConfig] 3.0.4.SP1
09:51:49,916 INFO  [MailService] Mail Service bound to java:/Mail

Any ideas ?

‹ Presentation from the last server forum - REST XML DB anyone? ›

Comments

by shlomo - 01/03/2009 - 14:43

Are other OS applications running as fast as they did before?
Maybe an OS swap issue?
Did you upgrade to a new JDK? 64 bit by any chance?

Run the server in debug mode (change jboss-log4j.xml) and resend the log.

by mark - 01/03/2009 - 14:58

OS - Windows XP
Java 1.6.0_11

I suspect that there is TCP/IP timeout - some service try to connect to some host.
And waiting time is depends from network configuration.

by shlomo - 01/03/2009 - 15:07

That might be the case with a socket appender in your jboss-log4j file:

look for this string:
appender name="SOCKET" class="org.apache.log4j.net.SocketAppender"

by mark - 01/03/2009 - 16:41

Didn't found
jboss-log4j is clean

by itai - 02/03/2009 - 10:46

Hi Mark ,

Can you please change the log level to debug in server/default/conf/jboss-log4j.xml and send the debug log so we can see more details .

by mark - 02/03/2009 - 17:29

I didn't find in the log nothing suspicious.

It seems to me happens not only for me.

http://www.jboss.org/index.html?module=bb&op=viewtopic&p=4206520

by shlomo - 04/03/2009 - 15:39

They also provided only the INFO log level and not the DEBUG log level.

please provide us with the log in DEBUG mode.

Thanks.

by mark - 04/03/2009 - 18:13

Attached

by shlomo - 05/03/2009 - 09:29

First inspection shows that your server booted at 2009-03-04 17:06:57,680 in 1m:26s:958ms, which is normal.

Other then that:
1-The ClusterSynchronizationTask takes 20 seconds to load (2009-03-04 17:07:17,931) and has nothing to do with Jboss since if I assume correctly, the wroklight.ear is yours?
2-The next minute and a half (up to 2009-03-04 17:08:29,778) are again, application specific tasks which have nothing to do with JBoss.
3-You also have failed inserts into the DB, which also takes time, and there are also 10 seconds spent on excluding the LIB dir of your worklight.ear.

Hope this helps,

by mark - 05/03/2009 - 09:55

Thanks for your investigations.

What you mean "excluding the LIB dir of your worklight.ear." ?

by shlomo - 05/03/2009 - 10:21

Thats what the log states:

2009-03-04 17:06:09,458 38783 DEBUG [org.jboss.deployment.EarLibExcludeDeployer] (main:) Excluding ear's lib directory: FileHandler@24955103[path=worklight.ear/lib context=file:/C:/dev/worklight/server_trunk/app-server/target/app-server-jboss-5.0.0/worklight/jboss/server/worklight/deploy/ real=file:/C:/dev/worklight/server_trunk/app-server/target/app-server-jboss-5.0.0/worklight/jboss/server/worklight/deploy/worklight.ear/lib/]
2009-03-04 17:06:18,849 48174 DEBUG [org.jboss.deployment.OptAnnotationMetaDataDeployer] (main:) Deployment is metadata-complete, skipping annotation processing, ejbJarMetaData=null, jbossWebMetaData=org.jboss.metadata.web.spec.Web24MetaData@1484bc6c, jbossClientMetaData=null, metaDataCompleteIsDefault=false