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
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.
>> 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