]> git.proxmox.com Git - mirror_frr.git/commitdiff
vtysh: show live log messages
authorDavid Lamparter <equinox@diac24.net>
Fri, 6 Dec 2019 12:48:06 +0000 (13:48 +0100)
committerDavid Lamparter <equinox@opensourcerouting.org>
Mon, 28 Feb 2022 12:33:27 +0000 (13:33 +0100)
https://www.youtube.com/watch?v=8psFQCEgA18

Signed-off-by: David Lamparter <equinox@opensourcerouting.org>
configure.ac
doc/user/vtysh.rst
vtysh/subdir.am
vtysh/vtysh.c
vtysh/vtysh.h

index ddd883e54f45d4e70d9639265c6f3d6440dd9378..170d16ca6a823f8dd37e69b3d736d99392019d46 100644 (file)
@@ -1371,6 +1371,8 @@ case "${enable_vtysh}" in
       AC_MSG_ERROR([libreadline (needed for vtysh) not found and/or missing dependencies])
     ], [$LIBREADLINE])
   ], [])
+  LIBS="$LIBS -lreadline"
+  AC_CHECK_FUNCS([rl_clear_visible_line])
   LIBS="$prev_libs"
 
   AC_CHECK_HEADER([readline/history.h])
index ec674e377c99f0a301ba7ce03c22f81a17ed2e08..97b3863ef574f5be88ad4a4b0c74bfd307b6d6cd 100644 (file)
@@ -29,6 +29,30 @@ administrator with an external editor.
    vtysh.
 
 
+Live logs
+=========
+
+.. clicmd:: terminal monitor [DAEMON]
+
+   Receive and display log messages.
+
+   It is not currently possible to change the minimum message priority (fixed
+   to debug) or output formatting.  These will likely be made configurable in
+   the future.
+
+   Log messages are received asynchronously and may be printed both during
+   command execution as well as while on the prompt.  They are printed to
+   stderr, unlike regular CLI output which is printed to stdout.  The intent is
+   that stdin/stdout might be driven by some script while log messages are
+   visible on stderr.  If stdout and stderr are the same file, the prompt and
+   pending input will be cleared and reprinted appropriately.
+
+   .. note::
+
+      If ``vtysh`` cannot keep up, some log messages may be lost.  The daemons
+      do **not** wait for, get blocked by, or buffer messages for ``vtysh``.
+
+
 Pager usage
 ===========
 
index 5f7d85494844920858c71470bbaa17016a76e999..624361645e66ae80e078ccb88ceaa38f6894fab9 100644 (file)
@@ -7,6 +7,10 @@ bin_PROGRAMS += vtysh/vtysh
 man1 += $(MANBUILD)/vtysh.1
 endif
 
+clippy_scan += \
+       vtysh/vtysh.c \
+       # end
+
 vtysh_vtysh_SOURCES = \
        vtysh/vtysh_main.c \
        vtysh/vtysh.c \
index 2b9b2b4cca2a28a88ec87c4be1cc6c18346a84ca..e209cea6907ac43bc39139b8dd4950f8c4aba440 100644 (file)
@@ -40,6 +40,7 @@
 #include "linklist.h"
 #include "command.h"
 #include "memory.h"
+#include "network.h"
 #include "filter.h"
 #include "vtysh/vtysh.h"
 #include "vtysh/vtysh_daemons.h"
@@ -69,8 +70,14 @@ struct vtysh_client {
        int flag;
        char path[MAXPATHLEN];
        struct vtysh_client *next;
+
+       struct thread *log_reader;
+       int log_fd;
 };
 
+static bool stderr_tty;
+static bool stderr_stdout_same;
+
 /* Some utility functions for working on vtysh-specific vty tasks */
 
 static FILE *vty_open_pager(struct vty *vty)
