1 /* Copyright (c) 2002-2018 Dovecot authors, see the included COPYING file */
2
3 #include "lib.h"
4 #include "ioloop.h"
5 #include "str.h"
6 #include "hostpid.h"
7 #include "net.h"
8 #include "process-title.h"
9 #include "lib-signals.h"
10 #include "backtrace-string.h"
11 #include "printf-format-fix.h"
12 #include "write-full.h"
13 #include "time-util.h"
14 #include "failures-private.h"
15
16 #include <unistd.h>
17 #include <fcntl.h>
18 #include <syslog.h>
19 #include <time.h>
20 #include <poll.h>
21
22 #define LOG_TYPE_FLAG_PREFIX_LEN 0x40
23 #define LOG_TYPE_FLAG_DISABLE_LOG_PREFIX 0x80
24
25 const char *failure_log_type_prefixes[LOG_TYPE_COUNT] = {
26 "Debug: ",
27 "Info: ",
28 "Warning: ",
29 "Error: ",
30 "Fatal: ",
31 "Panic: "
32 };
33
34 const char *failure_log_type_names[LOG_TYPE_COUNT] = {
35 "debug", "info", "warning", "error", "fatal", "panic"
36 };
37
38 static int log_fd_write(int fd, const unsigned char *data, size_t len);
39
40 static void error_handler_real(const struct failure_context *ctx,
41 const char *format, va_list args);
42
43 /* Initialize working defaults */
44 static failure_callback_t *fatal_handler ATTR_NORETURN =
45 default_fatal_handler;
46 static failure_callback_t *error_handler = default_error_handler;
47 static failure_callback_t *info_handler = default_error_handler;
48 static failure_callback_t *debug_handler = default_error_handler;
49 static void (*failure_exit_callback)(int *) = NULL;
50
51 static struct failure_context failure_ctx_debug = { .type = LOG_TYPE_DEBUG };
52 static struct failure_context failure_ctx_info = { .type = LOG_TYPE_INFO };
53 static struct failure_context failure_ctx_warning = { .type = LOG_TYPE_WARNING };
54 static struct failure_context failure_ctx_error = { .type = LOG_TYPE_ERROR };
55
56 static int log_fd = STDERR_FILENO, log_info_fd = STDERR_FILENO,
57 log_debug_fd = STDERR_FILENO;
58 static char *log_prefix = NULL;
59 static char *log_stamp_format = NULL, *log_stamp_format_suffix = NULL;
60 static bool failure_ignore_errors = FALSE, log_prefix_sent = FALSE;
61 static bool coredump_on_error = FALSE;
62 static void log_timestamp_add(const struct failure_context *ctx, string_t *str);
63 static void log_prefix_add(const struct failure_context *ctx, string_t *str);
64 static void i_failure_send_option_forced(const char *key, const char *value);
65 static int internal_send_split(string_t *full_str, size_t prefix_len);
66
default_format(const struct failure_context * ctx,size_t * prefix_len_r ATTR_UNUSED,const char * format,va_list args)67 static string_t * ATTR_FORMAT(3, 0) default_format(const struct failure_context *ctx,
68 size_t *prefix_len_r ATTR_UNUSED,
69 const char *format,
70 va_list args)
71 {
72 string_t *str = t_str_new(256);
73 log_timestamp_add(ctx, str);
74 log_prefix_add(ctx, str);
75
76 /* make sure there's no %n in there and fix %m */
77 str_vprintfa(str, printf_format_fix(format), args);
78 return str;
79 }
80
default_write(enum log_type type,string_t * data,size_t prefix_len ATTR_UNUSED)81 static int default_write(enum log_type type, string_t *data, size_t prefix_len ATTR_UNUSED)
82 {
83 int fd;
84
85 switch (type) {
86 case LOG_TYPE_DEBUG:
87 fd = log_debug_fd;
88 break;
89 case LOG_TYPE_INFO:
90 fd = log_info_fd;
91 break;
92 default:
93 fd = log_fd;
94 break;
95 }
96 str_append_c(data, '\n');
97 return log_fd_write(fd, str_data(data), str_len(data));
98 }
99
default_on_handler_failure(const struct failure_context * ctx)100 static void default_on_handler_failure(const struct failure_context *ctx)
101 {
102 const char *log_type = "info";
103 switch (ctx->type) {
104 case LOG_TYPE_DEBUG:
105 log_type = "debug";
106 /* fall through */
107 case LOG_TYPE_INFO:
108 /* we failed to log to info/debug log, try to log the
109 write error to error log - maybe that'll work. */
110 i_fatal_status(FATAL_LOGWRITE, "write() failed to %s log: %m",
111 log_type);
112 break;
113 default:
114 failure_exit(FATAL_LOGWRITE);
115 break;
116 }
117 }
118
default_post_handler(const struct failure_context * ctx)119 static void default_post_handler(const struct failure_context *ctx)
120 {
121 if (ctx->type == LOG_TYPE_ERROR && coredump_on_error)
122 abort();
123 }
124
syslog_format(const struct failure_context * ctx,size_t * prefix_len_r ATTR_UNUSED,const char * format,va_list args)125 static string_t * ATTR_FORMAT(3, 0) syslog_format(const struct failure_context *ctx,
126 size_t *prefix_len_r ATTR_UNUSED,
127 const char *format,
128 va_list args)
129 {
130 string_t *str = t_str_new(128);
131 if (ctx->type == LOG_TYPE_INFO) {
132 if (ctx->log_prefix != NULL)
133 str_append(str, ctx->log_prefix);
134 else if (log_prefix != NULL)
135 str_append(str, log_prefix);
136 } else {
137 log_prefix_add(ctx, str);
138 }
139 str_vprintfa(str, format, args);
140 return str;
141 }
142
syslog_write(enum log_type type,string_t * data,size_t prefix_len ATTR_UNUSED)143 static int syslog_write(enum log_type type, string_t *data, size_t prefix_len ATTR_UNUSED)
144 {
145 int level = LOG_ERR;
146
147 switch (type) {
148 case LOG_TYPE_DEBUG:
149 level = LOG_DEBUG;
150 break;
151 case LOG_TYPE_INFO:
152 level = LOG_INFO;
153 break;
154 case LOG_TYPE_WARNING:
155 level = LOG_WARNING;
156 break;
157 case LOG_TYPE_ERROR:
158 level = LOG_ERR;
159 break;
160 case LOG_TYPE_FATAL:
161 case LOG_TYPE_PANIC:
162 level = LOG_CRIT;
163 break;
164 case LOG_TYPE_COUNT:
165 case LOG_TYPE_OPTION:
166 i_unreached();
167 }
168 syslog(level, "%s", str_c(data));
169 return 0;
170 }
171
syslog_on_handler_failure(const struct failure_context * ctx ATTR_UNUSED)172 static void syslog_on_handler_failure(const struct failure_context *ctx ATTR_UNUSED)
173 {
174 failure_exit(FATAL_LOGERROR);
175 }
176
syslog_post_handler(const struct failure_context * ctx ATTR_UNUSED)177 static void syslog_post_handler(const struct failure_context *ctx ATTR_UNUSED)
178 {
179 }
180
internal_format(const struct failure_context * ctx,size_t * prefix_len_r,const char * format,va_list args)181 static string_t * ATTR_FORMAT(3, 0) internal_format(const struct failure_context *ctx,
182 size_t *prefix_len_r,
183 const char *format,
184 va_list args)
185 {
186 string_t *str;
187 unsigned char log_type = ctx->type + 1;
188
189 if (ctx->log_prefix != NULL) {
190 log_type |= LOG_TYPE_FLAG_DISABLE_LOG_PREFIX;
191 if (ctx->log_prefix_type_pos != 0)
192 log_type |= LOG_TYPE_FLAG_PREFIX_LEN;
193 } else if (!log_prefix_sent && log_prefix != NULL) {
194 log_prefix_sent = TRUE;
195 i_failure_send_option_forced("prefix", log_prefix);
196 }
197
198 str = t_str_new(128);
199 str_printfa(str, "\001%c%s ", log_type, my_pid);
200 if ((log_type & LOG_TYPE_FLAG_PREFIX_LEN) != 0)
201 str_printfa(str, "%u ", ctx->log_prefix_type_pos);
202 if (ctx->log_prefix != NULL)
203 str_append(str, ctx->log_prefix);
204 *prefix_len_r = str_len(str);
205
206 str_vprintfa(str, format, args);
207 return str;
208 }
209
internal_write(enum log_type type ATTR_UNUSED,string_t * data,size_t prefix_len)210 static int internal_write(enum log_type type ATTR_UNUSED, string_t *data, size_t prefix_len)
211 {
212 if (str_len(data)+1 <= PIPE_BUF) {
213 str_append_c(data, '\n');
214 return log_fd_write(STDERR_FILENO,
215 str_data(data), str_len(data));
216 }
217 return internal_send_split(data, prefix_len);
218 }
219
internal_on_handler_failure(const struct failure_context * ctx ATTR_UNUSED)220 static void internal_on_handler_failure(const struct failure_context *ctx ATTR_UNUSED)
221 {
222 failure_exit(FATAL_LOGERROR);
223 }
224
internal_post_handler(const struct failure_context * ctx ATTR_UNUSED)225 static void internal_post_handler(const struct failure_context *ctx ATTR_UNUSED)
226 {
227 }
228
229 static struct failure_handler_vfuncs default_handler_vfuncs = {
230 .write = &default_write,
231 .format = &default_format,
232 .on_handler_failure = &default_on_handler_failure,
233 .post_handler = &default_post_handler
234 };
235
236 static struct failure_handler_vfuncs syslog_handler_vfuncs = {
237 .write = &syslog_write,
238 .format = &syslog_format,
239 .on_handler_failure = &syslog_on_handler_failure,
240 .post_handler = &syslog_post_handler
241 };
242
243 static struct failure_handler_vfuncs internal_handler_vfuncs = {
244 .write = &internal_write,
245 .format = &internal_format,
246 .on_handler_failure = &internal_on_handler_failure,
247 .post_handler = &internal_post_handler
248 };
249
250 struct failure_handler_config failure_handler = { .fatal_err_reset = FATAL_LOGWRITE,
251 .v = &default_handler_vfuncs };
252
common_handler(const struct failure_context * ctx,const char * format,va_list args)253 static int common_handler(const struct failure_context *ctx,
254 const char *format, va_list args)
255 {
256 static int recursed = 0;
257 int ret;
258 size_t prefix_len = 0;
259
260 if (recursed >= 2) {
261 /* we're being called from some signal handler or we ran
262 out of memory */
263 return -1;
264 }
265 recursed++;
266
267 T_BEGIN {
268 string_t *str = failure_handler.v->format(ctx, &prefix_len, format, args);
269 ret = failure_handler.v->write(ctx->type, str, prefix_len);
270 } T_END;
271
272 if (ret < 0 && failure_ignore_errors)
273 ret = 0;
274
275 recursed--;
276 return ret;
277 }
278
error_handler_real(const struct failure_context * ctx,const char * format,va_list args)279 static void error_handler_real(const struct failure_context *ctx,
280 const char *format, va_list args)
281 {
282 if (common_handler(ctx, format, args) < 0)
283 failure_handler.v->on_handler_failure(ctx);
284 failure_handler.v->post_handler(ctx);
285 }
286
287 static void ATTR_FORMAT(2, 0)
288 i_internal_error_handler(const struct failure_context *ctx,
289 const char *format, va_list args);
290
291 /* kludgy .. we want to trust log_stamp_format with -Wformat-nonliteral */
292 static const char *
293 get_log_stamp_format(const char *format_arg, unsigned int timestamp_usecs)
294 ATTR_FORMAT_ARG(1);
295
get_log_stamp_format(const char * format_arg ATTR_UNUSED,unsigned int timestamp_usecs)296 static const char *get_log_stamp_format(const char *format_arg ATTR_UNUSED,
297 unsigned int timestamp_usecs)
298 {
299 if (log_stamp_format_suffix == NULL)
300 return log_stamp_format;
301 return t_strdup_printf("%s%06u%s", log_stamp_format,
302 timestamp_usecs, log_stamp_format_suffix);
303 }
304
failure_exit(int status)305 void failure_exit(int status)
306 {
307 static bool recursed = FALSE;
308
309 if (failure_exit_callback != NULL && !recursed) {
310 recursed = TRUE;
311 failure_exit_callback(&status);
312 }
313 lib_exit(status);
314 }
315
log_timestamp_add(const struct failure_context * ctx,string_t * str)316 static void log_timestamp_add(const struct failure_context *ctx, string_t *str)
317 {
318 const struct tm *tm = ctx->timestamp;
319 char buf[256];
320 struct timeval now;
321
322 if (log_stamp_format != NULL) {
323 if (tm == NULL) {
324 i_gettimeofday(&now);
325 tm = localtime(&now.tv_sec);
326 } else {
327 now.tv_usec = ctx->timestamp_usecs;
328 }
329
330 if (strftime(buf, sizeof(buf),
331 get_log_stamp_format("unused", now.tv_usec), tm) > 0)
332 str_append(str, buf);
333 }
334 }
335
log_prefix_add(const struct failure_context * ctx,string_t * str)336 static void log_prefix_add(const struct failure_context *ctx, string_t *str)
337 {
338 if (ctx->log_prefix == NULL) {
339 /* use global log prefix */
340 if (log_prefix != NULL)
341 str_append(str, log_prefix);
342 str_append(str, failure_log_type_prefixes[ctx->type]);
343 } else if (ctx->log_prefix_type_pos == 0) {
344 str_append(str, ctx->log_prefix);
345 str_append(str, failure_log_type_prefixes[ctx->type]);
346 } else {
347 i_assert(ctx->log_prefix_type_pos <= strlen(ctx->log_prefix));
348 str_append_data(str, ctx->log_prefix, ctx->log_prefix_type_pos);
349 str_append(str, failure_log_type_prefixes[ctx->type]);
350 str_append(str, ctx->log_prefix + ctx->log_prefix_type_pos);
351 }
352 }
353
fd_wait_writable(int fd)354 static void fd_wait_writable(int fd)
355 {
356 struct pollfd pfd = {
357 .fd = fd,
358 .events = POLLOUT | POLLERR | POLLHUP | POLLNVAL,
359 };
360
361 /* Use poll() instead of ioloop, because we don't want to recurse back
362 to log writing in case something fails. */
363 if (poll(&pfd, 1, -1) < 0 && errno != EINTR) {
364 /* Unexpected error. We're already blocking on log writes,
365 so we can't log it. */
366 abort();
367 }
368 }
369
log_fd_write(int fd,const unsigned char * data,size_t len)370 static int log_fd_write(int fd, const unsigned char *data, size_t len)
371 {
372 ssize_t ret;
373 unsigned int prev_signal_term_counter = signal_term_counter;
374 unsigned int terminal_eintr_count = 0;
375 const char *old_title = NULL;
376 bool failed = FALSE, process_title_changed = FALSE;
377
378 while (!failed &&
379 (ret = write(fd, data, len)) != (ssize_t)len) {
380 if (ret > 0) {
381 /* some was written, continue.. */
382 data += ret;
383 len -= ret;
384 continue;
385 }
386 if (ret == 0) {
387 /* out of disk space? */
388 errno = ENOSPC;
389 failed = TRUE;
390 break;
391 }
392 switch (errno) {
393 case EAGAIN: {
394 /* Log fd is nonblocking - wait until we can write more.
395 Indicate in process title that the process is waiting
396 because it's waiting on the log.
397
398 Remember that the log fd is shared across processes,
399 which also means the log fd flags are shared. So if
400 one process changes the O_NONBLOCK flag for a log fd,
401 all the processes see the change. To avoid problems,
402 we'll wait using poll() instead of changing the
403 O_NONBLOCK flag. */
404 if (!process_title_changed) {
405 const char *title;
406
407 process_title_changed = TRUE;
408 old_title = t_strdup(process_title_get());
409 if (old_title == NULL)
410 title = "[blocking on log write]";
411 else
412 title = t_strdup_printf("%s - [blocking on log write]",
413 old_title);
414 process_title_set(title);
415 }
416 fd_wait_writable(fd);
417 break;
418 }
419 case EINTR:
420 if (prev_signal_term_counter == signal_term_counter) {
421 /* non-terminal signal. ignore. */
422 } else if (terminal_eintr_count++ == 0) {
423 /* we'd rather not die in the middle of
424 writing to log. try again once more */
425 } else {
426 /* received two terminal signals.
427 someone wants us dead. */
428 failed = TRUE;
429 break;
430 }
431 break;
432 default:
433 failed = TRUE;
434 break;
435 }
436 prev_signal_term_counter = signal_term_counter;
437 }
438 if (process_title_changed)
439 process_title_set(old_title);
440 return failed ? -1 : 0;
441 }
442
443 static void ATTR_NORETURN
default_fatal_finish(enum log_type type,int status)444 default_fatal_finish(enum log_type type, int status)
445 {
446 const char *backtrace;
447 static int recursed = 0;
448
449 recursed++;
450 if ((type == LOG_TYPE_PANIC || status == FATAL_OUTOFMEM) &&
451 recursed == 1) {
452 if (backtrace_get(&backtrace) == 0)
453 i_error("Raw backtrace: %s", backtrace);
454 }
455 recursed--;
456
457 if (type == LOG_TYPE_PANIC || getenv("CORE_ERROR") != NULL ||
458 (status == FATAL_OUTOFMEM && getenv("CORE_OUTOFMEM") != NULL))
459 abort();
460 else
461 failure_exit(status);
462 }
463
fatal_handler_real(const struct failure_context * ctx,const char * format,va_list args)464 static void ATTR_NORETURN fatal_handler_real(const struct failure_context *ctx,
465 const char *format, va_list args)
466 {
467 int status = ctx->exit_status;
468 if (common_handler(ctx, format, args) < 0 &&
469 status == FATAL_DEFAULT)
470 status = failure_handler.fatal_err_reset;
471 default_fatal_finish(ctx->type, status);
472 }
473
default_fatal_handler(const struct failure_context * ctx,const char * format,va_list args)474 void default_fatal_handler(const struct failure_context *ctx,
475 const char *format, va_list args)
476 {
477 failure_handler.v = &default_handler_vfuncs;
478 failure_handler.fatal_err_reset = FATAL_LOGWRITE;
479 fatal_handler_real(ctx, format, args);
480 }
481
default_error_handler(const struct failure_context * ctx,const char * format,va_list args)482 void default_error_handler(const struct failure_context *ctx,
483 const char *format, va_list args)
484 {
485 failure_handler.v = &default_handler_vfuncs;
486 failure_handler.fatal_err_reset = FATAL_LOGWRITE;
487 error_handler_real(ctx, format, args);
488 }
489
i_log_type(const struct failure_context * ctx,const char * format,...)490 void i_log_type(const struct failure_context *ctx, const char *format, ...)
491 {
492 va_list args;
493
494 va_start(args, format);
495 i_log_typev(ctx, format, args);
496 va_end(args);
497 }
498
i_log_typev(const struct failure_context * ctx,const char * format,va_list args)499 void i_log_typev(const struct failure_context *ctx, const char *format,
500 va_list args)
501 {
502 switch (ctx->type) {
503 case LOG_TYPE_DEBUG:
504 debug_handler(ctx, format, args);
505 break;
506 case LOG_TYPE_INFO:
507 info_handler(ctx, format, args);
508 break;
509 default:
510 error_handler(ctx, format, args);
511 }
512 }
513
i_panic(const char * format,...)514 void i_panic(const char *format, ...)
515 {
516 struct failure_context ctx;
517 va_list args;
518
519 lib_set_clean_exit(TRUE);
520 i_zero(&ctx);
521 ctx.type = LOG_TYPE_PANIC;
522
523 va_start(args, format);
524 fatal_handler(&ctx, format, args);
525 i_unreached();
526 /*va_end(args);*/
527 }
528
i_fatal(const char * format,...)529 void i_fatal(const char *format, ...)
530 {
531 struct failure_context ctx;
532 va_list args;
533
534 lib_set_clean_exit(TRUE);
535 i_zero(&ctx);
536 ctx.type = LOG_TYPE_FATAL;
537 ctx.exit_status = FATAL_DEFAULT;
538
539 va_start(args, format);
540 fatal_handler(&ctx, format, args);
541 i_unreached();
542 /*va_end(args);*/
543 }
544
i_fatal_status(int status,const char * format,...)545 void i_fatal_status(int status, const char *format, ...)
546 {
547 struct failure_context ctx;
548 va_list args;
549
550 lib_set_clean_exit(TRUE);
551 i_zero(&ctx);
552 ctx.type = LOG_TYPE_FATAL;
553 ctx.exit_status = status;
554
555 va_start(args, format);
556 fatal_handler(&ctx, format, args);
557 i_unreached();
558 /*va_end(args);*/
559 }
560
i_error(const char * format,...)561 void i_error(const char *format, ...)
562 {
563 int old_errno = errno;
564 va_list args;
565
566 va_start(args, format);
567 error_handler(&failure_ctx_error, format, args);
568 va_end(args);
569
570 errno = old_errno;
571 }
572
i_warning(const char * format,...)573 void i_warning(const char *format, ...)
574 {
575 int old_errno = errno;
576 va_list args;
577
578 va_start(args, format);
579 error_handler(&failure_ctx_warning, format, args);
580 va_end(args);
581
582 errno = old_errno;
583 }
584
i_info(const char * format,...)585 void i_info(const char *format, ...)
586 {
587 int old_errno = errno;
588 va_list args;
589
590 va_start(args, format);
591 info_handler(&failure_ctx_info, format, args);
592 va_end(args);
593
594 errno = old_errno;
595 }
596
i_debug(const char * format,...)597 void i_debug(const char *format, ...)
598 {
599 int old_errno = errno;
600 va_list args;
601
602 va_start(args, format);
603 debug_handler(&failure_ctx_debug, format, args);
604 va_end(args);
605
606 errno = old_errno;
607 }
608
i_set_fatal_handler(failure_callback_t * callback ATTR_NORETURN)609 void i_set_fatal_handler(failure_callback_t *callback ATTR_NORETURN)
610 {
611 fatal_handler = callback;
612 }
613
i_set_error_handler(failure_callback_t * callback)614 void i_set_error_handler(failure_callback_t *callback)
615 {
616 coredump_on_error = getenv("CORE_ERROR") != NULL;
617 error_handler = callback;
618 }
619
i_set_info_handler(failure_callback_t * callback)620 void i_set_info_handler(failure_callback_t *callback)
621 {
622 info_handler = callback;
623 }
624
i_set_debug_handler(failure_callback_t * callback)625 void i_set_debug_handler(failure_callback_t *callback)
626 {
627 debug_handler = callback;
628 }
629
i_get_failure_handlers(failure_callback_t ** fatal_callback_r,failure_callback_t ** error_callback_r,failure_callback_t ** info_callback_r,failure_callback_t ** debug_callback_r)630 void i_get_failure_handlers(failure_callback_t **fatal_callback_r,
631 failure_callback_t **error_callback_r,
632 failure_callback_t **info_callback_r,
633 failure_callback_t **debug_callback_r)
634 {
635 *fatal_callback_r = fatal_handler;
636 *error_callback_r = error_handler;
637 *info_callback_r = info_handler;
638 *debug_callback_r = debug_handler;
639 }
640
i_syslog_fatal_handler(const struct failure_context * ctx,const char * format,va_list args)641 void i_syslog_fatal_handler(const struct failure_context *ctx,
642 const char *format, va_list args)
643 {
644 failure_handler.v = &syslog_handler_vfuncs;
645 failure_handler.fatal_err_reset = FATAL_LOGERROR;
646 fatal_handler_real(ctx, format, args);
647 }
648
i_syslog_error_handler(const struct failure_context * ctx,const char * format,va_list args)649 void i_syslog_error_handler(const struct failure_context *ctx,
650 const char *format, va_list args)
651 {
652 failure_handler.v = &syslog_handler_vfuncs;
653 failure_handler.fatal_err_reset = FATAL_LOGERROR;
654 error_handler_real(ctx, format, args);
655 }
656
i_set_failure_syslog(const char * ident,int options,int facility)657 void i_set_failure_syslog(const char *ident, int options, int facility)
658 {
659 openlog(ident, options, facility);
660
661 i_set_fatal_handler(i_syslog_fatal_handler);
662 i_set_error_handler(i_syslog_error_handler);
663 i_set_info_handler(i_syslog_error_handler);
664 i_set_debug_handler(i_syslog_error_handler);
665 }
666
open_log_file(int * fd,const char * path)667 static void open_log_file(int *fd, const char *path)
668 {
669 const char *str;
670
671 if (*fd != STDERR_FILENO) {
672 if (close(*fd) < 0) {
673 str = t_strdup_printf("close(%d) failed: %m\n", *fd);
674 (void)write_full(STDERR_FILENO, str, strlen(str));
675 }
676 }
677
678 if (path == NULL || strcmp(path, "/dev/stderr") == 0)
679 *fd = STDERR_FILENO;
680 else {
681 *fd = open(path, O_CREAT | O_APPEND | O_WRONLY, 0600);
682 if (*fd == -1) {
683 *fd = STDERR_FILENO;
684 str = t_strdup_printf("Can't open log file %s: %m\n",
685 path);
686 (void)write_full(STDERR_FILENO, str, strlen(str));
687 if (fd == &log_fd)
688 failure_exit(FATAL_LOGOPEN);
689 else
690 i_fatal_status(FATAL_LOGOPEN, "%s", str);
691 }
692 fd_close_on_exec(*fd, TRUE);
693 }
694 }
695
i_set_failure_file(const char * path,const char * prefix)696 void i_set_failure_file(const char *path, const char *prefix)
697 {
698 i_set_failure_prefix("%s", prefix);
699
700 if (log_info_fd != STDERR_FILENO && log_info_fd != log_fd) {
701 if (close(log_info_fd) < 0)
702 i_error("close(%d) failed: %m", log_info_fd);
703 }
704
705 if (log_debug_fd != STDERR_FILENO && log_debug_fd != log_info_fd &&
706 log_debug_fd != log_fd) {
707 if (close(log_debug_fd) < 0)
708 i_error("close(%d) failed: %m", log_debug_fd);
709 }
710
711 open_log_file(&log_fd, path);
712 /* if info/debug logs are elsewhere, i_set_info/debug_file()
713 overrides these later. */
714 log_info_fd = log_fd;
715 log_debug_fd = log_fd;
716
717 i_set_fatal_handler(default_fatal_handler);
718 i_set_error_handler(default_error_handler);
719 i_set_info_handler(default_error_handler);
720 i_set_debug_handler(default_error_handler);
721 }
722
i_failure_send_option_forced(const char * key,const char * value)723 static void i_failure_send_option_forced(const char *key, const char *value)
724 {
725 const char *str;
726
727 str = t_strdup_printf("\001%c%s %s=%s\n", LOG_TYPE_OPTION+1,
728 my_pid, key, value);
729 (void)write_full(STDERR_FILENO, str, strlen(str));
730 }
731
i_failure_send_option(const char * key,const char * value)732 static void i_failure_send_option(const char *key, const char *value)
733 {
734 if (error_handler == i_internal_error_handler)
735 i_failure_send_option_forced(key, value);
736 }
737
i_set_failure_prefix(const char * prefix_fmt,...)738 void i_set_failure_prefix(const char *prefix_fmt, ...)
739 {
740 va_list args;
741
742 va_start(args, prefix_fmt);
743 i_free(log_prefix);
744 log_prefix = i_strdup_vprintf(prefix_fmt, args);
745 va_end(args);
746
747 log_prefix_sent = FALSE;
748 }
749
i_unset_failure_prefix(void)750 void i_unset_failure_prefix(void)
751 {
752 i_free(log_prefix);
753 log_prefix = i_strdup("");
754 log_prefix_sent = FALSE;
755 }
756
i_get_failure_prefix(void)757 const char *i_get_failure_prefix(void)
758 {
759 return log_prefix != NULL ? log_prefix : "";
760 }
761
internal_send_split(string_t * full_str,size_t prefix_len)762 static int internal_send_split(string_t *full_str, size_t prefix_len)
763 {
764 /* This function splits the log line into PIPE_BUF sized blocks, so
765 the log process doesn't see partial lines. The log prefix is
766 repeated for each sent line. However, if the log prefix is
767 excessively long, we're still going to send the log lines even
768 if they are longer than PIPE_BUF. LINE_MIN_TEXT_LEN controls the
769 minimum number of bytes we're going to send of the actual log line
770 regardless of the log prefix length. (Alternative solution could be
771 to just forcibly split the line to PIPE_BUF length blocks without
772 repeating the log prefix for subsequent lines.) */
773 #define LINE_MIN_TEXT_LEN 128
774 #if LINE_MIN_TEXT_LEN >= PIPE_BUF
775 # error LINE_MIN_TEXT_LEN too large
776 #endif
777 string_t *str;
778 size_t max_text_len, pos = prefix_len;
779
780 str = t_str_new(PIPE_BUF);
781 str_append_data(str, str_data(full_str), prefix_len);
782 if (prefix_len < PIPE_BUF) {
783 max_text_len = I_MAX(PIPE_BUF - prefix_len - 1,
784 LINE_MIN_TEXT_LEN);
785 } else {
786 max_text_len = LINE_MIN_TEXT_LEN;
787 }
788
789 while (pos < str_len(full_str)) {
790 str_truncate(str, prefix_len);
791 str_append_max(str, str_c(full_str) + pos, max_text_len);
792 str_append_c(str, '\n');
793 if (log_fd_write(STDERR_FILENO,
794 str_data(str), str_len(str)) < 0)
795 return -1;
796 pos += max_text_len;
797 }
798 return 0;
799 }
800
801
line_parse_prefix(const char * line,enum log_type * log_type_r,bool * replace_prefix_r,bool * have_prefix_len_r)802 static bool line_parse_prefix(const char *line, enum log_type *log_type_r,
803 bool *replace_prefix_r, bool *have_prefix_len_r)
804 {
805 if (*line != 1)
806 return FALSE;
807
808 unsigned char log_type = (line[1] & 0x3f);
809 if (log_type == '\0') {
810 i_warning("Broken log line follows (type=NUL)");
811 return FALSE;
812 }
813 log_type--;
814
815 if (log_type > LOG_TYPE_OPTION) {
816 i_warning("Broken log line follows (type=%d)", log_type);
817 return FALSE;
818 }
819 *log_type_r = log_type;
820 *replace_prefix_r = (line[1] & LOG_TYPE_FLAG_DISABLE_LOG_PREFIX) != 0;
821 *have_prefix_len_r = (line[1] & LOG_TYPE_FLAG_PREFIX_LEN) != 0;
822 return TRUE;
823 }
824
i_failure_parse_line(const char * line,struct failure_line * failure)825 void i_failure_parse_line(const char *line, struct failure_line *failure)
826 {
827 bool have_prefix_len = FALSE;
828
829 i_zero(failure);
830 if (!line_parse_prefix(line, &failure->log_type,
831 &failure->disable_log_prefix,
832 &have_prefix_len)) {
833 failure->log_type = LOG_TYPE_ERROR;
834 failure->text = line;
835 return;
836 }
837
838 line += 2;
839 failure->text = line;
840 while (*line >= '0' && *line <= '9') {
841 failure->pid = failure->pid*10 + (*line - '0');
842 line++;
843 }
844 if (*line != ' ') {
845 /* some old protocol? */
846 failure->pid = 0;
847 return;
848 }
849 line++;
850
851 if (have_prefix_len) {
852 if (str_parse_uint(line, &failure->log_prefix_len, &line) < 0 ||
853 line[0] != ' ') {
854 /* unexpected, but ignore */
855 } else {
856 line++;
857 if (failure->log_prefix_len > strlen(line)) {
858 /* invalid */
859 failure->log_prefix_len = 0;
860 }
861 }
862 }
863 failure->text = line;
864 }
865
866 static void ATTR_NORETURN ATTR_FORMAT(2, 0)
i_internal_fatal_handler(const struct failure_context * ctx,const char * format,va_list args)867 i_internal_fatal_handler(const struct failure_context *ctx,
868 const char *format, va_list args)
869 {
870 failure_handler.v = &internal_handler_vfuncs;
871 failure_handler.fatal_err_reset = FATAL_LOGERROR;
872 fatal_handler_real(ctx, format, args);
873
874
875 }
876
877 static void
i_internal_error_handler(const struct failure_context * ctx,const char * format,va_list args)878 i_internal_error_handler(const struct failure_context *ctx,
879 const char *format, va_list args)
880 {
881 failure_handler.v = &internal_handler_vfuncs;
882 failure_handler.fatal_err_reset = FATAL_LOGERROR;
883 error_handler_real(ctx, format, args);
884 }
885
i_set_failure_internal(void)886 void i_set_failure_internal(void)
887 {
888 fd_set_nonblock(STDERR_FILENO, TRUE);
889 i_set_fatal_handler(i_internal_fatal_handler);
890 i_set_error_handler(i_internal_error_handler);
891 i_set_info_handler(i_internal_error_handler);
892 i_set_debug_handler(i_internal_error_handler);
893 }
894
i_failure_handler_is_internal(failure_callback_t * const callback)895 bool i_failure_handler_is_internal(failure_callback_t *const callback)
896 {
897 return callback == i_internal_fatal_handler ||
898 callback == i_internal_error_handler;
899 }
900
i_set_failure_ignore_errors(bool ignore)901 void i_set_failure_ignore_errors(bool ignore)
902 {
903 failure_ignore_errors = ignore;
904 }
905
i_set_info_file(const char * path)906 void i_set_info_file(const char *path)
907 {
908 if (log_info_fd == log_fd)
909 log_info_fd = STDERR_FILENO;
910
911 open_log_file(&log_info_fd, path);
912 info_handler = default_error_handler;
913 /* write debug-level messages to the info_log_path,
914 until i_set_debug_file() was called */
915 log_debug_fd = log_info_fd;
916 i_set_debug_handler(default_error_handler);
917 }
918
i_set_debug_file(const char * path)919 void i_set_debug_file(const char *path)
920 {
921 if (log_debug_fd == log_fd || log_debug_fd == log_info_fd)
922 log_debug_fd = STDERR_FILENO;
923
924 open_log_file(&log_debug_fd, path);
925 debug_handler = default_error_handler;
926 }
927
i_set_failure_timestamp_format(const char * fmt)928 void i_set_failure_timestamp_format(const char *fmt)
929 {
930 const char *p;
931
932 i_free(log_stamp_format);
933 i_free_and_null(log_stamp_format_suffix);
934
935 p = strstr(fmt, "%{usecs}");
936 if (p == NULL)
937 log_stamp_format = i_strdup(fmt);
938 else {
939 log_stamp_format = i_strdup_until(fmt, p);
940 log_stamp_format_suffix = i_strdup(p + 8);
941 }
942 }
943
i_set_failure_send_ip(const struct ip_addr * ip)944 void i_set_failure_send_ip(const struct ip_addr *ip)
945 {
946 i_failure_send_option("ip", net_ip2addr(ip));
947 }
948
i_set_failure_send_prefix(const char * prefix)949 void i_set_failure_send_prefix(const char *prefix)
950 {
951 i_failure_send_option("prefix", prefix);
952 }
953
i_set_failure_exit_callback(void (* callback)(int * status))954 void i_set_failure_exit_callback(void (*callback)(int *status))
955 {
956 failure_exit_callback = callback;
957 }
958
failures_deinit(void)959 void failures_deinit(void)
960 {
961 if (log_debug_fd == log_info_fd || log_debug_fd == log_fd)
962 log_debug_fd = STDERR_FILENO;
963
964 if (log_info_fd == log_fd)
965 log_info_fd = STDERR_FILENO;
966
967 if (log_fd != STDERR_FILENO) {
968 i_close_fd(&log_fd);
969 log_fd = STDERR_FILENO;
970 }
971
972 if (log_info_fd != STDERR_FILENO) {
973 i_close_fd(&log_info_fd);
974 log_info_fd = STDERR_FILENO;
975 }
976
977 if (log_debug_fd != STDERR_FILENO) {
978 i_close_fd(&log_debug_fd);
979 log_debug_fd = STDERR_FILENO;
980 }
981
982 i_free_and_null(log_prefix);
983 i_free_and_null(log_stamp_format);
984 i_free_and_null(log_stamp_format_suffix);
985 }
986