Confluence process is stealthy killed short after the startup

[Grigory Salnikov]

Ok, guys, I give up.

I can't locate the issue. Tomcat is just killed and that's all. 

Here's the result of the ./start-confluence.sh -fg

./start-confluence.sh -fg
executing as current user
If you encounter issues starting up Confluence, please see the Installation guide at http://confluence.atlassian.com/display/DOC/Confluence+Installation+Guide

Server startup logs are located in /opt/atl/instd/atlassian-confluence-6.8.2/logs/catalina.out
---------------------------------------------------------------------------
Using Java: /usr/bin/java
2019-04-16 14:43:12,029 INFO [main] [atlassian.confluence.bootstrap.SynchronyProxyWatchdog] A Context element for ${confluence.context.path}/synchrony-proxy is found in /opt/atl/instd/atlassian-confluence-6.8.2/conf/server.xml. No further action is required
---------------------------------------------------------------------------
Using CATALINA_BASE: /opt/atl/instd/atlassian-confluence-6.8.2
Using CATALINA_HOME: /opt/atl/instd/atlassian-confluence-6.8.2
Using CATALINA_TMPDIR: /opt/atl/instd/atlassian-confluence-6.8.2/temp
Using JRE_HOME: /usr
Using CLASSPATH: /opt/atl/instd/atlassian-confluence-6.8.2/bin/bootstrap.jar:/opt/atl/instd/atlassian-confluence-6.8.2/bin/tomcat-juli.jar
Using CATALINA_PID: /opt/atl/instd/atlassian-confluence-6.8.2/work/catalina.pid
16-Apr-2019 14:43:13.061 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 14:43:13.239 WARNING [main] org.apache.catalina.startup.SetAllPropertiesRule.begin [SetAllPropertiesRule]{Server/Service/Connector} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 14:43:13.250 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 14:43:13.288 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.
16-Apr-2019 14:43:13.356 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.
16-Apr-2019 14:43:13.416 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.
Killed

And I also noticed that JRE_HOME variable keeps resetting to /usr

Even if I manually set it back

 export JRE_HOME=/opt/java/jdk1.8.0_171/jre

 it doesn't help:

./start-confluence.sh -fg
executing as current user
If you encounter issues starting up Confluence, please see the Installation guide at http://confluence.atlassian.com/display/DOC/Confluence+Installation+Guide

Server startup logs are located in /opt/atl/instd/atlassian-confluence-6.8.2/logs/catalina.out
---------------------------------------------------------------------------
Using Java: /opt/java/jdk1.8.0_171/jre/bin/java
2019-04-16 14:45:24,358 INFO [main] [atlassian.confluence.bootstrap.SynchronyProxyWatchdog] A Context element for ${confluence.context.path}/synchrony-proxy is found in /opt/atl/instd/atlassian-confluence-6.8.2/conf/server.xml. No further action is required
---------------------------------------------------------------------------
Using CATALINA_BASE: /opt/atl/instd/atlassian-confluence-6.8.2
Using CATALINA_HOME: /opt/atl/instd/atlassian-confluence-6.8.2
Using CATALINA_TMPDIR: /opt/atl/instd/atlassian-confluence-6.8.2/temp
Using JRE_HOME: /opt/java/jdk1.8.0_171/jre
Using CLASSPATH: /opt/atl/instd/atlassian-confluence-6.8.2/bin/bootstrap.jar:/opt/atl/instd/atlassian-confluence-6.8.2/bin/tomcat-juli.jar
Using CATALINA_PID: /opt/atl/instd/atlassian-confluence-6.8.2/work/catalina.pid
16-Apr-2019 14:45:25.593 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 14:45:26.212 WARNING [main] org.apache.catalina.startup.SetAllPropertiesRule.begin [SetAllPropertiesRule]{Server/Service/Connector} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 14:45:26.224 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 14:45:26.229 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.
16-Apr-2019 14:45:26.588 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.
16-Apr-2019 14:45:26.631 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.
16-Apr-2019 14:45:27.334 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8090"]
16-Apr-2019 14:45:27.403 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
16-Apr-2019 14:45:27.426 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 2010 ms
16-Apr-2019 14:45:27.435 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service Tomcat-Standalone
16-Apr-2019 14:45:27.435 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.0.51
Killed

I don't know whether it's related somehow.

I checked all the possible logs and there's literally nothing. I checked atlassian-confluence.log, catalina.out, /var/log/messages, dmesg:

