From patchwork Wed Dec 8 13:59:54 2021 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Mohammad Heib X-Patchwork-Id: 1565219 Return-Path: X-Original-To: incoming@patchwork.ozlabs.org Delivered-To: patchwork-incoming@bilbo.ozlabs.org Authentication-Results: bilbo.ozlabs.org; dkim=fail reason="signature verification failed" (1024-bit key; unprotected) header.d=redhat.com header.i=@redhat.com header.a=rsa-sha256 header.s=mimecast20190719 header.b=guMiQtkR; dkim-atps=neutral Authentication-Results: ozlabs.org; spf=pass (sender SPF authorized) smtp.mailfrom=openvswitch.org (client-ip=2605:bc80:3010::136; helo=smtp3.osuosl.org; envelope-from=ovs-dev-bounces@openvswitch.org; receiver=) Received: from smtp3.osuosl.org (smtp3.osuosl.org [IPv6:2605:bc80:3010::136]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (No client certificate requested) by bilbo.ozlabs.org (Postfix) with ESMTPS id 4J8Jhs1cgrz9sR4 for ; Thu, 9 Dec 2021 01:00:28 +1100 (AEDT) Received: from localhost (localhost [127.0.0.1]) by smtp3.osuosl.org (Postfix) with ESMTP id B333B60A59; Wed, 8 Dec 2021 14:00:26 +0000 (UTC) X-Virus-Scanned: amavisd-new at osuosl.org Received: from smtp3.osuosl.org ([127.0.0.1]) by localhost (smtp3.osuosl.org [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id O6LOoqKAlPlq; Wed, 8 Dec 2021 14:00:25 +0000 (UTC) Received: from lists.linuxfoundation.org (lf-lists.osuosl.org [IPv6:2605:bc80:3010:104::8cd3:938]) by smtp3.osuosl.org (Postfix) with ESMTPS id A21C46070D; Wed, 8 Dec 2021 14:00:24 +0000 (UTC) Received: from lf-lists.osuosl.org (localhost [127.0.0.1]) by lists.linuxfoundation.org (Postfix) with ESMTP id 830B3C002F; Wed, 8 Dec 2021 14:00:24 +0000 (UTC) X-Original-To: dev@openvswitch.org Delivered-To: ovs-dev@lists.linuxfoundation.org Received: from smtp2.osuosl.org (smtp2.osuosl.org [140.211.166.133]) by lists.linuxfoundation.org (Postfix) with ESMTP id A5728C0012 for ; Wed, 8 Dec 2021 14:00:22 +0000 (UTC) Received: from localhost (localhost [127.0.0.1]) by smtp2.osuosl.org (Postfix) with ESMTP id 88F0940249 for ; Wed, 8 Dec 2021 14:00:22 +0000 (UTC) X-Virus-Scanned: amavisd-new at osuosl.org Authentication-Results: smtp2.osuosl.org (amavisd-new); dkim=pass (1024-bit key) header.d=redhat.com Received: from smtp2.osuosl.org ([127.0.0.1]) by localhost (smtp2.osuosl.org [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id w_XnjR1RvrbX for ; Wed, 8 Dec 2021 14:00:21 +0000 (UTC) X-Greylist: domain auto-whitelisted by SQLgrey-1.8.0 Received: from us-smtp-delivery-124.mimecast.com (us-smtp-delivery-124.mimecast.com [170.10.133.124]) by smtp2.osuosl.org (Postfix) with ESMTPS id 07465400CB for ; Wed, 8 Dec 2021 14:00:20 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1638972019; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding; bh=jPqxTgFBraGH7bU4AVz+4zQzNFRnTyR258u+NNNEizQ=; b=guMiQtkRsJnBAfQhrBeEOReP38M1GV0MdiuIFNiOteQMc7vNwZvpIVbPf6vspDV+islgRD mV/RAW+3jfonSScuqhxa4dxOQVLhTTJwR3kfsIJ854XhWC9xpcCZQ2dZjYLGI6Twag1lTx Rpbv9qA24+nHGP4gyOXK1k0lnDU78Lg= Received: from mimecast-mx01.redhat.com (mimecast-mx01.redhat.com [209.132.183.4]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-560-8B8-cU_BMlWjIG4w9x9l0w-1; Wed, 08 Dec 2021 09:00:18 -0500 X-MC-Unique: 8B8-cU_BMlWjIG4w9x9l0w-1 Received: from smtp.corp.redhat.com (int-mx04.intmail.prod.int.phx2.redhat.com [10.5.11.14]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mimecast-mx01.redhat.com (Postfix) with ESMTPS id 96AFA802C92 for ; Wed, 8 Dec 2021 14:00:17 +0000 (UTC) Received: from mheiblap.localdomain.com (unknown [10.35.206.239]) by smtp.corp.redhat.com (Postfix) with ESMTP id 3A36D5ED2D; Wed, 8 Dec 2021 14:00:01 +0000 (UTC) From: Mohammad Heib To: dev@openvswitch.org Date: Wed, 8 Dec 2021 15:59:54 +0200 Message-Id: <20211208135954.425965-1-mheib@redhat.com> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 2.79 on 10.5.11.14 Authentication-Results: relay.mimecast.com; auth=pass smtp.auth=CUSA124A263 smtp.mailfrom=mheib@redhat.com X-Mimecast-Spam-Score: 0 X-Mimecast-Originator: redhat.com Subject: [ovs-dev] [PATCH ovn v4] controller/pinctrl: improve packet-in debuggability X-BeenThere: ovs-dev@openvswitch.org X-Mailman-Version: 2.1.15 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: ovs-dev-bounces@openvswitch.org Sender: "dev" 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 --- controller/pinctrl.c | 39 ++++++++++++++++++++++++++++++++++++++ include/ovn/actions.h | 1 + lib/actions.c | 44 +++++++++++++++++++++++++++++++++++++++++++ tests/ovn.at | 8 ++++++++ 4 files changed, 92 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..da00ee349 100644 --- a/lib/actions.c +++ b/lib/actions.c @@ -4315,3 +4315,47 @@ 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) +{ + switch (ovnact_opc) { +#define ACTION_OPCODES \ + 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); + } +} 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`])