Bug 1084166 - AD user sync broken with update
Summary: AD user sync broken with update
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Fedora EPEL
Classification: Fedora
Component: 389-ds-base
Version: el5
Hardware: All
OS: Linux
unspecified
urgent
Target Milestone: ---
Assignee: Rich Megginson
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-04-03 17:55 UTC by Orion Poplawski
Modified: 2020-09-13 20:43 UTC (History)
5 users (show)

Fixed In Version: 389-ds-base-1.3.1.10-1
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2015-04-29 19:08:16 UTC
Type: Bug


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github 389ds 389-ds-base issues 829 0 None None None 2020-09-13 20:43:24 UTC

Description Orion Poplawski 2014-04-03 17:55:00 UTC
Description of problem:

We've been running 389-ds with AD user sync successfully for years.  Some time around Sep 2013-Jan 2014 AD user sync broke.  We see messages like:

[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): windows_replay_update: Looking at add operation local dn="uid=testuser2,ou=People,dc=nwra,dc=com" (ours,user,not group)
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): map_entry_dn_outbound: looking for AD entry for DS dn="uid=testuser2,ou=People,dc=nwra,dc=com" guid="(null)"
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): map_entry_dn_outbound: looking for AD entry for DS dn="uid=testuser2,ou=People,dc=nwra,dc=com" username="testuser2"
[03/Apr/2014:10:42:39 -0700] - Calling windows entry search request plugin
[03/Apr/2014:10:42:39 -0700] - windows_search_entry: received 1 messages, 0 entries, 0 references
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): map_entry_dn_outbound: entry not found - rc 0
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): windows_replay_update: Processing add operation local dn="uid=testuser2,ou=People,dc=nwra,dc=com" remote dn="cn=testuser2,(null)"
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): process_replay_add: dn="cn=testuser2,(null)" (not present,add allowed)
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): process_replay_add: failed to create mapped entry dn="cn=testuser2,(null)"
[03/Apr/2014:10:42:39 -0700] - Calling windows entry search request plugin
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - Could not retrieve entry from Windows using search base [cn=testuser2,(null)] scope [0] filter [(objectclass=*)]: error 34:Invalid DN syntax
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): New Windows entry cn=testuser2,(null) will be enabled.
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): Received result code 34 (0000208F: NameErr: DSID-031001F7, problem 2006 (BAD_NAME), data 8350, best match of:  'cn=testuser2,(null)' ) for modify operation
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): Consumer failed to replay change (uniqueid 51319681-bb5711e3-bfb09871-595bd420, CSN 533d9d91000000010000): Invalid DN syntax. Skipping.
[03/Apr/2014:10:42:39 -0700] agmt="cn=AD Sync" (hephaestus:636) - load=1 rec=2 csn=533d9d91000100010000
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): windows_replay_update: Looking at modify operation local dn="uid=testuser2,ou=People,dc=nwra,dc=com" (ours,user,not group)
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): map_entry_dn_outbound: looking for AD entry for DS dn="uid=testuser2,ou=People,dc=nwra,dc=com" guid="(null)"
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): map_entry_dn_outbound: looking for AD entry for DS dn="uid=testuser2,ou=People,dc=nwra,dc=com" username="testuser2"
[03/Apr/2014:10:42:39 -0700] - Calling windows entry search request plugin
[03/Apr/2014:10:42:39 -0700] - windows_search_entry: received 1 messages, 0 entries, 0 references
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): map_entry_dn_outbound: entry not found - rc 0
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): windows_replay_update: Processing modify operation local dn="uid=testuser2,ou=People,dc=nwra,dc=com" remote dn="cn=testuser2,(null)"
[03/Apr/2014:10:42:39 -0700] - Calling windows entry search request plugin
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - Could not retrieve entry from Windows using search base [cn=testuser2,(null)] scope [0] filter [(objectclass=*)]: error 34:Invalid DN syntax
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): New Windows entry cn=testuser2,(null) will be enabled.
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): Received result code 34 (0000208F: NameErr: DSID-031001F7, problem 2006 (BAD_NAME), data 8350, best match of:  'cn=testuser2,(null)' ) for modify operation
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): Consumer failed to replay change (uniqueid 51319681-bb5711e3-bfb09871-595bd420, CSN 533d9d91000100010000): Invalid DN syntax. Skipping.
[03/Apr/2014:10:42:39 -0700] agmt="cn=AD Sync" (hephaestus:636) - load=1 rec=3 csn=533d9d91000200010000
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): windows_replay_update: Looking at add operation local dn="cn=testuser2,ou=auto.home,dc=cora,dc=nwra,dc=com" (ours)
[03/Apr/2014:10:42:39 -0700] agmt="cn=AD Sync" (hephaestus:636) - load=1 rec=4 csn=533d9d91000400010000
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): windows_replay_update: Looking at modify operation local dn="uid=testuser2,ou=People,dc=nwra,dc=com" (ours,user,not group)
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): map_entry_dn_outbound: looking for AD entry for DS dn="uid=testuser2,ou=People,dc=nwra,dc=com" guid="(null)"
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): map_entry_dn_outbound: looking for AD entry for DS dn="uid=testuser2,ou=People,dc=nwra,dc=com" username="testuser2"
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=boulder" (ldap:636): No linger to cancel on the connection
[03/Apr/2014:10:42:39 -0700] - Calling windows entry search request plugin
[03/Apr/2014:10:42:39 -0700] - windows_search_entry: received 1 messages, 0 entries, 0 references
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): map_entry_dn_outbound: entry not found - rc 0
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): windows_replay_update: Processing modify operation local dn="uid=testuser2,ou=People,dc=nwra,dc=com" remote dn="cn=testuser2,(null)"
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): process_replay_add: dn="cn=testuser2,(null)" (not present,add allowed)
[03/Apr/2014:10:42:39 -0700] - Windows sync entry: Created new remote entry:
 dn: cn=testuser2,(null)
