middleware infrastructure blog

Getting Fusion Middleware Application MBeans

2011-06-23T07:13:00.000-07:00

To get fusion middleware MBeans (eg: BPEL properties, Mediator properties), the WLST shell that needs to be invoked is different from the regular weblogic WLST shell.

For querying the SOA MBeans, the following shell needs to be invoked.

SOA_ORACLE_HOME\common\bin\wlst.cmd (eg: C:\oracle\Middleware\Oracle_SOA1\common\bin\wlst.cmd)

fmwMBean.py
===================
connect('weblogic','password','t3://Adminhost:port')
domainRuntime()
SOAInfraConfigobj = ObjectName('oracle.as.soainfra.config:Location=soa_server1,name=soa-infra,type=SoaInfraConfig,Application=soa-infra')
print 'Common Properties for soa_server1'
print 'AuditLevel at SOAConfig (Global)~', mbs.getAttribute(SOAInfraConfigobj,'AuditLevel')
print 'CallbackServerURL~', mbs.getAttribute(SOAInfraConfigobj,'CallbackServerURL')
print 'GlobalTxMaxRetry~', mbs.getAttribute(SOAInfraConfigobj,'GlobalTxMaxRetry')
print 'GlobalTxRetryInterval~', mbs.getAttribute(SOAInfraConfigobj,'GlobalTxRetryInterval')

#Get BPEL Properties
BPELMBeanobj = ObjectName('oracle.as.soainfra.config:Location=soa_server1,name=bpel,type=BPELConfig,Application=soa-infra')
print 'BPEL Properties for soa_server1'
print 'DispatcherEngineThreads~', mbs.getAttribute(BPELMBeanobj,'DispatcherEngineThreads')
print 'DispatcherInvokeThreads~', mbs.getAttribute(BPELMBeanobj,'DispatcherInvokeThreads')
print 'DispatcherSystemThreads~', mbs.getAttribute(BPELMBeanobj,'DispatcherSystemThreads')
print 'LargeDocumentThreshold~', mbs.getAttribute(BPELMBeanobj,'LargeDocumentThreshold')

#Get Mediator Properties
MediatorMbeanobj = ObjectName('oracle.as.soainfra.config:Location=soa_server1,name=mediator,type=MediatorConfig,Application=soa-infra')
print 'Mediator Properties for soa_server1'
print 'AuditLevel for Mediator~',mbs.getAttribute(MediatorMbeanobj,'AuditLevel')
print 'ContainerIdLeaseTimeout~', mbs.getAttribute(MediatorMbeanobj,'ContainerIdLeaseTimeout')
print 'ResequencerWorkerThreadCount~', mbs.getAttribute(MediatorMbeanobj,'ResequencerWorkerThreadCount')

#Get HumanWorkFlow Properties
Humanworkflowobj = ObjectName('oracle.as.soainfra.config:Location=soa_server1,name=human-workflow,type=HWFMailerConfig,Application=soa-infra')
print 'Human Workflow Properties for soa_server1'
print 'Email from address~', mbs.getAttribute(Humanworkflowobj,'ASNSDriverEmailFromAddress')

#Get Adapter Properties for soa_server1
print 'Adapter Properties for soa_server1'
AdapterMbeanobj = ObjectName('oracle.as.soainfra.config:Location=soa_server1,name=adapter,type=AdapterConfig,Application=soa-infra')
print 'GlobalInboundJcaRetryCount~', mbs.getAttribute(AdapterMbeanobj,'GlobalInboundJcaRetryCount')
==============

The above script can be executed as:
c:\$SOA_ORACLE_HOME\common\bin\wlst.cmd fmwMBean.py > wlst.out

This data can be generated into an excel file (without the need to access em).
The above script generates values with a delimiter ~
The below script generates an excel file
Get text2xls.pl from :
http://www.perlmonks.org/bare/?node_id=72985
If you haven't used perl before, download it from ActivePerl site and to run a perl script, just do $ perl script.pl
To run the current script:

C:\WLST>perl text2xls.pl -i wlst.out -o test1.xls -d ~ (wlst.out is generated from above wlst script and -d option is the delimiter)
Starting text2xls.pl
infile = wlst.out
outfile = test1.xls
Finished text2xls.pl

This would generate an excel file (test1.xls) with MBean values without the need for em.

Both the above two operations (generating wlst.out and converting wlst.out to excel) can be wrapped in a batch/shell script for better automation.

References: http://biemond.blogspot.com/2010/02/invoking-fmw-application-mbeans-in.html
http://www.perlmonks.org/bare/?node_id=72985

WebLogic Plan file merger with webdescriptor

2010-11-02T18:28:00.000-07:00

Ever seen this error when a plan file is applied to an application on weblogic10.3?

<[WebAppModule(test:test.war)] Error parsing descriptor in Web appplication "C:\webapp\test.war"
weblogic.descriptor.DescriptorValidateException: The following failures occurred:
-- EnvEntryType is a required value that has not been specified.
at weblogic.descriptor.internal.AbstractDescriptorBeanHelper.validateSubTree(AbstractDescriptorBeanHelper.java:113)

This is because of some wierd whitespace issue that weblogic is not able to parse the webdescriptor file or the plan file.
The same plan and application works on wls11g (Either wls11g is more forgiving or does a better parsing)
You are better off to redo the plan xml or webdescriptor file, if you encounter the above error.

Oracle Enterprise Manager perl Syntax

2010-10-24T14:12:00.000-07:00

We needed to enable metric "Log File Pattern Matched Line Count" from OEM.
We were looking for java.lang.OutOfMemory string within our weblogic log file.
As first time user, I went ahead and added the string name and really did not care to check the "Ignore Pattern in Perl" that had "%" by default.

This was telling the EM to ignore virtually everything and no wonder we did not receive alerts.
The right to look for a string "java.lang.OutOfMemoryError" was:

Jrockit JRCMD

2010-10-19T21:17:00.000-07:00

