Commit | Line | Data |
---|---|---|
8f128379 | 1 | /* $Cambridge: exim/src/src/log.c,v 1.13 2007/08/22 10:10:23 ph10 Exp $ */ |
059ec3d9 PH |
2 | |
3 | /************************************************* | |
4 | * Exim - an Internet mail transport agent * | |
5 | *************************************************/ | |
6 | ||
184e8823 | 7 | /* Copyright (c) University of Cambridge 1995 - 2007 */ |
059ec3d9 PH |
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_process }; | |
23 | ||
24 | static uschar *log_names[] = { US"main", US"reject", US"panic", 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 | ||
35 | static uschar *mainlog_datestamp = NULL; | |
36 | static uschar *rejectlog_datestamp = NULL; | |
37 | ||
38 | static int mainlogfd = -1; | |
39 | static int rejectlogfd = -1; | |
40 | static ino_t mainlog_inode = 0; | |
41 | static ino_t rejectlog_inode = 0; | |
42 | ||
43 | static uschar *panic_save_buffer = NULL; | |
44 | static BOOL panic_recurseflag = FALSE; | |
45 | ||
46 | static BOOL syslog_open = FALSE; | |
47 | static BOOL path_inspected = FALSE; | |
48 | static int logging_mode = LOG_MODE_FILE; | |
49 | static uschar *file_path = US""; | |
50 | ||
51 | ||
52 | ||
53 | ||
54 | /************************************************* | |
55 | * Write to syslog * | |
56 | *************************************************/ | |
57 | ||
58 | /* The given string is split into sections according to length, or at embedded | |
59 | newlines, and syslogged as a numbered sequence if it is overlong or if there is | |
9675b384 PH |
60 | more than one line. However, if we are running in the test harness, do not do |
61 | anything. (The test harness doesn't use syslog - for obvious reasons - but we | |
62 | can get here if there is a failure to open the panic log.) | |
059ec3d9 PH |
63 | |
64 | Arguments: | |
65 | priority syslog priority | |
66 | s the string to be written | |
67 | ||
68 | Returns: nothing | |
69 | */ | |
70 | ||
71 | static void | |
72 | write_syslog(int priority, uschar *s) | |
73 | { | |
74 | int len, pass; | |
75 | int linecount = 0; | |
76 | ||
9675b384 PH |
77 | if (running_in_test_harness) return; |
78 | ||
059ec3d9 PH |
79 | if (!syslog_timestamp) s += log_timezone? 26 : 20; |
80 | ||
81 | len = Ustrlen(s); | |
82 | ||
83 | #ifndef NO_OPENLOG | |
84 | if (!syslog_open) | |
85 | { | |
86 | #ifdef SYSLOG_LOG_PID | |
87 | openlog(CS syslog_processname, LOG_PID|LOG_CONS, syslog_facility); | |
88 | #else | |
89 | openlog(CS syslog_processname, LOG_CONS, syslog_facility); | |
90 | #endif | |
91 | syslog_open = TRUE; | |
92 | } | |
93 | #endif | |
94 | ||
95 | /* First do a scan through the message in order to determine how many lines | |
96 | it is going to end up as. Then rescan to output it. */ | |
97 | ||
98 | for (pass = 0; pass < 2; pass++) | |
99 | { | |
100 | int i; | |
101 | int tlen; | |
102 | uschar *ss = s; | |
103 | for (i = 1, tlen = len; tlen > 0; i++) | |
104 | { | |
105 | int plen = tlen; | |
106 | uschar *nlptr = Ustrchr(ss, '\n'); | |
107 | if (nlptr != NULL) plen = nlptr - ss; | |
108 | #ifndef SYSLOG_LONG_LINES | |
109 | if (plen > MAX_SYSLOG_LEN) plen = MAX_SYSLOG_LEN; | |
110 | #endif | |
111 | tlen -= plen; | |
112 | if (ss[plen] == '\n') tlen--; /* chars left */ | |
113 | ||
114 | if (pass == 0) linecount++; else | |
115 | { | |
116 | if (linecount == 1) | |
117 | syslog(priority, "%.*s", plen, ss); | |
118 | else | |
119 | syslog(priority, "[%d%c%d] %.*s", i, | |
120 | (ss[plen] == '\n' && tlen != 0)? '\\' : '/', | |
121 | linecount, plen, ss); | |
122 | } | |
123 | ss += plen; | |
124 | if (*ss == '\n') ss++; | |
125 | } | |
126 | } | |
127 | } | |
128 | ||
129 | ||
130 | ||
131 | /************************************************* | |
132 | * Die tidily * | |
133 | *************************************************/ | |
134 | ||
135 | /* This is called when Exim is dying as a result of something going wrong in | |
136 | the logging, or after a log call with LOG_PANIC_DIE set. Optionally write a | |
137 | message to debug_file or a stderr file, if they exist. Then, if in the middle | |
8f128379 PH |
138 | of accepting a message, throw it away tidily by calling receive_bomb_out(); |
139 | this will attempt to send an SMTP response if appropriate. Passing NULL as the | |
140 | first argument stops it trying to run the NOTQUIT ACL (which might try further | |
141 | logging and thus cause problems). Otherwise, try to close down an outstanding | |
142 | SMTP call tidily. | |
059ec3d9 PH |
143 | |
144 | Arguments: | |
145 | s1 Error message to write to debug_file and/or stderr and syslog | |
146 | s2 Error message for any SMTP call that is in progress | |
147 | Returns: The function does not return | |
148 | */ | |
149 | ||
150 | static void | |
151 | die(uschar *s1, uschar *s2) | |
152 | { | |
153 | if (s1 != NULL) | |
154 | { | |
155 | write_syslog(LOG_CRIT, s1); | |
156 | if (debug_file != NULL) debug_printf("%s\n", s1); | |
157 | if (log_stderr != NULL && log_stderr != debug_file) | |
158 | fprintf(log_stderr, "%s\n", s1); | |
159 | } | |
8f128379 | 160 | if (receive_call_bombout) receive_bomb_out(NULL, s2); /* does not return */ |
059ec3d9 PH |
161 | if (smtp_input) smtp_closedown(s2); |
162 | exim_exit(EXIT_FAILURE); | |
163 | } | |
164 | ||
165 | ||
166 | ||
167 | /************************************************* | |
168 | * Create a log file * | |
169 | *************************************************/ | |
170 | ||
171 | /* This function is called to create and open a log file. It may be called in a | |
172 | subprocess when the original process is root. | |
173 | ||
174 | Arguments: | |
175 | name the file name | |
176 | ||
177 | The file name has been build in a working buffer, so it is permissible to | |
178 | overwrite it temporarily if it is necessary to create the directory. | |
179 | ||
180 | Returns: a file descriptor, or < 0 on failure (errno set) | |
181 | */ | |
182 | ||
183 | static int | |
184 | create_log(uschar *name) | |
185 | { | |
186 | int fd = Uopen(name, O_CREAT|O_APPEND|O_WRONLY, LOG_MODE); | |
187 | ||
188 | /* If creation failed, attempt to build a log directory in case that is the | |
189 | problem. */ | |
190 | ||
191 | if (fd < 0 && errno == ENOENT) | |
192 | { | |
193 | BOOL created; | |
194 | uschar *lastslash = Ustrrchr(name, '/'); | |
195 | *lastslash = 0; | |
196 | created = directory_make(NULL, name, LOG_DIRECTORY_MODE, FALSE); | |
197 | DEBUG(D_any) debug_printf("%s log directory %s\n", | |
198 | created? "created" : "failed to create", name); | |
199 | *lastslash = '/'; | |
200 | if (created) fd = Uopen(name, O_CREAT|O_APPEND|O_WRONLY, LOG_MODE); | |
201 | } | |
202 | ||
203 | return fd; | |
204 | } | |
205 | ||
206 | ||
207 | ||
208 | ||
209 | /************************************************* | |
210 | * Open a log file * | |
211 | *************************************************/ | |
212 | ||
213 | /* This function opens one of a number of logs, which all (except for the | |
214 | "process log") reside in the same directory, creating the directory if it does | |
215 | not exist. This may be called recursively on failure, in order to open the | |
216 | panic log. | |
217 | ||
218 | The directory is in the static variable file_path. This is static so that it | |
219 | the work of sorting out the path is done just once per Exim process. | |
220 | ||
221 | Exim is normally configured to avoid running as root wherever possible, the log | |
222 | files must be owned by the non-privileged exim user. To ensure this, first try | |
223 | an open without O_CREAT - most of the time this will succeed. If it fails, try | |
224 | to create the file; if running as root, this must be done in a subprocess to | |
225 | avoid races. | |
226 | ||
227 | Arguments: | |
228 | fd where to return the resulting file descriptor | |
229 | type lt_main, lt_reject, lt_panic, or lt_process | |
230 | ||
231 | Returns: nothing | |
232 | */ | |
233 | ||
234 | static void | |
235 | open_log(int *fd, int type) | |
236 | { | |
237 | uid_t euid; | |
238 | BOOL ok; | |
239 | uschar buffer[LOG_NAME_SIZE]; | |
240 | ||
241 | /* Sort out the file name. This depends on the type of log we are opening. The | |
242 | process "log" is written in the spool directory by default, but a path name can | |
243 | be specified in the configuration. */ | |
244 | ||
245 | if (type == lt_process) | |
246 | { | |
247 | if (process_log_path == NULL) | |
248 | ok = string_format(buffer, sizeof(buffer), "%s/exim-process.info", | |
249 | spool_directory); | |
250 | else | |
251 | ok = string_format(buffer, sizeof(buffer), "%s", process_log_path); | |
252 | } | |
253 | ||
254 | /* The names of the other three logs are controlled by file_path. The panic log | |
255 | is written to the same directory as the main and reject logs, but its name does | |
256 | not have a datestamp. The use of datestamps is indicated by %D in file_path. | |
257 | When opening the panic log, if %D is present, we remove the datestamp from the | |
258 | generated name; if it is at the start, remove a following non-alphameric | |
259 | character as well; otherwise, remove a preceding non-alphameric character. This | |
260 | is definitely kludgy, but it sort of does what people want, I hope. */ | |
261 | ||
262 | else | |
263 | { | |
264 | ok = string_format(buffer, sizeof(buffer), CS file_path, log_names[type]); | |
265 | ||
266 | /* Save the name of the mainlog for rollover processing. Without a datestamp, | |
267 | it gets statted to see if it has been cycled. With a datestamp, the datestamp | |
268 | will be compared. The static slot for saving it is the same size as buffer, | |
269 | and the text has been checked above to fit, so this use of strcpy() is OK. */ | |
270 | ||
271 | if (type == lt_main) | |
272 | { | |
273 | Ustrcpy(mainlog_name, buffer); | |
274 | mainlog_datestamp = mainlog_name + string_datestamp_offset; | |
275 | } | |
276 | ||
277 | /* Ditto for the reject log */ | |
278 | ||
279 | else if (type == lt_reject) | |
280 | { | |
281 | Ustrcpy(rejectlog_name, buffer); | |
282 | rejectlog_datestamp = rejectlog_name + string_datestamp_offset; | |
283 | } | |
284 | ||
285 | /* Remove any datestamp if this is the panic log. This is rare, so there's no | |
286 | need to optimize getting the datestamp length. We remove one non-alphanumeric | |
287 | char afterwards if at the start, otherwise one before. */ | |
288 | ||
289 | else if (string_datestamp_offset >= 0) | |
290 | { | |
291 | uschar *from = buffer + string_datestamp_offset; | |
292 | uschar *to = from + Ustrlen(tod_stamp(tod_log_datestamp)); | |
293 | if (from == buffer || from[-1] == '/') | |
294 | { | |
295 | if (!isalnum(*to)) to++; | |
296 | } | |
297 | else | |
298 | { | |
299 | if (!isalnum(from[-1])) from--; | |
300 | } | |
301 | ||
302 | /* This strcpy is ok, because we know that to is a substring of from. */ | |
303 | ||
304 | Ustrcpy(from, to); | |
305 | } | |
306 | } | |
307 | ||
308 | /* If the file name is too long, it is an unrecoverable disaster */ | |
309 | ||
310 | if (!ok) | |
311 | { | |
312 | die(US"exim: log file path too long: aborting", | |
313 | US"Logging failure; please try later"); | |
314 | } | |
315 | ||
316 | /* We now have the file name. Try to open an existing file. After a successful | |
317 | open, arrange for automatic closure on exec(), and then return. */ | |
318 | ||
319 | *fd = Uopen(buffer, O_APPEND|O_WRONLY, LOG_MODE); | |
320 | ||
321 | if (*fd >= 0) | |
322 | { | |
ff790e47 | 323 | (void)fcntl(*fd, F_SETFD, fcntl(*fd, F_GETFD) | FD_CLOEXEC); |
059ec3d9 PH |
324 | return; |
325 | } | |
326 | ||
327 | /* Open was not successful: try creating the file. If this is a root process, | |
328 | we must do the creating in a subprocess set to exim:exim in order to ensure | |
329 | that the file is created with the right ownership. Otherwise, there can be a | |
901f42cb PH |
330 | race if another Exim process is trying to write to the log at the same time. |
331 | The use of SIGUSR1 by the exiwhat utility can provoke a lot of simultaneous | |
332 | writing. */ | |
059ec3d9 PH |
333 | |
334 | euid = geteuid(); | |
335 | ||
336 | /* If we are already running as the Exim user (even if that user is root), | |
337 | we can go ahead and create in the current process. */ | |
338 | ||
339 | if (euid == exim_uid) *fd = create_log(buffer); | |
340 | ||
341 | /* Otherwise, if we are root, do the creation in an exim:exim subprocess. If we | |
342 | are neither exim nor root, creation is not attempted. */ | |
343 | ||
344 | else if (euid == root_uid) | |
345 | { | |
346 | int status; | |
347 | pid_t pid = fork(); | |
348 | ||
349 | /* In the subprocess, change uid/gid and do the creation. Return 0 from the | |
350 | subprocess on success. There doesn't seem much point in testing for setgid | |
351 | and setuid errors. */ | |
352 | ||
353 | if (pid == 0) | |
354 | { | |
355 | (void)setgid(exim_gid); | |
356 | (void)setuid(exim_uid); | |
357 | _exit((create_log(buffer) < 0)? 1 : 0); | |
358 | } | |
359 | ||
901f42cb | 360 | /* If we created a subprocess, wait for it. If it succeeded retry the open. */ |
059ec3d9 | 361 | |
901f42cb PH |
362 | if (pid > 0) |
363 | { | |
364 | while (waitpid(pid, &status, 0) != pid); | |
365 | if (status == 0) *fd = Uopen(buffer, O_APPEND|O_WRONLY, LOG_MODE); | |
366 | } | |
367 | ||
368 | /* If we failed to create a subprocess, we are in a bad way. We fall through | |
369 | with *fd still < 0, and errno set, letting the code below handle the error. */ | |
059ec3d9 PH |
370 | } |
371 | ||
372 | /* If we now have an open file, set the close-on-exec flag and return. */ | |
373 | ||
374 | if (*fd >= 0) | |
375 | { | |
ff790e47 | 376 | (void)fcntl(*fd, F_SETFD, fcntl(*fd, F_GETFD) | FD_CLOEXEC); |
059ec3d9 PH |
377 | return; |
378 | } | |
379 | ||
380 | /* Creation failed. There are some circumstances in which we get here when | |
381 | the effective uid is not root or exim, which is the problem. (For example, a | |
382 | non-setuid binary with log_arguments set, called in certain ways.) Rather than | |
383 | just bombing out, force the log to stderr and carry on if stderr is available. | |
384 | */ | |
385 | ||
386 | if (euid != root_uid && euid != exim_uid && log_stderr != NULL) | |
387 | { | |
388 | *fd = fileno(log_stderr); | |
389 | return; | |
390 | } | |
391 | ||
392 | /* Otherwise this is a disaster. This call is deliberately ONLY to the panic | |
393 | log. If possible, save a copy of the original line that was being logged. If we | |
394 | are recursing (can't open the panic log either), the pointer will already be | |
395 | set. */ | |
396 | ||
397 | if (panic_save_buffer == NULL) | |
398 | { | |
399 | panic_save_buffer = (uschar *)malloc(LOG_BUFFER_SIZE); | |
400 | if (panic_save_buffer != NULL) | |
401 | memcpy(panic_save_buffer, log_buffer, LOG_BUFFER_SIZE); | |
402 | } | |
403 | ||
404 | log_write(0, LOG_PANIC_DIE, "Cannot open %s log file \"%s\": %s: " | |
405 | "euid=%d egid=%d", log_names[type], buffer, strerror(errno), euid, getegid()); | |
406 | /* Never returns */ | |
407 | } | |
408 | ||
409 | ||
410 | ||
411 | /************************************************* | |
412 | * Add configuration file info to log line * | |
413 | *************************************************/ | |
414 | ||
415 | /* This is put in a function because it's needed twice (once for debugging, | |
416 | once for real). | |
417 | ||
418 | Arguments: | |
419 | ptr pointer to the end of the line we are building | |
420 | flags log flags | |
421 | ||
422 | Returns: updated pointer | |
423 | */ | |
424 | ||
425 | static uschar * | |
426 | log_config_info(uschar *ptr, int flags) | |
427 | { | |
428 | Ustrcpy(ptr, "Exim configuration error"); | |
429 | ptr += 24; | |
430 | ||
431 | if ((flags & (LOG_CONFIG_FOR & ~LOG_CONFIG)) != 0) | |
432 | { | |
433 | Ustrcpy(ptr, " for "); | |
434 | return ptr + 5; | |
435 | } | |
436 | ||
437 | if ((flags & (LOG_CONFIG_IN & ~LOG_CONFIG)) != 0) | |
438 | { | |
439 | sprintf(CS ptr, " in line %d of %s", config_lineno, config_filename); | |
440 | while (*ptr) ptr++; | |
441 | } | |
442 | ||
443 | Ustrcpy(ptr, ":\n "); | |
444 | return ptr + 4; | |
445 | } | |
446 | ||
447 | ||
448 | /************************************************* | |
449 | * A write() operation failed * | |
450 | *************************************************/ | |
451 | ||
452 | /* This function is called when write() fails on anything other than the panic | |
453 | log, which can happen if a disk gets full or a file gets too large or whatever. | |
454 | We try to save the relevant message in the panic_save buffer before crashing | |
455 | out. | |
456 | ||
457 | Arguments: | |
458 | name the name of the log being written | |
459 | length the string length being written | |
460 | rc the return value from write() | |
461 | ||
462 | Returns: does not return | |
463 | */ | |
464 | ||
465 | static void | |
466 | log_write_failed(uschar *name, int length, int rc) | |
467 | { | |
468 | int save_errno = errno; | |
469 | ||
470 | if (panic_save_buffer == NULL) | |
471 | { | |
472 | panic_save_buffer = (uschar *)malloc(LOG_BUFFER_SIZE); | |
473 | if (panic_save_buffer != NULL) | |
474 | memcpy(panic_save_buffer, log_buffer, LOG_BUFFER_SIZE); | |
475 | } | |
476 | ||
477 | log_write(0, LOG_PANIC_DIE, "failed to write to %s: length=%d result=%d " | |
478 | "errno=%d (%s)", name, length, rc, save_errno, | |
479 | (save_errno == 0)? "write incomplete" : strerror(save_errno)); | |
480 | /* Never returns */ | |
481 | } | |
482 | ||
483 | ||
484 | ||
485 | /************************************************* | |
486 | * Write message to log file * | |
487 | *************************************************/ | |
488 | ||
489 | /* Exim can be configured to log to local files, or use syslog, or both. This | |
490 | is controlled by the setting of log_file_path. The following cases are | |
491 | recognized: | |
492 | ||
493 | log_file_path = "" write files in the spool/log directory | |
494 | log_file_path = "xxx" write files in the xxx directory | |
495 | log_file_path = "syslog" write to syslog | |
496 | log_file_path = "syslog : xxx" write to syslog and to files (any order) | |
497 | ||
498 | The one exception to this is messages containing LOG_PROCESS. These are always | |
499 | written to exim-process.info in the spool directory. They aren't really log | |
500 | messages in the same sense as the others. | |
501 | ||
502 | The message always gets '\n' added on the end of it, since more than one | |
503 | process may be writing to the log at once and we don't want intermingling to | |
504 | happen in the middle of lines. To be absolutely sure of this we write the data | |
505 | into a private buffer and then put it out in a single write() call. | |
506 | ||
507 | The flags determine which log(s) the message is written to, or for syslogging, | |
508 | which priority to use, and in the case of the panic log, whether the process | |
509 | should die afterwards. | |
510 | ||
511 | The variable really_exim is TRUE only when exim is running in privileged state | |
512 | (i.e. not with a changed configuration or with testing options such as -brw). | |
513 | If it is not, don't try to write to the log because permission will probably be | |
514 | denied. | |
515 | ||
516 | Avoid actually writing to the logs when exim is called with -bv or -bt to | |
517 | test an address, but take other actions, such as panicing. | |
518 | ||
519 | In Exim proper, the buffer for building the message is got at start-up, so that | |
520 | nothing gets done if it can't be got. However, some functions that are also | |
521 | used in utilities occasionally obey log_write calls in error situations, and it | |
522 | is simplest to put a single malloc() here rather than put one in each utility. | |
523 | Malloc is used directly because the store functions may call log_write(). | |
524 | ||
525 | If a message_id exists, we include it after the timestamp. | |
526 | ||
527 | Arguments: | |
528 | selector write to main log or LOG_INFO only if this value is zero, or if | |
529 | its bit is set in log_write_selector | |
530 | flags each bit indicates some independent action: | |
531 | LOG_SENDER add raw sender to the message | |
532 | LOG_RECIPIENTS add raw recipients list to message | |
533 | LOG_CONFIG add "Exim configuration error" | |
534 | LOG_CONFIG_FOR add " for " instead of ":\n " | |
535 | LOG_CONFIG_IN add " in line x[ of file y]" | |
536 | LOG_MAIN write to main log or syslog LOG_INFO | |
537 | LOG_REJECT write to reject log or syslog LOG_NOTICE | |
538 | LOG_PANIC write to panic log or syslog LOG_ALERT | |
539 | LOG_PANIC_DIE write to panic log or LOG_ALERT and then crash | |
540 | LOG_PROCESS write to process log (always a file) | |
541 | format a printf() format | |
542 | ... arguments for format | |
543 | ||
544 | Returns: nothing | |
545 | */ | |
546 | ||
547 | void | |
548 | log_write(unsigned int selector, int flags, char *format, ...) | |
549 | { | |
550 | uschar *ptr; | |
551 | int length, rc; | |
552 | int paniclogfd; | |
553 | va_list ap; | |
554 | ||
555 | /* If panic_recurseflag is set, we have failed to open the panic log. This is | |
556 | the ultimate disaster. First try to write the message to a debug file and/or | |
557 | stderr and also to syslog. If panic_save_buffer is not NULL, it contains the | |
558 | original log line that caused the problem. Afterwards, expire. */ | |
559 | ||
560 | if (panic_recurseflag) | |
561 | { | |
562 | uschar *extra = (panic_save_buffer == NULL)? US"" : panic_save_buffer; | |
563 | if (debug_file != NULL) debug_printf("%s%s", extra, log_buffer); | |
564 | if (log_stderr != NULL && log_stderr != debug_file) | |
565 | fprintf(log_stderr, "%s%s", extra, log_buffer); | |
566 | if (*extra != 0) write_syslog(LOG_CRIT, extra); | |
567 | write_syslog(LOG_CRIT, log_buffer); | |
568 | die(US"exim: could not open panic log - aborting: see message(s) above", | |
569 | US"Unexpected log failure, please try later"); | |
570 | } | |
571 | ||
572 | /* Ensure we have a buffer (see comment above); this should never be obeyed | |
573 | when running Exim proper, only when running utilities. */ | |
574 | ||
575 | if (log_buffer == NULL) | |
576 | { | |
577 | log_buffer = (uschar *)malloc(LOG_BUFFER_SIZE); | |
578 | if (log_buffer == NULL) | |
579 | { | |
580 | fprintf(stderr, "exim: failed to get store for log buffer\n"); | |
581 | exim_exit(EXIT_FAILURE); | |
582 | } | |
583 | } | |
584 | ||
585 | /* If we haven't already done so, inspect the setting of log_file_path to | |
586 | determine whether to log to files and/or to syslog. Bits in logging_mode | |
587 | control this, and for file logging, the path must end up in file_path. This | |
588 | variable must be in permanent store because it may be required again later in | |
589 | the process. */ | |
590 | ||
591 | if (!path_inspected) | |
592 | { | |
593 | BOOL multiple = FALSE; | |
594 | int old_pool = store_pool; | |
595 | ||
596 | store_pool = POOL_PERM; | |
597 | ||
598 | /* If nothing has been set, don't waste effort... the default values for the | |
599 | statics are file_path="" and logging_mode = LOG_MODE_FILE. */ | |
600 | ||
601 | if (log_file_path[0] != 0) | |
602 | { | |
603 | int sep = ':'; /* Fixed separator - outside use */ | |
604 | uschar *s; | |
605 | uschar *ss = log_file_path; | |
606 | logging_mode = 0; | |
607 | while ((s = string_nextinlist(&ss,&sep,log_buffer,LOG_BUFFER_SIZE)) != NULL) | |
608 | { | |
609 | if (Ustrcmp(s, "syslog") == 0) | |
610 | logging_mode |= LOG_MODE_SYSLOG; | |
611 | else if ((logging_mode & LOG_MODE_FILE) != 0) multiple = TRUE; | |
612 | else | |
613 | { | |
614 | logging_mode |= LOG_MODE_FILE; | |
615 | ||
616 | /* If a non-empty path is given, use it */ | |
617 | ||
618 | if (s[0] != 0) | |
619 | { | |
620 | file_path = string_copy(s); | |
621 | } | |
622 | ||
623 | /* If the path is empty, we want to use the first non-empty, non- | |
624 | syslog item in LOG_FILE_PATH, if there is one, since the value of | |
625 | log_file_path may have been set at runtime. If there is no such item, | |
626 | use the ultimate default in the spool directory. */ | |
627 | ||
628 | else | |
629 | { | |
630 | uschar *t; | |
631 | uschar *tt = US LOG_FILE_PATH; | |
632 | while ((t = string_nextinlist(&tt,&sep,log_buffer,LOG_BUFFER_SIZE)) | |
633 | != NULL) | |
634 | { | |
635 | if (Ustrcmp(t, "syslog") == 0 || t[0] == 0) continue; | |
636 | file_path = string_copy(t); | |
637 | break; | |
638 | } | |
639 | } /* Empty item in log_file_path */ | |
640 | } /* First non-syslog item in log_file_path */ | |
641 | } /* Scan of log_file_path */ | |
642 | } | |
643 | ||
644 | /* If no modes have been selected, it is a major disaster */ | |
645 | ||
646 | if (logging_mode == 0) | |
647 | die(US"Neither syslog nor file logging set in log_file_path", | |
648 | US"Unexpected logging failure"); | |
649 | ||
650 | /* Set up the ultimate default if necessary. Then revert to the old store | |
651 | pool, and record that we've sorted out the path. */ | |
652 | ||
653 | if ((logging_mode & LOG_MODE_FILE) != 0 && file_path[0] == 0) | |
654 | file_path = string_sprintf("%s/log/%%slog", spool_directory); | |
655 | store_pool = old_pool; | |
656 | path_inspected = TRUE; | |
657 | ||
658 | /* If more than one file path was given, log a complaint. This recursive call | |
659 | should work since we have now set up the routing. */ | |
660 | ||
661 | if (multiple) | |
662 | { | |
663 | log_write(0, LOG_MAIN|LOG_PANIC, | |
664 | "More than one path given in log_file_path: using %s", file_path); | |
665 | } | |
666 | } | |
667 | ||
668 | /* If debugging, show all log entries, but don't show headers. Do it all | |
669 | in one go so that it doesn't get split when multi-processing. */ | |
670 | ||
671 | DEBUG(D_any|D_v) | |
672 | { | |
673 | int i; | |
674 | ptr = log_buffer; | |
675 | ||
676 | Ustrcpy(ptr, "LOG:"); | |
677 | ptr += 4; | |
678 | ||
679 | /* Show the options that were passed into the call. These are those whose | |
680 | flag values do not have the 0x80000000 bit in them. Note that this | |
681 | automatically exclude the "all" setting. */ | |
682 | ||
683 | for (i = 0; i < log_options_count; i++) | |
684 | { | |
685 | unsigned int bit = log_options[i].bit; | |
686 | if ((bit & 0x80000000) != 0) continue; | |
687 | if ((selector & bit) != 0) | |
688 | { | |
689 | *ptr++ = ' '; | |
690 | Ustrcpy(ptr, log_options[i].name); | |
691 | while (*ptr) ptr++; | |
692 | } | |
693 | } | |
694 | ||
695 | sprintf(CS ptr, "%s%s%s%s%s\n ", | |
696 | ((flags & LOG_MAIN) != 0)? " MAIN" : "", | |
697 | ((flags & LOG_PANIC) != 0)? " PANIC" : "", | |
698 | ((flags & LOG_PANIC_DIE) == LOG_PANIC_DIE)? " DIE" : "", | |
699 | ((flags & LOG_PROCESS) != 0)? " PROCESS": "", | |
700 | ((flags & LOG_REJECT) != 0)? " REJECT" : ""); | |
701 | ||
702 | while(*ptr) ptr++; | |
703 | if ((flags & LOG_CONFIG) != 0) ptr = log_config_info(ptr, flags); | |
704 | ||
705 | va_start(ap, format); | |
706 | if (!string_vformat(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer)-1, format, ap)) | |
707 | Ustrcpy(ptr, "**** log string overflowed log buffer ****"); | |
708 | va_end(ap); | |
709 | ||
710 | while(*ptr) ptr++; | |
711 | Ustrcat(ptr, "\n"); | |
712 | debug_printf("%s", log_buffer); | |
713 | } | |
714 | ||
715 | /* If no log file is specified, we are in a mess. */ | |
716 | ||
717 | if ((flags & (LOG_MAIN|LOG_PANIC|LOG_REJECT|LOG_PROCESS)) == 0) | |
718 | log_write(0, LOG_MAIN|LOG_PANIC_DIE, "log_write called with no log " | |
719 | "flags set"); | |
720 | ||
721 | /* There are some weird circumstances in which logging is disabled. */ | |
722 | ||
723 | if (disable_logging) | |
724 | { | |
725 | DEBUG(D_any) debug_printf("log writing disabled\n"); | |
726 | return; | |
727 | } | |
728 | ||
a7d7aa58 PH |
729 | /* Handle disabled reject log */ |
730 | ||
731 | if (!write_rejectlog) flags &= ~LOG_REJECT; | |
732 | ||
059ec3d9 PH |
733 | /* Create the main message in the log buffer, including the message |
734 | id except for the process log and when called by a utility. */ | |
735 | ||
736 | ptr = log_buffer; | |
f3f065bb PH |
737 | sprintf(CS ptr, "%s ", tod_stamp(tod_log)); |
738 | while(*ptr) ptr++; | |
739 | ||
740 | if ((log_extra_selector & LX_pid) != 0) | |
741 | { | |
742 | sprintf(CS ptr, "[%d] ", (int)getpid()); | |
743 | while (*ptr) ptr++; | |
744 | } | |
745 | ||
059ec3d9 | 746 | if (really_exim && (flags & LOG_PROCESS) == 0 && message_id[0] != 0) |
f3f065bb PH |
747 | { |
748 | sprintf(CS ptr, "%s ", message_id); | |
749 | while(*ptr) ptr++; | |
750 | } | |
059ec3d9 | 751 | |
059ec3d9 PH |
752 | if ((flags & LOG_CONFIG) != 0) ptr = log_config_info(ptr, flags); |
753 | ||
754 | va_start(ap, format); | |
755 | if (!string_vformat(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer)-1, format, ap)) | |
756 | Ustrcpy(ptr, "**** log string overflowed log buffer ****\n"); | |
757 | while(*ptr) ptr++; | |
758 | va_end(ap); | |
759 | ||
760 | /* Add the raw, unrewritten, sender to the message if required. This is done | |
761 | this way because it kind of fits with LOG_RECIPIENTS. */ | |
762 | ||
763 | if ((flags & LOG_SENDER) != 0 && | |
ccfdb010 | 764 | ptr < log_buffer + LOG_BUFFER_SIZE - 10 - Ustrlen(raw_sender)) |
059ec3d9 PH |
765 | { |
766 | sprintf(CS ptr, " from <%s>", raw_sender); | |
767 | while (*ptr) ptr++; | |
768 | } | |
769 | ||
770 | /* Add list of recipients to the message if required; the raw list, | |
771 | before rewriting, was saved in raw_recipients. There may be none, if an ACL | |
772 | discarded them all. */ | |
773 | ||
774 | if ((flags & LOG_RECIPIENTS) != 0 && ptr < log_buffer + LOG_BUFFER_SIZE - 6 && | |
775 | raw_recipients_count > 0) | |
776 | { | |
777 | int i; | |
778 | sprintf(CS ptr, " for"); | |
779 | while (*ptr) ptr++; | |
780 | for (i = 0; i < raw_recipients_count; i++) | |
781 | { | |
782 | uschar *s = raw_recipients[i]; | |
783 | if (log_buffer + LOG_BUFFER_SIZE - ptr < Ustrlen(s) + 3) break; | |
784 | sprintf(CS ptr, " %s", s); | |
785 | while (*ptr) ptr++; | |
786 | } | |
787 | } | |
788 | ||
789 | sprintf(CS ptr, "\n"); | |
790 | while(*ptr) ptr++; | |
791 | length = ptr - log_buffer; | |
792 | ||
793 | /* Handle loggable errors when running a utility, or when address testing. | |
794 | Write to log_stderr unless debugging (when it will already have been written), | |
795 | or unless there is no log_stderr (expn called from daemon, for example). */ | |
796 | ||
797 | if (!really_exim || log_testing_mode) | |
798 | { | |
799 | if (debug_selector == 0 && log_stderr != NULL && | |
800 | (selector == 0 || (selector & log_write_selector) != 0)) | |
801 | { | |
802 | if (host_checking) | |
803 | fprintf(log_stderr, "LOG: %s", CS(log_buffer + 20)); /* no timestamp */ | |
804 | else | |
805 | fprintf(log_stderr, "%s", CS log_buffer); | |
806 | } | |
807 | if ((flags & LOG_PANIC_DIE) == LOG_PANIC_DIE) exim_exit(EXIT_FAILURE); | |
808 | return; | |
809 | } | |
810 | ||
811 | /* Handle the main log. We know that either syslog or file logging (or both) is | |
812 | set up. A real file gets left open during reception or delivery once it has | |
813 | been opened, but we don't want to keep on writing to it for too long after it | |
814 | has been renamed. Therefore, do a stat() and see if the inode has changed, and | |
815 | if so, re-open. */ | |
816 | ||
817 | if ((flags & LOG_MAIN) != 0 && | |
818 | (selector == 0 || (selector & log_write_selector) != 0)) | |
819 | { | |
820 | if ((logging_mode & LOG_MODE_SYSLOG) != 0 && | |
821 | (syslog_duplication || (flags & (LOG_REJECT|LOG_PANIC)) == 0)) | |
822 | write_syslog(LOG_INFO, log_buffer); | |
823 | ||
824 | if ((logging_mode & LOG_MODE_FILE) != 0) | |
825 | { | |
826 | struct stat statbuf; | |
827 | ||
828 | /* Check for a change to the mainlog file name when datestamping is in | |
829 | operation. This happens at midnight, at which point we want to roll over | |
830 | the file. Closing it has the desired effect. */ | |
831 | ||
832 | if (mainlog_datestamp != NULL) | |
833 | { | |
834 | uschar *nowstamp = tod_stamp(tod_log_datestamp); | |
835 | if (Ustrncmp (mainlog_datestamp, nowstamp, Ustrlen(nowstamp)) != 0) | |
836 | { | |
f1e894f3 | 837 | (void)close(mainlogfd); /* Close the file */ |
059ec3d9 PH |
838 | mainlogfd = -1; /* Clear the file descriptor */ |
839 | mainlog_inode = 0; /* Unset the inode */ | |
840 | mainlog_datestamp = NULL; /* Clear the datestamp */ | |
841 | } | |
842 | } | |
843 | ||
844 | /* Otherwise, we want to check whether the file has been renamed by a | |
845 | cycling script. This could be "if else", but for safety's sake, leave it as | |
846 | "if" so that renaming the log starts a new file even when datestamping is | |
847 | happening. */ | |
848 | ||
849 | if (mainlogfd >= 0) | |
850 | { | |
851 | if (Ustat(mainlog_name, &statbuf) < 0 || statbuf.st_ino != mainlog_inode) | |
852 | { | |
f1e894f3 | 853 | (void)close(mainlogfd); |
059ec3d9 PH |
854 | mainlogfd = -1; |
855 | mainlog_inode = 0; | |
856 | } | |
857 | } | |
858 | ||
859 | /* If the log is closed, open it. Then write the line. */ | |
860 | ||
861 | if (mainlogfd < 0) | |
862 | { | |
863 | open_log(&mainlogfd, lt_main); /* No return on error */ | |
864 | if (fstat(mainlogfd, &statbuf) >= 0) mainlog_inode = statbuf.st_ino; | |
865 | } | |
866 | ||
867 | /* Failing to write to the log is disastrous */ | |
868 | ||
869 | if ((rc = write(mainlogfd, log_buffer, length)) != length) | |
870 | { | |
871 | log_write_failed(US"main log", length, rc); | |
872 | /* That function does not return */ | |
873 | } | |
874 | } | |
875 | } | |
876 | ||
a7d7aa58 PH |
877 | /* Handle the log for rejected messages. This can be globally disabled, in |
878 | which case the flags are altered above. If there are any header lines (i.e. if | |
879 | the rejection is happening after the DATA phase), log the recipients and the | |
880 | headers. */ | |
059ec3d9 | 881 | |
a7d7aa58 | 882 | if ((flags & LOG_REJECT) != 0) |
059ec3d9 PH |
883 | { |
884 | header_line *h; | |
885 | ||
886 | if (header_list != NULL && (log_extra_selector & LX_rejected_header) != 0) | |
887 | { | |
888 | if (recipients_count > 0) | |
889 | { | |
890 | int i; | |
891 | ||
892 | /* List the sender */ | |
893 | ||
894 | string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer), | |
895 | "Envelope-from: <%s>\n", sender_address); | |
896 | while (*ptr) ptr++; | |
897 | ||
898 | /* List up to 5 recipients */ | |
899 | ||
900 | string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer), | |
901 | "Envelope-to: <%s>\n", recipients_list[0].address); | |
902 | while (*ptr) ptr++; | |
903 | ||
904 | for (i = 1; i < recipients_count && i < 5; i++) | |
905 | { | |
906 | string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer), " <%s>\n", | |
907 | recipients_list[i].address); | |
908 | while (*ptr) ptr++; | |
909 | } | |
910 | ||
911 | if (i < recipients_count) | |
912 | { | |
913 | (void)string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer), | |
914 | " ...\n"); | |
915 | while (*ptr) ptr++; | |
916 | } | |
917 | } | |
918 | ||
919 | /* A header with a NULL text is an unfilled in Received: header */ | |
920 | ||
921 | for (h = header_list; h != NULL; h = h->next) | |
922 | { | |
923 | BOOL fitted; | |
924 | if (h->text == NULL) continue; | |
925 | fitted = string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer), | |
926 | "%c %s", h->type, h->text); | |
927 | while(*ptr) ptr++; | |
928 | if (!fitted) /* Buffer is full; truncate */ | |
929 | { | |
930 | ptr -= 100; /* For message and separator */ | |
931 | if (ptr[-1] == '\n') ptr--; | |
932 | Ustrcpy(ptr, "\n*** truncated ***\n"); | |
933 | while (*ptr) ptr++; | |
934 | break; | |
935 | } | |
936 | } | |
937 | ||
938 | length = ptr - log_buffer; | |
939 | } | |
940 | ||
941 | /* Write to syslog or to a log file */ | |
942 | ||
943 | if ((logging_mode & LOG_MODE_SYSLOG) != 0 && | |
944 | (syslog_duplication || (flags & LOG_PANIC) == 0)) | |
945 | write_syslog(LOG_NOTICE, log_buffer); | |
946 | ||
947 | /* Check for a change to the rejectlog file name when datestamping is in | |
948 | operation. This happens at midnight, at which point we want to roll over | |
949 | the file. Closing it has the desired effect. */ | |
950 | ||
951 | if ((logging_mode & LOG_MODE_FILE) != 0) | |
952 | { | |
953 | struct stat statbuf; | |
954 | ||
955 | if (rejectlog_datestamp != NULL) | |
956 | { | |
957 | uschar *nowstamp = tod_stamp(tod_log_datestamp); | |
958 | if (Ustrncmp (rejectlog_datestamp, nowstamp, Ustrlen(nowstamp)) != 0) | |
959 | { | |
f1e894f3 | 960 | (void)close(rejectlogfd); /* Close the file */ |
059ec3d9 PH |
961 | rejectlogfd = -1; /* Clear the file descriptor */ |
962 | rejectlog_inode = 0; /* Unset the inode */ | |
963 | rejectlog_datestamp = NULL; /* Clear the datestamp */ | |
964 | } | |
965 | } | |
966 | ||
967 | /* Otherwise, we want to check whether the file has been renamed by a | |
968 | cycling script. This could be "if else", but for safety's sake, leave it as | |
969 | "if" so that renaming the log starts a new file even when datestamping is | |
970 | happening. */ | |
971 | ||
972 | if (rejectlogfd >= 0) | |
973 | { | |
974 | if (Ustat(rejectlog_name, &statbuf) < 0 || | |
975 | statbuf.st_ino != rejectlog_inode) | |
976 | { | |
f1e894f3 | 977 | (void)close(rejectlogfd); |
059ec3d9 PH |
978 | rejectlogfd = -1; |
979 | rejectlog_inode = 0; | |
980 | } | |
981 | } | |
982 | ||
983 | /* Open the file if necessary, and write the data */ | |
984 | ||
985 | if (rejectlogfd < 0) | |
986 | { | |
987 | open_log(&rejectlogfd, lt_reject); /* No return on error */ | |
988 | if (fstat(rejectlogfd, &statbuf) >= 0) rejectlog_inode = statbuf.st_ino; | |
989 | } | |
990 | ||
991 | if ((rc = write(rejectlogfd, log_buffer, length)) != length) | |
992 | { | |
993 | log_write_failed(US"reject log", length, rc); | |
994 | /* That function does not return */ | |
995 | } | |
996 | } | |
997 | } | |
998 | ||
999 | ||
1000 | /* Handle the process log file, where exim processes can be made to dump | |
1001 | details of what they are doing by sending them a USR1 signal. Note that | |
1002 | a message id is not automatically added above. This information is always | |
1003 | written to a file - never to syslog. */ | |
1004 | ||
1005 | if ((flags & LOG_PROCESS) != 0) | |
1006 | { | |
1007 | int processlogfd; | |
1008 | open_log(&processlogfd, lt_process); /* No return on error */ | |
1009 | if ((rc = write(processlogfd, log_buffer, length)) != length) | |
1010 | { | |
1011 | log_write_failed(US"process log", length, rc); | |
1012 | /* That function does not return */ | |
1013 | } | |
1014 | (void)close(processlogfd); | |
1015 | } | |
1016 | ||
1017 | ||
1018 | /* Handle the panic log, which is not kept open like the others. If it fails to | |
1019 | open, there will be a recursive call to log_write(). We detect this above and | |
1020 | attempt to write to the system log as a last-ditch try at telling somebody. In | |
47c7a64a | 1021 | all cases except mua_wrapper, try to write to log_stderr. */ |
059ec3d9 PH |
1022 | |
1023 | if ((flags & LOG_PANIC) != 0) | |
1024 | { | |
47c7a64a | 1025 | if (log_stderr != NULL && log_stderr != debug_file && !mua_wrapper) |
059ec3d9 PH |
1026 | fprintf(log_stderr, "%s", CS log_buffer); |
1027 | ||
1028 | if ((logging_mode & LOG_MODE_SYSLOG) != 0) | |
1029 | { | |
1030 | write_syslog(LOG_ALERT, log_buffer); | |
1031 | } | |
1032 | ||
1033 | /* If this panic logging was caused by a failure to open the main log, | |
1034 | the original log line is in panic_save_buffer. Make an attempt to write it. */ | |
1035 | ||
1036 | if ((logging_mode & LOG_MODE_FILE) != 0) | |
1037 | { | |
1038 | panic_recurseflag = TRUE; | |
1039 | open_log(&paniclogfd, lt_panic); /* Won't return on failure */ | |
1040 | panic_recurseflag = FALSE; | |
1041 | ||
1042 | if (panic_save_buffer != NULL) | |
1043 | (void) write(paniclogfd, panic_save_buffer, Ustrlen(panic_save_buffer)); | |
1044 | ||
1045 | if ((rc = write(paniclogfd, log_buffer, length)) != length) | |
1046 | { | |
1047 | int save_errno = errno; | |
1048 | write_syslog(LOG_CRIT, log_buffer); | |
1049 | sprintf(CS log_buffer, "write failed on panic log: length=%d result=%d " | |
1050 | "errno=%d (%s)", length, rc, save_errno, strerror(save_errno)); | |
1051 | write_syslog(LOG_CRIT, log_buffer); | |
1052 | flags |= LOG_PANIC_DIE; | |
1053 | } | |
1054 | ||
f1e894f3 | 1055 | (void)close(paniclogfd); |
059ec3d9 PH |
1056 | } |
1057 | ||
1058 | /* Give up if the DIE flag is set */ | |
1059 | ||
1060 | if ((flags & LOG_PANIC_DIE) != LOG_PANIC) | |
1061 | die(NULL, US"Unexpected failure, please try later"); | |
1062 | } | |
1063 | } | |
1064 | ||
1065 | ||
1066 | ||
1067 | /************************************************* | |
1068 | * Close any open log files * | |
1069 | *************************************************/ | |
1070 | ||
1071 | void | |
1072 | log_close_all(void) | |
1073 | { | |
1074 | if (mainlogfd >= 0) | |
f1e894f3 | 1075 | { (void)close(mainlogfd); mainlogfd = -1; } |
059ec3d9 | 1076 | if (rejectlogfd >= 0) |
f1e894f3 | 1077 | { (void)close(rejectlogfd); rejectlogfd = -1; } |
059ec3d9 PH |
1078 | closelog(); |
1079 | syslog_open = FALSE; | |
1080 | } | |
1081 | ||
1082 | /* End of log.c */ |