Avoid unnecessary iprop full resyncs after resets

When resetting the ulog header or initializing it from a dump file
kdb_last_t value, instead of setting kdb_num to 0, create a dummy
entry for the last_sno value so that we can remember its timestamp.
With this change, a slave no longer needs to perform two full resyncs
after an upstream header initialization.  Dummy entries are never
transmitted to downstream slaves because the iprop protocol never
transmits the kdb_first_sno update; if one is somehow transmitted, the
slave will ignore it because it doesn't have the kdb_commit flag set.

reset_header() is renamed to reset_ulog(), takes a kdb_log_context
parameter, and is responsible for syncing the header.  sync_update()
now returns void and aborts if msync() fails, just like sync_header().
A new helper set_dummy() writes a dummy entry and sets the ulog to
point to it.

Adjust kproplog to recognize and display dummy entries.  Adjust
t_ulog.c and t_iprop.py for the new behavior.  In t_iprop.py, remove a
kpropd -t test which became redundant with the previous test.

ticket: 8164 (new)

diff --git a/src/lib/kdb/kdb_log.c b/src/lib/kdb/kdb_log.c
index faca467fcf5b55df6492081c88a8a55a1a2ad8fb..d377a2042291ebd67b4c04080b6e0d307f5d1430 100644 (file)
--- a/src/lib/kdb/kdb_log.c
+++ b/src/lib/kdb/kdb_log.c
@@ -51,14 +51,11 @@ time_current(kdbe_time_t *out)
 }
 
 /* Sync update entry to disk. */
-static krb5_error_code
+static void
 sync_update(kdb_hlog_t *ulog, kdb_ent_header_t *upd)
 {
     unsigned long start, end, size;
 
-    if (ulog == NULL)
-        return KRB5_LOG_ERROR;
-
     if (!pagesize)
         pagesize = getpagesize();
 
@@ -68,7 +65,11 @@ sync_update(kdb_hlog_t *ulog, kdb_ent_header_t *upd)
         ~(pagesize - 1);
 
     size = end - start;
-    return msync((caddr_t)start, size, MS_SYNC);
+    if (msync((caddr_t)start, size, MS_SYNC)) {
+        /* Couldn't sync to disk, let's panic. */
+        syslog(LOG_ERR, _("could not sync ulog update to disk"));
+        abort();
+    }
 }
 
 /* Sync memory to disk for the update log header. */
@@ -199,15 +200,42 @@ resize(kdb_hlog_t *ulog, uint32_t ulogentries, int ulogfd,
     return 0;
 }
 
+/* Set the ulog to contain only a dummy entry with the given serial number and
+ * timestamp. */
+static void
+set_dummy(kdb_log_context *log_ctx, kdb_sno_t sno, const kdbe_time_t *kdb_time)
+{
+    kdb_hlog_t *ulog = log_ctx->ulog;
+    kdb_ent_header_t *ent = INDEX(ulog, (sno - 1) % log_ctx->ulogentries);
+
+    memset(ent, 0, sizeof(*ent));
+    ent->kdb_umagic = KDB_ULOG_MAGIC;
+    ent->kdb_entry_sno = sno;
+    ent->kdb_time = *kdb_time;
+    sync_update(ulog, ent);
+
+    ulog->kdb_num = 1;
+    ulog->kdb_first_sno = ulog->kdb_last_sno = sno;
+    ulog->kdb_first_time = ulog->kdb_last_time = *kdb_time;
+}
+
+/* Reinitialize the ulog header, starting from sno 1 with the current time. */
 static void
