VisiBroker Threads

[[Explanation of Example|Back]]

In this example we capture and analyze the important stack traces of the client and server during invocations.

Stack traces are very useful debugging information. Since they can be captured while the processes are running with minimal impact, they can even be taken from production systems under high load. They provide insights into the current state and load situation of the application.

The "echo_service_cpp" and "echo_service_java" [[Explanation of Example|examples]] are used in this demonstration.

Scenario

  • The Client creates 2 threads to call 1 Server.
  • Each client thread calls the Server once.
  • Each invocation blocks for 100 seconds at the Server side.

Preparation

Configure the Client by modifying c.sh in both the C++ and Java examples:

  • Set the following properties:
    • server_sleep_time 100
    • vbroker.agent.enableLocator=false
  • Disable all the other properties.

Configure the Server by modifying s.sh in both the C++ and Java examples:

  • Set the following properties:
    • vbroker.agent.enableLocator=false
    • vbroker.se.iiop_tp.scm.iiop_tp.dispatcher.threadMin=5
    • vbroker.se.default.local.manager.enabled=false (for VBC++ only)
  • Disable all the other properties.

Note that to avoid any unnecessary distraction from the topic of Thread and Connection tuning, the Smart Agent and the VBC++ local IPC manager are disabled for all the examples in subsequent articles.

Execution

Make sure you have set up the necessary VisiBroker environment and build the examples before running this demonstration.

Running the C++ Example:

  • Start the Server:
    • s.sh 1
  • Start the Client:
    • c.sh 1 1 2
  • Take note of the Server and Client PIDs.
  • Capture the Server stack trace:
    • pstack <Server PID>
  • Capture the Client stack trace:
    • pstack <Client PID>

Running the Java Example:

  • Start the Server:
    • s.sh 1
  • Start the Client:
    • c.sh 1 1 2
  • Take note of the Server and Client PIDs.
  • Capture the Server stack trace:
    • jstack <Server PID>
  • Capture the Client stack trace:
    • jstack <Client PID>

Identifying VisiBroker Threads

After capturing the full stack trace of the application process, you need to identify which of the threads are associated with VisiBroker and which belongs to the application. This information is important when tuning Visibroker or the application logic.

VisiBroker Thread Pool is responsible for managing the life cycle of the Worker Threads servicing the requests at the server-side ORB. However, the application logic is responsible for managing the life cycle of the threads making the invocations in the client-side ORB.

So while tuning VisiBroker you must be aware that the Thread Pool Dispatcher properties only affect the server-side Worker Threads managed by VisiBroker, and not the client-side invocation threads managed by the application.

Example of VBC++ Stack Traces

How does the VBC++ client-side invocation thread's stack trace looks like ?

Example 1: This means that the invocation thread has send the request and is waiting for the reply to arrive by reading from socket:

fe7bd2d8 read (...)
fef3e4ec void VISTCPConnBase::_read (...)
fef3e414 void VISTCPConnBase::read (...)
fedfc594 void VISGIOPInputBuffer::read_from_connection (...)
fee097a8 ProtocolEngine::Message*VISGIOPMessage::create (...)
fee038f4 ProtocolEngine::Message*VISGIOPConn::receive_message (...)
fee0317c ProtocolEngine::Message*VISGIOPConn::_receive_reply (...)
fee0133c ProtocolEngine::Message*VISGIOPConn::invoke (...)
feeb501c ProtocolEngine::ReplyMessage*VISGIOPProtocolConnector::invoke (...)
feea5ed4 CORBA_MarshalInBuffer*VISDelegate::invoke (...)
000176b8 char*Tutorial::EchoService::echo (...)
00015a08 void ClientThread::begin (...)
ff31dd3c void*VISThread::_start (...)
fe7bc400 _lwp_start (...)

Example 2: This means that the invocation thread has send the request, and is waiting for the reply by waiting in a waiter queue because another thread is reading from the same socket:

fe7bc4a0 lwp_park (...)
fe7b676c cond_wait_queue (...)
fe7b6cec cond_wait (...)
fe7b6d28 pthread_cond_wait (...)
ff31f644 void VISCondition::wait (...)
fee04c58 ProtocolEngine::Message*VISGIOPConn::_wait_for_reply (...)
fee02d68 ProtocolEngine::Message*VISGIOPConn::_receive_reply (...)
fee0133c ProtocolEngine::Message*VISGIOPConn::invoke (...)
feeb501c ProtocolEngine::ReplyMessage*VISGIOPProtocolConnector::invoke (...)
feea5ed4 CORBA_MarshalInBuffer*VISDelegate::invoke (...)
000176b8 char*Tutorial::EchoService::echo (...)
00015a08 void ClientThread::begin (...)
ff31dd3c void*VISThread::_start (...)
fe7bc400 _lwp_start (...)

How does the VBC++ server-side Worker Thread's stack trace looks like ?

