On 12/8/21 5:26 PM, Ilya Maximets wrote:
On 12/8/21 15:11, Mohammad Heib wrote:
On 12/6/21 4:08 PM, Ilya Maximets wrote:
On 12/6/21 15:01, Ilya Maximets wrote:
On 12/6/21 14:35, Ilya Maximets wrote:
On 12/6/21 10:09, Mohammad Heib wrote:
Improve packet-in debuggability within pinctrl module
by printing basic details about each received packet-in
message, those messages will be printed to the logs only
when DBG log level is enabled.

Also, add two coverage counters that will indicate the total
packet-in messages that were received and the number of times
that the pinctrl main thread was notified to handle a change
in the local DBs, those counters can be used by the user as
an indicator to enable the DBG logs level and see more details
about the received packet-in in the logs.

Reported-at: https://bugzilla.redhat.com/show_bug.cgi?id=1821965
Signed-off-by: Mohammad Heib <[email protected]>
---
  controller/pinctrl.c  |  39 ++++++++++++++
  include/ovn/actions.h |   1 +
  lib/actions.c         | 123 ++++++++++++++++++++++++++++++++++++++++++
  tests/ovn.at          |   8 +++
  4 files changed, 171 insertions(+)

diff --git a/controller/pinctrl.c b/controller/pinctrl.c
index 0d443c150..4ce16ac74 100644
--- a/controller/pinctrl.c
+++ b/controller/pinctrl.c
@@ -364,6 +364,8 @@ COVERAGE_DEFINE(pinctrl_drop_put_mac_binding);
  COVERAGE_DEFINE(pinctrl_drop_buffered_packets_map);
  COVERAGE_DEFINE(pinctrl_drop_controller_event);
  COVERAGE_DEFINE(pinctrl_drop_put_vport_binding);
+COVERAGE_DEFINE(pinctrl_notify_main_thread);
+COVERAGE_DEFINE(pinctrl_total_pin_pkts);
struct empty_lb_backends_event {
      struct hmap_node hmap_node;
@@ -3268,6 +3270,41 @@ process_packet_in(struct rconn *swconn, const struct 
ofp_header *msg)
                       ntohl(ah->opcode));
          break;
      }
+
+
+    if (VLOG_IS_DBG_ENABLED()) {
+        struct ds pin_str = DS_EMPTY_INITIALIZER;
+        char * opc_str = ovnact_op_to_string(ntohl(ah->opcode));
+
+        ds_put_format(&pin_str,
+                        "pinctrl received  packet-in | opcode=%s",
+                        opc_str);
+
+        ds_put_format(&pin_str, "| OF_Table_ID=%u", pin.table_id);
+        ds_put_format(&pin_str, "| OF_Cookie_ID=0x%"PRIx64,
+                        ntohll(pin.cookie));
+
+        if (pin.flow_metadata.flow.in_port.ofp_port) {
+            ds_put_format(&pin_str, "| in-port=%u",
+                            pin.flow_metadata.flow.in_port.ofp_port);
+        }
+
+        ds_put_format(&pin_str, "| src-mac="ETH_ADDR_FMT",",
+                        ETH_ADDR_ARGS(headers.dl_src));
+        ds_put_format(&pin_str, " dst-mac="ETH_ADDR_FMT,
+                        ETH_ADDR_ARGS(headers.dl_dst));
+        if (headers.dl_type != htons(ETH_TYPE_IPV6)) {
+            ds_put_format(&pin_str, "| src-ip="IP_FMT",",
+                            IP_ARGS(headers.nw_src));
+            ds_put_format(&pin_str, " dst-ip="IP_FMT,
+                            IP_ARGS(headers.nw_dst));
+        }
+
+        VLOG_DBG("%s \n", ds_cstr(&pin_str));
+        ds_destroy(&pin_str);
+        free(opc_str);
+    }
+
  }
