Compiler masochism compliance.
[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/%M in file_path.
259 When opening the panic log, if %D or %M is present, we remove the datestamp
260 from the generated name; if it is at the start, remove a following
261 non-alphanumeric character as well; otherwise, remove a preceding
262 non-alphanumeric character. This is definitely kludgy, but it sort of does what
263 people want, I hope. */
264
265 else
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
329 if (!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
336 open, arrange for automatic closure on exec(), and then return. */
337
338 *fd = Uopen(buffer, O_APPEND|O_WRONLY, LOG_MODE);
339
340 if (*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,
347 we must do the creating in a subprocess set to exim:exim in order to ensure
348 that the file is created with the right ownership. Otherwise, there can be a
349 race if another Exim process is trying to write to the log at the same time.
350 The use of SIGUSR1 by the exiwhat utility can provoke a lot of simultaneous
351 writing. */
352
353 euid = geteuid();
354
355 /* If we are already running as the Exim user (even if that user is root),
356 we can go ahead and create in the current process. */
357
358 if (euid == exim_uid) *fd = create_log(buffer);
359
360 /* Otherwise, if we are root, do the creation in an exim:exim subprocess. If we
361 are neither exim nor root, creation is not attempted. */
362
363 else 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
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 one exception to this is messages containing LOG_PROCESS. These are always
527 written to exim-process.info in the spool directory. They aren't really log
528 messages in the same sense as the others.
529
530 The message always gets '\n' added on the end of it, since more than one
531 process may be writing to the log at once and we don't want intermingling to
532 happen in the middle of lines. To be absolutely sure of this we write the data
533 into a private buffer and then put it out in a single write() call.
534
535 The flags determine which log(s) the message is written to, or for syslogging,
536 which priority to use, and in the case of the panic log, whether the process
537 should die afterwards.
538
539 The 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).
541 If it is not, don't try to write to the log because permission will probably be
542 denied.
543
544 Avoid actually writing to the logs when exim is called with -bv or -bt to
545 test an address, but take other actions, such as panicing.
546
547 In Exim proper, the buffer for building the message is got at start-up, so that
548 nothing gets done if it can't be got. However, some functions that are also
549 used in utilities occasionally obey log_write calls in error situations, and it
550 is simplest to put a single malloc() here rather than put one in each utility.
551 Malloc is used directly because the store functions may call log_write().
552
553 If a message_id exists, we include it after the timestamp.
554
555 Arguments:
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
572 Returns:    nothing
573 */
574
575 void
576 log_write(unsigned int selector, int flags, const char *format, ...)
577 {
578 uschar *ptr;
579 int length, rc;
580 int paniclogfd;
581 va_list ap;
582
583 /* If panic_recurseflag is set, we have failed to open the panic log. This is
584 the ultimate disaster. First try to write the message to a debug file and/or
585 stderr and also to syslog. If panic_save_buffer is not NULL, it contains the
586 original log line that caused the problem. Afterwards, expire. */
587
588 if (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
601 when running Exim proper, only when running utilities. */
602
603 if (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
614 determine whether to log to files and/or to syslog. Bits in logging_mode
615 control this, and for file logging, the path must end up in file_path. This
616 variable must be in permanent store because it may be required again later in
617 the process. */
618
619 if (!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
697 in one go so that it doesn't get split when multi-processing. */
698
699 DEBUG(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
745 if ((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
751 if (disable_logging)
752   {
753   DEBUG(D_any) debug_printf("log writing disabled\n");
754   return;
755   }
756
757 /* Handle disabled reject log */
758
759 if (!write_rejectlog) flags &= ~LOG_REJECT;
760
761 /* Create the main message in the log buffer, including the message
762 id except for the process log and when called by a utility. */
763
764 ptr = log_buffer;
765 sprintf(CS ptr, "%s ", tod_stamp(tod_log));
766 while(*ptr) ptr++;
767
768 if ((log_extra_selector & LX_pid) != 0)
769   {
770   sprintf(CS ptr, "[%d] ", (int)getpid());
771   while (*ptr) ptr++;
772   }
773
774 if (really_exim && (flags & LOG_PROCESS) == 0 && message_id[0] != 0)
775   {
776   sprintf(CS ptr, "%s ", message_id);
777   while(*ptr) ptr++;
778   }
779
780 if ((flags & LOG_CONFIG) != 0) ptr = log_config_info(ptr, flags);
781
782 va_start(ap, format);
783 if (!string_vformat(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer)-1, format, ap))
784   Ustrcpy(ptr, "**** log string overflowed log buffer ****\n");
785 while(*ptr) ptr++;
786 va_end(ap);
787
788 /* Add the raw, unrewritten, sender to the message if required. This is done
789 this way because it kind of fits with LOG_RECIPIENTS. */
790
791 if ((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,
799 before rewriting, was saved in raw_recipients. There may be none, if an ACL
800 discarded them all. */
801
802 if ((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
817 sprintf(CS  ptr, "\n");
818 while(*ptr) ptr++;
819 length = ptr - log_buffer;
820
821 /* Handle loggable errors when running a utility, or when address testing.
822 Write to log_stderr unless debugging (when it will already have been written),
823 or unless there is no log_stderr (expn called from daemon, for example). */
824
825 if (!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
840 set up. A real file gets left open during reception or delivery once it has
841 been opened, but we don't want to keep on writing to it for too long after it
842 has been renamed. Therefore, do a stat() and see if the inode has changed, and
843 if so, re-open. */
844
845 if ((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
906 which case the flags are altered above. If there are any header lines (i.e. if
907 the rejection is happening after the DATA phase), log the recipients and the
908 headers. */
909
910 if ((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
1029 details of what they are doing by sending them a USR1 signal. Note that
1030 a message id is not automatically added above. This information is always
1031 written to a file - never to syslog. */
1032
1033 if ((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
1047 open, there will be a recursive call to log_write(). We detect this above and
1048 attempt to write to the system log as a last-ditch try at telling somebody. In
1049 all cases except mua_wrapper, try to write to log_stderr. */
1050
1051 if ((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
1099 void
1100 log_close_all(void)
1101 {
1102 if (mainlogfd >= 0)
1103   { (void)close(mainlogfd); mainlogfd = -1; }
1104 if (rejectlogfd >= 0)
1105   { (void)close(rejectlogfd); rejectlogfd = -1; }
1106 closelog();
1107 syslog_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
1117 and/or -name sequences, and sets/unsets bits in a bit string accordingly. It
1118 also recognizes a numeric setting of the form =<number>, but this is not
1119 intended for user use. It's an easy way for Exim to pass the debug settings
1120 when it is re-exec'ed.
1121
1122 The log options are held in two unsigned ints (because there became too many
1123 for one). The top bit in the table means "put in 2nd selector". This does not
1124 yet apply to debug options, so the "=" facility sets only the first selector.
1125
1126 The "all" selector, which must be equal to 0xffffffff, is recognized specially.
1127 It sets all the bits in both selectors. However, there is a facility for then
1128 unsetting certain bits, because we want to turn off "memory" in the debug case.
1129
1130 The action taken for bad values varies depending upon why we're here.
1131 For log messages, or if the debugging is triggered from config, then we write
1132 to the log on the way out.  For debug setting triggered from the command-line,
1133 we treat it as an unknown option: error message to stderr and die.
1134
1135 Arguments:
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
1146 Returns:         nothing on success - bomb out on failure
1147 */
1148
1149 void
1150 decode_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 {
1154 uschar *errmsg;
1155 if (string == NULL) return;
1156
1157 if (*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
1169 else 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
1253 ERROR_RETURN:
1254 if (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   }
1264 else 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
1274 within the configuration to activate debugging later, based on certain
1275 conditions.  If debugging is already in progress, we return early, no action
1276 taken (besides debug-logging that we wanted debug-logging).
1277
1278 Failures in options are not fatal but will result in paniclog entries for the
1279 misconfiguration.
1280
1281 The first use of this is in ACL logic, "control = debug/tag=foo/opts=+expand"
1282 which can be combined with conditions, etc, to activate extra logging only
1283 for certain sources. */
1284
1285 void
1286 debug_logging_activate(uschar *tag_name, uschar *opts)
1287 {
1288 int fd = -1;
1289
1290 if (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
1297 if (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
1304 debug_selector = D_default;
1305 if (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
1311 open_log(&fd, lt_debug, tag_name);
1312
1313 if (fd != -1)
1314   debug_file = fdopen(fd, "w");
1315 else
1316   log_write(0, LOG_MAIN|LOG_PANIC, "unable to open debug log");
1317 }
1318
1319
1320 /* End of log.c */