CUCM LDAP Sync response - zero results

[riedmueller]

Hello,

I am trying to re-create some labs from an CICD course, and I am having no luck accomplishing a syncronization between my CUCM node (10.5) and my Domain Controller (2008R2).

Running wireshark on the DC, the search message from CUCM nets a reply of "zero results".

LDAP System as sAMAccountname set up as the user ID

LDAP Directory is pretty generic

The server address at the bottom of the page is obviously correct...

The Windows Server is set up so that the user dirsync is a Domain Admin. The ou CCMUsers definitely exists and is populated with one user

The user has all the required fields filled out (I had Steve Vai playing in the background, so..)

I run Wireshark on the DC, filtered for traffic between CUCM and DC, and I see the search request, but also see a "zero results" message

Any help or insight would be greatly appreciated!

[Jaime Valencia]

Try with the Administrator password from your LDAP server, if it works, then most likely it's a permissions issue from the account you're using.

[riedmueller]

Thanks Jaime

I just tried it and am still getting 0 results. It's like it does not look below the search base, even though it is supposed to.

In the capture of the LDAP traffic, the search message from CUCM specifies the scope as baseObject (0)

I know very little about directory services, but I used the LDP application built in to windows 2008 to search the directory using my DirSync user account, when I searched DC=collab10x,DC=com with the base scope specified and a filter of (object class=user), no records were returned. But, when I searched specifying "one level" below the base, I got a response (I have one user in the "root folder" of the domain, testing this specifically). When I selected "subtree" and searched again, I got all of the user records from all of the subordinate OUs and CNs.

I've done LDAP sync with CUCM before (8.6), so I know that it works; but in this instance, I cannot make it cooperate!

[TrevorRobinson7532]

Were you able to solve this?

[TrevorRobinson7532]

Was there ever any resolution on this issue? We are seeing the same problem right now.

[Jonathan Unger]

Hi Trevor,

There are several reasons why an LDAP sync can fail or return 0 results.

A few questions for you:

1. Is this a brand new LDAP sync you are configuring? Or is this an existing sync which is no longer working?
2. What version of CUCM and Windows Server are you running?

There is a log you can download from RTMT called "Cisco DirSync" which should give you an idea of where the problem is. Usually if a sync is failing and there are no obvious configurations/errors I can see, I will run the LDAP sync, wait a minute, and then download the DirSync log from RTMT and take a look. I would not recommend posting the DirSync trace here as it contains LDAP usernames and LDAP server IP addresses.

Semi-Pro Tip: If you are like me and too lazy to open RTMT sometimes you can also just SSH to the publisher server and start tailing the DirSync logfile before running your sync to capture the logs. Command to do so is:

file tail activelog /cm/trace/dirsync/log4j recent

[TrevorRobinson7532]

I am not a member of the team that manages CUCM but have asked them to get the version information. My team owns the LDAP implementation so I am trying to help them troubleshoot this. The sync was already configured but the process started failing after we upgraded our LDAP servers. I don't think this is a permissions issue for the service account because we tested giving them broad privileges in our test environment to no effect. 

I believe they have already provided me with the log details that you are requesting. I've pasted the errors we started seeing when the sync broke below.

2019-05-17 00:00:00,423 ERROR [DSLDAPSyncImpl(1e6e4ad1-8f0a-4c53-f1f1-59ceb5bed726)] ldapplugable.DSLDAPSyncImpl (DSLDAPSyncImpl.java:908) - LDAPSync(1e6e4ad1-8f0a-4c53-f1f1-59ceb5bed726)[checkLDAP] Failed to check LDAP - java.lang.NullPointerException
2019-05-17 00:00:00,438 ERROR [DSLDAPSyncImpl(1e6e4ad1-8f0a-4c53-f1f1-59ceb5bed726)] ldapplugable.DSLDAPSyncImpl (DSLDAPSyncImpl.java:909) - LDAPSync(1e6e4ad1-8f0a-4c53-f1f1-59ceb5bed726)[checkLDAP] java.lang.NullPointerException

[Jonathan Unger]

Hi There,

Are there any additional errors in the log above the ones you have posted (older)? Unfortunately the log entries posted are not giving me an indication as to what is causing the issue.

You mentioned that the issue started happening after the LDAP servers were upgraded. Was that the only change made to the LDAP environment?

[TrevorRobinson7532]

Those are the first log messages from the sync process that ran 2019-05-17. I've attached a larger snippet of the logs that shows some of the messages from the preceding day as well as the following.

We upgraded by building new servers with RHEL7 and the latest LDAP server version. After migrating the data (which includes the CUCM service account and access permissions) we updated DNS to point to the VIP in front of the new cluster.

[Jonathan Unger]

Hi Trevor,

Do the users in the new LDAP directory contain the exact same attributes as the old? The log indicates that there are several missing attributes (see below):

2019-05-16 00:10:21,223 ERROR [DirSync-DBInterface] common.DSDBInterface (DSDBInterface.java:568) - DSDBInterface.updateUserInfo LDAP data discarded: Missing LDAP attribute: Attribute Count=6 AgreementId=1e6e4ad1-8f0a-4c53-f1f1-59ceb5bed726
[directoryuri, firstname, mailid, department, discoveryuseridentity, lastname]

Can you engage your CUCM team to check the following?

1. What is the setting currently configured in CUCM under "System > LDAP > LDAP System"? Ensure that the LDAP server type matches your new RHEL server LDAP type.
   
   
2. Confirm that the LDAP server address field is pointed at the correct VIP.
   
   
3. Review the Standard User Fields to be Synchronized  section of the LDAP directory configuration on CUCM and compare that with your LDAP directory to ensure all of the fields being synchronized exist in the new version of the directory.

