Search This Blog

Wednesday 24 February 2016

Trouble shooting Application slowness issue in weblogic

Linux performance related commands

top - to check cpu and memory usage

top - 03:32:44 up 1 day, 23:09,  6 users,  load average: 0.00, 0.05, 0.32
Tasks: 157 total,   1 running, 156 sleeping,   0 stopped,   0 zombie
Cpu(s):  1.1%us,  0.3%sy,  0.0%ni, 97.7%id,  0.8%wa,  0.0%hi,  0.1%si,  0.0%st
Mem:   1011508k total,  1001500k used,    10008k free,     3528k buffers
Swap:  2097148k total,   333960k used,  1763188k free,    69648k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
   10 root      20   0     0    0    0 S  3.7  0.0   0:19.80 rcu_sched
13415 oracle    20   0 1286m 293m 4116 S  1.8 29.7   0:29.02 java
    1 root      20   0 19408  376  200 S  0.0  0.0   0:04.57 init


System activity report
sar -r 2 5
sar -r 2 

[oracle@OEL6 ~]$ sar -r 2 2
Linux 3.8.13-98.2.2.el6uek.x86_64 (OEL6)        02/10/2016      _x86_64_        (1 CPU)

03:33:57 AM kbmemfree kbmemused  %memused kbbuffers  kbcached  kbcommit   %commit
03:33:59 AM     11020   1000488     98.91      2692     69448   2032144     65.37
03:34:01 AM     11020   1000488     98.91      2692     69448   2032144     65.37
Average:        11020   1000488     98.91      2692     69448   2032144     65.37


Input and out put statistics

iostat 2 5
iostat 2

[oracle@OEL6 ~]$ iostat 2 1
Linux 3.8.13-98.2.2.el6uek.x86_64 (OEL6)        02/10/2016      _x86_64_        (1 CPU)

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.12    0.00    0.37    0.85    0.00   97.66

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
scd0              0.00         0.00         0.00        544          0
sda               4.91       160.92        43.61   27073268    7336356
fd0               0.00         0.00         0.00         16          0

[oracle@OEL6 ~]$ free
             total       used       free     shared    buffers     cached
Mem:       1011508     999864      11644       2328       3064      60936
-/+ buffers/cache:     935864      75644
Swap:      2097148     334344    1762804


df -h - Disk usage

[oracle@OEL6 ~]$ df -h /home/oracle/
Filesystem      Size  Used Avail Use% Mounted on
/dev/sda3        57G   23G   32G  42% /


jmap -heap will display the snap shot of heap usage


[oracle@OEL6 ~]$ /home/oracle/jdk1.7.0_21/bin/jmap -heap 12659
Attaching to process ID 12659, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 23.21-b01

using thread-local object allocation.
Mark Sweep Compact GC

Heap Configuration:
   MinHeapFreeRatio = 40
   MaxHeapFreeRatio = 70
   MaxHeapSize      = 268435456 (256.0MB)
   NewSize          = 1310720 (1.25MB)
   MaxNewSize       = 17592186044415 MB
   OldSize          = 5439488 (5.1875MB)
   NewRatio         = 2
   SurvivorRatio    = 8
   PermSize         = 21757952 (20.75MB)
   MaxPermSize      = 268435456 (256.0MB)
   G1HeapRegionSize = 0 (0.0MB)

Heap Usage:
New Generation (Eden + 1 Survivor Space):
   capacity = 80543744 (76.8125MB)
   used     = 75933440 (72.415771484375MB)
   free     = 4610304 (4.396728515625MB)
   94.27602471521563% used
Eden Space:
   capacity = 71630848 (68.3125MB)
   used     = 71377800 (68.07117462158203MB)
   free     = 253048 (0.24132537841796875MB)
   99.6467332063415% used
From Space:
   capacity = 8912896 (8.5MB)
   used     = 4555640 (4.344596862792969MB)
   free     = 4357256 (4.155403137207031MB)
   51.112904268152576% used
To Space:
   capacity = 8912896 (8.5MB)
   used     = 0 (0.0MB)
   free     = 8912896 (8.5MB)
   0.0% used
tenured generation:
   capacity = 178978816 (170.6875MB)
   used     = 101403672 (96.7060775756836MB)
   free     = 77575144 (73.9814224243164MB)
   56.65680121607241% used
Perm Generation:
   capacity = 130940928 (124.875MB)
   used     = 130640608 (124.58859252929688MB)
   free     = 300320 (0.286407470703125MB)
   99.7706446681056% used

69269 interned Strings occupying 8985680 bytes.


Validation

Welogic Server check
Check for the weblogic server status 
Number of free vs available threads and stuck threads 
Timeouts in logs ( Application logs and server logs)
Check java Heap memory size ( Free memory) 

Unix server Check
Check I/O statistics -   iostat 
Check the memory,swap Bottleneck - free
To check top process CPU utilizations -top
Check the disk space - df -h

