Concurrent identity refresh task getting stuck

kcwong · August 13, 2021, 9:37am

I have:

A plugin that will launch several threads.
A task named “IDRefresh”. It is the default identity refresh task but with “Allow Concurrency” enabled.
Each thread started by the plugin will be allocated an identity unique to that thread.
Each thread will launch IDRefresh with parameter to refresh that thread’s identity.

But I found that often some of the IDRefresh task will get stuck. They will forever be pending until I clean them up with iiq console (with the terminateOrphans please command).

How can I troubleshoot this? I want to stop them from getting stuck but I have no idea what they are getting stuck on.

adam_creaney · August 23, 2021, 3:20pm

Hi @kcwong - a good first step would be to turn on some logging for the refresh process.

I would turn on logging for:

sailpoint.task.IdentityRefreshExecutor
sailpoint.api.Identitizer

These will be very verbose and add lots of information to your logs, so make sure they are turned off after debugging. This should narrow down which methods are getting stuck.

kcwong · September 3, 2021, 7:43am

Thanks @adam_creaney for the suggestion.

But searching through the log, I couldn’t find anything worthy of notice from Identitizer and IdentityRefreshExecutor. Instead, I found SQL exceptions:

2021-09-03 15:00:29,147  WARN QuartzScheduler_Worker-2 org.hibernate.util.JDBCExceptionReporter:100 - SQL Error: 2627, SQLState: 23000
2021-09-03 15:00:29,147 ERROR QuartzScheduler_Worker-2 org.hibernate.util.JDBCExceptionReporter:101 - Violation of UNIQUE KEY constraint 'UQ__spt_task__72E12F1B85E4BF00'. Cannot insert duplicate key in object 'identityiq.spt_task_result'. The duplicate key value is (IntegrationTest-IDRefresh).
2021-09-03 15:00:29,147 ERROR QuartzScheduler_Worker-2 sailpoint.api.TaskManager:2009 - Unable to close TaskResult: IntegrationTest-IDRefresh
2021-09-03 15:00:29,147 ERROR QuartzScheduler_Worker-2 sailpoint.api.TaskManager:2010 - sailpoint.tools.GeneralException: could not update: [sailpoint.object.TaskResult#8a42e2777baa7375017baa7564e40052]
2021-09-03 15:00:29,163  WARN QuartzScheduler_Worker-2 org.hibernate.util.JDBCExceptionReporter:100 - SQL Error: 2627, SQLState: 23000
2021-09-03 15:00:29,163 ERROR QuartzScheduler_Worker-2 org.hibernate.util.JDBCExceptionReporter:101 - Violation of UNIQUE KEY constraint 'UQ__spt_task__72E12F1B85E4BF00'. Cannot insert duplicate key in object 'identityiq.spt_task_result'. The duplicate key value is (IntegrationTest-IDRefresh).
2021-09-03 15:00:29,163 ERROR QuartzScheduler_Worker-2 sailpoint.scheduler.JobAdapter:138 - The 11742f33ce774939a310801073492955 task failed to execute
sailpoint.tools.GeneralException: could not update: [sailpoint.object.TaskResult#8a42e2777baa7375017baa7564e40052]
	at sailpoint.persistence.HibernatePersistenceManager.commitTransaction(HibernatePersistenceManager.java:497)
	at sailpoint.persistence.ClassPersistenceManager.commitTransaction(ClassPersistenceManager.java:207)
	at sailpoint.server.InternalContext.commitTransaction(InternalContext.java:520)
	at sailpoint.api.Terminator.innerDelete(Terminator.java:323)
	at sailpoint.api.Terminator.visitTaskSchedule(Terminator.java:2607)
	at sailpoint.object.TaskSchedule.visit(TaskSchedule.java:844)
	at sailpoint.object.Visitor.visit(Visitor.java:26)
	at sailpoint.api.Terminator.deleteObject(Terminator.java:256)
	at sailpoint.scheduler.JobAdapter.execute(JobAdapter.java:133)
	at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
Caused by: org.hibernate.exception.ConstraintViolationException: could not update: [sailpoint.object.TaskResult#8a42e2777baa7375017baa7564e40052]
	at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:96)
	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
	at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2596)
	at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2478)
	at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2805)
	at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:114)
	at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:268)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:260)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:180)
	at sailpoint.persistence.PatchedDefaultFlushEventListener.performExecutions(PatchedDefaultFlushEventListener.java:39)
	at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51)
	at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1206)
	at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:375)
	at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:137)
	at sailpoint.persistence.HibernatePersistenceManager.commitTransaction(HibernatePersistenceManager.java:483)
	... 10 more
Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: Violation of UNIQUE KEY constraint 'UQ__spt_task__72E12F1B85E4BF00'. Cannot insert duplicate key in object 'identityiq.spt_task_result'. The duplicate key value is (IntegrationTest-IDRefresh).
	at com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDatabaseError(SQLServerException.java:256)
	at com.microsoft.sqlserver.jdbc.SQLServerStatement.getNextResult(SQLServerStatement.java:1621)
	at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.doExecutePreparedStatement(SQLServerPreparedStatement.java:592)
	at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement$PrepStmtExecCmd.doExecute(SQLServerPreparedStatement.java:522)
	at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:7194)
	at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:2930)
	at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeCommand(SQLServerStatement.java:248)
	at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeStatement(SQLServerStatement.java:223)
	at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.executeUpdate(SQLServerPreparedStatement.java:471)
	at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105)
	at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105)
	at org.hibernate.jdbc.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:46)
	at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2574)
	... 22 more

