ofproto: Make OpenFlow connection log messages name the datapath.

Until now, log messages about OpenFlow connections have named the target
of the connection, e.g. "tcp:1.2.3.4:5555", but they have not named the
datapath.  Most often, every datapath has the same target, so this can
make it difficult to tell which connection is going wrong.  Usually, that
isn't important, because all connections with the same target will have the
same problems, but it's probably better to be more informative.

This commit changes the log messages to include the datapath name, so that
"tcp:1.2.3.4:5555" becomes, e.g., "xenbr0<->tcp:1.2.3.4:5555".

Requested-by: Keith Amidon <keith@nicira.com>

diff --git a/extras/ezio/ovs-switchui.c b/extras/ezio/ovs-switchui.c
index a1adcc5..af74af5 100644 (file)
--- a/extras/ezio/ovs-switchui.c
+++ b/extras/ezio/ovs-switchui.c
@@ -161,7 +161,7 @@ main(int argc, char *argv[])
     }
 
     rconn = rconn_create(5, 5);
-    rconn_connect(rconn, argv[0]);
+    rconn_connect(rconn, argv[0], NULL);
 
     die_if_already_running();
     daemonize();

diff --git a/lib/rconn.c b/lib/rconn.c
index 62159c3..01673e9 100644 (file)
--- a/lib/rconn.c
+++ b/lib/rconn.c
@@ -64,7 +64,8 @@ struct rconn {
     time_t state_entered;
 
     struct vconn *vconn;
-    char *name;
+    char *name;                 /* Human-readable descriptive name. */
+    char *target;               /* vconn name, passed to vconn_open(). */
     bool reliable;
 
     struct ovs_queue txq;
@@ -134,7 +135,8 @@ static unsigned int elapsed_in_this_state(const struct rconn *);
 static unsigned int timeout(const struct rconn *);
 static bool timed_out(const struct rconn *);
 static void state_transition(struct rconn *, enum state);
-static void set_vconn_name(struct rconn *, const char *name);
+static void rconn_set_target__(struct rconn *,
+                               const char *target, const char *name);
 static int try_send(struct rconn *);
 static void reconnect(struct rconn *);
 static void report_error(struct rconn *, int error);
@@ -170,6 +172,7 @@ rconn_create(int probe_interval, int max_backoff)
 
     rc->vconn = NULL;
     rc->name = xstrdup("void");
+    rc->target = xstrdup("void");
     rc->reliable = false;
 
     queue_init(&rc->txq);
@@ -232,21 +235,37 @@ rconn_get_probe_interval(const struct rconn *rc)
     return rc->probe_interval;
 }
 
+/* Drops any existing connection on 'rc', then sets up 'rc' to connect to
+ * 'target' and reconnect as needed.  'target' should be a remote OpenFlow
+ * target in a form acceptable to vconn_open().
+ *
+ * If 'name' is nonnull, then it is used in log messages in place of 'target'.
+ * It should presumably give more information to a human reader than 'target',
+ * but it need not be acceptable to vconn_open(). */
 void
-rconn_connect(struct rconn *rc, const char *name)
+rconn_connect(struct rconn *rc, const char *target, const char *name)
 {
     rconn_disconnect(rc);
-    set_vconn_name(rc, name);
+    rconn_set_target__(rc, target, name);
     rc->reliable = true;
     reconnect(rc);
 }
 
+/* Drops any existing connection on 'rc', then configures 'rc' to use
+ * 'vconn'.  If the connection on 'vconn' drops, 'rc' will not reconnect on it
+ * own.
+ *
+ * By default, the target obtained from vconn_get_name(vconn) is used in log
+ * messages.  If 'name' is nonnull, then it is used instead.  It should
+ * presumably give more information to a human reader than the target, but it
+ * need not be acceptable to vconn_open(). */
 void
-rconn_connect_unreliably(struct rconn *rc, struct vconn *vconn)
+rconn_connect_unreliably(struct rconn *rc,
+                         struct vconn *vconn, const char *name)
 {
     assert(vconn != NULL);
     rconn_disconnect(rc);
-    set_vconn_name(rc, vconn_get_name(vconn));
+    rconn_set_target__(rc, vconn_get_name(vconn), name);
     rc->reliable = false;
     rc->vconn = vconn;
     rc->last_connected = time_now();
@@ -271,7 +290,7 @@ rconn_disconnect(struct rconn *rc)
             vconn_close(rc->vconn);
             rc->vconn = NULL;
         }
-        set_vconn_name(rc, "void");
+        rconn_set_target__(rc, "void", NULL);
         rc->reliable = false;
 
         rc->backoff = 0;
