Confluence server docker suddenly stopped working

[Jamie Belanger]

I've been running Confluence server on my own hardware for over a year now. The last time I did any updates to it was in April, when I upgraded the base image to 6.15.2. I'm running using the official Docker image with MySQL drivers manually copied in via my own Dockerfile.

Everything has been fine barring occasional slowness, but I'm the only one currently using the server so I don't mind much. My server hardly reboots (Mint Linux 18.3 host, AMD 8 core CPU, 32 GB ram). But when it does need a reboot, all of my Docker containers come back fine.

Last week we had a storm in the northeast that knocked out my power for half a day. My server came back up and everything works, except Confluence. So no changes to my config, no changes to my host, no changes to my database, and no changes to the Docker container. But when I try to connect, it just sits and spins and gives zero feedback.

Here's what I see in the logs:

Mon Oct 21 15:00:28 GMT 2019 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.,
Exception in thread "Task-Thread-for-com.mchange.v2.async.ThreadPerTaskAsynchronousRunner@67e56cca" Exception in thread "Task-Thread-for-com.mchange.v2.async.ThreadPerTaskAsynchronousRunner@67e56cca" Exception in thread "Task-Thread-for-com.mchange.v2.async.ThreadPerTaskAsynchronousRunner@67e56cca" Exception in thread "Task-Thread-for-com.mchange.v2.async.ThreadPerTaskAsynchronousRunner@67e56cca" Exception in thread "Task-Thread-for-com.mchange.v2.async.ThreadPerTaskAsynchronousRunner@67e56cca" Exception in thread "Task-Thread-for-com.mchange.v2.async.ThreadPerTaskAsynchronousRunner@67e56cca" java.lang.IllegalStateException: Timer already cancelled.,
at java.util.Timer.sched(Unknown Source),
at java.util.Timer.schedule(Unknown Source),
at com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1965),
at com.mchange.v2.async.ThreadPerTaskAsynchronousRunner$TaskThread.run(ThreadPerTaskAsynchronousRunner.java:267),
java.lang.IllegalStateException: Timer already cancelled.,
at java.util.Timer.sched(Unknown Source),
at java.util.Timer.schedule(Unknown Source),
at com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1965),
at com.mchange.v2.async.ThreadPerTaskAsynchronousRunner$TaskThread.run(ThreadPerTaskAsynchronousRunner.java:267),
java.lang.IllegalStateException: Timer already cancelled.,
at java.util.Timer.sched(Unknown Source),
at java.util.Timer.schedule(Unknown Source),
at com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1965),
at com.mchange.v2.async.ThreadPerTaskAsynchronousRunner$TaskThread.run(ThreadPerTaskAsynchronousRunner.java:267),
java.lang.IllegalStateException: Timer already cancelled.,
at java.util.Timer.sched(Unknown Source),
at java.util.Timer.schedule(Unknown Source),
at com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1965),
at com.mchange.v2.async.ThreadPerTaskAsynchronousRunner$TaskThread.run(ThreadPerTaskAsynchronousRunner.java:267),
java.lang.IllegalStateException: Timer already cancelled.,
at java.util.Timer.sched(Unknown Source),
at java.util.Timer.schedule(Unknown Source),
at com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1965),
at com.mchange.v2.async.ThreadPerTaskAsynchronousRunner$TaskThread.run(ThreadPerTaskAsynchronousRunner.java:267),
java.lang.IllegalStateException: Timer already cancelled.,
at java.util.Timer.sched(Unknown Source),
at java.util.Timer.schedule(Unknown Source),
at com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1965),
at com.mchange.v2.async.ThreadPerTaskAsynchronousRunner$TaskThread.run(ThreadPerTaskAsynchronousRunner.java:267),
Exception in thread "Task-Thread-for-com.mchange.v2.async.ThreadPerTaskAsynchronousRunner@67e56cca" java.lang.IllegalStateException: Timer already cancelled.,
at java.util.Timer.sched(Unknown Source),
at java.util.Timer.schedule(Unknown Source),
at com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1965),
at com.mchange.v2.async.ThreadPerTaskAsynchronousRunner$TaskThread.run(ThreadPerTaskAsynchronousRunner.java:267),
,
Session terminated, terminating shell... ...waiting for child to terminate.,
/bin/bash: warning: setlocale: LC_ALL: cannot change locale (en_US.UTF-8),
User is currently root. Will change directory ownership to daemon:daemon, then downgrade permission to daemon,
bash: warning: setlocale: LC_ALL: cannot change locale (en_US.UTF-8),
/bin/bash: warning: setlocale: LC_ALL: cannot change locale (en_US.UTF-8),
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/atlassian/confluence/logs/catalina.out,
---------------------------------------------------------------------------,
Using Java: /opt/java/openjdk/bin/java,
Picked up JAVA_TOOL_OPTIONS: -XX:+UnlockExperimentalVMOptions -XX:+UseCGroupMemoryLimitForHeap,
Picked up JAVA_TOOL_OPTIONS: -XX:+UnlockExperimentalVMOptions -XX:+UseCGroupMemoryLimitForHeap,
2019-10-21 15:05:46,946 INFO [main] [atlassian.confluence.bootstrap.SynchronyProxyWatchdog] A Context element for ${confluence.context.path}/synchrony-proxy is found in /opt/atlassian/confluence/conf/server.xml. No further action is required,
---------------------------------------------------------------------------,
Picked up JAVA_TOOL_OPTIONS: -XX:+UnlockExperimentalVMOptions -XX:+UseCGroupMemoryLimitForHeap,
21-Oct-2019 15:05:47.308 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server} Setting property 'debug' to '0' did not find a matching property.,
21-Oct-2019 15:05:47.364 WARNING [main] org.apache.catalina.startup.SetAllPropertiesRule.begin [SetAllPropertiesRule]{Server/Service/Connector} Setting property 'proxyPort' to '' did not find a matching property.,
21-Oct-2019 15:05:47.366 WARNING [main] org.apache.catalina.startup.SetAllPropertiesRule.begin [SetAllPropertiesRule]{Server/Service/Connector} Setting property 'debug' to '0' did not find a matching property.,
21-Oct-2019 15:05:47.439 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine} Setting property 'debug' to '0' did not find a matching property.,
21-Oct-2019 15:05:47.443 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.,
21-Oct-2019 15:05:47.468 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.,
21-Oct-2019 15:05:47.483 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.,
21-Oct-2019 15:05:47.694 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8090"],
21-Oct-2019 15:05:47.706 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read,
21-Oct-2019 15:05:47.714 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 474 ms,
21-Oct-2019 15:05:47.720 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Tomcat-Standalone],
21-Oct-2019 15:05:47.720 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/9.0.12,
21-Oct-2019 15:05:48.753 INFO [localhost-startStop-2] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.,
21-Oct-2019 15:05:48.770 INFO [localhost-startStop-2] org.apache.catalina.core.ApplicationContext.log Spring WebApplicationInitializers detected on classpath: [com.atlassian.synchrony.proxy.SynchronyDispatcherServletInitializer@50d5d3f6],
21-Oct-2019 15:05:49.202 INFO [localhost-startStop-2] org.apache.catalina.core.ApplicationContext.log Initializing Spring FrameworkServlet 'dispatcher',
21-Oct-2019 15:05:49.203 INFO [localhost-startStop-2] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization started,
21-Oct-2019 15:05:49.209 INFO [localhost-startStop-2] org.springframework.web.context.support.AnnotationConfigWebApplicationContext.prepareRefresh Refreshing WebApplicationContext for namespace 'dispatcher-servlet': startup date [Mon Oct 21 15:05:49 GMT 2019]; root of context hierarchy,
2019-10-21 15:05:49,221 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] contextInitialized Starting Confluence 6.15.2 [build 8100 based on commit hash 4410012ac87e845516b70bc69b6f7a893eabaa5a] - synchrony version 2.1.0-master-9d112c9d,
21-Oct-2019 15:05:49.281 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],
21-Oct-2019 15:05:49.674 INFO [localhost-startStop-2] org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler.initialize Initializing ExecutorService 'defaultSockJsTaskScheduler',
21-Oct-2019 15:05:49.709 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],
21-Oct-2019 15:05:50.015 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],
21-Oct-2019 15:05:50.042 INFO [localhost-startStop-2] org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.initControllerAdviceCache Looking for @ControllerAdvice: WebApplicationContext for namespace 'dispatcher-servlet': startup date [Mon Oct 21 15:05:49 GMT 2019]; root of context hierarchy,
21-Oct-2019 15:05:50.106 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(),
21-Oct-2019 15:05:50.107 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),
21-Oct-2019 15:05:50.166 INFO [localhost-startStop-2] org.springframework.context.support.DefaultLifecycleProcessor.start Starting beans in phase 2147483647,
21-Oct-2019 15:05:50.185 INFO [localhost-startStop-2] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization completed in 981 ms,

