Delta Import timeouts on Identity Broker 5.1 Management Agents

Hi Andrew,

What is your configured setting for Page size (objects) on the Run Profile? How many changes are expected to be imported when the timeout occurs?

timeout settings are Timeout 999 secs, Operation Timeout 600. I believe the number of changes are normally small (in the 10s), however can't be certain of the number of objects as the adapter page in Broker 5.1 never seems to display the number of changes pending accurately.

As an example, I ran a Full Import on the MA last night and it brought in rougly 1600 changes. I'm attempting to run another Delta Import now.

Just had this timeout again

Is it happening consistently to all Delta Import operations or only intermitantly?

has been intermittent - but this morning has been on all delta imports. I'm now running a Full Import again now, as the changes get lost - IDB appears to return them to the FIM MA, however the operation times out somewhere.

Will email the logs thru as there seems to be buttons for adding video/images but not files.

Thanks for the clarifications.

For the record, you should be able to attach files by simply dragging them into the reply box.

Hi Andrew, Could you also please attach a screenshot of the failed runs in MIM so I can compare the timestamps? Sorry, should have asked for this earlier.

The stopped-extension-dll exceptions correspond to the Windows event log entry originally included.

Thanks Andrew. From your screenshot and logs, they're all timing out just after 1 minute. You definitely don't have it set as 60 instead of 600? Of the Delta Imports that were successful, did they all finish in under a minute? Did any last longer? I might have to add in some extra logging because I can't see why the timeout would happen after only 60 seconds given your configuration.

leave it with me for the moment, will do some additional testing after the current full import completes.

Here are the log entries from the latest Delta Import attempt, confirmed the operation timeout was 600secs. The first and last entry times marry up with the start and end time of the MA.

Can this please be investigated as a priority as this is in a production environment (not yet live), with a go live target in the next few weeks. The way the system is currently behaving it will not be possible to go live with the system in this state - this MA in particular is the authoritative source for Student Identities.

Hi Andrew,

Unfortunately I haven't been able to reproduce this in my test environment. Could you please try placing this patched copy of Unify.IdentityBroker.FIMAdapter.dll into the MIM extensions directory and re-attempting the Delta Import? If you let me know of a directory that I could create log files in, I can add some extra logging as well to try to diagnose this quicker.

Edit: I originally uploaded the wrong file, I've updated the link above but the link/attachment in the email notification will likely still be wrong.

Can log to C:\UNIFY\Logs\

Hi Andrew,

Given that the timeouts are interspersed with timeouts for reflection as well, I'm wondering if there is just too much activity happening at the same time - Adam has hinted at this as well in your other issue (IDB 5.1 returning duplicate objects that only exist once in the Adapter/Connector). Could you please try reattempting the import in isolation of other operations in Identity Broker?

This issue is now occurring again with the same symptoms - further details provided to Adam via email, however the error within FIM is included below. EB Pending checks and Delta imports are timing out.

The extensible extension returned an unsupported error.
The stack trace is:

"Unify.Product.IdentityBroker.LdapOperationException: Error during processing of SearchRequest targetting cn=changelog: Operation timed out while waiting for message queue with id of 9. ---> System.OperationCanceledException: Operation timed out while waiting for message queue with id of 9.
at Unify.Product.IdentityBroker.LdapConnection.GetMessage(Int32 messageId)
at Unify.Product.IdentityBroker.SearchRequest.Send(Func`2 send, Func`2 recv)
at Unify.Product.IdentityBroker.LdapConnection.SendRequest(ILdapRequest request)
--- End of inner exception stack trace ---
at Unify.Product.IdentityBroker.LdapConnection.SendRequest(ILdapRequest request)
at Unify.Product.IdentityBroker.LdapConnectionProxy.VerifyChangeLogConsistency(Int64 lastChangeNumber)
at Unify.Product.IdentityBroker.ImportProxy.<GetChangedEntriesPaged>d__30.MoveNext()
at System.Linq.Enumerable.<SelectManyIterator>d__14`2.MoveNext()
at System.Linq.Enumerable.WhereSelectEnumerableIterator`2.MoveNext()
at System.Linq.Enumerable.<SelectManyIterator>d__14`2.MoveNext()
at Unify.Product.IdentityBroker.ExtensionMethods.Take[TSource](IEnumerator`1 source, Int32 count, IList`1& items)
at Unify.Product.IdentityBroker.ExtensionMethods.<Page>d__3`1.MoveNext()
at Unify.Product.IdentityBroker.ImportProxy.Import(GetImportEntriesRunStep importRunStep)
Forefront Identity Manager 4.3.2266.0"

Thanks Andrew, looking into it.

Hi Andrew, I've attached an Identity Broker patch that removes locking around the change log. It's one of the simpler tables as it doesn't have to deal with updates or deletes. I have been smashing my instance of Identity Broker with the patch and was unable to trigger any issues.

Unify.IdentityBroker.ChangeLog.Repository.Sql.dll

Patch for v5.0: Unify.IdentityBroker.ChangeLog.Repository.Sql.dll

thanks Adam - does this go in the Services\Patches directory?

Either there, or the main Services directory.

Thanks.

Thanks Adam - appears to be working now, so will keep monitoring over the coming week and advise if we run into issues again.