logging.c

   1 /*
   2  * Session logging.
   3  */
   4
   5 #include <stdio.h>
   6 #include <stdlib.h>
   7 #include <ctype.h>
   8
   9 #include <time.h>
  10 #include <assert.h>
  11
  12 #include "putty.h"
  13
  14 /* log session to file stuff ... */
  15 struct LogContext {
  16     FILE *lgfp;
  17     enum { L_CLOSED, L_OPENING, L_OPEN, L_ERROR } state;
  18     bufchain queue;
  19     Filename currlogfilename;
  20     void *frontend;
  21     Config cfg;
  22 };
  23
  24 static void xlatlognam(Filename *d, Filename s, char *hostname, struct tm *tm);
  25
  26 /*
  27  * Internal wrapper function which must be called for _all_ output
  28  * to the log file. It takes care of opening the log file if it
  29  * isn't open, buffering data if it's in the process of being
  30  * opened asynchronously, etc.
  31  */
  32 static void logwrite(struct LogContext *ctx, void *data, int len)
  33 {
  34     /*
  35      * In state L_CLOSED, we call logfopen, which will set the state
  36      * to one of L_OPENING, L_OPEN or L_ERROR. Hence we process all of
  37      * those three _after_ processing L_CLOSED.
  38      */
  39     if (ctx->state == L_CLOSED)
  40         logfopen(ctx);
  41
  42     if (ctx->state == L_OPENING) {
  43         bufchain_add(&ctx->queue, data, len);
  44     } else if (ctx->state == L_OPEN) {
  45         assert(ctx->lgfp);
  46         fwrite(data, 1, len, ctx->lgfp);
  47     }                                  /* else L_ERROR, so ignore the write */
  48 }
  49
  50 /*
  51  * Convenience wrapper on logwrite() which printf-formats the
  52  * string.
  53  */
  54 static void logprintf(struct LogContext *ctx, const char *fmt, ...)
  55 {
  56     va_list ap;
  57     char *data;
  58
  59     va_start(ap, fmt);
  60     data = dupvprintf(fmt, ap);
  61     va_end(ap);
  62
  63     logwrite(ctx, data, strlen(data));
  64     sfree(data);
  65 }
  66
  67 /*
  68  * Flush any open log file.
  69  */
  70 void logflush(void *handle) {
  71     struct LogContext *ctx = (struct LogContext *)handle;
  72     if (ctx->cfg.logtype > 0)
  73         if (ctx->state == L_OPEN)
  74             fflush(ctx->lgfp);
  75 }
  76
  77 static void logfopen_callback(void *handle, int mode)
  78 {
  79     struct LogContext *ctx = (struct LogContext *)handle;
  80     char buf[256], *event;
  81     struct tm tm;
  82     const char *fmode;
  83
  84     if (mode == 0) {
  85         ctx->state = L_ERROR;          /* disable logging */
  86     } else {
  87         fmode = (mode == 1 ? "ab" : "wb");
  88         ctx->lgfp = f_open(ctx->currlogfilename, fmode, TRUE);
  89         if (ctx->lgfp)
  90             ctx->state = L_OPEN;
  91         else
  92             ctx->state = L_ERROR;
  93     }
  94
  95     if (ctx->state == L_OPEN) {
  96         /* Write header line into log file. */
  97         tm = ltime();
  98         strftime(buf, 24, "%Y.%m.%d %H:%M:%S", &tm);
  99         logprintf(ctx, "=~=~=~=~=~=~=~=~=~=~=~= PuTTY log %s"
 100                   " =~=~=~=~=~=~=~=~=~=~=~=\r\n", buf);
 101     }
 102
 103     event = dupprintf("%s session log (%s mode) to file: %s",
 104                       (mode == 0 ? "Disabled writing" :
 105                        mode == 1 ? "Appending" : "Writing new"),
 106                       (ctx->cfg.logtype == LGTYP_ASCII ? "ASCII" :
 107                        ctx->cfg.logtype == LGTYP_DEBUG ? "raw" :
 108                        ctx->cfg.logtype == LGTYP_PACKETS ? "SSH packets" :
 109                        ctx->cfg.logtype == LGTYP_SSHRAW ? "SSH raw data" :
 110                        "unknown"),
 111                       filename_to_str(&ctx->currlogfilename));
 112     logevent(ctx->frontend, event);
 113     sfree(event);
 114
 115     /*
 116      * Having either succeeded or failed in opening the log file,
 117      * we should write any queued data out.
 118      */
 119     assert(ctx->state != L_OPENING);   /* make _sure_ it won't be requeued */
 120     while (bufchain_size(&ctx->queue)) {
 121         void *data;
 122         int len;
 123         bufchain_prefix(&ctx->queue, &data, &len);
 124         logwrite(ctx, data, len);
 125         bufchain_consume(&ctx->queue, len);
 126     }
 127 }
 128
 129 /*
 130  * Open the log file. Takes care of detecting an already-existing
 131  * file and asking the user whether they want to append, overwrite
 132  * or cancel logging.
 133  */
 134 void logfopen(void *handle)
 135 {
 136     struct LogContext *ctx = (struct LogContext *)handle;
 137     struct tm tm;
 138     int mode;
 139
 140     /* Prevent repeat calls */
 141     if (ctx->state != L_CLOSED)
 142         return;
 143
 144     if (!ctx->cfg.logtype)
 145         return;
 146
 147     tm = ltime();
 148
 149     /* substitute special codes in file name */
 150     xlatlognam(&ctx->currlogfilename, ctx->cfg.logfilename,ctx->cfg.host, &tm);
 151
 152     ctx->lgfp = f_open(ctx->currlogfilename, "r", FALSE);  /* file already present? */
 153     if (ctx->lgfp) {
 154         fclose(ctx->lgfp);
 155         if (ctx->cfg.logxfovr != LGXF_ASK) {
 156             mode = ((ctx->cfg.logxfovr == LGXF_OVR) ? 2 : 1);
 157         } else
 158             mode = askappend(ctx->frontend, ctx->currlogfilename,
 159                              logfopen_callback, ctx);
 160     } else
 161         mode = 2;                      /* create == overwrite */
 162
 163     if (mode < 0)
 164         ctx->state = L_OPENING;
 165     else
 166         logfopen_callback(ctx, mode);  /* open the file */
 167 }
 168
 169 void logfclose(void *handle)
 170 {
 171     struct LogContext *ctx = (struct LogContext *)handle;
 172     if (ctx->lgfp) {
 173         fclose(ctx->lgfp);
 174         ctx->lgfp = NULL;
 175     }
 176     ctx->state = L_CLOSED;
 177 }
 178
 179 /*
 180  * Log session traffic.
 181  */
 182 void logtraffic(void *handle, unsigned char c, int logmode)
 183 {
 184     struct LogContext *ctx = (struct LogContext *)handle;
 185     if (ctx->cfg.logtype > 0) {
 186         if (ctx->cfg.logtype == logmode)
 187             logwrite(ctx, &c, 1);
 188     }
 189 }
 190
 191 /*
 192  * Log an Event Log entry. Used in SSH packet logging mode; this is
 193  * also as convenient a place as any to put the output of Event Log
 194  * entries to stderr when a command-line tool is in verbose mode.
 195  * (In particular, this is a better place to put it than in the
 196  * front ends, because it only has to be done once for all
 197  * platforms. Platforms which don't have a meaningful stderr can
 198  * just avoid defining FLAG_STDERR.
 199  */
 200 void log_eventlog(void *handle, const char *event)
 201 {
 202     struct LogContext *ctx = (struct LogContext *)handle;
 203     if ((flags & FLAG_STDERR) && (flags & FLAG_VERBOSE)) {
 204         fprintf(stderr, "%s\n", event);
 205         fflush(stderr);
 206     }
 207     /* If we don't have a context yet (eg winnet.c init) then skip entirely */
 208     if (!ctx)
 209         return;
 210     if (ctx->cfg.logtype != LGTYP_PACKETS &&
 211         ctx->cfg.logtype != LGTYP_SSHRAW)
 212         return;
 213     logprintf(ctx, "Event Log: %s\r\n", event);
 214     logflush(ctx);
 215 }
 216
 217 /*
 218  * Log an SSH packet.
 219  * If n_blanks != 0, blank or omit some parts.
 220  * Set of blanking areas must be in increasing order.
 221  */
 222 void log_packet(void *handle, int direction, int type,
 223                 char *texttype, void *data, int len,
 224                 int n_blanks, const struct logblank_t *blanks)
 225 {
 226     struct LogContext *ctx = (struct LogContext *)handle;
 227     char dumpdata[80], smalldata[5];
 228     int p = 0, b = 0, omitted = 0;
 229     int output_pos = 0; /* NZ if pending output in dumpdata */
 230
 231     if (!(ctx->cfg.logtype == LGTYP_SSHRAW ||
 232           (ctx->cfg.logtype == LGTYP_PACKETS && texttype)))
 233         return;
 234
 235     /* Packet header. */
 236     if (texttype)
 237         logprintf(ctx, "%s packet type %d / 0x%02x (%s)\r\n",
 238                   direction == PKT_INCOMING ? "Incoming" : "Outgoing",
 239                   type, type, texttype);
 240     else
 241         logprintf(ctx, "%s raw data\r\n",
 242                   direction == PKT_INCOMING ? "Incoming" : "Outgoing");
 243
 244     /*
 245      * Output a hex/ASCII dump of the packet body, blanking/omitting
 246      * parts as specified.
 247      */
 248     while (p < len) {
 249         int blktype;
 250
 251         /* Move to a current entry in the blanking array. */
 252         while ((b < n_blanks) &&
 253                (p >= blanks[b].offset + blanks[b].len))
 254             b++;
 255         /* Work out what type of blanking to apply to
 256          * this byte. */
 257         blktype = PKTLOG_EMIT; /* default */
 258         if ((b < n_blanks) &&
 259             (p >= blanks[b].offset) &&
 260             (p < blanks[b].offset + blanks[b].len))
 261             blktype = blanks[b].type;
 262
 263         /* If we're about to stop omitting, it's time to say how
 264          * much we omitted. */
 265         if ((blktype != PKTLOG_OMIT) && omitted) {
 266             logprintf(ctx, "  (%d byte%s omitted)\r\n",
 267                       omitted, (omitted==1?"":"s"));
 268             omitted = 0;
 269         }
 270
 271         /* (Re-)initialise dumpdata as necessary
 272          * (start of row, or if we've just stopped omitting) */
 273         if (!output_pos && !omitted)
 274             sprintf(dumpdata, "  %08x%*s\r\n", p-(p%16), 1+3*16+2+16, "");
 275
 276         /* Deal with the current byte. */
 277         if (blktype == PKTLOG_OMIT) {
 278             omitted++;
 279         } else {
 280             int c;
 281             if (blktype == PKTLOG_BLANK) {
 282                 c = 'X';
 283                 sprintf(smalldata, "XX");
 284             } else {  /* PKTLOG_EMIT */
 285                 c = ((unsigned char *)data)[p];
 286                 sprintf(smalldata, "%02x", c);
 287             }
 288             dumpdata[10+2+3*(p%16)] = smalldata[0];
 289             dumpdata[10+2+3*(p%16)+1] = smalldata[1];
 290             dumpdata[10+1+3*16+2+(p%16)] = (isprint(c) ? c : '.');
 291             output_pos = (p%16) + 1;
 292         }
 293
 294         p++;
 295
 296         /* Flush row if necessary */
 297         if (((p % 16) == 0) || (p == len) || omitted) {
 298             if (output_pos) {
 299                 strcpy(dumpdata + 10+1+3*16+2+output_pos, "\r\n");
 300                 logwrite(ctx, dumpdata, strlen(dumpdata));
 301                 output_pos = 0;
 302             }
 303         }
 304
 305     }
 306
 307     /* Tidy up */
 308     if (omitted)
 309         logprintf(ctx, "  (%d byte%s omitted)\r\n",
 310                   omitted, (omitted==1?"":"s"));
 311     logflush(ctx);
 312 }
 313
 314 void *log_init(void *frontend, Config *cfg)
 315 {
 316     struct LogContext *ctx = snew(struct LogContext);
 317     ctx->lgfp = NULL;
 318     ctx->state = L_CLOSED;
 319     ctx->frontend = frontend;
 320     ctx->cfg = *cfg;                   /* STRUCTURE COPY */
 321     bufchain_init(&ctx->queue);
 322     return ctx;
 323 }
 324
 325 void log_free(void *handle)
 326 {
 327     struct LogContext *ctx = (struct LogContext *)handle;
 328
 329     logfclose(ctx);
 330     bufchain_clear(&ctx->queue);
 331     sfree(ctx);
 332 }
 333
 334 void log_reconfig(void *handle, Config *cfg)
 335 {
 336     struct LogContext *ctx = (struct LogContext *)handle;
 337     int reset_logging;
 338
 339     if (!filename_equal(ctx->cfg.logfilename, cfg->logfilename) ||
 340         ctx->cfg.logtype != cfg->logtype)
 341         reset_logging = TRUE;
 342     else
 343         reset_logging = FALSE;
 344
 345     if (reset_logging)
 346         logfclose(ctx);
 347
 348     ctx->cfg = *cfg;                   /* STRUCTURE COPY */
 349
 350     if (reset_logging)
 351         logfopen(ctx);
 352 }
 353
 354 /*
 355  * translate format codes into time/date strings
 356  * and insert them into log file name
 357  *
 358  * "&Y":YYYY   "&m":MM   "&d":DD   "&T":hhmmss   "&h":<hostname>   "&&":&
 359  */
 360 static void xlatlognam(Filename *dest, Filename src,
 361                        char *hostname, struct tm *tm) {
 362     char buf[10], *bufp;
 363     int size;
 364     char buffer[FILENAME_MAX];
 365     int len = sizeof(buffer)-1;
 366     char *d;
 367     const char *s;
 368
 369     d = buffer;
 370     s = filename_to_str(&src);
 371
 372     while (*s) {
 373         /* Let (bufp, len) be the string to append. */
 374         bufp = buf;                    /* don't usually override this */
 375         if (*s == '&') {
 376             char c;
 377             s++;
 378             size = 0;
 379             if (*s) switch (c = *s++, tolower(c)) {
 380               case 'y':
 381                 size = strftime(buf, sizeof(buf), "%Y", tm);
 382                 break;
 383               case 'm':
 384                 size = strftime(buf, sizeof(buf), "%m", tm);
 385                 break;
 386               case 'd':
 387                 size = strftime(buf, sizeof(buf), "%d", tm);
 388                 break;
 389               case 't':
 390                 size = strftime(buf, sizeof(buf), "%H%M%S", tm);
 391                 break;
 392               case 'h':
 393                 bufp = hostname;
 394                 size = strlen(bufp);
 395                 break;
 396               default:
 397                 buf[0] = '&';
 398                 size = 1;
 399                 if (c != '&')
 400                     buf[size++] = c;
 401             }
 402         } else {
 403             buf[0] = *s++;
 404             size = 1;
 405         }
 406         if (size > len)
 407             size = len;
 408         memcpy(d, bufp, size);
 409         d += size;
 410         len -= size;
 411     }
 412     *d = '\0';
 413
 414     *dest = filename_from_str(buffer);
 415 }