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