logging.c

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