make ipropd_slave tell its status in a status file

The ipropd_slave will log its status to /var/heimdal/ipropd-slave-status
if its connecting, up to date, or disconnected.

The master will now also confirm to slaves that are are in fact up to date
if they just restart, before there was no confirmation, the slave just didn't
get any deltas.

doc/setup.texi

@@ -596,6 +596,18 @@ slave#  /usr/heimdal/libexec/ipropd-slave master &
 To manage the iprop log file you should use the @command{iprop-log}
 command. With it you can dump, truncate and replay the logfile.
 
+@subsection Status of iprop master and slave
+
+Both the master and slave provides status of the world as they see it.
+
+The master write outs the current status of the slaves, last seen and
+their version number in @file{/var/heimdal/slaves-stats}.
+
+The slave write out the current status in @file{/var/heimdal/ipropd-slave-status}.
+
+These locations can be changed with command line options, and in the
+case of @command{ipropd_master}, the configuration file.
+
 @node Encryption types and salting, Credential cache server - KCM, Incremental propagation, Setting up a realm
 @section Encryption types and salting
 @cindex Salting

lib/kadm5/iprop.h

@@ -61,7 +61,8 @@ enum iprop_cmd { I_HAVE = 1,
 		 ONE_PRINC = 4,
 		 NOW_YOU_HAVE = 5,
 		 ARE_YOU_THERE = 6,
-		 I_AM_HERE = 7
+		 I_AM_HERE = 7,
+		 YOU_HAVE_LAST_VERSION = 8
 };
 
 extern sig_atomic_t exit_flag;

lib/kadm5/ipropd_master.c

@@ -310,11 +310,6 @@ error:
     remove_slave(context, s, root);
 }
 
