X-Git-Url: http://www.chiark.greenend.org.uk/ucgi/~ian/git?p=secnet.git;a=blobdiff_plain;f=site.c;h=11690523b066ea66a707769720e92d7f70cb6d88;hp=f0a2922fe3eb9f7dc7bad4585129186f83fa9a17;hb=77effe1d38ae820fdb5a2e623b50f467565256cb;hpb=925c5ca83e5eb67604b837ce8d3e02fae2adb260

diff --git a/site.c b/site.c
index f0a2922..1169052 100644
--- a/site.c
+++ b/site.c
@@ -299,35 +299,75 @@ struct site {
     struct transform_inst_if *new_transform; /* For key setup/verify */
 };
 
+static uint32_t event_log_priority(struct site *st, uint32_t event)
+{
+    if (!(event&st->log_events))
+	return 0;
+    switch(event) {
+    case LOG_UNEXPECTED:    return M_INFO;
+    case LOG_SETUP_INIT:    return M_INFO;
+    case LOG_SETUP_TIMEOUT: return M_NOTICE;
+    case LOG_ACTIVATE_KEY:  return M_INFO;
+    case LOG_TIMEOUT_KEY:   return M_INFO;
+    case LOG_SEC:           return M_SECURITY;
+    case LOG_STATE:         return M_DEBUG;
+    case LOG_DROP:          return M_DEBUG;
+    case LOG_DUMP:          return M_DEBUG;
+    case LOG_ERROR:         return M_ERR;
+    case LOG_PEER_ADDRS:    return M_DEBUG;
+    default:                return M_ERR;
+    }
+}
+
+static void vslog(struct site *st, uint32_t event, cstring_t msg, va_list ap)
+FORMAT(printf,3,0);
+static void vslog(struct site *st, uint32_t event, cstring_t msg, va_list ap)
+{
+    uint32_t class;
+
+    class=event_log_priority(st, event);
+    if (class) {
+	slilog_part(st->log,class,"%s: ",st->tunname);
+	vslilog_part(st->log,class,msg,ap);
+	slilog_part(st->log,class,"\n");
+    }
+}
+
 static void slog(struct site *st, uint32_t event, cstring_t msg, ...)
 FORMAT(printf,3,4);
 static void slog(struct site *st, uint32_t event, cstring_t msg, ...)
 {
     va_list ap;
-    char buf[240];
-    uint32_t class;
-
     va_start(ap,msg);
+    vslog(st,event,msg,ap);
+    va_end(ap);
+}
 
-    if (event&st->log_events) {
-	switch(event) {
-	case LOG_UNEXPECTED: class=M_INFO; break;
-	case LOG_SETUP_INIT: class=M_INFO; break;
-	case LOG_SETUP_TIMEOUT: class=M_NOTICE; break;
-	case LOG_ACTIVATE_KEY: class=M_INFO; break;
-	case LOG_TIMEOUT_KEY: class=M_INFO; break;
-	case LOG_SEC: class=M_SECURITY; break;
-	case LOG_STATE: class=M_DEBUG; break;
-	case LOG_DROP: class=M_DEBUG; break;
-	case LOG_DUMP: class=M_DEBUG; break;
-	case LOG_ERROR: class=M_ERR; break;
-	case LOG_PEER_ADDRS: class=M_DEBUG; break;
-	default: class=M_ERR; break;
-	}
+static void logtimeout(struct site *st, const char *fmt, ...)
+FORMAT(printf,2,3);
+static void logtimeout(struct site *st, const char *fmt, ...)
+{
+    uint32_t class=event_log_priority(st,LOG_SETUP_TIMEOUT);
+    if (!class)
+	return;
 
-	vsnprintf(buf,sizeof(buf),msg,ap);
-	slilog(st->log,class,"%s: %s",st->tunname,buf);
+    va_list ap;
+    va_start(ap,fmt);
+
+    slilog_part(st->log,class,"%s: ",st->tunname);
+    vslilog_part(st->log,class,fmt,ap);
+
+    const char *delim;
+    int i;
+    for (i=0, delim=" (tried ";
+	 i<st->setup_peers.npeers;
+	 i++, delim=", ") {
+	transport_peer *peer=&st->setup_peers.peers[i];
+	const char *s=comm_addr_to_string(&peer->addr);
+	slilog_part(st->log,class,"%s%s",delim,s);
     }
+
+    slilog_part(st->log,class,")\n");
     va_end(ap);
 }
 
@@ -1077,7 +1117,7 @@ static bool_t send_msg(struct site *st)
 	st->retries--;
 	return True;
     } else if (st->state==SITE_SENTMSG5) {
-	slog(st,LOG_SETUP_TIMEOUT,"timed out sending MSG5, stashing new key");
+	logtimeout(st,"timed out sending MSG5, stashing new key");
 	/* We stash the key we have produced, in case it turns out that
 	 * our peer did see our MSG5 after all and starts using it. */
 	/* This is a bit like some of activate_new_key */
@@ -1095,7 +1135,7 @@ static bool_t send_msg(struct site *st)
 	enter_state_wait(st);
 	return False;
     } else {
-	slog(st,LOG_SETUP_TIMEOUT,"timed out sending key setup packet "
+	logtimeout(st,"timed out sending key setup packet "
 	    "(in state %s)",state_name(st->state));
 	enter_state_wait(st);
 	return False;
@@ -1134,6 +1174,7 @@ static void site_resolve_callback(void *sst, struct in_addr *address)
 static bool_t initiate_key_setup(struct site *st, cstring_t reason,
 				 const struct comm_addr *prod_hint)
 {
+    /* Reentrancy hazard: can call enter_new_state/enter_state_* */
     if (st->state!=SITE_RUN) return False;
     slog(st,LOG_SETUP_INIT,"initiating key exchange (%s)",reason);
     if (st->address) {
@@ -1246,6 +1287,7 @@ static void enter_state_run(struct site *st)
 
 static bool_t enter_state_resolve(struct site *st)
 {
+    /* Reentrancy hazard!  See ensure_resolving. */
     state_assert(st,st->state==SITE_RUN);
     slog(st,LOG_STATE,"entering state RESOLVE");
     st->state=SITE_RESOLVE;
@@ -1911,14 +1953,14 @@ static void transport_peers_debug(struct site *st, transport_peers *dst,
 	 i++, (argp+=stride?stride:sizeof(*args))) {
 	const struct comm_addr *ca=(void*)argp;
 	slog(st, LOG_PEER_ADDRS, " args: addrs[%d]=%s",
-	     i, ca->comm->addr_to_string(ca->comm->st,ca));
+	     i, comm_addr_to_string(ca));
     }
     for (i=0; i<dst->npeers; i++) {
 	struct timeval diff;
 	timersub(tv_now,&dst->peers[i].last,&diff);
 	const struct comm_addr *ca=&dst->peers[i].addr;
 	slog(st, LOG_PEER_ADDRS, " peers: addrs[%d]=%s T-%ld.%06ld",
-	     i, ca->comm->addr_to_string(ca->comm->st,ca),
+	     i, comm_addr_to_string(ca),
 	     (unsigned long)diff.tv_sec, (unsigned long)diff.tv_usec);
     }
 }