Diagnose attempts to connect the wrong protocol to a network port.

Sometimes, when a user asks me to help debug a problem, it turns out that
an SSL connection was being made on a TCP port, or vice versa, or that an
OpenFlow connection was being made on a JSON-RPC port, or vice versa, and
so on.  This commit adds log messages that diagnose this kind of problem,
e.g. "tcp:127.0.0.1:6633: received JSON-RPC data on OpenFlow channel".

diff --git a/lib/jsonrpc.c b/lib/jsonrpc.c
index 828bdac21a90e6eebe8b9ac62c3fb72fd42ca1f4..bb4f6baf35449b1cf6606218b063704efb9d73f2 100644 (file)
--- a/lib/jsonrpc.c
+++ b/lib/jsonrpc.c
@@ -267,6 +267,12 @@ jsonrpc_recv(struct jsonrpc *rpc, struct jsonrpc_msg **msgp)
             if (json_parser_is_done(rpc->parser)) {
                 jsonrpc_received(rpc);
                 if (rpc->status) {
+                    const struct byteq *q = &rpc->input;
+                    if (q->head <= BYTEQ_SIZE) {
+                        stream_report_content(q->buffer, q->head,
+                                              STREAM_JSONRPC,
+                                              THIS_MODULE, rpc->name);
+                    }
                     return rpc->status;
                 }
             }

diff --git a/lib/stream-ssl.c b/lib/stream-ssl.c
index 27c9d4c92de6a440df9e41e8ada5978953f4a992..462ac4283e0be928023c669c1a6075840a22c58a 100644 (file)
--- a/lib/stream-ssl.c
+++ b/lib/stream-ssl.c
@@ -124,6 +124,10 @@ struct ssl_stream
      * deadlock and livelock situations above.
      */
     int rx_want, tx_want;
+
+    /* A few bytes of header data in case SSL negotation fails. */
+    uint8_t head[2];
+    short int n_head;
 };
 
 /* SSL context created by ssl_init(). */
