X-Git-Url: https://asedeno.scripts.mit.edu/gitweb/?a=blobdiff_plain;f=logging.c;h=865fe9b82ed8dc547b48ddb2d06cdc010dd8973d;hb=991d30412d0911e7727a852d0a00ae0f1bec1b3e;hp=b2401c38c456a3d544281aa4e7a782c1eb4cc789;hpb=a1f3b7a358adaa7c2a98359cd0373aa823eeb14b;p=PuTTY.git diff --git a/logging.c b/logging.c index b2401c38..865fe9b8 100644 --- a/logging.c +++ b/logging.c @@ -16,13 +16,14 @@ struct LogContext { FILE *lgfp; enum { L_CLOSED, L_OPENING, L_OPEN, L_ERROR } state; bufchain queue; - Filename currlogfilename; + Filename *currlogfilename; void *frontend; Conf *conf; int logtype; /* cached out of conf */ }; -static void xlatlognam(Filename *d, Filename s, char *hostname, struct tm *tm); +static Filename *xlatlognam(Filename *s, char *hostname, int port, + struct tm *tm); /* * Internal wrapper function which must be called for _all_ output @@ -87,16 +88,19 @@ static void logfopen_callback(void *handle, int mode) char buf[256], *event; struct tm tm; const char *fmode; + int shout = FALSE; if (mode == 0) { ctx->state = L_ERROR; /* disable logging */ } else { fmode = (mode == 1 ? "ab" : "wb"); ctx->lgfp = f_open(ctx->currlogfilename, fmode, FALSE); - if (ctx->lgfp) + if (ctx->lgfp) { ctx->state = L_OPEN; - else + } else { ctx->state = L_ERROR; + shout = TRUE; + } } if (ctx->state == L_OPEN) { @@ -116,8 +120,25 @@ static void logfopen_callback(void *handle, int mode) ctx->logtype == LGTYP_PACKETS ? "SSH packets" : ctx->logtype == LGTYP_SSHRAW ? "SSH raw data" : "unknown"), - filename_to_str(&ctx->currlogfilename)); + filename_to_str(ctx->currlogfilename)); logevent(ctx->frontend, event); + if (shout) { + /* + * If we failed to open the log file due to filesystem error + * (as opposed to user action such as clicking Cancel in the + * askappend box), we should log it more prominently. We do + * this by sending it to the same place that stderr output + * from the main session goes (so, either a console tool's + * actual stderr, or a terminal window). + * + * Of course this is one case in which that policy won't cause + * it to turn up embarrassingly in a log file of real server + * output, because the whole point is that we haven't managed + * to open any such log file :-) + */ + from_backend(ctx->frontend, 1, event, strlen(event)); + from_backend(ctx->frontend, 1, "\r\n", 2); + } sfree(event); /* @@ -143,6 +164,7 @@ void logfopen(void *handle) { struct LogContext *ctx = (struct LogContext *)handle; struct tm tm; + FILE *fp; int mode; /* Prevent repeat calls */ @@ -155,14 +177,17 @@ void logfopen(void *handle) tm = ltime(); /* substitute special codes in file name */ - xlatlognam(&ctx->currlogfilename, - *conf_get_filename(ctx->conf, CONF_logfilename), - conf_get_str(ctx->conf, CONF_host), &tm); - - ctx->lgfp = f_open(ctx->currlogfilename, "r", FALSE); /* file already present? */ - if (ctx->lgfp) { + if (ctx->currlogfilename) + filename_free(ctx->currlogfilename); + ctx->currlogfilename = + xlatlognam(conf_get_filename(ctx->conf, CONF_logfilename), + conf_get_str(ctx->conf, CONF_host), + conf_get_int(ctx->conf, CONF_port), &tm); + + fp = f_open(ctx->currlogfilename, "r", FALSE); /* file already present? */ + if (fp) { int logxfovr = conf_get_int(ctx->conf, CONF_logxfovr); - fclose(ctx->lgfp); + fclose(fp); if (logxfovr != LGXF_ASK) { mode = ((logxfovr == LGXF_OVR) ? 2 : 1); } else @@ -231,9 +256,10 @@ void log_eventlog(void *handle, const char *event) * Set of blanking areas must be in increasing order. */ void log_packet(void *handle, int direction, int type, - char *texttype, const void *data, int len, + const char *texttype, const void *data, int len, int n_blanks, const struct logblank_t *blanks, - const unsigned long *seq) + const unsigned long *seq, + unsigned downstream_id, const char *additional_log_text) { struct LogContext *ctx = (struct LogContext *)handle; char dumpdata[80], smalldata[5]; @@ -246,18 +272,37 @@ void log_packet(void *handle, int direction, int type, /* Packet header. */ if (texttype) { - if (seq) { - logprintf(ctx, "%s packet #0x%lx, type %d / 0x%02x (%s)\r\n", - direction == PKT_INCOMING ? "Incoming" : "Outgoing", - *seq, type, type, texttype); - } else { - 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", + logprintf(ctx, "%s packet ", direction == PKT_INCOMING ? "Incoming" : "Outgoing"); + + if (seq) + logprintf(ctx, "#0x%lx, ", *seq); + + logprintf(ctx, "type %d / 0x%02x (%s)", type, type, texttype); + + if (downstream_id) { + logprintf(ctx, " on behalf of downstream #%u", downstream_id); + if (additional_log_text) + logprintf(ctx, " (%s)", additional_log_text); + } + + logprintf(ctx, "\r\n"); + } else { + /* + * Raw data is logged with a timestamp, so that it's possible + * to determine whether a mysterious delay occurred at the + * client or server end. (Timestamping the raw data avoids + * cluttering the normal case of only logging decrypted SSH + * messages, and also adds conceptual rigour in the case where + * an SSH message arrives in several pieces.) + */ + char buf[256]; + struct tm tm; + tm = ltime(); + strftime(buf, 24, "%Y-%m-%d %H:%M:%S", &tm); + logprintf(ctx, "%s raw data at %s\r\n", + direction == PKT_INCOMING ? "Incoming" : "Outgoing", + buf); } /* @@ -338,6 +383,7 @@ void *log_init(void *frontend, Conf *conf) ctx->frontend = frontend; ctx->conf = conf_copy(conf); ctx->logtype = conf_get_int(ctx->conf, CONF_logtype); + ctx->currlogfilename = NULL; bufchain_init(&ctx->queue); return ctx; } @@ -348,6 +394,9 @@ void log_free(void *handle) logfclose(ctx); bufchain_clear(&ctx->queue); + if (ctx->currlogfilename) + filename_free(ctx->currlogfilename); + conf_free(ctx->conf); sfree(ctx); } @@ -356,8 +405,8 @@ void log_reconfig(void *handle, Conf *conf) struct LogContext *ctx = (struct LogContext *)handle; int reset_logging; - if (!filename_equal(*conf_get_filename(ctx->conf, CONF_logfilename), - *conf_get_filename(conf, CONF_logfilename)) || + if (!filename_equal(conf_get_filename(ctx->conf, CONF_logfilename), + conf_get_filename(conf, CONF_logfilename)) || conf_get_int(ctx->conf, CONF_logtype) != conf_get_int(conf, CONF_logtype)) reset_logging = TRUE; @@ -382,19 +431,23 @@ void log_reconfig(void *handle, Conf *conf) * * "&Y":YYYY "&m":MM "&d":DD "&T":hhmmss "&h": "&&":& */ -static void xlatlognam(Filename *dest, Filename src, - char *hostname, struct tm *tm) { - char buf[10], *bufp; +static Filename *xlatlognam(Filename *src, char *hostname, int port, + struct tm *tm) +{ + char buf[32], *bufp; int size; - char buffer[FILENAME_MAX]; - int len = sizeof(buffer)-1; - char *d; + char *buffer; + int buflen, bufsize; const char *s; + Filename *ret; - d = buffer; - s = filename_to_str(&src); + bufsize = FILENAME_MAX; + buffer = snewn(bufsize, char); + buflen = 0; + s = filename_to_str(src); while (*s) { + int sanitise = FALSE; /* Let (bufp, len) be the string to append. */ bufp = buf; /* don't usually override this */ if (*s == '&') { @@ -418,23 +471,39 @@ static void xlatlognam(Filename *dest, Filename src, bufp = hostname; size = strlen(bufp); break; + case 'p': + size = sprintf(buf, "%d", port); + break; default: buf[0] = '&'; size = 1; if (c != '&') buf[size++] = c; } + /* Never allow path separators - or any other illegal + * filename character - to come out of any of these + * auto-format directives. E.g. 'hostname' can contain + * colons, if it's an IPv6 address, and colons aren't + * legal in filenames on Windows. */ + sanitise = TRUE; } else { buf[0] = *s++; size = 1; } - if (size > len) - size = len; - memcpy(d, bufp, size); - d += size; - len -= size; + if (bufsize <= buflen + size) { + bufsize = (buflen + size) * 5 / 4 + 512; + buffer = sresize(buffer, bufsize, char); + } + while (size-- > 0) { + char c = *bufp++; + if (sanitise) + c = filename_char_sanitise(c); + buffer[buflen++] = c; + } } - *d = '\0'; + buffer[buflen] = '\0'; - *dest = filename_from_str(buffer); + ret = filename_from_str(buffer); + sfree(buffer); + return ret; }