Confluence is never normally stopping: Tomcat did not stop in time.

[Teodor Mamolea]

Hi there,

Please let me know why confluence is not well stopping and if this is an issue into tomcat product instead. Thanks in advance.

It shouldn't be a hardware resource related issue as it runs on a powerful machine.

Attaching WARN logs captured right after stopping the confluence server application with 120 seconds timeout (aka `catalina.sh stop 120 -force`)

16:20:14 [Catalina-utility-3] o.a.c.c.C.[.[.[/synchrony-proxy][INFO] log - Destroying Spring FrameworkServlet 'dispatcher'
2021-09-04 16:20:14,051 INFO [Catalina-utility-4] [com.atlassian.confluence.plugin.PluginFrameworkContextListener] ServletContext about to be shut down; shutting down plugin framework
2021-09-04 16:20:14,585 WARN [FelixShutdown] [com.atlassian.business.insights.core.service.DefaultDataExportOrchestrator] DefaultDataExportOrchestrator is about to be destroyed. Cancelling possible in flight export.
2021-09-04 16:20:14,983 WARN [FelixShutdown] [org.springframework.beans.factory.support.DisposableBeanAdapter] Invocation of destroy method failed on bean with name 'com.atlassian.troubleshooting.stp.hercules.DefaultLogScanService': java.lang.NullPointerException
2021-09-04 16:20:15,694 WARN [FelixShutdown] [com.addonengine.addons.analytics.scheduler.EventLimiterScheduleManagerImpl] Destroying Event Limiter Schedule
2021-09-04 16:20:15,700 WARN [FelixShutdown] [com.addonengine.addons.analytics.scheduler.DataRetentionScheduleManagerImpl] Destroying Data Retention Schedule
2021-09-04 16:20:19,612 INFO [FelixStartLevel] [com.atlassian.confluence.plugin.ModuleDescriptorCache] Removing inactive plugin module from cache: com.atlassian.confluence.extra.team-calendars:calendar-content-type
2021-09-04 16:20:19,612 INFO [FelixStartLevel] [com.atlassian.confluence.plugin.ModuleDescriptorCache] Removing inactive plugin module from cache: com.atlassian.confluence.extra.team-calendars:space-calendars-view-content-type
2021-09-04 16:20:20,989 INFO [FelixStartLevel] [com.atlassian.confluence.plugin.ModuleDescriptorCache] Removing inactive plugin module from cache: com.atlassian.confluence.plugins.confluence-content-property-storage:content-property
2021-09-04 16:20:21,629 INFO [Catalina-utility-4] [com.atlassian.confluence.lifecycle] Stopping Confluence
2021-09-04 16:20:21,630 INFO [Catalina-utility-4] [com.atlassian.confluence.setup.DefaultBootstrapManager] Unlock file 'lock' in confluence.home directory /home/<user>/.confluence
Tomcat did not stop in time.
To aid diagnostics a thread dump has been written to standard out.
2021-09-04 16:22:14
Full thread dump OpenJDK 64-Bit Server VM (11.0.12+7-post-Debian-2deb10u1 mixed mode, sharing):

Threads class SMR info:
_java_thread_list=0x00007f1fa49797c0, length=57, elements={
0x00007f2118e78000, 0x00007f2118e7a000, 0x00007f2118e7f800, 0x00007f2118e81800,
0x00007f2118e83800, 0x00007f2118e8e000, 0x00007f2118e90000, 0x00007f2118ec6000,
0x00007f1f39653800, 0x00007f1f39713800, 0x00007f1f39b7d800, 0x00007f1f39b7e800,
0x00007f1f39b80000, 0x00007f1f39b81000, 0x00007f1f39b82000, 0x00007f1f39b83800,
0x00007f1f39b84800, 0x00007f1f39b86000, 0x00007f1f39b87000, 0x00007f1f39b88800,
0x00007f1f39b8d000, 0x00007f1f39e85800, 0x00007f1f39e88800, 0x00007f1f3989c800,
0x00007f1f3a383000, 0x00007f1f3a3ca800, 0x00007f1f3a3cc000, 0x00007f1f3a3ce000,
0x00007f1f3a3d0000, 0x00007f1f3a3ee000, 0x00007f1f3a3ef000, 0x00007f2010001000,
0x00007f1fc4001800, 0x00007f1f3a400000, 0x00007f2010002800, 0x00007f1f3a401000,
0x00007f1ff0001800, 0x00007f1f3a402000, 0x00007f1fd0001800, 0x00007f1f382cc000,
0x00007f1f38351800, 0x00007f1f3834d800, 0x00007f1f38352800, 0x00007f1f38353800,
0x00007f1f38355000, 0x00007f1f3831e800, 0x00007f1f38362800, 0x00007f1f38356800,
0x00007f1f38367800, 0x00007f1f3836d800, 0x00007f1f3836e800, 0x00007f1f3ae53000,
0x00007f1f3ae58000, 0x00007f1f3ae59000, 0x00007f1f3ae5a000, 0x00007f1e781bf800,
0x00007f2118017000
}

"Reference Handler" #2 daemon prio=10 os_prio=0 cpu=29.12ms elapsed=841.38s tid=0x00007f2118e78000 nid=0x4d6 waiting on condition [0x00007f20e73f7000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.12/Native Method)
at java.lang.ref.Reference.processPendingReferences(java.base@11.0.12/Reference.java:241)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.12/Reference.java:213)

"Finalizer" #3 daemon prio=8 os_prio=0 cpu=7.94ms elapsed=841.38s tid=0x00007f2118e7a000 nid=0x4d7 in Object.wait() [0x00007f20e72f6000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.12/Native Method)
- waiting on <no object reference available>
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.12/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000006c0000988> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.12/ReferenceQueue.java:176)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.12/Finalizer.java:170)

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 cpu=0.52ms elapsed=841.38s tid=0x00007f2118e7f800 nid=0x4d8 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"Service Thread" #5 daemon prio=9 os_prio=0 cpu=29.91ms elapsed=841.38s tid=0x00007f2118e81800 nid=0x4d9 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #6 daemon prio=9 os_prio=0 cpu=76234.65ms Killing Tomcat with the PID: 1215
elapsed=841.38s tid=0x00007f2118e83800 nid=0x4da waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile taskThe Tomcat process has been killed.

