Bug 729717 - Windows sync logs errors when a delete is synced from AD
Summary: Windows sync logs errors when a delete is synced from AD
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: 389
Classification: Retired
Component: Replication - General
Version: 1.2.9
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Nathan Kinder
QA Contact: Ben Levenson
URL:
Whiteboard:
Depends On:
Blocks: 690318 389_1.2.9 729838
TreeView+ depends on / blocked
 
Reported: 2011-08-10 15:59 UTC by Nathan Kinder
Modified: 2015-12-10 18:40 UTC (History)
2 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2015-12-10 18:40:59 UTC
Embargoed:


Attachments (Terms of Use)
Patch (3.85 KB, patch)
2011-08-10 21:21 UTC, Nathan Kinder
nkinder: review?
rmeggins: review+
Details | Diff

Description Nathan Kinder 2011-08-10 15:59:24 UTC
When a user delete operation is synced from AD->DS, the following messages are logged in the DS error log at the fatal log level:

------------------------------------------------------------------------------
[10/Aug/2011:08:22:06 -0700] NSMMReplicationPlugin - Could not retrieve entry from Windows using search base [<GUID=c20e55507a39ee4aa53a8024687466e2>] scope [0] filter [(objectclass=*)]: error 32:No such object
[10/Aug/2011:08:22:06 -0700] NSMMReplicationPlugin - Could not retrieve entry from Windows using search base [<GUID=c20e55507a39ee4aa53a8024687466e2>] scope [0] filter [(objectclass=*)]: error 32:No such object
------------------------------------------------------------------------------

Replication level logging shows that at least one of these errors are related to enabling the account, which we shouldn't be trying to do for a delete:

------------------------------------------------------------------------------
[09/Aug/2011:15:18:32 -0700] NSMMReplicationPlugin - changelog program - agmt="cn=meTo10.14.54.184389" (10:389): CSN 4e41b0fb000000010000 found, position set for replay
[09/Aug/2011:15:18:32 -0700] agmt="cn=meTo10.14.54.184389" (10:389) - load=1 rec=1 csn=4e41b236000100010000
[09/Aug/2011:15:18:32 -0700] NSMMReplicationPlugin - agmt="cn=meTo10.14.54.184389" (10:389): windows_replay_update: Looking at delete operation local dn="uid=deleteme,ou=people,dc=example,dc=com" (ours,user,not group)
[09/Aug/2011:15:18:32 -0700] NSMMReplicationPlugin - agmt="cn=meTo10.14.54.184389" (10:389): map_entry_dn_outbound: looking for AD entry for DS dn="nsuniqueid=ab112e01-c2d411e0-9734812a-3e1fdb92,uid=deleteme,ou=People,dc=example,dc=com" guid="29d3c7efd7d5c94b9994f0ce0717c13b"
[09/Aug/2011:15:18:32 -0700] - Calling windows entry search request plugin
[09/Aug/2011:15:18:32 -0700] NSMMReplicationPlugin - Could not retrieve entry from Windows using search base [<GUID=29d3c7efd7d5c94b9994f0ce0717c13b>] scope [0] filter [(objectclass=*)]: error 32:No such object
[09/Aug/2011:15:18:32 -0700] NSMMReplicationPlugin - agmt="cn=meTo10.14.54.184389" (10:389): map_entry_dn_outbound: return code -1 from search for AD entry dn="<GUID=29d3c7efd7d5c94b9994f0ce0717c13b>" or dn="(null)"
[09/Aug/2011:15:18:32 -0700] NSMMReplicationPlugin - agmt="cn=meTo10.14.54.184389" (10:389): map_entry_dn_outbound: entry not found - rc -1
[09/Aug/2011:15:18:32 -0700] NSMMReplicationPlugin - agmt="cn=meTo10.14.54.184389" (10:389): windows_replay_update: Processing delete operation local dn="uid=deleteme,ou=people,dc=example,dc=com" remote dn="<GUID=29d3c7efd7d5c94b9994f0ce0717c13b>"
[09/Aug/2011:15:18:32 -0700] NSMMReplicationPlugin - agmt="cn=meTo10.14.54.184389" (10:389): Received result code 0 (0000208D: NameErr: DSID-031001A8, problem 2001 (NO_OBJECT), data 0, best match of: 	'' ) for delete operation 
[09/Aug/2011:15:18:32 -0700] NSMMReplicationPlugin - agmt="cn=meTo10.14.54.184389" (10:389): windows_replay_update: deleted remote entry, dn="<GUID=29d3c7efd7d5c94b9994f0ce0717c13b>", result=0
[09/Aug/2011:15:18:32 -0700] - Calling windows entry search request plugin
[09/Aug/2011:15:18:32 -0700] NSMMReplicationPlugin - Could not retrieve entry from Windows using search base [<GUID=29d3c7efd7d5c94b9994f0ce0717c13b>] scope [0] filter [(objectclass=*)]: error 32:No such object
[09/Aug/2011:15:18:32 -0700] NSMMReplicationPlugin - agmt="cn=meTo10.14.54.184389" (10:389): New Windows entry <GUID=29d3c7efd7d5c94b9994f0ce0717c13b> will be enabled.
[09/Aug/2011:15:18:32 -0700] NSMMReplicationPlugin - agmt="cn=meTo10.14.54.184389" (10:389): Received result code 32 (0000208D: NameErr: DSID-031001A8, problem 2001 (NO_OBJECT), data 0, best match of: 	'' ) for modify operation 
[09/Aug/2011:15:18:32 -0700] NSMMReplicationPlugin - agmt="cn=meTo10.14.54.184389" (10:389): Consumer failed to replay change (uniqueid ab112e01-c2d411e0-9734812a-3e1fdb92, CSN 4e41b236000100010000): No such object. Skipping.
------------------------------------------------------------------------------

These errors do not block syncing future changes, but we should not have errors like this at the fatal log level for normal sync operations.  We also should not be trying to enable an account for a delete operation.

Comment 1 Nathan Kinder 2011-08-10 21:21:28 UTC
Created attachment 517697 [details]
Patch

Comment 2 Nathan Kinder 2011-08-10 22:15:35 UTC
Pushed to master.  Thanks to Rich for his review!

Counting objects: 25, done.
Delta compression using up to 2 threads.
Compressing objects: 100% (16/16), done.
Writing objects: 100% (16/16), 2.44 KiB, done.
Total 16 (delta 12), reused 0 (delta 0)
To ssh://git.fedorahosted.org/git/389/ds.git
   d7d0b2a..a150e8e  master -> master


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