poll-loop: Make wakeup logging more portable and easier to understand.
[sliver-openvswitch.git] / lib / poll-loop.c
index e47cccc..c944477 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 <poll.h>
 #include <stdlib.h>
 #include <string.h>
-#include "backtrace.h"
 #include "coverage.h"
 #include "dynamic-string.h"
 #include "fatal-signal.h"
 #include "list.h"
+#include "socket-util.h"
 #include "timeval.h"
 #include "vlog.h"
 
+#undef poll_fd_wait
+#undef poll_timer_wait
+#undef poll_timer_wait_until
+#undef poll_immediate_wake
+
 VLOG_DEFINE_THIS_MODULE(poll_loop);
 
 COVERAGE_DEFINE(poll_fd_wait);
@@ -41,7 +46,7 @@ struct poll_waiter {
     struct list node;           /* Element in global waiters list. */
     int fd;                     /* File descriptor. */
     short int events;           /* Events to wait for (POLLIN, POLLOUT). */
-    struct backtrace *backtrace; /* Optionally, event that created waiter. */
+    const char *where;          /* Where the waiter was created. */
 
     /* Set only when poll_block() is called. */
     struct pollfd *pollfd;      /* Pointer to element of the pollfds array. */
@@ -57,10 +62,11 @@ static size_t n_waiters;
  * wait forever. */
 static int timeout = -1;
 
-/* Backtrace of 'timeout''s registration, if debugging is enabled. */
-static struct backtrace timeout_backtrace;
+/* Location where waiter created. */
+static const char *timeout_where;
 
-static struct poll_waiter *new_waiter(int fd, short int events);
+static struct poll_waiter *new_waiter(int fd, short int events,
+                                      const char *where);
 
 /* Registers 'fd' as waiting for the specified 'events' (which should be POLLIN
  * or POLLOUT or POLLIN | POLLOUT).  The following call to poll_block() will
@@ -68,23 +74,24 @@ static struct poll_waiter *new_waiter(int fd, short int events);
  *
  * The event registration is one-shot: only the following call to poll_block()
  * is affected.  The event will need to be re-registered after poll_block() is
- * called if it is to persist. */
+ * called if it is to persist.
+ *
+ * Ordinarily the 'where' argument is supplied automatically; see poll-loop.h
+ * for more information. */
 struct poll_waiter *
-poll_fd_wait(int fd, short int events)
+poll_fd_wait(int fd, short int events, const char *where)
 {
     COVERAGE_INC(poll_fd_wait);
-    return new_waiter(fd, events);
+    return new_waiter(fd, events, where);
 }
 
 /* The caller must ensure that 'msec' is not negative. */
 static void
-poll_timer_wait__(int msec)
+poll_timer_wait__(int msec, const char *where)
 {
     if (timeout < 0 || msec < timeout) {
         timeout = msec;
-        if (VLOG_IS_DBG_ENABLED()) {
-            backtrace_capture(&timeout_backtrace);
-        }
+        timeout_where = where;
     }
 }
 
@@ -94,13 +101,17 @@ poll_timer_wait__(int msec)
  *
  * The timer registration is one-shot: only the following call to poll_block()
  * is affected.  The timer will need to be re-registered after poll_block() is
- * called if it is to persist. */
+ * called if it is to persist.
+ *
+ * Ordinarily the 'where' argument is supplied automatically; see poll-loop.h
+ * for more information. */
 void
-poll_timer_wait(long long int msec)
+poll_timer_wait(long long int msec, const char *where)
 {
-    poll_timer_wait__(msec < 0 ? 0
-                      : msec > INT_MAX ? INT_MAX
-                      : msec);
+    poll_timer_wait__((msec < 0 ? 0
+                       : msec > INT_MAX ? INT_MAX
+                       : msec),
+                      where);
 }
 
 /* Causes the following call to poll_block() to wake up when the current time,
@@ -110,26 +121,33 @@ poll_timer_wait(long long int msec)
  *
  * The timer registration is one-shot: only the following call to poll_block()
  * is affected.  The timer will need to be re-registered after poll_block() is
- * called if it is to persist. */
+ * called if it is to persist.
+ *
+ * Ordinarily the 'where' argument is supplied automatically; see poll-loop.h
+ * for more information. */
 void
-poll_timer_wait_until(long long int msec)
+poll_timer_wait_until(long long int msec, const char *where)
 {
     long long int now = time_msec();
-    poll_timer_wait__(msec <= now ? 0
-                      : msec < now + INT_MAX ? msec - now
-                      : INT_MAX);
+    poll_timer_wait__((msec <= now ? 0
+                       : msec < now + INT_MAX ? msec - now
+                       : INT_MAX),
+                      where);
 }
 
 /* Causes the following call to poll_block() to wake up immediately, without
- * blocking. */
+ * blocking.
+ *
+ * Ordinarily the 'where' argument is supplied automatically; see poll-loop.h
+ * for more information. */
 void
-poll_immediate_wake(void)
+poll_immediate_wake(const char *where)
 {
-    poll_timer_wait(0);
+    poll_timer_wait(0, where);
 }
 
 static void PRINTF_FORMAT(2, 3)
-log_wakeup(const struct backtrace *backtrace, const char *format, ...)
+log_wakeup(const char *where, const char *format, ...)
 {
     struct ds ds;
     va_list args;
@@ -139,14 +157,10 @@ log_wakeup(const struct backtrace *backtrace, const char *format, ...)
     ds_put_format_valist(&ds, format, args);
     va_end(args);
 
-    if (backtrace) {
-        int i;
-
-        ds_put_char(&ds, ':');
-        for (i = 0; i < backtrace->n_frames; i++) {
-            ds_put_format(&ds, " 0x%"PRIxPTR, backtrace->frames[i]);
-        }
+    if (where) {
+        ds_put_format(&ds, " at %s", where);
     }
+
     VLOG_DBG("%s", ds_cstr(&ds));
     ds_destroy(&ds);
 }
@@ -190,24 +204,26 @@ poll_block(void)
         static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 5);
         VLOG_ERR_RL(&rl, "poll: %s", strerror(-retval));
     } else if (!retval && VLOG_IS_DBG_ENABLED()) {
-        log_wakeup(&timeout_backtrace, "%d-ms timeout", timeout);
+        log_wakeup(timeout_where, "%d-ms timeout", timeout);
     }
 
     LIST_FOR_EACH_SAFE (pw, next, node, &waiters) {
         if (pw->pollfd->revents && VLOG_IS_DBG_ENABLED()) {
-            log_wakeup(pw->backtrace, "%s%s%s%s%s on fd %d",
+            char *description = describe_fd(pw->fd);
+            log_wakeup(pw->where, "%s%s%s%s%s on fd %d (%s)",
                        pw->pollfd->revents & POLLIN ? "[POLLIN]" : "",
                        pw->pollfd->revents & POLLOUT ? "[POLLOUT]" : "",
                        pw->pollfd->revents & POLLERR ? "[POLLERR]" : "",
                        pw->pollfd->revents & POLLHUP ? "[POLLHUP]" : "",
                        pw->pollfd->revents & POLLNVAL ? "[POLLNVAL]" : "",
-                       pw->fd);
+                       pw->fd, description);
+            free(description);
         }
         poll_cancel(pw);
     }
 
     timeout = -1;
-    timeout_backtrace.n_frames = 0;
+    timeout_where = NULL;
 
     /* Handle any pending signals before doing anything else. */
     fatal_signal_run();
@@ -224,7 +240,6 @@ poll_cancel(struct poll_waiter *pw)
 {
     if (pw) {
         list_remove(&pw->node);
-        free(pw->backtrace);
         free(pw);
         n_waiters--;
     }
@@ -232,16 +247,13 @@ poll_cancel(struct poll_waiter *pw)
 \f
 /* Creates and returns a new poll_waiter for 'fd' and 'events'. */
 static struct poll_waiter *
-new_waiter(int fd, short int events)
+new_waiter(int fd, short int events, const char *where)
 {
     struct poll_waiter *waiter = xzalloc(sizeof *waiter);
     assert(fd >= 0);
     waiter->fd = fd;
     waiter->events = events;
-    if (VLOG_IS_DBG_ENABLED()) {
-        waiter->backtrace = xmalloc(sizeof *waiter->backtrace);
-        backtrace_capture(waiter->backtrace);
-    }
+    waiter->where = where;
     list_push_back(&waiters, &waiter->node);
     n_waiters++;
     return waiter;