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