Confluence started failing with 404 log shows SEVERE One of more Filters Failed to Start Edited

[petritis]

Confluence was working and one day started failing with 404 errors the catalina.log does not show much.

It shows a couple severe errors:

22-Nov-2017 08:41:49.051 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal One or more Filters failed to start. Full details will be found in the appropriate container log file
22-Nov-2017 08:41:49.059 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal Context [/confluence] startup failed due to previous errors

And here is the full log:

22-Nov-2017 08:40:55.914 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server} Setting property 'debug' to '0' did not find a matching property.
22-Nov-2017 08:40:56.130 WARNING [main] org.apache.catalina.startup.SetAllPropertiesRule.begin [SetAllPropertiesRule]{Server/Service/Connector} Setting property 'debug' to '0' did not find a matching property.
22-Nov-2017 08:40:56.151 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin [SetPropertiesRule]{Server/Service/Engine} Setting property 'debug' to '0' did not find a matching property.
22-Nov-2017 08:40:56.164 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.
22-Nov-2017 08:40:56.227 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.
22-Nov-2017 08:40:56.299 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.
22-Nov-2017 08:40:57.246 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8090"]
22-Nov-2017 08:40:57.347 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
22-Nov-2017 08:40:57.351 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 1644 ms
22-Nov-2017 08:40:57.386 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service Tomcat-Standalone
22-Nov-2017 08:40:57.388 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.0.43
22-Nov-2017 08:41:02.467 INFO [localhost-startStop-2] org.apache.catalina.core.ApplicationContext.log Spring WebApplicationInitializers detected on classpath: [com.atlassian.synchrony.proxy.SynchronyDispatcherServletInitializer@7175d7d2]
22-Nov-2017 08:41:04.047 INFO [localhost-startStop-2] org.apache.catalina.core.ApplicationContext.log Initializing Spring FrameworkServlet 'dispatcher'
22-Nov-2017 08:41:04.048 INFO [localhost-startStop-2] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization started
22-Nov-2017 08:41:04.083 INFO [localhost-startStop-2] org.springframework.web.context.support.AnnotationConfigWebApplicationContext.prepareRefresh Refreshing WebApplicationContext for namespace 'dispatcher-servlet': startup date [Wed Nov 22 08:41:04 EST 2017]; root of context hierarchy
22-Nov-2017 08:41:04.228 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]
2017-11-22 08:41:05,066 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] contextInitialized Starting Confluence 6.4.0 [build 7400 based on commit hash f2dd15fadfb45568d4c57973599993b8f86142a0] - synchrony version 1.0.0-release-confluence_6.1-4020a123
22-Nov-2017 08:41:05.800 INFO [localhost-startStop-2] org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler.initialize Initializing ExecutorService 'defaultSockJsTaskScheduler'
22-Nov-2017 08:41:07.173 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]
22-Nov-2017 08:41:08.390 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]
22-Nov-2017 08:41:08.549 INFO [localhost-startStop-2] org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.initControllerAdviceCache Looking for @ControllerAdvice: WebApplicationContext for namespace 'dispatcher-servlet': startup date [Wed Nov 22 08:41:04 EST 2017]; root of context hierarchy
22-Nov-2017 08:41:08.919 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()
22-Nov-2017 08:41:08.921 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)
22-Nov-2017 08:41:09.301 INFO [localhost-startStop-2] org.springframework.context.support.DefaultLifecycleProcessor.start Starting beans in phase 2147483647
22-Nov-2017 08:41:09.376 INFO [localhost-startStop-2] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization completed in 5328 ms
2017-11-22 08:41:15,956 INFO [localhost-startStop-1] [atlassian.confluence.cluster.DefaultClusterConfigurationHelper] lambda$populateExistingClusterSetupConfig$1 Populating setup configuration if running with Cluster mode...
22-Nov-2017 08:41:49.051 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal One or more Filters failed to start. Full details will be found in the appropriate container log file
22-Nov-2017 08:41:49.059 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal Context [/confluence] startup failed due to previous errors
22-Nov-2017 08:41:49.208 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesJdbc The web application [confluence] registered the JDBC driver [net.sourceforge.jtds.jdbc.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
22-Nov-2017 08:41:49.209 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesJdbc The web application [confluence] registered the JDBC driver [com.github.gquintana.metrics.sql.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
22-Nov-2017 08:41:49.209 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesJdbc The web application [confluence] registered the JDBC driver [org.hsqldb.jdbc.JDBCDriver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
22-Nov-2017 08:41:49.209 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesJdbc The web application [confluence] registered the JDBC driver [com.microsoft.sqlserver.jdbc.SQLServerDriver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
22-Nov-2017 08:41:49.210 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesJdbc The web application [confluence] registered the JDBC driver [org.h2.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
22-Nov-2017 08:41:49.210 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesJdbc The web application [confluence] registered the JDBC driver [org.postgresql.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
22-Nov-2017 08:41:49.260 INFO [localhost-startStop-3] org.apache.catalina.startup.HostConfig.deployDescriptor Deploying configuration descriptor /opt/atlassian/confluence/conf/Standalone/localhost/synchrony-proxy.xml
22-Nov-2017 08:41:49.286 WARNING [localhost-startStop-3] org.apache.catalina.startup.SetContextPropertiesRule.begin [SetContextPropertiesRule]{Context} Setting property 'debug' to '0' did not find a matching property.
22-Nov-2017 08:41:50.969 INFO [localhost-startStop-3] org.apache.catalina.core.ApplicationContext.log Spring WebApplicationInitializers detected on classpath: [com.atlassian.synchrony.proxy.SynchronyDispatcherServletInitializer@64bd4cf9]
22-Nov-2017 08:41:51.804 INFO [localhost-startStop-3] org.apache.catalina.core.ApplicationContext.log Initializing Spring FrameworkServlet 'dispatcher'
22-Nov-2017 08:41:51.805 INFO [localhost-startStop-3] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization started
22-Nov-2017 08:41:51.824 INFO [localhost-startStop-3] org.springframework.web.context.support.AnnotationConfigWebApplicationContext.prepareRefresh Refreshing WebApplicationContext for namespace 'dispatcher-servlet': startup date [Wed Nov 22 08:41:51 EST 2017]; root of context hierarchy
22-Nov-2017 08:41:51.972 INFO [localhost-startStop-3] org.springframework.web.context.support.AnnotationConfigWebApplicationContext.loadBeanDefinitions Registering annotated classes: [class com.atlassian.synchrony.proxy.websocket.WebSocketConfig,class com.atlassian.synchrony.proxy.web.SynchronyWebMvcConfig]
22-Nov-2017 08:41:53.183 INFO [localhost-startStop-3] org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler.initialize Initializing ExecutorService 'defaultSockJsTaskScheduler'
22-Nov-2017 08:41:53.845 INFO [localhost-startStop-3] 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]
22-Nov-2017 08:41:54.432 INFO [localhost-startStop-3] org.springframework.web.servlet.handler.SimpleUrlHandlerMapping.registerHandler Mapped URL path [/**] onto handler of type [class org.springframework.web.servlet.resource.DefaultServletHttpRequestHandler]
22-Nov-2017 08:41:54.519 INFO [localhost-startStop-3] org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.initControllerAdviceCache Looking for @ControllerAdvice: WebApplicationContext for namespace 'dispatcher-servlet': startup date [Wed Nov 22 08:41:51 EST 2017]; root of context hierarchy
22-Nov-2017 08:41:54.709 INFO [localhost-startStop-3] 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()
22-Nov-2017 08:41:54.712 INFO [localhost-startStop-3] 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)
22-Nov-2017 08:41:54.905 INFO [localhost-startStop-3] org.springframework.context.support.DefaultLifecycleProcessor.start Starting beans in phase 2147483647
22-Nov-2017 08:41:54.983 INFO [localhost-startStop-3] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization completed in 3168 ms
22-Nov-2017 08:41:54.993 INFO [localhost-startStop-3] org.apache.catalina.startup.HostConfig.deployDescriptor Deployment of configuration descriptor /opt/atlassian/confluence/conf/Standalone/localhost/synchrony-proxy.xml has finished in 5,733 ms
22-Nov-2017 08:41:55.003 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8090"]
22-Nov-2017 08:41:55.061 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 54268 ms

I haven't been able to figure out what is wrong, and have been without confluence for over a week now (it is self hosted and used for family info - but with very light usage)

[petritis]

I turned on the debug logging profile and saw that one problem was that some directories were owned by root.  It started up better after that but still had the 404.

I ended up installing confluence on a VM and restored to it. That is currently working.  When I get a chance I will wipe it on the 'server' that it is on, reinstall and restore it.  It is only used by family and is very, very low traffic, so it might be a while before I get around to moving it back.

[Nic Brough [Adaptavist]]

This is typical of a Confluence that has been installed to run as one user, then run as another user (who takes ownership of some of the installation and data) and then flipped back to the correct user, who then finds they can't write to all the files they need to because the other user now owns them.

The usual correction is to stop Confluence completely, recursively change the ownership back to the right owner for confluence home and install, and restart it.