Enable debug log Weblogic

There are some Java parameters that can be set to enable Weblogic debug logs. We need to put following parameters

-Dweblogic.StdoutDebugEnabled=true
-Dweblogic.log.RedirectStdoutToServerLogEnabled=true
-Dweblogic.diagnostics.debug.DebugLogger.DISABLED=false

and one or more of the following parameters that depend on our needs. The list was retrieved from this source.

Java Messaging Services

Messaging Kernel
-Dweblogic.debug.DebugMessagingKernel=true

MDB connectivity
-Dweblogic.debug.DebugEjbMdbConnection=true

JMS Wrappers
-Dweblogic.debug.DebugJMSWrappers=true

JMS SAF
Sending side:
-Dweblogic.debug.DebugJMSSAF=true
-Dweblogic.debug.DebugJMSMessagePath=true

Receiving side:
-Dweblogic.debug.DebugJMSBackEnd=true
-Dweblogic.debug.DebugJMSFrontEnd=true
-Dweblogic.debug.DebugJMSMessagePath=true

JMS Distributed Destinations
-Dweblogic.debug.DebugJMSCommon=true
-Dweblogic.debug.DebugJMSDistTopic=true
-Dweblogic.debug.DebugJMSMessagePath=true

JMS Boot
-Dweblogic.debug.DebugJMSBoot=true
-Dweblogic.debug.DebugMessagingKernelBoot=true
-Dweblogic.debug.DebugStoreIOLogicalBoot=true

JMS store
Logical IO:
-Dweblogic.debug.DebugJMSStoreIOLogical=true
-Dweblogic.debug.DebugJMSStoreIOLogicalBoot=true

Physical IO:
-Dweblogic.debug.DebugStoreIOPhysical=true
-Dweblogic.debug.DebugStoreIOPhysicalVerbose=true

Store XA:
-Dweblogic.debug.DebugStoreXA=true
-Dweblogic.debug.DebugStoreXAVerbose=true

JMS CDS
-Dweblogic.debug.DebugJMSCDS=true

JMS Backend
-Dweblogic.debug.DebugJMSBackEnd=true

JMS Frontend
-Dweblogic.debug.DebugJMSFrontEnd=true

JMS Dispatcher
-Dweblogic.debug.DebugJMSDispatcher=true

Messaging Bridge :
-Dweblogic.debug.DebugMessagingBridgeRuntime=true
-Dweblogic.debug.DebugMessagingBridgeRuntimeVerbose=true
-Dweblogic.debug.DebugMessagingBridgeStartup=true

Clustering
-Dweblogic.diagnostics.debug.DebugLogger.DISABLED=false & one or all of the following
-Dweblogic.debug.DebugClusterAnnouncements=true
-Dweblogic.debug.DebugCluster=true
-Dweblogic.debug.DebugClusterFragments=true
-Dweblogic.debug.DebugJTAMigration=true
-Dweblogic.debug.DebugAsyncQueue=true
-Dweblogic.debug.DebugReplication=true
-Dweblogic.debug.DebugReplicationDetails=true
-Dweblogic.debug.DebugServerMigration=true
-Dweblogic.debug.DebugSingletonServices=true
-Dweblogic.debug.DebugConsensusLeasing=true
-Dweblogic.debug.DebugUnicastMessaging=true
-Dweblogic.cluster.leasing.ClusterFormation=true
-Dweblogic.cluster.leasing.ClusterGroupView=true
-Dweblogic.cluster.leasing.ClusterLeader=true
-Dweblogic.cluster.leasing.ClusterLeaderService=true
-Dweblogic.cluster.leasing.ClusterMember=true
-Dweblogic.cluster.leasing.ClusterMessaging=true
-Dweblogic.cluster.leasing.LeaseClient=true
-Dweblogic.cluster.leasing.LeaseServer=true
-Dweblogic.cluster.leasing.LeaseView=true
-Dweblogic.cluster.leasing.MachineState=true
-Dweblogic.cluster.leasing.DiscoveryService=true
-Dweblogic.cluster.leasing.DisconnectMonitor=true
-Dweblogic.cluster.leasing.MessageEndPoint=true
-Dweblogic.cluster.leasing.MessageSender=true
-Dweblogic.cluster.leasing.SRMResult=true
-Dweblogic.cluster.leasing.FailureDetector=true
-Dweblogic.cluster.leasing.SRMService

RMI & IIOP

