14 /* log session to file stuff ... */
17 enum { L_CLOSED, L_OPENING, L_OPEN, L_ERROR } state;
19 Filename *currlogfilename;
22 int logtype; /* cached out of conf */
25 static Filename *xlatlognam(Filename *s, char *hostname, struct tm *tm);
28 * Internal wrapper function which must be called for _all_ output
29 * to the log file. It takes care of opening the log file if it
30 * isn't open, buffering data if it's in the process of being
31 * opened asynchronously, etc.
33 static void logwrite(struct LogContext *ctx, void *data, int len)
36 * In state L_CLOSED, we call logfopen, which will set the state
37 * to one of L_OPENING, L_OPEN or L_ERROR. Hence we process all of
38 * those three _after_ processing L_CLOSED.
40 if (ctx->state == L_CLOSED)
43 if (ctx->state == L_OPENING) {
44 bufchain_add(&ctx->queue, data, len);
45 } else if (ctx->state == L_OPEN) {
47 if (fwrite(data, 1, len, ctx->lgfp) < (size_t)len) {
50 /* Log state is L_ERROR so this won't cause a loop */
51 logevent(ctx->frontend,
52 "Disabled writing session log due to error while writing");
54 } /* else L_ERROR, so ignore the write */
58 * Convenience wrapper on logwrite() which printf-formats the
61 static void logprintf(struct LogContext *ctx, const char *fmt, ...)
67 data = dupvprintf(fmt, ap);
70 logwrite(ctx, data, strlen(data));
75 * Flush any open log file.
77 void logflush(void *handle) {
78 struct LogContext *ctx = (struct LogContext *)handle;
80 if (ctx->state == L_OPEN)
84 static void logfopen_callback(void *handle, int mode)
86 struct LogContext *ctx = (struct LogContext *)handle;
87 char buf[256], *event;
92 ctx->state = L_ERROR; /* disable logging */
94 fmode = (mode == 1 ? "ab" : "wb");
95 ctx->lgfp = f_open(ctx->currlogfilename, fmode, FALSE);
102 if (ctx->state == L_OPEN) {
103 /* Write header line into log file. */
105 strftime(buf, 24, "%Y.%m.%d %H:%M:%S", &tm);
106 logprintf(ctx, "=~=~=~=~=~=~=~=~=~=~=~= PuTTY log %s"
107 " =~=~=~=~=~=~=~=~=~=~=~=\r\n", buf);
110 event = dupprintf("%s session log (%s mode) to file: %s",
111 ctx->state == L_ERROR ?
112 (mode == 0 ? "Disabled writing" : "Error writing") :
113 (mode == 1 ? "Appending" : "Writing new"),
114 (ctx->logtype == LGTYP_ASCII ? "ASCII" :
115 ctx->logtype == LGTYP_DEBUG ? "raw" :
116 ctx->logtype == LGTYP_PACKETS ? "SSH packets" :
117 ctx->logtype == LGTYP_SSHRAW ? "SSH raw data" :
119 filename_to_str(ctx->currlogfilename));
120 logevent(ctx->frontend, event);
124 * Having either succeeded or failed in opening the log file,
125 * we should write any queued data out.
127 assert(ctx->state != L_OPENING); /* make _sure_ it won't be requeued */
128 while (bufchain_size(&ctx->queue)) {
131 bufchain_prefix(&ctx->queue, &data, &len);
132 logwrite(ctx, data, len);
133 bufchain_consume(&ctx->queue, len);
138 * Open the log file. Takes care of detecting an already-existing
139 * file and asking the user whether they want to append, overwrite
142 void logfopen(void *handle)
144 struct LogContext *ctx = (struct LogContext *)handle;
148 /* Prevent repeat calls */
149 if (ctx->state != L_CLOSED)
157 /* substitute special codes in file name */
158 if (ctx->currlogfilename)
159 filename_free(ctx->currlogfilename);
160 ctx->currlogfilename =
161 xlatlognam(conf_get_filename(ctx->conf, CONF_logfilename),
162 conf_get_str(ctx->conf, CONF_host), &tm);
164 ctx->lgfp = f_open(ctx->currlogfilename, "r", FALSE); /* file already present? */
166 int logxfovr = conf_get_int(ctx->conf, CONF_logxfovr);
168 if (logxfovr != LGXF_ASK) {
169 mode = ((logxfovr == LGXF_OVR) ? 2 : 1);
171 mode = askappend(ctx->frontend, ctx->currlogfilename,
172 logfopen_callback, ctx);
174 mode = 2; /* create == overwrite */
177 ctx->state = L_OPENING;
179 logfopen_callback(ctx, mode); /* open the file */
182 void logfclose(void *handle)
184 struct LogContext *ctx = (struct LogContext *)handle;
189 ctx->state = L_CLOSED;
193 * Log session traffic.
195 void logtraffic(void *handle, unsigned char c, int logmode)
197 struct LogContext *ctx = (struct LogContext *)handle;
198 if (ctx->logtype > 0) {
199 if (ctx->logtype == logmode)
200 logwrite(ctx, &c, 1);
205 * Log an Event Log entry. Used in SSH packet logging mode; this is
206 * also as convenient a place as any to put the output of Event Log
207 * entries to stderr when a command-line tool is in verbose mode.
208 * (In particular, this is a better place to put it than in the
209 * front ends, because it only has to be done once for all
210 * platforms. Platforms which don't have a meaningful stderr can
211 * just avoid defining FLAG_STDERR.
213 void log_eventlog(void *handle, const char *event)
215 struct LogContext *ctx = (struct LogContext *)handle;
216 if ((flags & FLAG_STDERR) && (flags & FLAG_VERBOSE)) {
217 fprintf(stderr, "%s\n", event);
220 /* If we don't have a context yet (eg winnet.c init) then skip entirely */
223 if (ctx->logtype != LGTYP_PACKETS &&
224 ctx->logtype != LGTYP_SSHRAW)
226 logprintf(ctx, "Event Log: %s\r\n", event);
232 * If n_blanks != 0, blank or omit some parts.
233 * Set of blanking areas must be in increasing order.
235 void log_packet(void *handle, int direction, int type,
236 char *texttype, const void *data, int len,
237 int n_blanks, const struct logblank_t *blanks,
238 const unsigned long *seq,
239 unsigned downstream_id, const char *additional_log_text)
241 struct LogContext *ctx = (struct LogContext *)handle;
242 char dumpdata[80], smalldata[5];
243 int p = 0, b = 0, omitted = 0;
244 int output_pos = 0; /* NZ if pending output in dumpdata */
246 if (!(ctx->logtype == LGTYP_SSHRAW ||
247 (ctx->logtype == LGTYP_PACKETS && texttype)))
252 logprintf(ctx, "%s packet ",
253 direction == PKT_INCOMING ? "Incoming" : "Outgoing");
256 logprintf(ctx, "#0x%lx, ", *seq);
258 logprintf(ctx, "type %d / 0x%02x (%s)", type, type, texttype);
261 logprintf(ctx, " on behalf of downstream #%u", downstream_id);
262 if (additional_log_text)
263 logprintf(ctx, " (%s)", additional_log_text);
266 logprintf(ctx, "\r\n");
269 * Raw data is logged with a timestamp, so that it's possible
270 * to determine whether a mysterious delay occurred at the
271 * client or server end. (Timestamping the raw data avoids
272 * cluttering the normal case of only logging decrypted SSH
273 * messages, and also adds conceptual rigour in the case where
274 * an SSH message arrives in several pieces.)
279 strftime(buf, 24, "%Y-%m-%d %H:%M:%S", &tm);
280 logprintf(ctx, "%s raw data at %s\r\n",
281 direction == PKT_INCOMING ? "Incoming" : "Outgoing",
286 * Output a hex/ASCII dump of the packet body, blanking/omitting
287 * parts as specified.
292 /* Move to a current entry in the blanking array. */
293 while ((b < n_blanks) &&
294 (p >= blanks[b].offset + blanks[b].len))
296 /* Work out what type of blanking to apply to
298 blktype = PKTLOG_EMIT; /* default */
299 if ((b < n_blanks) &&
300 (p >= blanks[b].offset) &&
301 (p < blanks[b].offset + blanks[b].len))
302 blktype = blanks[b].type;
304 /* If we're about to stop omitting, it's time to say how
305 * much we omitted. */
306 if ((blktype != PKTLOG_OMIT) && omitted) {
307 logprintf(ctx, " (%d byte%s omitted)\r\n",
308 omitted, (omitted==1?"":"s"));
312 /* (Re-)initialise dumpdata as necessary
313 * (start of row, or if we've just stopped omitting) */
314 if (!output_pos && !omitted)
315 sprintf(dumpdata, " %08x%*s\r\n", p-(p%16), 1+3*16+2+16, "");
317 /* Deal with the current byte. */
318 if (blktype == PKTLOG_OMIT) {
322 if (blktype == PKTLOG_BLANK) {
324 sprintf(smalldata, "XX");
325 } else { /* PKTLOG_EMIT */
326 c = ((unsigned char *)data)[p];
327 sprintf(smalldata, "%02x", c);
329 dumpdata[10+2+3*(p%16)] = smalldata[0];
330 dumpdata[10+2+3*(p%16)+1] = smalldata[1];
331 dumpdata[10+1+3*16+2+(p%16)] = (isprint(c) ? c : '.');
332 output_pos = (p%16) + 1;
337 /* Flush row if necessary */
338 if (((p % 16) == 0) || (p == len) || omitted) {
340 strcpy(dumpdata + 10+1+3*16+2+output_pos, "\r\n");
341 logwrite(ctx, dumpdata, strlen(dumpdata));
350 logprintf(ctx, " (%d byte%s omitted)\r\n",
351 omitted, (omitted==1?"":"s"));
355 void *log_init(void *frontend, Conf *conf)
357 struct LogContext *ctx = snew(struct LogContext);
359 ctx->state = L_CLOSED;
360 ctx->frontend = frontend;
361 ctx->conf = conf_copy(conf);
362 ctx->logtype = conf_get_int(ctx->conf, CONF_logtype);
363 ctx->currlogfilename = NULL;
364 bufchain_init(&ctx->queue);
368 void log_free(void *handle)
370 struct LogContext *ctx = (struct LogContext *)handle;
373 bufchain_clear(&ctx->queue);
374 if (ctx->currlogfilename)
375 filename_free(ctx->currlogfilename);
379 void log_reconfig(void *handle, Conf *conf)
381 struct LogContext *ctx = (struct LogContext *)handle;
384 if (!filename_equal(conf_get_filename(ctx->conf, CONF_logfilename),
385 conf_get_filename(conf, CONF_logfilename)) ||
386 conf_get_int(ctx->conf, CONF_logtype) !=
387 conf_get_int(conf, CONF_logtype))
388 reset_logging = TRUE;
390 reset_logging = FALSE;
395 conf_free(ctx->conf);
396 ctx->conf = conf_copy(conf);
398 ctx->logtype = conf_get_int(ctx->conf, CONF_logtype);
405 * translate format codes into time/date strings
406 * and insert them into log file name
408 * "&Y":YYYY "&m":MM "&d":DD "&T":hhmmss "&h":<hostname> "&&":&
410 static Filename *xlatlognam(Filename *src, char *hostname, struct tm *tm)
419 bufsize = FILENAME_MAX;
420 buffer = snewn(bufsize, char);
422 s = filename_to_str(src);
425 /* Let (bufp, len) be the string to append. */
426 bufp = buf; /* don't usually override this */
431 if (*s) switch (c = *s++, tolower((unsigned char)c)) {
433 size = strftime(buf, sizeof(buf), "%Y", tm);
436 size = strftime(buf, sizeof(buf), "%m", tm);
439 size = strftime(buf, sizeof(buf), "%d", tm);
442 size = strftime(buf, sizeof(buf), "%H%M%S", tm);
458 if (bufsize <= buflen + size) {
459 bufsize = (buflen + size) * 5 / 4 + 512;
460 buffer = sresize(buffer, bufsize, char);
462 memcpy(buffer + buflen, bufp, size);
465 buffer[buflen] = '\0';
467 ret = filename_from_str(buffer);