0
Answered

Error during processing of SearchRequest targetting cn=changelog: Operation timed out

Bob Bradley 7 years ago updated by anonymous 7 years ago 3

The following 3 exceptions were logged today in the Application Event log for a failed MIM DI run profle against an IdB adapter:

<p style="margin-top:5pt;margin-bottom:5pt;font-family:Calibri;font-size:11.0pt"><span lang="en-US">Log Name:      Application</span><span lang="en-AU"><br>
</span><span lang="en-US">Source:       
FIMSynchronizationService</span><span lang="en-AU"><br>
</span><span lang="en-US">Date:         
5/07/2017 12:44:09 PM</span><span lang="en-AU"><br>
</span><span lang="en-US">Event ID:     
6110</span><span lang="en-AU"><br>
</span><span lang="en-US">Task Category: Management Agent Run Profile</span><span lang="en-AU"><br>
</span><span lang="en-US">Level:        
Warning</span><span lang="en-AU"><br>
</span><span lang="en-US">Keywords:     
Classic</span><span lang="en-AU"><br>
</span><span lang="en-US">User:         
N/A</span><span lang="en-AU"><br>
</span><span lang="en-US">Computer:     
AUHBSMIMWP0001.corp.qbe.com</span><span lang="en-AU"><br>
</span><span lang="en-US">Description:</span><span lang="en-AU"><br>
</span><span lang="en-US">The management agent "License Entitlements"
step execution completed on run profile "DI" but the watermark was
not saved.</span><span lang="en-AU"><br>
</span><span lang="en-US"> </span><span lang="en-AU"><br>
</span><span lang="en-US"> Additional
Information</span><span lang="en-AU"><br>
</span><span lang="en-US"> Discovery
Errors       : "0"</span><span lang="en-AU"><br>
</span><span lang="en-US"> Synchronization
Errors : "0"</span><span lang="en-AU"><br>
</span><span lang="en-US"> Metaverse Retry
Errors : "0"</span><span lang="en-AU"><br>
</span><span lang="en-US"> Export
Errors          : "0"</span><span lang="en-AU"><br>
</span><span lang="en-US"> Warnings               : "0"</span><span lang="en-AU"><br>
</span><span lang="en-US"> </span><span lang="en-AU"><br>
</span><span lang="en-US"> User Action</span><span lang="en-AU"><br>
</span><span lang="en-US"> View the
management agent run history for details.</span><span lang="en-AU"><br>
</span><span lang="en-US">Event Xml:</span><span lang="en-AU"><br>
</span><span lang="en-US"><Event xmlns="</span><a href="http://schemas.microsoft.com/win/2004/08/events/event"><span lang="en-US">http://schemas.microsoft.com/win/2004/08/events/event</span></a><span lang="en-US">"></span><span lang="en-AU"><br>
</span><span lang="en-US">  <System></span><span lang="en-AU"><br>
</span><span lang="en-US">    <Provider
Name="FIMSynchronizationService" /></span><span lang="en-AU"><br>
</span><span lang="en-US">    <EventID
Qualifiers="32768">6110</EventID></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Level>3</Level></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Task>1</Task></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Keywords>0x80000000000000</Keywords></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<TimeCreated SystemTime="2017-07-05T02:44:09.000000000Z"
/></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<EventRecordID>9375144</EventRecordID></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Channel>Application</Channel></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Computer>AUHBSMIMWP0001.corp.qbe.com</Computer></span><span lang="en-AU"><br>
</span><span lang="en-US">    <Security
/></span><span lang="en-AU"><br>
</span><span lang="en-US">  </System></span><span lang="en-AU"><br>
</span><span lang="en-US"> 
<EventData></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Data>License Entitlements</Data></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Data>DI</Data></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Data>0</Data></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Data>0</Data></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Data>0</Data></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Data>0</Data></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Data>0</Data></span><span lang="en-AU"><br>
</span><span lang="en-US"> 
</EventData></span><span lang="en-AU"><br>
</span><span lang="en-US"></Event></span></p>
<p style="margin-top:5pt;margin-bottom:5pt;font-family:Calibri;font-size:11.0pt"><span lang="en-US">Log Name:      Application</span><span lang="en-AU"><br>
</span><span lang="en-US">Source:       
FIMSynchronizationService</span><span lang="en-AU"><br>
</span><span lang="en-US">Date:         
5/07/2017 12:44:09 PM</span><span lang="en-AU"><br>
</span><span lang="en-US">Event ID:     
6803</span><span lang="en-AU"><br>
</span><span lang="en-US">Task Category: Management Agent Run Profile</span><span lang="en-AU"><br>
</span><span lang="en-US">Level:        
Error</span><span lang="en-AU"><br>
</span><span lang="en-US">Keywords:     
Classic</span><span lang="en-AU"><br>
</span><span lang="en-US">User:         
N/A</span><span lang="en-AU"><br>
</span><span lang="en-US">Computer:     
AUHBSMIMWP0001.corp.qbe.com</span><span lang="en-AU"><br>
</span><span lang="en-US">Description:</span><span lang="en-AU"><br>
</span><span lang="en-US">The management agent "License Entitlements"
failed on run profile "DI" because the server encountered errors.</span><span lang="en-AU"><br>
</span><span lang="en-US">Event Xml:</span><span lang="en-AU"><br>
</span><span lang="en-US"><Event xmlns="</span><a href="http://schemas.microsoft.com/win/2004/08/events/event"><span lang="en-US">http://schemas.microsoft.com/win/2004/08/events/event</span></a><span lang="en-US">"></span><span lang="en-AU"><br>
</span><span lang="en-US">  <System></span><span lang="en-AU"><br>
</span><span lang="en-US">    <Provider
Name="FIMSynchronizationService" /></span><span lang="en-AU"><br>
</span><span lang="en-US">    <EventID
Qualifiers="49152">6803</EventID></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Level>2</Level></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Task>1</Task></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Keywords>0x80000000000000</Keywords></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<TimeCreated SystemTime="2017-07-05T02:44:09.000000000Z"
/></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<EventRecordID>9375143</EventRecordID></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Channel>Application</Channel></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Computer>AUHBSMIMWP0001.corp.qbe.com</Computer></span><span lang="en-AU"><br>
</span><span lang="en-US">    <Security
/></span><span lang="en-AU"><br>
</span><span lang="en-US">  </System></span><span lang="en-AU"><br>
</span><span lang="en-US"> 
<EventData></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Data>License Entitlements</Data></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Data>DI</Data></span><span lang="en-AU"><br>
</span><span lang="en-US"> 
</EventData></span><span lang="en-AU"><br>
</span><span lang="en-US"></Event></span></p>
<p style="margin-top:5pt;margin-bottom:5pt;font-family:Calibri;font-size:11.0pt"><span lang="en-US">Log Name:      Application</span><span lang="en-AU"><br>
</span><span lang="en-US">Source:       
FIMSynchronizationService</span><span lang="en-AU"><br>
</span><span lang="en-US">Date:         
5/07/2017 12:44:09 PM</span><span lang="en-AU"><br>
</span><span lang="en-US">Event ID:     
6801</span><span lang="en-AU"><br>
</span><span lang="en-US">Task Category: Server</span><span lang="en-AU"><br>
</span><span lang="en-US">Level:        
Error</span><span lang="en-AU"><br>
</span><span lang="en-US">Keywords:     
Classic</span><span lang="en-AU"><br>
</span><span lang="en-US">User:         
N/A</span><span lang="en-AU"><br>
</span><span lang="en-US">Computer:     
AUHBSMIMWP0001.corp.qbe.com</span><span lang="en-AU"><br>
</span><span lang="en-US">Description:</span><span lang="en-AU"><br>
</span><span lang="en-US">The extensible extension returned an unsupported error.</span><span lang="en-AU"><br>
</span><span lang="en-US"> The stack trace
is:</span><span lang="en-AU"><br>
</span><span lang="en-US"> </span><span lang="en-AU"><br>
</span><span lang="en-US"> "Unify.Product.IdentityBroker.LdapOperationException:
Error during processing of SearchRequest targetting cn=changelog: Operation
timed out.</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
Unify.Product.IdentityBroker.LdapConnection.SendRequest(ILdapRequest request)</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
Unify.Product.IdentityBroker.LdapConnectionProxy.<SearchRequestPaged>d__9.MoveNext()</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
Unify.Product.IdentityBroker.ImportProxy.<GetChangedEntriesPaged>d__33.MoveNext()</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
System.Linq.Enumerable.<SelectManyIterator>d__14`2.MoveNext()</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
System.Linq.Enumerable.WhereSelectEnumerableIterator`2.MoveNext()</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
System.Linq.Enumerable.<SelectManyIterator>d__14`2.MoveNext()</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
Unify.Product.IdentityBroker.ExtensionMethods.Take[TSource](IEnumerator`1
source, Int32 count, IList`1& items)</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
Unify.Product.IdentityBroker.ExtensionMethods.<Page>d__3`1.MoveNext()</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
Unify.Product.IdentityBroker.ImportProxy.Import(GetImportEntriesRunStep
importRunStep)</span><span lang="en-AU"><br>
</span><span lang="en-US">Forefront Identity Manager 4.3.2195.0"</span><span lang="en-AU"><br>
</span><span lang="en-US">Event Xml:</span><span lang="en-AU"><br>
</span><span lang="en-US"><Event xmlns="</span><a href="http://schemas.microsoft.com/win/2004/08/events/event"><span lang="en-US">http://schemas.microsoft.com/win/2004/08/events/event</span></a><span lang="en-US">"></span><span lang="en-AU"><br>
</span><span lang="en-US">  <System></span><span lang="en-AU"><br>
</span><span lang="en-US">    <Provider
Name="FIMSynchronizationService" /></span><span lang="en-AU"><br>
</span><span lang="en-US">    <EventID
Qualifiers="49152">6801</EventID></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Level>2</Level></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Task>3</Task></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Keywords>0x80000000000000</Keywords></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<TimeCreated SystemTime="2017-07-05T02:44:09.000000000Z"
/></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<EventRecordID>9375142</EventRecordID></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Channel>Application</Channel></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Computer>AUHBSMIMWP0001.corp.qbe.com</Computer></span><span lang="en-AU"><br>
</span><span lang="en-US">    <Security
/></span><span lang="en-AU"><br>
</span><span lang="en-US">  </System></span><span lang="en-AU"><br>
</span><span lang="en-US"> 
<EventData></span><span lang="en-AU"><br>
</span><span lang="en-US">   
<Data>Unify.Product.IdentityBroker.LdapOperationException: Error
during processing of SearchRequest targetting cn=changelog: Operation timed
out.</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
Unify.Product.IdentityBroker.LdapConnection.SendRequest(ILdapRequest request)</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
Unify.Product.IdentityBroker.LdapConnectionProxy.<SearchRequestPaged>d__9.MoveNext()</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
Unify.Product.IdentityBroker.ImportProxy.<GetChangedEntriesPaged>d__33.MoveNext()</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
System.Linq.Enumerable.<SelectManyIterator>d__14`2.MoveNext()</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
System.Linq.Enumerable.WhereSelectEnumerableIterator`2.MoveNext()</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
System.Linq.Enumerable.<SelectManyIterator>d__14`2.MoveNext()</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
Unify.Product.IdentityBroker.ExtensionMethods.Take[TSource](IEnumerator`1
source, Int32 count, IList`1& items)</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
Unify.Product.IdentityBroker.ExtensionMethods.<Page>d__3`1.MoveNext()</span><span lang="en-AU"><br>
</span><span lang="en-US">   at
Unify.Product.IdentityBroker.ImportProxy.Import(GetImportEntriesRunStep
importRunStep)</span><span lang="en-AU"><br>
</span><span lang="en-US">Forefront Identity Manager 4.3.2195.0</Data></span><span lang="en-AU"><br>
</span><span lang="en-US"> 
</EventData></span><span lang="en-AU"><br>
</span><span lang="en-US"></Event></span></p>