-Dweblogic.diagnostics.debug.DebugLogger.DISABLED=false & one or all of the following
-Dweblogic.debug.DebugCorbaClientHttp=true
-Dweblogic.debug.DebugCorbaClientIIOP=true
-Dweblogic.debug.DebugIIOPNaming=true
-Dweblogic.iiop.naming=true
-Dweblogic.debug.DebugIIOPOTS=true
-Dweblogic.iiop.ots=true
-Dweblogic.debug.DebugIIOPTransport=true
-Dweblogic.iiop.transport=true
-Dweblogic.debug.DebugIIOPTunneling=true
-Dweblogic.iiop.http.tunnelLogin=true
-Dweblogic.iiop.http.tunnelRecv=true
-Dweblogic.iiop.http.tunnelSend=true
-Dweblogic.debug.client.dgc=true, to enable debug for dgc
-Dweblogic.rmi.extensions.server.ServerHelper.DebugExportObject=true
-Dweblogic.debug.DebugDGCEnrollment=true
-Dweblogic.debug.ForceGCEachDGCPeriod=true
-Dweblogic.debug.LogDGCStatistics=true
-Dweblogic.debug.DebugMessaging=true
-Dweblogic.debug.DebugGenericMethodDescriptor=true
-Dweblogic.debug.DebugIIOPDetail=true
-Dweblogic.debug.DebugIIOPMarshal=true
-Dweblogic.debug.DebugIIOPTransport=true
-Dweblogic.debug.DebugIIOPSecurity=true
-Dweblogic.debug.DebugIIOPStartup=true
-Dweblogic.debug.DebugIIOPRepalcer=true
-Dweblogic.debug.DebugIIOPConnection=true
-Dweblogic.debug.DebugIIOPDetail=true
-Dweblogic.debug.DebugIIOPDetail=true
-Dweblogic.iiop.marshal=true
-Dweblogic.iiop.transport=true
-Dweblogic.iiop.security=true
-Dweblogic.iiop.startup=true
-Dweblogic.iiop.replacer=true
-Dweblogic.iiop.connection=true

Deployment debugs

-Dweblogic.debug.DebugDeployment=true
-Dweblogic.debug.DebugDeploymentServiceInternal=true
-Dweblogic.debug.DebugDeploymentServiceTransport=true
-Dweblogic.debug.DebugDeploymentServiceTransportHttp=true
-Dweblogic.debug.DebugDeploymentServiceStatusUpdates=true
If you have problem in edit lock, system resource deployment or configuration updates, you may also turn on configure debug flag:
-Dweblogic.debug.DebugConfigurationEdit=true


HTTP Debugs

-Dweblogic.debug.DebugURLResolution=true
-Dweblogic.debug.DebugHttp=true
-Dweblogic.debug.httpd=true
-Dweblogic.debug.httpd.log=true
-Dweblogic.debug.httpd.servlet=true

JTA

-Dweblogic.debug.DebugJTAPropagate=true
-Dweblogic.debug.DebugJTAGateway=true
-Dweblogic.debug.DebugJTAXA=true
-Dweblogic.debug.DebugJTA2PC=true
-Dweblogic.debug.DebugJTAJDBC=true
-Dweblogic.debug.DebugJDBCSQL=true

JNDI

-Dweblogic.debug.DebugJNDI =true
-Dweblogic.debug.DebugJNDIResolution =true
-Dweblogic.debug.DebugJNDIFactories =true
-Dweblogic.debug.DebugJNDIAppVersion =true

Workmanager

-Dweblogic.workmanager=true
-Dweblogic.StuckThreadHandling=true
-Dweblogic.IncrementAdvisor=true
-Dweblogic.MinThreadsConstraint=true
-Dweblogic.responsetimerequestclass=true
-Dweblogic.workmanagerservice=true

Server Life Cycle

-Dweblogic.slc=true
-Dweblogic.slcruntime=true
-Dweblogic.debug.DebugServerLifeCycle=true

Classloaders

-Dweblogic.utils.classloaders.GenericClassLoader.Verbose=true
-Dweblogic.utils.classloaders.ChangeAwareClassLoader.Verbose=true
-Dweblogic.utils.classloaders.ClasspathClassFinder=true
-Dweblogic.utils.classloaders.DefaultFilteringClassLoader.Verbose=true
-Dweblogic.utils.classloaders.FilteringClassLoader.Verbose=true
-Dweblogic.utils.classloaders.FilteringClassLoader.ResourceDump=true
-Dweblogic.utils.classloaders.URLClassFinder.Verbose=true

WebService

-Dweblogic.wsee.verbose=*

Security

SAML:
-Dweblogic.debug.DebugSecuritySAMLService=true
-Dweblogic.debug.DebugSecuritySAMLCredMap=true
-Dweblogic.debug.DebugSecuritySAMLAtn=true
-Dweblogic.debug.DebugSecuritySAMLLib=true
-Dweblogic.debug.DebugSecuritySAML2Service=true
-Dweblogic.debug.DebugSecuritySAML2CredMap=true
-Dweblogic.debug.DebugSecuritySAML2Atn=true
-Dweblogic.debug.DebugSecuritySAML2Lib=true
-Dweblogic.debug.DebugSecurityCredMap=true

