Java mon amour: April 2009

Tuesday, April 28, 2009

Memory analysis on Linux

see also http://rimuhosting.com/howto/memory.jsp

to show the physical and swap memory:

free -m

total used free shared buffers cached
Mem: 7728 7131 597 0 377 1875
-/+ buffers/cache: 4878 2850
Swap: 32767 0 32767

to show the memory usage per process:

ps aux

USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
beasvbt 18204 0.1 6.9 981712 548220 ? Sl 2008 247:53 /opt/bea9/albpm6.0/j2eewl/jre/bin/java -Xms512m -Xmx512m
beasvbt 25100 0.0 11.1 1752064 884604 ? Ssl 2008 153:40 /opt/bea9/jdk1.5.0_14_amd64/bin/java -Dweblogic.Name=ofop
root 26350 0.0 0.2 20488 17052 ? S 2008 0:07 /opt/NAI/Linuxshield/libexec/scanner -e /opt/NAI/Linuxshi
beasvbt 28344 0.0 0.0 52776 1020 ? S Mar03 0:00 /bin/sh ./startWebLogic.sh
beasvbt 28345 0.0 0.0 52780 1160 ? S Mar03 0:00 /bin/sh /opt/bea9/user_projects/edu/ofop/ofop_bpm_edu/bin
beasvbt 28381 1.3 10.1 1122036 801376 ? Sl Mar03 1084:46 /opt/bea9/jdk1.5.0_14_amd64/bin/java -client -Xms256m -X

vmstat 1 2 shows you if you are swapping

procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
r b swpd free buff cache si so bi bo in cs us sy id wa
0 0 1048 24096 332176 2739716 0 0 17 35 2 0 3 3 93 1
0 0 1048 24096 332180 2739716 0 0 0 60 1049 639 2 1 97 0

Monday, April 27, 2009

More on the deadlock, with code decompiled

these are the 3 threads:

this thread is waiting for the TransactionLogger to complete writing the transaction file:

"[ACTIVE] ExecuteThread: '402' for queue: 'weblogic.kernel.Default (self-tuning)'" waiting for lock weblogic.transaction.internal.ResourceCheckpoint@4e5c2e7c WAITING
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:474)
weblogic.transaction.internal.ResourceCheckpoint.blockingStore(ResourceCheckpoint.java:330)
weblogic.transaction.internal.XAResourceDescriptor.checkpointResourceDiscovery(XAResourceDescriptor.java:1102)
weblogic.transaction.internal.XAResourceDescriptor.refreshCheckpoint(XAResourceDescriptor.java:925)
weblogic.transaction.internal.ServerTransactionManagerImpl.checkpoint(ServerTransactionManagerImpl.java:1421)
weblogic.transaction.internal.ServerTransactionManagerImpl.wakeUp(ServerTransactionManagerImpl.java:1483)
weblogic.transaction.internal.WLSTimer.timerExpired(WLSTimer.java:35)
weblogic.timers.internal.TimerImpl.run(TimerImpl.java:265)
weblogic.work.ServerWorkManagerImpl$WorkAdapterImpl.run(ServerWorkManagerImpl.java:518)
weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
weblogic.work.ExecuteThread.run(ExecuteThread.java:181)

synchronized void blockingStore(TransactionLogger transactionlogger)
{
transactionlogger.store(this);
try
{
if(!ioComplete)
wait();
}
catch(InterruptedException interruptedexception) { }
}

this thread is blocked waiting on a lock on a JDBCConnection, and there are 400 of these, all waiting on the same Connection:

"[ACTIVE] ExecuteThread: '401' for queue: 'weblogic.kernel.Default (self-tuning)'" waiting for lock weblogic.jdbcx.base.BaseXAConnection@2923410e BLOCKED
weblogic.jdbcx.base.BaseXAResource.end(Unknown Source)
weblogic.jdbc.jta.DataSource.end(DataSource.java:803)
weblogic.transaction.internal.XAServerResourceInfo.end(XAServerResourceInfo.java:1232)
weblogic.transaction.internal.XAServerResourceInfo.internalDelist(XAServerResourceInfo.java:404)
weblogic.transaction.internal.XAServerResourceInfo.delist(XAServerResourceInfo.java:326)
weblogic.transaction.internal.ServerTransactionImpl.delistAll(ServerTransactionImpl.java:1624)
weblogic.transaction.internal.ServerTransactionImpl.localRollback(ServerTransactionImpl.java:2012)
weblogic.transaction.internal.ServerTransactionImpl.globalRetryRollback(ServerTransactionImpl.java:3020)
weblogic.transaction.internal.ServerTransactionImpl.access$100(ServerTransactionImpl.java:66)
weblogic.transaction.internal.ServerTransactionImpl$1.run(ServerTransactionImpl.java:3252)
weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
weblogic.work.ExecuteThread.run(ExecuteThread.java:181)

public void end(Xid xid, int i)
throws XAException
{
synchronized(xaConnection)
{
checkXid(xid);
implXAResource.end(xid, i);
try
{
xaConnection.setGlobalTransaction(false);
if(implXAResource.requiredLocalAutoCommit gt 0)
xaConnection.unforceAutoCommitMode();
}
catch(SQLException sqlexception)
{
throw new XAException(sqlexception.getMessage());
}
}
}

