Changes from 12.2.1 to 12.3-rc-1 causing slow stop in Tomcat on Windows

Help / Discuss
1

Good day,

I have gone back and determined on which version the slow stop problem on Windows using Tomcat started happening - 12.3-rc-1. The problem does not occur in the immediately preceding version - 12.2.1.

All versions starting with 12.3-rc-1 exhibit this behavior - slow stop in Tomcat on Windows.

Any ideas what changed from 12.2.1 and 12.3-rc-1 that might be causing this issue? Please let me know what I can do to help us narrow this issue down.

Thanks!

Bill

2

Tomcat catalina log output from when stopping the service (12.3-rc-1):

24-Feb-2021 15:19:10.387 INFO [Thread-20] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["http-nio-8080"]
24-Feb-2021 15:19:10.591 INFO [Thread-20] org.apache.catalina.core.StandardService.stopInternal Stopping service [Catalina]
24-Feb-2021 15:19:10.777 WARNING [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [xwiki] appears to have started a thread named [searcherExecutor-10-thread-1] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
java.base@11.0.10/jdk.internal.misc.Unsafe.park(Native Method)
java.base@11.0.10/java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
java.base@11.0.10/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2081)
java.base@11.0.10/java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:433)
java.base@11.0.10/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
java.base@11.0.10/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
java.base@11.0.10/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
java.base@11.0.10/java.lang.Thread.run(Thread.java:834)
24-Feb-2021 15:19:10.793 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@45ad82a5]) and a value of type [org.codehaus.plexus.classworlds.realm.ClassRealm] (value [ClassRealm[plexus.core, parent: null]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:10.793 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@70f19d8b]) and a value of type [java.util.Stack] (value [[org.xwiki.context.ExecutionContext@610fd4]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:10.793 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@72f072d]) and a value of type [java.util.Stack] (value [[org.xwiki.container.servlet.ServletRequest@28605124]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:10.793 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@70f19d8b]) and a value of type [java.util.Stack] (value [[org.xwiki.context.ExecutionContext@54819c66]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:10.793 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@5c16268d]) and a value of type [java.util.Stack] (value [[org.xwiki.container.servlet.ServletResponse@237f444d]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:10.793 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@70f19d8b]) and a value of type [java.util.Stack] (value [[org.xwiki.context.ExecutionContext@93cc877]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:10.793 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@72f072d]) and a value of type [java.util.Stack] (value [[org.xwiki.container.servlet.ServletRequest@5106079a]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:12.574 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@3c496179]) and a value of type [java.util.LinkedList] (value [[org.xwiki.logging.event.LoggerListener@654d1791]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:12.574 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@5c16268d]) and a value of type [java.util.Stack] (value [[org.xwiki.container.servlet.ServletResponse@add143f]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:12.606 INFO [Thread-20] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler ["http-nio-8080"]
24-Feb-2021 15:19:12.637 INFO [Thread-20] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio-8080"]

Tomcat stderr output when stopping the service:

24-Feb-2021 15:19:10.387 INFO [Thread-20] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["http-nio-8080"]
24-Feb-2021 15:19:10.591 INFO [Thread-20] org.apache.catalina.core.StandardService.stopInternal Stopping service [Catalina]
Exception in thread "User event dispatcher thread" org.infinispan.IllegalLifecycleStateException: ISPN000323: Cache 'configuration.document.space' is in 'TERMINATED' state and so it does not accept new invocations. Either restart it or recreate the cache container.
at org.infinispan.interceptors.impl.InvocationContextInterceptor.ignoreCommand(InvocationContextInterceptor.java:98)
at org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:87)
at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:248)
at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:527)
at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:520)
at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:438)
at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:660)
at org.xwiki.cache.infinispan.internal.InfinispanCache.get(InfinispanCache.java:101)
at org.xwiki.configuration.internal.AbstractDocumentConfigurationSource.getPropertyValue(AbstractDocumentConfigurationSource.java:319)
at org.xwiki.configuration.internal.AbstractDocumentConfigurationSource.containsKey(AbstractDocumentConfigurationSource.java:199)
at org.xwiki.configuration.internal.AbstractSpacesConfigurationSource$SpaceConfigurationSource.containsKey(AbstractSpacesConfigurationSource.java:171)
at org.xwiki.configuration.internal.AbstractCompositeConfigurationSource.containsKey(AbstractCompositeConfigurationSource.java:45)
at org.xwiki.configuration.internal.AbstractCompositeConfigurationSource.containsKey(AbstractCompositeConfigurationSource.java:45)
at org.xwiki.configuration.internal.AbstractCompositeConfigurationSource.getProperty(AbstractCompositeConfigurationSource.java:95)
at org.xwiki.url.internal.DefaultURLConfiguration.getURLFormatId(DefaultURLConfiguration.java:55)
at org.xwiki.url.internal.URLExecutionContextInitializer.initialize(URLExecutionContextInitializer.java:55)
at org.xwiki.context.internal.DefaultExecutionContextManager.runInitializers(DefaultExecutionContextManager.java:131)
at org.xwiki.context.internal.DefaultExecutionContextManager.pushContext(DefaultExecutionContextManager.java:112)
at org.xwiki.notifications.notifiers.internal.UserEventDispatcher.run(UserEventDispatcher.java:129)
at java.base/java.lang.Thread.run(Thread.java:834)
24-Feb-2021 15:19:10.777 WARNING [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [xwiki] appears to have started a thread named [searcherExecutor-10-thread-1] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
java.base@11.0.10/jdk.internal.misc.Unsafe.park(Native Method)
java.base@11.0.10/java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
java.base@11.0.10/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2081)
java.base@11.0.10/java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:433)
java.base@11.0.10/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
java.base@11.0.10/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
java.base@11.0.10/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
java.base@11.0.10/java.lang.Thread.run(Thread.java:834)
24-Feb-2021 15:19:10.793 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@45ad82a5]) and a value of type [org.codehaus.plexus.classworlds.realm.ClassRealm] (value [ClassRealm[plexus.core, parent: null]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:10.793 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@70f19d8b]) and a value of type [java.util.Stack] (value [[org.xwiki.context.ExecutionContext@610fd4]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:10.793 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@72f072d]) and a value of type [java.util.Stack] (value [[org.xwiki.container.servlet.ServletRequest@28605124]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:10.793 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@70f19d8b]) and a value of type [java.util.Stack] (value [[org.xwiki.context.ExecutionContext@54819c66]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:10.793 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@5c16268d]) and a value of type [java.util.Stack] (value [[org.xwiki.container.servlet.ServletResponse@237f444d]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:10.793 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@70f19d8b]) and a value of type [java.util.Stack] (value [[org.xwiki.context.ExecutionContext@93cc877]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:10.793 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@72f072d]) and a value of type [java.util.Stack] (value [[org.xwiki.container.servlet.ServletRequest@5106079a]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:12.574 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@3c496179]) and a value of type [java.util.LinkedList] (value [[org.xwiki.logging.event.LoggerListener@654d1791]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:12.574 SEVERE [Thread-20] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [xwiki] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@5c16268d]) and a value of type [java.util.Stack] (value [[org.xwiki.container.servlet.ServletResponse@add143f]]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
24-Feb-2021 15:19:12.606 INFO [Thread-20] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler ["http-nio-8080"]
24-Feb-2021 15:19:12.637 INFO [Thread-20] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio-8080"]

Please let me know what other data I can collect to assist in troubleshooting.

Thanks!

Bill

3

While the slow stop was occurring I ran jstack -l -e <pid of tomcat service process> - here is the output:

2021-02-25 09:27:15
Full thread dump OpenJDK 64-Bit Server VM (11.0.10+9 mixed mode):

Threads class SMR info:
_java_thread_list=0x0000000028307130, length=29, elements={
0x0000000021432800, 0x0000000021461000, 0x000000002146d000, 0x000000002146e800,
0x000000002146f800, 0x0000000021472800, 0x00000000214bd000, 0x00000000214c6000,
0x000000002164d800, 0x0000000021702000, 0x000000002185b800, 0x00000000266a8800,
0x000000002939f000, 0x0000000029742000, 0x0000000029743000, 0x0000000029747000,
0x0000000029741800, 0x000000002974d800, 0x0000000029748000, 0x000000002974e800,
0x000000002974c000, 0x0000000029749800, 0x000000002974a800, 0x000000002974c800,
0x0000000029748800, 0x000000002974b000, 0x000000002d574800, 0x0000000029743800,
0x000000002d577800
}

"Reference Handler" #2 daemon prio=10 os_prio=2 cpu=15.63ms elapsed=556.85s allocated=0B defined_classes=0 tid=0x0000000021432800 nid=0xdec waiting on condition [0x0000000021cee000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.10/Native Method)
at java.lang.ref.Reference.processPendingReferences(java.base@11.0.10/Reference.java:241)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.10/Reference.java:213)

