From 9c2aa9192198769264df3d127332358b73983aed Mon Sep 17 00:00:00 2001 From: David Lamparter Date: Thu, 8 Apr 2021 12:57:58 +0200 Subject: [PATCH 01/10] lib: de-conflict `log-filter` CLI command `log-filter WORD` was giving me a serious headache since it also matches `log WORD` due to the way the CLI token handling works. This meant that a mistyped `log something` command would silently be interpreted as a filter string, causing me serious headscratching and WTFs until I figured what was going on. Remove this UX pitfall so noone else falls into it. (Since the command was never saved to config, renaming it shouldn't cause trouble.) [Also I apparently forgot to update the docs when I transferred this over to the new zlog bits...] TODO for a rainy day: since we collect all the CLI commands anyway, we should warn somewhere for "2nd level ambiguous" commands like this. Signed-off-by: David Lamparter --- doc/user/basic.rst | 21 ++++++++++++++++----- lib/log_vty.c | 9 ++++++--- 2 files changed, 22 insertions(+), 8 deletions(-) diff --git a/doc/user/basic.rst b/doc/user/basic.rst index 0db2361296..5e8d217126 100644 --- a/doc/user/basic.rst +++ b/doc/user/basic.rst @@ -174,11 +174,17 @@ Basic Config Commands is used to start the daemon then this command is turned on by default and cannot be turned off and the [no] form of the command is dissallowed. -.. clicmd:: log-filter WORD [DAEMON] +.. clicmd:: log filtered-file [FILENAME [LEVEL]] + + Configure a destination file for filtered logs with the + :clicmd:`log filter-text WORD` command. + +.. clicmd:: log filter-text WORD This command forces logs to be filtered on a specific string. A log message will only be printed if it matches on one of the filters in the log-filter - table. Can be daemon independent. + table. The filter only applies to file logging targets configured with + :clicmd:`log filtered-file [FILENAME [LEVEL]]`. .. note:: @@ -187,10 +193,15 @@ Basic Config Commands Log filters prevent this but you should still expect a small performance hit due to filtering each of all those logs. -.. clicmd:: log-filter clear [DAEMON] + .. note:: - This command clears all current filters in the log-filter table. Can be - daemon independent. + This setting is not saved to ``frr.conf`` and not shown in + :clicmd:`show running-config`. It is intended for ephemeral debugging + purposes only. + +.. clicmd:: clear log filter-text + + This command clears all current filters in the log-filter table. .. clicmd:: log immediate-mode diff --git a/lib/log_vty.c b/lib/log_vty.c index 9dbf216d31..aa1888a9e9 100644 --- a/lib/log_vty.c +++ b/lib/log_vty.c @@ -588,8 +588,9 @@ DEFUN (no_config_log_filterfile, DEFPY (log_filter, log_filter_cmd, - "[no] log-filter WORD$filter", + "[no] log filter-text WORD$filter", NO_STR + "Logging control\n" FILTER_LOG_STR "String to filter by\n") { @@ -616,8 +617,9 @@ DEFPY (log_filter, /* Clear all log filters */ DEFPY (log_filter_clear, log_filter_clear_cmd, - "clear log-filter", + "clear log filter-text", CLEAR_STR + "Logging control\n" FILTER_LOG_STR) { zlog_filter_clear(); @@ -627,8 +629,9 @@ DEFPY (log_filter_clear, /* Show log filter */ DEFPY (show_log_filter, show_log_filter_cmd, - "show log-filter", + "show logging filter-text", SHOW_STR + "Show current logging configuration\n" FILTER_LOG_STR) { char log_filters[ZLOG_FILTERS_MAX * (ZLOG_FILTER_LENGTH_MAX + 3)] = ""; From ba9256d2d089034e66d7c06734a4495afba9513d Mon Sep 17 00:00:00 2001 From: David Lamparter Date: Thu, 8 Apr 2021 14:29:18 +0200 Subject: [PATCH 02/10] lib: add hook for `show logging` CLI ... so additional targets can print their state. Signed-off-by: David Lamparter --- lib/log_vty.c | 3 +++ lib/log_vty.h | 2 ++ 2 files changed, 5 insertions(+) diff --git a/lib/log_vty.c b/lib/log_vty.c index aa1888a9e9..7057a06c51 100644 --- a/lib/log_vty.c +++ b/lib/log_vty.c @@ -34,6 +34,7 @@ #define ZLOG_MAXLVL(a, b) MAX(a, b) DEFINE_HOOK(zlog_rotate, (), ()); +DEFINE_HOOK(zlog_cli_show, (struct vty * vty), (vty)); static const int log_default_lvl = LOG_DEBUG; @@ -194,6 +195,8 @@ DEFUN_NOSH (show_logging, vty_out(vty, "Record priority: %s\n", (zt_file.record_priority ? "enabled" : "disabled")); vty_out(vty, "Timestamp precision: %d\n", zt_file.ts_subsec); + + hook_call(zlog_cli_show, vty); return CMD_SUCCESS; } diff --git a/lib/log_vty.h b/lib/log_vty.h index f0fb7d3dba..913ff5f88e 100644 --- a/lib/log_vty.h +++ b/lib/log_vty.h @@ -37,6 +37,8 @@ extern void log_show_syslog(struct vty *vty); DECLARE_HOOK(zlog_rotate, (), ()); extern void zlog_rotate(void); +DECLARE_HOOK(zlog_cli_show, (struct vty * vty), (vty)); + #ifdef __cplusplus } #endif From e3daa82c1897c289384988add6932f74b0de4e9e Mon Sep 17 00:00:00 2001 From: David Lamparter Date: Mon, 22 Mar 2021 13:45:20 +0100 Subject: [PATCH 03/10] lib: record output argument positions in zlog printfrr() recently acquired the capability to record start/end of formatting outputs. Make use of this in the zlog code so logging targets have access to this information. (This also records how long the `[XXXXX-XXXXX][EC 9999999]` prefix was so log targets can choose to skip over it.) Signed-off-by: David Lamparter --- lib/zlog.c | 33 ++++++++++++++++++++++++++++++++- lib/zlog.h | 4 ++++ 2 files changed, 36 insertions(+), 1 deletion(-) diff --git a/lib/zlog.c b/lib/zlog.c index 89ab9265d1..c96e2fc08e 100644 --- a/lib/zlog.c +++ b/lib/zlog.c @@ -107,6 +107,7 @@ struct zlog_msg { size_t stackbufsz; char *text; size_t textlen; + size_t hdrlen; /* This is always ISO8601 with sub-second precision 9 here, it's * converted for callers as needed. ts_dot points to the "." @@ -118,6 +119,15 @@ struct zlog_msg { */ uint32_t ts_flags; char ts_str[32], *ts_dot, ts_zonetail[8]; + + /* at the time of writing, 16 args was the actual maximum of arguments + * to a single zlog call. Particularly printing flag bitmasks seems + * to drive this. That said, the overhead of dynamically sizing this + * probably outweighs the value. If anything, a printfrr extension + * for printing flag bitmasks might be a good idea. + */ + struct fmt_outpos argpos[24]; + size_t n_argpos; }; /* thread-local log message buffering @@ -592,9 +602,13 @@ const char *zlog_msg_text(struct zlog_msg *msg, size_t *textlen) if (need) need += bputch(&fb, ' '); - hdrlen = need; + msg->hdrlen = hdrlen = need; assert(hdrlen < msg->stackbufsz); + fb.outpos = msg->argpos; + fb.outpos_n = array_size(msg->argpos); + fb.outpos_i = 0; + va_copy(args, msg->args); need += vbprintfrr(&fb, msg->fmt, args); va_end(args); @@ -612,6 +626,7 @@ const char *zlog_msg_text(struct zlog_msg *msg, size_t *textlen) fb.buf = msg->text; fb.len = need; fb.pos = msg->text + hdrlen; + fb.outpos_i = 0; va_copy(args, msg->args); vbprintfrr(&fb, msg->fmt, args); @@ -619,12 +634,28 @@ const char *zlog_msg_text(struct zlog_msg *msg, size_t *textlen) bputch(&fb, '\0'); } + + msg->n_argpos = fb.outpos_i; } if (textlen) *textlen = msg->textlen; return msg->text; } +void zlog_msg_args(struct zlog_msg *msg, size_t *hdrlen, size_t *n_argpos, + const struct fmt_outpos **argpos) +{ + if (!msg->text) + zlog_msg_text(msg, NULL); + + if (hdrlen) + *hdrlen = msg->hdrlen; + if (n_argpos) + *n_argpos = msg->n_argpos; + if (argpos) + *argpos = msg->argpos; +} + #define ZLOG_TS_FORMAT (ZLOG_TS_ISO8601 | ZLOG_TS_LEGACY) #define ZLOG_TS_FLAGS ~ZLOG_TS_PREC diff --git a/lib/zlog.h b/lib/zlog.h index c421c16f38..b463606d97 100644 --- a/lib/zlog.h +++ b/lib/zlog.h @@ -31,6 +31,7 @@ #include "frrcu.h" #include "memory.h" #include "hook.h" +#include "printfrr.h" #ifdef __cplusplus extern "C" { @@ -146,6 +147,9 @@ extern const struct xref_logmsg *zlog_msg_xref(struct zlog_msg *msg); /* pass NULL as textlen if you don't need it. */ extern const char *zlog_msg_text(struct zlog_msg *msg, size_t *textlen); +extern void zlog_msg_args(struct zlog_msg *msg, size_t *hdrlen, + size_t *n_argpos, const struct fmt_outpos **argpos); + /* timestamp formatting control flags */ /* sub-second digit count */ From f6caaa6524342ba734ba8266b5f808d8d1c1e80b Mon Sep 17 00:00:00 2001 From: David Lamparter Date: Sat, 10 Apr 2021 21:36:50 +0200 Subject: [PATCH 04/10] lib: use fbuf for zlog_msg_ts() Signed-off-by: David Lamparter --- lib/zlog.c | 39 ++++++++++++++++++++++++++------------- lib/zlog.h | 2 +- lib/zlog_targets.c | 14 ++++++++++---- 3 files changed, 37 insertions(+), 18 deletions(-) diff --git a/lib/zlog.c b/lib/zlog.c index c96e2fc08e..e843c1e475 100644 --- a/lib/zlog.c +++ b/lib/zlog.c @@ -659,9 +659,9 @@ void zlog_msg_args(struct zlog_msg *msg, size_t *hdrlen, size_t *n_argpos, #define ZLOG_TS_FORMAT (ZLOG_TS_ISO8601 | ZLOG_TS_LEGACY) #define ZLOG_TS_FLAGS ~ZLOG_TS_PREC -size_t zlog_msg_ts(struct zlog_msg *msg, char *out, size_t outsz, - uint32_t flags) +size_t zlog_msg_ts(struct zlog_msg *msg, struct fbuf *out, uint32_t flags) { + size_t outsz = out ? (out->buf + out->len - out->pos) : 0; size_t len1; if (!(flags & ZLOG_TS_FORMAT)) @@ -703,32 +703,45 @@ size_t zlog_msg_ts(struct zlog_msg *msg, char *out, size_t outsz, len1 = strlen(msg->ts_str); if (flags & ZLOG_TS_LEGACY) { - if (len1 + 1 > outsz) - return 0; + if (!out) + return len1; + + if (len1 > outsz) { + memset(out->pos, 0, outsz); + out->pos += outsz; + return len1; + } /* just swap out the formatting, faster than redoing it */ for (char *p = msg->ts_str; p < msg->ts_str + len1; p++) { switch (*p) { case '-': - *out++ = '/'; + *out->pos++ = '/'; break; case 'T': - *out++ = ' '; + *out->pos++ = ' '; break; default: - *out++ = *p; + *out->pos++ = *p; } } - *out = '\0'; return len1; } else { size_t len2 = strlen(msg->ts_zonetail); - if (len1 + len2 + 1 > outsz) - return 0; - memcpy(out, msg->ts_str, len1); - memcpy(out + len1, msg->ts_zonetail, len2); - out[len1 + len2] = '\0'; + if (!out) + return len1 + len2; + + if (len1 + len2 > outsz) { + memset(out->pos, 0, outsz); + out->pos += outsz; + return len1 + len2; + } + + memcpy(out->pos, msg->ts_str, len1); + out->pos += len1; + memcpy(out->pos, msg->ts_zonetail, len2); + out->pos += len2; return len1 + len2; } } diff --git a/lib/zlog.h b/lib/zlog.h index b463606d97..452dbcbd0f 100644 --- a/lib/zlog.h +++ b/lib/zlog.h @@ -165,7 +165,7 @@ extern void zlog_msg_args(struct zlog_msg *msg, size_t *hdrlen, /* default is local time zone */ #define ZLOG_TS_UTC (1 << 10) -extern size_t zlog_msg_ts(struct zlog_msg *msg, char *out, size_t outsz, +extern size_t zlog_msg_ts(struct zlog_msg *msg, struct fbuf *out, uint32_t flags); /* This list & struct implements the actual logging targets. It is accessed diff --git a/lib/zlog_targets.c b/lib/zlog_targets.c index 7799fbfda7..80cb246b7a 100644 --- a/lib/zlog_targets.c +++ b/lib/zlog_targets.c @@ -82,10 +82,16 @@ void zlog_fd(struct zlog_target *zt, struct zlog_msg *msgs[], size_t nmsgs) iov[iovpos].iov_base = ts_pos; if (iovpos > 0) *ts_pos++ = '\n'; - ts_pos += zlog_msg_ts(msg, ts_pos, - sizeof(ts_buf) - 1 - - (ts_pos - ts_buf), - ZLOG_TS_LEGACY | zte->ts_subsec); + + struct fbuf fbuf = { + .buf = ts_buf, + .pos = ts_pos, + .len = sizeof(ts_buf), + }; + zlog_msg_ts(msg, &fbuf, + ZLOG_TS_LEGACY | zte->ts_subsec); + ts_pos = fbuf.pos; + *ts_pos++ = ' '; iov[iovpos].iov_len = ts_pos - (char *)iov[iovpos].iov_base; From 243ff228a9b4b680c2c405320634f4f72c65191c Mon Sep 17 00:00:00 2001 From: David Lamparter Date: Thu, 8 Apr 2021 14:28:43 +0200 Subject: [PATCH 05/10] lib: add RFC3164 logging timestamps This is old-style syslog, used among other things for /dev/log. Signed-off-by: David Lamparter --- lib/zlog.c | 37 ++++++++++++++++++++++++++++++++++++- lib/zlog.h | 4 ++++ 2 files changed, 40 insertions(+), 1 deletion(-) diff --git a/lib/zlog.c b/lib/zlog.c index e843c1e475..d88337cb83 100644 --- a/lib/zlog.c +++ b/lib/zlog.c @@ -117,8 +117,14 @@ struct zlog_msg { * Valid if ZLOG_TS_ISO8601 is set. * (0 if timestamp has not been formatted yet) */ - uint32_t ts_flags; char ts_str[32], *ts_dot, ts_zonetail[8]; + uint32_t ts_flags; + + /* "mmm dd hh:mm:ss" for 3164 legacy syslog - too dissimilar from + * the above, so just kept separately here. + */ + uint32_t ts_3164_flags; + char ts_3164_str[16]; /* at the time of writing, 16 args was the actual maximum of arguments * to a single zlog call. Particularly printing flag bitmasks seems @@ -746,6 +752,35 @@ size_t zlog_msg_ts(struct zlog_msg *msg, struct fbuf *out, uint32_t flags) } } +size_t zlog_msg_ts_3164(struct zlog_msg *msg, struct fbuf *out, uint32_t flags) +{ + flags &= ZLOG_TS_UTC; + + if (!msg->ts_3164_str[0] || flags != msg->ts_3164_flags) { + /* these are "hardcoded" in RFC3164, so they're here too... */ + static const char *const months[12] = { + "Jan", "Feb", "Mar", "Apr", "May", "Jun", + "Jul", "Aug", "Sep", "Oct", "Nov", "Dec", + }; + struct tm tm; + + /* RFC3164 explicitly asks for local time, but common usage + * also includes UTC. + */ + if (flags & ZLOG_TS_UTC) + gmtime_r(&msg->ts.tv_sec, &tm); + else + localtime_r(&msg->ts.tv_sec, &tm); + + snprintfrr(msg->ts_3164_str, sizeof(msg->ts_3164_str), + "%3s %2d %02d:%02d:%02d", months[tm.tm_mon], + tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec); + + msg->ts_3164_flags = flags; + } + return bputs(out, msg->ts_3164_str); +} + void zlog_set_prefix_ec(bool enable) { atomic_store_explicit(&zlog_ec, enable, memory_order_relaxed); diff --git a/lib/zlog.h b/lib/zlog.h index 452dbcbd0f..f71d28c99a 100644 --- a/lib/zlog.h +++ b/lib/zlog.h @@ -168,6 +168,10 @@ extern void zlog_msg_args(struct zlog_msg *msg, size_t *hdrlen, extern size_t zlog_msg_ts(struct zlog_msg *msg, struct fbuf *out, uint32_t flags); +/* "mmm dd hh:mm:ss" for RFC3164 syslog. Only ZLOG_TS_UTC for flags. */ +extern size_t zlog_msg_ts_3164(struct zlog_msg *msg, struct fbuf *out, + uint32_t flags); + /* This list & struct implements the actual logging targets. It is accessed * lock-free from all threads, and thus MUST only be changed atomically, i.e. * RCU. From 8b94cb4388d62ad341ff352266dd5d91780e4eec Mon Sep 17 00:00:00 2001 From: David Lamparter Date: Sat, 10 Apr 2021 21:51:48 +0200 Subject: [PATCH 06/10] lib: include `\n` in zlog_msg_text() Since the file targets append one anyway, save them some extra work. syslog can use `%.*s` since it's "forced" printf by API anyway. Signed-off-by: David Lamparter --- lib/log_filter.c | 16 ++++++++++------ lib/zlog.c | 4 ++-- lib/zlog.h | 8 +++++++- lib/zlog_targets.c | 20 ++++++++------------ 4 files changed, 27 insertions(+), 21 deletions(-) diff --git a/lib/log_filter.c b/lib/log_filter.c index 721e57a628..f01497dead 100644 --- a/lib/log_filter.c +++ b/lib/log_filter.c @@ -111,13 +111,14 @@ int zlog_filter_dump(char *buf, size_t max_size) return len; } -static int search_buf(const char *buf) +static int search_buf(const char *buf, size_t len) { char *found = NULL; frr_with_mutex(&logfilterlock) { for (int i = 0; i < zlog_filter_count; i++) { - found = strstr(buf, zlog_filters[i]); + found = memmem(buf, len, zlog_filters[i], + strlen(zlog_filters[i])); if (found != NULL) return 0; } @@ -131,12 +132,15 @@ static void zlog_filterfile_fd(struct zlog_target *zt, struct zlog_msg *msgs[], { struct zlog_msg *msgfilt[nmsgs]; size_t i, o = 0; + const char *text; + size_t text_len; for (i = 0; i < nmsgs; i++) { - if (zlog_msg_prio(msgs[i]) >= LOG_DEBUG - && search_buf(zlog_msg_text(msgs[i], NULL)) < 0) - continue; - + if (zlog_msg_prio(msgs[i]) >= LOG_DEBUG) { + text = zlog_msg_text(msgs[i], &text_len); + if (search_buf(text, text_len) < 0) + continue; + } msgfilt[o++] = msgs[i]; } diff --git a/lib/zlog.c b/lib/zlog.c index d88337cb83..91cb7151eb 100644 --- a/lib/zlog.c +++ b/lib/zlog.c @@ -620,7 +620,7 @@ const char *zlog_msg_text(struct zlog_msg *msg, size_t *textlen) va_end(args); msg->textlen = need; - need += bputch(&fb, '\0'); + need += bputch(&fb, '\n'); if (need <= msg->stackbufsz) msg->text = msg->stackbuf; @@ -638,7 +638,7 @@ const char *zlog_msg_text(struct zlog_msg *msg, size_t *textlen) vbprintfrr(&fb, msg->fmt, args); va_end(args); - bputch(&fb, '\0'); + bputch(&fb, '\n'); } msg->n_argpos = fb.outpos_i; diff --git a/lib/zlog.h b/lib/zlog.h index f71d28c99a..1b03e3fd12 100644 --- a/lib/zlog.h +++ b/lib/zlog.h @@ -144,7 +144,13 @@ struct zlog_msg; extern int zlog_msg_prio(struct zlog_msg *msg); extern const struct xref_logmsg *zlog_msg_xref(struct zlog_msg *msg); -/* pass NULL as textlen if you don't need it. */ +/* text is NOT \0 terminated; instead there is a \n after textlen since the + * logging targets would jump extra hoops otherwise for a single byte. (the + * \n is not included in textlen) + * + * calling this with NULL textlen is likely wrong. + * use "%.*s", (int)textlen, text when passing to printf-like functions + */ extern const char *zlog_msg_text(struct zlog_msg *msg, size_t *textlen); extern void zlog_msg_args(struct zlog_msg *msg, size_t *hdrlen, diff --git a/lib/zlog_targets.c b/lib/zlog_targets.c index 80cb246b7a..127de12240 100644 --- a/lib/zlog_targets.c +++ b/lib/zlog_targets.c @@ -79,15 +79,13 @@ void zlog_fd(struct zlog_target *zt, struct zlog_msg *msgs[], size_t nmsgs) int prio = zlog_msg_prio(msg); if (prio <= zt->prio_min) { - iov[iovpos].iov_base = ts_pos; - if (iovpos > 0) - *ts_pos++ = '\n'; - struct fbuf fbuf = { .buf = ts_buf, .pos = ts_pos, .len = sizeof(ts_buf), }; + + iov[iovpos].iov_base = ts_pos; zlog_msg_ts(msg, &fbuf, ZLOG_TS_LEGACY | zte->ts_subsec); ts_pos = fbuf.pos; @@ -113,7 +111,7 @@ void zlog_fd(struct zlog_target *zt, struct zlog_msg *msgs[], size_t nmsgs) iov[iovpos].iov_base = (char *)zlog_msg_text(msg, &textlen); - iov[iovpos].iov_len = textlen; + iov[iovpos].iov_len = textlen + 1; iovpos++; } @@ -126,11 +124,6 @@ void zlog_fd(struct zlog_target *zt, struct zlog_msg *msgs[], size_t nmsgs) if (iovpos > 0 && (ts_buf + sizeof(ts_buf) - ts_pos < TS_LEN || i + 1 == nmsgs || array_size(iov) - iovpos < 5)) { - iov[iovpos].iov_base = (char *)"\n"; - iov[iovpos].iov_len = 1; - - iovpos++; - writev(fd, iov, iovpos); iovpos = 0; @@ -445,13 +438,16 @@ static void zlog_syslog(struct zlog_target *zt, struct zlog_msg *msgs[], { size_t i; struct zlt_syslog *zte = container_of(zt, struct zlt_syslog, zt); + const char *text; + size_t text_len; for (i = 0; i < nmsgs; i++) { if (zlog_msg_prio(msgs[i]) > zt->prio_min) continue; - syslog(zlog_msg_prio(msgs[i]) | zte->syslog_facility, "%s", - zlog_msg_text(msgs[i], NULL)); + text = zlog_msg_text(msgs[i], &text_len); + syslog(zlog_msg_prio(msgs[i]) | zte->syslog_facility, "%.*s", + (int)text_len, text); } } From 78598fd0195510d0d1338bf8c28e606d67e63359 Mon Sep 17 00:00:00 2001 From: David Lamparter Date: Sun, 11 Apr 2021 03:59:25 +0200 Subject: [PATCH 07/10] lib: cache PID & TID in zlog code glibc removed its pid cache a while back, and grabbing this from TLS is faster than repeatedly calling the kernel... Also use `intmax_t` which is more appropriate for both PID & TID. Signed-off-by: David Lamparter --- lib/zlog.c | 35 ++++++++++++++++++++++++++++++++--- lib/zlog.h | 5 +++++ 2 files changed, 37 insertions(+), 3 deletions(-) diff --git a/lib/zlog.c b/lib/zlog.c index 91cb7151eb..d44add48b3 100644 --- a/lib/zlog.c +++ b/lib/zlog.c @@ -220,8 +220,15 @@ static inline void zlog_tls_set(struct zlog_tls *val) #endif #ifdef CAN_DO_TLS -static long zlog_gettid(void) +static intmax_t zlog_gettid(void) { +#ifndef __OpenBSD__ + /* accessing a TLS variable is much faster than a syscall */ + static thread_local intmax_t cached_tid = -1; + if (cached_tid != -1) + return cached_tid; +#endif + long rv = -1; #ifdef HAVE_PTHREAD_GETTHREADID_NP rv = pthread_getthreadid_np(); @@ -241,6 +248,10 @@ static long zlog_gettid(void) rv = mach_thread_self(); mach_port_deallocate(mach_task_self(), rv); #endif + +#ifndef __OpenBSD__ + cached_tid = rv; +#endif return rv; } @@ -260,7 +271,7 @@ void zlog_tls_buffer_init(void) for (i = 0; i < array_size(zlog_tls->msgp); i++) zlog_tls->msgp[i] = &zlog_tls->msgs[i]; - snprintfrr(mmpath, sizeof(mmpath), "logbuf.%ld", zlog_gettid()); + snprintfrr(mmpath, sizeof(mmpath), "logbuf.%jd", zlog_gettid()); mmfd = openat(zlog_tmpdirfd, mmpath, O_RDWR | O_CREAT | O_EXCL | O_CLOEXEC, 0600); @@ -327,7 +338,7 @@ void zlog_tls_buffer_fini(void) zlog_tls_free(zlog_tls); zlog_tls_set(NULL); - snprintfrr(mmpath, sizeof(mmpath), "logbuf.%ld", zlog_gettid()); + snprintfrr(mmpath, sizeof(mmpath), "logbuf.%jd", zlog_gettid()); if (do_unlink && unlinkat(zlog_tmpdirfd, mmpath, 0)) zlog_err("unlink logbuf: %s (%d)", strerror(errno), errno); } @@ -342,6 +353,24 @@ void zlog_tls_buffer_fini(void) } #endif +void zlog_msg_pid(struct zlog_msg *msg, intmax_t *pid, intmax_t *tid) +{ +#ifndef __OpenBSD__ + static thread_local intmax_t cached_pid = -1; + if (cached_pid != -1) + *pid = cached_pid; + else + cached_pid = *pid = (intmax_t)getpid(); +#else + *pid = (intmax_t)getpid(); +#endif +#ifdef CAN_DO_TLS + *tid = zlog_gettid(); +#else + *tid = *pid; +#endif +} + static inline void zlog_tls_free(void *arg) { struct zlog_tls *zlog_tls = arg; diff --git a/lib/zlog.h b/lib/zlog.h index 1b03e3fd12..7fd7b0e5c7 100644 --- a/lib/zlog.h +++ b/lib/zlog.h @@ -178,6 +178,11 @@ extern size_t zlog_msg_ts(struct zlog_msg *msg, struct fbuf *out, extern size_t zlog_msg_ts_3164(struct zlog_msg *msg, struct fbuf *out, uint32_t flags); +/* currently just returns the current PID/TID since we never write another + * thread's messages + */ +extern void zlog_msg_pid(struct zlog_msg *msg, intmax_t *pid, intmax_t *tid); + /* This list & struct implements the actual logging targets. It is accessed * lock-free from all threads, and thus MUST only be changed atomically, i.e. * RCU. From 5c58f5d3365276aa3681c8e8a448b3e3ea8669bf Mon Sep 17 00:00:00 2001 From: David Lamparter Date: Sun, 11 Apr 2021 04:00:08 +0200 Subject: [PATCH 08/10] lib: save instance number in zlog Signed-off-by: David Lamparter --- lib/zlog.c | 2 ++ lib/zlog.h | 1 + 2 files changed, 3 insertions(+) diff --git a/lib/zlog.c b/lib/zlog.c index d44add48b3..6fd52cae62 100644 --- a/lib/zlog.c +++ b/lib/zlog.c @@ -67,6 +67,7 @@ DEFINE_HOOK(zlog_aux_init, (const char *prefix, int prio_min), char zlog_prefix[128]; size_t zlog_prefixsz; int zlog_tmpdirfd = -1; +int zlog_instance = -1; static atomic_bool zlog_ec = true, zlog_xid = true; @@ -885,6 +886,7 @@ void zlog_init(const char *progname, const char *protoname, { zlog_uid = uid; zlog_gid = gid; + zlog_instance = instance; if (instance) { snprintfrr(zlog_tmpdir, sizeof(zlog_tmpdir), diff --git a/lib/zlog.h b/lib/zlog.h index 7fd7b0e5c7..ecc30f09b2 100644 --- a/lib/zlog.h +++ b/lib/zlog.h @@ -40,6 +40,7 @@ extern "C" { extern char zlog_prefix[]; extern size_t zlog_prefixsz; extern int zlog_tmpdirfd; +extern int zlog_instance; struct xref_logmsg { struct xref xref; From c6610ea98f44ed2d5d9556076322d3a6a9023675 Mon Sep 17 00:00:00 2001 From: David Lamparter Date: Sun, 11 Apr 2021 18:23:16 +0200 Subject: [PATCH 09/10] lib: make a few log symbols accessible Might've made a few things too many `static` there. Signed-off-by: David Lamparter --- lib/log_vty.c | 13 ++++++++++--- lib/log_vty.h | 3 +++ lib/zlog.h | 5 +++++ lib/zlog_targets.c | 1 - 4 files changed, 18 insertions(+), 4 deletions(-) diff --git a/lib/log_vty.c b/lib/log_vty.c index 7057a06c51..cbb8de8976 100644 --- a/lib/log_vty.c +++ b/lib/log_vty.c @@ -58,7 +58,7 @@ static struct zlog_cfg_filterfile zt_filterfile = { }, }; -static const char *zlog_progname; +const char *zlog_progname; static const char *zlog_protoname; static const struct facility_map { @@ -95,7 +95,14 @@ static const char * const zlog_priority[] = { "notifications", "informational", "debugging", NULL, }; -static const char *facility_name(int facility) +const char *zlog_priority_str(int priority) +{ + if (priority > LOG_DEBUG) + return "???"; + return zlog_priority[priority]; +} + +const char *facility_name(int facility) { const struct facility_map *fm; @@ -105,7 +112,7 @@ static const char *facility_name(int facility) return ""; } -static int facility_match(const char *str) +int facility_match(const char *str) { const struct facility_map *fm; diff --git a/lib/log_vty.h b/lib/log_vty.h index 913ff5f88e..db46b3cb5b 100644 --- a/lib/log_vty.h +++ b/lib/log_vty.h @@ -34,6 +34,9 @@ extern void log_config_write(struct vty *vty); extern int log_level_match(const char *s); extern void log_show_syslog(struct vty *vty); +extern int facility_match(const char *str); +extern const char *facility_name(int facility); + DECLARE_HOOK(zlog_rotate, (), ()); extern void zlog_rotate(void); diff --git a/lib/zlog.h b/lib/zlog.h index ecc30f09b2..d9c8952ac5 100644 --- a/lib/zlog.h +++ b/lib/zlog.h @@ -37,10 +37,13 @@ extern "C" { #endif +DECLARE_MGROUP(LOG); + extern char zlog_prefix[]; extern size_t zlog_prefixsz; extern int zlog_tmpdirfd; extern int zlog_instance; +extern const char *zlog_progname; struct xref_logmsg { struct xref xref; @@ -274,6 +277,8 @@ extern void zlog_tls_buffer_fini(void); /* Enable or disable 'immediate' output - default is to buffer messages. */ extern void zlog_set_immediate(bool set_p); +extern const char *zlog_priority_str(int priority); + #ifdef __cplusplus } #endif diff --git a/lib/zlog_targets.c b/lib/zlog_targets.c index 127de12240..48785ad298 100644 --- a/lib/zlog_targets.c +++ b/lib/zlog_targets.c @@ -31,7 +31,6 @@ * absolute end. */ -DECLARE_MGROUP(LOG); DEFINE_MGROUP_ACTIVEATEXIT(LOG, "logging subsystem"); DEFINE_MTYPE_STATIC(LOG, LOG_FD, "log file target"); From ca846ff82c5ed74cd5d71f316d4a3e428655cc1f Mon Sep 17 00:00:00 2001 From: David Lamparter Date: Tue, 13 Apr 2021 00:52:55 +0200 Subject: [PATCH 10/10] lib: fix printf format on NetBSD *sigh*. It doesn't accept `%m` otherwise. Signed-off-by: David Lamparter --- lib/compiler.h | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/lib/compiler.h b/lib/compiler.h index bbfe01b569..8b8ec08c25 100644 --- a/lib/compiler.h +++ b/lib/compiler.h @@ -356,7 +356,11 @@ extern "C" { #define PRIx64 "Lx" #else /* !_FRR_ATTRIBUTE_PRINTFRR */ +#ifdef __NetBSD__ +#define PRINTFRR(a, b) __attribute__((format(gnu_syslog, a, b))) +#else #define PRINTFRR(a, b) __attribute__((format(printf, a, b))) +#endif /* frr-format plugin is C-only for now, so no point in doing these shenanigans * for C++... (also they can break some C++ stuff...)