Lock around more ulog operations

Always lock the ulog when accessing it.  We can currently get away
with some laxness on iprop slaves because they are mostly synchronous,
but hierarchical iprop will allow master and slave operations to take
place concurrently, requiring more strict locking.

Add new functions ulog_get_last and ulog_set_last, which access the
ulog header with locking, and use them in kdb5_util and kpropd.  Add
locking to ulog_replay and ulog_init_header.

ulog_lock and ulog_sync_header are no longer used outside of kdb_log.c
after these changes, so make them static functions and remove the
ulog_ prefix.  Add an unlock_ulog function for clarity.

diff --git a/src/include/kdb_log.h b/src/include/kdb_log.h
index 35b9d55655704d406068310793f8825e8096153d..7f35eb7c86c61f5c7ad4232e5cc23724b504fb6e 100644 (file)
--- a/src/include/kdb_log.h
+++ b/src/include/kdb_log.h
@@ -69,7 +69,7 @@ extern "C" {
  */
 krb5_error_code ulog_map(krb5_context context, const char *logname,
                          uint32_t entries, int caller, char **db_args);
-void ulog_init_header(krb5_context context);
+krb5_error_code ulog_init_header(krb5_context context);
 krb5_error_code ulog_add_update(krb5_context context, kdb_incr_update_t *upd);
 krb5_error_code ulog_get_entries(krb5_context context, const kdb_last_t *last,
                                  kdb_incr_result_t *ulog_handle);
@@ -81,9 +81,10 @@ krb5_error_code ulog_conv_2dbentry(krb5_context context, krb5_db_entry **entry,
                                    kdb_incr_update_t *update);
 void ulog_free_entries(kdb_incr_update_t *updates, int no_of_updates);
 krb5_error_code ulog_set_role(krb5_context ctx, iprop_role role);
-krb5_error_code ulog_lock(krb5_context ctx, int mode);
 update_status_t ulog_get_sno_status(krb5_context context,
                                     const kdb_last_t *last);
+krb5_error_code ulog_get_last(krb5_context context, kdb_last_t *last_out);
+krb5_error_code ulog_set_last(krb5_context context, const kdb_last_t *last);
 
 typedef struct kdb_hlog {
     uint32_t        kdb_hmagic;     /* Log header magic # */
@@ -97,8 +98,6 @@ typedef struct kdb_hlog {
     uint16_t        kdb_block;      /* Block size of each element */
 } kdb_hlog_t;
 
-void ulog_sync_header(kdb_hlog_t *);
-
 typedef struct kdb_ent_header {
     uint32_t        kdb_umagic;     /* Update entry magic # */
     kdb_sno_t       kdb_entry_sno;  /* Serial # of entry */

diff --git a/src/kadmin/dbutil/dump.c b/src/kadmin/dbutil/dump.c
index a94fb31303f4693b51d7e6f7be7b02e6a6b70dc3..def1d6a6bae0c71936720de7af1d7f902d894704 100644 (file)
--- a/src/kadmin/dbutil/dump.c
+++ b/src/kadmin/dbutil/dump.c
@@ -1231,6 +1231,7 @@ dump_db(int argc, char **argv)
     unsigned int ipropx_version = IPROPX_VERSION_0;
     krb5_kvno kt_kvno;
     krb5_boolean conditional = FALSE;
+    kdb_last_t last;
 
     /* Parse the arguments. */
     dump = &r1_11_version;
@@ -1404,11 +1405,16 @@ dump_db(int argc, char **argv)
     }
 
     if (dump_sno) {
+        ret = ulog_get_last(util_context, &last);
+        if (ret) {
+            com_err(progname, ret, _("while reading update log header"));
+            goto error;
+        }
         if (ipropx_version)
             fprintf(f, " %u", IPROPX_VERSION);
-        fprintf(f, " %u", log_ctx->ulog->kdb_last_sno);
-        fprintf(f, " %u", log_ctx->ulog->kdb_last_time.seconds);
-        fprintf(f, " %u", log_ctx->ulog->kdb_last_time.useconds);
+        fprintf(f, " %u", last.last_sno);
+        fprintf(f, " %u", last.last_time.seconds);
+        fprintf(f, " %u", last.last_time.useconds);
     }
 
     if (dump->header[strlen(dump->header)-1] != '\n')
@@ -1639,8 +1645,13 @@ load_db(int argc, char **argv)
     if (!update) {
         /* Initialize the ulog header before promoting so we can't leave behind
          * the pre-load ulog state if we are killed just after promoting. */
-        if (log_ctx != NULL && log_ctx->iproprole)
-            ulog_init_header(util_context);
+        if (log_ctx != NULL && log_ctx->iproprole) {
+            ret = ulog_init_header(util_context);
+            if (ret) {
+                com_err(progname, ret, _("while reinitializing update log"));
+                goto error;
+            }
+        }
 
         ret = krb5_db_promote(util_context, db5util_db_args);
         /* Ignore a not supported error since there is nothing to do about it
@@ -1654,11 +1665,18 @@ load_db(int argc, char **argv)
         if (log_ctx != NULL && log_ctx->iproprole) {
             /* Reinitialize the ulog header since we replaced the DB, and
              * record the iprop state if we received it. */
-            ulog_init_header(util_context);
+            ret = ulog_init_header(util_context);
+            if (ret) {
+                com_err(progname, ret, _("while reinitializing update log"));
+                goto error;
+            }
             if (iprop_load) {
-                log_ctx->ulog->kdb_last_sno = last.last_sno;
-                log_ctx->ulog->kdb_last_time = last.last_time;
-                ulog_sync_header(log_ctx->ulog);
+                ret = ulog_set_last(util_context, &last);
+                if (ret) {
+                    com_err(progname, ret,
+                            _("while writing update log header"));
+                    goto error;
+                }
             }
         }
     }

diff --git a/src/kadmin/dbutil/kdb5_create.c b/src/kadmin/dbutil/kdb5_create.c
index 31b3c6efb04b6d22f360b5c4b40a0c7437eed622..f6df9923e45a7bc3583f6a6b0bc348447baecea3 100644 (file)
--- a/src/kadmin/dbutil/kdb5_create.c
+++ b/src/kadmin/dbutil/kdb5_create.c
@@ -300,7 +300,12 @@ void kdb5_create(argc, argv)
          * We're reinitializing the update log in case one already
          * existed, but this should never happen.
          */
-        ulog_init_header(util_context);
+        retval = ulog_init_header(util_context);
+        if (retval) {
+            com_err(argv[0], retval, _("while initializing update log"));
+            exit_status++;
+            return;
+        }
 
         /*
          * Since we're creating a new db we shouldn't worry about

diff --git a/src/lib/kdb/kdb5.c b/src/lib/kdb/kdb5.c
index b35d9ca5b7e04d53b6ab8784bd39657c67446997..8233a48ccc1c53e1cb00b2e87a0fa010fc4a5fcc 100644 (file)
--- a/src/lib/kdb/kdb5.c
+++ b/src/lib/kdb/kdb5.c
@@ -2266,7 +2266,7 @@ krb5_db_create_policy(krb5_context kcontext, osa_policy_ent_t policy)
     status = v->create_policy(kcontext, policy);
     /* iprop does not support policy mods; force full resync. */
     if (!status && logging(kcontext))
-        ulog_init_header(kcontext);
+        status = ulog_init_header(kcontext);
     return status;
 }
 
