| 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 | void *reset_point; |
| 231 | int length = Ustrlen(buffer); |
| 232 | int i; |
| 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_get(0); |
| 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 (i = stripchart_varstart; i < stripchart_number; i++) |
| 250 | { |
| 251 | if (pcre_exec(stripchart_regex[i], NULL, CS buffer, length, 0, PCRE_EOPT, |
| 252 | NULL, 0) >= 0) |
| 253 | stripchart_total[i]++; |
| 254 | } |
| 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 (pcre_exec(yyyymmdd_regex,NULL,CS buffer,length,0,PCRE_EOPT,NULL,0) >= 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 | { |
| 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 | |
| 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 != NULL) |
| 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 to |
| 368 | * be expanded! */ |
| 369 | string_format(log_file_wanted, sizeof(log_file_wanted), CS log_file); |
| 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 */ |