Hi,

On Thu, Feb 15, 2024 at 3:50 PM Markus Rexhepi-Lindberg via FreeIPA-users <freeipa-users@lists.fedorahosted.org> wrote:
The replication step fails while installing a new ipa replica server.

Some facts:

* Both servers running version 4.9.12.
* Both servers running RHEL 8.9
* Master located in Sweden and replica located in USA.
* Actual domain has been substituted with "example.com".

Some logs:

= replica=

replica# ipa-replica-install --verbose --setup-dns --forwarder 10.0.2.200 --forwarder 10.0.2.201 --forwarder 10.0.2.202 --setup-ca
...
Created connection context.ldap2_140175491229624
Fetching nsDS5ReplicaId from master [attempt 1/5]
retrieving schema for SchemaCache url=ldap://se-rhidm02x.se.example.com:389 conn=<ldap.ldapobject.SimpleLDAPObject object at 0x7f7d2304e278>
Successfully updated nsDS5ReplicaId.
Add or update replica config cn=replica,cn=dc\=lnx\,dc\=example\,dc\=com,cn=mapping tree,cn=config
Added replica config cn=replica,cn=dc\=lnx\,dc\=example\,dc\=com,cn=mapping tree,cn=config
update_entry modlist [(0, 'nsDS5ReplicaBindDN', [b'cn=ldap/se-rhidm02x.se.example.com@LNX.EXAMPLE.COM,cn=config'])]
Add or update replica config cn=replica,cn=dc\=lnx\,dc\=example\,dc\=com,cn=mapping tree,cn=config
No update to cn=replica,cn=dc\=lnx\,dc\=example\,dc\=com,cn=mapping tree,cn=config necessary
The replica creates an entry on the master cn=replica,cn=dc\=lnx\,dc\=example\,dc\=com,cn=mapping tree,cn=config that should contain nsDS5ReplicaId, nsDS5ReplicaBindDN: cn=replication manager,cn=config and nsDS5ReplicaBindDNGroup: cn=replication managers,cn=sysaccounts,cn=etc,dc=ipa,dc=test

Since there is a message "No update to ... necessary, it looks like the master already knows about this replica, maybe it is not the first time you try to add it?
 