-reset_header(kdb_hlog_t *ulog)
+reset_ulog(kdb_log_context *log_ctx)
 {
+    kdbe_time_t kdb_time;
+    kdb_hlog_t *ulog = log_ctx->ulog;
+
     memset(ulog, 0, sizeof(*ulog));
     ulog->kdb_hmagic = KDB_ULOG_HDR_MAGIC;
     ulog->db_version_num = KDB_VERSION;
-    ulog->kdb_state = KDB_STABLE;
     ulog->kdb_block = ULOG_BLOCK;
-    time_current(&ulog->kdb_last_time);
+
+    /* Create a dummy entry to remember the timestamp for downstreams. */
+    time_current(&kdb_time);
+    set_dummy(log_ctx, 1, &kdb_time);
+    ulog->kdb_state = KDB_STABLE;
+    sync_header(ulog);
 }
 
 /*
@@ -276,14 +304,13 @@ store_update(kdb_log_context *log_ctx, kdb_incr_update_t *upd)
         return KRB5_LOG_CONV;
 
     indx_log->kdb_commit = TRUE;
-    retval = sync_update(ulog, indx_log);
-    if (retval)
-        return retval;
+    sync_update(ulog, indx_log);
 
     /* Modify the ulog header to reflect the new update. */
     ulog->kdb_last_sno = upd->kdb_entry_sno;
     ulog->kdb_last_time = upd->kdb_time;
     if (ulog->kdb_num == 0) {
+        /* We should only see this in old ulogs. */
         ulog->kdb_num = 1;
         ulog->kdb_first_sno = upd->kdb_entry_sno;
         ulog->kdb_first_time = upd->kdb_time;
@@ -318,7 +345,7 @@ ulog_add_update(krb5_context context, kdb_incr_update_t *upd)
     /* If we have reached the last possible serial number, reinitialize the
      * ulog and start over.  Slaves will do a full resync. */
     if (ulog->kdb_last_sno == (kdb_sno_t)-1)
-        reset_header(ulog);
+        reset_ulog(log_ctx);
 
     upd->kdb_entry_sno = ulog->kdb_last_sno + 1;
     time_current(&upd->kdb_time);
@@ -367,7 +394,7 @@ ulog_replay(krb5_context context, kdb_incr_result_t *incr_ret, char **db_args)
         /* If (unexpectedly) this update does not follow the last one we
          * stored, discard any previous ulog state. */
         if (ulog->kdb_num != 0 && upd->kdb_entry_sno != ulog->kdb_last_sno + 1)
-            reset_header(ulog);
+            reset_ulog(log_ctx);
 
         if (upd->kdb_deleted) {
             dbprincstr = k5memdup0(upd->kdb_princ_name.utf8str_t_val,
@@ -411,10 +438,8 @@ ulog_replay(krb5_context context, kdb_incr_result_t *incr_ret, char **db_args)
 cleanup:
     if (fupd)
         ulog_free_entries(fupd, no_of_updates);
-    if (retval) {
-        reset_header(ulog);
-        sync_header(ulog);
-    }
+    if (retval)
+        reset_ulog(log_ctx);
     unlock_ulog(context);
     krb5_db_unlock(context);
     return retval;
@@ -432,8 +457,7 @@ ulog_init_header(krb5_context context)
     ret = lock_ulog(context, KRB5_LOCKMODE_EXCLUSIVE);
     if (ret)
         return ret;
-    reset_header(ulog);
-    sync_header(ulog);
+    reset_ulog(log_ctx);
     unlock_ulog(context);
     return 0;
 }
@@ -498,8 +522,7 @@ ulog_map(krb5_context context, const char *logname, uint32_t ulogentries)
             unlock_ulog(context);
             return KRB5_LOG_CORRUPT;
         }
-        reset_header(ulog);
-        sync_header(ulog);
+        reset_ulog(log_ctx);
     }
 
     /* Reinit ulog if ulogentries changed such that we have too many entries or
@@ -507,10 +530,8 @@ ulog_map(krb5_context context, const char *logname, uint32_t ulogentries)
     if (ulog->kdb_num != 0 &&
         (ulog->kdb_num > ulogentries ||
          !check_sno(log_ctx, ulog->kdb_first_sno, &ulog->kdb_first_time) ||
-         !check_sno(log_ctx, ulog->kdb_last_sno, &ulog->kdb_last_time))) {
-        reset_header(ulog);
-        sync_header(ulog);
-    }
+         !check_sno(log_ctx, ulog->kdb_last_sno, &ulog->kdb_last_time)))
+        reset_ulog(log_ctx);
 
     if (ulog->kdb_num != ulogentries) {
         /* Expand the ulog file if it isn't big enough. */
