On 4/01/2018 12:26 PM, Vitaly Davidovich wrote:
On Wed, Jan 3, 2018 at 8:36 PM David Holmes <david.hol...@oracle.com
<mailto:david.hol...@oracle.com>> wrote:
On 4/01/2018 3:13 AM, Vitaly Davidovich wrote:
> On Wed, Jan 3, 2018 at 12:00 PM, Alan Bateman
<alan.bate...@oracle.com <mailto:alan.bate...@oracle.com>>
> wrote:
>
>> The stack trace looks like JDK 8 or older. The initialization
has changed
>> quite a bit in JDK 9+ and would be interesting to see if you can
duplicate
>> it there.
>>
> Yes - it's 8u152 as I mentioned in the follow-up email (sorry,
should've
> mentioned that initially).
>
> Trying this on JDK9 is a bit tricky as the code (and its
dependencies) in
> question isn't easily runnable on 9 without quite a bit of work.
>
> Do you agree with the deadlock assessment though? That's what it
looks like
> to me but wanted to make sure I'm not missing anything.
You're not missing anything. It's a class initialization related
"deadlock".
Thread A has called FileSystems.getDefault() which is doing <clinit> of
DefaultFileSystemHolder, which in turn leads to Runtime.loadLibrary0
which needs to lock the Runtime instance.
Thread B is already doing a loadLibrary and holds the Runtime lock, the
loadLibrary code then needs to do FileSystems.getDefault() which has to
load and initialize DefaultFileSystemHolder, but that initialization is
already in progress so internally the thread does a wait().
So Thread B is waiting for Thread A to finish initialization, but holds
the monitor lock that Thread A needs to finish the initialization.
Deadlock.
AFAICS this will still be possible in 9/10/11
That’s what I thought - thanks for confirming David. I’m slightly
surprised this hasn’t been reported before, although perhaps I’ve failed
in finding the report.
I couldn't find anything either. Although it seems "obvious" upon
analysis it may be very rare to have such an initialization race.
Does this deserve a bug report? I know Hotspot and some core classes in
the JDK do an elaborate dance to avoid classloading issues, but this is
“user” code. This has been worked around on our end by forcing the
default FS to load before this code runs. Perhaps something similar can
be done as the JDK bootstraps.
Definitely worth a bug report. Not sure what we can do on the JDK side
as I'm unclear whether the default filesystem necessarily gets
initialized after the module system is up.
Cheers,
David
Cheers,
David
> Thanks Alan
>
>>
>> -Alan
>>
>>
>> On 03/01/2018 16:56, Vitaly Davidovich wrote:
>>
>>> Hi all,
>>>
>>> Consider the following stacktraces of the main app thread and a
background
>>> thread:
>>>
>>> "main" #1 prio=5 os_prio=0 tid=0x0000000001bfd000 nid=0x1958
waiting for
>>> monitor entry [0x00002b98ceba3000]
>>>
>>> java.lang.Thread.State: BLOCKED (on object monitor)
>>>
>>> at
java.lang.Runtime.loadLibrary0(Runtime.java:862)
>>>
>>> - waiting to lock <0x00000007bf834b20> (a
>>> java.lang.Runtime)
>>>
>>> at java.lang.System.loadLibrary(System.java:1122)
>>>
>>> at sun.nio.fs.UnixNativeDispatcher$1.run(
>>> UnixNativeDispatcher.java:573)
>>>
>>> at sun.nio.fs.UnixNativeDispatcher$1.run(
>>> UnixNativeDispatcher.java:571)
>>>
>>> at
java.security.AccessController.doPrivileged(Native
>>> Method)
>>>
>>> at sun.nio.fs.UnixNativeDispatcher.<clinit>(
>>> UnixNativeDispatcher.java:571)
>>>
>>> at sun.nio.fs.UnixFileSystem.<ini
>>> t>(UnixFileSystem.java:67)
>>>
>>> at sun.nio.fs.LinuxFileSystem.<
>>> init>(LinuxFileSystem.java:39)
>>>
>>> at
sun.nio.fs.LinuxFileSystemProvider.newFileSystem(
>>> LinuxFileSystemProvider.java:46)
>>>
>>> at
sun.nio.fs.LinuxFileSystemProvider.newFileSystem(
>>> LinuxFileSystemProvider.java:39)
>>>
>>> at sun.nio.fs.UnixFileSystemProvider.<init>(
>>> UnixFileSystemProvider.java:56)
>>>
>>> at sun.nio.fs.LinuxFileSystemProvider.<init>
>>> (LinuxFileSystemProvider.java:41)
>>>
>>> at
>>> sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
>>> Method)
>>>
>>> at sun.reflect.NativeConstructorA
>>> ccessorImpl.newInstance(
>>> NativeConstructorAccessorImpl.java:62)
>>>
>>> at sun.reflect.DelegatingConstructorAccessorI
>>> mpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
>>>
>>> at java.lang.reflect.Constructor.
>>> newInstance(Constructor.java:423)
>>>
>>> at java.lang.Class.newInstance(Class.java:442)
>>>
>>> at
sun.nio.fs.DefaultFileSystemProvider.createProvider(
>>> DefaultFileSystemProvider.java:48)
>>>
>>> at sun.nio.fs.DefaultFileSystemProvider.create(
>>> DefaultFileSystemProvider.java:63)
>>>
>>> at
java.nio.file.FileSystems$DefaultFileSystemHolder.
>>> getDefaultProvider(FileSystems.java:108)
>>>
>>> at
java.nio.file.FileSystems$DefaultFileSystemHolder.
>>> access$000(FileSystems.java:89)
>>>
>>> at java.nio.file.FileSystems$Defa
>>> ultFileSystemHolder$1.run(
>>> FileSystems.java:98)
>>>
>>> at java.nio.file.FileSystems$Defa
>>> ultFileSystemHolder$1.run(
>>> FileSystems.java:96)
>>>
>>> at
java.security.AccessController.doPrivileged(Native
>>> Method)
>>>
>>> at
java.nio.file.FileSystems$DefaultFileSystemHolder.
>>> defaultFileSystem(FileSystems.java:96)
>>>
>>> at
java.nio.file.FileSystems$DefaultFileSystemHolder.<
>>> clinit>(FileSystems.java:90)
>>>
>>> at java.nio.file.FileSystems.getD
>>> efault(FileSystems.java:
>>> 176)
>>>
>>> at java.nio.file.Paths.get(Paths.java:84)
>>>
>>> at <some_package>.ServiceLoader.
>>> setup(ServiceLoader.java:446)
>>>
>>> at <some_package>.MetadataAdminLoader.main(
>>> MetadataAdminLoader.java:52)
>>>
>>>
>>>
>>>
>>>
>>> "shardDbExecutor-0-pool-0" #33 prio=5 os_prio=0
tid=0x0000000001ebf000
>>> nid=0x1d01 in Object.wait() [0x00002b991f941000]
>>>
>>> java.lang.Thread.State: RUNNABLE
>>>
>>> at java.nio.file.FileSystems.getD
>>> efault(FileSystems.java:
>>> 176)
>>>
>>> at java.nio.file.Paths.get(Paths.java:138)
>>>
>>> at sun.misc.Launcher$ExtClassLoader.findLibrary(
>>> Launcher.java:224)
>>>
>>> at java.lang.ClassLoader.loadLibr
>>> ary(ClassLoader.java:1830)
>>>
>>> at
java.lang.Runtime.loadLibrary0(Runtime.java:870)
>>>
>>> - locked <0x00000007bf834b20> (a
java.lang.Runtime)
>>>
>>> at java.lang.System.loadLibrary(System.java:1122)
>>>
>>> at sun.security.ec.SunEC$1.run(SunEC.java:60)
>>>
>>> at sun.security.ec.SunEC$1.run(SunEC.java:58)
>>>
>>> at
java.security.AccessController.doPrivileged(Native
>>> Method)
>>>
>>> at sun.security.ec.SunEC.<clinit>(SunEC.java:58)
>>>
>>> at
>>> sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
>>> Method)
>>>
>>> at sun.reflect.NativeConstructorA
>>> ccessorImpl.newInstance(
>>> NativeConstructorAccessorImpl.java:62)
>>>
>>> at sun.reflect.DelegatingConstructorAccessorI
>>> mpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
>>>
>>> at java.lang.reflect.Constructor.
>>> newInstance(Constructor.java:423)
>>>
>>> at java.lang.Class.newInstance(Class.java:442)
>>>
>>> at sun.security.jca.ProviderConfig$2.run(
>>> ProviderConfig.java:221)
>>>
>>> at sun.security.jca.ProviderConfig$2.run(
>>>
>>> ProviderConfig.java:206)
>>>
>>> at
java.security.AccessController.doPrivileged(Native
>>> Method)
>>>
>>> at
sun.security.jca.ProviderConfig.doLoadProvider(
>>> ProviderConfig.java:206)
>>>
>>> at sun.security.jca.ProviderConfig.getProvider(
>>> ProviderConfig.java:187)
>>>
>>> - locked <0x00000007bea03f48> (a
sun.security.jca.
>>> ProviderConfig)
>>>
>>> at sun.security.jca.ProviderList.
>>> getProvider(ProviderList.java:233)
>>>
>>> at sun.security.jca.ProviderList.
>>> getService(ProviderList.java:331)
>>>
>>> at sun.security.jca.GetInstance.
>>> getInstance(GetInstance.java:157)
>>>
>>> at javax.net.ssl.SSLContext.getIn
>>> stance(SSLContext.java:156)
>>>
>>> at com.microsoft.sqlserver.jdbc.
>>> TDSChannel.enableSSL(IOBuffer.java:1658)
>>>
>>> at
com.microsoft.sqlserver.jdbc.SQLServerConnection.
>>> connectHelper(SQLServerConnection.java:1976)
>>>
>>> at com.microsoft.sqlserver.jdbc.S
>>> QLServerConnection.login(
>>> SQLServerConnection.java:1627)
>>>
>>> at
com.microsoft.sqlserver.jdbc.SQLServerConnection.
>>> connectInternal(SQLServerConnection.java:1458)
>>>
>>> at com.microsoft.sqlserver.jdbc.S
>>> QLServerConnection.connect(
>>> SQLServerConnection.java:772)
>>>
>>> at
com.microsoft.sqlserver.jdbc.SQLServerDriver.connect(
>>> SQLServerDriver.java:1168)
>>>
>>> at
java.sql.DriverManager.getConnection(DriverManager.
>>> java:664)
>>>
>>> at
java.sql.DriverManager.getConnection(DriverManager.
>>> java:208)
>>>
>>> at
<some_package>.ConnectionPool.createGoodConnection(
>>> ConnectionPool.java:565)
>>>
>>> at
<some_package>.ConnectionPool.createNewConnection(
>>> ConnectionPool.java:519)
>>>
>>> at <some_package>.ConnectionPool.
>>> getConnection(ConnectionPool.java:407)
>>>
>>> at <some_package>.StatementCachingConnectionImpl
>>> .setupConnection(StatementCachingConnectionImpl.java:94)
>>>
>>> at
<some_package>.StatementCachingConnectionImpl.<init>(
>>> StatementCachingConnectionImpl.java:54)
>>>
>>> at <some_package>.TestConnectionFactories$
>>> FaultInjectingConnection.<init>(TestConnectionFactories.java:90)
>>>
>>> at <some_package>.TestConnectionF
>>> actories.lambda$static$3(
>>> TestConnectionFactories.java:33)
>>>
>>> at <some_package>.TestConnectionFactories$$
>>> Lambda$12/1738236591.newConnection(Unknown Source)
>>>
>>> at <some_package>.SedaExecutor.
>>> setupConnections(SedaExecutor.java:130)
>>>
>>> at
<some_package>.SedaExecutor$SedaThreadFactory.lambda$
>>> newThread$0(SedaExecutor.java:165)
>>>
>>> at
>>> <some_package>.SedaExecutor$SedaThreadFactory$$Lambda$22/139
>>> 2419022.run(Unknown
>>> Source)
>>>
>>> at java.lang.Thread.run(Thread.java:748)
>>>
>>>
>>> The application intermittently hangs on startup, and the above
callstacks
>>> are present. It seems like there's a deadlock due to
concurrent class
>>> loading and default FileSystem initialization (which itself
triggers class
>>> loading here).
>>>
>>> I wasn't able to find any existing JBS entries reporting
anything similar.
>>> Am I seeing this right? Is this a known issue?
>>>
>>> Thanks
>>>
>>
>>
--
Sent from my phone
