From: Ben Pfaff <blp@nicira.com>
Date: Mon, 20 Jun 2011 22:06:33 +0000 (-0700)
Subject: vlog: Add a little more detail to ratelimit messages
X-Git-Url: https://pintos-os.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=e2eed6a7581193da43210a26ad182fb2a697eaf5;p=openvswitch

vlog: Add a little more detail to ratelimit messages

When a message is suppressed by vlog ratelimiting, and then that message
occurs again much later, sometimes we get messages like this:

   Dropped 4 log messages in last 8695 seconds due to excessive rate

It seems pretty clear in this case that in fact we just didn't get that
kind of message for most of that 8695 seconds.  This commit improves the
message by adding a little more detail, e.g.:

   Dropped 4 log messages in last 8695 seconds (most recently, 6697 seconds
   ago) due to excessive rate.

Bug #2144.
---

diff --git a/lib/vlog.c b/lib/vlog.c
index 265e9c6d..279c6e73 100644
--- a/lib/vlog.c
+++ b/lib/vlog.c
@@ -740,6 +740,7 @@ vlog_should_drop(const struct vlog_module *module, enum vlog_level level,
             if (!rl->n_dropped) {
                 rl->first_dropped = now;
             }
+            rl->last_dropped = now;
             rl->n_dropped++;
             return true;
         }
@@ -747,10 +748,15 @@ vlog_should_drop(const struct vlog_module *module, enum vlog_level level,
     rl->tokens -= VLOG_MSG_TOKENS;
 
     if (rl->n_dropped) {
+        time_t now = time_now();
+        unsigned int first_dropped_elapsed = now - rl->first_dropped;
+        unsigned int last_dropped_elapsed = now - rl->last_dropped;
+
         vlog(module, level,
-             "Dropped %u log messages in last %u seconds "
-             "due to excessive rate",
-             rl->n_dropped, (unsigned int) (time_now() - rl->first_dropped));
+             "Dropped %u log messages in last %u seconds (most recently, "
+             "%u seconds ago) due to excessive rate",
+             rl->n_dropped, first_dropped_elapsed, last_dropped_elapsed);
+
         rl->n_dropped = 0;
     }
     return false;
diff --git a/lib/vlog.h b/lib/vlog.h
index 3f40c297..1a11f598 100644
--- a/lib/vlog.h
+++ b/lib/vlog.h
@@ -112,6 +112,7 @@ struct vlog_rate_limit {
     unsigned int tokens;        /* Current number of tokens. */
     time_t last_fill;           /* Last time tokens added. */
     time_t first_dropped;       /* Time first message was dropped. */
+    time_t last_dropped;        /* Time of most recent message drop. */
     unsigned int n_dropped;     /* Number of messages dropped. */
 };
 
@@ -130,6 +131,7 @@ struct vlog_rate_limit {
             0,                              /* tokens */    \
             0,                              /* last_fill */ \
             0,                              /* first_dropped */ \
+            0,                              /* last_dropped */ \
             0,                              /* n_dropped */ \
         }