src/exim_monitor/em_log.c

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