@@ -550,7 +571,7 @@ ulog_get_entries(krb5_context context, const kdb_last_t *last,
     /* If another process terminated mid-update, reset the ulog and force full
      * resyncs. */
     if (ulog->kdb_state != KDB_STABLE)
-        reset_header(ulog);
+        reset_ulog(log_ctx);
 
     ulog_handle->ret = get_sno_status(log_ctx, last);
     if (ulog_handle->ret != UPDATE_OK)
@@ -649,8 +670,8 @@ ulog_set_last(krb5_context context, const kdb_last_t *last)
     ret = lock_ulog(context, KRB5_LOCKMODE_EXCLUSIVE);
     if (ret)
         return ret;
-    ulog->kdb_last_sno = last->last_sno;
-    ulog->kdb_last_time = last->last_time;
+
+    set_dummy(log_ctx, last->last_sno, &last->last_time);
     sync_header(ulog);
     unlock_ulog(context);
     return 0;

diff --git a/src/lib/kdb/t_ulog.c b/src/lib/kdb/t_ulog.c
index 2fb8a827aea5a2a840638d21bf73234168dceb21..96e00bb40f5001efc9ce8ef590597a2b5fe1305d 100644 (file)
--- a/src/lib/kdb/t_ulog.c
+++ b/src/lib/kdb/t_ulog.c
@@ -77,12 +77,12 @@ main(int argc, char **argv)
     ulog->kdb_first_sno = ulog->kdb_last_sno - ulog->kdb_num + 1;
 
     /* Add an empty update.  This should reinitialize the ulog, then add the
-     * update with serial number 1. */
+     * update with serial number 2. */
     memset(&upd, 0, sizeof(kdb_incr_update_t));
     if (ulog_add_update(context, &upd) != 0)
         abort();
-    assert(ulog->kdb_num == 1);
+    assert(ulog->kdb_num == 2);
     assert(ulog->kdb_first_sno == 1);
-    assert(ulog->kdb_last_sno == 1);
+    assert(ulog->kdb_last_sno == 2);
     return 0;
 }

diff --git a/src/slave/kproplog.c b/src/slave/kproplog.c
index efa1f432d0dafe74368d44517f3a644351550657..857ef03da8ae4d3259d9d47828150a831fc706d5 100644 (file)
--- a/src/slave/kproplog.c
+++ b/src/slave/kproplog.c
@@ -357,6 +357,17 @@ print_update(kdb_hlog_t *ulog, uint32_t entry, uint32_t ulogentries,
             exit(1);
         }
 
+        printf("---\n");
+        printf(_("Update Entry\n"));
+
+        printf(_("\tUpdate serial # : %u\n"), indx_log->kdb_entry_sno);
+
+        /* The initial entry after a reset is a dummy entry; skip it. */
+        if (indx_log->kdb_entry_size == 0) {
+            printf(_("\tDummy entry\n"));
+            continue;
+        }
+
         memset(&upd, 0, sizeof(kdb_incr_update_t));
         xdrmem_create(&xdrs, (char *)indx_log->entry_data,
                       indx_log->kdb_entry_size, XDR_DECODE);
@@ -365,11 +376,6 @@ print_update(kdb_hlog_t *ulog, uint32_t entry, uint32_t ulogentries,
             exit(1);
         }
 
-        printf("---\n");
-        printf(_("Update Entry\n"));
-
-        printf(_("\tUpdate serial # : %u\n"), indx_log->kdb_entry_sno);
-
         printf(_("\tUpdate operation : "));
         if (upd.kdb_deleted)
             printf(_("Delete\n"));

diff --git a/src/tests/t_iprop.py b/src/tests/t_iprop.py
index 1ed8dbd109069ffa72d9bbda1918680e9b783123..6b38b8a12f1cf9050d375772a7c8c6a2d4d10cee 100755 (executable)
--- a/src/tests/t_iprop.py
+++ b/src/tests/t_iprop.py
@@ -100,7 +100,13 @@ def check_ulog(num, first, last, entries, env=None):
         m = re.match(r'\tUpdate principal : (.*)$', line)
         if m:
             eprinc = entries[ser - first]
