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