Test Linux Confluence instance 6.7.2 stops immediately after the start for 1-2 hours.

[Novak Ivo]

It starts normally to work after 1-2h. If I use the command ./start-confluence.sh --disable-all-addons, the result is similar.

The last log when Confluence stops from Catallina.out  -> 2019-05-02 07:01:50,300 INFO [localhost-startStop-1] [atlassian.confluence.cluster.DefaultClusterConfigurationHelper] lambda$populateExistingClusterSetupConfig$1 Populating setup configuration if running with Cluster mode...

Last log when Confluence stops from atlassian-confluence.log -> 2019-05-02 07:02:10,530 INFO [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] earlyStartup Plugin system earlyStartup begun

The test instace is the copy of Production and has 1/2 of RAM and 1/2CPUs from VM.  The command "top" shows nearly no CPUs activities during that period. 

Collabrative editing is disabled.   After 2 hours the confluence start to work

Do you have an idea what can be wrong?

[Daniel Eads]

Hey Novak,

After looking at the behavior you've described and seeing that you're on Confluence 6.7, I think it's possible your Confluence instance might be infected with malware due to a security advisory from a couple months ago. I've written a detailed article on how to work on detection for this and steps you can take for remediation.

You mentioned that you didn't see a lot of activity in top - most of the infections we've seen have been bitcoin miners (so CPU would be at or near 100) but other payloads are out in the wild. What you'll want to do is see if there are any processes running under the confluence user account when Confluence itself is not running. That would be clear proof that there's an infection going on.

We haven't heard of cases of people getting infected behind firewalls, but you can't rule that out as a possibility. If your server is exposed to the internet, the vulnerability is definitely something to look in to as we've seen activity from several different sources scanning the internet for vulnerable Confluence installs.

Outside of that, it's worth instrumenting your JVM to see if there is a plugin with a memory leak. We've got a good discussion here about ways you can instrument the java heap. 

Thanks,
Daniel | Atlassian Support

[sara]

Please provide some more logs.

[Novak Ivo]

Logs from Catalian.out - there is no activity between 7:01 and 8:30

