I've been trying to set up a replica for a FreeIPA server (3.3.5 on Fedora 19) and am running into what appears to be an encoding issue on the server as it tries to deliver data to the replica. It is line 9 below:
[09/Nov/2017:12:34:08 +0000] NSMMReplicationPlugin - conn=1275 op=7 repl="dc=example,dc=com": Acquired replica [09/Nov/2017:12:34:08 +0000] NSMMReplicationPlugin - conn=1275 op=7 repl="dc=example,dc=com": StartNSDS90ReplicationRequest: response=0 rc=0 [09/Nov/2017:12:34:08 +0000] NSMMReplicationPlugin - conn=1275 op=7 Relinquishing consumer connection extension [09/Nov/2017:12:34:08 +0000] NSMMReplicationPlugin - conn=1275 op=8 Acquired consumer connection extension [09/Nov/2017:12:34:08 +0000] NSMMReplicationPlugin - conn=1275 op=8 repl="dc=example,dc=com": Released replica held by locking_purl=conn=1275 id=7 [09/Nov/2017:12:34:08 +0000] NSMMReplicationPlugin - conn=1275 op=8 Relinquishing consumer connection extension [09/Nov/2017:12:34:09 +0000] NSMMReplicationPlugin - agmt="cn= meToipa-replica.example.com" (ipa-replica:389): Replica was successfully acquired. [09/Nov/2017:12:34:09 +0000] NSMMReplicationPlugin - Beginning total update of replica "agmt="cn=meToipa-replica.example.com" (ipa-replica:389)". *[09/Nov/2017:12:34:09 +0000] NSMMReplicationPlugin - agmt="cn=meToipa-replica.example.com http://meToipa-replica.example.com" (ipa-replica:389): send_entry: Encoding Error* [09/Nov/2017:12:34:09 +0000] - repl5_tot_waitfor_async_results: 400 403 [09/Nov/2017:12:34:10 +0000] - repl5_tot_waitfor_async_results: 403 403 [09/Nov/2017:12:34:11 +0000] NSMMReplicationPlugin - agmt="cn= meToipa-replica.example.com" (ipa-replica:389): Successfully released consumer [09/Nov/2017:12:34:11 +0000] NSMMReplicationPlugin - agmt="cn= meToipa-replica.example.com" (ipa-replica:389): Beginning linger on the connection *[09/Nov/2017:12:34:11 +0000] NSMMReplicationPlugin - agmt="cn=meToipa-replica.example.com http://meToipa-replica.example.com" (ipa-replica:389): repl5_tot_run: failed to obtain data to send to the consumer; LDAP error - -1* [09/Nov/2017:12:34:12 +0000] NSMMReplicationPlugin - agmt="cn= meToipa-replica.example.com" (ipa-replica:389): Cancelling linger on the connection [09/Nov/2017:12:34:12 +0000] NSMMReplicationPlugin - agmt="cn= meToipa-replica.example.com" (ipa-replica:389): Disconnected from the consumer [09/Nov/2017:12:34:12 +0000] NSMMReplicationPlugin - agmt="cn= meToipa-replica.example.com" (ipa-replica:389): State: start -> ready_to_acquire_replica [09/Nov/2017:12:34:12 +0000] NSMMReplicationPlugin - agmt="cn= meToipa-replica.example.com" (ipa-replica:389): Trying non-secure slapi_ldap_init_ext [09/Nov/2017:12:34:12 +0000] NSMMReplicationPlugin - agmt="cn= meToipa-replica.example.com" (ipa-replica:389): binddn = , passwd = [09/Nov/2017:12:34:12 +0000] NSMMReplicationPlugin - agmt="cn= meToipa-replica.example.com" (ipa-replica:389): No linger to cancel on the connection
I've traced this to the `repl5_tot_run` in the 389 source code and the logs indicate that it makes it through acquiring the replica, but fails on the `slapi_search_internal_callback_pb` call which seems like it's supposed to transmit data to the replica. Continuing through the source, it seems like the Encoding error is the key since the `slapi_search` calls `send_entry` to encode the LDAP transaction and the `entry2bere` function must be unhappy with something it's receiving.
Any ideas on what could be causing this? Is there a rogue data entry in my directory that's hitting a corner case of the encoder?
I've attached replica logs below for further context, though I'm currently thinking the problem is master side. The "LDAP error: Can't contact LDAP server" you see below is actually what the ipa master put into 'nsds5ReplicaLastInitStatus' attribute of the replica agreement and I've confirmed ldapsearch (389 and 636) are both happy going either way.
Connection check OK Adding [10.0.3.78 ipa-replica.example.com] to your /etc/hosts file Configuring NTP daemon (ntpd) [1/4]: stopping ntpd [2/4]: writing configuration [3/4]: configuring ntpd to start on boot [4/4]: starting ntpd Done configuring NTP daemon (ntpd). Configuring directory server (dirsrv). Estimated time: 1 minute [1/42]: creating directory server user [2/42]: creating directory server instance [3/42]: updating configuration in dse.ldif [4/42]: restarting directory server [5/42]: adding default schema [6/42]: enabling memberof plugin [7/42]: enabling winsync plugin [8/42]: configuring replication version plugin [9/42]: enabling IPA enrollment plugin [10/42]: enabling ldapi [11/42]: configuring uniqueness plugin [12/42]: configuring uuid plugin [13/42]: configuring modrdn plugin [14/42]: configuring DNS plugin [15/42]: enabling entryUSN plugin [16/42]: configuring lockout plugin [17/42]: configuring topology plugin [18/42]: creating indices [19/42]: enabling referential integrity plugin [20/42]: configuring ssl for ds instance [21/42]: configuring certmap.conf [22/42]: configure autobind for root [23/42]: configure new location for managed entries [24/42]: configure dirsrv ccache [25/42]: enabling SASL mapping fallback [26/42]: restarting directory server [27/42]: setting up initial replication Starting replication, please wait until this has completed. Update in progress, 5 seconds elapsed [ipa.example.com] reports: Update failed! Status: [-1 Total update abortedLDAP error: Can't contact LDAP server]
[error] RuntimeError: Failed to start replication Your system may be partly configured. Run /usr/sbin/ipa-server-install --uninstall to clean up.
ipa.ipapython.install.cli.install_tool(Replica): ERROR Failed to start replication ipa.ipapython.install.cli.install_tool(Replica): ERROR The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information