Locked ownable synchronizers:
- None

"Finalizer" #3 daemon prio=8 os_prio=1 cpu=31.25ms elapsed=556.83s allocated=13872B defined_classes=3 tid=0x0000000021461000 nid=0x1bf8 in Object.wait() [0x0000000021def000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.10/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000000902026b0> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.10/ReferenceQueue.java:176)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.10/Finalizer.java:170)

Locked ownable synchronizers:
- None

"Signal Dispatcher" #4 daemon prio=9 os_prio=2 cpu=0.00ms elapsed=556.77s allocated=0B defined_classes=0 tid=0x000000002146d000 nid=0x1754 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"Attach Listener" #5 daemon prio=5 os_prio=2 cpu=0.00ms elapsed=556.77s allocated=0B defined_classes=0 tid=0x000000002146e800 nid=0x1bdc waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"Service Thread" #6 daemon prio=9 os_prio=0 cpu=0.00ms elapsed=556.77s allocated=0B defined_classes=0 tid=0x000000002146f800 nid=0x14ec runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"C2 CompilerThread0" #7 daemon prio=9 os_prio=2 cpu=79750.00ms elapsed=556.77s allocated=1912B defined_classes=0 tid=0x0000000021472800 nid=0x1bcc waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task

Locked ownable synchronizers:
- None

