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