tail -f /opt/atl/confluence-home/logs/atlassian-confluence.log
jquery (com.atlassian.plugins.jquery, Version: 1.7.2.1-confluence-custom-m03, Installed: bundled)

atlassian-confluence.log
2019-04-16 10:29:15,399 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] contextInitialized Starting Confluence 6.8.2 [build 7701 based on commit hash 595a75ab8495b571f620afe86c10e3b32d763479] - synchrony version 2.1.0-release-confluence_6.5-1a01ab2d
2019-04-16 10:29:20,349 INFO [localhost-startStop-1] [atlassian.confluence.cluster.DefaultClusterConfigurationHelper] lambda$populateExistingClusterSetupConfig$1 Populating setup configuration if running with Cluster mode...
2019-04-16 10:29:20,521 INFO [localhost-startStop-1] [springframework.web.context.ContextLoader] initWebApplicationContext Root WebApplicationContext: initialization started
2019-04-16 10:29:23,903 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] <init> Loading EhCache cache manager
2019-04-16 10:29:36,604 INFO [localhost-startStop-1] [springframework.web.context.ContextLoader] initWebApplicationContext Root WebApplicationContext: initialization completed in 16083 ms
2019-04-16 10:29:37,390 INFO [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] earlyStartup Plugin system earlyStartup begun
2019-04-16 10:29:56,862 WARN [ThreadPoolAsyncTaskExecutor::Thread 24] [spring.scanner.util.ProductFilterUtil] detectProduct Couldn't detect product, will use ProductFilter.ALL
2019-04-16 10:29:56,896 WARN [ThreadPoolAsyncTaskExecutor::Thread 19] [spring.scanner.util.ProductFilterUtil] detectProduct Couldn't detect product, will use ProductFilter.ALL

catalina.out
SLF4J: A number (1) of logging calls during the initialization phase have been intercepted and are
SLF4J: now being replayed. These are subject to the filtering rules of the underlying logging system.
SLF4J: See also http://www.slf4j.org/codes.html#replay
16-Apr-2019 10:29:14.615 INFO [localhost-startStop-2] org.apache.catalina.core.ApplicationContext.log Spring WebApplicationInitializers detected on classpath: [com.atlassian.synchrony.proxy.SynchronyDispatcherServletInitializer@b201846]
2019-04-16 10:29:15,399 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] contextInitialized Starting Confluence 6.8.2 [build 7701 based on commit hash 595a75ab8495b571f620afe86c10e3b32d763479] - synchrony version 2.1.0-release-confluence_6.5-1a01ab2d
2019-04-16 10:29:20,349 INFO [localhost-startStop-1] [atlassian.confluence.cluster.DefaultClusterConfigurationHelper] lambda$populateExistingClusterSetupConfig$1 Populating setup configuration if running with Cluster mode...
16-Apr-2019 11:02:23.191 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 11:02:23.704 WARNING [main] org.apache.catalina.startup.SetAllPropertiesRule.begin [SetAllPropertiesRule]{Server/Service/Connector} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 11:02:23.865 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 11:02:23.870 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.
16-Apr-2019 11:02:23.984 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.
16-Apr-2019 11:02:24.057 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.
16-Apr-2019 11:02:24.571 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8090"]
16-Apr-2019 11:02:24.592 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
16-Apr-2019 11:02:24.596 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 1542 ms
16-Apr-2019 11:02:24.645 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service Tomcat-Standalone
16-Apr-2019 11:02:24.646 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.0.51
16-Apr-2019 11:33:38.257 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 11:33:38.669 WARNING [main] org.apache.catalina.startup.SetAllPropertiesRule.begin [SetAllPropertiesRule]{Server/Service/Connector} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 11:33:38.700 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 11:33:38.722 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.
16-Apr-2019 11:33:38.918 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.
16-Apr-2019 11:33:38.948 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.
16-Apr-2019 11:33:39.617 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8090"]
16-Apr-2019 11:33:39.648 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
16-Apr-2019 11:33:39.684 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 1562 ms
16-Apr-2019 11:33:39.693 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service Tomcat-Standalone
16-Apr-2019 11:33:39.693 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.0.51
16-Apr-2019 11:34:13.892 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 11:34:14.045 WARNING [main] org.apache.catalina.startup.SetAllPropertiesRule.begin [SetAllPropertiesRule]{Server/Service/Connector} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 11:34:14.065 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 11:34:14.069 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.
16-Apr-2019 11:34:14.131 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.
16-Apr-2019 11:34:14.177 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.
16-Apr-2019 11:34:14.887 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8090"]
16-Apr-2019 11:34:14.915 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
16-Apr-2019 11:34:14.927 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 1213 ms
16-Apr-2019 11:34:14.937 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service Tomcat-Standalone
16-Apr-2019 11:34:14.937 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.0.51
16-Apr-2019 11:34:24.058 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 11:34:24.151 WARNING [main] org.apache.catalina.startup.SetAllPropertiesRule.begin [SetAllPropertiesRule]{Server/Service/Connector} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 11:34:24.159 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine} Setting property 'debug' to '0' did not find a matching property.
16-Apr-2019 11:34:24.200 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.
16-Apr-2019 11:34:24.247 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.
16-Apr-2019 11:34:24.335 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.
16-Apr-2019 11:34:25.042 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8090"]
16-Apr-2019 11:34:25.063 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
16-Apr-2019 11:34:25.074 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 1161 ms
16-Apr-2019 11:34:25.081 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service Tomcat-Standalone
16-Apr-2019 11:34:25.081 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.0.51

