https://bz.apache.org/bugzilla/show_bug.cgi?id=63251

            Bug ID: 63251
           Summary: [JDK-8194653] Deadlock in FileSystems.getDefault on
                    catalina startup
           Product: Tomcat 9
           Version: 9.0.14
          Hardware: PC
                OS: Linux
            Status: NEW
          Severity: major
          Priority: P2
         Component: Catalina
          Assignee: dev@tomcat.apache.org
          Reporter: dmitry.bed...@gmail.com
  Target Milestone: -----

Tomcat 9.0.14 fails to start with default logging settings intermittently.
Thread dump shows a dead lock (known issue in JRE:
https://bugs.openjdk.java.net/browse/JDK-8194653)

Other libraries like Gatling, Payara and others workaround it by calling
FileSystems.getDefault from main thread before starting other threads.

Full thread dump OpenJDK 64-Bit Server VM (25.201-b10 mixed mode):

"FileHandlerLogFilesCleaner-1" #11 daemon prio=5 os_prio=0
tid=0x00007fcfc41c4000 nid=0x27 waiting for monitor entry [0x00007fcf8fffa000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at java.lang.Runtime.loadLibrary0(Runtime.java:862)
        - waiting to lock <0x000000008001a690> (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.<init>(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.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at
sun.reflect.DelegatingConstructorAccessorImpl.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$DefaultFileSystemHolder$1.run(FileSystems.java:98)
        at
java.nio.file.FileSystems$DefaultFileSystemHolder$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.getDefault(FileSystems.java:176)
        at java.io.File.toPath(File.java:2234)
        - locked <0x0000000080b1c268> (a java.io.File)
        at
org.apache.juli.FileHandler.streamFilesForDelete(FileHandler.java:559)
        at org.apache.juli.FileHandler.lambda$clean$0(FileHandler.java:546)
        at org.apache.juli.FileHandler$$Lambda$1/20132171.run(Unknown Source)
        at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)

"AsyncFileHandlerWriter-1259475182" #10 daemon prio=5 os_prio=0
tid=0x00007fcfc4141800 nid=0x25 waiting on condition [0x00007fcfb41f8000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x000000008011cac8> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at
java.util.concurrent.LinkedBlockingDeque.pollFirst(LinkedBlockingDeque.java:522)
        at
java.util.concurrent.LinkedBlockingDeque.poll(LinkedBlockingDeque.java:684)
        at
org.apache.juli.AsyncFileHandler$LoggerThread.run(AsyncFileHandler.java:159)

"Service Thread" #7 daemon prio=9 os_prio=0 tid=0x00007fcfc40cd800 nid=0x1c
runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007fcfc40c6800 nid=0x1b
waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007fcfc40c4000 nid=0x1a
waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007fcfc40c2000 nid=0x19
waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007fcfc407a800 nid=0x18 in
Object.wait() [0x00007fcfb47fe000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x0000000080008ed0> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
        - locked <0x0000000080008ed0> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216)

"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007fcfc4078000 nid=0x17
in Object.wait() [0x00007fcfc81c6000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x0000000080006bf8> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:502)
        at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
        - locked <0x0000000080006bf8> (a java.lang.ref.Reference$Lock)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"main" #1 prio=5 os_prio=0 tid=0x00007fcfc400a800 nid=0x15 in Object.wait()
[0x00007fcfcb86e000]
   java.lang.Thread.State: RUNNABLE
        at java.nio.file.FileSystems.getDefault(FileSystems.java:176)
        at java.nio.file.Paths.get(Paths.java:138)
        at sun.misc.Launcher$ExtClassLoader.findLibrary(Launcher.java:235)
        at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1830)
        at java.lang.Runtime.loadLibrary0(Runtime.java:870)
        - locked <0x000000008001a690> (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.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at
sun.reflect.DelegatingConstructorAccessorImpl.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 <0x000000008005db60> (a sun.security.jca.ProviderConfig)
        at sun.security.jca.ProviderList.getProvider(ProviderList.java:233)
        at sun.security.jca.ProviderList.getIndex(ProviderList.java:263)
        at
sun.security.jca.ProviderList.getProviderConfig(ProviderList.java:247)
        at sun.security.jca.ProviderList.getProvider(ProviderList.java:253)
        at java.net.URL.getURLStreamHandler(URL.java:1159)
        at java.net.URL.<init>(URL.java:421)
        at sun.misc.URLClassPath$JarLoader.<init>(URLClassPath.java:822)
        at sun.misc.URLClassPath$3.run(URLClassPath.java:575)
        at sun.misc.URLClassPath$3.run(URLClassPath.java:565)
        at java.security.AccessController.doPrivileged(Native Method)
        at sun.misc.URLClassPath.getLoader(URLClassPath.java:564)
        at sun.misc.URLClassPath.getLoader(URLClassPath.java:529)
        - locked <0x00000000808c3b48> (a sun.misc.URLClassPath)
        at sun.misc.URLClassPath.getNextLoader(URLClassPath.java:494)
        - locked <0x00000000808c3b48> (a sun.misc.URLClassPath)
        at sun.misc.URLClassPath.getResource(URLClassPath.java:248)
        at java.net.URLClassLoader$1.run(URLClassLoader.java:366)
        at java.net.URLClassLoader$1.run(URLClassLoader.java:363)
        at java.security.AccessController.doPrivileged(Native Method)
        at java.net.URLClassLoader.findClass(URLClassLoader.java:362)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        - locked <0x00000000808cf780> (a java.lang.Object)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at org.apache.catalina.startup.Bootstrap.init(Bootstrap.java:263)
        at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:461)
        - locked <0x000000008086db40> (a java.lang.Object)

"VM Thread" os_prio=0 tid=0x00007fcfc406e800 nid=0x16 runnable 

"VM Periodic Task Thread" os_prio=0 tid=0x00007fcfc40d0800 nid=0x1d waiting on
condition 

JNI global references: 322

Heap
 def new generation   total 157248K, used 13977K [0x0000000080000000,
0x000000008aaa0000, 0x00000000aaaa0000)
  eden space 139776K,  10% used [0x0000000080000000, 0x0000000080da67d8,
0x0000000088880000)
  from space 17472K,   0% used [0x0000000088880000, 0x0000000088880000,
0x0000000089990000)
  to   space 17472K,   0% used [0x0000000089990000, 0x0000000089990000,
0x000000008aaa0000)
 tenured generation   total 349568K, used 0K [0x00000000aaaa0000,
0x00000000c0000000, 0x0000000100000000)
   the space 349568K,   0% used [0x00000000aaaa0000, 0x00000000aaaa0000,
0x00000000aaaa0200, 0x00000000c0000000)
 Metaspace       used 6094K, capacity 6240K, committed 6400K, reserved 1056768K
  class space    used 664K, capacity 741K, committed 768K, reserved 1048576K

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org

Reply via email to