Waiting up to 300 seconds for replication (ldap://se-rhidm02x.se.example.com:389) cn=meTousidc1-rhidm01x.idc1.us.example.com,cn=replica,cn=dc\=lnx\,dc\=example\,dc\=com,cn=mapping tree,cn=config (objectclass=*)
Entry found [LDAPEntry(ipapython.dn.DN('cn=meTousidc1-rhidm01x.idc1.us.example.com,cn=replica,cn=dc\=lnx\,dc\=example\,dc\=com,cn=mapping tree,cn=config'), {'objectClass': [b'nsds5replicationagreement', b'top']
, 'cn': [b'meTousidc1-rhidm01x.idc1.us.example.com'], 'nsDS5ReplicaHost': [b'usidc1-rhidm01x.idc1.us.example.com'], 'nsDS5ReplicaPort': [b'389'], 'nsds5replicaTimeout': [b'120'], 'nsDS5ReplicaRoot': [b'dc=lnx,d
c=example,dc=com'], 'description': [b'me to usidc1-rhidm01x.idc1.us.example.com'], 'nsDS5ReplicatedAttributeList': [b'(objectclass=*) $ EXCLUDE memberof idnssoaserial entryusn krblastsuccessfulauth krblastfaile
dauth krbloginfailedcount passwordgraceusertime'], 'nsDS5ReplicaTransportInfo': [b'LDAP'], 'nsDS5ReplicaBindMethod': [b'SASL/GSSAPI'], 'nsds5ReplicaStripAttrs': [b'modifiersName modifyTimestamp internalMo
difiersName internalModifyTimestamp'], 'nsDS5ReplicatedAttributeListTotal': [b'(objectclass=*) $ EXCLUDE entryusn krblastsuccessfulauth krblastfailedauth krbloginfailedcount passwordgraceusertime'], 'nsds
5replicareapactive': [b'0'], 'nsds5replicaLastUpdateStart': [b'19700101000000Z'], 'nsds5replicaLastUpdateEnd': [b'19700101000000Z'], 'nsds5replicaChangesSentSinceStartup': [b''], 'nsds5replicaLastUpdateSt
atus': [b'Error (-2) Problem connecting to replica - LDAP error: Local error (connection error)'], 'nsds5replicaLastUpdateStatusJSON': [b'{"state": "red", "ldap_rc": "-2", "ldap_rc_text": "Local error", "
repl_rc": "16", "repl_rc_text": "connection error", "date": "2024-02-15T14:35:36Z", "message": "Error (-2) Problem connecting to replica - LDAP error: Local error (connection error)"}'], 'nsds5replicaUpda
teInProgress': [b'FALSE'], 'nsds5replicaLastInitStart': [b'19700101000000Z'], 'nsds5replicaLastInitEnd': [b'19700101000000Z']})]

The replica starts replication by setting nsds5BeginReplicaRefresh=start on the master (entry cn=meToreplica,...) and reads the entry to check the replication status.
This message "Error (-2) Problem connecting to replica - LDAP error: Local error (connection error)" indicates an issue when the master tries to communicate with the replica. You may find corresponding logs in the master's 389ds error log and maybe a failed connection in the replica's 389ds access log.

Waiting up to 300 seconds for replication (ldapi://%2Frun%2Fslapd-LNX-EXAMPLE-COM.socket) cn=meTose-rhidm02x.se.example.com,cn=replica,cn=dc\=lnx\,dc\=example\,dc\=com,cn=mapping tree,cn=config (objectclass=*)
Entry found [LDAPEntry(ipapython.dn.DN('cn=meTose-rhidm02x.se.example.com,cn=replica,cn=dc\=lnx\,dc\=example\,dc\=com,cn=mapping tree,cn=config'), {'objectClass': [b'nsds5replicationagreement', b'top'], 'cn': [
b'meTose-rhidm02x.se.example.com'], 'nsDS5ReplicaHost': [b'se-rhidm02x.se.example.com'], 'nsDS5ReplicaPort': [b'389'], 'nsds5replicaTimeout': [b'120'], 'nsDS5ReplicaRoot': [b'dc=lnx,dc=example,dc=com'], 'descripti
on': [b'me to se-rhidm02x.se.example.com'], 'nsDS5ReplicatedAttributeList': [b'(objectclass=*) $ EXCLUDE memberof idnssoaserial entryusn krblastsuccessfulauth krblastfailedauth krbloginfailedcount passwordgr
aceusertime'], 'nsDS5ReplicaTransportInfo': [b'LDAP'], 'nsDS5ReplicaBindMethod': [b'SASL/GSSAPI'], 'nsds5ReplicaStripAttrs': [b'modifiersName modifyTimestamp internalModifiersName internalModifyTimestamp'
], 'nsDS5ReplicatedAttributeListTotal': [b'(objectclass=*) $ EXCLUDE entryusn krblastsuccessfulauth krblastfailedauth krbloginfailedcount passwordgraceusertime'], 'nsds5replicareapactive': [b'0'], 'nsds5r
eplicaLastUpdateStart': [b'19700101000000Z'], 'nsds5replicaLastUpdateEnd': [b'19700101000000Z'], 'nsds5replicaChangesSentSinceStartup': [b''], 'nsds5replicaLastUpdateStatus': [b'Error (0) No replication s
essions started since server startup'], 'nsds5replicaLastUpdateStatusJSON': [b'{"state": "green", "ldap_rc": "0", "ldap_rc_text": "success", "repl_rc": "0", "repl_rc_text": "replica acquired", "date": "20
24-02-15T14:35:28Z", "message": "Error (0) No replication sessions started since server startup"}'], 'nsds5replicaUpdateInProgress': [b'FALSE'], 'nsds5replicaLastInitStart': [b'19700101000000Z'], 'nsds5re
plicaLastInitEnd': [b'19700101000000Z']})]
Starting replication, please wait until this has completed.
Update in progress, 15 seconds elapsed
[ldap://se-rhidm02x.se.example.com:389] reports: Update failed! Status: [Error (-2) - LDAP error: Local error - no response received]

replica# cat /var/log/dirsrv/slapd-LNX-EXAMPLE-COM/errors
...
[15/Feb/2024:09:35:58.128874085 -0500] - WARN - NSMMReplicationPlugin - repl5_inc_run - agmt="cn=meTose-rhidm02x.se.example.com" (se-rhidm02x:389): The remote replica has a different database generation ID than the local database.  You may have to reinitialize the remote replica, or the local replica.
...

replica# cat /var/log/dirsrv/slapd-LNX-EXAMPLE-COM/access
...
[15/Feb/2024:09:35:28.821998361 -0500] conn=6 fd=119 slot=119 connection from 10.0.13.145 to 192.168.224.21
[15/Feb/2024:09:35:28.827100928 -0500] conn=6 op=0 UNBIND
[15/Feb/2024:09:35:28.827120206 -0500] conn=6 op=0 fd=119 closed error - U1
...

= master =

master# cat /var/log/dirsrv/slapd-LNX-EXAMPLE-COM/access
...
[15/Feb/2024:15:35:44.803292478 +0100] conn=37567 op=31 SRCH base="cn=meTousidc1-rhidm01x.idc1.us.example.com,cn=replica,cn=dc\3Dlnx\2Cdc\3Dexample\2Cdc\3Dcom,cn=mapping tree,cn=config" scope=0 filter="(objectC
lass=*)" attrs="nsds5BeginReplicaRefresh nsds5replicaLastInitStart cn nsds5replicaLastInitStatusJSON nsds5replicaLastInitEnd nsds5replicaUpdateInProgress nsds5replicaLastInitStatus"
[15/Feb/2024:15:35:44.803737834 +0100] conn=37567 op=31 RESULT err=0 tag=101 nentries=1 wtime=0.000219465 optime=0.000451462 etime=0.000669200
[15/Feb/2024:15:35:45.170456864 +0100] conn=37383 op=16 UNBIND
[15/Feb/2024:15:35:45.170486056 +0100] conn=37383 op=16 fd=273 closed error - U1
...

master# cat /var/log/dirsrv/slapd-LNX-EXAMPLE-COM/errors
...
[15/Feb/2024:15:35:37.160764934 +0100] - WARN - NSMMReplicationPlugin - repl5_tot_run - Unable to acquire replica for total update, error: -2, retrying in 1 seconds.
[15/Feb/2024:15:35:38.274695202 +0100] - WARN - NSMMReplicationPlugin - repl5_tot_run - Unable to acquire replica for total update, error: -2, retrying in 2 seconds.
[15/Feb/2024:15:35:40.388281036 +0100] - WARN - NSMMReplicationPlugin - repl5_tot_run - Unable to acquire replica for total update, error: -2, retrying in 3 seconds.
[15/Feb/2024:15:35:43.503252882 +0100] - WARN - NSMMReplicationPlugin - repl5_tot_run - Unable to acquire replica for total update, error: -2, retrying in 4 seconds.
[15/Feb/2024:15:35:47.618537566 +0100] - WARN - NSMMReplicationPlugin - repl5_tot_run - Unable to acquire replica for total update, error: -2, retrying in 5 seconds.
...
Is there any log right before that one which would indicate a bind issue from master to replica?

You can re-try a clean install:
- on the replica, ipa-server-install --uninstall -U; kdestroy -A
- on the master, ipa server-del <replica fqdn>
- on the replica, ipa-replica-install <your options>

flo
--
_______________________________________________
FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org
To unsubscribe send an email to freeipa-users-leave@lists.fedorahosted.org
Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives: https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahosted.org
Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue