Tidies to SMTP dialogue debugging output.
[exim.git] / src / exim_monitor / em_log.c
1 /* $Cambridge: exim/src/exim_monitor/em_log.c,v 1.3 2006/02/07 11:18:59 ph10 Exp $ */
2
3 /*************************************************
4 *                 Exim Monitor                   *
5 *************************************************/
6
7 /* Copyright (c) University of Cambridge 1995 - 2006 */
8 /* See the file NOTICE for conditions of use and distribution. */
9
10 /* This module contains code for scanning the smaill log,
11 extracting information from it, and displaying a "tail". */
12
13 #include "em_hdr.h"
14
15 #define log_buffer_len 4096      /* For each log entry */
16
17 /* If anonymizing, don't alter these strings (this is all an ad hoc hack). */
18
19 #ifdef ANONYMIZE
20 static char *oklist[] = {
21   "Completed",
22   "defer",
23   "from",
24   "Connection timed out",
25   "Start queue run: pid=",
26   "End queue run: pid=",
27   "host lookup did not complete",
28   "unexpected disconnection while reading SMTP command from",
29   "verify failed for SMTP recipient",
30   "H=",
31   "U=",
32   "id=",
33   "<",
34   ">",
35   "(",
36   ")",
37   "[",
38   "]",
39   "@",
40   "=",
41   "*",
42   ".",
43   "-",
44   "\"",
45   " ",
46   "\n"};
47 static int oklist_size = sizeof(oklist) / sizeof(uschar *);
48 #endif
49
50
51
52 /*************************************************
53 *             Write to the log display           *
54 *************************************************/
55
56 static int visible = 0;
57 static int scrolled = FALSE;
58 static int size = 0;
59 static int top = 0;
60
61 static void show_log(char *s, ...)
62 {
63 int length, newtop;
64 va_list ap;
65 XawTextBlock b;
66 uschar buffer[log_buffer_len + 24];
67
68 /* Do nothing if not tailing a log */
69
70 if (log_widget == NULL) return;
71
72 /* Initialize the text block structure */
73
74 b.firstPos = 0;
75 b.ptr = CS buffer;
76 b.format = FMT8BIT;
77
78 /* We want to know whether the window has been scrolled back or not,
79 so that we can cease automatically scrolling with new text. This turns
80 out to be tricky with the text widget. We can detect whether the
81 scroll bar has been operated by checking on the "top" value, but it's
82 harder to detect that it has been returned to the bottom. The following
83 heuristic does its best. */
84
85 newtop = XawTextTopPosition(log_widget);
86 if (newtop != top)
87   {
88   if (!scrolled)
89     {
90     visible = size - top;      /* save size of window */
91     scrolled = newtop < top;
92     }
93   else if (newtop > size - visible) scrolled = FALSE;
94   top = newtop;
95   }
96
97 /* Format the text that is to be written. */
98
99 va_start(ap, s);
100 vsprintf(CS buffer, s, ap);
101 va_end(ap);
102 length = Ustrlen(buffer);
103
104 /* If we are anonymizing for screen shots, flatten various things. */
105
106 #ifdef ANONYMIZE
107   {
108   uschar *p = buffer + 9;
109   if (p[6] == '-' && p[13] == '-') p += 17;
110
111   while (p < buffer + length)
112     {
113     int i;
114
115     /* Check for strings to be left alone */
116
117     for (i = 0; i < oklist_size; i++)
118       {
119       int len = Ustrlen(oklist[i]);
120       if (Ustrncmp(p, oklist[i], len) == 0)
121         {
122         p += len;
123         break;
124         }
125       }
126     if (i < oklist_size) continue;
127
128     /* Leave driver names, size, protocol, alone */
129
130     if ((*p == 'D' || *p == 'P' || *p == 'T' || *p == 'S' || *p == 'R') &&
131         p[1] == '=')
132       {
133       p += 2;
134       while (*p != ' ' && *p != 0) p++;
135       continue;
136       }
137
138     /* Leave C= text alone */
139
140     if (Ustrncmp(p, "C=\"", 3) == 0)
141       {
142       p += 3;
143       while (*p != 0 && *p != '"') p++;
144       continue;
145       }
146
147     /* Flatten remaining chars */
148
149     if (isdigit(*p)) *p++ = 'x';
150     else if (isalpha(*p)) *p++ = 'x';
151     else *p++ = '$';
152     }
153   }
154 #endif
155
156 /* If this would overflow the buffer, throw away 50% of the
157 current stuff in the buffer. Code defensively against odd
158 extreme cases that shouldn't actually arise. */
159
160 if (size + length > log_buffer_size)
161   {
162   if (size == 0) length = log_buffer_size/2; else
163     {
164     int cutcount = log_buffer_size/2;
165     if (cutcount > size) cutcount = size; else
166       {
167       while (cutcount < size && log_display_buffer[cutcount] != '\n')
168         cutcount++;
169       cutcount++;
170       }
171     b.length = 0;
172     XawTextReplace(log_widget, 0, cutcount, &b);
173     size -= cutcount;
174     top -= cutcount;
175     if (top < 0) top = 0;
176     if (top < cutcount) XawTextInvalidate(log_widget, 0, 999999);
177     xs_SetValues(log_widget, 1, "displayPosition", top);
178     }
179   }
180
181 /* Insert the new text at the end of the buffer. */
182
183 b.length = length;
184 XawTextReplace(log_widget, 999999, 999999, &b);
185 size += length;
186
187 /* When not scrolled back, we want to keep the bottom line
188 always visible. Put the insert point at the start of it because
189 this stops left/right scrolling with some X libraries. */
190
191 if (!scrolled)
192   {
193   XawTextSetInsertionPoint(log_widget, size - length);
194   top = XawTextTopPosition(log_widget);
195   }
196 }
197
198
199
200
201 /*************************************************
202 *            Function to read the log            *
203 *************************************************/
204
205 /* We read any new log entries, and use their data to
206 updated total counts for the configured stripcharts.
207 The count for the queue chart is handled separately.
208 We also munge the log entries and display a one-line
209 version in the log window. */
210
211 void read_log(void)
212 {
213 struct stat statdata;
214 uschar buffer[log_buffer_len];
215
216 /* If log is not yet open, skip all of this. */
217
218 if (LOG != NULL)
219   {
220   fseek(LOG, log_position, SEEK_SET);
221
222   while (Ufgets(buffer, log_buffer_len, LOG) != NULL)
223     {
224     uschar *id;
225     uschar *p = buffer;
226     void *reset_point;
227     int length = Ustrlen(buffer);
228     int i;
229
230     /* Skip totally blank lines (paranoia: there shouldn't be any) */
231
232     while (*p == ' ' || *p == '\t') p++;
233     if (*p == '\n') continue;
234
235     /* We should now have a complete log entry in the buffer; check
236     it for various regular expression matches and take appropriate
237     action. Get the current store point so we can reset to it. */
238
239     reset_point = store_get(0);
240
241     /* First, update any stripchart data values, noting that the zeroth
242     stripchart is the queue length, which is handled elsewhere, and the
243     1st may the a size monitor. */
244
245     for (i = stripchart_varstart; i < stripchart_number; i++)
246       {
247       if (pcre_exec(stripchart_regex[i], NULL, CS buffer, length, 0, PCRE_EOPT,
248             NULL, 0) >= 0)
249         stripchart_total[i]++;
250       }
251
252     /* Munge the log entry and display shortened form on one line.
253     We omit the date and show only the time. Remove any time zone offset. */
254
255     if (pcre_exec(yyyymmdd_regex,NULL,CS buffer,length,0,PCRE_EOPT,NULL,0) >= 0)
256       {
257       if ((buffer[20] == '+' || buffer[20] == '-') &&
258           isdigit(buffer[21]) && buffer[25] == ' ')
259         memmove(buffer + 20, buffer + 26, Ustrlen(buffer + 26) + 1);
260       id = string_copyn(buffer + 20, MESSAGE_ID_LENGTH);
261       show_log("%s", buffer+11);
262       }
263     else
264       {
265       id = US"";
266       show_log("%s", buffer);
267       }
268
269     /* Deal with frozen and unfrozen messages */
270
271     if (strstric(buffer, US"frozen", FALSE) != NULL)
272       {
273       queue_item *qq = find_queue(id, queue_noop, 0);
274       if (qq != NULL)
275         {
276         if (strstric(buffer, US"unfrozen", FALSE) != NULL)
277           qq->frozen = FALSE;
278         else qq->frozen = TRUE;
279         }
280       }
281
282     /* Notice defer messages, and add the destination if it
283     isn't already on the list for this message, with a pointer
284     to the parent if we can. */
285
286     if ((p = Ustrstr(buffer, "==")) != NULL)
287       {
288       queue_item *qq = find_queue(id, queue_noop, 0);
289       if (qq != NULL)
290         {
291         dest_item *d;
292         uschar *q, *r;
293         p += 2;
294         while (isspace(*p)) p++;
295         q = p;
296         while (*p != 0 && !isspace(*p))
297           {
298           if (*p++ != '\"') continue;
299           while (*p != 0)
300             {
301             if (*p == '\\') p += 2;
302               else if (*p++ == '\"') break;
303             }
304           }
305         *p++ = 0;
306         if ((r = strstric(q, qualify_domain, FALSE)) != NULL &&
307           *(--r) == '@') *r = 0;
308
309         /* If we already have this destination, as tested case-insensitively,
310         do not add it to the destinations list. */
311
312         d = find_dest(qq, q, dest_add, TRUE);
313
314         if (d->parent == NULL)
315           {
316           while (isspace(*p)) p++;
317           if (*p == '<')
318             {
319             dest_item *dd;
320             q = ++p;
321             while (*p != 0 && *p != '>') p++;
322             *p = 0;
323             if ((p = strstric(q, qualify_domain, FALSE)) != NULL &&
324               *(--p) == '@') *p = 0;
325             dd = find_dest(qq, q, dest_noop, FALSE);
326             if (dd != NULL && dd != d) d->parent = dd;
327             }
328           }
329         }
330       }
331
332     store_reset(reset_point);
333     }
334   }
335
336
337 /* We have to detect when the log file is changed, and switch to the new file.
338 In practice, for non-datestamped files, this means that some deliveries might
339 go unrecorded, since they'll be written to the old file, but this usually
340 happens in the middle of the night, and I don't think the hassle of keeping
341 track of two log files is worth it.
342
343 First we check the datestamped name of the log file if necessary; if it is
344 different to the file we currently have open, go for the new file. As happens
345 in Exim itself, we leave in the following inode check, even when datestamping
346 because it does no harm and will cope should a file actually be renamed for
347 some reason.
348
349 The test for a changed log file is to look up the inode of the file by name and
350 compare it with the saved inode of the file we currently are processing. This
351 accords with the usual interpretation of POSIX and other Unix specs that imply
352 "one file, one inode". However, it appears that on some Digital systems, if an
353 open file is unlinked, a new file may be created with the same inode while the
354 old file remains in existence. This can happen if the old log file is renamed,
355 processed in some way, and then deleted. To work round this, also test for a
356 link count of zero on the currently open file. */
357
358 if (log_datestamping)
359   {
360   uschar log_file_wanted[256];
361   string_format(log_file_wanted, sizeof(log_file_wanted), CS log_file);
362   if (Ustrcmp(log_file_wanted, log_file_open) != 0)
363     {
364     if (LOG != NULL)
365       {
366       fclose(LOG);
367       LOG = NULL;
368       }
369     Ustrcpy(log_file_open, log_file_wanted);
370     }
371   }
372
373 if (LOG == NULL ||
374     (fstat(fileno(LOG), &statdata) == 0 && statdata.st_nlink == 0) ||
375     (Ustat(log_file, &statdata) == 0 && log_inode != statdata.st_ino))
376   {
377   FILE *TEST;
378
379   /* Experiment shows that sometimes you can't immediately open
380   the new log file - presumably immediately after the old one
381   is renamed and before the new one exists. Therefore do a
382   trial open first to be sure. */
383
384   if ((TEST = fopen(CS log_file_open, "r")) != NULL)
385     {
386     if (LOG != NULL) fclose(LOG);
387     LOG = TEST;
388     fstat(fileno(LOG), &statdata);
389     log_inode = statdata.st_ino;
390     }
391   }
392
393 /* Save the position we have got to in the log. */
394
395 if (LOG != NULL) log_position = ftell(LOG);
396 }
397
398 /* End of em_log.c */