[Daniel Ebers]

Hi @Teodor Mamolea

this is nothing very unusual and was spotted also for Jira in the past.

Question: is it causing problems for operations of any kind? The last time I spoke to Confluence administrators they said as long as Confluence will be stopped properly it is not of any harm.

Happy for any details!

Regards,
Daniel

[Teodor Mamolea]

Not a big issue if those logs don't mean that confluence's state is negatively affected somehow.

Just wondering what may cause such an unexpected state? How to be sure that it is not about some existing running critical jobs in confluence-background which being forcefully killed may produce a non expected state into its data?, so a next start operation of it to fail because of an corrupted state for example...

Sometimes it does not well stop even in 10 minutes and more.

Thanks ahead

[Daniel Ebers]

I would not expect any critical side effects by this.
To pinpoint the cause it would be needed to take a deeper look into the setup - which is impossible from Community side.

I would probably start checking the configuration, including memory settings if you really want to get to the bottom of that case.

[Teodor Mamolea]

Can't see this error to happen anymore, somehow it was fixed maybe as part of upgrade to the 7.13.1 version.

Tried to stop confluence few times as did before and can't see this error anymore.

Please consider this case `somehow solved` (:

Thanks for your time.

[Teodor Mamolea]

You can see that order of these logs differ in both cases. Maybe something around it:

2021-09-04 16:20:21,629 INFO [Catalina-utility-4] [com.atlassian.confluence.lifecycle] Stopping Confluence
2021-09-04 16:20:21,630 INFO [Catalina-utility-4] [com.atlassian.confluence.setup.DefaultBootstrapManager] Unlock file 'lock' in confluence.home directory /home/<user>/.confluence

 Sorry for spamming (:

[Teodor Mamolea]

Want to add details that sometimes it successfully is closed (caught this case just few times) and these are actual logs (can be compared with the above ones, maybe it says much more information to you):

21:28:45 [Catalina-utility-4] o.a.c.c.C.[.[.[/synchrony-proxy][INFO] log - Destroying Spring FrameworkServlet 'dispatcher'
2021-09-04 21:28:45,324 INFO [Catalina-utility-3] [com.atlassian.confluence.lifecycle] Shutting down long running task service
2021-09-04 21:28:48,808 WARN [FelixShutdown] [com.atlassian.business.insights.core.service.DefaultDataExportOrchestrator] DefaultDataExportOrchestrator is about to be destroyed. Cancelling possible in flight export.
2021-09-04 21:28:49,608 WARN [FelixShutdown] [com.addonengine.addons.analytics.scheduler.EventLimiterScheduleManagerImpl] Destroying Event Limiter Schedule
2021-09-04 21:28:49,609 WARN [FelixShutdown] [com.addonengine.addons.analytics.scheduler.DataRetentionScheduleManagerImpl] Destroying Data Retention Schedule
2021-09-04 21:28:56,466 WARN [Catalina-utility-3] [com.atlassian.confluence.util.profiling.DurationThresholdWarningTimingHelperFactory] Execution time for publishing event com.atlassian.plugin.event.events.PluginFrameworkShutdownEvent@622b2e55 took 11110 ms (warning threshold is 5000 ms)
2021-09-04 21:28:56,468 INFO [Catalina-utility-3] [com.atlassian.confluence.setup.DefaultBootstrapManager] Unlock file 'lock' in confluence.home directory /home/<user>/.confluence
2021-09-04 21:28:56,627 INFO [Catalina-utility-3] [com.atlassian.confluence.lifecycle] Shutting down long running task service
2021-09-04 21:28:56,701 INFO [Catalina-utility-3] [com.atlassian.confluence.lifecycle] Shutting down EhCache cache manager
2021-09-04 21:28:56,709 INFO [Catalina-utility-3] [com.atlassian.confluence.lifecycle] Shutting down EhCache cache manager
2021-09-04 21:28:56,712 INFO [Catalina-utility-3] [com.atlassian.confluence.lifecycle] Stopping Confluence
Tomcat stopped.