X-Git-Url: https://www.chiark.greenend.org.uk/ucgi/~mdw/git/tripe/blobdiff_plain/b5c45da15703d85b506a1ea1eb38c318c3418ed3..452bf3f6897b8c6a22b51e1ef228da39136d51a7:/keyexch.c?ds=sidebyside

diff --git a/keyexch.c b/keyexch.c
index 18594cf3..ea4748e2 100644
--- a/keyexch.c
+++ b/keyexch.c
@@ -1,6 +1,6 @@
 /* -*-c-*-
  *
- * $Id: keyexch.c,v 1.13 2004/04/18 18:08:11 mdw Exp $
+ * $Id$
  *
  * Key exchange protocol
  *
@@ -72,7 +72,7 @@
  *	Challenge accpeted: here's the answer.  Commit to my challenge.  Move
  *	to @KXS_COMMIT@.
  *
- * %$\cookie{kx-switch}, c_A, c_B, E_K(r_B^\alpha, w_A))$%
+ * %$\cookie{kx-switch-rq}, c_A, c_B, E_K(r_B^\alpha, w_A))$%
  *	Reply received: here's my reply.  Committed; send data; move to
  *	@KXS_SWITCH@.
  *
@@ -85,7 +85,14 @@
 #define T_VALID MIN(2)			/* Challenge validity period */
 #define T_RETRY SEC(10)			/* Challenge retransmit interval */
 
-#define ISVALID(kx, now) ((now) < (kx)->t_valid)
+#define VALIDP(kx, now) ((now) < (kx)->t_valid)
+
+/*----- Static tables -----------------------------------------------------*/
+
+static const char *const pkname[] = {
+  "pre-challenge", "cookie", "challenge",
+  "reply", "switch-rq", "switch-ok"
+};
 
 /*----- Various utilities -------------------------------------------------*/
 
@@ -161,7 +168,7 @@ static void timer(struct timeval *tv, void *v)
   keyexch *kx = v;
   kx->f &= ~KXF_TIMER;
   T( trace(T_KEYEXCH, "keyexch: timer has popped"); )
