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