Tomcat fails to start after upgrading Confluence

Chris Riley June 9, 2017

Hi folks,

 

I’ve run an upgrade of Confluence from 5.5.2 to 6.2. After this upgrade, Confluence attempts to restart, but the log shows that Tomcat is failing to start due to a severe error, below. From the internet searches I’ve done up to now, it appears the message is referring to a <filter> tag in web.xml. It also suggests that more info can be found by looking at the appropriate log file. I don’t know what log file this message is referring to, and I have looked at all the logs in the \Atlassian\Confluence\logs folder.

 

So, I’m thinking the message is telling me that there might be a way to get a more verbose message that will at least tell me what <filter> is the problem, and I can go from there. It’s either that, or back out of the upgrade and try again, but I get a feeling I’m going to have the same web.xml problem.

 

Can anyone suggest how to get more info about this error?

 

Your help is very much appreciated.

 

Chris

 

 

08-Jun-2017 09:29:33.657 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)

08-Jun-2017 09:29:33.657 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]

08-Jun-2017 09:29:33.720 INFO [localhost-startStop-2] org.springframework.context.support.DefaultLifecycleProcessor.start Starting beans in phase 2147483647

08-Jun-2017 09:29:33.767 INFO [localhost-startStop-2] org.springframework.web.servlet.DispatcherServlet.initServletBean FrameworkServlet 'dispatcher': initialization completed in 2079 ms

08-Jun-2017 09:33:12.539 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

08-Jun-2017 09:33:12.539 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal Context [] startup failed due to previous errors

08-Jun-2017 09:33:31.320 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesJdbc The web application [ROOT] 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.

08-Jun-2017 09:33:31.320 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesJdbc The web application [ROOT] 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.

08-Jun-2017 09:33:31.320 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesJdbc The web application [ROOT] 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.

08-Jun-2017 09:33:31.320 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesJdbc The web application [ROOT] 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.

 

 

1 answer

0 votes
AnnWorley
Atlassian Team
Atlassian Team members are employees working across the company in a wide variety of roles.
June 9, 2017

Please check <confluence_home>/logs/atlassian-confluence.log
(The <confluence_home> directory is the path defined in the following file: <confluence_install>/confluence/WEB-INF/classes/confluence-init.properties)

If the catalina log is not showing "server startup in xxx ms" then there may not be much in the atlassian-confluence.log.

I look forward to hearing what you find.

 

Chris Riley June 9, 2017

Og for goodness sake, that's where that log is! I was looking for it. I thought it was in the \Atlassian\Confluence\logs folder, but could not find it. Good, let me take a look through that, and I'll reply with my findings.

Thanks for the tip Ann. :)

Chris

AnnWorley
Atlassian Team
Atlassian Team members are employees working across the company in a wide variety of roles.
June 9, 2017

My pleasure - your Tomcat log says "Full details will be found in the appropriate container log file" as you mentioned, so hopefully there will be a hint there.

Chris Riley June 12, 2017

