src/exim_monitor/em_log.c

   1 /*************************************************
   2 *                 Exim Monitor                   *
   3 *************************************************/
   4
   5 /* Copyright (c) University of Cambridge 1995 - 2018 */
   6 /* See the file NOTICE for conditions of use and distribution. */
   7
   8 /* This module contains code for scanning the main log,
   9 extracting information from it, and displaying a "tail". */
  10
  11 #include "em_hdr.h"
  12
  13 #define log_buffer_len 4096      /* For each log entry */
  14
  15 /* If anonymizing, don't alter these strings (this is all an ad hoc hack). */
  16
  17 #ifdef ANONYMIZE
  18 static char *oklist[] = {
  19   "Completed",
  20   "defer",
  21   "from",
  22   "Connection timed out",
  23   "Start queue run: pid=",
  24   "End queue run: pid=",
  25   "host lookup did not complete",
  26   "unexpected disconnection while reading SMTP command from",
  27   "verify failed for SMTP recipient",
  28   "H=",
  29   "U=",
  30   "id=",
  31   "<",
  32   ">",
  33   "(",
  34   ")",
  35   "[",
  36   "]",
  37   "@",
  38   "=",
  39   "*",
  40   ".",
  41   "-",
  42   "\"",
  43   " ",
  44   "\n"};
  45 static int oklist_size = sizeof(oklist) / sizeof(uschar *);
  46 #endif
  47
  48
  49
  50 /*************************************************
  51 *             Write to the log display           *
  52 *************************************************/
  53
  54 static int visible = 0;
  55 static int scrolled = FALSE;
  56 static int size = 0;
  57 static int top = 0;
  58
  59 static void show_log(char *s, ...) PRINTF_FUNCTION(1,2);
  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   if (fseek(LOG, log_position, SEEK_SET))
 221     {
 222     perror("logfile fseek");
 223     exit(1);
 224     }
 225
 226   while (Ufgets(buffer, log_buffer_len, LOG) != NULL)
 227     {
 228     uschar *id;
 229     uschar *p = buffer;
 230     rmark reset_point;
 231     int length = Ustrlen(buffer);
 232     pcre2_match_data * md = pcre2_match_data_create(1, NULL);
 233
 234     /* Skip totally blank lines (paranoia: there shouldn't be any) */
 235
 236     while (*p == ' ' || *p == '\t') p++;
 237     if (*p == '\n') continue;
 238
 239     /* We should now have a complete log entry in the buffer; check
 240     it for various regular expression matches and take appropriate
 241     action. Get the current store point so we can reset to it. */
 242
 243     reset_point = store_mark();
 244
 245     /* First, update any stripchart data values, noting that the zeroth
 246     stripchart is the queue length, which is handled elsewhere, and the
 247     1st may the a size monitor. */
 248
 249     for (int i = stripchart_varstart; i < stripchart_number; i++)
 250       if (pcre2_match(stripchart_regex[i], (PCRE2_SPTR)buffer, length,
 251                         0, PCRE_EOPT, md, NULL) >= 0)
 252         stripchart_total[i]++;
 253
 254     /* Munge the log entry and display shortened form on one line.
 255     We omit the date and show only the time. Remove any time zone offset.
 256     Take note of the presence of [pid]. */
 257
 258     if (pcre2_match(yyyymmdd_regex, (PCRE2_SPTR) buffer, length, 0, PCRE_EOPT,
 259                       md, NULL) >= 0)
 260       {
 261       int pidlength = 0;
 262       if (  (buffer[20] == '+' || buffer[20] == '-')
 263          && isdigit(buffer[21]) && buffer[25] == ' ')
 264         memmove(buffer + 20, buffer + 26, Ustrlen(buffer + 26) + 1);
 265       if (buffer[20] == '[')
 266         while (Ustrchr("[]0123456789", buffer[20+pidlength++]) != NULL)
 267           ;
 268       id = string_copyn(buffer + 20 + pidlength, MESSAGE_ID_LENGTH);
 269       show_log("%s", buffer+11);
 270       }
 271     else
 272       {
 273       id = US"";
 274       show_log("%s", buffer);
 275       }
 276     pcre2_match_data_free(md);
 277
 278     /* Deal with frozen and unfrozen messages */
 279
 280     if (strstric(buffer, US"frozen", FALSE) != NULL)
 281       {
 282       queue_item *qq = find_queue(id, queue_noop, 0);
 283       if (qq)
 284         qq->frozen = strstric(buffer, US"unfrozen", FALSE) == NULL;
 285       }
 286
 287     /* Notice defer messages, and add the destination if it
 288     isn't already on the list for this message, with a pointer
 289     to the parent if we can. */
 290
 291     if ((p = Ustrstr(buffer, "==")) != NULL)
 292       {
 293       queue_item *qq = find_queue(id, queue_noop, 0);
 294       if (qq != NULL)
 295         {
 296         dest_item *d;
 297         uschar *q, *r;
 298         p += 2;
 299         while (isspace(*p)) p++;
 300         q = p;
 301         while (*p != 0 && !isspace(*p))
 302           {
 303           if (*p++ != '\"') continue;
 304           while (*p != 0)
 305             {
 306             if (*p == '\\') p += 2;
 307               else if (*p++ == '\"') break;
 308             }
 309           }
 310         *p++ = 0;
 311         if ((r = strstric(q, qualify_domain, FALSE)) != NULL &&
 312           *(--r) == '@') *r = 0;
 313
 314         /* If we already have this destination, as tested case-insensitively,
 315         do not add it to the destinations list. */
 316
 317         d = find_dest(qq, q, dest_add, TRUE);
 318
 319         if (d->parent == NULL)
 320           {
 321           while (isspace(*p)) p++;
 322           if (*p == '<')
 323             {
 324             dest_item *dd;
 325             q = ++p;
 326             while (*p != 0 && *p != '>') p++;
 327             *p = 0;
 328             if ((p = strstric(q, qualify_domain, FALSE)) != NULL &&
 329               *(--p) == '@') *p = 0;
 330             dd = find_dest(qq, q, dest_noop, FALSE);
 331             if (dd != NULL && dd != d) d->parent = dd;
 332             }
 333           }
 334         }
 335       }
 336
 337     store_reset(reset_point);
 338     }
 339   }
 340
 341
 342 /* We have to detect when the log file is changed, and switch to the new file.
 343 In practice, for non-datestamped files, this means that some deliveries might
 344 go unrecorded, since they'll be written to the old file, but this usually
 345 happens in the middle of the night, and I don't think the hassle of keeping
 346 track of two log files is worth it.
 347
 348 First we check the datestamped name of the log file if necessary; if it is
 349 different to the file we currently have open, go for the new file. As happens
 350 in Exim itself, we leave in the following inode check, even when datestamping
 351 because it does no harm and will cope should a file actually be renamed for
 352 some reason.
 353
 354 The test for a changed log file is to look up the inode of the file by name and
 355 compare it with the saved inode of the file we currently are processing. This
 356 accords with the usual interpretation of POSIX and other Unix specs that imply
 357 "one file, one inode". However, it appears that on some Digital systems, if an
 358 open file is unlinked, a new file may be created with the same inode while the
 359 old file remains in existence. This can happen if the old log file is renamed,
 360 processed in some way, and then deleted. To work round this, also test for a
 361 link count of zero on the currently open file. */
 362
 363 if (log_datestamping)
 364   {
 365   uschar log_file_wanted[256];
 366   /* Do *not* use "%s" here, we need the %D datestamp in the log_file string to
 367   be expanded.  The trailing NULL arg is to quieten preprocessors that need at
 368   least one arg for a variadic set in a macro. */
 369   string_format(log_file_wanted, sizeof(log_file_wanted), CS log_file, NULL);
 370   if (Ustrcmp(log_file_wanted, log_file_open) != 0)
 371     {
 372     if (LOG != NULL)
 373       {
 374       fclose(LOG);
 375       LOG = NULL;
 376       }
 377     Ustrcpy(log_file_open, log_file_wanted);
 378     }
 379   }
 380
 381 if (LOG == NULL ||
 382     (fstat(fileno(LOG), &statdata) == 0 && statdata.st_nlink == 0) ||
 383     (Ustat(log_file, &statdata) == 0 && log_inode != statdata.st_ino))
 384   {
 385   FILE *TEST;
 386
 387   /* Experiment shows that sometimes you can't immediately open
 388   the new log file - presumably immediately after the old one
 389   is renamed and before the new one exists. Therefore do a
 390   trial open first to be sure. */
 391
 392   if ((TEST = fopen(CS log_file_open, "r")) != NULL)
 393     {
 394     if (LOG != NULL) fclose(LOG);
 395     LOG = TEST;
 396     if (fstat(fileno(LOG), &statdata))
 397       {
 398       fprintf(stderr, "fstat %s: %s\n", log_file_open, strerror(errno));
 399       exit(1);
 400       }
 401     log_inode = statdata.st_ino;
 402     }
 403   }
 404
 405 /* Save the position we have got to in the log. */
 406
 407 if (LOG != NULL) log_position = ftell(LOG);
 408 }
 409
 410 /* End of em_log.c */