@@ -289,6 +308,7 @@ rconn_destroy(struct rconn *rc)
         size_t i;
 
         free(rc->name);
+        free(rc->target);
         vconn_close(rc->vconn);
         flush_queue(rc);
         queue_destroy(&rc->txq);
@@ -318,7 +338,7 @@ reconnect(struct rconn *rc)
 
     VLOG_INFO("%s: connecting...", rc->name);
     rc->n_attempted_connections++;
-    retval = vconn_open(rc->name, OFP_VERSION, &rc->vconn);
+    retval = vconn_open(rc->target, OFP_VERSION, &rc->vconn);
     if (!retval) {
         rc->remote_ip = vconn_get_remote_ip(rc->vconn);
         rc->local_ip = vconn_get_local_ip(rc->vconn);
@@ -620,13 +640,31 @@ rconn_add_monitor(struct rconn *rc, struct vconn *vconn)
     }
 }
 
-/* Returns 'rc''s name (the 'name' argument passed to rconn_new()). */
+/* Returns 'rc''s name.  This is a name for human consumption, appropriate for
+ * use in log messages.  It is not necessarily a name that may be passed
+ * directly to, e.g., vconn_open(). */
 const char *
 rconn_get_name(const struct rconn *rc)
 {
     return rc->name;
 }
 
+/* Sets 'rc''s name to 'new_name'. */
+void
+rconn_set_name(struct rconn *rc, const char *new_name)
+{
+    free(rc->name);
+    rc->name = xstrdup(new_name);
+}
+
+/* Returns 'rc''s target.  This is intended to be a string that may be passed
+ * directly to, e.g., vconn_open(). */
+const char *
+rconn_get_target(const struct rconn *rc)
+{
+    return rc->target;
+}
+
 /* Returns true if 'rconn' is connected or in the process of reconnecting,
  * false if 'rconn' is disconnected and will not reconnect on its own. */
 bool
@@ -846,14 +884,18 @@ rconn_packet_counter_dec(struct rconn_packet_counter *c)
     }
 }
 \f
-/* Set the name of the remote vconn to 'name' and clear out the cached IP
- * address and port information, since changing the name also likely changes
- * these values. */
+/* Set rc->target and rc->name to 'target' and 'name', respectively.  If 'name'
+ * is null, 'target' is used.
+ *
+ * Also, clear out the cached IP address and port information, since changing
+ * the target also likely changes these values. */
 static void