/* Called with in the pinctrl_handler thread context. */
@@ -3285,6 +3322,7 @@ pinctrl_recv(struct rconn *swconn, const struct 
ofp_header *oh,
          config.miss_send_len = UINT16_MAX;
          set_switch_config(swconn, &config);
      } else if (type == OFPTYPE_PACKET_IN) {
+        COVERAGE_INC(pinctrl_total_pin_pkts);
          process_packet_in(swconn, oh);
      } else {
          if (VLOG_IS_DBG_ENABLED()) {
@@ -3309,6 +3347,7 @@ notify_pinctrl_handler(void)
  static void
  notify_pinctrl_main(void)
  {
+    COVERAGE_INC(pinctrl_notify_main_thread);
      seq_change(pinctrl_main_seq);
  }
diff --git a/include/ovn/actions.h b/include/ovn/actions.h
index ede5eb93c..cdef5fb03 100644
--- a/include/ovn/actions.h
+++ b/include/ovn/actions.h
@@ -806,5 +806,6 @@ void ovnacts_encode(const struct ovnact[], size_t 
ovnacts_len,
                      struct ofpbuf *ofpacts);
void ovnacts_free(struct ovnact[], size_t ovnacts_len);
+char *ovnact_op_to_string(uint32_t);
#endif /* ovn/actions.h */
diff --git a/lib/actions.c b/lib/actions.c
index 6b9a426ae..a0ff0cb6a 100644
--- a/lib/actions.c
+++ b/lib/actions.c
@@ -4315,3 +4315,126 @@ ovnacts_free(struct ovnact *ovnacts, size_t ovnacts_len)
          }
      }
  }
+
+/* Return ovn action opcode string representation.
+ * The returned memory is dynamically allocated
+ * and the caller must free it using free().
+ */
+
+char *
+ovnact_op_to_string(uint32_t ovnact_opc)
+{
+    struct ds opc_str = DS_EMPTY_INITIALIZER;
+
+    switch (ovnact_opc) {
+    case ACTION_OPCODE_ARP:
+        ds_put_cstr(&opc_str, "ARP");
+        break;
+    case ACTION_OPCODE_IGMP:
+        ds_put_cstr(&opc_str, "IGMP");
+        break;
+
+    case ACTION_OPCODE_PUT_ARP:
+        ds_put_cstr(&opc_str, "PUT_ARP");
+        break;
+
+    case ACTION_OPCODE_PUT_DHCP_OPTS:
+        ds_put_cstr(&opc_str, "PUT_DHCP_OPTS");
+        break;
+
+    case ACTION_OPCODE_ND_NA:
+        ds_put_cstr(&opc_str, "ND_NA");
+        break;
+
+    case ACTION_OPCODE_ND_NA_ROUTER:
+        ds_put_cstr(&opc_str, "ND_NA_ROUTER");
+        break;
+
+    case ACTION_OPCODE_PUT_ND:
+        ds_put_cstr(&opc_str, "PUT_ND");
+        break;
+
+    case ACTION_OPCODE_PUT_FDB:
+        ds_put_cstr(&opc_str, "PUT_FDB");
+        break;
+
+    case ACTION_OPCODE_PUT_DHCPV6_OPTS:
+        ds_put_cstr(&opc_str, "PUT_DHCPV6_OPTS");
+        break;
+
+    case ACTION_OPCODE_DNS_LOOKUP:
+        ds_put_cstr(&opc_str, "DNS_LOOKUP");
+        break;
+
+    case ACTION_OPCODE_LOG:
+        ds_put_cstr(&opc_str, "LOG");
+        break;
+
+    case ACTION_OPCODE_PUT_ND_RA_OPTS:
+        ds_put_cstr(&opc_str, "PUT_ND_RA_OPTS");
+        break;
+
+    case ACTION_OPCODE_ND_NS:
+        ds_put_cstr(&opc_str, "ND_NS");
+        break;
+
+    case ACTION_OPCODE_ICMP:
+        ds_put_cstr(&opc_str, "ICMP");
+        break;
+
+    case ACTION_OPCODE_ICMP4_ERROR:
+    case ACTION_OPCODE_ICMP6_ERROR:
+        if (ovnact_opc == ACTION_OPCODE_ICMP4_ERROR) {
+            ds_put_cstr(&opc_str, "ICMP4_ERROR");
+        } else {
+            ds_put_cstr(&opc_str, "ICMP6_ERROR");
+        }
+        break;
+
+    case ACTION_OPCODE_TCP_RESET:
+        ds_put_cstr(&opc_str, "TCP_RESET");
+        break;
+
+    case ACTION_OPCODE_SCTP_ABORT:
+        ds_put_cstr(&opc_str, "SCTP_ABORT");
+        break;
+
+    case ACTION_OPCODE_REJECT:
+        ds_put_cstr(&opc_str, "REJECT");
+        break;
+
+    case ACTION_OPCODE_PUT_ICMP4_FRAG_MTU:
+    case ACTION_OPCODE_PUT_ICMP6_FRAG_MTU:
+        if (ovnact_opc == ACTION_OPCODE_PUT_ICMP4_FRAG_MTU) {
+            ds_put_cstr(&opc_str, "PUT_ICMP4_FRAG_MTU");
+        } else {
+            ds_put_cstr(&opc_str, "PUT_ICMP6_FRAG_MTU");
+        }
+        break;
+
+    case ACTION_OPCODE_EVENT:
+        ds_put_cstr(&opc_str, "EVENT");
+        break;
+
+    case ACTION_OPCODE_BIND_VPORT:
+        ds_put_cstr(&opc_str, "BIND_VPORT");
+        break;
+    case ACTION_OPCODE_DHCP6_SERVER:
+        ds_put_cstr(&opc_str, "DHCP6_SERVER");
+        break;
+
+    case ACTION_OPCODE_HANDLE_SVC_CHECK:
+        ds_put_cstr(&opc_str, "HANDLE_SVC_CHECK");
+        break;
+
+    case ACTION_OPCODE_BFD_MSG:
+        ds_put_cstr(&opc_str, "BFD_MSG");
+        break;
+
+    default:
+        ds_put_format(&opc_str, "unrecognized(%"PRIu32")",
+                      ovnact_opc);
+        break;
+    }
+    return ds_steal_cstr(&opc_str);
+}
I didn't look at the patch from a functional standpoint, but can we
replace the above function with something like this (not tested):
Hi Ilya,
thank you for the review.
i submitted a new version 
<https://patchwork.ozlabs.org/project/ovn/patch/[email protected]/>
 with your proposed changes.

