diff --git a/lib/kadm5/admin.h b/lib/kadm5/admin.h index a556efd22..3b80158ce 100644 --- a/lib/kadm5/admin.h +++ b/lib/kadm5/admin.h @@ -53,6 +53,17 @@ #define LOG_VERSION_FIRST 1 #define LOG_VERSION_UBER 0 +#define LOG_HEADER_SZ ((off_t)(sizeof(uint32_t) * 4)) +#define LOG_TRAILER_SZ ((off_t)(sizeof(uint32_t) * 2)) +#define LOG_WRAPPER_SZ ((off_t)(LOG_HEADER_SZ + LOG_TRAILER_SZ)) +#define LOG_UBER_LEN ((off_t)(sizeof(uint64_t) + sizeof(uint32_t) * 2)) +#define LOG_UBER_SZ ((off_t)(LOG_WRAPPER_SZ + LOG_UBER_LEN)) + +struct kadm5_log_snap { + char bytes; + char buf[LOG_UBER_SZ + LOG_HEADER_SZ]; +}; + #include #define KRB5_KDB_DISALLOW_POSTDATED 0x00000001 diff --git a/lib/kadm5/ipropd_master.c b/lib/kadm5/ipropd_master.c index 6914c43cd..70bb9aa1e 100644 --- a/lib/kadm5/ipropd_master.c +++ b/lib/kadm5/ipropd_master.c @@ -132,7 +132,6 @@ struct slave { krb5_auth_context ac; uint32_t version; uint32_t version_tstamp; - uint32_t version_ack; time_t seen; unsigned long flags; #define SLAVE_F_DEAD 0x1 @@ -376,7 +375,6 @@ add_slave (krb5_context context, krb5_keytab keytab, slave **root, krb5_warnx (context, "connection from %s", s->name); s->version = 0; - s->version_ack = 0; s->flags = 0; slave_seen(s); s->next = *root; @@ -862,8 +860,11 @@ diffready(krb5_context context, slave *s) * Don't send any diffs until slave has sent an I_HAVE telling us the * initial version number! */ - if ((s->flags & SLAVE_F_READY) == 0) + if ((s->flags & SLAVE_F_READY) == 0) { + if (verbose) + krb5_warnx(context, "not sending diffs to not-ready slave %s", s->name); return 0; + } if (s->flags & SLAVE_F_DEAD) { if (verbose) @@ -872,8 +873,11 @@ diffready(krb5_context context, slave *s) } /* Write any remainder of previous write, if we can. */ - if (send_tail(context, s) != 0) + if (send_tail(context, s) != 0 && have_tail(s)) { + if (verbose) + krb5_warnx(context, "not sending diffs to busy slave %s", s->name); return 0; + } return 1; } @@ -881,10 +885,6 @@ diffready(krb5_context context, slave *s) static int nodiffs(krb5_context context, slave *s, uint32_t current_version) { - krb5_storage *sp; - krb5_data data; - int ret; - if (s->version < current_version) return 0; @@ -897,6 +897,20 @@ nodiffs(krb5_context context, slave *s, uint32_t current_version) if (verbose) krb5_warnx(context, "slave %s version %ld already sent", s->name, (long)s->version); + return 1; +} + +static void +send_you_have_last_version(krb5_context context, slave *s) +{ + krb5_storage *sp; + krb5_data data; + int ret; + + if (verbose) + krb5_warnx(context, "slave %s version %ld is latest", s->name, + (long)s->version); + sp = krb5_storage_emem(); if (sp == NULL) krb5_errx(context, IPROPD_RESTART, "krb5_storage_from_mem"); @@ -909,19 +923,17 @@ nodiffs(krb5_context context, slave *s, uint32_t current_version) krb5_storage_free(sp); if (ret == 0) { ret = mk_priv_tail(context, s, &data); + if (ret) + krb5_err(context, IPROPD_RESTART, ret, + "sending you have last version"); krb5_data_free(&data); } if (ret == 0) send_tail(context, s); - - return 1; } -/* - * Lock the log and return initial version and timestamp - */ static int -get_first(kadm5_server_context *server_context, int log_fd, +get_first(kadm5_server_context *server_context, uint32_t *initial_verp, uint32_t *initial_timep) { krb5_context context = server_context->context; @@ -931,19 +943,14 @@ get_first(kadm5_server_context *server_context, int log_fd, * We don't want to perform tight retry loops on log access errors, so on * error mark the slave dead. The slave reconnect after a delay... */ - if (flock(log_fd, LOCK_SH) == -1) { - krb5_warn(context, errno, "could not obtain shared lock on log file"); - return -1; - } - ret = kadm5_log_get_version_fd(server_context, log_fd, LOG_VERSION_FIRST, + ret = kadm5_log_get_version_fd(server_context, -1, LOG_VERSION_FIRST, initial_verp, initial_timep); - if (ret == HEIM_ERR_EOF) - ret = kadm5_log_get_version_fd(server_context, log_fd, + if (ret == HEIM_ERR_EOF || ret == KADM5_LOG_EMPTY) + ret = kadm5_log_get_version_fd(server_context, -1, LOG_VERSION_UBER, initial_verp, initial_timep); if (ret != 0) { - flock(log_fd, LOCK_UN); krb5_warn(context, ret, "could not read initial log entry"); return -1; } @@ -954,17 +961,20 @@ get_first(kadm5_server_context *server_context, int log_fd, /*- * Find the left end of the diffs in the log we want to send. * - * - On success, return a positive offset to the first new entry, retaining - * a read lock on the log file. - * - On error, return a negative offset, with the lock released. + * - On success, return a positive offset to the first new entry. + * - On error, return a negative offset. * - If we simply find no successor entry in the log, return zero * with the lock released, which indicates that fallback to send_complete() * is needed. + * + * The caller must use kadm5_log_snapshot()/kadm5_log_snapshot_verify() to + * ensure that the data read here is consistent because there have been only + * append writes and/or there have been no log rotations. */ static off_t get_left(kadm5_server_context *server_context, slave *s, krb5_storage *sp, - int log_fd, uint32_t current_version, - uint32_t *initial_verp, uint32_t *initial_timep) + uint32_t current_version, uint32_t *initial_verp, + uint32_t *initial_timep) { krb5_context context = server_context->context; off_t pos; @@ -974,17 +984,13 @@ get_left(kadm5_server_context *server_context, slave *s, krb5_storage *sp, for (;;) { uint32_t ver = s->version; - /* This acquires a read lock on success */ - ret = get_first(server_context, log_fd, - initial_verp, initial_timep); + ret = get_first(server_context, initial_verp, initial_timep); if (ret != 0) return -1; /* When the slave version is out of range, send the whole database. */ - if (ver == 0 || ver < *initial_verp || ver > current_version) { - flock(log_fd, LOCK_UN); + if (ver == 0 || ver + 1 < *initial_verp || ver > current_version) return 0; - } /* Avoid seeking past the last committed record */ if (kadm5_log_goto_end(server_context, sp) != 0 || @@ -1016,13 +1022,12 @@ get_left(kadm5_server_context *server_context, slave *s, krb5_storage *sp, goto err; /* - * Drop the lock and try to find the left entry by seeking backward - * from the end of the end of the log. If we succeed, re-acquire the - * lock, update "next_diff", and retry the fast-path. + * Slow path: seek backwards, entry by entry, from the end. + * + * Try to find the left entry by seeking backward from the end of the + * end of the log. If we succeed, update "next_diff", and retry the + * fast-path. */ - flock(log_fd, LOCK_UN); - - /* Slow path: seek backwards, entry by entry, from the end */ for (;;) { enum kadm_ops op; uint32_t len; @@ -1038,7 +1043,7 @@ get_left(kadm5_server_context *server_context, slave *s, krb5_storage *sp, /* * We don't expect to reach the slave's version, unless the log - * has been modified after we released the lock. + * has been rotated. */ if (ver == s->version) { krb5_warnx(context, "iprop log truncated while sending diffs " @@ -1060,33 +1065,28 @@ get_left(kadm5_server_context *server_context, slave *s, krb5_storage *sp, /* * If we loop then we're hoping to hit the fast path so we can return a - * non-zero, positive left offset with the lock held. + * non-zero, positive left offset. * * We just updated the fast path pre-conditions, so unless a log - * truncation event happens between the point where we dropped the lock - * and the point where we rearcuire it above, we will hit the fast - * path. + * truncation event happens again, we will hit the fast path. */ } err: - flock(log_fd, LOCK_UN); return -1; } static off_t -get_right(krb5_context context, int log_fd, krb5_storage *sp, - int lastver, slave *s, off_t left, uint32_t *verp) +get_right(krb5_context context, krb5_storage *sp, int lastver, slave *s, + off_t left, uint32_t *verp) { int ret = 0; int i = 0; uint32_t ver = s->version; off_t right = krb5_storage_seek(sp, left, SEEK_SET); - if (right <= 0) { - flock(log_fd, LOCK_UN); + if (right <= 0) return -1; - } /* The "lastver" bound should preclude us reaching EOF */ for (; ret == 0 && i < SEND_DIFFS_MAX_RECORDS && ver < lastver; ++i) { @@ -1101,18 +1101,23 @@ get_right(krb5_context context, int log_fd, krb5_storage *sp, right = krb5_storage_seek(sp, 0, SEEK_CUR); else right = -1; - if (right <= 0) { - flock(log_fd, LOCK_UN); + if (right <= 0) return -1; - } *verp = ver; return right; } -static void -send_diffs(kadm5_server_context *server_context, slave *s, int log_fd, +/* + * This function _must_ send something to the client unless it's dead, and if + * dead it must mark it so (and so close the connection). It is an error to + * return from this function without having done so _unless_ the client is + * either dead or not ready. + */ +static kadm5_ret_t +send_diffs(kadm5_server_context *server_context, slave *s, const char *database, uint32_t current_version) { + struct kadm5_log_snap snap; krb5_context context = server_context->context; krb5_storage *sp; uint32_t initial_version; @@ -1122,84 +1127,122 @@ send_diffs(kadm5_server_context *server_context, slave *s, int log_fd, off_t right = 0; krb5_ssize_t bytes; krb5_data data; - int ret = 0; + kadm5_ret_t ret = 0; - if (!diffready(context, s) || nodiffs(context, s, current_version)) - return; + /* + * diffready() can send part of an extant buffer, and does nothing if the + * client is either dead or not ready. + */ + if (!diffready(context, s)) + return 0; + + /* From this point onwards we cannot return without having sent anything */ + + if (nodiffs(context, s, current_version)) { + if (verbose) + krb5_warnx(context, "not sending diffs to up-to-date slave %s (no diffs)", s->name); + + send_you_have_last_version(context, s); + return 0; + } if (verbose) krb5_warnx(context, "sending diffs to live-seeming slave %s", s->name); - sp = krb5_storage_from_fd(log_fd); + ret = kadm5_log_snapshot(server_context, &snap); + if (ret) { + /* + * Here ret would be KADM5_LOG_CORRUPT. What can we do? + */ + send_you_have_last_version(context, s); + return 0; + } + + sp = krb5_storage_from_fd(server_context->log_context.log_fd); if (sp == NULL) krb5_err(context, IPROPD_RESTART_SLOW, ENOMEM, "send_diffs: out of memory"); - left = get_left(server_context, s, sp, log_fd, current_version, + left = get_left(server_context, s, sp, current_version, &initial_version, &initial_tstamp); if (left < 0) { + /* Some sort of error; fallback on full prop */ krb5_storage_free(sp); - slave_dead(context, s); - return; + if (verbose) + krb5_warnx(context, "sending full prop to slave %s " + "(could not find offset for incremental)", s->name); + send_complete(context, s, database, current_version, + initial_version, initial_tstamp); + return 0; } if (left == 0) { /* Slave's version is not in the log, fall back on send_complete() */ krb5_storage_free(sp); + if (verbose) + krb5_warnx(context, "sending full prop to slave %s " + "(their version is too old)", s->name); send_complete(context, s, database, current_version, initial_version, initial_tstamp); - return; + return 0; } - /* We still hold the read lock, if right > 0 */ - right = get_right(server_context->context, log_fd, sp, current_version, + right = get_right(server_context->context, sp, current_version, s, left, &ver); if (right == left) { - flock(log_fd, LOCK_UN); + /* Shouldn't happen */ krb5_storage_free(sp); - return; + if (verbose) + krb5_warnx(context, "not sending diffs to up-to-date slave %s (weird)", s->name); + send_you_have_last_version(context, s); + return 0; } if (right < left) { assert(right < 0); krb5_storage_free(sp); slave_dead(context, s); - return; + return 0; } if (krb5_storage_seek(sp, left, SEEK_SET) != left) { - ret = errno ? errno : EIO; - flock(log_fd, LOCK_UN); - krb5_warn(context, ret, "send_diffs: krb5_storage_seek"); + krb5_warn(context, errno ? errno : EIO, "send_diffs: krb5_storage_seek"); krb5_storage_free(sp); slave_dead(context, s); - return; + return 0; } ret = krb5_data_alloc(&data, right - left + 4); - if (ret) { - flock(log_fd, LOCK_UN); - krb5_warn(context, ret, "send_diffs: krb5_data_alloc"); - krb5_storage_free(sp); - slave_dead(context, s); - return; - } + if (ret) + krb5_err(context, IPROPD_RESTART_SLOW, ENOMEM, "out of memory"); bytes = krb5_storage_read(sp, (char *)data.data + 4, data.length - 4); - flock(log_fd, LOCK_UN); krb5_storage_free(sp); - if (bytes != data.length - 4) - krb5_errx(context, IPROPD_RESTART, "locked log truncated???"); + if (bytes != data.length - 4) { + krb5_warnx(context, "send_diffs: log rotated"); + return KADM5_LOG_SNAPSHOT_INVALID; + } + + ret = kadm5_log_snapshot_verify(server_context, &snap); + if (ret) { + krb5_data_free(&data); + if (ret == KADM5_LOG_SNAPSHOT_INVALID) { + krb5_warnx(context, "send_diffs: log rotated"); + return ret; + } + krb5_err(context, IPROPD_RESTART_SLOW, ENOMEM, "out of memory"); + } sp = krb5_storage_from_data(&data); - if (sp == NULL) { + if (sp == NULL) krb5_err(context, IPROPD_RESTART_SLOW, ENOMEM, "out of memory"); - return; - } ret = krb5_store_uint32(sp, FOR_YOU); krb5_storage_free(sp); - if (ret == 0) + if (ret == 0) { ret = mk_priv_tail(context, s, &data); + if (ret == ENOMEM) + krb5_err(context, IPROPD_RESTART_SLOW, ENOMEM, "out of memory"); + } krb5_data_free(&data); if (ret == 0) { /* Save the fast-path continuation */ @@ -1221,10 +1264,10 @@ send_diffs(kadm5_server_context *server_context, slave *s, int log_fd, krb5_warn(context, ret, "send_diffs: making or sending " "KRB-PRIV message"); slave_dead(context, s); - return; + return ret; } slave_seen(s); - return; + return 0; } /* Sensible bound on slave message size */ @@ -1299,7 +1342,7 @@ read_msg(krb5_context context, slave *s, krb5_data *out) } static int -process_msg(kadm5_server_context *server_context, slave *s, int log_fd, +process_msg(kadm5_server_context *server_context, slave *s, const char *database, uint32_t current_version) { krb5_context context = server_context->context; @@ -1307,6 +1350,7 @@ process_msg(kadm5_server_context *server_context, slave *s, int log_fd, krb5_data out; krb5_storage *sp; uint32_t tmp; + int tries = 3; ret = read_msg(context, s, &out); if (ret) { @@ -1372,9 +1416,9 @@ process_msg(kadm5_server_context *server_context, slave *s, int log_fd, krb5_warnx(context, "slave %s ready for updates from version %u", s->name, tmp); } - if ((s->version_ack = tmp) < s->version) - break; - send_diffs(server_context, s, log_fd, database, current_version); + do { + ret = send_diffs(server_context, s, database, current_version); + } while (ret == KADM5_LOG_SNAPSHOT_INVALID && tries--); break; case I_AM_HERE : if (verbose) @@ -1490,7 +1534,7 @@ write_stats(krb5_context context, slave *slaves, uint32_t current_version) } else rtbl_add_column_entry(tbl, SLAVE_ADDRESS, ""); - snprintf(str, sizeof(str), "%u", (unsigned)slaves->version_ack); + snprintf(str, sizeof(str), "%u", (unsigned)slaves->version); rtbl_add_column_entry(tbl, SLAVE_VERSION, str); if (slaves->flags & SLAVE_F_DEAD) @@ -1571,7 +1615,6 @@ main(int argc, char **argv) kadm5_server_context *server_context; kadm5_config_params conf; krb5_socket_t signal_fd, listen_fd; - int log_fd; slave *slaves = NULL; uint32_t current_version = 0, old_version = 0; krb5_keytab keytab; @@ -1675,21 +1718,16 @@ main(int argc, char **argv) server_context = (kadm5_server_context *)kadm_handle; - log_fd = open (server_context->log_context.log_file, O_RDONLY, 0); - if (log_fd < 0) - krb5_err (context, 1, errno, "open %s", - server_context->log_context.log_file); + ret = kadm5_log_init_nolock(server_context); + if (ret) + krb5_err(context, 1, ret, "Could not open iprop log file"); - if (fstat(log_fd, &st) == -1) + if (fstat(server_context->log_context.log_fd, &st) == -1) krb5_err(context, 1, errno, "stat %s", server_context->log_context.log_file); - if (flock(log_fd, LOCK_SH) == -1) - krb5_err(context, 1, errno, "shared flock %s", - server_context->log_context.log_file); - kadm5_log_get_version_fd(server_context, log_fd, LOG_VERSION_LAST, + kadm5_log_get_version_fd(server_context, -1, LOG_VERSION_LAST, ¤t_version, NULL); - flock(log_fd, LOCK_UN); signal_fd = make_signal_socket (context); listen_fd = make_listen_socket (context, port_str); @@ -1706,7 +1744,7 @@ main(int argc, char **argv) int max_fd = 0; struct timeval to = {30, 0}; uint32_t vers; - struct stat st2;; + struct stat st2; #ifndef NO_LIMIT_FD_SETSIZE if (signal_fd >= FD_SETSIZE || listen_fd >= FD_SETSIZE || @@ -1748,36 +1786,24 @@ main(int argc, char **argv) } if (st2.st_dev != st.st_dev || st2.st_ino != st.st_ino) { - (void) close(log_fd); + kadm5_log_end(server_context); - log_fd = open(server_context->log_context.log_file, O_RDONLY, 0); - if (log_fd < 0) - krb5_err(context, IPROPD_RESTART_SLOW, errno, "open %s", - server_context->log_context.log_file); + ret = kadm5_log_init_nolock(server_context); + if (ret) + krb5_err(context, IPROPD_RESTART_SLOW, ret, + "Could not re-open iprop log file"); - if (fstat(log_fd, &st) == -1) + if (fstat(server_context->log_context.log_fd, &st) == -1) krb5_err(context, IPROPD_RESTART_SLOW, errno, "stat %s", server_context->log_context.log_file); - if (flock(log_fd, LOCK_SH) == -1) - krb5_err(context, IPROPD_RESTART, errno, "shared flock %s", - server_context->log_context.log_file); - kadm5_log_get_version_fd(server_context, log_fd, LOG_VERSION_LAST, + kadm5_log_get_version_fd(server_context, -1, LOG_VERSION_LAST, ¤t_version, NULL); - flock(log_fd, LOCK_UN); } if (ret == 0) { - /* Recover from failed transactions */ - if (kadm5_log_init_nb(server_context) == 0) - kadm5_log_end(server_context); - - if (flock(log_fd, LOCK_SH) == -1) - krb5_err(context, IPROPD_RESTART, errno, - "could not lock log file"); - kadm5_log_get_version_fd(server_context, log_fd, LOG_VERSION_LAST, + kadm5_log_get_version_fd(server_context, -1, LOG_VERSION_LAST, ¤t_version, NULL); - flock(log_fd, LOCK_UN); if (current_version > old_version) { if (verbose) @@ -1786,10 +1812,14 @@ main(int argc, char **argv) (unsigned long)old_version, (unsigned long)current_version); for (p = slaves; p != NULL; p = p->next) { + int tries = 3; + if (p->flags & SLAVE_F_DEAD) continue; - send_diffs(server_context, p, log_fd, database, - current_version); + do { + ret = send_diffs(server_context, p, database, + current_version); + } while (ret == KADM5_LOG_SNAPSHOT_INVALID && tries--); } old_version = current_version; } @@ -1816,12 +1846,8 @@ main(int argc, char **argv) --ret; assert(ret >= 0); old_version = current_version; - if (flock(log_fd, LOCK_SH) == -1) - krb5_err(context, IPROPD_RESTART, errno, "shared flock %s", - server_context->log_context.log_file); - kadm5_log_get_version_fd(server_context, log_fd, LOG_VERSION_LAST, + kadm5_log_get_version_fd(server_context, -1, LOG_VERSION_LAST, ¤t_version, NULL); - flock(log_fd, LOCK_UN); if (current_version != old_version) { /* * If current_version < old_version then the log got @@ -1841,10 +1867,14 @@ main(int argc, char **argv) (unsigned long)old_version, (unsigned long)current_version); for (p = slaves; p != NULL; p = p->next) { + int tries = 3; + if (p->flags & SLAVE_F_DEAD) continue; - send_diffs(server_context, p, log_fd, database, - current_version); + do { + ret = send_diffs(server_context, p, database, + current_version); + } while (ret == EAGAIN && tries--); } } else { if (verbose) @@ -1859,8 +1889,12 @@ main(int argc, char **argv) FD_ISSET(p->fd, &writeset) && ((have_tail(p) && send_tail(context, p) == 0) || (!have_tail(p) && more_diffs(p)))) { - send_diffs(server_context, p, log_fd, database, - current_version); + int tries = 3; + + do { + ret = send_diffs(server_context, p, database, + current_version); + } while (ret == KADM5_LOG_SNAPSHOT_INVALID && tries--); } } @@ -1870,10 +1904,12 @@ main(int argc, char **argv) if (ret && FD_ISSET(p->fd, &readset)) { --ret; assert(ret >= 0); - ret = process_msg(server_context, p, log_fd, database, + ret = process_msg(server_context, p, database, current_version); - if (ret && ret != EWOULDBLOCK) + if (ret && ret != EWOULDBLOCK) { + krb5_warn(context, ret, "process_msg()"); slave_dead(context, p); + } } else if (slave_gone_p (p)) slave_dead(context, p); else if (slave_missing_p (p)) diff --git a/lib/kadm5/ipropd_slave.c b/lib/kadm5/ipropd_slave.c index 38a989eef..07846d34e 100644 --- a/lib/kadm5/ipropd_slave.c +++ b/lib/kadm5/ipropd_slave.c @@ -355,11 +355,6 @@ receive_loop(krb5_context context, if (verbose) krb5_warnx(context, "receiving diffs"); - ret = kadm5_log_exclusivelock(server_context); - if (ret) - krb5_err(context, IPROPD_RESTART, ret, - "Failed to lock iprop log for writes"); - /* * Seek to the first entry in the message from the master that is * past the current version of the local database. @@ -477,9 +472,6 @@ receive(krb5_context context, if (ret) krb5_err(context, IPROPD_RESTART_SLOW, ret, "db->close"); - (void) kadm5_log_sharedlock(server_context); - if (verbose) - krb5_warnx(context, "downgraded iprop log lock to shared"); kadm5_log_signal_master(server_context); if (verbose) krb5_warnx(context, "signaled master for hierarchical iprop"); @@ -531,9 +523,6 @@ reinit_log(krb5_context context, ret = kadm5_log_reinit(server_context, vno); if (ret) krb5_err(context, IPROPD_RESTART_SLOW, ret, "kadm5_log_reinit"); - (void) kadm5_log_sharedlock(server_context); - if (verbose) - krb5_warnx(context, "downgraded iprop log lock to shared"); } @@ -553,10 +542,6 @@ receive_everything(krb5_context context, int fd, krb5_warnx(context, "receive complete database"); - ret = kadm5_log_exclusivelock(server_context); - if (ret) - krb5_err(context, IPROPD_RESTART, ret, - "Failed to lock iprop log for writes"); if (server_context->db->hdb_method_name) { ret = asprintf(&dbname, "%.*s:%s-NEW", (int) strlen(server_context->db->hdb_method_name) - 1, @@ -900,9 +885,6 @@ main(int argc, char **argv) ret = kadm5_log_init(server_context); if (ret) krb5_err(context, 1, ret, "kadm5_log_init"); - (void) kadm5_log_sharedlock(server_context); - if (verbose) - krb5_warnx(context, "downgraded iprop log lock to shared"); ret = server_context->db->hdb_close(context, server_context->db); if (ret) @@ -1091,9 +1073,6 @@ main(int argc, char **argv) krb5_err(context, IPROPD_RESTART, ret, "kadm5_log_init while " "handling a message from the master"); } - (void) kadm5_log_sharedlock(server_context); - if (verbose) - krb5_warnx(context, "downgraded iprop log lock to shared"); ret = server_context->db->hdb_close (context, server_context->db); if (ret) @@ -1125,7 +1104,6 @@ main(int argc, char **argv) krb5_warnx(context, "master sent us a full dump"); ret = receive_everything(context, master_fd, server_context, auth_context); - (void) kadm5_log_sharedlock(server_context); if (ret == 0) { ret = ihave(context, auth_context, master_fd, server_context->log_context.version); @@ -1134,8 +1112,6 @@ main(int argc, char **argv) connected = FALSE; else is_up_to_date(context, status_file, server_context); - if (verbose) - krb5_warnx(context, "downgraded iprop log lock to shared"); kadm5_log_signal_master(server_context); if (verbose) krb5_warnx(context, "signaled master for hierarchical iprop"); @@ -1152,6 +1128,7 @@ main(int argc, char **argv) * * So we don't ihave() here. */ + is_up_to_date(context, status_file, server_context); send_im_here(context, master_fd, auth_context); break; case YOU_HAVE_LAST_VERSION: @@ -1175,7 +1152,7 @@ main(int argc, char **argv) slave_status(context, status_file, "disconnected from master"); retry: if (connected == FALSE) - krb5_warnx (context, "disconnected for server"); + krb5_warnx (context, "disconnected from server"); if (exit_flag) krb5_warnx (context, "got an exit signal"); diff --git a/lib/kadm5/kadm5_err.et b/lib/kadm5/kadm5_err.et index e9a3a0b86..a863668e9 100644 --- a/lib/kadm5/kadm5_err.et +++ b/lib/kadm5/kadm5_err.et @@ -73,6 +73,8 @@ error_code OLD_SERVER_HOOK_VERSION, "KADM5 server hook is too old for this versi error_code NEW_SERVER_HOOK_VERSION, "KADM5 server hook is too new for this version of Heimdal" error_code READ_ONLY, "Database is read-only; try primary server" error_code PASS_Q_GENERIC, "Unspecified password quality failure" +error_code LOG_SNAPSHOT_INVALID, "Incremental propagation log rotated; restart operation" +error_code LOG_EMPTY, "Incremental propagation log is empty" # MIT has: diff --git a/lib/kadm5/kadm5_locl.h b/lib/kadm5/kadm5_locl.h index cb0b1b4cb..ba95ecf1a 100644 --- a/lib/kadm5/kadm5_locl.h +++ b/lib/kadm5/kadm5_locl.h @@ -86,6 +86,7 @@ #include #include #include + #include "private.h" #endif /* __KADM5_LOCL_H__ */ diff --git a/lib/kadm5/libkadm5srv-exports.def b/lib/kadm5/libkadm5srv-exports.def index 56366ae20..89dd38f7d 100644 --- a/lib/kadm5/libkadm5srv-exports.def +++ b/lib/kadm5/libkadm5srv-exports.def @@ -85,6 +85,8 @@ EXPORTS kadm5_log_init_sharedlock kadm5_log_next kadm5_log_nop + kadm5_log_snapshot + kadm5_log_snapshot_verify kadm5_log_truncate kadm5_log_modify _kadm5_acl_check_permission diff --git a/lib/kadm5/log.c b/lib/kadm5/log.c index e85d9aa1a..468123388 100644 --- a/lib/kadm5/log.c +++ b/lib/kadm5/log.c @@ -174,12 +174,6 @@ RCSID("$Id$"); * will deadlock with ipropd-slave -- don't do that. */ -#define LOG_HEADER_SZ ((off_t)(sizeof(uint32_t) * 4)) -#define LOG_TRAILER_SZ ((off_t)(sizeof(uint32_t) * 2)) -#define LOG_WRAPPER_SZ ((off_t)(LOG_HEADER_SZ + LOG_TRAILER_SZ)) -#define LOG_UBER_LEN ((off_t)(sizeof(uint64_t) + sizeof(uint32_t) * 2)) -#define LOG_UBER_SZ ((off_t)(LOG_WRAPPER_SZ + LOG_UBER_LEN)) - #define LOG_NOPEEK 0 #define LOG_DOPEEK 1 @@ -490,23 +484,53 @@ kadm5_log_get_version_fd(kadm5_server_context *server_context, int fd, { kadm5_ret_t ret = 0; krb5_storage *sp; - enum kadm_ops op = kadm_get; - uint32_t len = 0; uint32_t tmp; - if (fd == -1) - return 0; /* /dev/null */ - if (tstamp == NULL) tstamp = &tmp; *ver = 0; *tstamp = 0; + if (fd == -1) + fd = server_context->log_context.log_fd; + sp = krb5_storage_from_fd(fd); if (sp == NULL) return errno ? errno : ENOMEM; + ret = kadm5_log_get_version_sp(server_context, sp, which, ver, tstamp); + krb5_storage_free(sp); + return ret; +} + +kadm5_ret_t +kadm5_log_get_version_sp(kadm5_server_context *server_context, krb5_storage *sp, + int which, uint32_t *ver, uint32_t *tstamp) +{ + struct kadm5_log_snap snap; + kadm5_ret_t ret = 0; + enum kadm_ops op = kadm_get; + uint32_t len = 0; + uint32_t tmp; + + /* + * If we're operating lock-less-ly then get a snapshot of the log so we can + * validate that what we read here is correct once we're done reading it. + */ + memset(&snap, 0, sizeof(snap)); + if (server_context->log_context.lock_mode == LOCK_UN) { + ret = kadm5_log_snapshot(server_context, &snap); + if (ret) + return ret; + } + + if (tstamp == NULL) + tstamp = &tmp; + + *ver = 0; + *tstamp = 0; + switch (which) { case LOG_VERSION_LAST: ret = kadm5_log_goto_end(server_context, sp); @@ -531,10 +555,92 @@ kadm5_log_get_version_fd(kadm5_server_context *server_context, int fd, break; } - krb5_storage_free(sp); + if (ret == 0 && server_context->log_context.lock_mode == LOCK_UN) + /* Validate the snapshot when operating lock-less-ly */ + return kadm5_log_snapshot_verify(server_context, &snap); return ret; } +/* + * For lock-less reading of the log first get a snapshot, then read, then + * verify the snapshot before using the data read. If snapshot verification + * fails, start over. + * + * This will be used in ipropd-master and iprop-log to avoid needing a lock on + * the iprop log. For example, when a client says I_HAVE $ver then the server + * gets a snapshot, finds the offset to $ver and the offset to the end of the + * log, reads all that into memory, then the server veerifies the snapshot, and + * finally it sends the data to client, but if the snapshot verification fails + * then the server starts over the process of finding the offset to $ver. + * + * The way this works is that as long as the log is not rotated and truncated, + * then we can expect the header of the first record after the uber-record to + * remain the same. + */ +kadm5_ret_t +kadm5_log_snapshot(kadm5_server_context *server_context, + struct kadm5_log_snap *snap) +{ + ssize_t bytes; + + assert(sizeof(snap->buf) < CHAR_MAX); + snap->bytes = 0; + + bytes = pread(server_context->log_context.log_fd, + snap->buf, sizeof(snap->buf), 0); + if (bytes < 0) + return errno; + if (bytes < LOG_UBER_SZ) + return KADM5_LOG_CORRUPT; + if (bytes < sizeof(snap->buf)) + bytes = LOG_UBER_SZ; + + snap->bytes = bytes; + return 0; +} + +/* + * kadm5_log_snapshot_verify() checks that the iprop log has not been rotated + * since the given `snap` snapshot. Returns -1 if the log has been rotated. + */ +kadm5_ret_t +kadm5_log_snapshot_verify(kadm5_server_context *server_context, + struct kadm5_log_snap *snap) +{ + struct kadm5_log_snap v; + kadm5_ret_t ret; + + assert(sizeof(snap->buf) < CHAR_MAX); + if (snap->bytes < LOG_UBER_SZ) + return KADM5_LOG_SNAPSHOT_INVALID; + + ret = kadm5_log_snapshot(server_context, &v); + if (ret) + return ret; + + if (v.bytes < LOG_UBER_SZ) + return KADM5_LOG_CORRUPT; + + /* The two snapshots are equal -> no log rotation, no log change at all */ + if (snap->bytes == v.bytes && memcmp(snap->buf, v.buf, v.bytes) == 0) + return 0; + + /* + * Both snapshots capture the first record's header past the uber record? + * Check that that first record's header is the same for both. + */ + if (snap->bytes == v.bytes && v.bytes == sizeof(v.buf) && + memcmp(snap->buf + LOG_UBER_SZ, v.buf + LOG_UBER_SZ, + LOG_HEADER_SZ) == 0) + return 0; /* No log rotation, but the log did change */ + + /* + * Log rotated, or we don't have any log entries but the uber record + * changed. + */ + return KADM5_LOG_SNAPSHOT_INVALID; +} + /* Get the version of the last confirmed entry in the log */ kadm5_ret_t kadm5_log_get_version(kadm5_server_context *server_context, uint32_t *ver) @@ -2133,7 +2239,7 @@ kadm5_log_goto_first(kadm5_server_context *server_context, krb5_storage *sp) if (ret) return ret; if (op == kadm_nop && len == LOG_UBER_LEN && seek_next(sp) == -1) - return KADM5_LOG_CORRUPT; + return KADM5_LOG_EMPTY; return 0; } @@ -2503,6 +2609,13 @@ load_entries(kadm5_server_context *context, krb5_data *p, /* * Truncate the log, retaining at most `keep' entries and at most `maxbytes'. * If `maxbytes' is zero, keep at most the default log size limit. + * + * I.e., rotate the log, except we don't rename a new log into place. + * + * Ensures that the log will be smaller than prior to truncation. This is + * important as it ensures that the log snapshot approach used by ipropd-master + * to read the log lock-less-ly will work. See also kadm5_log_snapshot() and + * kadm5_log_snapshot_verify(). */ kadm5_ret_t kadm5_log_truncate(kadm5_server_context *context, size_t keep, size_t maxbytes) @@ -2514,7 +2627,10 @@ kadm5_log_truncate(kadm5_server_context *context, size_t keep, size_t maxbytes) krb5_storage *sp; ssize_t bytes; uint64_t sz; - off_t off; + off_t off, fsz; + + if ((fsz = lseek(context->log_context.log_fd, 0, SEEK_END)) < 0) + return errno; if (maxbytes == 0) maxbytes = get_max_log_size(context->context); @@ -2549,6 +2665,50 @@ kadm5_log_truncate(kadm5_server_context *context, size_t keep, size_t maxbytes) return EOVERFLOW; /* caller should ask for fewer entries */ } + /* Ensure that the iprop log will be smaller, or defer truncation */ + if (sz >= fsz) { + uint32_t skip; + + krb5_data_free(&entries); + + if (first > last) + first = 1; + + skip = (last - first) / 2; + + if (skip < 2) { + /* + * There must be an entry that is just large enough, or larger, + * that it alone causes the log to exceed the log size + * limit. + */ + krb5_warnx(context->context, + "Unable to truncate log due to very large record; " + "deferring truncation"); + return 0; + } + first += (last - first) / 2; + ret = load_entries(context, &entries, last - first, maxbytes, &first, &last); + if (ret) + return ret; + + sz = LOG_UBER_SZ + entries.length; + off = (off_t)sz; + if (off < 0 || off != sz || sz < entries.length) { + krb5_data_free(&entries); + return EOVERFLOW; /* caller should ask for fewer entries */ + } + + if (sz >= fsz) { + /* Should never happen! */ + krb5_data_free(&entries); + krb5_warnx(context->context, + "Unable to truncate log due to very large record; " + "deferring truncation"); + return 0; + } + } + /* Truncate to zero size and seek to zero offset */ if (ftruncate(context->log_context.log_fd, 0) < 0 || lseek(context->log_context.log_fd, 0, SEEK_SET) < 0) { diff --git a/lib/kadm5/version-script.map b/lib/kadm5/version-script.map index 6de88fc22..b08c0fa1a 100644 --- a/lib/kadm5/version-script.map +++ b/lib/kadm5/version-script.map @@ -87,6 +87,8 @@ HEIMDAL_KAMD5_SERVER_1.0 { kadm5_log_init_sharedlock; kadm5_log_next; kadm5_log_nop; + kadm5_log_snapshot; + kadm5_log_snapshot_verify; kadm5_log_truncate; kadm5_log_modify; _kadm5_acl_check_permission; diff --git a/tests/kdc/check-iprop.in b/tests/kdc/check-iprop.in index 7efdac4a4..665b5b1ff 100644 --- a/tests/kdc/check-iprop.in +++ b/tests/kdc/check-iprop.in @@ -31,9 +31,6 @@ # OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF # SUCH DAMAGE. -# Skip until hierarchical iprop deadlock is fixed -exit 77 - top_builddir="@top_builddir@" env_setup="@env_setup@" objdir="@objdir@" @@ -285,14 +282,14 @@ rm -f iprop-slave-status iprop-slave-status2 ipropd_slave2=$ipropd_slave ipropd_master2=$ipropd_master -ipropd_slave="${ipropd_slave} --status-file=iprop-slave-status --port=$ipropport" +ipropd_slave="${ipropd_slave} --verbose --status-file=iprop-slave-status --port=$ipropport" ipropd_slave="${ipropd_slave} --hostname=slave.test.h5l.se -k ${keytab}" ipropd_slave="${ipropd_slave} --detach localhost" -ipropd_master="${ipropd_master} --hostname=localhost -k ${keytab}" +ipropd_master="${ipropd_master} --verbose --hostname=localhost -k ${keytab}" ipropd_master="${ipropd_master} --port=$ipropport" ipropd_master="${ipropd_master} --database=${objdir}/current-db --detach" -ipropd_slave2="${ipropd_slave2} --status-file=iprop-slave-status2 --port=$ipropport2" +ipropd_slave2="${ipropd_slave2} --verbose --status-file=iprop-slave-status2 --port=$ipropport2" ipropd_slave2="${ipropd_slave2} --hostname=slave.test.h5l.se -k ${keytab}" ipropd_slave2="${ipropd_slave2} --pidfile-basename=ipropd-slave2" ipropd_slave2="${ipropd_slave2} --detach localhost" @@ -554,7 +551,7 @@ wait_for_master_down wait_for "slave to disconnect" \ ${EGREP} 'disconnected' iprop-slave-status >/dev/null -if ! tail -30 messages.log | grep 'disconnected for server' > /dev/null; then +if ! tail -30 messages.log | grep 'disconnected from server' > /dev/null; then echo "client didnt disconnect" exit 1 fi