@@ -2299,7 +2299,7 @@ krb5_db_put_policy(krb5_context kcontext, osa_policy_ent_t policy)
     status = v->put_policy(kcontext, policy);
     /* iprop does not support policy mods; force full resync. */
     if (!status && logging(kcontext))
-        ulog_init_header(kcontext);
+        status = ulog_init_header(kcontext);
     return status;
 }
 
@@ -2333,7 +2333,7 @@ krb5_db_delete_policy(krb5_context kcontext, char *policy)
     status = v->delete_policy(kcontext, policy);
     /* iprop does not support policy mods; force full resync. */
     if (!status && logging(kcontext))
-        ulog_init_header(kcontext);
+        status = ulog_init_header(kcontext);
     return status;
 }
 

diff --git a/src/lib/kdb/kdb_log.c b/src/lib/kdb/kdb_log.c
index dcc1bcf447b1e3c2ffe86d3591836929ad758733..378a497a31f0f291976b2209e4f76403e8a6e723 100644 (file)
--- a/src/lib/kdb/kdb_log.c
+++ b/src/lib/kdb/kdb_log.c
@@ -72,15 +72,15 @@ sync_update(kdb_hlog_t *ulog, kdb_ent_header_t *upd)
 }
 
 /* Sync memory to disk for the update log header. */