I have enough memory and even have enabled a swap:

free -m
      total used free shared buff/cache available
Mem:  3790  167  3241 19     381        3376
Swap: 511   0    511

swapon -s
Filename   Type Size    Used Priority
/swapfile1 file 524284  0    -1

I've exhasted all my resources and am open to any suggestions.

Thanks in advance.

P.S. Forgot to mention:

A process and open port appear for a couple of seconds (in ps aux, nestat).

Yesterday I was able to start the application once but it didn't last long.

Any help would be much appreciated.

[Diego · Accepted solution]

Hello there!

Hey Grigory, based on your version and symptoms, it sounds like your instance might be affected by an opportunistic attack against the CVE-2019-3396 Widget Connector vulnerability from March 20th (see Confluence Security Advisory - 2019-03-20). We've seen an infection going around that injects malware and the bitcoin miner it tries to run uses all the CPU available on the box. Initially the kerberods malware was being deployed as the payload, but other attacks might be trying to inject different payloads.

I'd recommend tackling things in this order:

1. Kill malicious processes
2. Clean up your crontab
3. Upgrade Confluence
4. Use a malware scanner to find remaining malware traces

Malicious processes

The top command will help you find processes (probably running under the confluence user account) that are consuming a large amount of CPU. If Confluence is currently stopped, you can probably plan on killing any processes running as the confluence user. note the process ID (pid) from the top output and then kill the process using kill -9 followed by the pid. Example:

sudo kill -9 12395

Clean up your crontab

Since most malware adds a cronjob that relaunches the malware every few minutes, you'll also need to check the crontab file and remove any suspicious-looking entries. For Ubuntu, this is stored in the /var/spool/cron/crontabs/ directory. Normally you should use the crontab command to edit the crontab, but for cleanup purposes we'll be inspecting the file for any pre-existing entries.

Using vim (or whichever text editor you're comfortable with), you'll open the file and remove suspicious-looking jobs.

sudo vim /var/spool/cron/crontabs/confluence

Confluence comes up on system startup through the SysV/systemd daemons, so we would expect the confluence user's crontab to not exist under normal circumstances. It's most likely the case that any entries in this file are malicious, but make sure you check them before deleting them entirely.

Upgrade Confluence

Once your CPU is under control and new malicious process aren't spawning, you need to upgrade Confluence to a version that isn't affected by the vulnerability. I'd recommend looking at one of these versions (latest releases as of this post):

• 6.13.4 (6.13 is an Enterprise release)
• 6.14.3
• 6.15.2

Use a malware scanner

Finally, you need to clean up any remaining traces of malware on your system. The LSD malware cleanup tool will be useful for removing the Kerberods malware. Other malware payloads might need different cleanup tools depending on which attack and payload were used. A good starting place for detecting other types of infections are the scanners linked here. Once a particular infection is identified, googling for "____ removal tool" is a good place to start if the scanner was unable to remove the malware automatically.

Taking in consideration your application version and symptoms, it is likely that you are affected by this vulnerability.

[Grigory Salnikov]

Thank you so much @Diego !

Yes, you're right, I found the process.

I'll clean it up later and post the detail here so that it could help someone as well.

[Diego]

Nice Grigory!

Let us know if you are able to clean your instance and get Connie up and running again.