Coverage Report

Created: 2023-11-19 07:06

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