If you are one of those shops where remote access from JRMC (Jrockit Management Console) is not possible, jrcmd comes to rescue.
All we need is access through SSH.
This came in real handy for our environments where remote access is not allowed.

$ ./Jrockit_home/bin/jrcmd PID heap_diagnostics
This would print heap summary, Memory layout (similar to pmap in solaris) and details object statistics

If you are new to Jrockit and familiar with other JVM tools like Jhat or MAT,and would need to do an offline analysis, then a heap dump can be generated in HPROF format.

$ ./Jrockit_home/bin/jrcmd PID hprofdump filename=heapdump.hprof
(heapdump.hprof is created from JVM process spawning directory. For weblogic it will be under domain directory - assuming startscript is triggred from there)
This hprof can be further analyzed with tools like jhat or MAT (Eclipse Memory analyzer tool).
MAT would provide all sorts of info from leak suspects to Accumulated Objects by Class as shown above.

Another neat feature from JRMD is baselining the heap and native memory.
$./Jrockit_home/bin/jrcmd PID print_memusage scale=M baseline
This prints base line of memory usage (both java and native heap) something like:

Subsequent runs of same command would baseline to first snapshot and shows the added java & native heaps.

Reference:
https://www.packtpub.com/oracle-jrockit-the-definitive-guide/book

WebLogic & Oracle RAC

2010-04-26T13:25:00.000-07:00

It's a common scenario to have weblogic hosted apps connect to Oracle RAC in the backend. From weblogic perspective, there are two ways to connect to Oracle RAC.

1) Use WebLogic Multipool: This would mean all the failover/loadbalancing of JDBC calls will be taken care by weblogic JDBC framework - built within application server.
2) Connect-time failover : This would mean, all failover/loadbalancing of jdbc calls will be taken care by Oracle driver.

Now what is better approach? Based on testing and feedback from Oracle, multipool approach is a better choice.

In case of connect-time failover scenario, failover can take lot of time (max would depend on tcp timeout).
Oracle FCF (fast connection failover) would help to some extent in reducing the failover time, but still the failover would be connection by connection instead of whole pool atonce.
Failover in case of multipool is faster compared to FastConnection Failover feature from Oracle DB.
Also, XA connections are better taken care of w.r.t multipools since weblogic framework would make sure all JDBC calls within an XA transaction would reach the same Oracle server.(which is not the case with Oracle thin driver)

JVM memory profiling (jmap & jhat)

2009-08-24T19:41:00.000-07:00

The newer versions of Sun JDK (1.5, 1.6) has better memory profiling tools available. One such combination is jmap and jhat.
Both of the tools are now part of JDK1.6 distribution (located under javahome/bin folder)
To get to a probable source of memory leak (or to figure out which objects are consuming most part of the heap) we have these JDK builtin tools for rescue.
Essentially, we can get the heap snapshot with jmap. we can get a heap dump from jmap which can be read by jhat.
Here is how it looks: (I am trying to profile my weblogic11g process and its processID is 23707)

To get current heap usage stats :
===================================

# ./jmap -heap 23707 (23707 being java process ID )

To get list of all objects on the heap (both live and not reachable)
This is my WebLogic11g process.

# ./jmap -histo 23707 (23707 being java process ID )

To get a heap dump :
(I have specified file name as myheap.bin)
# ./jmap -dump:format=b,file=myheap.bin 23707
Dumping heap to /weblogic11g/jdk160_11/bin/myheap.bin ...
Heap dump file created

To read the heap dump thats generated, jhat can be used as follows :
# ./jhat myheap.bin
Reading from myheap.bin...
Dump file created Mon Aug 24 16:20:26 EDT 2009
Snapshot read, resolving...
Resolving 546388 objects...
.......................
Snapshot resolved.
Started HTTP server on port 7000
Server is ready.

jhat would start a webserver and all object allocations can be viewed and queried. The object allocation can be accessed through browser as http://myIP:7000

Here is a snapshot with default access. we find basic allocation information and also different options to query the objects.
We can get object allocation by size as :

If you prefer a GUI based view, you can check MAT(from eclipse) or visualGC.

getRealPath returns Null on WebLogic Server

2009-07-20T13:00:00.000-07:00

Applications that were running ok on Tomcat/Jetty would return a Null for ServletContext.getRealPath() when deployed on weblogic server.

The reason is, Tomcat implementation would explode the WAR upon deployment, where as weblogic doesn't.

To get things working irrespective of archive/explode, we are better off using ServletContext.getResourceAsStream()

Installing XAMPP on 64bit RHEL

2009-06-12T13:14:00.000-07:00

Today I had to install Apache on 64bit RHEL mahine.
Since my machines did't have compiler installed, I got a binary distribution (rpm) and tried install hoping it would be a quick fix.

And the reponse I got was:

[root@localhost apache]# rpm -ivh httpd-2.2.2-1.x86_64.rpm

warning: httpd-2.2.2-1.x86_64.rpm: Header V3 DSA signature: NOKEY, key ID 751d7f27 error: Failed dependencies:
apr >= 1.2.0 is needed by httpd-2.2.2-1.x86_64
apr-util >= 1.2.0 is needed by httpd-2.2.2-1.x86_64
libapr-1.so.0()(64bit) is needed by httpd-2.2.2-1.x86_64
libaprutil-1.so.0()(64bit) is needed by httpd-2.2.2-1.x86_64
libcrypto.so.4()(64bit) is needed by httpd-2.2.2-1.x86_64
liblber-2.2.so.7()(64bit) is needed by httpd-2.2.2-1.x86_64
libldap-2.2.so.7()(64bit) is needed by httpd-2.2.2-1.x86_64
libpq.so.3()(64bit) is needed by httpd-2.2.2-1.x86_64
libssl.so.4()(64bit) is needed by httpd-2.2.2-1.x86_64

I googled and got some information from this blog
I went ahead and downloaded XAMPP package for linux, installed and ran it and what I got was:

[root@localhost lampp]# ./lampp start
XAMPP is currently only availably as 32 bit application. Please use a 32 bit compatibility library for your system.

