Community resources
Community resources
Community resources
- Community
- Products
- Confluence
- Questions
- Confluence Service Will Not Start on Server
Confluence Service Will Not Start on Server
Neither I nor anyone in my department can think of any updates or configuration changes that were made the server or the Confluence application, but Tomcat will either not start, or start and then die immediately.
Confluence is installed on a VM running Ubuntu Server 16.04. It appears to have plenty of memory and partition space. I've looked through various logs without seeing anything specific to describe the problem in a way I can understand. I have an open support ticket, but given the importance of this outage to our organization, any prompt help would be much appreciated.
Here is what I see when I run start-confluence.sh -fg :
****************************************************
17-Apr-2019 11:09:48.162 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server} Setting property 'debug' to '0' did not find a matching property.
17-Apr-2019 11:09:48.258 WARNING [main] org.apache.catalina.startup.SetAllPropertiesRule.begin [SetAllPropertiesRule]{Server/Service/Connector} Setting property 'debug' to '0' did not find a matching property.
17-Apr-2019 11:09:48.345 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine} Setting property 'debug' to '0' did not find a matching property.
17-Apr-2019 11:09:48.350 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.
17-Apr-2019 11:09:48.388 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.
17-Apr-2019 11:09:48.409 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.
17-Apr-2019 11:09:48.692 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8090"]
17-Apr-2019 11:09:48.705 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
17-Apr-2019 11:09:48.712 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 702 ms
17-Apr-2019 11:09:48.720 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Tomcat-Standalone]
17-Apr-2019 11:09:48.720 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/9.0.12
17-Apr-2019 11:09:50.280 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.
17-Apr-2019 11:09:50.494 INFO [localhost-startStop-2] org.apache.catalina.core.ApplicationContext.log Spring WebApplicationInitializers detected on classpath: [com.atlassian.synchrony.proxy.SynchronyDispatcherServletInitializer@6dfacbd2]
17-Apr-2019 11:09:50.825 INFO [localhost-startStop-2] org.apache.catalina.core.ApplicationContext.log Initializing Spring FrameworkServlet 'dispatcher'
17-Apr-2019 11:09:50.825 INFO [localhost-startStop-2] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization started
17-Apr-2019 11:09:50.830 INFO [localhost-startStop-2] org.springframework.web.context.support.AnnotationConfigWebApplicationContext.prepareRefresh Refreshing WebApplicationContext for namespace 'dispatcher-servlet': startup date [Wed Apr 17 11:09:50 EDT 2019]; root of context hierarchy
17-Apr-2019 11:09:50.884 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]
2019-04-17 11:09:50,915 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] contextInitialized Starting Confluence 6.12.2 [build 7901 based on commit hash 119ca25093da5dbe5f504cc7d71e386a1aab2736] - synchrony version 2.1.0-master-e100417c
17-Apr-2019 11:09:51.454 INFO [localhost-startStop-2] org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler.initialize Initializing ExecutorService 'defaultSockJsTaskScheduler'
17-Apr-2019 11:09:51.508 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]
17-Apr-2019 11:09:51.883 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]
17-Apr-2019 11:09:51.990 INFO [localhost-startStop-2] org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.initControllerAdviceCache Looking for @ControllerAdvice: WebApplicationContext for namespace 'dispatcher-servlet': startup date [Wed Apr 17 11:09:50 EDT 2019]; root of context hierarchy
17-Apr-2019 11:09:52.100 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()
17-Apr-2019 11:09:52.103 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)
17-Apr-2019 11:09:52.233 INFO [localhost-startStop-2] org.springframework.context.support.DefaultLifecycleProcessor.start Starting beans in phase 2147483647
17-Apr-2019 11:09:52.328 INFO [localhost-startStop-2] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization completed in 1503 ms
Killed
****************************************************
Here is what I see in journalctl pertaining to confluence.service :
Apr 17 10:44:10 ub16-confluence.pbsd.net crontab[20716]: (confluence) REPLACE (confluence)
Apr 17 11:03:07 ub16-confluence.pbsd.net systemd[1]: Stopping confluence.service...
Apr 17 11:03:07 ub16-confluence.pbsd.net confluence[22339]: executing using dedicated user
Apr 17 11:03:07 ub16-confluence.pbsd.net runuser[22345]: pam_unix(runuser:session): session opened for user confluence by (uid=0)
Apr 17 11:03:07 ub16-confluence.pbsd.net confluence[22339]: If you encounter issues starting up Confluence, please see the Installation guide at http://confluence.atlassian.com/display/DOC/Confluence+Installation+Guide
Apr 17 11:03:07 ub16-confluence.pbsd.net confluence[22339]: Server startup logs are located in /opt/atlassian/confluence/logs/catalina.out
Apr 17 11:03:07 ub16-confluence.pbsd.net confluence[22339]: ---------------------------------------------------------------------------
Apr 17 11:03:07 ub16-confluence.pbsd.net confluence[22339]: Using Java: /opt/atlassian/confluence/jre//bin/java
Apr 17 11:03:08 ub16-confluence.pbsd.net confluence[22339]: 2019-04-17 11:03:08,034 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
Apr 17 11:03:08 ub16-confluence.pbsd.net confluence[22339]: ---------------------------------------------------------------------------
Apr 17 11:03:08 ub16-confluence.pbsd.net confluence[22339]: PID file found but either no matching process was found or the current user does not have permission to stop the process. Stop aborted.
Apr 17 11:03:08 ub16-confluence.pbsd.net runuser[22345]: pam_unix(runuser:session): session closed for user confluence
Apr 17 11:03:08 ub16-confluence.pbsd.net systemd[1]: confluence.service: Control process exited, code=exited status=1
Apr 17 11:03:08 ub16-confluence.pbsd.net systemd[1]: Stopped confluence.service.
Apr 17 11:03:08 ub16-confluence.pbsd.net systemd[1]: confluence.service: Unit entered failed state.
Apr 17 11:03:08 ub16-confluence.pbsd.net systemd[1]: confluence.service: Failed with result 'exit-code'.
Apr 17 11:03:08 ub16-confluence.pbsd.net systemd[1]: Starting confluence.service...
Apr 17 11:03:08 ub16-confluence.pbsd.net confluence[22394]: To run Confluence in the foreground, start the server with start-confluence.sh -fg
Apr 17 11:03:08 ub16-confluence.pbsd.net confluence[22394]: executing using dedicated user: confluence
Apr 17 11:03:08 ub16-confluence.pbsd.net runuser[22399]: pam_unix(runuser:session): session opened for user confluence by (uid=0)
Apr 17 11:03:08 ub16-confluence.pbsd.net confluence[22394]: If you encounter issues starting up Confluence, please see the Installation guide at http://confluence.atlassian.com/display/DOC/Confluence+Installation+Guide
Apr 17 11:03:08 ub16-confluence.pbsd.net confluence[22394]: Server startup logs are located in /opt/atlassian/confluence/logs/catalina.out
Apr 17 11:03:08 ub16-confluence.pbsd.net confluence[22394]: ---------------------------------------------------------------------------
Apr 17 11:03:08 ub16-confluence.pbsd.net confluence[22394]: Using Java: /opt/atlassian/confluence/jre//bin/java
Apr 17 11:03:08 ub16-confluence.pbsd.net confluence[22394]: 2019-04-17 11:03:08,753 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
Apr 17 11:03:08 ub16-confluence.pbsd.net confluence[22394]: ---------------------------------------------------------------------------
Apr 17 11:03:08 ub16-confluence.pbsd.net confluence[22394]: Existing PID file found during start.
Apr 17 11:03:08 ub16-confluence.pbsd.net confluence[22394]: Removing/clearing stale PID file.
Apr 17 11:03:08 ub16-confluence.pbsd.net confluence[22394]: Tomcat started.
Apr 17 11:03:08 ub16-confluence.pbsd.net runuser[22399]: pam_unix(runuser:session): session closed for user confluence
Apr 17 11:03:08 ub16-confluence.pbsd.net systemd[1]: Started confluence.service.
Apr 17 11:03:18 ub16-confluence.pbsd.net crontab[22489]: (confluence) REPLACE (confluence)
****************************************************
And here is what I see in catalina.out :
17-Apr-2019 08:43:31.382 INFO [localhost-startStop-2] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization completed in 1428 ms
17-Apr-2019 11:03:09.335 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server} Setting property 'debug' to '0' did not find a matching property.
17-Apr-2019 11:03:09.403 WARNING [main] org.apache.catalina.startup.SetAllPropertiesRule.begin [SetAllPropertiesRule]{Server/Service/Connector} Setting property 'debug' to '0' did not find a matching property.
17-Apr-2019 11:03:09.491 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine} Setting property 'debug' to '0' did not find a matching property.
17-Apr-2019 11:03:09.496 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.
17-Apr-2019 11:03:09.541 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.
17-Apr-2019 11:03:09.569 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.
17-Apr-2019 11:03:10.035 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8090"]
17-Apr-2019 11:03:10.048 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
17-Apr-2019 11:03:10.058 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 815 ms
17-Apr-2019 11:03:10.069 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Tomcat-Standalone]
17-Apr-2019 11:03:10.069 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/9.0.12
17-Apr-2019 11:03:11.590 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.
17-Apr-2019 11:03:11.840 INFO [localhost-startStop-2] org.apache.catalina.core.ApplicationContext.log Spring WebApplicationInitializers detected on classpath: [com.atlassian.synchrony.proxy.SynchronyDispatcherServletInitializer@14bc297b]
17-Apr-2019 11:03:12.174 INFO [localhost-startStop-2] org.apache.catalina.core.ApplicationContext.log Initializing Spring FrameworkServlet 'dispatcher'
17-Apr-2019 11:03:12.174 INFO [localhost-startStop-2] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization started
17-Apr-2019 11:03:12.179 INFO [localhost-startStop-2] org.springframework.web.context.support.AnnotationConfigWebApplicationContext.prepareRefresh Refreshing WebApplicationContext for namespace 'dispatcher-servlet': startup date [Wed Apr 17 11:03:12 EDT 2019]; root of context hierarchy
17-Apr-2019 11:03:12.262 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]
2019-04-17 11:03:12,284 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] contextInitialized Starting Confluence 6.12.2 [build 7901 based on commit hash 119ca25093da5dbe5f504cc7d71e386a1aab2736] - synchrony version 2.1.0-master-e100417c
17-Apr-2019 11:03:12.834 INFO [localhost-startStop-2] org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler.initialize Initializing ExecutorService 'defaultSockJsTaskScheduler'
17-Apr-2019 11:03:12.891 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]
17-Apr-2019 11:03:13.348 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()
17-Apr-2019 11:03:13.351 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)
17-Apr-2019 11:03:13.380 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]
17-Apr-2019 11:03:13.422 INFO [localhost-startStop-2] org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.initControllerAdviceCache Looking for @ControllerAdvice: WebApplicationContext for namespace 'dispatcher-servlet': startup date [Wed Apr 17 11:03:12 EDT 2019]; root of context hierarchy
17-Apr-2019 11:03:13.566 INFO [localhost-startStop-2] org.springframework.context.support.DefaultLifecycleProcessor.start Starting beans in phase 2147483647
17-Apr-2019 11:03:13.609 INFO [localhost-startStop-2] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization completed in 1435 ms
2 answers
1 accepted
I have resolved this issue. We were on 6.12.2 and got hit with this exploit:
https://confluence.atlassian.com/doc/confluence-security-advisory-2019-03-20-966660264.html
Instructions on how to resolve the problem (prior to upgrading, of course) are noted here:
I don't see anything critical in the logs. Was the Linux OS updated? As it seems that the whole tomcat was killed, could you check the linux system logs (/var/log/...)?
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
Posted before I saw your update... Well, pointed into the right direction ;-) Hope you get it all recovered.
Best
JP
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.