Repository lockup when loading workflow definition

[ianw]

I'm in the process of upgrading from 4.2 to 5.1. The database, repository, share and Solr are all on separate machines.

The problem I'm having is that the repository does not complete starting up if a certain workflow is configured. The last few lines of the log file are:

2017-03-06 17:11:30,041 INFO [org.springframework.extensions.webscripts.DeclarativeRegistry] [asynchronouslyRefreshedCacheThreadPool1] Registered 0 Schema Description Documents (+0 failed)
2017-03-06 17:11:32,300 INFO [org.springframework.extensions.webscripts.DeclarativeRegistry] [localhost-startStop-1] Registered 428 Web Scripts (+0 failed), 578 URLs
2017-03-06 17:11:32,301 INFO [org.springframework.extensions.webscripts.DeclarativeRegistry] [localhost-startStop-1] Registered 1 Package Description Documents (+0 failed)
2017-03-06 17:11:32,301 INFO [org.springframework.extensions.webscripts.DeclarativeRegistry] [localhost-startStop-1] Registered 0 Schema Description Documents (+0 failed)
2017-03-06 17:11:32,304 INFO [org.springframework.extensions.webscripts.AbstractRuntimeContainer] [localhost-startStop-1] Initialised Repository Web Script Container (in 6844.422ms)
2017-03-06 17:11:32,343 INFO [org.springframework.extensions.webscripts.TemplateProcessorRegistry] [localhost-startStop-1] Registered template processor freemarker for extension ftl
2017-03-06 17:11:32,345 INFO [org.springframework.extensions.webscripts.ScriptProcessorRegistry] [localhost-startStop-1] Registered script processor javascript for extension js
2017-03-06 17:11:32,352 DEBUG [org.alfresco.repo.workflow] [localhost-startStop-1] Workflow deployer: Definition 'alfresco/extension/workflow/dna.bpmn' already deployed

There are no errors in the log.

On a fresh install of 5.1 the workflow is deployed and the repository starts up fully.

On the upgraded system, if the workflow is deployed without its model, as below, then the system starts up fully.

<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<beans xmlns="http://www.springframework.org/schema/beans" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-2.0.xsd">
 <bean parent="workflowDeployer" id="dna.workflowBootstrap">
<!--
 <property name="models">
 <list>
 <value>alfresco/extension/workflow/dna-model.xml</value>
 </list>
 </property>
-->
 <property name="workflowDefinitions">
 <props>
 <prop key="engineId">activiti</prop>
 <prop key="mimeType">text/xml</prop>
 <prop key="location">alfresco/extension/workflow/dna.bpmn</prop>
 <prop key="redeploy">false</prop>
 </props>
 </property>
 </bean>
</beans>

If I start with the complete workflow, use a remote debugger with a breakpoint set in WorkflowDeployer.java, function public void init() and just press continue when the breakpoint is reached the system the repository starts up fully. There seems to be some sort of race hazard.

Any ideas on how to debug further or, better still, fix the issue?

Regards,

Ian

Edit, further information:

Whilst in the locked state the following thread states exist:

Daemon Thread [Catalina-startStop-1] (Suspended) 
 owns: StandardHost (id=157) 
 Unsafe.park(boolean, long) line: not available [native method] 
 LockSupport.park(Object) line: 175 
 FutureTask<V>.awaitDone(boolean, long) line: 429 
 FutureTask<V>.get() line: 191 
 HostConfig.deployWARs(File, String[]) line: 832 
 HostConfig.deployApps() line: 495 
 HostConfig.start() line: 1713 
 HostConfig.lifecycleEvent(LifecycleEvent) line: 337 
 LifecycleSupport.fireLifecycleEvent(String, Object) line: 117 
 StandardHost(LifecycleBase).fireLifecycleEvent(String, Object) line: 90 
 StandardHost(LifecycleBase).setStateInternal(LifecycleState, Object, boolean) line: 394 
 StandardHost(LifecycleBase).setState(LifecycleState) line: 339 
 StandardHost(ContainerBase).startInternal() line: 1137 
 StandardHost.startInternal() line: 819 
 StandardHost(LifecycleBase).start() line: 147 
 ContainerBase$StartChild.call() line: 1572 
 ContainerBase$StartChild.call() line: 1562 
 FutureTask<V>.run() line: 266 
 ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker) line: 1142 
 ThreadPoolExecutor$Worker.run() line: 617 
 Thread.run() line: 745 

