Hey folks,
Apologies for the slightly off-topic post, since this isn't performance
related, but I hope I'll be excused since this might be interesting to the
group members.
We're recently facing an issue where a JVM is deadlocking in some SSL code.
The resulting jstack report is bizarre -- in the deadlock analysis section
it indicates that one of the locks is held by some thread, but in that
thread's stack, it doesn't show the lock anywhere. Was curious if anyone
had any ideas on how a lock might be "held but not held".
jstack output is as follows (with other threads and irrelevant bottom stack
frames removed):
Found one Java-level deadlock:
=============================
"Thread-38190":
waiting to lock monitor 0x00000000267f2628 (object 0x00000000802ba7f8, a
sun.security.provider.Sun),
which is held by "New I/O worker #1810850"
"New I/O worker #1810850":
waiting to lock monitor 0x000000007482f5f8 (object 0x0000000080ac88f0, a
java.lang.Class),
which is held by "New I/O worker #1810853"
"New I/O worker #1810853":
waiting to lock monitor 0x00000000267f2628 (object 0x00000000802ba7f8, a
sun.security.provider.Sun),
which is held by "New I/O worker #1810850"
Java stack information for the threads listed above:
===================================================
"Thread-38190":
at java.security.Provider.getService(Provider.java:1035)
- waiting to lock <0x00000000802ba7f8> (a sun.security.provider.Sun)
at sun.security.jca.ProviderList.getService(ProviderList.java:332)
at sun.security.jca.GetInstance.getInstance(GetInstance.java:157)
at javax.net.ssl.SSLContext.getInstance(SSLContext.java:156)
at
org.apache.kudu.client.SecurityContext.<init>(SecurityContext.java:84)
...
"New I/O worker #1810850":
at
sun.security.ssl.CipherSuite$BulkCipher.isAvailable(CipherSuite.java:542)
- waiting to lock <0x0000000080ac88f0> (a java.lang.Class for
sun.security.ssl.CipherSuite$BulkCipher)
at
sun.security.ssl.CipherSuite$BulkCipher.isAvailable(CipherSuite.java:527)
at sun.security.ssl.CipherSuite.isAvailable(CipherSuite.java:194)
at
sun.security.ssl.Handshaker.getActiveProtocols(Handshaker.java:712)
at sun.security.ssl.Handshaker.activate(Handshaker.java:498)
at
sun.security.ssl.SSLEngineImpl.kickstartHandshake(SSLEngineImpl.java:729)
- locked <0x000000008eca76f8> (a sun.security.ssl.SSLEngineImpl)
at
sun.security.ssl.SSLEngineImpl.beginHandshake(SSLEngineImpl.java:756)
at
org.apache.kudu.client.shaded.org.jboss.netty.handler.ssl.SslHandler.handshake(SslHandler.java:361)
- locked <0x000000008eca8298> (a java.lang.Object)
at
org.apache.kudu.client.Negotiator.startTlsHandshake(Negotiator.java:432)
...
"New I/O worker #1810853":
at java.security.Provider.getService(Provider.java:1035)
- waiting to lock <0x00000000802ba7f8> (a sun.security.provider.Sun)
at
sun.security.jca.ProviderList$ServiceList.tryGet(ProviderList.java:444)
at
sun.security.jca.ProviderList$ServiceList.access$200(ProviderList.java:376)
at
sun.security.jca.ProviderList$ServiceList$1.hasNext(ProviderList.java:486)
at javax.crypto.Cipher.getInstance(Cipher.java:513)
at sun.security.ssl.JsseJce.getCipher(JsseJce.java:229)
at sun.security.ssl.CipherBox.<init>(CipherBox.java:179)
at sun.security.ssl.CipherBox.newCipherBox(CipherBox.java:263)
at
sun.security.ssl.CipherSuite$BulkCipher.newCipher(CipherSuite.java:505)
at
sun.security.ssl.CipherSuite$BulkCipher.isAvailable(CipherSuite.java:572)
- locked <0x0000000080ac88f0> (a java.lang.Class for
sun.security.ssl.CipherSuite$BulkCipher)
at
sun.security.ssl.CipherSuite$BulkCipher.isAvailable(CipherSuite.java:527)
at sun.security.ssl.CipherSuite.isAvailable(CipherSuite.java:194)
at
sun.security.ssl.SSLContextImpl.getApplicableCipherSuiteList(SSLContextImpl.java:346)
at
sun.security.ssl.SSLContextImpl.getDefaultCipherSuiteList(SSLContextImpl.java:297)
- locked <0x000000008ebd1880> (a
sun.security.ssl.SSLContextImpl$TLSContext)
at sun.security.ssl.SSLEngineImpl.init(SSLEngineImpl.java:402)
at sun.security.ssl.SSLEngineImpl.<init>(SSLEngineImpl.java:349)
at
sun.security.ssl.SSLContextImpl.engineCreateSSLEngine(SSLContextImpl.java:201)
at javax.net.ssl.SSLContext.createSSLEngine(SSLContext.java:329)
...
Note that multiple threads are waiting on "0x00000000802ba7f8, a
sun.security.provider.Sun" but no thread is listed as holding this in its
stacks.
The additional thread info from higher up in the jstack is:
"Thread-38190" #2454575 prio=5 os_prio=0 tid=0x0000000040fff000 nid=0x8b12
waiting for monitor entry [0x00007ff9a129e000]
"New I/O worker #1810850" #2448031 daemon prio=5 os_prio=0
tid=0x00007ff87df00000 nid=0x42bf waiting for monitor entry
[0x00007ff918a61000]
"New I/O worker #1810853" #2448034 daemon prio=5 os_prio=0
tid=0x00007ff87df02800 nid=0x42c4 waiting for monitor entry
[0x00007ff911654000]
Native frames look like normal lock acquisition:
0x00007ffa4e6546d5 __pthread_cond_wait + 0xc5
0x00007ffa50516f7d _ZN13ObjectMonitor6EnterIEP6Thread + 0x31d
0x00007ffa50518f11 _ZN13ObjectMonitor5enterEP6Thread + 0x301
0x00007ffa505cc8ff
_ZN13SharedRuntime26complete_monitor_locking_CEP7oopDescP9BasicLockP10JavaThread
+ 0x9f
Other relevant info:
- JVM: Java HotSpot(TM) 64-Bit Server VM (25.102-b14 mixed mode)
(jdk1.8.0_102)
- OS: RHEL 7.2 (kernel 3.10.0-327.36.2.el7.x86_64) [not that infamous
futex bug]
- libc version: glibc-2.17-157.el7.x86_64
- nothing interesting in dmesg
- this app actually is a native application which embeds a JVM using JNI,
if that makes a difference.
Anyone else seen issues like this with relatively recent Java 8? Or any
ideas on next steps to debug the phantom lock holder?
-Todd
--
You received this message because you are subscribed to the Google Groups
"mechanical-sympathy" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
For more options, visit https://groups.google.com/d/optout.
