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 /* Global setting for buffered vs immediate output. The default is
85 * per-pthread buffering.
87 static bool default_immediate
;
89 /* cf. zlog.h for additional comments on this struct.
91 * Note: you MUST NOT pass the format string + va_list to non-FRR format
92 * string functions (e.g. vsyslog, sd_journal_printv, ...) since FRR uses an
93 * extended prinf() with additional formats (%pI4 and the like).
95 * Also remember to use va_copy() on args.
104 const struct xref_logmsg
*xref
;
111 /* This is always ISO8601 with sub-second precision 9 here, it's
112 * converted for callers as needed. ts_dot points to the "."
113 * separating sub-seconds. ts_zonetail is "Z" or "+00:00" for the
116 * Valid if ZLOG_TS_ISO8601 is set.
117 * (0 if timestamp has not been formatted yet)
120 char ts_str
[32], *ts_dot
, ts_zonetail
[8];
123 /* thread-local log message buffering
125 * This is strictly optional and set up by calling zlog_tls_buffer_init()
126 * on a particular thread.
128 * If in use, this will create a temporary file in /var/tmp which is used as
129 * memory-mapped MAP_SHARED log message buffer. The idea there is that buffer
130 * access doesn't require any syscalls, but in case of a crash the kernel
131 * knows to sync the memory back to disk. This way the user can still get the
132 * last log messages if there were any left unwritten in the buffer.
134 * Sizing this dynamically isn't particularly useful, so here's an 8k buffer
135 * with a message limit of 64 messages. Message metadata (e.g. priority,
136 * timestamp) aren't in the mmap region, so they're lost on crash, but we can
140 #if defined(HAVE_OPENAT) && defined(HAVE_UNLINKAT)
144 #define TLS_LOG_BUF_SIZE 8192
145 #define TLS_LOG_MAXMSG 64
153 struct zlog_msg msgs
[TLS_LOG_MAXMSG
];
154 struct zlog_msg
*msgp
[TLS_LOG_MAXMSG
];
157 static inline void zlog_tls_free(void *arg
);
159 /* proper ELF TLS is a bit faster than pthread_[gs]etspecific, so if it's
160 * available we'll use it here
164 static pthread_key_t zlog_tls_key
;
166 static void zlog_tls_key_init(void) __attribute__((_CONSTRUCTOR(500)));
167 static void zlog_tls_key_init(void)
169 pthread_key_create(&zlog_tls_key
, zlog_tls_free
);
172 static void zlog_tls_key_fini(void) __attribute__((_DESTRUCTOR(500)));
173 static void zlog_tls_key_fini(void)
175 pthread_key_delete(zlog_tls_key
);
178 static inline struct zlog_tls
*zlog_tls_get(void)
180 return pthread_getspecific(zlog_tls_key
);
183 static inline void zlog_tls_set(struct zlog_tls
*val
)
185 pthread_setspecific(zlog_tls_key
, val
);
188 # ifndef thread_local
189 # define thread_local __thread
192 static thread_local
struct zlog_tls
*zlog_tls_var
193 __attribute__((tls_model("initial-exec")));
195 static inline struct zlog_tls
*zlog_tls_get(void)
200 static inline void zlog_tls_set(struct zlog_tls
*val
)
207 static long zlog_gettid(void)
210 #ifdef HAVE_PTHREAD_GETTHREADID_NP
211 rv
= pthread_getthreadid_np();
213 rv
= syscall(__NR_gettid
);
214 #elif defined(__NetBSD__)
216 #elif defined(__FreeBSD__)
218 #elif defined(__DragonFly__)
220 #elif defined(__OpenBSD__)
224 #elif defined(__APPLE__)
225 rv
= mach_thread_self();
226 mach_port_deallocate(mach_task_self(), rv
);
231 void zlog_tls_buffer_init(void)
233 struct zlog_tls
*zlog_tls
;
234 char mmpath
[MAXPATHLEN
];
238 zlog_tls
= zlog_tls_get();
240 if (zlog_tls
|| zlog_tmpdirfd
< 0)
243 zlog_tls
= XCALLOC(MTYPE_LOG_TLSBUF
, sizeof(*zlog_tls
));
244 for (i
= 0; i
< array_size(zlog_tls
->msgp
); i
++)
245 zlog_tls
->msgp
[i
] = &zlog_tls
->msgs
[i
];
247 snprintfrr(mmpath
, sizeof(mmpath
), "logbuf.%ld", zlog_gettid());
249 mmfd
= openat(zlog_tmpdirfd
, mmpath
,
250 O_RDWR
| O_CREAT
| O_EXCL
| O_CLOEXEC
, 0600);
252 zlog_err("failed to open thread log buffer \"%s\": %s",
253 mmpath
, strerror(errno
));
256 fchown(mmfd
, zlog_uid
, zlog_gid
);
258 #ifdef HAVE_POSIX_FALLOCATE
259 if (posix_fallocate(mmfd
, 0, TLS_LOG_BUF_SIZE
) != 0)
260 /* note next statement is under above if() */
262 if (ftruncate(mmfd
, TLS_LOG_BUF_SIZE
) < 0) {
263 zlog_err("failed to allocate thread log buffer \"%s\": %s",
264 mmpath
, strerror(errno
));
265 goto out_anon_unlink
;
268 zlog_tls
->mmbuf
= mmap(NULL
, TLS_LOG_BUF_SIZE
, PROT_READ
| PROT_WRITE
,
269 MAP_SHARED
, mmfd
, 0);
270 if (zlog_tls
->mmbuf
== MAP_FAILED
) {
271 zlog_err("failed to mmap thread log buffer \"%s\": %s",
272 mmpath
, strerror(errno
));
273 goto out_anon_unlink
;
275 zlog_tls
->do_unlink
= true;
278 zlog_tls_set(zlog_tls
);
282 unlinkat(zlog_tmpdirfd
, mmpath
, 0);
286 #ifndef MAP_ANONYMOUS
287 #define MAP_ANONYMOUS MAP_ANON
289 zlog_tls
->mmbuf
= mmap(NULL
, TLS_LOG_BUF_SIZE
, PROT_READ
| PROT_WRITE
,
290 MAP_ANONYMOUS
| MAP_PRIVATE
, -1, 0);
292 if (!zlog_tls
->mmbuf
) {
293 zlog_err("failed to anonymous-mmap thread log buffer: %s",
295 XFREE(MTYPE_LOG_TLSBUF
, zlog_tls
);
300 zlog_tls_set(zlog_tls
);
303 void zlog_tls_buffer_fini(void)
305 char mmpath
[MAXPATHLEN
];
306 struct zlog_tls
*zlog_tls
= zlog_tls_get();
307 bool do_unlink
= zlog_tls
? zlog_tls
->do_unlink
: false;
309 zlog_tls_buffer_flush();
311 zlog_tls_free(zlog_tls
);
314 snprintfrr(mmpath
, sizeof(mmpath
), "logbuf.%ld", zlog_gettid());
315 if (do_unlink
&& unlinkat(zlog_tmpdirfd
, mmpath
, 0))
316 zlog_err("unlink logbuf: %s (%d)", strerror(errno
), errno
);
319 #else /* !CAN_DO_TLS */
320 void zlog_tls_buffer_init(void)
324 void zlog_tls_buffer_fini(void)
329 static inline void zlog_tls_free(void *arg
)
331 struct zlog_tls
*zlog_tls
= arg
;
336 munmap(zlog_tls
->mmbuf
, TLS_LOG_BUF_SIZE
);
337 XFREE(MTYPE_LOG_TLSBUF
, zlog_tls
);
340 void zlog_tls_buffer_flush(void)
342 struct zlog_target
*zt
;
343 struct zlog_tls
*zlog_tls
= zlog_tls_get();
347 if (!zlog_tls
->nmsgs
)
351 frr_each (zlog_targets
, &zlog_targets
, zt
) {
355 zt
->logfn(zt
, zlog_tls
->msgp
, zlog_tls
->nmsgs
);
359 zlog_tls
->bufpos
= 0;
364 static void vzlog_notls(const struct xref_logmsg
*xref
, int prio
,
365 const char *fmt
, va_list ap
)
367 struct zlog_target
*zt
;
368 struct zlog_msg stackmsg
= {
369 .prio
= prio
& LOG_PRIMASK
,
375 clock_gettime(CLOCK_REALTIME
, &msg
->ts
);
376 va_copy(msg
->args
, ap
);
377 msg
->stackbuf
= stackbuf
;
378 msg
->stackbufsz
= sizeof(stackbuf
);
381 frr_each (zlog_targets
, &zlog_targets
, zt
) {
382 if (prio
> zt
->prio_min
)
387 zt
->logfn(zt
, &msg
, 1);
392 if (msg
->text
&& msg
->text
!= stackbuf
)
393 XFREE(MTYPE_LOG_MESSAGE
, msg
->text
);
396 static void vzlog_tls(struct zlog_tls
*zlog_tls
, const struct xref_logmsg
*xref
,
397 int prio
, const char *fmt
, va_list ap
)
399 struct zlog_target
*zt
;
400 struct zlog_msg
*msg
;
402 bool ignoremsg
= true;
403 bool immediate
= default_immediate
;
405 /* avoid further processing cost if no target wants this message */
407 frr_each (zlog_targets
, &zlog_targets
, zt
) {
408 if (prio
> zt
->prio_min
)
418 msg
= &zlog_tls
->msgs
[zlog_tls
->nmsgs
];
420 if (zlog_tls
->nmsgs
== array_size(zlog_tls
->msgs
))
423 memset(msg
, 0, sizeof(*msg
));
424 clock_gettime(CLOCK_REALTIME
, &msg
->ts
);
425 va_copy(msg
->args
, ap
);
426 msg
->stackbuf
= buf
= zlog_tls
->mmbuf
+ zlog_tls
->bufpos
;
427 msg
->stackbufsz
= TLS_LOG_BUF_SIZE
- zlog_tls
->bufpos
- 1;
429 msg
->prio
= prio
& LOG_PRIMASK
;
431 if (msg
->prio
< LOG_INFO
)
435 /* messages written later need to take the formatting cost
436 * immediately since we can't hold a reference on varargs
438 zlog_msg_text(msg
, NULL
);
440 if (msg
->text
!= buf
)
441 /* zlog_msg_text called malloc() on us :( */
444 zlog_tls
->bufpos
+= msg
->textlen
+ 1;
445 /* write a second \0 to mark current end position
446 * (in case of crash this signals end of unwritten log
447 * messages in mmap'd logbuf file)
449 zlog_tls
->mmbuf
[zlog_tls
->bufpos
] = '\0';
451 /* avoid malloc() for next message */
452 if (TLS_LOG_BUF_SIZE
- zlog_tls
->bufpos
< 256)
458 zlog_tls_buffer_flush();
461 if (msg
->text
&& msg
->text
!= buf
)
462 XFREE(MTYPE_LOG_MESSAGE
, msg
->text
);
465 void vzlogx(const struct xref_logmsg
*xref
, int prio
,
466 const char *fmt
, va_list ap
)
468 struct zlog_tls
*zlog_tls
= zlog_tls_get();
473 char *msg
= vasprintfrr(MTYPE_LOG_MESSAGE
, fmt
, copy
);
477 frrtracelog(TRACE_ERR
, msg
);
480 frrtracelog(TRACE_WARNING
, msg
);
483 frrtracelog(TRACE_DEBUG
, msg
);
486 frrtracelog(TRACE_DEBUG
, msg
);
490 frrtracelog(TRACE_INFO
, msg
);
495 XFREE(MTYPE_LOG_MESSAGE
, msg
);
499 vzlog_tls(zlog_tls
, xref
, prio
, fmt
, ap
);
501 vzlog_notls(xref
, prio
, fmt
, ap
);
504 void zlog_sigsafe(const char *text
, size_t len
)
506 struct zlog_target
*zt
;
507 const char *end
= text
+ len
, *nlpos
;
510 nlpos
= memchr(text
, '\n', end
- text
);
514 frr_each (zlog_targets
, &zlog_targets
, zt
) {
515 if (LOG_CRIT
> zt
->prio_min
)
517 if (!zt
->logfn_sigsafe
)
520 zt
->logfn_sigsafe(zt
, text
, nlpos
- text
);
530 int zlog_msg_prio(struct zlog_msg
*msg
)
535 const struct xref_logmsg
*zlog_msg_xref(struct zlog_msg
*msg
)
540 const char *zlog_msg_text(struct zlog_msg
*msg
, size_t *textlen
)
545 size_t need
= 0, hdrlen
;
547 .buf
= msg
->stackbuf
,
548 .pos
= msg
->stackbuf
,
549 .len
= msg
->stackbufsz
,
552 do_ec
= atomic_load_explicit(&zlog_ec
, memory_order_relaxed
);
553 do_xid
= atomic_load_explicit(&zlog_xid
, memory_order_relaxed
);
555 if (msg
->xref
&& do_xid
&& msg
->xref
->xref
.xrefdata
->uid
[0]) {
556 need
+= bputch(&fb
, '[');
557 need
+= bputs(&fb
, msg
->xref
->xref
.xrefdata
->uid
);
558 need
+= bputch(&fb
, ']');
560 if (msg
->xref
&& do_ec
&& msg
->xref
->ec
)
561 need
+= bprintfrr(&fb
, "[EC %u]", msg
->xref
->ec
);
563 need
+= bputch(&fb
, ' ');
566 assert(hdrlen
< msg
->stackbufsz
);
568 va_copy(args
, msg
->args
);
569 need
+= vbprintfrr(&fb
, msg
->fmt
, args
);
573 need
+= bputch(&fb
, '\0');
575 if (need
<= msg
->stackbufsz
)
576 msg
->text
= msg
->stackbuf
;
578 msg
->text
= XMALLOC(MTYPE_LOG_MESSAGE
, need
);
580 memcpy(msg
->text
, msg
->stackbuf
, hdrlen
);
584 fb
.pos
= msg
->text
+ hdrlen
;
586 va_copy(args
, msg
->args
);
587 vbprintfrr(&fb
, msg
->fmt
, args
);
594 *textlen
= msg
->textlen
;
598 #define ZLOG_TS_FORMAT (ZLOG_TS_ISO8601 | ZLOG_TS_LEGACY)
599 #define ZLOG_TS_FLAGS ~ZLOG_TS_PREC
601 size_t zlog_msg_ts(struct zlog_msg
*msg
, char *out
, size_t outsz
,
606 if (!(flags
& ZLOG_TS_FORMAT
))
609 if (!(msg
->ts_flags
& ZLOG_TS_FORMAT
) ||
610 ((msg
->ts_flags
^ flags
) & ZLOG_TS_UTC
)) {
613 if (flags
& ZLOG_TS_UTC
)
614 gmtime_r(&msg
->ts
.tv_sec
, &tm
);
616 localtime_r(&msg
->ts
.tv_sec
, &tm
);
618 strftime(msg
->ts_str
, sizeof(msg
->ts_str
),
619 "%Y-%m-%dT%H:%M:%S", &tm
);
621 if (flags
& ZLOG_TS_UTC
) {
622 msg
->ts_zonetail
[0] = 'Z';
623 msg
->ts_zonetail
[1] = '\0';
625 snprintfrr(msg
->ts_zonetail
, sizeof(msg
->ts_zonetail
),
627 (int)(tm
.tm_gmtoff
/ 3600),
628 (int)(labs(tm
.tm_gmtoff
) / 60) % 60);
630 msg
->ts_dot
= msg
->ts_str
+ strlen(msg
->ts_str
);
631 snprintfrr(msg
->ts_dot
,
632 msg
->ts_str
+ sizeof(msg
->ts_str
) - msg
->ts_dot
,
633 ".%09lu", (unsigned long)msg
->ts
.tv_nsec
);
635 msg
->ts_flags
= ZLOG_TS_ISO8601
| (flags
& ZLOG_TS_UTC
);
638 len1
= flags
& ZLOG_TS_PREC
;
639 len1
= (msg
->ts_dot
- msg
->ts_str
) + (len1
? len1
+ 1 : 0);
641 if (len1
> strlen(msg
->ts_str
))
642 len1
= strlen(msg
->ts_str
);
644 if (flags
& ZLOG_TS_LEGACY
) {
645 if (len1
+ 1 > outsz
)
648 /* just swap out the formatting, faster than redoing it */
649 for (char *p
= msg
->ts_str
; p
< msg
->ts_str
+ len1
; p
++) {
664 size_t len2
= strlen(msg
->ts_zonetail
);
666 if (len1
+ len2
+ 1 > outsz
)
668 memcpy(out
, msg
->ts_str
, len1
);
669 memcpy(out
+ len1
, msg
->ts_zonetail
, len2
);
670 out
[len1
+ len2
] = '\0';
675 void zlog_set_prefix_ec(bool enable
)
677 atomic_store_explicit(&zlog_ec
, enable
, memory_order_relaxed
);
680 bool zlog_get_prefix_ec(void)
682 return atomic_load_explicit(&zlog_ec
, memory_order_relaxed
);
685 void zlog_set_prefix_xid(bool enable
)
687 atomic_store_explicit(&zlog_xid
, enable
, memory_order_relaxed
);
690 bool zlog_get_prefix_xid(void)
692 return atomic_load_explicit(&zlog_xid
, memory_order_relaxed
);
695 /* setup functions */
697 struct zlog_target
*zlog_target_clone(struct memtype
*mt
,
698 struct zlog_target
*oldzt
, size_t size
)
700 struct zlog_target
*newzt
;
702 newzt
= XCALLOC(mt
, size
);
704 newzt
->prio_min
= oldzt
->prio_min
;
705 newzt
->logfn
= oldzt
->logfn
;
706 newzt
->logfn_sigsafe
= oldzt
->logfn_sigsafe
;
712 struct zlog_target
*zlog_target_replace(struct zlog_target
*oldzt
,
713 struct zlog_target
*newzt
)
716 zlog_targets_add_tail(&zlog_targets
, newzt
);
718 zlog_targets_del(&zlog_targets
, oldzt
);
723 * Enable or disable 'immediate' output - default is to buffer
724 * each pthread's messages.
726 void zlog_set_immediate(bool set_p
)
728 default_immediate
= set_p
;
733 #define TMPBASEDIR "/var/tmp/frr"
735 static char zlog_tmpdir
[MAXPATHLEN
];
737 void zlog_aux_init(const char *prefix
, int prio_min
)
740 strlcpy(zlog_prefix
, prefix
, sizeof(zlog_prefix
));
742 hook_call(zlog_aux_init
, prefix
, prio_min
);
745 void zlog_init(const char *progname
, const char *protoname
,
746 unsigned short instance
, uid_t uid
, gid_t gid
)
752 snprintfrr(zlog_tmpdir
, sizeof(zlog_tmpdir
),
753 "/var/tmp/frr/%s-%d.%ld",
754 progname
, instance
, (long)getpid());
756 zlog_prefixsz
= snprintfrr(zlog_prefix
, sizeof(zlog_prefix
),
757 "%s[%d]: ", protoname
, instance
);
759 snprintfrr(zlog_tmpdir
, sizeof(zlog_tmpdir
),
760 "/var/tmp/frr/%s.%ld",
761 progname
, (long)getpid());
763 zlog_prefixsz
= snprintfrr(zlog_prefix
, sizeof(zlog_prefix
),
767 if (mkdir(TMPBASEDIR
, 0700) != 0) {
768 if (errno
!= EEXIST
) {
769 zlog_err("failed to mkdir \"%s\": %s",
770 TMPBASEDIR
, strerror(errno
));
774 chown(TMPBASEDIR
, zlog_uid
, zlog_gid
);
776 if (mkdir(zlog_tmpdir
, 0700) != 0) {
777 zlog_err("failed to mkdir \"%s\": %s",
778 zlog_tmpdir
, strerror(errno
));
783 zlog_tmpdirfd
= open(zlog_tmpdir
,
784 O_PATH
| O_RDONLY
| O_CLOEXEC
);
786 zlog_tmpdirfd
= open(zlog_tmpdir
,
787 O_DIRECTORY
| O_RDONLY
| O_CLOEXEC
);
789 if (zlog_tmpdirfd
< 0) {
790 zlog_err("failed to open \"%s\": %s",
791 zlog_tmpdir
, strerror(errno
));
796 fchownat(zlog_tmpdirfd
, "", zlog_uid
, zlog_gid
, AT_EMPTY_PATH
);
798 chown(zlog_tmpdir
, zlog_uid
, zlog_gid
);
801 hook_call(zlog_init
, progname
, protoname
, instance
, uid
, gid
);
805 zlog_err("crashlog and per-thread log buffering unavailable!");
806 hook_call(zlog_init
, progname
, protoname
, instance
, uid
, gid
);
811 hook_call(zlog_fini
);
813 if (zlog_tmpdirfd
>= 0) {
814 close(zlog_tmpdirfd
);
817 if (rmdir(zlog_tmpdir
))
818 zlog_err("failed to rmdir \"%s\": %s",
819 zlog_tmpdir
, strerror(errno
));