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