[Freeipa-users] Freeipa 4.3.0 replica installation fails with DuplicateEntry: This entry already exists

Nathan Peters Nathan.Peters at globalrelay.net
Wed Jan 20 19:24:55 UTC 2016 

Now we are starting to get somewhere (although a resolution still is not visible) :)

First, thank you Petr and Rob for your help on this issue.  I apologize for our hard to parse server names.  I'm not a fan of them myself and in earlier reports I had been reformatting everything nicely with dc1, dc2, dc3 etc.  After having to submit so many reports I started to get lazy an thought it may be more helpful to see data closer to what we are actually using.

Petr hit the nail on the head with the "does everyone who binds get the same result" question, which although it has not revealed a resolution, has revealed a bunch of really interesting facts about the process.

Going back to the original logs that were running on the remote master during the replica installation attempt I see the following :

[18/Jan/2016:09:28:32 -0800] conn=18732 fd=77 slot=77 connection from 10.21.0.98 to 10.178.0.98
> [18/Jan/2016:09:28:32 -0800] conn=18732 op=0 BIND dn="" method=sasl version=3 mech=GSSAPI
> [18/Jan/2016:09:28:32 -0800] conn=18732 op=0 RESULT err=14 tag=97 nentries=0 etime=0, SASL bind in progress
> [18/Jan/2016:09:28:32 -0800] conn=18732 op=1 BIND dn="" method=sasl version=3 mech=GSSAPI
> [18/Jan/2016:09:28:32 -0800] conn=18732 op=1 RESULT err=14 tag=97 nentries=0 etime=0, SASL bind in progress
> [18/Jan/2016:09:28:32 -0800] conn=18732 op=2 BIND dn="" method=sasl version=3 mech=GSSAPI
> [18/Jan/2016:09:28:32 -0800] conn=18732 op=2 RESULT err=0 tag=97 nentries=0 etime=0 dn="fqdn=dc2-ipa-dev-van.mydomain.net,cn=computers,cn=accounts,dc=mydomain,dc=net"
> [18/Jan/2016:09:28:32 -0800] conn=18732 op=3 SRCH base="cn=replication,cn=etc,dc=mydomain,dc=net" scope=0 filter="(objectClass=*)" attrs=ALL
> [18/Jan/2016:09:28:32 -0800] conn=18732 op=3 RESULT err=0 tag=101 nentries=1 etime=0
> [18/Jan/2016:09:28:32 -0800] conn=18732 op=4 SRCH base="cn=schema" scope=0 filter="(objectClass=*)" attrs="attributeTypes objectClasses"
> [18/Jan/2016:09:28:32 -0800] conn=18732 op=4 RESULT err=0 tag=101 nentries=1 etime=0

So, conn18732 was opened with a bind dn of "" ?  Is this supposed to happen?

Here is what I see when I search that base using the same empty bind dn :

---snip---
[root at dc2-ipa-dev-van ~]# ldapsearch -H ldaps://dc2-ipa-dev-nvan.mydomain.net -b "cn=replica,cn=dc\3Dmydomain\2Cdc\3Dnet,cn=mapping tree,cn=config" -D ""
# extended LDIF
#
# LDAPv3
# base <cn=replica,cn=dc\3Dmydomain\2Cdc\3Dnet,cn=mapping tree,cn=config> with scope subtree
# filter: (objectclass=*)
# requesting: ALL
#

# search result
search: 2
result: 0 Success

# numResponses: 1
---snip---

Here is a similar empty looking result when I bind as the admin user

---snip---
[root at dc2-ipa-dev-van ~]# ldapsearch -H ldaps://dc2-ipa-dev-nvan.mydomain.net -b "cn=replica,cn=dc\3Dmydomain\2Cdc\3Dnet,cn=mapping tree,cn=config" -D "uid=admin,cn=users,cn=accounts,dc=mydomain,dc=net" -W
Enter LDAP Password:
# extended LDIF
#
# LDAPv3
# base <cn=replica,cn=dc\3Dmydomain\2Cdc\3Dnet,cn=mapping tree,cn=config> with scope subtree
# filter: (objectclass=*)
# requesting: ALL
#

# search result
search: 2
result: 0 Success

# numResponses: 1
---snip---

So we know that for whatever reason, this particular DN cannot be searched from anyone other than directory manager.

