New logging mode, which records the exact bytes sent over the wire

in an SSH connection _in addition_ to the decrypted packets. This
will hopefully come in useful for debugging wire data corruption
issues: you can strace the server, enable this mode in the client,
and compare the sent and received data.

I'd _like_ to have this mode also log Diffie-Hellman private
exponents, session IDs, encryption and MAC keys, so that the
resulting log file could be used to independently verify the
correctness of all cryptographic operations performed by PuTTY.
However, I haven't been able to convince myself that the security
implications are acceptable. (It doesn't matter that this
information would permit an attacker to decrypt the session, because
the _already_ decrypted session is stored alongside it in the log
file. And I'm not planning, under any circumstances, to log users'
private keys. But gaining access to the log file while the session
was still running would permit an attacker to _hijack_ the session,
and that's the iffy bit.)

git-svn-id: svn://svn.tartarus.org/sgt/putty@6835 cda61777-01e9-0310-a592-d414129be87e

diff --git a/config.c b/config.c
index 7992e27..84262f8 100644 (file)
--- a/config.c
+++ b/config.c
@@ -1171,20 +1171,24 @@ void setup_config_box(struct controlbox *b, int midsession,
      * logging can sensibly be available.
      */
     {
-       char *sshlogname;
+       char *sshlogname, *sshrawlogname;
        if ((midsession && protocol == PROT_SSH) ||
-           (!midsession && backends[3].name != NULL))
-           sshlogname = "Log SSH packet data";
-       else
-           sshlogname = NULL;         /* this will disable the button */
-       ctrl_radiobuttons(s, "Session logging:", NO_SHORTCUT, 1,
+           (!midsession && backends[3].name != NULL)) {
+           sshlogname = "SSH packets";
+           sshrawlogname = "SSH packets and raw data";
+        } else {
+           sshlogname = NULL;         /* this will disable both buttons */
+           sshrawlogname = NULL;      /* this will just placate optimisers */
+        }
+       ctrl_radiobuttons(s, "Session logging:", NO_SHORTCUT, 2,
                          HELPCTX(logging_main),
                          loggingbuttons_handler,
                          I(offsetof(Config, logtype)),
-                         "Logging turned off completely", 't', I(LGTYP_NONE),
-                         "Log printable output only", 'p', I(LGTYP_ASCII),
-                         "Log all session output", 'l', I(LGTYP_DEBUG),
+                         "None", 't', I(LGTYP_NONE),
+                         "Printable output", 'p', I(LGTYP_ASCII),
+                         "All session output", 'l', I(LGTYP_DEBUG),
                          sshlogname, 's', I(LGTYP_PACKETS),
+                         sshrawlogname, 'r', I(LGTYP_SSHRAW),
                          NULL);
     }
     ctrl_filesel(s, "Log file name:", 'f',

diff --git a/logging.c b/logging.c
index 8122a48..1a98213 100644 (file)
--- a/logging.c
+++ b/logging.c
@@ -106,6 +106,7 @@ static void logfopen_callback(void *handle, int mode)
                      (ctx->cfg.logtype == LGTYP_ASCII ? "ASCII" :
                       ctx->cfg.logtype == LGTYP_DEBUG ? "raw" :
                       ctx->cfg.logtype == LGTYP_PACKETS ? "SSH packets" :
+                      ctx->cfg.logtype == LGTYP_SSHRAW ? "SSH raw data" :
                       "unknown"),
                      filename_to_str(&ctx->currlogfilename));
     logevent(ctx->frontend, event);
@@ -203,9 +204,11 @@ void log_eventlog(void *handle, const char *event)
        fprintf(stderr, "%s\n", event);
        fflush(stderr);
     }
-    if (ctx->cfg.logtype != LGTYP_PACKETS)
+    if (ctx->cfg.logtype != LGTYP_PACKETS &&
+       ctx->cfg.logtype != LGTYP_SSHRAW)
        return;
     logprintf(ctx, "Event Log: %s\r\n", event);
+    logflush(ctx);
 }
 
 /*
@@ -222,13 +225,18 @@ void log_packet(void *handle, int direction, int type,
     int p = 0, b = 0, omitted = 0;
     int output_pos = 0; /* NZ if pending output in dumpdata */
 
-    if (ctx->cfg.logtype != LGTYP_PACKETS)
+    if (!(ctx->cfg.logtype == LGTYP_SSHRAW ||
+          (ctx->cfg.logtype == LGTYP_PACKETS && texttype)))
        return;
 
     /* Packet header. */