-  kx_start(kx);
+  kx_start(kx, 0);
 }
 
 /* --- @settimer@ --- *
@@ -423,7 +430,7 @@ static ge *getreply(keyexch *kx, ge *c, mp *ck)
   G_EXP(gg, y, gg->g, a);
   ok = G_EQ(gg, y, c);
   if (!ok) {
-    a_warn("invalid expected-reply check from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "bad-expected-reply-log", A_END);
     IF_TRACING(T_KEYEXCH, IF_TRACING(T_CRYPTO, {
       trace(T_CRYPTO, "crypto: computed challenge = %s", gestr(gg, y));
     }))
@@ -457,7 +464,7 @@ static int dochallenge(keyexch *kx, unsigned msg, buf *b)
   /* --- Ensure that we're in a sensible state --- */
 
   if (kx->s != KXS_CHAL) {
-    a_warn("unexpected challenge from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "unexpected", "%s", pkname[msg], A_END);
     goto bad;
   }
 
@@ -467,7 +474,7 @@ static int dochallenge(keyexch *kx, unsigned msg, buf *b)
       (msg >= KX_COOKIE && (hc = buf_get(b, algs.hashsz)) == 0) ||
       (msg >= KX_CHAL && (ck = buf_getmp(b)) == 0) ||
       BLEFT(b)) {
-    a_warn("malformed packet from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "invalid", "%s", pkname[msg], A_END);
     goto bad;
   }
 
@@ -484,6 +491,7 @@ static int dochallenge(keyexch *kx, unsigned msg, buf *b)
 
   if (!hc && kx->nr >= KX_THRESH) {
     T( trace(T_KEYEXCH, "keyexch: too many challenges -- sending cookie"); )
+    a_warn("KX", "?PEER", p_name, "sending-cookie", A_END);
     b = p_txstart(kx->p, MSG_KEYEXCH | KX_COOKIE);
     G_TOBUF(gg, b, kx->c);
     h = GH_INIT(algs.h);
@@ -498,7 +506,7 @@ static int dochallenge(keyexch *kx, unsigned msg, buf *b)
   /* --- Discard a packet with an invalid cookie --- */
 
   if (hc && memcmp(hc, kx->hc, algs.hashsz) != 0) {
-    a_warn("incorrect cookie from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", "incorrect", "cookie", A_END);
     goto bad;
   }
 
@@ -719,11 +727,11 @@ static kxchal *matchreply(keyexch *kx, unsigned ty, const octet *hc_in,
     if (ck) trace(T_CRYPTO, "crypto: check value = %s", mpstr(ck));
   }))
   if (memcmp(hc_out, kx->hc, algs.hashsz) != 0) {
-    a_warn("incorrect cookie from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "incorrect", "cookie", A_END);
     goto bad;
   }
   if ((kxc = kxc_byhc(kx, hc_in)) == 0) {
-    a_warn("received reply for unknown challenge from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "unknown-challenge", A_END);
     goto bad;
   }
 
@@ -731,7 +739,7 @@ static kxchal *matchreply(keyexch *kx, unsigned ty, const octet *hc_in,
 
   if (!kxc->r) {
     if (!ck) {
-      a_warn("unexpected switch request from `%s'", p_name(kx->p));
+      a_warn("KX", "?PEER", kx->p, "unexpected", "switch-rq", A_END);
       goto bad;
     }
     if ((r = getreply(kx, kxc->c, ck)) == 0)
@@ -744,20 +752,20 @@ static kxchal *matchreply(keyexch *kx, unsigned ty, const octet *hc_in,
 
   buf_init(&bb, buf_o, sizeof(buf_o));
   if (ks_decrypt(kxc->ks, ty, b, &bb)) {
-    a_warn("failed to decrypt reply from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "decrypt-failed", "reply", A_END);
     goto bad;
   }
   buf_init(b, BBASE(&bb), BLEN(&bb));
   r = G_CREATE(gg);
   if (G_FROMBUF(gg, b, r)) {
-    a_warn("invalid reply packet from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "invalid", "reply", A_END);
     goto bad;
   }
   IF_TRACING(T_KEYEXCH, IF_TRACING(T_CRYPTO, {
     trace(T_CRYPTO, "crypto: reply = %s", gestr(gg, r));
   }))
   if (!G_EQ(gg, r, kx->rx)) {
-    a_warn("incorrect reply from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "incorrect", "reply", A_END);
     goto bad;
   }
 
@@ -814,20 +822,20 @@ static int doreply(keyexch *kx, buf *b)
   kxchal *kxc;
 
   if (kx->s != KXS_CHAL && kx->s != KXS_COMMIT) {
-    a_warn("unexpected reply from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "unexpected", "reply", A_END);
     goto bad;
   }
   if ((hc_in = buf_get(b, algs.hashsz)) == 0 ||
       (hc_out = buf_get(b, algs.hashsz)) == 0 ||
       (ck = buf_getmp(b)) == 0) {
-    a_warn("invalid reply packet from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "invalid", "reply", A_END);
     goto bad;
   }
   if ((kxc = matchreply(kx, MSG_KEYEXCH | KX_REPLY,
 			hc_in, hc_out, ck, b)) == 0)
     goto bad;
   if (BLEFT(b)) {
-    a_warn("invalid reply packet from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "invalid", "reply", A_END);
     goto bad;
   }
   if (kx->s == KXS_CHAL) {
@@ -842,6 +850,25 @@ bad:
   return (-1);
 }
 
+/* --- @kxfinish@ --- *
+ *
+ * Arguments:	@keyexch *kx@ = pointer to key exchange block
+ *
+ * Returns:	---
+ *
+ * Use:		Sets everything up following a successful key exchange.
+ */
+
+static void kxfinish(keyexch *kx)
+{
+  kxchal *kxc = kx->r[0];
+  ks_activate(kxc->ks);
+  settimer(kx, ks_tregen(kxc->ks));
+  kx->s = KXS_SWITCH;
+  a_notify("KXDONE", "?PEER", kx->p, A_END);
+  p_stats(kx->p)->t_kx = time(0);
+}
+
 /* --- @doswitch@ --- *
  *
  * Arguments:	@keyexch *kx@ = pointer to key exchange block
@@ -859,30 +886,28 @@ static int doswitch(keyexch *kx, buf *b)
 
   if ((hc_in = buf_get(b, algs.hashsz)) == 0 ||
       (hc_out = buf_get(b, algs.hashsz)) == 0) {
-    a_warn("invalid switch request from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "invalid", "switch-rq", A_END);
     goto bad;
   }
   if ((kxc = matchreply(kx, MSG_KEYEXCH | KX_SWITCH,
 			hc_in, hc_out, 0, b)) == 0)
     goto bad;
   if ((hswrq = buf_get(b, algs.hashsz)) == 0 || BLEFT(b)) {
-    a_warn("invalid switch request from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", "invalid", "switch-rq", A_END);
     goto bad;
   }
   IF_TRACING(T_KEYEXCH, {
     trace_block(T_CRYPTO, "crypto: switch request hash", hswrq, algs.hashsz);
   })
   if (memcmp(hswrq, kxc->hswrq_in, algs.hashsz) != 0) {
-    a_warn("incorrect switch request hash from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "incorrect", "switch-rq", A_END);
     goto bad;
   }
   switch (kx->s) {
     case KXS_CHAL:
       commit(kx, kxc);
     case KXS_COMMIT:
-      ks_activate(kxc->ks);
-      settimer(kx, ks_tregen(kxc->ks));
-      kx->s = KXS_SWITCH;
+      kxfinish(kx);
       break;
   }
   resend(kx);
@@ -909,18 +934,18 @@ static int doswitchok(keyexch *kx, buf *b)
   buf bb;
 
   if (kx->s < KXS_COMMIT) {
-    a_warn("unexpected switch confirmation from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "unexpected", "switch-ok", A_END);
     goto bad;
   }
   kxc = kx->r[0];
   buf_init(&bb, buf_o, sizeof(buf_o));
   if (ks_decrypt(kxc->ks, MSG_KEYEXCH | KX_SWITCHOK, b, &bb)) {
-    a_warn("failed to decrypt switch confirmation from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "decrypt-failed", "switch-ok", A_END);
     goto bad;
   }
   buf_init(b, BBASE(&bb), BLEN(&bb));
   if ((hswok = buf_get(b, algs.hashsz)) == 0 || BLEFT(b)) {
-    a_warn("invalid switch confirmation from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", "invalid", "switch-ok", A_END);
     goto bad;
   }
   IF_TRACING(T_KEYEXCH, {
@@ -928,14 +953,11 @@ static int doswitchok(keyexch *kx, buf *b)
 		hswok, algs.hashsz);
   })
   if (memcmp(hswok, kxc->hswok_in, algs.hashsz) != 0) {
-    a_warn("incorrect switch confirmation hash from `%s'", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "incorrect", "switch-ok", A_END);
     goto bad;
   }
-  if (kx->s < KXS_SWITCH) {
-    ks_activate(kxc->ks);
-    settimer(kx, ks_tregen(kxc->ks));
-    kx->s = KXS_SWITCH;
-  }
+  if (kx->s < KXS_SWITCH)
+    kxfinish(kx);
   return (0);
 
 bad:
@@ -1037,7 +1059,7 @@ static int checkpub(keyexch *kx)
   now = time(0);
   if (KEY_EXPIRED(now, kx->texp_kpub)) {
     stop(kx);
-    a_warn("public key for `%s' has expired", p_name(kx->p));
+    a_warn("KX", "?PEER", kx->p, "public-key-expired", A_END);
     G_COPY(gg, kx->kpub, gg->i);
     kx->f &= ~KXF_PUBKEY;
     return (-1);
@@ -1048,6 +1070,7 @@ static int checkpub(keyexch *kx)
 /* --- @kx_start@ --- *
  *
  * Arguments:	@keyexch *kx@ = pointer to key exchange context
+ *		@int forcep@ = nonzero to ignore the quiet timer
  *
  * Returns:	---
  *
@@ -1056,15 +1079,16 @@ static int checkpub(keyexch *kx)
  *		this); if no exchange is in progress, one is commenced.
  */
 
-void kx_start(keyexch *kx)
+void kx_start(keyexch *kx, int forcep)
 {
   time_t now = time(0);
 
   if (checkpub(kx))
     return;
-  if (!ISVALID(kx, now)) {
+  if (forcep || !VALIDP(kx, now)) {
     stop(kx);
     start(kx, now);
+    a_notify("KXSTART", "?PEER", kx->p, A_END);
   }
   resend(kx);
 }
@@ -1088,17 +1112,10 @@ void kx_message(keyexch *kx, unsigned msg, buf *b)
   size_t sz = BSZ(b);
   int rc;
 
-#ifndef NTRACE
-  static const char *const pkname[] = {
-    "prechallenge", "cookie", "challenge",
-    "reply", "switch request", "switch confirmation"
-  };
-#endif
-
   if (checkpub(kx))
     return;
 
-  if (!ISVALID(kx, now)) {
+  if (!VALIDP(kx, now)) {
     stop(kx);
     start(kx, now);
   }
@@ -1122,8 +1139,7 @@ void kx_message(keyexch *kx, unsigned msg, buf *b)
       rc = doswitchok(kx, b);
       break;
     default:
-      a_warn("unexpected key exchange message type %u from `%p'",
-	     p_name(kx->p));
+      a_warn("KX", "?PEER", kx->p, "unknown-message", "0x%02x", msg, A_END);
       rc = -1;
       break;
   }
@@ -1202,6 +1218,7 @@ int kx_init(keyexch *kx, peer *p, keyset **ks)
   kx->f = KXF_DEAD | KXF_PUBKEY;
   start(kx, time(0));
   resend(kx);
+  /* Don't notify here: the ADD message hasn't gone out yet. */
   return (0);
 }