Make t_iprop.py faster and more robust

Catch SIGUSR1 in iprop-mode kpropd so that we can use it to interrupt
sleeps and make kpropd do an iprop request immediately.

In k5test.py, add prod_kpropd and read_from_kpropd methods to allow
test scripts to send a SIGUSR1 to kpropd and to read its stdout/stderr
output; also allow the test script to specify additional arguments
when starting kpropd.

In t_iprop.py, start kpropd with -d and, instead of sleeping, read
kpropd output until we see an indication that kpropd is in sync with
the master.  To avoid delays, prod kpropd before waiting for sync and
after a completed full prop.

3 files changed, 80 insertions, 32 deletions

diff --git a/src/slave/kpropd.c b/src/slave/kpropd.c
index afa02f438..627230232 100644
--- a/src/slave/kpropd.c
+++ b/src/slave/kpropd.c
@@ -198,6 +198,12 @@ alarm_handler(int sig)
 }
 
 static void
+usr1_handler(int sig)
+{
+    /* Nothing to do, just let the signal interrupt sleep(). */
+}
+
+static void
 kill_do_standalone(int sig)
 {
     if (fullprop_child > 0) {
@@ -288,15 +294,17 @@ main(argc, argv)
     }
 
     /*
-     * This is the iprop case.  We'll fork a child to run do_standalone().
-     * The parent will run do_iprop().  We try to kill the child if we
-     * get killed.
+     * This is the iprop case.  We'll fork a child to run do_standalone().  The
+     * parent will run do_iprop().  We try to kill the child if we get killed.
+     * Catch SIGUSR1 so tests can use it to interrupt the sleep timer and force
+     * an iprop request.
      */
     signal_wrapper(SIGHUP, kill_do_standalone);
     signal_wrapper(SIGINT, kill_do_standalone);
     signal_wrapper(SIGQUIT, kill_do_standalone);
     signal_wrapper(SIGTERM, kill_do_standalone);
     signal_wrapper(SIGSEGV, kill_do_standalone);
+    signal_wrapper(SIGUSR1, usr1_handler);
     atexit(atexit_kill_do_standalone);
     fullprop_child = fork();
     switch (fullprop_child) {
diff --git a/src/tests/t_iprop.py b/src/tests/t_iprop.py
index 33bf91879..bcd669b9e 100644
--- a/src/tests/t_iprop.py
+++ b/src/tests/t_iprop.py
@@ -5,6 +5,41 @@ import time
 
 from k5test import *
 
+def wait_for_prop(realm):
+    # Make kpropd go if it's sleeping.
+    realm.prod_kpropd()
+
+    # Read lines from kpropd output until we are synchronized.
+    output('*** Waiting for sync from kpropd\n')
+    while True:
+        line = realm.read_from_kpropd()
+        if line == '':
+            fail('kpropd process exited unexpectedly')
+        output('kpropd: ' + line)
+
+        if 'KDC is synchronized' in line or 'Got incremental updates' in line:
+            output('*** Sync complete\n')
+            return
+
+        if 'load process for full propagation completed' in line:
+            # kpropd's child process has finished a DB load; make the parent
+            # do another iprop request.  This will be unnecessary if kpropd
+            # is simplified to use a single process.
+            realm.prod_kpropd()
+
+        # Detect some failure conditions.
+        if 'Rejected connection' in line:
+            fail('kpropd rejected kprop connection')
+        if 'get updates failed' in line:
+            fail('iprop_get_updates failed')
+        if 'permission denied' in line:
+            fail('kadmind denied update')
+        if 'error from master' in line or 'error returned from master' in line:
+            fail('kadmind reported error')
+        if 'invalid return' in line:
+            fail('kadmind returned invalid result')
+
+
 iprop_kdc_conf = {
     'all' : { 'libdefaults' : { 'default_realm' : 'KRBTEST.COM'},
               'realms' : { '$realm' : {
@@ -58,25 +93,14 @@ acl = open(acl_file, 'w')
 acl.write(realm.host_princ + '\n')
 acl.close()
 
-realm.start_kpropd()
+realm.start_kpropd(['-d'])
 realm.run_kadminl('modprinc -allow_tix w')
 out = realm.run_as_master([kproplog, '-h'])
 if 'Last serial # : 8' not in out:
     fail('Update log on master has incorrect last serial number')
 
-# We need to give iprop (really, a full resync here and maybe an
-# incremental) a chance to happen.
-#
-# Sometimes we need to wait a long time because kpropd's do_iprop()
-# can race with kadmind and fail to kadm5 init, which leads -apparently-
-# to some backoff effect.
-output('Sleeping for 3 seconds\n')
-time.sleep(3)
-
-# Now check that iprop happened.  Note that we depend on timing here,
-# thus the above sleep, but there's no way to wait synchronously or force
-# iprop to happen (since iprop here is a pull system) and then wait for
-# it synchronously.
+# Check that iprop happened.
+wait_for_prop(realm)
 out = realm.run_as_slave([kproplog, '-h'])
 if 'Last serial # : 8' not in out:
     fail('Update log on slave has incorrect last serial number')
@@ -88,8 +112,7 @@ if 'Last serial # : 9' not in out:
     fail('Update log on master has incorrect last serial number')
 
 # Check that we're at sno 9 on the slave side too.
-output('Sleeping for 3 seconds\n')
-time.sleep(3)
+wait_for_prop(realm)
 out = realm.run_as_slave([kproplog, '-h'])
 if 'Last serial # : 9' not in out:
     fail('Update log on slave has incorrect last serial number')
@@ -99,8 +122,7 @@ realm.run_as_slave([kproplog, '-R'])
 out = realm.run_as_slave([kproplog, '-h'])
 if 'Last serial # : None' not in out:
     fail('Reset of update log on slave failed')
-output('Sleeping for 3 seconds\n')
-time.sleep(3)
+wait_for_prop(realm)
 # Check that a full resync happened.
 out = realm.run_as_slave([kproplog, '-h'])
 if 'Last serial # : 9' not in out:
@@ -112,8 +134,7 @@ out = realm.run_as_master([kproplog, '-h'])
 if 'Last serial # : 10' not in out:
     fail('Update log on master has incorrect last serial number')
 
-output('Sleeping for 3 seconds\n')
-time.sleep(3)
+wait_for_prop(realm)
 out = realm.run_as_slave([kproplog, '-h'])
 if 'Last serial # : 10' not in out:
     fail('Update log on slave has incorrect last serial number')
@@ -129,8 +150,7 @@ realm.run_kadminl('modprinc -allow_tix w')
 out = realm.run_as_master([kproplog, '-h'])
 if 'Last serial # : 1' not in out:
     fail('Update log on master has incorrect last serial number')
-output('Sleeping for 3 seconds\n')
-time.sleep(3)
+wait_for_prop(realm)
 # Check that a full resync happened.
 out = realm.run_as_slave([kproplog, '-h'])
 if 'Last serial # : 1' not in out:
diff --git a/src/util/k5test.py b/src/util/k5test.py
index 4fd8cf752..3400154ca 100644
--- a/src/util/k5test.py
+++ b/src/util/k5test.py
@@ -251,14 +251,26 @@ Scripts may use the following realm methods and attributes:
 * realm.start_kadmind(): Start a kadmind with the realm's master KDC
   environment.  Errors if a kadmind is already running.
 
-* realm.start_kpropd(): Start a kpropd with the realm's slave KDC
-  environment.  Errors if a kpropd is already running.
-
 * realm.stop_kadmind(): Stop the kadmind process.  Errors if no
   kadmind is running.
 
-* realm.stop(): Stop any KDC and kadmind processes running on behalf
-  of the realm.
+* realm.start_kpropd(args=[]): Start a kpropd with the realm's slave
+  KDC environment.  Errors if a kpropd is already running.  If args is
+  given, it contains a list of additional kpropd arguments.
+
+* realm.stop_kpropd(): Stop the kpropd process.  Errors if no kpropd
+  is running.
+
+* realm.read_from_kpropd(): Read a line from the stdout or stderr of
+  the kpropd process.  Most useful if kpropd is started with the -d
+  option.
+
+* realm.prod_kpropd(): Send a USR1 signal to a kpropd to make it stop
+  sleeping and perform an iprop request.  kpropd must be running in
+  iprop mode or a USR1 will simply terminate it.
+
+* realm.stop(): Stop any daemon processes running on behalf of the
+  realm.
 
 * realm.addprinc(princname, password=None): Using kadmin.local, create
   a principle in the KDB named princname, with either a random or
@@ -910,7 +922,7 @@ class K5Realm(object):
         stop_daemon(self._kadmind_proc)
         self._kadmind_proc = None
 
-    def start_kpropd(self):
+    def start_kpropd(self, args=[]):
         global krb5kdc
         assert(self._kpropd_proc is None)
         slavedump_path = os.path.join(self.testdir, 'incoming-slave-datatrans')
@@ -919,7 +931,7 @@ class K5Realm(object):
                                            str(self.portbase + 3),
                                            '-f', slavedump_path,
                                            '-p', kdb5_util,
-                                           '-a', kpropdacl_path],
+                                           '-a', kpropdacl_path] + args,
                                           self.env_slave, 'ready')
 
     def stop_kpropd(self):
@@ -927,6 +939,14 @@ class K5Realm(object):
         stop_daemon(self._kpropd_proc)
         self._kpropd_proc = None
 
+    def read_from_kpropd(self):
+        assert(self._kpropd_proc is not None)
+        return self._kpropd_proc.stdout.readline()
+
+    def prod_kpropd(self):
+        assert(self._kpropd_proc is not None)
+        self._kpropd_proc.send_signal(signal.SIGUSR1)
+
     def stop(self):
         if self._kdc_proc:
             self.stop_kdc()