"C1 CompilerThread0" #9 daemon prio=9 os_prio=2 cpu=14421.88ms elapsed=556.77s allocated=212K defined_classes=0 tid=0x00000000214bd000 nid=0x1d20 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task

Locked ownable synchronizers:
- None

"Sweeper thread" #10 daemon prio=9 os_prio=2 cpu=250.00ms elapsed=556.77s allocated=0B defined_classes=0 tid=0x00000000214c6000 nid=0x1d10 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"Common-Cleaner" #11 daemon prio=8 os_prio=1 cpu=0.00ms elapsed=556.32s allocated=0B defined_classes=0 tid=0x000000002164d800 nid=0x1d08 in Object.wait() [0x00000000225ef000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.10/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x0000000090202b00> (a java.lang.ref.ReferenceQueue$Lock)
at jdk.internal.ref.CleanerImpl.run(java.base@11.0.10/CleanerImpl.java:148)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)
at jdk.internal.misc.InnocuousThread.run(java.base@11.0.10/InnocuousThread.java:134)

Locked ownable synchronizers:
- None

"AsyncFileHandlerWriter-1712669532" #14 daemon prio=5 os_prio=0 cpu=46.88ms elapsed=554.75s allocated=420K defined_classes=73 tid=0x0000000021702000 nid=0x1bc4 waiting on condition [0x00000000227ee000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.10/Native Method)
- parking to wait for <0x0000000090204a70> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.10/LockSupport.java:234)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(java.base@11.0.10/AbstractQueuedSynchronizer.java:2123)
at java.util.concurrent.LinkedBlockingDeque.pollFirst(java.base@11.0.10/LinkedBlockingDeque.java:513)
at java.util.concurrent.LinkedBlockingDeque.poll(java.base@11.0.10/LinkedBlockingDeque.java:675)
at org.apache.juli.AsyncFileHandler$LoggerThread.run(AsyncFileHandler.java:159)

Locked ownable synchronizers:
- None

"FileHandlerLogFilesCleaner-1" #15 daemon prio=5 os_prio=0 cpu=62.50ms elapsed=554.32s allocated=496K defined_classes=110 tid=0x000000002185b800 nid=0x1bbc waiting on condition [0x00000000228ef000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.10/Native Method)
- parking to wait for <0x0000000090202e70> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.10/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.10/AbstractQueuedSynchronizer.java:2081)
at java.util.concurrent.LinkedBlockingQueue.take(java.base@11.0.10/LinkedBlockingQueue.java:433)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.10/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

"ForkJoinPool.commonPool-worker-3" #18 daemon prio=5 os_prio=0 cpu=312.50ms elapsed=444.13s allocated=136M defined_classes=10 tid=0x00000000266a8800 nid=0x17e8 waiting on condition [0x000000002b7fe000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.10/Native Method)
- parking to wait for <0x0000000092801318> (a java.util.concurrent.ForkJoinPool)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.10/LockSupport.java:194)
at java.util.concurrent.ForkJoinPool.runWorker(java.base@11.0.10/ForkJoinPool.java:1628)
at java.util.concurrent.ForkJoinWorkerThread.run(java.base@11.0.10/ForkJoinWorkerThread.java:183)

Locked ownable synchronizers:
- None

"searcherExecutor-10-thread-1" #33 prio=5 os_prio=0 cpu=1156.25ms elapsed=360.07s allocated=164M defined_classes=285 tid=0x000000002939f000 nid=0x1664 waiting on condition [0x000000002f63f000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.10/Native Method)
- parking to wait for <0x0000000094c00308> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.10/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.10/AbstractQueuedSynchronizer.java:2081)
at java.util.concurrent.LinkedBlockingQueue.take(java.base@11.0.10/LinkedBlockingQueue.java:433)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.10/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

