Replace all uses of strerror() by ovs_strerror(), for thread safety.
[sliver-openvswitch.git] / lib / timeval.c
index e507140..0ccfa42 100644 (file)
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2008, 2009, 2010, 2011, 2012 Nicira, Inc.
+ * Copyright (c) 2008, 2009, 2010, 2011, 2012, 2013 Nicira, Inc.
  *
  * Licensed under the Apache License, Version 2.0 (the "License");
  * you may not use this file except in compliance with the License.
 
 #include <config.h>
 #include "timeval.h"
-#include <assert.h>
 #include <errno.h>
-#if HAVE_EXECINFO_H
-#include <execinfo.h>
-#endif
 #include <poll.h>
 #include <signal.h>
 #include <stdlib.h>
 #include "dummy.h"
 #include "dynamic-string.h"
 #include "fatal-signal.h"
+#include "hash.h"
+#include "hmap.h"
+#include "ovs-thread.h"
 #include "signals.h"
 #include "unixctl.h"
 #include "util.h"
 #include "vlog.h"
 
-#ifndef HAVE_EXECINFO_H
-#define HAVE_EXECINFO_H 0
+/* backtrace() from <execinfo.h> is really useful, but it is not signal safe
+ * everywhere, such as on x86-64.  */
+#if HAVE_BACKTRACE && !defined __x86_64__
+#  define USE_BACKTRACE 1
+#  include <execinfo.h>
+#else
+#  define USE_BACKTRACE 0
 #endif
 
 VLOG_DEFINE_THIS_MODULE(timeval);
@@ -72,6 +76,10 @@ static long long int deadline = LLONG_MAX;
 struct trace {
     void *backtrace[32]; /* Populated by backtrace(). */
     size_t n_frames;     /* Number of frames in 'backtrace'. */
+
+    /* format_backtraces() helper data. */
+    struct hmap_node node;
+    size_t count;
 };
 
 #define MAX_TRACES 50
@@ -92,6 +100,20 @@ static void timespec_add(struct timespec *sum,
                          const struct timespec *a, const struct timespec *b);
 static unixctl_cb_func backtrace_cb;
 
+#if !USE_BACKTRACE
+static int
+backtrace(void **buffer OVS_UNUSED, int size OVS_UNUSED)
+{
+    NOT_REACHED();
+}
+
+static char **
+backtrace_symbols(void *const *buffer OVS_UNUSED, int size OVS_UNUSED)
+{
+    NOT_REACHED();
+}
+#endif  /* !USE_BACKTRACE */
+
 /* Initializes the timetracking module, if not already initialized. */
 static void
 time_init(void)
@@ -103,9 +125,19 @@ time_init(void)
     }
     inited = true;
 
+    /* The implementation of backtrace() in glibc does some one time
+     * initialization which is not signal safe.  This can cause deadlocks if
+     * run from the signal handler.  As a workaround, force the initialization
+     * to happen here. */
+    if (USE_BACKTRACE) {
+        void *bt[1];
+
+        backtrace(bt, ARRAY_SIZE(bt));
+    }
+
     memset(traces, 0, sizeof traces);
 
-    if (HAVE_EXECINFO_H && CACHE_TIME) {
+    if (USE_BACKTRACE && CACHE_TIME) {
         unixctl_command_register("backtrace", "", 0, 0, backtrace_cb, NULL);
     }
 
@@ -136,35 +168,6 @@ set_up_signal(int flags)
     xsigaction(SIGALRM, &sa, NULL);
 }
 
-/* Remove SA_RESTART from the flags for SIGALRM, so that any system call that
- * is interrupted by the periodic timer interrupt will return EINTR instead of
- * continuing after the signal handler returns.
- *
- * time_disable_restart() and time_enable_restart() may be usefully wrapped
- * around function calls that might otherwise block forever unless interrupted
- * by a signal, e.g.:
- *
- *   time_disable_restart();
- *   fcntl(fd, F_SETLKW, &lock);
- *   time_enable_restart();
- */
-void
-time_disable_restart(void)
-{
-    time_init();
-    set_up_signal(0);
-}
-
-/* Add SA_RESTART to the flags for SIGALRM, so that any system call that
- * is interrupted by the periodic timer interrupt will continue after the
- * signal handler returns instead of returning EINTR. */
-void
-time_enable_restart(void)
-{
-    time_init();
-    set_up_signal(SA_RESTART);
-}
-
 static void
 set_up_timer(void)
 {
@@ -176,7 +179,7 @@ set_up_timer(void)
     }
 
     if (timer_create(monotonic_clock, NULL, &timer_id)) {
-        VLOG_FATAL("timer_create failed (%s)", strerror(errno));
+        VLOG_FATAL("timer_create failed (%s)", ovs_strerror(errno));
     }
 
     itimer.it_interval.tv_sec = 0;
@@ -184,7 +187,7 @@ set_up_timer(void)
     itimer.it_value = itimer.it_interval;
 
     if (timer_settime(timer_id, 0, &itimer, NULL)) {
-        VLOG_FATAL("timer_settime failed (%s)", strerror(errno));
+        VLOG_FATAL("timer_settime failed (%s)", ovs_strerror(errno));
     }
 }
 
@@ -295,17 +298,13 @@ time_alarm(unsigned int secs)
     long long int now;
     long long int msecs;
 
-    sigset_t oldsigs;
-
+    assert_single_threaded();
     time_init();
     time_refresh();
 
     now = time_msec();
-    msecs = secs * 1000;
-
-    block_sigalrm(&oldsigs);
+    msecs = secs * 1000LL;
     deadline = now < LLONG_MAX - msecs ? now + msecs : LLONG_MAX;
