• Post Reply Bookmark Topic Watch Topic
  • New Topic
programming forums Java Mobile Certification Databases Caching Books Engineering Micro Controllers OS Languages Paradigms IDEs Build Tools Frameworks Application Servers Open Source This Site Careers Other Pie Elite all forums
this forum made possible by our volunteer staff, including ...
Marshals:
  • Campbell Ritchie
  • Jeanne Boyarsky
  • Ron McLeod
  • Paul Clapham
  • Liutauras Vilda
Sheriffs:
  • paul wheaton
  • Rob Spoor
  • Devaka Cooray
Saloon Keepers:
  • Stephan van Hulst
  • Tim Holloway
  • Carey Brown
  • Frits Walraven
  • Tim Moores
Bartenders:
  • Mikalai Zaikin

Server boot time issue

 
Greenhorn
Posts: 8
  • Mark post as helpful
  • send pies
    Number of slices to send:
    Optional 'thank-you' note:
  • Quote
  • Report post to moderator
I've just upgraded from JBoss AS 4.2 to 5.1 and have encountered a boot time issue that did not exist with 4.2. If I start the server while connected to my company's VPN, it takes 5:32 mins. With 4.2, it took about 1 min. If I start the server disconnected from the VPN, but still connected to internet (high speed cable), it takes about 1:40 mins. If I disable my network card, it takes 1:10 mins. I have not made any modifications to the server configuration that ships in the jboss-5.1.0.GA-jdk6.zip (also tried the jboss-5.1.0.GA.zip with the same results).

Any ideas on why the server startup would be network sensitive?

After turning on debug level logging for everything, I found these performance killers:
2010-02-25 12:56:31,003 DEBUG [org.jboss.management.j2ee.deployers.LocalJBossServerDomain] (main) handleNotification: javax.management.Notification[source=jboss.system:service=ServiceController][type=org.jboss.system.ServiceMBean.start][message=]
2010-02-25 12:56:43,466 FINE [sun.rmi.transport.tcp] (RMI Scheduler(0)) RMI Scheduler(0): close connection
2010-02-25 12:56:43,481 FINE [sun.rmi.transport.tcp] (RMI TCP Connection(2)-3.7.149.84) RMI TCP Connection(2)-3.7.149.84: (port 1851) connection closed
2010-02-25 12:56:43,481 FINE [sun.rmi.transport.tcp] (RMI TCP Connection(2)-3.7.149.84) RMI TCP Connection(2)-3.7.149.84: close connection
2010-02-25 12:56:43,481 FINE [sun.rmi.transport.tcp] (RMI Scheduler(0)) RMI Scheduler(0): close connection
2010-02-25 12:56:43,481 FINE [sun.rmi.transport.tcp] (RMI TCP Connection(1)-3.7.149.84) RMI TCP Connection(1)-3.7.149.84: (port 1090) connection closed
2010-02-25 12:56:43,481 FINE [sun.rmi.transport.tcp] (RMI TCP Connection(1)-3.7.149.84) RMI TCP Connection(1)-3.7.149.84: close connection
2010-02-25 12:57:56,347 DEBUG [org.jboss.remoting.ServerInvoker] (main) SocketServerInvoker[HCU-C1WYGC1:4446] added org.jboss.profileservice.management.upload.remoting.DeployHandler@18309b0 for subsystem 'DeploymentManager'

As you can see, SocketServerInvoker takes over a minute.

2010-02-25 12:57:56,347 DEBUG [org.jboss.profileservice.management.ManagementViewImpl] (main) addTemplate: org.jboss.resource.deployers.management.DsDataSourceTemplate@98843
2010-02-25 12:57:56,347 DEBUG [org.jboss.profileservice.management.ManagementViewImpl] (main) addTemplate: org.jboss.resource.deployers.management.DsDataSourceTemplate@1d11c11
2010-02-25 12:59:21,346 DEBUG [org.jboss.profileservice.remoting.ProxyFactory] (main) Bound ProfileService proxy under: ProfileService
2010-02-25 12:59:21,424 DEBUG [org.jboss.profileservice.remoting.ProxyFactory] (main) Created ManagementView proxy

Here, ProxyFactory takes over a minute

2010-02-25 12:59:28,508 DEBUG [org.jboss.aop.microcontainer.beans.GenericBeanAspectFactory] (main) Creating advice InvocationContextInterceptor with loader null
2010-02-25 12:59:32,573 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] (Thread-14) Periodic recovery - second pass <Thu, 25 Feb 2010 12:59:32>
2010-02-25 12:59:32,589 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] (Thread-14) AtomicActionRecoveryModule: Second pass
2010-02-25 13:00:24,142 DEBUG [org.apache.catalina.session.ManagerBase] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) Start expire sessions StandardManager at 1267131624142 sessioncount 0

Here, ManagerBase takes nearly a minute.

Thanks for any / all help you can throw my way.
Dan
 