Looks like startup is unable to locate the database because it is pointing to the wrong location listed in the file productionDatabaseContext.xml. For these tests, we are using the internal database for the original install of 5.5.2, as well as the 6.2 upgrade. The link below is about the same problem, but for version 6.1 – we used 6.2. And, their problem doesn’t seem to be a part of an upgrade process. Unfortunately, no one has posted a solution. Anybody know where the file productionDatabaseContext.xml? Maybe it will reveal the problem, and can be fixed. Otherwise, Im not sure if even backing out and running the upgrade again is going to fix it, if it couldn’t find the original database during the first upgrade attempt. Any thoughts? Somebody else had this problem: https://community.developer.atlassian.com/t/bug-with-confluence-6-1-0/1124 … 2017-06-12 10:54:30,164 WARN [localhost-startStop-1] [jdbc.env.internal.JdbcEnvironmentInitiator] initiateService HHH000342: Could not obtain connection to query metadata : Unable to resolve name [com.atlassian.hibernate.dialect.HSQL2Dialect] as strategy [org.hibernate.dialect.Dialect] 2017-06-12 10:54:30,210 WARN [localhost-startStop-1] [confluence.impl.vcache.SynchronousExternalCache] lambda$get$11 Failed to read entry from cache 'com.atlassian.bandana.BandanaPersister': Failed due to UNCLASSIFIED_FAILURE 2017-06-12 10:54:30,664 WARN [localhost-startStop-1] [jdbc.env.internal.JdbcEnvironmentInitiator] initiateService HHH000342: Could not obtain connection to query metadata : Unable to resolve name [com.atlassian.hibernate.dialect.HSQL2Dialect] as strategy [org.hibernate.dialect.Dialect] 2017-06-12 10:54:30,679 ERROR [localhost-startStop-1] [atlassian.confluence.plugin.BandanaPluginStateStore] load Exception when loading plugins state from the database. Falling back to in memory state. java.util.concurrent.CompletionException: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'tenantedTransactionManager' defined in class path resource [databaseSubsystemContext.xml]: Invocation of init method failed; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'tenantedLocalSessionFactoryBean5' defined in class path resource [productionDatabaseContext.xml]: Invocation of init method failed; nested exception is org.hibernate.service.spi.ServiceException: Unable to create requested service [org.hibernate.engine.jdbc.env.spi.JdbcEnvironment]                 at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:273)                 at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:280)                 at java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:824)                 at java.util.concurrent.CompletableFuture.uniHandleStage(CompletableFuture.java:834)                 at java.util.concurrent.CompletableFuture.handle(CompletableFuture.java:2155)                 at java.util.concurrent.CompletableFuture.handle(CompletableFuture.java:110)                 at com.atlassian.confluence.impl.concurrency.CompletionStageUtils.foldResult(CompletionStageUtils.java:19)                 at com.atlassian.confluence.impl.vcache.SynchronousExternalCache.get(SynchronousExternalCache.java:236)                 at com.atlassian.confluence.setup.bandana.ConfluenceCachingBandanaPersister.retrieve(ConfluenceCachingBandanaPersister.java:78)                 at com.atlassian.confluence.setup.bandana.ConfluenceCachingBandanaPersister.retrieve(ConfluenceCachingBandanaPersister.java:71)                 at com.atlassian.bandana.DefaultBandanaManager.getValue(DefaultBandanaManager.java:32)                 at com.atlassian.bandana.DefaultBandanaManager.getValue(DefaultBandanaManager.java:24)                 at com.atlassian.confluence.plugin.BandanaPluginStateStore.lambda$load$1(BandanaPluginStateStore.java:57)                 at com.atlassian.confluence.tenant.TenantGate$3.call(TenantGate.java:145)                 at com.atlassian.confluence.plugin.BandanaPluginStateStore.load(BandanaPluginStateStore.java:69)                 at com.atlassian.confluence.plugin.CachingPluginStateStore.lambda$load$0(CachingPluginStateStore.java:44)                 at com.atlassian.vcache.internal.core.metrics.TimedSupplier.get(TimedSupplier.java:32)                 at com.atlassian.vcache.internal.legacy.LegacyJvmCache.lambda$get$4(LegacyJvmCache.java:52)                 at java.util.Optional.orElseGet(Optional.java:267)                 at com.atlassian.vcache.internal.legacy.LegacyJvmCache.get(LegacyJvmCache.java:50)                 at com.atlassian.vcache.internal.core.metrics.TimedLocalCacheOperations.get(TimedLocalCacheOperations.java:64)                 at com.atlassian.confluence.plugin.CachingPluginStateStore.load(CachingPluginStateStore.java:43)                 at com.atlassian.plugin.manager.PluginPersistentStateModifier.getState(PluginPersistentStateModifier.java:18)                 at com.atlassian.plugin.manager.DefaultPluginManager.getState(DefaultPluginManager.java:1090)                 at com.atlassian.plugin.manager.DefaultPluginManager.earlyStartup(DefaultPluginManager.java:540)                 at com.atlassian.confluence.plugin.ConfluencePluginManager.earlyStartup(ConfluencePluginManager.java:143)                 at com.atlassian.confluence.plugin.PluginFrameworkContextListener.contextInitialized(PluginFrameworkContextListener.java:63)                 at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4853)                 at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5314)                 at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:145)                 at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1408)                 at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1398)                 at java.util.concurrent.FutureTask.run(FutureTask.java:266)                 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)                 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)                 at java.lang.Thread.run(Thread.java:748) Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'tenantedTransactionManager' defined in class path resource [databaseSubsystemContext.xml]: Invocation of init method failed; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'tenantedLocalSessionFactoryBean5' defined in class path resource [productionDatabaseContext.xml]: Invocation of init method failed; nested exception is org.hibernate.service.spi.ServiceException: Unable to create requested service [org.hibernate.engine.jdbc.env.spi.JdbcEnvironment]                 at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1578)                 at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:545)                 at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)                 at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)                 at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)                 at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)                 at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:207)                 at org.springframework.beans.factory.support.CglibSubclassingInstantiationStrategy$LookupOverrideMethodInterceptor.intercept(CglibSubclassingInstantiationStrategy.java:285)                 at com.atlassian.confluence.tenant.TenantGate$$EnhancerBySpringCGLIB$$767ea2cd.createTenantedDelegate(<generated>)                 at com.atlassian.confluence.tenant.TenantGate$2.getTarget(TenantGate.java:114)                 at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:187)                 at com.sun.proxy.$Proxy53.getTransaction(Unknown Source)                 at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:427)                 at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:276)                 at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)                 at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)                 at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:208)                 at com.sun.proxy.$Proxy55.retrieve(Unknown Source)                 at com.atlassian.confluence.setup.bandana.ConfluenceCachingBandanaPersister.lambda$retrieve$0(ConfluenceCachingBandanaPersister.java:80)                 at com.atlassian.confluence.impl.vcache.SynchronousExternalCache.lambda$get$11(SynchronousExternalCache.java:239)                 at com.atlassian.confluence.impl.concurrency.CompletionStageUtils.lambda$foldResult$0(CompletionStageUtils.java:19)                 at java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:822)                 ... 33 more

