Ensure we log the error message when unlink() fails.
[exim.git] / src / src / log.c
... / ...
CommitLineData
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
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
22enum { lt_main, lt_reject, lt_panic, lt_debug, lt_process };
23
24static uschar *log_names[] = { US"main", US"reject", US"panic", US"debug", US"process" };
25
26
27
28/*************************************************
29* Local static variables *
30*************************************************/
31
32static uschar mainlog_name[LOG_NAME_SIZE];
33static uschar rejectlog_name[LOG_NAME_SIZE];
34static uschar debuglog_name[LOG_NAME_SIZE];
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
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.)
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
78if (running_in_test_harness) return;
79
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
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.
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 }
161if (receive_call_bombout) receive_bomb_out(NULL, s2); /* does not return */
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
185create_log(uschar *name)
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
209
210/*************************************************
211* Open a log file *
212*************************************************/
213
214/* This function opens one of a number of logs, which all (except for the
215"process log") reside in the same directory, creating the directory if it does
216not exist. This may be called recursively on failure, in order to open the
217panic log.
218
219The directory is in the static variable file_path. This is static so that it
220the work of sorting out the path is done just once per Exim process.
221
222Exim is normally configured to avoid running as root wherever possible, the log
223files must be owned by the non-privileged exim user. To ensure this, first try
224an open without O_CREAT - most of the time this will succeed. If it fails, try
225to create the file; if running as root, this must be done in a subprocess to
226avoid races.
227
228Arguments:
229 fd where to return the resulting file descriptor
230 type lt_main, lt_reject, lt_panic, lt_debug or lt_process
231 tag optional tag to include in the name (only hooked up for debug)
232
233Returns: nothing
234*/
235
236static void
237open_log(int *fd, int type, uschar *tag)
238{
239uid_t euid;
240BOOL ok, ok2;
241uschar buffer[LOG_NAME_SIZE];
242
243/* Sort out the file name. This depends on the type of log we are opening. The
244process "log" is written in the spool directory by default, but a path name can
245be specified in the configuration. */
246
247if (type == lt_process)
248 {
249 if (process_log_path == NULL)
250 ok = string_format(buffer, sizeof(buffer), "%s/exim-process.info",
251 spool_directory);
252 else
253 ok = string_format(buffer, sizeof(buffer), "%s", process_log_path);
254 }
255
256/* The names of the other three logs are controlled by file_path. The panic log
257is written to the same directory as the main and reject logs, but its name does
258not have a datestamp. The use of datestamps is indicated by %D/%M in file_path.
259When opening the panic log, if %D or %M is present, we remove the datestamp
260from the generated name; if it is at the start, remove a following
261non-alphanumeric character as well; otherwise, remove a preceding
262non-alphanumeric character. This is definitely kludgy, but it sort of does what
263people want, I hope. */
264
265else
266 {
267 ok = string_format(buffer, sizeof(buffer), CS file_path, log_names[type]);
268
269 /* Save the name of the mainlog for rollover processing. Without a datestamp,
270 it gets statted to see if it has been cycled. With a datestamp, the datestamp
271 will be compared. The static slot for saving it is the same size as buffer,
272 and the text has been checked above to fit, so this use of strcpy() is OK. */
273
274 if (type == lt_main)
275 {
276 Ustrcpy(mainlog_name, buffer);
277 mainlog_datestamp = mainlog_name + string_datestamp_offset;
278 }
279
280 /* Ditto for the reject log */
281
282 else if (type == lt_reject)
283 {
284 Ustrcpy(rejectlog_name, buffer);
285 rejectlog_datestamp = rejectlog_name + string_datestamp_offset;
286 }
287
288 /* and deal with the debug log (which keeps the datestamp, but does not
289 update it) */
290
291 else if (type == lt_debug)
292 {
293 Ustrcpy(debuglog_name, buffer);
294 if (tag)
295 {
296 /* this won't change the offset of the datestamp */
297 ok2 = string_format(buffer, sizeof(buffer), "%s%s",
298 debuglog_name, tag);
299 if (ok2)
300 Ustrcpy(debuglog_name, buffer);
301 }
302 }
303
304 /* Remove any datestamp if this is the panic log. This is rare, so there's no
305 need to optimize getting the datestamp length. We remove one non-alphanumeric
306 char afterwards if at the start, otherwise one before. */
307
308 else if (string_datestamp_offset >= 0)
309 {
310 uschar *from = buffer + string_datestamp_offset;
311 uschar *to = from + string_datestamp_length;
312 if (from == buffer || from[-1] == '/')
313 {
314 if (!isalnum(*to)) to++;
315 }
316 else
317 {
318 if (!isalnum(from[-1])) from--;
319 }
320
321 /* This strcpy is ok, because we know that to is a substring of from. */
322
323 Ustrcpy(from, to);
324 }
325 }
326
327/* If the file name is too long, it is an unrecoverable disaster */
328
329if (!ok)
330 {
331 die(US"exim: log file path too long: aborting",
332 US"Logging failure; please try later");
333 }
334
335/* We now have the file name. Try to open an existing file. After a successful
336open, arrange for automatic closure on exec(), and then return. */
337
338*fd = Uopen(buffer, O_APPEND|O_WRONLY, LOG_MODE);
339
340if (*fd >= 0)
341 {
342 (void)fcntl(*fd, F_SETFD, fcntl(*fd, F_GETFD) | FD_CLOEXEC);
343 return;
344 }
345
346/* Open was not successful: try creating the file. If this is a root process,
347we must do the creating in a subprocess set to exim:exim in order to ensure
348that the file is created with the right ownership. Otherwise, there can be a
349race if another Exim process is trying to write to the log at the same time.
350The use of SIGUSR1 by the exiwhat utility can provoke a lot of simultaneous
351writing. */
352
353euid = geteuid();
354
355/* If we are already running as the Exim user (even if that user is root),
356we can go ahead and create in the current process. */
357
358if (euid == exim_uid) *fd = create_log(buffer);
359
360/* Otherwise, if we are root, do the creation in an exim:exim subprocess. If we
361are neither exim nor root, creation is not attempted. */
362
363else if (euid == root_uid)
364 {
365 int status, rv;
366 pid_t pid = fork();
367
368 /* In the subprocess, change uid/gid and do the creation. Return 0 from the
369 subprocess on success. If we don't check for setuid failures, then the file
370 can be created as root, so vulnerabilities which cause setuid to fail mean
371 that the Exim user can use symlinks to cause a file to be opened/created as
372 root. We always open for append, so can't nuke existing content but it would
373 still be Rather Bad. */
374
375 if (pid == 0)
376 {
377 rv = setgid(exim_gid);
378 if (rv)
379 die(US"exim: setgid for log-file creation failed, aborting",
380 US"Unexpected log failure, please try later");
381 rv = setuid(exim_uid);
382 if (rv)
383 die(US"exim: setuid for log-file creation failed, aborting",
384 US"Unexpected log failure, please try later");
385 _exit((create_log(buffer) < 0)? 1 : 0);
386 }
387
388 /* If we created a subprocess, wait for it. If it succeeded retry the open. */
389
390 if (pid > 0)
391 {
392 while (waitpid(pid, &status, 0) != pid);
393 if (status == 0) *fd = Uopen(buffer, O_APPEND|O_WRONLY, LOG_MODE);
394 }
395
396 /* If we failed to create a subprocess, we are in a bad way. We fall through
397 with *fd still < 0, and errno set, letting the code below handle the error. */
398 }
399
400/* If we now have an open file, set the close-on-exec flag and return. */
401
402if (*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
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
526The one exception to this is messages containing LOG_PROCESS. These are always
527written to exim-process.info in the spool directory. They aren't really log
528messages in the same sense as the others.
529
530The message always gets '\n' added on the end of it, since more than one
531process may be writing to the log at once and we don't want intermingling to
532happen in the middle of lines. To be absolutely sure of this we write the data
533into a private buffer and then put it out in a single write() call.
534
535The flags determine which log(s) the message is written to, or for syslogging,
536which priority to use, and in the case of the panic log, whether the process
537should die afterwards.
538
539The variable really_exim is TRUE only when exim is running in privileged state
540(i.e. not with a changed configuration or with testing options such as -brw).
541If it is not, don't try to write to the log because permission will probably be
542denied.
543
544Avoid actually writing to the logs when exim is called with -bv or -bt to
545test an address, but take other actions, such as panicing.
546
547In Exim proper, the buffer for building the message is got at start-up, so that
548nothing gets done if it can't be got. However, some functions that are also
549used in utilities occasionally obey log_write calls in error situations, and it
550is simplest to put a single malloc() here rather than put one in each utility.
551Malloc is used directly because the store functions may call log_write().
552
553If a message_id exists, we include it after the timestamp.
554
555Arguments:
556 selector write to main log or LOG_INFO only if this value is zero, or if
557 its bit is set in log_write_selector
558 flags each bit indicates some independent action:
559 LOG_SENDER add raw sender to the message
560 LOG_RECIPIENTS add raw recipients list to message
561 LOG_CONFIG add "Exim configuration error"
562 LOG_CONFIG_FOR add " for " instead of ":\n "
563 LOG_CONFIG_IN add " in line x[ of file y]"
564 LOG_MAIN write to main log or syslog LOG_INFO
565 LOG_REJECT write to reject log or syslog LOG_NOTICE
566 LOG_PANIC write to panic log or syslog LOG_ALERT
567 LOG_PANIC_DIE write to panic log or LOG_ALERT and then crash
568 LOG_PROCESS write to process log (always a file)
569 format a printf() format
570 ... arguments for format
571
572Returns: nothing
573*/
574
575void
576log_write(unsigned int selector, int flags, const char *format, ...)
577{
578uschar *ptr;
579int length, rc;
580int paniclogfd;
581va_list ap;
582
583/* If panic_recurseflag is set, we have failed to open the panic log. This is
584the ultimate disaster. First try to write the message to a debug file and/or
585stderr and also to syslog. If panic_save_buffer is not NULL, it contains the
586original log line that caused the problem. Afterwards, expire. */
587
588if (panic_recurseflag)
589 {
590 uschar *extra = (panic_save_buffer == NULL)? US"" : panic_save_buffer;
591 if (debug_file != NULL) debug_printf("%s%s", extra, log_buffer);
592 if (log_stderr != NULL && log_stderr != debug_file)
593 fprintf(log_stderr, "%s%s", extra, log_buffer);
594 if (*extra != 0) write_syslog(LOG_CRIT, extra);
595 write_syslog(LOG_CRIT, log_buffer);
596 die(US"exim: could not open panic log - aborting: see message(s) above",
597 US"Unexpected log failure, please try later");
598 }
599
600/* Ensure we have a buffer (see comment above); this should never be obeyed
601when running Exim proper, only when running utilities. */
602
603if (log_buffer == NULL)
604 {
605 log_buffer = (uschar *)malloc(LOG_BUFFER_SIZE);
606 if (log_buffer == NULL)
607 {
608 fprintf(stderr, "exim: failed to get store for log buffer\n");
609 exim_exit(EXIT_FAILURE);
610 }
611 }
612
613/* If we haven't already done so, inspect the setting of log_file_path to
614determine whether to log to files and/or to syslog. Bits in logging_mode
615control this, and for file logging, the path must end up in file_path. This
616variable must be in permanent store because it may be required again later in
617the process. */
618
619if (!path_inspected)
620 {
621 BOOL multiple = FALSE;
622 int old_pool = store_pool;
623
624 store_pool = POOL_PERM;
625
626 /* If nothing has been set, don't waste effort... the default values for the
627 statics are file_path="" and logging_mode = LOG_MODE_FILE. */
628
629 if (log_file_path[0] != 0)
630 {
631 int sep = ':'; /* Fixed separator - outside use */
632 uschar *s;
633 uschar *ss = log_file_path;
634 logging_mode = 0;
635 while ((s = string_nextinlist(&ss,&sep,log_buffer,LOG_BUFFER_SIZE)) != NULL)
636 {
637 if (Ustrcmp(s, "syslog") == 0)
638 logging_mode |= LOG_MODE_SYSLOG;
639 else if ((logging_mode & LOG_MODE_FILE) != 0) multiple = TRUE;
640 else
641 {
642 logging_mode |= LOG_MODE_FILE;
643
644 /* If a non-empty path is given, use it */
645
646 if (s[0] != 0)
647 {
648 file_path = string_copy(s);
649 }
650
651 /* If the path is empty, we want to use the first non-empty, non-
652 syslog item in LOG_FILE_PATH, if there is one, since the value of
653 log_file_path may have been set at runtime. If there is no such item,
654 use the ultimate default in the spool directory. */
655
656 else
657 {
658 uschar *t;
659 uschar *tt = US LOG_FILE_PATH;
660 while ((t = string_nextinlist(&tt,&sep,log_buffer,LOG_BUFFER_SIZE))
661 != NULL)
662 {
663 if (Ustrcmp(t, "syslog") == 0 || t[0] == 0) continue;
664 file_path = string_copy(t);
665 break;
666 }
667 } /* Empty item in log_file_path */
668 } /* First non-syslog item in log_file_path */
669 } /* Scan of log_file_path */
670 }
671
672 /* If no modes have been selected, it is a major disaster */
673
674 if (logging_mode == 0)
675 die(US"Neither syslog nor file logging set in log_file_path",
676 US"Unexpected logging failure");
677
678 /* Set up the ultimate default if necessary. Then revert to the old store
679 pool, and record that we've sorted out the path. */
680
681 if ((logging_mode & LOG_MODE_FILE) != 0 && file_path[0] == 0)
682 file_path = string_sprintf("%s/log/%%slog", spool_directory);
683 store_pool = old_pool;
684 path_inspected = TRUE;
685
686 /* If more than one file path was given, log a complaint. This recursive call
687 should work since we have now set up the routing. */
688
689 if (multiple)
690 {
691 log_write(0, LOG_MAIN|LOG_PANIC,
692 "More than one path given in log_file_path: using %s", file_path);
693 }
694 }
695
696/* If debugging, show all log entries, but don't show headers. Do it all
697in one go so that it doesn't get split when multi-processing. */
698
699DEBUG(D_any|D_v)
700 {
701 int i;
702 ptr = log_buffer;
703
704 Ustrcpy(ptr, "LOG:");
705 ptr += 4;
706
707 /* Show the options that were passed into the call. These are those whose
708 flag values do not have the 0x80000000 bit in them. Note that this
709 automatically exclude the "all" setting. */
710
711 for (i = 0; i < log_options_count; i++)
712 {
713 unsigned int bit = log_options[i].bit;
714 if ((bit & 0x80000000) != 0) continue;
715 if ((selector & bit) != 0)
716 {
717 *ptr++ = ' ';
718 Ustrcpy(ptr, log_options[i].name);
719 while (*ptr) ptr++;
720 }
721 }
722
723 sprintf(CS ptr, "%s%s%s%s%s\n ",
724 ((flags & LOG_MAIN) != 0)? " MAIN" : "",
725 ((flags & LOG_PANIC) != 0)? " PANIC" : "",
726 ((flags & LOG_PANIC_DIE) == LOG_PANIC_DIE)? " DIE" : "",
727 ((flags & LOG_PROCESS) != 0)? " PROCESS": "",
728 ((flags & LOG_REJECT) != 0)? " REJECT" : "");
729
730 while(*ptr) ptr++;
731 if ((flags & LOG_CONFIG) != 0) ptr = log_config_info(ptr, flags);
732
733 va_start(ap, format);
734 if (!string_vformat(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer)-1, format, ap))
735 Ustrcpy(ptr, "**** log string overflowed log buffer ****");
736 va_end(ap);
737
738 while(*ptr) ptr++;
739 Ustrcat(ptr, "\n");
740 debug_printf("%s", log_buffer);
741 }
742
743/* If no log file is specified, we are in a mess. */
744
745if ((flags & (LOG_MAIN|LOG_PANIC|LOG_REJECT|LOG_PROCESS)) == 0)
746 log_write(0, LOG_MAIN|LOG_PANIC_DIE, "log_write called with no log "
747 "flags set");
748
749/* There are some weird circumstances in which logging is disabled. */
750
751if (disable_logging)
752 {
753 DEBUG(D_any) debug_printf("log writing disabled\n");
754 return;
755 }
756
757/* Handle disabled reject log */
758
759if (!write_rejectlog) flags &= ~LOG_REJECT;
760
761/* Create the main message in the log buffer, including the message
762id except for the process log and when called by a utility. */
763
764ptr = log_buffer;
765sprintf(CS ptr, "%s ", tod_stamp(tod_log));
766while(*ptr) ptr++;
767
768if ((log_extra_selector & LX_pid) != 0)
769 {
770 sprintf(CS ptr, "[%d] ", (int)getpid());
771 while (*ptr) ptr++;
772 }
773
774if (really_exim && (flags & LOG_PROCESS) == 0 && message_id[0] != 0)
775 {
776 sprintf(CS ptr, "%s ", message_id);
777 while(*ptr) ptr++;
778 }
779
780if ((flags & LOG_CONFIG) != 0) ptr = log_config_info(ptr, flags);
781
782va_start(ap, format);
783if (!string_vformat(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer)-1, format, ap))
784 Ustrcpy(ptr, "**** log string overflowed log buffer ****\n");
785while(*ptr) ptr++;
786va_end(ap);
787
788/* Add the raw, unrewritten, sender to the message if required. This is done
789this way because it kind of fits with LOG_RECIPIENTS. */
790
791if ((flags & LOG_SENDER) != 0 &&
792 ptr < log_buffer + LOG_BUFFER_SIZE - 10 - Ustrlen(raw_sender))
793 {
794 sprintf(CS ptr, " from <%s>", raw_sender);
795 while (*ptr) ptr++;
796 }
797
798/* Add list of recipients to the message if required; the raw list,
799before rewriting, was saved in raw_recipients. There may be none, if an ACL
800discarded them all. */
801
802if ((flags & LOG_RECIPIENTS) != 0 && ptr < log_buffer + LOG_BUFFER_SIZE - 6 &&
803 raw_recipients_count > 0)
804 {
805 int i;
806 sprintf(CS ptr, " for");
807 while (*ptr) ptr++;
808 for (i = 0; i < raw_recipients_count; i++)
809 {
810 uschar *s = raw_recipients[i];
811 if (log_buffer + LOG_BUFFER_SIZE - ptr < Ustrlen(s) + 3) break;
812 sprintf(CS ptr, " %s", s);
813 while (*ptr) ptr++;
814 }
815 }
816
817sprintf(CS ptr, "\n");
818while(*ptr) ptr++;
819length = ptr - log_buffer;
820
821/* Handle loggable errors when running a utility, or when address testing.
822Write to log_stderr unless debugging (when it will already have been written),
823or unless there is no log_stderr (expn called from daemon, for example). */
824
825if (!really_exim || log_testing_mode)
826 {
827 if (debug_selector == 0 && log_stderr != NULL &&
828 (selector == 0 || (selector & log_write_selector) != 0))
829 {
830 if (host_checking)
831 fprintf(log_stderr, "LOG: %s", CS(log_buffer + 20)); /* no timestamp */
832 else
833 fprintf(log_stderr, "%s", CS log_buffer);
834 }
835 if ((flags & LOG_PANIC_DIE) == LOG_PANIC_DIE) exim_exit(EXIT_FAILURE);
836 return;
837 }
838
839/* Handle the main log. We know that either syslog or file logging (or both) is
840set up. A real file gets left open during reception or delivery once it has
841been opened, but we don't want to keep on writing to it for too long after it
842has been renamed. Therefore, do a stat() and see if the inode has changed, and
843if so, re-open. */
844
845if ((flags & LOG_MAIN) != 0 &&
846 (selector == 0 || (selector & log_write_selector) != 0))
847 {
848 if ((logging_mode & LOG_MODE_SYSLOG) != 0 &&
849 (syslog_duplication || (flags & (LOG_REJECT|LOG_PANIC)) == 0))
850 write_syslog(LOG_INFO, log_buffer);
851
852 if ((logging_mode & LOG_MODE_FILE) != 0)
853 {
854 struct stat statbuf;
855
856 /* Check for a change to the mainlog file name when datestamping is in
857 operation. This happens at midnight, at which point we want to roll over
858 the file. Closing it has the desired effect. */
859
860 if (mainlog_datestamp != NULL)
861 {
862 uschar *nowstamp = tod_stamp(string_datestamp_type);
863 if (Ustrncmp (mainlog_datestamp, nowstamp, Ustrlen(nowstamp)) != 0)
864 {
865 (void)close(mainlogfd); /* Close the file */
866 mainlogfd = -1; /* Clear the file descriptor */
867 mainlog_inode = 0; /* Unset the inode */
868 mainlog_datestamp = NULL; /* Clear the datestamp */
869 }
870 }
871
872 /* Otherwise, we want to check whether the file has been renamed by a
873 cycling script. This could be "if else", but for safety's sake, leave it as
874 "if" so that renaming the log starts a new file even when datestamping is
875 happening. */
876
877 if (mainlogfd >= 0)
878 {
879 if (Ustat(mainlog_name, &statbuf) < 0 || statbuf.st_ino != mainlog_inode)
880 {
881 (void)close(mainlogfd);
882 mainlogfd = -1;
883 mainlog_inode = 0;
884 }
885 }
886
887 /* If the log is closed, open it. Then write the line. */
888
889 if (mainlogfd < 0)
890 {
891 open_log(&mainlogfd, lt_main, NULL); /* No return on error */
892 if (fstat(mainlogfd, &statbuf) >= 0) mainlog_inode = statbuf.st_ino;
893 }
894
895 /* Failing to write to the log is disastrous */
896
897 if ((rc = write(mainlogfd, log_buffer, length)) != length)
898 {
899 log_write_failed(US"main log", length, rc);
900 /* That function does not return */
901 }
902 }
903 }
904
905/* Handle the log for rejected messages. This can be globally disabled, in
906which case the flags are altered above. If there are any header lines (i.e. if
907the rejection is happening after the DATA phase), log the recipients and the
908headers. */
909
910if ((flags & LOG_REJECT) != 0)
911 {
912 header_line *h;
913
914 if (header_list != NULL && (log_extra_selector & LX_rejected_header) != 0)
915 {
916 if (recipients_count > 0)
917 {
918 int i;
919
920 /* List the sender */
921
922 string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer),
923 "Envelope-from: <%s>\n", sender_address);
924 while (*ptr) ptr++;
925
926 /* List up to 5 recipients */
927
928 string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer),
929 "Envelope-to: <%s>\n", recipients_list[0].address);
930 while (*ptr) ptr++;
931
932 for (i = 1; i < recipients_count && i < 5; i++)
933 {
934 string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer), " <%s>\n",
935 recipients_list[i].address);
936 while (*ptr) ptr++;
937 }
938
939 if (i < recipients_count)
940 {
941 (void)string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer),
942 " ...\n");
943 while (*ptr) ptr++;
944 }
945 }
946
947 /* A header with a NULL text is an unfilled in Received: header */
948
949 for (h = header_list; h != NULL; h = h->next)
950 {
951 BOOL fitted;
952 if (h->text == NULL) continue;
953 fitted = string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer),
954 "%c %s", h->type, h->text);
955 while(*ptr) ptr++;
956 if (!fitted) /* Buffer is full; truncate */
957 {
958 ptr -= 100; /* For message and separator */
959 if (ptr[-1] == '\n') ptr--;
960 Ustrcpy(ptr, "\n*** truncated ***\n");
961 while (*ptr) ptr++;
962 break;
963 }
964 }
965
966 length = ptr - log_buffer;
967 }
968
969 /* Write to syslog or to a log file */
970
971 if ((logging_mode & LOG_MODE_SYSLOG) != 0 &&
972 (syslog_duplication || (flags & LOG_PANIC) == 0))
973 write_syslog(LOG_NOTICE, log_buffer);
974
975 /* Check for a change to the rejectlog file name when datestamping is in
976 operation. This happens at midnight, at which point we want to roll over
977 the file. Closing it has the desired effect. */
978
979 if ((logging_mode & LOG_MODE_FILE) != 0)
980 {
981 struct stat statbuf;
982
983 if (rejectlog_datestamp != NULL)
984 {
985 uschar *nowstamp = tod_stamp(string_datestamp_type);
986 if (Ustrncmp (rejectlog_datestamp, nowstamp, Ustrlen(nowstamp)) != 0)
987 {
988 (void)close(rejectlogfd); /* Close the file */
989 rejectlogfd = -1; /* Clear the file descriptor */
990 rejectlog_inode = 0; /* Unset the inode */
991 rejectlog_datestamp = NULL; /* Clear the datestamp */
992 }
993 }
994
995 /* Otherwise, we want to check whether the file has been renamed by a
996 cycling script. This could be "if else", but for safety's sake, leave it as
997 "if" so that renaming the log starts a new file even when datestamping is
998 happening. */
999
1000 if (rejectlogfd >= 0)
1001 {
1002 if (Ustat(rejectlog_name, &statbuf) < 0 ||
1003 statbuf.st_ino != rejectlog_inode)
1004 {
1005 (void)close(rejectlogfd);
1006 rejectlogfd = -1;
1007 rejectlog_inode = 0;
1008 }
1009 }
1010
1011 /* Open the file if necessary, and write the data */
1012
1013 if (rejectlogfd < 0)
1014 {
1015 open_log(&rejectlogfd, lt_reject, NULL); /* No return on error */
1016 if (fstat(rejectlogfd, &statbuf) >= 0) rejectlog_inode = statbuf.st_ino;
1017 }
1018
1019 if ((rc = write(rejectlogfd, log_buffer, length)) != length)
1020 {
1021 log_write_failed(US"reject log", length, rc);
1022 /* That function does not return */
1023 }
1024 }
1025 }
1026
1027
1028/* Handle the process log file, where exim processes can be made to dump
1029details of what they are doing by sending them a USR1 signal. Note that
1030a message id is not automatically added above. This information is always
1031written to a file - never to syslog. */
1032
1033if ((flags & LOG_PROCESS) != 0)
1034 {
1035 int processlogfd;
1036 open_log(&processlogfd, lt_process, NULL); /* No return on error */
1037 if ((rc = write(processlogfd, log_buffer, length)) != length)
1038 {
1039 log_write_failed(US"process log", length, rc);
1040 /* That function does not return */
1041 }
1042 (void)close(processlogfd);
1043 }
1044
1045
1046/* Handle the panic log, which is not kept open like the others. If it fails to
1047open, there will be a recursive call to log_write(). We detect this above and
1048attempt to write to the system log as a last-ditch try at telling somebody. In
1049all cases except mua_wrapper, try to write to log_stderr. */
1050
1051if ((flags & LOG_PANIC) != 0)
1052 {
1053 if (log_stderr != NULL && log_stderr != debug_file && !mua_wrapper)
1054 fprintf(log_stderr, "%s", CS log_buffer);
1055
1056 if ((logging_mode & LOG_MODE_SYSLOG) != 0)
1057 {
1058 write_syslog(LOG_ALERT, log_buffer);
1059 }
1060
1061 /* If this panic logging was caused by a failure to open the main log,
1062 the original log line is in panic_save_buffer. Make an attempt to write it. */
1063
1064 if ((logging_mode & LOG_MODE_FILE) != 0)
1065 {
1066 panic_recurseflag = TRUE;
1067 open_log(&paniclogfd, lt_panic, NULL); /* Won't return on failure */
1068 panic_recurseflag = FALSE;
1069
1070 if (panic_save_buffer != NULL)
1071 (void) write(paniclogfd, panic_save_buffer, Ustrlen(panic_save_buffer));
1072
1073 if ((rc = write(paniclogfd, log_buffer, length)) != length)
1074 {
1075 int save_errno = errno;
1076 write_syslog(LOG_CRIT, log_buffer);
1077 sprintf(CS log_buffer, "write failed on panic log: length=%d result=%d "
1078 "errno=%d (%s)", length, rc, save_errno, strerror(save_errno));
1079 write_syslog(LOG_CRIT, log_buffer);
1080 flags |= LOG_PANIC_DIE;
1081 }
1082
1083 (void)close(paniclogfd);
1084 }
1085
1086 /* Give up if the DIE flag is set */
1087
1088 if ((flags & LOG_PANIC_DIE) != LOG_PANIC)
1089 die(NULL, US"Unexpected failure, please try later");
1090 }
1091}
1092
1093
1094
1095/*************************************************
1096* Close any open log files *
1097*************************************************/
1098
1099void
1100log_close_all(void)
1101{
1102if (mainlogfd >= 0)
1103 { (void)close(mainlogfd); mainlogfd = -1; }
1104if (rejectlogfd >= 0)
1105 { (void)close(rejectlogfd); rejectlogfd = -1; }
1106closelog();
1107syslog_open = FALSE;
1108}
1109
1110
1111
1112/*************************************************
1113* Decode bit settings for log/debug *
1114*************************************************/
1115
1116/* This function decodes a string containing bit settings in the form of +name
1117and/or -name sequences, and sets/unsets bits in a bit string accordingly. It
1118also recognizes a numeric setting of the form =<number>, but this is not
1119intended for user use. It's an easy way for Exim to pass the debug settings
1120when it is re-exec'ed.
1121
1122The log options are held in two unsigned ints (because there became too many
1123for one). The top bit in the table means "put in 2nd selector". This does not
1124yet apply to debug options, so the "=" facility sets only the first selector.
1125
1126The "all" selector, which must be equal to 0xffffffff, is recognized specially.
1127It sets all the bits in both selectors. However, there is a facility for then
1128unsetting certain bits, because we want to turn off "memory" in the debug case.
1129
1130The action taken for bad values varies depending upon why we're here.
1131For log messages, or if the debugging is triggered from config, then we write
1132to the log on the way out. For debug setting triggered from the command-line,
1133we treat it as an unknown option: error message to stderr and die.
1134
1135Arguments:
1136 selector1 address of the first bit string
1137 selector2 address of the second bit string, or NULL
1138 notall1 bits to exclude from "all" for selector1
1139 notall2 bits to exclude from "all" for selector2
1140 string the configured string
1141 options the table of option names
1142 count size of table
1143 which "log" or "debug"
1144 flags DEBUG_FROM_CONFIG
1145
1146Returns: nothing on success - bomb out on failure
1147*/
1148
1149void
1150decode_bits(unsigned int *selector1, unsigned int *selector2, int notall1,
1151 int notall2, uschar *string, bit_table *options, int count, uschar *which,
1152 int flags)
1153{
1154uschar *errmsg;
1155if (string == NULL) return;
1156
1157if (*string == '=')
1158 {
1159 char *end; /* Not uschar */
1160 *selector1 = strtoul(CS string+1, &end, 0);
1161 if (*end == 0) return;
1162 errmsg = string_sprintf("malformed numeric %s_selector setting: %s", which,
1163 string);
1164 goto ERROR_RETURN;
1165 }
1166
1167/* Handle symbolic setting */
1168
1169else for(;;)
1170 {
1171 BOOL adding;
1172 uschar *s;
1173 int len;
1174 bit_table *start, *end;
1175
1176 while (isspace(*string)) string++;
1177 if (*string == 0) return;
1178
1179 if (*string != '+' && *string != '-')
1180 {
1181 errmsg = string_sprintf("malformed %s_selector setting: "
1182 "+ or - expected but found \"%s\"", which, string);
1183 goto ERROR_RETURN;
1184 }
1185
1186 adding = *string++ == '+';
1187 s = string;
1188 while (isalnum(*string) || *string == '_') string++;
1189 len = string - s;
1190
1191 start = options;
1192 end = options + count;
1193
1194 while (start < end)
1195 {
1196 bit_table *middle = start + (end - start)/2;
1197 int c = Ustrncmp(s, middle->name, len);
1198 if (c == 0)
1199 {
1200 if (middle->name[len] != 0) c = -1; else
1201 {
1202 unsigned int bit = middle->bit;
1203 unsigned int *selector;
1204
1205 /* The value with all bits set means "force all bits in both selectors"
1206 in the case where two are being handled. However, the top bit in the
1207 second selector is never set. When setting, some bits can be excluded.
1208 */
1209
1210 if (bit == 0xffffffff)
1211 {
1212 if (adding)
1213 {
1214 *selector1 = 0xffffffff ^ notall1;
1215 if (selector2 != NULL) *selector2 = 0x7fffffff ^ notall2;
1216 }
1217 else
1218 {
1219 *selector1 = 0;
1220 if (selector2 != NULL) *selector2 = 0;
1221 }
1222 }
1223
1224 /* Otherwise, the 0x80000000 bit means "this value, without the top
1225 bit, belongs in the second selector". */
1226
1227 else
1228 {
1229 if ((bit & 0x80000000) != 0)
1230 {
1231 selector = selector2;
1232 bit &= 0x7fffffff;
1233 }
1234 else selector = selector1;
1235 if (adding) *selector |= bit; else *selector &= ~bit;
1236 }
1237 break; /* Out of loop to match selector name */
1238 }
1239 }
1240 if (c < 0) end = middle; else start = middle + 1;
1241 } /* Loop to match selector name */
1242
1243 if (start >= end)
1244 {
1245 errmsg = string_sprintf("unknown %s_selector setting: %c%.*s", which,
1246 adding? '+' : '-', len, s);
1247 goto ERROR_RETURN;
1248 }
1249 } /* Loop for selector names */
1250
1251/* Handle disasters */
1252
1253ERROR_RETURN:
1254if (Ustrcmp(which, "debug") == 0)
1255 {
1256 if (flags & DEBUG_FROM_CONFIG)
1257 {
1258 log_write(0, LOG_CONFIG|LOG_PANIC, "%s", errmsg);
1259 return;
1260 }
1261 fprintf(stderr, "exim: %s\n", errmsg);
1262 exit(EXIT_FAILURE);
1263 }
1264else log_write(0, LOG_CONFIG|LOG_PANIC_DIE, "%s", errmsg);
1265}
1266
1267
1268
1269/*************************************************
1270* Activate a debug logfile (late) *
1271*************************************************/
1272
1273/* Normally, debugging is activated from the command-line; it may be useful
1274within the configuration to activate debugging later, based on certain
1275conditions. If debugging is already in progress, we return early, no action
1276taken (besides debug-logging that we wanted debug-logging).
1277
1278Failures in options are not fatal but will result in paniclog entries for the
1279misconfiguration.
1280
1281The first use of this is in ACL logic, "control = debug/tag=foo/opts=+expand"
1282which can be combined with conditions, etc, to activate extra logging only
1283for certain sources. */
1284
1285void
1286debug_logging_activate(uschar *tag_name, uschar *opts)
1287{
1288int fd = -1;
1289
1290if (debug_file)
1291 {
1292 debug_printf("DEBUGGING ACTIVATED FROM WITHIN CONFIG.\n"
1293 "DEBUG: Tag=\"%s\" Opts=\"%s\"\n", tag_name, opts);
1294 return;
1295 }
1296
1297if (tag_name != NULL && (Ustrchr(tag_name, '/') != NULL))
1298 {
1299 log_write(0, LOG_MAIN|LOG_PANIC, "debug tag may not contain a '/' in: %s",
1300 tag_name);
1301 return;
1302 }
1303
1304debug_selector = D_default;
1305if (opts)
1306 {
1307 decode_bits(&debug_selector, NULL, D_memory, 0, opts,
1308 debug_options, debug_options_count, US"debug", DEBUG_FROM_CONFIG);
1309 }
1310
1311open_log(&fd, lt_debug, tag_name);
1312
1313if (fd != -1)
1314 debug_file = fdopen(fd, "w");
1315else
1316 log_write(0, LOG_MAIN|LOG_PANIC, "unable to open debug log");
1317}
1318
1319
1320/* End of log.c */