-void
-ulog_sync_header(kdb_hlog_t *ulog)
+static void
+sync_header(kdb_hlog_t *ulog)
 {
     if (!pagesize)
         pagesize = getpagesize();
 
     if (msync((caddr_t)ulog, pagesize, MS_SYNC)) {
         /* Couldn't sync to disk, let's panic. */
-        syslog(LOG_ERR, _("ulog_sync_header: could not sync to disk"));
+        syslog(LOG_ERR, _("could not sync ulog header to disk"));
         abort();
     }
 }
@@ -190,7 +190,7 @@ resize(kdb_hlog_t *ulog, uint32_t ulogentries, int ulogfd,
     ulog->db_version_num = KDB_VERSION;
     ulog->kdb_state = KDB_STABLE;
     ulog->kdb_block = new_block;
-    ulog_sync_header(ulog);
+    sync_header(ulog);
 
     /* Expand log considering new block size. */
     if (extend_file_to(ulogfd, new_size) < 0)
@@ -210,19 +210,25 @@ reset_header(kdb_hlog_t *ulog)
     time_current(&ulog->kdb_last_time);
 }
 
-krb5_error_code
-ulog_lock(krb5_context ctx, int mode)
+/*
+ * If any database operations will be invoked while the ulog lock is held, the
+ * caller must explicitly lock the database before locking the ulog, or
+ * deadlock may result.
+ */
+static krb5_error_code
+lock_ulog(krb5_context context, int mode)
 {
     kdb_log_context *log_ctx = NULL;
     kdb_hlog_t *ulog = NULL;
 
-    if (ctx == NULL)
-        return KRB5_LOG_ERROR;
-    if (ctx->kdblog_context == NULL ||
-        ctx->kdblog_context->iproprole == IPROP_NULL)
-        return 0;
-    INIT_ULOG(ctx);
-    return krb5_lock_file(ctx, log_ctx->ulogfd, mode);
+    INIT_ULOG(context);
+    return krb5_lock_file(context, log_ctx->ulogfd, mode);
+}
+
+static void
+unlock_ulog(krb5_context context)
+{
+    (void)lock_ulog(context, KRB5_LOCKMODE_UNLOCK);
 }
 
 /*
@@ -246,7 +252,7 @@ ulog_add_update(krb5_context context, kdb_incr_update_t *upd)
     int ulogfd;
 
     INIT_ULOG(context);
-    retval = ulog_lock(context, KRB5_LOCKMODE_EXCLUSIVE);
+    retval = lock_ulog(context, KRB5_LOCKMODE_EXCLUSIVE);
     if (retval)
         return retval;
 
@@ -317,13 +323,12 @@ ulog_add_update(krb5_context context, kdb_incr_update_t *upd)
     ulog->kdb_state = KDB_STABLE;
 
 cleanup:
-    ulog_sync_header(ulog);
-    ulog_lock(context, KRB5_LOCKMODE_UNLOCK);
+    sync_header(ulog);
+    unlock_ulog(context);
     return retval;
 }
 
-/* Used by the slave to update its hash db from* the incr update log.  Must be
- * called with lock held. */
+/* Used by the slave to update its hash db from the incr update log. */
 krb5_error_code
 ulog_replay(krb5_context context, kdb_incr_result_t *incr_ret, char **db_args)
 {
@@ -339,6 +344,20 @@ ulog_replay(krb5_context context, kdb_incr_result_t *incr_ret, char **db_args)
 
     INIT_ULOG(context);
 
+    /* Lock the DB before the ulog to avoid deadlock. */
+    retval = krb5_db_open(context, db_args,
+                          KRB5_KDB_OPEN_RW | KRB5_KDB_SRV_TYPE_ADMIN);
+    if (retval)
+        return retval;
+    retval = krb5_db_lock(context, KRB5_DB_LOCKMODE_EXCLUSIVE);
+    if (retval)
+        return retval;
+    retval = lock_ulog(context, KRB5_LOCKMODE_EXCLUSIVE);
+    if (retval) {
+        krb5_db_unlock(context);
+        return retval;
+    }
+
     no_of_updates = incr_ret->updates.kdb_ulog_t_len;
     upd = incr_ret->updates.kdb_ulog_t_val;
     fupd = upd;
@@ -350,11 +369,6 @@ ulog_replay(krb5_context context, kdb_incr_result_t *incr_ret, char **db_args)
     errlast.last_time.useconds = (unsigned int)0;
     last = &errlast;
 
-    retval = krb5_db_open(context, db_args,
-                          KRB5_KDB_OPEN_RW | KRB5_KDB_SRV_TYPE_ADMIN);
-    if (retval)
-        goto cleanup;
-
     for (i = 0; i < no_of_updates; i++) {
         if (!upd->kdb_commit)
             continue;
@@ -401,21 +415,28 @@ cleanup:
     /* Record a new last serial number and timestamp in the ulog header. */
     ulog->kdb_last_sno = last->last_sno;
     ulog->kdb_last_time = last->last_time;
-    ulog_sync_header(ulog);
-
+    sync_header(ulog);
+    unlock_ulog(context);
+    krb5_db_unlock(context);
     return retval;
 }
 
-/* Reinitialize the log header.  Locking is the caller's responsibility. */
-void
+/* Reinitialize the log header. */
+krb5_error_code
 ulog_init_header(krb5_context context)
 {
+    krb5_error_code ret;
     kdb_log_context *log_ctx;
     kdb_hlog_t *ulog;
 
     INIT_ULOG(context);
+    ret = lock_ulog(context, KRB5_LOCKMODE_EXCLUSIVE);
+    if (ret)
+        return ret;
     reset_header(ulog);
-    ulog_sync_header(ulog);
+    sync_header(ulog);
+    unlock_ulog(context);
+    return 0;
 }
 
 /*
@@ -519,26 +540,26 @@ ulog_map(krb5_context context, const char *logname, uint32_t ulogentries,
     log_ctx->ulogentries = ulogentries;
     log_ctx->ulogfd = ulogfd;
 
-    retval = ulog_lock(context, KRB5_LOCKMODE_EXCLUSIVE);
+    retval = lock_ulog(context, KRB5_LOCKMODE_EXCLUSIVE);
     if (retval)
         return retval;
 
     if (ulog->kdb_hmagic != KDB_ULOG_HDR_MAGIC && ulog->kdb_hmagic != 0) {
-        ulog_lock(context, KRB5_LOCKMODE_UNLOCK);
+        unlock_ulog(context);
         return KRB5_LOG_CORRUPT;
     }
 
     if (ulog->kdb_hmagic != KDB_ULOG_HDR_MAGIC) {
         reset_header(ulog);
         if (caller != FKPROPLOG)
-            ulog_sync_header(ulog);
-        ulog_lock(context, KRB5_LOCKMODE_UNLOCK);
+            sync_header(ulog);
+        unlock_ulog(context);
         return 0;
     }
 
     if (caller == FKPROPLOG || caller == FKPROPD) {
         /* kproplog and kpropd don't need to do anything else. */
-        ulog_lock(context, KRB5_LOCKMODE_UNLOCK);
+        unlock_ulog(context);
         return 0;
     }
 