objectClass: top
objectClass: person
objectClass: organizationalperson
objectClass: user
userprincipalname: testuser2@nwra.local
sAMAccountName: testuser2
cn: testuser2
sn: testuser2
mail: testuser2@nwra.com

[03/Apr/2014:10:42:39 -0700] - Attempting to add entry cn=testuser2,(null) to AD for local entry uid=testuser2,ou=People,dc=nwra,dc=com
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): Received result code 34 (0000208F: NameErr: DSID-031001F7, problem 2006 (BAD_NAME), data 8350, best match of:  '(null)' ) for add operation
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): windows_replay_add: Cannot replay add operation.
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): windows_replay_update: The modify operation added the sync objectclass and attribute, so the entry was added to windows - result [1]
[03/Apr/2014:10:42:39 -0700] NSMMReplicationPlugin - agmt="cn=AD Sync" (hephaestus:636): Simple bind resumed

Notice the "(null)" for the AD DN base.

Version-Release number of selected component (if applicable):
389-ds-base-1.2.11.28-1.el5.x86_64

We expect that was working in 389-ds-base-1.2.9.9-1.el5.x86_64 and broke in one of:
389-ds-base-1.2.10.14-1.el5.x86_64
389-ds-base-1.2.10.14-2.el5.x86_64
389-ds-base-1.2.11.25-1.el5.x86_64

Another user on the mailing list had this same problem and reported it working again with the 1.3.X series.

Comment 1 Noriko Hosoi 2014-04-03 18:34:32 UTC
Thank you for your report.  May I ask you to try one thing?

Recently, we had a similar report and it turned out the reporter's indexes were some how outdated.  The index files were ntUniqueId.db4 and ntUserDomainId.db4.  Once they reindexed them, it started working for them.  Could you try that?

Thanks.

Comment 2 Orion Poplawski 2014-04-03 19:34:45 UTC
That does not appear to help.  Reindexed everything in userRoot too.  Anything else to try?  Thanks.

Comment 3 Noriko Hosoi 2014-04-03 20:07:57 UTC
We fixed these winsync related bugs since we moved to trac ticket (about 2 years ago).  Do you see any fix which could be related to your case?  (Please check the tickets which milestone is 1.3.0 or newer.)

https://fedorahosted.org/389/query?status=closed&component=Sync+Service&order=milestone&desc=1&report=16&col=id&col=summary&col=status&col=type&col=priority&col=milestone&col=component

Thanks.

Comment 4 Rich Megginson 2014-04-03 23:10:21 UTC
This problem is specific to EL5 and is likely due to some difference between our support for mozldap vs. openldap.

I am able to reproduce the problem on EL5.

Comment 5 Rich Megginson 2014-04-03 23:11:28 UTC
This was likely broken when we switched EL5 over to 389-ds-base-1.2.11.  We had to do that because it was simply too difficult to keep backporting security errata and other critical bug fixes to 1.2.10/1.2.9.  We are working on a fix and hope to have something soon.

Comment 6 Rich Megginson 2014-04-04 02:26:13 UTC
No, not just el5/mozldap.  This is the culprit: https://fedorahosted.org/389/ticket/47492 - we need to re-fix this ASAP.

Comment 7 Rich Megginson 2014-04-04 02:27:49 UTC
Upstream ticket:
https://fedorahosted.org/389/ticket/47492

Comment 8 Orion Poplawski 2014-04-18 21:01:22 UTC
Any packages we can test?  Is this in 389-ds-base-1.2.11.29-1.el5?

Comment 9 Noriko Hosoi 2014-04-18 21:23:16 UTC
(In reply to Orion Poplawski from comment #8)
> Any packages we can test?  Is this in 389-ds-base-1.2.11.29-1.el5?

Yes, it is.
http://directory.fedoraproject.org/wiki/Releases/1.2.11.29
Ticket 47492 - PassSync removes User must change password flag on the Windows side


Note You need to log in before you can comment on or make changes to this bug.