"Statistics storing daemon" #52 daemon prio=5 os_prio=0 cpu=15.63ms elapsed=323.60s allocated=100088B defined_classes=0 tid=0x0000000029742000 nid=0xe4c waiting on condition [0x00000000354ee000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.10/Native Method)
- parking to wait for <0x0000000094ec0d90> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.10/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.10/AbstractQueuedSynchronizer.java:2081)
at java.util.concurrent.ArrayBlockingQueue.take(java.base@11.0.10/ArrayBlockingQueue.java:417)
at com.xpn.xwiki.stats.impl.xwiki.XWikiStatsStoreService.register(XWikiStatsStoreService.java:146)
at com.xpn.xwiki.stats.impl.xwiki.XWikiStatsStoreService.runInternal(XWikiStatsStoreService.java:124)
at com.xpn.xwiki.util.AbstractXWikiRunnable.run(AbstractXWikiRunnable.java:133)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-1" #54 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=322.99s allocated=0B defined_classes=0 tid=0x0000000029743000 nid=0x3a8 in Object.wait() [0x0000000035e5e000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x0000000094ec1120> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-2" #55 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=322.99s allocated=0B defined_classes=0 tid=0x0000000029747000 nid=0x830 in Object.wait() [0x000000003635f000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x0000000094ec1330> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-3" #56 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=322.99s allocated=0B defined_classes=0 tid=0x0000000029741800 nid=0x1990 in Object.wait() [0x00000000366de000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x0000000094ec14d0> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-4" #57 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=322.99s allocated=0B defined_classes=0 tid=0x000000002974d800 nid=0x910 in Object.wait() [0x00000000367de000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x0000000094ec1cb0> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-5" #58 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=322.99s allocated=0B defined_classes=0 tid=0x0000000029748000 nid=0xf20 in Object.wait() [0x00000000368de000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x0000000094ec2078> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-6" #59 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=322.99s allocated=0B defined_classes=0 tid=0x000000002974e800 nid=0x1ce0 in Object.wait() [0x00000000369df000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x0000000094ec2370> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-7" #60 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=322.99s allocated=0B defined_classes=0 tid=0x000000002974c000 nid=0x970 in Object.wait() [0x0000000037b7e000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x0000000094ec2668> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-8" #61 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=322.99s allocated=0B defined_classes=0 tid=0x0000000029749800 nid=0x136c in Object.wait() [0x0000000037c7f000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x0000000094ec2960> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-9" #62 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=322.99s allocated=0B defined_classes=0 tid=0x000000002974a800 nid=0xafc in Object.wait() [0x0000000037d7f000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x0000000094ec2c58> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-10" #63 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=322.99s allocated=0B defined_classes=0 tid=0x000000002974c800 nid=0x1ffc in Object.wait() [0x0000000037e7f000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x0000000094ec2f50> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_QuartzSchedulerThread" #64 daemon prio=5 os_prio=0 cpu=0.00ms elapsed=322.96s allocated=3184B defined_classes=0 tid=0x0000000029748800 nid=0x1718 in Object.wait() [0x0000000037f7f000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:427)
- waiting to re-lock in wait() <0x0000000094c78af8> (a java.lang.Object)

Locked ownable synchronizers:
- None

"Active Installs Ping Thread" #66 daemon prio=5 os_prio=0 cpu=328.13ms elapsed=322.68s allocated=27266K defined_classes=181 tid=0x000000002974b000 nid=0x1c08 waiting on condition [0x00000000393df000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(java.base@11.0.10/Native Method)
at org.xwiki.activeinstalls.internal.client.ActiveInstallsPingThread.runInternal(ActiveInstallsPingThread.java:80)
at com.xpn.xwiki.util.AbstractXWikiRunnable.run(AbstractXWikiRunnable.java:133)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

"Live E-Mail notifications thread" #69 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=320.41s allocated=67904B defined_classes=0 tid=0x000000002d574800 nid=0x182c waiting on condition [0x000000003924e000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(java.base@11.0.10/Native Method)
at org.xwiki.notifications.notifiers.internal.email.live.LiveNotificationEmailListener$NotificationGraceTimeRunnable.run(LiveNotificationEmailListener.java:95)
at org.xwiki.context.concurrent.ExecutionContextRunnable.run(ExecutionContextRunnable.java:71)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