WebService Security
-Dweblogic.xml.crypto.wss.debug=true
-Dweblogic.xml.crypto.wss.verbose=true
-Dweblogic.xml.crypto.keyinfo.debug=true
-Dweblogic.xml.crypto.keyinfo.verbose=true
-Dweblogic.xml.crypto.dsig.debug=true
-Dweblogic.xml.crypto.dsig.verbose=true
-Dweblogic.xml.crypto.encrypt.debug=true
-Dweblogic.xml.crypto.encrypt.verbose=true

Few commands to troubleshoot:

Networking slowness

ping -c 3 -M do -s 30000 -T IP


Grep based on time range
grep -v -e "^[2014-03-06T08:[30-59]" soa_server2-diagnostic-1297.log |more

Find number of threads running in the system

cat /proc/PID/status

ps -eLo pid,cmd,nlwp

Heap dump

/u01/app/jdk1.6.0_31/bin/jmap -dump:format=b,file=heapdump.hprof 8440

Top running process consuming high CPU

top –H –b –p PID

Strace monitors the system calls and signals of a specific program

/usr/bin/strace –s 200 –o /u01/tmp/some.txt –fp <PID>

Search receive from and socket descriptor from the output file

List of open files: Lsof

/usr/bin/lsof  |grep port

Sar reports extraction:

LC_ALL=C sar -A -f /var/log/sa/sa09 >> sar_node1_nov9.txt

You can use ksar tool and generate a nice PDF from the output file.

Zombie process: 

 ps -lA |grep '^. Z'

4 Z     0  4332  3938  0  85   0 -     0 exit   ?        00:00:00 pwck <defunct>

4 Z     0  4339  3938  0  80   0 -     0 exit   ?        00:00:00 test <defunct>

4 Z     0  4739  3938  0  82   0 -     0 exit   ?        00:00:00 pwck <defunct>

0 Z     0 27064  3938  0  75   0 -     0 exit   ?        00:00:00 ldapsearch <defunct>

$ ps axo stat,ppid,comm |grep -w defunct

Zs    3938 pwck <defunct>

Zs    3938 test <defunct>

Zs    3938 pwck <defunct>

Zs    3938 ldapsearch <defunct>

$ ps -ef |grep 3938

Pmap command reports the memory map of a process:
cat /proc/pid/status or whatever

pmap -x <process pid>

Java heap dump

I recently worked on a project where I was faced with "out of memory" problem. Exception appeared usually after the application has worked for several weeks. I solved the problem with VisualVM tool that ships with Java 1.6 JDK.
VisualVM tool provides a direct connection to any Virtual Machine locally or remote, or can load heap dump or thread dump from a file.

To dump heap memory to a file type in console(linux):

1.             Get java process id
ps -eaf | grep java

2.             Dump heap memory to a file using jmap ("jmap prints shared object memory maps or heap memory details of a given process or core file or a remote debug server")
jmap -heap:format=b PID (where PID i id of your java process)

3.             Run jvisualvm
jvisualvm -J-Xmx512M

4.             Load heap.bin file

5.             Find biggest objects by retained size. After file loads you can see every object that was in memory at the time the dump was taken.Click on find biggest objects by retained size and you will get hierarchy of biggest objects in memory.

ps – Displays The Processes

ps command will report a snapshot of the current processes. To select all processes use the -A or -e option:
# ps -A
Sample Outputs:

ps -A
PID TTY TIME CMD
1 ttyp0 00:00:22 init
89 ? 00:00:00 init-logger
142 ? 00:00:00 udevd
634 ? 00:00:00 syslog-ng
635 ? 00:20:39 syslog-ng
718 ? 00:00:00 zabbix_agentd
720 ? 00:04:02 zabbix_agentd
736 ? 00:00:00 xinetd
754 ? 00:00:00 mysqld_safe
784 ? 21:08:05 mysqld
788 pts/2 00:00:00 zsh
820 ? 00:00:01 logger
826 ? 00:00:00 httpd
827 ? 00:00:34 httpd
1154 ? 00:00:00 gam_server
1633 ? 00:05:30 httpd
1642 ? 00:00:05 pure-ftpd
....
32656 ? 00:00:00 exim
32659 ? 00:00:02 php5
32660 ? 00:00:00 php5
32691 ? 00:00:00 gam_server
32698 ? 00:00:01 php5
32700 ? 00:00:00 php5
32704 ? 00:00:00 exim
32705 ? 00:00:00 cpsrvd-ssl
32707 pts/0 00:00:00 ps

Now for some switches that will allow you to do a lot more with this command:

Show Long Format Output

# ps -Al

