Monday Jun 16, 2014

Detailed Analysis of a Stuck Weblogic Execute Thread Running JDBC Code

The following thread was extracted from a thread dump taken on a JVM instance running WebLogic Server.

In this post I will deconstruct this thread and describe the data it contains and the potential issues it may illuminate.

[STUCK] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)' id=73 idx=0x128 nid=13410 prio=1 alive, in native, daemon 

 java.net.SocketInputStream.socketRead0(Native Method)

java.net.SocketInputStream.read(SocketInputStream.java:129)

oracle.net.ns.Packet.receive(Unknown Source)

oracle.net.ns.DataPacket.receive(Unknown Source)

oracle.net.ns.NetInputStream.getNextPacket(Unknown Source)

oracle.net.ns.NetInputStream.read(Unknown Source)

oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1099)

oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:1070)

oracle.jdbc.driver.T4CTTIoauthenticate.receiveOauth(T4CTTIoauthenticate.java:751)

oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:362)

oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:420)

oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:165)

oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:35)

oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:801)

java.sql.DriverManager.getConnection(DriverManager.java:140)

com.foo.abc.util.ConnectionPool.createConnection(Unknown Source)

This thread is considered Stuck by WebLogic because it's been running for over the time defined in MaxStuckThreadTime (600 seconds by default). Weblogic Server waits for this time to be reached before marking a thread as stuck if the thread is still working after this time.  If you deem that 600 seconds is too long before a running thread is considered stuck then you can change the value of the this parameter using the WebLogic Console (as shown below), or use setMaxStuckThreadTime from the ServerFailureTriggerMBean interface.

An error including BEA-000337 will be logged in the server log file when the thread changes its status to stuck but the server won't take further action on this thread.  However, you might want to investigate why this thread is taking such a long time to process the work assigned to it.

Lets now look at the thread itself.  From its header, you can spot the thread identifier (2 in this example) and the queue where it originated.  The term Self-tuning indicates that the associated thread pool consistently checks the overall throughput to determine if the thread count should change.

id (or tid) is the thread identifier, a unique process-wide number that identifies this thread within the JVM process.  This id is unique but can be reused by another thread once this thread is terminated. 

nid is the OS-level native thread identifier.  It can be used effectively to correlate with high CPU usage threads identified at the OS level (e.g. with Linux watch command).  See Unexpected High CPU Usage with WebLogic Server (WLS) Support Pattern (Doc ID 779349.1) for detailed steps.

idx is the thread index in the threads array.

prio refers to the thread priority, a number inherited from the thread that created it.  You can learn more about thread priorities at Class Thread but basically threads with higher priority are executed in preference to threads with lower priority.

alive refers to the fact that this thread has not ended yet and is still active.  

in native means that the thread uses the operating system's native ability to manage multi-threaded processes.  

daemon indicates that this thread can't prevent the JVM from exiting.

The thread header is accompanied with a full java stack which lists each method and class invoked since the first assignement to the thread up to its most recent action. This thread consists of obtaining a connection to an Oracle database using a Type 4 JDBC driver and then issuing a call but getting no response from the back end database server.  The database failed to respond, and the thread has probably been in the same waiting mode (unchanged and not progressing java stack) for a long time since it's now considered stuck; the most recent invocation being java.net.SocketInputStream.socketRead0.

At this point the back end database needs to be checked to understand why it's not responding to the java thread request.  A starting point could be to query v$session to find potential blocking sessions at the database level.

Blocking sessions occur when one session holds an exclusive lock on an object and doesn't release it.

Needless to say, the communication with the database needs to be confirmed as healthy with none to very limited latency.  Firewall issues should be ruled out as well.  Firewalls could time out idle sockets used by JDBC connections to the database and lead to not closing the socket the JDBC driver is using.

Tuesday Feb 05, 2013

Troubleshooting Tools Part 2 - jstack

In my latest blog post I talked about VisualVM, a very effective monitoring and troubleshooting tool.  Many other easy-to-use and free tools can be used while working with Java SE.  First of all, and since there is no need to re-invent the wheel, you can access documentation of such tools for Windows at Quick Troubleshooting Tips on Windows for Java SE 6 and for Solaris and Linux at Troubleshooting Tools on Solaris OS and Linux for Java SE 6

These tools include jstack, jinfo, jconsole, jmap, jstat, jhat and a few others.

jstack can be use to dump the java threads.  While working with WebLogic Server, you can dump the java threads with various tools such as WLST.  jstack can do just that but differs from <ctrl>+<break> or kill -3 since it doesn't dump a heap summary along with the threads.  

In addition, jstack can print lock information with -l option and the list of synchronizers that may be exclusively owned by a thread.  Such information can be very useful while monitoring concurrent access by threads.

jstack comes as part of the JDK installed with WebLogic Server.  With instances of WLS running, you can open a new shell, execute the setDomain script and run jstack or any tool that's part of the JDK package. Thread dumps taken by jstack can be redirected to files, e.g. jstack <pid> > myTD.txt.

PIDs can be obtained on Solaris/Linux with the ps (report process status) command, e.g. ps -ef | grep java, and from the task managed on Windows.  In task manager you might need to go to View and Select Columns to add PID or process identifiers.

About

The official blog for Oracle WebLogic Server fans and followers!

Stay Connected

Search

Archives
« July 2014
SunMonTueWedThuFriSat
  
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
  
       
Today