"Java2D Disposer" #75 daemon prio=10 os_prio=2 cpu=0.00ms elapsed=297.02s allocated=0B defined_classes=0 tid=0x0000000029743800 nid=0x1cc in Object.wait() [0x0000000039c1f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.10/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x0000000092510880> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.10/ReferenceQueue.java:176)
at sun.java2d.Disposer.run(java.desktop@11.0.10/Disposer.java:144)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

"DestroyJavaVM" #106 prio=5 os_prio=0 cpu=0.00ms elapsed=58.22s allocated=488B defined_classes=0 tid=0x000000002d577800 nid=0x1644 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"VM Thread" os_prio=2 cpu=3468.75ms elapsed=556.94s tid=0x0000000021432000 nid=0x1bfc runnable

"GC Thread#0" os_prio=2 cpu=750.00ms elapsed=557.52s tid=0x0000000002387800 nid=0x1be0 runnable

"GC Thread#1" os_prio=2 cpu=843.75ms elapsed=534.61s tid=0x000000002306d800 nid=0x1760 runnable

"GC Thread#2" os_prio=2 cpu=796.88ms elapsed=534.61s tid=0x000000002306e800 nid=0xd34 runnable

"GC Thread#3" os_prio=2 cpu=781.25ms elapsed=534.61s tid=0x0000000022c6e800 nid=0x1e18 runnable

"G1 Main Marker" os_prio=2 cpu=15.63ms elapsed=557.50s tid=0x00000000023b2000 nid=0x1bd8 runnable

"G1 Conc#0" os_prio=2 cpu=875.00ms elapsed=557.50s tid=0x00000000023b4800 nid=0x1bd4 runnable

"G1 Refine#0" os_prio=2 cpu=78.13ms elapsed=557.46s tid=0x00000000208a2800 nid=0x1bf4 runnable

"G1 Young RemSet Sampling" os_prio=2 cpu=0.00ms elapsed=557.46s tid=0x00000000208a3000 nid=0x1bec runnable
"VM Periodic Task Thread" os_prio=2 cpu=187.50ms elapsed=556.21s tid=0x0000000021653800 nid=0x1bc8 waiting on condition

JNI global refs: 39, weak refs: 44

Bill

4

Daemon threads can’t block the shutdown so what’s left seems to be:

"searcherExecutor-10-thread-1" #33 prio=5 os_prio=0 cpu=1156.25ms elapsed=360.07s allocated=164M defined_classes=285 tid=0x000000002939f000 nid=0x1664 waiting on condition [0x000000002f63f000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.10/Native Method)
- parking to wait for <0x0000000094c00308> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.10/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.10/AbstractQueuedSynchronizer.java:2081)
at java.util.concurrent.LinkedBlockingQueue.take(java.base@11.0.10/LinkedBlockingQueue.java:433)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.10/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

After some search on Google it seems to be a Solr thread but not really sure why it’s blocking like this (feels like a bug). Solr was indeed upgraded in 12.3-rc-1 to 8.5.1 (from 8.1.1). Did you reproduce with 13.1 too (Solr was upgraded to 8.8.0 in 13.1) ?

5

Hi @tmortagne - yes - the problem is there (Tomcat slow stop) in 13.1 also.

Below is thread dump from 13.1 - thread dump taken while process in “stopping…” state (not yet stopped), just as before.

2021-02-25 10:45:50
Full thread dump OpenJDK 64-Bit Server VM (11.0.10+9 mixed mode):

Threads class SMR info:
_java_thread_list=0x000000003160a0f0, length=29, elements={
0x00000000219d6000, 0x00000000219e0000, 0x0000000021a3d800, 0x0000000021a3f000,
0x0000000021a40800, 0x00000000219e9800, 0x00000000219ed800, 0x00000000219f5800,
0x0000000021baa800, 0x0000000021c67800, 0x0000000021e1d800, 0x0000000028e02000,
0x00000000286a9000, 0x0000000028df2800, 0x0000000023a69800, 0x0000000023a70000,
0x0000000023a71000, 0x0000000023a71800, 0x000000002d8ca000, 0x00000000291c0000,
0x00000000291c5000, 0x00000000291c4000, 0x00000000291c1800, 0x00000000291c1000,
0x00000000291bf000, 0x00000000291c2800, 0x00000000291c3000, 0x0000000023888000,
0x000000002388a000
}

"Reference Handler" #2 daemon prio=10 os_prio=2 cpu=0.00ms elapsed=577.63s allocated=0B defined_classes=0 tid=0x00000000219d6000 nid=0x1564 waiting on condition [0x000000002226f000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.10/Native Method)
at java.lang.ref.Reference.processPendingReferences(java.base@11.0.10/Reference.java:241)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.10/Reference.java:213)

Locked ownable synchronizers:
- None

