Confluence fail to start after reboot

[Hoang Nguyen]

Greetings,

Our confluence VM running on CentOS 7.5.1804 fail to start automatically. I am not quite sure what the problem is, but if I go into the box, one hour it has been rebooted, perform: "systemctl stop confluence" and then ""systemctl start confluence", the web gui will show up. Confluence 6.10.1

I can see where the VM failed and has to power off abruptly and the services automatically started:

2018-12-04 07:43:55,964 WARN [Caesium-1-4] [impl.schedule.caesium.JobRunnerWrapper] runJob Scheduled job LaasPerformanceLoggingJob#LaasPerformanceLoggingJob completed unsuccessfully with response JobRunnerResponse[runOutcome=ABORTED,message='LaaS performance logging is turned off']
2018-12-04 08:29:07,035 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] contextInitialized Starting Confluence 6.10.1 [build 7702 based on commit hash c32f84c806260a834c2e109e904a2d8ee4f8e175] - synchrony version 2.1.0-master-ed94c233

I can also see where the processes stopped (after the reboot):

2018-12-04 08:31:56,518 INFO [localhost-startStop-3] [com.atlassian.confluence.lifecycle] contextDestroyed Stopping Confluence

This is where I have to manually stop it:

2018-12-04 09:32:58,478 INFO [localhost-startStop-3] [atlassian.plugin.manager.DefaultPluginManager] shutdown Preparing to shut down the plugin system

This is where I have to manually start it:

2018-12-04 09:33:44,655 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] info Starting Confluence 6.10.1 [build 7702 based on commit hash c32f84c806260a834c2e109e904a2d8ee4f8e175] - synchrony version 2.1.0-master-ed94c233

Here is where I think it starts to fail:

 2018-12-04 08:31:22,159 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] init Confluence is ready to serve