-    logprintf(ctx, "%s packet type %d / 0x%02x (%s)\r\n",
-             direction == PKT_INCOMING ? "Incoming" : "Outgoing",
-             type, type, texttype);
+    if (texttype)
+        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 c648921..f5396e4 100644 (file)
--- a/putty.h
+++ b/putty.h
@@ -163,6 +163,7 @@ struct unicode_data {
 #define LGTYP_ASCII 1                 /* logmode: pure ascii */
 #define LGTYP_DEBUG 2                 /* logmode: all chars of traffic */
 #define LGTYP_PACKETS 3                       /* logmode: SSH data packets */
+#define LGTYP_SSHRAW 4                /* logmode: SSH raw data */
 
 typedef enum {
     /* Actual special commands. Originally Telnet, but some codes have

diff --git a/ssh.c b/ssh.c
index a161604..fc68bf9 100644 (file)
--- a/ssh.c
+++ b/ssh.c
@@ -1442,11 +1442,17 @@ static int s_wrpkt_prepare(Ssh ssh, struct Packet *pkt, int *offset_p)
     return biglen + 4;         /* len(length+padding+type+data+CRC) */
 }
 
+static int s_write(Ssh ssh, void *data, int len)
+{
+    log_packet(ssh->logctx, PKT_OUTGOING, -1, NULL, data, len, 0, NULL);
+    return sk_write(ssh->s, (char *)data, len);
+}
+
 static void s_wrpkt(Ssh ssh, struct Packet *pkt)
 {
     int len, backlog, offset;
     len = s_wrpkt_prepare(ssh, pkt, &offset);
-    backlog = sk_write(ssh->s, (char *)pkt->data + offset, len);
+    backlog = s_write(ssh, pkt->data + offset, len);
     if (backlog > SSH_MAX_BACKLOG)
        ssh_throttle_all(ssh, 1, backlog);
     ssh_free_packet(pkt);
@@ -1830,7 +1836,7 @@ static void ssh2_pkt_send_noqueue(Ssh ssh, struct Packet *pkt)
        return;
     }
     len = ssh2_pkt_construct(ssh, pkt);
-    backlog = sk_write(ssh->s, (char *)pkt->data, len);
+    backlog = s_write(ssh, pkt->data, len);
     if (backlog > SSH_MAX_BACKLOG)
        ssh_throttle_all(ssh, 1, backlog);
 
@@ -1928,8 +1934,7 @@ static void ssh2_pkt_defer(Ssh ssh, struct Packet *pkt)
 static void ssh_pkt_defersend(Ssh ssh)
 {
     int backlog;
-    backlog = sk_write(ssh->s, (char *)ssh->deferred_send_data,
-                      ssh->deferred_len);
+    backlog = s_write(ssh, ssh->deferred_send_data, ssh->deferred_len);
     ssh->deferred_len = ssh->deferred_size = 0;
     sfree(ssh->deferred_send_data);
     ssh->deferred_send_data = NULL;
@@ -2418,7 +2423,7 @@ static int do_ssh_init(Ssh ssh, unsigned char c)
         }
         logeventf(ssh, "We claim version: %.*s",
                   strcspn(verstring, "\015\012"), verstring);
-       sk_write(ssh->s, verstring, strlen(verstring));
+       s_write(ssh, verstring, strlen(verstring));
         sfree(verstring);
        if (ssh->version == 2)
            do_ssh2_transport(ssh, NULL, -1, NULL);
@@ -2438,7 +2443,9 @@ static int do_ssh_init(Ssh ssh, unsigned char c)
 static void ssh_process_incoming_data(Ssh ssh,
                                      unsigned char **data, int *datalen)
 {
-    struct Packet *pktin = ssh->s_rdpkt(ssh, data, datalen);
+    struct Packet *pktin;
+
+    pktin = ssh->s_rdpkt(ssh, data, datalen);
     if (pktin) {
        ssh->protocol(ssh, NULL, 0, pktin);
        ssh_free_packet(pktin);
@@ -2481,6 +2488,9 @@ static void ssh_set_frozen(Ssh ssh, int frozen)
 
 static void ssh_gotdata(Ssh ssh, unsigned char *data, int datalen)
 {
+    /* Log raw data, if we're in that mode. */
+    log_packet(ssh->logctx, PKT_INCOMING, -1, NULL, data, datalen, 0, NULL);
+
     crBegin(ssh->ssh_gotdata_crstate);
 
     /*