Coverage Report

Created: 2025-10-23 06:55

next uncovered line (L), next uncovered region (R), next uncovered branch (B)
/src/frr/lib/zlog.c
Line
Count
Source
1
// SPDX-License-Identifier: ISC
2
/*
3
 * Copyright (c) 2015-19  David Lamparter, for NetDEF, Inc.
4
 */
5
6
#include "zebra.h"
7
8
#include <unistd.h>
9
#include <sys/time.h>
10
#include <sys/mman.h>
11
#include <sys/types.h>
12
#include <time.h>
13
#include <stdlib.h>
14
#include <stdio.h>
15
#include <string.h>
16
#include <stdarg.h>
17
#include <pthread.h>
18
19
/* gettid() & co. */
20
#ifdef HAVE_PTHREAD_NP_H
21
#include <pthread_np.h>
22
#endif
23
#ifdef linux
24
#include <sys/syscall.h>
25
#endif
26
#ifdef __FreeBSD__
27
#include <sys/thr.h>
28
#endif
29
#ifdef __NetBSD__
30
#include <lwp.h>
31
#endif
32
#ifdef __DragonFly__
33
#include <sys/lwp.h>
34
#endif
35
#ifdef __APPLE__
36
#include <mach/mach_traps.h>
37
#endif
38
39
#ifdef HAVE_LIBUNWIND
40
#define UNW_LOCAL_ONLY
41
#include <libunwind.h>
42
#include <dlfcn.h>
43
#endif
44
45
#include "memory.h"
46
#include "atomlist.h"
47
#include "printfrr.h"
48
#include "frrcu.h"
49
#include "zlog.h"
50
#include "libfrr_trace.h"
51
#include "frrevent.h"
52
53
8
DEFINE_MTYPE_STATIC(LIB, LOG_MESSAGE,  "log message");
54
8
DEFINE_MTYPE_STATIC(LIB, LOG_TLSBUF,   "log thread-local buffer");
55
8
56
8
DEFINE_HOOK(zlog_init, (const char *progname, const char *protoname,
57
8
      unsigned short instance, uid_t uid, gid_t gid),
58
8
           (progname, protoname, instance, uid, gid));
59
8
DEFINE_KOOH(zlog_fini, (), ());
60
8
DEFINE_HOOK(zlog_aux_init, (const char *prefix, int prio_min),
61
8
         (prefix, prio_min));
62
8
63
8
char zlog_prefix[128];
64
8
size_t zlog_prefixsz;
65
8
int zlog_tmpdirfd = -1;
66
8
int zlog_instance = -1;
67
8
68
8
static atomic_bool zlog_ec = true, zlog_xid = true;
69
8
70
8
/* these are kept around because logging is initialized (and directories
71
8
 * & files created) before zprivs code switches to the FRR user;  therefore
72
8
 * we need to chown() things so we don't get permission errors later when
73
8
 * trying to delete things on shutdown
74
8
 */
75
8
static uid_t zlog_uid = -1;
76
8
static gid_t zlog_gid = -1;
77
8
78
7.60k
DECLARE_ATOMLIST(zlog_targets, struct zlog_target, head);
zlog.c:zlog_targets_next_safe
Line
Count
Source
78
DECLARE_ATOMLIST(zlog_targets, struct zlog_target, head);
zlog.c:zlog_targets_first
Line
Count
Source
78
DECLARE_ATOMLIST(zlog_targets, struct zlog_target, head);
zlog.c:zlog_targets_next
Line
Count
Source
78
DECLARE_ATOMLIST(zlog_targets, struct zlog_target, head);
Unexecuted instantiation: zlog.c:zlog_targets_del
79
static struct zlog_targets_head zlog_targets;
80
81
/* Global setting for buffered vs immediate output. The default is
82
 * per-pthread buffering.
83
 */
84
static bool default_immediate;
85
86
/* cf. zlog.h for additional comments on this struct.
87
 *
88
 * Note: you MUST NOT pass the format string + va_list to non-FRR format
89
 * string functions (e.g. vsyslog, sd_journal_printv, ...) since FRR uses an
90
 * extended prinf() with additional formats (%pI4 and the like).
91
 *
92
 * Also remember to use va_copy() on args.
93
 */
94
95
struct zlog_msg {
96
  struct timespec ts;
97
  int prio;
98
99
  const char *fmt;
100
  va_list args;
101
  const struct xref_logmsg *xref;
102
103
  char *stackbuf;
104
  size_t stackbufsz;
105
  char *text;
106
  size_t textlen;
107
  size_t hdrlen;
108
109
  /* This is always ISO8601 with sub-second precision 9 here, it's
110
   * converted for callers as needed.  ts_dot points to the "."
111
   * separating sub-seconds.  ts_zonetail is "Z" or "+00:00" for the
112
   * local time offset.
113
   *
114
   * Valid if ZLOG_TS_ISO8601 is set.
115
   * (0 if timestamp has not been formatted yet)
116
   */
117
  char ts_str[32], *ts_dot, ts_zonetail[8];
118
  uint32_t ts_flags;
119
120
  /* "mmm dd hh:mm:ss" for 3164 legacy syslog - too dissimilar from
121
   * the above, so just kept separately here.
122
   */
123
  uint32_t ts_3164_flags;
124
  char ts_3164_str[16];
125
126
  /* at the time of writing, 16 args was the actual maximum of arguments
127
   * to a single zlog call.  Particularly printing flag bitmasks seems
128
   * to drive this.  That said, the overhead of dynamically sizing this
129
   * probably outweighs the value.  If anything, a printfrr extension
130
   * for printing flag bitmasks might be a good idea.
131
   */
132
  struct fmt_outpos argpos[24];
133
  size_t n_argpos;
134
};
135
136
/* thread-local log message buffering
137
 *
138
 * This is strictly optional and set up by calling zlog_tls_buffer_init()
139
 * on a particular thread.
140
 *
141
 * If in use, this will create a temporary file in /var/tmp which is used as
142
 * memory-mapped MAP_SHARED log message buffer.  The idea there is that buffer
143
 * access doesn't require any syscalls, but in case of a crash the kernel
144
 * knows to sync the memory back to disk.  This way the user can still get the
145
 * last log messages if there were any left unwritten in the buffer.
146
 *
147
 * Sizing this dynamically isn't particularly useful, so here's an 8k buffer
148
 * with a message limit of 64 messages.  Message metadata (e.g. priority,
149
 * timestamp) aren't in the mmap region, so they're lost on crash, but we can
150
 * live with that.
151
 */
