Project

General

Profile

Actions

Defect #1819

closed

Failed provisioning during attribute recalculation

Added by Alena Peterová over 4 years ago. Updated over 4 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Vít Švanda
Category:
Provisioning
Target version:
Start date:
08/23/2019
Due date:
% Done:

90%

Estimated time:
Affected versions:
Owner:

Description

Version 9.7.4
We removed a testing role which filled an attribute with Merge strategy.

At the same time a provisioning from some other asynchronous event was attempted. (The user didn't have this role.) The provisioning failed.

Full error:

org.springframework.transaction.TransactionSystemException: Could not commit JPA transaction; nested exception is javax.persistence.RollbackException: Transaction marked as rollbackOnly
    at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:526)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:761)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:730)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:484)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:291)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655)
    at eu.bcvsolutions.idm.core.model.service.impl.DefaultEntityEventManager$$EnhancerBySpringCGLIB$$90d022c9.process(<generated>)
    at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor.executeInternal(DefaultProvisioningExecutor.java:164)
    at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor$$FastClassBySpringCGLIB$$68607120.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655)
    at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor$$EnhancerBySpringCGLIB$$b5a081c.executeInternal(<generated>)
    at sun.reflect.GeneratedMethodAccessor1298.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.context.event.ApplicationListenerMethodAdapter.doInvoke(ApplicationListenerMethodAdapter.java:223)
    at org.springframework.context.event.ApplicationListenerMethodAdapter.processEvent(ApplicationListenerMethodAdapter.java:144)
    at org.springframework.transaction.event.ApplicationListenerMethodTransactionalAdapter$TransactionSynchronizationEventAdapter.processEvent(ApplicationListenerMethodTransactionalAdapter.java:133)
    at org.springframework.transaction.event.ApplicationListenerMethodTransactionalAdapter$TransactionSynchronizationEventAdapter.afterCompletion(ApplicationListenerMethodTransactionalAdapter.java:120)
    at org.springframework.transaction.support.TransactionSynchronizationUtils.invokeAfterCompletion(TransactionSynchronizationUtils.java:168)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.invokeAfterCompletion(AbstractPlatformTransactionManager.java:1001)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.triggerAfterCompletion(AbstractPlatformTransactionManager.java:976)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:806)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:730)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:484)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:291)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655)
    at eu.bcvsolutions.idm.core.model.service.impl.DefaultEntityEventManager$$EnhancerBySpringCGLIB$$90d022c9.process(<generated>)
    at eu.bcvsolutions.idm.core.model.event.processor.event.EntityEventExecuteProcessor.process(EntityEventExecuteProcessor.java:52)
    at eu.bcvsolutions.idm.core.api.event.AbstractEntityEventProcessor.onApplicationEvent(AbstractEntityEventProcessor.java:238)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:166)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:138)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:381)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:348)
    at eu.bcvsolutions.idm.core.model.service.impl.DefaultEntityEventManager.process(DefaultEntityEventManager.java:247)
    at eu.bcvsolutions.idm.core.model.service.impl.DefaultEntityEventManager.process(DefaultEntityEventManager.java:177)
    at eu.bcvsolutions.idm.core.model.service.impl.DefaultEntityEventManager$2.run(DefaultEntityEventManager.java:536)
    at org.springframework.security.concurrent.DelegatingSecurityContextRunnable.run(DelegatingSecurityContextRunnable.java:80)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: javax.persistence.RollbackException: Transaction marked as rollbackOnly
    at org.hibernate.jpa.internal.TransactionImpl.commit(TransactionImpl.java:74)
    at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:517)
    ... 50 more