@@ -126,27 +133,27 @@ static void vtysh_pager_envdef(bool fallback)
 /* --- */
 
 struct vtysh_client vtysh_client[] = {
-       {.fd = -1, .name = "zebra", .flag = VTYSH_ZEBRA, .next = NULL},
-       {.fd = -1, .name = "ripd", .flag = VTYSH_RIPD, .next = NULL},
-       {.fd = -1, .name = "ripngd", .flag = VTYSH_RIPNGD, .next = NULL},
-       {.fd = -1, .name = "ospfd", .flag = VTYSH_OSPFD, .next = NULL},
-       {.fd = -1, .name = "ospf6d", .flag = VTYSH_OSPF6D, .next = NULL},
-       {.fd = -1, .name = "ldpd", .flag = VTYSH_LDPD, .next = NULL},
-       {.fd = -1, .name = "bgpd", .flag = VTYSH_BGPD, .next = NULL},
-       {.fd = -1, .name = "isisd", .flag = VTYSH_ISISD, .next = NULL},
-       {.fd = -1, .name = "pimd", .flag = VTYSH_PIMD, .next = NULL},
-       {.fd = -1, .name = "nhrpd", .flag = VTYSH_NHRPD, .next = NULL},
-       {.fd = -1, .name = "eigrpd", .flag = VTYSH_EIGRPD, .next = NULL},
-       {.fd = -1, .name = "babeld", .flag = VTYSH_BABELD, .next = NULL},
-       {.fd = -1, .name = "sharpd", .flag = VTYSH_SHARPD, .next = NULL},
-       {.fd = -1, .name = "fabricd", .flag = VTYSH_FABRICD, .next = NULL},
-       {.fd = -1, .name = "watchfrr", .flag = VTYSH_WATCHFRR, .next = NULL},
-       {.fd = -1, .name = "pbrd", .flag = VTYSH_PBRD, .next = NULL},
-       {.fd = -1, .name = "staticd", .flag = VTYSH_STATICD, .next = NULL},
-       {.fd = -1, .name = "bfdd", .flag = VTYSH_BFDD, .next = NULL},
-       {.fd = -1, .name = "vrrpd", .flag = VTYSH_VRRPD, .next = NULL},
-       {.fd = -1, .name = "pathd", .flag = VTYSH_PATHD, .next = NULL},
-       {.fd = -1, .name = "pim6d", .flag = VTYSH_PIM6D, .next = NULL},
+       {.name = "zebra", .flag = VTYSH_ZEBRA},
+       {.name = "ripd", .flag = VTYSH_RIPD},
+       {.name = "ripngd", .flag = VTYSH_RIPNGD},
+       {.name = "ospfd", .flag = VTYSH_OSPFD},
+       {.name = "ospf6d", .flag = VTYSH_OSPF6D},
+       {.name = "ldpd", .flag = VTYSH_LDPD},
+       {.name = "bgpd", .flag = VTYSH_BGPD},
+       {.name = "isisd", .flag = VTYSH_ISISD},
+       {.name = "pimd", .flag = VTYSH_PIMD},
+       {.name = "nhrpd", .flag = VTYSH_NHRPD},
+       {.name = "eigrpd", .flag = VTYSH_EIGRPD},
+       {.name = "babeld", .flag = VTYSH_BABELD},
+       {.name = "sharpd", .flag = VTYSH_SHARPD},
+       {.name = "fabricd", .flag = VTYSH_FABRICD},
+       {.name = "watchfrr", .flag = VTYSH_WATCHFRR},
+       {.name = "pbrd", .flag = VTYSH_PBRD},
+       {.name = "staticd", .flag = VTYSH_STATICD},
+       {.name = "bfdd", .flag = VTYSH_BFDD},
+       {.name = "vrrpd", .flag = VTYSH_VRRPD},
+       {.name = "pathd", .flag = VTYSH_PATHD},
+       {.name = "pim6d", .flag = VTYSH_PIM6D},
 };
 
 /* Searches for client by name, returns index */
@@ -182,8 +189,8 @@ static void vclient_close(struct vtysh_client *vclient)
        }
 }
 