-            if m.group(1) != eprinc:
+            if eprinc == None:
+                fail('Expected dummy update entry %d' % ser)
+            elif m.group(1) != eprinc:
+                fail('Expected princ %s in update entry %d' % (eprinc, ser))
+        if line == '\tDummy entry':
+            eprinc = entries[ser - first]
+            if eprinc != None:
                 fail('Expected princ %s in update entry %d' % (eprinc, ser))
 
 # slave1 will receive updates from master, and slave2 will receive
@@ -158,7 +164,7 @@ realm.run([kdb5_util, 'load', dumpfile], slave2)
 # Reinitialize the master ulog so we know exactly what to expect in
 # it.
 realm.run([kproplog, '-R'])
-check_ulog(0, 0, 0, [])
+check_ulog(1, 1, 1, [None])
 
 # Make some changes to the master DB.
 realm.addprinc(pr1)
@@ -166,22 +172,22 @@ realm.addprinc(pr3)
 realm.addprinc(pr2)
 realm.run([kadminl, 'modprinc', '-allow_tix', pr2])
 realm.run([kadminl, 'modprinc', '+allow_tix', pr2])
-check_ulog(5, 1, 5, [pr1, pr3, pr2, pr2, pr2])
+check_ulog(6, 1, 6, [None, pr1, pr3, pr2, pr2, pr2])
 
 # Start kpropd for slave1 and get a full dump from master.
 kpropd1 = realm.start_kpropd(slave1, ['-d'])
-wait_for_prop(kpropd1, True, 0, 5)
+wait_for_prop(kpropd1, True, 1, 6)
 out = realm.run([kadminl, 'listprincs'], env=slave1)
 if pr1 not in out or pr2 not in out or pr3 not in out:
     fail('slave1 does not have all principals from master')
-check_ulog(0, 0, 5, [], slave1)
+check_ulog(1, 6, 6, [None], slave1)
 
 # Make a change and check that it propagates incrementally.
 realm.run([kadminl, 'modprinc', '-allow_tix', pr2])
-check_ulog(6, 1, 6, [pr1, pr3, pr2, pr2, pr2, pr2])
+check_ulog(7, 1, 7, [None, pr1, pr3, pr2, pr2, pr2, pr2])
 kpropd1.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd1, False, 5, 6)
-check_ulog(1, 6, 6, [pr2], slave1)
+wait_for_prop(kpropd1, False, 6, 7)
+check_ulog(2, 6, 7, [None, pr2], slave1)
 out = realm.run([kadminl, 'getprinc', pr2], env=slave1)
 if 'Attributes: DISALLOW_ALL_TIX' not in out:
     fail('slave1 does not have modification from master')
@@ -203,8 +209,8 @@ realm.start_server([kadmind, '-nofork', '-proponly', '-W', '-p', kdb5_util,
 kpropd2 = realm.start_server([kpropd, '-d', '-D', '-P', slave2_kprop_port,
                               '-f', slave2_in_dump_path, '-p', kdb5_util,
                               '-a', acl_file, '-A', hostname], 'ready', slave2)
-wait_for_prop(kpropd2, True, 0, 6)
-check_ulog(0, 0, 6, [], slave2)
+wait_for_prop(kpropd2, True, 1, 7)
+check_ulog(1, 7, 7, [None], slave2)
 out = realm.run([kadminl, 'listprincs'], env=slave1)
 if pr1 not in out or pr2 not in out or pr3 not in out:
     fail('slave2 does not have all principals from slave1')
@@ -212,16 +218,16 @@ if pr1 not in out or pr2 not in out or pr3 not in out:
 # Make another change and check that it propagates incrementally to
 # both slaves.
 realm.run([kadminl, 'modprinc', '-maxrenewlife', '22 hours', pr1])
-check_ulog(7, 1, 7, [pr1, pr3, pr2, pr2, pr2, pr2, pr1])
+check_ulog(8, 1, 8, [None, pr1, pr3, pr2, pr2, pr2, pr2, pr1])
 kpropd1.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd1, False, 6, 7)
-check_ulog(2, 6, 7, [pr2, pr1], slave1)
+wait_for_prop(kpropd1, False, 7, 8)
+check_ulog(3, 6, 8, [None, pr2, pr1], slave1)
 out = realm.run([kadminl, 'getprinc', pr1], env=slave1)
 if 'Maximum renewable life: 0 days 22:00:00\n' not in out:
     fail('slave1 does not have modification from master')
 kpropd2.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd2, False, 6, 7)
