Unable to start Confluence or some plugins are disabled upon startup

Problem

  1. Confluence uses Microsoft SQL Server.
  2. Confluence cannot start after installing or upgrading some plugins or the newly installed/upgraded plugins are disabled upon startup. Known affected plugins:
    • Universal Plugin Manager (UPM)
    • Office Connector
    • SharePoint Connector
    • Scroll Office
    • RefinedWiki
    • (New) Code Macro
    • Table Plugin
    • Team Calendars for Confluence
  3. The following appears in the atlassian-confluence.log:

    2011-02-28 14:49:29,366 ERROR [Thread-1] [internal.util.concurrent.RunnableTimedExecution] execute Closing runnable for context NonValidatingOsgiBundleXmlApplicationContext(bundle=com.atlassian.confluence.extra.officeconnector, config=osgibundle:/META-INF/spring/*.xml) did not finish in 10000ms; consider taking a snapshot and then shutdown the VM in case the thread still hangs
    

    In context similar to:

    2011-02-28 14:49:19,366 INFO [Thread-1] [atlassian.plugin.manager.DefaultPluginManager] notifyPluginDisabled Disabling com.atlassian.confluence.extra.officeconnector
    2011-02-28 14:49:29,366 ERROR [Thread-1] [internal.util.concurrent.RunnableTimedExecution] execute Closing runnable for context NonValidatingOsgiBundleXmlApplicationContext(bundle=com.atlassian.confluence.extra.officeconnector, config=osgibundle:/META-INF/spring/*.xml) did not finish in 10000ms; consider taking a snapshot and then shutdown the VM in case the thread still hangs
    2011-02-28 14:49:29,398 INFO [Thread-1] [atlassian.plugin.manager.DefaultPluginManager] notifyPluginDisabled Disabling com.atlassian.confluence.extra.sharepoint
    2011-02-28 14:49:39,398 ERROR [Thread-1] [internal.util.concurrent.RunnableTimedExecution] execute Closing runnable for context NonValidatingOsgiBundleXmlApplicationContext(bundle=com.atlassian.confluence.extra.sharepoint, config=osgibundle:/META-INF/spring/*.xml) did not finish in 10000ms; consider taking a snapshot and then shutdown the VM in case the thread still hangs
    2011-02-28 14:49:39,398 ERROR [Thread-1] [atlassian.plugin.manager.PluginEnabler] enable Unable to start the following plugins due to timeout while waiting for plugin to enable: com.atlassian.confluence.extra.officeconnector,com.atlassian.confluence.extra.sharepoint
    2011-02-28 14:49:40,335 INFO [Thread-1] [atlassian.plugin.manager.DefaultPluginManager] init Plugin system started in 0:22:00.859
    2011-02-28 14:49:41,085 ERROR [Spring executor 7] [extender.internal.activator.ContextLoaderListener] onOsgiApplicationEvent Application context refresh failed (NonValidatingOsgiBundleXmlApplicationContext(bundle=com.atlassian.confluence.extra.officeconnector, config=osgibundle:/META-INF/spring/*.xml))
    java.lang.IllegalStateException: Invalid BundleContext.
    	at org.apache.felix.framework.BundleContextImpl.checkValidity(BundleContextImpl.java:366)
    	at org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:236)
    	at org.springframework.osgi.context.support.AbstractOsgiBundleApplicationContext.publishContextAsOsgiServiceIfNecessary(AbstractOsgiBundleApplicationContext.java:344)
    	at org.springframework.osgi.context.support.AbstractOsgiBundleApplicationContext.finishRefresh(AbstractOsgiBundleApplicationContext.java:237)
    	at org.springframework.osgi.context.support.AbstractDelegatedExecutionApplicationContext$4.run(AbstractDelegatedExecutionApplicationContext.java:358)
    	at org.springframework.osgi.util.internal.PrivilegedUtils.executeWithCustomTCCL(PrivilegedUtils.java:85)
    	at org.springframework.osgi.context.support.AbstractDelegatedExecutionApplicationContext.completeRefresh(AbstractDelegatedExecutionApplicationContext.java:320)
    	at org.springframework.osgi.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor$CompleteRefreshTask.run(DependencyWaiterApplicationContextExecutor.java:132)
    	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    	at java.lang.Thread.run(Thread.java:662)
    2011-02-28 14:49:42,163 ERROR [Spring executor 6] [extender.internal.activator.ContextLoaderListener] onOsgiApplicationEvent Application context refresh failed (NonValidatingOsgiBundleXmlApplicationContext(bundle=com.atlassian.confluence.extra.sharepoint, config=osgibundle:/META-INF/spring/*.xml))
    java.lang.IllegalStateException: Invalid BundleContext.
    	at org.apache.felix.framework.BundleContextImpl.checkValidity(BundleContextImpl.java:366)
    	at org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:236)
    	at org.springframework.osgi.context.support.AbstractOsgiBundleApplicationContext.publishContextAsOsgiServiceIfNecessary(AbstractOsgiBundleApplicationContext.java:344)
    	at org.springframework.osgi.context.support.AbstractOsgiBundleApplicationContext.finishRefresh(AbstractOsgiBundleApplicationContext.java:237)
    	at org.springframework.osgi.context.support.AbstractDelegatedExecutionApplicationContext$4.run(AbstractDelegatedExecutionApplicationContext.java:358)
    	at org.springframework.osgi.util.internal.PrivilegedUtils.executeWithCustomTCCL(PrivilegedUtils.java:85)
    	at org.springframework.osgi.context.support.AbstractDelegatedExecutionApplicationContext.completeRefresh(AbstractDelegatedExecutionApplicationContext.java:320)
    	at org.springframework.osgi.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor$CompleteRefreshTask.run(DependencyWaiterApplicationContextExecutor.java:132)
    	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    	at java.lang.Thread.run(Thread.java:662)

Diagnosis

Take thread dumps of the process every 30 seconds from start-up until after the timeout warnings. If they contain the following, then the Workaround should apply. If not, the thread-dumps should help diagnose the real problem.

Spring executor stack trace
"Spring executor 1" prio=6 tid=0x36810c00 nid=0xfb0 runnable [0x3851e000]
   java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at java.io.DataInputStream.readFully(DataInputStream.java:178)
	at java.io.DataInputStream.readFully(DataInputStream.java:152)
	at net.sourceforge.jtds.jdbc.SharedSocket.readPacket(SharedSocket.java:841)
	at net.sourceforge.jtds.jdbc.SharedSocket.getNetPacket(SharedSocket.java:722)
	- locked <0x0465b108> (a java.util.ArrayList)
	at net.sourceforge.jtds.jdbc.ResponseStream.getPacket(ResponseStream.java:466)
	at net.sourceforge.jtds.jdbc.ResponseStream.read(ResponseStream.java:103)
	at net.sourceforge.jtds.jdbc.ResponseStream.peek(ResponseStream.java:88)
	at net.sourceforge.jtds.jdbc.TdsCore.wait(TdsCore.java:3928)
	at net.sourceforge.jtds.jdbc.TdsCore.executeSQL(TdsCore.java:1045)
	- locked <0x04660820> (a net.sourceforge.jtds.jdbc.TdsCore)
	at net.sourceforge.jtds.jdbc.JtdsStatement.executeSQLQuery(JtdsStatement.java:465)
	at net.sourceforge.jtds.jdbc.JtdsPreparedStatement.executeQuery(JtdsPreparedStatement.java:777)
	- locked <0x0465acf8> (a net.sourceforge.jtds.jdbc.ConnectionJDBC3)
	at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:76)
	at net.sf.hibernate.impl.BatcherImpl.getResultSet(BatcherImpl.java:89)
	at net.sf.hibernate.loader.Loader.getResultSet(Loader.java:880)
	at net.sf.hibernate.loader.Loader.doQuery(Loader.java:273)
	at net.sf.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:138)
	at net.sf.hibernate.loader.Loader.doList(Loader.java:1063)
	at net.sf.hibernate.loader.Loader.list(Loader.java:1054)
	at net.sf.hibernate.hql.QueryTranslator.list(QueryTranslator.java:854)
	at net.sf.hibernate.impl.SessionImpl.find(SessionImpl.java:1552)
	at net.sf.hibernate.impl.QueryImpl.list(QueryImpl.java:49)
	at com.atlassian.confluence.setup.bandana.persistence.dao.hibernate.HibernateConfluenceBandanaRecordDao$1.doInHibernate(HibernateConfluenceBandanaRecordDao.java:53)
	at org.springframework.orm.hibernate.HibernateTemplate.execute(HibernateTemplate.java:370)
	at org.springframework.orm.hibernate.HibernateTemplate.execute(HibernateTemplate.java:337)
	at com.atlassian.confluence.setup.bandana.persistence.dao.hibernate.HibernateConfluenceBandanaRecordDao.getRecord(HibernateConfluenceBandanaRecordDao.java:45)
	at com.atlassian.confluence.setup.bandana.ConfluenceDaoBandanaPersister.retrieve(ConfluenceDaoBandanaPersister.java:30)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:304)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at $Proxy5.retrieve(Unknown Source)
	at com.atlassian.confluence.setup.bandana.ConfluenceCachingBandanaPersister.retrieve(ConfluenceCachingBandanaPersister.java:61)
	at com.atlassian.bandana.DefaultBandanaManager.getValue(DefaultBandanaManager.java:32)
	at com.atlassian.bandana.DefaultBandanaManager.getValue(DefaultBandanaManager.java:24)
	at sun.reflect.GeneratedMethodAccessor84.invoke(Unknown Source)

Cause

This problem happens when some of the plugins ended up waiting to get access to the BANDANA table. The problem is that Microsoft SQL Server is escalating row locks to table locks and thereby blocking access to the table and causing an effective deadlock. This bug is being tackled at  CONF-21986 - Database deadlock during initialisation of plugins Resolved .

Workaround

Configure your database to use the recommended isolation level, which is Read Committed with Row Versioning. Please refer to the workaround listed in this KB article for instructions.

Resolution

  1. Resolution 1:
    1. Upgrade to Confluence 3.5.9 or higher where  CONF-21986 - Database deadlock during initialisation of plugins Resolved  has been fixed.
  2. Resolution 2:
    1. Add the JVM parameter -Datlassian.plugins.enable.wait=300. See Configuring System Properties for tips on how to set an environment variable.

Was this helpful?

Thanks for your feedback!

Why was this unhelpful?

Have a question about this article?

See questions about this article

Powered by Confluence and Scroll Viewport