[TrevorRobinson7532]

Just to confirm, the sync was successful of 2019-06-16 so those log messages are part of that.

1.) Confirmed that the setting was still 'Sun or Oracle Directory Server'. We didn't change the flavor of LDAP server, just upgraded the major version.

2.) Definitely hitting the right VIP. We can see searches hitting the correct LDAP servers with the correct user filter in the logs but an LDAP search scope of 'base'. Trying to figure out what the sync process would be trying to check with these. Seems like some check is failing.

3.) I took a look at the Docs and we should be alright. The list of attributes that you highlighted have never been part of our directory so I don't think those are causing a problem. Especially since the sync process was successful on the 16th.

[TrevorRobinson7532]

Here are the LDAP logs. You can see it attempting to search our base user DN with our user object class as a filter. However, the search scope is 0 (base) so it is only looking at the 'ou=users,dc=autozone,dc=com' entry and none of its children.

[10/Jul/2019:12:59:37.207119925 -0500] conn=528609 op=1 SRCH base="ou=users,dc=autozone,dc=com" scope=0 filter="(objectClass=azPerson)" attrs=ALL

[10/Jul/2019:12:59:37.211274083 -0500] conn=528609 op=1 RESULT err=0 tag=101 nentries=0 etime=0.0004378427

[10/Jul/2019:12:59:37.255681104 -0500] conn=528609 op=2 SRCH base="" scope=0 filter="(objectClass=*)" attrs="subschemaSubentry"

[10/Jul/2019:12:59:37.259150769 -0500] conn=528609 op=2 RESULT err=0 tag=101 nentries=1 etime=0.0003770877

[10/Jul/2019:12:59:37.265605578 -0500] conn=528609 op=3 SRCH base="cn=schema" scope=0 filter="(objectClass=subschema)" attrs="objectClasses attributeTypes matchingRules ldapSyntaxes objectClass javaSerializedData javaClassName javaFactory javaCodebase javaReferenceAddress javaClassNames javaremotelocation"

[10/Jul/2019:12:59:37.454170066 -0500] conn=528609 op=3 RESULT err=0 tag=101 nentries=1 etime=0.1811187725

--

[10/Jul/2019:12:59:44.310922033 -0500] conn=528611 op=1 SRCH base="ou=users,dc=autozone,dc=com" scope=0 filter="(objectClass=azPerson)" attrs=ALL

[10/Jul/2019:12:59:44.312762891 -0500] conn=528611 op=1 RESULT err=0 tag=101 nentries=0 etime=0.0002070336

[10/Jul/2019:12:59:44.315536232 -0500] conn=528611 op=2 SRCH base="" scope=0 filter="(objectClass=*)" attrs="subschemaSubentry"

[10/Jul/2019:12:59:44.318557879 -0500] conn=528611 op=2 RESULT err=0 tag=101 nentries=1 etime=0.0003227679

[10/Jul/2019:12:59:44.321068220 -0500] conn=528611 op=3 SRCH base="cn=schema" scope=0 filter="(objectClass=subschema)" attrs="objectClasses attributeTypes matchingRules ldapSyntaxes objectClass javaSerializedData javaClassName javaFactory javaCodebase javaReferenceAddress javaClassNames javaremotelocation"

[10/Jul/2019:12:59:44.504192787 -0500] conn=528611 op=3 RESULT err=0 tag=101 nentries=1 etime=0.1816616922

--

[10/Jul/2019:12:59:45.023284095 -0500] conn=528613 op=1 SRCH base="" scope=0 filter="(objectClass=*)" attrs=ALL

[10/Jul/2019:12:59:45.026470972 -0500] conn=528613 op=1 RESULT err=0 tag=101 nentries=1 etime=0.0003476025

[Jonathan Unger]

Hi Trevor,

Thanks for that background information!

To my understanding, CUCM will always try to use a search base with a scope of wholeSubtree.

In the lab I changed my LDAP server type to "Sun or Oracle Directory Server" and took a PCAP to see what scope was being used in the LDAP request. I did see that 3 packets were sent, the first 2 with a scope of baseObject and the last packet with a scope of wholeSubtree.

Interestingly enough I saw no reference of the scope being used in the DirSync logs on the server (even though I have them set to debug). This could just be the normal logging behaviour in CUCM version 12.0.1.10000-10. This is why I took a PCAP on the LDAP server directly to see what scope was being used. This is odd and makes me less trustworthy of those logs (they may not tell the whole story).

Here is what I would recommend for next steps:

1. Confirm that the load balancer/proxy does not modify any contents of the LDAP requests.
   
   
2. Take a PCAP on the LDAP server (if possible) during a sync attempt to confirm with certainty which search scope is being used.
   
   
3. This is a long shot, I read somewhere else that someone was able to get the search scope to behave by changing the LDAP directory server address FROM FQDN to IP address in CUCM and performing a re-sync. Would be worth a shot if things are completely broken.
   
   
4. If #1 #2 and #3 offer no insight, I would recommend opening a case with Cisco TAC on CUCM and getting them to take a look. If you do end up having to go down this route, please do share the solution as there may be others with the same issue

[TrevorRobinson7532]

Nothing gets modified by the loadbalancer. They way it is configured, the SSL session is passed through to the LDAP server so it only sees the encrypted traffic.

The logs I posted with the scope information are from the LDAP server's logs so they are definitely accurate. We are seeing the first two searches with scope of baseObject but not the third with wholeSubtree. For whatever reason it seems like CUCM is not making that third search.

I believe we already have a case with Cisco TAC so I will follow up with the group that manages CUCM. Was just trying another route since it seemed like the OP had the same issue.

[Jonathan Unger]

Hi Trevor,

Thanks for that additional info.

Once the solution is found please do follow up!