When publishing an asset deletion that had an asset link, the asset link deletion always fails

• Type: Bug
• Status: Closed
• Resolution: Fixed
• Affects Version/s: 7.2.X, 7.3.X, Master
• Fix Version/s: 7.2.10 DXP FP17, 7.2.10.6 DXP SP6, 7.2.X, 7.3.X, 7.4.3.11 CE GA11, Master
• Component/s: Asset Framework, Performance, Staging > Export/Import
• Labels:
  • backend_test
  • ee-ts
  • liferay-dxp-72-sp6
  • liferay-fixpack-dxp-17-7210
  • liferay-fixpack-dxp-4-7310
  • liferay-update-dxp-4-7310
  • liferay-update-dxp-6-7413
  • liferay-update-dxp-7-7413
• Branch Version/s:
  7.3.x, 7.2.x
• Backported to Branch:
  Committed
• Fix Priority: 3
• Git Pull Request: https://github.com/liferay-echo/liferay-portal/pull/7065

Description
If you have an asset that has one or more related assets, and this asset is then deleted, then doing a publish process with deletion replication enabled will always result in the deletion of the asset link to fail.

This is because the UUID is populated incorrectly in the SystemEvent table. The AssetLink deletion occurs after the AssetEntry deletion, which means that the SystemEvent that is generated for the AssetLink deletion no longer has access to the AssetEntry UUID. This causes the AssetLink to wind up with a blank UUID in the SystemEvent table, which ultimately causes the publication process to fail, with a StringIndexOutOfBoundsException being thrown, for that SystemEvent.

From my testing, it appears that there is some other process that cleans up the orphaned AssetLinks on the Live Site; so I'm not too concerned about the possibility of this bug causing faulty data. However, I am concerned about the performance implications that can result from trying to publish many AssetLink deletion events in a single process. Since each one of these AssetLink deletions is destined to fail with an Exception, significant resources and time may be spent generating stacktraces if there are a lot of AssetLink deletions to be published.

Steps to Reproduce
1. Create a new Site and enable staging on it.
2. On the staging Site, create two Web Content Articles.
3. In the Related Assets of the second Web Content Article, link it to the first Web Content Article
4. Publish the staging Site.
5. On the staging Site, delete the second Web Content Article.
6. Set the log levels of com.liferay.exportimport to WARN or higher (INFO, DEBUG).
7. Publish the staging Site with the Replicate Individual Deletions box checked.
8. Check to see if a WARN message exists in the logs that says "Unable to process deletion for com.liferay.asset.kernel.model.adapter.StagedAssetLink with UUID".
Expected Result: No such message would exist because the AssetLink deletion would be published successfully.
Actual Result: The following message appears in the log:

2022-01-26 17:32:37.330 WARN  [liferay/background_task-3][DeletionSystemEventImporter:109] Unable to process deletion for com.liferay.asset.kernel.model.adapter.StagedAssetLink with UUID
java.lang.StringIndexOutOfBoundsException: String index out of range: -1
        at java.lang.String.substring(String.java:1967) ~[?:1.8.0_291]
        at com.liferay.asset.link.internal.exportimport.staged.model.repository.StagedAssetLinkStagedModelRepository._parseAssetEntry1Uuid(StagedAssetLinkStagedModelRepository.java:294) ~[?:?]
        at com.liferay.asset.link.internal.exportimport.staged.model.repository.StagedAssetLinkStagedModelRepository.deleteStagedModel(StagedAssetLinkStagedModelRepository.java:96) ~[?:?]
        at com.liferay.exportimport.data.handler.base.BaseStagedModelDataHandler.deleteStagedModel(BaseStagedModelDataHandler.java:59) ~[?:?]
        at com.liferay.exportimport.kernel.lar.StagedModelDataHandlerUtil.deleteStagedModel(StagedModelDataHandlerUtil.java:69) ~[portal-kernel.jar:?]
        at com.liferay.exportimport.internal.lar.DeletionSystemEventImporter._importDeletionSystemEvents(DeletionSystemEventImporter.java:104) ~[?:?]
        at com.liferay.exportimport.internal.lar.DeletionSystemEventImporter.access$000(DeletionSystemEventImporter.java:44) ~[?:?]
        at com.liferay.exportimport.internal.lar.DeletionSystemEventImporter$1.processElement(DeletionSystemEventImporter.java:76) ~[?:?]
        at com.liferay.portal.kernel.xml.ElementHandler.endElement(ElementHandler.java:53) ~[portal-kernel.jar:?]
        at org.apache.xerces.parsers.AbstractSAXParser.endElement(Unknown Source) ~[xercesImpl.jar:?]
        at org.apache.xerces.parsers.AbstractXMLDocumentParser.emptyElement(Unknown Source) ~[xercesImpl.jar:?]
        at org.apache.xerces.impl.XMLNSDocumentScannerImpl.scanStartElement(Unknown Source) ~[xercesImpl.jar:2.12.1]
        at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl$FragmentContentDispatcher.dispatch(Unknown Source) ~[xercesImpl.jar:2.12.1]
        at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl.scanDocument(Unknown Source) ~[xercesImpl.jar:2.12.1]
        at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source) ~[xercesImpl.jar:?]
        at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source) ~[xercesImpl.jar:?]
        at org.apache.xerces.parsers.XMLParser.parse(Unknown Source) ~[xercesImpl.jar:?]
        at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source) ~[xercesImpl.jar:?]
        at com.liferay.portal.security.xml.StripDoctypeXMLReader.parse(StripDoctypeXMLReader.java:138) ~[portal-impl.jar:?]
        at com.liferay.exportimport.internal.lar.DeletionSystemEventImporter.importDeletionSystemEvents(DeletionSystemEventImporter.java:84) ~[?:?]
        at com.liferay.exportimport.internal.controller.LayoutImportController.importDataDeletions(LayoutImportController.java:185) ~[?:?]
        at com.liferay.portlet.exportimport.service.impl.ExportImportLocalServiceImpl.importLayoutsDataDeletions(ExportImportLocalServiceImpl.java:262) ~[portal-impl.jar:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_291]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_291]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_291]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_291]
        at com.liferay.portal.spring.aop.AopMethodInvocationImpl.proceed(AopMethodInvocationImpl.java:50) ~[portal-impl.jar:?]
        at com.liferay.portal.spring.transaction.TransactionInterceptor.invoke(TransactionInterceptor.java:69) ~[portal-impl.jar:?]
        at com.liferay.portal.spring.aop.AopMethodInvocationImpl.proceed(AopMethodInvocationImpl.java:57) ~[portal-impl.jar:?]
        at com.liferay.change.tracking.internal.aop.CTTransactionAdvice.invoke(CTTransactionAdvice.java:80) ~[?:?]
        at com.liferay.portal.spring.aop.AopMethodInvocationImpl.proceed(AopMethodInvocationImpl.java:57) ~[portal-impl.jar:?]
        at com.liferay.portal.spring.aop.AopInvocationHandler.invoke(AopInvocationHandler.java:49) ~[portal-impl.jar:?]
        at com.sun.proxy.$Proxy95.importLayoutsDataDeletions(Unknown Source) ~[?:?]
        at com.liferay.exportimport.kernel.service.ExportImportLocalServiceUtil.importLayoutsDataDeletions(ExportImportLocalServiceUtil.java:125) ~[portal-kernel.jar:?]
        at com.liferay.exportimport.internal.background.task.LayoutStagingBackgroundTaskExecutor$LayoutStagingImportCallable.call(LayoutStagingBackgroundTaskExecutor.java:276) ~[?:?]
        at com.liferay.exportimport.internal.background.task.LayoutStagingBackgroundTaskExecutor$LayoutStagingImportCallable.call(LayoutStagingBackgroundTaskExecutor.java:258) ~[?:?]
        at com.liferay.portal.spring.transaction.BaseTransactionExecutor.execute(BaseTransactionExecutor.java:37) [portal-impl.jar:?]
        at com.liferay.portal.spring.transaction.TransactionInvokerImpl.invoke(TransactionInvokerImpl.java:39) [portal-impl.jar:?]
        at com.liferay.portal.kernel.transaction.TransactionInvokerUtil.invoke(TransactionInvokerUtil.java:28) [portal-kernel.jar:?]
        at com.liferay.exportimport.internal.background.task.LayoutStagingBackgroundTaskExecutor.execute(LayoutStagingBackgroundTaskExecutor.java:145) [bundleFile:?]
        at com.liferay.portal.background.task.internal.SerialBackgroundTaskExecutor.execute(SerialBackgroundTaskExecutor.java:63) [bundleFile:?]
        at com.liferay.portal.kernel.backgroundtask.DelegatingBackgroundTaskExecutor.execute(DelegatingBackgroundTaskExecutor.java:41) [portal-kernel.jar:?]
        at com.liferay.portal.background.task.internal.ThreadLocalAwareBackgroundTaskExecutor.execute(ThreadLocalAwareBackgroundTaskExecutor.java:72) [bundleFile:?]
        at com.liferay.portal.background.task.internal.messaging.BackgroundTaskMessageListener.doReceive(BackgroundTaskMessageListener.java:136) [bundleFile:?]
        at com.liferay.portal.kernel.messaging.BaseMessageListener.doReceive(BaseMessageListener.java:48) [portal-kernel.jar:?]
        at com.liferay.portal.kernel.messaging.BaseMessageListener.receive(BaseMessageListener.java:34) [portal-kernel.jar:?]
        at com.liferay.portal.kernel.messaging.InvokerMessageListener.receive(InvokerMessageListener.java:74) [portal-kernel.jar:?]
        at com.liferay.portal.messaging.internal.ParallelDestination$1.run(ParallelDestination.java:56) [bundleFile:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_291]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_291]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_291]