This discussion is archived
14 Replies Latest reply: Apr 26, 2013 7:52 AM by 1005722 RSS

SSLSocketImpl Deadlock with Jre 1.7.09

852276 Newbie
Currently Being Moderated
Since we upgraded from the latest 1.6 vm to 1.7 (1.7.09), we have been experiencing an SSLSocketImpl deadlock. It seems to occur after 4 hours or so. Looking at the stack dump, it appears to be a lock contention down in the java library. I've seen references to older releases with a similar issue but with no proposed workarounds or solutions. Any thoughts?

Best Regards,
Bill Smith

Found one Java-level deadlock:
=============================
"Fox:Sender:18":
waiting to lock monitor 0x0685945c (object 0x22b05f88, a sun.security.ssl.SSLSocketImpl),
which is held by "Nre:Engine"
"Nre:Engine":
waiting for ownable synchronizer 0x22b06190, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
which is held by "Fox:Sender:18"

Java stack information for the threads listed above:
===================================================
"Fox:Sender:18":
at sun.security.ssl.SSLSocketImpl.getConnectionState(SSLSocketImpl.java:649)
- waiting to lock <0x22b05f88> (a sun.security.ssl.SSLSocketImpl)
at sun.security.ssl.SSLSocketImpl.isClosed(SSLSocketImpl.java:1462)
at java.net.Socket.getTcpNoDelay(Socket.java:953)
at sun.security.ssl.BaseSSLSocketImpl.getTcpNoDelay(BaseSSLSocketImpl.java:345)
at sun.security.ssl.SSLSocketImpl.writeRecordInternal(SSLSocketImpl.java:819)
at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:801)
at sun.security.ssl.AppOutputStream.write(AppOutputStream.java:122)
- locked <0x22b10880> (a sun.security.ssl.AppOutputStream)
at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
- locked <0x22b17d40> (a java.io.BufferedOutputStream)
at com.tridium.fox.message.MessageWriter.flush(MessageWriter.java:195)
at com.tridium.fox.session.FoxSession.writeFrame(FoxSession.java:846)
at com.tridium.fox.session.SessionSender.run(SessionSender.java:61)
at java.lang.Thread.run(Thread.java:722)
"Nre:Engine":
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x22b06190> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197)
at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:214)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:290)
at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:799)
at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:672)
at sun.security.ssl.SSLSocketImpl.sendAlert(SSLSocketImpl.java:2023)
at sun.security.ssl.SSLSocketImpl.warning(SSLSocketImpl.java:1850)
at sun.security.ssl.SSLSocketImpl.closeInternal(SSLSocketImpl.java:1618)
- locked <0x22b05f88> (a sun.security.ssl.SSLSocketImpl)
at sun.security.ssl.SSLSocketImpl.close(SSLSocketImpl.java:1554)
at com.tridium.crypto.core.io.CryptoCoreClientSocketFactory$NSSLSocket.close(CryptoCoreClientSocketFactory.java:353)
- locked <0x22b05f68> (a com.tridium.crypto.core.io.CryptoCoreClientSocketFactory$NSSLSocket)
at com.tridium.fox.session.FoxSession.close(FoxSession.java:226)
at com.tridium.fox.sys.BFoxConnection.close(BFoxConnection.java:256)
at com.tridium.fox.sys.BFoxClientConnection.doLingerTimeout(BFoxClientConnection.java:952)
- locked <0x18b109a0> (a java.util.HashMap)
at auto.com_tridium_fox_sys_BFoxClientConnection.invoke(AutoGenerated)
at com.tridium.sys.schema.ComponentSlotMap.invoke(ComponentSlotMap.java:1556)
at com.tridium.sys.schema.ComponentSlotMap.invoke(ComponentSlotMap.java:1521)
at javax.baja.sys.BComponent.invoke(BComponent.java:1098)
at com.tridium.sys.engine.EngineUtil.invoke(EngineUtil.java:29)
at com.tridium.sys.engine.NClockTicket.process(NClockTicket.java:116)
at com.tridium.sys.engine.TicketQueue.scan(TicketQueue.java:107)
at com.tridium.sys.engine.TicketQueue.check(TicketQueue.java:43)
at com.tridium.sys.engine.EngineManager.execute(EngineManager.java:205)
at com.tridium.sys.engine.EngineManager$EngineThread.run(EngineManager.java:691)