Essentially, it was saying lampp was meant for only 32bit applications and my OS was 64bit,
to be precise Linux 2.6.18-53.el5 #1 SMP Wed Oct 10 16:34:19 EDT 2007 x86_64 x86_64 x86_64 GNU/Linux

searching on the web I could only find workarounds for ubuntu and not anything for RHEL.

The workaround for RHEL was to commented out the 64bit check in the lampp executable script as:

=================
# XAMPP is currently 32 bit only
#case `uname -m` in
# *_64)
# if /opt/lampp/bin/php -v > /dev/null 2>&1
# then
# :
# else
# $de && echo "XAMPP gibt es zur Zeit nur als 32-Bit Applikation. Bitte verwende eine 32-Bit Kompatibilitaetsbibliothek fuer Dein System."
# $de || echo "XAMPP is currently only availably as 32 bit application. Please use a 32 bit compatibility library for your system."
# exit
# fi
# ;;
#esac
================

Once that is done, I had no issues in starting my Apache, Mysql and PHP engines.

[root@localhost lampp]# ./lampp start
Starting XAMPP for Linux 1.7.1...
XAMPP: Starting Apache with SSL (and PHP5)...
XAMPP: Starting MySQL...
XAMPP: Starting ProFTPD...
XAMPP for Linux started.

WebLogic authentication with Siteminder

2009-06-02T08:58:00.000-07:00

We have encountered this issue while setting up siteminder on weblogic 9.2
Once the request is authenticated through policy server/siteminder, weblogic would ask for login again.

This is because, for WebLogic Server versions 9.2 and later, client requests that use HTTP BASIC authentication must pass WebLogic Server authentication, even if access control is not enabled on the target resource.

The corresponding configMbean flag is enforce-valid-basic-auth-credentials and default is "true".
We would have to set this to "false" to disable default weblogic authentication.
For some reason, this does not seem to be configurable through Admin console.
We would have to edit config.xml as:

Link to BEA docs

core file analysis on solaris

2009-05-29T10:20:00.000-07:00

A core dump is a detailed snapshot of the process at that point in time.
It has all the information related to OS threads(pstack info), data mapping to memory locations (pmap info), PC (program counter), stack pointer etc.
A core file has be studied by experienced OS admin or the vendor. It is lot easier to run debugger on the system where process crash has occurred.

Before the core dump/core file is sent to vendor, we can check few things and in most cases we should be able to figure out the culprit.

With pstack, we will able to get the LWP that triggered the crash.

# pstack core
core 'core' of 6604: /WebLogic/jdk1.5.0_10/bin/sparcv9/java -Xms2048m -Xmx4096m
----------------- lwp# 28 / thread# 28 --------------------
ffffffff7eea8ebc uadmin (6, 0, fffffffe454fb7f0, 10050, 10000, 11c00) + 4
ffffffff7ee3e698 addsev (f9c8, 10011b5d0, 0, ffffffff7eadd140, 0, ffffffff7ea1a000) + 40
ffffffff7e7b2de8 __1cCosFabort6Fi_v_ (1, fc00, e, ffffffff7ea1a000, 26726c, b400) + 60
ffffffff7e84a348 __1cHVMErrorOreport_and_die6M_v_ (0, ffffffff7eac9424, ffffffff7eac93f0, ffffffff7e9076ec, ffffffff7eabd938, 0) + c68
ffffffff7e36ea90 JVM_handle_solaris_signal (b, 13070, fffffffe454fbf00, 10022fa60, fffffffe454fc1e0, 10800) + b00
ffffffff7f217f6c __sighndlr (b, fffffffe454fc1e0, fffffffe454fbf00, ffffffff7e36df60, 0, 0) + c
ffffffff7f211ab0 call_user_handler (fffffffe52702c00, fffffffe454fc1e0, fffffffe454fbf00, 0, 0, 0) + 25c
ffffffff7f211c74 sigacthandler (b, fffffffe454fc1e0, fffffffe454fbf00, fffffffffffffff8, ffffffffffffffe0, 2) + 68
--- called from signal handler with signal 11 (SIGSEGV) ---
fffffffe43b06204 Java_weblogic_socket_DevPollSocketMuxer_initDevPoll (10022fba8, fffffffe454fc590, 10800, 0, 1bfbfa0, ffff) + 2fc ffffffff75c0d098 ???????? (10022fa60, fffffffe454fc680, fffffffe454fc590, ffffffffffffff10, 11800, ffffffff7ea1a000) ffffffff75c0d038 ???????? (80000000, 0, 0, 0, 8, fffffffe454fbdc1) ffffffff75c05978 ???????? (c000, 6, 0, ffffffff75c17180, 3, fffffffe454fbed1) ffffffff75c0023c ???????? (fffffffe454fc8b8, fffffffe454fcc80, a, fffffffe577b54c8, ffffffff75c0b560, fffffffe454fcca0)
ffffffff7e29b9b8 __1cJJavaCallsLcall_helper6
................
.................
ffffffff7e7b2878 __1cG_start6Fpv_0_ (10022fa60, d800, b000, b378, ffffffff7eabd1a4, ffffffff7ea1a000) + 210
ffffffff7f217c9c _lwp_start (0, 0, 0, 0, 0, 0)

From the above, we can figure out that signal 11 was raised fron initDevpoll function.
Java_weblogic_socket_DevPollSocketMuxer_initDevPoll

We will get more details with a debugger.
I am using a debugger mdb that ships with solaris OS. There are other debuggers like gdb and dbx that can be used.

Debuggers can do a lot more than simple commands. We can debug an active userprocess, live OS kernel and device drivers etc.
Complete documentatio of mdb can be found at
http://docs.sun.com/app/docs/doc/817-2543

I am running this against the same core file as shown above.

# mdb core
mdb: warning: core file is from SunOS 5.9 Generic_118558-36; shared text mappings may not match installed libraries
Loading modules: [ libthread.so.1 libc.so.1 ld.so.1 ]
Now once you are in debugger session, you can run commands (called dcmd)
The "status" command as shown below would print the summary informtion of the process.