152
153
#if defined(HAVE_OPENAT) && defined(HAVE_UNLINKAT)
154
#define CAN_DO_TLS 1
155
#endif
156
157
1.52k
#define TLS_LOG_BUF_SIZE  8192
158
#define TLS_LOG_MAXMSG    64
159
160
struct zlog_tls {
161
  char *mmbuf;
162
  size_t bufpos;
163
  bool do_unlink;
164
165
  size_t nmsgs;
166
  struct zlog_msg msgs[TLS_LOG_MAXMSG];
167
  struct zlog_msg *msgp[TLS_LOG_MAXMSG];
168
};
169
170
static inline void zlog_tls_free(void *arg);
171
172
/* proper ELF TLS is a bit faster than pthread_[gs]etspecific, so if it's
173
 * available we'll use it here
174
 */
175
176
#ifdef __OpenBSD__
177
static pthread_key_t zlog_tls_key;
178
179
static void zlog_tls_key_init(void) __attribute__((_CONSTRUCTOR(500)));
180
static void zlog_tls_key_init(void)
181
{
182
  pthread_key_create(&zlog_tls_key, zlog_tls_free);
183
}
184
185
static void zlog_tls_key_fini(void) __attribute__((_DESTRUCTOR(500)));
186
static void zlog_tls_key_fini(void)
187
{
188
  pthread_key_delete(zlog_tls_key);
189
}
190
191
static inline struct zlog_tls *zlog_tls_get(void)
192
{
193
  return pthread_getspecific(zlog_tls_key);
194
}
195
196
static inline void zlog_tls_set(struct zlog_tls *val)
197
{
198
  pthread_setspecific(zlog_tls_key, val);
199
}
200
#else
201
# ifndef thread_local
202
#  define thread_local __thread
203
# endif
204
205
static thread_local struct zlog_tls *zlog_tls_var
206
  __attribute__((tls_model("initial-exec")));