The container is running. I can see it's not crashing. And I can connect to the container just fine. I'm not familiar enough with the program to know what threads are crashing or why. I... just have no idea how to troubleshoot from here. Any ideas are very much appreciated!

Update:

After leaving the container running all night it eventually started showing a database connection error page. I tinkered with this a lot more this evening and I think it's a networking issue, but can't for the life of me figure out why it's happening.

In short (too late), from inside the container I can see the host, connect to ports 80 and 443 using the internal IP, and can connect to the outside world. But the moment I try to connect to an internal-only address/port (ie `curl 192.168.42.2:3306` for MySQL) it hangs. From other machines inside my network I can execute that command and it works. But from inside the Confluence container it just hangs until it eventually times out.

[Jamie Belanger]

After much experimentation, I managed to track this down. Symptoms in case someone else runs into this (including a future version of me):

Docker containers in bridge networks can reach other machines on network using curl / wget

Containers in bridge networks can _not_ reach host -- anything but external facing ports like 80 and 443 will just sit, spin, and time out.

The fix was the firewall. Something in ufw got corrupted during the power outage, and the gufw interface is so simplistic that it doesn't help see what happened. Manually re-adding a ufw rule fixed the issue.

```

sudo ufw allow in on docker0 to any port 3306

```

[Mehran Moss]

Jamie, I am coming across same issue I believe, running Confluence Server under Windows Server 2019 virtual environment. But I am not sure how you solved the issue?

[Jamie Belanger]

This particular issue was a corruption in the firewall on my Linux Mint host machine. To clarify, I have my server configured like this:

• Host = Mint Linux
• MySQL = running on bare metal, port 3306
• Confluence = running in a Docker container

The problem was that the docker bridge network (called "docker0" by default) was trying to call the MySQL server, and the Host's firewall was blocking the connection. The command above re-added the rule to let the inbound traffic to that port through.

If you're having a similar networking issue, you may want to look at the Windows firewall to see if it's blocking traffic to your SQL server from the docker network. If it is, you'll have to figure out how to add an exception for traffic from that network to that port. I don't use Windows at all anymore so I don't know for sure how to do that. Just search for something like "windows firewall inbound port rule"