DB Server check
Check for hung sessions
Check for long running queries
Check for CPU usage – If beyond a certain threshold need to take an action
Stale Stats

Tuesday 23 February 2016

How to match the JVM thread id with Linux Process ID

THREAD: A process is divided into multiple  lite weight process. Each lite weight process is called  thread.

Thread dump provide a snap shot of current active threads. It provide stack trace of all java threads in jvm.

When do we take thread dumps:

There could be scenarios like
1.server hang
2.crash
3. Performance delays.
4. In case of stuck threads.

Different ways to take thread dumps:

Method 1 : unix command

 kill -3 pid

Method 2:  java command

cd /home/oracle/Middleware/Oracle_Home/user_projects/domains/pavan_domain/bin
[oracle@OEL6 bin]$ . ./setDomainEnv.sh
[oracle@OEL6 bin]$/home/oracle/jdk1.7.0_21/bin/java weblogic.Admin -url t3://localhost:9001 -username weblogic -password weblogic123 THREAD_DUMP

Method 3: Console 
Click on MS1 -> Monitoring -> Performance -> Dump Thread Stacks

Method 4: wlst

[oracle@OEL6 bin]$ . ./setDomainEnv.sh
[oracle@OEL6 pavan_domain]$ java weblogic.WLST
wls:/offline> connect('weblogic','weblogic','t3://localhost:9001')
wls:/pavan_domain/serverConfig> cd('Servers')
wls:/pavan_domain/serverConfig/Servers> ls()
dr--   AdminServer
dr--   ms1
dr--   ms2
wls:/pavan_domain/serverConfig/Servers> cd('ms1')
wls:/pavan_domain/serverConfig/Servers/ms1> threadDump()


How to match JVM Thread ID with Linux Process id


[oracle@OEL6 pavan_domain]$ ps -ef | grep -i Dweblogic.Name=ms1

oracle    8296  8244  0 02:20 pts/0    00:00:45 /home/oracle/jdk1.7.0_21/bin/java -server -Xms256m -Xmx256m -XX:MaxPermSize=256m -Dweblogic.Name=ms1 -Djava.security.policy=/home/oracle/Middleware/Oracle_Home/wlserver/server/lib/weblogic.policy -Dweblogic.ProductionModeEnabled=true -Dweblogic.security.SSL.trustedCAKeyStore=/home/oracle/Middleware/Oracle_Home/wlserver/server/lib/cacerts -Xverify:none -Djava.endorsed.dirs=/home/oracle/jdk1.7.0_21/jre/lib/endorsed:/home/oracle/Middleware/Oracle_Home/wlserver/../oracle_common/modules/endorsed -da -Dwls.home=/home/oracle/Middleware/Oracle_Home/wlserver/server -Dweblogic.home=/home/oracle/Middleware/Oracle_Home/wlserver/server -Dweblogic.management.server=http://localhost:9001 -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:/home/oracle/Middleware/Oracle_Home/user_projects/domains/pavan_domain/gc.log weblogic.Server

[oracle@OEL6 pavan_domain]$ top -b -H -p 8296
  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 8298 oracle    20   0 1284m 224m 1112 S  2.0 22.7   0:03.61 java
 8313 oracle    20   0 1284m 224m 1112 S  2.0 22.7   0:00.88 java
 8296 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.00 java
 8297 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:04.40 java
 8299 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.01 java
 8300 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.03 java
 8301 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.00 java
 8302 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:03.01 java
 8303 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:03.25 java
 8304 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.00 java
 8305 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:03.93 java
 8306 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.00 java
 8309 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.66 java
 8310 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:10.81 java
 8311 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.00 java
 8312 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:02.77 java
 8314 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:08.24 java
 8315 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.12 java
 8316 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.32 java
 8343 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.00 java
 8345 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.02 java
 8349 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:01.90 java
 8381 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.94 java
 8383 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.04 java
 8386 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.00 java
 8387 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.04 java
 8388 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.00 java
 8389 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.05 java
 8622 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.00 java
 8623 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.00 java

Stuck Thread from thread dump:

"[STUCK] ExecuteThread: '3' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x00007fe980d03000 nid=0x20c4 in Object.wait() [0x00007fe98d86a000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000000e71abac8> (a weblogic.work.ExecuteThread)
        at java.lang.Object.wait(Object.java:503)
        at weblogic.work.ExecuteThread.waitForRequest(ExecuteThread.java:238)
        - locked <0x00000000e71abac8> (a weblogic.work.ExecuteThread)
        at weblogic.work.ExecuteThread.run(ExecuteThread.java:264)

convert nid 0x20c4 to decimal number 8388 and compare against top -b -H -p 8296 out put

 8388 oracle    20   0 1284m 224m 1112 S  0.0 22.7   0:00.00 java