char *
ovnact_op_to_string(uint32_t ovnact_opc)
{
     switch (ovnact_opc) {
#define OVNACT(ENUM, STRUCT) \
     case ACTION_OPCODE_##ENUM: return xstrdup(#ENUM);
OVNACTS
#undef OVNACT
     default: return xasprintf("unrecognized(%"PRIu32")", ovnact_opc);
     }
}

?
Or maybe that will not work since not all actions has an opcode....

In this case, something like this should work:

char *
ovnact_op_to_string(uint32_t ovnact_opc)
{
     const char *s;

     switch (ovnact_opc) {
#define ACTION_OPCODES(ENUM)
  i guess (ENUM) is redundant here?
Yep.

ACTION_OPCODE(ARP) \
         ACTION_OPCODE(IGMP)                         \
         ACTION_OPCODE(PUT_ARP)                      \
         ACTION_OPCODE(PUT_DHCP_OPTS)                \
         ACTION_OPCODE(ND_NA)                        \
         ACTION_OPCODE(ND_NA_ROUTER)                 \
         ACTION_OPCODE(PUT_ND)                       \
         ACTION_OPCODE(PUT_FDB)                      \
         ACTION_OPCODE(PUT_DHCPV6_OPTS)              \
         ACTION_OPCODE(DNS_LOOKUP)                   \
         ACTION_OPCODE(LOG)                          \
         ACTION_OPCODE(PUT_ND_RA_OPTS)               \
         ACTION_OPCODE(ND_NS)                        \
         ACTION_OPCODE(ICMP)                         \
         ACTION_OPCODE(ICMP4_ERROR)                  \
         ACTION_OPCODE(ICMP6_ERROR)                  \
         ACTION_OPCODE(TCP_RESET)                    \
         ACTION_OPCODE(SCTP_ABORT)                   \
         ACTION_OPCODE(REJECT)                       \
         ACTION_OPCODE(PUT_ICMP4_FRAG_MTU)           \
         ACTION_OPCODE(PUT_ICMP6_FRAG_MTU)           \
         ACTION_OPCODE(EVENT)                        \
         ACTION_OPCODE(BIND_VPORT)                   \
         ACTION_OPCODE(DHCP6_SERVER)                 \
         ACTION_OPCODE(HANDLE_SVC_CHECK)             \
         ACTION_OPCODE(BFD_MSG)
  #define ACTION_OPCODE(ENUM) \
      case ACTION_OPCODE_##ENUM: return xstrdup(#ENUM);
  ACTION_OPCODES
  #undef ACTION_OPCODE
     default: return xasprintf("unrecognized(%"PRIu32")", ovnact_opc);
     }
     return xstrdup(s);
it was a bit complicated for me to understand the macros so if you please can 
take a look
and see if it's implemented properly.
Seems correct.  In general, to test tricky macros, you may just
invoke a preprocessor and look at the final result.  For OVN
it will be something like this:

   gcc -E lib/actions.c -I ./include -I ./lib  -I./ -I./ovs -I./ovs/lib 
-I./ovs/include | less
wonderful trick :) thank you for sharing this :)


