Uploaded image for project: 'Confluence Data Center'
  1. Confluence Data Center
  2. CONFSERVER-56098

Confluence attempts ALTER statement on AO tables intermittently at runtime and/or on restart

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Tracked Elsewhere
    • Icon: Medium Medium
    • None
    • 6.4.3, 6.6.6, 6.6.7, 6.10.1, 6.13.1
    • Server - Platform
    • None

      Summary

      This bug is relatively similar in behavior to the one reported in JRASERVER-63126 in which restarts can perform unnecessary ALTER statements on the AO table. If these tables are large, an error can occur when multiple processes attempt to access the same db resources. Moreover, this behavior can occur at runtime in edge cases

      Environment

      • Confluence 6.0+ Server or Data Center
      • Some plugins creating table with LONGTEXT columns: eg: DVCS, webhook

      Steps to Reproduce

      1. Set up Confluence
      2. Enable AO debug logging or DB SQL logging
      3. Restart Confluence

      Expected Results

      Confluence doesn't do unnecessary table modification

      Actual Results

      During Startup

      Confluence does unnecessary table modification. If those tables are large, it can cause example error:

      Caused by: Error : 54, Position : 12, Sql = ALTER TABLE "AO_950DC3_TC_SUBCALS" MODIFY ("CREATED" DEFAULT 0), OriginalSql = ALTER TABLE "AO_950DC3_TC_SUBCALS" MODIFY ("CREATED" DEFAULT 0), Error Msg = ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired

      At Runtime

      Confluence can throw the following error

      2019-02-11 03:57:05,059 DEBUG [http-nio-1101-exec-4] [plugins.createcontent.exceptions.RestExceptionMapper] toResponse create-content-plugin exception
       -- referer: https://confluence-base-url/confluence/pages/editpage.action?pageId=123456789 | url: /confluence/rest/create-dialog/1.0/blueprints/web-items | traceId: 061ac753dbbb1bc8 | userName: someuser
      com.atlassian.activeobjects.internal.ActiveObjectsInitException: bundle [com.atlassian.confluence.plugins.confluence-create-content-plugin]
      	at com.atlassian.activeobjects.osgi.TenantAwareActiveObjects$1$1$1.call(TenantAwareActiveObjects.java:95)
      	at com.atlassian.activeobjects.osgi.TenantAwareActiveObjects$1$1$1.call(TenantAwareActiveObjects.java:86)
      	at com.atlassian.sal.core.executor.ThreadLocalDelegateCallable.call(ThreadLocalDelegateCallable.java:38)
      	at com.atlassian.confluence.impl.vcache.VCacheRequestContextManager.doInRequestContextInternal(VCacheRequestContextManager.java:87)
      	at com.atlassian.confluence.impl.vcache.VCacheRequestContextManager.doInRequestContext(VCacheRequestContextManager.java:71)
      	at com.atlassian.confluence.vcache.VCacheRequestContextOperations.lambda$withRequestContext$1(VCacheRequestContextOperations.java:59)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      	at java.lang.Thread.run(Thread.java:748)
      Caused by: com.atlassian.activeobjects.internal.ActiveObjectsSqlException: There was a SQL exception thrown by the Active Objects library:
      Database:
      	- name:Oracle
      	- version:Oracle Database 12c Enterprise Edition Release - 64bit Production
      With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
      Advanced Analytics and Real Application Testing options
      	- minor version:1
      	- major version:12
      Driver:
      	- name:Oracle JDBC driver
      	- version:x.x
      
      java.sql.SQLException: ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired
      
      	at com.atlassian.activeobjects.internal.EntityManagedActiveObjects.migrate(EntityManagedActiveObjects.java:53)
      	at com.atlassian.activeobjects.internal.AbstractActiveObjectsFactory$1.doInTransaction(AbstractActiveObjectsFactory.java:77)
      	at com.atlassian.activeobjects.internal.AbstractActiveObjectsFactory$1.doInTransaction(AbstractActiveObjectsFactory.java:72)
      	at com.atlassian.sal.core.transaction.HostContextTransactionTemplate$1.doInTransaction(HostContextTransactionTemplate.java:21)
      	at com.atlassian.sal.spring.component.SpringHostContextAccessor$1.doInTransaction(SpringHostContextAccessor.java:71)
      	at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:133)
      	at com.atlassian.sal.spring.component.SpringHostContextAccessor.doInTransaction(SpringHostContextAccessor.java:68)
      	at com.atlassian.confluence.spring.transaction.interceptor.ConfluenceSpringHostContextAccessor.access$001(ConfluenceSpringHostContextAccessor.java:21)
      	at com.atlassian.confluence.spring.transaction.interceptor.ConfluenceSpringHostContextAccessor.lambda$doInTransaction$3(ConfluenceSpringHostContextAccessor.java:72)
      	at com.atlassian.confluence.impl.vcache.VCacheRequestContextManager.doInRequestContextInternal(VCacheRequestContextManager.java:87)
      	at com.atlassian.confluence.impl.vcache.VCacheRequestContextManager.doInRequestContext(VCacheRequestContextManager.java:71)
      	at com.atlassian.confluence.spring.transaction.interceptor.ConfluenceSpringHostContextAccessor.doInTransaction(ConfluenceSpringHostContextAccessor.java:72)
      	at sun.reflect.GeneratedMethodAccessor257.invoke(Unknown Source)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:498)
      	at com.atlassian.plugin.util.ContextClassLoaderSettingInvocationHandler.invoke(ContextClassLoaderSettingInvocationHandler.java:26)
      	at com.sun.proxy.$Proxy316.doInTransaction(Unknown Source)
      	at sun.reflect.GeneratedMethodAccessor257.invoke(Unknown Source)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:498)
      	at com.atlassian.plugin.osgi.bridge.external.HostComponentFactoryBean$DynamicServiceInvocationHandler.invoke(HostComponentFactoryBean.java:136)
      	at com.sun.proxy.$Proxy316.doInTransaction(Unknown Source)
      	at com.atlassian.sal.core.transaction.HostContextTransactionTemplate.execute(HostContextTransactionTemplate.java:18)
      	at sun.reflect.GeneratedMethodAccessor258.invoke(Unknown Source)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:498)
      	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:302)
      	at org.eclipse.gemini.blueprint.service.importer.support.internal.aop.ServiceInvoker.doInvoke(ServiceInvoker.java:56)
      	at org.eclipse.gemini.blueprint.service.importer.support.internal.aop.ServiceInvoker.invoke(ServiceInvoker.java:60)
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
      	at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:133)
      	at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:121)
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
      	at org.eclipse.gemini.blueprint.service.util.internal.aop.ServiceTCCLInterceptor.invokeUnprivileged(ServiceTCCLInterceptor.java:70)
      	at org.eclipse.gemini.blueprint.service.util.internal.aop.ServiceTCCLInterceptor.invoke(ServiceTCCLInterceptor.java:53)
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
      	at org.eclipse.gemini.blueprint.service.importer.support.LocalBundleContextAdvice.invoke(LocalBundleContextAdvice.java:57)
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
      	at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:133)
      	at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:121)
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
      	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:208)
      	at com.sun.proxy.$Proxy911.execute(Unknown Source)
      	at com.atlassian.activeobjects.internal.AbstractActiveObjectsFactory.create(AbstractActiveObjectsFactory.java:72)
      	at com.atlassian.activeobjects.internal.DelegatingActiveObjectsFactory.create(DelegatingActiveObjectsFactory.java:32)
      	at com.atlassian.activeobjects.osgi.TenantAwareActiveObjects$1$1$1.call(TenantAwareActiveObjects.java:91)
      	... 9 more
      Caused by: java.sql.SQLException: ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired
      
      	at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:494)
      	at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:446)
      	at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:1054)
      	at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:623)
      	at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:252)
      	at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:612)
      	at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:213)
      	at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:37)
      	at oracle.jdbc.driver.T4CStatement.executeForRows(T4CStatement.java:896)
      	at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1119)
      	at oracle.jdbc.driver.OracleStatement.executeUpdateInternal(OracleStatement.java:1661)
      	at oracle.jdbc.driver.OracleStatement.executeLargeUpdate(OracleStatement.java:1626)
      	at oracle.jdbc.driver.OracleStatement.executeUpdate(OracleStatement.java:1613)
      	at oracle.jdbc.driver.OracleStatementWrapper.executeUpdate(OracleStatementWrapper.java:282)
      	at org.apache.tomcat.dbcp.dbcp2.DelegatingStatement.executeUpdate(DelegatingStatement.java:233)
      	at org.apache.tomcat.dbcp.dbcp2.DelegatingStatement.executeUpdate(DelegatingStatement.java:233)
      	at net.java.ao.DatabaseProvider.executeUpdate(DatabaseProvider.java:2238)
      	at net.java.ao.DatabaseProvider.executeUpdateForAction(DatabaseProvider.java:2294)
      	at net.java.ao.DatabaseProvider.executeUpdatesForActions(DatabaseProvider.java:2266)
      	at net.java.ao.schema.SchemaGenerator.migrate(SchemaGenerator.java:91)
      	at net.java.ao.EntityManager.migrate(EntityManager.java:128)
      	at com.atlassian.activeobjects.internal.EntityManagedActiveObjects.migrate(EntityManagedActiveObjects.java:51)
      	... 54 more
      Caused by: Error : 54, Position : 12, Sql = ALTER TABLE "AO_54C900_C_TEMPLATE_REF" MODIFY ("TEMPLATE_ID" DEFAULT 0), OriginalSql = ALTER TABLE "AO_54C900_C_TEMPLATE_REF" MODIFY ("TEMPLATE_ID" DEFAULT 0), Error Msg = ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired
      
      	at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:498)
      	... 75 more 
      

      Notes

      This is a bug in the AO library which allows for those unnecessary queries to run:

      Workaround

      Restarting the node experiencing this behavior should resolve this issue temporarily.

            Unassigned Unassigned
            nlopez@atlassian.com Nancy Lopez
            Votes:
            3 Vote for this issue
            Watchers:
            11 Start watching this issue

              Created:
              Updated:
              Resolved: