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!
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.
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!
There are several reasons why an LDAP sync can fail or return 0 results.
A few questions for you:
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
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
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?
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.
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?
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.
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
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 18.104.22.16800-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:
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.