IdStory Identity Manager

LRT can hang in "waiting" even if there is no error

• sync from csv file
• syncing 2 roles
• assign one role in IdM to some users
• remove one role from csv
• syncing this new csv
• one item end in failed state
• LRT end correctly

Next I will try to generate some other errors, find how to replicate this issue

I tried to replicate it with some other errors as already existing code. Nothing cause the issue.
I look into the code and found nothing suspicious.
Long running task end processor is has nothing to do with this.
Only thing which I want to test and debug more is AbstractLongRunningTaskExecutor::end because there is if, else if but no else. So theoretically there is possibility that EXECUTED is not correctly set.
Next I will look to project if I will be find something in logs to get some more clue what is happening.

This happened in our environment running on 12.2.3.
Synchronization of tree nodes tried to remove missing tree node, but there are some contracts on this tree node, so the result is 1 Unsuccessfully Deleted entities and the LRT is Waiting. The problem is that the following LRTs weren't started at all.

Synchronization log:

Synchronization was started in [2023-01-24T09:40:30.380911+01:00[Europe/Prague]].
-------------------------
Synchronization used the following settings:
Synchronization mapping: [Mapování organizace]
Correlation attribute: [__NAME__]
Is running as reconciliation: [true]
Linked account action: [UPDATE_ENTITY]
Unlinked account action: [LINK_AND_UPDATE_ENTITY]
Missing entity action: [CREATE_ENTITY]
Missing account action: [DELETE_ENTITY]
-------------------------
Start search with filter NONE.
-------------------------
We found [65] roots: [[006_116101_228, 006_900915_264, 006_163301_192, 006_116103_236, 006_100908_247, 006_178311_182, 006_116102_229, 006_111202_235, 006_900903_248, 006_178301_181, 006_176301_180, 006_111202_243, 006_100941_159, 006_125301_198, 006_103301_232, 006_100902_219, 006_178201_179, 006_900904_249, 006_140050_234, 006_100906_226, 006_131100_193, 006_100904_231, 006_900906_250, 006_151201_173, 006_117301_167, 006_115301_166, 006_163606_190, 006_121301_187, 006_131302_237, 006_131303_238, 006_100951_227, 006_151102_172, 006_181401_184, 006_900901_215, 006_178302_240, 006_900901_259, 006_111101_161, 006_151101_171, 006_900916_251, 006_111320_164, 006_100911_157, 006_163606_189, 006_131106_191, 006_189402_241, 006_163307_239, 006_900902_254, 006_121101_233, 006_111201_163, 006_142301_183, 006_111103_242, 006_140058_244, 006_151601_174, 006_100905_218, 006_187401_185, 006_100903_217, 006_189403_245, 006_151320_176, 006_189401_186, 006_125301_246, 006_900901_253, 006_100902_221, 006_100902_224, 006_163100_188, 006_111102_162, 006_101301_168]]
-------------------------
Reconciliation - error for uid [006_100901_215]
-------------------------
eu.bcvsolutions.idm.core.exception.TreeNodeException: Tree node [006_100901_215] has contract assigned, cannot be deleted. Remove them at first.
    at eu.bcvsolutions.idm.core.model.event.processor.tree.TreeNodeDeleteProcessor.checkWithoutForceDelete(TreeNodeDeleteProcessor.java:220)
    at eu.bcvsolutions.idm.core.model.event.processor.tree.TreeNodeDeleteProcessor.process(TreeNodeDeleteProcessor.java:98)
    at eu.bcvsolutions.idm.core.api.event.AbstractEntityEventProcessor.onApplicationEvent(AbstractEntityEventProcessor.java:244)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:172)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:165)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:403)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:373)
    at eu.bcvsolutions.idm.core.model.service.impl.DefaultEntityEventManager.process(DefaultEntityEventManager.java:253)
    at eu.bcvsolutions.idm.core.api.service.AbstractEventableDtoService.publish(AbstractEventableDtoService.java:68)
    at eu.bcvsolutions.idm.core.eav.api.service.AbstractFormableService.publish(AbstractFormableService.java:97)
    at eu.bcvsolutions.idm.core.api.service.AbstractEventableDtoService.publish(AbstractEventableDtoService.java:54)
    at eu.bcvsolutions.idm.core.api.service.AbstractEventableDtoService.delete(AbstractEventableDtoService.java:109)
    at eu.bcvsolutions.idm.core.api.service.AbstractEventableDtoService$$FastClassBySpringCGLIB$$28b457d3.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:752)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:295)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691)
    at eu.bcvsolutions.idm.core.model.service.impl.DefaultIdmTreeNodeService$$EnhancerBySpringCGLIB$$173b13cb.delete(<generated>)
    at eu.bcvsolutions.idm.acc.service.impl.TreeSynchronizationExecutor.deleteChildrenRecursively(TreeSynchronizationExecutor.java:569)
    at eu.bcvsolutions.idm.acc.service.impl.TreeSynchronizationExecutor.doDeleteEntity(TreeSynchronizationExecutor.java:386)
    at eu.bcvsolutions.idm.acc.service.impl.AbstractSynchronizationExecutor.resolveMissingAccountSituation(AbstractSynchronizationExecutor.java:1246)
    at eu.bcvsolutions.idm.acc.service.impl.AbstractSynchronizationExecutor.doItemSynchronization(AbstractSynchronizationExecutor.java:507)
    at eu.bcvsolutions.idm.acc.service.impl.DefaultSynchronizationService.doItemSynchronization(DefaultSynchronizationService.java:218)
    at eu.bcvsolutions.idm.acc.service.impl.DefaultSynchronizationService$$FastClassBySpringCGLIB$$66d7ee75.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:752)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:295)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691)
    at eu.bcvsolutions.idm.acc.service.impl.DefaultSynchronizationService$$EnhancerBySpringCGLIB$$cb279776.doItemSynchronization(<generated>)
    at eu.bcvsolutions.idm.acc.event.processor.synchronization.SynchronizationItemProcessor.process(SynchronizationItemProcessor.java:52)
    at eu.bcvsolutions.idm.core.api.event.AbstractEntityEventProcessor.onApplicationEvent(AbstractEntityEventProcessor.java:244)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:172)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:165)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:403)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:373)
    at eu.bcvsolutions.idm.core.model.service.impl.DefaultEntityEventManager.process(DefaultEntityEventManager.java:253)
    at eu.bcvsolutions.idm.core.model.service.impl.DefaultEntityEventManager.process(DefaultEntityEventManager.java:180)
    at eu.bcvsolutions.idm.acc.service.impl.AbstractSynchronizationExecutor.startReconciliation(AbstractSynchronizationExecutor.java:747)
    at eu.bcvsolutions.idm.acc.service.impl.TreeSynchronizationExecutor.processTreeSync(TreeSynchronizationExecutor.java:550)
    at eu.bcvsolutions.idm.acc.service.impl.TreeSynchronizationExecutor.process(TreeSynchronizationExecutor.java:157)
    at eu.bcvsolutions.idm.acc.service.impl.DefaultSynchronizationService.startSynchronization(DefaultSynchronizationService.java:189)
    at eu.bcvsolutions.idm.acc.service.impl.DefaultSynchronizationService$$FastClassBySpringCGLIB$$66d7ee75.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:687)
    at eu.bcvsolutions.idm.acc.service.impl.DefaultSynchronizationService$$EnhancerBySpringCGLIB$$cb279776.startSynchronization(<generated>)
    at eu.bcvsolutions.idm.acc.scheduler.task.impl.SynchronizationSchedulableTaskExecutor.process(SynchronizationSchedulableTaskExecutor.java:79)
    at eu.bcvsolutions.idm.acc.scheduler.task.impl.SynchronizationSchedulableTaskExecutor.process(SynchronizationSchedulableTaskExecutor.java:38)
    at eu.bcvsolutions.idm.core.scheduler.api.service.AbstractLongRunningTaskExecutor.call(AbstractLongRunningTaskExecutor.java:269)
    at eu.bcvsolutions.idm.core.scheduler.api.service.AbstractLongRunningTaskExecutor$$FastClassBySpringCGLIB$$f9eae371.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:687)
    at eu.bcvsolutions.idm.acc.scheduler.task.impl.SynchronizationSchedulableTaskExecutor$$EnhancerBySpringCGLIB$$bd8d7edb.call(<generated>)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at eu.bcvsolutions.idm.core.config.DelegatingTransactionContextRunnable.run(DelegatingTransactionContextRunnable.java:39)
    at org.springframework.security.concurrent.DelegatingSecurityContextRunnable.run(DelegatingSecurityContextRunnable.java:84)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    at java.base/java.lang.Thread.run(Thread.java:829)