-check_ulog(1, 7, 7, [pr1], slave2)
+wait_for_prop(kpropd2, False, 7, 8)
+check_ulog(2, 7, 8, [None, pr1], slave2)
 out = realm.run([kadminl, 'getprinc', pr1], env=slave2)
 if 'Maximum renewable life: 0 days 22:00:00\n' not in out:
     fail('slave2 does not have modification from slave1')
@@ -231,126 +237,120 @@ if 'Maximum renewable life: 0 days 22:00:00\n' not in out:
 # slave2 should still be in sync with slave1 after the resync, so make
 # sure it doesn't take a full resync.
 realm.run([kproplog, '-R'], slave1)
-check_ulog(0, 0, 0, [], slave1)
+check_ulog(1, 1, 1, [None], slave1)
 kpropd1.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd1, True, 0, 7)
-check_ulog(2, 6, 7, [pr2, pr1], slave1)
+wait_for_prop(kpropd1, True, 1, 8)
+check_ulog(3, 6, 8, [None, pr2, pr1], slave1)
 kpropd2.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd2, False, 7, 7)
-check_ulog(1, 7, 7, [pr1], slave2)
+wait_for_prop(kpropd2, False, 8, 8)
+check_ulog(2, 7, 8, [None, pr1], slave2)
 
 # Make another change and check that it propagates incrementally to
 # both slaves.
 realm.run([kadminl, 'modprinc', '+allow_tix', 'w'])
-check_ulog(8, 1, 8, [pr1, pr3, pr2, pr2, pr2, pr2, pr1, pr2])
+check_ulog(9, 1, 9, [None, pr1, pr3, pr2, pr2, pr2, pr2, pr1, pr2])
 kpropd1.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd1, False, 7, 8)
-check_ulog(3, 6, 8, [pr2, pr1, pr2], slave1)
+wait_for_prop(kpropd1, False, 8, 9)
+check_ulog(4, 6, 9, [None, pr2, pr1, pr2], slave1)
 out = realm.run([kadminl, 'getprinc', pr2], env=slave1)
 if 'Attributes:\n' not in out:
     fail('slave1 does not have modification from master')
 kpropd2.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd2, False, 7, 8)
-check_ulog(2, 7, 8, [pr1, pr2], slave2)
+wait_for_prop(kpropd2, False, 8, 9)
+check_ulog(3, 7, 9, [None, pr1, pr2], slave2)
 out = realm.run([kadminl, 'getprinc', pr2], env=slave2)
 if 'Attributes:\n' not in out:
     fail('slave2 does not have modification from slave1')
 
 # Create a policy and check that it propagates via full resync.
 realm.run([kadminl, 'addpol', '-minclasses', '2', 'testpol'])
-check_ulog(0, 0, 0, [])
+check_ulog(1, 1, 1, [None])
 kpropd1.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd1, True, 8, 0)
-check_ulog(0, 0, 0, [], slave1)
+wait_for_prop(kpropd1, True, 9, 1)
+check_ulog(1, 1, 1, [None], slave1)
 out = realm.run([kadminl, 'getpol', 'testpol'], env=slave1)
 if 'Minimum number of password character classes: 2' not in out:
     fail('slave1 does not have policy from master')
 kpropd2.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd2, True, 8, 0)
-check_ulog(0, 0, 0, [], slave2)
+wait_for_prop(kpropd2, True, 9, 1)
+check_ulog(1, 1, 1, [None], slave2)
 out = realm.run([kadminl, 'getpol', 'testpol'], env=slave2)
 if 'Minimum number of password character classes: 2' not in out:
     fail('slave2 does not have policy from slave1')
 
 # Modify the policy and test that it also propagates via full resync.
 realm.run([kadminl, 'modpol', '-minlength', '17', 'testpol'])