-static ssize_t vtysh_client_receive(struct vtysh_client *vclient,
-                                   char *buf, size_t bufsz, int *pass_fd)
+static ssize_t vtysh_client_receive(struct vtysh_client *vclient, char *buf,
+                                   size_t bufsz, int *pass_fd)
 {
        struct iovec iov[1] = {
                {
@@ -289,9 +296,8 @@ static int vtysh_client_run(struct vtysh_client *vclient, const char *line,
        do {
                ssize_t nread;
 
-               nread = vtysh_client_receive(vclient, bufvalid,
-                                            buf + bufsz - bufvalid - 1,
-                                            pass_fd);
+               nread = vtysh_client_receive(
+                       vclient, bufvalid, buf + bufsz - bufvalid - 1, pass_fd);
 
                if (nread < 0 && (errno == EINTR || errno == EAGAIN))
                        continue;
@@ -1630,6 +1636,8 @@ static int vtysh_end(void)
        return CMD_SUCCESS;
 }
 
+#include "vtysh/vtysh_clippy.c"
+
 DEFUNSH(VTYSH_REALLYALL, vtysh_end_all, vtysh_end_all_cmd, "end",
        "End current mode and change to enable mode\n")
 {
@@ -3512,6 +3520,281 @@ DEFUN (vtysh_show_daemons,
        return CMD_SUCCESS;
 }
 
+struct visual_prio {
+       /* 4 characters for nice alignment */
+       const char *label;
+
+       int c256_background;
+       int c256_formatarg;
+};
+
+/* clang-format off */
+struct visual_prio visual_prios[] = {
+       [LOG_EMERG] = {
+               .label = "\e[31;1mEMRG",
+               .c256_background = 53,
+               .c256_formatarg = 225,
+       },
+       [LOG_ALERT] = {
+               .label = "\e[31;1mALRT",
+               .c256_background = 53,
+               .c256_formatarg = 225,
+       },
+       [LOG_CRIT] = {
+               .label = "\e[31;1mCRIT",
+               .c256_background = 53,
+               .c256_formatarg = 225,
+       },
+       [LOG_ERR] = {
+               .label = "\e[38;5;202mERR!",
+               .c256_background = 52,
+               .c256_formatarg = 224,
+       },
+       [LOG_WARNING] = {
+               .label = "\e[38;5;222mWARN",
+               .c256_background = 58,
+               .c256_formatarg = 230,
+       },
+       [LOG_NOTICE] = {
+               .label = "NTFY",
+               .c256_background = 234,
+               .c256_formatarg = 195,
+       },
+       [LOG_INFO] = {
+               .label = "\e[38;5;192mINFO",
+               .c256_background = 236,
+               .c256_formatarg = 195,
+       },
+       [LOG_DEBUG] = {
+               .label = "\e[38;5;116mDEBG",
+               .c256_background = 238,
+               .c256_formatarg = 195,
+       },
+};
+/* clang-format on */
+
+static void vtysh_log_print(struct vtysh_client *vclient,
+                           struct zlog_live_hdr *hdr, const char *text)
+{
+       size_t textlen = hdr->textlen, textpos = 0;
+       time_t ts = hdr->ts_sec;
+       struct visual_prio *vis;
+       struct tm tm;
+       char ts_buf[32];
+
+       if (hdr->prio > array_size(visual_prios))
+               vis = &visual_prios[LOG_CRIT];
+       else
+               vis = &visual_prios[hdr->prio];
+
+       localtime_r(&ts, &tm);
+       strftime(ts_buf, sizeof(ts_buf), "%Y-%m-%d %H:%M:%S", &tm);
+
+       if (!stderr_tty) {
+               const char *label = vis->label + strlen(vis->label) - 4;
+
+               fprintf(stderr, "%s.%03u [%s] %s: %.*s\n", ts_buf,
+                       hdr->ts_nsec / 1000000U, label, vclient->name,
+                       (int)textlen, text);
+               return;
+       }
+
+       fprintf(stderr,
+               "\e[48;5;%dm\e[38;5;247m%s.%03u [%s\e[38;5;247m] \e[38;5;255m%s\e[38;5;247m: \e[38;5;251m",
+               vis->c256_background, ts_buf, hdr->ts_nsec / 1000000U,
+               vis->label, vclient->name);
+
+       for (size_t fmtpos = 0; fmtpos < hdr->n_argpos; fmtpos++) {
+               struct fmt_outpos *fmt = &hdr->argpos[fmtpos];
+
+               if (fmt->off_start < textpos || fmt->off_end < fmt->off_start ||
+                   fmt->off_end > textlen)
+                       continue;
+
+               while (fmt->off_end > fmt->off_start &&
+                      text[fmt->off_end - 1] == ' ')
+                       fmt->off_end--;
+
+               fprintf(stderr, "%.*s\e[38;5;%dm%.*s\e[38;5;251m",
+                       (int)(fmt->off_start - textpos), text + textpos,
+                       vis->c256_formatarg,
+                       (int)(fmt->off_end - fmt->off_start),
+                       text + fmt->off_start);
+               textpos = fmt->off_end;
+       }
+       fprintf(stderr, "%.*s\033[K\033[m\n", (int)(textlen - textpos),
+               text + textpos);
+}
+
+static void vtysh_log_read(struct thread *thread)
+{
+       struct vtysh_client *vclient = THREAD_ARG(thread);
+       struct {
+               struct zlog_live_hdr hdr;
+               char text[4096];
+       } buf;
+       const char *text;
+       ssize_t ret;
+
+       thread_add_read(master, vtysh_log_read, vclient, vclient->log_fd,
+                       &vclient->log_reader);
+
+       ret = recv(vclient->log_fd, &buf, sizeof(buf), 0);
+
+       if (ret < 0 && ERRNO_IO_RETRY(errno))
+               return;
+
+       if (ret <= 0) {
+               struct timespec ts;
+
+               if (ret != 0)
+                       snprintfrr(buf.text, sizeof(buf.text),
+                                  "log monitor connection error: %m");
+               else
+                       snprintfrr(
+                               buf.text, sizeof(buf.text),
+                               "log monitor connection closed unexpectedly");
+               buf.hdr.textlen = strlen(buf.text);
+
+               THREAD_OFF(vclient->log_reader);
+               close(vclient->log_fd);
+               vclient->log_fd = -1;
+
+               clock_gettime(CLOCK_REALTIME, &ts);
+               buf.hdr.ts_sec = ts.tv_sec;
+               buf.hdr.ts_nsec = ts.tv_nsec;
+               buf.hdr.prio = LOG_ERR;
+               buf.hdr.flags = 0;
+               buf.hdr.arghdrlen = 0;
+               buf.hdr.n_argpos = 0;
+       }
+
+       if (stderr_stdout_same) {
+#ifdef HAVE_RL_CLEAR_VISIBLE_LINE
+               rl_clear_visible_line();
+#else
+               puts("\r");
+#endif
+               fflush(stdout);
+       }
+
+       text = buf.text + sizeof(buf.hdr.argpos[0]) * buf.hdr.n_argpos;
+       vtysh_log_print(vclient, &buf.hdr, text);
+
+       if (stderr_stdout_same)
+               rl_forced_update_display();
+
+       return;
+}
+
+#ifdef CLIPPY
+/* clippy/clidef can't process the DEFPY below without some value for this */
+#define DAEMONS_LIST "daemon"
+#endif
+
+DEFPY (vtysh_terminal_monitor,
+       vtysh_terminal_monitor_cmd,
+       "terminal monitor ["DAEMONS_LIST"]$daemon",
+       "Set terminal line parameters\n"
+       "Receive log messages to active VTY session\n"
+       DAEMONS_STR)
+{
+       static const char line[] = "terminal monitor\n";
+       int ret_all = CMD_SUCCESS, ret, fd;
+       size_t i, ok = 0;
+
+       for (i = 0; i < array_size(vtysh_client); i++) {
+               struct vtysh_client *vclient = &vtysh_client[i];
+
+               if (daemon && strcmp(vclient->name, daemon))
+                       continue;
+
+               for (; vclient; vclient = vclient->next) {
+                       if (vclient->log_fd != -1) {
+                               vty_out(vty, "%% %s: already monitoring logs\n",
+                                       vclient->name);
+                               ok++;
+                               continue;
+                       }
+
+                       fd = -1;
+                       ret = vtysh_client_run(vclient, line, NULL, NULL, &fd);
+                       if (fd != -1) {
+                               set_nonblocking(fd);
+                               vclient->log_fd = fd;
+                               thread_add_read(master, vtysh_log_read, vclient,
+                                               vclient->log_fd,
+                                               &vclient->log_reader);
+                       }
+                       if (ret != CMD_SUCCESS) {
+                               vty_out(vty, "%% failed to enable logs on %s\n",
+                                       vclient->name);
+                               ret_all = CMD_WARNING;
+                       } else
+                               ok++;
+               }
+       }
+
+       if (!ok && ret_all == CMD_SUCCESS) {
+               vty_out(vty,
+                       "%% command had no effect, relevant daemons not connected?\n");
+               ret_all = CMD_WARNING;
+       }
+       return ret_all;
+}
+
+DEFPY (no_vtysh_terminal_monitor,
+       no_vtysh_terminal_monitor_cmd,
+       "no terminal monitor ["DAEMONS_LIST"]$daemon",
+       NO_STR
+       "Set terminal line parameters\n"
+       "Receive log messages to active VTY session\n"
+       DAEMONS_STR)
+{
+       static const char line[] = "no terminal monitor\n";
+       int ret_all = CMD_SUCCESS, ret;
+       size_t i, ok = 0;
+
+       for (i = 0; i < array_size(vtysh_client); i++) {
+               struct vtysh_client *vclient = &vtysh_client[i];
+
+               if (daemon && strcmp(vclient->name, daemon))
+                       continue;
+
+               for (; vclient; vclient = vclient->next) {
+                       /* run this even if log_fd == -1, in case something
+                        * got desync'd
+                        */
+                       ret = vtysh_client_run(vclient, line, NULL, NULL, NULL);
+                       if (ret != CMD_SUCCESS) {
+                               vty_out(vty,
+                                       "%% failed to disable logs on %s\n",
+                                       vclient->name);
+                               ret_all = CMD_WARNING;
+                       } else
+                               ok++;
+
+                       /* with this being a datagram socket, we can't expect
+                        * a close notification...
+                        */
+                       if (vclient->log_fd != -1) {
+                               THREAD_OFF(vclient->log_reader);
+
+                               close(vclient->log_fd);
+                               vclient->log_fd = -1;
+                       }
+               }
+       }
+
+       if (!ok && ret_all == CMD_SUCCESS) {
+               vty_out(vty,
+                       "%% command had no effect, relevant daemons not connected?\n");
+               ret_all = CMD_WARNING;
+       }
+       return ret_all;
+}
+
+
 /* Execute command in child process. */
 static void execute_command(const char *command, int argc, const char *arg1,
                            const char *arg2)
@@ -4019,8 +4302,21 @@ void vtysh_uninit(void)
 
 void vtysh_init_vty(void)
 {
+       struct stat st_out, st_err;
+
        cmd_defer_tree(true);
 
+       for (size_t i = 0; i < array_size(vtysh_client); i++) {
+               vtysh_client[i].fd = -1;
+               vtysh_client[i].log_fd = -1;
+       }
+
+       stderr_tty = isatty(STDERR_FILENO);
+
+       if (fstat(STDOUT_FILENO, &st_out) || fstat(STDERR_FILENO, &st_err) ||
+           (st_out.st_dev == st_err.st_dev && st_out.st_ino == st_err.st_ino))
+               stderr_stdout_same = true;
+
        /* Make vty structure. */
        vty = vty_new();
        vty->type = VTY_SHELL;
@@ -4514,6 +4810,9 @@ void vtysh_init_vty(void)
        install_element(VIEW_NODE, &vtysh_terminal_no_length_cmd);
        install_element(VIEW_NODE, &vtysh_show_daemons_cmd);
 
+       install_element(VIEW_NODE, &vtysh_terminal_monitor_cmd);
+       install_element(VIEW_NODE, &no_vtysh_terminal_monitor_cmd);
+
        install_element(VIEW_NODE, &vtysh_ping_cmd);
        install_element(VIEW_NODE, &vtysh_ping_ip_cmd);
        install_element(VIEW_NODE, &vtysh_traceroute_cmd);
index 8fb85293e559ac8aee5d094a326e83cf52b71fac..6053955be96d71ba3fbbbec45152b3a8b75cb9b0 100644 (file)
 #include "memory.h"
 DECLARE_MGROUP(MVTYSH);
 
+struct thread_master;
+
+extern struct thread_master *master;
+
 #define VTYSH_ZEBRA     0x00001
 #define VTYSH_RIPD      0x00002
 #define VTYSH_RIPNGD    0x00004