To make the code even better, we need to use this trick directly
on the 'enum action_opcode', so we will have all the definitions
in the same place and will not need to remember that we need
to adjust the to_string function every time the enum changed.

It should look like this:

diff --git a/include/ovn/actions.h b/include/ovn/actions.h
index ede5eb93c..668210834 100644
--- a/include/ovn/actions.h
+++ b/include/ovn/actions.h
@@ -500,XX +500,XX @@ void *ovnact_put(struct ofpbuf *, enum ovnact_type, 
size_t len);
  OVNACTS
  #undef OVNACT
-enum action_opcode {
-    /* "arp { ...actions... }".
-     *
-     * The actions, in OpenFlow 1.3 format, follow the action_header.
-     */
-    ACTION_OPCODE_ARP,
-
-    /* "put_arp(port, ip, mac)"
-     *
-     * Arguments are passed through the packet metadata and data, as follows:
-     *
-     *     MFF_REG0 = ip
-     *     MFF_LOG_INPORT = port
-     *     MFF_ETH_SRC = mac
-     */
-    ACTION_OPCODE_PUT_ARP,
-
-    <........>
-
+#define ACTION_OPCODES                                                        \
+    /* "arp { ...actions... }".                                               \
+     *                                                                        \
+     * The actions, in OpenFlow 1.3 format, follow the action_header.         \
+     */                                                                       \
+    ACTION_OPCODE(ARP)                                                        \
+                                                                              \
+    /* "put_arp(port, ip, mac)"                                               \
+     *                                                                        \
+     * Arguments are passed through the packet metadata and data, as follows: \
+     *                                                                        \
+     *     MFF_REG0 = ip                                                      \
+     *     MFF_LOG_INPORT = port                                              \
+     *     MFF_ETH_SRC = mac                                                  \
+     */                                                                       \
+    ACTION_OPCODE(PUT_ARP)                                                    \
+                                                                              \
+     <........>                                                               \
+
+
+enum action_opcode {
+#define ACTION_OPCODE(NAME) ACTION_OPCODE_##NAME,
+    ACTION_OPCODES
+#undef ACTION_OPCODE
+};
---

After that you may re-use the 'ACTION_OPCODES' macro inside the
ovnact_op_to_string() without re-defining.

This is something that definitely needs to be done, but I'm not
sure if that needs to be done in this patch.  Maybe as a
separate patch/prerequisite to this one.

Best regards, Ilya Maximets.
yes,

i will try to add it as a separate patch since this patch already merged.
thank you so much :)



And this line is obviously not needed.  Ugh.
And sorry for the trailing whitespaces.

thanks :)
}

Should be easier to track and modify in the future.

Best regards, Ilya Maximets.


_______________________________________________
dev mailing list
[email protected]
https://mail.openvswitch.org/mailman/listinfo/ovs-dev

Reply via email to