Found 1 deadlock.

Heap
PSYoungGen total 76352K, used 12792K [0x22ac0000, 0x27fe0000, 0x28010000)
eden space 65344K, 16% used [0x22ac0000,0x23572b58,0x26a90000)
from space 11008K, 16% used [0x26a90000,0x26c5b598,0x27550000)
to space 10816K, 0% used [0x27550000,0x27550000,0x27fe0000)
ParOldGen total 40000K, used 25250K [0x18010000, 0x1a720000, 0x22ac0000)
object space 40000K, 63% used [0x18010000,0x198b8918,0x1a720000)
PSPermGen total 27904K, used 16593K [0x10010000, 0x11b50000, 0x18010000)
object space 27904K, 59% used [0x10010000,0x11044610,0x11b50000)
  • 1. Re: SSLSocketImpl Deadlock with Jre 1.7.09
    EJP Guru
    Currently Being Moderated
    Your code appears to be be writing and closing the same socket simultaneously in two different threads. A very strange usage pattern.
  • 2. Re: SSLSocketImpl Deadlock with Jre 1.7.09
    852276 Newbie
    Currently Being Moderated
    Agreed. We are looking into re-factoring that. However, it still seems that the jre shouldn't deadlock. I can understand corrupt data or an exception being thrown, but it seems the same thing could happen if you have two threads: one for the input stream, one for the output stream. While one is writing, the other could close and the same scenario would occur.
  • 3. Re: SSLSocketImpl Deadlock with Jre 1.7.09
    EJP Guru
    Currently Being Moderated
    I agree it certainly shouldn't deadlock but either of the cases you describe is incorrect. SSL close requires sending and possibly receiving data and shouldn't be done during other I/O operations on the socket.
  • 4. Re: SSLSocketImpl Deadlock with Jre 1.7.09
    986365 Newbie
    Currently Being Moderated
    I googled our deadlock and it led me here. Don't know if it's the same problem though, we're running 1.7.09 and tomcat 7.0.34 using the apr connector (apr-1.4.6) (openssl-1.0.1c)

    Found one Java-level deadlock:
    =============================
    "http-apr-18102-exec-118":
    waiting to lock monitor 0x0000000001f26df8 (object 0x00000000e239c1c0, a sun.security.ssl.SSLSocketImpl),
    which is held by "Finalizer"
    "Finalizer":
    waiting for ownable synchronizer 0x00000000e239c6e8, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
    which is held by "http-apr-18102-exec-118"

    Java stack information for the threads listed above:
    ===================================================
    "http-apr-18102-exec-118":
    at sun.security.ssl.SSLSocketImpl.getConnectionState(SSLSocketImpl.java:649)
    - waiting to lock <0x00000000e239c1c0> (a sun.security.ssl.SSLSocketImpl)
    at sun.security.ssl.SSLSocketImpl.isClosed(SSLSocketImpl.java:1462)
    at java.net.Socket.getTcpNoDelay(Socket.java:953)
    at sun.security.ssl.BaseSSLSocketImpl.getTcpNoDelay(BaseSSLSocketImpl.java:345)
    at sun.security.ssl.SSLSocketImpl.writeRecordInternal(SSLSocketImpl.java:819)
    at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:801)
    at sun.security.ssl.AppOutputStream.write(AppOutputStream.java:122)
    - locked <0x00000000e23a3ca8> (a sun.security.ssl.AppOutputStream)
    at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
    at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
    - locked <0x00000000e23a3c90> (a java.io.BufferedOutputStream)
    at java.io.PrintStream.flush(PrintStream.java:338)
    - locked <0x00000000e23a3c70> (a java.io.PrintStream)
    at sun.net.www.http.HttpClient.writeRequests(HttpClient.java:549)
    at sun.net.www.http.HttpClient.writeRequests(HttpClient.java:556)
    at sun.net.www.protocol.http.HttpURLConnection.writeRequests(HttpURLConnection.java:619)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1320)
    - locked <0x00000000e2453938> (a sun.net.www.protocol.https.DelegateHttpsURLConnection)
    at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:468)
    at sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:338)
    at com.semantico.sgk.core.sams.SAMSCommunicatorImpl.logResponse(SAMSCommunicatorImpl.java:334)
    at com.semantico.sgk.core.sams.SAMSCommunicatorImpl.post(SAMSCommunicatorImpl.java:392)
    at com.semantico.sgk.core.sams.SAMSCommunicatorImpl.logAuthorisationFailure(SAMSCommunicatorImpl.java:279)
    at com.semantico.sgk.core.GatewayImpl.logAuthorisationFailure(GatewayImpl.java:179)
    at com.semantico.sgk.core.ClientImpl.logAuthorisationFailure(ClientImpl.java:279)
    at com.semantico.sgk.filters.authorization.AuthorizationFilter.logFailureWithSams(AuthorizationFilter.java:86)
    at com.semantico.sgk.filters.authorization.AuthorizationFilter.doPostFailure(AuthorizationFilter.java:64)
    at com.semantico.sgk.filters.HTTPFilter.doFilter(HTTPFilter.java:75)
    at com.semantico.sgk.filters.AbstractFilter.doFilter(AbstractFilter.java:60)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
    at com.semantico.sgk.filters.HTTPFilter.doFilter(HTTPFilter.java:58)
    at com.semantico.sgk.filters.AbstractFilter.doFilter(AbstractFilter.java:60)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
    at com.semantico.sgk.filters.HTTPFilter.doFilter(HTTPFilter.java:58)
    at com.semantico.sgk.filters.AbstractFilter.doFilter(AbstractFilter.java:60)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
    at com.semantico.sgk.filters.ExcludeFilter.doFilter(ExcludeFilter.java:61)
    at com.semantico.sgk.filters.AbstractFilter.doFilter(AbstractFilter.java:60)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
    at com.semantico.sgk.filters.LoggingFilter.doFilter(LoggingFilter.java:42)
    at com.semantico.sgk.filters.AbstractFilter.doFilter(AbstractFilter.java:60)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:936)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:407)
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1004)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:589)
    at org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:1780)
    - locked <0x00000000e22fb5f0> (a org.apache.tomcat.util.net.SocketWrapper)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
    at java.lang.Thread.run(Thread.java:722)

    "Finalizer":
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00000000e239c6e8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197)
    at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:214)
    at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:290)
    at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:799)
    at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:672)
    at sun.security.ssl.SSLSocketImpl.sendAlert(SSLSocketImpl.java:2023)
    at sun.security.ssl.SSLSocketImpl.warning(SSLSocketImpl.java:1850)
    at sun.security.ssl.SSLSocketImpl.closeInternal(SSLSocketImpl.java:1618)
    - locked <0x00000000e239c1c0> (a sun.security.ssl.SSLSocketImpl)
    at sun.security.ssl.SSLSocketImpl.close(SSLSocketImpl.java:1554)
    at sun.security.ssl.BaseSSLSocketImpl.finalize(BaseSSLSocketImpl.java:249)
    at java.lang.ref.Finalizer.invokeFinalizeMethod(Native Method)
    at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:101)
    at java.lang.ref.Finalizer.access$100(Finalizer.java:32)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:178)

    Found 1 deadlock.

    Heap
    PSYoungGen total 2368K, used 1600K [0x00000000f5560000, 0x00000000f58a0000, 0x0000000100000000)
    eden space 1600K, 100% used [0x00000000f5560000,0x00000000f56f0000,0x00000000f56f0000)
    from space 768K, 0% used [0x00000000f56f0000,0x00000000f56f0000,0x00000000f57b0000)
    to space 832K, 0% used [0x00000000f57d0000,0x00000000f57d0000,0x00000000f58a0000)
    ParOldGen total 349568K, used 349566K [0x00000000e0000000, 0x00000000f5560000, 0x00000000f5560000)
    object space 349568K, 99% used [0x00000000e0000000,0x00000000f555f8b0,0x00000000f5560000)
    PSPermGen total 25280K, used 25022K [0x00000000d8000000, 0x00000000d98b0000, 0x00000000e0000000)
    object space 25280K, 98% used [0x00000000d8000000,0x00000000d986fb88,0x00000000d98b0000)
  • 5. Re: SSLSocketImpl Deadlock with Jre 1.7.09
    986365 Newbie
    Currently Being Moderated
    Having googled some more I doubt that this is a Java bug, rather that when using the APR connector a socket timeout isn't happening, however when we use the BIO connector it is.

    My best guess, without testing yet is that as per http://tomcat.apache.org/tomcat-7.0-doc/config/http.html#SSL%20Support

    The BIO and NIO implementation support the following Java TCP socket attributes in addition to the common Connector and HTTP attributes listed above.

    socket.soTimeout     
    This is equivalent to standard attribute connectionTimeout.

    And this is passed down to the HttpClient class to set a timeout.
  • 6. Re: SSLSocketImpl Deadlock with Jre 1.7.09
    994688 Newbie
    Currently Being Moderated
    We are seeing fairly frequent deadlocks when systems are under load. The deadlocks (so far) have always happened when the socket is being torn down due to some error. That is, the application is not explicitly closing the connection, but rather is being closed by SSLSocketImpl due to some detected error. Here's the simplest stack trace I've seen so far:

    0226/17:58:10.571/INFO 0:Found one Java-level deadlock:
    0226/17:58:10.571/INFO 0:=============================
    0226/17:58:10.571/INFO 0:"pool-1-thread-1":
    0226/17:58:10.571/INFO 0: waiting to lock monitor 0x00007f6d60003818 (object 0x0000000789b18e78, a java.lang.Object),
    0226/17:58:10.571/INFO 0: which is held by "JJSMessage.Sender:0x7ae31a19 (0x58e7a27a): long-ms2/172.30.3.104:7483 c51d0993-12a2-4e93-a064-726a0023caca->MNM"
    0226/17:58:10.571/INFO 0:"JJSMessage.Sender:0x7ae31a19 (0x58e7a27a): long-ms2/172.30.3.104:7483 c51d0993-12a2-4e93-a064-726a0023caca->MNM":
    0226/17:58:10.571/INFO 0: waiting to lock monitor 0x00007f6dd8960550 (object 0x000000078c9cedf0, a sun.security.ssl.SSLSocketImpl),
    0226/17:58:10.571/INFO 0: which is held by "Socket reader for: /172.30.3.104:7483"
    0226/17:58:10.572/INFO 0:"Socket reader for: /172.30.3.104:7483":
    0226/17:58:10.572/INFO 0: waiting for ownable synchronizer 0x000000078c9cf028, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
    0226/17:58:10.572/INFO 0: which is held by "JJSMessage.Sender:0x7ae31a19 (0x58e7a27a): long-ms2/172.30.3.104:7483 c51d0993-12a2-4e93-a064-726a0023caca->MNM"
    0226/17:58:10.572/INFO 0:
    0226/17:58:10.572/INFO 0:Java stack information for the threads listed above:
    0226/17:58:10.572/INFO 0:===================================================
    0226/17:58:10.572/INFO 0:"pool-1-thread-1":
    0226/17:58:10.572/INFO 0: at nac.jjs.Connection.testLocks(Connection.java:1321)
    0226/17:58:10.572/INFO 0: - waiting to lock <0x0000000789b18e78> (a java.lang.Object)
    0226/17:58:10.572/INFO 0: at nac.services.clustermanager.NodeConnectionManager.testLocks(NodeConnectionManager.java:280)
    0226/17:58:10.572/INFO 0: at ESMain$WatchdogStatusProvider.returnStatus(ESMain.java:647)
    0226/17:58:10.572/INFO 0: at nac.common.util.WatchdogHeartbeatServer$HBServer.run(WatchdogHeartbeatServer.java:203)
    0226/17:58:10.572/INFO 0: at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
    0226/17:58:10.572/INFO 0: at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
    0226/17:58:10.572/INFO 0: at java.util.concurrent.FutureTask.run(FutureTask.java:166)
    0226/17:58:10.572/INFO 0: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    0226/17:58:10.572/INFO 0: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    0226/17:58:10.572/INFO 0: at java.lang.Thread.run(Thread.java:722)
    0226/17:58:10.572/INFO 0:"JJSMessage.Sender:0x7ae31a19 (0x58e7a27a): long-ms2/172.30.3.104:7483 c51d0993-12a2-4e93-a064-726a0023caca->MNM":
    0226/17:58:10.572/INFO 0: at sun.security.ssl.SSLSocketImpl.getConnectionState(SSLSocketImpl.java:649)
    0226/17:58:10.572/INFO 0: - waiting to lock <0x000000078c9cedf0> (a sun.security.ssl.SSLSocketImpl)
    0226/17:58:10.572/INFO 0: at sun.security.ssl.SSLSocketImpl.isClosed(SSLSocketImpl.java:1446)
    0226/17:58:10.572/INFO 0: at java.net.Socket.getTcpNoDelay(Socket.java:953)
    0226/17:58:10.572/INFO 0: at sun.security.ssl.BaseSSLSocketImpl.getTcpNoDelay(BaseSSLSocketImpl.java:345)
    0226/17:58:10.572/INFO 0: at sun.security.ssl.SSLSocketImpl.writeRecordInternal(SSLSocketImpl.java:819)
    0226/17:58:10.573/INFO 0: at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:801)
    0226/17:58:10.573/INFO 0: at sun.security.ssl.AppOutputStream.write(AppOutputStream.java:122)
    0226/17:58:10.573/INFO 0: - locked <0x000000078c9d3ce0> (a sun.security.ssl.AppOutputStream)
    0226/17:58:10.573/INFO 0: at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
    0226/17:58:10.573/INFO 0: at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
    0226/17:58:10.573/INFO 0: - locked <0x000000078c9dcd20> (a java.io.BufferedOutputStream)
    0226/17:58:10.573/INFO 0: at java.io.ObjectOutputStream$BlockDataOutputStream.flush(ObjectOutputStream.java:1803)
    0226/17:58:10.573/INFO 0: at java.io.ObjectOutputStream.flush(ObjectOutputStream.java:715)
    0226/17:58:10.573/INFO 0: at nac.jjs.Connection.sendObject(Connection.java:1404)
    0226/17:58:10.573/INFO 0: - locked <0x0000000789b18e78> (a java.lang.Object)
    0226/17:58:10.573/INFO 0: at nac.jjs.Connection.send(Connection.java:1316)
    0226/17:58:10.573/INFO 0: at nac.jjs.JJSPacket.send(JJSPacket.java:124)
    0226/17:58:10.573/INFO 0: at nac.jjs.JJSMessage$Sender.run(JJSMessage.java:345)
    0226/17:58:10.573/INFO 0: at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
    0226/17:58:10.573/INFO 0: at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
    0226/17:58:10.573/INFO 0: at java.util.concurrent.FutureTask.run(FutureTask.java:166)
    0226/17:58:10.573/INFO 0: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    0226/17:58:10.573/INFO 0: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    0226/17:58:10.573/INFO 0: at java.lang.Thread.run(Thread.java:722)
    0226/17:58:10.573/INFO 0:"Socket reader for: /172.30.3.104:7483":
    0226/17:58:10.573/INFO 0: at sun.misc.Unsafe.park(Native Method)
    0226/17:58:10.573/INFO 0: - parking to wait for <0x000000078c9cf028> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
    0226/17:58:10.573/INFO 0: at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
    0226/17:58:10.573/INFO 0: at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
    0226/17:58:10.573/INFO 0: at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867)
    0226/17:58:10.574/INFO 0: at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197)
    0226/17:58:10.574/INFO 0: at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:214)
    0226/17:58:10.574/INFO 0: at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:290)
    0226/17:58:10.574/INFO 0: at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:799)
    0226/17:58:10.574/INFO 0: at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:672)
    0226/17:58:10.574/INFO 0: at sun.security.ssl.SSLSocketImpl.sendAlert(SSLSocketImpl.java:2007)
    0226/17:58:10.574/INFO 0: at sun.security.ssl.SSLSocketImpl.fatal(SSLSocketImpl.java:1881)
    0226/17:58:10.574/INFO 0: - locked <0x000000078c9cedf0> (a sun.security.ssl.SSLSocketImpl)
    0226/17:58:10.574/INFO 0: at sun.security.ssl.SSLSocketImpl.fatal(SSLSocketImpl.java:1844)
    0226/17:58:10.574/INFO 0: - locked <0x000000078c9cedf0> (a sun.security.ssl.SSLSocketImpl)
    0226/17:58:10.574/INFO 0: at sun.security.ssl.SSLSocketImpl.handleException(SSLSocketImpl.java:1808)
    0226/17:58:10.574/INFO 0: - locked <0x000000078c9cedf0> (a sun.security.ssl.SSLSocketImpl)
    0226/17:58:10.574/INFO 0: at sun.security.ssl.SSLSocketImpl.handleException(SSLSocketImpl.java:1753)
    0226/17:58:10.574/INFO 0: at sun.security.ssl.AppInputStream.read(AppInputStream.java:113)
    0226/17:58:10.574/INFO 0: - locked <0x000000078c9cf930> (a sun.security.ssl.AppInputStream)
    0226/17:58:10.574/INFO 0: at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
    0226/17:58:10.574/INFO 0: at java.io.BufferedInputStream.read(BufferedInputStream.java:254)
    0226/17:58:10.574/INFO 0: - locked <0x000000078c9d44d0> (a java.io.BufferedInputStream)
    0226/17:58:10.574/INFO 0: at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2272)
    0226/17:58:10.574/INFO 0: at java.io.ObjectInputStream$BlockDataInputStream.peek(ObjectInputStream.java:2565)
    0226/17:58:10.574/INFO 0: at java.io.ObjectInputStream$BlockDataInputStream.peekByte(ObjectInputStream.java:2575)
    0226/17:58:10.574/INFO 0: at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1315)
    0226/17:58:10.574/INFO 0: at java.io.ObjectInputStream.readUnshared(ObjectInputStream.java:459)
    0226/17:58:10.574/INFO 0: at nac.jjs.Connection.run(Connection.java:910)
    0226/17:58:10.574/INFO 0: at java.lang.Thread.run(Thread.java:722)
    0226/17:58:10.575/INFO 0:
    0226/17:58:10.575/INFO 0:Found 1 deadlock.

    The problem/bug is that the locks, a synchronization on SSLSocketImpl (0x000000078c9cedf0) and a lock() call on the ReentrantLock (0x000000078c9cf028) are not being obtained in the same order, resulting in the deadlock. I do not know why an error is being detected in the network stream, but this deadlock is something that was definitely introduced in jdk 7. We're running the latest version: "1.7.0_15" on 64 bit CentOS 6.3 systems.
  • 7. Re: SSLSocketImpl Deadlock with Jre 1.7.09
    1005722 Newbie
    Currently Being Moderated
    Have just encountered the same deadlock issue.
    After investigating the source code of SSLSocketImpl:
    http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/7-b147/sun/security/ssl/SSLSocketImpl.java#SSLSocketImpl
    it seems that I found a workaround for the problem.

    Let's first look on the source code. Deadlock occurs in the void writeRecord(OutputRecord r) method when we get Alerts.alert_close_notify alert while reading input stream:
    if (r.isAlert(Alerts.alert_close_notify) && getSoLinger() >= 0) {
    ....................
    if (writeLock.tryLock(getSoLinger(), TimeUnit.SECONDS)) {
    try {
    writeRecordInternal(r);
    } finally {
    writeLock.unlock();
    }
    ....................
    } else {
    writeLock.lock();
    try {
    writeRecordInternal(r);
    } finally {
    writeLock.unlock();
    }
    }
    And yeah, it happens when we get into to the second branch.

    So, my suggested workaround is to set SO_LINGER timeout for the socket:
    socket.setSoLinger(true, SO_LINGER_TIMEOUT_SECONDS);
    In this case thread will fail to obtain write lock in the specified timeout, invalidate session and then, finally, it will release another 3(!!!) locks it already holds.

    Hope this helps!
  • 8. Re: SSLSocketImpl Deadlock with Jre 1.7.09
    PhHein Guru Moderator
    Currently Being Moderated
    Thanks for the workaround. I'm locking this thread now to prevent more me too posts.
  • 9. Re: SSLSocketImpl Deadlock with Jre 1.7.09
    EJP Guru
    Currently Being Moderated
    How will it help exactly? If It doesn't get the lock within the timeout it will retry to get the lock with an infinite timeout.

    The real question here is what exactly did the JSSE authors think the SO_LINGER timeout had to do with write locks?

    @PHhein Unlocked it. This was hardly a 'me too' post.
  • 10. Re: SSLSocketImpl Deadlock with Jre 1.7.09
    PhHein Guru Moderator
    Currently Being Moderated
    EJP wrote:
    @PHhein Unlocked it. This was hardly a 'me too' post.
    No problem, fine for me.
  • 11. Re: SSLSocketImpl Deadlock with Jre 1.7.09
    1005722 Newbie
    Currently Being Moderated
    EJP wrote:
    How will it help exactly? If It doesn't get the lock within the timeout it will retry to get the lock with an infinite timeout.
    No-no, it will either lock with timeout if (r.isAlert(Alerts.alert_close_notify) && getSoLinger() >= 0) or lock infinitely otherwise.
    It's probably hard to see in because of lack of code formatting (unfortunately, it's not possible to post code here!). It's better to have a look at the full source code at codegrep.
  • 12. Re: SSLSocketImpl Deadlock with Jre 1.7.09
    PhHein Guru Moderator
    Currently Being Moderated
    WTF? {noformat}
    code here 
    {noformat}
    String hi ="HI!";
  • 13. Re: SSLSocketImpl Deadlock with Jre 1.7.09
    gimbal2 Guru
    Currently Being Moderated
    1002719 wrote:
    (unfortunately, it's not possible to post code here!).
    It is when you read read the announcements before posting. Use \
     tags.
    if (r.isAlert(Alerts.alert_close_notify) && getSoLinger() >= 0) {
    ....................
    if (writeLock.tryLock(getSoLinger(), TimeUnit.SECONDS)) {
    try {
    writeRecordInternal(r);
    } finally {
    writeLock.unlock();
    }
    ....................
    } else {
    writeLock.lock();
    try {
    writeRecordInternal(r);
    } finally {
    writeLock.unlock();
    }
    }
                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
  • 14. Re: SSLSocketImpl Deadlock with Jre 1.7.09
    1005722 Newbie
    Currently Being Moderated
    Wow, strange it's not on the text editor panel. Neither is it shown at the Plain Text Help sidebar. It's rather counter intuitive to search for it in FAQ :)

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points