207
208
static inline struct zlog_tls *zlog_tls_get(void)
209
3.04k
{
210
3.04k
  return zlog_tls_var;
211
3.04k
}
212
213
static inline void zlog_tls_set(struct zlog_tls *val)
214
4
{
215
4
  zlog_tls_var = val;
216
4
}
217
#endif
218
219
#ifdef CAN_DO_TLS
220
static intmax_t zlog_gettid(void)
221
4
{
222
4
#ifndef __OpenBSD__
223
  /* accessing a TLS variable is much faster than a syscall */
224
4
  static thread_local intmax_t cached_tid = -1;
225
4
  if (cached_tid != -1)
226
0
    return cached_tid;
227
4
#endif
228
229
4
  long rv = -1;
230
#ifdef HAVE_PTHREAD_GETTHREADID_NP
231
  rv = pthread_getthreadid_np();
232
#elif defined(linux)
233
4
  rv = syscall(__NR_gettid);
234
#elif defined(__NetBSD__)
235
  rv = _lwp_self();
236
#elif defined(__FreeBSD__)
237
  thr_self(&rv);
238
#elif defined(__DragonFly__)
239
  rv = lwp_gettid();
240
#elif defined(__OpenBSD__)
241
  rv = getthrid();
242
#elif defined(__sun)
243
  rv = pthread_self();
244
#elif defined(__APPLE__)
245
  rv = mach_thread_self();
246
  mach_port_deallocate(mach_task_self(), rv);
247
#endif
248
249
4
#ifndef __OpenBSD__
250
4
  cached_tid = rv;
251
4
#endif
252
4
  return rv;
253
4
}
254
255
void zlog_tls_buffer_init(void)
256
4
{
257
4
  struct zlog_tls *zlog_tls;
258
4
  char mmpath[MAXPATHLEN];
259
4
  int mmfd;
260
4
  size_t i;
261
262
4
  zlog_tls = zlog_tls_get();
263
264
4
  if (zlog_tls || zlog_tmpdirfd < 0)
265
0
    return;
266
267
4
  zlog_tls = XCALLOC(MTYPE_LOG_TLSBUF, sizeof(*zlog_tls));
268
260
  for (i = 0; i < array_size(zlog_tls->msgp); i++)
269
256
    zlog_tls->msgp[i] = &zlog_tls->msgs[i];
270
271
4
  snprintfrr(mmpath, sizeof(mmpath), "logbuf.%jd", zlog_gettid());
272
273
4
  mmfd = openat(zlog_tmpdirfd, mmpath,
274
4
          O_RDWR | O_CREAT | O_EXCL | O_CLOEXEC, 0600);
275
4
  if (mmfd < 0) {
276
0
    zlog_err("failed to open thread log buffer \"%s\": %s",
277
0
       mmpath, strerror(errno));
278
0
    goto out_anon;
279
0
  }
280
4
  fchown(mmfd, zlog_uid, zlog_gid);
281
282
4
#ifdef HAVE_POSIX_FALLOCATE
283
4
  if (posix_fallocate(mmfd, 0, TLS_LOG_BUF_SIZE) != 0)
284
  /* note next statement is under above if() */
285
0
#endif
286
0
  if (ftruncate(mmfd, TLS_LOG_BUF_SIZE) < 0) {
287
0
    zlog_err("failed to allocate thread log buffer \"%s\": %s",
288
0
       mmpath, strerror(errno));
289
0
    goto out_anon_unlink;
290
0
  }
291
292
4
  zlog_tls->mmbuf = mmap(NULL, TLS_LOG_BUF_SIZE, PROT_READ | PROT_WRITE,
293
4
            MAP_SHARED, mmfd, 0);
294
4
  if (zlog_tls->mmbuf == MAP_FAILED) {
295
0
    zlog_err("failed to mmap thread log buffer \"%s\": %s",
296
0
       mmpath, strerror(errno));
297
0
    goto out_anon_unlink;
298
0
  }
299
4
  zlog_tls->do_unlink = true;
300
301
4
  close(mmfd);
302
4
  zlog_tls_set(zlog_tls);
303
4
  return;
304
305
0
out_anon_unlink:
306
0
  unlinkat(zlog_tmpdirfd, mmpath, 0);
307
0
  close(mmfd);
308
0
out_anon:
309
310
#ifndef MAP_ANONYMOUS
311
#define MAP_ANONYMOUS MAP_ANON
312
#endif
313
0
  zlog_tls->mmbuf = mmap(NULL, TLS_LOG_BUF_SIZE, PROT_READ | PROT_WRITE,
314
0
            MAP_ANONYMOUS | MAP_PRIVATE, -1, 0);
315
316
0
  if (!zlog_tls->mmbuf) {
317
0
    zlog_err("failed to anonymous-mmap thread log buffer: %s",
318
0
       strerror(errno));
319
0
    XFREE(MTYPE_LOG_TLSBUF, zlog_tls);
320
0
    zlog_tls_set(NULL);
321
0
    return;
322
0
  }
323
324
0
  zlog_tls_set(zlog_tls);
325
0
}
326
327
void zlog_tls_buffer_fini(void)
328
0
{
329
0
  char mmpath[MAXPATHLEN];
330
0
  struct zlog_tls *zlog_tls = zlog_tls_get();
331
0
  bool do_unlink = zlog_tls ? zlog_tls->do_unlink : false;
332
333
0
  zlog_tls_buffer_flush();
334
335
0
  zlog_tls_free(zlog_tls);
336
0
  zlog_tls_set(NULL);
337
338
0
  snprintfrr(mmpath, sizeof(mmpath), "logbuf.%jd", zlog_gettid());
339
0
  if (do_unlink && unlinkat(zlog_tmpdirfd, mmpath, 0))
340
0
    zlog_err("unlink logbuf: %s (%d)", strerror(errno), errno);
341
0
}
342
343
#else /* !CAN_DO_TLS */
344
void zlog_tls_buffer_init(void)
345
{
346
}
347
348
void zlog_tls_buffer_fini(void)
349
{
350
}
351
#endif
352
353
void zlog_msg_pid(struct zlog_msg *msg, intmax_t *pid, intmax_t *tid)
354
0
{
355
0
#ifndef __OpenBSD__
356
0
  static thread_local intmax_t cached_pid = -1;
357
0
  if (cached_pid != -1)
358
0
    *pid = cached_pid;
359
0
  else
360
0
    cached_pid = *pid = (intmax_t)getpid();
361
#else
362
  *pid = (intmax_t)getpid();
363
#endif
364
0
#ifdef CAN_DO_TLS
365
0
  *tid = zlog_gettid();
366
#else
367
  *tid = *pid;
368
#endif
369
0
}
370
371
static inline void zlog_tls_free(void *arg)
372
0
{
373
0
  struct zlog_tls *zlog_tls = arg;
374
375
0
  if (!zlog_tls)
376
0
    return;
377
378
0
  munmap(zlog_tls->mmbuf, TLS_LOG_BUF_SIZE);
379
0
  XFREE(MTYPE_LOG_TLSBUF, zlog_tls);
380
0
}
381
382
void zlog_tls_buffer_flush(void)
383
1.52k
{
384
1.52k
  struct zlog_target *zt;
385
1.52k
  struct zlog_tls *zlog_tls = zlog_tls_get();
386
387
1.52k
  if (!zlog_tls)
388
0
    return;
389
1.52k
  if (!zlog_tls->nmsgs)
390
0
    return;
391
392
1.52k
  rcu_read_lock();
393
1.52k
  frr_each_safe (zlog_targets, &zlog_targets, zt) {
394
1.52k
    if (!zt->logfn)
395
0
      continue;
396
397
1.52k
    zt->logfn(zt, zlog_tls->msgp, zlog_tls->nmsgs);
398
1.52k
  }
399
1.52k
  rcu_read_unlock();
400
401
1.52k
  zlog_tls->bufpos = 0;
402
1.52k
  zlog_tls->nmsgs = 0;
403
1.52k
}
404
405
406
static void vzlog_notls(const struct xref_logmsg *xref, int prio,
407
      const char *fmt, va_list ap)