@@ -551,7 +572,7 @@ ulog_map(krb5_context context, const char *logname, uint32_t ulogentries,
             (ulog->kdb_last_sno > ulog->kdb_num ||
              ulog->kdb_num > ulogentries)) {
             reset_header(ulog);
-            ulog_sync_header(ulog);
+            sync_header(ulog);
         }
 
         /* Expand ulog if we have specified a greater size. */
@@ -559,12 +580,12 @@ ulog_map(krb5_context context, const char *logname, uint32_t ulogentries,
             ulog_filesize += ulogentries * ulog->kdb_block;
 
             if (extend_file_to(ulogfd, ulog_filesize) < 0) {
-                ulog_lock(context, KRB5_LOCKMODE_UNLOCK);
+                unlock_ulog(context);
                 return errno;
             }
         }
     }
-    ulog_lock(context, KRB5_LOCKMODE_UNLOCK);
+    unlock_ulog(context);
 
     return 0;
 }
@@ -587,7 +608,7 @@ ulog_get_entries(krb5_context context, const kdb_last_t *last,
     INIT_ULOG(context);
     ulogentries = log_ctx->ulogentries;
 
-    retval = ulog_lock(context, KRB5_LOCKMODE_SHARED);
+    retval = lock_ulog(context, KRB5_LOCKMODE_SHARED);
     if (retval)
         return retval;
 
@@ -637,7 +658,7 @@ ulog_get_entries(krb5_context context, const kdb_last_t *last,
     ulog_handle->ret = UPDATE_OK;
 
 cleanup:
-    (void)ulog_lock(context, KRB5_LOCKMODE_UNLOCK);
+    unlock_ulog(context);
     return retval;
 }
 
@@ -658,9 +679,44 @@ ulog_get_sno_status(krb5_context context, const kdb_last_t *last)
 {
     update_status_t status;
 
-    if (ulog_lock(context, KRB5_LOCKMODE_SHARED) != 0)
+    if (lock_ulog(context, KRB5_LOCKMODE_SHARED) != 0)
         return UPDATE_ERROR;
     status = get_sno_status(context->kdblog_context, last);
-    (void)ulog_lock(context, KRB5_LOCKMODE_UNLOCK);
+    unlock_ulog(context);
     return status;
 }
+
+krb5_error_code
+ulog_get_last(krb5_context context, kdb_last_t *last_out)
+{
+    krb5_error_code ret;
+    kdb_log_context *log_ctx;
+    kdb_hlog_t *ulog;
+
+    INIT_ULOG(context);
+    ret = lock_ulog(context, KRB5_LOCKMODE_SHARED);
+    if (ret)
+        return ret;
+    last_out->last_sno = log_ctx->ulog->kdb_last_sno;
+    last_out->last_time = log_ctx->ulog->kdb_last_time;
+    unlock_ulog(context);
+    return 0;
+}
+
+krb5_error_code
+ulog_set_last(krb5_context context, const kdb_last_t *last)
+{
+    krb5_error_code ret;
+    kdb_log_context *log_ctx;
+    kdb_hlog_t *ulog;
+
+    INIT_ULOG(context);
+    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;
+    sync_header(ulog);
+    unlock_ulog(context);
+    return 0;
+}

diff --git a/src/lib/kdb/libkdb5.exports b/src/lib/kdb/libkdb5.exports
index 67d4336ef1fb8131af94426864cead1a4467f033..cb4c3df55be0e065f1ab3dd96a4a6107d50c1df3 100644 (file)
--- a/src/lib/kdb/libkdb5.exports
+++ b/src/lib/kdb/libkdb5.exports
@@ -90,11 +90,12 @@ ulog_init_header
 ulog_map
 ulog_set_role
 ulog_free_entries
-ulog_sync_header
 xdr_kdb_last_t
 xdr_kdb_incr_result_t
 xdr_kdb_fullresync_result_t
 ulog_get_entries
+ulog_get_last
 ulog_get_sno_status
 ulog_replay
+ulog_set_last
 xdr_kdb_incr_update_t

diff --git a/src/slave/kpropd.c b/src/slave/kpropd.c
index afeb53fa3b416a0a43900d6f0f840a423d96ca88..65fb3e84fca2d473db0d18e03b43fd969dc7c671 100644 (file)
--- a/src/slave/kpropd.c
+++ b/src/slave/kpropd.c
@@ -147,7 +147,7 @@ static int db_args_size = 0;
 static void parse_args(char **argv);
 static void do_standalone(void);
 static void doit(int fd);
-static krb5_error_code do_iprop(kdb_log_context *log_ctx);
+static krb5_error_code do_iprop(void);
 static void kerberos_authenticate(krb5_context context, int fd,
                                   krb5_principal *clientp, krb5_enctype *etype,
                                   struct sockaddr_storage *my_sin);
@@ -321,7 +321,7 @@ main(int argc, char **argv)
         /* NOTREACHED */
         break;
     default:
-        retval = do_iprop(log_ctx);
+        retval = do_iprop();
         /* do_iprop() can return due to failures and runonce. */
         kill(fullprop_child, SIGHUP);
         wait(NULL);
@@ -606,7 +606,7 @@ full_resync(CLIENT *clnt)
  * Returns non-zero on failure due to errors.
  */
 krb5_error_code
-do_iprop(kdb_log_context *log_ctx)
+do_iprop()
 {
     kadm5_ret_t retval;
     krb5_principal iprop_svc_principal;
@@ -621,13 +621,10 @@ do_iprop(kdb_log_context *log_ctx)
     kdb_last_t mylast;
     kdb_fullresync_result_t *full_ret;
     kadm5_iprop_handle_t handle;
-    kdb_hlog_t *ulog;
 
     if (debug)
         fprintf(stderr, _("Incremental propagation enabled\n"));
 
-    ulog = log_ctx->ulog;
-
     pollin = params.iprop_poll_time;
     if (pollin == 0)
         pollin = 10;
@@ -771,8 +768,11 @@ reinit:
          * Get the most recent ulog entry sno + ts, which
          * we package in the request to the master KDC
          */
-        mylast.last_sno = ulog->kdb_last_sno;
-        mylast.last_time = ulog->kdb_last_time;
+        retval = ulog_get_last(kpropd_context, &mylast);
+        if (retval) {
+            com_err(progname, retval, _("reading update log header"));
+            goto done;
+        }
 
         /*
          * Loop continuously on an iprop_get_updates_1(),

diff --git a/src/slave/kproplog.c b/src/slave/kproplog.c
index b0512795139174b0221148a41e9fc33abadb2848..853aa0633fe25829411ffabc35003aa05f5b82e7 100644 (file)
--- a/src/slave/kproplog.c
+++ b/src/slave/kproplog.c
@@ -480,7 +480,11 @@ main(int argc, char **argv)
     }
 
     if (reset) {
-        ulog_init_header(context);
+        if (ulog_init_header(context) != 0) {
+            fprintf(stderr, _("Couldn't reinitialize ulog file %s\n\n"),
+                    params.iprop_logfile);
+            exit(1);
+        }
         printf(_("Reinitialized the ulog.\n"));
         exit(0);
     }