The task result ID reported in the log matches the one my plugin found to be stuck.

My plugin launches the task with the runWithResult API:

			TaskManager manager = new TaskManager(context);
			TaskResult tr = manager.runWithResult(task, parameters);

And then I monitors the TaskResult by repeatedly searching for TaskResult with its ID and checking its status:

			do {
				TaskResult r = context.getObjectById(TaskResult.class, id);
				if (r != null) {
					CompletionStatus status = r.getCompletionStatus();
					context.decache(r);
					// Check status here, break when completed
				}
				Thread.sleep(5000);
			} while (!timeout);

Is it perhaps due to a delicate timing issue, my code checking the status blocks the task from updating it?

adam_creaney · September 13, 2021, 4:35pm

The SQL exception being thrown is stating that you already have a TaskResult with the name ‘IntegrationTest-IDRefresh’ . What does your TaskDefinition look like (XML) and what does the Map ‘parameters’ contain?

kcwong · September 15, 2021, 1:58am

This is the task definition:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE TaskDefinition PUBLIC "sailpoint.dtd" "sailpoint.dtd">
<TaskDefinition name="IntegrationTest-IDRefresh" concurrent="true" resultAction="Rename" subType="task_item_type_identity" type="Identity">
  <Attributes>
    <Map>
      <entry key="TaskSchedule.host"/>
      <entry key="checkHistory" value="false"/>
      <entry key="checkPolicies" value="true"/>
      <entry key="correlateEntitlements" value="true"/>
      <entry key="correlateScope" value="true"/>
      <entry key="deleteDormantGroups" value="true"/>
      <entry key="disableManagerLookup" value="false"/>
      <entry key="doManualActions" value="false"/>
      <entry key="enableManualAccountSelection" value="false"/>
      <entry key="enablePartitioning" value="false"/>
      <entry key="excludeInactive" value="false"/>
      <entry key="filter" value=""/>
      <entry key="filterNeedsRefresh" value="false"/>
      <entry key="forceWorkflow" value="false"/>
      <entry key="includeWindowModified" value="false"/>
      <entry key="keepInactiveViolations" value="false"/>
      <entry key="markDormantScopes" value="false"/>
      <entry key="noAutoCreateScopes" value="false"/>
      <entry key="noMaintenanceWindowRetry" value="false"/>
      <entry key="noResetNeedsRefresh" value="false"/>
      <entry key="noRoleDeprovisioning" value="true"/>
      <entry key="processTriggers" value="true"/>
      <entry key="promoteAttributes" value="true"/>
      <entry key="promoteManagedAttributes" value="true"/>
      <entry key="provision" value="true"/>
      <entry key="refreshCertifications" value="false"/>
      <entry key="refreshCompositeApplications" value="true"/>
      <entry key="refreshGroups" value="false"/>
      <entry key="refreshIdentityEntitlements" value="true"/>
      <entry key="refreshManagerStatus" value="true"/>
      <entry key="refreshRoleMetadata" value="false"/>
      <entry key="refreshScorecard" value="false"/>
      <entry key="synchronizeAttributes" value="true"/>
      <entry key="taskCompletionEmailNotify" value="Disabled"/>
      <entry key="taskCompletionEmailRecipients"/>
      <entry key="taskCompletionEmailTemplate"/>
    </Map>
  </Attributes>
  <Description>Identity refresh task for Integration Test plugin</Description>
  <Owner>
    <Reference class="sailpoint.object.Identity" name="spadmin"/>
  </Owner>
  <Parent>
    <Reference class="sailpoint.object.TaskDefinition" name="Identity Refresh"/>
  </Parent>
</TaskDefinition>

Parameters is constructed like this:

	public static boolean refreshIdentity(AbstractTestCase tc, String... identityName) throws GeneralException, TimeoutException, SkipException {
		List<Filter> filterList = new ArrayList<Filter>();
		if (identityName != null) {
			for (String name : identityName) {
				Filter f = Filter.eq("name", name);
				filterList.add(f);
			}
		}
		Filter f = Filter.or(filterList.toArray(new Filter[0]));
		Map<String, Object> parameters = new HashMap<String, Object>();
		parameters.put(TASK_FILTER, f.toString());

For example, parameters map contains:
Key: filter
Value: name == ''00000001" || name == “00000002”

Topic		Replies	Views
Refresh Identity task get stuck IIQ Discussion and Questions	7	922	July 23, 2023
Maximum refresh exceptions reached every 4-6 hours IIQ Discussion and Questions identityiq	3	760	July 25, 2023
Error during role refresh IIQ Discussion and Questions	5	1131	July 19, 2023
Identity Refresh Error - A different object with the same identifier value was already associated with the session IdentityIQ (IIQ)	0	1979	June 22, 2022
Identity Refresh Error - A different object with the same identifier value was already associated with the session IIQ Discussion and Questions identityiq	3	1549	July 19, 2023

Concurrent identity refresh task getting stuck

Related Topics