To turn on extra full mode (it will show command line arguments passed to process):

# ps -AlF

To See Threads ( LWP and NLWP)

# ps -AlFH

To See Threads After Processes

# ps -AlLm

Print All Process On The Server

# ps ax
# ps axu

Print A Process Tree

# ps -ejH
# ps axjf
# pstree

Print Security Information

# ps -eo euser,ruser,suser,fuser,f,comm,label
# ps axZ
# ps -eM

See Every Process Running As User Vivek

# ps -U vivek -u vivek u

Set Output In a User-Defined Format

# ps -eo pid,tid,class,rtprio,ni,pri,psr,pcpu,stat,wchan:14,comm
# ps axo stat,euid,ruid,tty,tpgid,sess,pgrp,ppid,pid,pcpu,comm
# ps -eopid,tt,user,fname,tmout,f,wchan

Display Only The Process IDs of httpd (apache)

# ps -C httpd -o pid=
OR
# pgrep httpd
OR
# pgrep -u vivek php-cgi

Display The Name of PID 58721

# ps -p 58721 -o comm=

Find Out The Top 10 Memory Consuming Process

# ps -auxf | sort -nr -k 4 | head -10

Find Out top 10 CPU Consuming Process

# ps -auxf | sort -nr -k 3 | head -10

PRSTAT Linux – How to pinpoint high CPU Java VM Threads

This article will provide you with an equivalent approach, for JVM on Linux OS, of the powerful Solaris OS prstat command; allowing you to quickly pinpoint the high CPU Java VM Thread contributors.

One key concept to understand for a Java VM running on the Linux OS is that Java threads are implemented as native Threads, which results in each thread being a separate Linux process.

Ok thanks for the info but why is this related to prstat?

Well this key concept means that you don’t need a prstat command for Linux. Since each Java VM Thread is implemented as a native Thread, each Thread CPU % can simply be extracted out-of-the-box using the top command.

You still need to generate Thread Dump data of your JVM process in order to correlate with the Linux top command output.

Thanks for this explanation. Now please show me how to do this

Please simply follow the instructions below:

1)     Execute the top command (press SHIFT-H to get the Threads toggle view) or use -H option (to show all Threads) and find the PID associated with your affected  / high CPU WLS process(es) (remember, many may show up since each Java Thread is implemented as a separate Linux process)

2)     Immediately after, generate a few Thread Dump snapshots using kill –3 <PID> of the parent WLS process. Thread Dump provides you with the complete list with associated Stack Trace of each Java Thread within your JVM process

3)     Now, convert the PID(s) extracted from the top command output to HEX format

4)     The next step is to search from the Thread Dump data for a match nid=<HEX PID>

5)     The final step is to analyze the affected Thread(s) and analyze the Stack Trace so you can determine where in the code is the problem (application code, middleware itself, JDK etc.)

Example: top command captured of a Weblogic Server Java Thread running at 40% CPU utilization along with Thread Dump data via kill -3 <PID>

## top output sample 

PID USER PRI NI SIZE RSS SHARE STAT %CPU %MEM TIME COMMAND

...........

22111 userWLS 9 0 86616 84M 26780 S 0.0 40.1 0:00 java

• Decimal to HEX conversion of Java Thread (native Thread) 22111 >> 0x565F
• Now using the HEX value, we can search within the Thread Dump for the following keyword: nid=0x565F

## Thread Dump output sample Thread as per the above search criteria nid=0x565F

"ExecuteThread: '0' for queue: 'default'" daemon prio=1 tid=0x83da550 nid=0x565Fwaiting on monitor [0x56138000..0x56138870]

  at java.util.zip.ZipFile.getEntry(Native Method)

  at java.util.zip.ZipFile.getEntry(ZipFile.java:172)

  at java.util.jar.JarFile.getEntry(JarFile.java:269)

  at java.util.jar.JarFile.getJarEntry(JarFile.java:252)

  at sun.misc.URLClassPath$JarLoader.getResource(URLClassPath.java:989)

  at sun.misc.URLClassPath$JarLoader.findResource(URLClassPath.java:967)

  at sun.misc.URLClassPath.findResource(URLClassPath.java:262)

  at java.net.URLClassLoader$4.run(URLClassLoader.java:763)

  at java.security.AccessController.doPrivileged(AccessController.java:224)

  at java.net.URLClassLoader.findResource(URLClassLoader.java:760)

  at java.lang.ClassLoader.getResource(ClassLoader.java:444)

  at java.lang.ClassLoader.getResourceAsStream(ClassLoader.java:504)

  ............................................

In the above example, the problem was related to an excessive class loading / IO problem.

As you can see, the approach did allow us to quickly pinpoint high CPU Thread contributor but you will need to spend additional time to analyze the root cause which is now your job.