-------------------------
Synchronization was correctly ended in [2023-01-24T09:40:35.084547+01:00[Europe/Prague]].
-------------------------
Start automatic role recalculation (after sync) isnt allowed [{0}]

I tried to replicate this in the current develop. These were my steps:

1. prepare a CSV file for tree node synchronization with two nodes, one parent, one sub
2. set synchronization to remove the tree node on Missing account
3. synchronize the tree node
4. put one contract on the sub tree node
5. remove the sub tree node from the CSV file
6. run the synchronization

The task finished with one ignore (the parent) and one fail (the sub). But it finished, it was not left in the Waiting state and the following tasks (ProcessSkippedAutomaticRoleByTreeTaskExecutor) were started and finished as well.

It's not quite clear what causes the reported behavior but we would need a clear set of steps to replicate the issue. :(

• the tree node is used in 296 contract slices as a work position
• the tree node has two accounts in systems - 1) HR (only sync), 2) MS AD (only provisioning)
• the tree node doesn't have any direct automatic roles, though its parent's parent has one automatic role with the recursion Down by structure
• After end, start the automatic role recalculation is unchecked
  • when I check the checkbox, the LRT ProcessSkippedAutomaticRoleByTreeTaskExecutor is started and also ends in Waiting state
    

    After success sync have to recount automatic roles (by tree structure). We start recount automatic roles by tree structure (synchronously) now [2023-01-24T10:35:15.209280+01:00[Europe/Prague]].
    -------------------------
    Recalculation of automatic roles by tree structure ended in [2023-01-24T10:35:15.248402+01:00[Europe/Prague]], role requests will be processed asynchronously.
    

• the synchronization processes 65 accounts

Alena Peterová wrote in #note-7:

Some more things to check (TODO):

• the tree node has two accounts in systems - 1) HR (only sync), 2) MS AD (only provisioning)

This may be the problem! When I manually removed the AccTreeAccount for MS AD from the tree node, then the synchronization also ended with a failed item for this tree node, but the LRT state was Executed and following LRT started.