cd-error exporting to IdB

Completely uninformative events in the Application Event log - one for each csentry that should have been exported:

Source: FIMSynchronizationService

ECMA2 export run caused an error

Error Name: Other

Error Detail:

Hi Carol,

Is there any mention in the IDB logs about activity on the LDAP endpoint? Have you tried running a trace to check for LDAP traffic?

Hi Carol,

As per my previous comment, have you tried running a network trace to verify that LDAP messages are being sent? Is there any mention of LDAP traffic in the IDB logs? There should be entries like the following

20170405,05:12:53,UNIFY Identity Broker,LDAP engine,Information,"Handling of LDAP bind request.
Handling of LDAP bind request received on connection 127.0.0.1:17628 to connect as user Admin completed successfully. The bind was successful. Duration: 00:00:00.0865004.",Normal
20170405,05:14:46,UNIFY Identity Broker,LDAP engine,Information,"Handling of LDAP add request.
Handling of LDAP add request received from user Admin on connection 127.0.0.1:17628 to add an entity with a distinguished name of CN=2,OU=Test,DC=IdentityBroker started.",Verbose

I did try a wireshark trace but wasn't sure whether it would pick up the traffic as MIM Sync and IdB are on the same server. I didn't see anything on port 389. Will have another go - unless you can suggest a better tool to use?

In that case you can use RawCap.exe (zipped as RawCap.zip) to capture traffic on 127.0.0.1.

Noticed this in the IdB log - Bulk Update postponed? Any idea what that is about?

20170405,05:49:57,UNIFY Identity Broker,LDAP Engine,Information,The LDAP endpoint has started at address 127.0.0.1:389.,Normal

20170405,05:50:27,UNIFY Identity Broker,LDAP Engine,Information,A client has connected to the LDAP endpoint from address: 127.0.0.1:63199.,Normal

20170405,05:50:27,UNIFY Identity Broker,LDAP engine,Information,"Handling of LDAP bind request.

Handling of LDAP bind request received on connection 127.0.0.1:63199 to connect as user IdBLDAP completed successfully. The bind was successful. Duration: 00:00:00.1750140.",Normal

20170405,05:50:31,UNIFY Identity Broker,LDAP engine,Information,"Handling of LDAP Bulk Start request.

Handling of LDAP Bulk Start request received from user IdBLDAP on connection 127.0.0.1:63199 completed successfully. Duration 00:00:01.9091401.",Normal

20170405,05:50:31,UNIFY Identity Broker,LDAP engine,Information,"Handling of LDAP Bulk Update request.

Handling of LDAP Bulk Update request received from user IdBLDAP on connection 127.0.0.1:63199 was postponed as it was not the next expected bulk request. This request will be handled as part of a future request. Duration 00:00:01.1630843.",Normal

20170405,05:51:36,UNIFY Identity Broker,LDAP engine,Information,"Handling of LDAP unbind request.

Handling of LDAP unbind request received on connection 127.0.0.1:63199 to connect as user IdBLDAP completed successfully. Duration: 00:00:00.0030016.",Normal

It suggests that pages of the bulk update request are being received out of order or pages are being missed -- the LDAP trace should give us a better picture of this.

I have noticed there are a few instances of duplicate UserIDs where the casing is different. I had made UserID the key on the connector, but Idb imported them fine, however MIM sees them as duplicates. Going to ask if they can be renamed or removed to see if it's a factor here.

Cannot currently get an LDAP trace - there is a long process involved with getting new software on a server here.

There were a few duplicate UserIDs (Aurion allows with different casing) but the admin deleted them for me and it hasn't made any difference. I also tried changing the IdB Adpater CH to "CN=@IdbID" just for the hell of it.

Log Name: Forefront Identity Manager Management Agent
Source: ForefrontIdentityManager.ManagementAgent
Date: 6/04/2017 8:25:32 AM
Event ID: 3
Task Category: None
Level: Error
Keywords: Classic
User: N/A
Computer: DPAC01MIM001.nonprod.protected.ind
Description:
Unhandled exception, the CLR will not terminate: System.NullReferenceException: Object reference not set to an instance of an object.
at Unify.Product.IdentityBroker.LdapMessage.get_MessageId()
at Unify.Product.IdentityBroker.LdapConnection.ListenForResponses()
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
at System.Threading.ThreadHelper.ThreadStart().
Event Xml:
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
<System>
<Provider Name="ForefrontIdentityManager.ManagementAgent" />
<EventID Qualifiers="0">3</EventID>
<Level>2</Level>
<Task>0</Task>
<Keywords>0x80000000000000</Keywords>
<TimeCreated SystemTime="2017-04-05T22:25:32.000000000Z" />
<EventRecordID>30151</EventRecordID>
<Channel>Forefront Identity Manager Management Agent</Channel>
<Computer>DPAC01MIM001.nonprod.protected.ind</Computer>
<Security />
</System>
<EventData>
<Data>Unhandled exception, the CLR will not terminate: System.NullReferenceException: Object reference not set to an instance of an object.
at Unify.Product.IdentityBroker.LdapMessage.get_MessageId()
at Unify.Product.IdentityBroker.LdapConnection.ListenForResponses()
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
at System.Threading.ThreadHelper.ThreadStart().</Data>
</EventData>
</Event>

Hi Carol,

I'm attaching the latest Unify.IdentityBroker.FIMAdapter.dll which should prevent the error from your latest comment, although this only occurrs when the export is already in a bad state. We may get a more helpful error though with this.

Looks like that new dll fixed it! I didn't think it had because it still three errors, but all the exports have gone out to Aurion this time. I think the errors were just because I hadn't refreshed the MA after updating the dll.

Hi Curtis,
This is still a problem for a number of exports - still no further detail other than "cd-error" and the same message about the postponed update in the IdB log.
I have managed to get redcap on the server now and have done a trace while running the export. I had a look at the results with wireshark but don't know what I'm supposed to be looking for, so hoping you can see what the issue is here.
Thanks,
Carol

I had to switch to using a combined key of PersonNumber + UserId in the connector because, it turns out, Aurion allows duplicate UserIds as long as the case is different, and they can't be changed. IdB also accepted the dupliactes and then MIM had a problem with them.

You're right I wasn't populating PersonNumber and UserId as part of provisioning. I added that in and now getting a different error for the adds - will send separately.

A general comment on exports - a common scenario I see is where the MIM export run profile completes with a success status but no export counters. It is only when you figure this doesn't make sense that you go digging in the logs to find the root cause. It seems to me that in some cases we're not seeing the error status returning to MIM. I can't be more specific right now but was wondering if anyone else was seeing this behaviour. I didn't report it at the time because I worked out the root cause and fixed it (whatever it was).

Yes I think so, but don't have specifics right now.