14 /* log session to file stuff ... */
\r
17 enum { L_CLOSED, L_OPENING, L_OPEN, L_ERROR } state;
\r
19 Filename *currlogfilename;
\r
22 int logtype; /* cached out of conf */
\r
25 static Filename *xlatlognam(const Filename *s,
\r
26 const char *hostname, int port,
\r
27 const struct tm *tm);
\r
30 * Internal wrapper function which must be called for _all_ output
\r
31 * to the log file. It takes care of opening the log file if it
\r
32 * isn't open, buffering data if it's in the process of being
\r
33 * opened asynchronously, etc.
\r
35 static void logwrite(LogContext *ctx, ptrlen data)
\r
38 * In state L_CLOSED, we call logfopen, which will set the state
\r
39 * to one of L_OPENING, L_OPEN or L_ERROR. Hence we process all of
\r
40 * those three _after_ processing L_CLOSED.
\r
42 if (ctx->state == L_CLOSED)
\r
45 if (ctx->state == L_OPENING) {
\r
46 bufchain_add(&ctx->queue, data.ptr, data.len);
\r
47 } else if (ctx->state == L_OPEN) {
\r
49 if (fwrite(data.ptr, 1, data.len, ctx->lgfp) < data.len) {
\r
51 ctx->state = L_ERROR;
\r
52 lp_eventlog(ctx->lp, "Disabled writing session log "
\r
53 "due to error while writing");
\r
55 } /* else L_ERROR, so ignore the write */
\r
59 * Convenience wrapper on logwrite() which printf-formats the
\r
62 static PRINTF_LIKE(2, 3) void logprintf(LogContext *ctx, const char *fmt, ...)
\r
68 data = dupvprintf(fmt, ap);
\r
71 logwrite(ctx, ptrlen_from_asciz(data));
\r
76 * Flush any open log file.
\r
78 void logflush(LogContext *ctx)
\r
80 if (ctx->logtype > 0)
\r
81 if (ctx->state == L_OPEN)
\r
85 LogPolicy *log_get_policy(LogContext *ctx)
\r
90 static void logfopen_callback(void *vctx, int mode)
\r
92 LogContext *ctx = (LogContext *)vctx;
\r
93 char buf[256], *event;
\r
99 ctx->state = L_ERROR; /* disable logging */
\r
101 fmode = (mode == 1 ? "ab" : "wb");
\r
102 ctx->lgfp = f_open(ctx->currlogfilename, fmode, false);
\r
104 ctx->state = L_OPEN;
\r
106 ctx->state = L_ERROR;
\r
111 if (ctx->state == L_OPEN && conf_get_bool(ctx->conf, CONF_logheader)) {
\r
112 /* Write header line into log file. */
\r
114 strftime(buf, 24, "%Y.%m.%d %H:%M:%S", &tm);
\r
115 logprintf(ctx, "=~=~=~=~=~=~=~=~=~=~=~= PuTTY log %s"
\r
116 " =~=~=~=~=~=~=~=~=~=~=~=\r\n", buf);
\r
119 event = dupprintf("%s session log (%s mode) to file: %s",
\r
120 ctx->state == L_ERROR ?
\r
121 (mode == 0 ? "Disabled writing" : "Error writing") :
\r
122 (mode == 1 ? "Appending" : "Writing new"),
\r
123 (ctx->logtype == LGTYP_ASCII ? "ASCII" :
\r
124 ctx->logtype == LGTYP_DEBUG ? "raw" :
\r
125 ctx->logtype == LGTYP_PACKETS ? "SSH packets" :
\r
126 ctx->logtype == LGTYP_SSHRAW ? "SSH raw data" :
\r
128 filename_to_str(ctx->currlogfilename));
\r
129 lp_eventlog(ctx->lp, event);
\r
132 * If we failed to open the log file due to filesystem error
\r
133 * (as opposed to user action such as clicking Cancel in the
\r
134 * askappend box), we should log it more prominently.
\r
136 lp_logging_error(ctx->lp, event);
\r
141 * Having either succeeded or failed in opening the log file,
\r
142 * we should write any queued data out.
\r
144 assert(ctx->state != L_OPENING); /* make _sure_ it won't be requeued */
\r
145 while (bufchain_size(&ctx->queue)) {
\r
146 ptrlen data = bufchain_prefix(&ctx->queue);
\r
147 logwrite(ctx, data);
\r
148 bufchain_consume(&ctx->queue, data.len);
\r
154 * Open the log file. Takes care of detecting an already-existing
\r
155 * file and asking the user whether they want to append, overwrite
\r
156 * or cancel logging.
\r
158 void logfopen(LogContext *ctx)
\r
163 /* Prevent repeat calls */
\r
164 if (ctx->state != L_CLOSED)
\r
172 /* substitute special codes in file name */
\r
173 if (ctx->currlogfilename)
\r
174 filename_free(ctx->currlogfilename);
\r
175 ctx->currlogfilename =
\r
176 xlatlognam(conf_get_filename(ctx->conf, CONF_logfilename),
\r
177 conf_dest(ctx->conf), /* hostname or serial line */
\r
178 conf_get_int(ctx->conf, CONF_port), &tm);
\r
180 if (open_for_write_would_lose_data(ctx->currlogfilename)) {
\r
181 int logxfovr = conf_get_int(ctx->conf, CONF_logxfovr);
\r
182 if (logxfovr != LGXF_ASK) {
\r
183 mode = ((logxfovr == LGXF_OVR) ? 2 : 1);
\r
185 mode = lp_askappend(ctx->lp, ctx->currlogfilename,
\r
186 logfopen_callback, ctx);
\r
188 mode = 2; /* create == overwrite */
\r
191 ctx->state = L_OPENING;
\r
193 logfopen_callback(ctx, mode); /* open the file */
\r
196 void logfclose(LogContext *ctx)
\r
202 ctx->state = L_CLOSED;
\r
206 * Log session traffic.
\r
208 void logtraffic(LogContext *ctx, unsigned char c, int logmode)
\r
210 if (ctx->logtype > 0) {
\r
211 if (ctx->logtype == logmode)
\r
212 logwrite(ctx, make_ptrlen(&c, 1));
\r
216 static void logevent_internal(LogContext *ctx, const char *event)
\r
218 if (ctx->logtype == LGTYP_PACKETS || ctx->logtype == LGTYP_SSHRAW) {
\r
219 logprintf(ctx, "Event Log: %s\r\n", event);
\r
222 lp_eventlog(ctx->lp, event);
\r
225 void logevent(LogContext *ctx, const char *event)
\r
231 * Replace newlines in Event Log messages with spaces. (Sometimes
\r
232 * the same message string is reused for the Event Log and a GUI
\r
233 * dialog box; newlines are sometimes appropriate in the latter,
\r
234 * but never in the former.)
\r
236 if (strchr(event, '\n') || strchr(event, '\r')) {
\r
237 char *dup = dupstr(event);
\r
238 char *p = dup, *q = dup;
\r
240 if (*p == '\r' || *p == '\n') {
\r
243 } while (*p == '\r' || *p == '\n');
\r
250 logevent_internal(ctx, dup);
\r
253 logevent_internal(ctx, event);
\r
257 void logevent_and_free(LogContext *ctx, char *event)
\r
259 logevent(ctx, event);
\r
263 void logeventvf(LogContext *ctx, const char *fmt, va_list ap)
\r
265 logevent_and_free(ctx, dupvprintf(fmt, ap));
\r
268 void logeventf(LogContext *ctx, const char *fmt, ...)
\r
273 logeventvf(ctx, fmt, ap);
\r
278 * Log an SSH packet.
\r
279 * If n_blanks != 0, blank or omit some parts.
\r
280 * Set of blanking areas must be in increasing order.
\r
282 void log_packet(LogContext *ctx, int direction, int type,
\r
283 const char *texttype, const void *data, size_t len,
\r
284 int n_blanks, const struct logblank_t *blanks,
\r
285 const unsigned long *seq,
\r
286 unsigned downstream_id, const char *additional_log_text)
\r
288 char dumpdata[128], smalldata[5];
\r
289 size_t p = 0, b = 0, omitted = 0;
\r
290 int output_pos = 0; /* NZ if pending output in dumpdata */
\r
292 if (!(ctx->logtype == LGTYP_SSHRAW ||
\r
293 (ctx->logtype == LGTYP_PACKETS && texttype)))
\r
296 /* Packet header. */
\r
298 logprintf(ctx, "%s packet ",
\r
299 direction == PKT_INCOMING ? "Incoming" : "Outgoing");
\r
302 logprintf(ctx, "#0x%lx, ", *seq);
\r
304 logprintf(ctx, "type %d / 0x%02x (%s)", type, type, texttype);
\r
306 if (downstream_id) {
\r
307 logprintf(ctx, " on behalf of downstream #%u", downstream_id);
\r
308 if (additional_log_text)
\r
309 logprintf(ctx, " (%s)", additional_log_text);
\r
312 logprintf(ctx, "\r\n");
\r
315 * Raw data is logged with a timestamp, so that it's possible
\r
316 * to determine whether a mysterious delay occurred at the
\r
317 * client or server end. (Timestamping the raw data avoids
\r
318 * cluttering the normal case of only logging decrypted SSH
\r
319 * messages, and also adds conceptual rigour in the case where
\r
320 * an SSH message arrives in several pieces.)
\r
325 strftime(buf, 24, "%Y-%m-%d %H:%M:%S", &tm);
\r
326 logprintf(ctx, "%s raw data at %s\r\n",
\r
327 direction == PKT_INCOMING ? "Incoming" : "Outgoing",
\r
332 * Output a hex/ASCII dump of the packet body, blanking/omitting
\r
333 * parts as specified.
\r
338 /* Move to a current entry in the blanking array. */
\r
339 while ((b < n_blanks) &&
\r
340 (p >= blanks[b].offset + blanks[b].len))
\r
342 /* Work out what type of blanking to apply to
\r
344 blktype = PKTLOG_EMIT; /* default */
\r
345 if ((b < n_blanks) &&
\r
346 (p >= blanks[b].offset) &&
\r
347 (p < blanks[b].offset + blanks[b].len))
\r
348 blktype = blanks[b].type;
\r
350 /* If we're about to stop omitting, it's time to say how
\r
351 * much we omitted. */
\r
352 if ((blktype != PKTLOG_OMIT) && omitted) {
\r
353 logprintf(ctx, " (%"SIZEu" byte%s omitted)\r\n",
\r
354 omitted, (omitted==1?"":"s"));
\r
358 /* (Re-)initialise dumpdata as necessary
\r
359 * (start of row, or if we've just stopped omitting) */
\r
360 if (!output_pos && !omitted)
\r
361 sprintf(dumpdata, " %08"SIZEx"%*s\r\n",
\r
362 p-(p%16), 1+3*16+2+16, "");
\r
364 /* Deal with the current byte. */
\r
365 if (blktype == PKTLOG_OMIT) {
\r
369 if (blktype == PKTLOG_BLANK) {
\r
371 sprintf(smalldata, "XX");
\r
372 } else { /* PKTLOG_EMIT */
\r
373 c = ((const unsigned char *)data)[p];
\r
374 sprintf(smalldata, "%02x", c);
\r
376 dumpdata[10+2+3*(p%16)] = smalldata[0];
\r
377 dumpdata[10+2+3*(p%16)+1] = smalldata[1];
\r
378 dumpdata[10+1+3*16+2+(p%16)] = (c >= 0x20 && c < 0x7F ? c : '.');
\r
379 output_pos = (p%16) + 1;
\r
384 /* Flush row if necessary */
\r
385 if (((p % 16) == 0) || (p == len) || omitted) {
\r
387 strcpy(dumpdata + 10+1+3*16+2+output_pos, "\r\n");
\r
388 logwrite(ctx, ptrlen_from_asciz(dumpdata));
\r
397 logprintf(ctx, " (%"SIZEu" byte%s omitted)\r\n",
\r
398 omitted, (omitted==1?"":"s"));
\r
402 LogContext *log_init(LogPolicy *lp, Conf *conf)
\r
404 LogContext *ctx = snew(LogContext);
\r
406 ctx->state = L_CLOSED;
\r
408 ctx->conf = conf_copy(conf);
\r
409 ctx->logtype = conf_get_int(ctx->conf, CONF_logtype);
\r
410 ctx->currlogfilename = NULL;
\r
411 bufchain_init(&ctx->queue);
\r
415 void log_free(LogContext *ctx)
\r
418 bufchain_clear(&ctx->queue);
\r
419 if (ctx->currlogfilename)
\r
420 filename_free(ctx->currlogfilename);
\r
421 conf_free(ctx->conf);
\r
425 void log_reconfig(LogContext *ctx, Conf *conf)
\r
427 bool reset_logging;
\r
429 if (!filename_equal(conf_get_filename(ctx->conf, CONF_logfilename),
\r
430 conf_get_filename(conf, CONF_logfilename)) ||
\r
431 conf_get_int(ctx->conf, CONF_logtype) !=
\r
432 conf_get_int(conf, CONF_logtype))
\r
433 reset_logging = true;
\r
435 reset_logging = false;
\r
440 conf_free(ctx->conf);
\r
441 ctx->conf = conf_copy(conf);
\r
443 ctx->logtype = conf_get_int(ctx->conf, CONF_logtype);
\r
450 * translate format codes into time/date strings
\r
451 * and insert them into log file name
\r
453 * "&Y":YYYY "&m":MM "&d":DD "&T":hhmmss "&h":<hostname> "&&":&
\r
455 static Filename *xlatlognam(const Filename *src,
\r
456 const char *hostname, int port,
\r
457 const struct tm *tm)
\r
466 buffer = strbuf_new();
\r
467 s = filename_to_str(src);
\r
470 bool sanitise = false;
\r
471 /* Let (bufp, len) be the string to append. */
\r
472 bufp = buf; /* don't usually override this */
\r
477 if (*s) switch (c = *s++, tolower((unsigned char)c)) {
\r
479 size = strftime(buf, sizeof(buf), "%Y", tm);
\r
482 size = strftime(buf, sizeof(buf), "%m", tm);
\r
485 size = strftime(buf, sizeof(buf), "%d", tm);
\r
488 size = strftime(buf, sizeof(buf), "%H%M%S", tm);
\r
492 size = strlen(bufp);
\r
495 size = sprintf(buf, "%d", port);
\r
503 /* Never allow path separators - or any other illegal
\r
504 * filename character - to come out of any of these
\r
505 * auto-format directives. E.g. 'hostname' can contain
\r
506 * colons, if it's an IPv6 address, and colons aren't
\r
507 * legal in filenames on Windows. */
\r
513 while (size-- > 0) {
\r
516 c = filename_char_sanitise(c);
\r
517 put_byte(buffer, c);
\r
521 ret = filename_from_str(buffer->s);
\r
522 strbuf_free(buffer);
\r