408
0
{
409
0
  struct zlog_target *zt;
410
0
  struct zlog_msg stackmsg = {
411
0
    .prio = prio & LOG_PRIMASK,
412
0
    .fmt = fmt,
413
0
    .xref = xref,
414
0
  }, *msg = &stackmsg;
415
0
  char stackbuf[512];
416
417
0
  clock_gettime(CLOCK_REALTIME, &msg->ts);
418
0
  va_copy(msg->args, ap);
419
0
  msg->stackbuf = stackbuf;
420
0
  msg->stackbufsz = sizeof(stackbuf);
421
422
0
  rcu_read_lock();
423
0
  frr_each_safe (zlog_targets, &zlog_targets, zt) {
424
0
    if (prio > zt->prio_min)
425
0
      continue;
426
0
    if (!zt->logfn)
427
0
      continue;
428
429
0
    zt->logfn(zt, &msg, 1);
430
0
  }
431
0
  rcu_read_unlock();
432
433
0
  va_end(msg->args);
434
0
  if (msg->text && msg->text != stackbuf)
435
0
    XFREE(MTYPE_LOG_MESSAGE, msg->text);
436
0
}
437
438
static void vzlog_tls(struct zlog_tls *zlog_tls, const struct xref_logmsg *xref,
439
          int prio, const char *fmt, va_list ap)
440
1.52k
{
441
1.52k
  struct zlog_target *zt;
442
1.52k
  struct zlog_msg *msg;
443
1.52k
  char *buf;
444
1.52k
  bool ignoremsg = true;
445
1.52k
  bool immediate = default_immediate;
446
447
  /* avoid further processing cost if no target wants this message */
448
1.52k
  rcu_read_lock();
449
1.52k
  frr_each (zlog_targets, &zlog_targets, zt) {
450
1.52k
    if (prio > zt->prio_min)
451
0
      continue;
452
1.52k
    ignoremsg = false;
453
1.52k
    break;
454
1.52k
  }
455
1.52k
  rcu_read_unlock();
456
457
1.52k
  if (ignoremsg)
458
0
    return;
459
460
1.52k
  msg = &zlog_tls->msgs[zlog_tls->nmsgs];
461
1.52k
  zlog_tls->nmsgs++;
462
1.52k
  if (zlog_tls->nmsgs == array_size(zlog_tls->msgs))
463
0
    immediate = true;
464
465
1.52k
  memset(msg, 0, sizeof(*msg));
466
1.52k
  clock_gettime(CLOCK_REALTIME, &msg->ts);
467
1.52k
  va_copy(msg->args, ap);
468
1.52k
  msg->stackbuf = buf = zlog_tls->mmbuf + zlog_tls->bufpos;
469
1.52k
  msg->stackbufsz = TLS_LOG_BUF_SIZE - zlog_tls->bufpos - 1;
470
1.52k
  msg->fmt = fmt;
471
1.52k
  msg->prio = prio & LOG_PRIMASK;
472
1.52k
  msg->xref = xref;
473
1.52k
  if (msg->prio < LOG_INFO)
474
1.52k
    immediate = true;
475
476
1.52k
  if (!immediate) {
477
    /* messages written later need to take the formatting cost
478
     * immediately since we can't hold a reference on varargs
479
     */
480
0
    zlog_msg_text(msg, NULL);
481
482
0
    if (msg->text != buf)
483
      /* zlog_msg_text called malloc() on us :( */
484
0
      immediate = true;
485
0
    else {
486
0
      zlog_tls->bufpos += msg->textlen + 1;
487
      /* write a second \0 to mark current end position
488
       * (in case of crash this signals end of unwritten log
489
       * messages in mmap'd logbuf file)
490
       */
491
0
      zlog_tls->mmbuf[zlog_tls->bufpos] = '\0';
492
493
      /* avoid malloc() for next message */
494
0
      if (TLS_LOG_BUF_SIZE - zlog_tls->bufpos < 256)
495
0
        immediate = true;
496
0
    }
497
0
  }
498
499
1.52k
  if (immediate)
500
1.52k
    zlog_tls_buffer_flush();
501
502
1.52k
  va_end(msg->args);
503
1.52k
  if (msg->text && msg->text != buf)
504
0
    XFREE(MTYPE_LOG_MESSAGE, msg->text);
505
1.52k
}
506
507
static void zlog_backtrace_msg(const struct xref_logmsg *xref, int prio)
508
0
{
509
0
  struct event *tc = pthread_getspecific(thread_current);
510
0
  const char *uid = xref->xref.xrefdata->uid;
511
0
  bool found_thread = false;
512
513
0
  zlog(prio, "| (%s) message in thread %jd, at %s(), %s:%d", uid,
514
0
       zlog_gettid(), xref->xref.func, xref->xref.file, xref->xref.line);
515
516
#ifdef HAVE_LIBUNWIND
517
  const char *threadfunc = tc ? tc->xref->funcname : NULL;
518
  bool found_caller = false;
519
  unw_cursor_t cursor;
520
  unw_context_t uc;
521
  unw_word_t ip, off, sp;
522
  Dl_info dlinfo;
523
524
  unw_getcontext(&uc);
525
526
  unw_init_local(&cursor, &uc);
527
  while (unw_step(&cursor) > 0) {
528
    char buf[96], name[128] = "?";
529
    bool is_thread = false;
530
531
    unw_get_reg(&cursor, UNW_REG_IP, &ip);
532
    unw_get_reg(&cursor, UNW_REG_SP, &sp);
533
534
    if (unw_is_signal_frame(&cursor))
535
      zlog(prio, "| (%s)    ---- signal ----", uid);
536
537
    if (!unw_get_proc_name(&cursor, buf, sizeof(buf), &off)) {
538
      if (!strcmp(buf, xref->xref.func))
539
        found_caller = true;
540
      if (threadfunc && !strcmp(buf, threadfunc))
541
        found_thread = is_thread = true;
542
543
      snprintf(name, sizeof(name), "%s+%#lx", buf, (long)off);
544
    }
545
546
    if (!found_caller)
547
      continue;
548
549
    if (dladdr((void *)ip, &dlinfo))
550
      zlog(prio, "| (%s) %-36s %16lx+%08lx %16lx %s", uid,
551
           name, (long)dlinfo.dli_fbase,
552
           (long)ip - (long)dlinfo.dli_fbase, (long)sp,
553
           dlinfo.dli_fname);
554
    else
555
      zlog(prio, "| (%s) %-36s %16lx %16lx", uid, name,
556
           (long)ip, (long)sp);
557
558
    if (is_thread)
559
      zlog(prio, "| (%s) ^- scheduled from %s(), %s:%u", uid,
560
           tc->xref->xref.func, tc->xref->xref.file,
561
           tc->xref->xref.line);
562
  }
563
#elif defined(HAVE_GLIBC_BACKTRACE)
564
  void *frames[64];
565
0
  char **names = NULL;
566
0
  int n_frames, i;
567
568
0
  n_frames = backtrace(frames, array_size(frames));
569
0
  if (n_frames < 0)
570
0
    n_frames = 0;
571
0
  if (n_frames)
572
0
    names = backtrace_symbols(frames, n_frames);
573
574
0
  for (i = 0; i < n_frames; i++) {
575
0
    void *retaddr = frames[i];
576
0
    char *loc = names[i];
577
578
0
    zlog(prio, "| (%s) %16lx %-36s", uid, (long)retaddr, loc);
579
0
  }
580
0
  free(names);
581
0
#endif
582
0
  if (!found_thread && tc)
583
0
    zlog(prio, "| (%s) scheduled from %s(), %s:%u", uid,
584
0
         tc->xref->xref.func, tc->xref->xref.file,
585
0
         tc->xref->xref.line);
586
0
}
587
588
void vzlogx(const struct xref_logmsg *xref, int prio,
589
      const char *fmt, va_list ap)
