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