Introducing the all-new TIBCO Community site!

For current users, please click "Sign In" to reset your password and access the enhanced features. If you're a first-time visitor, we extend a warm welcome—click "Sign Up" to become a part of the TIBCO Community!

If you're seeking alternative community sites, explore ibi, Jaspersoft, and Spotfire.

Jump to content
  • How to troubleshoot slow startup or shutdown of TIBCO ActiveMatrix BusinessWorks? 5 (BW) applications


    Manoj Chaurasia

    How to quickly troubleshoot slow startup or shutdown of BW applications. What data to collect and what to look for.

    BW application logs, even with debug logging turned on, may not contain useful information for troubleshooting slow startup or shutdown. To identify the operation that is causing the slowness, a thread dump of the application would be needed. In the case of a slow startup, check what the main thread is doing and in the case of a slow shutdown, check the AMI Worker thread. The instructions for taking a thread dump can be found here

     

    Example 1 - Slow startup

    The following log excerpt shows startup taking more than 3 minutes.


    2020 Oct  24 13:30:07:701 GMT -0400 BW.Slow-Startup-Process_Archive Info [bW-Core] BWENGINE-300001 Process Engine version 5.14.0, build V11, 2018-7-11 
    2020 Oct  24 13:30:07:704 GMT -0400 BW.Slow-Startup-Process_Archive Info [bW-Core] BWENGINE-300009 BW Plugins: version 5.14.0, build V11, 2018-7-11 
    2020 Oct  24 13:30:07:707 GMT -0400 BW.Slow-Startup-Process_Archive Info [bW-Core] BWENGINE-300010 XML Support: TIBCOXML Version 5.60.200.001 
    2020 Oct  24 13:30:07:708 GMT -0400 BW.Slow-Startup-Process_Archive Info [bW-Core] BWENGINE-300011 Java version: Java HotSpot 64-Bit Server VM 25.181-b13 
    2020 Oct  24 13:30:07:708 GMT -0400 BW.Slow-Startup-Process_Archive Info [bW-Core] BWENGINE-300012 OS version: amd64 Windows 10 10.0 
    2020 Oct  24 13:33:33:377 GMT -0400 BW.Slow-Startup-Process_Archive Info [bW-Core] BWENGINE-300013 Tibrv string encoding: UTF-8 
    2020 Oct  24 13:33:33:700 GMT -0400 BW.Slow-Startup-Process_Archive Info [bW-Core] BWENGINE-300002 Engine Slow-Startup-Process_Archive started


    A thread dump taken during the startup shows the main thread waiting on a socketRead() method. The thread stack trace shows that the application is retrieving a WSDL or XSD from an HTTP location. If multiple thread dumps taken a few seconds apart show the thread in the same state, it can be concluded that this operation is causing the slowness. 


    "main" #1 prio=5 os_prio=0 tid=0x00000000023a1000 nid=0x961d4 runnable [0x000000000014e000]
       java.lang.Thread.State: RUNNABLE
            at java.net.SocketInputStream.socketRead0(Native Method)
            at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
            at java.net.SocketInputStream.read(SocketInputStream.java:171)
            at java.net.SocketInputStream.read(SocketInputStream.java:141)
            at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
            at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
            at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
            - locked <0x00000000fe7e7d18> (a java.io.BufferedInputStream)
            at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:735)
            at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:678)
            at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1587)
            - locked <0x00000000fe7db328> (a sun.net.www.protocol.http.HttpURLConnection)
            at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1492)
            - locked <0x00000000fe7db328> (a sun.net.www.protocol.http.HttpURLConnection)
            at java.net.URL.openStream(URL.java:1045)
            at com.tibco.xml.tns.impl.TnsDocumentStoreImpl.a(TnsDocumentStoreImpl.java:329)
            at com.tibco.xml.tns.impl.TnsDocumentStoreImpl.a(TnsDocumentStoreImpl.java:278)
            at com.tibco.xml.tns.impl.TnsDocumentStoreImpl.documentAddedOrChanged(TnsDocumentStoreImpl.java:136)
            at com.tibco.objectrepo.schema.VFileTNSCache.documentAddedOrChanged(VFileTNSCache.java:207)
            at com.tibco.objectrepo.schema.VFileTNSCache.if(VFileTNSCache.java:181)
            at com.tibco.objectrepo.schema.VFileTNSCache.if(VFileTNSCache.java:170)
            at com.tibco.objectrepo.schema.VFileTNSCache.<init>(VFileTNSCache.java:155)
            at com.tibco.pe.core.RepoAgentImpl.<init>(Unknown Source)
            at com.tibco.pe.core.RepoLoader.if(Unknown Source)
            at com.tibco.pe.core.RepoLoader.<init>(Unknown Source)
            at com.tibco.pe.PEMain.a(Unknown Source)
            at com.tibco.pe.PEMain.do(Unknown Source)
            at com.tibco.pe.PEMain.a(Unknown Source)
            at com.tibco.pe.PEMain.<init>(Unknown Source)
            at com.tibco.pe.PEMain.main(Unknown Source)

       Locked ownable synchronizers:

            - None


     

    Example 2 - Slow shutdown

    The following log excerpt shows shutdown taking around 4 minutes.


    2020 Oct 25 15:05:14:896 GMT -0400 BW.Slow-Shutdown-Process_Archive Info [bW-Core] BWENGINE-300014 Starting delayed shutdown, max-delay=[0], wait-for-checkpoints=[false] 
    2020 Oct 25 15:09:06:552 GMT -0400 BW.Slow-Shutdown-Process_Archive Debug [bW-Core]  Shutdown max timeout exceeded, 0 jobs still running 
    2020 Oct 25 15:09:06:556 GMT -0400 BW.Slow-Shutdown-Process_Archive Info [bW-Core] BWENGINE-300006 Engine Slow-Shutdown-Process_Archive terminating
     


    A thread dump taken during the shutdown shows the thread AMI Worker 1 in BLOCKED state waiting to acquire a monitor lock owned by the thread Thread-15. Thread-15 is associated with JMS Queue Receiver activity and could end up waiting on the receive() call (possibly blocking other threads) if Receiver Timeout is set to a high value for the JMS Queue Receiver activity and there are no messages in the queue.    


    "Thread-15" #31 prio=5 os_prio=0 tid=0x00000000188b7000 nid=0x9614c in Object.wait() [0x000000001a8ff000]
       java.lang.Thread.State: TIMED_WAITING (on object monitor)
            at java.lang.Object.wait(Native Method)
            - waiting on <0x00000000fcc16db8> (a java.lang.Object)
            at com.tibco.tibjms.TibjmsxSessionImp._getSyncMessage(TibjmsxSessionImp.java:2288)
            at com.tibco.tibjms.TibjmsxSessionImp._receive(TibjmsxSessionImp.java:2122)
            - locked <0x00000000fcc16db8> (a java.lang.Object)
            at com.tibco.tibjms.TibjmsMessageConsumer._receive(TibjmsMessageConsumer.java:276)
            at com.tibco.tibjms.TibjmsMessageConsumer.receive(TibjmsMessageConsumer.java:481)
            at com.tibco.plugin.share.jms.impl.JMSReceiver$SessionController.run(Unknown Source)
            - locked <0x00000000fcc52e10> (a com.tibco.plugin.share.jms.impl.JMSReceiver$SessionController)

       Locked ownable synchronizers:

            - None

    "AMI Worker 1" #34 prio=5 os_prio=0 tid=0x00000000188bc800 nid=0x96224 waiting for monitor entry [0x000000001a8bf000]
       java.lang.Thread.State: BLOCKED (on object monitor)
            at com.tibco.plugin.share.jms.impl.JMSReceiver$SessionController.deactivate(Unknown Source)
            - waiting to lock <0x00000000fcc52e10> (a com.tibco.plugin.share.jms.impl.JMSReceiver$SessionController)
            at com.tibco.plugin.share.jms.impl.JMSReceiver.deactivate(Unknown Source)
            - locked <0x00000000fcc16708> (a [Lcom.tibco.plugin.share.jms.impl.JMSReceiver$SessionController;)
            - locked <0x00000000f045db40> (a com.tibco.plugin.share.jms.impl.JMSReceiver)
            at com.tibco.plugin.jms.JMSAbstractEventSource.deactivate(Unknown Source)
            - locked <0x00000000f045dc30> (a com.tibco.plugin.jms.JMSQueueEventSource)
            at com.tibco.pe.core.ProcessStarter.setState(Unknown Source)
            at com.tibco.pe.core.ProcessStarter.setState(Unknown Source)
            at com.tibco.pe.core.JobPool.long(Unknown Source)
            at com.tibco.pe.core.JobPool.suspendAllStarters(Unknown Source)
            - locked <0x00000000f048c390> (a java.lang.Object)
            at com.tibco.pe.core.JobPool.delayedShutdown(Unknown Source)
            - locked <0x00000000f048c390> (a java.lang.Object)
            at com.tibco.pe.hawk.EngineHawkMicroagent$DelayedStopApplicationInstanceMethod.onInvoke(Unknown Source)



    User Feedback

    Recommended Comments

    There are no comments to display.


×
×
  • Create New...