02-May-2019 07:01:41.824 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server} Setting property 'debug' to '0' did not find a matching property.
02-May-2019 07:01:41.886 WARNING [main] org.apache.catalina.startup.SetAllPropertiesRule.begin [SetAllPropertiesRule]{Server/Service/Connector} Setting property 'debug' to '0' did not find a matching property.
02-May-2019 07:01:41.903 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine} Setting property 'debug' to '0' did not find a matching property.
02-May-2019 07:01:41.909 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine/Host} Setting property 'debug' to '0' did not find a matching property.
02-May-2019 07:01:41.944 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine/Host/Context} Setting property 'debug' to '0' did not find a matching property.
02-May-2019 07:01:41.967 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine/Host/Context} Setting property 'debug' to '0' did not find a matching property.
02-May-2019 07:01:42.275 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
02-May-2019 07:01:42.290 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
02-May-2019 07:01:42.294 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8093"]
02-May-2019 07:01:42.296 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
02-May-2019 07:01:42.298 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 542 ms
02-May-2019 07:01:42.305 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service Tomcat-Standalone
02-May-2019 07:01:42.305 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.0.50
02-May-2019 07:01:44.860 INFO [localhost-startStop-2] org.apache.catalina.core.ApplicationContext.log Spring WebApplicationInitializers detected on classpath: [com.atlassian.synchrony.proxy.SynchronyDispatcherServletInitializer@b0f38f6]
02-May-2019 07:01:45.534 INFO [localhost-startStop-2] org.apache.catalina.core.ApplicationContext.log Initializing Spring FrameworkServlet 'dispatcher'
02-May-2019 07:01:45.534 INFO [localhost-startStop-2] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization started
02-May-2019 07:01:45.540 INFO [localhost-startStop-2] org.springframework.web.context.support.AnnotationConfigWebApplicationContext.prepareRefresh Refreshing WebApplicationContext for namespace 'dispatcher-servlet': startup date [Thu May 02 07:01:45 CEST 2019]; root of context hierarchy
2019-05-02 07:01:45,631 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] contextInitialized Starting Confluence 6.7.2 [build 7601 based on commit hash 2b9cef12215b66d36aac7298ee6598161e5b8cbb] - synchrony version 2.1.0-release-confluence_6.5-1a01ab2d
02-May-2019 07:01:45.659 INFO [localhost-startStop-2] org.springframework.web.context.support.AnnotationConfigWebApplicationContext.loadBeanDefinitions Registering annotated classes: [class com.atlassian.synchrony.proxy.websocket.WebSocketConfig,class com.atlassian.synchrony.proxy.web.SynchronyWebMvcConfig]
02-May-2019 07:01:46.537 INFO [localhost-startStop-2] org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler.initialize Initializing ExecutorService  'defaultSockJsTaskScheduler'
02-May-2019 07:01:46.612 INFO [localhost-startStop-2] org.springframework.web.socket.server.support.WebSocketHandlerMapping.registerHandler Mapped URL path [/v1/bayeux-sync1] onto handler of type [class org.springframework.web.socket.server.support.WebSocketHttpRequestHandler]
02-May-2019 07:01:47.561 INFO [localhost-startStop-2] org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping.register Mapped "{[/healthcheck]}" onto public com.atlassian.synchrony.proxy.web.HealthCheckResult com.atlassian.synchrony.proxy.web.SynchronyProxyRestController.getSynchronyProxyInfo()
02-May-2019 07:01:47.563 INFO [localhost-startStop-2] org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping.register Mapped "{[/reload],methods=[PUT]}" onto public org.springframework.http.ResponseEntity com.atlassian.synchrony.proxy.web.SynchronyProxyRestController.reloadConfiguration(com.atlassian.synchrony.proxy.web.SynchronyProxyConfigPayload)
02-May-2019 07:01:47.667 INFO [localhost-startStop-2] org.springframework.web.servlet.handler.SimpleUrlHandlerMapping.registerHandler Mapped URL path [/**] onto handler of type [class org.springframework.web.servlet.resource.DefaultServletHttpRequestHandler]
02-May-2019 07:01:47.836 INFO [localhost-startStop-2] org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.initControllerAdviceCache Looking for @ControllerAdvice: WebApplicationContext for namespace 'dispatcher-servlet': startup date [Thu May 02 07:01:45 CEST 2019]; root of context hierarchy
02-May-2019 07:01:48.054 INFO [localhost-startStop-2] org.springframework.context.support.DefaultLifecycleProcessor.start Starting beans in phase 2147483647
02-May-2019 07:01:48.098 INFO [localhost-startStop-2] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization completed in 2564 ms
2019-05-02 07:01:50,300 INFO [localhost-startStop-1] [atlassian.confluence.cluster.DefaultClusterConfigurationHelper] lambda$populateExistingClusterSetupConfig$1 Populating setup configuration if running with Cluster mode...
02-May-2019 08:30:33.744 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
02-May-2019 08:30:33.760 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8093"]
02-May-2019 08:30:33.772 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 5331473 ms

[Novak Ivo]

there is no activity between 7:02 and 8:26 log atlassian-confluence:

2019-05-02 07:00:34,811 INFO [localhost-startStop-3] [atlassian.plugin.manager.DefaultPluginManager] shutdown Preparing to shut down the plugin system
2019-05-02 07:00:34,862 INFO [localhost-startStop-3] [atlassian.plugin.manager.DefaultPluginManager] shutdown Shutting down the plugin system
2019-05-02 07:00:44,261 WARN [Gemini Blueprint context shutdown thread1] [expose.jmx.schedule.JmxInstrumentSchedulerImpl] destroy atlassian-instrumentation-jmx expose scheduler stopped.
2019-05-02 07:01:45,631 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] contextInitialized Starting Confluence 6.7.2 [build 7601 based on commit hash 2b9cef12215b66d36aac7298ee6598161e5b8cbb] - synchrony version 2.1.0-release-confluence_6.5-1a01ab2d
2019-05-02 07:01:50,300 INFO [localhost-startStop-1] [atlassian.confluence.cluster.DefaultClusterConfigurationHelper] lambda$populateExistingClusterSetupConfig$1 Populating setup configuration if running with Cluster mode...
2019-05-02 07:01:50,576 INFO [localhost-startStop-1] [springframework.web.context.ContextLoader] initWebApplicationContext Root WebApplicationContext: initialization started
2019-05-02 07:01:54,901 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] <init> Loading EhCache cache manager
2019-05-02 07:02:09,284 INFO [localhost-startStop-1] [springframework.web.context.ContextLoader] initWebApplicationContext Root WebApplicationContext: initialization completed in 18708 ms
2019-05-02 07:02:10,530 INFO [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] earlyStartup Plugin system earlyStartup begun
2019-05-02 08:26:27,389 WARN [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] addPlugins Plugin 'com.adaptavist.confluence.contentFormattingMacros' is disabled due to startup options!
2019-05-02 08:26:28,464 WARN [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] addPlugins Plugin 'com.atlassian.troubleshooting.plugin-confluence' is disabled due to startup options!
2019-05-02 08:26:33,448 WARN [ThreadPoolAsyncTaskExecutor::Thread 34] [spring.scanner.util.ProductFilterUtil] detectProduct Couldn't detect product, will use ProductFilter.ALL
2019-05-02 08:26:33,484 WARN [ThreadPoolAsyncTaskExecutor::Thread 24] [spring.scanner.util.ProductFilterUtil] detectProduct Couldn't detect product, will use ProductFilter.ALL
2019-05-02 08:27:14,813 WARN [Navlink Plugin Executor:thread-1] [confluence.impl.vcache.SynchronousExternalCache] lambda$get$11 Failed to read entry from cache 'com.atlassian.bandana.BandanaPersister': Failed due to UNCLASSIFIED_FAILURE
2019-05-02 08:27:24,803 WARN [Navlink Plugin Executor:thread-1] [confluence.impl.vcache.SynchronousExternalCache] lambda$get$11 Failed to read entry from cache 'com.atlassian.bandana.BandanaPersister': Failed due to UNCLASSIFIED_FAILURE
2019-05-02 08:27:34,803 WARN [Navlink Plugin Executor:thread-2] [confluence.impl.vcache.SynchronousExternalCache] lambda$get$11 Failed to read entry from cache 'com.atlassian.bandana.BandanaPersister': Failed due to UNCLASSIFIED_FAILURE
2019-05-02 08:27:44,803 WARN [Navlink Plugin Executor:thread-1] [confluence.impl.vcache.SynchronousExternalCache] lambda$get$11 Failed to read entry from cache 'com.atlassian.bandana.BandanaPersister': Failed due to UNCLASSIFIED_FAILURE
2019-05-02 08:27:54,803 WARN [Navlink Plugin Executor:thread-3] [confluence.impl.vcache.SynchronousExternalCache] lambda$get$11 Failed to read entry from cache 'com.atlassian.bandana.BandanaPersister': Failed due to UNCLASSIFIED_FAILURE
2019-05-02 08:28:04,803 WARN [Navlink Plugin Executor:thread-2] [confluence.impl.vcache.SynchronousExternalCache] lambda$get$11 Failed to read entry from cache 'com.atlassian.bandana.BandanaPersister': Failed due to UNCLASSIFIED_FAILURE
2019-05-02 08:28:14,804 WARN [Navlink Plugin Executor:thread-7] [confluence.impl.vcache.SynchronousExternalCache] lambda$get$11 Failed to read entry from cache 'com.atlassian.bandana.BandanaPersister': Failed due to UNCLASSIFIED_FAILURE
2019-05-02 08:28:24,804 WARN [Navlink Plugin Executor:thread-8] [confluence.impl.vcache.SynchronousExternalCache] lambda$get$11 Failed to read entry from cache 'com.atlassian.bandana.BandanaPersister': Failed due to UNCLASSIFIED_FAILURE
2019-05-02 08:28:28,272 INFO [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] logTime Plugin system earlyStartup ended
2019-05-02 08:28:28,381 INFO [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] lateStartup Plugin system lateStartup begun
2019-05-02 08:28:28,390 WARN [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] addPlugins Plugin 'biz.artemissoftware.plugins.confluence.send-email-to-page' is disabled due to startup options!
2019-05-02 08:28:28,393 WARN [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] addPlugins Plugin 'com.adaptavist.confluence.pageinfo' is disabled due to startup options!
2019-05-02 08:28:28,468 WARN [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] addPlugins Plugin 'com.atlassian.confluence.extra.team-calendars' is disabled due to startup options!
2019-05-02 08:28:28,605 WARN [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] addPlugins Plugin 'com.atlassian.confluence.plugins.editor.confluence-source-editor' is disabled due to startup options!
2019-05-02 08:28:28,703 WARN [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] addPlugins Plugin 'com.cinergix.confluence.plugins.creately.CreatelyConfluence' is disabled due to startup options!
2019-0

[Novak Ivo]

Hello  Craig,

yes , Confluence proces is still running > ps -ef | grep -i confluence  shows all settings. Top command shows Confluence process too.     The Instance has 16GB RAM.       CATALINA_OPTS="-Xms14g -Xmx14g -XX:+UseG1GC ${CATALINA_OPTS}".  

IN

[Craig Castle-Mead]

Hey Novak,

Is the Confluence process itself still running (check ps output)?

What are your XMS/XMS settings and what's the total RAM on this server?

CCM