[ovs-dev] [error reporting 3/6] ofproto: Consistently log OpenFlow error replies.

[Ben Pfaff]

Until now, logging of OpenFlow error replies sent to controllers has been
haphazard.  This commit logs them centrally, ensuring that every OpenFlow
error sent to a controller is logged.

At the same time, we can eliminate the individual log messages that a few
OpenFlow errors triggered.
---
 ofproto/connmgr.c |   24 +++++++++++++++++++++++-
 ofproto/ofproto.c |   24 +++++-------------------
 2 files changed, 28 insertions(+), 20 deletions(-)

diff --git a/ofproto/connmgr.c b/ofproto/connmgr.c
index 2d0b8c5..6432ba6 100644
--- a/ofproto/connmgr.c
+++ b/ofproto/connmgr.c
@@ -828,8 +828,30 @@ void
 ofconn_send_error(const struct ofconn *ofconn,
                   const struct ofp_header *request, int error)
 {
-    struct ofpbuf *msg = ofputil_encode_error_msg(error, request);
+    struct ofpbuf *msg;
+
+    msg = ofputil_encode_error_msg(error, request);
     if (msg) {
+        static struct vlog_rate_limit err_rl = VLOG_RATE_LIMIT_INIT(10, 10);
+
+        if (!VLOG_DROP_INFO(&err_rl)) {
+            const struct ofputil_msg_type *type;
+            const char *type_name;
+            size_t request_len;
+            char *error_s;
+
+            request_len = ntohs(request->length);
+            type_name = (!ofputil_decode_msg_type_partial(request,
+                                                          MIN(64, request_len),
+                                                          &type)
+                         ? ofputil_msg_type_name(type)
+                         : "invalid");
+
+            error_s = ofputil_error_to_string(error);
+            VLOG_INFO("%s: sending %s error reply to %s message",
+                      rconn_get_name(ofconn->rconn), error_s, type_name);
+            free(error_s);
+        }
         ofconn_send_reply(ofconn, msg);
     }
 }
diff --git a/ofproto/ofproto.c b/ofproto/ofproto.c
index 090d4d3..76feb91 100644
--- a/ofproto/ofproto.c
+++ b/ofproto/ofproto.c
@@ -1553,18 +1553,12 @@ handle_set_config(struct ofconn *ofconn, const struct ofp_switch_config *osc)
 
 /* Checks whether 'ofconn' is a slave controller.  If so, returns an OpenFlow
  * error message code (composed with ofp_mkerr()) for the caller to propagate
- * upward.  Otherwise, returns 0.
- *
- * The log message mentions 'msg_type'. */
+ * upward.  Otherwise, returns 0. */
 static int
-reject_slave_controller(struct ofconn *ofconn, const char *msg_type)
+reject_slave_controller(const struct ofconn *ofconn)
 {
     if (ofconn_get_type(ofconn) == OFCONN_PRIMARY
         && ofconn_get_role(ofconn) == NX_ROLE_SLAVE) {
-        static struct vlog_rate_limit perm_rl = VLOG_RATE_LIMIT_INIT(1, 5);
-        VLOG_WARN_RL(&perm_rl, "rejecting %s message from slave controller",
-                     msg_type);
-
         return ofp_mkerr(OFPET_BAD_REQUEST, OFPBRC_EPERM);
     } else {
         return 0;
@@ -1585,7 +1579,7 @@ handle_packet_out(struct ofconn *ofconn, const struct ofp_header *oh)
 
     COVERAGE_INC(ofproto_packet_out);
 
-    error = reject_slave_controller(ofconn, "OFPT_PACKET_OUT");
+    error = reject_slave_controller(ofconn);
     if (error) {
         return error;
     }
@@ -1653,7 +1647,7 @@ handle_port_mod(struct ofconn *ofconn, const struct ofp_header *oh)
     struct ofport *port;
     int error;
 
-    error = reject_slave_controller(ofconn, "OFPT_PORT_MOD");
+    error = reject_slave_controller(ofconn);
     if (error) {
         return error;
     }
@@ -2450,7 +2444,7 @@ handle_flow_mod(struct ofconn *ofconn, const struct ofp_header *oh)
     struct ofputil_flow_mod fm;
     int error;
 
-    error = reject_slave_controller(ofconn, "flow_mod");
+    error = reject_slave_controller(ofconn);
     if (error) {
         return error;
     }
@@ -2507,15 +2501,12 @@ handle_role_request(struct ofconn *ofconn, const struct ofp_header *oh)
     uint32_t role;
 
     if (ofconn_get_type(ofconn) != OFCONN_PRIMARY) {
-        VLOG_WARN_RL(&rl, "ignoring role request on service connection");
         return ofp_mkerr(OFPET_BAD_REQUEST, OFPBRC_EPERM);
     }
 
     role = ntohl(nrr->role);
     if (role != NX_ROLE_OTHER && role != NX_ROLE_MASTER
         && role != NX_ROLE_SLAVE) {
-        VLOG_WARN_RL(&rl, "received request for unknown role %"PRIu32, role);
-
         /* There's no good error code for this. */
         return ofp_mkerr(OFPET_BAD_REQUEST, -1);
     }
@@ -2680,11 +2671,6 @@ handle_openflow__(struct ofconn *ofconn, const struct ofpbuf *msg)
     case OFPUTIL_NXST_FLOW_REPLY:
     case OFPUTIL_NXST_AGGREGATE_REPLY:
     default:
-        if (VLOG_IS_WARN_ENABLED()) {
-            char *s = ofp_to_string(oh, ntohs(oh->length), 2);
-            VLOG_DBG_RL(&rl, "OpenFlow message ignored: %s", s);
-            free(s);
-        }
         if (oh->type == OFPT_STATS_REQUEST || oh->type == OFPT_STATS_REPLY) {
             return ofp_mkerr(OFPET_BAD_REQUEST, OFPBRC_BAD_STAT);
         } else {
-- 
1.7.4.4