2 * Copyright (c) 2015-19 David Lamparter, for NetDEF, Inc.
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.
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.
22 #include <sys/types.h>
31 #ifdef HAVE_PTHREAD_NP_H
32 #include <pthread_np.h>
35 #include <sys/syscall.h>
47 #include <mach/mach_traps.h>
55 #include "libfrr_trace.h"
57 DEFINE_MTYPE_STATIC(LIB
, LOG_MESSAGE
, "log message");
58 DEFINE_MTYPE_STATIC(LIB
, LOG_TLSBUF
, "log thread-local buffer");
60 DEFINE_HOOK(zlog_init
, (const char *progname
, const char *protoname
,
61 unsigned short instance
, uid_t uid
, gid_t gid
),
62 (progname
, protoname
, instance
, uid
, gid
));
63 DEFINE_KOOH(zlog_fini
, (), ());
64 DEFINE_HOOK(zlog_aux_init
, (const char *prefix
, int prio_min
),
67 char zlog_prefix
[128];
69 int zlog_tmpdirfd
= -1;
71 static atomic_bool zlog_ec
= true, zlog_xid
= true;
73 /* these are kept around because logging is initialized (and directories
74 * & files created) before zprivs code switches to the FRR user; therefore
75 * we need to chown() things so we don't get permission errors later when
76 * trying to delete things on shutdown
78 static uid_t zlog_uid
= -1;
79 static gid_t zlog_gid
= -1;
81 DECLARE_ATOMLIST(zlog_targets
, struct zlog_target
, head
);
82 static struct zlog_targets_head zlog_targets
;
84 /* cf. zlog.h for additional comments on this struct.
86 * Note: you MUST NOT pass the format string + va_list to non-FRR format
87 * string functions (e.g. vsyslog, sd_journal_printv, ...) since FRR uses an
88 * extended prinf() with additional formats (%pI4 and the like).
90 * Also remember to use va_copy() on args.
99 const struct xref_logmsg
*xref
;
106 /* This is always ISO8601 with sub-second precision 9 here, it's
107 * converted for callers as needed. ts_dot points to the "."
108 * separating sub-seconds. ts_zonetail is "Z" or "+00:00" for the
111 * Valid if ZLOG_TS_ISO8601 is set.
112 * (0 if timestamp has not been formatted yet)
115 char ts_str
[32], *ts_dot
, ts_zonetail
[8];
118 /* thread-local log message buffering
120 * This is strictly optional and set up by calling zlog_tls_buffer_init()
121 * on a particular thread.
123 * If in use, this will create a temporary file in /var/tmp which is used as
124 * memory-mapped MAP_SHARED log message buffer. The idea there is that buffer
125 * access doesn't require any syscalls, but in case of a crash the kernel
126 * knows to sync the memory back to disk. This way the user can still get the
127 * last log messages if there were any left unwritten in the buffer.
129 * Sizing this dynamically isn't particularly useful, so here's an 8k buffer
130 * with a message limit of 64 messages. Message metadata (e.g. priority,
131 * timestamp) aren't in the mmap region, so they're lost on crash, but we can
135 #if defined(HAVE_OPENAT) && defined(HAVE_UNLINKAT)
139 #define TLS_LOG_BUF_SIZE 8192
140 #define TLS_LOG_MAXMSG 64
148 struct zlog_msg msgs
[TLS_LOG_MAXMSG
];
149 struct zlog_msg
*msgp
[TLS_LOG_MAXMSG
];
152 static inline void zlog_tls_free(void *arg
);
154 /* proper ELF TLS is a bit faster than pthread_[gs]etspecific, so if it's
155 * available we'll use it here
159 static pthread_key_t zlog_tls_key
;
161 static void zlog_tls_key_init(void) __attribute__((_CONSTRUCTOR(500)));
162 static void zlog_tls_key_init(void)
164 pthread_key_create(&zlog_tls_key
, zlog_tls_free
);
167 static void zlog_tls_key_fini(void) __attribute__((_DESTRUCTOR(500)));
168 static void zlog_tls_key_fini(void)
170 pthread_key_delete(zlog_tls_key
);
173 static inline struct zlog_tls
*zlog_tls_get(void)
175 return pthread_getspecific(zlog_tls_key
);
178 static inline void zlog_tls_set(struct zlog_tls
*val
)
180 pthread_setspecific(zlog_tls_key
, val
);
183 # ifndef thread_local
184 # define thread_local __thread
187 static thread_local
struct zlog_tls
*zlog_tls_var
188 __attribute__((tls_model("initial-exec")));
190 static inline struct zlog_tls
*zlog_tls_get(void)
195 static inline void zlog_tls_set(struct zlog_tls
*val
)
202 static long zlog_gettid(void)
205 #ifdef HAVE_PTHREAD_GETTHREADID_NP
206 rv
= pthread_getthreadid_np();
208 rv
= syscall(__NR_gettid
);
209 #elif defined(__NetBSD__)
211 #elif defined(__FreeBSD__)
213 #elif defined(__DragonFly__)
215 #elif defined(__OpenBSD__)
219 #elif defined(__APPLE__)
220 rv
= mach_thread_self();
221 mach_port_deallocate(mach_task_self(), rv
);
226 void zlog_tls_buffer_init(void)
228 struct zlog_tls
*zlog_tls
;
229 char mmpath
[MAXPATHLEN
];
233 zlog_tls
= zlog_tls_get();
235 if (zlog_tls
|| zlog_tmpdirfd
< 0)
238 zlog_tls
= XCALLOC(MTYPE_LOG_TLSBUF
, sizeof(*zlog_tls
));
239 for (i
= 0; i
< array_size(zlog_tls
->msgp
); i
++)
240 zlog_tls
->msgp
[i
] = &zlog_tls
->msgs
[i
];
242 snprintfrr(mmpath
, sizeof(mmpath
), "logbuf.%ld", zlog_gettid());
244 mmfd
= openat(zlog_tmpdirfd
, mmpath
,
245 O_RDWR
| O_CREAT
| O_EXCL
| O_CLOEXEC
, 0600);
247 zlog_err("failed to open thread log buffer \"%s\": %s",
248 mmpath
, strerror(errno
));
251 fchown(mmfd
, zlog_uid
, zlog_gid
);
253 #ifdef HAVE_POSIX_FALLOCATE
254 if (posix_fallocate(mmfd
, 0, TLS_LOG_BUF_SIZE
) != 0)
255 /* note next statement is under above if() */
257 if (ftruncate(mmfd
, TLS_LOG_BUF_SIZE
) < 0) {
258 zlog_err("failed to allocate thread log buffer \"%s\": %s",
259 mmpath
, strerror(errno
));
260 goto out_anon_unlink
;
263 zlog_tls
->mmbuf
= mmap(NULL
, TLS_LOG_BUF_SIZE
, PROT_READ
| PROT_WRITE
,
264 MAP_SHARED
, mmfd
, 0);
265 if (zlog_tls
->mmbuf
== MAP_FAILED
) {
266 zlog_err("failed to mmap thread log buffer \"%s\": %s",
267 mmpath
, strerror(errno
));
268 goto out_anon_unlink
;
270 zlog_tls
->do_unlink
= true;
273 zlog_tls_set(zlog_tls
);
277 unlinkat(zlog_tmpdirfd
, mmpath
, 0);
281 #ifndef MAP_ANONYMOUS
282 #define MAP_ANONYMOUS MAP_ANON
284 zlog_tls
->mmbuf
= mmap(NULL
, TLS_LOG_BUF_SIZE
, PROT_READ
| PROT_WRITE
,
285 MAP_ANONYMOUS
| MAP_PRIVATE
, -1, 0);
287 if (!zlog_tls
->mmbuf
) {
288 zlog_err("failed to anonymous-mmap thread log buffer: %s",
290 XFREE(MTYPE_LOG_TLSBUF
, zlog_tls
);
295 zlog_tls_set(zlog_tls
);
298 void zlog_tls_buffer_fini(void)
300 char mmpath
[MAXPATHLEN
];
301 struct zlog_tls
*zlog_tls
= zlog_tls_get();
302 bool do_unlink
= zlog_tls
? zlog_tls
->do_unlink
: false;
304 zlog_tls_buffer_flush();
306 zlog_tls_free(zlog_tls
);
309 snprintfrr(mmpath
, sizeof(mmpath
), "logbuf.%ld", zlog_gettid());
310 if (do_unlink
&& unlinkat(zlog_tmpdirfd
, mmpath
, 0))
311 zlog_err("unlink logbuf: %s (%d)", strerror(errno
), errno
);
314 #else /* !CAN_DO_TLS */
315 void zlog_tls_buffer_init(void)
319 void zlog_tls_buffer_fini(void)
324 static inline void zlog_tls_free(void *arg
)
326 struct zlog_tls
*zlog_tls
= arg
;
331 munmap(zlog_tls
->mmbuf
, TLS_LOG_BUF_SIZE
);
332 XFREE(MTYPE_LOG_TLSBUF
, zlog_tls
);
335 void zlog_tls_buffer_flush(void)
337 struct zlog_target
*zt
;
338 struct zlog_tls
*zlog_tls
= zlog_tls_get();
342 if (!zlog_tls
->nmsgs
)
346 frr_each (zlog_targets
, &zlog_targets
, zt
) {
350 zt
->logfn(zt
, zlog_tls
->msgp
, zlog_tls
->nmsgs
);
354 zlog_tls
->bufpos
= 0;
359 static void vzlog_notls(const struct xref_logmsg
*xref
, int prio
,
360 const char *fmt
, va_list ap
)
362 struct zlog_target
*zt
;
363 struct zlog_msg stackmsg
= {
364 .prio
= prio
& LOG_PRIMASK
,
370 clock_gettime(CLOCK_REALTIME
, &msg
->ts
);
371 va_copy(msg
->args
, ap
);
372 msg
->stackbuf
= stackbuf
;
373 msg
->stackbufsz
= sizeof(stackbuf
);
376 frr_each (zlog_targets
, &zlog_targets
, zt
) {
377 if (prio
> zt
->prio_min
)
382 zt
->logfn(zt
, &msg
, 1);
387 if (msg
->text
&& msg
->text
!= stackbuf
)
388 XFREE(MTYPE_LOG_MESSAGE
, msg
->text
);
391 static void vzlog_tls(struct zlog_tls
*zlog_tls
, const struct xref_logmsg
*xref
,
392 int prio
, const char *fmt
, va_list ap
)
394 struct zlog_target
*zt
;
395 struct zlog_msg
*msg
;
397 bool ignoremsg
= true;
398 bool immediate
= false;
400 /* avoid further processing cost if no target wants this message */
402 frr_each (zlog_targets
, &zlog_targets
, zt
) {
403 if (prio
> zt
->prio_min
)
413 msg
= &zlog_tls
->msgs
[zlog_tls
->nmsgs
];
415 if (zlog_tls
->nmsgs
== array_size(zlog_tls
->msgs
))
418 memset(msg
, 0, sizeof(*msg
));
419 clock_gettime(CLOCK_REALTIME
, &msg
->ts
);
420 va_copy(msg
->args
, ap
);
421 msg
->stackbuf
= buf
= zlog_tls
->mmbuf
+ zlog_tls
->bufpos
;
422 msg
->stackbufsz
= TLS_LOG_BUF_SIZE
- zlog_tls
->bufpos
- 1;
424 msg
->prio
= prio
& LOG_PRIMASK
;
426 if (msg
->prio
< LOG_INFO
)
430 /* messages written later need to take the formatting cost
431 * immediately since we can't hold a reference on varargs
433 zlog_msg_text(msg
, NULL
);
435 if (msg
->text
!= buf
)
436 /* zlog_msg_text called malloc() on us :( */
439 zlog_tls
->bufpos
+= msg
->textlen
+ 1;
440 /* write a second \0 to mark current end position
441 * (in case of crash this signals end of unwritten log
442 * messages in mmap'd logbuf file)
444 zlog_tls
->mmbuf
[zlog_tls
->bufpos
] = '\0';
446 /* avoid malloc() for next message */
447 if (TLS_LOG_BUF_SIZE
- zlog_tls
->bufpos
< 256)
453 zlog_tls_buffer_flush();
456 if (msg
->text
&& msg
->text
!= buf
)
457 XFREE(MTYPE_LOG_MESSAGE
, msg
->text
);
460 void vzlogx(const struct xref_logmsg
*xref
, int prio
,
461 const char *fmt
, va_list ap
)
463 struct zlog_tls
*zlog_tls
= zlog_tls_get();
468 char *msg
= vasprintfrr(MTYPE_LOG_MESSAGE
, fmt
, copy
);
472 frrtracelog(TRACE_ERR
, msg
);
475 frrtracelog(TRACE_WARNING
, msg
);
478 frrtracelog(TRACE_DEBUG
, msg
);
481 frrtracelog(TRACE_DEBUG
, msg
);
485 frrtracelog(TRACE_INFO
, msg
);
490 XFREE(MTYPE_LOG_MESSAGE
, msg
);
494 vzlog_tls(zlog_tls
, xref
, prio
, fmt
, ap
);
496 vzlog_notls(xref
, prio
, fmt
, ap
);
499 void zlog_sigsafe(const char *text
, size_t len
)
501 struct zlog_target
*zt
;
502 const char *end
= text
+ len
, *nlpos
;
505 nlpos
= memchr(text
, '\n', end
- text
);
509 frr_each (zlog_targets
, &zlog_targets
, zt
) {
510 if (LOG_CRIT
> zt
->prio_min
)
512 if (!zt
->logfn_sigsafe
)
515 zt
->logfn_sigsafe(zt
, text
, nlpos
- text
);
525 int zlog_msg_prio(struct zlog_msg
*msg
)
530 const struct xref_logmsg
*zlog_msg_xref(struct zlog_msg
*msg
)
535 const char *zlog_msg_text(struct zlog_msg
*msg
, size_t *textlen
)
540 size_t need
= 0, hdrlen
;
542 .buf
= msg
->stackbuf
,
543 .pos
= msg
->stackbuf
,
544 .len
= msg
->stackbufsz
,
547 do_ec
= atomic_load_explicit(&zlog_ec
, memory_order_relaxed
);
548 do_xid
= atomic_load_explicit(&zlog_xid
, memory_order_relaxed
);
550 if (msg
->xref
&& do_xid
&& msg
->xref
->xref
.xrefdata
->uid
[0]) {
551 need
+= bputch(&fb
, '[');
552 need
+= bputs(&fb
, msg
->xref
->xref
.xrefdata
->uid
);
553 need
+= bputch(&fb
, ']');
555 if (msg
->xref
&& do_ec
&& msg
->xref
->ec
)
556 need
+= bprintfrr(&fb
, "[EC %u]", msg
->xref
->ec
);
558 need
+= bputch(&fb
, ' ');
561 assert(hdrlen
< msg
->stackbufsz
);
563 va_copy(args
, msg
->args
);
564 need
+= vbprintfrr(&fb
, msg
->fmt
, args
);
568 need
+= bputch(&fb
, '\0');
570 if (need
<= msg
->stackbufsz
)
571 msg
->text
= msg
->stackbuf
;
573 msg
->text
= XMALLOC(MTYPE_LOG_MESSAGE
, need
);
575 memcpy(msg
->text
, msg
->stackbuf
, hdrlen
);
579 fb
.pos
= msg
->text
+ hdrlen
;
581 va_copy(args
, msg
->args
);
582 vbprintfrr(&fb
, msg
->fmt
, args
);
589 *textlen
= msg
->textlen
;
593 #define ZLOG_TS_FORMAT (ZLOG_TS_ISO8601 | ZLOG_TS_LEGACY)
594 #define ZLOG_TS_FLAGS ~ZLOG_TS_PREC
596 size_t zlog_msg_ts(struct zlog_msg
*msg
, char *out
, size_t outsz
,
601 if (!(flags
& ZLOG_TS_FORMAT
))
604 if (!(msg
->ts_flags
& ZLOG_TS_FORMAT
) ||
605 ((msg
->ts_flags
^ flags
) & ZLOG_TS_UTC
)) {
608 if (flags
& ZLOG_TS_UTC
)
609 gmtime_r(&msg
->ts
.tv_sec
, &tm
);
611 localtime_r(&msg
->ts
.tv_sec
, &tm
);
613 strftime(msg
->ts_str
, sizeof(msg
->ts_str
),
614 "%Y-%m-%dT%H:%M:%S", &tm
);
616 if (flags
& ZLOG_TS_UTC
) {
617 msg
->ts_zonetail
[0] = 'Z';
618 msg
->ts_zonetail
[1] = '\0';
620 snprintfrr(msg
->ts_zonetail
, sizeof(msg
->ts_zonetail
),
622 (int)(tm
.tm_gmtoff
/ 3600),
623 (int)(labs(tm
.tm_gmtoff
) / 60) % 60);
625 msg
->ts_dot
= msg
->ts_str
+ strlen(msg
->ts_str
);
626 snprintfrr(msg
->ts_dot
,
627 msg
->ts_str
+ sizeof(msg
->ts_str
) - msg
->ts_dot
,
628 ".%09lu", (unsigned long)msg
->ts
.tv_nsec
);
630 msg
->ts_flags
= ZLOG_TS_ISO8601
| (flags
& ZLOG_TS_UTC
);
633 len1
= flags
& ZLOG_TS_PREC
;
634 len1
= (msg
->ts_dot
- msg
->ts_str
) + (len1
? len1
+ 1 : 0);
636 if (len1
> strlen(msg
->ts_str
))
637 len1
= strlen(msg
->ts_str
);
639 if (flags
& ZLOG_TS_LEGACY
) {
640 if (len1
+ 1 > outsz
)
643 /* just swap out the formatting, faster than redoing it */
644 for (char *p
= msg
->ts_str
; p
< msg
->ts_str
+ len1
; p
++) {
659 size_t len2
= strlen(msg
->ts_zonetail
);
661 if (len1
+ len2
+ 1 > outsz
)
663 memcpy(out
, msg
->ts_str
, len1
);
664 memcpy(out
+ len1
, msg
->ts_zonetail
, len2
);
665 out
[len1
+ len2
] = '\0';
670 void zlog_set_prefix_ec(bool enable
)
672 atomic_store_explicit(&zlog_ec
, enable
, memory_order_relaxed
);
675 bool zlog_get_prefix_ec(void)
677 return atomic_load_explicit(&zlog_ec
, memory_order_relaxed
);
680 void zlog_set_prefix_xid(bool enable
)
682 atomic_store_explicit(&zlog_xid
, enable
, memory_order_relaxed
);
685 bool zlog_get_prefix_xid(void)
687 return atomic_load_explicit(&zlog_xid
, memory_order_relaxed
);
690 /* setup functions */
692 struct zlog_target
*zlog_target_clone(struct memtype
*mt
,
693 struct zlog_target
*oldzt
, size_t size
)
695 struct zlog_target
*newzt
;
697 newzt
= XCALLOC(mt
, size
);
699 newzt
->prio_min
= oldzt
->prio_min
;
700 newzt
->logfn
= oldzt
->logfn
;
701 newzt
->logfn_sigsafe
= oldzt
->logfn_sigsafe
;
707 struct zlog_target
*zlog_target_replace(struct zlog_target
*oldzt
,
708 struct zlog_target
*newzt
)
711 zlog_targets_add_tail(&zlog_targets
, newzt
);
713 zlog_targets_del(&zlog_targets
, oldzt
);
720 #define TMPBASEDIR "/var/tmp/frr"
722 static char zlog_tmpdir
[MAXPATHLEN
];
724 void zlog_aux_init(const char *prefix
, int prio_min
)
727 strlcpy(zlog_prefix
, prefix
, sizeof(zlog_prefix
));
729 hook_call(zlog_aux_init
, prefix
, prio_min
);
732 void zlog_init(const char *progname
, const char *protoname
,
733 unsigned short instance
, uid_t uid
, gid_t gid
)
739 snprintfrr(zlog_tmpdir
, sizeof(zlog_tmpdir
),
740 "/var/tmp/frr/%s-%d.%ld",
741 progname
, instance
, (long)getpid());
743 zlog_prefixsz
= snprintfrr(zlog_prefix
, sizeof(zlog_prefix
),
744 "%s[%d]: ", protoname
, instance
);
746 snprintfrr(zlog_tmpdir
, sizeof(zlog_tmpdir
),
747 "/var/tmp/frr/%s.%ld",
748 progname
, (long)getpid());
750 zlog_prefixsz
= snprintfrr(zlog_prefix
, sizeof(zlog_prefix
),
754 if (mkdir(TMPBASEDIR
, 0700) != 0) {
755 if (errno
!= EEXIST
) {
756 zlog_err("failed to mkdir \"%s\": %s",
757 TMPBASEDIR
, strerror(errno
));
761 chown(TMPBASEDIR
, zlog_uid
, zlog_gid
);
763 if (mkdir(zlog_tmpdir
, 0700) != 0) {
764 zlog_err("failed to mkdir \"%s\": %s",
765 zlog_tmpdir
, strerror(errno
));
770 zlog_tmpdirfd
= open(zlog_tmpdir
,
771 O_PATH
| O_RDONLY
| O_CLOEXEC
);
773 zlog_tmpdirfd
= open(zlog_tmpdir
,
774 O_DIRECTORY
| O_RDONLY
| O_CLOEXEC
);
776 if (zlog_tmpdirfd
< 0) {
777 zlog_err("failed to open \"%s\": %s",
778 zlog_tmpdir
, strerror(errno
));
783 fchownat(zlog_tmpdirfd
, "", zlog_uid
, zlog_gid
, AT_EMPTY_PATH
);
785 chown(zlog_tmpdir
, zlog_uid
, zlog_gid
);
788 hook_call(zlog_init
, progname
, protoname
, instance
, uid
, gid
);
792 zlog_err("crashlog and per-thread log buffering unavailable!");
793 hook_call(zlog_init
, progname
, protoname
, instance
, uid
, gid
);
798 hook_call(zlog_fini
);
800 if (zlog_tmpdirfd
>= 0) {
801 close(zlog_tmpdirfd
);
804 if (rmdir(zlog_tmpdir
))
805 zlog_err("failed to rmdir \"%s\": %s",
806 zlog_tmpdir
, strerror(errno
));