Starting WebSphere with both JRebel and XRebel extremely slow

ZeroTurnaround Homepage Forums JRebel Support Starting WebSphere with both JRebel and XRebel extremely slow

This topic contains 2 replies, has 2 voices, and was last updated by  Mark Kocsis 4 days, 11 hours ago.

Viewing 3 posts - 1 through 3 (of 3 total)
  • Author
    Posts
  • #66938

    Mark Kocsis
    Member

    I use both XRebel and JRebel. I have noticed that starting my server takes a long time. I decided to get some benchmarks. The main issue seems to be that when both tools are used numerous hung threads occur. I can send you whatever logs you want and can regenerate them if needed. Hopefully, my time calculations were correct. I attempted to keep my environment (processes running, etc.) the same for all tests.

    My environment
    Windows 7 Professional
    Eclipse Oxygen.2 Release (4.7.2) Build id: 20171218-0600
    WebSphere 8.5.5.9 – Debug Mode
    JRebel For Eclipse 7.1.4
    XRebel 3.4.3

    Neither JRebel nor XRebel
    Test 1: [1/10/18 7:05:54:132 EST] – [1/10/18 7:08:15:890 EST] = 2 mins 21 secs
    Test 2: [1/10/18 7:11:23:391 EST] – [1/10/18 7:13:26:499 EST] = 2 mins 3 secs
    Test 3: [1/10/18 7:20:03:135 EST] – [1/10/18 7:22:08:458 EST] = 2 mins 5 secs

    Just JRebel (Non Legacy)
    Test 1: [1/10/18 7:28:50:524 EST] – [1/10/18 7:37:40:806 EST] = 8 mins 50 secs
    Test 2: [1/10/18 7:43:53:476 EST] – [1/10/18 7:52:21:895 EST] = 8 mins 28 secs
    Test 3: [1/10/18 8:06:49:480 EST] – [1/10/18 8:15:09:571 EST] = 9 mins 3 secs

    Just JRebel (Legacy)
    Test 1: [1/10/18 8:53:37:757 EST] – [1/10/18 9:00:56:770 EST] = 7 mins 19 secs
    Test 2: [1/10/18 9:10:51:267 EST] – [1/10/18 9:17:52:569 EST] = 7 mins 1 secs
    Test 3: [1/10/18 9:26:43:286 EST] – [1/10/18 9:33:24:994 EST] = 7 mins 4 secs

    Just XRebel
    Test 1: [1/10/18 9:41:23:766 EST] – [1/10/18 9:48:33:763 EST] = 7 mins 10 secs
    Test 2: [1/10/18 9:54:13:097 EST] – [1/10/18 10:00:24:772 EST] = 6 mins 11 secs
    Test 3: [1/10/18 10:06:37:721 EST] – [1/10/18 10:13:33:524 EST] = 6 mins 56 secs

    Both JRebel (Non Legacy) and XRebel
    Test 1: [1/10/18 10:20:32:822 EST] – [1/10/18 10:50:52:021 EST] = 30 mins 20 secs
    Test 2: [1/10/18 10:57:42:008 EST] – [1/10/18 11:28:37:695 EST] = 30 mins 56 secs
    Test 3: [1/10/18 11:46:48:491 EST] – [1/10/18 12:31:49:467 EST] = 45 mins 1 secs (Not sure what happened here)

    Both JRebel (Legacy) and XRebel
    Test 1: [1/10/18 12:42:55:214 EST] – [1/10/18 13:00:59:279 EST] = 18 mins 17 secs
    Test 2: [1/10/18 13:19:59:748 EST] – [1/10/18 13:39:02:129 EST] = 19 mins 3 secs
    Test 3: [1/10/18 13:52:36:674 EST] – [1/10/18 14:14:13:248 EST] = 21 mins 37 secs

    Obviously, I can’t wait 30 minutes for the server to start. What I do at the moment is use one tool or the other. Below is the stack trace for the first hung thread:

    [1/11/18 7:31:50:252 EST] 000000a0 SharedEJBRunt I WSVR0057I: EJB jar started: RASPersistence.jar
    [1/11/18 7:40:26:095 EST] 00000105 ThreadMonitor W WSVR0605W: Thread “server.startup : 4” (000000a0) has been active for 754248 milliseconds and may be hung. There is/are 1 thread(s) in total in the server that may be hung.
    at com.zeroturnaround.javarebel.gxb.get(SourceFile:480)
    at com.zeroturnaround.javarebel.gry.get(SourceFile:726)
    at com.zeroturnaround.reload.ae.a(SourceFile:99)
    at com.zeroturnaround.javarebel.to.a(SourceFile:185)
    at com.zeroturnaround.javarebel.ut.a(SourceFile:81)
    at com.zeroturnaround.javarebel.to.a(SourceFile:360)
    at com.zeroturnaround.javarebel.SDKIntegrationImpl.findReloadableClass(SourceFile:104)
    at com.ibm.ws.classloader.CompoundClassLoader.localFindClass(CompoundClassLoader.java)
    at com.ibm.ws.classloader.CompoundClassLoader.loadClass(CompoundClassLoader.java:605)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:741)
    at java.lang.Class.forNameImpl(Native Method)
    at java.lang.Class.forName(Class.java:309)
    at com.zeroturnaround.javarebel.tu.a(SourceFile:118)
    at com.zeroturnaround.javarebel.tu.a(SourceFile:302)
    at com.zeroturnaround.javarebel.tm.transform(SourceFile:123)
    at java.lang.ClassLoader.defineClass(ClassLoader.java)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:95)
    at sun.reflect.DelegatingMethodAccessorImpl.__invoke(DelegatingMethodAccessorImpl.java:56)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java)
    at java.lang.reflect.Method.invoke(Method.java:620)
    at com.zeroturnaround.javarebel.th.a(SourceFile:94)
    at com.zeroturnaround.javarebel.th.a(SourceFile:83)
    at com.zeroturnaround.javarebel.to.a(SourceFile:193)
    at com.zeroturnaround.javarebel.ut.a(SourceFile:81)
    at com.zeroturnaround.javarebel.to.a(SourceFile:360)
    at com.zeroturnaround.javarebel.SDKIntegrationImpl.findReloadableClass(SourceFile:104)
    at com.ibm.ws.classloader.CompoundClassLoader.localFindClass(CompoundClassLoader.java)
    at com.ibm.ws.classloader.CompoundClassLoader.loadClass(CompoundClassLoader.java:605)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:741)
    at com.ibm.ws.webbeans.services.ScannerServiceImpl.convertClassNamesToClass(ScannerServiceImpl.java:490)
    at com.ibm.ws.webbeans.services.ScannerServiceImpl.ecsScan(ScannerServiceImpl.java:428)
    at com.ibm.ws.webbeans.services.ScannerServiceImpl.populateBeans(ScannerServiceImpl.java:231)
    at com.ibm.ws.webbeans.services.JCDIComponentImpl.populateOneDeployedObject(JCDIComponentImpl.java:333)
    at com.ibm.ws.webbeans.services.JCDIComponentImpl.isJCDIEnabled(JCDIComponentImpl.java:837)
    at com.ibm.ws.jaxrs.metadata.JAXRSServerMetaDataBuilder.buildJAXRSMetaData(JAXRSServerMetaDataBuilder.java:85)
    at com.ibm.ws.jaxrs.component.JAXRSComponentImpl.stateChanged(JAXRSComponentImpl.java:294)
    at com.ibm.ws.runtime.component.ApplicationMgrImpl.stateChanged(ApplicationMgrImpl.java:1123)
    at com.ibm.ws.runtime.component.DeployedApplicationImpl.fireDeployedObjectEvent(DeployedApplicationImpl.java:1366)
    at com.ibm.ws.runtime.component.DeployedModuleImpl.setState(DeployedModuleImpl.java:248)
    at com.ibm.ws.runtime.component.DeployedModuleImpl.start(DeployedModuleImpl.java:636)
    at com.ibm.ws.runtime.component.DeployedApplicationImpl.start(DeployedApplicationImpl.java:972)
    at com.ibm.ws.runtime.component.ApplicationMgrImpl.startApplication(ApplicationMgrImpl.java:777)
    at com.ibm.ws.runtime.component.ApplicationMgrImpl$5.run(ApplicationMgrImpl.java:2197)
    at com.ibm.ws.security.auth.ContextManagerImpl.runAs(ContextManagerImpl.java:5396)
    at com.ibm.ws.security.auth.ContextManagerImpl.runAsSystem(ContextManagerImpl.java:5612)
    at com.ibm.ws.security.core.SecurityContext.runAsSystem(SecurityContext.java:255)
    at com.ibm.ws.runtime.component.ApplicationMgrImpl.start(ApplicationMgrImpl.java:2202)
    at com.ibm.ws.runtime.component.CompositionUnitMgrImpl.start(CompositionUnitMgrImpl.java:435)
    at com.ibm.ws.runtime.component.CompositionUnitImpl.start(CompositionUnitImpl.java:123)
    at com.ibm.ws.runtime.component.CompositionUnitMgrImpl.start(CompositionUnitMgrImpl.java:378)
    at com.ibm.ws.runtime.component.CompositionUnitMgrImpl.access$500(CompositionUnitMgrImpl.java:126)
    at com.ibm.ws.runtime.component.CompositionUnitMgrImpl$CUInitializer.run(CompositionUnitMgrImpl.java:984)
    at com.ibm.wsspi.runtime.component.WsComponentImpl$_AsynchInitializer.run(WsComponentImpl.java:502)
    at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1881)
    [1/11/18 7:41:43:394 EST] 000000a0 webapp I com.ibm.ws.webcontainer.webapp.WebGroupImpl WebGroup SRVE0169I: Loading Web Module: com.nsk.ras.template.templateWeb.war.

    I then get a number of hung threads similar to:

    [1/11/18 7:43:26:108 EST] 0000005d ThreadMonitor W WSVR0605W: Thread “SoapConnectorThreadPool : 38” (0000012a) has been active for 754928 milliseconds and may be hung. There is/are 2 thread(s) in total in the server that may be hung.

    If I start with just JRebel or just XRebel I do not get the hung threads. I am not thrilled with the 7 minute start times, but it is acceptable.

    Thanks,

    Mark

    #66947

    Valerie Avramenko
    Rebel Staff

    Hello Mark!

    WOW, that’s hell of the slowdown! Let’s try to figure it out. Could you please send us your performance and trace level jrebel.log file generated while reproducing this behaviour to support@zeroturnaround.com with the link to this forum topic?

    To generate it just add -Drebel.log=trace -Drebel.log.dump_stack_traces=10 -Drebel.log.perf=true to your VM arguments, restart your server, reproduce the issue, stop the server, archive the log file and send to us. The file should be in your $USER_HOME/.jrebel folder (might be hidden).

    Also just to clarify, if you run WAS not in the debug mode, is performance any different?

    Kind regards,
    Valerie

    #66949

    Mark Kocsis
    Member

    I did some tests to answer your question about starting with debugging off and it is much better with debugging off.

    Neither JRebel nor XRebel
    Test 1: [1/12/18 8:14:44:788 EST] – [1/12/18 8:16:17:557 EST] = 1 mins 27 secs
    Test 2: [1/12/18 8:24:30:430 EST] – [1/12/18 8:26:02:769 EST] = 1 mins 38 secs
    Test 3: [1/12/18 8:38:08:185 EST] – [1/12/18 8:39:42:046 EST] = 1 mins 34 secs

    Both JRebel (Non Legacy) and XRebel
    Test 1: [1/12/18 7:20:24:320 EST] – [1/12/18 7:27:04:859 EST] = 6 mins 40 secs
    Test 2: [1/12/18 7:34:28:149 EST] – [1/12/18 7:40:37:549 EST] = 5 mins 51 secs
    Test 3: [1/12/18 8:00:36:049 EST] – [1/12/18 8:07:06:765 EST] = 6 mins 30 secs
    No hung threads.

    Both JRebel (Legacy) and XRebel
    Test 1: [1/12/18 8:47:37:576 EST] – [1/12/18 8:54:27:812 EST] = 6 mins 50 secs
    Test 2: [1/12/18 8:59:28:032 EST] – [1/12/18 9:06:22:612 EST] = 6 mins 54 secs
    Test 3: [1/12/18 9:12:20:547 EST] – [1/12/18 9:18:23:543 EST] = 6 mins 3 secs
    No hung threads.

    I wanted to mention, I did check the configuration of the various thread pools in my WebSphere instance to ensure I didn’t have the maximum amount set too low.

Viewing 3 posts - 1 through 3 (of 3 total)

You must be logged in to reply to this topic.