From a3c67498603dbba7030d2cefe3395840a87e3f8d Mon Sep 17 00:00:00 2001 From: David Lamparter Date: Wed, 3 Mar 2021 00:14:02 +0100 Subject: [PATCH] lib: add [XXXXX-XXXXX] log prefix & config This logs the unique ID prefix from the xref that each log message call has, and adds on/off knobs for both EC and unique ID printing. Signed-off-by: David Lamparter --- lib/log_vty.c | 32 +++++++++++++++++++++++ lib/zlog.c | 70 ++++++++++++++++++++++++++++++++++++++++++++++++--- lib/zlog.h | 40 ++++++++++------------------- 3 files changed, 112 insertions(+), 30 deletions(-) diff --git a/lib/log_vty.c b/lib/log_vty.c index 7dadca8059..c26621ae99 100644 --- a/lib/log_vty.c +++ b/lib/log_vty.c @@ -532,6 +532,28 @@ DEFUN (no_config_log_timestamp_precision, return CMD_SUCCESS; } +DEFPY (config_log_ec, + config_log_ec_cmd, + "[no] log error-category", + NO_STR + "Logging control\n" + "Prefix log message text with [EC 9999] code\n") +{ + zlog_set_prefix_ec(!no); + return CMD_SUCCESS; +} + +DEFPY (config_log_xid, + config_log_xid_cmd, + "[no] log unique-id", + NO_STR + "Logging control\n" + "Prefix log message text with [XXXXX-XXXXX] identifier\n") +{ + zlog_set_prefix_xid(!no); + return CMD_SUCCESS; +} + DEFPY (config_log_filterfile, config_log_filterfile_cmd, "log filtered-file FILENAME [$levelarg]", @@ -699,6 +721,11 @@ void log_config_write(struct vty *vty) if (zt_file.ts_subsec > 0) vty_out(vty, "log timestamp precision %d\n", zt_file.ts_subsec); + + if (!zlog_get_prefix_ec()) + vty_out(vty, "no log error-category\n"); + if (!zlog_get_prefix_xid()) + vty_out(vty, "no log unique-id\n"); } static int log_vty_init(const char *progname, const char *protoname, @@ -707,6 +734,9 @@ static int log_vty_init(const char *progname, const char *protoname, zlog_progname = progname; zlog_protoname = protoname; + zlog_set_prefix_ec(true); + zlog_set_prefix_xid(true); + zlog_filterfile_init(&zt_filterfile); zlog_file_set_fd(&zt_stdout, STDOUT_FILENO); @@ -737,6 +767,8 @@ void log_cmd_init(void) install_element(CONFIG_NODE, &no_config_log_record_priority_cmd); install_element(CONFIG_NODE, &config_log_timestamp_precision_cmd); install_element(CONFIG_NODE, &no_config_log_timestamp_precision_cmd); + install_element(CONFIG_NODE, &config_log_ec_cmd); + install_element(CONFIG_NODE, &config_log_xid_cmd); install_element(VIEW_NODE, &show_log_filter_cmd); install_element(CONFIG_NODE, &log_filter_cmd); diff --git a/lib/zlog.c b/lib/zlog.c index 7304854648..f546709328 100644 --- a/lib/zlog.c +++ b/lib/zlog.c @@ -68,6 +68,8 @@ char zlog_prefix[128]; size_t zlog_prefixsz; int zlog_tmpdirfd = -1; +static atomic_bool zlog_ec = true, zlog_xid = true; + /* these are kept around because logging is initialized (and directories * & files created) before zprivs code switches to the FRR user; therefore * we need to chown() things so we don't get permission errors later when @@ -530,12 +532,54 @@ const char *zlog_msg_text(struct zlog_msg *msg, size_t *textlen) { if (!msg->text) { va_list args; + bool do_xid, do_ec; + size_t need = 0, hdrlen; + struct fbuf fb = { + .buf = msg->stackbuf, + .pos = msg->stackbuf, + .len = msg->stackbufsz, + }; + + do_ec = atomic_load_explicit(&zlog_ec, memory_order_relaxed); + do_xid = atomic_load_explicit(&zlog_xid, memory_order_relaxed); + + if (msg->xref && do_xid && msg->xref->xref.xrefdata->uid[0]) { + need += bputch(&fb, '['); + need += bputs(&fb, msg->xref->xref.xrefdata->uid); + need += bputch(&fb, ']'); + } + if (msg->xref && do_ec && msg->xref->ec) + need += bprintfrr(&fb, "[EC %u]", msg->xref->ec); + if (need) + need += bputch(&fb, ' '); + + hdrlen = need; + assert(hdrlen < msg->stackbufsz); va_copy(args, msg->args); - msg->text = vasnprintfrr(MTYPE_LOG_MESSAGE, msg->stackbuf, - msg->stackbufsz, msg->fmt, args); - msg->textlen = strlen(msg->text); + need += vbprintfrr(&fb, msg->fmt, args); va_end(args); + + msg->textlen = need; + need += bputch(&fb, '\0'); + + if (need <= msg->stackbufsz) + msg->text = msg->stackbuf; + else { + msg->text = XMALLOC(MTYPE_LOG_MESSAGE, need); + + memcpy(msg->text, msg->stackbuf, hdrlen); + + fb.buf = msg->text; + fb.len = need; + fb.pos = msg->text + hdrlen; + + va_copy(args, msg->args); + vbprintfrr(&fb, msg->fmt, args); + va_end(args); + + bputch(&fb, '\0'); + } } if (textlen) *textlen = msg->textlen; @@ -619,6 +663,26 @@ size_t zlog_msg_ts(struct zlog_msg *msg, char *out, size_t outsz, } } +void zlog_set_prefix_ec(bool enable) +{ + atomic_store_explicit(&zlog_ec, enable, memory_order_relaxed); +} + +bool zlog_get_prefix_ec(void) +{ + return atomic_load_explicit(&zlog_ec, memory_order_relaxed); +} + +void zlog_set_prefix_xid(bool enable) +{ + atomic_store_explicit(&zlog_xid, enable, memory_order_relaxed); +} + +bool zlog_get_prefix_xid(void) +{ + return atomic_load_explicit(&zlog_xid, memory_order_relaxed); +} + /* setup functions */ struct zlog_target *zlog_target_clone(struct memtype *mt, diff --git a/lib/zlog.h b/lib/zlog.h index 25c2627f38..66d8f1e5d7 100644 --- a/lib/zlog.h +++ b/lib/zlog.h @@ -85,31 +85,6 @@ static inline void zlog_ref(const struct xref_logmsg *xref, va_end(ap); } -#define _zlog_ref(prio, msg, ...) \ - do { \ - static struct xrefdata _xrefdata = { \ - .xref = NULL, \ - .uid = {}, \ - .hashstr = (msg), \ - .hashu32 = {(prio), 0}, \ - }; \ - static const struct xref_logmsg _xref __attribute__( \ - (used)) = { \ - .xref = XREF_INIT(XREFT_LOGMSG, &_xrefdata, __func__), \ - .fmtstring = (msg), \ - .priority = (prio), \ - .args = (#__VA_ARGS__), \ - }; \ - XREF_LINK(_xref.xref); \ - zlog_ref(&_xref, (msg), ##__VA_ARGS__); \ - } while (0) - -#define zlog_err(...) _zlog_ref(LOG_ERR, __VA_ARGS__) -#define zlog_warn(...) _zlog_ref(LOG_WARNING, __VA_ARGS__) -#define zlog_info(...) _zlog_ref(LOG_INFO, __VA_ARGS__) -#define zlog_notice(...) _zlog_ref(LOG_NOTICE, __VA_ARGS__) -#define zlog_debug(...) _zlog_ref(LOG_DEBUG, __VA_ARGS__) - #define _zlog_ecref(ec_, prio, msg, ...) \ do { \ static struct xrefdata _xrefdata = { \ @@ -127,16 +102,22 @@ static inline void zlog_ref(const struct xref_logmsg *xref, .args = (#__VA_ARGS__), \ }; \ XREF_LINK(_xref.xref); \ - zlog_ref(&_xref, "[EC %u] " msg, ec_, ##__VA_ARGS__); \ + zlog_ref(&_xref, (msg), ##__VA_ARGS__); \ } while (0) +#define zlog_err(...) _zlog_ecref(0, LOG_ERR, __VA_ARGS__) +#define zlog_warn(...) _zlog_ecref(0, LOG_WARNING, __VA_ARGS__) +#define zlog_info(...) _zlog_ecref(0, LOG_INFO, __VA_ARGS__) +#define zlog_notice(...) _zlog_ecref(0, LOG_NOTICE, __VA_ARGS__) +#define zlog_debug(...) _zlog_ecref(0, LOG_DEBUG, __VA_ARGS__) + #define flog_err(ferr_id, format, ...) \ _zlog_ecref(ferr_id, LOG_ERR, format, ## __VA_ARGS__) #define flog_warn(ferr_id, format, ...) \ _zlog_ecref(ferr_id, LOG_WARNING, format, ## __VA_ARGS__) #define flog_err_sys(ferr_id, format, ...) \ - flog_err(ferr_id, format, ##__VA_ARGS__) + _zlog_ecref(ferr_id, LOG_ERR, format, ## __VA_ARGS__) extern void zlog_sigsafe(const char *text, size_t len); @@ -250,6 +231,11 @@ DECLARE_HOOK(zlog_init, (const char *progname, const char *protoname, extern void zlog_fini(void); DECLARE_KOOH(zlog_fini, (), ()); +extern void zlog_set_prefix_ec(bool enable); +extern bool zlog_get_prefix_ec(void); +extern void zlog_set_prefix_xid(bool enable); +extern bool zlog_get_prefix_xid(void); + /* for tools & test programs, i.e. anything not a daemon. * (no cleanup needed at exit) */