Example 1: This means that the Worker Thread is busy doing some work (i.e. sleeping in this example):
fe7bc7dc nanosleep (...)
00016830 char*EchoImpl::echo(unsigned long,const char*) (...)
0001731c void POA_Tutorial::EchoService::_echo (...)
fee21ab8 void VISSkelInfo::execute (...)
fee333d4 void VISGIOPProtocolAdapter::_do_request (...)
fee327c0 void VISGIOPProtocolAdapter::dispatchMessage (...)
fef324ac void VISThreadPoolDispatcher::do_work (...)
fef2fa40 void VISDispatchWorker::do_work(VISThreadSpecificData*) (...)
fef21574 void VISThreadPool::_perform_task(VISTPoolWorker*) (...)
fef237dc void VISTPoolWorker::begin() (...)
ff31dd3c void*VISThread::_start(void*) (...)
fe7bc400 _lwp_start (...)

Example 2: This means that the Worker Thread is idle and waiting in Thread Pool:
fe7bc4a0 lwp_park (...)
fe7b676c cond_wait_queue (...)
fe7b6cec cond_wait (...)
fe7b6d28 pthread_cond_wait (...)
ff31f644 void VISCondition::wait (...)
fef21464 void VISThreadPool::_perform_task (...)
fef237dc void VISTPoolWorker::begin (...)
ff31dd3c void*VISThread::_start (...)
fe7bc400 _lwp_start (...)

Please note that the above stack trace snapshots are captured using Solaris's "pstack" tool based on the given C++ example using VisiBroker 8.5. For readability the C++ function names were demangled with c++filt and details replaced with (...).

The stack traces captured with other tools in other platforms, VisiBroker versions or use cases may appear different.

Example of VBJ Stack Traces

How does the VBJ client-side invocation thread's stack trace looks like ?

