Created On:  14 January 2011

Problem:

  • Product: VisiBroker for Java 
  • Product Version: 8.0 and below
  • Product Component: Security
  • Platform: All
The VisiBroker for Java Server with security feature enabled appears hung and does not accept new SSL connection.
When a thread dump is captured, it is observed that many threads are blocked while trying to remove the SSL connections.
A snippet of the important threads in the thread dump is as follows:


"VBJ ThreadPool Worker id=XXX" daemon prio=3 tid=0x023e7800 nid=0x1661 runnable [0x9367f000]
   java.lang.Thread.State: RUNNABLE
 at java.net.SocketInputStream.socketRead0(Native Method)
 at java.net.SocketInputStream.read(SocketInputStream.java:129)
 at com.sun.net.ssl.internal.ssl.InputRecord.readFully(InputRecord.java:293)
 at com.sun.net.ssl.internal.ssl.InputRecord.read(InputRecord.java:331)
 at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:789)
 - locked <0xc9c46388> (a java.lang.Object)
 at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1112)
 - locked <0xc9c4f4f0> (a java.lang.Object)
 at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:744)
 at com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:75)
 - locked <0xc9c46320> (a com.sun.net.ssl.internal.ssl.AppInputStream)
 at com.borland.security.csiv2.SSLConnection.read(SSLConnection.java:759)
 at com.inprise.vbroker.GIOP.BaseInputStream.readFromConnection(Unknown Source)
 at com.inprise.vbroker.GIOP.MessageFactory.readMessage(Unknown Source)
 at com.inprise.vbroker.GIOP.GiopConnection.receive_message(Unknown Source)
 at com.inprise.vbroker.IIOP.ProtocolConnection.receive(Unknown Source)
 at com.inprise.vbroker.IIOP.ProtocolConnection.receive_request(Unknown Source)
 at com.inprise.vbroker.IIOP.ServerProtocolAdapter.readMessage(Unknown Source)
 at com.inprise.vbroker.orb.TPDispatcherImpl$TPDispatcher.run(Unknown Source)
 at com.inprise.vbroker.orb.ThreadPool$PoolWorker.run(Unknown Source)

"SocketListener se=ssl scm=ssl orb=1478a43" daemon prio=3 tid=0x0108ac00 nid=0x189 waiting for monitor entry [0x9337f000]
   java.lang.Thread.State: BLOCKED (on object monitor)
 at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1087)
 - waiting to lock <0xc9c4f4f0> (a java.lang.Object)
 at com.sun.net.ssl.internal.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:623)
 at com.sun.net.ssl.internal.ssl.AppOutputStream.write(AppOutputStream.java:59)
 - locked <0xc9c44f50> (a com.sun.net.ssl.internal.ssl.AppOutputStream)
 at com.borland.security.csiv2.SSLConnection.write(SSLConnection.java:951)
 - locked <0xc9c53148> (a com.borland.security.csiv2.SSLConnection)
 at com.inprise.vbroker.GIOP.OutputStream.write(Unknown Source)
 at com.inprise.vbroker.GIOP.OutputStream.writeUnfragmented(Unknown Source)
 at com.inprise.vbroker.GIOP.Message.write(Unknown Source)
 at com.inprise.vbroker.GIOP.GiopConnection.send_message(Unknown Source)
 at com.inprise.vbroker.GIOP.GiopConnection.send_message(Unknown Source)
 at com.inprise.vbroker.GIOP.GiopProtocolAdapter.close(Unknown Source)
 at com.inprise.vbroker.IIOP.ServerProtocolAdapter.close(Unknown Source)
 at com.inprise.vbroker.orb.SocketSCM.detachAgedConnection(Unknown Source)
 at com.inprise.vbroker.orb.SocketSCM.newConnection(Unknown Source)
 - locked <0xc6884188> (a com.inprise.vbroker.orb.SocketSCM)
 at com.inprise.vbroker.orb.SocketSCM$ListenerThread.run(Unknown Source)
 at java.lang.Thread.run(Thread.java:619)

"VBJ ThreadPool Worker id=YYY" daemon prio=3 tid=0x02fbc000 nid=0x41b7 waiting for monitor entry [0x9017f000]
   java.lang.Thread.State: BLOCKED (on object monitor)
 at com.inprise.vbroker.orb.SocketSCM.removeConnection(Unknown Source)
 - waiting to lock <0xc6884188> (a com.inprise.vbroker.orb.SocketSCM)
 at com.inprise.vbroker.orb.TPDispatcherImpl$TPDispatcher.run(Unknown Source)
 at com.inprise.vbroker.orb.ThreadPool$PoolWorker.run(Unknown Source)

"VBJ ThreadPool Worker id=ZZZ" daemon prio=3 tid=0x00f3e800 nid=0x41ae waiting for monitor entry [0x898ff000]
   java.lang.Thread.State: BLOCKED (on object monitor)
 at com.inprise.vbroker.orb.SocketSCM.removeConnection(Unknown Source)
 - waiting to lock <0xc6884188> (a com.inprise.vbroker.orb.SocketSCM)
 at com.inprise.vbroker.orb.TPDispatcherImpl$TPDispatcher.run(Unknown Source)
 at com.inprise.vbroker.orb.ThreadPool$PoolWorker.run(Unknown Source)

...............................
An object monitor is blocked pending the successful SSL handshake between a client and server process.
This indirectly is blocking other threads that are accepting new connections and removing existing connections from the connection pool.

Resolution:

An enhancement CR 10297 (RPI 1078180) was raised to prevent the Server from hanging due to unresponsive Client during SSL handshake.  A new property "vbroker.security.server.ssl.handshakeTimeout" is introduced to allow user to configure the Server side SSL handshake timeout.

This property specifies the maximum time (in milliseconds) for the SSL handshake to complete at the Server side. It can help to prevent the Server from hanging due to unresponsive Clients during SSL handshake. The default timeout is 5000ms. To disable the timeout, set it to 0.

Note that this property is also applicable to VBC Security.  It is generally available in all platforms in VB 8.5 SP1 released.

Incident #2492887