In SSH packet logging mode, log SSH-2 packet sequence numbers, in

both directions. We had a bug report yesterday about a Cisco router
sending SSH2_MSG_UNIMPLEMENTED and it wasn't clear for which packet;
logging the sequence numbers should make such problems much easier
to diagnose.

(In fact this logging fix wouldn't have helped in yesterday's case,
because the router also didn't bother to fill in the sequence number
field in the SSH2_MSG_UNIMPLEMENTED packet! This is a precautionary
measure against the next one of these problems.)

[originally from svn r8295]

diff --git a/logging.c b/logging.c
index bd5705cb1c8b121121e61de9e8cec5f25d3a13f4..db02892a5742f190dc256e7f3c8f655c22ad1ce5 100644 (file)
--- a/logging.c
+++ b/logging.c
@@ -220,8 +220,9 @@ void log_eventlog(void *handle, const char *event)
  * Set of blanking areas must be in increasing order.
  */
 void log_packet(void *handle, int direction, int type,
-               char *texttype, void *data, int len,
-               int n_blanks, const struct logblank_t *blanks)
+               char *texttype, const void *data, int len,
+               int n_blanks, const struct logblank_t *blanks,
+               const unsigned long *seq)
 {
     struct LogContext *ctx = (struct LogContext *)handle;
     char dumpdata[80], smalldata[5];
@@ -233,13 +234,20 @@ void log_packet(void *handle, int direction, int type,
        return;
 
     /* Packet header. */
-    if (texttype)
-        logprintf(ctx, "%s packet type %d / 0x%02x (%s)\r\n",
-                  direction == PKT_INCOMING ? "Incoming" : "Outgoing",
-                  type, type, texttype);
-    else
+    if (texttype) {
+       if (seq) {
+           logprintf(ctx, "%s packet #0x%lx, type %d / 0x%02x (%s)\r\n",
+                     direction == PKT_INCOMING ? "Incoming" : "Outgoing",
+                     *seq, type, type, texttype);
+       } else {
+           logprintf(ctx, "%s packet type %d / 0x%02x (%s)\r\n",
+                     direction == PKT_INCOMING ? "Incoming" : "Outgoing",
+                     type, type, texttype);
+       }
+    } else {
         logprintf(ctx, "%s raw data\r\n",
                   direction == PKT_INCOMING ? "Incoming" : "Outgoing");
+    }
 
     /*
      * Output a hex/ASCII dump of the packet body, blanking/omitting

diff --git a/putty.h b/putty.h
index 8aea91c14ce90c1cab3ca323680b132cb926f073..070ba313404450577078eeb1aa6a9d0d2cefc0da 100644 (file)
--- a/putty.h
+++ b/putty.h
@@ -870,8 +870,9 @@ struct logblank_t {
     int type;
 };
 void log_packet(void *logctx, int direction, int type,
-               char *texttype, void *data, int len,
-               int n_blanks, const struct logblank_t *blanks);
+               char *texttype, const void *data, int len,
+               int n_blanks, const struct logblank_t *blanks,
+               const unsigned long *sequence);
 
 /*
  * Exports from testback.c

diff --git a/ssh.c b/ssh.c
index f2e1f51a6facc14b24b8ded03217cb4413824f60..be086594b869f3cfac61f72458ce2a0f279a14f8 100644 (file)
--- a/ssh.c
+++ b/ssh.c
@@ -1287,7 +1287,7 @@ static struct Packet *ssh1_rdpkt(Ssh ssh, unsigned char **data, int *datalen)
                   PKT_INCOMING, st->pktin->type,
                   ssh1_pkt_type(st->pktin->type),
                   st->pktin->body, st->pktin->length,
-                  nblanks, &blank);
+                  nblanks, &blank, NULL);
     }
 
     crFinish(st->pktin);
@@ -1447,7 +1447,7 @@ static struct Packet *ssh2_rdpkt(Ssh ssh, unsigned char **data, int *datalen)
                   ssh2_pkt_type(ssh->pkt_kctx, ssh->pkt_actx,
                                 st->pktin->type),
                   st->pktin->data+6, st->pktin->length-6,
-                  nblanks, &blank);
+                  nblanks, &blank, &st->pktin->sequence);
     }
 
     crFinish(st->pktin);
@@ -1472,7 +1472,7 @@ static int s_wrpkt_prepare(Ssh ssh, struct Packet *pkt, int *offset_p)
        log_packet(ssh->logctx, PKT_OUTGOING, pkt->data[12],
                   ssh1_pkt_type(pkt->data[12]),
                   pkt->body, pkt->length - (pkt->body - pkt->data),
-                  pkt->nblanks, pkt->blanks);
+                  pkt->nblanks, pkt->blanks, NULL);
     sfree(pkt->blanks); pkt->blanks = NULL;
     pkt->nblanks = 0;
 
@@ -1512,7 +1512,8 @@ static int s_wrpkt_prepare(Ssh ssh, struct Packet *pkt, int *offset_p)
 static int s_write(Ssh ssh, void *data, int len)
 {
     if (ssh->logctx)
-       log_packet(ssh->logctx, PKT_OUTGOING, -1, NULL, data, len, 0, NULL);
+       log_packet(ssh->logctx, PKT_OUTGOING, -1, NULL, data, len,
+                  0, NULL, NULL);
     return sk_write(ssh->s, (char *)data, len);
 }
 
@@ -1795,7 +1796,7 @@ static int ssh2_pkt_construct(Ssh ssh, struct Packet *pkt)
        log_packet(ssh->logctx, PKT_OUTGOING, pkt->data[5],
                   ssh2_pkt_type(ssh->pkt_kctx, ssh->pkt_actx, pkt->data[5]),
                   pkt->body, pkt->length - (pkt->body - pkt->data),
-                  pkt->nblanks, pkt->blanks);
+                  pkt->nblanks, pkt->blanks, &ssh->v2_outgoing_sequence);
     sfree(pkt->blanks); pkt->blanks = NULL;
     pkt->nblanks = 0;
 
@@ -2664,7 +2665,7 @@ static void ssh_gotdata(Ssh ssh, unsigned char *data, int datalen)
     /* Log raw data, if we're in that mode. */
     if (ssh->logctx)
        log_packet(ssh->logctx, PKT_INCOMING, -1, NULL, data, datalen,
-                  0, NULL);
+                  0, NULL, NULL);
 
     crBegin(ssh->ssh_gotdata_crstate);