590
1.52k
{
591
1.52k
  struct zlog_tls *zlog_tls = zlog_tls_get();
592
593
#ifdef HAVE_LTTNG
594
  va_list copy;
595
  va_copy(copy, ap);
596
  char *msg = vasprintfrr(MTYPE_LOG_MESSAGE, fmt, copy);
597
598
  switch (prio) {
599
  case LOG_ERR:
600
    frrtracelog(TRACE_ERR, msg);
601
    break;
602
  case LOG_WARNING:
603
    frrtracelog(TRACE_WARNING, msg);
604
    break;
605
  case LOG_DEBUG:
606
    frrtracelog(TRACE_DEBUG, msg);
607
    break;
608
  case LOG_NOTICE:
609
    frrtracelog(TRACE_DEBUG, msg);
610
    break;
611
  case LOG_INFO:
612
  default:
613
    frrtracelog(TRACE_INFO, msg);
614
    break;
615
  }
616
617
  va_end(copy);
618
  XFREE(MTYPE_LOG_MESSAGE, msg);
619
#endif
620
621
1.52k
  if (zlog_tls)
622
1.52k
    vzlog_tls(zlog_tls, xref, prio, fmt, ap);
623
0
  else
624
0
    vzlog_notls(xref, prio, fmt, ap);
625
626
1.52k
  if (xref) {
627
0
    struct xrefdata_logmsg *xrdl;
628
629
0
    xrdl = container_of(xref->xref.xrefdata, struct xrefdata_logmsg,
630
0
            xrefdata);
631
0
    if (xrdl->fl_print_bt)
632
0
      zlog_backtrace_msg(xref, prio);
633
0
  }
634
1.52k
}
635
636
void zlog_sigsafe(const char *text, size_t len)
637
0
{
638
0
  struct zlog_target *zt;
639
0
  const char *end = text + len, *nlpos;
640
641
0
  while (text < end) {
642
0
    nlpos = memchr(text, '\n', end - text);
643
0
    if (!nlpos)
644
0
      nlpos = end;
645
646
0
    frr_each (zlog_targets, &zlog_targets, zt) {
647
0
      if (LOG_CRIT > zt->prio_min)
648
0
        continue;
649
0
      if (!zt->logfn_sigsafe)
650
0
        continue;
651
652
0
      zt->logfn_sigsafe(zt, text, nlpos - text);
653
0
    }
654
655
0
    if (nlpos == end)
656
0
      break;
657
0
    text = nlpos + 1;
658
0
  }
659
0
}
660
661
void _zlog_assert_failed(const struct xref_assert *xref, const char *extra, ...)
662
0
{
663
0
  va_list ap;
664
0
  static bool assert_in_assert; /* "global-ish" variable, init to 0 */
665
666
0
  if (assert_in_assert)
667
0
    abort();
668
0
  assert_in_assert = true;
669
670
0
  if (extra) {
671
0
    struct va_format vaf;
672
673
0
    va_start(ap, extra);
674
0
    vaf.fmt = extra;
675
0
    vaf.va = &ap;
676
677
0
    zlog(LOG_CRIT,
678
0
         "%s:%d: %s(): assertion (%s) failed, extra info: %pVA",
679
0
         xref->xref.file, xref->xref.line, xref->xref.func,
680
0
         xref->expr, &vaf);
681
682
0
    va_end(ap);
683
0
  } else
684
0
    zlog(LOG_CRIT, "%s:%d: %s(): assertion (%s) failed",
685
0
         xref->xref.file, xref->xref.line, xref->xref.func,
686
0
         xref->expr);
687
688
  /* abort() prints backtrace & memstats in SIGABRT handler */
689
0
  abort();
690
0
}
691
692
int zlog_msg_prio(struct zlog_msg *msg)
693
1.52k
{
694
1.52k
  return msg->prio;
695
1.52k
}
696
697
const struct xref_logmsg *zlog_msg_xref(struct zlog_msg *msg)
698
0
{
699
0
  return msg->xref;
700
0
}
701
702
const char *zlog_msg_text(struct zlog_msg *msg, size_t *textlen)
703
1.52k
{
704
1.52k
  if (!msg->text) {
705
1.52k
    va_list args;
706
1.52k
    bool do_xid, do_ec;
707
1.52k
    size_t need = 0, hdrlen;
708
1.52k
    struct fbuf fb = {
709
1.52k
      .buf = msg->stackbuf,
710
1.52k
      .pos = msg->stackbuf,
711
1.52k
      .len = msg->stackbufsz,
712
1.52k
    };
713
714
1.52k
    do_ec = atomic_load_explicit(&zlog_ec, memory_order_relaxed);
715
1.52k
    do_xid = atomic_load_explicit(&zlog_xid, memory_order_relaxed);
716
717
1.52k
    if (msg->xref && do_xid && msg->xref->xref.xrefdata->uid[0]) {
718
0
      need += bputch(&fb, '[');
719
0
      need += bputs(&fb, msg->xref->xref.xrefdata->uid);
720
0
      need += bputch(&fb, ']');
721
0
    }
722
1.52k
    if (msg->xref && do_ec && msg->xref->ec)
723
0
      need += bprintfrr(&fb, "[EC %u]", msg->xref->ec);
724
1.52k
    if (need)
725
0
      need += bputch(&fb, ' ');
726
727
1.52k
    msg->hdrlen = hdrlen = need;
728
1.52k
    assert(hdrlen < msg->stackbufsz);
729
730
1.52k
    fb.outpos = msg->argpos;
731
1.52k
    fb.outpos_n = array_size(msg->argpos);
732
1.52k
    fb.outpos_i = 0;
733
734
1.52k
    va_copy(args, msg->args);
735
1.52k
#pragma GCC diagnostic push
736
1.52k
#pragma GCC diagnostic ignored "-Wformat-nonliteral"
737
    /* format-string checking is done further up the chain */
738
1.52k
    need += vbprintfrr(&fb, msg->fmt, args);
739
1.52k
#pragma GCC diagnostic pop
740
1.52k
    va_end(args);
741
742
1.52k
    msg->textlen = need;
743
1.52k
    need += bputch(&fb, '\n');
744
745
1.52k
    if (need <= msg->stackbufsz)
746
1.52k
      msg->text = msg->stackbuf;
747
0
    else {
748
0
      msg->text = XMALLOC(MTYPE_LOG_MESSAGE, need);
749
750
0
      memcpy(msg->text, msg->stackbuf, hdrlen);
751
752
0
      fb.buf = msg->text;
753
0
      fb.len = need;
754
0
      fb.pos = msg->text + hdrlen;
755
0
      fb.outpos_i = 0;
756
757
0
      va_copy(args, msg->args);
758
0
#pragma GCC diagnostic push
759
0
#pragma GCC diagnostic ignored "-Wformat-nonliteral"
760
      /* same as above */
761
0
      vbprintfrr(&fb, msg->fmt, args);
762
0
#pragma GCC diagnostic pop
763
0
      va_end(args);
764
765
0
      bputch(&fb, '\n');
766
0
    }
767
768
1.52k
    msg->n_argpos = fb.outpos_i;
769
1.52k
  }
770
1.52k
  if (textlen)
771
1.52k
    *textlen = msg->textlen;
772
1.52k
  return msg->text;
773
1.52k
}
774
775
void zlog_msg_args(struct zlog_msg *msg, size_t *hdrlen, size_t *n_argpos,
776
       const struct fmt_outpos **argpos)
