[Freeipa-users] Encoding Error in Initial Replication

2017-11-09 Thread Nevada Sanchez via FreeIPA-users 
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 +] NSMMReplicationPlugin - conn=1275 op=7
repl="dc=example,dc=com": Acquired replica
[09/Nov/2017:12:34:08 +] NSMMReplicationPlugin - conn=1275 op=7
repl="dc=example,dc=com": StartNSDS90ReplicationRequest: response=0 rc=0
[09/Nov/2017:12:34:08 +] NSMMReplicationPlugin - conn=1275 op=7
Relinquishing consumer connection extension
[09/Nov/2017:12:34:08 +] NSMMReplicationPlugin - conn=1275 op=8
Acquired consumer connection extension
[09/Nov/2017:12:34:08 +] 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 +] NSMMReplicationPlugin - conn=1275 op=8
Relinquishing consumer connection extension
[09/Nov/2017:12:34:09 +] NSMMReplicationPlugin - agmt="cn=
meToipa-replica.example.com" (ipa-replica:389): Replica was successfully
acquired.
[09/Nov/2017:12:34:09 +] NSMMReplicationPlugin - Beginning total update
of replica "agmt="cn=meToipa-replica.example.com" (ipa-replica:389)".
*[09/Nov/2017:12:34:09 +] NSMMReplicationPlugin -
agmt="cn=meToipa-replica.example.com "
(ipa-replica:389): send_entry: Encoding Error*
[09/Nov/2017:12:34:09 +] - repl5_tot_waitfor_async_results: 400 403
[09/Nov/2017:12:34:10 +] - repl5_tot_waitfor_async_results: 403 403
[09/Nov/2017:12:34:11 +] NSMMReplicationPlugin - agmt="cn=
meToipa-replica.example.com" (ipa-replica:389): Successfully released
consumer
[09/Nov/2017:12:34:11 +] NSMMReplicationPlugin - agmt="cn=
meToipa-replica.example.com" (ipa-replica:389): Beginning linger on the
connection
*[09/Nov/2017:12:34:11 +] NSMMReplicationPlugin -
agmt="cn=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 +] NSMMReplicationPlugin - agmt="cn=
meToipa-replica.example.com" (ipa-replica:389): Cancelling linger on the
connection
[09/Nov/2017:12:34:12 +] NSMMReplicationPlugin - agmt="cn=
meToipa-replica.example.com" (ipa-replica:389): Disconnected from the
consumer
[09/Nov/2017:12:34:12 +] NSMMReplicationPlugin - agmt="cn=
meToipa-replica.example.com" (ipa-replica:389): State: start ->
ready_to_acquire_replica
[09/Nov/2017:12:34:12 +] NSMMReplicationPlugin - agmt="cn=
meToipa-replica.example.com" (ipa-replica:389): Trying non-secure
slapi_ldap_init_ext
[09/Nov/2017:12:34:12 +] NSMMReplicationPlugin - agmt="cn=
meToipa-replica.example.com" (ipa-replica:389): binddn = ,  passwd =
[09/Nov/2017:12:34:12 +] 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

[Freeipa-users] Re: Encoding Error in Initial Replication

2017-11-09 Thread Nevada Sanchez via FreeIPA-users 
Thanks. I'm actually trying to upgrade to 4.5, and I'm following
instructions for migrating to new platform/OS, which involves preparing and
then installing a replica on the new platform (which is IPA 4.5/fedora 26).

Anyway, I did manage to trace the encoding error to entries in LDAP that
don't have a unique ID. Here's a gdb trace:

Breakpoint 1, entry2bere (e=e@entry=0x7ff37517d8b0,
excluded_attrs=excluded_attrs@entry=0x7ff37403b9a0)
at ldap/servers/plugins/replication/repl5_total.c:244
(gdb) p *e
$2 = {e_sdn =
  {flag = 6 '\006', udn = 0x0,
   dn = 0x7ff37517d9b0
"nsuniqueid=17105281-b68811e3-a4c3e04e-631dd285,fqdn=eda-cr18x.example.com
+nsuniqueid=17105281-b68811e3-a4c3e04e-631dd285,cn=computers,cn=accounts,dc=example,dc=com",
   ndn = 0x7ff37517d600
"nsuniqueid=17105281-b68811e3-a4c3e04e-631dd285,fqdn=eda-cr18x.example.com
+nsuniqueid=17105281-b68811e3-a4c3e04e-631dd285,cn=computers,cn=accounts,dc=example,dc=com",
   ndn_len = 179}, e_srdn = {
   flag = 0 '\000',
   rrdn = 0x7ff3751939c0
"nsuniqueid=17105281-b68811e3-a4c3e04e-631dd285,fqdn=eda-cr18x.example.com
+nsuniqueid=17105281-b68811e3-a4c3e04e-631dd285",
   rdns = 0x0, butcheredupto = -1, nrdn = 0x0, all_rdns =
0x7ff3751633e0, all_nrdns = 0x0},
  e_uniqueid = 0x0, e_dncsnset = 0x7ff3751926b0,
  e_maxcsn = 0x7ff37517db30, e_attrs = 0x7ff375172340, e_deleted_attrs
= 0x7ff3751934a0,
  e_virtual_attrs = 0x0, e_virtual_watermark = 0, e_virtual_lock =
0x7ff37517d970,
  e_extension = 0x7ff37514c920, e_flags = 1 '\001', e_aux_attrs = 0x0}

Note that `e_uniqueid` is NULL. Also, I have deleted the `eda-cr18x` host
long ago, and can't find it through any ldapsearch. I just don't know where
it's coming from.

On Thu, Nov 9, 2017 at 12:41 Felipe Barreto <fbarr...@redhat.com> wrote:

> Hello,
>
> freeIPA 3.x is no longer supported, you need to update it.
> The same to Fedora.
>
> On 11/09/2017 01:38 PM, Nevada Sanchez via FreeIPA-users wrote:
> > 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 +] NSMMReplicationPlugin - conn=1275 op=7
> > repl="dc=example,dc=com": Acquired replica
> > [09/Nov/2017:12:34:08 +] NSMMReplicationPlugin - conn=1275 op=7
> > repl="dc=example,dc=com": StartNSDS90ReplicationRequest: response=0 rc=0
> > [09/Nov/2017:12:34:08 +] NSMMReplicationPlugin - conn=1275 op=7
> > Relinquishing consumer connection extension
> > [09/Nov/2017:12:34:08 +] NSMMReplicationPlugin - conn=1275 op=8
> > Acquired consumer connection extension
> > [09/Nov/2017:12:34:08 +] 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 +] NSMMReplicationPlugin - conn=1275 op=8
> > Relinquishing consumer connection extension
> > [09/Nov/2017:12:34:09 +] NSMMReplicationPlugin -
> > agmt="cn=meToipa-replica.example.com
> > <http://meToipa-replica.example.com>" (ipa-replica:389): Replica was
> > successfully acquired.
> > [09/Nov/2017:12:34:09 +] NSMMReplicationPlugin - Beginning total
> > update of replica "agmt="cn=meToipa-replica.example.com
> > <http://meToipa-replica.example.com>" (ipa-replica:389)".
> > *[09/Nov/2017:12:34:09 +] 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 +] - repl5_tot_waitfor_async_results: 400 403
> > [09/Nov/2017:12:34:10 +] - repl5_tot_waitfor_async_results: 403 403
> > [09/Nov/2017:12:34:11 +] NSMMReplicationPlugin -
> > agmt="cn=meToipa-replica.example.com
> > <http://meToipa-replica.example.com>" (ipa-replica:389): Successfully
> > released consumer
> > [09/Nov/2017:12:34:11 +] NSMMReplicationPlugin -
> > agmt="cn=meToipa-replica.example.com
> > <http://meToipa-replica.example.com>" (ipa-replica:389): Beginning
> > linger on the connection
> > *[09/Nov/2017:12:34:11 +] 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 +] NSMMReplicationPlugin -
> > agmt="cn=meToipa-replica.example.com
> > <http://meToipa-replica.example.com>" (ip