vlog: Implement rate-limiting.

diff --git a/include/vlog.h b/include/vlog.h
index f2641b092e28d0431f69b81e536458dbd9ed79a9..3196743621054a2e3fb1ebbe091e3a27b2a19ffc 100644 (file)
--- a/include/vlog.h
+++ b/include/vlog.h
@@ -34,7 +34,11 @@
 #ifndef VLOG_H
 #define VLOG_H 1
 
+#include <limits.h>
+#include <stdarg.h>
 #include <stdbool.h>
+#include <time.h>
+#include "util.h"
 
 /* Logging importance levels. */
 enum vlog_level {
@@ -102,6 +106,36 @@ enum vlog_module {
 const char *vlog_get_module_name(enum vlog_module);
 enum vlog_module vlog_get_module_val(const char *name);
 
+/* Rate-limiter for log messages. */
+struct vlog_rate_limit {
+    /* Configuration settings. */
+    unsigned int rate;          /* Tokens per second. */
+    unsigned int burst;         /* Max cumulative tokens credit. */
+
+    /* Current status. */
+    unsigned int tokens;        /* Current number of tokens. */
+    time_t last_fill;           /* Last time tokens added. */
+    time_t first_dropped;       /* Time first message was dropped. */
+    unsigned int n_dropped;     /* Number of messages dropped. */
+};
+
+/* Number of tokens to emit a message.  We add 'rate' token per second, which
+ * is 60 times the unit used for 'rate', thus 60 tokens are required to emit
+ * one message. */
+#define VLOG_MSG_TOKENS 60
+
+/* Initializer for a struct vlog_rate_limit, to set up a maximum rate of RATE
+ * messages per minute and a maximum burst size of BURST messages. */
+#define VLOG_RATE_LIMIT_INIT(RATE, BURST)                   \
+        {                                                   \
+            RATE,                           /* rate */      \
+            (MIN(BURST, UINT_MAX / VLOG_MSG_TOKENS)         \
+             * VLOG_MSG_TOKENS),            /* burst */     \
+            0,                              /* tokens */    \
+            0,                              /* last_fill */ \
+            0,                              /* n_dropped */ \
+        }
+
 /* Configuring how each module logs messages. */
 enum vlog_level vlog_get_level(enum vlog_module, enum vlog_facility);
 void vlog_set_levels(enum vlog_module, enum vlog_facility, enum vlog_level);
@@ -115,6 +149,11 @@ void vlog_init(void);
 void vlog_exit(void);
 void vlog(enum vlog_module, enum vlog_level, const char *format, ...)
     __attribute__((format(printf, 3, 4)));
+void vlog_valist(enum vlog_module, enum vlog_level, const char *, va_list)
+    __attribute__((format(printf, 3, 0)));
+void vlog_rate_limit(enum vlog_module, enum vlog_level,
+                     struct vlog_rate_limit *, const char *, ...)
+    __attribute__((format(printf, 4, 5)));
 
 /* Convenience macros.  To use these, define THIS_MODULE as a macro that
  * expands to the module used by the current source file, e.g.
@@ -135,4 +174,17 @@ void vlog(enum vlog_module, enum vlog_level, const char *format, ...)
 #define VLOG_IS_WARN_ENABLED() vlog_is_enabled(THIS_MODULE, VLL_WARN)
 #define VLOG_IS_DBG_ENABLED() vlog_is_enabled(THIS_MODULE, VLL_DBG)
 
+/* Convenience macros.  To use these, define THIS_MODULE as a macro that
+ * expands to the module used by the current source file, e.g.
+ *      #include "vlog.h"
+ *      #define THIS_MODULE VLM_netlink
+ * Guaranteed to preserve errno.
+ */
+#define VLOG_ERR_RL(RL, ...) \
+        vlog_rate_limit(THIS_MODULE, VLL_ERR, RL, __VA_ARGS__)
+#define VLOG_WARN_RL(RL, ...) \
+        vlog_rate_limit(THIS_MODULE, VLL_WARN, RL, __VA_ARGS__)
+#define VLOG_DBG_RL(RL, ...) \
+        vlog_rate_limit(THIS_MODULE, VLL_DBG, RL, __VA_ARGS__)
+
 #endif /* vlog.h */

diff --git a/lib/vlog.c b/lib/vlog.c
index 19590e30f2d387876b162f9daf6d5e2f034e0203..663b3df04566ba0f5715b82a129a4a45e1aef090 100644 (file)
--- a/lib/vlog.c
+++ b/lib/vlog.c
@@ -43,6 +43,7 @@
 #include <syslog.h>
 #include <time.h>
 #include "dynamic-string.h"
+#include "sat-math.h"
 #include "timeval.h"
 #include "util.h"
 
@@ -309,7 +310,8 @@ vlog_is_enabled(enum vlog_module module, enum vlog_level level)
  *
  * Guaranteed to preserve errno. */
 void
-vlog(enum vlog_module module, enum vlog_level level, const char *message, ...)
+vlog_valist(enum vlog_module module, enum vlog_level level,
+            const char *message, va_list args)
 {
     bool log_console = levels[module][VLF_CONSOLE] >= level;
     bool log_syslog = levels[module][VLF_SYSLOG] >= level;
@@ -359,3 +361,57 @@ vlog(enum vlog_module module, enum vlog_level level, const char *message, ...)
         errno = save_errno;
     }
 }
+
+void
+vlog(enum vlog_module module, enum vlog_level level, const char *message, ...)
+{
+    va_list args;
+
+    va_start(args, message);
+    vlog_valist(module, level, message, args);
+    va_end(args);
+}
+
+void
+vlog_rate_limit(enum vlog_module module, enum vlog_level level,
+                struct vlog_rate_limit *rl, const char *message, ...)
+{
+    va_list args;
+
+    if (!vlog_is_enabled(module, level)) {
+        return;
+    }
+
+    if (rl->tokens < VLOG_MSG_TOKENS) {
+        time_t now = time_now();
+        if (rl->last_fill > now) {
+            /* Last filled in the future?  Time must have gone backward, or
+             * 'rl' has not been used before. */
+            rl->tokens = rl->burst;
+        } else if (rl->last_fill < now) {
+            unsigned int add = sat_mul(rl->rate, now - rl->last_fill);
+            unsigned int tokens = sat_add(rl->tokens, add);
+            rl->tokens = MIN(tokens, rl->burst);
+            rl->last_fill = now;
+        }
+        if (rl->tokens < VLOG_MSG_TOKENS) {
+            if (!rl->n_dropped) {
+                rl->first_dropped = now;
+            }
+            rl->n_dropped++;
+            return;
+        }
+    }
+    rl->tokens -= VLOG_MSG_TOKENS;
+
+    va_start(args, message);
+    vlog_valist(module, level, message, args);
+    va_end(args);
+
+    if (rl->n_dropped) {
+        vlog(module, level,
+             "Dropped %u messages in last %u seconds due to excessive rate",
+             rl->n_dropped, (unsigned int) (time_now() - rl->first_dropped));
+        rl->n_dropped = 0;
+    }
+}