-check_ulog(0, 0, 0, [])
+check_ulog(1, 1, 1, [None])
 kpropd1.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd1, True, 0, 0)
-check_ulog(0, 0, 0, [], slave1)
+wait_for_prop(kpropd1, True, 1, 1)
+check_ulog(1, 1, 1, [None], slave1)
 out = realm.run([kadminl, 'getpol', 'testpol'], env=slave1)
 if 'Minimum password length: 17' not in out:
     fail('slave1 does not have policy change from master')
 kpropd2.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd2, True, 0, 0)
-check_ulog(0, 0, 0, [], slave2)
+wait_for_prop(kpropd2, True, 1, 1)
+check_ulog(1, 1, 1, [None], slave2)
 out = realm.run([kadminl, 'getpol', 'testpol'], env=slave2)
 if 'Minimum password length: 17' not in out:
     fail('slave2 does not have policy change from slave1')
 
 # Delete the policy and test that it propagates via full resync.
 realm.run([kadminl, 'delpol', 'testpol'])
-check_ulog(0, 0, 0, [])
+check_ulog(1, 1, 1, [None])
 kpropd1.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd1, True, 0, 0)
-check_ulog(0, 0, 0, [], slave1)
+wait_for_prop(kpropd1, True, 1, 1)
+check_ulog(1, 1, 1, [None], slave1)
 out = realm.run([kadminl, 'getpol', 'testpol'], env=slave1, expected_code=1)
 if 'Policy does not exist' not in out:
     fail('slave1 did not get policy deletion from master')
 kpropd2.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd2, True, 0, 0)
-check_ulog(0, 0, 0, [], slave2)
+wait_for_prop(kpropd2, True, 1, 1)
+check_ulog(1, 1, 1, [None], slave2)
 out = realm.run([kadminl, 'getpol', 'testpol'], env=slave2, expected_code=1)
 if 'Policy does not exist' not in out:
     fail('slave2 did not get policy deletion from slave1')
 
-# Modify a principal on the master and test that it propagates via
-# full resync.  (The master's ulog does not remember the timestamp it
-# had at serial number 0, so it does not know that an incremental
-# propagation is possible.)
+# Modify a principal on the master and test that it propagates incrementally.
 realm.run([kadminl, 'modprinc', '-maxlife', '10 minutes', pr1])
-check_ulog(1, 1, 1, [pr1])
+check_ulog(2, 1, 2, [None, pr1])
 kpropd1.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd1, True, 0, 1)
-check_ulog(0, 0, 1, [], slave1)
+wait_for_prop(kpropd1, False, 1, 2)
+check_ulog(2, 1, 2, [None, pr1], slave1)
 out = realm.run([kadminl, 'getprinc', pr1], env=slave1)
 if 'Maximum ticket life: 0 days 00:10:00' not in out:
     fail('slave1 does not have modification from master')
 kpropd2.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd2, True, 0, 1)
-check_ulog(0, 0, 1, [], slave2)
+wait_for_prop(kpropd2, False, 1, 2)
+check_ulog(2, 1, 2, [None, pr1], slave2)
 out = realm.run([kadminl, 'getprinc', pr1], env=slave2)
 if 'Maximum ticket life: 0 days 00:10:00' not in out:
     fail('slave2 does not have modification from slave1')
 
-# Delete a principal and test that it propagates incrementally to
-# slave1.  slave2 needs another full resync because slave1 no longer
-# has serial number 1 in its ulog after processing its first
-# incremental update.
+# Delete a principal and test that it propagates incrementally.
 realm.run([kadminl, 'delprinc', pr3])
-check_ulog(2, 1, 2, [pr1, pr3])
+check_ulog(3, 1, 3, [None, pr1, pr3])
 kpropd1.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd1, False, 1, 2)
-check_ulog(1, 2, 2, [pr3], slave1)
+wait_for_prop(kpropd1, False, 2, 3)
+check_ulog(3, 1, 3, [None, pr1, pr3], slave1)
 out = realm.run([kadminl, 'getprinc', pr3], env=slave1, expected_code=1)
 if 'Principal does not exist' not in out:
     fail('slave1 does not have principal deletion from master')
 kpropd2.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd2, True, 1, 2)