Application log:
2019-08-22 21:16:44.910  INFO 20935 --- [task-executor-2] e.b.i.c.a.e.AbstractEntityEventProcessor : Processor [prepare-connector-object-processor]([acc]) start for [CoreEvent [type: UPDATE
, content: eu.bcvsolutions.idm.acc.dto.SysProvisioningOperationDto [id=df5d2e85-06ce-419d-9ffe-c438e5c4b568], properties: {}]] with order [-1000].
2019-08-22 21:16:45.066  INFO 20935 --- [task-executor-1] somethingGetDepartment                        : End 'somethingGetDepartment' script.
2019-08-22 21:16:45.105  INFO 20935 --- [task-executor-4] somethingGetDepartment                        : Start 'somethingGetDepartment' script.
2019-08-22 21:16:45.221  INFO 20935 --- [task-executor-4] somethingGetDepartment                        : End 'somethingGetDepartment' script.
2019-08-22 21:16:45.242  INFO 20935 --- [task-executor-4] somethingAdGetDepartmentNumber                : Start 'somethingAdGetDepartmentNumber' script.
2019-08-22 21:16:45.316  INFO 20935 --- [task-executor-4] somethingAdGetDepartmentNumber                : End 'somethingAdGetDepartmentNumber' script.
2019-08-22 21:16:45.338  INFO 20935 --- [task-executor-4] somethingGetDepartment                        : Start 'somethingGetDepartment' script.
2019-08-22 21:16:45.402  INFO 20935 --- [task-executor-4] somethingGetDepartment                        : End 'somethingGetDepartment' script.
2019-08-22 21:16:50.086  INFO 20935 --- [task-executor-3] e.b.i.c.m.s.i.DefaultEntityEventManager  : Publishing event [CoreEvent [type: DELETE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=d3517e1a-ea79-4c29-ad01-2e6199f00b27], properties: {}]]
2019-08-22 21:16:50.088  INFO 20935 --- [task-executor-3] e.b.i.c.a.e.AbstractEntityEventProcessor : Processor [attribute-controlled-value-delete-processor]([acc]) start for [CoreEvent [type: DELETE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=d3517e1a-ea79-4c29-ad01-2e6199f00b27], properties: {}]] with order [0].
2019-08-22 21:16:50.089  INFO 20935 --- [task-executor-3] e.b.i.c.a.e.AbstractEntityEventProcessor : Processor [attribute-controlled-value-delete-processor]([acc]) end for [CoreEvent [type: DELETE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=d3517e1a-ea79-4c29-ad01-2e6199f00b27], properties: {}]] with order [0].
2019-08-22 21:16:50.089  INFO 20935 --- [task-executor-3] e.b.i.c.m.s.i.DefaultEntityEventManager  : Event [CoreEvent [type: DELETE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=d3517e1a-ea79-4c29-ad01-2e6199f00b27], properties: {}]] is completed
2019-08-22 21:16:50.089  INFO 20935 --- [task-executor-3] e.b.i.c.m.s.i.DefaultEntityEventManager  : Publishing event [CoreEvent [type: CREATE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=null], properties: {}]]
2019-08-22 21:16:50.089  INFO 20935 --- [task-executor-3] e.b.i.c.a.e.AbstractEntityEventProcessor : Processor [core-entity-generate-values-processor]([core]) start for [CoreEvent [type: CREATE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=null], properties: {}]] with order [-100].
2019-08-22 21:16:50.089  INFO 20935 --- [task-executor-3] e.b.i.c.a.e.AbstractEntityEventProcessor : Processor [core-entity-generate-values-processor]([core]) end for [CoreEvent [type: CREATE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=null], properties: {}]] with order [-100].
2019-08-22 21:16:50.089  INFO 20935 --- [task-executor-3] e.b.i.c.a.e.AbstractEntityEventProcessor : Processor [attribute-controlled-value-save-processor]([acc]) start for [CoreEvent [type: CREATE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=null], properties: {}]] with order [0].
2019-08-22 21:16:50.109  INFO 20935 --- [task-executor-3] e.b.i.c.a.e.AbstractEntityEventProcessor : Processor [attribute-controlled-value-save-processor]([acc]) end for [CoreEvent [type: CREATE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=ac21a786-6224-4b8d-a26c-32a0aca35ee9], properties: {}]] with order [0].
2019-08-22 21:16:50.109  INFO 20935 --- [task-executor-3] e.b.i.c.m.s.i.DefaultEntityEventManager  : Event [CoreEvent [type: CREATE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=ac21a786-6224-4b8d-a26c-32a0aca35ee9], properties: {}]] is completed
2019-08-22 21:16:51.563  INFO 20935 --- [task-executor-2] e.b.i.c.m.s.i.DefaultEntityEventManager  : Publishing event [CoreEvent [type: DELETE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=d3517e1a-ea79-4c29-ad01-2e6199f00b27], properties: {}]]
2019-08-22 21:16:51.565  INFO 20935 --- [task-executor-2] e.b.i.c.a.e.AbstractEntityEventProcessor : Processor [attribute-controlled-value-delete-processor]([acc]) start for [CoreEvent [type: DELETE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=d3517e1a-ea79-4c29-ad01-2e6199f00b27], properties: {}]] with order [0].
2019-08-22 21:16:51.565  INFO 20935 --- [task-executor-2] e.b.i.c.a.e.AbstractEntityEventProcessor : Processor [attribute-controlled-value-delete-processor]([acc]) end for [CoreEvent [type: DELETE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=d3517e1a-ea79-4c29-ad01-2e6199f00b27], properties: {}]] with order [0].
2019-08-22 21:16:51.565  INFO 20935 --- [task-executor-2] e.b.i.c.m.s.i.DefaultEntityEventManager  : Event [CoreEvent [type: DELETE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=d3517e1a-ea79-4c29-ad01-2e6199f00b27], properties: {}]] is completed
2019-08-22 21:16:51.566  INFO 20935 --- [task-executor-2] e.b.i.c.m.s.i.DefaultEntityEventManager  : Publishing event [CoreEvent [type: CREATE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=null], properties: {}]]
2019-08-22 21:16:51.566  INFO 20935 --- [task-executor-2] e.b.i.c.a.e.AbstractEntityEventProcessor : Processor [core-entity-generate-values-processor]([core]) start for [CoreEvent [type: CREATE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=null], properties: {}]] with order [-100].
2019-08-22 21:16:51.566  INFO 20935 --- [task-executor-2] e.b.i.c.a.e.AbstractEntityEventProcessor : Processor [core-entity-generate-values-processor]([core]) end for [CoreEvent [type: CREATE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=null], properties: {}]] with order [-100].
2019-08-22 21:16:51.566  INFO 20935 --- [task-executor-2] e.b.i.c.a.e.AbstractEntityEventProcessor : Processor [attribute-controlled-value-save-processor]([acc]) start for [CoreEvent [type: CREATE, content: eu.bcvsolutions.idm.acc.dto.SysAttributeControlledValueDto [id=null], properties: {}]] with order [0].
2019-08-22 21:16:51.595 ERROR 20935 --- [task-executor-2] e.b.i.c.a.e.AbstractEntityEventProcessor : [core:EVENT_EXECUTE_PROCESSOR_FAILED:6d2621a6-77f9-452c-bdbc-77bafb43ff35] Event [null] failed in processor [attribute-controlled-value-save-processor]. ({eventId=null, processor=attribute-controlled-value-save-processor})
2019-08-22 21:16:51.599 ERROR 20935 --- [task-executor-2] i.DefaultSysProvisioningOperationService : [acc:PROVISIONING_FAILED:000aabb3-34cf-49dd-8624-177b97bee57e] Provisioning operation for object with uid [xxxxxxx] on system [AD uživatelé], operation type [UPDATE], object class [__ACCOUNT__] failed. ({name=xxxxxx, system=AD uživatelé, operationType=UPDATE, objectClass=__ACCOUNT__})
2019-08-22 21:16:51.604  INFO 20935 --- [task-executor-3] ontrolledValuesRecalculationTaskExecutor : End: Merge - attribute controlled values recalculation for system [6d33e1f9-a24c-430c-ad32-860d640b3a29]


Files

failed_provisioning_overview.png (6.59 KB) failed_provisioning_overview.png Alena Peterová, 08/23/2019 01:31 PM
failed_provisioning.png (52 KB) failed_provisioning.png Alena Peterová, 08/23/2019 01:31 PM
LRT_delete_role_recalculate.png (20.6 KB) LRT_delete_role_recalculate.png Alena Peterová, 08/23/2019 01:31 PM

Related issues

Related to IdStory Identity Manager - Defect #1818: Duplicate values in controlled values for Merge strategyClosedVít Švanda08/23/2019

Actions
Actions

Also available in: Atom PDF