This is the first time I've seen a timeout occur for a DI to the change log - is there something that can be set specifically to mitigate this?  So far indexing issues have impacted only full imports, but not deltas - and these are mitigated by daily index rebuilds.

Answer

Answer
Under review

Hi Bob,

Which version of Identity Broker is installed, and do you have any patches installed for Unify.IdentityBroker.ChangeLog.Repository.Sql.dll? As of Identity Broker v5.1, there should no longer be any SQL locking around access to the changelog context. This change will also be included in an upcoming Identity Broker v5.0 release, although it is not present in the current v5.0.5 RC1.

Answer
Under review

Hi Bob,

Which version of Identity Broker is installed, and do you have any patches installed for Unify.IdentityBroker.ChangeLog.Repository.Sql.dll? As of Identity Broker v5.1, there should no longer be any SQL locking around access to the changelog context. This change will also be included in an upcoming Identity Broker v5.0 release, although it is not present in the current v5.0.5 RC1.

Curtis - version is v5.0.5 Revision #0, and no there is no patch in place for that DLL.  We in a position to upgrade to the latest 5.0 version so please let me know when this is ready so we can install to DEV/UAT.  Thanks.

Answered
please let me know when this is ready

Will do.

Related issue: Delta Import timeouts on Identity Broker 5.1 Management Agents