Log anything that could prevent a daemon from starting.
[sliver-openvswitch.git] / lib / timeval.c
index f3e6583..099730e 100644 (file)
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2008, 2009, 2010 Nicira Networks.
+ * Copyright (c) 2008, 2009, 2010, 2011 Nicira Networks.
  *
  * Licensed under the Apache License, Version 2.0 (the "License");
  * you may not use this file except in compliance with the License.
 #include <unistd.h>
 #include "coverage.h"
 #include "fatal-signal.h"
+#include "signals.h"
 #include "util.h"
-
 #include "vlog.h"
-#define THIS_MODULE VLM_timeval
 
-/* Initialized? */
-static bool inited;
+VLOG_DEFINE_THIS_MODULE(timeval);
 
-/* Does this system have monotonic timers? */
-static bool monotonic_inited;
+/* The clock to use for measuring time intervals.  This is CLOCK_MONOTONIC by
+ * preference, but on systems that don't have a monotonic clock we fall back
+ * to CLOCK_REALTIME. */
 static clockid_t monotonic_clock;
 
-/* Has a timer tick occurred? */
-static volatile sig_atomic_t wall_tick;
-static volatile sig_atomic_t monotonic_tick;
+/* Has a timer tick occurred?
+ *
+ * We initialize these to true to force time_init() to get called on the first
+ * call to time_msec() or another function that queries the current time. */
+static volatile sig_atomic_t wall_tick = true;
+static volatile sig_atomic_t monotonic_tick = true;
 
 /* The current time, as of the last refresh. */
 static struct timespec wall_time;
@@ -60,41 +62,30 @@ static void unblock_sigalrm(const sigset_t *);
 static void log_poll_interval(long long int last_wakeup,
                               const struct rusage *last_rusage);
 
-/* Initializes the timetracking module. */
-void
+/* Initializes the timetracking module.
+ *
+ * It is not necessary to call this function directly, because other time
+ * functions will call it automatically, but it doesn't hurt. */
+static void
 time_init(void)
 {
+    static bool inited;
     if (inited) {
         return;
     }
-
-    coverage_init();
-
     inited = true;
-    time_refresh();
 
-    set_up_signal(SA_RESTART);
-    set_up_timer();
-}
-
-static void
-set_up_monotonic(void)
-{
-    int err;
-
-    if (monotonic_inited) {
-        return;
-    }
+    coverage_init();
 
-    err = clock_gettime(CLOCK_MONOTONIC, &monotonic_time);
-    if (!err) {
+    if (!clock_gettime(CLOCK_MONOTONIC, &monotonic_time)) {
         monotonic_clock = CLOCK_MONOTONIC;
     } else {
         monotonic_clock = CLOCK_REALTIME;
         VLOG_DBG("monotonic timer not available");
     }
 
-    monotonic_inited = true;
+    set_up_signal(SA_RESTART);
+    set_up_timer();
 }
 
 static void
@@ -106,9 +97,7 @@ set_up_signal(int flags)
     sa.sa_handler = sigalrm_handler;
     sigemptyset(&sa.sa_mask);
     sa.sa_flags = flags;
-    if (sigaction(SIGALRM, &sa, NULL)) {
-        ovs_fatal(errno, "sigaction(SIGALRM) failed");
-    }
+    xsigaction(SIGALRM, &sa, NULL);
 }
 
 /* Remove SA_RESTART from the flags for SIGALRM, so that any system call that
@@ -126,6 +115,7 @@ set_up_signal(int flags)
 void
 time_disable_restart(void)
 {
+    time_init();
     set_up_signal(0);
 }
 
@@ -135,19 +125,18 @@ time_disable_restart(void)
 void
 time_enable_restart(void)
 {
+    time_init();
     set_up_signal(SA_RESTART);
 }
 
 static void
 set_up_timer(void)
 {
-    timer_t timer_id;
+    static timer_t timer_id;    /* "static" to avoid apparent memory leak. */
     struct itimerspec itimer;
 
-    set_up_monotonic();
-
     if (timer_create(monotonic_clock, NULL, &timer_id)) {
-        ovs_fatal(errno, "timer_create failed");
+        VLOG_FATAL("timer_create failed (%s)", strerror(errno));
     }
 
     itimer.it_interval.tv_sec = 0;