-set_vconn_name(struct rconn *rc, const char *name)
+rconn_set_target__(struct rconn *rc, const char *target, const char *name)
 {
     free(rc->name);
-    rc->name = xstrdup(name);
+    rc->name = xstrdup(name ? name : target);
+    free(rc->target);
+    rc->target = xstrdup(target);
     rc->local_ip = 0;
     rc->remote_ip = 0;
     rc->remote_port = 0;

diff --git a/lib/rconn.h b/lib/rconn.h
index d1ae5db..4df2f34 100644 (file)
--- a/lib/rconn.h
+++ b/lib/rconn.h
@@ -44,8 +44,9 @@ int rconn_get_max_backoff(const struct rconn *);
 void rconn_set_probe_interval(struct rconn *, int inactivity_probe_interval);
 int rconn_get_probe_interval(const struct rconn *);
 
-void rconn_connect(struct rconn *, const char *name);
-void rconn_connect_unreliably(struct rconn *, struct vconn *vconn);
+void rconn_connect(struct rconn *, const char *target, const char *name);
+void rconn_connect_unreliably(struct rconn *,
+                              struct vconn *, const char *name);
 void rconn_reconnect(struct rconn *);
 void rconn_disconnect(struct rconn *);
 void rconn_destroy(struct rconn *);
@@ -63,6 +64,9 @@ unsigned int rconn_packets_received(const struct rconn *);
 void rconn_add_monitor(struct rconn *, struct vconn *);
 
 const char *rconn_get_name(const struct rconn *);
+void rconn_set_name(struct rconn *, const char *new_name);
+const char *rconn_get_target(const struct rconn *);
+
 bool rconn_is_alive(const struct rconn *);
 bool rconn_is_connected(const struct rconn *);
 bool rconn_is_admitted(const struct rconn *);

diff --git a/ofproto/ofproto.c b/ofproto/ofproto.c
index bf5081b..050b4df 100644 (file)
--- a/ofproto/ofproto.c
+++ b/ofproto/ofproto.c
@@ -225,6 +225,7 @@ static void ofconn_destroy(struct ofconn *);
 static void ofconn_run(struct ofconn *, struct ofproto *);
 static void ofconn_wait(struct ofconn *);
 static bool ofconn_receives_async_msgs(const struct ofconn *);
+static char *ofconn_make_name(const struct ofproto *, const char *target);
 
 static void queue_tx(struct ofpbuf *msg, const struct ofconn *ofconn,
                      struct rconn_packet_counter *counter);
@@ -459,7 +460,9 @@ add_controller(struct ofproto *ofproto, const struct ofproto_controller *c)
     if (discovery) {
         ofconn->discovery = discovery;
     } else {
-        rconn_connect(ofconn->rconn, c->target);
+        char *name = ofconn_make_name(ofproto, c->target);
+        rconn_connect(ofconn->rconn, c->target, name);
+        free(name);
     }
     hmap_insert(&ofproto->controllers, &ofconn->hmap_node,
                 hash_string(c->target, 0));
@@ -510,7 +513,7 @@ update_controller(struct ofconn *ofconn, const struct ofproto_controller *c)
 static const char *
 ofconn_get_target(const struct ofconn *ofconn)
 {
-    return ofconn->discovery ? "discover" : rconn_get_name(ofconn->rconn);
+    return ofconn->discovery ? "discover" : rconn_get_target(ofconn->rconn);
 }
 
 static struct ofconn *
@@ -1079,9 +1082,13 @@ ofproto_run1(struct ofproto *p)
         retval = pvconn_accept(p->listeners[i], OFP_VERSION, &vconn);
         if (!retval) {
             struct rconn *rconn;
+            char *name;
 
             rconn = rconn_create(60, 0);
-            rconn_connect_unreliably(rconn, vconn);
+            name = ofconn_make_name(p, vconn_get_name(vconn));
+            rconn_connect_unreliably(rconn, vconn, name);
+            free(name);
+
             ofconn_create(p, rconn, OFCONN_TRANSIENT);
         } else if (retval != EAGAIN) {
             VLOG_WARN_RL(&rl, "accept failed (%s)", strerror(retval));
@@ -1632,7 +1639,9 @@ ofconn_run(struct ofconn *ofconn, struct ofproto *p)
         }
         if (discovery_run(ofconn->discovery, &controller_name)) {
             if (controller_name) {
-                rconn_connect(ofconn->rconn, controller_name);
+                char *ofconn_name = ofconn_make_name(p, controller_name);
+                rconn_connect(ofconn->rconn, controller_name, ofconn_name);
+                free(ofconn_name);
             } else {
                 rconn_disconnect(ofconn->rconn);
             }
@@ -1700,6 +1709,18 @@ ofconn_receives_async_msgs(const struct ofconn *ofconn)
         return ofconn->miss_send_len > 0;
     }
 }
+
+/* Returns a human-readable name for an OpenFlow connection between 'ofproto'
+ * and 'target', suitable for use in log messages for identifying the
+ * connection.
+ *
+ * The name is dynamically allocated.  The caller should free it (with free())
+ * when it is no longer needed. */
+static char *
+ofconn_make_name(const struct ofproto *ofproto, const char *target)
+{
+    return xasprintf("%s<->%s", dpif_base_name(ofproto->dpif), target);
+}
 \f
 /* Caller is responsible for initializing the 'cr' member of the returned
  * rule. */

diff --git a/ofproto/status.c b/ofproto/status.c
index 133bde0..7fe2378 100644 (file)
--- a/ofproto/status.c
+++ b/ofproto/status.c
@@ -97,7 +97,7 @@ rconn_status_cb(struct status_reply *sr, void *rconn_)
     uint32_t remote_ip = rconn_get_remote_ip(rconn);
     uint32_t local_ip = rconn_get_local_ip(rconn);
 
-    status_reply_put(sr, "name=%s", rconn_get_name(rconn));
+    status_reply_put(sr, "name=%s", rconn_get_target(rconn));
     if (remote_ip) {
         status_reply_put(sr, "remote-ip="IP_FMT, IP_ARGS(&remote_ip));
         status_reply_put(sr, "remote-port=%d", 

diff --git a/utilities/ovs-controller.c b/utilities/ovs-controller.c
index 8de3400..f4358e9 100644 (file)
--- a/utilities/ovs-controller.c
+++ b/utilities/ovs-controller.c
@@ -211,7 +211,7 @@ static void
 new_switch(struct switch_ *sw, struct vconn *vconn)
 {
     sw->rconn = rconn_create(60, 0);
-    rconn_connect_unreliably(sw->rconn, vconn);
+    rconn_connect_unreliably(sw->rconn, vconn, NULL);
     sw->lswitch = lswitch_create(sw->rconn, learn_macs, exact_flows,
                                  set_up_flows ? max_idle : -1,
                                  action_normal);