So I now have a few new questions...

1. What user is the ipa-replica-install command supposed to bind as ?  directory manager, admin, or "" ?

2/3. Should the ACL on that replica DN allow "" to get results?  Isn't that essentially an anonymous bind ? What should the ACL be ?

For reference, here is the result when I search from the new replica against the existing master using directory manager (I get a good result):

[root at dc2-ipa-dev-van ~]# ldapsearch -H ldaps://dc2-ipa-dev-nvan.mydomain.net -b "cn=replica,cn=dc\3Dmydomain\2Cdc\3Dnet,cn=mapping tree,cn=config" -D "cn=directory manager" -W
Enter LDAP Password:
# extended LDIF
#
# LDAPv3
# base <cn=replica,cn=dc\3Dmydomain\2Cdc\3Dnet,cn=mapping tree,cn=config> with scope subtree
# filter: (objectclass=*)
# requesting: ALL
#

# replica, dc\3Dmydomain\2Cdc\3Dnet, mapping tree, config
dn: cn=replica,cn=dc\3Dmydomain\2Cdc\3Dnet,cn=mapping tree,cn=config
cn: replica
nsDS5Flags: 1
nsDS5ReplicaBindDN: cn=replication manager,cn=config
nsDS5ReplicaBindDN: krbprincipalname=ldap/dc1-ipa-dev-nvan.mydomain.net
 @mydomain.NET,cn=services,cn=accounts,dc=mydomain,dc=net
nsDS5ReplicaBindDN: krbprincipalname=ldap/dc1-ipa-dev-van.mydomain.net@
 mydomain.NET,cn=services,cn=accounts,dc=mydomain,dc=net
nsDS5ReplicaId: 15
nsDS5ReplicaName: 74d8b993-bcb911e5-ba5283c7-2a40cd64
nsDS5ReplicaRoot: dc=mydomain,dc=net
nsDS5ReplicaType: 3
nsState:: DwAAAAAAAACJ2p9WAAAAAAAAAAAAAAAAbAEAAAAAAAAFAAAAAAAAAA==
nsds5ReplicaLegacyConsumer: off
nsds5replicabinddngroup: cn=replication managers,cn=sysaccounts,cn=etc,dc=mydomain,dc=net
nsds5replicabinddngroupcheckinterval: 60
objectClass: nsds5replica
objectClass: top
objectClass: extensibleobject
nsds5ReplicaChangeCount: 91169
nsds5replicareapactive: 0

# meTodc1-ipa-dev-nvan.mydomain.net, replica, dc\3Dmydomain\2Cdc\
 3Dnet, mapping tree, config
dn: cn=meTodc1-ipa-dev-nvan.mydomain.net,cn=replica,cn=dc\3Dmydomain\2Cdc\3Dnet,cn=mapping tree,cn=config
cn: meTodc1-ipa-dev-nvan.mydomain.net
description: me to dc1-ipa-dev-nvan.mydomain.net
nsDS5ReplicaBindMethod: SASL/GSSAPI
nsDS5ReplicaHost: dc1-ipa-dev-nvan.mydomain.net
nsDS5ReplicaPort: 389
nsDS5ReplicaRoot: dc=mydomain,dc=net
nsDS5ReplicaTransportInfo: LDAP
nsDS5ReplicatedAttributeList: (objectclass=*) $ EXCLUDE memberof idnssoaserial
  entryusn krblastsuccessfulauth krblastfailedauth krbloginfailedcount
nsDS5ReplicatedAttributeListTotal: (objectclass=*) $ EXCLUDE entryusn krblasts
 uccessfulauth krblastfailedauth krbloginfailedcount
