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