author
Posts: 5856
7
Android Eclipse IDE Ubuntu
  • Mark post as helpful
  • send pies
    Number of slices to send:
    Optional 'thank-you' note:
  • Quote
  • Report post to moderator
Dan, welcome to Java Ranch!

Looks like it is waiting on a network request and either that request is taking a long time or is timing out. A scan through the forums will probably yield several posts asking out similar networking issues, though yours is the first to mention VPN (I haven't noticed the delay when connected to my VPN). The thing we usually recommend is to take a thread dump during that 1-minute wait to verify that it is indeed waiting on the network (it usually is, but at least going through the motions eliminates other possibilities). And there is usually nothing that can be done about it (though I vaguely recall that fixing the /etc/hosts file helped in one case) other than locating and correcting the network issue.
 
Ranch Hand
Posts: 650
  • Mark post as helpful
  • send pies
    Number of slices to send:
    Optional 'thank-you' note:
  • Quote
  • Report post to moderator
Also, as the log file is not written asynchronously, won't writing more information to it cause the performance to drop? Perhaps turning the log level up to DEBUG for the entire site just made things worse?

I know that I've gone to great lengths to reduce the amount of information written to the log file, and found it improved the start-up time somewhat.

I don't expect this to resolve the issue at hand, just that I think it may be contributing to it.

 
Peter Johnson
author
Posts: 5856
7
Android Eclipse IDE Ubuntu
  • Mark post as helpful
  • send pies
    Number of slices to send:
    Optional 'thank-you' note:
  • Quote
  • Report post to moderator
Yes, reducing the logging level usually helps speed things up, but when there is a 1 minute time span between log entries, changing the level does not help (at least, not for reducing that 1 minute).
 
Dan Seaver
Greenhorn
Posts: 8
  • Mark post as helpful
  • send pies
    Number of slices to send:
    Optional 'thank-you' note:
  • Quote
  • Report post to moderator
Thanks for the warm welcome, Peter.
I don't understand why JBoss would be doing anything over the network. I'm running it locally and haven't configured anything to look elsewhere. Maybe the thread dump will help?
I turned on the debug level logging for the console and did a <ctrl><break> when the logging paused to get the following dump:


I don't see anything that points to the network, but maybe I'm not wearing the right glasses.

Thanks for any help you may have.

Dan
 
Sheriff
Posts: 10445
227
IntelliJ IDE Ubuntu
  • Mark post as helpful
  • send pies
    Number of slices to send:
    Optional 'thank-you' note:
  • Quote
  • Report post to moderator


Those are bugs which have been fixed:

https://jira.jboss.org/jira/browse/JBCL-117

https://jira.jboss.org/jira/browse/JBCL-118

Later versions of JBoss AS have this fix.
 
Dan Seaver
Greenhorn
Posts: 8
  • Mark post as helpful
  • send pies
    Number of slices to send:
    Optional 'thank-you' note:
  • Quote
  • Report post to moderator
Thanks much Jaikiran.
I haven't applied patches to JBoss in the past. Can you point me to a doc for doing this?
Looks like JBCL-118 has some other files that need to be applied as well. How do I get those applied?

Or...Do I need to upgrade to JBoss 6.0.M2 to get the fix. I'd rather do dev work against a GA version if possible.
Do you know if there are other point releases scheduled for 5.1.0 that will include the fix?

Thanks again,
Dan
 
Jaikiran Pai
Sheriff
Posts: 10445
227
IntelliJ IDE Ubuntu
  • Mark post as helpful
  • send pies
    Number of slices to send:
    Optional 'thank-you' note:
  • Quote
  • Report post to moderator

Dan Seaver wrote:
I haven't applied patches to JBoss in the past. Can you point me to a doc for doing this?


Actually, that patch is spread across various projects outside the AS. So the easiest way to *build* an AS to get those patches is to update the AS' component-matrix/pom.xml (which dictates the version of other projects being pulled in) to use the 2.1.3.GA version of jboss-vfs project.

So:
1) Checkout AS 5.1.0 from tag http://anonsvn.jboss.org/repos/jbossas/tags/JBoss_5_1_0_GA/
2) Build the AS as per the instructions here (section JBossAS 5.x and Earlier versions)
3) Once the AS is built, just run it once to make sure everything is fine.
4) Edit the AS_CHECKOUT/component-matrix/pom.xml to change the jboss vfs version to:


(currently it contains 2.1.2.GA)

and rebuild the AS again. That should get you the fix.

Dan Seaver wrote:

Do you know if there are other point releases scheduled for 5.1.0 that will include the fix?


There are no more 5.1.0 community AS releases.
 
Dan Seaver
Greenhorn
Posts: 8
  • Mark post as helpful
  • send pies
    Number of slices to send:
    Optional 'thank-you' note:
  • Quote
  • Report post to moderator
Thanks much! That solved the performance problem. Now the server starts up in 0:46 instead of 5:07!
 
reply
    Bookmark Topic Watch Topic
  • New Topic