"Finalizer" #3 daemon prio=8 os_prio=1 cpu=0.00ms elapsed=577.63s allocated=166K defined_classes=4 tid=0x00000000219e0000 nid=0x1744 in Object.wait() [0x000000002236f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.10/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x0000000090402b48> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.10/ReferenceQueue.java:176)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.10/Finalizer.java:170)

Locked ownable synchronizers:
- None

"Signal Dispatcher" #4 daemon prio=9 os_prio=2 cpu=0.00ms elapsed=577.61s allocated=0B defined_classes=0 tid=0x0000000021a3d800 nid=0x1f84 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"Attach Listener" #5 daemon prio=5 os_prio=2 cpu=0.00ms elapsed=577.61s allocated=0B defined_classes=0 tid=0x0000000021a3f000 nid=0x1d04 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"Service Thread" #6 daemon prio=9 os_prio=0 cpu=0.00ms elapsed=577.61s allocated=0B defined_classes=0 tid=0x0000000021a40800 nid=0x1268 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"C2 CompilerThread0" #7 daemon prio=9 os_prio=2 cpu=56468.75ms elapsed=577.61s allocated=368B defined_classes=0 tid=0x00000000219e9800 nid=0xf54 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task

Locked ownable synchronizers:
- None

"C1 CompilerThread0" #9 daemon prio=9 os_prio=2 cpu=11515.63ms elapsed=577.61s allocated=200K defined_classes=0 tid=0x00000000219ed800 nid=0x61c waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task

Locked ownable synchronizers:
- None

"Sweeper thread" #10 daemon prio=9 os_prio=2 cpu=125.00ms elapsed=577.61s allocated=0B defined_classes=0 tid=0x00000000219f5800 nid=0x778 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"Common-Cleaner" #11 daemon prio=8 os_prio=1 cpu=15.63ms elapsed=577.58s allocated=0B defined_classes=0 tid=0x0000000021baa800 nid=0x17cc in Object.wait() [0x0000000022b6e000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.10/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x0000000090402fe0> (a java.lang.ref.ReferenceQueue$Lock)
at jdk.internal.ref.CleanerImpl.run(java.base@11.0.10/CleanerImpl.java:148)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)
at jdk.internal.misc.InnocuousThread.run(java.base@11.0.10/InnocuousThread.java:134)

Locked ownable synchronizers:
- None

"AsyncFileHandlerWriter-1712669532" #14 daemon prio=5 os_prio=0 cpu=15.63ms elapsed=577.50s allocated=474K defined_classes=80 tid=0x0000000021c67800 nid=0x12f4 waiting on condition [0x0000000022d6f000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.10/Native Method)
- parking to wait for <0x0000000090404260> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.10/LockSupport.java:234)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(java.base@11.0.10/AbstractQueuedSynchronizer.java:2123)
at java.util.concurrent.LinkedBlockingDeque.pollFirst(java.base@11.0.10/LinkedBlockingDeque.java:513)
at java.util.concurrent.LinkedBlockingDeque.poll(java.base@11.0.10/LinkedBlockingDeque.java:675)
at org.apache.juli.AsyncFileHandler$LoggerThread.run(AsyncFileHandler.java:159)

Locked ownable synchronizers:
- None

"FileHandlerLogFilesCleaner-1" #15 daemon prio=5 os_prio=0 cpu=31.25ms elapsed=577.45s allocated=519K defined_classes=120 tid=0x0000000021e1d800 nid=0x1618 waiting on condition [0x0000000022e6e000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.10/Native Method)
- parking to wait for <0x00000000904031d8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.10/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.10/AbstractQueuedSynchronizer.java:2081)
at java.util.concurrent.LinkedBlockingQueue.take(java.base@11.0.10/LinkedBlockingQueue.java:433)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.10/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

"RxSchedulerPurge-1" #17 daemon prio=5 os_prio=0 cpu=0.00ms elapsed=532.58s allocated=241K defined_classes=1 tid=0x0000000028e02000 nid=0x1c98 waiting on condition [0x000000002be9f000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.10/Native Method)
- parking to wait for <0x0000000092e66190> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.10/LockSupport.java:234)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(java.base@11.0.10/AbstractQueuedSynchronizer.java:2123)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.10/ScheduledThreadPoolExecutor.java:1182)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.10/ScheduledThreadPoolExecutor.java:899)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.10/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

"RxCachedWorkerPoolEvictor-1" #18 daemon prio=5 os_prio=0 cpu=0.00ms elapsed=532.56s allocated=320B defined_classes=0 tid=0x00000000286a9000 nid=0x1c1c waiting on condition [0x000000002bf9e000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.10/Native Method)
- parking to wait for <0x0000000092eac6e8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.10/LockSupport.java:234)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(java.base@11.0.10/AbstractQueuedSynchronizer.java:2123)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.10/ScheduledThreadPoolExecutor.java:1182)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.10/ScheduledThreadPoolExecutor.java:899)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.10/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