2018-12-04 08:31:22,287 WARN [synchrony-interop-executor:thread-2] [plugins.synchrony.bootstrap.DefaultSynchronyProxyMonitor] pollHealthcheck Could
 not ping the synchrony-proxy [http://127.0.0.1:80/synchrony-proxy/healthcheck]: {}
java.net.SocketException: Connection reset

 2018-12-04 08:31:23,574 INFO [read-only-transaction:thread-1] [atlassian.confluence.user.DefaultUserAccessor] getUserNamesWithConfluenceAccess Found USE permission with no associated username or group: [USECONFLUENCE,0,null,null,null]
2018-12-04 08:31:23,580 WARN [StartEventPublisher:thread-1] [atlassian.confluence.event.MonitorableCallerRunsPolicy] rejectedExecution Queue Overflow happened: Runnable: [Invoker: com.atlassian.confluence.event.ConfluenceListenerHandlersConfiguration$TimingListenerHandler$1$1@c82af2d; Event: com.atlassian.confluence.impl.startup.ConfluenceStartAnalyticsEvent@a325aa0]; Executor: [java.util.concurrent.ThreadPoolExecutor@7a144761[Running, pool size = 1, active threads = 1, queued tasks = 192, completed tasks = 255]]
2018-12-04 08:31:23,581 WARN [StartEventPublisher:thread-1] [atlassian.confluence.event.MonitorableCallerRunsPolicy] rejectedExecution Queue Overflow happened: Runnable: [Invoker: com.atlassian.confluence.event.ConfluenceListenerHandlersConfiguration$TimingListenerHandler$1$1@19b2f75e; Event: com.atlassian.confluence.impl.startup.ConfluenceStartAnalyticsEvent@a325aa0]; Executor: [java.util.concurrent.ThreadPoolExecutor@7a144761[Running, pool size = 1, active threads = 1, queued tasks = 192, completed tasks = 255]]
2018-12-04 08:31:23,581 WARN [StartEventPublisher:thread-1] [atlassian.confluence.event.MonitorableCallerRunsPolicy] rejectedExecution Queue Overflow happened: Runnable: [Invoker: com.atlassian.confluence.event.ConfluenceListenerHandlersConfiguration$TimingListenerHandler$1$1@7a7a75a9; Event: com.atlassian.confluence.impl.startup.ConfluenceStartAnalyticsEvent@a325aa0]; Executor: [java.util.concurrent.ThreadPoolExecutor@7a144761[Running, pool size = 1, active threads = 1, queued tasks = 192, completed tasks = 255]]
2018-12-04 08:31:23,581 WARN [StartEventPublisher:thread-1] [atlassian.confluence.event.MonitorableCallerRunsPolicy] rejectedExecution Queue Overflow happened: Runnable: [Invoker: com.atlassian.confluence.event.ConfluenceListenerHandlersConfiguration$TimingListenerHandler$1$1@29e43738; Event: com.atlassian.confluence.impl.startup.ConfluenceStartAnalyticsEvent@a325aa0]; Executor: [java.util.concurrent.ThreadPoolExecutor@7a144761[Running, pool size = 1, active threads = 1, queued tasks = 192, completed tasks = 255]]
2018-12-04 08:31:23,581 WARN [StartEventPublisher:thread-1] [atlassian.confluence.event.MonitorableCallerRunsPolicy] rejectedExecution Queue Overflow happened: Runnable: [Invoker: com.atlassian.confluence.event.ConfluenceListenerHandlersConfiguration$TimingListenerHandler$1$1@739f984b; Event: com.atlassian.confluence.impl.startup.ConfluenceStartAnalyticsEvent@a325aa0]; Executor: [java.util.concurrent.ThreadPoolExecutor@7a144761[Running, pool size = 1, active threads = 1, queued tasks = 192, completed tasks = 255]]
2018-12-04 08:31:23,581 WARN [StartEventPublisher:thread-1] [atlassian.confluence.event.MonitorableCallerRunsPolicy] rejectedExecution Queue Overflow happened: Runnable: [Invoker: com.atlassian.confluence.event.ConfluenceListenerHandlersConfiguration$TimingListenerHandler$1$1@1f24ce11; Event: com.atlassian.confluence.impl.startup.ConfluenceStartAnalyticsEvent@a325aa0]; Executor: [java.util.concurrent.ThreadPoolExecutor@7a144761[Running, pool size = 1, active threads = 1, queued tasks = 192, completed tasks = 255]]
2018-12-04 08:31:23,581 WARN [StartEventPublisher:thread-1] [atlassian.confluence.event.MonitorableCallerRunsPolicy] rejectedExecution Queue Overflow happened: Runnable: [Invoker: com.atlassian.confluence.event.ConfluenceListenerHandlersConfiguration$TimingListenerHandler$1$1@5d3b092e; Event: com.atlassian.confluence.impl.startup.ConfluenceStartAnalyticsEvent@a325aa0]; Executor: [java.util.concurrent.ThreadPoolExecutor@7a144761[Running, pool size = 1, active threads = 1, queued tasks = 192, completed tasks = 255]]
2018-12-04 08:31:23,623 INFO [localhost-startStop-3] [atlassian.plugin.manager.DefaultPluginManager] shutdown Preparing to shut down the plugin system
2018-12-04 08:31:23,631 INFO [localhost-startStop-3] [atlassian.plugin.manager.DefaultPluginManager] shutdown Shutting down the plugin system
2018-12-04 08:31:25,603 WARN [Gemini Blueprint context shutdown thread1] [expose.jmx.schedule.JmxInstrumentSchedulerImpl] destroy atlassian-instrumentation-jmx expose scheduler stopped.
2018-12-04 08:31:27,296 ERROR [AtlassianEvent::CustomizableThreadFactory-1] [confluence.macro.browser.DefaultMacroMetadataManager] buildMacroMetadata Error getting data from MacroMetadataProvider,
org.eclipse.gemini.blueprint.service.importer.ServiceProxyDestroyedException: service proxy has been destroyed

2018-12-04 08:31:30,811 ERROR [AtlassianEvent::CustomizableThreadFactory-1] [atlassian.confluence.event.ConfluenceEventDispatcher] run There was an exception thrown trying to dispatch event [com.atlassian.confluence.event.events.plugin.AsyncPluginFrameworkStartedEvent[source=com.atlassian.confluence.plugin.ConfluencePluginManager@7fa7d81b]] from the invoker [com.atlassian.confluence.event.ConfluenceListenerHandlersConfiguration$TimingListenerHandler$1$1@6a78e43b]
java.lang.RuntimeException: service proxy has been destroyed. Listener: com.atlassian.confluence.plugins.featurediscovery.PluginModuleEventListener event: com.atlassian.confluence.event.events.plugin.AsyncPluginFrameworkStartedEvent
 

2018-12-04 08:31:41,921 ERROR [localhost-startStop-3] [internal.util.concurrent.RunnableTimedExecution] execute Closing runnable for context NonValidatingOsgiBundleXmlApplicationContext(bundle=com.atlassian.confluence.plugins.confluence-mobile-plugin, config=osgibundle:/META-INF/spring/*.xml) did not finish in 10000ms; consider taking a snapshot and then shutdown the VM in case the thread still hangs
2018-12-04 08:31:43,160 INFO [Gemini Blueprint context shutdown thread2] [plugins.synchrony.bootstrap.DefaultSynchronyProcessManager] lambda$stop$9 Stopping Synchrony...
2018-12-04 08:31:46,163 INFO [Gemini Blueprint context shutdown thread2] [plugins.synchrony.bootstrap.DefaultSynchronyProcessManager] lambda$stop$9 Stopping Synchrony...
2018-12-04 08:31:56,240 WARN [Gemini Blueprint context shutdown thread1] [plugins.mobile.remoteservice.MobileHttpClient] destroy Could not dispose of HttpClient
java.lang.RuntimeException: Retry failed; interrupted while waiting
 

2018-12-04 08:31:56,272 ERROR [localhost-startStop-3] [hipchat.spacetoroom.service.SpaceToRoomNotificationService] hipChatNotifications Failed to obtain hipchat notifications for event com.atlassian.plugin.event.events.PluginFrameworkShutdownEvent@beb428b: service proxy has been destroyed
2018-12-04 08:31:56,273 WARN [localhost-startStop-3] [confluence.util.profiling.DurationThresholdWarningTimingHelperFactory] logMessage Execution time for publishing event com.atlassian.plugin.event.events.PluginFrameworkShutdownEvent@beb428b took 32641 ms (warning threshold is 5000 ms)
2018-12-04 08:31:56,460 INFO [localhost-startStop-3] [com.atlassian.confluence.lifecycle] destroy Shutting down long running task service
2018-12-04 08:31:56,504 INFO [localhost-startStop-3] [com.atlassian.confluence.lifecycle] shutdownCacheManager Shutting down EhCache cache manager
2018-12-04 08:31:56,518 INFO [localhost-startStop-3] [com.atlassian.confluence.lifecycle] contextDestroyed Stopping Confluence
 

Does this look familiar to anybody? Why does stopping and starting the service manually worked? But the automatic startup does not?

[M Amine]

It is unusual. Can you please check system message (/var/log/messages) and check if the system (OS) is asking for confluence stop?