@@ -264,6 +268,7 @@ new_ssl_stream(const char *name, int fd, enum session_type type,
     sslv->ssl = ssl;
     sslv->txbuf = NULL;
     sslv->rx_want = sslv->tx_want = SSL_NOTHING;
+    sslv->n_head = 0;
     *streamp = &sslv->stream;
     return 0;
 
@@ -414,6 +419,13 @@ ssl_connect(struct stream *stream)
         /* Fall through. */
 
     case STATE_SSL_CONNECTING:
+        /* Capture the first few bytes of received data so that we can guess
+         * what kind of funny data we've been sent if SSL negotation fails. */
+        if (sslv->n_head <= 0) {
+            sslv->n_head = recv(sslv->fd, sslv->head, sizeof sslv->head,
+                                MSG_PEEK);
+        }
+
         retval = (sslv->type == CLIENT
                    ? SSL_connect(sslv->ssl) : SSL_accept(sslv->ssl));
         if (retval != 1) {
@@ -425,6 +437,8 @@ ssl_connect(struct stream *stream)
                 interpret_ssl_error((sslv->type == CLIENT ? "SSL_connect"
                                      : "SSL_accept"), retval, error, &unused);
                 shutdown(sslv->fd, SHUT_RDWR);
+                stream_report_content(sslv->head, sslv->n_head, STREAM_SSL,
+                                      THIS_MODULE, stream_get_name(stream));
                 return EPROTO;
             }
         } else if (bootstrap_ca_cert) {

diff --git a/lib/stream.c b/lib/stream.c
index 43b73af0adf9f7f542019a031e57b3515a799298..667a23ff370facf6d8266aa976afc993bd992d6b 100644 (file)
--- a/lib/stream.c
+++ b/lib/stream.c
@@ -718,5 +718,66 @@ pstream_open_with_default_ports(const char *name_,
 
     return error;
 }
+\f
+/* Attempts to guess the content type of a stream whose first few bytes were
+ * the 'size' bytes of 'data'. */
+static enum stream_content_type
+stream_guess_content(const uint8_t *data, size_t size)
+{
+    if (size >= 2) {
+#define PAIR(A, B) (((A) << 8) | (B))
+        switch (PAIR(data[0], data[1])) {
+        case PAIR(0x16, 0x03):  /* Handshake, version 3. */
+            return STREAM_SSL;
+        case PAIR('{', '"'):
+            return STREAM_JSONRPC;
+        case PAIR(OFP_VERSION, OFPT_HELLO):
+            return STREAM_OPENFLOW;
+        }
+    }
+
+    return STREAM_UNKNOWN;
+}
+
+/* Returns a string represenation of 'type'. */
+static const char *
+stream_content_type_to_string(enum stream_content_type type)
+{
+    switch (type) {
+    case STREAM_UNKNOWN:
+    default:
+        return "unknown";
 
+    case STREAM_JSONRPC:
+        return "JSON-RPC";
 
+    case STREAM_OPENFLOW:
+        return "OpenFlow";
+
+    case STREAM_SSL:
+        return "SSL";
+    }
+}
+
+/* Attempts to guess the content type of a stream whose first few bytes were
+ * the 'size' bytes of 'data'.  If this is done successfully, and the guessed
+ * content type is other than 'expected_type', then log a message in vlog
+ * module 'module', naming 'stream_name' as the source, explaining what
+ * content was expected and what was actually received. */
+void
+stream_report_content(const void *data, size_t size,
+                      enum stream_content_type expected_type,
+                      enum vlog_module module, const char *stream_name)
+{
+    static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(5, 5);
+    enum stream_content_type actual_type;
+
+    actual_type = stream_guess_content(data, size);
+    if (actual_type != expected_type && actual_type != STREAM_UNKNOWN) {
+        vlog_rate_limit(module, VLL_WARN, &rl,
+                        "%s: received %s data on %s channel",
+                        stream_name,
+                        stream_content_type_to_string(expected_type),
+                        stream_content_type_to_string(actual_type));
+    }
+}

diff --git a/lib/stream.h b/lib/stream.h
index d8b0814663db00b49eb0d246e2d016f3904bf4bf..256667e6852039e057dc0cc33a96b1048a658914 100644 (file)
--- a/lib/stream.h
+++ b/lib/stream.h
@@ -20,6 +20,7 @@
 #include <stdbool.h>
 #include <stddef.h>
 #include <stdint.h>
+#include "vlog.h"
 
 struct pstream;
 struct stream;
@@ -72,5 +73,17 @@ int pstream_open_with_default_ports(const char *name,
                                     uint16_t default_ptcp_port,
                                     uint16_t default_pssl_port,
                                     struct pstream **);
+\f
+/* Error reporting. */
+
+enum stream_content_type {
+    STREAM_UNKNOWN,
+    STREAM_OPENFLOW,
+    STREAM_SSL,
+    STREAM_JSONRPC
+};
+
+void stream_report_content(const void *, size_t, enum stream_content_type,
+                           enum vlog_module, const char *stream_name);
 
 #endif /* stream.h */

diff --git a/lib/vconn-stream.c b/lib/vconn-stream.c
index 0a721d97a1aa3de9ceac388fb98eefd3da208862..3d0887463ac87d8854a3342e857d74970425a22c 100644 (file)
--- a/lib/vconn-stream.c
+++ b/lib/vconn-stream.c
@@ -44,6 +44,7 @@ struct vconn_stream
     struct stream *stream;
     struct ofpbuf *rxbuf;
     struct ofpbuf *txbuf;
+    int n_packets;
 };
 
 static struct vconn_class stream_vconn_class;
@@ -63,6 +64,7 @@ vconn_stream_new(struct stream *stream, int connect_status)
     s->stream = stream;
     s->txbuf = NULL;
     s->rxbuf = NULL;
+    s->n_packets = 0;
     s->vconn.remote_ip = stream_get_remote_ip(stream);
     s->vconn.remote_port = stream_get_remote_port(stream);
     s->vconn.local_ip = stream_get_local_ip(stream);
@@ -102,6 +104,12 @@ static void
 vconn_stream_close(struct vconn *vconn)
 {
     struct vconn_stream *s = vconn_stream_cast(vconn);
+
+    if ((vconn->error == EPROTO || s->n_packets < 1) && s->rxbuf) {
+        stream_report_content(s->rxbuf->data, s->rxbuf->size, STREAM_OPENFLOW,
+                              THIS_MODULE, vconn_get_name(vconn));
+    }
+
     stream_close(s->stream);
     vconn_stream_clear_txbuf(s);
     ofpbuf_delete(s->rxbuf);
@@ -172,6 +180,7 @@ vconn_stream_recv(struct vconn *vconn, struct ofpbuf **bufferp)
         }
     }
 
+    s->n_packets++;
     *bufferp = s->rxbuf;
     s->rxbuf = NULL;
     return 0;