"searcherExecutor-15-thread-1" #29 prio=5 os_prio=0 cpu=93.75ms elapsed=511.52s allocated=4733K defined_classes=33 tid=0x0000000028df2800 nid=0x19b4 waiting on condition [0x000000002fc7e000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.10/Native Method)
- parking to wait for <0x000000009466a258> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.10/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.10/AbstractQueuedSynchronizer.java:2081)
at java.util.concurrent.LinkedBlockingQueue.take(java.base@11.0.10/LinkedBlockingQueue.java:433)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.10/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

"Statistics storing daemon" #260 daemon prio=5 os_prio=0 cpu=0.00ms elapsed=200.04s allocated=65080B defined_classes=0 tid=0x0000000023a69800 nid=0x144 waiting on condition [0x000000003705f000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.10/Native Method)
- parking to wait for <0x00000000959fd628> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.10/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.10/AbstractQueuedSynchronizer.java:2081)
at java.util.concurrent.ArrayBlockingQueue.take(java.base@11.0.10/ArrayBlockingQueue.java:417)
at com.xpn.xwiki.stats.impl.xwiki.XWikiStatsStoreService.register(XWikiStatsStoreService.java:146)
at com.xpn.xwiki.stats.impl.xwiki.XWikiStatsStoreService.runInternal(XWikiStatsStoreService.java:124)
at com.xpn.xwiki.util.AbstractXWikiRunnable.run(AbstractXWikiRunnable.java:133)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-1" #262 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=199.75s allocated=0B defined_classes=0 tid=0x0000000023a70000 nid=0x1f8c in Object.wait() [0x000000003725e000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x00000000959ebe10> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-2" #263 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=199.75s allocated=0B defined_classes=0 tid=0x0000000023a71000 nid=0x4bc in Object.wait() [0x000000003735f000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x00000000959ec128> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-3" #264 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=199.75s allocated=0B defined_classes=0 tid=0x0000000023a71800 nid=0x458 in Object.wait() [0x000000003745f000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x00000000959ec440> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-4" #265 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=199.75s allocated=0B defined_classes=0 tid=0x000000002d8ca000 nid=0x1d60 in Object.wait() [0x000000003755f000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x00000000959ec758> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-5" #266 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=199.75s allocated=0B defined_classes=0 tid=0x00000000291c0000 nid=0x1e0c in Object.wait() [0x000000003765f000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x00000000959eca70> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-6" #267 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=199.75s allocated=0B defined_classes=0 tid=0x00000000291c5000 nid=0x18c8 in Object.wait() [0x000000003775e000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x00000000959ecd88> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-7" #268 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=199.75s allocated=0B defined_classes=0 tid=0x00000000291c4000 nid=0x13b4 in Object.wait() [0x000000003785e000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x00000000959ed0a0> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-8" #269 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=199.75s allocated=0B defined_classes=0 tid=0x00000000291c1800 nid=0x1788 in Object.wait() [0x000000003795f000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x00000000959ed3b8> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-9" #270 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=199.75s allocated=0B defined_classes=0 tid=0x00000000291c1000 nid=0x8ac in Object.wait() [0x0000000038aaf000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x00000000959ed6d0> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_Worker-10" #271 daemon prio=4 os_prio=-1 cpu=0.00ms elapsed=199.75s allocated=0B defined_classes=0 tid=0x00000000291bf000 nid=0x1c8c in Object.wait() [0x0000000038bae000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
- waiting to re-lock in wait() <0x00000000959ed9e8> (a java.lang.Object)

Locked ownable synchronizers:
- None

"DefaultQuartzScheduler_QuartzSchedulerThread" #272 daemon prio=5 os_prio=0 cpu=0.00ms elapsed=199.73s allocated=1216B defined_classes=0 tid=0x00000000291c2800 nid=0x1408 in Object.wait() [0x0000000038caf000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.10/Native Method)
- waiting on <no object reference available>
at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:427)
- waiting to re-lock in wait() <0x00000000959ee860> (a java.lang.Object)

Locked ownable synchronizers:
- None

"Active Installs Ping Thread" #274 daemon prio=5 os_prio=0 cpu=265.63ms elapsed=199.63s allocated=24611K defined_classes=182 tid=0x00000000291c3000 nid=0x1698 waiting on condition [0x0000000033eef000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(java.base@11.0.10/Native Method)
at org.xwiki.activeinstalls.internal.client.ActiveInstallsPingThread.runInternal(ActiveInstallsPingThread.java:80)
at com.xpn.xwiki.util.AbstractXWikiRunnable.run(AbstractXWikiRunnable.java:133)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

