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 <mh...@redhat.com> >>> --- >>> 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): >> >> 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) > 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);
And this line is obviously not needed. Ugh. And sorry for the trailing whitespaces. > } > > Should be easier to track and modify in the future. > >> >> Best regards, Ilya Maximets. >> > _______________________________________________ dev mailing list d...@openvswitch.org https://mail.openvswitch.org/mailman/listinfo/ovs-dev
