Actions
Defect #3121
open
When you run synchronization via LRT SynchronizationSchedulableTaskExecutor and items for delete failes, this LRT will hang in waiting state
Added by Roman Kučera over 2 years ago. Updated almost 2 years ago.
Status:
In Progress
Priority:
Normal
Assignee:
Roman Kučera
Category:
Long running task
Target version:
-
Start date:
05/16/2022
Due date:
% Done:
20%
Estimated time:
Description
When you running synchronization via SynchronizationSchedulableTaskExecutor LRT.
This synchronization should remove some items (account missing), but the removal in IdM failed for some reason then the LRT will hang in waiting state for ever.
It doesn't matter which system is used as the source, it can happen with AD groups sync, with contract sync, with tree nodes.
The synchronization itself is ended, so there is no issue.
Workaround for this is set account missing state to ignore....
Updated by Roman Kučera over 2 years ago
LRT can hang in "waiting" even if there is no error
Updated by Roman Kučera over 2 years ago
- Category set to Long running task
- Status changed from New to In Progress
- Assignee set to Roman Kučera
Updated by Roman Kučera over 2 years ago
I tried to replicate this issue on clear product on local env.
Setup
Setup
- 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.
Updated by Roman Kučera over 2 years ago
- % Done changed from 0 to 20
Attribute running is correctly set to false, but for some reason the task is not ended in proper way = End date is not set. State is not switched from running.
Now I have two places to check, but the issue is how to replicate stuck LRT:- Check AbstractLongRunningTaskExecutor::call lines 280-286 is called after ::end. In debug the LRT is already set as not running and has end date.
- AbstractLongRunningTaskExecutor::end because there is if, else if but no else. So theoretically there is possibility that EXECUTED is not correctly set.
Updated by Alena Peterová almost 2 years ago
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}]
Updated by Tomáš Doischer almost 2 years ago
I tried to replicate this in the current develop. These were my steps:
- prepare a CSV file for tree node synchronization with two nodes, one parent, one sub
- set synchronization to remove the tree node on Missing account
- synchronize the tree node
- put one contract on the sub tree node
- remove the sub tree node from the CSV file
- 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. :(
Updated by Alena Peterová almost 2 years ago
Some more things to check (TODO):
- 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.
- when I check the checkbox, the LRT ProcessSkippedAutomaticRoleByTreeTaskExecutor is started and also ends in Waiting state
- the synchronization processes 65 accounts
Updated by Alena Peterová almost 2 years ago
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.
Actions