Daemon Thread [localhost-startStop-1] (Suspended) 
 owns: Object (id=124) 
 owns: StandardContext (id=125) 
 waiting for: AbstractAsynchronouslyRefreshedCache$Refresh (id=123) 
 Object.wait(long) line: not available [native method] 
 CompiledModelsCache(AbstractAsynchronouslyRefreshedCache<T>).waitForBuild(AbstractAsynchronouslyRefreshedCache$Refresh) line: 214 
 CompiledModelsCache(AbstractAsynchronouslyRefreshedCache<T>).get(String) line: 174 
 DictionaryDAOImpl.getDictionaryRegistry(String) line: 705 
 CMISStrictDictionaryService(CMISAbstractDictionaryService).getRegistry(String) line: 154 
 CMISStrictDictionaryService(CMISAbstractDictionaryService).getRegistry() line: 146 
 CMISDictionaryReload.reload() line: 53 
 CMISDictionaryReload.onBootstrap(ApplicationEvent) line: 62 
 CMISDictionaryReload(AbstractLifecycleBean).onApplicationEvent(ApplicationEvent) line: 56 
 SafeApplicationEventMulticaster.multicastEventInternal(ApplicationEvent) line: 207 
 SafeApplicationEventMulticaster.multicastEvent(ApplicationEvent) line: 178 
 XmlWebApplicationContext(AbstractApplicationContext).publishEvent(ApplicationEvent) line: 334 
 XmlWebApplicationContext(AbstractApplicationContext).finishRefresh() line: 950 
 XmlWebApplicationContext(AbstractApplicationContext).refresh() line: 482 
 ContextLoaderListener(ContextLoader).configureAndRefreshWebApplicationContext(ConfigurableWebApplicationContext, ServletContext) line: 410 
 ContextLoaderListener(ContextLoader).initWebApplicationContext(ServletContext) line: 306 
 ContextLoaderListener(ContextLoaderListener).contextInitialized(ServletContextEvent) line: 112 
 ContextLoaderListener.contextInitialized(ServletContextEvent) line: 63 
 StandardContext.listenerStart() line: 5068 
 StandardContext.startInternal() line: 5584 
 StandardContext(LifecycleBase).start() line: 147 
 StandardHost(ContainerBase).addChildInternal(Container) line: 899 
 StandardHost(ContainerBase).addChild(Container) line: 875 
 StandardHost.addChild(Container) line: 652 
 HostConfig.deployWAR(ContextName, File) line: 1092 
 HostConfig$DeployWar.run() line: 1984 
 Executors$RunnableAdapter<T>.call() line: 511 
 FutureTask<V>.run() line: 266 
 ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker) line: 1142 
 ThreadPoolExecutor$Worker.run() line: 617 
 Thread.run() line: 745 