777
0
{
778
0
  if (!msg->text)
779
0
    zlog_msg_text(msg, NULL);
780
781
0
  if (hdrlen)
782
0
    *hdrlen = msg->hdrlen;
783
0
  if (n_argpos)
784
0
    *n_argpos = msg->n_argpos;
785
0
  if (argpos)
786
0
    *argpos = msg->argpos;
787
0
}
788
789
3.04k
#define ZLOG_TS_FORMAT    (ZLOG_TS_ISO8601 | ZLOG_TS_LEGACY)
790
#define ZLOG_TS_FLAGS   ~ZLOG_TS_PREC
791
792
size_t zlog_msg_ts(struct zlog_msg *msg, struct fbuf *out, uint32_t flags)
793
1.52k
{
794
1.52k
  size_t outsz = out ? (out->buf + out->len - out->pos) : 0;
795
1.52k
  size_t len1;
796
797
1.52k
  if (!(flags & ZLOG_TS_FORMAT))
798
0
    return 0;
799
800
1.52k
  if (!(msg->ts_flags & ZLOG_TS_FORMAT) ||
801
1.52k
      ((msg->ts_flags ^ flags) & ZLOG_TS_UTC)) {
802
1.52k
    struct tm tm;
803
804
1.52k
    if (flags & ZLOG_TS_UTC)
805
0
      gmtime_r(&msg->ts.tv_sec, &tm);
806
1.52k
    else
807
1.52k
      localtime_r(&msg->ts.tv_sec, &tm);
808
809
1.52k
    strftime(msg->ts_str, sizeof(msg->ts_str),
810
1.52k
       "%Y-%m-%dT%H:%M:%S", &tm);
811
812
1.52k
    if (flags & ZLOG_TS_UTC) {
813
0
      msg->ts_zonetail[0] = 'Z';
814
0
      msg->ts_zonetail[1] = '\0';
815
0
    } else
816
1.52k
      snprintfrr(msg->ts_zonetail, sizeof(msg->ts_zonetail),
817
1.52k
           "%+03d:%02d",
818
1.52k
           (int)(tm.tm_gmtoff / 3600),
819
1.52k
           (int)(labs(tm.tm_gmtoff) / 60) % 60);
820
821
1.52k
    msg->ts_dot = msg->ts_str + strlen(msg->ts_str);
822
1.52k
    snprintfrr(msg->ts_dot,
823
1.52k
         msg->ts_str + sizeof(msg->ts_str) - msg->ts_dot,
824
1.52k
         ".%09lu", (unsigned long)msg->ts.tv_nsec);
825
826
1.52k
    msg->ts_flags = ZLOG_TS_ISO8601 | (flags & ZLOG_TS_UTC);
827
1.52k
  }
828
829
1.52k
  len1 = flags & ZLOG_TS_PREC;
830
1.52k
  len1 = (msg->ts_dot - msg->ts_str) + (len1 ? len1 + 1 : 0);
831
832
1.52k
  if (len1 > strlen(msg->ts_str))
833
0
    len1 = strlen(msg->ts_str);
834
835
1.52k
  if (flags & ZLOG_TS_LEGACY) {
836
1.52k
    if (!out)
837
0
      return len1;
838
839
1.52k
    if (len1 > outsz) {
840
0
      memset(out->pos, 0, outsz);
841
0
      out->pos += outsz;
842
0
      return len1;
843
0
    }
844
845
    /* just swap out the formatting, faster than redoing it */
846
30.4k
    for (char *p = msg->ts_str; p < msg->ts_str + len1; p++) {
847
28.8k
      switch (*p) {
848
3.04k
      case '-':
849
3.04k
        *out->pos++ = '/';
850
3.04k
        break;
851
1.52k
      case 'T':
852
1.52k
        *out->pos++ = ' ';
853
1.52k
        break;
854
24.3k
      default:
855
24.3k
        *out->pos++ = *p;
856
28.8k
      }
857
28.8k
    }
858
1.52k
    return len1;
859
1.52k
  } else {
860
0
    size_t len2 = strlen(msg->ts_zonetail);
861
862
0
    if (!out)
863
0
      return len1 + len2;
864
865
0
    if (len1 + len2 > outsz) {
866
0
      memset(out->pos, 0, outsz);
867
0
      out->pos += outsz;
868
0
      return len1 + len2;
869
0
    }
870
871
0
    memcpy(out->pos, msg->ts_str, len1);
872
0
    out->pos += len1;
873
0
    memcpy(out->pos, msg->ts_zonetail, len2);
874
0
    out->pos += len2;
875
0
    return len1 + len2;
876
0
  }
877
1.52k
}
878
879
size_t zlog_msg_ts_3164(struct zlog_msg *msg, struct fbuf *out, uint32_t flags)
880
0
{
881
0
  flags &= ZLOG_TS_UTC;
882
883
0
  if (!msg->ts_3164_str[0] || flags != msg->ts_3164_flags) {
884
    /* these are "hardcoded" in RFC3164, so they're here too... */
885
0
    static const char *const months[12] = {
886
0
      "Jan", "Feb", "Mar", "Apr", "May", "Jun",
887
0
      "Jul", "Aug", "Sep", "Oct", "Nov", "Dec",
888
0
    };
889
0
    struct tm tm;
890
891
    /* RFC3164 explicitly asks for local time, but common usage
892
     * also includes UTC.
893
     */
894
0
    if (flags & ZLOG_TS_UTC)
895
0
      gmtime_r(&msg->ts.tv_sec, &tm);
896
0
    else
897
0
      localtime_r(&msg->ts.tv_sec, &tm);
898
899
0
    snprintfrr(msg->ts_3164_str, sizeof(msg->ts_3164_str),
900
0
         "%3s %2d %02d:%02d:%02d", months[tm.tm_mon],
901
0
         tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec);
902
903
0
    msg->ts_3164_flags = flags;
904
0
  }
905
0
  return bputs(out, msg->ts_3164_str);
906
0
}
907
908
void zlog_msg_tsraw(struct zlog_msg *msg, struct timespec *ts)
909
0
{
910
0
  memcpy(ts, &msg->ts, sizeof(*ts));
911
0
}
912
913
void zlog_set_prefix_ec(bool enable)
914
4
{
915
4
  atomic_store_explicit(&zlog_ec, enable, memory_order_relaxed);
916
4
}
917
918
bool zlog_get_prefix_ec(void)
919
0
{
920
0
  return atomic_load_explicit(&zlog_ec, memory_order_relaxed);
921
0
}
922
923
void zlog_set_prefix_xid(bool enable)
924
4
{
925
4
  atomic_store_explicit(&zlog_xid, enable, memory_order_relaxed);
926
4
}
927
928
bool zlog_get_prefix_xid(void)
929
0
{
930
0
  return atomic_load_explicit(&zlog_xid, memory_order_relaxed);
931
0
}
932
933
/* setup functions */
934
935
struct zlog_target *zlog_target_clone(struct memtype *mt,
936
              struct zlog_target *oldzt, size_t size)
