On Thu, Dec 2, 2021 at 5:41 AM Mohammad Heib <[email protected]> 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]>
Thanks for v2. Looks like the patch has some compilation issues. Please see https://github.com/ovsrobot/ovn/runs/4394028501?check_suite_focus=true Please see few comments below. Thanks Numan > --- > controller/pinctrl.c | 39 ++++++++++++++ > include/ovn/actions.h | 1 + > lib/actions.c | 119 ++++++++++++++++++++++++++++++++++++++++++ > tests/ovn.at | 8 +++ > 4 files changed, 167 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..44b6c30d1 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(const ovs_be32); > > #endif /* ovn/actions.h */ > diff --git a/lib/actions.c b/lib/actions.c > index 6b9a426ae..3d6b33ad6 100644 > --- a/lib/actions.c > +++ b/lib/actions.c > @@ -4315,3 +4315,122 @@ ovnacts_free(struct ovnact *ovnacts, size_t > ovnacts_len) > } > } > } > + > +/* Return ovn action opcode string representation.*/ Please also mention in the comment that it's the responsibility of the caller to free up the returned string. > +char * > +ovnact_op_to_string(const ovs_be32 ovnact_opc) The compilation error is because of ovs_be32. You need to change the type from "const ovs_be32" to uint32_t. Also there's no need for const here. > +{ > + 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_cstr(&opc_str); It's better to use - ds_steal_cstr() here. Thanks Numan > +} > diff --git a/tests/ovn.at b/tests/ovn.at > index a4ed03041..9ec62e321 100644 > --- a/tests/ovn.at > +++ b/tests/ovn.at > @@ -18283,6 +18283,8 @@ ovs-vsctl -- add-port br-int hv1-vif3 -- \ > options:rxq_pcap=hv1/vif3-rx.pcap \ > ofport-request=3 > > +ovs-appctl -t ovn-controller vlog/set dbg > + > sim_add hv2 > as hv2 > ovs-vsctl add-br br-phys > @@ -18473,6 +18475,8 @@ wait_row_count Port_Binding 1 logical_port=sw0-vir > chassis=$hv1_ch_uuid > check_row_count Port_Binding 1 logical_port=sw0-vir virtual_parent=sw0-p1 > wait_for_ports_up sw0-vir > check ovn-nbctl --wait=hv sync > +AT_CHECK([test 2 = `cat hv1/ovn-controller.log | grep "pinctrl received > packet-in" | \ > +grep opcode=BIND_VPORT | grep OF_Table_ID=24 | wc -l`]) > > wait_row_count Port_Binding 1 logical_port=sw0-vir6 chassis=$hv1_ch_uuid > check_row_count Port_Binding 1 logical_port=sw0-vir6 virtual_parent=sw0-p1 > @@ -21339,6 +21343,10 @@ list mac_binding], [0], [lr0-sw0 > > AT_CHECK([test 1 = `cat hv1/ovn-controller.log | grep NXT_PACKET_IN2 | \ > grep table_id=10 | wc -l`]) > + > +AT_CHECK([test 1 = `cat hv1/ovn-controller.log | grep "pinctrl received > packet-in" | \ > +grep opcode=PUT_ARP | grep OF_Table_ID=10 | wc -l`]) > + > AT_CHECK([test 1 = `as hv1 ovs-ofctl dump-flows br-int table=10 | grep arp | > \ > grep controller | grep -v n_packets=0 | wc -l`]) > > -- > 2.26.3 > > _______________________________________________ > dev mailing list > [email protected] > https://mail.openvswitch.org/mailman/listinfo/ovs-dev > _______________________________________________ dev mailing list [email protected] https://mail.openvswitch.org/mailman/listinfo/ovs-dev