-    unblock_sigalrm(&oldsigs);
 }
 
 /* Like poll(), except:
@@ -392,15 +391,13 @@ sigalrm_handler(int sig_nr OVS_UNUSED)
     wall_tick = true;
     monotonic_tick = true;
 
-#if HAVE_EXECINFO_H
-    if (CACHE_TIME) {
+    if (USE_BACKTRACE && CACHE_TIME) {
         struct trace *trace = &traces[trace_head];
 
         trace->n_frames = backtrace(trace->backtrace,
                                     ARRAY_SIZE(trace->backtrace));
         trace_head = (trace_head + 1) % MAX_TRACES;
     }
-#endif
 }
 
 static void
@@ -425,13 +422,13 @@ block_sigalrm(sigset_t *oldsigs)
     sigset_t sigalrm;
     sigemptyset(&sigalrm);
     sigaddset(&sigalrm, SIGALRM);
-    xsigprocmask(SIG_BLOCK, &sigalrm, oldsigs);
+    xpthread_sigmask(SIG_BLOCK, &sigalrm, oldsigs);
 }
 
 static void
 unblock_sigalrm(const sigset_t *oldsigs)
 {
-    xsigprocmask(SIG_SETMASK, oldsigs, NULL);
+    xpthread_sigmask(SIG_SETMASK, oldsigs, NULL);
 }
 
 long long int
@@ -459,7 +456,7 @@ void
 xgettimeofday(struct timeval *tv)
 {
     if (gettimeofday(tv, NULL) == -1) {
-        VLOG_FATAL("gettimeofday failed (%s)", strerror(errno));
+        VLOG_FATAL("gettimeofday failed (%s)", ovs_strerror(errno));
     }
 }
 
@@ -491,7 +488,7 @@ log_poll_interval(long long int last_wakeup)
 {
     long long int interval = time_msec() - last_wakeup;
 
-    if (interval >= 1000) {
+    if (interval >= 1000 && !warp_offset.tv_sec && !warp_offset.tv_nsec) {
         const struct rusage *last_rusage = get_recent_rusage();
         struct rusage rusage;
 
@@ -577,13 +574,40 @@ get_cpu_usage(void)
     return cpu_usage;
 }
 
-static void
-format_backtraces(struct ds *ds)
+static uint32_t
+hash_trace(struct trace *trace)
+{
+    return hash_bytes(trace->backtrace,
+                      trace->n_frames * sizeof *trace->backtrace, 0);
+}
+
+static struct trace *
+trace_map_lookup(struct hmap *trace_map, struct trace *key)
+{
+    struct trace *value;
+
+    HMAP_FOR_EACH_WITH_HASH (value, node, hash_trace(key), trace_map) {
+        if (key->n_frames == value->n_frames
+            && !memcmp(key->backtrace, value->backtrace,
+                       key->n_frames * sizeof *key->backtrace)) {
+            return value;
+        }
+    }
+    return NULL;
+}
+
+/*  Appends a string to 'ds' representing backtraces recorded at regular
+ *  intervals in the recent past.  This information can be used to get a sense
+ *  of what the process has been spending the majority of time doing.  Will
+ *  ommit any backtraces which have not occurred at least 'min_count' times. */
+void
+format_backtraces(struct ds *ds, size_t min_count)
 {
     time_init();
 
-#if HAVE_EXECINFO_H
-    if (CACHE_TIME) {
+    if (USE_BACKTRACE && CACHE_TIME) {
+        struct hmap trace_map = HMAP_INITIALIZER(&trace_map);
+        struct trace *trace, *next;
         sigset_t oldsigs;
         size_t i;
 
@@ -591,16 +615,34 @@ format_backtraces(struct ds *ds)
 
         for (i = 0; i < MAX_TRACES; i++) {
             struct trace *trace = &traces[i];
+            struct trace *map_trace;
+
+            if (!trace->n_frames) {
+                continue;
+            }
+
+            map_trace = trace_map_lookup(&trace_map, trace);
+            if (map_trace) {
+                map_trace->count++;
+            } else {
+                hmap_insert(&trace_map, &trace->node, hash_trace(trace));
+                trace->count = 1;
+            }
+        }
+
+        HMAP_FOR_EACH_SAFE (trace, next, node, &trace_map) {
             char **frame_strs;
             size_t j;
 
-            if (!trace->n_frames) {
+            hmap_remove(&trace_map, &trace->node);
+
+            if (trace->count < min_count) {
                 continue;
             }
 
             frame_strs = backtrace_symbols(trace->backtrace, trace->n_frames);
 
-            ds_put_format(ds, "Backtrace %zu\n", i + 1);
+            ds_put_format(ds, "Count %zu\n", trace->count);
             for (j = 0; j < trace->n_frames; j++) {
                 ds_put_format(ds, "%s\n", frame_strs[j]);
             }
@@ -608,10 +650,11 @@ format_backtraces(struct ds *ds)
 
             free(frame_strs);
         }
+        hmap_destroy(&trace_map);
+
         ds_chomp(ds, '\n');
         unblock_sigalrm(&oldsigs);
     }
-#endif
 }
 \f
 /* Unixctl interface. */
@@ -659,8 +702,8 @@ backtrace_cb(struct unixctl_conn *conn,
 {
     struct ds ds = DS_EMPTY_INITIALIZER;
 
-    assert(HAVE_EXECINFO_H && CACHE_TIME);
-    format_backtraces(&ds);
+    ovs_assert(USE_BACKTRACE && CACHE_TIME);
+    format_backtraces(&ds, 0);
     unixctl_command_reply(conn, ds_cstr(&ds));
     ds_destroy(&ds);
 }