Deadlock in SSLSocket locks Finalizer

[Xuelei Fan]

Does it happen in JDK 6 and previous releases?  In JDK 6 and previous
release, Oracle JSSE provider in server side may check the usability of
ciphers and then generate dummy sockets.  JDK 7 changed the behaviors.

BTW, I experienced a few cases that application may cleanup SSLSocket in
a fixed period no matter the status of the sockets, as may also kick off
SSLSocket finalizer.

Xuelei

On 9/20/2013 6:22 PM, Dmitry Neverov wrote:
> Hi,
> 
> we have a strange problem with ssl sockets. I didn't find anything
> similar in the bug tracker. I've posted a bug twice, but have never got
> back. Maybe someone can help.
> 
> We see an example of the deadlock described in
> http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=8013809. The strange
> thing is that one of the locked threads is a Finalizer and the other one
> is an application thread. It seems like the socket used by an
> application is being finalized:
> 
> 
> "Finalizer" daemon group="system" prio=8 tid=3 nid=3 waiting on java.util.concurrent.locks.ReentrantLock$NonfairSync at 188a1f7
>    by "TC: 17:37:45 getCurrentState: "CMLS Root" {instance id=321, parent internal id=321, parent id=CMLS_Root, description: "https://gitblit.cid-dev.net/gitblit-0.9.2/git/CMLS/CMLS.Classifiers.NaiveBayes.git#master-2"}; 17:37:45 Loading VCS changes for "CMLS Root" {instance id=321, parent internal id=321, parent id=CMLS_Root, description: "https://gitblit.cid-dev.net/gitblit-0.9.2/git/CMLS/CMLS.Classifiers.NaiveBayes.git#master-2"}; VCS Periodical executor 6"
>    java.lang.Thread.State: WAITING
>     at sun.misc.Unsafe.park(Native Method)
>     at java.util.concurrent.locks.LockSupport.park(Unknown Source)
>     at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(Unknown Source)
>     at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Unknown Source)
>     at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(Unknown Source)
>     at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(Unknown Source)
>     at java.util.concurrent.locks.ReentrantLock.lock(Unknown Source)
>     at sun.security.ssl.SSLSocketImpl.writeRecord(Unknown Source)
>     at sun.security.ssl.SSLSocketImpl.writeRecord(Unknown Source)
>     at sun.security.ssl.SSLSocketImpl.sendAlert(Unknown Source)
>     at sun.security.ssl.SSLSocketImpl.warning(Unknown Source)
>     at sun.security.ssl.SSLSocketImpl.closeInternal(Unknown Source)
>     at sun.security.ssl.SSLSocketImpl.close(Unknown Source)
>     at sun.security.ssl.BaseSSLSocketImpl.finalize(Unknown Source)
>     at java.lang.ref.Finalizer.invokeFinalizeMethod(Native Method)
>     at java.lang.ref.Finalizer.runFinalizer(Unknown Source)
>     at java.lang.ref.Finalizer.access$100(Unknown Source)
>     at java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source)
> 
> 
> "TC: 17:37:45 getCurrentState: "CMLS Root" {instance id=321, parent internal id=321, parent id=CMLS_Root, description: "https://gitblit.cid-dev.net/gitblit-0.9.2/git/CMLS/CMLS.Classifiers.NaiveBayes.git#master-2"}; 17:37:45 Loading VCS changes for "CMLS Root" {instance id=321, parent internal id=321, parent id=CMLS_Root, description: "https://gitblit.cid-dev.net/gitblit-0.9.2/git/CMLS/CMLS.Classifiers.NaiveBayes.git#master-2"}; VCS Periodical executor 6" group="main" prio=5 tid=104 nid=104 blocked on sun.security.ssl.SSLSocketImpl at eb5db2
>    by "Finalizer"
>    java.lang.Thread.State: BLOCKED
>     at sun.security.ssl.SSLSocketImpl.getConnectionState(Unknown Source)
>     at sun.security.ssl.SSLSocketImpl.isClosed(Unknown Source)
>     at java.net.Socket.getTcpNoDelay(Unknown Source)
>     at sun.security.ssl.BaseSSLSocketImpl.getTcpNoDelay(Unknown Source)
>     at sun.security.ssl.SSLSocketImpl.writeRecordInternal(Unknown Source)
>     at sun.security.ssl.SSLSocketImpl.writeRecord(Unknown Source)
>     at sun.security.ssl.AppOutputStream.write(Unknown Source)
>     at java.io.BufferedOutputStream.flushBuffer(Unknown Source)
>     at java.io.BufferedOutputStream.flush(Unknown Source)
>     at java.io.PrintStream.flush(Unknown Source)
>     at sun.net.www.MessageHeader.print(Unknown Source)
>     at sun.net.www.http.HttpClient.writeRequests(Unknown Source)
>     at sun.net.www.http.HttpClient.writeRequests(Unknown Source)
>     at sun.net.www.protocol.http.HttpURLConnection.writeRequests(Unknown Source)
>     at sun.net.www.protocol.http.HttpURLConnection.getInputStream(Unknown Source)
>     at java.net.HttpURLConnection.getResponseCode(Unknown Source)
>     at sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(Unknown Source)
>     at org.eclipse.jgit.util.HttpSupport.response(HttpSupport.java:167)
>     at org.eclipse.jgit.transport.TransportHttp.connect(TransportHttp.java:459)
>     at org.eclipse.jgit.transport.TransportHttp.openFetch(TransportHttp.java:305)
>     at jetbrains.buildServer.buildTriggers.vcs.git.GitVcsSupport.getRemoteRefs(GitVcsSupport.java:472)
>     at jetbrains.buildServer.buildTriggers.vcs.git.GitVcsSupport.getRemoteRefs(GitVcsSupport.java:454)
>     at jetbrains.buildServer.buildTriggers.vcs.git.GitVcsSupport.getCurrentState(GitVcsSupport.java:125)
>     at jetbrains.buildServer.buildTriggers.vcs.git.GitCollectChangesPolicy.getCurrentState(GitCollectChangesPolicy.java:176)
>     at jetbrains.vcs.api.services.impl.RepositoryStateServiceProvider$1.getCurrentState(RepositoryStateServiceProvider.java:9)
>     at jetbrains.buildServer.vcs.impl.VcsRootInstanceImpl.getCurrentState(VcsRootInstanceImpl.java:117)
>     at jetbrains.buildServer.vcs.impl.VcsChangesLoaderImpl.getCurrentState(VcsChangesLoaderImpl.java:21)
>     at jetbrains.buildServer.vcs.impl.VcsChangesLoaderImpl.access$200(VcsChangesLoaderImpl.java:290)
>     at jetbrains.buildServer.vcs.impl.VcsChangesLoaderImpl$6.run(VcsChangesLoaderImpl.java:8)
>     at jetbrains.buildServer.util.NamedThreadFactory.executeWithNewThreadName(NamedThreadFactory.java:103)
>     at jetbrains.buildServer.vcs.impl.VcsChangesLoaderImpl.doCollectStates(VcsChangesLoaderImpl.java:54)
>     at jetbrains.buildServer.vcs.impl.VcsChangesLoaderImpl.collectStatesForAllRoots(VcsChangesLoaderImpl.java:220)
>     at jetbrains.buildServer.vcs.impl.VcsChangesLoaderImpl.getLoadChangesIntervals(VcsChangesLoaderImpl.java:7)
>     at jetbrains.buildServer.vcs.impl.VcsChangesLoaderImpl.loadChangesNoLocking(VcsChangesLoaderImpl.java:288)
>     at jetbrains.buildServer.vcs.impl.VcsChangesLoaderImpl.tryLoadChanges(VcsChangesLoaderImpl.java:33)
>     at jetbrains.buildServer.serverSide.impl.VcsModificationChecker$1$1.run(VcsModificationChecker.java:12)
>     at jetbrains.buildServer.util.NamedThreadFactory.executeWithNewThreadName(NamedThreadFactory.java:103)
>     at jetbrains.buildServer.serverSide.impl.VcsModificationChecker$1.run(VcsModificationChecker.java:3)
>     at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
>     at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
>     at java.util.concurrent.FutureTask.run(Unknown Source)
>     at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
>     at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
>     at java.lang.Thread.run(Unknown Source)
> 
> Has anyone seen something like this? The problem reproduces every 1-3
> hours with jdk 1.7.0_21 and once a day with jdk 1.7.0_40. I know that
> deadlock has been fixed, but isn't it strange that live Socket is
> finalized?
> 
> --
> Dmitry Neverov
> JetBrains
> http://www.jetbrains.com
> "Develop with pleasure!"
>