937
0
{
938
0
  struct zlog_target *newzt;
939
940
0
  newzt = XCALLOC(mt, size);
941
0
  if (oldzt) {
942
0
    newzt->prio_min = oldzt->prio_min;
943
0
    newzt->logfn = oldzt->logfn;
944
0
    newzt->logfn_sigsafe = oldzt->logfn_sigsafe;
945
0
  }
946
947
0
  return newzt;
948
0
}
949
950
struct zlog_target *zlog_target_replace(struct zlog_target *oldzt,
951
          struct zlog_target *newzt)
952
12
{
953
12
  if (newzt)
954
8
    zlog_targets_add_tail(&zlog_targets, newzt);
955
12
  if (oldzt)
956
0
    zlog_targets_del(&zlog_targets, oldzt);
957
12
  return oldzt;
958
12
}
959
960
/*
961
 * Enable or disable 'immediate' output - default is to buffer
962
 * each pthread's messages.
963
 */
964
void zlog_set_immediate(bool set_p)
965
0
{
966
0
  default_immediate = set_p;
967
0
}
968
969
/* common init */
970
971
12
#define TMPBASEDIR "/var/tmp/frr"
972
973
static char zlog_tmpdir[MAXPATHLEN];
974
975
void zlog_aux_init(const char *prefix, int prio_min)
976
0
{
977
0
  if (prefix)
978
0
    strlcpy(zlog_prefix, prefix, sizeof(zlog_prefix));
979
980
0
  hook_call(zlog_aux_init, prefix, prio_min);
981
0
}
982
983
void zlog_init(const char *progname, const char *protoname,
984
         unsigned short instance, uid_t uid, gid_t gid)