> ::status
debugging core file of java (64-bit) from
executable file: /WebLogic/jdk1.5.0_10/bin/sparcv9/java
initial argv:
/WebLogic/jdk1.5.0_10/bin/sparcv9/java -Xms2048m -Xmx4096m .
threading model: multi-threaded
status: process terminated by SIGABRT (Abort)

To get the stack that caused the crash you can use "stack" command:

> ::stack
libc.so.1`uadmin+4(6, 0, fffffffe454fb7f0, 10050, 10000, 11c00)
libc.so.1`addsev+0x40(f9c8, 10011b5d0, 0, ffffffff7eadd140, 0, ffffffff7ea1a000)
libjvm.so`__1cCosFabort6Fi_v_+0x60(1, fc00, e, ffffffff7ea1a000, 26726c, b400)
libjvm.so`__1cHVMErrorOreport_and_die6M_v_+0xc68(0, ffffffff7eac9424,ffffffff7eac93f0, ffffffff7e9076ec, ffffffff7eabd938, 0)
libjvm.so`JVM_handle_solaris_signal+0xb00(b, 13070, fffffffe454fbf00, 10022fa60, fffffffe454fc1e0, 10800)
libthread.so.1`__sighndlr+0xc(b, fffffffe454fc1e0, fffffffe454fbf00,ffffffff7e36df60, 0, 0)
libthread.so.1`call_user_handler+0x25c(fffffffe52702c00, fffffffe454fc1e0,fffffffe454fbf00, 0, 0, 0)
libthread.so.1`sigacthandler+0x68(b, fffffffe454fc1e0, fffffffe454fbf00,fffffffffffffff8, ffffffffffffffe0, 2)
libmuxer.so`Java_weblogic_socket_DevPollSocketMuxer_initDevPoll+0x2fc(10022fba8, fffffffe454fc590, 10800, 0, 1bfbfa0, ffff)
...........
libjvm.so`__1cG_start6Fpv_0_+0x210(10022fa60, d800, b000, b378, ffffffff7eabd1a4, ffffffff7ea1a000)
libthread.so.1`_lwp_start(0, 0, 0, 0, 0, 0)

This would give a little more information than pstack by printing the shared object of the funtion.
In the above case the crash originated from:
libmuxer.so`Java_weblogic_socket_DevPollSocketMuxer_initDevPoll
// libmuxer.so is the shared object where initDevPoll is called from

In this scenario this was an issue from weblogic performance pack libmuxer.so and getting the updated performance pack from BEA support fixed the issue.

WebLogic WLST Script Generator

2009-05-26T21:54:00.001-07:00

WLS10.x comes with a recording feature whereby WLST scripts can be generated by recording a set of actions through Admin Console.
This is a screen snapshot of recording to generate WLST script.

Once generated, the script can be augmented to suit our needs.
For instance, I created a set of managed servers and added them to a cluster through Admin console.
The generated script (say sample.py) would look like:

startEdit()
cd('/')
cmo.createServer('managed1')
cd('/Servers/managed1')
cmo.setListenAddress('')
cmo.setListenPort(7003)
cd('/')
cmo.createCluster('testcluster')
cd('/Clusters/testcluster')
cmo.setClusterMessagingMode('unicast')
cmo.setClusterBroadcastChannel('')
cd('/Servers/managed1')
cmo.setCluster(getMBean('/Clusters/testcluster'))
activate()
startEdit()
cd('/')
cmo.createServer('managed2')
cd('/Servers/managed2')
cmo.setListenAddress('')
cmo.setListenPort(7005)
cmo.setCluster(getMBean('/Clusters/testcluster'))
activate()
startEdit()

We can augment the script by adding following actions:
1) Connect to Admin Server
2) Start a change session
3) < Add the generated WLST code >
4) Disconnect from Admin Server
5) Exit WLST

This would look like:

# connect to Admin Server(username being "system" and password "weblogic" and url localhost:7001)
connect(system,weblogic,t3://localhost:7001)
edit()
< Add the generated WLST code >
disconnect()
exit()

Now the script can be called either from shell script or ant.
Here is how you call from shell script.
I learnt this from David's blog.

#!/bin/ksh
/common/bin/.wlst.sh /mywlst/sample.py "$@"

Running wlst script through ant is documented at http://e-docs.bea.com/wls/docs100/config_scripting/using_WLST.html#wp1093337

Another posting I found useful was to automate tasks like creating domain by reading a CSV file in WLST.
Check out Bala's blog for this and other WLST related features.

WebLogic JDBC with Oracle RAC

2009-05-19T21:59:00.000-07:00

WebLogic can connect to oracle RAC either through weblogic multi pools or through Connect-Time failover (underlying JDBC driver will be responsible for failover)

In case of Multi Pool/Multi Datasource, each pool/datasource is assigned to one RAC node and weblogic JDBC framework would make sure of loadbalancing/failover. For WLS8.1, this can be done by configuring multi pools and from WLS9.x through Multi datasource.

In case of Connect-Time failover, underlying JDBC driver will perform the failover under failure conditions.

Transaction handling would different based on whether the transaction is local or Global( XA transaction with Prepare/commit phases).

As for global transaction, weblogic does not provide transparent failover to database connections.
If RAC node fails before COMMIT phase, application would receive an exception and this has to be handled in the application by getting a new connection and attempting to process the transaction.

There is good article that provides step by step instructions on setting on weblogic multi datasource with oracle RAC
http://www.oracle.com/technology/products/weblogic/howto/rac/index.html

Types of java.lang.OutOfMemoryError

2009-05-14T22:15:00.000-07:00

These are the list of OutOfMemoryErrors a typical java application can see:

java.lang.OutOfMemoryError: Perm Space
java.lang.OutOfMemoryError: Java heap space
java.lang.OutOfMemoryError: unable to create new native thread
java.lang.OutOfMemoryError: requested xxxx bytes for Chunk::new. Out of swap space

java.lang.OutOfMemoryError: Perm Space
This indicates JVM ran out of PermSpace.
permspace is specific to jvm implementations.
For Eg, SUN JVM has one but Jrockit doesn't have an allocated permspace, i.e its part of heap.
To understand what information is stored in permspace, an example would be:
classA obj = new classA()
obj is an object i.e instance of classA.

Now JVM maintains the structure for "obj" on heap where as stucture for classA will be on permspace.
This is the reason applications that has lots of classes(libraries, JSPs) tend to occupy more permspace.
Also, we would see this space used when classloading (dynamic) is done.
Typical example would be application deployments on appservers like weblogic.
There is other kinds of information stored on permspace like information for JVM optimizations etc.

java.lang.OutOfMemoryError: Java heap space
This is a typical java out of memory from application.
This message simply says, for this particular request the response from JVM was "OutOfMemoryError".
Typically we see this message if JVM heap is full and FullGC is not able to reclaim any objects.
This can be an expected memory shortage or a memory leak.
Typically out of memory from memory leaks occur over a period of time, where as out of memory from load would occur under peak usage and JVM would recover (continue servicing requests even if some request fails with OutOfMemory error.
Obviously for load based OOM, increasing heap would help.
For memory leak scenario, we would have to use profiler tools to get to root cause. JDK6 provides a utility jmap that would serve the basic needs. We can have JVM generate a heap dump on OOM error. The heap dumps can be read by tools like jhat.
There are lot of commercial tools available like YourKit, Jprofiler etc to analyze memory leaks.

java.lang.OutOfMemoryError: unable to create new native thread
This would mean, the java process size has reached its limit.
When an application creates a java thread object, correspondingly an OS thread has to be created and to create this thread OS tries to reserve space for its stack (thread stack to store local variables) within the process address space.
In most cases, we will see this error if the application spawns too many threads.

java.lang.OutOfMemoryError: requested xxx bytes for Chunk::new. Out of swap space
This would mean the process could not allocate memory as the virtual memory was full. This can happen if there are too many process running on the machine or there is some other process colocated on same machine that consuming most of the process memory.
If neither is the case, the the current process might be having a native memory leak. This can some from native code within the application and rarely can be from JVM itself which has JNI code.

Dealing with java.net.BindException: Address already in use

2009-05-12T21:17:00.000-07:00

Depending on the software, we see these errors. The underlying reason is the same.
We see the error if a process tries to listen on address+port thats already in use.

java.net.BindException: Address already in use

Address already in use: make_sock: could not bind to address

Unable to bind socket - Address already in use

Under ideal circumstances, after socket connection is dropped (both ends acknowledge FIN), underlying application would call close() which inturn is handled by OS kernel. Unless the OS kernel releases the concerned network resource, the port cannot be used by another process.

TO fix the issue, get the process ID thats already listening and kill it.

On Windows we can use netstat:
Here I am looking for my weblogic process running on port 7001.
netstat would give the process ID (2056 in this case).

C:\>netstat -o -a -n | findstr :7001
TCP 0.0.0.0:7001 0.0.0.0:0 LISTENING 2056
Go to windows process list and kill the process.

On Unix we can use lsof (need lsof package installed)
Here I am looking for my weblogic server listening on port 7002.
18664 is the PID.

# lsof -i | grep 7002
java 18664 root 47u IPv4 0x30079bee4e0 0t0 TCP unixmachine:7002 (LISTEN)

We can get the complete process listing as:
# /usr/ucb/ps auwwx | grep 18664

Kill the process as:
# kill -9 18664

Horizontal scaling vs vertical scaling of JVMs.

2009-05-11T21:22:00.000-07:00

What is the best approach for scaling a JVM ?

Horizontal scaling : Stacking more memory (java heap) to existing JVM.
Vertical scaling : Adding more JVMs.

One of the fundamental scaling questions we hear is whether to add more heap to existing JVM/s or add more instances with existing heap sizing.

The answer is "it depends". Adding more heap to exisiting JVM/s would be better interms of performance (TPS), but this will hold true only to a certain limit.

Once the JVMs approach 2GB+ heaps, adding more heap will start to degrade
performance because of factors like GC. So, after some point adding more instances would make sense.

Based on simple webapp tests, horizontal scaling is better until 2GB heaps and there after vertical scaling of JVMs would be a better option.

garbage collection in java

2009-05-04T20:59:00.000-07:00

Recently one of our developers wanted to know why the application seems to use a lot more memory than the steady state (amount of memory JVM consumes after the startup of application server with application deployed) when there were no users on the system for a while.

For the purpose of discussion, say the JVM has max of 1GB heap and steady state memory consumption is 300MB. The heap usage was around 700MB on an idle system.

Well, this is an expected behavior from the JVM. (SUN JVM)
Garbage collection is a condition based trigger. This would mean garbage collection is reactive and not proactive.
Most probable reason for this is GC is resource intensive operation and we only want this when needed.
Only a request will trigger a Full GC , If the request needs 100MB of memory (as an example) and JVM is not able to find 100MB of contiguous memory, this will trigger a Full GC, else, it will not initiate a GC cycle. (even if there are objects that have no references and are ready to be GCed).
Just because the system/jvm is idle, GC will not be "proactive" to clean up the unused objects.

Difference between close_wait and time_wait

2008-12-26T13:45:00.000-08:00

If we take snapshot of netstat (netstat -nP tcp) the common states we see would be ESTABLISHED, TIME_WAIT, CLOSE_WAIT.
I will try explaining what they mean.

Before we go into TIME_WAIT and CLOSE_WAIT, lets take close look at sequence of steps for socket closing.
Socket connection is essentially between two peers (Browser to webserver, a java client to webserver, webserver to DB server, a webserver to another webserver etc )

Say there is a socket connection established between webserver1 and webserver2. This would be the closing sequence, once the data transfer is done: (From TCP sequence diagram)

Here I am assuming webserver1 initiates the close of connection.
1) Socket on webserver1 sends a TCP segment with FIN bit (in TCP header) and the socket goes into FIN_WAIT_1 state.

2) Socket on webserver2 receives the FIN and responds back with ACK to acknowledge the FIN and the socket goes to CLOSE_WAIT state.
Now until the application calls the close() on this socket this is going to be in CLOSE_WAIT state.

3) Socket on webserver1 receives the ACK and changes to FIN_WAIT_2

4) Socket on webserver2 closes the connection(once the application calls close()) and sends back FIN to its peer to close the connection and changes its state to Last Ack

5) Socket on webserver1 receives the FIN and sends back ACK.
At this point the socket implementation on webserver1 would start a timer (TIME_WAIT) to handle the scenario where last ACK has been lost and server resends FIN.
Now the socket would wait for 2* MSL (Maximum segment lifetime- default is 4mins for solaris & windows)

6) Socket on webserver2 receives the ACK and it moves the connection to closed state

7) After TIME_WAIT is elapsed socket/connection will be closed on webserver1.

These multiple levels of acknowledgments & retransmits are needed since TCP is a reliable protocol unlike basic UDP
Here is what the three states mean:

ESTABLISHED:
This is pretty explanatory which basically means the two ends are in a state where data transfer can occur or occurring in both directions. (tcp socket is full duplex, i.e data can be received and responded to on same channel)

CLOSE_WAIT:
This is a state where socket is waiting for the application to execute close()
CLOSE_WAIT is not something that can be configured where as TIME_WAIT can be set through tcp_time_wait_interval (The attribute tcp_close_wait_interval has nothing to do with close_wait state and this was renamed to tcp_time_wait_interval starting from Solaris 7)
A socket can be in CLOSE_WAIT state indefinitely until the application closes it.
Faulty scenarios would be like filedescriptor leak, server not being execute close() on socket leading to pile up of close_wait sockets. (At java level, this manifests as "Too many open files" error)

TIME_WAIT:
This is just a time based wait on socket before closing down the connection permanently.
Under most circumstances, sockets in TIME_WAIT is nothing to worry about.

References:
http://www.port80software.com/200ok/archive/2004/12/07/205.aspx

Managing keystores, keys and certificates

2008-12-22T18:58:00.000-08:00

There are times when you have to deal with keystores/cert in different formats.
In a typical infrastructure, we deal with different entities like loadbalancers, webservers like Apache, java web/app servers like Tomcat, weblogic,Oracle app server.
Each of these support limited set of formats/extensions.
For eg:
Weblogic & Tomcat would only understand java keystores (jks), Oracle understands only PKCS12 format through its Wallet Manager (repository for certs analogous to java keystore).
We have command line utilities like java keytool to deal with java keystores, openSSL (commonly used with Apache servers).
We also have GUI tools to deal with cert repositories.

KeyTool IUI:
This is GUI for java keytool utility. The requirement is that you would need JDK1.6.0 and above.
This supports most of the prominent keystore formats like JKS (.jks,.ks), JCEKS (.jce), PKCS12(.p12,.pfx) and most certificate formats like DER(.crt,.cer) ,PKCS7(.p7b) ,PEM(.pem) ,PKCS10(.p10)
This tool pretty much does most of format conversions.
For eg:
We can convert keypair in PKCS12 to JKS and viceversa, sign a file with private key, verify a signed file etc

Portecle
Portecle is another user friendly GUI application for creating, managing and examining keystores, keys, certificates, certificate requests, certificate revocation lists and more.
Its pretty capable of performing similar set of tasks though somewhat lesser functionality to what KeyTool IUI provides.

Reference http://www.startux.de/index.php/java/44-dealing-with-java-keystores

Test with Spreadsheet converter

2008-12-19T14:30:00.000-08:00

Testing with spreadsheetsmapwizard

Working with google maps

2008-12-17T19:18:00.000-08:00

Testing with Google Maps, panoramic view near my workplace

Mapping java thread to pstack and pmap

2008-12-12T22:24:00.000-08:00

Starting from solaris9, we have a one-one threading model. Solaris library libthread.so schedules the solaris threads to run on LWPs. LWPs are mapped 1-1 with kernel threads. The kernel threads are the ones that are scheduled on processor's dispatch queue. With no debugger handy, if we need comprehensive information related to a thread or set of threads, we would need:
1) java thread dumps(kill -3 pid)
2) pstack (pstack pid)
3) pmap (pmap )

Here is an example on how we can related all the three outputs:
1) Java thread dump:
This is single thread stack trace taken from java thread dump:
The below thread has a java level thread identifier "0x00651988" that is passed as argument for the native thread call.
It also has native thread id as nid=0x2c6 that corresponds to a LWP.

"Thread-646" daemon prio=10 tid=0x00651988 nid=0x2c6 runnable [0x629ff000..0x629ff8f0] at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at java.net.SocketInputStream.read(SocketInputStream.java:182) at com.novell.ldap.asn1.ASN1Identifier.(Unknown Source) at com.novell.ldap.Connection$ReaderThread.run(Unknown Source) at java.lang.Thread.run(Thread.java:595)

2) Pstack Output
The corresponding native thread for the above java thread is shown below: (obtained from executing #pstack pid) nid=0x2c6, the corresponding decimal representation for 0x2c6 is 710, so we got to look for thread# 710 from pstack

----------------- lwp# 710 / thread# 710 -------------------- ff31f4a8 read (32, 629fec98, 1)
fead346c JVM_Read (32, 629fec98, 1, 8460, 651988, ff0148f8) + b8
6f89c1a4 Java_java_net_SocketInputStream_socketRead0 (651a44, 629ff500, 32, 629ff4f8, 0, 1) + 1fc
f960fe6c ???????? (d1265768, d12653b0, d1301f58, 0, 1, 0)
fa6946e4 ???????? (ffffffff, d1265308, 1, 1, 651988, ff150000)
f904e644 ???????? (d1265768, b6, 0, 8388, 80000000, 1)
f90058b8 ???????? (d1265768, b6, 0, f9015d28, 74f6f258, 629ff640)
f90058b8 ???????? (d1301f40, b7, 0, f9015ce0, d1379800, 629ff6c8)
f9005764 ???????? (d1265830, 7082c430, 0, f9015f40, 1, 629ff790)
f9005c2c ???????? (0, ff013928, 0, f9016230, 7ce8, 629ff808)
f9000218 ???????? (629ff8f0, 629ffaf0, a, 7082d668, f900a840, 629ffa08)
…………..
feadb2e4 __1cKJavaThreadDrun6M_v_ (651988, ff01882c, 6f7c, 0, 6c00, 8c00) + 2b0
fee71a00 __1cG_start6Fpv_0_ (651988, 732b, fefc0000, 0, 4ff4, 4c00) + 208
ff395370 _lwp_start (0, 0, 0, 0, 0, 0)

A pstack is native representation of the java thread stack trace. There are 6 arguments for each function that are loaded into the registers. This is Solaris standard register allocation model (there are 6 registers for parameter passing) In the above example we see 6 arguments as:
fee71a00 __1cG_start6Fpv_0_ (651988, 732b, fefc0000, 0, 4ff4, 4c00) + 208
fee71a00 is the program counter. (Virtual address space where the library is loaded)
651988 is the first arguments thats pushed to register0 and note this is the tid from java thread dump (tid=0x00651988)

3) pmap output (pmap pid)
We can trace the library loaded based on the native stack with help of pmap. Refering the same example:
ff395370 _lwp_start (0, 0, 0, 0, 0, 0)
Check the PC value "ff395370" and see where it fits in pmap:
pmap output indicates as below: (We know ff395370 fits in this range)
FF380000 96K r-x-- /usr/lib/libthread.so.1
FF3A8000 8K rwx-- /usr/lib/libthread.so.1
This tells _lwp_start function is from libthread.so library

Similarly:
6f89c1a4 Java_java_net_SocketInputStream_socketRead0 (651a44, 629ff500, 32, 629ff4f8, 0, 1) + 1fc
Based on pmap output, "6f89c1a4" fits in:
6F890000 72K r-x-- /WebLogic/utils/bea922/jdk150_10/jre/lib/sparc/libnet.so
6F8B0000 8K rwx-- /WebLogic/utils/bea922/jdk150_10/jre/lib/sparc/libnet.so
This tells the Java_java_net_SocketInputStream_socketRead function was from libnet.so

Finally,
fead346c JVM_Read (32, 629fec98, 1, 8460, 651988, ff0148f8) + b8
Based on pmapt output "fead346c" fits in:
FE800000 7936K r-x-- /WebLogic/utils/bea922/jdk150_10/jre/lib/sparc/server/libjvm.so
FEFC0000 400K rwx-- /WebLogic/utils/bea922/jdk150_10/jre/lib/sparc/server/libjvm.so
This tells JVM_Read function is from libjvm.so

How SSL works under covers

2008-12-07T20:17:00.000-08:00

SSL essentially uses hybrid crypto system (combination of symmetric & asymmetric algorithms)

i) Exchange of "symmetric key/s" is done through asymmetric algorithms (client encrypts the "symmetric key" with public key and server decrypts with its private key) ii) Exchange of data is done with by symmetric key algorithm. The sequence of events in one-way SSL communication are:
1) Client sends a SSL request

2) Socket level TCP handshake occurs.

3) Client sends ClientHello message. This includes information from client on its supported SSLversion, Ciphers,message authentication function This is message from SSL debug enabled weblogic server accepting SSL browser request: Nov 25, 2008 10:07:15 AM CST Debug SecuritySSL AdminServer [ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)' HANDSHAKEMESSAGE: ClientHello
4) Server sends back ClientHello message and this includes: The SSL or TLS version that will be used for the SSL session, cipher that will be used for the SSL session, session ID for the SSL session, server digital certificate (or chain of certificates) At this point client and server agree on the ssl version,ciphers to be used, message authentication function to be used. These are messages from SSL debug enabled weblogic server accepting/responding SSL browser request:

Nov 25, 2008 10:07:15 AM CST Debug SecuritySSL AdminServer [ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)' 14297843 SSL3/TLS MAC

Nov 25, 2008 10:07:15 AM CST Debug SecuritySSL AdminServer [ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)' Using JCE Cipher: SunJCE version 1.6 for algorithm RC4

Nov 25, 2008 10:07:15 AM CST Debug SecuritySSL AdminServer [ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)' Will use default Mac for algorithm SSL3MAC_MD5

5) Client validates the server certificate by checking the certificate authority and other details like domain name and expiration date. All browsers come preloaded with the certificates of common CAs. For Eg, in Internet Explorer, these can be viewed from: Tools-> Internet Options --> Content Tab-->Certificates -->Trusted Root CAs After the validation client generates the MASTER_KEY and encrypts it with server's public key(available from certificate) and sends back to server. Server decrypts the MASTER_KEY with its private key.

6) Client as well as the server use the MASTER_KEY to generate the session keys, which are symmetric keys used to encrypt and decrypt information exchanged during the SSL session.

7) From this point both client and server encrypt data with their own session keys.

What to look for in java thread dumps

2008-12-01T13:23:00.000-08:00

A java thread dump is snapshot of JVM at that point in time.
More specifically it’s a snapshot of all the java threads at that point in time.
A typical thread dump comprises of JVM spawned and application spawned threads. Some of the JVM spawned threads are (Sun JVM1.5.x)
Low Memory Detector (Daemon thread to detect and report low memory conditions)
CompilerThreadn (Daemon thread/s to compile & optimize byte code)
Signal Dispatcher (Daemon thread to respond OS signals)
Finalizer (Daemon thread to handle objects in finalizer queue)
Reference Handler (Daemon thread to handle objects in reference queue)
VM Thread (Main thread from JVM)
GC task thread#n (Thread/s to perform garbage collection)