-check_ulog(0, 0, 2, [], slave2)
+wait_for_prop(kpropd2, False, 2, 3)
+check_ulog(3, 1, 3, [None, pr1, pr3], slave2)
 out = realm.run([kadminl, 'getprinc', pr3], env=slave2, expected_code=1)
 if 'Principal does not exist' not in out:
     fail('slave2 does not have principal deletion from slave1')
 
 # Reset the ulog on the master to force a full resync.
 realm.run([kproplog, '-R'])
-check_ulog(0, 0, 0, [])
+check_ulog(1, 1, 1, [None])
 kpropd1.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd1, True, 2, 0)
-check_ulog(0, 0, 0, [], slave1)
+wait_for_prop(kpropd1, True, 3, 1)
+check_ulog(1, 1, 1, [None], slave1)
 kpropd2.send_signal(signal.SIGUSR1)
-wait_for_prop(kpropd2, True, 2, 0)
-check_ulog(0, 0, 0, [], slave2)
+wait_for_prop(kpropd2, True, 3, 1)
+check_ulog(1, 1, 1, [None], slave2)
 
 # Stop the kprop daemons so we can test kpropd -t.
 stop_daemon(kpropd1)
@@ -360,40 +360,27 @@ stop_daemon(kpropd2)
 out = realm.run_kpropd_once(slave1, ['-d'])
 if 'KDC is synchronized' not in out:
     fail('Expected synchronized from kpropd -t')
-check_ulog(0, 0, 0, [], slave1)
+check_ulog(1, 1, 1, [None], slave1)
 
-# Make a change on the master; this will cause a full resync since the
-# master was recently reinitialized.
+# Make a change on the master and fetch it incrementally.
 realm.run([kadminl, 'modprinc', '-maxlife', '5 minutes', pr1])
-check_ulog(1, 1, 1, [pr1])
+check_ulog(2, 1, 2, [None, pr1])
 out = realm.run_kpropd_once(slave1, ['-d'])
-if ('Full propagation transfer finished' not in out or
-    'KDC is synchronized' not in out):
+if 'Got incremental updates (sno=2 ' not in out:
     fail('Expected full dump and synchronized from kpropd -t')
-check_ulog(0, 0, 1, [], slave1)
+check_ulog(2, 1, 2, [None, pr1], slave1)
 out = realm.run([kadminl, 'getprinc', pr1], env=slave1)
 if 'Maximum ticket life: 0 days 00:05:00' not in out:
     fail('slave1 does not have modification from master after kpropd -t')
 
-# Make another change and get it via incremental update.
-realm.run([kadminl, 'modprinc', '-maxlife', '15 minutes', pr1])
-check_ulog(2, 1, 2, [pr1, pr1])
-out = realm.run_kpropd_once(slave1, ['-d'])
-if 'Got incremental updates (sno=2 ' not in out:
-    fail('Expected incremental updates from kpropd -t')
-check_ulog(1, 2, 2, [pr1], slave1)
-out = realm.run([kadminl, 'getprinc', pr1], env=slave1)
-if 'Maximum ticket life: 0 days 00:15:00' not in out:
-    fail('slave1 does not have modification from master after kpropd -t')
-
 # Propagate a policy change via full resync.
 realm.run([kadminl, 'addpol', '-minclasses', '3', 'testpol'])
-check_ulog(0, 0, 0, [])
+check_ulog(1, 1, 1, [None])
 out = realm.run_kpropd_once(slave1, ['-d'])
 if ('Full propagation transfer finished' not in out or
     'KDC is synchronized' not in out):
     fail('Expected full dump and synchronized from kpropd -t')
-check_ulog(0, 0, 0, [], slave1)
+check_ulog(1, 1, 1, [None], slave1)
 out = realm.run([kadminl, 'getpol', 'testpol'], env=slave1)
 if 'Minimum number of password character classes: 3' not in out:
     fail('slave1 does not have policy from master after kpropd -t')