From f52d626c166ad0f94f9d3752a4d8978dd3d9ccfc Mon Sep 17 00:00:00 2001
From: Christian Heimes <cheimes@redhat.com>
Date: Fri, 22 Jun 2018 09:39:26 +0200
Subject: [PATCH] Improve and fix timeout bug in wait_for_entry()

replication.wait_for_entry() now can wait for an attribute value to
appear on a replica.

Fixed timeout handling caused by bad rounding and comparison. For small
timeouts, the actual time was rounded down. For example for 60 seconds
timeout and fast replica, the query accumulated to about 0.45 seconds
plus 60 seconds sleep. 60.45 is large enough to terminate the loop
"while int(time.time()) < timeout", but not large enough to trigger the
exception in "if int(time.time()) > timeout", because int(60.65) == 60.

See: https://pagure.io/freeipa/issue/7593
Fixes: https://pagure.io/freeipa/issue/7595
Signed-off-by: Christian Heimes <cheimes@redhat.com>
Reviewed-By: Fraser Tweedale <ftweedal@redhat.com>
---
 ipaserver/install/replication.py | 57 +++++++++++++++++---------------
 1 file changed, 31 insertions(+), 26 deletions(-)

diff --git a/ipaserver/install/replication.py b/ipaserver/install/replication.py
index d4b41caa45409fa1537ae10f182599307f3e0439..5a491f248236c8d2166484d0db2acccb28ccf178 100644
--- a/ipaserver/install/replication.py
+++ b/ipaserver/install/replication.py
@@ -17,7 +17,9 @@
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 #
 
-from __future__ import print_function
+from __future__ import print_function, absolute_import
+
+import itertools
 
 import six
 import time
@@ -170,40 +172,43 @@ def wait_for_task(conn, dn):
     return exit_code
 
 
-def wait_for_entry(connection, dn, timeout=7200, attr='', quiet=True):
-    """Wait for entry and/or attr to show up"""
-
-    filter = "(objectclass=*)"
+def wait_for_entry(connection, dn, timeout=7200, attr=None, attrvalue='*',
+                   quiet=True):
+    """Wait for entry and/or attr to show up
+    """
+    log = root_logger.debug if quiet else root_logger.info
     attrlist = []
-    if attr:
-        filter = "(%s=*)" % attr
+    if attr is not None:
+        filterstr = ipaldap.LDAPClient.make_filter_from_attr(attr, attrvalue)
         attrlist.append(attr)
-    timeout += int(time.time())
-
-    if not quiet:
-        sys.stdout.write("Waiting for %s %s:%s " % (connection, dn, attr))
-        sys.stdout.flush()
-    entry = None
-    while not entry and int(time.time()) < timeout:
+    else:
+        filterstr = "(objectclass=*)"
+    log("Waiting for replication (%s) %s %s", connection, dn, filterstr)
+    entry = []
+    deadline = time.time() + timeout
+    for i in itertools.count(start=1):
         try:
-            [entry] = connection.get_entries(
-                dn, ldap.SCOPE_BASE, filter, attrlist)
+            entry = connection.get_entries(
+                dn, ldap.SCOPE_BASE, filterstr, attrlist)
         except errors.NotFound:
             pass  # no entry yet
         except Exception as e:  # badness
             root_logger.error("Error reading entry %s: %s", dn, e)
             raise
-        if not entry:
-            if not quiet:
-                sys.stdout.write(".")
-                sys.stdout.flush()
-            time.sleep(1)
 
-    if not entry and int(time.time()) > timeout:
-        raise errors.NotFound(
-            reason="wait_for_entry timeout for %s for %s" % (connection, dn))
-    elif entry and not quiet:
-        root_logger.error("The waited for entry is: %s", entry)
+        if entry:
+            log("Entry found %r", entry)
+            return
+        elif time.time() > deadline:
+            raise errors.NotFound(
+                reason="wait_for_entry timeout on {} for {}".format(
+                    connection, dn
+                )
+            )
+        else:
+            if i % 10 == 0:
+                root_logger.debug("Still waiting for replication of %s", dn)
+            time.sleep(1)
 
 
 class ReplicationManager(object):
-- 
2.17.1