Application threads are spawned from application (can be a combination of application server/web server and java application deployed).
A typical thread dump snapshot would have most of the threads in one of the following states:
R - Runnable ; MW - monitor wait; CW - conditional wait. (Terminology might differ depending on JVM implementation)
CW - conditional wait:
A thread in conditional wait would mean its waiting on a certain condition to be fullfilled. Typical Scenarios would include:
i) An idle thread waiting for work to be assigned.
ii) Thread waiting to get an EJB instance from pool
iii) Thread waiting to get a connection from connection pool.
Eg1:
"ExecuteThread: '16' for queue: 'weblogic.kernel.Default'" daemon prio=5 tid=0x010dc720 nid=0x29 in Object.wait() [a1a7f000..a1a7fc30]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:429)
at weblogic.kernel.ExecuteThread.waitForRequest(ExecuteThread.java:154) - locked <0xb1593fa0> (a weblogic.kernel.ExecuteThread)
at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:174)

The above thread is an idle thread in weblogic server and is in conditional wait within ExecuteThread.waitForRequest() i.e waiting on a condition to fullfill before it starts executing. Condition being, socket reader thread would accept the request and delegate the call to notify() on this waiting thread which then resumes the request execution.

Eg2:
http-8080-Processor25" daemon prio=1 tid=0x09298688 nid=0x2781 in Object.wait() [0xa82f8000..0xa82f8fc0]
at java.lang.Object.wait(Native Method)- waiting on <0xab436a68> (a org.apache.commons.pool.impl.GenericObjectPool)
at java.lang.Object.wait(Object.java:474)
at org.apache.commons.pool.impl.GenericObjectPool.bor rowObject(GenericObjectPool.java:810)- locked <0xab436a68> (a org.apache.commons.pool.impl.GenericObjectPool)
at org.apache.commons.dbcp.PoolingDataSource.getConne ction(PoolingDataSource.java:95)
at org.apache.commons.dbcp.BasicDataSource.getConnect ion(BasicDataSource.java:540)
at org.springframework.orm.hibernate3.LocalDataSource ConnectionProvider.getConnection(LocalDataSourceCo nnectionProvider.java:81)
at org.hibernate.jdbc.ConnectionManager.openConnectio n(ConnectionManager.java:417)
at org.hibernate.jdbc.ConnectionManager.getConnection (ConnectionManager.java:144
This is from tomcat/hibernate framework.
The thread is waiting on pool object, but looks like all the pool objects are in use. When one of the executing threads is done using the poolobject, it issues a notify() on this thread so that it can resume and pick the poolobject (JDBC connection) Any time a thread goes to wait(), it releases the current lock.

MW - Waiting for Monitor entry
MW is waiting for monitor entry i.e the thread is blocked and waiting to enter a synchronized block/method to get a java monitor. From the thread dump we can determine the monitor that is blocking the thread. If too many threads are in MW state across multiple snapshots, we know there is a contention for the lock.
Eg:
TP-Processor633" daemon prio=5 tid=0x004921d0 nid=0x5ba waiting for monitor entry [872fe000..872ffc28]
at oracle.jdbc.pool.OracleConnectionCacheImpl.closeSingleConnection(OracleConnectionCacheImpl.java:677) - waiting to lock <0xbf4e98f8> (a oracle.jdbc.pool.OracleConnectionCacheImpl) at oracle.jdbc.pool.OracleConnectionCacheImpl.reusePo oledConnection(OracleConnectionCacheImpl.java:592)
at oracle.jdbc.pool.OracleConnectionEventListener.connectionClosed(OracleConnectionEventListener.java:130) - locked <0xbf4e9e60> (a oracle.jdbc.pool.OracleConnectionEventListener)
at oracle.jdbc.pool.OraclePooledConnection.callListener(OraclePooledConnection.java:482)
at oracle.jdbc.pool.OraclePooledConnection.logicalClose(OraclePooledConnection.java:445) - locked <0xcc9af820> (a oracle.jdbc.pool.OraclePooledConnection)
at oracle.jdbc.driver.OracleConnection.logicalClose(OracleConnection.java:2936) - locked <0xcc9af8c8> (a oracle.jdbc.driver.OracleConnection)
at oracle.jdbc.driver.OracleConnection.close(OracleConnection.java:1454) - locked <0xcc9af8c8> (a oracle.jdbc.driver.OracleConnection)
..........
In the example above, the thread is waiting to lock "0xbf4e98f8" (object ID for "oracle.jdbc.pool.OracleConnectionCacheImpl") Note this thread is already holding locks for "0xbf4e9e60"(OracleConnectionEventListener),
"0xcc9af820" (OraclePooledConnection) and "0xcc9af8c8" (OracleConnection)
Having several threads in same state (waiting for same object), indicates there is a contention for the object.
In the current example, thread dump would reveal the thread holding the lock (Look for the thread with entry: - locked <0xbf4e98f8>)

R- Runnable
This state would mean thread is executing/utilizing the CPU or OS ready state for utilizing the CPU.
Eg:
"[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x005af448 nid=0x20 runnable [0x6847d000..0x6847f8f0]
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at oracle.net.ns.Packet.receive(Unknown Source)
at oracle.net.ns.DataPacket.receive(Unknown Source)
........................
at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3316)
at oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3361) - locked <0xe225f140> (a oracle.jdbc.driver.T4CPreparedStatement) - locked <0xe221b390> (a oracle.jdbc.driver.T4CConnection)
at weblogic.jdbc.wrapper.PreparedStatement.executeQuery(PreparedStatement.java:100)
at com.determine.log.FQLogListImpl.collect(FQLogListImpl.java:80)
at com.determine.persistence.DBFacade.collect(DBFacade.java:75)
......
The above thread is connected to DB (opened socket on server and reading response from DB server). Now if the thread is in same state across multiple thread dumps, we know either the query is taking long time to execute or there is some issue with DB server that’s causing the DB to respond slowly.

There are good tools that parse and provide graphical representation of threads dumps like Samurai , Thread Dump Analyzer.