985
4
{
986
4
  zlog_uid = uid;
987
4
  zlog_gid = gid;
988
4
  zlog_instance = instance;
989
990
4
  if (instance) {
991
0
    snprintfrr(zlog_tmpdir, sizeof(zlog_tmpdir), "%s/%s-%d.%ld",
992
0
         TMPBASEDIR, progname, instance, (long)getpid());
993
994
0
    zlog_prefixsz = snprintfrr(zlog_prefix, sizeof(zlog_prefix),
995
0
             "%s[%d]: ", protoname, instance);
996
4
  } else {
997
4
    snprintfrr(zlog_tmpdir, sizeof(zlog_tmpdir), "%s/%s.%ld",
998
4
         TMPBASEDIR, progname, (long)getpid());
999
1000
4
    zlog_prefixsz = snprintfrr(zlog_prefix, sizeof(zlog_prefix),
1001
4
             "%s: ", protoname);
1002
4
  }
1003
1004
4
  if (mkdir(TMPBASEDIR, 0700) != 0) {
1005
3
    if (errno != EEXIST) {
1006
0
      zlog_err("failed to mkdir \"%s\": %s",
1007
0
         TMPBASEDIR, strerror(errno));
1008
0
      goto out_warn;
1009
0
    }
1010
3
  }
1011
4
  chown(TMPBASEDIR, zlog_uid, zlog_gid);
1012
1013
4
  if (mkdir(zlog_tmpdir, 0700) != 0) {
1014
0
    zlog_err("failed to mkdir \"%s\": %s",
1015
0
       zlog_tmpdir, strerror(errno));
1016
0
    goto out_warn;
1017
0
  }
1018
1019
4
#ifdef O_PATH
1020
4
  zlog_tmpdirfd = open(zlog_tmpdir,
1021
4
           O_PATH | O_RDONLY | O_CLOEXEC);
1022
#else
1023
  zlog_tmpdirfd = open(zlog_tmpdir,
1024
           O_DIRECTORY | O_RDONLY | O_CLOEXEC);
1025
#endif
1026
4
  if (zlog_tmpdirfd < 0) {
1027
0
    zlog_err("failed to open \"%s\": %s",
1028
0
       zlog_tmpdir, strerror(errno));
1029
0
    goto out_warn;
1030
0
  }
1031
1032
4
#ifdef AT_EMPTY_PATH
1033
4
  fchownat(zlog_tmpdirfd, "", zlog_uid, zlog_gid, AT_EMPTY_PATH);
1034
#else
1035
  chown(zlog_tmpdir, zlog_uid, zlog_gid);
1036
#endif
1037
1038
4
  hook_call(zlog_init, progname, protoname, instance, uid, gid);
1039
4
  return;
1040
1041
0
out_warn:
1042
0
  zlog_err("crashlog and per-thread log buffering unavailable!");
1043
0
  hook_call(zlog_init, progname, protoname, instance, uid, gid);
1044
0
}
1045
1046
void zlog_fini(void)
1047
0
{
1048
0
  hook_call(zlog_fini);
1049
1050
0
  if (zlog_tmpdirfd >= 0) {
1051
0
    close(zlog_tmpdirfd);
1052
0
    zlog_tmpdirfd = -1;
1053
1054
0
    if (rmdir(zlog_tmpdir))
1055
0
      zlog_err("failed to rmdir \"%s\": %s",
1056
0
         zlog_tmpdir, strerror(errno));
1057
0
  }
1058
0
}