diff --git a/bfdd/bfdd.c b/bfdd/bfdd.c index bed6ccd14219..e8e213c748dd 100644 --- a/bfdd/bfdd.c +++ b/bfdd/bfdd.c @@ -25,6 +25,7 @@ #include "bfd.h" #include "bfdd_nb.h" #include "lib/version.h" +#include "lib/command.h" /* diff --git a/bgpd/rfapi/rfapi_vty.c b/bgpd/rfapi/rfapi_vty.c index 89f6852e2b57..7a42e5aed901 100644 --- a/bgpd/rfapi/rfapi_vty.c +++ b/bgpd/rfapi/rfapi_vty.c @@ -25,7 +25,6 @@ #include "lib/memory.h" #include "lib/routemap.h" #include "lib/log.h" -#include "lib/log_int.h" #include "lib/linklist.h" #include "lib/command.h" @@ -371,7 +370,7 @@ int rfapiStream2Vty(void *stream, /* input */ *fp = (int (*)(void *, const char *, ...))rfapiDebugPrintf; *outstream = NULL; *vty_newline = str_vty_newline(*vty); - return (vzlog_test(LOG_DEBUG)); + return 1; } if (((uintptr_t)stream == (uintptr_t)1) diff --git a/bgpd/valgrind.supp b/bgpd/valgrind.supp index 7a25c88363e0..ed236a6dc5a4 100644 --- a/bgpd/valgrind.supp +++ b/bgpd/valgrind.supp @@ -7,3 +7,11 @@ fun:ly_load_plugins_dir fun:ly_load_plugins } +{ + + Memcheck:Leak + match-leak-kinds: reachable + fun:calloc + fun:qcalloc + fun:zlog_target_clone +} diff --git a/configure.ac b/configure.ac index 35261aced473..6f7ca9defd8d 100755 --- a/configure.ac +++ b/configure.ac @@ -959,7 +959,7 @@ int main(int argc, char **argv) { AC_CHECK_HEADERS([pthread_np.h],,, [ #include ]) -AC_CHECK_FUNCS([pthread_setname_np pthread_set_name_np]) +AC_CHECK_FUNCS([pthread_setname_np pthread_set_name_np pthread_getthreadid_np]) needsync=true @@ -1202,7 +1202,11 @@ dnl other functions dnl --------------- AC_CHECK_FUNCS([ \ strlcat strlcpy \ - getgrouplist]) + getgrouplist \ + openat \ + unlinkat \ + posix_fallocate \ + ]) dnl ########################################################################## dnl LARGE if block spans a lot of "configure"! @@ -2197,22 +2201,12 @@ if test "$enable_backtrace" != "no" ; then fi if test "$backtrace_ok" = "no"; then - case "$host_os" in - sunos* | solaris2*) - AC_CHECK_FUNCS([printstack], [ - AC_DEFINE([HAVE_PRINTSTACK], [1], [Solaris printstack]) + AC_CHECK_HEADER([execinfo.h], [ + AC_SEARCH_LIBS([backtrace], [execinfo], [ + AC_DEFINE([HAVE_GLIBC_BACKTRACE], [1], [Glibc backtrace]) backtrace_ok=yes - ]) - ;; - esac - if test "$backtrace_ok" = "no"; then - AC_CHECK_HEADER([execinfo.h], [ - AC_SEARCH_LIBS([backtrace], [execinfo], [ - AC_DEFINE([HAVE_GLIBC_BACKTRACE], [1], [Glibc backtrace]) - backtrace_ok=yes - ],, [-lm]) - ]) - fi + ],, [-lm]) + ]) fi if test "$enable_backtrace" = "yes" -a "$backtrace_ok" = "no"; then diff --git a/doc/developer/logging.rst b/doc/developer/logging.rst index db577c921603..0430ad72a3b1 100644 --- a/doc/developer/logging.rst +++ b/doc/developer/logging.rst @@ -1,7 +1,7 @@ .. _logging: -Developer's Guide to Logging -============================ +Logging +======= One of the most frequent decisions to make while writing code for FRR is what to log, what level to log it at, and when to log it. Here is a list of @@ -116,8 +116,11 @@ AS-Safety while AS-Safe) * extensions are only AS-Safe if their printer is AS-Safe +Log levels +---------- + Errors and warnings -------------------- +^^^^^^^^^^^^^^^^^^^ If it is something that the user will want to look at and maybe do something, it is either an **error** or a **warning**. @@ -163,7 +166,7 @@ Examples for errors: Informational messages ----------------------- +^^^^^^^^^^^^^^^^^^^^^^ Anything that provides introspection to the user during normal operation is an **info** message. @@ -202,7 +205,7 @@ Examples: Debug messages and asserts --------------------------- +^^^^^^^^^^^^^^^^^^^^^^^^^^ Everything that is only interesting on-demand, or only while developing, is a **debug** message. It might be interesting to the user for a @@ -239,3 +242,180 @@ Examples: * some field that is absolutely needed is :code:`NULL` * any other kind of data structure corruption that will cause the daemon to crash sooner or later, one way or another + +Thread-local buffering +---------------------- + +The core logging code in :file:`lib/zlog.c` allows setting up per-thread log +message buffers in order to improve logging performance. The following rules +apply for this buffering: + +* Only messages of priority *DEBUG* or *INFO* are buffered. +* Any higher-priority message causes the thread's entire buffer to be flushed, + thus message ordering is preserved on a per-thread level. +* There is no guarantee on ordering between different threads; in most cases + this is arbitrary to begin with since the threads essentially race each + other in printing log messages. If an order is established with some + synchronization primitive, add calls to :c:func:`zlog_tls_buffer_flush()`. +* The buffers are only ever accessed by the thread they are created by. This + means no locking is necessary. + +Both the main/default thread and additional threads created by +:c:func:`frr_pthread_new()` with the default :c:func:`frr_run()` handler will +initialize thread-local buffering and call :c:func:`zlog_tls_buffer_flush()` +when idle. + +If some piece of code runs for an extended period, it may be useful to insert +calls to :c:func:`zlog_tls_buffer_flush()` in appropriate places: + +.. c:function:: void zlog_tls_buffer_flush(void) + + Write out any pending log messages that the calling thread may have in its + buffer. This function is safe to call regardless of the per-thread log + buffer being set up / in use or not. + +When working with threads that do not use the :c:type:`struct thread_master` +event loop, per-thread buffers can be managed with: + +.. c:function:: void zlog_tls_buffer_init(void) + + Set up thread-local buffering for log messages. This function may be + called repeatedly without adverse effects, but remember to call + :c:func:`zlog_tls_buffer_fini()` at thread exit. + + .. warning:: + + If this function is called, but :c:func:`zlog_tls_buffer_flush()` is + not used, log message output will lag behind since messages will only be + written out when the buffer is full. + + Exiting the thread without calling :c:func:`zlog_tls_buffer_fini()` + will cause buffered log messages to be lost. + +.. c:function:: void zlog_tls_buffer_fini(void) + + Flush pending messages and tear down thread-local log message buffering. + This function may be called repeatedly regardless of whether + :c:func:`zlog_tls_buffer_init()` was ever called. + +Log targets +----------- + +The actual logging subsystem (in :file:`lib/zlog.c`) is heavily separated +from the actual log writers. It uses an atomic linked-list (`zlog_targets`) +with RCU to maintain the log targets to be called. This list is intended to +function as "backend" only, it **is not used for configuration**. + +Logging targets provide their configuration layer on top of this and maintain +their own capability to enumerate and store their configuration. Some targets +(e.g. syslog) are inherently single instance and just stuff their config in +global variables. Others (e.g. file/fd output) are multi-instance capable. +There is another layer boundary here between these and the VTY configuration +that they use. + +Basic internals +^^^^^^^^^^^^^^^ + +.. c:type:: struct zlog_target + + This struct needs to be filled in by any log target and then passed to + :c:func:`zlog_target_replace()`. After it has been registered, + **RCU semantics apply**. Most changes to associated data should make a + copy, change that, and then replace the entire struct. + + Additional per-target data should be "appended" by embedding this struct + into a larger one, for use with `containerof()`, and + :c:func:`zlog_target_clone()` and :c:func:`zlog_target_free()` should be + used to allocate/free the entire container struct. + + Do not use this structure to maintain configuration. It should only + contain (a copy of) the data needed to perform the actual logging. For + example, the syslog target uses this: + + .. code-block:: c + + struct zlt_syslog { + struct zlog_target zt; + int syslog_facility; + }; + + static void zlog_syslog(struct zlog_target *zt, struct zlog_msg *msgs[], size_t nmsgs) + { + struct zlt_syslog *zte = container_of(zt, struct zlt_syslog, zt); + size_t i; + + for (i = 0; i < nmsgs; i++) + if (zlog_msg_prio(msgs[i]) <= zt->prio_min) + syslog(zlog_msg_prio(msgs[i]) | zte->syslog_facility, "%s", + zlog_msg_text(msgs[i], NULL)); + } + + +.. c:function:: struct zlog_target *zlog_target_clone(struct memtype *mt, struct zlog_target *oldzt, size_t size) + + Allocates a logging target struct. Note that the ``oldzt`` argument may be + ``NULL`` to allocate a "from scratch". If ``oldzt`` is not ``NULL``, the + generic bits in :c:type:`struct zlog_target` are copied. **Target specific + bits are not copied.** + +.. c:function:: struct zlog_target *zlog_target_replace(struct zlog_target *oldzt, struct zlog_target *newzt) + + Adds, replaces or deletes a logging target (either ``oldzt`` or ``newzt`` may be ``NULL``.) + + Returns ``oldzt`` for freeing. The target remains possibly in use by + other threads until the RCU cycle ends. This implies you cannot release + resources (e.g. memory, file descriptors) immediately. + + The replace operation is not atomic; for a brief period it is possible that + messages are delivered on both ``oldzt`` and ``newzt``. + + .. warning:: + + ``oldzt`` must remain **functional** until the RCU cycle ends. + +.. c:function:: void zlog_target_free(struct memtype *mt, struct zlog_target *zt) + + Counterpart to :c:func:`zlog_target_clone()`, frees a target (using RCU.) + +.. c:member:: void (*zlog_target.logfn)(struct zlog_target *zt, struct zlog_msg *msgs[], size_t nmsg) + + Called on a target to deliver "normal" logging messages. ``msgs`` is an + array of opaque structs containing the actual message. Use ``zlog_msg_*`` + functions to access message data (this is done to allow some optimizations, + e.g. lazy formatting the message text and timestamp as needed.) + + .. note:: + + ``logfn()`` must check each individual message's priority value against + the configured ``prio_min``. While the ``prio_min`` field is common to + all targets and used by the core logging code to early-drop unneeded log + messages, the array is **not** filtered for each ``logfn()`` call. + +.. c:member:: void (*zlog_target.logfn_sigsafe)(struct zlog_target *zt, const char *text, size_t len) + + Called to deliver "exception" logging messages (i.e. SEGV messages.) + Must be Async-Signal-Safe (may not allocate memory or call "complicated" + libc functions.) May be ``NULL`` if the log target cannot handle this. + +Standard targets +^^^^^^^^^^^^^^^^ + +:file:`lib/zlog_targets.c` provides the standard file / fd / syslog targets. +The syslog target is single-instance while file / fd targets can be +instantiated as needed. There are 3 built-in targets that are fully +autonomous without any config: + +- startup logging to `stderr`, until either :c:func:`zlog_startup_end()` or + :c:func:`zlog_aux_init()` is called. +- stdout logging for non-daemon programs using :c:func:`zlog_aux_init()` +- crashlogs written to :file:`/var/tmp/frr.daemon.crashlog` + +The regular CLI/command-line logging setup is handled by :file:`lib/log_vty.c` +which makes the appropriate instantiations of syslog / file / fd targets. + +.. todo:: + + :c:func:`zlog_startup_end()` should do an explicit switchover from + startup stderr logging to configured logging. Currently, configured logging + starts in parallel as soon as the respective setup is executed. This results + in some duplicate logging. diff --git a/doc/user/basic.rst b/doc/user/basic.rst index edcfce45ad6d..5b7786de18e8 100644 --- a/doc/user/basic.rst +++ b/doc/user/basic.rst @@ -86,6 +86,15 @@ Basic Config Commands debugging. Note that the existing code logs its most important messages with severity ``errors``. + .. warning:: + + FRRouting uses the ``writev()`` system call to write log messages. This + call is supposed to be atomic, but in reality this does not hold for + pipes or terminals, only regular files. This means that in rare cases, + concurrent log messages from distinct threads may get jumbled in + terminal output. Use a log file and ``tail -f`` if this rare chance is + inacceptable to your setup. + .. index:: single: no log file [FILENAME [LEVEL]] single: log file FILENAME [LEVEL] @@ -104,14 +113,6 @@ Basic Config Commands deprecated ``log trap`` command) will be used. The ``no`` form of the command disables logging to a file. - .. note:: - - If you do not configure any file logging, and a daemon crashes due to a - signal or an assertion failure, it will attempt to save the crash - information in a file named :file:`/var/tmp/frr..crashlog`. - For security reasons, this will not happen if the file exists already, so - it is important to delete the file after reporting the crash information. - .. index:: single: no log syslog [LEVEL] single: log syslog [LEVEL] diff --git a/doc/user/setup.rst b/doc/user/setup.rst index 6d61a970d205..f60a66b9fd28 100644 --- a/doc/user/setup.rst +++ b/doc/user/setup.rst @@ -6,6 +6,22 @@ Basic Setup After installing FRR, some basic configuration must be completed before it is ready to use. +Crash logs +---------- + +If any daemon should crash for some reason (segmentation fault, assertion +failure, etc.), it will attempt to write a backtrace to a file located in +:file:`/var/tmp/frr/[-]./crashlog`. This feature is +not affected by any configuration options. + +The crashlog file's directory also contains files corresponding to per-thread +message buffers in files named +:file:`/var/tmp/frr/[-]./logbuf.`. In case of a +crash, these may contain unwritten buffered log messages. To show the contents +of these buffers, pipe their contents through ``tr '\0' '\n'``. A blank line +marks the end of valid unwritten data (it will generally be followed by +garbled, older log messages since the buffer is not cleared.) + Daemons Configuration File -------------------------- After a fresh install, starting FRR will do nothing. This is because daemons diff --git a/ldpd/ldpd.c b/ldpd/ldpd.c index 741c8c4655a2..a355b4a82663 100644 --- a/ldpd/ldpd.c +++ b/ldpd/ldpd.c @@ -308,9 +308,15 @@ main(int argc, char *argv[]) exit(1); } - if (lflag || eflag) - openzlog(ldpd_di.progname, "LDP", 0, - LOG_CONS | LOG_NDELAY | LOG_PID, LOG_DAEMON); + if (lflag || eflag) { + struct zprivs_ids_t ids; + + zprivs_preinit(&ldpd_privs); + zprivs_get_ids(&ids); + + zlog_init(ldpd_di.progname, "LDP", 0, + ids.uid_normal, ids.gid_normal); + } if (lflag) lde(); else if (eflag) @@ -486,7 +492,7 @@ ldpd_shutdown(void) static pid_t start_child(enum ldpd_process p, char *argv0, int fd_async, int fd_sync) { - char *argv[3]; + char *argv[7]; int argc = 0, nullfd; pid_t pid; @@ -529,6 +535,11 @@ start_child(enum ldpd_process p, char *argv0, int fd_async, int fd_sync) argv[argc++] = (char *)"-E"; break; } + + argv[argc++] = (char *)"-u"; + argv[argc++] = (char *)ldpd_privs.user; + argv[argc++] = (char *)"-g"; + argv[argc++] = (char *)ldpd_privs.group; argv[argc++] = NULL; execvp(argv0, argv); diff --git a/ldpd/log.c b/ldpd/log.c index b138e5754aa7..19030175884e 100644 --- a/ldpd/log.c +++ b/ldpd/log.c @@ -24,7 +24,6 @@ #include "log.h" #include -#include const char *log_procname; diff --git a/lib/clippy.c b/lib/clippy.c index cd8067f5ebfd..2e09c24c66f8 100644 --- a/lib/clippy.c +++ b/lib/clippy.c @@ -107,21 +107,11 @@ int main(int argc, char **argv) #include "log.h" #include "zassert.h" -#define ZLOG_FUNC(FUNCNAME) \ - void FUNCNAME(const char *format, ...) \ - { \ - va_list args; \ - va_start(args, format); \ - vfprintf(stderr, format, args); \ - fputs("\n", stderr); \ - va_end(args); \ - } - -ZLOG_FUNC(zlog_err) -ZLOG_FUNC(zlog_warn) -ZLOG_FUNC(zlog_info) -ZLOG_FUNC(zlog_notice) -ZLOG_FUNC(zlog_debug) +void vzlog(int prio, const char *format, va_list args) +{ + vfprintf(stderr, format, args); + fputs("\n", stderr); +} void _zlog_assert_failed(const char *assertion, const char *file, unsigned int line, const char *function) diff --git a/lib/command.c b/lib/command.c index 8811b3a79154..be8f1e72a36f 100644 --- a/lib/command.c +++ b/lib/command.c @@ -31,7 +31,7 @@ #include "frrstr.h" #include "memory.h" #include "log.h" -#include "log_int.h" +#include "log_vty.h" #include "thread.h" #include "vector.h" #include "linklist.h" @@ -198,65 +198,6 @@ static struct cmd_node enable_node = { static struct cmd_node config_node = {CONFIG_NODE, "%s(config)# ", 1}; -static const struct facility_map { - int facility; - const char *name; - size_t match; -} syslog_facilities[] = { - {LOG_KERN, "kern", 1}, - {LOG_USER, "user", 2}, - {LOG_MAIL, "mail", 1}, - {LOG_DAEMON, "daemon", 1}, - {LOG_AUTH, "auth", 1}, - {LOG_SYSLOG, "syslog", 1}, - {LOG_LPR, "lpr", 2}, - {LOG_NEWS, "news", 1}, - {LOG_UUCP, "uucp", 2}, - {LOG_CRON, "cron", 1}, -#ifdef LOG_FTP - {LOG_FTP, "ftp", 1}, -#endif - {LOG_LOCAL0, "local0", 6}, - {LOG_LOCAL1, "local1", 6}, - {LOG_LOCAL2, "local2", 6}, - {LOG_LOCAL3, "local3", 6}, - {LOG_LOCAL4, "local4", 6}, - {LOG_LOCAL5, "local5", 6}, - {LOG_LOCAL6, "local6", 6}, - {LOG_LOCAL7, "local7", 6}, - {0, NULL, 0}, -}; - -static const char *facility_name(int facility) -{ - const struct facility_map *fm; - - for (fm = syslog_facilities; fm->name; fm++) - if (fm->facility == facility) - return fm->name; - return ""; -} - -static int facility_match(const char *str) -{ - const struct facility_map *fm; - - for (fm = syslog_facilities; fm->name; fm++) - if (!strncmp(str, fm->name, fm->match)) - return fm->facility; - return -1; -} - -static int level_match(const char *s) -{ - int level; - - for (level = 0; zlog_priority[level] != NULL; level++) - if (!strncmp(s, zlog_priority[level], 2)) - return level; - return ZLOG_DISABLED; -} - /* This is called from main when a daemon is invoked with -v or --version. */ void print_version(const char *progname) { @@ -493,6 +434,8 @@ static char *zencrypt(const char *passwd) return crypt(passwd, salt); } +static bool full_cli; + /* This function write configuration of this host. */ static int config_write_host(struct vty *vty) { @@ -508,7 +451,7 @@ static int config_write_host(struct vty *vty) * which would cause other daemons to then switch to syslog when they * parse frr.conf. */ - if (strcmp(zlog_default->protoname, "WATCHFRR")) { + if (full_cli) { if (host.encrypt) { if (host.password_encrypt) vty_out(vty, "password 8 %s\n", @@ -523,59 +466,7 @@ static int config_write_host(struct vty *vty) vty_out(vty, "enable password %s\n", host.enable); } - - if (host.logfile - && (zlog_default->maxlvl[ZLOG_DEST_FILE] - != ZLOG_DISABLED)) { - vty_out(vty, "log file %s", host.logfile); - if (zlog_default->maxlvl[ZLOG_DEST_FILE] - != zlog_default->default_lvl) - vty_out(vty, " %s", - zlog_priority - [zlog_default->maxlvl - [ZLOG_DEST_FILE]]); - vty_out(vty, "\n"); - } - - if (zlog_default->maxlvl[ZLOG_DEST_STDOUT] != ZLOG_DISABLED) { - vty_out(vty, "log stdout"); - if (zlog_default->maxlvl[ZLOG_DEST_STDOUT] - != zlog_default->default_lvl) - vty_out(vty, " %s", - zlog_priority - [zlog_default->maxlvl - [ZLOG_DEST_STDOUT]]); - vty_out(vty, "\n"); - } - - if (zlog_default->maxlvl[ZLOG_DEST_MONITOR] == ZLOG_DISABLED) - vty_out(vty, "no log monitor\n"); - else if (zlog_default->maxlvl[ZLOG_DEST_MONITOR] - != zlog_default->default_lvl) - vty_out(vty, "log monitor %s\n", - zlog_priority[zlog_default->maxlvl - [ZLOG_DEST_MONITOR]]); - - if (zlog_default->maxlvl[ZLOG_DEST_SYSLOG] != ZLOG_DISABLED) { - vty_out(vty, "log syslog"); - if (zlog_default->maxlvl[ZLOG_DEST_SYSLOG] - != zlog_default->default_lvl) - vty_out(vty, " %s", - zlog_priority[zlog_default->maxlvl - [ZLOG_DEST_SYSLOG]]); - vty_out(vty, "\n"); - } - - if (zlog_default->facility != LOG_DAEMON) - vty_out(vty, "log facility %s\n", - facility_name(zlog_default->facility)); - - if (zlog_default->record_priority == 1) - vty_out(vty, "log record-priority\n"); - - if (zlog_default->timestamp_precision > 0) - vty_out(vty, "log timestamp precision %d\n", - zlog_default->timestamp_precision); + log_config_write(vty); if (host.advanced) vty_out(vty, "service advanced-vty\n"); @@ -2273,7 +2164,8 @@ DEFUN (config_logmsg, int level; char *message; - if ((level = level_match(argv[idx_log_level]->arg)) == ZLOG_DISABLED) + level = log_level_match(argv[idx_log_level]->arg); + if (level == ZLOG_DISABLED) return CMD_ERR_NO_MATCH; zlog(level, "%s", @@ -2284,348 +2176,6 @@ DEFUN (config_logmsg, return CMD_SUCCESS; } -DEFUN (show_logging, - show_logging_cmd, - "show logging", - SHOW_STR - "Show current logging configuration\n") -{ - struct zlog *zl = zlog_default; - - vty_out(vty, "Syslog logging: "); - if (zl->maxlvl[ZLOG_DEST_SYSLOG] == ZLOG_DISABLED) - vty_out(vty, "disabled"); - else - vty_out(vty, "level %s, facility %s, ident %s", - zlog_priority[zl->maxlvl[ZLOG_DEST_SYSLOG]], - facility_name(zl->facility), zl->ident); - vty_out(vty, "\n"); - - vty_out(vty, "Stdout logging: "); - if (zl->maxlvl[ZLOG_DEST_STDOUT] == ZLOG_DISABLED) - vty_out(vty, "disabled"); - else - vty_out(vty, "level %s", - zlog_priority[zl->maxlvl[ZLOG_DEST_STDOUT]]); - vty_out(vty, "\n"); - - vty_out(vty, "Monitor logging: "); - if (zl->maxlvl[ZLOG_DEST_MONITOR] == ZLOG_DISABLED) - vty_out(vty, "disabled"); - else - vty_out(vty, "level %s", - zlog_priority[zl->maxlvl[ZLOG_DEST_MONITOR]]); - vty_out(vty, "\n"); - - vty_out(vty, "File logging: "); - if ((zl->maxlvl[ZLOG_DEST_FILE] == ZLOG_DISABLED) || !zl->fp) - vty_out(vty, "disabled"); - else - vty_out(vty, "level %s, filename %s", - zlog_priority[zl->maxlvl[ZLOG_DEST_FILE]], - zl->filename); - vty_out(vty, "\n"); - - vty_out(vty, "Protocol name: %s\n", zl->protoname); - vty_out(vty, "Record priority: %s\n", - (zl->record_priority ? "enabled" : "disabled")); - vty_out(vty, "Timestamp precision: %d\n", zl->timestamp_precision); - - return CMD_SUCCESS; -} - -DEFUN (config_log_stdout, - config_log_stdout_cmd, - "log stdout []", - "Logging control\n" - "Set stdout logging level\n" - LOG_LEVEL_DESC) -{ - int idx_log_level = 2; - - if (argc == idx_log_level) { - zlog_set_level(ZLOG_DEST_STDOUT, zlog_default->default_lvl); - return CMD_SUCCESS; - } - int level; - - if ((level = level_match(argv[idx_log_level]->arg)) == ZLOG_DISABLED) - return CMD_ERR_NO_MATCH; - zlog_set_level(ZLOG_DEST_STDOUT, level); - return CMD_SUCCESS; -} - -DEFUN (no_config_log_stdout, - no_config_log_stdout_cmd, - "no log stdout []", - NO_STR - "Logging control\n" - "Cancel logging to stdout\n" - LOG_LEVEL_DESC) -{ - zlog_set_level(ZLOG_DEST_STDOUT, ZLOG_DISABLED); - return CMD_SUCCESS; -} - -DEFUN (config_log_monitor, - config_log_monitor_cmd, - "log monitor []", - "Logging control\n" - "Set terminal line (monitor) logging level\n" - LOG_LEVEL_DESC) -{ - int idx_log_level = 2; - - if (argc == idx_log_level) { - zlog_set_level(ZLOG_DEST_MONITOR, zlog_default->default_lvl); - return CMD_SUCCESS; - } - int level; - - if ((level = level_match(argv[idx_log_level]->arg)) == ZLOG_DISABLED) - return CMD_ERR_NO_MATCH; - zlog_set_level(ZLOG_DEST_MONITOR, level); - return CMD_SUCCESS; -} - -DEFUN (no_config_log_monitor, - no_config_log_monitor_cmd, - "no log monitor []", - NO_STR - "Logging control\n" - "Disable terminal line (monitor) logging\n" - LOG_LEVEL_DESC) -{ - zlog_set_level(ZLOG_DEST_MONITOR, ZLOG_DISABLED); - return CMD_SUCCESS; -} - -static int set_log_file(struct vty *vty, const char *fname, int loglevel) -{ - int ret; - char *p = NULL; - const char *fullpath; - - /* Path detection. */ - if (!IS_DIRECTORY_SEP(*fname)) { - char cwd[MAXPATHLEN + 1]; - cwd[MAXPATHLEN] = '\0'; - - if (getcwd(cwd, MAXPATHLEN) == NULL) { - flog_err_sys(EC_LIB_SYSTEM_CALL, - "config_log_file: Unable to alloc mem!"); - return CMD_WARNING_CONFIG_FAILED; - } - - p = XMALLOC(MTYPE_TMP, strlen(cwd) + strlen(fname) + 2); - sprintf(p, "%s/%s", cwd, fname); - fullpath = p; - } else - fullpath = fname; - - ret = zlog_set_file(fullpath, loglevel); - - XFREE(MTYPE_TMP, p); - - if (!ret) { - if (vty) - vty_out(vty, "can't open logfile %s\n", fname); - return CMD_WARNING_CONFIG_FAILED; - } - - XFREE(MTYPE_HOST, host.logfile); - - host.logfile = XSTRDUP(MTYPE_HOST, fname); - -#if defined(HAVE_CUMULUS) - if (zlog_default->maxlvl[ZLOG_DEST_SYSLOG] != ZLOG_DISABLED) - zlog_set_level(ZLOG_DEST_SYSLOG, ZLOG_DISABLED); -#endif - return CMD_SUCCESS; -} - -void command_setup_early_logging(const char *dest, const char *level) -{ - char *token; - - if (level) { - int nlevel = level_match(level); - - if (nlevel != ZLOG_DISABLED) - zlog_default->default_lvl = nlevel; - } - - if (!dest) - return; - - if (strcmp(dest, "stdout") == 0) { - zlog_set_level(ZLOG_DEST_STDOUT, zlog_default->default_lvl); - return; - } - - if (strcmp(dest, "syslog") == 0) { - zlog_set_level(ZLOG_DEST_SYSLOG, zlog_default->default_lvl); - return; - } - - token = strstr(dest, ":"); - if (token == NULL) - return; - - token++; - - set_log_file(NULL, token, zlog_default->default_lvl); -} - -DEFUN (config_log_file, - config_log_file_cmd, - "log file FILENAME []", - "Logging control\n" - "Logging to file\n" - "Logging filename\n" - LOG_LEVEL_DESC) -{ - int idx_filename = 2; - int idx_log_levels = 3; - if (argc == 4) { - int level; - if ((level = level_match(argv[idx_log_levels]->arg)) - == ZLOG_DISABLED) - return CMD_ERR_NO_MATCH; - return set_log_file(vty, argv[idx_filename]->arg, level); - } else - return set_log_file(vty, argv[idx_filename]->arg, - zlog_default->default_lvl); -} - -static void disable_log_file(void) -{ - zlog_reset_file(); - - XFREE(MTYPE_HOST, host.logfile); -} - -DEFUN (no_config_log_file, - no_config_log_file_cmd, - "no log file [FILENAME [LEVEL]]", - NO_STR - "Logging control\n" - "Cancel logging to file\n" - "Logging file name\n" - "Logging level\n") -{ - disable_log_file(); - return CMD_SUCCESS; -} - -DEFUN (config_log_syslog, - config_log_syslog_cmd, - "log syslog []", - "Logging control\n" - "Set syslog logging level\n" - LOG_LEVEL_DESC) -{ - int idx_log_levels = 2; - - if (argc == 3) { - int level; - if ((level = level_match(argv[idx_log_levels]->arg)) - == ZLOG_DISABLED) - return CMD_ERR_NO_MATCH; - zlog_set_level(ZLOG_DEST_SYSLOG, level); - return CMD_SUCCESS; - } else { - zlog_set_level(ZLOG_DEST_SYSLOG, zlog_default->default_lvl); - return CMD_SUCCESS; - } -} - -DEFUN (no_config_log_syslog, - no_config_log_syslog_cmd, - "no log syslog [] []", - NO_STR - "Logging control\n" - "Cancel logging to syslog\n" - LOG_FACILITY_DESC - LOG_LEVEL_DESC) -{ - zlog_set_level(ZLOG_DEST_SYSLOG, ZLOG_DISABLED); - return CMD_SUCCESS; -} - -DEFUN (config_log_facility, - config_log_facility_cmd, - "log facility ", - "Logging control\n" - "Facility parameter for syslog messages\n" - LOG_FACILITY_DESC) -{ - int idx_target = 2; - int facility = facility_match(argv[idx_target]->arg); - - zlog_default->facility = facility; - return CMD_SUCCESS; -} - -DEFUN (no_config_log_facility, - no_config_log_facility_cmd, - "no log facility []", - NO_STR - "Logging control\n" - "Reset syslog facility to default (daemon)\n" - LOG_FACILITY_DESC) -{ - zlog_default->facility = LOG_DAEMON; - return CMD_SUCCESS; -} - -DEFUN (config_log_record_priority, - config_log_record_priority_cmd, - "log record-priority", - "Logging control\n" - "Log the priority of the message within the message\n") -{ - zlog_default->record_priority = 1; - return CMD_SUCCESS; -} - -DEFUN (no_config_log_record_priority, - no_config_log_record_priority_cmd, - "no log record-priority", - NO_STR - "Logging control\n" - "Do not log the priority of the message within the message\n") -{ - zlog_default->record_priority = 0; - return CMD_SUCCESS; -} - -DEFUN (config_log_timestamp_precision, - config_log_timestamp_precision_cmd, - "log timestamp precision (0-6)", - "Logging control\n" - "Timestamp configuration\n" - "Set the timestamp precision\n" - "Number of subsecond digits\n") -{ - int idx_number = 3; - zlog_default->timestamp_precision = - strtoul(argv[idx_number]->arg, NULL, 10); - return CMD_SUCCESS; -} - -DEFUN (no_config_log_timestamp_precision, - no_config_log_timestamp_precision_cmd, - "no log timestamp precision", - NO_STR - "Logging control\n" - "Timestamp configuration\n" - "Reset the timestamp precision to the default value of 0\n") -{ - zlog_default->timestamp_precision = 0; - return CMD_SUCCESS; -} - DEFUN (debug_memstats, debug_memstats_cmd, "[no] debug memstats-at-exit", @@ -2875,7 +2425,6 @@ void cmd_init(int terminal) #endif host.password = NULL; host.enable = NULL; - host.logfile = NULL; host.config = NULL; host.noconfig = (terminal < 0); host.lines = -1; @@ -2903,7 +2452,6 @@ void cmd_init(int terminal) install_element(VIEW_NODE, &config_enable_cmd); install_element(VIEW_NODE, &config_terminal_length_cmd); install_element(VIEW_NODE, &config_terminal_no_length_cmd); - install_element(VIEW_NODE, &show_logging_cmd); install_element(VIEW_NODE, &show_commandtree_cmd); install_element(VIEW_NODE, &echo_cmd); install_element(VIEW_NODE, &autocomplete_cmd); @@ -2930,6 +2478,8 @@ void cmd_init(int terminal) install_element(CONFIG_NODE, &no_domainname_cmd); if (terminal > 0) { + full_cli = true; + install_element(CONFIG_NODE, &debug_memstats_cmd); install_element(CONFIG_NODE, &password_cmd); @@ -2937,23 +2487,6 @@ void cmd_init(int terminal) install_element(CONFIG_NODE, &enable_password_cmd); install_element(CONFIG_NODE, &no_enable_password_cmd); - install_element(CONFIG_NODE, &config_log_stdout_cmd); - install_element(CONFIG_NODE, &no_config_log_stdout_cmd); - install_element(CONFIG_NODE, &config_log_monitor_cmd); - install_element(CONFIG_NODE, &no_config_log_monitor_cmd); - install_element(CONFIG_NODE, &config_log_file_cmd); - install_element(CONFIG_NODE, &no_config_log_file_cmd); - install_element(CONFIG_NODE, &config_log_syslog_cmd); - install_element(CONFIG_NODE, &no_config_log_syslog_cmd); - install_element(CONFIG_NODE, &config_log_facility_cmd); - install_element(CONFIG_NODE, &no_config_log_facility_cmd); - install_element(CONFIG_NODE, &config_log_record_priority_cmd); - 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, &service_password_encrypt_cmd); install_element(CONFIG_NODE, &no_service_password_encrypt_cmd); install_element(CONFIG_NODE, &banner_motd_default_cmd); @@ -2963,6 +2496,7 @@ void cmd_init(int terminal) install_element(CONFIG_NODE, &service_terminal_length_cmd); install_element(CONFIG_NODE, &no_service_terminal_length_cmd); + log_cmd_init(); vrf_install_commands(); } @@ -3000,7 +2534,6 @@ void cmd_terminate(void) XFREE(MTYPE_HOST, host.password_encrypt); XFREE(MTYPE_HOST, host.enable); XFREE(MTYPE_HOST, host.enable_encrypt); - XFREE(MTYPE_HOST, host.logfile); XFREE(MTYPE_HOST, host.motdfile); XFREE(MTYPE_HOST, host.config); XFREE(MTYPE_HOST, host.motd); diff --git a/lib/command.h b/lib/command.h index ea8a76a964f7..190e0e93af2d 100644 --- a/lib/command.h +++ b/lib/command.h @@ -66,9 +66,6 @@ struct host { /* System wide terminal lines. */ int lines; - /* Log filename. */ - char *logfile; - /* config file name of this host */ char *config; int noconfig; diff --git a/lib/frr_pthread.c b/lib/frr_pthread.c index 55f0b55ed6e7..e237934f8158 100644 --- a/lib/frr_pthread.c +++ b/lib/frr_pthread.c @@ -27,6 +27,7 @@ #include "frr_pthread.h" #include "memory.h" #include "linklist.h" +#include "zlog.h" DEFINE_MTYPE_STATIC(LIB, FRR_PTHREAD, "FRR POSIX Thread") DEFINE_MTYPE_STATIC(LIB, PTHREAD_PRIM, "POSIX sync primitives") @@ -273,6 +274,8 @@ static void *fpt_run(void *arg) struct frr_pthread *fpt = arg; fpt->master->owner = pthread_self(); + zlog_tls_buffer_init(); + int sleeper[2]; pipe(sleeper); thread_add_read(fpt->master, &fpt_dummy, NULL, sleeper[0], NULL); @@ -294,5 +297,7 @@ static void *fpt_run(void *arg) close(sleeper[1]); close(sleeper[0]); + zlog_tls_buffer_fini(); + return NULL; } diff --git a/lib/grammar_sandbox_main.c b/lib/grammar_sandbox_main.c index aa54720dabe9..fbb97d2dd561 100644 --- a/lib/grammar_sandbox_main.c +++ b/lib/grammar_sandbox_main.c @@ -45,11 +45,7 @@ int main(int argc, char **argv) master = thread_master_create(NULL); - openzlog("grammar_sandbox", "NONE", 0, LOG_CONS | LOG_NDELAY | LOG_PID, - LOG_DAEMON); - zlog_set_level(ZLOG_DEST_SYSLOG, ZLOG_DISABLED); - zlog_set_level(ZLOG_DEST_STDOUT, LOG_DEBUG); - zlog_set_level(ZLOG_DEST_MONITOR, ZLOG_DISABLED); + zlog_aux_init("NONE: ", LOG_DEBUG); /* Library inits. */ cmd_init(1); diff --git a/lib/hook.c b/lib/hook.c index 870d158aac44..5a8ad00d660d 100644 --- a/lib/hook.c +++ b/lib/hook.c @@ -18,16 +18,26 @@ #include "config.h" #endif +#include + #include "memory.h" #include "hook.h" DEFINE_MTYPE_STATIC(LIB, HOOK_ENTRY, "Hook entry") -void _hook_register(struct hook *hook, void *funcptr, void *arg, bool has_arg, - struct frrmod_runtime *module, const char *funcname, - int priority) +void _hook_register(struct hook *hook, struct hookent *stackent, void *funcptr, + void *arg, bool has_arg, struct frrmod_runtime *module, + const char *funcname, int priority) { - struct hookent *he = XCALLOC(MTYPE_HOOK_ENTRY, sizeof(*he)), **pos; + struct hookent *he, **pos; + + if (!stackent->ent_used) + he = stackent; + else { + he = XCALLOC(MTYPE_HOOK_ENTRY, sizeof(*he)); + he->ent_on_heap = true; + } + he->ent_used = true; he->hookfn = funcptr; he->hookarg = arg; he->has_arg = has_arg; @@ -52,7 +62,10 @@ void _hook_unregister(struct hook *hook, void *funcptr, void *arg, bool has_arg) if (he->hookfn == funcptr && he->hookarg == arg && he->has_arg == has_arg) { *prev = he->next; - XFREE(MTYPE_HOOK_ENTRY, he); + if (he->ent_on_heap) + XFREE(MTYPE_HOOK_ENTRY, he); + else + memset(he, 0, sizeof(*he)); break; } } diff --git a/lib/hook.h b/lib/hook.h index f7fb7b8a5cf6..3823cebe6ac5 100644 --- a/lib/hook.h +++ b/lib/hook.h @@ -114,7 +114,9 @@ struct hookent { struct hookent *next; void *hookfn; /* actually a function pointer */ void *hookarg; - bool has_arg; + bool has_arg : 1; + bool ent_on_heap : 1; + bool ent_used : 1; int priority; struct frrmod_runtime *module; const char *fnname; @@ -133,21 +135,33 @@ struct hook { * always use hook_register(), which uses the static inline helper from * DECLARE_HOOK in order to get type safety */ -extern void _hook_register(struct hook *hook, void *funcptr, void *arg, - bool has_arg, struct frrmod_runtime *module, +extern void _hook_register(struct hook *hook, struct hookent *stackent, + void *funcptr, void *arg, bool has_arg, + struct frrmod_runtime *module, const char *funcname, int priority); + +/* most hook_register calls are not in a loop or similar and can use a + * statically allocated "struct hookent" from the data segment + */ +#define _hook_reg_svar(hook, funcptr, arg, has_arg, module, funcname, prio) \ + do { \ + static struct hookent stack_hookent = { .ent_on_heap = 0, }; \ + _hook_register(hook, &stack_hookent, funcptr, arg, has_arg, \ + module, funcname, prio); \ + } while (0) + #define hook_register(hookname, func) \ - _hook_register(&_hook_##hookname, _hook_typecheck_##hookname(func), \ + _hook_reg_svar(&_hook_##hookname, _hook_typecheck_##hookname(func), \ NULL, false, THIS_MODULE, #func, HOOK_DEFAULT_PRIORITY) #define hook_register_arg(hookname, func, arg) \ - _hook_register(&_hook_##hookname, \ + _hook_reg_svar(&_hook_##hookname, \ _hook_typecheck_arg_##hookname(func), arg, true, \ THIS_MODULE, #func, HOOK_DEFAULT_PRIORITY) #define hook_register_prio(hookname, prio, func) \ - _hook_register(&_hook_##hookname, _hook_typecheck_##hookname(func), \ + _hook_reg_svar(&_hook_##hookname, _hook_typecheck_##hookname(func), \ NULL, false, THIS_MODULE, #func, prio) #define hook_register_arg_prio(hookname, prio, func, arg) \ - _hook_register(&_hook_##hookname, \ + _hook_reg_svar(&_hook_##hookname, \ _hook_typecheck_arg_##hookname(func), arg, true, \ THIS_MODULE, #func, prio) diff --git a/lib/libfrr.c b/lib/libfrr.c index 9a681103d4ec..ac165f254ef6 100644 --- a/lib/libfrr.c +++ b/lib/libfrr.c @@ -33,7 +33,6 @@ #include "lib_vty.h" #include "log_vty.h" #include "zclient.h" -#include "log_int.h" #include "module.h" #include "network.h" #include "lib_errors.h" @@ -630,6 +629,7 @@ struct thread_master *frr_init(void) { struct option_chain *oc; struct frrmod_runtime *module; + struct zprivs_ids_t ids; char moderr[256]; char p_instance[16] = "", p_pathspace[256] = ""; const char *dir; @@ -657,9 +657,11 @@ struct thread_master *frr_init(void) #endif zprivs_preinit(di->privs); + zprivs_get_ids(&ids); - openzlog(di->progname, di->logname, di->instance, - LOG_CONS | LOG_NDELAY | LOG_PID, LOG_DAEMON); + zlog_init(di->progname, di->logname, di->instance, + ids.uid_normal, ids.gid_normal); + zlog_tls_buffer_init(); command_setup_early_logging(di->early_logging, di->early_loglevel); @@ -709,7 +711,6 @@ struct thread_master *frr_init(void) vty_init(master, di->log_always); lib_cmd_init(); - log_filter_cmd_init(); frr_pthread_init(); @@ -1086,7 +1087,7 @@ void frr_run(struct thread_master *master) } /* end fixed stderr startup logging */ - zlog_startup_stderr = false; + zlog_startup_end(); struct thread thread; while (thread_fetch(master, &thread)) @@ -1119,7 +1120,8 @@ void frr_fini(void) /* signal_init -> nothing needed */ thread_master_free(master); master = NULL; - closezlog(); + zlog_tls_buffer_fini(); + zlog_fini(); /* frrmod_init -> nothing needed / hooks */ rcu_shutdown(); diff --git a/lib/log.c b/lib/log.c index b3be5216aaa6..9b0f5b3d85c7 100644 --- a/lib/log.c +++ b/lib/log.c @@ -25,7 +25,6 @@ #include "zclient.h" #include "log.h" -#include "log_int.h" #include "memory.h" #include "command.h" #include "lib_errors.h" @@ -33,154 +32,12 @@ #include "printfrr.h" #include "frr_pthread.h" -#ifndef SUNOS_5 -#include -#endif -/* for printstack on solaris */ -#ifdef HAVE_UCONTEXT_H -#include -#endif - #ifdef HAVE_LIBUNWIND #define UNW_LOCAL_ONLY #include #include #endif -DEFINE_MTYPE_STATIC(LIB, ZLOG, "Logging") - -/* hook for external logging */ -DEFINE_HOOK(zebra_ext_log, (int priority, const char *format, va_list args), - (priority, format, args)); - -static int logfile_fd = -1; /* Used in signal handler. */ - -struct zlog *zlog_default = NULL; -bool zlog_startup_stderr = true; - -/* lock protecting zlog_default for mt-safe zlog */ -static pthread_mutex_t loglock = PTHREAD_MUTEX_INITIALIZER; - -const char *zlog_priority[] = { - "emergencies", "alerts", "critical", "errors", "warnings", - "notifications", "informational", "debugging", NULL, -}; - -static char zlog_filters[ZLOG_FILTERS_MAX][ZLOG_FILTER_LENGTH_MAX + 1]; -static uint8_t zlog_filter_count; - -/* - * look for a match on the filter in the current filters, loglock must be held - */ -static int zlog_filter_lookup(const char *lookup) -{ - for (int i = 0; i < zlog_filter_count; i++) { - if (strncmp(lookup, zlog_filters[i], sizeof(zlog_filters[0])) - == 0) - return i; - } - return -1; -} - -void zlog_filter_clear(void) -{ - frr_with_mutex(&loglock) { - zlog_filter_count = 0; - } -} - -int zlog_filter_add(const char *filter) -{ - frr_with_mutex(&loglock) { - if (zlog_filter_count >= ZLOG_FILTERS_MAX) - return 1; - - if (zlog_filter_lookup(filter) != -1) - /* Filter already present */ - return -1; - - strlcpy(zlog_filters[zlog_filter_count], filter, - sizeof(zlog_filters[0])); - - if (zlog_filters[zlog_filter_count][0] == '\0') - /* Filter was either empty or didn't get copied - * correctly - */ - return -1; - - zlog_filter_count++; - } - return 0; -} - -int zlog_filter_del(const char *filter) -{ - frr_with_mutex(&loglock) { - int found_idx = zlog_filter_lookup(filter); - int last_idx = zlog_filter_count - 1; - - if (found_idx == -1) - /* Didn't find the filter to delete */ - return -1; - - /* Adjust the filter array */ - memmove(zlog_filters[found_idx], zlog_filters[found_idx + 1], - (last_idx - found_idx) * sizeof(zlog_filters[0])); - - zlog_filter_count--; - } - return 0; -} - -/* Dump all filters to buffer, delimited by new line */ -int zlog_filter_dump(char *buf, size_t max_size) -{ - int len = 0; - - frr_with_mutex(&loglock) { - for (int i = 0; i < zlog_filter_count; i++) { - int ret; - ret = snprintf(buf + len, max_size - len, " %s\n", - zlog_filters[i]); - len += ret; - if ((ret < 0) || ((size_t)len >= max_size)) - return -1; - } - } - - return len; -} - -/* - * write_wrapper - * - * glibc has declared that the return value from write *must* not be - * ignored. - * gcc see's this problem and issues a warning for the line. - * - * Why is this a big deal you say? Because both of them are right - * and if you have -Werror enabled then all calls to write - * generate a build error and the build stops. - * - * clang has helpfully allowed this construct: - * (void)write(...) - * to tell the compiler yeah I know it has a return value - * I don't care about it at this time. - * gcc doesn't have this ability. - * - * This code was written such that it didn't care about the - * return value from write. At this time do I want - * to go through and fix and test this code for correctness. - * So just wrapper the bad behavior and move on. - */ -static void write_wrapper(int fd, const void *buf, size_t count) -{ - if (write(fd, buf, count) <= 0) - return; - - return; -} - /** * Looks up a message in a message list by key. * @@ -264,274 +121,12 @@ size_t quagga_timestamp(int timestamp_precision, char *buf, size_t buflen) return 0; } -static inline void timestamp_control_render(struct timestamp_control *ctl) -{ - if (!ctl->already_rendered) { - ctl->len = quagga_timestamp(ctl->precision, ctl->buf, - sizeof(ctl->buf)); - ctl->already_rendered = 1; - } -} - -/* Utility routine for current time printing. */ -static void time_print(FILE *fp, struct timestamp_control *ctl) -{ - timestamp_control_render(ctl); - fprintf(fp, "%s ", ctl->buf); -} - -static int time_print_buf(char *buf, int len, int max_size, - struct timestamp_control *ctl) -{ - timestamp_control_render(ctl); - - if (ctl->len + 1 >= (unsigned long)max_size) - return -1; - - return snprintf(buf + len, max_size - len, "%s ", ctl->buf); -} - -static void vzlog_file(struct zlog *zl, struct timestamp_control *tsctl, - const char *proto_str, int record_priority, int priority, - FILE *fp, const char *msg) -{ - time_print(fp, tsctl); - if (record_priority) - fprintf(fp, "%s: ", zlog_priority[priority]); - - fprintf(fp, "%s%s\n", proto_str, msg); - fflush(fp); -} - -/* Search a buf for the filter strings, loglock must be held */ -static int search_buf(const char *buf) -{ - char *found = NULL; - - for (int i = 0; i < zlog_filter_count; i++) { - found = strstr(buf, zlog_filters[i]); - if (found != NULL) - return 0; - } - - return -1; -} - -/* Filter out a log */ -static int vzlog_filter(struct zlog *zl, struct timestamp_control *tsctl, - const char *proto_str, int priority, const char *msg) -{ - int len = 0; - int ret = 0; - char buf[1024] = ""; - - ret = time_print_buf(buf, len, sizeof(buf), tsctl); - - len += ret; - if ((ret < 0) || ((size_t)len >= sizeof(buf))) - goto search; - - if (zl && zl->record_priority) - snprintf(buf + len, sizeof(buf) - len, "%s: %s: %s", - zlog_priority[priority], proto_str, msg); - else - snprintf(buf + len, sizeof(buf) - len, "%s: %s", proto_str, - msg); - -search: - return search_buf(buf); -} - -/* va_list version of zlog. */ -void vzlog(int priority, const char *format, va_list args) -{ - frr_mutex_lock_autounlock(&loglock); - - char proto_str[32] = ""; - int original_errno = errno; - struct timestamp_control tsctl = {}; - tsctl.already_rendered = 0; - struct zlog *zl = zlog_default; - char buf[256], *msg; - - if (zl == NULL) { - tsctl.precision = 0; - } else { - tsctl.precision = zl->timestamp_precision; - if (zl->instance) - sprintf(proto_str, "%s[%d]: ", zl->protoname, - zl->instance); - else - sprintf(proto_str, "%s: ", zl->protoname); - } - - msg = vasnprintfrr(MTYPE_TMP, buf, sizeof(buf), format, args); - - /* If it doesn't match on a filter, do nothing with the debug log */ - if ((priority == LOG_DEBUG) && zlog_filter_count - && vzlog_filter(zl, &tsctl, proto_str, priority, msg)) - goto out; - - /* call external hook */ - hook_call(zebra_ext_log, priority, format, args); - - /* When zlog_default is also NULL, use stderr for logging. */ - if (zl == NULL) { - time_print(stderr, &tsctl); - fprintf(stderr, "%s: %s\n", "unknown", msg); - fflush(stderr); - goto out; - } - - /* Syslog output */ - if (priority <= zl->maxlvl[ZLOG_DEST_SYSLOG]) - syslog(priority | zlog_default->facility, "%s", msg); - - /* File output. */ - if ((priority <= zl->maxlvl[ZLOG_DEST_FILE]) && zl->fp) - vzlog_file(zl, &tsctl, proto_str, zl->record_priority, priority, - zl->fp, msg); - - /* fixed-config logging to stderr while we're stating up & haven't - * daemonized / reached mainloop yet - * - * note the "else" on stdout output -- we don't want to print the same - * message to both stderr and stdout. */ - if (zlog_startup_stderr && priority <= LOG_WARNING) - vzlog_file(zl, &tsctl, proto_str, 1, priority, stderr, msg); - else if (priority <= zl->maxlvl[ZLOG_DEST_STDOUT]) - vzlog_file(zl, &tsctl, proto_str, zl->record_priority, priority, - stdout, msg); - - /* Terminal monitor. */ - if (priority <= zl->maxlvl[ZLOG_DEST_MONITOR]) - vty_log((zl->record_priority ? zlog_priority[priority] : NULL), - proto_str, msg, &tsctl); - -out: - if (msg != buf) - XFREE(MTYPE_TMP, msg); - errno = original_errno; -} - -int vzlog_test(int priority) -{ - frr_mutex_lock_autounlock(&loglock); - - struct zlog *zl = zlog_default; - - /* When zlog_default is also NULL, use stderr for logging. */ - if (zl == NULL) - return 1; - /* Syslog output */ - else if (priority <= zl->maxlvl[ZLOG_DEST_SYSLOG]) - return 1; - /* File output. */ - else if ((priority <= zl->maxlvl[ZLOG_DEST_FILE]) && zl->fp) - return 1; - /* stdout output. */ - else if (priority <= zl->maxlvl[ZLOG_DEST_STDOUT]) - return 1; - /* Terminal monitor. */ - else if (priority <= zl->maxlvl[ZLOG_DEST_MONITOR]) - return 1; - - return 0; -} - /* * crash handling * * NB: only AS-Safe (async-signal) functions can be used here! */ -/* Needs to be enhanced to support Solaris. */ -static int syslog_connect(void) -{ -#ifdef SUNOS_5 - return -1; -#else - int fd; - struct sockaddr_un addr; - - if ((fd = socket(AF_UNIX, SOCK_DGRAM, 0)) < 0) - return -1; - addr.sun_family = AF_UNIX; -#ifdef _PATH_LOG -#define SYSLOG_SOCKET_PATH _PATH_LOG -#else -#define SYSLOG_SOCKET_PATH "/dev/log" -#endif - strlcpy(addr.sun_path, SYSLOG_SOCKET_PATH, sizeof(addr.sun_path)); -#undef SYSLOG_SOCKET_PATH - if (connect(fd, (struct sockaddr *)&addr, sizeof(addr)) < 0) { - close(fd); - return -1; - } - return fd; -#endif -} - -static void syslog_sigsafe(int priority, const char *msg, size_t msglen) -{ - static int syslog_fd = -1; - char buf[sizeof("<1234567890>ripngd[1234567890]: ") + msglen + 50]; - struct fbuf fb = { .buf = buf, .pos = buf, .len = sizeof(buf) }; - - if ((syslog_fd < 0) && ((syslog_fd = syslog_connect()) < 0)) - return; - - /* forget about the timestamp, too difficult in a signal handler */ - bprintfrr(&fb, "<%d>%s", priority, zlog_default->ident); - if (zlog_default->syslog_options & LOG_PID) - bprintfrr(&fb, "[%ld]", (long)getpid()); - bprintfrr(&fb, ": %s", msg); - write_wrapper(syslog_fd, fb.buf, fb.pos - fb.buf); -} - -static int open_crashlog(void) -{ - char crashlog_buf[PATH_MAX]; - const char *crashlog_default = "/var/tmp/frr.crashlog", *crashlog; - - if (!zlog_default || !zlog_default->ident) - crashlog = crashlog_default; - else { - snprintfrr(crashlog_buf, sizeof(crashlog_buf), - "/var/tmp/frr.%s.crashlog", zlog_default->ident); - crashlog = crashlog_buf; - } - return open(crashlog, O_WRONLY | O_CREAT | O_EXCL, LOGFILE_MASK); -} - -/* N.B. implicit priority is most severe */ -#define PRI LOG_CRIT - -static void crash_write(struct fbuf *fb, char *msgstart) -{ - if (fb->pos == fb->buf) - return; - if (!msgstart) - msgstart = fb->buf; - - /* If no file logging configured, try to write to fallback log file. */ - if ((logfile_fd >= 0) || ((logfile_fd = open_crashlog()) >= 0)) - write(logfile_fd, fb->buf, fb->pos - fb->buf); - if (!zlog_default) - write(STDERR_FILENO, fb->buf, fb->pos - fb->buf); - else { - if (PRI <= zlog_default->maxlvl[ZLOG_DEST_STDOUT]) - write(STDOUT_FILENO, fb->buf, fb->pos - fb->buf); - /* Remove trailing '\n' for monitor and syslog */ - fb->pos--; - if (PRI <= zlog_default->maxlvl[ZLOG_DEST_MONITOR]) - vty_log_fixed(fb->buf, fb->pos - fb->buf); - if (PRI <= zlog_default->maxlvl[ZLOG_DEST_SYSLOG]) - syslog_sigsafe(PRI | zlog_default->facility, msgstart, - fb->pos - msgstart); - } -} - /* Note: the goal here is to use only async-signal-safe functions. */ void zlog_signal(int signo, const char *action, void *siginfo_v, void *program_counter) @@ -540,14 +135,9 @@ void zlog_signal(int signo, const char *action, void *siginfo_v, time_t now; char buf[sizeof("DEFAULT: Received signal S at T (si_addr 0xP, PC 0xP); aborting...") + 100]; - char *msgstart; struct fbuf fb = { .buf = buf, .pos = buf, .len = sizeof(buf) }; time(&now); - if (zlog_default) - bprintfrr(&fb, "%s: ", zlog_default->protoname); - - msgstart = fb.pos; bprintfrr(&fb, "Received signal %d at %lld", signo, (long long)now); if (program_counter) @@ -559,9 +149,9 @@ void zlog_signal(int signo, const char *action, void *siginfo_v, (ptrdiff_t)siginfo->si_addr); bprintfrr(&fb, "; %s\n", action); - crash_write(&fb, msgstart); + zlog_sigsafe(fb.buf, fb.pos - fb.buf); - zlog_backtrace_sigsafe(PRI, program_counter); + zlog_backtrace_sigsafe(LOG_CRIT, program_counter); fb.pos = buf; @@ -574,7 +164,7 @@ void zlog_signal(int signo, const char *action, void *siginfo_v, bprintfrr(&fb, "in thread %s scheduled from %s:%d\n", tc->funcname, tc->schedfrom, tc->schedfrom_line); - crash_write(&fb, NULL); + zlog_sigsafe(fb.buf, fb.pos - fb.buf); } /* Log a backtrace using only async-signal-safe functions. @@ -609,85 +199,35 @@ void zlog_backtrace_sigsafe(int priority, void *program_counter) bprintfrr(&fb, " %s (mapped at %p)", dlinfo.dli_fname, dlinfo.dli_fbase); bprintfrr(&fb, "\n"); - crash_write(&fb, NULL); + zlog_sigsafe(fb.buf, fb.pos - fb.buf); } -#elif defined(HAVE_GLIBC_BACKTRACE) || defined(HAVE_PRINTSTACK) - static const char pclabel[] = "Program counter: "; +#elif defined(HAVE_GLIBC_BACKTRACE) void *array[64]; - int size; + int size, i; char buf[128]; struct fbuf fb = { .buf = buf, .pos = buf, .len = sizeof(buf) }; char **bt = NULL; -#ifdef HAVE_GLIBC_BACKTRACE size = backtrace(array, array_size(array)); if (size <= 0 || (size_t)size > array_size(array)) return; -#define DUMP(FD) \ - { \ - if (program_counter) { \ - write_wrapper(FD, pclabel, sizeof(pclabel) - 1); \ - backtrace_symbols_fd(&program_counter, 1, FD); \ - } \ - write_wrapper(FD, fb.buf, fb.pos - fb.buf); \ - backtrace_symbols_fd(array, size, FD); \ - } -#elif defined(HAVE_PRINTSTACK) - size = 0; - -#define DUMP(FD) \ - { \ - if (program_counter) \ - write_wrapper((FD), pclabel, sizeof(pclabel) - 1); \ - write_wrapper((FD), fb.buf, fb.pos - fb.buf); \ - printstack((FD)); \ - } -#endif /* HAVE_GLIBC_BACKTRACE, HAVE_PRINTSTACK */ + bprintfrr(&fb, "Backtrace for %d stack frames:", size); + zlog_sigsafe(fb.pos, fb.buf - fb.pos); - bprintfrr(&fb, "Backtrace for %d stack frames:\n", size); + bt = backtrace_symbols(array, size); - if ((logfile_fd >= 0) || ((logfile_fd = open_crashlog()) >= 0)) - DUMP(logfile_fd) - if (!zlog_default) - DUMP(STDERR_FILENO) - else { - if (priority <= zlog_default->maxlvl[ZLOG_DEST_STDOUT]) - DUMP(STDOUT_FILENO) - /* Remove trailing '\n' for monitor and syslog */ - fb.pos--; - if (priority <= zlog_default->maxlvl[ZLOG_DEST_MONITOR]) - vty_log_fixed(fb.buf, fb.pos - fb.buf); - if (priority <= zlog_default->maxlvl[ZLOG_DEST_SYSLOG]) - syslog_sigsafe(priority | zlog_default->facility, - fb.buf, fb.pos - fb.buf); - { - int i; -#ifdef HAVE_GLIBC_BACKTRACE - bt = backtrace_symbols(array, size); -#endif - /* Just print the function addresses. */ - for (i = 0; i < size; i++) { - fb.pos = buf; - if (bt) - bprintfrr(&fb, "%s", bt[i]); - else - bprintfrr(&fb, "[bt %d] 0x%tx", i, - (ptrdiff_t)(array[i])); - if (priority - <= zlog_default->maxlvl[ZLOG_DEST_MONITOR]) - vty_log_fixed(fb.buf, fb.pos - fb.buf); - if (priority - <= zlog_default->maxlvl[ZLOG_DEST_SYSLOG]) - syslog_sigsafe(priority - | zlog_default->facility, - fb.buf, fb.pos - fb.buf); - } - if (bt) - free(bt); - } + for (i = 0; i < size; i++) { + fb.pos = buf; + if (bt) + bprintfrr(&fb, "%s", bt[i]); + else + bprintfrr(&fb, "[bt %d] 0x%tx", i, + (ptrdiff_t)(array[i])); + zlog_sigsafe(fb.buf, fb.pos - fb.buf); } -#undef DUMP + if (bt) + free(bt); #endif /* HAVE_STRACK_TRACE */ } @@ -754,36 +294,6 @@ void zlog_backtrace(int priority) #endif } -void zlog(int priority, const char *format, ...) -{ - va_list args; - - va_start(args, format); - vzlog(priority, format, args); - va_end(args); -} - -#define ZLOG_FUNC(FUNCNAME, PRIORITY) \ - void FUNCNAME(const char *format, ...) \ - { \ - va_list args; \ - va_start(args, format); \ - vzlog(PRIORITY, format, args); \ - va_end(args); \ - } - -ZLOG_FUNC(zlog_err, LOG_ERR) - -ZLOG_FUNC(zlog_warn, LOG_WARNING) - -ZLOG_FUNC(zlog_info, LOG_INFO) - -ZLOG_FUNC(zlog_notice, LOG_NOTICE) - -ZLOG_FUNC(zlog_debug, LOG_DEBUG) - -#undef ZLOG_FUNC - void zlog_thread_info(int log_level) { struct thread *tc; @@ -801,11 +311,6 @@ void zlog_thread_info(int log_level) void _zlog_assert_failed(const char *assertion, const char *file, unsigned int line, const char *function) { - /* Force fallback file logging? */ - if (zlog_default && !zlog_default->fp - && ((logfile_fd = open_crashlog()) >= 0) - && ((zlog_default->fp = fdopen(logfile_fd, "w")) != NULL)) - zlog_default->maxlvl[ZLOG_DEST_FILE] = LOG_ERR; zlog(LOG_CRIT, "Assertion `%s' failed in file %s, line %u, function %s", assertion, file, line, (function ? function : "?")); zlog_backtrace(LOG_CRIT); @@ -816,174 +321,14 @@ void _zlog_assert_failed(const char *assertion, const char *file, void memory_oom(size_t size, const char *name) { - flog_err_sys(EC_LIB_SYSTEM_CALL, - "out of memory: failed to allocate %zu bytes for %s" - "object", - size, name); - zlog_backtrace(LOG_ERR); + zlog(LOG_CRIT, + "out of memory: failed to allocate %zu bytes for %s object", + size, name); + zlog_backtrace(LOG_CRIT); + log_memstats(stderr, "log"); abort(); } -/* Open log stream */ -void openzlog(const char *progname, const char *protoname, - unsigned short instance, int syslog_flags, int syslog_facility) -{ - struct zlog *zl; - unsigned int i; - - zl = XCALLOC(MTYPE_ZLOG, sizeof(struct zlog)); - - zl->ident = progname; - zl->protoname = protoname; - zl->instance = instance; - zl->facility = syslog_facility; - zl->syslog_options = syslog_flags; - - /* Set default logging levels. */ - for (i = 0; i < array_size(zl->maxlvl); i++) - zl->maxlvl[i] = ZLOG_DISABLED; - zl->maxlvl[ZLOG_DEST_MONITOR] = LOG_DEBUG; - zl->default_lvl = LOG_DEBUG; - - openlog(progname, syslog_flags, zl->facility); - - frr_with_mutex(&loglock) { - zlog_default = zl; - } - -#ifdef HAVE_GLIBC_BACKTRACE - /* work around backtrace() using lazily resolved dynamically linked - * symbols, which will otherwise cause funny breakage in the SEGV - * handler. - * (particularly, the dynamic linker can call malloc(), which uses locks - * in programs linked with -pthread, thus can deadlock.) */ - void *bt[4]; - backtrace(bt, array_size(bt)); - free(backtrace_symbols(bt, 0)); - backtrace_symbols_fd(bt, 0, 0); -#endif -} - -void closezlog(void) -{ - frr_mutex_lock_autounlock(&loglock); - - struct zlog *zl = zlog_default; - - closelog(); - - if (zl->fp != NULL) - fclose(zl->fp); - - XFREE(MTYPE_ZLOG, zl->filename); - - XFREE(MTYPE_ZLOG, zl); - zlog_default = NULL; -} - -/* Called from command.c. */ -void zlog_set_level(zlog_dest_t dest, int log_level) -{ - frr_with_mutex(&loglock) { - zlog_default->maxlvl[dest] = log_level; - } -} - -int zlog_set_file(const char *filename, int log_level) -{ - struct zlog *zl; - FILE *fp; - mode_t oldumask; - int ret = 1; - - /* There is opend file. */ - zlog_reset_file(); - - /* Open file. */ - oldumask = umask(0777 & ~LOGFILE_MASK); - fp = fopen(filename, "a"); - umask(oldumask); - if (fp == NULL) { - ret = 0; - } else { - frr_with_mutex(&loglock) { - zl = zlog_default; - - /* Set flags. */ - zl->filename = XSTRDUP(MTYPE_ZLOG, filename); - zl->maxlvl[ZLOG_DEST_FILE] = log_level; - zl->fp = fp; - logfile_fd = fileno(fp); - } - } - - return ret; -} - -/* Reset opend file. */ -int zlog_reset_file(void) -{ - frr_mutex_lock_autounlock(&loglock); - - struct zlog *zl = zlog_default; - - if (zl->fp) - fclose(zl->fp); - zl->fp = NULL; - logfile_fd = -1; - zl->maxlvl[ZLOG_DEST_FILE] = ZLOG_DISABLED; - - XFREE(MTYPE_ZLOG, zl->filename); - - return 1; -} - -/* Reopen log file. */ -int zlog_rotate(void) -{ - pthread_mutex_lock(&loglock); - - struct zlog *zl = zlog_default; - int level; - int ret = 1; - - if (zl->fp) - fclose(zl->fp); - zl->fp = NULL; - logfile_fd = -1; - level = zl->maxlvl[ZLOG_DEST_FILE]; - zl->maxlvl[ZLOG_DEST_FILE] = ZLOG_DISABLED; - - if (zl->filename) { - mode_t oldumask; - int save_errno; - - oldumask = umask(0777 & ~LOGFILE_MASK); - zl->fp = fopen(zl->filename, "a"); - save_errno = errno; - umask(oldumask); - if (zl->fp == NULL) { - - pthread_mutex_unlock(&loglock); - - flog_err_sys( - EC_LIB_SYSTEM_CALL, - "Log rotate failed: cannot open file %s for append: %s", - zl->filename, safe_strerror(save_errno)); - ret = -1; - - pthread_mutex_lock(&loglock); - } else { - logfile_fd = fileno(zl->fp); - zl->maxlvl[ZLOG_DEST_FILE] = level; - } - } - - pthread_mutex_unlock(&loglock); - - return ret; -} - /* Wrapper around strerror to handle case where it returns NULL. */ const char *safe_strerror(int errnum) { diff --git a/lib/log.h b/lib/log.h index d79ad9f8055f..b65ae5d5d5bd 100644 --- a/lib/log.h +++ b/lib/log.h @@ -22,21 +22,22 @@ #ifndef _ZEBRA_LOG_H #define _ZEBRA_LOG_H +#include "zassert.h" + #include #include #include #include #include + #include "lib/hook.h" +#include "lib/zlog.h" +#include "lib/zlog_targets.h" #ifdef __cplusplus extern "C" { #endif -/* Hook for external logging function */ -DECLARE_HOOK(zebra_ext_log, (int priority, const char *format, va_list args), - (priority, format, args)); - /* Here is some guidance on logging levels to use: * * LOG_DEBUG - For all messages that are enabled by optional debugging @@ -53,19 +54,7 @@ DECLARE_HOOK(zebra_ext_log, (int priority, const char *format, va_list args), * please use LOG_ERR instead. */ -/* If maxlvl is set to ZLOG_DISABLED, then no messages will be sent - to that logging destination. */ -#define ZLOG_DISABLED (LOG_EMERG-1) - -typedef enum { - ZLOG_DEST_SYSLOG = 0, - ZLOG_DEST_STDOUT, - ZLOG_DEST_MONITOR, - ZLOG_DEST_FILE -} zlog_dest_t; -#define ZLOG_NUM_DESTS (ZLOG_DEST_FILE+1) - -extern bool zlog_startup_stderr; +extern void zlog_rotate(void); /* Message structure. */ struct message { @@ -73,22 +62,6 @@ struct message { const char *str; }; -/* Open zlog function */ -extern void openzlog(const char *progname, const char *protoname, - uint16_t instance, int syslog_options, - int syslog_facility); - -/* Close zlog function. */ -extern void closezlog(void); - -/* Handy zlog functions. */ -extern void zlog_err(const char *format, ...) PRINTFRR(1, 2); -extern void zlog_warn(const char *format, ...) PRINTFRR(1, 2); -extern void zlog_info(const char *format, ...) PRINTFRR(1, 2); -extern void zlog_notice(const char *format, ...) PRINTFRR(1, 2); -extern void zlog_debug(const char *format, ...) PRINTFRR(1, 2); -extern void zlog(int priority, const char *format, ...) PRINTFRR(2, 3); - /* For logs which have error codes associated with them */ #define flog_err(ferr_id, format, ...) \ zlog_err("[EC %" PRIu32 "] " format, ferr_id, ##__VA_ARGS__) @@ -101,23 +74,16 @@ extern void zlog(int priority, const char *format, ...) PRINTFRR(2, 3); extern void zlog_thread_info(int log_level); -/* Set logging level for the given destination. If the log_level - argument is ZLOG_DISABLED, then the destination is disabled. - This function should not be used for file logging (use zlog_set_file - or zlog_reset_file instead). */ -extern void zlog_set_level(zlog_dest_t, int log_level); - -/* Set logging to the given filename at the specified level. */ -extern int zlog_set_file(const char *filename, int log_level); -/* Disable file logging. */ -extern int zlog_reset_file(void); - -/* Rotate log. */ -extern int zlog_rotate(void); - #define ZLOG_FILTERS_MAX 100 /* Max # of filters at once */ #define ZLOG_FILTER_LENGTH_MAX 80 /* 80 character filter limit */ +struct zlog_cfg_filterfile { + struct zlog_cfg_file parent; +}; + +extern void zlog_filterfile_init(struct zlog_cfg_filterfile *zcf); +extern void zlog_filterfile_fini(struct zlog_cfg_filterfile *zcf); + /* Add/Del/Dump log filters */ extern void zlog_filter_clear(void); extern int zlog_filter_add(const char *filter); @@ -176,8 +142,6 @@ extern int proto_redistnum(int afi, const char *s); extern const char *zserv_command_string(unsigned int command); -extern int vzlog_test(int priority); - /* structure useful for avoiding repeated rendering of the same timestamp */ struct timestamp_control { size_t len; /* length of rendered timestamp */ diff --git a/lib/log_filter.c b/lib/log_filter.c new file mode 100644 index 000000000000..721e57a62804 --- /dev/null +++ b/lib/log_filter.c @@ -0,0 +1,156 @@ +/* + * Logging - Filtered file log target + * Copyright (C) 2019 Cumulus Networks, Inc. + * Stephen Worley + * + * This program is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License as published by the Free + * Software Foundation; either version 2 of the License, or (at your option) + * any later version. + * + * This program is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for + * more details. + * + * You should have received a copy of the GNU General Public License along + * with this program; see the file COPYING; if not, write to the Free Software + * Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA + */ + +#include + +#include "frr_pthread.h" +#include "log.h" + +static pthread_mutex_t logfilterlock = PTHREAD_MUTEX_INITIALIZER; +static char zlog_filters[ZLOG_FILTERS_MAX][ZLOG_FILTER_LENGTH_MAX + 1]; +static uint8_t zlog_filter_count; + +/* + * look for a match on the filter in the current filters, + * logfilterlock must be held + */ +static int zlog_filter_lookup(const char *lookup) +{ + for (int i = 0; i < zlog_filter_count; i++) { + if (strncmp(lookup, zlog_filters[i], sizeof(zlog_filters[0])) + == 0) + return i; + } + return -1; +} + +void zlog_filter_clear(void) +{ + frr_with_mutex(&logfilterlock) { + zlog_filter_count = 0; + } +} + +int zlog_filter_add(const char *filter) +{ + frr_with_mutex(&logfilterlock) { + if (zlog_filter_count >= ZLOG_FILTERS_MAX) + return 1; + + if (zlog_filter_lookup(filter) != -1) + /* Filter already present */ + return -1; + + strlcpy(zlog_filters[zlog_filter_count], filter, + sizeof(zlog_filters[0])); + + if (zlog_filters[zlog_filter_count][0] == '\0') + /* Filter was either empty or didn't get copied + * correctly + */ + return -1; + + zlog_filter_count++; + } + return 0; +} + +int zlog_filter_del(const char *filter) +{ + frr_with_mutex(&logfilterlock) { + int found_idx = zlog_filter_lookup(filter); + int last_idx = zlog_filter_count - 1; + + if (found_idx == -1) + /* Didn't find the filter to delete */ + return -1; + + /* Adjust the filter array */ + memmove(zlog_filters[found_idx], zlog_filters[found_idx + 1], + (last_idx - found_idx) * sizeof(zlog_filters[0])); + + zlog_filter_count--; + } + return 0; +} + +/* Dump all filters to buffer, delimited by new line */ +int zlog_filter_dump(char *buf, size_t max_size) +{ + int len = 0; + + frr_with_mutex(&logfilterlock) { + for (int i = 0; i < zlog_filter_count; i++) { + int ret; + + ret = snprintf(buf + len, max_size - len, " %s\n", + zlog_filters[i]); + len += ret; + if ((ret < 0) || ((size_t)len >= max_size)) + return -1; + } + } + + return len; +} + +static int search_buf(const char *buf) +{ + char *found = NULL; + + frr_with_mutex(&logfilterlock) { + for (int i = 0; i < zlog_filter_count; i++) { + found = strstr(buf, zlog_filters[i]); + if (found != NULL) + return 0; + } + } + + return -1; +} + +static void zlog_filterfile_fd(struct zlog_target *zt, struct zlog_msg *msgs[], + size_t nmsgs) +{ + struct zlog_msg *msgfilt[nmsgs]; + size_t i, o = 0; + + for (i = 0; i < nmsgs; i++) { + if (zlog_msg_prio(msgs[i]) >= LOG_DEBUG + && search_buf(zlog_msg_text(msgs[i], NULL)) < 0) + continue; + + msgfilt[o++] = msgs[i]; + } + + if (o) + zlog_fd(zt, msgfilt, o); +} + +void zlog_filterfile_init(struct zlog_cfg_filterfile *zcf) +{ + zlog_file_init(&zcf->parent); + zcf->parent.zlog_wrap = zlog_filterfile_fd; +} + +void zlog_filterfile_fini(struct zlog_cfg_filterfile *zcf) +{ + zlog_file_fini(&zcf->parent); +} diff --git a/lib/log_int.h b/lib/log_int.h deleted file mode 100644 index 287e626eab36..000000000000 --- a/lib/log_int.h +++ /dev/null @@ -1,59 +0,0 @@ -/* - * Zebra logging funcions. - * Copyright (C) 1997, 1998, 1999 Kunihiro Ishiguro - * - * This file is part of GNU Zebra. - * - * GNU Zebra is free software; you can redistribute it and/or modify it - * under the terms of the GNU General Public License as published by the - * Free Software Foundation; either version 2, or (at your option) any - * later version. - * - * GNU Zebra is distributed in the hope that it will be useful, but - * WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU - * General Public License for more details. - * - * You should have received a copy of the GNU General Public License along - * with this program; see the file COPYING; if not, write to the Free Software - * Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA - */ - -#ifndef _ZEBRA_LOG_PRIVATE_H -#define _ZEBRA_LOG_PRIVATE_H - -#include "log.h" - -#ifdef __cplusplus -extern "C" { -#endif - -struct zlog { - const char *ident; /* daemon name (first arg to openlog) */ - const char *protoname; - unsigned short instance; - int maxlvl[ZLOG_NUM_DESTS]; /* maximum priority to send to associated - logging destination */ - int default_lvl; /* maxlvl to use if none is specified */ - FILE *fp; - char *filename; - int facility; /* as per syslog facility */ - int record_priority; /* should messages logged through stdio include the - priority of the message? */ - int syslog_options; /* 2nd arg to openlog */ - int timestamp_precision; /* # of digits of subsecond precision */ -}; - -/* Default logging strucutre. */ -extern struct zlog *zlog_default; - -extern const char *zlog_priority[]; - -/* Generic function for zlog. */ -extern void vzlog(int priority, const char *format, va_list args); - -#ifdef __cplusplus -} -#endif - -#endif /* _ZEBRA_LOG_PRIVATE_H */ diff --git a/lib/log_vty.c b/lib/log_vty.c index 68d598f5656d..97026e5dbc77 100644 --- a/lib/log_vty.c +++ b/lib/log_vty.c @@ -22,12 +22,542 @@ #include "lib/log_vty.h" #include "command.h" -#include "lib/vty.h" #include "lib/log.h" +#include "lib/zlog_targets.h" +#include "lib/lib_errors.h" +#include "lib/printfrr.h" + #ifndef VTYSH_EXTRACT_PL #include "lib/log_vty_clippy.c" #endif +#define ZLOG_MAXLVL(a, b) MAX(a, b) + +DEFINE_HOOK(zlog_rotate, (), ()) + +static const int log_default_lvl = LOG_DEBUG; + +static int log_config_stdout_lvl = ZLOG_DISABLED; +static int log_config_syslog_lvl = ZLOG_DISABLED; +static int log_cmdline_stdout_lvl = ZLOG_DISABLED; +static int log_cmdline_syslog_lvl = ZLOG_DISABLED; + +static struct zlog_cfg_file zt_file_cmdline = { + .prio_min = ZLOG_DISABLED, +}; +static struct zlog_cfg_file zt_file = { + .prio_min = ZLOG_DISABLED, +}; +static struct zlog_cfg_file zt_stdout = { + .prio_min = ZLOG_DISABLED, +}; +static struct zlog_cfg_filterfile zt_filterfile = { + .parent = { + .prio_min = ZLOG_DISABLED, + }, +}; + +static const char *zlog_progname; +static const char *zlog_protoname; + +static const struct facility_map { + int facility; + const char *name; + size_t match; +} syslog_facilities[] = { + {LOG_KERN, "kern", 1}, + {LOG_USER, "user", 2}, + {LOG_MAIL, "mail", 1}, + {LOG_DAEMON, "daemon", 1}, + {LOG_AUTH, "auth", 1}, + {LOG_SYSLOG, "syslog", 1}, + {LOG_LPR, "lpr", 2}, + {LOG_NEWS, "news", 1}, + {LOG_UUCP, "uucp", 2}, + {LOG_CRON, "cron", 1}, +#ifdef LOG_FTP + {LOG_FTP, "ftp", 1}, +#endif + {LOG_LOCAL0, "local0", 6}, + {LOG_LOCAL1, "local1", 6}, + {LOG_LOCAL2, "local2", 6}, + {LOG_LOCAL3, "local3", 6}, + {LOG_LOCAL4, "local4", 6}, + {LOG_LOCAL5, "local5", 6}, + {LOG_LOCAL6, "local6", 6}, + {LOG_LOCAL7, "local7", 6}, + {0, NULL, 0}, +}; + +static const char * const zlog_priority[] = { + "emergencies", "alerts", "critical", "errors", "warnings", + "notifications", "informational", "debugging", NULL, +}; + +static const char *facility_name(int facility) +{ + const struct facility_map *fm; + + for (fm = syslog_facilities; fm->name; fm++) + if (fm->facility == facility) + return fm->name; + return ""; +} + +static int facility_match(const char *str) +{ + const struct facility_map *fm; + + for (fm = syslog_facilities; fm->name; fm++) + if (!strncmp(str, fm->name, fm->match)) + return fm->facility; + return -1; +} + +int log_level_match(const char *s) +{ + int level; + + for (level = 0; zlog_priority[level] != NULL; level++) + if (!strncmp(s, zlog_priority[level], 2)) + return level; + return ZLOG_DISABLED; +} + +void zlog_rotate(void) +{ + zlog_file_rotate(&zt_file); + zlog_file_rotate(&zt_filterfile.parent); + hook_call(zlog_rotate); +} + + +void log_show_syslog(struct vty *vty) +{ + int level = zlog_syslog_get_prio_min(); + + vty_out(vty, "Syslog logging: "); + if (level == ZLOG_DISABLED) + vty_out(vty, "disabled\n"); + else + vty_out(vty, "level %s, facility %s, ident %s\n", + zlog_priority[level], + facility_name(zlog_syslog_get_facility()), + zlog_progname); +} + +DEFUN (show_logging, + show_logging_cmd, + "show logging", + SHOW_STR + "Show current logging configuration\n") +{ + log_show_syslog(vty); + + vty_out(vty, "Stdout logging: "); + if (zt_stdout.prio_min == ZLOG_DISABLED) + vty_out(vty, "disabled"); + else + vty_out(vty, "level %s", + zlog_priority[zt_stdout.prio_min]); + vty_out(vty, "\n"); + + vty_out(vty, "File logging: "); + if (zt_file.prio_min == ZLOG_DISABLED || !zt_file.filename) + vty_out(vty, "disabled"); + else + vty_out(vty, "level %s, filename %s", + zlog_priority[zt_file.prio_min], zt_file.filename); + vty_out(vty, "\n"); + + if (zt_filterfile.parent.prio_min != ZLOG_DISABLED + && zt_filterfile.parent.filename) + vty_out(vty, "Filtered-file logging: level %s, filename %s\n", + zlog_priority[zt_filterfile.parent.prio_min], + zt_filterfile.parent.filename); + + if (log_cmdline_syslog_lvl != ZLOG_DISABLED) + vty_out(vty, + "From command line: \"--log syslog --log-level %s\"\n", + zlog_priority[log_cmdline_syslog_lvl]); + if (log_cmdline_stdout_lvl != ZLOG_DISABLED) + vty_out(vty, + "From command line: \"--log stdout --log-level %s\"\n", + zlog_priority[log_cmdline_stdout_lvl]); + if (zt_file_cmdline.prio_min != ZLOG_DISABLED) + vty_out(vty, + "From command line: \"--log file:%s --log-level %s\"\n", + zt_file_cmdline.filename, + zlog_priority[zt_file_cmdline.prio_min]); + + vty_out(vty, "Protocol name: %s\n", zlog_protoname); + vty_out(vty, "Record priority: %s\n", + (zt_file.record_priority ? "enabled" : "disabled")); + vty_out(vty, "Timestamp precision: %d\n", zt_file.ts_subsec); + return CMD_SUCCESS; +} + +DEFPY (config_log_stdout, + config_log_stdout_cmd, + "log stdout [$levelarg]", + "Logging control\n" + "Set stdout logging level\n" + LOG_LEVEL_DESC) +{ + int level; + + if (levelarg) { + level = log_level_match(levelarg); + if (level == ZLOG_DISABLED) + return CMD_ERR_NO_MATCH; + } else + level = log_default_lvl; + + log_config_stdout_lvl = level; + zt_stdout.prio_min = ZLOG_MAXLVL(log_config_stdout_lvl, + log_cmdline_stdout_lvl); + zlog_file_set_other(&zt_stdout); + return CMD_SUCCESS; +} + +DEFUN (no_config_log_stdout, + no_config_log_stdout_cmd, + "no log stdout []", + NO_STR + "Logging control\n" + "Cancel logging to stdout\n" + LOG_LEVEL_DESC) +{ + log_config_stdout_lvl = ZLOG_DISABLED; + zt_stdout.prio_min = ZLOG_MAXLVL(log_config_stdout_lvl, + log_cmdline_stdout_lvl); + zlog_file_set_other(&zt_stdout); + return CMD_SUCCESS; +} + +DEFUN_HIDDEN (config_log_monitor, + config_log_monitor_cmd, + "log monitor []", + "Logging control\n" + "Set terminal line (monitor) logging level\n" + LOG_LEVEL_DESC) +{ + vty_out(vty, "%% \"log monitor\" is deprecated and does nothing.\n"); + return CMD_SUCCESS; +} + +DEFUN_HIDDEN (no_config_log_monitor, + no_config_log_monitor_cmd, + "no log monitor []", + NO_STR + "Logging control\n" + "Disable terminal line (monitor) logging\n" + LOG_LEVEL_DESC) +{ + return CMD_SUCCESS; +} + +static int set_log_file(struct zlog_cfg_file *target, struct vty *vty, + const char *fname, int loglevel) +{ + char *p = NULL; + const char *fullpath; + bool ok; + + /* Path detection. */ + if (!IS_DIRECTORY_SEP(*fname)) { + char cwd[MAXPATHLEN + 1]; + + cwd[MAXPATHLEN] = '\0'; + + if (getcwd(cwd, MAXPATHLEN) == NULL) { + flog_err_sys(EC_LIB_SYSTEM_CALL, + "config_log_file: Unable to alloc mem!"); + return CMD_WARNING_CONFIG_FAILED; + } + + p = XMALLOC(MTYPE_TMP, strlen(cwd) + strlen(fname) + 2); + sprintf(p, "%s/%s", cwd, fname); + fullpath = p; + } else + fullpath = fname; + + target->prio_min = loglevel; + ok = zlog_file_set_filename(target, fullpath); + + XFREE(MTYPE_TMP, p); + + if (!ok) { + if (vty) + vty_out(vty, "can't open logfile %s\n", fname); + return CMD_WARNING_CONFIG_FAILED; + } + return CMD_SUCCESS; +} + +void command_setup_early_logging(const char *dest, const char *level) +{ + int nlevel; + char *sep; + int len; + char type[8]; + + if (level) { + nlevel = log_level_match(level); + + if (nlevel == ZLOG_DISABLED) { + fprintf(stderr, "invalid log level \"%s\"\n", level); + exit(1); + } + } else + nlevel = log_default_lvl; + + if (!dest) + return; + + sep = strchr(dest, ':'); + len = sep ? (int)(sep - dest) : (int)strlen(dest); + + snprintfrr(type, sizeof(type), "%.*s", len, dest); + + if (strcmp(type, "stdout") == 0) { + log_cmdline_stdout_lvl = nlevel; + zt_stdout.prio_min = ZLOG_MAXLVL(log_config_stdout_lvl, + log_cmdline_stdout_lvl); + zlog_file_set_other(&zt_stdout); + return; + } + if (strcmp(type, "syslog") == 0) { + log_cmdline_syslog_lvl = nlevel; + zlog_syslog_set_prio_min(ZLOG_MAXLVL(log_config_syslog_lvl, + log_cmdline_syslog_lvl)); + return; + } + if (strcmp(type, "file") == 0 && sep) { + sep++; + set_log_file(&zt_file_cmdline, NULL, sep, nlevel); + return; + } + + fprintf(stderr, "invalid log target \"%s\" (\"%s\")\n", type, dest); + exit(1); +} + +DEFUN (clear_log_cmdline, + clear_log_cmdline_cmd, + "clear log cmdline-targets", + CLEAR_STR + "Logging control\n" + "Disable log targets specified at startup by --log option\n") +{ + zt_file_cmdline.prio_min = ZLOG_DISABLED; + zlog_file_set_other(&zt_file_cmdline); + + log_cmdline_syslog_lvl = ZLOG_DISABLED; + zlog_syslog_set_prio_min(ZLOG_MAXLVL(log_config_syslog_lvl, + log_cmdline_syslog_lvl)); + + log_cmdline_stdout_lvl = ZLOG_DISABLED; + zt_stdout.prio_min = ZLOG_MAXLVL(log_config_stdout_lvl, + log_cmdline_stdout_lvl); + zlog_file_set_other(&zt_stdout); + + return CMD_SUCCESS; +} + +DEFPY (config_log_file, + config_log_file_cmd, + "log file FILENAME [$levelarg]", + "Logging control\n" + "Logging to file\n" + "Logging filename\n" + LOG_LEVEL_DESC) +{ + int level = log_default_lvl; + + if (levelarg) { + level = log_level_match(levelarg); + if (level == ZLOG_DISABLED) + return CMD_ERR_NO_MATCH; + } + return set_log_file(&zt_file, vty, filename, level); +} + +DEFUN (no_config_log_file, + no_config_log_file_cmd, + "no log file [FILENAME [LEVEL]]", + NO_STR + "Logging control\n" + "Cancel logging to file\n" + "Logging file name\n" + "Logging level\n") +{ + zt_file.prio_min = ZLOG_DISABLED; + zlog_file_set_other(&zt_file); + return CMD_SUCCESS; +} + +DEFPY (config_log_syslog, + config_log_syslog_cmd, + "log syslog [$levelarg]", + "Logging control\n" + "Set syslog logging level\n" + LOG_LEVEL_DESC) +{ + int level; + + if (levelarg) { + level = log_level_match(levelarg); + + if (level == ZLOG_DISABLED) + return CMD_ERR_NO_MATCH; + } else + level = log_default_lvl; + + log_config_syslog_lvl = level; + zlog_syslog_set_prio_min(ZLOG_MAXLVL(log_config_syslog_lvl, + log_cmdline_syslog_lvl)); + return CMD_SUCCESS; +} + +DEFUN (no_config_log_syslog, + no_config_log_syslog_cmd, + "no log syslog [] []", + NO_STR + "Logging control\n" + "Cancel logging to syslog\n" + LOG_FACILITY_DESC + LOG_LEVEL_DESC) +{ + log_config_syslog_lvl = ZLOG_DISABLED; + zlog_syslog_set_prio_min(ZLOG_MAXLVL(log_config_syslog_lvl, + log_cmdline_syslog_lvl)); + return CMD_SUCCESS; +} + +DEFPY (config_log_facility, + config_log_facility_cmd, + "log facility $facilityarg", + "Logging control\n" + "Facility parameter for syslog messages\n" + LOG_FACILITY_DESC) +{ + int facility = facility_match(facilityarg); + + zlog_syslog_set_facility(facility); + return CMD_SUCCESS; +} + +DEFUN (no_config_log_facility, + no_config_log_facility_cmd, + "no log facility []", + NO_STR + "Logging control\n" + "Reset syslog facility to default (daemon)\n" + LOG_FACILITY_DESC) +{ + zlog_syslog_set_facility(LOG_DAEMON); + return CMD_SUCCESS; +} + +DEFUN (config_log_record_priority, + config_log_record_priority_cmd, + "log record-priority", + "Logging control\n" + "Log the priority of the message within the message\n") +{ + zt_file.record_priority = true; + zlog_file_set_other(&zt_file); + zt_stdout.record_priority = true; + zlog_file_set_other(&zt_stdout); + zt_filterfile.parent.record_priority = true; + zlog_file_set_other(&zt_filterfile.parent); + return CMD_SUCCESS; +} + +DEFUN (no_config_log_record_priority, + no_config_log_record_priority_cmd, + "no log record-priority", + NO_STR + "Logging control\n" + "Do not log the priority of the message within the message\n") +{ + zt_file.record_priority = false; + zlog_file_set_other(&zt_file); + zt_stdout.record_priority = false; + zlog_file_set_other(&zt_stdout); + zt_filterfile.parent.record_priority = false; + zlog_file_set_other(&zt_filterfile.parent); + return CMD_SUCCESS; +} + +DEFPY (config_log_timestamp_precision, + config_log_timestamp_precision_cmd, + "log timestamp precision (0-6)", + "Logging control\n" + "Timestamp configuration\n" + "Set the timestamp precision\n" + "Number of subsecond digits\n") +{ + zt_file.ts_subsec = precision; + zlog_file_set_other(&zt_file); + zt_stdout.ts_subsec = precision; + zlog_file_set_other(&zt_stdout); + zt_filterfile.parent.ts_subsec = precision; + zlog_file_set_other(&zt_filterfile.parent); + return CMD_SUCCESS; +} + +DEFUN (no_config_log_timestamp_precision, + no_config_log_timestamp_precision_cmd, + "no log timestamp precision [(0-6)]", + NO_STR + "Logging control\n" + "Timestamp configuration\n" + "Reset the timestamp precision to the default value of 0\n" + "Number of subsecond digits\n") +{ + zt_file.ts_subsec = 0; + zlog_file_set_other(&zt_file); + zt_stdout.ts_subsec = 0; + zlog_file_set_other(&zt_stdout); + zt_filterfile.parent.ts_subsec = 0; + zlog_file_set_other(&zt_filterfile.parent); + return CMD_SUCCESS; +} + +DEFPY (config_log_filterfile, + config_log_filterfile_cmd, + "log filtered-file FILENAME [$levelarg]", + "Logging control\n" + "Logging to file with string filter\n" + "Logging filename\n" + LOG_LEVEL_DESC) +{ + int level = log_default_lvl; + + if (levelarg) { + level = log_level_match(levelarg); + if (level == ZLOG_DISABLED) + return CMD_ERR_NO_MATCH; + } + return set_log_file(&zt_filterfile.parent, vty, filename, level); +} + +DEFUN (no_config_log_filterfile, + no_config_log_filterfile_cmd, + "no log filtered-file [FILENAME [LEVEL]]", + NO_STR + "Logging control\n" + "Cancel logging to file with string filter\n" + "Logging file name\n" + "Logging level\n") +{ + zt_filterfile.parent.prio_min = ZLOG_DISABLED; + zlog_file_set_other(&zt_filterfile.parent); + return CMD_SUCCESS; +} + DEFPY (log_filter, log_filter_cmd, "[no] log-filter WORD$filter", @@ -89,9 +619,122 @@ DEFPY (show_log_filter, return CMD_SUCCESS; } -void log_filter_cmd_init(void) +void log_config_write(struct vty *vty) { + bool show_cmdline_hint = false; + + if (zt_file.prio_min != ZLOG_DISABLED && zt_file.filename) { + vty_out(vty, "log file %s", zt_file.filename); + + if (zt_file.prio_min != log_default_lvl) + vty_out(vty, " %s", zlog_priority[zt_file.prio_min]); + vty_out(vty, "\n"); + } + + if (zt_filterfile.parent.prio_min != ZLOG_DISABLED + && zt_filterfile.parent.filename) { + vty_out(vty, "log filtered-file %s", + zt_filterfile.parent.filename); + + if (zt_filterfile.parent.prio_min != log_default_lvl) + vty_out(vty, " %s", + zlog_priority[zt_filterfile.parent.prio_min]); + vty_out(vty, "\n"); + } + + if (log_config_stdout_lvl != ZLOG_DISABLED) { + vty_out(vty, "log stdout"); + + if (log_config_stdout_lvl != log_default_lvl) + vty_out(vty, " %s", + zlog_priority[log_config_stdout_lvl]); + vty_out(vty, "\n"); + } + + if (log_config_syslog_lvl != ZLOG_DISABLED) { + vty_out(vty, "log syslog"); + + if (log_config_syslog_lvl != log_default_lvl) + vty_out(vty, " %s", + zlog_priority[log_config_syslog_lvl]); + vty_out(vty, "\n"); + } + + if (log_cmdline_syslog_lvl != ZLOG_DISABLED) { + vty_out(vty, + "! \"log syslog %s\" enabled by \"--log\" startup option\n", + zlog_priority[log_cmdline_syslog_lvl]); + show_cmdline_hint = true; + } + if (log_cmdline_stdout_lvl != ZLOG_DISABLED) { + vty_out(vty, + "! \"log stdout %s\" enabled by \"--log\" startup option\n", + zlog_priority[log_cmdline_stdout_lvl]); + show_cmdline_hint = true; + } + if (zt_file_cmdline.prio_min != ZLOG_DISABLED) { + vty_out(vty, + "! \"log file %s %s\" enabled by \"--log\" startup option\n", + zt_file_cmdline.filename, + zlog_priority[zt_file_cmdline.prio_min]); + show_cmdline_hint = true; + } + if (show_cmdline_hint) + vty_out(vty, + "! use \"clear log cmdline-targets\" to remove this target\n"); + + if (zlog_syslog_get_facility() != LOG_DAEMON) + vty_out(vty, "log facility %s\n", + facility_name(zlog_syslog_get_facility())); + + if (zt_file.record_priority == 1) + vty_out(vty, "log record-priority\n"); + + if (zt_file.ts_subsec > 0) + vty_out(vty, "log timestamp precision %d\n", + zt_file.ts_subsec); +} + +static int log_vty_init(const char *progname, const char *protoname, + unsigned short instance, uid_t uid, gid_t gid) +{ + zlog_progname = progname; + zlog_protoname = protoname; + + zlog_filterfile_init(&zt_filterfile); + + zlog_file_set_fd(&zt_stdout, STDOUT_FILENO); + return 0; +} + +__attribute__((_CONSTRUCTOR(475))) static void log_vty_preinit(void) +{ + hook_register(zlog_init, log_vty_init); +} + +void log_cmd_init(void) +{ + install_element(VIEW_NODE, &show_logging_cmd); + install_element(ENABLE_NODE, &clear_log_cmdline_cmd); + + install_element(CONFIG_NODE, &config_log_stdout_cmd); + install_element(CONFIG_NODE, &no_config_log_stdout_cmd); + install_element(CONFIG_NODE, &config_log_monitor_cmd); + install_element(CONFIG_NODE, &no_config_log_monitor_cmd); + install_element(CONFIG_NODE, &config_log_file_cmd); + install_element(CONFIG_NODE, &no_config_log_file_cmd); + install_element(CONFIG_NODE, &config_log_syslog_cmd); + install_element(CONFIG_NODE, &no_config_log_syslog_cmd); + install_element(CONFIG_NODE, &config_log_facility_cmd); + install_element(CONFIG_NODE, &no_config_log_facility_cmd); + install_element(CONFIG_NODE, &config_log_record_priority_cmd); + 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(VIEW_NODE, &show_log_filter_cmd); install_element(CONFIG_NODE, &log_filter_cmd); install_element(CONFIG_NODE, &log_filter_clear_cmd); + install_element(CONFIG_NODE, &config_log_filterfile_cmd); + install_element(CONFIG_NODE, &no_config_log_filterfile_cmd); } diff --git a/lib/log_vty.h b/lib/log_vty.h index fa5627e4bd1a..0fd60e9b078a 100644 --- a/lib/log_vty.h +++ b/lib/log_vty.h @@ -20,5 +20,17 @@ #ifndef __LOG_VTY_H__ #define __LOG_VTY_H__ -extern void log_filter_cmd_init(void); + +#include "lib/hook.h" + +struct vty; + +extern void log_cmd_init(void); +extern void log_config_write(struct vty *vty); +extern int log_level_match(const char *s); +extern void log_show_syslog(struct vty *vty); + +DECLARE_HOOK(zlog_rotate, (), ()) +extern void zlog_rotate(void); + #endif /* __LOG_VTY_H__ */ diff --git a/lib/memory.c b/lib/memory.c index 149e294d5001..3a29404827e5 100644 --- a/lib/memory.c +++ b/lib/memory.c @@ -163,7 +163,8 @@ static int qmem_exit_walker(void *arg, struct memgroup *mg, struct memtype *mt) } else if (mt->n_alloc) { char size[32]; - eda->error++; + if (!mg->active_at_exit) + eda->error++; snprintf(size, sizeof(size), "%10zu", mt->size); fprintf(eda->fp, "%s: memstats: %-30s: %6zu * %s\n", eda->prefix, mt->name, mt->n_alloc, diff --git a/lib/memory.h b/lib/memory.h index e4e05faa4ff8..13f2f9b11ac0 100644 --- a/lib/memory.h +++ b/lib/memory.h @@ -17,6 +17,7 @@ #ifndef _QUAGGA_MEMORY_H #define _QUAGGA_MEMORY_H +#include #include #include #include @@ -48,6 +49,8 @@ struct memgroup { struct memgroup *next, **ref; struct memtype *types, **insert; const char *name; + /* ignore group on dumping memleaks at exit */ + bool active_at_exit; }; /* macro usage: @@ -76,7 +79,7 @@ struct memgroup { */ #define DECLARE_MGROUP(name) extern struct memgroup _mg_##name; -#define DEFINE_MGROUP(mname, desc) \ +#define _DEFINE_MGROUP(mname, desc, ...) \ struct memgroup _mg_##mname \ __attribute__((section(".data.mgroups"))) = { \ .name = desc, \ @@ -84,6 +87,7 @@ struct memgroup { .next = NULL, \ .insert = NULL, \ .ref = NULL, \ + __VA_ARGS__ \ }; \ static void _mginit_##mname(void) __attribute__((_CONSTRUCTOR(1000))); \ static void _mginit_##mname(void) \ @@ -99,7 +103,13 @@ struct memgroup { if (_mg_##mname.next) \ _mg_##mname.next->ref = _mg_##mname.ref; \ *_mg_##mname.ref = _mg_##mname.next; \ - } + } \ + /* end */ + +#define DEFINE_MGROUP(mname, desc) \ + _DEFINE_MGROUP(mname, desc, ) +#define DEFINE_MGROUP_ACTIVEATEXIT(mname, desc) \ + _DEFINE_MGROUP(mname, desc, .active_at_exit = true) #define DECLARE_MTYPE(name) \ extern struct memtype MTYPE_##name[1]; \ diff --git a/lib/subdir.am b/lib/subdir.am index 4f62eb226413..a01909e90d87 100644 --- a/lib/subdir.am +++ b/lib/subdir.am @@ -45,6 +45,7 @@ lib_libfrr_la_SOURCES = \ lib/libfrr.c \ lib/linklist.c \ lib/log.c \ + lib/log_filter.c \ lib/log_vty.c \ lib/md5.c \ lib/memory.c \ @@ -100,6 +101,8 @@ lib_libfrr_la_SOURCES = \ lib/yang_translator.c \ lib/yang_wrappers.c \ lib/zclient.c \ + lib/zlog.c \ + lib/zlog_targets.c \ lib/printf/printf-pos.c \ lib/printf/vfprintf.c \ lib/printf/glue.c \ @@ -254,6 +257,8 @@ pkginclude_HEADERS += \ lib/zassert.h \ lib/zclient.h \ lib/zebra.h \ + lib/zlog.h \ + lib/zlog_targets.h \ lib/pbr.h \ # end @@ -265,7 +270,6 @@ nodist_pkginclude_HEADERS += \ noinst_HEADERS += \ lib/clippy.h \ - lib/log_int.h \ lib/plist_int.h \ lib/printf/printfcommon.h \ lib/printf/printflocal.h \ diff --git a/lib/thread.c b/lib/thread.c index dbf668a699c1..4d689a9f88a9 100644 --- a/lib/thread.c +++ b/lib/thread.c @@ -724,6 +724,7 @@ static int fd_poll(struct thread_master *m, struct pollfd *pfds, nfds_t pfdsize, < 0) // effect a poll (return immediately) timeout = 0; + zlog_tls_buffer_flush(); rcu_read_unlock(); rcu_assert_read_unlocked(); diff --git a/lib/zlog.c b/lib/zlog.c new file mode 100644 index 000000000000..4cab23699412 --- /dev/null +++ b/lib/zlog.c @@ -0,0 +1,702 @@ +/* + * Copyright (c) 2015-19 David Lamparter, for NetDEF, Inc. + * + * Permission to use, copy, modify, and distribute this software for any + * purpose with or without fee is hereby granted, provided that the above + * copyright notice and this permission notice appear in all copies. + * + * THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES + * WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF + * MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR + * ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES + * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN + * ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF + * OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE. + */ + +#include "zebra.h" + +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +/* gettid() & co. */ +#ifdef HAVE_PTHREAD_NP_H +#include +#endif +#ifdef linux +#include +#endif +#ifdef __FreeBSD__ +#include +#endif +#ifdef __NetBSD__ +#include +#endif +#ifdef __DragonFly__ +#include +#endif +#ifdef __APPLE__ +#include +#endif + +#include "memory.h" +#include "atomlist.h" +#include "printfrr.h" +#include "frrcu.h" +#include "zlog.h" + +DEFINE_MTYPE_STATIC(LIB, LOG_MESSAGE, "log message") +DEFINE_MTYPE_STATIC(LIB, LOG_TLSBUF, "log thread-local buffer") + +DEFINE_HOOK(zlog_init, (const char *progname, const char *protoname, + unsigned short instance, uid_t uid, gid_t gid), + (progname, protoname, instance, uid, gid)) +DEFINE_KOOH(zlog_fini, (), ()) +DEFINE_HOOK(zlog_aux_init, (const char *prefix, int prio_min), + (prefix, prio_min)) + +char zlog_prefix[128]; +size_t zlog_prefixsz; +int zlog_tmpdirfd = -1; + +/* 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 + * trying to delete things on shutdown + */ +static uid_t zlog_uid = -1; +static gid_t zlog_gid = -1; + +DECLARE_ATOMLIST(zlog_targets, struct zlog_target, head); +static struct zlog_targets_head zlog_targets; + +/* cf. zlog.h for additional comments on this struct. + * + * Note: you MUST NOT pass the format string + va_list to non-FRR format + * string functions (e.g. vsyslog, sd_journal_printv, ...) since FRR uses an + * extended prinf() with additional formats (%pI4 and the like). + * + * Also remember to use va_copy() on args. + */ + +struct zlog_msg { + struct timespec ts; + int prio; + + const char *fmt; + va_list args; + + char *stackbuf; + size_t stackbufsz; + char *text; + size_t textlen; + + /* This is always ISO8601 with sub-second precision 9 here, it's + * converted for callers as needed. ts_dot points to the "." + * separating sub-seconds. ts_zonetail is "Z" or "+00:00" for the + * local time offset. + * + * 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]; +}; + +/* thread-local log message buffering + * + * This is strictly optional and set up by calling zlog_tls_buffer_init() + * on a particular thread. + * + * If in use, this will create a temporary file in /var/tmp which is used as + * memory-mapped MAP_SHARED log message buffer. The idea there is that buffer + * access doesn't require any syscalls, but in case of a crash the kernel + * knows to sync the memory back to disk. This way the user can still get the + * last log messages if there were any left unwritten in the buffer. + * + * Sizing this dynamically isn't particularly useful, so here's an 8k buffer + * with a message limit of 64 messages. Message metadata (e.g. priority, + * timestamp) aren't in the mmap region, so they're lost on crash, but we can + * live with that. + */ + +#if defined(HAVE_OPENAT) && defined(HAVE_UNLINKAT) +#define CAN_DO_TLS 1 +#endif + +#define TLS_LOG_BUF_SIZE 8192 +#define TLS_LOG_MAXMSG 64 + +struct zlog_tls { + char *mmbuf; + size_t bufpos; + + size_t nmsgs; + struct zlog_msg msgs[TLS_LOG_MAXMSG]; + struct zlog_msg *msgp[TLS_LOG_MAXMSG]; +}; + +static inline void zlog_tls_free(void *arg); + +/* proper ELF TLS is a bit faster than pthread_[gs]etspecific, so if it's + * available we'll use it here + */ + +#ifdef __OpenBSD__ +static pthread_key_t zlog_tls_key; + +static void zlog_tls_key_init(void) __attribute__((_CONSTRUCTOR(500))); +static void zlog_tls_key_init(void) +{ + pthread_key_create(&zlog_tls_key, zlog_tls_free); +} + +static void zlog_tls_key_fini(void) __attribute__((_DESTRUCTOR(500))); +static void zlog_tls_key_fini(void) +{ + pthread_key_delete(zlog_tls_key); +} + +static inline struct zlog_tls *zlog_tls_get(void) +{ + return pthread_getspecific(zlog_tls_key); +} + +static inline void zlog_tls_set(struct zlog_tls *val) +{ + pthread_setspecific(zlog_tls_key, val); +} +#else +# ifndef thread_local +# define thread_local __thread +# endif + +static thread_local struct zlog_tls *zlog_tls_var + __attribute__((tls_model("initial-exec"))); + +static inline struct zlog_tls *zlog_tls_get(void) +{ + return zlog_tls_var; +} + +static inline void zlog_tls_set(struct zlog_tls *val) +{ + zlog_tls_var = val; +} +#endif + +#ifdef CAN_DO_TLS +static long zlog_gettid(void) +{ + long rv = -1; +#ifdef HAVE_PTHREAD_GETTHREADID_NP + rv = pthread_getthreadid_np(); +#elif defined(linux) + rv = syscall(__NR_gettid); +#elif defined(__NetBSD__) + rv = _lwp_self(); +#elif defined(__FreeBSD__) + thr_self(&rv); +#elif defined(__DragonFly__) + rv = lwp_gettid(); +#elif defined(__OpenBSD__) + rv = getthrid(); +#elif defined(__sun) + rv = pthread_self(); +#elif defined(__APPLE__) + rv = mach_thread_self(); + mach_port_deallocate(mach_task_self(), rv); +#endif + return rv; +} + +void zlog_tls_buffer_init(void) +{ + struct zlog_tls *zlog_tls; + char mmpath[MAXPATHLEN]; + int mmfd; + size_t i; + + zlog_tls = zlog_tls_get(); + + if (zlog_tls || zlog_tmpdirfd < 0) + return; + + zlog_tls = XCALLOC(MTYPE_LOG_TLSBUF, sizeof(*zlog_tls)); + 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()); + + mmfd = openat(zlog_tmpdirfd, mmpath, + O_RDWR | O_CREAT | O_EXCL | O_CLOEXEC, 0600); + fchown(mmfd, zlog_uid, zlog_gid); + + if (mmfd < 0) { + zlog_err("failed to open thread log buffer \"%s\": %s", + mmpath, strerror(errno)); + goto out_anon; + } + +#ifdef HAVE_POSIX_FALLOCATE + if (posix_fallocate(mmfd, 0, TLS_LOG_BUF_SIZE) < 0) { +#else + if (ftruncate(mmfd, TLS_LOG_BUF_SIZE) < 0) { +#endif + zlog_err("failed to allocate thread log buffer \"%s\": %s", + mmpath, strerror(errno)); + goto out_anon_unlink; + } + + zlog_tls->mmbuf = mmap(NULL, TLS_LOG_BUF_SIZE, PROT_READ | PROT_WRITE, + MAP_SHARED, mmfd, 0); + if (zlog_tls->mmbuf == MAP_FAILED) { + zlog_err("failed to mmap thread log buffer \"%s\": %s", + mmpath, strerror(errno)); + goto out_anon_unlink; + } + + close(mmfd); + zlog_tls_set(zlog_tls); + return; + +out_anon_unlink: + unlink(mmpath); + close(mmfd); +out_anon: + +#ifndef MAP_ANONYMOUS +#define MAP_ANONYMOUS MAP_ANON +#endif + zlog_tls->mmbuf = mmap(NULL, TLS_LOG_BUF_SIZE, PROT_READ | PROT_WRITE, + MAP_ANONYMOUS | MAP_PRIVATE, -1, 0); + + if (!zlog_tls->mmbuf) { + zlog_err("failed to anonymous-mmap thread log buffer: %s", + strerror(errno)); + XFREE(MTYPE_LOG_TLSBUF, zlog_tls); + zlog_tls_set(NULL); + return; + } + + zlog_tls_set(zlog_tls); +} + +void zlog_tls_buffer_fini(void) +{ + char mmpath[MAXPATHLEN]; + + zlog_tls_buffer_flush(); + + zlog_tls_free(zlog_tls_get()); + zlog_tls_set(NULL); + + snprintfrr(mmpath, sizeof(mmpath), "logbuf.%ld", zlog_gettid()); + if (unlinkat(zlog_tmpdirfd, mmpath, 0)) + zlog_err("unlink logbuf: %s (%d)", strerror(errno), errno); +} + +#else /* !CAN_DO_TLS */ +void zlog_tls_buffer_init(void) +{ +} + +void zlog_tls_buffer_fini(void) +{ +} +#endif + +static inline void zlog_tls_free(void *arg) +{ + struct zlog_tls *zlog_tls = arg; + + if (!zlog_tls) + return; + + munmap(zlog_tls->mmbuf, TLS_LOG_BUF_SIZE); + XFREE(MTYPE_LOG_TLSBUF, zlog_tls); +} + +void zlog_tls_buffer_flush(void) +{ + struct zlog_target *zt; + struct zlog_tls *zlog_tls = zlog_tls_get(); + + if (!zlog_tls) + return; + if (!zlog_tls->nmsgs) + return; + + rcu_read_lock(); + frr_each (zlog_targets, &zlog_targets, zt) { + if (!zt->logfn) + continue; + + zt->logfn(zt, zlog_tls->msgp, zlog_tls->nmsgs); + } + rcu_read_unlock(); + + zlog_tls->bufpos = 0; + zlog_tls->nmsgs = 0; +} + + +static void vzlog_notls(int prio, const char *fmt, va_list ap) +{ + struct zlog_target *zt; + struct zlog_msg stackmsg = { + .prio = prio & LOG_PRIMASK, + .fmt = fmt, + }, *msg = &stackmsg; + char stackbuf[512]; + + clock_gettime(CLOCK_REALTIME, &msg->ts); + va_copy(msg->args, ap); + msg->stackbuf = stackbuf; + msg->stackbufsz = sizeof(stackbuf); + + rcu_read_lock(); + frr_each (zlog_targets, &zlog_targets, zt) { + if (prio > zt->prio_min) + continue; + if (!zt->logfn) + continue; + + zt->logfn(zt, &msg, 1); + } + rcu_read_unlock(); + + va_end(msg->args); + if (msg->text && msg->text != stackbuf) + XFREE(MTYPE_LOG_MESSAGE, msg->text); +} + +static void vzlog_tls(struct zlog_tls *zlog_tls, int prio, + const char *fmt, va_list ap) +{ + struct zlog_target *zt; + struct zlog_msg *msg; + char *buf; + bool ignoremsg = true; + bool immediate = false; + + /* avoid further processing cost if no target wants this message */ + rcu_read_lock(); + frr_each (zlog_targets, &zlog_targets, zt) { + if (prio > zt->prio_min) + continue; + ignoremsg = false; + break; + } + rcu_read_unlock(); + + if (ignoremsg) + return; + + msg = &zlog_tls->msgs[zlog_tls->nmsgs]; + zlog_tls->nmsgs++; + if (zlog_tls->nmsgs == array_size(zlog_tls->msgs)) + immediate = true; + + memset(msg, 0, sizeof(*msg)); + clock_gettime(CLOCK_REALTIME, &msg->ts); + va_copy(msg->args, ap); + msg->stackbuf = buf = zlog_tls->mmbuf + zlog_tls->bufpos; + msg->stackbufsz = TLS_LOG_BUF_SIZE - zlog_tls->bufpos - 1; + msg->fmt = fmt; + msg->prio = prio & LOG_PRIMASK; + if (msg->prio < LOG_INFO) + immediate = true; + + if (!immediate) { + /* messages written later need to take the formatting cost + * immediately since we can't hold a reference on varargs + */ + zlog_msg_text(msg, NULL); + + if (msg->text != buf) + /* zlog_msg_text called malloc() on us :( */ + immediate = true; + else { + zlog_tls->bufpos += msg->textlen + 1; + /* write a second \0 to mark current end position + * (in case of crash this signals end of unwritten log + * messages in mmap'd logbuf file) + */ + zlog_tls->mmbuf[zlog_tls->bufpos] = '\0'; + + /* avoid malloc() for next message */ + if (TLS_LOG_BUF_SIZE - zlog_tls->bufpos < 256) + immediate = true; + } + } + + if (immediate) + zlog_tls_buffer_flush(); + + va_end(msg->args); + if (msg->text && msg->text != buf) + XFREE(MTYPE_LOG_MESSAGE, msg->text); +} + +void vzlog(int prio, const char *fmt, va_list ap) +{ + struct zlog_tls *zlog_tls = zlog_tls_get(); + + if (zlog_tls) + vzlog_tls(zlog_tls, prio, fmt, ap); + else + vzlog_notls(prio, fmt, ap); +} + +void zlog_sigsafe(const char *text, size_t len) +{ + struct zlog_target *zt; + const char *end = text + len, *nlpos; + + while (text < end) { + nlpos = memchr(text, '\n', end - text); + if (!nlpos) + nlpos = end; + + frr_each (zlog_targets, &zlog_targets, zt) { + if (LOG_CRIT > zt->prio_min) + continue; + if (!zt->logfn_sigsafe) + continue; + + zt->logfn_sigsafe(zt, text, nlpos - text); + } + + if (nlpos == end) + break; + text = nlpos + 1; + } +} + + +int zlog_msg_prio(struct zlog_msg *msg) +{ + return msg->prio; +} + +const char *zlog_msg_text(struct zlog_msg *msg, size_t *textlen) +{ + if (!msg->text) { + va_list args; + + va_copy(args, msg->args); + msg->text = vasnprintfrr(MTYPE_LOG_MESSAGE, msg->stackbuf, + msg->stackbufsz, msg->fmt, args); + msg->textlen = strlen(msg->text); + va_end(args); + } + if (textlen) + *textlen = msg->textlen; + return msg->text; +} + +#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 len1; + + if (!(flags & ZLOG_TS_FORMAT)) + return 0; + + if (!(msg->ts_flags & ZLOG_TS_FORMAT) || + ((msg->ts_flags ^ flags) & ZLOG_TS_UTC)) { + struct tm tm; + + if (flags & ZLOG_TS_UTC) + gmtime_r(&msg->ts.tv_sec, &tm); + else + localtime_r(&msg->ts.tv_sec, &tm); + + strftime(msg->ts_str, sizeof(msg->ts_str), + "%Y-%m-%dT%H:%M:%S", &tm); + + if (flags & ZLOG_TS_UTC) { + msg->ts_zonetail[0] = 'Z'; + msg->ts_zonetail[1] = '\0'; + } else + snprintfrr(msg->ts_zonetail, sizeof(msg->ts_zonetail), + "%+03d:%02d", + (int)(tm.tm_gmtoff / 3600), + (int)(labs(tm.tm_gmtoff) / 60) % 60); + + msg->ts_dot = msg->ts_str + strlen(msg->ts_str); + snprintfrr(msg->ts_dot, + msg->ts_str + sizeof(msg->ts_str) - msg->ts_dot, + ".%09lu", (unsigned long)msg->ts.tv_nsec); + + msg->ts_flags = ZLOG_TS_ISO8601 | (flags & ZLOG_TS_UTC); + } + + len1 = flags & ZLOG_TS_PREC; + len1 = (msg->ts_dot - msg->ts_str) + (len1 ? len1 + 1 : 0); + + if (len1 > strlen(msg->ts_str)) + len1 = strlen(msg->ts_str); + + if (flags & ZLOG_TS_LEGACY) { + if (len1 + 1 > outsz) + return 0; + + /* 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++ = '/'; + break; + case 'T': + *out++ = ' '; + break; + default: + *out++ = *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'; + return len1 + len2; + } +} + +/* setup functions */ + +struct zlog_target *zlog_target_clone(struct memtype *mt, + struct zlog_target *oldzt, size_t size) +{ + struct zlog_target *newzt; + + newzt = XCALLOC(mt, size); + if (oldzt) { + newzt->prio_min = oldzt->prio_min; + newzt->logfn = oldzt->logfn; + newzt->logfn_sigsafe = oldzt->logfn_sigsafe; + } + + return newzt; +} + +struct zlog_target *zlog_target_replace(struct zlog_target *oldzt, + struct zlog_target *newzt) +{ + if (newzt) + zlog_targets_add_tail(&zlog_targets, newzt); + if (oldzt) + zlog_targets_del(&zlog_targets, oldzt); + return oldzt; +} + + +/* common init */ + +#define TMPBASEDIR "/var/tmp/frr" + +static char zlog_tmpdir[MAXPATHLEN]; + +void zlog_aux_init(const char *prefix, int prio_min) +{ + if (prefix) + strlcpy(zlog_prefix, prefix, sizeof(zlog_prefix)); + + hook_call(zlog_aux_init, prefix, prio_min); +} + +void zlog_init(const char *progname, const char *protoname, + unsigned short instance, uid_t uid, gid_t gid) +{ + zlog_uid = uid; + zlog_gid = gid; + + if (instance) { + snprintfrr(zlog_tmpdir, sizeof(zlog_tmpdir), + "/var/tmp/frr/%s-%d.%ld", + progname, instance, (long)getpid()); + + zlog_prefixsz = snprintfrr(zlog_prefix, sizeof(zlog_prefix), + "%s[%d]: ", protoname, instance); + } else { + snprintfrr(zlog_tmpdir, sizeof(zlog_tmpdir), + "/var/tmp/frr/%s.%ld", + progname, (long)getpid()); + + zlog_prefixsz = snprintfrr(zlog_prefix, sizeof(zlog_prefix), + "%s: ", protoname); + } + + if (mkdir(TMPBASEDIR, 0700) != 0) { + if (errno != EEXIST) { + zlog_err("failed to mkdir \"%s\": %s", + TMPBASEDIR, strerror(errno)); + goto out_warn; + } + } + chown(TMPBASEDIR, zlog_uid, zlog_gid); + + if (mkdir(zlog_tmpdir, 0700) != 0) { + zlog_err("failed to mkdir \"%s\": %s", + zlog_tmpdir, strerror(errno)); + goto out_warn; + } + +#ifdef O_PATH + zlog_tmpdirfd = open(zlog_tmpdir, + O_PATH | O_RDONLY | O_CLOEXEC); +#else + zlog_tmpdirfd = open(zlog_tmpdir, + O_DIRECTORY | O_RDONLY | O_CLOEXEC); +#endif + if (zlog_tmpdirfd < 0) { + zlog_err("failed to open \"%s\": %s", + zlog_tmpdir, strerror(errno)); + goto out_warn; + } + +#ifdef AT_EMPTY_PATH + fchownat(zlog_tmpdirfd, "", zlog_uid, zlog_gid, AT_EMPTY_PATH); +#else + chown(zlog_tmpdir, zlog_uid, zlog_gid); +#endif + + hook_call(zlog_init, progname, protoname, instance, uid, gid); + return; + +out_warn: + zlog_err("crashlog and per-thread log buffering unavailable!"); + hook_call(zlog_init, progname, protoname, instance, uid, gid); +} + +void zlog_fini(void) +{ + hook_call(zlog_fini); + + if (zlog_tmpdirfd >= 0) { + close(zlog_tmpdirfd); + zlog_tmpdirfd = -1; + + if (rmdir(zlog_tmpdir)) + zlog_err("failed to rmdir \"%s\": %s", + zlog_tmpdir, strerror(errno)); + } +} diff --git a/lib/zlog.h b/lib/zlog.h new file mode 100644 index 000000000000..fd42ad50e459 --- /dev/null +++ b/lib/zlog.h @@ -0,0 +1,186 @@ +/* + * Copyright (c) 2015-19 David Lamparter, for NetDEF, Inc. + * + * Permission to use, copy, modify, and distribute this software for any + * purpose with or without fee is hereby granted, provided that the above + * copyright notice and this permission notice appear in all copies. + * + * THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES + * WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF + * MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR + * ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES + * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN + * ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF + * OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE. + */ + +#ifndef _FRR_ZLOG_H +#define _FRR_ZLOG_H + +#include +#include +#include +#include +#include +#include +#include + +#include "atomlist.h" +#include "frrcu.h" +#include "memory.h" +#include "hook.h" + +extern char zlog_prefix[]; +extern size_t zlog_prefixsz; +extern int zlog_tmpdirfd; + +/* These functions are set up to write to stdout/stderr without explicit + * initialization and/or before config load. There is no need to call e.g. + * fprintf(stderr, ...) just because it's "too early" at startup. Depending + * on context, it may still be the right thing to use fprintf though -- try to + * determine wether something is a log message or something else. + */ + +extern void vzlog(int prio, const char *fmt, va_list ap); + +__attribute__ ((format (printf, 2, 3))) +static inline void zlog(int prio, const char *fmt, ...) +{ + va_list ap; + + va_start(ap, fmt); + vzlog(prio, fmt, ap); + va_end(ap); +} + +#define zlog_err(...) zlog(LOG_ERR, __VA_ARGS__) +#define zlog_warn(...) zlog(LOG_WARNING, __VA_ARGS__) +#define zlog_info(...) zlog(LOG_INFO, __VA_ARGS__) +#define zlog_notice(...) zlog(LOG_NOTICE, __VA_ARGS__) +#define zlog_debug(...) zlog(LOG_DEBUG, __VA_ARGS__) + +extern void zlog_sigsafe(const char *text, size_t len); + +/* extra priority value to disable a target without deleting it */ +#define ZLOG_DISABLED (LOG_EMERG-1) + +/* zlog_msg encapsulates a particular logging call from somewhere in the code. + * The same struct is passed around to all zlog_targets. + * + * This is used to defer formatting the log message until it is actually + * requested by one of the targets. If none of the targets needs the message + * formatted, the formatting call is avoided entirely. + * + * This struct is opaque / private to the core zlog code. Logging targets + * should use zlog_msg_* functions to get text / timestamps / ... for a + * message. + */ + +struct zlog_msg; + +extern int zlog_msg_prio(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); + +/* timestamp formatting control flags */ + +/* sub-second digit count */ +#define ZLOG_TS_PREC 0xfU + +/* 8601: 0000-00-00T00:00:00Z (if used with ZLOG_TS_UTC) + * 0000-00-00T00:00:00+00:00 (otherwise) + * Legacy: 0000/00/00 00:00:00 (no TZ indicated!) + */ +#define ZLOG_TS_ISO8601 (1 << 8) +#define ZLOG_TS_LEGACY (1 << 9) + +/* 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, + 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. + * + * Since there's no atomic replace, the replacement action is an add followed + * by a delete. This means that during logging config changes, log messages + * may be duplicated in the log target that is being changed. The old entry + * being changed MUST also at the very least not crash or do other stupid + * things. + * + * This list and struct are NOT related to config. Logging config is kept + * separately, and results in creating appropriate zlog_target(s) to realize + * the config. Log targets may also be created from varying sources, e.g. + * command line options, or VTY commands ("log monitor"). + * + * struct zlog_target is intended to be embedded into a larger structure that + * contains additional field for the specific logging target, e.g. an fd or + * additional options. It MUST be the first field in that larger struct. + */ + +PREDECL_ATOMLIST(zlog_targets) +struct zlog_target { + struct zlog_targets_item head; + + int prio_min; + + void (*logfn)(struct zlog_target *zt, struct zlog_msg *msg[], + size_t nmsgs); + + /* for crash handlers, set to NULL if log target can't write crash logs + * without possibly deadlocking (AS-Safe) + * + * text is not \0 terminated & split up into lines (e.g. no \n) + */ + void (*logfn_sigsafe)(struct zlog_target *zt, const char *text, + size_t len); + + struct rcu_head rcu_head; +}; + +/* make a copy for RCUpdating. oldzt may be NULL to allocate a fresh one. */ +extern struct zlog_target *zlog_target_clone(struct memtype *mt, + struct zlog_target *oldzt, + size_t size); + +/* update the zlog_targets list; both oldzt and newzt may be NULL. You + * still need to zlog_target_free() the old target afterwards if it wasn't + * NULL. + * + * Returns oldzt so you can zlog_target_free(zlog_target_replace(old, new)); + * (Some log targets may need extra cleanup inbetween, but remember the old + * target MUST remain functional until the end of the current RCU cycle.) + */ +extern struct zlog_target *zlog_target_replace(struct zlog_target *oldzt, + struct zlog_target *newzt); + +/* Mostly for symmetry for zlog_target_clone(), just rcu_free() internally. */ +#define zlog_target_free(mt, zt) \ + rcu_free(mt, zt, rcu_head) + +extern void zlog_init(const char *progname, const char *protoname, + unsigned short instance, uid_t uid, gid_t gid); +DECLARE_HOOK(zlog_init, (const char *progname, const char *protoname, + unsigned short instance, uid_t uid, gid_t gid), + (progname, protoname, instance, uid, gid)) + +extern void zlog_fini(void); +DECLARE_KOOH(zlog_fini, (), ()) + +/* for tools & test programs, i.e. anything not a daemon. + * (no cleanup needed at exit) + */ +extern void zlog_aux_init(const char *prefix, int prio_min); +DECLARE_HOOK(zlog_aux_init, (const char *prefix, int prio_min), + (prefix, prio_min)) + +extern void zlog_startup_end(void); + +extern void zlog_tls_buffer_init(void); +extern void zlog_tls_buffer_flush(void); +extern void zlog_tls_buffer_fini(void); + +#endif /* _FRR_ZLOG_H */ diff --git a/lib/zlog_targets.c b/lib/zlog_targets.c new file mode 100644 index 000000000000..b23ab073b45e --- /dev/null +++ b/lib/zlog_targets.c @@ -0,0 +1,574 @@ +/* + * Copyright (c) 2015-19 David Lamparter, for NetDEF, Inc. + * + * Permission to use, copy, modify, and distribute this software for any + * purpose with or without fee is hereby granted, provided that the above + * copyright notice and this permission notice appear in all copies. + * + * THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES + * WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF + * MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR + * ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES + * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN + * ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF + * OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE. + */ + +#include "zebra.h" + +#include +#include + +#include "memory.h" +#include "frrcu.h" +#include "frr_pthread.h" +#include "printfrr.h" +#include "zlog.h" +#include "zlog_targets.h" + +/* these allocations are intentionally left active even when doing full exit + * cleanup, in order to keep the logging subsystem fully functional until the + * absolute end. + */ + +DECLARE_MGROUP(LOG) +DEFINE_MGROUP_ACTIVEATEXIT(LOG, "logging subsystem") + +DEFINE_MTYPE_STATIC(LOG, LOG_FD, "log file target") +DEFINE_MTYPE_STATIC(LOG, LOG_FD_NAME, "log file name") +DEFINE_MTYPE_STATIC(LOG, LOG_FD_ROTATE, "log file rotate helper") +DEFINE_MTYPE_STATIC(LOG, LOG_SYSL, "syslog target") + +struct zlt_fd { + struct zlog_target zt; + + atomic_uint_fast32_t fd; + + char ts_subsec; + bool record_priority; + + struct rcu_head_close head_close; +}; + +static const char * const prionames[] = { + [LOG_EMERG] = "emergencies: ", + [LOG_ALERT] = "alerts: ", + [LOG_CRIT] = "critical: ", + [LOG_ERR] = "errors: ", + [LOG_WARNING] = "warnings: ", + [LOG_NOTICE] = "notifications: ", + [LOG_INFO] = "informational: ", + [LOG_DEBUG] = "debugging: ", +}; + +void zlog_fd(struct zlog_target *zt, struct zlog_msg *msgs[], size_t nmsgs) +{ + struct zlt_fd *zte = container_of(zt, struct zlt_fd, zt); + int fd; + size_t i, textlen, iovpos = 0; + size_t niov = MIN(4 * nmsgs + 1, IOV_MAX); + struct iovec iov[niov]; + /* "\nYYYY-MM-DD HH:MM:SS.NNNNNNNNN+ZZ:ZZ " = 37 chars */ +#define TS_LEN 40 + char ts_buf[TS_LEN * nmsgs], *ts_pos = ts_buf; + + fd = atomic_load_explicit(&zte->fd, memory_order_relaxed); + + for (i = 0; i < nmsgs; i++) { + struct zlog_msg *msg = msgs[i]; + int prio = zlog_msg_prio(msg); + + if (prio > zt->prio_min) + continue; + + 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); + *ts_pos++ = ' '; + iov[iovpos].iov_len = ts_pos - (char *)iov[iovpos].iov_base; + + iovpos++; + + if (zte->record_priority) { + iov[iovpos].iov_base = (char *)prionames[prio]; + iov[iovpos].iov_len = strlen(iov[iovpos].iov_base); + + iovpos++; + } + + iov[iovpos].iov_base = zlog_prefix; + iov[iovpos].iov_len = zlog_prefixsz; + + iovpos++; + + iov[iovpos].iov_base = (char *)zlog_msg_text(msg, &textlen); + iov[iovpos].iov_len = textlen; + + iovpos++; + + if (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; + ts_pos = ts_buf; + } + } + + assert(iovpos == 0); +} + +static void zlog_fd_sigsafe(struct zlog_target *zt, const char *text, + size_t len) +{ + struct zlt_fd *zte = container_of(zt, struct zlt_fd, zt); + struct iovec iov[4]; + int fd; + + iov[0].iov_base = (char *)prionames[LOG_CRIT]; + iov[0].iov_len = zte->record_priority ? strlen(iov[0].iov_base) : 0; + + iov[1].iov_base = zlog_prefix; + iov[1].iov_len = zlog_prefixsz; + + iov[2].iov_base = (char *)text; + iov[2].iov_len = len; + + iov[3].iov_base = (char *)"\n"; + iov[3].iov_len = 1; + + fd = atomic_load_explicit(&zte->fd, memory_order_relaxed); + + writev(fd, iov, array_size(iov)); +} + +/* + * (re-)configuration + */ + +void zlog_file_init(struct zlog_cfg_file *zcf) +{ + memset(zcf, 0, sizeof(*zcf)); + zcf->prio_min = ZLOG_DISABLED; + zcf->fd = -1; + pthread_mutex_init(&zcf->cfg_mtx, NULL); +} + +static void zlog_file_target_free(struct zlt_fd *zlt) +{ + if (!zlt) + return; + + rcu_close(&zlt->head_close, zlt->fd); + rcu_free(MTYPE_LOG_FD, zlt, zt.rcu_head); +} + +void zlog_file_fini(struct zlog_cfg_file *zcf) +{ + if (zcf->active) { + struct zlt_fd *ztf; + struct zlog_target *zt; + + zt = zlog_target_replace(&zcf->active->zt, NULL); + ztf = container_of(zt, struct zlt_fd, zt); + zlog_file_target_free(ztf); + } + XFREE(MTYPE_LOG_FD_NAME, zcf->filename); + pthread_mutex_destroy(&zcf->cfg_mtx); +} + +static bool zlog_file_cycle(struct zlog_cfg_file *zcf) +{ + struct zlog_target *zt, *old; + struct zlt_fd *zlt = NULL; + int fd; + bool rv = true; + + do { + if (zcf->prio_min == ZLOG_DISABLED) + break; + + if (zcf->fd != -1) + fd = dup(zcf->fd); + else if (zcf->filename) + fd = open(zcf->filename, + O_WRONLY | O_APPEND | O_CREAT | O_CLOEXEC + | O_NOCTTY, + LOGFILE_MASK); + else + fd = -1; + + if (fd < 0) { + rv = false; + break; + } + + zt = zlog_target_clone(MTYPE_LOG_FD, &zcf->active->zt, + sizeof(*zlt)); + zlt = container_of(zt, struct zlt_fd, zt); + + zlt->fd = fd; + zlt->record_priority = zcf->record_priority; + zlt->ts_subsec = zcf->ts_subsec; + + zlt->zt.prio_min = zcf->prio_min; + zlt->zt.logfn = zcf->zlog_wrap ? zcf->zlog_wrap : zlog_fd; + zlt->zt.logfn_sigsafe = zlog_fd_sigsafe; + } while (0); + + old = zlog_target_replace(&zcf->active->zt, &zlt->zt); + zcf->active = zlt; + + zlog_file_target_free(container_of(old, struct zlt_fd, zt)); + + return rv; +} + +void zlog_file_set_other(struct zlog_cfg_file *zcf) +{ + frr_with_mutex(&zcf->cfg_mtx) { + zlog_file_cycle(zcf); + } +} + +bool zlog_file_set_filename(struct zlog_cfg_file *zcf, const char *filename) +{ + frr_with_mutex(&zcf->cfg_mtx) { + XFREE(MTYPE_LOG_FD_NAME, zcf->filename); + zcf->filename = XSTRDUP(MTYPE_LOG_FD_NAME, filename); + zcf->fd = -1; + + return zlog_file_cycle(zcf); + } + assert(0); +} + +bool zlog_file_set_fd(struct zlog_cfg_file *zcf, int fd) +{ + frr_with_mutex(&zcf->cfg_mtx) { + if (zcf->fd == fd) + return true; + + XFREE(MTYPE_LOG_FD_NAME, zcf->filename); + zcf->fd = fd; + + return zlog_file_cycle(zcf); + } + assert(0); +} + +struct rcu_close_rotate { + struct rcu_head_close head_close; + struct rcu_head head_self; +}; + +bool zlog_file_rotate(struct zlog_cfg_file *zcf) +{ + struct rcu_close_rotate *rcr; + int fd; + + frr_with_mutex(&zcf->cfg_mtx) { + if (!zcf->active || !zcf->filename) + return true; + + fd = open(zcf->filename, + O_WRONLY | O_APPEND | O_CREAT | O_CLOEXEC | O_NOCTTY, + LOGFILE_MASK); + if (fd < 0) + return false; + + fd = atomic_exchange_explicit(&zcf->active->fd, + (uint_fast32_t)fd, + memory_order_relaxed); + } + + rcr = XCALLOC(MTYPE_LOG_FD_ROTATE, sizeof(*rcr)); + rcu_close(&rcr->head_close, fd); + rcu_free(MTYPE_LOG_FD_ROTATE, rcr, head_self); + + return true; +} + +/* fixed crash logging */ + +static struct zlt_fd zlog_crashlog; + +static void zlog_crashlog_sigsafe(struct zlog_target *zt, const char *text, + size_t len) +{ + static int crashlog_fd = -1; + + if (crashlog_fd == -1) { +#ifdef HAVE_OPENAT + crashlog_fd = openat(zlog_tmpdirfd, "crashlog", + O_WRONLY | O_APPEND | O_CREAT, + LOGFILE_MASK); +#endif + if (crashlog_fd < 0) + crashlog_fd = -2; + } + + if (crashlog_fd == -2) + return; + + zlog_crashlog.fd = crashlog_fd; + zlog_fd_sigsafe(&zlog_crashlog.zt, text, len); +} + +/* this is used for assert failures (they don't need AS-Safe logging) */ +static void zlog_crashlog_plain(struct zlog_target *zt, struct zlog_msg *msgs[], + size_t nmsgs) +{ + size_t i, len; + const char *text; + + for (i = 0; i < nmsgs; i++) { + if (zlog_msg_prio(msgs[i]) > zt->prio_min) + continue; + + text = zlog_msg_text(msgs[i], &len); + zlog_crashlog_sigsafe(zt, text, len); + } +} + +static void zlog_crashlog_init(void) +{ + zlog_crashlog.zt.prio_min = LOG_CRIT; + zlog_crashlog.zt.logfn = zlog_crashlog_plain; + zlog_crashlog.zt.logfn_sigsafe = zlog_crashlog_sigsafe; + zlog_crashlog.fd = -1; + + zlog_target_replace(NULL, &zlog_crashlog.zt); +} + +/* fixed logging for test/auxiliary programs */ + +static struct zlt_fd zlog_aux_stdout; +static bool zlog_is_aux; + +static int zlt_aux_init(const char *prefix, int prio_min) +{ + zlog_is_aux = true; + + zlog_aux_stdout.zt.prio_min = prio_min; + zlog_aux_stdout.zt.logfn = zlog_fd; + zlog_aux_stdout.zt.logfn_sigsafe = zlog_fd_sigsafe; + zlog_aux_stdout.fd = STDOUT_FILENO; + + zlog_target_replace(NULL, &zlog_aux_stdout.zt); + zlog_startup_end(); + return 0; +} + +static int zlt_init(const char *progname, const char *protoname, + unsigned short instance, uid_t uid, gid_t gid) +{ + openlog(progname, LOG_CONS | LOG_NDELAY | LOG_PID, LOG_DAEMON); + return 0; +} + +static int zlt_fini(void) +{ + closelog(); + return 0; +} + +/* fixed startup logging to stderr */ + +static struct zlt_fd zlog_startup_stderr; + +__attribute__((_CONSTRUCTOR(450))) static void zlog_startup_init(void) +{ + zlog_startup_stderr.zt.prio_min = LOG_WARNING; + zlog_startup_stderr.zt.logfn = zlog_fd; + zlog_startup_stderr.zt.logfn_sigsafe = zlog_fd_sigsafe; + zlog_startup_stderr.fd = STDERR_FILENO; + + zlog_target_replace(NULL, &zlog_startup_stderr.zt); + + hook_register(zlog_aux_init, zlt_aux_init); + hook_register(zlog_init, zlt_init); + hook_register(zlog_fini, zlt_fini); +} + +void zlog_startup_end(void) +{ + static bool startup_ended = false; + + if (startup_ended) + return; + startup_ended = true; + + zlog_target_replace(&zlog_startup_stderr.zt, NULL); + + if (zlog_is_aux) + return; + + /* until here, crashlogs go to stderr */ + zlog_crashlog_init(); +} + +/* syslog */ + +struct zlt_syslog { + struct zlog_target zt; + + int syslog_facility; +}; + +static void zlog_syslog(struct zlog_target *zt, struct zlog_msg *msgs[], + size_t nmsgs) +{ + size_t i; + struct zlt_syslog *zte = container_of(zt, struct zlt_syslog, zt); + + 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)); + } +} + +#ifndef _PATH_LOG +#define _PATH_LOG "/dev/log" +#endif + +static void zlog_syslog_sigsafe(struct zlog_target *zt, const char *text, + size_t len) +{ + static int syslog_fd = -1; + + char hdr[192]; + size_t hdrlen; + struct iovec iov[2]; + + if (syslog_fd == -1) { + syslog_fd = socket(AF_UNIX, SOCK_DGRAM, 0); + if (syslog_fd >= 0) { + struct sockaddr_un sa; + socklen_t salen = sizeof(sa); + + sa.sun_family = AF_UNIX; + strlcpy(sa.sun_path, _PATH_LOG, sizeof(sa.sun_path)); +#ifdef HAVE_STRUCT_SOCKADDR_UN_SUN_LEN + salen = sa.sun_len = SUN_LEN(&sa); +#endif + if (connect(syslog_fd, (struct sockaddr *)&sa, salen)) { + close(syslog_fd); + syslog_fd = -1; + } + } + + /* /dev/log could be a fifo instead of a socket */ + if (syslog_fd == -1) { + syslog_fd = open(_PATH_LOG, O_WRONLY | O_NOCTTY); + if (syslog_fd < 0) + /* give up ... */ + syslog_fd = -2; + } + } + + if (syslog_fd == -2) + return; + + /* note zlog_prefix includes trailing ": ", need to cut off 2 chars */ + hdrlen = snprintfrr(hdr, sizeof(hdr), "<%d>%.*s[%ld]: ", LOG_CRIT, + zlog_prefixsz > 2 ? (int)(zlog_prefixsz - 2) : 0, + zlog_prefix, (long)getpid()); + + iov[0].iov_base = hdr; + iov[0].iov_len = hdrlen; + + iov[1].iov_base = (char *)text; + iov[1].iov_len = len; + + writev(syslog_fd, iov, array_size(iov)); +} + + +static pthread_mutex_t syslog_cfg_mutex = PTHREAD_MUTEX_INITIALIZER; +static struct zlt_syslog *zlt_syslog; +static int syslog_facility = LOG_DAEMON; +static int syslog_prio_min = ZLOG_DISABLED; + +void zlog_syslog_set_facility(int facility) +{ + struct zlog_target *newztc; + struct zlt_syslog *newzt; + + frr_with_mutex(&syslog_cfg_mutex) { + if (facility == syslog_facility) + return; + syslog_facility = facility; + + if (syslog_prio_min == ZLOG_DISABLED) + return; + + newztc = zlog_target_clone(MTYPE_LOG_SYSL, &zlt_syslog->zt, + sizeof(*newzt)); + newzt = container_of(newztc, struct zlt_syslog, zt); + newzt->syslog_facility = syslog_facility; + + zlog_target_free(MTYPE_LOG_SYSL, + zlog_target_replace(&zlt_syslog->zt, + &newzt->zt)); + + zlt_syslog = newzt; + } +} + +int zlog_syslog_get_facility(void) +{ + frr_with_mutex(&syslog_cfg_mutex) { + return syslog_facility; + } + assert(0); +} + +void zlog_syslog_set_prio_min(int prio_min) +{ + struct zlog_target *newztc; + struct zlt_syslog *newzt = NULL; + + frr_with_mutex(&syslog_cfg_mutex) { + if (prio_min == syslog_prio_min) + return; + syslog_prio_min = prio_min; + + if (syslog_prio_min != ZLOG_DISABLED) { + newztc = zlog_target_clone(MTYPE_LOG_SYSL, + &zlt_syslog->zt, + sizeof(*newzt)); + newzt = container_of(newztc, struct zlt_syslog, zt); + newzt->zt.prio_min = prio_min; + newzt->zt.logfn = zlog_syslog; + newzt->zt.logfn_sigsafe = zlog_syslog_sigsafe; + newzt->syslog_facility = syslog_facility; + } + + zlog_target_free(MTYPE_LOG_SYSL, + zlog_target_replace(&zlt_syslog->zt, + &newzt->zt)); + + zlt_syslog = newzt; + } +} + +int zlog_syslog_get_prio_min(void) +{ + frr_with_mutex(&syslog_cfg_mutex) { + return syslog_prio_min; + } + assert(0); +} diff --git a/lib/zlog_targets.h b/lib/zlog_targets.h new file mode 100644 index 000000000000..f95d349a57db --- /dev/null +++ b/lib/zlog_targets.h @@ -0,0 +1,66 @@ +/* + * Copyright (c) 2015-19 David Lamparter, for NetDEF, Inc. + * + * Permission to use, copy, modify, and distribute this software for any + * purpose with or without fee is hereby granted, provided that the above + * copyright notice and this permission notice appear in all copies. + * + * THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES + * WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF + * MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR + * ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES + * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN + * ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF + * OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE. + */ + +#ifndef _FRR_ZLOG_TARGETS_H +#define _FRR_ZLOG_TARGETS_H + +#include + +#include "zlog.h" + +/* multiple file log targets can be active */ + +struct zlt_fd; + +struct zlog_cfg_file { + struct zlt_fd *active; + + pthread_mutex_t cfg_mtx; + + /* call zlog_file_set_other() to apply these */ + int prio_min; + char ts_subsec; + bool record_priority; + + /* call zlog_file_set_filename/fd() to change this */ + char *filename; + int fd; + + void (*zlog_wrap)(struct zlog_target *zt, struct zlog_msg *msgs[], + size_t nmsgs); +}; + +extern void zlog_file_init(struct zlog_cfg_file *zcf); +extern void zlog_file_fini(struct zlog_cfg_file *zcf); + +extern void zlog_file_set_other(struct zlog_cfg_file *zcf); +extern bool zlog_file_set_filename(struct zlog_cfg_file *zcf, const char *name); +extern bool zlog_file_set_fd(struct zlog_cfg_file *zcf, int fd); +extern bool zlog_file_rotate(struct zlog_cfg_file *zcf); + +extern void zlog_fd(struct zlog_target *zt, struct zlog_msg *msgs[], + size_t nmsgs); + +/* syslog is always limited to one target */ + +extern void zlog_syslog_set_facility(int facility); +extern int zlog_syslog_get_facility(void); + +/* use ZLOG_DISABLED to disable */ +extern void zlog_syslog_set_prio_min(int prio_min); +extern int zlog_syslog_get_prio_min(void); + +#endif /* _FRR_ZLOG_TARGETS_H */ diff --git a/pimd/pim_mlag.c b/pimd/pim_mlag.c index 304e6ac6bc9a..47735475f3f5 100644 --- a/pimd/pim_mlag.c +++ b/pimd/pim_mlag.c @@ -767,7 +767,7 @@ static void pim_mlag_process_mroute_del(struct mlag_mroute_del msg) int pim_zebra_mlag_handle_msg(struct stream *s, int len) { struct mlag_msg mlag_msg; - char buf[ZLOG_FILTER_LENGTH_MAX]; + char buf[80]; int rc = 0; size_t length; diff --git a/sharpd/sharp_logpump.c b/sharpd/sharp_logpump.c index d07e2d273f26..322d802b8aa9 100644 --- a/sharpd/sharp_logpump.c +++ b/sharpd/sharp_logpump.c @@ -77,6 +77,8 @@ static void *logpump_run(void *arg) period = 1000000000L / lp_frequency; + zlog_tls_buffer_init(); + clock_gettime(CLOCK_MONOTONIC, &start); next = start; do { @@ -109,6 +111,8 @@ static void *logpump_run(void *arg) #endif } while (delta < lp_duration); + zlog_tls_buffer_fini(); + #ifdef RUSAGE_THREAD getrusage(RUSAGE_THREAD, &lp_rusage); #else diff --git a/tests/bgpd/test_peer_attr.c b/tests/bgpd/test_peer_attr.c index 490b0ee73b82..f6a892df42bb 100644 --- a/tests/bgpd/test_peer_attr.c +++ b/tests/bgpd/test_peer_attr.c @@ -1381,8 +1381,7 @@ static void test_peer_attr(struct test *test, struct test_peer_attr *pa) static void bgp_startup(void) { cmd_init(1); - openzlog("testbgpd", "NONE", 0, LOG_CONS | LOG_NDELAY | LOG_PID, - LOG_DAEMON); + zlog_aux_init("NONE: ", LOG_DEBUG); zprivs_preinit(&bgpd_privs); zprivs_init(&bgpd_privs); @@ -1438,7 +1437,6 @@ static void bgp_shutdown(void) zprivs_terminate(&bgpd_privs); thread_master_free(master); master = NULL; - closezlog(); } int main(void) diff --git a/tests/lib/cli/common_cli.c b/tests/lib/cli/common_cli.c index bd81656ca971..3cade4a2c907 100644 --- a/tests/lib/cli/common_cli.c +++ b/tests/lib/cli/common_cli.c @@ -53,7 +53,6 @@ static void vty_do_exit(int isexit) nb_terminate(); yang_terminate(); thread_master_free(master); - closezlog(); log_memstats(stderr, "testcli"); if (!isexit) @@ -71,11 +70,7 @@ int main(int argc, char **argv) /* master init. */ master = thread_master_create(NULL); - openzlog("common-cli", "NONE", 0, LOG_CONS | LOG_NDELAY | LOG_PID, - LOG_DAEMON); - zlog_set_level(ZLOG_DEST_SYSLOG, ZLOG_DISABLED); - zlog_set_level(ZLOG_DEST_STDOUT, ZLOG_DISABLED); - zlog_set_level(ZLOG_DEST_MONITOR, LOG_DEBUG); + zlog_aux_init("NONE: ", ZLOG_DISABLED); /* Library inits. */ cmd_init(1); diff --git a/tests/lib/northbound/test_oper_data.c b/tests/lib/northbound/test_oper_data.c index 786fce33f95e..e16412986e49 100644 --- a/tests/lib/northbound/test_oper_data.c +++ b/tests/lib/northbound/test_oper_data.c @@ -374,7 +374,6 @@ static void vty_do_exit(int isexit) nb_terminate(); yang_terminate(); thread_master_free(master); - closezlog(); log_memstats(stderr, "test-nb-oper-data"); if (!isexit) @@ -402,11 +401,7 @@ int main(int argc, char **argv) /* master init. */ master = thread_master_create(NULL); - openzlog("test-nb-oper-data", "NONE", 0, - LOG_CONS | LOG_NDELAY | LOG_PID, LOG_DAEMON); - zlog_set_level(ZLOG_DEST_SYSLOG, ZLOG_DISABLED); - zlog_set_level(ZLOG_DEST_STDOUT, ZLOG_DISABLED); - zlog_set_level(ZLOG_DEST_MONITOR, LOG_DEBUG); + zlog_aux_init("NONE: ", ZLOG_DISABLED); /* Library inits. */ cmd_init(1); diff --git a/tests/lib/test_segv.c b/tests/lib/test_segv.c index 43ca0837d5f3..8133637adcd6 100644 --- a/tests/lib/test_segv.c +++ b/tests/lib/test_segv.c @@ -73,11 +73,7 @@ int main(void) master = thread_master_create(NULL); signal_init(master, array_size(sigs), sigs); - openzlog("testsegv", "NONE", 0, LOG_CONS | LOG_NDELAY | LOG_PID, - LOG_DAEMON); - zlog_set_level(ZLOG_DEST_SYSLOG, ZLOG_DISABLED); - zlog_set_level(ZLOG_DEST_STDOUT, LOG_DEBUG); - zlog_set_level(ZLOG_DEST_MONITOR, ZLOG_DISABLED); + zlog_aux_init("NONE: ", LOG_DEBUG); thread_execute(master, threadfunc, 0, 0); diff --git a/tests/lib/test_sig.c b/tests/lib/test_sig.c index cf63a3d047f1..2aceafb8f0f9 100644 --- a/tests/lib/test_sig.c +++ b/tests/lib/test_sig.c @@ -57,11 +57,7 @@ int main(void) master = thread_master_create(NULL); signal_init(master, array_size(sigs), sigs); - openzlog("testsig", "NONE", 0, LOG_CONS | LOG_NDELAY | LOG_PID, - LOG_DAEMON); - zlog_set_level(ZLOG_DEST_SYSLOG, ZLOG_DISABLED); - zlog_set_level(ZLOG_DEST_STDOUT, LOG_DEBUG); - zlog_set_level(ZLOG_DEST_MONITOR, ZLOG_DISABLED); + zlog_aux_init("NONE: ", LOG_DEBUG); while (thread_fetch(master, &t)) thread_call(&t); diff --git a/tests/lib/test_zlog.c b/tests/lib/test_zlog.c index 07885d984737..3042cc6cc1c8 100644 --- a/tests/lib/test_zlog.c +++ b/tests/lib/test_zlog.c @@ -52,9 +52,7 @@ bool (*tests[])(void) = { int main(int argc, char **argv) { - openzlog("testzlog", "NONE", 0, LOG_CONS | LOG_NDELAY | LOG_PID, - LOG_ERR); - zlog_set_file("test_zlog.log", LOG_DEBUG); + zlog_aux_init("NONE: ", ZLOG_DISABLED); for (unsigned int i = 0; i < array_size(tests); i++) if (!tests[i]()) diff --git a/vtysh/vtysh.c b/vtysh/vtysh.c index a5fa686eb56d..6f3c09fa7fcb 100644 --- a/vtysh/vtysh.c +++ b/vtysh/vtysh.c @@ -2710,103 +2710,6 @@ DEFUNSH(VTYSH_ALL, no_vtysh_config_enable_password, return CMD_SUCCESS; } -/* Log filter */ -DEFUN (vtysh_log_filter, - vtysh_log_filter_cmd, - "[no] log-filter WORD ["DAEMONS_LIST"]", - NO_STR - FILTER_LOG_STR - "String to filter by\n" - DAEMONS_STR) -{ - char *filter = NULL; - char *daemon = NULL; - int found = 0; - int idx = 0; - int daemon_idx = 2; - int total_len = 0; - int len = 0; - - char line[ZLOG_FILTER_LENGTH_MAX + 20]; - - found = argv_find(argv, argc, "no", &idx); - if (found == 1) { - len = snprintf(line, sizeof(line), "no log-filter"); - daemon_idx += 1; - } else - len = snprintf(line, sizeof(line), "log-filter"); - - total_len += len; - - idx = 1; - found = argv_find(argv, argc, "WORD", &idx); - if (found != 1) { - vty_out(vty, "%% No filter string given\n"); - return CMD_WARNING; - } - filter = argv[idx]->arg; - - if (strnlen(filter, ZLOG_FILTER_LENGTH_MAX + 1) - > ZLOG_FILTER_LENGTH_MAX) { - vty_out(vty, "%% Filter is too long\n"); - return CMD_WARNING; - } - - len = snprintf(line + total_len, sizeof(line) - total_len, " %s\n", - filter); - - if ((len < 0) || (size_t)(total_len + len) > sizeof(line)) { - vty_out(vty, "%% Error buffering filter to daemons\n"); - return CMD_ERR_INCOMPLETE; - } - - if (argc >= (daemon_idx + 1)) - daemon = argv[daemon_idx]->text; - - if (daemon != NULL) { - vty_out(vty, "Applying log filter change to %s:\n", daemon); - return vtysh_client_execute_name(daemon, line); - } else - return show_per_daemon(line, - "Applying log filter change to %s:\n"); -} - -/* Clear log filters */ -DEFUN (vtysh_log_filter_clear, - vtysh_log_filter_clear_cmd, - "log-filter clear ["DAEMONS_LIST"]", - FILTER_LOG_STR - CLEAR_STR - DAEMONS_STR) -{ - char *daemon = NULL; - int daemon_idx = 2; - - char line[] = "clear log-filter\n"; - - if (argc >= (daemon_idx + 1)) - daemon = argv[daemon_idx]->text; - - if (daemon != NULL) { - vty_out(vty, "Clearing all filters applied to %s:\n", daemon); - return vtysh_client_execute_name(daemon, line); - } else - return show_per_daemon(line, - "Clearing all filters applied to %s:\n"); -} - -/* Show log filter */ -DEFUN (vtysh_show_log_filter, - vtysh_show_log_filter_cmd, - "show log-filter", - SHOW_STR - FILTER_LOG_STR) -{ - char line[] = "do show log-filter\n"; - - return show_per_daemon(line, "Log filters applied to %s:\n"); -} - DEFUN (vtysh_write_terminal, vtysh_write_terminal_cmd, "write terminal ["DAEMONS_LIST"]", @@ -4106,9 +4009,6 @@ void vtysh_init_vty(void) /* Logging */ install_element(VIEW_NODE, &vtysh_show_logging_cmd); - install_element(VIEW_NODE, &vtysh_show_log_filter_cmd); - install_element(CONFIG_NODE, &vtysh_log_filter_cmd); - install_element(CONFIG_NODE, &vtysh_log_filter_clear_cmd); install_element(CONFIG_NODE, &vtysh_log_stdout_cmd); install_element(CONFIG_NODE, &vtysh_log_stdout_level_cmd); install_element(CONFIG_NODE, &no_vtysh_log_stdout_cmd); diff --git a/watchfrr/watchfrr.c b/watchfrr/watchfrr.c index 05e6651229a7..d6d8f77243ba 100644 --- a/watchfrr/watchfrr.c +++ b/watchfrr/watchfrr.c @@ -27,6 +27,7 @@ #include "command.h" #include "libfrr.h" #include "lib_errors.h" +#include "zlog_targets.h" #include #include @@ -1369,11 +1370,10 @@ int main(int argc, char **argv) frr_config_fork(); - zlog_set_level(ZLOG_DEST_MONITOR, ZLOG_DISABLED); if (watchfrr_di.daemon_mode) - zlog_set_level(ZLOG_DEST_SYSLOG, MIN(gs.loglevel, LOG_DEBUG)); + zlog_syslog_set_prio_min(MIN(gs.loglevel, LOG_DEBUG)); else - zlog_set_level(ZLOG_DEST_STDOUT, MIN(gs.loglevel, LOG_DEBUG)); + zlog_aux_init(NULL, MIN(gs.loglevel, LOG_DEBUG)); frr_run(master); diff --git a/watchfrr/watchfrr_vty.c b/watchfrr/watchfrr_vty.c index c06cb89382e6..eda4f5d516bf 100644 --- a/watchfrr/watchfrr_vty.c +++ b/watchfrr/watchfrr_vty.c @@ -23,6 +23,7 @@ #include "memory.h" #include "log.h" +#include "log_vty.h" #include "vty.h" #include "command.h" @@ -134,6 +135,19 @@ DEFUN (show_watchfrr, return CMD_SUCCESS; } +/* we don't have the other logging commands since watchfrr only accepts + * log config through command line options + */ +DEFUN_NOSH (show_logging, + show_logging_cmd, + "show logging", + SHOW_STR + "Show current logging configuration\n") +{ + log_show_syslog(vty); + return CMD_SUCCESS; +} + #ifndef VTYSH_EXTRACT_PL #include "watchfrr/watchfrr_vty_clippy.c" #endif @@ -190,4 +204,5 @@ void watchfrr_vty_init(void) install_element(CONFIG_NODE, &show_debugging_watchfrr_cmd); install_element(VIEW_NODE, &show_watchfrr_cmd); + install_element(VIEW_NODE, &show_logging_cmd); }