src/TortoisePlink/LOGGING.C

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