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
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
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
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) ?
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
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 https://jira.xwiki.org/browse/XWIKI and give all the info you can think of to reproduce the problem.
Created issue as requested:
https://jira.xwiki.org/browse/XWIKI-18387
Thanks @tmortagne for taking a look at it!
Upgraded to XWiki 13.8/Tomcat 9.0.54/JRE 11.0.12+7; FYI issue still exists - very slow stop of Tomcat service.
To test if the issue is caused by the solr version, I did the following:
Installed Solr 8.1.1
Disabled the embedded Solr instance by setting solr.type=remote in xwiki.properties
Created the needed cores as documented in http://extensions.xwiki.org/xwiki/bin/view/Extension/Solr%20Search%20API
Started remote Solr 8.1.1 instance
Started XWiki and let it finish indexing
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
Upgraded to XWiki 14.10.16/Tomcat 9.0.80/Java 11.0/20+8 - Issue still exists - very slow stop of Tomcat service.