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