exiwhat: Ensure the SIGUSR1 signal handler is safe.
[exim.git] / src / src / log.c
1 /* $Cambridge: exim/src/src/log.c,v 1.15 2010/06/06 00:27:52 pdp Exp $ */
2
3 /*************************************************
4 * Exim - an Internet mail transport agent *
5 *************************************************/
6
7 /* Copyright (c) University of Cambridge 1995 - 2009 */
8 /* See the file NOTICE for conditions of use and distribution. */
9
10 /* Functions for writing log files. The code for maintaining datestamped
11 log 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
22 enum { lt_main, lt_reject, lt_panic, lt_debug };
23
24 static uschar *log_names[] = { US"main", US"reject", US"panic", US"debug" };
25
26
27
28 /*************************************************
29 * Local static variables *
30 *************************************************/
31
32 static uschar mainlog_name[LOG_NAME_SIZE];
33 static uschar rejectlog_name[LOG_NAME_SIZE];
34 static uschar debuglog_name[LOG_NAME_SIZE];
35
36 static uschar *mainlog_datestamp = NULL;
37 static uschar *rejectlog_datestamp = NULL;
38
39 static int mainlogfd = -1;
40 static int rejectlogfd = -1;
41 static ino_t mainlog_inode = 0;
42 static ino_t rejectlog_inode = 0;
43
44 static uschar *panic_save_buffer = NULL;
45 static BOOL panic_recurseflag = FALSE;
46
47 static BOOL syslog_open = FALSE;
48 static BOOL path_inspected = FALSE;
49 static int logging_mode = LOG_MODE_FILE;
50 static 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
60 newlines, and syslogged as a numbered sequence if it is overlong or if there is
61 more than one line. However, if we are running in the test harness, do not do
62 anything. (The test harness doesn't use syslog - for obvious reasons - but we
63 can get here if there is a failure to open the panic log.)
64
65 Arguments:
66 priority syslog priority
67 s the string to be written
68
69 Returns: nothing
70 */
71
72 static void
73 write_syslog(int priority, uschar *s)
74 {
75 int len, pass;
76 int linecount = 0;
77
78 if (running_in_test_harness) return;
79
80 if (!syslog_timestamp) s += log_timezone? 26 : 20;
81
82 len = Ustrlen(s);
83
84 #ifndef NO_OPENLOG
85 if (!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
97 it is going to end up as. Then rescan to output it. */
98
99 for (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
137 the logging, or after a log call with LOG_PANIC_DIE set. Optionally write a
138 message to debug_file or a stderr file, if they exist. Then, if in the middle
139 of accepting a message, throw it away tidily by calling receive_bomb_out();
140 this will attempt to send an SMTP response if appropriate. Passing NULL as the
141 first argument stops it trying to run the NOTQUIT ACL (which might try further
142 logging and thus cause problems). Otherwise, try to close down an outstanding
143 SMTP call tidily.
144
145 Arguments:
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
148 Returns: The function does not return
149 */
150
151 static void
152 die(uschar *s1, uschar *s2)
153 {
154 if (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 }
161 if (receive_call_bombout) receive_bomb_out(NULL, s2); /* does not return */
162 if (smtp_input) smtp_closedown(s2);
163 exim_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
173 subprocess when the original process is root.
174
175 Arguments:
176 name the file name
177
178 The file name has been build in a working buffer, so it is permissible to
179 overwrite it temporarily if it is necessary to create the directory.
180
181 Returns: a file descriptor, or < 0 on failure (errno set)
182 */
183
184 static int
185 log_create(uschar *name)
186 {
187 int 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
190 problem. */
191
192 if (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
204 return fd;
205 }
206
207
208
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
214 in which we can create a log file. It must be signal-safe since it is called
215 by the usr1_handler().
216
217 Arguments:
218 name the file name
219
220 Returns: a file descriptor, or < 0 on failure (errno set)
221 */
222
223 int
224 log_create_as_exim(uschar *name)
225 {
226 pid_t pid = fork();
227 int status = 1;
228 int fd = -1;
229
230 /* In the subprocess, change uid/gid and do the creation. Return 0 from the
231 subprocess on success. If we don't check for setuid failures, then the file
232 can be created as root, so vulnerabilities which cause setuid to fail mean
233 that the Exim user can use symlinks to cause a file to be opened/created as
234 root. We always open for append, so can't nuke existing content but it would
235 still be Rather Bad. */
236
237 if (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
250 while (pid > 0 && waitpid(pid, &status, 0) != pid);
251 if (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
254 with fd still < 0, and errno set, letting the caller handle the error. */
255
256 return fd;
257 }
258
259
260
261
262 /*************************************************
263 * Open a log file *
264 *************************************************/
265
266 /* This function opens one of a number of logs, creating the log directory if
267 it does not exist. This may be called recursively on failure, in order to open
268 the panic log.
269
270 The directory is in the static variable file_path. This is static so that it
271 the work of sorting out the path is done just once per Exim process.
272
273 Exim is normally configured to avoid running as root wherever possible, the log
274 files must be owned by the non-privileged exim user. To ensure this, first try
275 an open without O_CREAT - most of the time this will succeed. If it fails, try
276 to create the file; if running as root, this must be done in a subprocess to
277 avoid races.
278
279 Arguments:
280 fd where to return the resulting file descriptor
281 type lt_main, lt_reject, lt_panic, or lt_debug
282 tag optional tag to include in the name (only hooked up for debug)
283
284 Returns: nothing
285 */
286
287 static void
288 open_log(int *fd, int type, uschar *tag)
289 {
290 uid_t euid;
291 BOOL ok, ok2;
292 uschar buffer[LOG_NAME_SIZE];
293
294 /* The names of the log files are controlled by file_path. The panic log is
295 written to the same directory as the main and reject logs, but its name does
296 not have a datestamp. The use of datestamps is indicated by %D/%M in file_path.
297 When opening the panic log, if %D or %M is present, we remove the datestamp
298 from the generated name; if it is at the start, remove a following
299 non-alphanumeric character as well; otherwise, remove a preceding
300 non-alphanumeric character. This is definitely kludgy, but it sort of does what
301 people want, I hope. */
302
303 ok = 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,
306 it gets statted to see if it has been cycled. With a datestamp, the datestamp
307 will be compared. The static slot for saving it is the same size as buffer,
308 and the text has been checked above to fit, so this use of strcpy() is OK. */
309
310 if (type == lt_main)
311 {
312 Ustrcpy(mainlog_name, buffer);
313 mainlog_datestamp = mainlog_name + string_datestamp_offset;
314 }
315
316 /* Ditto for the reject log */
317
318 else if (type == lt_reject)
319 {
320 Ustrcpy(rejectlog_name, buffer);
321 rejectlog_datestamp = rejectlog_name + string_datestamp_offset;
322 }
323
324 /* and deal with the debug log (which keeps the datestamp, but does not
325 update it) */
326
327 else if (type == lt_debug)
328 {
329 Ustrcpy(debuglog_name, buffer);
330 if (tag)
331 {
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);
337 }
338 }
339
340 /* Remove any datestamp if this is the panic log. This is rare, so there's no
341 need to optimize getting the datestamp length. We remove one non-alphanumeric
342 char afterwards if at the start, otherwise one before. */
343
344 else 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] == '/')
349 {
350 if (!isalnum(*to)) to++;
351 }
352 else
353 {
354 if (!isalnum(from[-1])) from--;
355 }
356
357 /* This strcpy is ok, because we know that to is a substring of from. */
358
359 Ustrcpy(from, to);
360 }
361
362 /* If the file name is too long, it is an unrecoverable disaster */
363
364 if (!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
371 open, arrange for automatic closure on exec(), and then return. */
372
373 *fd = Uopen(buffer, O_APPEND|O_WRONLY, LOG_MODE);
374
375 if (*fd >= 0)
376 {
377 (void)fcntl(*fd, F_SETFD, fcntl(*fd, F_GETFD) | FD_CLOEXEC);
378 return;
379 }
380
381 /* Open was not successful: try creating the file. If this is a root process,
382 we must do the creating in a subprocess set to exim:exim in order to ensure
383 that the file is created with the right ownership. Otherwise, there can be a
384 race if another Exim process is trying to write to the log at the same time.
385 The use of SIGUSR1 by the exiwhat utility can provoke a lot of simultaneous
386 writing. */
387
388 euid = geteuid();
389
390 /* If we are already running as the Exim user (even if that user is root),
391 we can go ahead and create in the current process. */
392
393 if (euid == exim_uid) *fd = log_create(buffer);
394
395 /* Otherwise, if we are root, do the creation in an exim:exim subprocess. If we
396 are neither exim nor root, creation is not attempted. */
397
398 else if (euid == root_uid) *fd = log_create_as_exim(buffer);
399
400 /* If we now have an open file, set the close-on-exec flag and return. */
401
402 if (*fd >= 0)
403 {
404 (void)fcntl(*fd, F_SETFD, fcntl(*fd, F_GETFD) | FD_CLOEXEC);
405 return;
406 }
407
408 /* Creation failed. There are some circumstances in which we get here when
409 the effective uid is not root or exim, which is the problem. (For example, a
410 non-setuid binary with log_arguments set, called in certain ways.) Rather than
411 just bombing out, force the log to stderr and carry on if stderr is available.
412 */
413
414 if (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
421 log. If possible, save a copy of the original line that was being logged. If we
422 are recursing (can't open the panic log either), the pointer will already be
423 set. */
424
425 if (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
432 log_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,
444 once for real).
445
446 Arguments:
447 ptr pointer to the end of the line we are building
448 flags log flags
449
450 Returns: updated pointer
451 */
452
453 static uschar *
454 log_config_info(uschar *ptr, int flags)
455 {
456 Ustrcpy(ptr, "Exim configuration error");
457 ptr += 24;
458
459 if ((flags & (LOG_CONFIG_FOR & ~LOG_CONFIG)) != 0)
460 {
461 Ustrcpy(ptr, " for ");
462 return ptr + 5;
463 }
464
465 if ((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
471 Ustrcpy(ptr, ":\n ");
472 return 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
481 log, which can happen if a disk gets full or a file gets too large or whatever.
482 We try to save the relevant message in the panic_save buffer before crashing
483 out.
484
485 Arguments:
486 name the name of the log being written
487 length the string length being written
488 rc the return value from write()
489
490 Returns: does not return
491 */
492
493 static void
494 log_write_failed(uschar *name, int length, int rc)
495 {
496 int save_errno = errno;
497
498 if (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
505 log_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
518 is controlled by the setting of log_file_path. The following cases are
519 recognized:
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
526 The message always gets '\n' added on the end of it, since more than one
527 process may be writing to the log at once and we don't want intermingling to
528 happen in the middle of lines. To be absolutely sure of this we write the data
529 into a private buffer and then put it out in a single write() call.
530
531 The flags determine which log(s) the message is written to, or for syslogging,
532 which priority to use, and in the case of the panic log, whether the process
533 should die afterwards.
534
535 The 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).
537 If it is not, don't try to write to the log because permission will probably be
538 denied.
539
540 Avoid actually writing to the logs when exim is called with -bv or -bt to
541 test an address, but take other actions, such as panicing.
542
543 In Exim proper, the buffer for building the message is got at start-up, so that
544 nothing gets done if it can't be got. However, some functions that are also
545 used in utilities occasionally obey log_write calls in error situations, and it
546 is simplest to put a single malloc() here rather than put one in each utility.
547 Malloc is used directly because the store functions may call log_write().
548
549 If a message_id exists, we include it after the timestamp.
550
551 Arguments:
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
564 format a printf() format
565 ... arguments for format
566
567 Returns: nothing
568 */
569
570 void
571 log_write(unsigned int selector, int flags, const char *format, ...)
572 {
573 uschar *ptr;
574 int length, rc;
575 int paniclogfd;
576 va_list ap;
577
578 /* If panic_recurseflag is set, we have failed to open the panic log. This is
579 the ultimate disaster. First try to write the message to a debug file and/or
580 stderr and also to syslog. If panic_save_buffer is not NULL, it contains the
581 original log line that caused the problem. Afterwards, expire. */
582
583 if (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
596 when running Exim proper, only when running utilities. */
597
598 if (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
609 determine whether to log to files and/or to syslog. Bits in logging_mode
610 control this, and for file logging, the path must end up in file_path. This
611 variable must be in permanent store because it may be required again later in
612 the process. */
613
614 if (!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
692 in one go so that it doesn't get split when multi-processing. */
693
694 DEBUG(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" : "",
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
739 if ((flags & (LOG_MAIN|LOG_PANIC|LOG_REJECT)) == 0)
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
745 if (disable_logging)
746 {
747 DEBUG(D_any) debug_printf("log writing disabled\n");
748 return;
749 }
750
751 /* Handle disabled reject log */
752
753 if (!write_rejectlog) flags &= ~LOG_REJECT;
754
755 /* Create the main message in the log buffer. Do not include the message id
756 when called by a utility. */
757
758 ptr = log_buffer;
759 sprintf(CS ptr, "%s ", tod_stamp(tod_log));
760 while(*ptr) ptr++;
761
762 if ((log_extra_selector & LX_pid) != 0)
763 {
764 sprintf(CS ptr, "[%d] ", (int)getpid());
765 while (*ptr) ptr++;
766 }
767
768 if (really_exim && message_id[0] != 0)
769 {
770 sprintf(CS ptr, "%s ", message_id);
771 while(*ptr) ptr++;
772 }
773
774 if ((flags & LOG_CONFIG) != 0) ptr = log_config_info(ptr, flags);
775
776 va_start(ap, format);
777 if (!string_vformat(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer)-1, format, ap))
778 Ustrcpy(ptr, "**** log string overflowed log buffer ****\n");
779 while(*ptr) ptr++;
780 va_end(ap);
781
782 /* Add the raw, unrewritten, sender to the message if required. This is done
783 this way because it kind of fits with LOG_RECIPIENTS. */
784
785 if ((flags & LOG_SENDER) != 0 &&
786 ptr < log_buffer + LOG_BUFFER_SIZE - 10 - Ustrlen(raw_sender))
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,
793 before rewriting, was saved in raw_recipients. There may be none, if an ACL
794 discarded them all. */
795
796 if ((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
811 sprintf(CS ptr, "\n");
812 while(*ptr) ptr++;
813 length = ptr - log_buffer;
814
815 /* Handle loggable errors when running a utility, or when address testing.
816 Write to log_stderr unless debugging (when it will already have been written),
817 or unless there is no log_stderr (expn called from daemon, for example). */
818
819 if (!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
834 set up. A real file gets left open during reception or delivery once it has
835 been opened, but we don't want to keep on writing to it for too long after it
836 has been renamed. Therefore, do a stat() and see if the inode has changed, and
837 if so, re-open. */
838
839 if ((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 {
856 uschar *nowstamp = tod_stamp(string_datestamp_type);
857 if (Ustrncmp (mainlog_datestamp, nowstamp, Ustrlen(nowstamp)) != 0)
858 {
859 (void)close(mainlogfd); /* Close the file */
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 {
875 (void)close(mainlogfd);
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 {
885 open_log(&mainlogfd, lt_main, NULL); /* No return on error */
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
899 /* Handle the log for rejected messages. This can be globally disabled, in
900 which case the flags are altered above. If there are any header lines (i.e. if
901 the rejection is happening after the DATA phase), log the recipients and the
902 headers. */
903
904 if ((flags & LOG_REJECT) != 0)
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 {
979 uschar *nowstamp = tod_stamp(string_datestamp_type);
980 if (Ustrncmp (rejectlog_datestamp, nowstamp, Ustrlen(nowstamp)) != 0)
981 {
982 (void)close(rejectlogfd); /* Close the file */
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 {
999 (void)close(rejectlogfd);
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 {
1009 open_log(&rejectlogfd, lt_reject, NULL); /* No return on error */
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
1022 /* Handle the panic log, which is not kept open like the others. If it fails to
1023 open, there will be a recursive call to log_write(). We detect this above and
1024 attempt to write to the system log as a last-ditch try at telling somebody. In
1025 all cases except mua_wrapper, try to write to log_stderr. */
1026
1027 if ((flags & LOG_PANIC) != 0)
1028 {
1029 if (log_stderr != NULL && log_stderr != debug_file && !mua_wrapper)
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;
1043 open_log(&paniclogfd, lt_panic, NULL); /* Won't return on failure */
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
1059 (void)close(paniclogfd);
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
1075 void
1076 log_close_all(void)
1077 {
1078 if (mainlogfd >= 0)
1079 { (void)close(mainlogfd); mainlogfd = -1; }
1080 if (rejectlogfd >= 0)
1081 { (void)close(rejectlogfd); rejectlogfd = -1; }
1082 closelog();
1083 syslog_open = FALSE;
1084 }
1085
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
1093 and/or -name sequences, and sets/unsets bits in a bit string accordingly. It
1094 also recognizes a numeric setting of the form =<number>, but this is not
1095 intended for user use. It's an easy way for Exim to pass the debug settings
1096 when it is re-exec'ed.
1097
1098 The log options are held in two unsigned ints (because there became too many
1099 for one). The top bit in the table means "put in 2nd selector". This does not
1100 yet apply to debug options, so the "=" facility sets only the first selector.
1101
1102 The "all" selector, which must be equal to 0xffffffff, is recognized specially.
1103 It sets all the bits in both selectors. However, there is a facility for then
1104 unsetting certain bits, because we want to turn off "memory" in the debug case.
1105
1106 The action taken for bad values varies depending upon why we're here.
1107 For log messages, or if the debugging is triggered from config, then we write
1108 to the log on the way out. For debug setting triggered from the command-line,
1109 we treat it as an unknown option: error message to stderr and die.
1110
1111 Arguments:
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
1122 Returns: nothing on success - bomb out on failure
1123 */
1124
1125 void
1126 decode_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 {
1130 uschar *errmsg;
1131 if (string == NULL) return;
1132
1133 if (*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
1145 else 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
1229 ERROR_RETURN:
1230 if (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 }
1240 else 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
1250 within the configuration to activate debugging later, based on certain
1251 conditions. If debugging is already in progress, we return early, no action
1252 taken (besides debug-logging that we wanted debug-logging).
1253
1254 Failures in options are not fatal but will result in paniclog entries for the
1255 misconfiguration.
1256
1257 The first use of this is in ACL logic, "control = debug/tag=foo/opts=+expand"
1258 which can be combined with conditions, etc, to activate extra logging only
1259 for certain sources. */
1260
1261 void
1262 debug_logging_activate(uschar *tag_name, uschar *opts)
1263 {
1264 int fd = -1;
1265
1266 if (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
1273 if (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
1280 debug_selector = D_default;
1281 if (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
1287 open_log(&fd, lt_debug, tag_name);
1288
1289 if (fd != -1)
1290 debug_file = fdopen(fd, "w");
1291 else
1292 log_write(0, LOG_MAIN|LOG_PANIC, "unable to open debug log");
1293 }
1294
1295
1296 /* End of log.c */