"[STANDBY] ExecuteThread: '400' for queue: 'weblogic.kernel.Default (self-tuning)'" waiting for lock weblogic.transaction.internal.ServerTransactionImpl@73937719 TIMED_WAITING
java.lang.Object.wait(Native Method)
weblogic.transaction.internal.ServerTransactionImpl.log(ServerTransactionImpl.java:1980)
weblogic.transaction.internal.ServerTransactionImpl.globalPrepare(ServerTransactionImpl.java:2291)
weblogic.transaction.internal.ServerTransactionImpl.internalCommit(ServerTransactionImpl.java:266)
weblogic.transaction.internal.ServerTransactionImpl.commit(ServerTransactionImpl.java:227)
weblogic.jms.backend.BEForwardingConsumer.processMessages(BEForwardingConsumer.java:478)
weblogic.jms.backend.BEForwardingConsumer.pushMessages(BEForwardingConsumer.java:285)
weblogic.messaging.util.DeliveryList.run(DeliveryList.java:256)
weblogic.work.ServerWorkManagerImpl$WorkAdapterImpl.run(ServerWorkManagerImpl.java:518)
weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
weblogic.work.ExecuteThread.run(ExecuteThread.java:181)

ServerTransactionImpl:
protected void log()
throws AbortRequestedException
{
label0:
{
synchronized(this)
{
if(!isCancelledUnsync())
break label0;
}
return;
}

Thursday, April 23, 2009

WLST quirk with getServerRuntimes()

this:

connect(username,password,url)

domainRuntime()

cmo.getServerRuntimes()

will not work! Don't ask me why.

use instead:

domainRuntimeService.getServerRuntimes()

domainRuntimeService is a WLST predefined variable.
Strange, uh?

Wednesday, April 22, 2009

The inner beauty of jrockit jrcmd

see http://edocs.bea.com/jrockit/geninfo/diagnos/ctrlbreakhndlr.html

sample commands and their output:

jrcmd 12075 print_class_summary
12075:
- Class Summary Information starts here
class java/lang/Object
*class java/lang/ThreadLocal$1
*class [Ljava/util/List;
*class [Lsun/util/calendar/Era;
*class sun/util/calendar/Era
*class net/sf/saxon/sort/GenericSorter
*class net/sf/saxon/sort/SortedIterator
*class mx4j/tools/adaptor/http/CommandProcessorUtil$ToStringComparator
*class java/util/HashMap$1
*class java/lang/StringCoding$1
*class org/apache/xerces/util/DefaultErrorHandler
*class jrockit/vm/Memset
*class jrockit/vm/StringMaker
*class net/sf/saxon/expr/DifferenceEnumeration
*class net/sf/saxon/expr/IntersectionEnumeration
*class net/sf/saxon/expr/UnionEnumeration
.......

jrcmd 12075 print_object_summary increaseonly=true
12075:

--------- Detailed Heap Statistics: ---------
34.1% 1820k 19368 +1820k [C
15.3% 817k 765 +817k [B
11.9% 634k 5414 +634k java/lang/Class
8.0% 429k 18306 +429k java/lang/String
2.7% 144k 1517 +144k [I
2.2% 115k 1187 +115k [Ljava/lang/Object;
1.9% 101k 4315 +101k java/util/HashMap$Entry
1.9% 99k 1835 +99k [Ljava/lang/String;
1.5% 79k 559 +79k [Ljava/util/HashMap$Entry;
1.4% 72k 3108 +72k java/util/Hashtable$Entry
0.7% 37k 230 +37k [Ljava/util/Hashtable$Entry;
0.5% 27k 709 +27k java/lang/ref/SoftReference

jrcmd 12075 print_threads

===== FULL THREAD DUMP ===============
Wed Apr 22 11:26:57 2009
BEA JRockit(R) R27.3.1-1-85830-1.5.0_11-20070716-1248-linux-x86_64

"Thread-21" id=44 idx=0x4 tid=12075 prio=5 alive, in native, daemon

"(Signal Handler)" id=2 idx=0x8 tid=12076 prio=5 alive, in native, daemon

"(Code Generation Thread 1)" id=3 idx=0xc tid=12077 prio=5 alive, in native, native_waiting, daemon

"(Code Optimization Thread 1)" id=4 idx=0x10 tid=12078 prio=5 alive, in native, native_waiting, daemon

"(GC Main Thread)" id=5 idx=0x14 tid=12079 prio=5 alive, in native, daemon

"(GC Worker Thread 1)" id=? idx=0x18 tid=12080 prio=5 alive, in native, native_waiting, daemon

"(GC Worker Thread 2)" id=? idx=0x1c tid=12081 prio=5 alive, in native, native_waiting, daemon

"(VM Periodic Task)" id=6 idx=0x20 tid=12082 prio=10 alive, in native, daemon
.....


===== END OF THREAD DUMP ===============

jrcmd 12075 verbosity set=memory,memdbg,codegen,opt,sampling filename="output.log"

12075:
Current logstatus:
jrockit : level=WARN, decorations=201, sanity=NONE
memory (gc) : level=INFO, decorations=201, sanity=NONE
nursery (yc) : level=WARN, decorations=201, sanity=NONE
model : level=WARN, decorations=201, sanity=NONE
devirtual : level=WARN, decorations=201, sanity=NONE
codegen (code) : level=INFO, decorations=201, sanity=NONE
native (jni) : level=WARN, decorations=201, sanity=NONE
thread : level=WARN, decorations=201, sanity=NONE
opt : level=INFO, decorations=201, sanity=NONE
optq (optqueue) : level=WARN, decorations=201, sanity=NONE
callprof : level=WARN, decorations=201, sanity=NONE
load (lib) : level=WARN, decorations=201, sanity=NONE
ssa : level=WARN, decorations=201, sanity=NONE
constprop : level=WARN, decorations=201, sanity=NONE
inline : level=WARN, decorations=201, sanity=NONE
........



jrcmd 12075 timestamp
12075:
==== Timestamp ====  uptime: 5 days, 03:43:14 time: Wed Apr 22 17:07:33 2009





jrcmd 12075 print_memusage
12075:
[JRockit] memtrace is collecting data...
[JRockit] *** 0th memory utilization report
(all numbers are in kbytes)
Total mapped                         ;;;;;;;3527708
; Total in-use                        ;;;;;; 231656
;;  executable                         ;;;;;  65460
;;;   java code                         ;;;;   4928;   7.5%
;;;;    used                             ;;;   4606;   93.5%
;;  shared modules (exec+ro+rw)        ;;;;;   5280
;;  guards                             ;;;;;    492
;;  readonly                           ;;;;;      0
;;  rw-memory                          ;;;;; 171124
;;;   Java-heap                         ;;;;  65536;   38.3%
;;;   Stacks                            ;;;;  11862;   6.9%
;;;   Native-memory                     ;;;;  93725;   54.8%
;;;;    java-heap-overhead               ;;;   2057
;;;;    codegen memory                   ;;;    704
;;;;    classes                          ;;;  38400;   41.0%
;;;;;     method bytecode                 ;;   2916
;;;;;     method structs                  ;;   4341    (#55573)
;;;;;     constantpool                    ;;  17310
;;;;;     classblock                      ;;   1999
;;;;;     class                           ;;   2873    (#5434)
;;;;;     other classdata                 ;;   4782
;;;;;     overhead                        ;;    203
;;;;    threads                          ;;;     55;   0.1%
;;;;    malloc:ed memory                 ;;;  20259;   21.6%
;;;;;     codeinfo                        ;;   1211
;;;;;     codeinfotrees                   ;;    642
;;;;;     exceptiontables                 ;;    337
;;;;;     metainfo/livemaptable           ;;   5081
;;;;;     codeblock structs               ;;      4
;;;;;     constants                       ;;     11
;;;;;     livemap global tables           ;;   2085
;;;;;     callprof cache                  ;;      0
;;;;;     paraminfo                       ;;     94    (#1204)
;;;;;     strings                         ;;   4020    (#65580)
;;;;;     strings(jstring)                ;;      0
;;;;;     typegraph                       ;;   1343
;;;;;     interface implementor list      ;;    265
;;;;;     thread contexts                 ;;     49
;;;;;     jar/zip memory                  ;;   6626
;;;;;     native handle memory            ;;     39
;;;;    unaccounted for memory           ;;;  32303;   34.5%;1.59
---------------------!!!




jrcmd 12075 heap_diagnostics 

======== BEGIN OF HEAPDIAGNOSTIC =========================

Invoked from diagnosticcommand

Total memory in system: 8377249792 bytes
Available physical memory in system: 1293717504 bytes
-Xmx (maximal heap size) is 4294967296 bytes
Heapsize: 4294967296 bytes
Free heap-memory: 3712605608 bytes

mmStartCompaction = 0x2b1e042b0000, mmEndCompaction = 0x2b1e082b0018


Memory layout:
00010000-003d0000 rwxp 00010000 00:00 0
00400000-00412000 r-xp 00000000 fd:04 1287492                            /opt/jrmc-3.1.0-1.5.0/bin/java
00420000-004e0000 rwxp 00420000 00:00 0
00511000-00513000 rwxp 00011000 fd:04 1287492                            /opt/jrmc-3.1.0-1.5.0/bin/java
00520000-07d60000 rwxp 00520000 00:00 0
07d7a000-0f9a5000 rwxp 07d7a000 00:00 0
0f9b0000-15ff0000 rwxp 0f9b0000 00:00 0
4005b000-4005d000 rwxp 4005b000 00:00 0
4005d000-40060000 ---p 4005d000 00:00 0
40060000-4009f000 rwxp 40060000 00:00 0
4009f000-400a2000 ---p 4009f000 00:00 0

--------- Detailed Heap Statistics: ---------
21.5% 72399k   637351     +0k [C
 8.6% 29000k   281013     +0k [Ljava/lang/Object;
 6.5% 21797k   697514     +0k java/lang/String
 5.1% 17145k    31500    -59k [B
 4.1% 13697k    87524     +0k [Ljava/util/HashMap$Entry;
 2.7% 9274k    65950     +0k java/lang/reflect/Method
 2.4% 8101k   207404     +0k java/util/HashMap$Entry
 2.0% 6778k   173542     +0k com/bea/common/security/xacml/attr/StringAttribute
 2.0% 6629k    33943     +0k java/lang/Class


     337244kB total ---

--------- End of Detailed Heap Statistics ---
----- Reference Objects statistics separated per class -----
    Total Reach Act PrevAct Null
    ----- ----- --- ------- ----
Finalizers:
        5     2   3       0    0 Total for all Finalizers
        2     1   1       0    0 => java/net/SocksSocketImpl
        1     0   1       0    0 => weblogic/socket/WeblogicSocket
        1     1   0       0    0 => java/net/SocketInputStream
        1     0   1       0    0 => java/net/SocketOutputStream
----- End of Reference Objects statistics -----
------------------- Printing heap ---------------------
"o"/"p" = 1k normal/pinned objects
"O"/"P" = 50k normal/pinned objects
"."/"/" = <1k normal/pinned objects (fragmentation)
" "/"_" = 1k/50k free space
-------------------------------------------------------
//////o///o/p/oo/OOOoooooooooooooooooooooo/OOooooo      0x2b1dfe2f7c70
ooooooooo/OOOOOOooooooooooo/Oooooooooooooooooooooo      0x2b1dfe357b98
ooooooooooooo..        OOOOOOOoooooooooooooo./oooo      0x2b1dfe3b7ac0
oooooooooooooooooooooooo/OOooooooooooooooooooooooo      0x2b1dfe3dbce0
oooooooooooooooooooo/oooooooooooooooo/OOOOOooooooo      0x2b1dfe423d38
oooooooooooooooooooooooooooo.   OOOooooooooooooooo      0x2b1dfe453ec0
ooooooooooooooooooooooooooo//.....................      0x2b1dfe460210
..............................Ooooooooooo/OOOOoooo      0x2b1dfe4a8268





the available commands are:

kill_rmp_server
start_rmp_server
kill_management_server
start_management_server
checkjrarecording
stopjrarecording
startjrarecording
print_object_summary
memleakserver
print_class_summary
print_codegenlist
run_optfile
dump_codelayout
dump_codelist
dump_codemap
print_utf8pool
print_properties
print_threads
datadump_request
runsystemgc
runfinalization
heap_diagnostics
oom_diagnostics
print_exceptions
version
timestamp
command_line
sanity
verbosity
set_filename
help
print_memusage

Saturday, April 18, 2009

Analysis of a deadlock

"[ACTIVE] ExecuteThread: '402' for queue: 'weblogic.kernel.Default (self-tuning)'" waiting for lock weblogic.transaction.internal.ResourceCheckpoint@4e5c2e7c WAITING
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:474)
weblogic.transaction.internal.ResourceCheckpoint.blockingStore(ResourceCheckpoint.java:330)
weblogic.transaction.internal.XAResourceDescriptor.checkpointResourceDiscovery(XAResourceDescriptor.java:1102)
weblogic.transaction.internal.XAResourceDescriptor.refreshCheckpoint(XAResourceDescriptor.java:925)
weblogic.transaction.internal.ServerTransactionManagerImpl.checkpoint(ServerTransactionManagerImpl.java:1421)
weblogic.transaction.internal.ServerTransactionManagerImpl.wakeUp(ServerTransactionManagerImpl.java:1483)
weblogic.transaction.internal.WLSTimer.timerExpired(WLSTimer.java:35)
weblogic.timers.internal.TimerImpl.run(TimerImpl.java:265)
weblogic.work.ServerWorkManagerImpl$WorkAdapterImpl.run(ServerWorkManagerImpl.java:518)
weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
weblogic.work.ExecuteThread.run(ExecuteThread.java:181)

this thread is blocked waiting on a lock on a JDBCConnection

"[ACTIVE] ExecuteThread: '401' for queue: 'weblogic.kernel.Default (self-tuning)'" waiting for lock weblogic.jdbcx.base.BaseXAConnection@2923410e BLOCKED
weblogic.jdbcx.base.BaseXAResource.end(Unknown Source)
weblogic.jdbc.jta.DataSource.end(DataSource.java:803)
weblogic.transaction.internal.XAServerResourceInfo.end(XAServerResourceInfo.java:1232)
weblogic.transaction.internal.XAServerResourceInfo.internalDelist(XAServerResourceInfo.java:404)
weblogic.transaction.internal.XAServerResourceInfo.delist(XAServerResourceInfo.java:326)
weblogic.transaction.internal.ServerTransactionImpl.delistAll(ServerTransactionImpl.java:1624)
weblogic.transaction.internal.ServerTransactionImpl.localRollback(ServerTransactionImpl.java:2012)
weblogic.transaction.internal.ServerTransactionImpl.globalRetryRollback(ServerTransactionImpl.java:3020)
weblogic.transaction.internal.ServerTransactionImpl.access$100(ServerTransactionImpl.java:66)
weblogic.transaction.internal.ServerTransactionImpl$1.run(ServerTransactionImpl.java:3252)
weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
weblogic.work.ExecuteThread.run(ExecuteThread.java:181)

"[STANDBY] ExecuteThread: '400' for queue: 'weblogic.kernel.Default (self-tuning)'" waiting for lock weblogic.transaction.internal.ServerTransactionImpl@73937719 TIMED_WAITING
java.lang.Object.wait(Native Method)
weblogic.transaction.internal.ServerTransactionImpl.log(ServerTransactionImpl.java:1980)
weblogic.transaction.internal.ServerTransactionImpl.globalPrepare(ServerTransactionImpl.java:2291)
weblogic.transaction.internal.ServerTransactionImpl.internalCommit(ServerTransactionImpl.java:266)
weblogic.transaction.internal.ServerTransactionImpl.commit(ServerTransactionImpl.java:227)
weblogic.jms.backend.BEForwardingConsumer.processMessages(BEForwardingConsumer.java:478)
weblogic.jms.backend.BEForwardingConsumer.pushMessages(BEForwardingConsumer.java:285)
weblogic.messaging.util.DeliveryList.run(DeliveryList.java:256)
weblogic.work.ServerWorkManagerImpl$WorkAdapterImpl.run(ServerWorkManagerImpl.java:518)
weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
weblogic.work.ExecuteThread.run(ExecuteThread.java:181)

enable JTA2PC, JTATLOG

either by passing:
-Dweblogic.debug.DebugJTA2PC=true
in the startWeblogic command,

or by using the Weblogic console (server/debug/weblogic/tlog and set DebugJTATLOG to true... No restarts are necessary)

or with WLST:

java weblogic.WLST
connect('weblogic', 'weblogic', 't3://myhost6360')
edit()
startEdit()
cd('/Servers/myserver/ServerDebug/myserver')
cmo.setDebugJTATLOG(true)
save()
activate()
disconnect()

read also this excellent article:
http://e-docs.bea.com/jrockit/geninfo/diagnos/thread_basics.html
http://edocs.bea.com/jrockit/docs142/userguide/apstkdmp.html
http://edocs.bea.com/jrockit/geninfo/diagnos/ctrlbreakhndlr.html on the jrcmd

Wednesday, April 15, 2009

Java Date to Epoch

import java.text.ParseException;
import java.text.SimpleDateFormat;
import java.util.Calendar;
import java.util.Date;
import java.util.GregorianCalendar;

public class DateConverter {
public static void main(String[] args) throws ParseException {
SimpleDateFormat df = (SimpleDateFormat) SimpleDateFormat.getInstance();
df.applyPattern("yyyy MMM dd HH:mm:ss");
Date date = df.parse("2009 Apr 14 16:46:23");
System.out.println(date);
Calendar cal = new GregorianCalendar();
cal.setTime(date);
System.out.println(cal.getTimeInMillis());
}
}

Unix most wanted commands

ps -fu beasvbd (lists the processes run by a given user)

find ./ -name *.jar | while read LINE; do echo $LINE;jar -tvf $LINE | grep TransactionSynchronizationRegistry; done (find in which jar a given class is)

find / -name startNodeManager.sh 2> /dev/null doesn't display error messages

Tuesday, April 14, 2009

Unicast

you should see in the log:

14-Apr-2009 19:28:05 o'clock CEST Notice Cluster BEA-000197 Listening for announcements from cluster using unicast cluster messaging

BAD_CERTIFICATE in startNodeManager.sh

<14-apr-2009>
javax.net.ssl.SSLKeyException: [Security:090482]BAD_CERTIFICATE alert was received from localhost - 127.0.0.1. Check the peer to determine why it rejected the certificate chain (trusted CA configuration, hostname verification). SSL debug tracing may be required to determine the exact reason the certificate was rejected.
at com.certicom.tls.interfaceimpl.TLSConnectionImpl.fireException(Unknown Source)
at com.certicom.tls.interfaceimpl.TLSConnectionImpl.fireAlertReceived(Unknown Source)
at com.certicom.tls.record.alert.AlertHandler.handle(Unknown Source)
at com.certicom.tls.record.alert.AlertHandler.handleAlertMessages(Unknown Source)
at com.certicom.tls.record.MessageInterpreter.interpretContent(Unknown Source)
at com.certicom.tls.record.MessageInterpreter.decryptMessage(Unknown Source)
at com.certicom.tls.record.ReadHandler.processRecord(Unknown Source)
at com.certicom.tls.record.ReadHandler.readRecord(Unknown Source)
at com.certicom.tls.record.ReadHandler.readUntilHandshakeComplete(Unknown Source)
at com.certicom.tls.interfaceimpl.TLSConnectionImpl.completeHandshake(Unknown Source)
at com.certicom.tls.record.ReadHandler.read(Unknown Source)
at com.certicom.io.InputSSLIOStreamWrapper.read(Unknown Source)
at sun.nio.cs.StreamDecoder$CharsetSD.readBytes(StreamDecoder.java:411)
at sun.nio.cs.StreamDecoder$CharsetSD.implRead(StreamDecoder.java:453)
at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:183)
at java.io.InputStreamReader.read(InputStreamReader.java:167)
at java.io.BufferedReader.fill(BufferedReader.java:136)
at java.io.BufferedReader.readLine(BufferedReader.java:299)
at java.io.BufferedReader.readLine(BufferedReader.java:362)
at weblogic.nodemanager.server.Handler.run(Handler.java:66)
at java.lang.Thread.run(Thread.java:595)

try this:

http://e-docs.bea.com/wls/docs90/secmanage/ssl.html#1194397

and also
http://e-docs.bea.com/wls/docs90/ConsoleHelp/taskh...sableHostNameVerification.html

you should start weblogic.Server with the property:
-Dweblogic.security.SSL.ignoreHostnameVerification=true

in the startWeblogic.sh or whatever you use to start...

Also, try:

-Dweblogic.webservice.client.verbose=true
-Dweblogic.security.SSL.verbose=true
-Dssl.debug=true
-Dweblogic.StdoutDebugEnabled=true

Wednesday, April 8, 2009

Setting Interface Address for Cluster Multicast

you should see in the logs:

Setting the interface address to : yourInterfaceAddress

Debug flags in Weblogic

here is an exciting list, they can be useful to troubleshoot stuff:

see also http://download.oracle.com/docs/cd/E12839_01/apirefs.1111/e13945/weblogic/management/configuration/ServerDebugMBean.html

-rw- ApplicationContainer false
-rw- ClassFinder false
-rw- ClassLoader false
-rw- ClassLoaderVerbose false
-rw- ClassloaderWebApp false
-rw- ClasspathServlet false
-rw- DebugAbbreviation false
-rw- DebugAppContainer false
-rw- DebugBootstrapServlet false
-rw- DebugCluster true
-rw- DebugClusterAnnouncements true
-rw- DebugClusterFragments true
-rw- DebugClusterHeartbeats true
-rw- DebugConfigurationEdit false
-rw- DebugConfigurationRuntime false
-rw- DebugConnection false
-rw- DebugConnectorService false
-rw- DebugConsensusLeasing false
-rw- DebugDGCEnrollment false
-rw- DebugDRSCalls false
-rw- DebugDRSHeartbeats false
-rw- DebugDRSMessages false
-rw- DebugDRSQueues false
-rw- DebugDRSStateTransitions false
-rw- DebugDRSUpdateStatus false
-rw- DebugDeploy false
-rw- DebugDeployment false
-rw- DebugDeploymentService false
-rw- DebugDeploymentServiceInternal false
-rw- DebugDeploymentServiceStatusUpdates false
-rw- DebugDeploymentServiceTransport false
-rw- DebugDeploymentServiceTransportHttp false
-rw- DebugDiagnosticAccessor false
-rw- DebugDiagnosticArchive false
-rw- DebugDiagnosticCollections false
-rw- DebugDiagnosticFileArchive false
-rw- DebugDiagnosticImage false
-rw- DebugDiagnosticInstrumentation false
-rw- DebugDiagnosticInstrumentationActions false
-rw- DebugDiagnosticInstrumentationConfig false
-rw- DebugDiagnosticInstrumentationEvents false
-rw- DebugDiagnosticInstrumentationWeaving false
-rw- DebugDiagnosticInstrumentationWeavingMatches false
-rw- DebugDiagnosticJdbcArchive false
-rw- DebugDiagnosticLifecycleHandlers false
-rw- DebugDiagnosticQuery false
-rw- DebugDiagnosticWatch false
-rw- DebugDiagnosticWlstoreArchive false
-rw- DebugDiagnosticsHarvester false
-rw- DebugDiagnosticsHarvesterData false
-rw- DebugDiagnosticsHarvesterMBeanPlugin false
-rw- DebugDiagnosticsHarvesterTreeBeanPlugin false
-rw- DebugDiagnosticsModule false
-rw- DebugDomainLogHandler false
-rw- DebugEjbCaching false
-rw- DebugEjbCmpDeployment false
-rw- DebugEjbCmpRuntime false
-rw- DebugEjbCompilation false
-rw- DebugEjbDeployment false
-rw- DebugEjbInvoke false
-rw- DebugEjbLocking false
-rw- DebugEjbMdbConnection false
-rw- DebugEjbPooling false
-rw- DebugEjbSecurity false
-rw- DebugEjbSwapping false
-rw- DebugEjbTimers false
-rw- DebugEmbeddedLDAP false
-rw- DebugEmbeddedLDAPLogLevel 0
-rw- DebugEmbeddedLDAPLogToConsole false
-rw- DebugEmbeddedLDAPWriteOverrideProps false
-rw- DebugEventManager false
-rw- DebugFailOver false
-rw- DebugFileDistributionServlet false
-rw- DebugHttp false
-rw- DebugHttpLogging false
-rw- DebugHttpSessions false
-rw- DebugIIOP false
-rw- DebugIIOPConnection false
-rw- DebugIIOPMarshal false
-rw- DebugIIOPNaming false
-rw- DebugIIOPOTS false
-rw- DebugIIOPReplacer false
-rw- DebugIIOPSecurity false
-rw- DebugIIOPStartup false
-rw- DebugIIOPTransport false
-rw- DebugIIOPTunneling false
-rw- DebugJ2EEManagement false
-rw- DebugJAXPDebugLevel 0
-rw- DebugJAXPDebugName null
-rw- DebugJAXPIncludeClass false
-rw- DebugJAXPIncludeLocation false
-rw- DebugJAXPIncludeName false
-rw- DebugJAXPIncludeTime false
-rw- DebugJAXPOutputStream null
-rw- DebugJAXPUseShortClass false
-rw- DebugJDBCConn false
-rw- DebugJDBCDriverLogging false
-rw- DebugJDBCInternal false
-rw- DebugJDBCRMI false
-rw- DebugJDBCSQL false
-rw- DebugJMSAME false
-rw- DebugJMSBackEnd false
-rw- DebugJMSBoot false
-rw- DebugJMSCDS false
-rw- DebugJMSCommon false
-rw- DebugJMSConfig false
-rw- DebugJMSDispatcher false
-rw- DebugJMSDistTopic false
-rw- DebugJMSDurableSubscribers false
-rw- DebugJMSFrontEnd false
-rw- DebugJMSJDBCScavengeOnFlush false
-rw- DebugJMSLocking false
-rw- DebugJMSMessagePath false
-rw- DebugJMSModule false
-rw- DebugJMSPauseResume false
-rw- DebugJMSSAF false
-rw- DebugJMSStore false
-rw- DebugJMSWrappers false
-rw- DebugJMSXA false
-rw- DebugJMX false
-rw- DebugJMXCompatibility false
-rw- DebugJMXCore false
-rw- DebugJMXDomain false
-rw- DebugJMXEdit false
-rw- DebugJMXRuntime false
-rw- DebugJNDI false
-rw- DebugJNDIFactories false
-rw- DebugJNDIResolution false
-rw- DebugJTA2PC false
-rw- DebugJTA2PCStackTrace false
-rw- DebugJTAAPI false
-rw- DebugJTAGateway false
-rw- DebugJTAGatewayStackTrace false
-rw- DebugJTAHealth false
-rw- DebugJTAJDBC false
-rw- DebugJTALLR false
-rw- DebugJTALifecycle false
-rw- DebugJTAMigration false
-rw- DebugJTANaming false
-rw- DebugJTANamingStackTrace false
-rw- DebugJTANonXA false
-rw- DebugJTAPropagate false
-rw- DebugJTARMI false
-rw- DebugJTARecovery false
-rw- DebugJTARecoveryStackTrace false
-rw- DebugJTAResourceHealth false
-rw- DebugJTAResourceName null
-rw- DebugJTATLOG false
-rw- DebugJTATransactionName null
-rw- DebugJTAXA false
-rw- DebugJTAXAStackTrace false
-rw- DebugLeaderElection false
-rw- DebugLibraries false
-rw- DebugLoadBalancing false
-rw- DebugLoggingConfiguration false
-rw- DebugMaskCriterias null
-rw- DebugMessaging false
-rw- DebugMessagingBridgeRuntime false
-rw- DebugMessagingBridgeRuntimeVerbose false
-rw- DebugMessagingBridgeStartup false
-rw- DebugMessagingKernel false
-rw- DebugMessagingKernelBoot false
-rw- DebugMuxer false
-rw- DebugMuxerConnection false
-rw- DebugMuxerDetail false
-rw- DebugMuxerException false
-rw- DebugMuxerTimeout false
-rw- DebugPathSvc false
-rw- DebugPathSvcVerbose false
-rw- DebugRA false
-rw- DebugRAConnEvents false
-rw- DebugRAConnections false
-rw- DebugRADeployment false
-rw- DebugRALifecycle false
-rw- DebugRALocalOut false
-rw- DebugRAParsing false
-rw- DebugRAPoolVerbose false
-rw- DebugRAPooling false
-rw- DebugRASecurityCtx false
-rw- DebugRAWork false
-rw- DebugRAWorkEvents false
-rw- DebugRAXAin false
-rw- DebugRAXAout false
-rw- DebugRAXAwork false
-rw- DebugRC4 false
-rw- DebugRSA false
-rw- DebugReplication false
-rw- DebugReplicationDetails false
-rw- DebugRouting false
-rw- DebugSAFAdmin false
-rw- DebugSAFLifeCycle false
-rw- DebugSAFManager false
-rw- DebugSAFMessagePath false
-rw- DebugSAFReceivingAgent false
-rw- DebugSAFSendingAgent false
-rw- DebugSAFStore false
-rw- DebugSAFTransport false
-rw- DebugSAFVerbose false
-rw- DebugSSL false
-rw- DebugSecurityAdjudicator false
-rw- DebugSecurityAtn false
-rw- DebugSecurityAtz false
-rw- DebugSecurityAuditor false
-rw- DebugSecurityCertPath false
-rw- DebugSecurityCredMap false
-rw- DebugSecurityEEngine false
-rw- DebugSecurityEncryptionService false
-rw- DebugSecurityJACC false
-rw- DebugSecurityJACCNonPolicy false
-rw- DebugSecurityJACCPolicy false
-rw- DebugSecurityKeyStore false
-rw- DebugSecurityPasswordPolicy false
-rw- DebugSecurityPredicate false
-rw- DebugSecurityRealm false
-rw- DebugSecurityRoleMap false
-rw- DebugSecuritySAMLAtn false
-rw- DebugSecuritySAMLCredMap false
-rw- DebugSecuritySAMLLib false
-rw- DebugSecuritySAMLService false
-rw- DebugSecuritySSL false
-rw- DebugSecuritySSLEaten false
-rw- DebugSecurityService false
-rw- DebugSecurityUserLockout false
-rw- DebugSelfTuning false
-rw- DebugServerLifeCycle false
-rw- DebugServerMigration false
-rw- DebugStoreAdmin false
-rw- DebugStoreIOLogical false
-rw- DebugStoreIOLogicalBoot false
-rw- DebugStoreIOPhysical false
-rw- DebugStoreIOPhysicalVerbose false
-rw- DebugStoreXA false
-rw- DebugStoreXAVerbose false
-rw- DebugTunnelingConnection false
-rw- DebugTunnelingConnectionTimeout false
-rw- DebugURLResolution false
-rw- DebugWANReplicationDetails false
-rw- DebugWTCConfig false
-rw- DebugWTCCorbaEx false
-rw- DebugWTCGwtEx false
-rw- DebugWTCJatmiEx false
-rw- DebugWTCTDomPdu false
-rw- DebugWTCUData false
-rw- DebugWTCtBridgeEx false
-rw- DebugWebAppIdentityAssertion false
-rw- DebugWebAppModule false
-rw- DebugWebAppSecurity false
-rw- DebugXMLEntityCacheDebugLevel 0
-rw- DebugXMLEntityCacheDebugName null
-rw- DebugXMLEntityCacheIncludeClass false
-rw- DebugXMLEntityCacheIncludeLocation false
-rw- DebugXMLEntityCacheIncludeName false
-rw- DebugXMLEntityCacheIncludeTime false
-rw- DebugXMLEntityCacheOutputStream null
-rw- DebugXMLEntityCacheUseShortClass false
-rw- DebugXMLRegistryDebugLevel 0
-rw- DebugXMLRegistryDebugName null
-rw- DebugXMLRegistryIncludeClass false
-rw- DebugXMLRegistryIncludeLocation false
-rw- DebugXMLRegistryIncludeName false
-rw- DebugXMLRegistryIncludeTime false
-rw- DebugXMLRegistryOutputStream null
-rw- DebugXMLRegistryUseShortClass false

Monday, April 6, 2009

Weblogic Cluster and cluster communication amongst manager servers

I was under the impression that ALL the communication amongst MS (managed servers) in the same cluster would occur via MULTICAST or UNICAST. This would include:

- HTTPSession synchronization - if Session Replication is enabled

- JNDI tree synchronization

- Health state monitoring

In reality most of these communication occurs with TCP-IP Sockets!

Setting Debug Flags on the Command Line

Set these flags from the command line during server startup by adding the following options:

-Dweblogic.debug.DebugCluster=true

-Dweblogic.debug.DebugClusterHeartBeats=true

-Dweblogic.debug.DebugClusterFragments=true

these flags should be available on the ServerDebugMBean.

in WLST, find('DebugCluster') should point you to the right place:

/Servers/yourServerName/ServerDebug/yourServerName DebugClusterHeartbeats
/Servers/yourServerName/ServerDebug/yourServerName DebugClusterAnnouncements
/Servers/yourServerName/ServerDebug/yourServerName DebugCluster
/Servers/yourServerName/ServerDebug/yourServerName DebugClusterFragments

so somethig like:

connect(......)
edit()
startEdit()
cd('/Servers/yourServerName/ServerDebug/yourServerName')
cmo.setDebugClusterHeartbeats(true)
cmo.setDebugClusterAnnouncements(true)
cmo.setDebugCluster(true)
cmo.setDebugClusterFragments (true)

save()
activate()

should do

you should see at this point messages in the log file, such as:

ClusterHeartbeats ... Sent Heartbeat with 1 items

ClusterHeartbeats ... Received Heartbeat with 1 items from 5446592690916645012S:bcdev07.server.ux.nuon.local:[5420,5420,-1,-1,-1,-1,-1]:bcdev07.server.ux.nuon.local:5410,bcdev07.server.ux.nuon.local:5420:prx_eb_alsb_dev:prx_eb_alsb_dev_server_2

ClusterAnnouncements ... Sending local attributes prx_eb_alsb_dev_server_1 jvmid:753244874926136889S:bcdev07.server.ux.nuon.local:bcdev07.server.ux.nuon.local:5410,bcdev07.server.ux.nuon.local:5420:prx_eb_alsb_dev:prx_eb_alsb_dev_server_1

Cluster .... Sending senderNum:1 seqNum:0 message:Attributes prx_eb_alsb_dev_server_1 jvmid:753244874926136889S:bcdev07.server.ux.nuon.local:bcdev07.server.ux.nuon.local:5410,bcdev07.server.ux.nuon.local:5420:prx_eb_alsb_dev:prx_eb_alsb_dev_server_1 outgoing message:message:[115, 114,

ClusterFragments .... Sending fragment senderNum:1 seqNum:0fragNum:0 containing 1067 bytes out of 2375

ClusterFragments .... Sending fragment senderNum:1 seqNum:0fragNum:1 containing 1067 bytes out of 2375

ClusterFragments .... Sending fragment senderNum:1 seqNum:0fragNum:2 containing 241 bytes out of 2375

Friday, April 3, 2009

Network Monitoring

http://www.howtoforge.com/network_monitoring_with_ntop

rrdtool + cacti

use iostat:

iostat
Linux 2.6.18-92.1.6.el5 (yourhostname) 05/12/2009

avg-cpu: %user %nice %system %iowait %steal %idle
0.29 0.05 0.54 0.09 0.00 99.04

Device: tps Blk_read/s Blk_wrtn/s Blk_read Blk_wrtn
sda 1.53 0.60 16.74 843702 23657360
sdb 0.06 0.40 1.77 571688 2496888
dm-0 0.02 0.08 0.12 117306 169328
dm-1 0.38 0.00 0.77 4902 1085280
dm-2 1.14 0.09 9.08 131618 12832832
dm-3 0.77 0.06 6.14 84162 8678000
dm-4 0.28 0.04 0.56 63482 791708
dm-5 0.02 0.28 0.07 394794 100160
dm-6 0.00 0.00 0.00 4040 0
dm-7 0.06 0.01 0.47 18098 663640
dm-8 0.18 0.38 1.30 535978 1833248

Useful Unix scripts

find files with size greater than 1GB:
find /ednpdtu3/u01/pipe -type f -size +1048576

Weblogic and Debug Flags for Transactions

digging in the weblogic.jdbc.jta.DataSource code, the weblogic.jdbcx.base.BaseXAResource, weblogic.transaction.internal.XAServerResourceInfo etc you can see that these flags are used to determine what should be logged:

JTAXA (DebugJTAXA)
JTAXAStackTrace (DebugJTAXAStackTrace)
JTA2PC (DebugJTA2PC)
JTARecovery (not important IMHO) (DebugJTARecovery)
JTAResourceHealth (DebugJTAResourceHealth)

all the JTA flags are:

DebugJTARecovery
DebugJTAAPI
DebugJTALLR
DebugJTARecoveryStackTrace
DebugJTATransactionName
DebugJTAJDBC
DebugJTAPropagate
DebugJTAHealth
DebugJTAXA
DebugJTALifecycle
DebugJTATLOG
DebugJTANonXA
DebugJTAXAStackTrace
DebugJTAResourceName
DebugJTAGatewayStackTrace
DebugJTA2PCStackTrace
DebugJTAResourceHealth
DebugJTANamingStackTrace
DebugJTA2PC
DebugJTAMigration
DebugJTANaming
DebugJTARMI
DebugJTAGateway

Thursday, April 2, 2009

Weblogic and Threads

for those who have missed the event, Weblogic doesn't have any more the concept of configurable Execute Queues for threads.
Instead, we have a single Thread Pool, and the different Work Manager will poach threads from it.

More on this topic:

http://edocs.bea.com/wls/docs100/ConsoleHelp/pagehelp/Corecoreserverservermonitorthreadstitle.html

Java mon amour