Confluence (self-hosted) fails to start

[jpcartailler]

Greetings,

Suddenly, Confluence stopped working. So we re-started it and it's not completing its startup. The catalina log is below.

In addition, one of users reporting seeing the following in their web browser (before we tried to restart): https://pastebin.com/GAzgZMCE

Any guidance would be much appreciated. Thanks!

JP

---

Version: 6.2.2

OS: Linux RHEL6

DB - PostgreSQL (on a separate server)

Startup (catalina) Log:

04-Dec-2017 11:19:33.893 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server} Setting property 'debug' to '0' did not find a matching property.
04-Dec-2017 11:19:33.938 WARNING [main] org.apache.catalina.startup.SetAllPropertiesRule.begin [SetAllPropertiesRule]{Server/Service/Connector} Setting property 'debug' to '0' did not find a matching property.
04-Dec-2017 11:19:33.946 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine} Setting property 'debug' to '0' did not find a matching property.
04-Dec-2017 11:19:33.951 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.
04-Dec-2017 11:19:33.975 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.
04-Dec-2017 11:19:33.991 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.
04-Dec-2017 11:19:34.207 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-9080"]
04-Dec-2017 11:19:34.222 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
04-Dec-2017 11:19:34.223 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 386 ms
04-Dec-2017 11:19:34.234 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service Tomcat-Standalone
04-Dec-2017 11:19:34.235 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.0.43
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
04-Dec-2017 11:19:36.008 INFO [localhost-startStop-2] org.apache.catalina.core.ApplicationContext.log Spring WebApplicationInitializers detected on classpath: [com.atlassian.synchrony.proxy.SynchronyDispatcherServletInitializer@48586f23]
2017-12-04 11:19:36,368 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] contextInitialized Starting Confluence 6.2.2 [build 7201 based on commit hash 3d89a43db3618502ceb73a83aa0af888aa0a285a] - synchrony version 0.3.1-release-confluence_6.1-e20fb944
2017-12-04 11:19:38,407 INFO [localhost-startStop-1] [atlassian.confluence.cluster.DefaultClusterConfigurationHelper] lambda$populateExistingClusterSetupConfig$1 Populating setup configuration if running with Cluster mode...
04-Dec-2017 11:19:41.993 INFO [localhost-startStop-2] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [5,925] milliseconds.
04-Dec-2017 11:19:42.181 INFO [localhost-startStop-2] org.apache.catalina.core.ApplicationContext.log Initializing Spring FrameworkServlet 'dispatcher'
04-Dec-2017 11:19:42.190 INFO [localhost-startStop-2] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization started
04-Dec-2017 11:19:42.194 INFO [localhost-startStop-2] org.springframework.web.context.support.AnnotationConfigWebApplicationContext.prepareRefresh Refreshing WebApplicationContext for namespace 'dispatcher-servlet': startup date [Mon Dec 04 11:19:42 CST 2017]; root of context hierarchy
04-Dec-2017 11:19:42.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]
04-Dec-2017 11:19:42.782 INFO [localhost-startStop-2] org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler.initialize Initializing ExecutorService  'defaultSockJsTaskScheduler'
04-Dec-2017 11:19:43.063 INFO [localhost-startStop-2] org.springframework.web.socket.server.support.WebSocketHandlerMapping.registerHandler Mapped URL path [/sockjs/v1/**] onto handler of type [class org.springframework.web.socket.sockjs.support.SockJsHttpRequestHandler]
04-Dec-2017 11:19:43.231 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()
04-Dec-2017 11:19:43.232 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)
04-Dec-2017 11:19:43.267 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]
04-Dec-2017 11:19:43.301 INFO [localhost-startStop-2] org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.initControllerAdviceCache Looking for @ControllerAdvice: WebApplicationContext for namespace 'dispatcher-servlet': startup date [Mon Dec 04 11:19:42 CST 2017]; root of context hierarchy
04-Dec-2017 11:19:43.431 INFO [localhost-startStop-2] org.springframework.context.support.DefaultLifecycleProcessor.start Starting beans in phase 2147483647
04-Dec-2017 11:19:43.474 INFO [localhost-startStop-2] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization completed in 1283 ms

If we try to access Confluence via HTTP, the page just loads on and on and on ... but never actually displays anything.

If we then try to shut it down, we see nothing in the Log, but the CLI output is:

[user ~/atlassian/confluence]$ ./bin/stop-confluence.sh
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 /app001/atlassian/confluence/logs/catalina.out
---------------------------------------------------------------------------
Using Java: /app001/atlassian/confluence/jre//bin/java
2017-12-04 11:21:56,306 INFO [main] [atlassian.confluence.bootstrap.SynchronyProxyWatchdog] A Context element for ${confluence.context.path}/synchrony-proxy is found in /app001/atlassian/confluence/conf/server.xml. No further action is required
---------------------------------------------------------------------------
Using CATALINA_BASE:   /app001/atlassian/confluence
Using CATALINA_HOME:   /app001/atlassian/confluence
Using CATALINA_TMPDIR: /app001/atlassian/confluence/temp
Using JRE_HOME:        /app001/atlassian/confluence/jre/
Using CLASSPATH:       /app001/atlassian/confluence/bin/bootstrap.jar:/app001/atlassian/confluence/bin/tomcat-juli.jar
Using CATALINA_PID:    /app001/atlassian/confluence/work/catalina.pid
Dec 04, 2017 11:21:56 AM org.apache.catalina.startup.Catalina stopServer
SEVERE: Could not contact localhost:8000. Tomcat may not be running.
Dec 04, 2017 11:21:56 AM org.apache.catalina.startup.Catalina stopServer
SEVERE: Catalina.stop:
java.net.ConnectException: Connection refused (Connection refused)
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
        at java.net.Socket.connect(Socket.java:589)
        at java.net.Socket.connect(Socket.java:538)
        at java.net.Socket.<init>(Socket.java:434)
        at java.net.Socket.<init>(Socket.java:211)
        at org.apache.catalina.startup.Catalina.stopServer(Catalina.java:450)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.apache.catalina.startup.Bootstrap.stopServer(Bootstrap.java:400)
        at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:487)

The stop command failed. Attempting to signal the process to stop through OS signal.
Tomcat stopped.

[AnnWorley · Accepted solution]

The error reported by your user (java.sql.SQLException: Connections could not be acquired from the underlying database!) indicates Confluence lost it's database connection. Please see this article - I would enumerate the resolutions but there are several things to check: Connections could not be acquired from the underlying database

[jpcartailler]

Thank you - we tracked it down! Password had been changed on the database side of things and someone had updated our other apps (like JIRA) but not Confluence. Many thx!