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