lib, vtysh: report lost messages on live log

The vtysh live logs don't try to buffer messages when vtysh isn't
reading them fast enough.  Either the kernel has space and can accept
messages without delay, or it doesn't and we continue on.

While this is intentional (otherwise slow vtysh could block a routing
daemon), at least give the user an indication if messages were dropped.

Signed-off-by: David Lamparter <equinox@opensourcerouting.org>

diff --git a/lib/zlog_live.c b/lib/zlog_live.c
index d871e20db10662e52632f0b34cc21b72b6b88e5b..931aa3461d563a1fae0ccaf1c55339b003d29c7f 100644 (file)
--- a/lib/zlog_live.c
+++ b/lib/zlog_live.c
@@ -40,6 +40,7 @@ struct zlt_live {
        struct rcu_head head_self;
 
        atomic_uint_fast32_t state;
+       atomic_uint_fast32_t lost_msgs;
 };
 
 static void zlog_live(struct zlog_target *zt, struct zlog_msg *msgs[],
@@ -99,6 +100,8 @@ static void zlog_live(struct zlog_target *zt, struct zlog_msg *msgs[],
                hdr->ts_nsec = ts.tv_nsec;
                hdr->pid = pid;
                hdr->tid = tid;
+               hdr->lost_msgs = atomic_load_explicit(&zte->lost_msgs,
+                                                     memory_order_relaxed);
                hdr->prio = prio;
                hdr->flags = 0;
                hdr->textlen = textlen;
@@ -125,8 +128,12 @@ static void zlog_live(struct zlog_target *zt, struct zlog_msg *msgs[],
        for (size_t msgpos = 0; msgpos < msgtotal; msgpos += sent) {
                sent = sendmmsg(fd, mmhs + msgpos, msgtotal - msgpos, 0);
 
-               if (sent <= 0 && (errno == EAGAIN || errno == EWOULDBLOCK))
+               if (sent <= 0 && (errno == EAGAIN || errno == EWOULDBLOCK)) {
+                       atomic_fetch_add_explicit(&zte->lost_msgs,
+                                                 msgtotal - msgpos,
+                                                 memory_order_relaxed);
                        break;
+               }
                if (sent <= 0)
                        goto out_err;
        }

diff --git a/lib/zlog_live.h b/lib/zlog_live.h
index ab8aae452f4bad1525ae05337e4894d0668e985b..55e60ae674b3534478cdcb13646cbcfb9ffb4238 100644 (file)
--- a/lib/zlog_live.h
+++ b/lib/zlog_live.h
@@ -33,6 +33,8 @@ struct zlog_live_hdr {
        int64_t pid;
        int64_t tid;
 
+       /* number of lost messages due to best-effort non-blocking mode */
+       uint32_t lost_msgs;
        /* syslog priority value */
        uint32_t prio;
        /* flags: currently unused */

diff --git a/vtysh/vtysh.c b/vtysh/vtysh.c
index ed008bd089a4c27e730a464edfa8d317e0716ce7..ed1f1fb5bb875bc3f987384c83de23173d45eb38 100644 (file)
--- a/vtysh/vtysh.c
+++ b/vtysh/vtysh.c
@@ -73,6 +73,7 @@ struct vtysh_client {
 
        struct thread *log_reader;
        int log_fd;
+       uint32_t lost_msgs;
 };
 
 static bool stderr_tty;
@@ -3654,6 +3655,15 @@ static void vtysh_log_read(struct thread *thread)
        if (ret < 0 && ERRNO_IO_RETRY(errno))
                return;
 
+       if (stderr_stdout_same) {
+#ifdef HAVE_RL_CLEAR_VISIBLE_LINE
+               rl_clear_visible_line();
+#else
+               puts("\r");
+#endif
+               fflush(stdout);
+       }
+
        if (ret <= 0) {
                struct timespec ts;
 
@@ -3679,15 +3689,15 @@ static void vtysh_log_read(struct thread *thread)
                buf.hdr.flags = 0;
                buf.hdr.texthdrlen = 0;
                buf.hdr.n_argpos = 0;
-       }
+       } else {
+               int32_t lost_msgs = buf.hdr.lost_msgs - vclient->lost_msgs;
 
-       if (stderr_stdout_same) {
-#ifdef HAVE_RL_CLEAR_VISIBLE_LINE
-               rl_clear_visible_line();
-#else
-               puts("\r");
-#endif
-               fflush(stdout);
+               if (lost_msgs > 0) {
+                       vclient->lost_msgs = buf.hdr.lost_msgs;
+                       fprintf(stderr,
+                               "%d log messages from %s lost (vtysh reading too slowly)\n",
+                               lost_msgs, vclient->name);
+               }
        }
 
        text = buf.text + sizeof(buf.hdr.argpos[0]) * buf.hdr.n_argpos;