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