"Farm distribution initialization" #284 daemon prio=5 os_prio=0 cpu=0.00ms elapsed=199.03s allocated=1590K defined_classes=3 tid=0x0000000023888000 nid=0x1624 waiting on condition [0x00000000392af000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.10/Native Method)
- parking to wait for <0x0000000095e10d68> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.10/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.10/AbstractQueuedSynchronizer.java:2081)
at org.xwiki.job.AbstractJobStatus.ask(AbstractJobStatus.java:364)
at org.xwiki.job.AbstractJobStatus.ask(AbstractJobStatus.java:331)
at org.xwiki.extension.distribution.internal.job.AbstractDistributionJob.runInternal(AbstractDistributionJob.java:203)
at org.xwiki.job.AbstractJob.runInContext(AbstractJob.java:243)
at org.xwiki.job.AbstractJob.run(AbstractJob.java:220)
at org.xwiki.extension.distribution.internal.DefaultDistributionManager$1.run(DefaultDistributionManager.java:222)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

"DestroyJavaVM" #310 prio=5 os_prio=0 cpu=0.00ms elapsed=60.80s allocated=488B defined_classes=0 tid=0x000000002388a000 nid=0xa38 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"VM Thread" os_prio=2 cpu=7781.25ms elapsed=577.64s tid=0x00000000219af800 nid=0x1c0c runnable

"GC Thread#0" os_prio=2 cpu=750.00ms elapsed=577.69s tid=0x00000000028f9000 nid=0x14e4 runnable

"GC Thread#1" os_prio=2 cpu=812.50ms elapsed=571.61s tid=0x0000000023c18000 nid=0x1440 runnable

"GC Thread#2" os_prio=2 cpu=718.75ms elapsed=571.61s tid=0x0000000023aea000 nid=0xdac runnable

"GC Thread#3" os_prio=2 cpu=812.50ms elapsed=571.61s tid=0x0000000023aea800 nid=0x1018 runnable

"G1 Main Marker" os_prio=2 cpu=0.00ms elapsed=577.69s tid=0x0000000002924800 nid=0x1b44 runnable

"G1 Conc#0" os_prio=2 cpu=187.50ms elapsed=577.69s tid=0x0000000002927000 nid=0x1f80 runnable

"G1 Refine#0" os_prio=2 cpu=62.50ms elapsed=577.64s tid=0x0000000020e1a800 nid=0xd7c runnable

"G1 Refine#1" os_prio=2 cpu=0.00ms elapsed=192.08s tid=0x000000002a697800 nid=0xbd0 runnable

"G1 Young RemSet Sampling" os_prio=2 cpu=15.63ms elapsed=577.64s tid=0x0000000020e1b000 nid=0x18c runnable
"VM Periodic Task Thread" os_prio=2 cpu=46.88ms elapsed=577.56s tid=0x0000000021bb9800 nid=0xfc waiting on condition

JNI global refs: 38, weak refs: 44

Thanks!

Bill

6

Seems to be the same problem:

"searcherExecutor-15-thread-1" #29 prio=5 os_prio=0 cpu=93.75ms elapsed=511.52s allocated=4733K defined_classes=33 tid=0x0000000028df2800 nid=0x19b4 waiting on condition [0x000000002fc7e000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.10/Native Method)
- parking to wait for <0x000000009466a258> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.10/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.10/AbstractQueuedSynchronizer.java:2081)
at java.util.concurrent.LinkedBlockingQueue.take(java.base@11.0.10/LinkedBlockingQueue.java:433)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.10/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

Locked ownable synchronizers:
- None

So I guess we’ll have to debug Solr.

Would be great if you could create an issue on Loading... and give all the info you can think of to reproduce the problem.

7

Created issue as requested:

https://jira.xwiki.org/browse/XWIKI-18387

Thanks @tmortagne for taking a look at it!

1 Like
8

Upgraded to XWiki 13.8/Tomcat 9.0.54/JRE 11.0.12+7; FYI issue still exists - very slow stop of Tomcat service.

9

To test if the issue is caused by the solr version, I did the following:

With the remote Solr 8.1.1 instance, XWiki stops nearly instantaneously.

Any ideas on why newer versions of Solr prevent the Tomcat service from stopping quickly on Windows?

Thanks!

Bill

1 Like
10

Upgraded to XWiki 14.10.16/Tomcat 9.0.80/Java 11.0/20+8 - Issue still exists - very slow stop of Tomcat service.