Chris Riley June 12, 2017

Hmm, trying to reply, but message keeps telling me that it was not accepted due to spam/language? How do I post the info?

AnnWorley
Atlassian Team
Atlassian Team members are employees working across the company in a wide variety of roles.
June 12, 2017

I am not sure what could be triggering the spam filter because I can't tell what you are trying to post, unfortunately, since it can't be posted (Catch-22).

If you are posting log snippets or code, maybe it will help to use the <> in the editor, like:

some code and logs
Chris Riley June 12, 2017

I've opened a ticket. Seems as though Atlassian is using some kind of holistic function for this? Very frustrating!

AnnWorley
Atlassian Team
Atlassian Team members are employees working across the company in a wide variety of roles.
June 12, 2017

I am sorry to hear of your frustration. Providing your logs to support for examination does seem like a good idea. I am sure they can help you get your instance up and running again.

Like Kamal Kailasa Babu likes this
Chris Riley June 15, 2017

Just wanted to keep this thread up to date...

I have a ticket open about this with Atlassian. This problem has occurred because of changes to the embedded database between 5.5 and 6.2. It was HSQLDB in 5.7, and was changed to H2 in 5.8. I didn't notice this in the release notes. Regardless, there would have been no way to prepare for this error before it happenned.

I'm following these instructions provided by Atlassian:

  1. Shutdown Confluence
  2. Edit your /confluence_home/confluence.cfg.xml file
  3. Change the following:
   <property name="hibernate.dialect">com.atlassian.hibernate.dialect.HSQL2Dialect</property>

to

   <property name="hibernate.dialect">org.hibernate.dialect.H2Dialect</property>

So far, this has at least prompted Confluence to trigger an update recovery, and fix the tables in the correct database, but then produces further errors, which I'm looking at right now. I'm also able to display the login page for the first time since I ran the upgrade.

To be clear, this problem is related only when using the embedded database. Normally production uses external databases, and this issue would not occur. Atlassian may have to come up with a solution, although looks like very few have run into this particular non-prod test scenario using an embedded DB.

Will post soon...

Chris Riley June 20, 2017

The above is the solution for this problem. Embedded databases changed between 5.5.2 and 6.2, and the confluence.cfg.xml file has to be updated as per my last post. After a couple of restarts, the upgrade was able to recover and complete, and Confluence 6.2 is now running in the test environment.

Thanks.

AnnWorley
Atlassian Team
Atlassian Team members are employees working across the company in a wide variety of roles.
June 20, 2017

Chris, I am sorry I missed that you were using the embedded database. I understand it's a test instance, so issues with the dependability of the H2 database are not show stoppers.

If you are using the test environment to try out an upgrade for Production, please also test with a copy of the Production database, on the same RDMS, to avoid any database related suprises when you do the Production upgrade.

Thank you so much for updating the Community to let us know what happened with your support request.

Suggest an answer

Log in or Sign up to answer
TAGS
AUG Leaders

Atlassian Community Events