Unable to save metadata during upgrade due to race condition with RawMetadataProcessorMessageListener

• Type: Bug
• Status: Closed
• Resolution: No Longer Reproducible
• Affects Version/s: 7.1.X
• Fix Version/s: 7.1.X
• Component/s: Core Infrastructure > Upgrade Framework
• Labels: None
• Story Points: 5
• Fix Priority: 3
• Sprint: Infra QA Sprint 18, Infra QA Sprint 19, Infra QA Sprint 20
• Git Pull Request: https://github.com/brianchandotcom/liferay-portal-ee/pull/29755

We're seeing this race condition intermittently on the PortalSmokeUpgrade#ViewPortalSmokeArchive7110 test.

Steps would be:

1. Create db dump on 7.1.10 with some documents and some DDM data
2. Shutdown, upgrade to 7.1.x

Expected result:
Upgrade completes without errors.

Actual result:
Upgrade fails intermittently on what appears to be a race condition, with:

com.liferay.portlet.documentlibrary.messaging.RawMetadataProcessorMessageListener

running before the following is loaded:

com.liferay.dynamic.data.mapping.storage.impl.JSONStorageAdapter

fuller context:

 [exec] 00:32:28,717 INFO  [com.liferay.portal.kernel.deploy.auto.AutoDeployScanner][AutoDeployDir:267] Processing powwow-portlet-7.1.10.48.war
     [exec] 00:32:38,605 INFO  [fileinstall-/opt/dev/projects/github/liferay-portal-7.1.x/bundles/osgi/war][BaseAutoDeployListener:43] Copying themes for /opt/dev/projects/github/liferay-portal-7.1.x/bundles/tomcat-9.0.17/temp/20200314243238568BBVLDZRU/admin-theme.war
     [exec] 00:32:38,647 INFO  [fileinstall-/opt/dev/projects/github/liferay-portal-7.1.x/bundles/osgi/war][BaseDeployer:877] Deploying admin-theme.war
     [exec] 00:32:39,598 WARN  [liferay/document_library_raw_metadata_processor-1][RawMetadataProcessorMessageListener:38] Unable to save metadata for file version 42146
     [exec] java.lang.NullPointerException
     [exec] 	at com.liferay.dynamic.data.mapping.storage.impl.StorageEngineImpl.create(StorageEngineImpl.java:47)
     [exec] 	at com.liferay.dynamic.data.mapping.internal.StorageEngineManagerImpl.create(StorageEngineManagerImpl.java:42)
     [exec] 	at com.liferay.dynamic.data.mapping.kernel.StorageEngineManagerUtil.create(StorageEngineManagerUtil.java:31)
     [exec] 	at com.liferay.portlet.documentlibrary.service.impl.DLFileEntryMetadataLocalServiceImpl.updateFileEntryMetadata(DLFileEntryMetadataLocalServiceImpl.java:201)
     [exec] 	at com.liferay.portlet.documentlibrary.service.impl.DLFileEntryMetadataLocalServiceImpl.updateFileEntryMetadata(DLFileEntryMetadataLocalServiceImpl.java:153)
     [exec] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     [exec] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
     [exec] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
     [exec] 	at java.lang.reflect.Method.invoke(Method.java:498)
     [exec] 	at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:153)
     [exec] 	at com.liferay.portal.spring.transaction.DefaultTransactionExecutor._execute(DefaultTransactionExecutor.java:203)
     [exec] 	at com.liferay.portal.spring.transaction.DefaultTransactionExecutor.execute(DefaultTransactionExecutor.java:94)
     [exec] 	at com.liferay.portal.spring.transaction.TransactionInterceptor.invoke(TransactionInterceptor.java:110)
     [exec] 	at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:130)
     [exec] 	at com.liferay.portal.spring.aop.RetryAdvice.invoke(RetryAdvice.java:47)
     [exec] 	at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:130)
     [exec] 	at com.liferay.portal.service.ServiceContextAdvice.invoke(ServiceContextAdvice.java:51)
     [exec] 	at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:130)
     [exec] 	at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:55)
     [exec] 	at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:130)
     [exec] 	at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:55)
     [exec] 	at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:130)
     [exec] 	at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:55)
     [exec] 	at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:130)
     [exec] 	at com.liferay.portal.cache.thread.local.ThreadLocalCacheAdvice.invoke(ThreadLocalCacheAdvice.java:48)
     [exec] 	at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:130)
     [exec] 	at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:55)
     [exec] 	at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:130)
     [exec] 	at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:55)
     [exec] 	at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:130)
     [exec] 	at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:55)
     [exec] 	at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:130)
     [exec] 	at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:55)
     [exec] 	at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:130)
     [exec] 	at com.liferay.portal.spring.aop.ChainableMethodAdvice.invoke(ChainableMethodAdvice.java:55)
     [exec] 	at com.liferay.portal.spring.aop.ServiceBeanMethodInvocation.proceed(ServiceBeanMethodInvocation.java:130)
     [exec] 	at com.liferay.portal.spring.aop.ServiceBeanAopProxy.invoke(ServiceBeanAopProxy.java:125)
     [exec] 	at com.sun.proxy.$Proxy163.updateFileEntryMetadata(Unknown Source)
     [exec] 	at com.liferay.document.library.kernel.service.DLFileEntryMetadataLocalServiceUtil.updateFileEntryMetadata(DLFileEntryMetadataLocalServiceUtil.java:400)
     [exec] 	at com.liferay.portlet.documentlibrary.util.RawMetadataProcessorImpl.saveMetadata(RawMetadataProcessorImpl.java:175)
     [exec] 	at com.liferay.document.library.kernel.util.RawMetadataProcessorUtil.saveMetadata(RawMetadataProcessorUtil.java:113)
     [exec] 	at com.liferay.portlet.documentlibrary.messaging.RawMetadataProcessorMessageListener.doReceive(RawMetadataProcessorMessageListener.java:34)
     [exec] 	at com.liferay.portal.kernel.messaging.BaseMessageListener.receive(BaseMessageListener.java:26)
     [exec] 	at com.liferay.portal.kernel.messaging.InvokerMessageListener.receive(InvokerMessageListener.java:74)
     [exec] 	at com.liferay.portal.kernel.messaging.SerialDestination$1.run(SerialDestination.java:58)
     [exec] 	at com.liferay.portal.kernel.concurrent.ThreadPoolExecutor$WorkerTask._runTask(ThreadPoolExecutor.java:752)
     [exec] 	at com.liferay.portal.kernel.concurrent.ThreadPoolExecutor$WorkerTask.run(ThreadPoolExecutor.java:664)
     [exec] 	at java.lang.Thread.run(Thread.java:745)

We don't see this affecting the same upgrade to 7.2 or to master