@@ -155,7 +144,7 @@ set_up_timer(void)
     itimer.it_value = itimer.it_interval;
 
     if (timer_settime(timer_id, 0, &itimer, NULL)) {
-        ovs_fatal(errno, "timer_settime failed");
+        VLOG_FATAL("timer_settime failed (%s)", strerror(errno));
     }
 }
 
@@ -167,12 +156,14 @@ set_up_timer(void)
 void
 time_postfork(void)
 {
+    time_init();
     set_up_timer();
 }
 
 static void
 refresh_wall(void)
 {
+    time_init();
     clock_gettime(CLOCK_REALTIME, &wall_time);
     wall_tick = false;
 }
@@ -180,7 +171,7 @@ refresh_wall(void)
 static void
 refresh_monotonic(void)
 {
-    set_up_monotonic();
+    time_init();
 
     if (monotonic_clock == CLOCK_MONOTONIC) {
         clock_gettime(monotonic_clock, &monotonic_time);
@@ -210,7 +201,7 @@ time_now(void)
 }
 
 /* Same as time_now() except does not write to static variables, for use in
- * signal handlers. set_up_monotonic() must have already been called. */
+ * signal handlers.  */
 static time_t
 time_now_sig(void)
 {
@@ -353,7 +344,6 @@ sigalrm_handler(int sig_nr)
 static void
 refresh_wall_if_ticked(void)
 {
-    assert(inited);
     if (wall_tick) {
         refresh_wall();
     }
@@ -362,7 +352,6 @@ refresh_wall_if_ticked(void)
 static void
 refresh_monotonic_if_ticked(void)
 {
-    assert(inited);
     if (monotonic_tick) {
         refresh_monotonic();
     }
@@ -374,17 +363,13 @@ block_sigalrm(sigset_t *oldsigs)
     sigset_t sigalrm;
     sigemptyset(&sigalrm);
     sigaddset(&sigalrm, SIGALRM);
-    if (sigprocmask(SIG_BLOCK, &sigalrm, oldsigs)) {
-        ovs_fatal(errno, "sigprocmask");
-    }
+    xsigprocmask(SIG_BLOCK, &sigalrm, oldsigs);
 }
 
 static void
 unblock_sigalrm(const sigset_t *oldsigs)
 {
-    if (sigprocmask(SIG_SETMASK, oldsigs, NULL)) {
-        ovs_fatal(errno, "sigprocmask");
-    }
+    xsigprocmask(SIG_SETMASK, oldsigs, NULL);
 }
 
 long long int
@@ -399,6 +384,14 @@ timeval_to_msec(const struct timeval *tv)
     return (long long int) tv->tv_sec * 1000 + tv->tv_usec / 1000;
 }
 
+void
+xgettimeofday(struct timeval *tv)
+{
+    if (gettimeofday(tv, NULL) == -1) {
+        VLOG_FATAL("gettimeofday failed (%s)", strerror(errno));
+    }
+}
+
 static long long int
 timeval_diff_msec(const struct timeval *a, const struct timeval *b)
 {
@@ -419,8 +412,9 @@ log_poll_interval(long long int last_wakeup, const struct rusage *last_rusage)
     now = time_msec();
     interval = MIN(10000, now - last_wakeup) << 4;
 
-    /* Warn if we took too much time between polls. */
-    if (n_samples > 10 && interval > mean_interval * 8) {
+    /* Warn if we took too much time between polls: at least 50 ms and at least
+     * 8X the mean interval. */
+    if (n_samples > 10 && interval > mean_interval * 8 && interval > 50 * 16) {
         struct rusage rusage;
 
         getrusage(RUSAGE_SELF, &rusage);
@@ -451,9 +445,9 @@ log_poll_interval(long long int last_wakeup, const struct rusage *last_rusage)
                       rusage.ru_nivcsw - last_rusage->ru_nivcsw);
         }
 
-        /* Care should be taken in the value chosen for logging.  Depending 
-         * on the configuration, syslog can write changes synchronously, 
-         * which can cause the coverage messages to take longer to log 
+        /* Care should be taken in the value chosen for logging.  Depending
+         * on the configuration, syslog can write changes synchronously,
+         * which can cause the coverage messages to take longer to log
          * than the processing delay that triggered it. */
         coverage_log(VLL_INFO, true);
     }