IPA failure in ipa user-del --preserve (rawhide): This entry already exists

[flo-renaud]

Issue Description
Starting with 389-ds 2.0.8 on rawhide, any call to ipa user-del --preserve fails with This entry already exists.
See for instance in PR #1128 the test testing-fedora/test_user_permissions : logs, report:

DEBUG    ipatests.pytest_ipa.integration.host.Host.master.cmd70:transport.py:513 RUN ['ipa', 'user-del', '--preserve', 'testuser']
DEBUG    ipatests.pytest_ipa.integration.host.Host.master.cmd70:transport.py:557 ipa: ERROR: This entry already exists
DEBUG    ipatests.pytest_ipa.integration.host.Host.master.cmd70:transport.py:217 Exit code: 1

Package Version and Platform:

• Platform: Fedora 35
• Package and version: 389-ds-base-2.0.8-1.fc34.x86_64

Steps to Reproduce
Steps to reproduce the behavior:

1. Install ipa server: ipa-server-install --domain ipa.test --realm IPA.TEST --setup-dns --auto-forwarders -a Secret123 -p Secret123 -U
2. Add a user: kinit admin; ipa user-add idmuser --first idmuser --last idmuser
3. Delete the user with ipa user-del idmuser --preserve

Additional information:
Adding nsslapd-errorlog-level: 65536 we can see the issue happens in NSUniqueAttribute plugin.

# date; ipa user-del idmuser --preserve
Wed Sep  1 10:50:13 AM EDT 2021
ipa: ERROR: This entry already exists

Access log:

[01/Sep/2021:10:50:13.728506777 -0400] conn=48 op=9 MODRDN dn="uid=idmuser,cn=users,cn=accounts,dc=ipa,dc=test" newrdn="uid=idmuser" newsuperior="cn=deleted users,cn=accounts,cn=provisioning,dc=ipa,dc=test"
[01/Sep/2021:10:50:13.756761101 -0400] conn=48 op=9 RESULT err=19 tag=109 nentries=0 wtime=0.000114939 optime=0.028257189 etime=0.028369512

Error log:

[01/Sep/2021:10:50:13.728572166 -0400] - DEBUG - NSUniqueAttr - preop_modrdn - MODRDN begin
[01/Sep/2021:10:50:13.730537596 -0400] - DEBUG - NSUniqueAttr - preop_modrdn - MODRDN newrdn=uid=idmuser
[01/Sep/2021:10:50:13.732567737 -0400] - DEBUG - NSUniqueAttr - preop_modrdn - MODRDN begin
[01/Sep/2021:10:50:13.734228715 -0400] - DEBUG - NSUniqueAttr - preop_modrdn - MODRDN newrdn=uid=idmuser
[01/Sep/2021:10:50:13.736357208 -0400] - DEBUG - NSUniqueAttr - preop_modrdn - MODRDN begin
[01/Sep/2021:10:50:13.738275244 -0400] - DEBUG - NSUniqueAttr - preop_modrdn - MODRDN newrdn=uid=idmuser
[01/Sep/2021:10:50:13.740273136 -0400] - DEBUG - NSUniqueAttr - preop_modrdn - MODRDN begin
[01/Sep/2021:10:50:13.742801084 -0400] - DEBUG - NSUniqueAttr - preop_modrdn - MODRDN newrdn=uid=idmuser
[01/Sep/2021:10:50:13.745076857 -0400] - DEBUG - NSUniqueAttr - search - SEARCH baseDN=dc=ipa,dc=test attr=ipaUniqueID target=cn=deleted users,cn=accounts,cn=provisioning,dc=ipa,dc=test
[01/Sep/2021:10:50:13.746808012 -0400] - DEBUG - NSUniqueAttr - search_one_berval - SEARCH filter=(|(ipaUniqueID=14032338-0b30-11ec-bb49-fa163e67fa8f))
[01/Sep/2021:10:50:13.749069092 -0400] - DEBUG - NSUniqueAttr - search_one_berval - SEARCH entry dn=uid=idmuser,cn=users,cn=accounts,dc=ipa,dc=test
[01/Sep/2021:10:50:13.750919854 -0400] - DEBUG - NSUniqueAttr - search_one_berval - SEARCH complete result=19
[01/Sep/2021:10:50:13.752775735 -0400] - DEBUG - NSUniqueAttr - search - SEARCH result = 19
[01/Sep/2021:10:50:13.754652994 -0400] - DEBUG - NSUniqueAttr - preop_modrdn - MODRDN result 19

Configuration of attr uniqueness plugin for ipaUniqueID:

dn: cn=ipaUniqueID uniqueness,cn=plugins,cn=config
cn: ipaUniqueID uniqueness
nsslapd-plugin-depends-on-type: database
nsslapd-pluginDescription: Enforce unique attribute values
nsslapd-pluginEnabled: on
nsslapd-pluginId: NSUniqueAttr
nsslapd-pluginInitfunc: NSUniqueAttr_Init
nsslapd-pluginPath: libattr-unique-plugin
nsslapd-pluginType: preoperation
nsslapd-pluginVendor: 389 Project
nsslapd-pluginVersion: 2.0.9
objectClass: top
objectClass: nsSlapdPlugin
objectClass: extensibleObject
uniqueness-across-all-subtrees: on
uniqueness-attribute-name: ipaUniqueID
uniqueness-exclude-subtrees: cn=staged users,cn=accounts,cn=provisioning,dc=ipa,dc=test
uniqueness-subtrees: dc=ipa,dc=test

There was an update in 2.0.8 related to attr uniqueness plugin, maybe worth checking if it's related: #4763

[flo-renaud]

Companion issue on IPA side: https://pagure.io/freeipa/issue/8976

[Firstyear]

There has been a single change recently here with 9cf2517b5e so I wonder if that's part of the impact here? It affects the subtree in which we searched for entries to compare, so that would check out with the symptoms you describe here ....

[tbordaz]

@Firstyear good catch. Indeed, I think the fix #4763 is invalid. The 'target' used in the fix is just to prevent that the operation fails because of source/target entry itself, it has nothing to do with the scope that is configured at plugin level.

I will comment #4763

[droideck]

4173918..57b6480 389-ds-base-1.4.3 -> 389-ds-base-1.4.3
3982ce6..012a6a3 389-ds-base-1.4.4 -> 389-ds-base-1.4.4
93aa9f4..4634ec6 389-ds-base-2.0 -> 389-ds-base-2.0