lib/zlog.c

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