update to pre-4.87 master
[exim.git] / src / src / log.c
1 /*************************************************
2 * Exim - an Internet mail transport agent *
3 *************************************************/
4
5 /* Copyright (c) University of Cambridge 1995 - 2015 */
6 /* See the file NOTICE for conditions of use and distribution. */
7
8 /* Functions for writing log files. The code for maintaining datestamped
9 log files was originally contributed by Tony Sheen. */
10
11
12 #include "exim.h"
13
14 #define LOG_NAME_SIZE 256
15 #define MAX_SYSLOG_LEN 870
16
17 #define LOG_MODE_FILE 1
18 #define LOG_MODE_SYSLOG 2
19
20 enum { lt_main, lt_reject, lt_panic, lt_debug };
21
22 static uschar *log_names[] = { US"main", US"reject", US"panic", US"debug" };
23
24
25
26 /*************************************************
27 * Local static variables *
28 *************************************************/
29
30 static uschar mainlog_name[LOG_NAME_SIZE];
31 static uschar rejectlog_name[LOG_NAME_SIZE];
32 static uschar debuglog_name[LOG_NAME_SIZE];
33
34 static uschar *mainlog_datestamp = NULL;
35 static uschar *rejectlog_datestamp = NULL;
36
37 static int mainlogfd = -1;
38 static int rejectlogfd = -1;
39 static ino_t mainlog_inode = 0;
40 static ino_t rejectlog_inode = 0;
41
42 static uschar *panic_save_buffer = NULL;
43 static BOOL panic_recurseflag = FALSE;
44
45 static BOOL syslog_open = FALSE;
46 static BOOL path_inspected = FALSE;
47 static int logging_mode = LOG_MODE_FILE;
48 static uschar *file_path = US"";
49
50
51
52
53 /*************************************************
54 * Write to syslog *
55 *************************************************/
56
57 /* The given string is split into sections according to length, or at embedded
58 newlines, and syslogged as a numbered sequence if it is overlong or if there is
59 more than one line. However, if we are running in the test harness, do not do
60 anything. (The test harness doesn't use syslog - for obvious reasons - but we
61 can get here if there is a failure to open the panic log.)
62
63 Arguments:
64 priority syslog priority
65 s the string to be written
66
67 Returns: nothing
68 */
69
70 static void
71 write_syslog(int priority, uschar *s)
72 {
73 int len, pass;
74 int linecount = 0;
75
76 if (running_in_test_harness) return;
77
78 if (!syslog_timestamp) s += log_timezone? 26 : 20;
79
80 len = Ustrlen(s);
81
82 #ifndef NO_OPENLOG
83 if (!syslog_open)
84 {
85 #ifdef SYSLOG_LOG_PID
86 openlog(CS syslog_processname, LOG_PID|LOG_CONS, syslog_facility);
87 #else
88 openlog(CS syslog_processname, LOG_CONS, syslog_facility);
89 #endif
90 syslog_open = TRUE;
91 }
92 #endif
93
94 /* First do a scan through the message in order to determine how many lines
95 it is going to end up as. Then rescan to output it. */
96
97 for (pass = 0; pass < 2; pass++)
98 {
99 int i;
100 int tlen;
101 uschar *ss = s;
102 for (i = 1, tlen = len; tlen > 0; i++)
103 {
104 int plen = tlen;
105 uschar *nlptr = Ustrchr(ss, '\n');
106 if (nlptr != NULL) plen = nlptr - ss;
107 #ifndef SYSLOG_LONG_LINES
108 if (plen > MAX_SYSLOG_LEN) plen = MAX_SYSLOG_LEN;
109 #endif
110 tlen -= plen;
111 if (ss[plen] == '\n') tlen--; /* chars left */
112
113 if (pass == 0) linecount++; else
114 {
115 if (linecount == 1)
116 syslog(priority, "%.*s", plen, ss);
117 else
118 syslog(priority, "[%d%c%d] %.*s", i,
119 (ss[plen] == '\n' && tlen != 0)? '\\' : '/',
120 linecount, plen, ss);
121 }
122 ss += plen;
123 if (*ss == '\n') ss++;
124 }
125 }
126 }
127
128
129
130 /*************************************************
131 * Die tidily *
132 *************************************************/
133
134 /* This is called when Exim is dying as a result of something going wrong in
135 the logging, or after a log call with LOG_PANIC_DIE set. Optionally write a
136 message to debug_file or a stderr file, if they exist. Then, if in the middle
137 of accepting a message, throw it away tidily by calling receive_bomb_out();
138 this will attempt to send an SMTP response if appropriate. Passing NULL as the
139 first argument stops it trying to run the NOTQUIT ACL (which might try further
140 logging and thus cause problems). Otherwise, try to close down an outstanding
141 SMTP call tidily.
142
143 Arguments:
144 s1 Error message to write to debug_file and/or stderr and syslog
145 s2 Error message for any SMTP call that is in progress
146 Returns: The function does not return
147 */
148
149 static void
150 die(uschar *s1, uschar *s2)
151 {
152 if (s1 != NULL)
153 {
154 write_syslog(LOG_CRIT, s1);
155 if (debug_file != NULL) debug_printf("%s\n", s1);
156 if (log_stderr != NULL && log_stderr != debug_file)
157 fprintf(log_stderr, "%s\n", s1);
158 }
159 if (receive_call_bombout) receive_bomb_out(NULL, s2); /* does not return */
160 if (smtp_input) smtp_closedown(s2);
161 exim_exit(EXIT_FAILURE);
162 }
163
164
165
166 /*************************************************
167 * Create a log file *
168 *************************************************/
169
170 /* This function is called to create and open a log file. It may be called in a
171 subprocess when the original process is root.
172
173 Arguments:
174 name the file name
175
176 The file name has been build in a working buffer, so it is permissible to
177 overwrite it temporarily if it is necessary to create the directory.
178
179 Returns: a file descriptor, or < 0 on failure (errno set)
180 */
181
182 int
183 log_create(uschar *name)
184 {
185 int fd = Uopen(name, O_CREAT|O_APPEND|O_WRONLY, LOG_MODE);
186
187 /* If creation failed, attempt to build a log directory in case that is the
188 problem. */
189
190 if (fd < 0 && errno == ENOENT)
191 {
192 BOOL created;
193 uschar *lastslash = Ustrrchr(name, '/');
194 *lastslash = 0;
195 created = directory_make(NULL, name, LOG_DIRECTORY_MODE, FALSE);
196 DEBUG(D_any) debug_printf("%s log directory %s\n",
197 created? "created" : "failed to create", name);
198 *lastslash = '/';
199 if (created) fd = Uopen(name, O_CREAT|O_APPEND|O_WRONLY, LOG_MODE);
200 }
201
202 return fd;
203 }
204
205
206
207 /*************************************************
208 * Create a log file as the exim user *
209 *************************************************/
210
211 /* This function is called when we are root to spawn an exim:exim subprocess
212 in which we can create a log file. It must be signal-safe since it is called
213 by the usr1_handler().
214
215 Arguments:
216 name the file name
217
218 Returns: a file descriptor, or < 0 on failure (errno set)
219 */
220
221 int
222 log_create_as_exim(uschar *name)
223 {
224 pid_t pid = fork();
225 int status = 1;
226 int fd = -1;
227
228 /* In the subprocess, change uid/gid and do the creation. Return 0 from the
229 subprocess on success. If we don't check for setuid failures, then the file
230 can be created as root, so vulnerabilities which cause setuid to fail mean
231 that the Exim user can use symlinks to cause a file to be opened/created as
232 root. We always open for append, so can't nuke existing content but it would
233 still be Rather Bad. */
234
235 if (pid == 0)
236 {
237 if (setgid(exim_gid) < 0)
238 die(US"exim: setgid for log-file creation failed, aborting",
239 US"Unexpected log failure, please try later");
240 if (setuid(exim_uid) < 0)
241 die(US"exim: setuid for log-file creation failed, aborting",
242 US"Unexpected log failure, please try later");
243 _exit((log_create(name) < 0)? 1 : 0);
244 }
245
246 /* If we created a subprocess, wait for it. If it succeeded, try the open. */
247
248 while (pid > 0 && waitpid(pid, &status, 0) != pid);
249 if (status == 0) fd = Uopen(name, O_APPEND|O_WRONLY, LOG_MODE);
250
251 /* If we failed to create a subprocess, we are in a bad way. We return
252 with fd still < 0, and errno set, letting the caller handle the error. */
253
254 return fd;
255 }
256
257
258
259
260 /*************************************************
261 * Open a log file *
262 *************************************************/
263
264 /* This function opens one of a number of logs, creating the log directory if
265 it does not exist. This may be called recursively on failure, in order to open
266 the panic log.
267
268 The directory is in the static variable file_path. This is static so that it
269 the work of sorting out the path is done just once per Exim process.
270
271 Exim is normally configured to avoid running as root wherever possible, the log
272 files must be owned by the non-privileged exim user. To ensure this, first try
273 an open without O_CREAT - most of the time this will succeed. If it fails, try
274 to create the file; if running as root, this must be done in a subprocess to
275 avoid races.
276
277 Arguments:
278 fd where to return the resulting file descriptor
279 type lt_main, lt_reject, lt_panic, or lt_debug
280 tag optional tag to include in the name (only hooked up for debug)
281
282 Returns: nothing
283 */
284
285 static void
286 open_log(int *fd, int type, uschar *tag)
287 {
288 uid_t euid;
289 BOOL ok, ok2;
290 uschar buffer[LOG_NAME_SIZE];
291
292 /* The names of the log files are controlled by file_path. The panic log is
293 written to the same directory as the main and reject logs, but its name does
294 not have a datestamp. The use of datestamps is indicated by %D/%M in file_path.
295 When opening the panic log, if %D or %M is present, we remove the datestamp
296 from the generated name; if it is at the start, remove a following
297 non-alphanumeric character as well; otherwise, remove a preceding
298 non-alphanumeric character. This is definitely kludgy, but it sort of does what
299 people want, I hope. */
300
301 ok = string_format(buffer, sizeof(buffer), CS file_path, log_names[type]);
302
303 /* Save the name of the mainlog for rollover processing. Without a datestamp,
304 it gets statted to see if it has been cycled. With a datestamp, the datestamp
305 will be compared. The static slot for saving it is the same size as buffer,
306 and the text has been checked above to fit, so this use of strcpy() is OK. */
307
308 if (type == lt_main)
309 {
310 Ustrcpy(mainlog_name, buffer);
311 mainlog_datestamp = mainlog_name + string_datestamp_offset;
312 }
313
314 /* Ditto for the reject log */
315
316 else if (type == lt_reject)
317 {
318 Ustrcpy(rejectlog_name, buffer);
319 rejectlog_datestamp = rejectlog_name + string_datestamp_offset;
320 }
321
322 /* and deal with the debug log (which keeps the datestamp, but does not
323 update it) */
324
325 else if (type == lt_debug)
326 {
327 Ustrcpy(debuglog_name, buffer);
328 if (tag)
329 {
330 /* this won't change the offset of the datestamp */
331 ok2 = string_format(buffer, sizeof(buffer), "%s%s",
332 debuglog_name, tag);
333 if (ok2)
334 Ustrcpy(debuglog_name, buffer);
335 }
336 }
337
338 /* Remove any datestamp if this is the panic log. This is rare, so there's no
339 need to optimize getting the datestamp length. We remove one non-alphanumeric
340 char afterwards if at the start, otherwise one before. */
341
342 else if (string_datestamp_offset >= 0)
343 {
344 uschar *from = buffer + string_datestamp_offset;
345 uschar *to = from + string_datestamp_length;
346 if (from == buffer || from[-1] == '/')
347 {
348 if (!isalnum(*to)) to++;
349 }
350 else
351 {
352 if (!isalnum(from[-1])) from--;
353 }
354
355 /* This strcpy is ok, because we know that to is a substring of from. */
356
357 Ustrcpy(from, to);
358 }
359
360 /* If the file name is too long, it is an unrecoverable disaster */
361
362 if (!ok)
363 {
364 die(US"exim: log file path too long: aborting",
365 US"Logging failure; please try later");
366 }
367
368 /* We now have the file name. Try to open an existing file. After a successful
369 open, arrange for automatic closure on exec(), and then return. */
370
371 *fd = Uopen(buffer, O_APPEND|O_WRONLY, LOG_MODE);
372
373 if (*fd >= 0)
374 {
375 (void)fcntl(*fd, F_SETFD, fcntl(*fd, F_GETFD) | FD_CLOEXEC);
376 return;
377 }
378
379 /* Open was not successful: try creating the file. If this is a root process,
380 we must do the creating in a subprocess set to exim:exim in order to ensure
381 that the file is created with the right ownership. Otherwise, there can be a
382 race if another Exim process is trying to write to the log at the same time.
383 The use of SIGUSR1 by the exiwhat utility can provoke a lot of simultaneous
384 writing. */
385
386 euid = geteuid();
387
388 /* If we are already running as the Exim user (even if that user is root),
389 we can go ahead and create in the current process. */
390
391 if (euid == exim_uid) *fd = log_create(buffer);
392
393 /* Otherwise, if we are root, do the creation in an exim:exim subprocess. If we
394 are neither exim nor root, creation is not attempted. */
395
396 else if (euid == root_uid) *fd = log_create_as_exim(buffer);
397
398 /* If we now have an open file, set the close-on-exec flag and return. */
399
400 if (*fd >= 0)
401 {
402 (void)fcntl(*fd, F_SETFD, fcntl(*fd, F_GETFD) | FD_CLOEXEC);
403 return;
404 }
405
406 /* Creation failed. There are some circumstances in which we get here when
407 the effective uid is not root or exim, which is the problem. (For example, a
408 non-setuid binary with log_arguments set, called in certain ways.) Rather than
409 just bombing out, force the log to stderr and carry on if stderr is available.
410 */
411
412 if (euid != root_uid && euid != exim_uid && log_stderr != NULL)
413 {
414 *fd = fileno(log_stderr);
415 return;
416 }
417
418 /* Otherwise this is a disaster. This call is deliberately ONLY to the panic
419 log. If possible, save a copy of the original line that was being logged. If we
420 are recursing (can't open the panic log either), the pointer will already be
421 set. */
422
423 if (panic_save_buffer == NULL)
424 {
425 panic_save_buffer = (uschar *)malloc(LOG_BUFFER_SIZE);
426 if (panic_save_buffer != NULL)
427 memcpy(panic_save_buffer, log_buffer, LOG_BUFFER_SIZE);
428 }
429
430 log_write(0, LOG_PANIC_DIE, "Cannot open %s log file \"%s\": %s: "
431 "euid=%d egid=%d", log_names[type], buffer, strerror(errno), euid, getegid());
432 /* Never returns */
433 }
434
435
436
437 /*************************************************
438 * Add configuration file info to log line *
439 *************************************************/
440
441 /* This is put in a function because it's needed twice (once for debugging,
442 once for real).
443
444 Arguments:
445 ptr pointer to the end of the line we are building
446 flags log flags
447
448 Returns: updated pointer
449 */
450
451 static uschar *
452 log_config_info(uschar *ptr, int flags)
453 {
454 Ustrcpy(ptr, "Exim configuration error");
455 ptr += 24;
456
457 if ((flags & (LOG_CONFIG_FOR & ~LOG_CONFIG)) != 0)
458 {
459 Ustrcpy(ptr, " for ");
460 return ptr + 5;
461 }
462
463 if ((flags & (LOG_CONFIG_IN & ~LOG_CONFIG)) != 0)
464 {
465 sprintf(CS ptr, " in line %d of %s", config_lineno, config_filename);
466 while (*ptr) ptr++;
467 }
468
469 Ustrcpy(ptr, ":\n ");
470 return ptr + 4;
471 }
472
473
474 /*************************************************
475 * A write() operation failed *
476 *************************************************/
477
478 /* This function is called when write() fails on anything other than the panic
479 log, which can happen if a disk gets full or a file gets too large or whatever.
480 We try to save the relevant message in the panic_save buffer before crashing
481 out.
482
483 The potential invoker should probably not call us for EINTR -1 writes. But
484 otherwise, short writes are bad as we don't do non-blocking writes to fds
485 subject to flow control. (If we do, that's new and the logic of this should
486 be reconsidered).
487
488 Arguments:
489 name the name of the log being written
490 length the string length being written
491 rc the return value from write()
492
493 Returns: does not return
494 */
495
496 static void
497 log_write_failed(uschar *name, int length, int rc)
498 {
499 int save_errno = errno;
500
501 if (panic_save_buffer == NULL)
502 {
503 panic_save_buffer = (uschar *)malloc(LOG_BUFFER_SIZE);
504 if (panic_save_buffer != NULL)
505 memcpy(panic_save_buffer, log_buffer, LOG_BUFFER_SIZE);
506 }
507
508 log_write(0, LOG_PANIC_DIE, "failed to write to %s: length=%d result=%d "
509 "errno=%d (%s)", name, length, rc, save_errno,
510 (save_errno == 0)? "write incomplete" : strerror(save_errno));
511 /* Never returns */
512 }
513
514
515
516 /*************************************************
517 * Write to an fd, retrying after signals *
518 *************************************************/
519
520 /* Basic write to fd for logs, handling EINTR.
521
522 Arguments:
523 fd the fd to write to
524 buf the string to write
525 length the string length being written
526
527 Returns:
528 length actually written, persisting an errno from write()
529 */
530 ssize_t
531 write_to_fd_buf(int fd, const uschar *buf, size_t length)
532 {
533 ssize_t wrote;
534 size_t total_written = 0;
535 const uschar *p = buf;
536 size_t left = length;
537
538 while (1)
539 {
540 wrote = write(fd, p, left);
541 if (wrote == (ssize_t)-1)
542 {
543 if (errno == EINTR) continue;
544 return wrote;
545 }
546 total_written += wrote;
547 if (wrote == left)
548 break;
549 else
550 {
551 p += wrote;
552 left -= wrote;
553 }
554 }
555 return total_written;
556 }
557
558
559
560 static void
561 set_file_path(void)
562 {
563 int sep = ':'; /* Fixed separator - outside use */
564 uschar *t;
565 const uschar *tt = US LOG_FILE_PATH;
566 while ((t = string_nextinlist(&tt, &sep, log_buffer, LOG_BUFFER_SIZE)))
567 {
568 if (Ustrcmp(t, "syslog") == 0 || t[0] == 0) continue;
569 file_path = string_copy(t);
570 break;
571 }
572 }
573
574
575
576 /*************************************************
577 * Write message to log file *
578 *************************************************/
579
580 /* Exim can be configured to log to local files, or use syslog, or both. This
581 is controlled by the setting of log_file_path. The following cases are
582 recognized:
583
584 log_file_path = "" write files in the spool/log directory
585 log_file_path = "xxx" write files in the xxx directory
586 log_file_path = "syslog" write to syslog
587 log_file_path = "syslog : xxx" write to syslog and to files (any order)
588
589 The message always gets '\n' added on the end of it, since more than one
590 process may be writing to the log at once and we don't want intermingling to
591 happen in the middle of lines. To be absolutely sure of this we write the data
592 into a private buffer and then put it out in a single write() call.
593
594 The flags determine which log(s) the message is written to, or for syslogging,
595 which priority to use, and in the case of the panic log, whether the process
596 should die afterwards.
597
598 The variable really_exim is TRUE only when exim is running in privileged state
599 (i.e. not with a changed configuration or with testing options such as -brw).
600 If it is not, don't try to write to the log because permission will probably be
601 denied.
602
603 Avoid actually writing to the logs when exim is called with -bv or -bt to
604 test an address, but take other actions, such as panicing.
605
606 In Exim proper, the buffer for building the message is got at start-up, so that
607 nothing gets done if it can't be got. However, some functions that are also
608 used in utilities occasionally obey log_write calls in error situations, and it
609 is simplest to put a single malloc() here rather than put one in each utility.
610 Malloc is used directly because the store functions may call log_write().
611
612 If a message_id exists, we include it after the timestamp.
613
614 Arguments:
615 selector write to main log or LOG_INFO only if this value is zero, or if
616 its bit is set in log_selector[0]
617 flags each bit indicates some independent action:
618 LOG_SENDER add raw sender to the message
619 LOG_RECIPIENTS add raw recipients list to message
620 LOG_CONFIG add "Exim configuration error"
621 LOG_CONFIG_FOR add " for " instead of ":\n "
622 LOG_CONFIG_IN add " in line x[ of file y]"
623 LOG_MAIN write to main log or syslog LOG_INFO
624 LOG_REJECT write to reject log or syslog LOG_NOTICE
625 LOG_PANIC write to panic log or syslog LOG_ALERT
626 LOG_PANIC_DIE write to panic log or LOG_ALERT and then crash
627 format a printf() format
628 ... arguments for format
629
630 Returns: nothing
631 */
632
633 void
634 log_write(unsigned int selector, int flags, const char *format, ...)
635 {
636 uschar *ptr;
637 int length;
638 int paniclogfd;
639 ssize_t written_len;
640 va_list ap;
641
642 /* If panic_recurseflag is set, we have failed to open the panic log. This is
643 the ultimate disaster. First try to write the message to a debug file and/or
644 stderr and also to syslog. If panic_save_buffer is not NULL, it contains the
645 original log line that caused the problem. Afterwards, expire. */
646
647 if (panic_recurseflag)
648 {
649 uschar *extra = (panic_save_buffer == NULL)? US"" : panic_save_buffer;
650 if (debug_file != NULL) debug_printf("%s%s", extra, log_buffer);
651 if (log_stderr != NULL && log_stderr != debug_file)
652 fprintf(log_stderr, "%s%s", extra, log_buffer);
653 if (*extra != 0) write_syslog(LOG_CRIT, extra);
654 write_syslog(LOG_CRIT, log_buffer);
655 die(US"exim: could not open panic log - aborting: see message(s) above",
656 US"Unexpected log failure, please try later");
657 }
658
659 /* Ensure we have a buffer (see comment above); this should never be obeyed
660 when running Exim proper, only when running utilities. */
661
662 if (log_buffer == NULL)
663 {
664 log_buffer = (uschar *)malloc(LOG_BUFFER_SIZE);
665 if (log_buffer == NULL)
666 {
667 fprintf(stderr, "exim: failed to get store for log buffer\n");
668 exim_exit(EXIT_FAILURE);
669 }
670 }
671
672 /* If we haven't already done so, inspect the setting of log_file_path to
673 determine whether to log to files and/or to syslog. Bits in logging_mode
674 control this, and for file logging, the path must end up in file_path. This
675 variable must be in permanent store because it may be required again later in
676 the process. */
677
678 if (!path_inspected)
679 {
680 BOOL multiple = FALSE;
681 int old_pool = store_pool;
682
683 store_pool = POOL_PERM;
684
685 /* If nothing has been set, don't waste effort... the default values for the
686 statics are file_path="" and logging_mode = LOG_MODE_FILE. */
687
688 if (*log_file_path)
689 {
690 int sep = ':'; /* Fixed separator - outside use */
691 uschar *s;
692 const uschar *ss = log_file_path;
693 logging_mode = 0;
694 while ((s = string_nextinlist(&ss, &sep, log_buffer, LOG_BUFFER_SIZE)))
695 {
696 if (Ustrcmp(s, "syslog") == 0)
697 logging_mode |= LOG_MODE_SYSLOG;
698 else if ((logging_mode & LOG_MODE_FILE) != 0) multiple = TRUE;
699 else
700 {
701 logging_mode |= LOG_MODE_FILE;
702
703 /* If a non-empty path is given, use it */
704
705 if (*s)
706 file_path = string_copy(s);
707
708 /* If the path is empty, we want to use the first non-empty, non-
709 syslog item in LOG_FILE_PATH, if there is one, since the value of
710 log_file_path may have been set at runtime. If there is no such item,
711 use the ultimate default in the spool directory. */
712
713 else
714 set_file_path(); /* Empty item in log_file_path */
715 } /* First non-syslog item in log_file_path */
716 } /* Scan of log_file_path */
717 }
718
719 /* If no modes have been selected, it is a major disaster */
720
721 if (logging_mode == 0)
722 die(US"Neither syslog nor file logging set in log_file_path",
723 US"Unexpected logging failure");
724
725 /* Set up the ultimate default if necessary. Then revert to the old store
726 pool, and record that we've sorted out the path. */
727
728 if ((logging_mode & LOG_MODE_FILE) != 0 && file_path[0] == 0)
729 file_path = string_sprintf("%s/log/%%slog", spool_directory);
730 store_pool = old_pool;
731 path_inspected = TRUE;
732
733 /* If more than one file path was given, log a complaint. This recursive call
734 should work since we have now set up the routing. */
735
736 if (multiple)
737 log_write(0, LOG_MAIN|LOG_PANIC,
738 "More than one path given in log_file_path: using %s", file_path);
739 }
740
741 /* If debugging, show all log entries, but don't show headers. Do it all
742 in one go so that it doesn't get split when multi-processing. */
743
744 DEBUG(D_any|D_v)
745 {
746 int i;
747 ptr = log_buffer;
748
749 Ustrcpy(ptr, "LOG:");
750 ptr += 4;
751
752 /* Show the selector that was passed into the call. */
753
754 for (i = 0; i < log_options_count; i++)
755 {
756 unsigned int bitnum = log_options[i].bit;
757 if (bitnum < BITWORDSIZE && selector == BIT(bitnum))
758 {
759 *ptr++ = ' ';
760 Ustrcpy(ptr, log_options[i].name);
761 while (*ptr) ptr++;
762 }
763 }
764
765 sprintf(CS ptr, "%s%s%s%s\n ",
766 ((flags & LOG_MAIN) != 0)? " MAIN" : "",
767 ((flags & LOG_PANIC) != 0)? " PANIC" : "",
768 ((flags & LOG_PANIC_DIE) == LOG_PANIC_DIE)? " DIE" : "",
769 ((flags & LOG_REJECT) != 0)? " REJECT" : "");
770
771 while(*ptr) ptr++;
772 if ((flags & LOG_CONFIG) != 0) ptr = log_config_info(ptr, flags);
773
774 va_start(ap, format);
775 if (!string_vformat(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer)-1, format, ap))
776 Ustrcpy(ptr, "**** log string overflowed log buffer ****");
777 va_end(ap);
778
779 while(*ptr) ptr++;
780 Ustrcat(ptr, "\n");
781 debug_printf("%s", log_buffer);
782 }
783
784 /* If no log file is specified, we are in a mess. */
785
786 if ((flags & (LOG_MAIN|LOG_PANIC|LOG_REJECT)) == 0)
787 log_write(0, LOG_MAIN|LOG_PANIC_DIE, "log_write called with no log "
788 "flags set");
789
790 /* There are some weird circumstances in which logging is disabled. */
791
792 if (disable_logging)
793 {
794 DEBUG(D_any) debug_printf("log writing disabled\n");
795 return;
796 }
797
798 /* Handle disabled reject log */
799
800 if (!write_rejectlog) flags &= ~LOG_REJECT;
801
802 /* Create the main message in the log buffer. Do not include the message id
803 when called by a utility. */
804
805 ptr = log_buffer;
806 sprintf(CS ptr, "%s ", tod_stamp(tod_log));
807 while(*ptr) ptr++;
808
809 if (LOGGING(pid))
810 {
811 sprintf(CS ptr, "[%d] ", (int)getpid());
812 while (*ptr) ptr++;
813 }
814
815 if (really_exim && message_id[0] != 0)
816 {
817 sprintf(CS ptr, "%s ", message_id);
818 while(*ptr) ptr++;
819 }
820
821 if ((flags & LOG_CONFIG) != 0) ptr = log_config_info(ptr, flags);
822
823 va_start(ap, format);
824 if (!string_vformat(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer)-1, format, ap))
825 Ustrcpy(ptr, "**** log string overflowed log buffer ****\n");
826 while(*ptr) ptr++;
827 va_end(ap);
828
829 /* Add the raw, unrewritten, sender to the message if required. This is done
830 this way because it kind of fits with LOG_RECIPIENTS. */
831
832 if ((flags & LOG_SENDER) != 0 &&
833 ptr < log_buffer + LOG_BUFFER_SIZE - 10 - Ustrlen(raw_sender))
834 {
835 sprintf(CS ptr, " from <%s>", raw_sender);
836 while (*ptr) ptr++;
837 }
838
839 /* Add list of recipients to the message if required; the raw list,
840 before rewriting, was saved in raw_recipients. There may be none, if an ACL
841 discarded them all. */
842
843 if ((flags & LOG_RECIPIENTS) != 0 && ptr < log_buffer + LOG_BUFFER_SIZE - 6 &&
844 raw_recipients_count > 0)
845 {
846 int i;
847 sprintf(CS ptr, " for");
848 while (*ptr) ptr++;
849 for (i = 0; i < raw_recipients_count; i++)
850 {
851 uschar *s = raw_recipients[i];
852 if (log_buffer + LOG_BUFFER_SIZE - ptr < Ustrlen(s) + 3) break;
853 sprintf(CS ptr, " %s", s);
854 while (*ptr) ptr++;
855 }
856 }
857
858 sprintf(CS ptr, "\n");
859 while(*ptr) ptr++;
860 length = ptr - log_buffer;
861
862 /* Handle loggable errors when running a utility, or when address testing.
863 Write to log_stderr unless debugging (when it will already have been written),
864 or unless there is no log_stderr (expn called from daemon, for example). */
865
866 if (!really_exim || log_testing_mode)
867 {
868 if (debug_selector == 0 && log_stderr != NULL &&
869 (selector == 0 || (selector & log_selector[0]) != 0))
870 {
871 if (host_checking)
872 fprintf(log_stderr, "LOG: %s", CS(log_buffer + 20)); /* no timestamp */
873 else
874 fprintf(log_stderr, "%s", CS log_buffer);
875 }
876 if ((flags & LOG_PANIC_DIE) == LOG_PANIC_DIE) exim_exit(EXIT_FAILURE);
877 return;
878 }
879
880 /* Handle the main log. We know that either syslog or file logging (or both) is
881 set up. A real file gets left open during reception or delivery once it has
882 been opened, but we don't want to keep on writing to it for too long after it
883 has been renamed. Therefore, do a stat() and see if the inode has changed, and
884 if so, re-open. */
885
886 if ((flags & LOG_MAIN) != 0 &&
887 (selector == 0 || (selector & log_selector[0]) != 0))
888 {
889 if ((logging_mode & LOG_MODE_SYSLOG) != 0 &&
890 (syslog_duplication || (flags & (LOG_REJECT|LOG_PANIC)) == 0))
891 write_syslog(LOG_INFO, log_buffer);
892
893 if ((logging_mode & LOG_MODE_FILE) != 0)
894 {
895 struct stat statbuf;
896
897 /* Check for a change to the mainlog file name when datestamping is in
898 operation. This happens at midnight, at which point we want to roll over
899 the file. Closing it has the desired effect. */
900
901 if (mainlog_datestamp != NULL)
902 {
903 uschar *nowstamp = tod_stamp(string_datestamp_type);
904 if (Ustrncmp (mainlog_datestamp, nowstamp, Ustrlen(nowstamp)) != 0)
905 {
906 (void)close(mainlogfd); /* Close the file */
907 mainlogfd = -1; /* Clear the file descriptor */
908 mainlog_inode = 0; /* Unset the inode */
909 mainlog_datestamp = NULL; /* Clear the datestamp */
910 }
911 }
912
913 /* Otherwise, we want to check whether the file has been renamed by a
914 cycling script. This could be "if else", but for safety's sake, leave it as
915 "if" so that renaming the log starts a new file even when datestamping is
916 happening. */
917
918 if (mainlogfd >= 0)
919 {
920 if (Ustat(mainlog_name, &statbuf) < 0 || statbuf.st_ino != mainlog_inode)
921 {
922 (void)close(mainlogfd);
923 mainlogfd = -1;
924 mainlog_inode = 0;
925 }
926 }
927
928 /* If the log is closed, open it. Then write the line. */
929
930 if (mainlogfd < 0)
931 {
932 open_log(&mainlogfd, lt_main, NULL); /* No return on error */
933 if (fstat(mainlogfd, &statbuf) >= 0) mainlog_inode = statbuf.st_ino;
934 }
935
936 /* Failing to write to the log is disastrous */
937
938 written_len = write_to_fd_buf(mainlogfd, log_buffer, length);
939 if (written_len != length)
940 {
941 log_write_failed(US"main log", length, written_len);
942 /* That function does not return */
943 }
944 }
945 }
946
947 /* Handle the log for rejected messages. This can be globally disabled, in
948 which case the flags are altered above. If there are any header lines (i.e. if
949 the rejection is happening after the DATA phase), log the recipients and the
950 headers. */
951
952 if ((flags & LOG_REJECT) != 0)
953 {
954 header_line *h;
955
956 if (header_list != NULL && LOGGING(rejected_header))
957 {
958 if (recipients_count > 0)
959 {
960 int i;
961
962 /* List the sender */
963
964 string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer),
965 "Envelope-from: <%s>\n", sender_address);
966 while (*ptr) ptr++;
967
968 /* List up to 5 recipients */
969
970 string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer),
971 "Envelope-to: <%s>\n", recipients_list[0].address);
972 while (*ptr) ptr++;
973
974 for (i = 1; i < recipients_count && i < 5; i++)
975 {
976 string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer), " <%s>\n",
977 recipients_list[i].address);
978 while (*ptr) ptr++;
979 }
980
981 if (i < recipients_count)
982 {
983 (void)string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer),
984 " ...\n");
985 while (*ptr) ptr++;
986 }
987 }
988
989 /* A header with a NULL text is an unfilled in Received: header */
990
991 for (h = header_list; h != NULL; h = h->next)
992 {
993 BOOL fitted;
994 if (h->text == NULL) continue;
995 fitted = string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer),
996 "%c %s", h->type, h->text);
997 while(*ptr) ptr++;
998 if (!fitted) /* Buffer is full; truncate */
999 {
1000 ptr -= 100; /* For message and separator */
1001 if (ptr[-1] == '\n') ptr--;
1002 Ustrcpy(ptr, "\n*** truncated ***\n");
1003 while (*ptr) ptr++;
1004 break;
1005 }
1006 }
1007
1008 length = ptr - log_buffer;
1009 }
1010
1011 /* Write to syslog or to a log file */
1012
1013 if ((logging_mode & LOG_MODE_SYSLOG) != 0 &&
1014 (syslog_duplication || (flags & LOG_PANIC) == 0))
1015 write_syslog(LOG_NOTICE, log_buffer);
1016
1017 /* Check for a change to the rejectlog file name when datestamping is in
1018 operation. This happens at midnight, at which point we want to roll over
1019 the file. Closing it has the desired effect. */
1020
1021 if ((logging_mode & LOG_MODE_FILE) != 0)
1022 {
1023 struct stat statbuf;
1024
1025 if (rejectlog_datestamp != NULL)
1026 {
1027 uschar *nowstamp = tod_stamp(string_datestamp_type);
1028 if (Ustrncmp (rejectlog_datestamp, nowstamp, Ustrlen(nowstamp)) != 0)
1029 {
1030 (void)close(rejectlogfd); /* Close the file */
1031 rejectlogfd = -1; /* Clear the file descriptor */
1032 rejectlog_inode = 0; /* Unset the inode */
1033 rejectlog_datestamp = NULL; /* Clear the datestamp */
1034 }
1035 }
1036
1037 /* Otherwise, we want to check whether the file has been renamed by a
1038 cycling script. This could be "if else", but for safety's sake, leave it as
1039 "if" so that renaming the log starts a new file even when datestamping is
1040 happening. */
1041
1042 if (rejectlogfd >= 0)
1043 {
1044 if (Ustat(rejectlog_name, &statbuf) < 0 ||
1045 statbuf.st_ino != rejectlog_inode)
1046 {
1047 (void)close(rejectlogfd);
1048 rejectlogfd = -1;
1049 rejectlog_inode = 0;
1050 }
1051 }
1052
1053 /* Open the file if necessary, and write the data */
1054
1055 if (rejectlogfd < 0)
1056 {
1057 open_log(&rejectlogfd, lt_reject, NULL); /* No return on error */
1058 if (fstat(rejectlogfd, &statbuf) >= 0) rejectlog_inode = statbuf.st_ino;
1059 }
1060
1061 written_len = write_to_fd_buf(rejectlogfd, log_buffer, length);
1062 if (written_len != length)
1063 {
1064 log_write_failed(US"reject log", length, written_len);
1065 /* That function does not return */
1066 }
1067 }
1068 }
1069
1070
1071 /* Handle the panic log, which is not kept open like the others. If it fails to
1072 open, there will be a recursive call to log_write(). We detect this above and
1073 attempt to write to the system log as a last-ditch try at telling somebody. In
1074 all cases except mua_wrapper, try to write to log_stderr. */
1075
1076 if ((flags & LOG_PANIC) != 0)
1077 {
1078 if (log_stderr != NULL && log_stderr != debug_file && !mua_wrapper)
1079 fprintf(log_stderr, "%s", CS log_buffer);
1080
1081 if ((logging_mode & LOG_MODE_SYSLOG) != 0)
1082 {
1083 write_syslog(LOG_ALERT, log_buffer);
1084 }
1085
1086 /* If this panic logging was caused by a failure to open the main log,
1087 the original log line is in panic_save_buffer. Make an attempt to write it. */
1088
1089 if ((logging_mode & LOG_MODE_FILE) != 0)
1090 {
1091 panic_recurseflag = TRUE;
1092 open_log(&paniclogfd, lt_panic, NULL); /* Won't return on failure */
1093 panic_recurseflag = FALSE;
1094
1095 if (panic_save_buffer != NULL)
1096 {
1097 int i = write(paniclogfd, panic_save_buffer, Ustrlen(panic_save_buffer));
1098 i = i; /* compiler quietening */
1099 }
1100
1101 written_len = write_to_fd_buf(paniclogfd, log_buffer, length);
1102 if (written_len != length)
1103 {
1104 int save_errno = errno;
1105 write_syslog(LOG_CRIT, log_buffer);
1106 sprintf(CS log_buffer, "write failed on panic log: length=%d result=%d "
1107 "errno=%d (%s)", length, (int)written_len, save_errno, strerror(save_errno));
1108 write_syslog(LOG_CRIT, log_buffer);
1109 flags |= LOG_PANIC_DIE;
1110 }
1111
1112 (void)close(paniclogfd);
1113 }
1114
1115 /* Give up if the DIE flag is set */
1116
1117 if ((flags & LOG_PANIC_DIE) != LOG_PANIC)
1118 die(NULL, US"Unexpected failure, please try later");
1119 }
1120 }
1121
1122
1123
1124 /*************************************************
1125 * Close any open log files *
1126 *************************************************/
1127
1128 void
1129 log_close_all(void)
1130 {
1131 if (mainlogfd >= 0)
1132 { (void)close(mainlogfd); mainlogfd = -1; }
1133 if (rejectlogfd >= 0)
1134 { (void)close(rejectlogfd); rejectlogfd = -1; }
1135 closelog();
1136 syslog_open = FALSE;
1137 }
1138
1139
1140
1141 /*************************************************
1142 * Multi-bit set or clear *
1143 *************************************************/
1144
1145 /* These functions take a list of bit indexes (terminated by -1) and
1146 clear or set the corresponding bits in the selector.
1147
1148 Arguments:
1149 selector address of the bit string
1150 selsize number of words in the bit string
1151 bits list of bits to set
1152 */
1153
1154 void
1155 bits_clear(unsigned int *selector, size_t selsize, int *bits)
1156 {
1157 for(; *bits != -1; ++bits)
1158 BIT_CLEAR(selector, selsize, *bits);
1159 }
1160
1161 void
1162 bits_set(unsigned int *selector, size_t selsize, int *bits)
1163 {
1164 for(; *bits != -1; ++bits)
1165 BIT_SET(selector, selsize, *bits);
1166 }
1167
1168
1169
1170 /*************************************************
1171 * Decode bit settings for log/debug *
1172 *************************************************/
1173
1174 /* This function decodes a string containing bit settings in the form of +name
1175 and/or -name sequences, and sets/unsets bits in a bit string accordingly. It
1176 also recognizes a numeric setting of the form =<number>, but this is not
1177 intended for user use. It's an easy way for Exim to pass the debug settings
1178 when it is re-exec'ed.
1179
1180 The option table is a list of names and bit indexes. The index -1
1181 means "set all bits, except for those listed in notall". The notall
1182 list is terminated by -1.
1183
1184 The action taken for bad values varies depending upon why we're here.
1185 For log messages, or if the debugging is triggered from config, then we write
1186 to the log on the way out. For debug setting triggered from the command-line,
1187 we treat it as an unknown option: error message to stderr and die.
1188
1189 Arguments:
1190 selector address of the bit string
1191 selsize number of words in the bit string
1192 notall list of bits to exclude from "all"
1193 string the configured string
1194 options the table of option names
1195 count size of table
1196 which "log" or "debug"
1197 flags DEBUG_FROM_CONFIG
1198
1199 Returns: nothing on success - bomb out on failure
1200 */
1201
1202 void
1203 decode_bits(unsigned int *selector, size_t selsize, int *notall,
1204 uschar *string, bit_table *options, int count, uschar *which, int flags)
1205 {
1206 uschar *errmsg;
1207 if (string == NULL) return;
1208
1209 if (*string == '=')
1210 {
1211 char *end; /* Not uschar */
1212 memset(selector, 0, sizeof(*selector)*selsize);
1213 *selector = strtoul(CS string+1, &end, 0);
1214 if (*end == 0) return;
1215 errmsg = string_sprintf("malformed numeric %s_selector setting: %s", which,
1216 string);
1217 goto ERROR_RETURN;
1218 }
1219
1220 /* Handle symbolic setting */
1221
1222 else for(;;)
1223 {
1224 BOOL adding;
1225 uschar *s;
1226 int len;
1227 bit_table *start, *end;
1228
1229 while (isspace(*string)) string++;
1230 if (*string == 0) return;
1231
1232 if (*string != '+' && *string != '-')
1233 {
1234 errmsg = string_sprintf("malformed %s_selector setting: "
1235 "+ or - expected but found \"%s\"", which, string);
1236 goto ERROR_RETURN;
1237 }
1238
1239 adding = *string++ == '+';
1240 s = string;
1241 while (isalnum(*string) || *string == '_') string++;
1242 len = string - s;
1243
1244 start = options;
1245 end = options + count;
1246
1247 while (start < end)
1248 {
1249 bit_table *middle = start + (end - start)/2;
1250 int c = Ustrncmp(s, middle->name, len);
1251 if (c == 0)
1252 {
1253 if (middle->name[len] != 0) c = -1; else
1254 {
1255 unsigned int bit = middle->bit;
1256
1257 if (bit == -1)
1258 {
1259 if (adding)
1260 {
1261 memset(selector, -1, sizeof(*selector)*selsize);
1262 bits_clear(selector, selsize, notall);
1263 }
1264 else
1265 memset(selector, 0, sizeof(*selector)*selsize);
1266 }
1267 else if (adding)
1268 BIT_SET(selector, selsize, bit);
1269 else
1270 BIT_CLEAR(selector, selsize, bit);
1271
1272 break; /* Out of loop to match selector name */
1273 }
1274 }
1275 if (c < 0) end = middle; else start = middle + 1;
1276 } /* Loop to match selector name */
1277
1278 if (start >= end)
1279 {
1280 errmsg = string_sprintf("unknown %s_selector setting: %c%.*s", which,
1281 adding? '+' : '-', len, s);
1282 goto ERROR_RETURN;
1283 }
1284 } /* Loop for selector names */
1285
1286 /* Handle disasters */
1287
1288 ERROR_RETURN:
1289 if (Ustrcmp(which, "debug") == 0)
1290 {
1291 if (flags & DEBUG_FROM_CONFIG)
1292 {
1293 log_write(0, LOG_CONFIG|LOG_PANIC, "%s", errmsg);
1294 return;
1295 }
1296 fprintf(stderr, "exim: %s\n", errmsg);
1297 exit(EXIT_FAILURE);
1298 }
1299 else log_write(0, LOG_CONFIG|LOG_PANIC_DIE, "%s", errmsg);
1300 }
1301
1302
1303
1304 /*************************************************
1305 * Activate a debug logfile (late) *
1306 *************************************************/
1307
1308 /* Normally, debugging is activated from the command-line; it may be useful
1309 within the configuration to activate debugging later, based on certain
1310 conditions. If debugging is already in progress, we return early, no action
1311 taken (besides debug-logging that we wanted debug-logging).
1312
1313 Failures in options are not fatal but will result in paniclog entries for the
1314 misconfiguration.
1315
1316 The first use of this is in ACL logic, "control = debug/tag=foo/opts=+expand"
1317 which can be combined with conditions, etc, to activate extra logging only
1318 for certain sources. The second use is inetd wait mode debug preservation. */
1319
1320 void
1321 debug_logging_activate(uschar *tag_name, uschar *opts)
1322 {
1323 int fd = -1;
1324
1325 if (debug_file)
1326 {
1327 debug_printf("DEBUGGING ACTIVATED FROM WITHIN CONFIG.\n"
1328 "DEBUG: Tag=\"%s\" Opts=\"%s\"\n", tag_name, opts ? opts : US"");
1329 return;
1330 }
1331
1332 if (tag_name != NULL && (Ustrchr(tag_name, '/') != NULL))
1333 {
1334 log_write(0, LOG_MAIN|LOG_PANIC, "debug tag may not contain a '/' in: %s",
1335 tag_name);
1336 return;
1337 }
1338
1339 debug_selector = D_default;
1340 if (opts)
1341 decode_bits(&debug_selector, 1, debug_notall, opts,
1342 debug_options, debug_options_count, US"debug", DEBUG_FROM_CONFIG);
1343
1344 /* When activating from a transport process we may never have logged at all
1345 resulting in certain setup not having been done. Hack this for now so we
1346 do not segfault; note that nondefault log locations will not work */
1347
1348 if (!*file_path) set_file_path();
1349
1350 open_log(&fd, lt_debug, tag_name);
1351
1352 if (fd != -1)
1353 debug_file = fdopen(fd, "w");
1354 else
1355 log_write(0, LOG_MAIN|LOG_PANIC, "unable to open debug log");
1356 }
1357
1358
1359 /* End of log.c */