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