Warn if the event loop or pcap_dispatch are too slow.

diff --git a/Makefile.in b/Makefile.in
index d06c8a6..a66d4c8 100644 (file)
--- a/Makefile.in
+++ b/Makefile.in
@@ -126,7 +126,7 @@ acct.o: acct.c acct.h decode.h addr.h conv.h daylog.h graph_db.h err.h \
 addr.o: addr.c addr.h
 bsd.o: bsd.c bsd.h config.h cdefs.h
 cap.o: cap.c acct.h cdefs.h cap.h config.h conv.h decode.h addr.h err.h \
- hosts_db.h localip.h opt.h
+ hosts_db.h localip.h now.h opt.h
 conv.o: conv.c conv.h err.h cdefs.h
 darkstat.o: darkstat.c acct.h cap.h cdefs.h config.h conv.h daylog.h \
  graph_db.h db.h dns.h err.h http.h hosts_db.h addr.h localip.h ncache.h \

diff --git a/cap.c b/cap.c
index 7757153..21e48fe 100644 (file)
--- a/cap.c
+++ b/cap.c
@@ -16,6 +16,7 @@
 #include "err.h"
 #include "hosts_db.h"
 #include "localip.h"
+#include "now.h"
 #include "opt.h"
 
 #include <sys/ioctl.h>
@@ -307,33 +308,19 @@ cap_poll(fd_set *read_set
 
    total = 0;
    for (;;) {
-#ifndef NDEBUG
-      struct timeval t1;
-      gettimeofday(&t1, NULL);
-#endif
+      struct timespec t;
+
+      timer_start(&t);
       ret = pcap_dispatch(
             pcap,
             -1,               /* count, -1 = entire buffer */
             callback,
             NULL);            /* user */
-
       if (ret < 0) {
          warnx("pcap_dispatch(): %s", pcap_geterr(pcap));
          return;
       }
-
-#ifndef NDEBUG
-      {
-         struct timeval t2;
-         int td;
-
-         gettimeofday(&t2, NULL);
-         td = (t2.tv_sec - t1.tv_sec) * 1000000 + t2.tv_usec - t1.tv_usec;
-         if (td > CAP_TIMEOUT*1000)
-            warnx("pcap_dispatch blocked for %d usec! (expected <= %d usec)\n",
-               td, CAP_TIMEOUT*1000);
-      }
-#endif
+      timer_stop(&t, 2*CAP_TIMEOUT*1000000, "pcap_dispatch took too long");
 
       /* Despite count = -1, Linux will only dispatch one packet at a time. */
       total += ret;

diff --git a/darkstat.c b/darkstat.c
index ea9bf2a..6c85b20 100644 (file)
--- a/darkstat.c
+++ b/darkstat.c
@@ -455,11 +455,12 @@ main(int argc, char **argv)
    while (running) {
       int select_ret, max_fd = -1, use_timeout = 0;
       struct timeval timeout;
+      struct timespec t;
       fd_set rs, ws;
 
+      timer_start(&t);
       FD_ZERO(&rs);
       FD_ZERO(&ws);
-
       cap_fd_set(&rs, &max_fd, &timeout, &use_timeout);
       http_fd_set(&rs, &ws, &max_fd, &timeout, &use_timeout);
 
@@ -494,6 +495,7 @@ main(int argc, char **argv)
       cap_poll(&rs);
       dns_poll();
       http_poll(&rs, &ws);
+      timer_stop(&t, 1000000000, "event loop took longer than a second");
    }
 
    verbosef("shutting down");

diff --git a/now.c b/now.c
index ffc1433..6e003c4 100644 (file)
--- a/now.c
+++ b/now.c
@@ -86,4 +86,30 @@ long real_to_mono(const long t) {
    return t - clock_real.tv_sec + clock_mono.tv_sec;
 }
 
+void timer_start(struct timespec *t) {
+   clock_gettime(CLOCK_MONOTONIC, t);
+}
+
+static int64_t ts_diff(const struct timespec * const a,
+                       const struct timespec * const b) {
+   return (int64_t)(a->tv_sec - b->tv_sec) * 1000000000 +
+          a->tv_nsec - b->tv_nsec;
+}
+
+void timer_stop(const struct timespec * const t,
+                const int64_t nsec,
+                const char *warning) {
+   struct timespec t2;
+   int64_t diff;
+
+   clock_gettime(CLOCK_MONOTONIC, &t2);
+   diff = ts_diff(&t2, t);
+   assert(diff > 0);
+   if (diff > nsec)
+      warnx("%s (took %lld nsec, over threshold of %lld nsec)",
+            warning,
+            (long long)diff,
+            (long long)nsec);
+}
+
 /* vim:set ts=3 sw=3 tw=80 et: */

diff --git a/now.h b/now.h
index 7f89423..9c61f45 100644 (file)
--- a/now.h
+++ b/now.h
@@ -15,6 +15,7 @@
  * ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF
  * OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
  */
+#include <sys/types.h>
 
 void now_init(void);
 void now_update(void); /* once per event loop (in darkstat.c) */
@@ -25,4 +26,11 @@ long now_mono(void);
 long mono_to_real(const long t);
 long real_to_mono(const long t);
 
+/* Emits warnings if a call is too slow. */
+struct timespec;
+void timer_start(struct timespec *t);
+void timer_stop(const struct timespec * const t,
+                const int64_t nsec,
+                const char *warning);
+
 /* vim:set ts=3 sw=3 tw=80 et: */