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