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