Daemon Thread [asynchronouslyRefreshedCacheThreadPool1] (Suspended) 
    waiting for: AbstractAsynchronouslyRefreshedCache$Refresh  (id=123) 
    Object.wait(long) line: not available [native method]   
    CompiledModelsCache(AbstractAsynchronouslyRefreshedCache<T>).waitForBuild(AbstractAsynchronouslyRefreshedCache$Refresh) line: 214   
    CompiledModelsCache(AbstractAsynchronouslyRefreshedCache<T>).get(String) line: 174  
    DictionaryDAOImpl.getDictionaryRegistry(String) line: 705   
    DictionaryDAOImpl.getTenantDictionaryRegistry() line: 305   
    DictionaryDAOImpl.getProperty(QName) line: 488  
    DictionaryComponent.getProperty(QName) line: 376    
    NodeRefPropertyMethodInterceptor.getValue(QName, Serializable) line: 289    
    NodeRefPropertyMethodInterceptor.invoke(MethodInvocation) line: 199 
    ReflectiveMethodInvocation.proceed() line: 172  
    JdkDynamicAopProxy.invoke(Object, Method, Object[]) line: 204   
    $Proxy20.getProperty(NodeRef, QName) line: not available    
    GeneratedMethodAccessor151.invoke(Object, Object[]) line: not available 
    DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 43  
    Method.invoke(Object, Object...) line: 498  
    AopUtils.invokeJoinpointUsingReflection(Object, Method, Object[]) line: 317 
    JdkDynamicAopProxy.invoke(Object, Method, Object[]) line: 198   
    $Proxy20.getProperty(NodeRef, QName) line: not available    
    Path.toDisplayPath(NodeService, PermissionService) line: 211    
    RepoStore.getPath(NodeRef) line: 301    
    RepoStore$2.doWork() line: 264  
    RepoStore$2.doWork() line: 261  
    AuthenticationUtil.runAs(RunAsWork<R>, String) line: 548    
    RepoStore.getBaseDir() line: 260    
    RepoStore.access$100(RepoStore) line: 71    
    RepoStore$4$1.execute() line: 438   
    RepoStore$4$1.execute() line: 435   
    RetryingTransactionHelper.doInTransaction(RetryingTransactionCallback<R>, boolean, boolean) line: 457   
    RepoStore$4.doWork() line: 434  
    RepoStore$4.doWork() line: 431  
    AuthenticationUtil.runAs(RunAsWork<R>, String) line: 548    
    RepoStore.getDocumentPaths(String, boolean, String) line: 430   
    DeclarativeRegistry.initWebScripts() line: 296  
    DeclarativeRegistry.reset() line: 183   
    RegistryAsynchronouslyRefreshedCache.doBuildCache(String) line: 83  
    RegistryAsynchronouslyRefreshedCache.access$000(RegistryAsynchronouslyRefreshedCache, String) line: 41  
    RegistryAsynchronouslyRefreshedCache$1.execute() line: 72   
    RegistryAsynchronouslyRefreshedCache$1.execute() line: 68   
    RetryingTransactionHelper.doInTransaction(RetryingTransactionCallback<R>, boolean, boolean) line: 457   
    RegistryAsynchronouslyRefreshedCache.buildCache(String) line: 67    
    RegistryAsynchronouslyRefreshedCache.buildCache(String) line: 41    
    RegistryAsynchronouslyRefreshedCache(AbstractAsynchronouslyRefreshedCache<T>).doRefresh(AbstractAsynchronouslyRefreshedCache$Refresh) line: 470 
    RegistryAsynchronouslyRefreshedCache(AbstractAsynchronouslyRefreshedCache<T>).doCall() line: 455    
    RegistryAsynchronouslyRefreshedCache(AbstractAsynchronouslyRefreshedCache<T>).call() line: 420  
    RegistryAsynchronouslyRefreshedCache(AbstractAsynchronouslyRefreshedCache<T>).call() line: 47   
    FutureTask<V>.run() line: 266   
    DynamicallySizedThreadPoolExecutor(ThreadPoolExecutor).runWorker(ThreadPoolExecutor$Worker) line: 1142  
    ThreadPoolExecutor$Worker.run() line: 617   
    Thread.run() line: 745 

If started using the breakpoint described above then these two threads

Daemon Thread [Catalina-startStop-1] (Suspended)    
Daemon Thread [localhost-startStop-1] (Suspended)   

have completed and don't exists anymore and the third

Daemon Thread [asynchronouslyRefreshedCacheThreadPool1] (Suspended) 
 Unsafe.park(boolean, long) line: not available [native method] 
 LockSupport.park(Object) line: 175 
 AbstractQueuedSynchronizer$ConditionObject.await() line: 2039 
 LinkedBlockingQueue<E>.take() line: 442 
 DynamicallySizedThreadPoolExecutor(ThreadPoolExecutor).getTask() line: 1067 
 DynamicallySizedThreadPoolExecutor(ThreadPoolExecutor).runWorker(ThreadPoolExecutor$Worker) line: 1127 
 ThreadPoolExecutor$Worker.run() line: 617 
 Thread.run() line: 745 

[ruudg]

Have you tried to comment your workflow deployer on Spring and restart?

I'm not sure that your problem depends by the workflow.

[ianw]

Yes, and then the repository starts without problem.

[ianw]

Currently the workflow is configured in tomcat/shared/classes/alfresco/extension/...

Not a fix, but a workaround; If the workflow is packaged in an amp file then the repository starts without any problems, go figure!

Reported as a bug. https://issues.alfresco.com/jira/browse/ALF-21876