nsds50ruv: {replicageneration} 553fe9bb000000040000
nsds50ruv: {replica 16 ldap://dc1-ipa-dev-nvan.mydomain.net:389} 569afd
 26000000100000 569b9201002200100000
nsds50ruv: {replica 17 ldap://dc1-ipa-dev-van.mydomain.net:389} 569b124
 b000000110000 569b91af000d00110000
nsds50ruv: {replica 15 ldap://dc2-ipa-dev-nvan.mydomain.net:389} 569aee
 040000000f0000 569b92010002000f0000
nsds50ruv: {replica 14 ldap://dc2-ipa-dev-van.mydomain.net:389} 569ae7b
 b0000000e0000 569b91320014000e0000
nsds5ReplicaEnabled: on
nsds5ReplicaStripAttrs: modifiersName modifyTimestamp internalModifiersName in
 ternalModifyTimestamp
nsds5replicaTimeout: 120
nsruvReplicaLastModified: {replica 16 ldap://dc1-ipa-dev-nvan.mydomain.
 net:389} 00000000
nsruvReplicaLastModified: {replica 17 ldap://dc1-ipa-dev-van.mydomain.n
 et:389} 00000000
nsruvReplicaLastModified: {replica 15 ldap://dc2-ipa-dev-nvan.mydomain.
 net:389} 00000000
nsruvReplicaLastModified: {replica 14 ldap://dc2-ipa-dev-van.mydomain.n
 et:389} 00000000
objectClass: nsds5replicationagreement
objectClass: top
objectClass: ipaReplTopoManagedAgreement
ipaReplTopoManagedAgreementState: managed agreement - controlled by topology p
 lugin
nsds5replicareapactive: 0
nsds5replicaLastUpdateStart: 20160120190605Z
nsds5replicaLastUpdateEnd: 20160120190605Z
nsds5replicaChangesSentSinceStartup:: MTU6NjY3LzIyNTk3NTEgMTQ6MS8wIDE3OjIyLzAg
 MTY6Mi8wIA==
nsds5replicaLastUpdateStatus: 0 Replica acquired successfully: Incremental upd
 ate succeeded
nsds5replicaUpdateInProgress: FALSE
nsds5replicaLastInitStart: 19700101000000Z
nsds5replicaLastInitEnd: 19700101000000Z

# meTodc1-ipa-dev-van.mydomain.net, replica, dc\3Dmydomain\2Cdc\3
 Dnet, mapping tree, config
dn: cn=meTodc1-ipa-dev-van.mydomain.net,cn=replica,cn=dc\3Dmydomain\2Cdc\3Dnet,cn=mapping tree,cn=config
cn: meTodc1-ipa-dev-van.mydomain.net
description: me to dc1-ipa-dev-van.mydomain.net
nsDS5ReplicaBindMethod: SASL/GSSAPI
nsDS5ReplicaHost: dc1-ipa-dev-van.mydomain.net
nsDS5ReplicaPort: 389
nsDS5ReplicaRoot: dc=mydomain,dc=net
nsDS5ReplicaTransportInfo: LDAP
nsDS5ReplicatedAttributeList: (objectclass=*) $ EXCLUDE memberof idnssoaserial
  entryusn krblastsuccessfulauth krblastfailedauth krbloginfailedcount
nsDS5ReplicatedAttributeListTotal: (objectclass=*) $ EXCLUDE entryusn krblasts
 uccessfulauth krblastfailedauth krbloginfailedcount
nsds5ReplicaStripAttrs: modifiersName modifyTimestamp internalModifiersName in
 ternalModifyTimestamp
nsds5replicaTimeout: 120
objectClass: nsds5replicationagreement
objectClass: top
objectClass: ipaReplTopoManagedAgreement
ipaReplTopoManagedAgreementState: managed agreement - controlled by topology p
 lugin
nsds50ruv: {replicageneration} 553fe9bb000000040000
nsds50ruv: {replica 17 ldap://dc1-ipa-dev-van.mydomain.net:389} 569b124
 b000000110000 569b9201000500110000
nsds50ruv: {replica 16 ldap://dc1-ipa-dev-nvan.mydomain.net:389} 569afd
 26000000100000 569b918d004a00100000
nsds50ruv: {replica 15 ldap://dc2-ipa-dev-nvan.mydomain.net:389} 569aee
 040000000f0000 569b92010002000f0000
nsds50ruv: {replica 14 ldap://dc2-ipa-dev-van.mydomain.net:389} 569ae7b
 b0000000e0000 569b91320014000e0000
nsruvReplicaLastModified: {replica 17 ldap://dc1-ipa-dev-van.mydomain.n
 et:389} 00000000
nsruvReplicaLastModified: {replica 16 ldap://dc1-ipa-dev-nvan.mydomain.
 net:389} 00000000
nsruvReplicaLastModified: {replica 15 ldap://dc2-ipa-dev-nvan.mydomain.
 net:389} 00000000
nsruvReplicaLastModified: {replica 14 ldap://dc2-ipa-dev-van.mydomain.n
 et:389} 00000000
nsds5replicareapactive: 0
nsds5replicaLastUpdateStart: 20160120190602Z
nsds5replicaLastUpdateEnd: 20160120190602Z
nsds5replicaChangesSentSinceStartup:: MTU6ODgzLzQwNDIwNTcgMTY6MjQzLzAgMTc6Mi8w
 IDA6MS8wIA==
nsds5replicaLastUpdateStatus: 0 Replica acquired successfully: Incremental upd
 ate succeeded
nsds5replicaUpdateInProgress: FALSE
nsds5replicaLastInitStart: 19700101000000Z
nsds5replicaLastInitEnd: 19700101000000Z

# search result
search: 2
result: 0 Success

# numResponses: 4
# numEntries: 3


-----Original Message-----
From: Petr Vobornik [mailto:pvoborni at redhat.com] 
Sent: January-20-16 2:02 AM
To: Rob Crittenden; Nathan Peters; Ludwig Krispenz
Cc: freeipa-users at redhat.com
Subject: Re: [Freeipa-users] Freeipa 4.3.0 replica installation fails with DuplicateEntry: This entry already exists

On 01/20/2016 12:31 AM, Rob Crittenden wrote:
> Nathan Peters wrote:
>> [18/Jan/2016:09:28:33 -0800] conn=18732 op=10 ADD dn="cn=replica,cn=dc\3Ddev-globalrelay\2Cdc\3Dnet,cn=mapping tree,cn=config"
>>   [18/Jan/2016:09:28:33 -0800] conn=18732 op=10 RESULT err=68 tag=105 nentries=0 etime=0
>>   [18/Jan/2016:09:28:33 -0800] conn=18732 op=11 UNBIND
>>
>> Do you mean that log entry ^?  I am seeing that entry on dc2-ipa-dev-nvan, the host that dc1-ipa-dev-van is contacting as its master when we attempt the ipa-replica-install.  Look through my earlier posts in this thread for a full log.
>
> Don't assume we have any idea what your hostnames mean, especially 
> when they differ only by a few characters. It is good to list them but 
> I'd also suggest you use terms like existing master and new server or 
> something so we can distinguish the players without having to slowly 
> parse every name.
>
>> Yes, of course that DN exists on all my masters.  With a 3 way replication it would have to exist because the current master is replicating to 2 other masters.  Here is the ldapsearch for all 3 existing hosts showing that DN (dn="cn=replica,cn=dc\3Ddev-globalrelay\2Cdc\3Dnet,cn=mapping tree,cn=config") which is apparently failing to be added because it already exists on all my hosts.
>
> The important thing here is that cn=config is not replicated. It is 
> configured on each master during replica setup, exactly where it is 
> failing for you. Given that it is failing on ANOTHER server says a lot.
>
> It is failing, I think in part, because this search on the remote 
> master is returning no entries:
>
> [18/Jan/2016:09:28:33 -0800] conn=18732 op=9 SRCH 
> base="cn=replica,cn=dc\3Dmydomain\2Cdc\3Dnet,cn=mapping tree,cn=config"
> scope=0 filter="(objectClass=*)" attrs=ALL
> [18/Jan/2016:09:28:33 -0800] conn=18732 op=9 RESULT err=0 tag=101
> nentries=0 etime=0

IMO this is the culprit. It should return the entry if it is in fact there.

>
> Right after this is the ADD which fails with err=68 which means that 
> in fact, it does exist.
>
> I'm not sure why this is happening. I don't immediately see why a 
> NotFound would be raised in this case but I'm guessing it is. It would 
> be interesting to walk through the code using the python debugger, pdb.
>
> In any case the duplicate entry is due to the replica setup code 
> trying to configure the remote master for basic replication and this 
> has already been done.

Yes the replica code works as expected.

Next step is to investigate why the search returns nothing. ACI issue? 
Weird DB state?

Can other user fetch it? E.g. admin?

If so wow does "cn=replica,cn=dc\3Dmydomain\2Cdc\3Dnet,cn=mapping
tree,cn=config" on the master server looks like?
--
Petr Vobornik

More information about the Freeipa-users mailing list