Example 1: This means that the invocation thread has sent the request and is waiting for the reply to arrive by reading from socket:
"Thread-3" prio=3 tid=0x002e8800 nid=0xd runnable [0xd6ffe000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at com.inprise.vbroker.IIOP.Connection.read(Unknown Source)
at com.inprise.vbroker.GIOP.BaseInputStream.readFromConnection(Unknown Source)
at com.inprise.vbroker.GIOP.MessageFactory.readMessage(Unknown Source)
at com.inprise.vbroker.GIOP.GiopConnection.receive_message(Unknown Source)
at com.inprise.vbroker.IIOP.ProtocolConnection.receive(Unknown Source)
at com.inprise.vbroker.IIOP.ProtocolConnection.receive_reply(Unknown Source)
at com.inprise.vbroker.GIOP.ProtocolConnector.invoke(Unknown Source)
at com.inprise.vbroker.orb.DelegateImpl.invoke(Unknown Source)
at org.omg.CORBA.portable.ObjectImpl._invoke(ObjectImpl.java:457)
at Tutorial._EchoServiceStub.echo(_EchoServiceStub.java:44)
at Tutorial.Worker.doWork(EchoClient.java:108)
at Tutorial.Worker.run(EchoClient.java:97)
at java.lang.Thread.run(Thread.java:662)


Example 2: This means that the invocation thread has sent the request, and is waiting for the reply by waiting in a waiter queue because another thread is reading from the same socket:
"Thread-4" prio=3 tid=0x0033bc00 nid=0xe in Object.wait() [0xd6eff000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xd7c72228> (a com.inprise.vbroker.GIOP.GiopConnection$GiopConnectionReplyWaiter)
at java.lang.Object.wait(Object.java:485)
at com.inprise.vbroker.IIOP.ProtocolConnection.receive_reply(Unknown Source)
- locked <0xd7c72228> (a com.inprise.vbroker.GIOP.GiopConnection$GiopConnectionReplyWaiter)
at com.inprise.vbroker.GIOP.ProtocolConnector.invoke(Unknown Source)
at com.inprise.vbroker.orb.DelegateImpl.invoke(Unknown Source)
at org.omg.CORBA.portable.ObjectImpl._invoke(ObjectImpl.java:457)
at Tutorial._EchoServiceStub.echo(_EchoServiceStub.java:44)
at Tutorial.Worker.doWork(EchoClient.java:108)
at Tutorial.Worker.run(EchoClient.java:97)
at java.lang.Thread.run(Thread.java:662)

How does the VBJ server-side Worker Thread's stack trace looks like ?

Example 1: This means that the Worker Thread is busy doing some work (i.e. sleeping in this example):
"VBJ ThreadPool Worker id=2 se=iiop_tp scm=iiop_tp orb=1764be1" daemon prio=3 tid=0x00288c00 nid=0xe waiting on condition [0xd6eff000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at Tutorial.SleepWork.perform(EchoServant.java:40)
at Tutorial.EchoServant.echo(EchoServant.java:18)
at Tutorial.EchoServicePOA._invoke(EchoServicePOA.java:68)
at Tutorial.EchoServicePOA._invoke(EchoServicePOA.java:50)
at com.inprise.vbroker.poa.POAImpl.invoke(Unknown Source)
at com.inprise.vbroker.poa.ActivationRecord.invoke(Unknown Source)
at com.inprise.vbroker.GIOP.GiopProtocolAdapter.doRequest(Unknown Source)
at com.inprise.vbroker.IIOP.ServerProtocolAdapter.doRequest(Unknown Source)
at com.inprise.vbroker.GIOP.GiopProtocolAdapter.dispatchMessage(Unknown Source)
at com.inprise.vbroker.orb.TPDispatcherImpl$TPDispatcher.run(Unknown Source)
at com.inprise.vbroker.orb.ThreadPool$PoolWorker.run(Unknown Source)


Example 2: This means that the Worker Thread is idle and waiting in Thread Pool:
"VBJ ThreadPool Worker id=4 se=iiop_tp scm=iiop_tp orb=1764be1" daemon prio=3 tid=0x002e7000 nid=0x10 in Object.wait() [0xd6cff000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xd8596528> (a com.inprise.vbroker.orb.TPDispatcherImpl)
at java.lang.Object.wait(Object.java:485)
at com.inprise.vbroker.orb.ThreadPool$PoolWorker.run(Unknown Source)
- locked <0xd8596528> (a com.inprise.vbroker.orb.TPDispatcherImpl)


Example 3: This means that the Worker Thread is waiting for new request to arrive by reading from socket:
"VBJ ThreadPool Worker id=3 se=iiop_tp scm=iiop_tp orb=1764be1" daemon prio=3 tid=0x00368c00 nid=0xf runnable [0xd6dff000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at com.inprise.vbroker.IIOP.Connection.read(Unknown Source)
at com.inprise.vbroker.GIOP.BaseInputStream.readFromConnection(Unknown Source)
at com.inprise.vbroker.GIOP.MessageFactory.readMessage(Unknown Source)
at com.inprise.vbroker.GIOP.GiopConnection.receive_message(Unknown Source)
at com.inprise.vbroker.IIOP.ProtocolConnection.receive(Unknown Source)
at com.inprise.vbroker.IIOP.ProtocolConnection.receive_request(Unknown Source)
at com.inprise.vbroker.IIOP.ServerProtocolAdapter.readMessage(Unknown Source)
at com.inprise.vbroker.orb.TPDispatcherImpl$TPDispatcher.run(Unknown Source)
at com.inprise.vbroker.orb.ThreadPool$PoolWorker.run(Unknown Source)


Please note that the above stack trace snapshots are captured using JDK6's "jstack" tool based on the given Java example using VisiBroker 8.5.

The stack traces captured with other tools in other platforms, VisiBroker versions or use cases may appear different.

Analysis of Stack Traces

After you've identified and analysed the threads in the stack traces, you should be able to make a better decision to tune the Visibroker properties, or to tune the application logic, or even to fix a bug. However, a good understanding of the client and server side application implementation details are needed when interpreting the stack traces.

For example, an application may become unresponsive due to a deadlock bug in the application logic. You may be able to identify the root cause of the deadlock after analyzing the application stack traces. But such issue is beyond the control of VisiBroker, and tuning VisiBroker cannot resolve it.

Another example is that you have identified 1000 VisiBroker worker threads doing some work inside the application code. Is this considered an issue ? To some applications, 1000 worker threads may be consider too high and may cause out of memory and instability issues. But to other applications, this may be the expected load during the peak periods and the system is already tuned to have sufficient resources to handle it. So good understanding of the application requirement and load is needed to make the correct tuning decision.

In the next article we will discuss the tuning of “vbroker.se.<se_name>.scm.<scm_name>.dispatcher.unlimitedConcurrency” property specific for VBC++ Server.

[[Explanation of Example|Back]]  |  [[Thread Pool Dispatcher unlimitedConcurrency|Next]]

Labels (1)

DISCLAIMER:

Some content on Community Tips & Information pages is not officially supported by Micro Focus. Please refer to our Terms of Use for more detail.
Top Contributors
Version history
Revision #:
2 of 2
Last update:
‎2020-03-13 21:04
Updated by:
 
The opinions expressed above are the personal opinions of the authors, not of Micro Focus. By using this site, you accept the Terms of Use and Rules of Participation. Certain versions of content ("Material") accessible here may contain branding from Hewlett-Packard Company (now HP Inc.) and Hewlett Packard Enterprise Company. As of September 1, 2017, the Material is now offered by Micro Focus, a separately owned and operated company. Any reference to the HP and Hewlett Packard Enterprise/HPE marks is historical in nature, and the HP and Hewlett Packard Enterprise/HPE marks are the property of their respective owners.