-struct prop_context {
-    krb5_auth_context auth_context;
-    krb5_socket_t fd;
-};
-
 static int
 prop_one (krb5_context context, HDB *db, hdb_entry_ex *entry, void *v)
 {
@@ -464,9 +459,19 @@ send_diffs (krb5_context context, slave *s, int log_fd,
     int ret = 0;
 
     if (s->version == current_version) {
+	char buf[4];
+
+	sp = krb5_storage_from_mem(buf, 4);
+	if (sp == NULL)
+	    krb5_errx(context, 1, "krb5_storage_from_mem");
+	krb5_store_int32(sp, YOU_HAVE_LAST_VERSION);
+	krb5_storage_free(sp);
+	data.data   = buf;
+	data.length = 4;
+	ret = krb5_write_priv_message(context, s->ac, &s->fd, &data);
 	krb5_warnx(context, "slave %s in sync already at version %ld",
 		   s->name, (long)s->version);
-	return 0;
+	return ret;
     }
 
     if (s->flags & SLAVE_F_DEAD)

lib/kadm5/ipropd_slave.c

@@ -337,6 +337,27 @@ send_im_here (krb5_context context, int fd,
 	krb5_err (context, 1, ret, "krb5_write_priv_message");
 }
 
+static void
+reinit_log(krb5_context context,
+	   kadm5_server_context *server_context,
+	   int32_t vno)
+{
+    krb5_error_code ret;
+
+    ret = kadm5_log_reinit (server_context);
+    if (ret)
+	krb5_err(context, 1, ret, "kadm5_log_reinit");
+
+    ret = kadm5_log_set_version (server_context, vno - 1);
+    if (ret)
+	krb5_err (context, 1, ret, "kadm5_log_set_version");
+
+    ret = kadm5_log_nop (server_context);
+    if (ret)
+	krb5_err (context, 1, ret, "kadm5_log_nop");
+}
+
+
 static krb5_error_code
 receive_everything (krb5_context context, int fd,
 		    kadm5_server_context *server_context,
@@ -417,17 +438,7 @@ receive_everything (krb5_context context, int fd,
     krb5_ret_int32 (sp, &vno);
     krb5_storage_free(sp);
 
-    ret = kadm5_log_reinit (server_context);
+    reinit_log(context, server_context, vno);
-    if (ret)
-	krb5_err(context, 1, ret, "kadm5_log_reinit");
-
-    ret = kadm5_log_set_version (server_context, vno - 1);
-    if (ret)
-	krb5_err (context, 1, ret, "kadm5_log_set_version");
-
-    ret = kadm5_log_nop (server_context);
-    if (ret)
-	krb5_err (context, 1, ret, "kadm5_log_nop");
 
     ret = mydb->hdb_rename (context, mydb, server_context->db->hdb_name);
     if (ret)
@@ -448,6 +459,46 @@ receive_everything (krb5_context context, int fd,
     return ret;
 }
 
+static void
+slave_status(const char *file, const char *status, ...)
+     __attribute__ ((format (printf, 2, 3)));
+
+
+static void
+slave_status(const char *file, const char *fmt, ...)
+{
+    char *status = NULL;
+    va_list args;
+    int len;
+    
+    va_start(args, fmt);
+    len = vasprintf(&status, fmt, args);
+    va_end(args);
+    if (len < 0 || status == NULL) {
+	unlink(file);
+	return;
+    }
+    
+    rk_dumpdata(file, status, len);
+    free(status);
+}
+
+static void
+is_up_to_date(krb5_context context, const char *file,
+	      kadm5_server_context *server_context)
+{
+    krb5_error_code ret;
+    char buf[80];
+    ret = krb5_format_time(context, time(NULL), buf, sizeof(buf), 1);
+    if (ret) {
+	unlink(file);
+	return;
+    }
+    slave_status(file, "up-to-date with version: %lu at %s\n",
+		 (unsigned long)server_context->log_context.version, buf);
+}
+
+static char *status_file;
 static char *config_file;
 static char *realm;
 static int version_flag;
@@ -465,6 +516,8 @@ static struct getargs args[] = {
       "keytab to get authentication from", "kspec" },
     { "time-lost", 0, arg_string, &server_time_lost,
       "time before server is considered lost", "time" },
+    { "status-file", 0, arg_string, &status_file,
+      "file to write out status into", "file" },
     { "port", 0, arg_string, &port_str,
       "port ipropd-slave will connect to", "port"},
 #ifdef SUPPORT_DETACH
@@ -549,6 +602,13 @@ main(int argc, char **argv)
 
     master = argv[0];
 
+    if (status_file == NULL) {
+	if (asprintf(&status_file,  "%s/ipropd-slave-status", hdb_db_dir(context)) < 0 || status_file == NULL)
+	    krb5_errx(context, 1, "can't allocate status file buffer"); 
+    }
+
+    slave_status(status_file, "bootstrapping\n");
+
 #ifdef SUPPORT_DETACH
     if (detach_from_console)
 	daemon(0, 0);
@@ -565,6 +625,8 @@ main(int argc, char **argv)
     if (time_before_lost < 0)
 	krb5_errx (context, 1, "couldn't parse time: %s", server_time_lost);
 
+    slave_status(status_file, "getting credentials from keytab/database\n");
+
     memset(&conf, 0, sizeof(conf));
     if(realm) {
 	conf.mask |= KADM5_CONFIG_REALM;
@@ -581,6 +643,8 @@ main(int argc, char **argv)
 
     server_context = (kadm5_server_context *)kadm_handle;
 
+    slave_status(status_file, "creating log file\n");
+
     ret = kadm5_log_init (server_context);
     if (ret)
 	krb5_err (context, 1, ret, "kadm5_log_init");
@@ -618,6 +682,8 @@ main(int argc, char **argv)
 	}
 	before = now;
 
+	slave_status(status_file, "connecting to master: %s\n", master);
+
 	master_fd = connect_to_master (context, master, port_str);
 	if (master_fd < 0)
 	    goto retry;
@@ -649,6 +715,8 @@ main(int argc, char **argv)
 
 	connected = TRUE;
 
+	slave_status(status_file, "connected to master, waiting instructions\n");
+
 	while (connected && !exit_flag) {
 	    krb5_data out;
 	    krb5_storage *sp;
@@ -693,18 +761,28 @@ main(int argc, char **argv)
 		receive (context, sp, server_context);
 		ret = ihave (context, auth_context, master_fd,
 			     server_context->log_context.version);
-		if (ret)
+		if (ret) {
 		    connected = FALSE;
+		} else {
+		    is_up_to_date(context, status_file, server_context);
+		}		
+
 		break;
 	    case TELL_YOU_EVERYTHING :
 		ret = receive_everything (context, master_fd, server_context,
 					  auth_context);
 		if (ret)
 		    connected = FALSE;
+		else
+		    is_up_to_date(context, status_file, server_context);
 		break;
 	    case ARE_YOU_THERE :
+		is_up_to_date(context, status_file, server_context);
 		send_im_here (context, master_fd, auth_context);
 		break;
+	    case YOU_HAVE_LAST_VERSION:
+		is_up_to_date(context, status_file, server_context);
+		break;
 	    case NOW_YOU_HAVE :
 	    case I_HAVE :
 	    case ONE_PRINC :
@@ -717,9 +795,12 @@ main(int argc, char **argv)
 	    krb5_data_free (&out);
 
 	}
+
+	slave_status(status_file, "disconnected from master");
     retry:
 	if (connected == FALSE)
 	    krb5_warnx (context, "disconnected for server");
+
 	if (exit_flag)
 	    krb5_warnx (context, "got an exit signal");
 
@@ -727,9 +808,14 @@ main(int argc, char **argv)
 	    close(master_fd);
 
 	reconnect += backoff;
-	if (reconnect > reconnect_max)
+	if (reconnect > reconnect_max) {
+	    slave_status(status_file, "disconnected from master for a long time");
 	    reconnect = reconnect_max;
 	}
+    }
+
+    if (status_file)
+	unlink(status_file);
 
     if (0);
 #ifndef NO_SIGXCPU

tests/kdc/check-iprop.in

@@ -90,6 +90,10 @@ ipdm=
 kdcpid=
 
 > iprop-stats
+rm -f iprop-slave-status
+
+ipropd_slave="${ipropd_slave} --status-file=iprop-slave-status"
+
 trap "echo 'killing ipropd s + m + kdc'; kill -9 \${ipdm} \${ipds} \${kdcpid} >/dev/null 2>/dev/null; tail messages.log ; tail iprop-stats; exit 1;" EXIT
 
 echo Starting kdc
@@ -111,9 +115,11 @@ KRB5_CONFIG="${objdir}/krb5-slave.conf" \
 ${ipropd_slave} --hostname=slave.test.h5l.se -k ${keytab} localhost &
 ipds=$!
 sh ${wait_kdc} ipropd-slave || exit 1
+sleep 1
 
 echo "checking slave is up"
 ${EGREP} 'iprop/slave.test.h5l.se@TEST.H5L.SE.*Up' iprop-stats >/dev/null || exit 1
+${EGREP} 'up-to-date with version' iprop-slave-status >/dev/null || { echo "slave to up to date" ; cat iprop-slave-status ; exit 1; }
 
 # ----------------- checking: pushing lives changes
 
@@ -140,7 +146,7 @@ ${kadmin} -l get host/bar@${R} > /dev/null 2>/dev/null && exit 1
 echo "kill slave"
 > iprop-stats
 sh ${leaks_kill} ipropd-slave $ipds || exit 1
-sleep 2
+rm -f iprop-slave-status
 
 ${EGREP} 'iprop/slave.test.h5l.se@TEST.H5L.SE.*Down' iprop-stats >/dev/null || exit 1
 
@@ -163,9 +169,11 @@ KRB5_CONFIG="${objdir}/krb5-slave.conf" \
 ${ipropd_slave} --hostname=slave.test.h5l.se -k ${keytab} localhost &
 ipds=$!
 sh ${wait_kdc} ipropd-slave || exit 1
+sleep 1
 
 echo "checking slave is up again"
 ${EGREP} 'iprop/slave.test.h5l.se@TEST.H5L.SE.*Up' iprop-stats >/dev/null || exit 1
+${EGREP} 'up-to-date with version' iprop-slave-status >/dev/null || { echo "slave not up to date" ; cat iprop-slave-status ; exit 1; }
 echo "checking for replay problems"
 ${EGREP} 'Entry already exists in database' messages.log && exit 1
 
@@ -175,15 +183,18 @@ sleep 2
 
 rm current.slave.log current-db.slave* || exit 1
 > iprop-stats
+rm -f iprop-slave-status
 > messages.log
 env ${HEIM_MALLOC_DEBUG} \
 KRB5_CONFIG="${objdir}/krb5-slave.conf" \
 ${ipropd_slave} --hostname=slave.test.h5l.se -k ${keytab} localhost &
 ipds=$!
 sh ${wait_kdc} ipropd-slave || exit 1
+sleep 1
 
 echo "checking slave is up again"
 ${EGREP} 'iprop/slave.test.h5l.se@TEST.H5L.SE.*Up' iprop-stats >/dev/null || exit 1
+${EGREP} 'up-to-date with version' iprop-slave-status >/dev/null || { echo "slave not up to date" ; cat iprop-slave-status ; exit 1; }
 echo "checking for replay problems"
 ${EGREP} 'Entry already exists in database' messages.log && exit 1
 
@@ -200,6 +211,8 @@ echo "Killing master and slave"
 sh ${leaks_kill} ipropd-master $ipdm || exit 1
 sh ${leaks_kill} ipropd-slave $ipds || exit 1
 
+rm -f iprop-slave-status
+
 #sleep 2
 #${EGREP} "^master down at " iprop-stats > /dev/null || exit 1
 
@@ -229,9 +242,11 @@ KRB5_CONFIG="${objdir}/krb5-slave.conf" \
 ${ipropd_slave} --hostname=slave.test.h5l.se -k ${keytab} localhost &
 ipds=$!
 sh ${wait_kdc} ipropd-slave || exit 1
+sleep 1
 
 echo "checking slave is up again"
 ${EGREP} 'iprop/slave.test.h5l.se@TEST.H5L.SE.*Up' iprop-stats >/dev/null || exit 1
+${EGREP} 'up-to-date with version' iprop-slave-status >/dev/null || { echo "slave to up to date" ; cat iprop-slave-status ; exit 1; }
 echo "checking for replay problems"
 ${EGREP} 'Entry already exists in database' messages.log && exit 1
 
@@ -244,6 +259,8 @@ sh ${leaks_kill} ipropd-master $ipdm || exit 1
 
 sleep 4
 
+${EGREP} 'disconnected' iprop-slave-status >/dev/null && { echo "slave still think its connected" ; cat iprop-slave-status ; exit 1; }
+
 if ! tail -30 messages.log | grep 'disconnected for server' > /dev/null; then
     echo "client didnt disconnect"
     exit 1
@@ -279,6 +296,8 @@ sh ${leaks_kill} kdc $kdcpid || exit 1
 sh ${leaks_kill} ipropd-master $ipdm || exit 1
 sh ${leaks_kill} ipropd-slave $ipds || exit 1
 
+rm -f iprop-slave-status
+
 echo "compare versions on master and slave logs"
 KRB5_CONFIG=${objdir}/krb5-slave.conf \
 ${iprop_log} last-version > slave-last.tmp