From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mails.dpdk.org (mails.dpdk.org [217.70.189.124]) by inbox.dpdk.org (Postfix) with ESMTP id 900DE43C96; Tue, 12 Mar 2024 23:01:42 +0100 (CET) Received: from mails.dpdk.org (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id 52395402CD; Tue, 12 Mar 2024 23:01:42 +0100 (CET) Received: from mail-pl1-f169.google.com (mail-pl1-f169.google.com [209.85.214.169]) by mails.dpdk.org (Postfix) with ESMTP id 7BA9040272 for ; Tue, 12 Mar 2024 23:01:40 +0100 (CET) Received: by mail-pl1-f169.google.com with SMTP id d9443c01a7336-1dd9066b7c3so3222055ad.2 for ; Tue, 12 Mar 2024 15:01:40 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=networkplumber-org.20230601.gappssmtp.com; s=20230601; t=1710280899; x=1710885699; darn=dpdk.org; h=content-transfer-encoding:mime-version:message-id:date:subject:cc :to:from:from:to:cc:subject:date:message-id:reply-to; bh=UMzgGRxzZjstoBRxMy5fKJ2zdcVH0tHjwiq8oZHSjJc=; b=McZlNl/IfBgwQM9x0J1/HWfX2pqF1CBHNl3f39OpXkZ3nSLV9ch1TV75hUv85cGTjG de0kXpVRL9HVBPJefgpEDbEqPKhPJFCyLDdNLyWt2agzMbLuhyP+8kZ7gFmQXUpSHZt5 NPjMJ3LiI3ROCnR5jK9Cgponq9+l5qGbiVolZsJoN0u5zZSf/RhZyTZGQfjHRF6TcoY7 n2j4UklG8Jcs1uZe69H7Fh/ZaPc/0zE+SgRDDKJZn72HFg+RTeo3izJSyalqAQ1aXZ5e UYdfEksOHbbj6usEJwg0bn5dEtD/NFXIkIsDAi2r5gBsJeyJrCH8eEeUtSNMt86ZFPOF 6+Vg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1710280899; x=1710885699; h=content-transfer-encoding:mime-version:message-id:date:subject:cc :to:from:x-gm-message-state:from:to:cc:subject:date:message-id :reply-to; bh=UMzgGRxzZjstoBRxMy5fKJ2zdcVH0tHjwiq8oZHSjJc=; b=FJEaojPP8qMaNtz6M3/R4fLPG8UoPz0Hmc9jcW+BG6SSx84srKjJR8+qno3qouSEhO YwN7gQzJwbBpeKCjn9Bc/PPf+DOEHWCGa0E2eAAJMisYMo/6xypfJ5p8bbIlyMOPh1mi Av7OJXTZk3O69CaAYVWxPEqikMSduAK9r6/fVhS79ct0WVMMrZLR/43yVMvmWX21QWRR mGin8czCQDSvNX5uNTn0z4FGnMN30c/aCi7Hl2f2J0KXAKUzteqIy/yZOdPF3aKBxSY+ mKvGXJ8I1PWJb6wzWlU+ICm7l8mKi/8Bzzxb2CT/DgLwHzikLLR+LQPJ0+GXz/IAvjI1 bHZA== X-Gm-Message-State: AOJu0Yxi94z52+ZcFL26ZYQjDFSbFi0aqZE3mmpKO5dsUceIifpOziYg hLu5a146kiLyZ5p8SUJ5y1TvMOKsFXlpI7G81amXnMK5Mz647EUWFfzi6SgiS3n9N6+5h3yJz6R i X-Google-Smtp-Source: AGHT+IFRMScKLwuicQYX26NbP46DhDPAaH5Eh03SuCzIx8tsaIFQVATm+4vXNi9I78QqbWzCHPWEIA== X-Received: by 2002:a17:902:d581:b0:1dd:a134:5699 with SMTP id k1-20020a170902d58100b001dda1345699mr5859654plh.28.1710280899338; Tue, 12 Mar 2024 15:01:39 -0700 (PDT) Received: from hermes.local (204-195-123-141.wavecable.com. [204.195.123.141]) by smtp.gmail.com with ESMTPSA id e4-20020a170902b78400b001dcc3a46a6bsm7129493pls.262.2024.03.12.15.01.38 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Tue, 12 Mar 2024 15:01:38 -0700 (PDT) From: Stephen Hemminger To: dev@dpdk.org Cc: Stephen Hemminger , Ori Kam , Aman Singh , Yuying Zhang Subject: [PATCH] test-pmd: add more packet decode options (verbose) Date: Tue, 12 Mar 2024 15:01:27 -0700 Message-ID: <20240312220129.70667-1-stephen@networkplumber.org> X-Mailer: git-send-email 2.43.0 MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit X-BeenThere: dev@dpdk.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: DPDK patches and discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: dev-bounces@dpdk.org The existing verbose levels 1..3 provide a messy multi-line output per packet. This is unhelpful when diagnosing many types of problems like packet flow. This patch adds two new levels: 4: one line per packet is printed in a format resembling tshark output. With addresses and protocol info. 5: dump packet in hex. Useful if the driver is messing up the data. Signed-off-by: Stephen Hemminger --- app/test-pmd/cmdline_flow.c | 3 +- app/test-pmd/config.c | 33 +- app/test-pmd/testpmd.h | 11 + app/test-pmd/util.c | 355 +++++++++++++++++++- doc/guides/testpmd_app_ug/testpmd_funcs.rst | 5 +- 5 files changed, 391 insertions(+), 16 deletions(-) diff --git a/app/test-pmd/cmdline_flow.c b/app/test-pmd/cmdline_flow.c index 5f761903c1d1..03141c04cae5 100644 --- a/app/test-pmd/cmdline_flow.c +++ b/app/test-pmd/cmdline_flow.c @@ -14002,7 +14002,8 @@ cmd_set_raw_parsed(const struct buffer *in) upper_layer = proto; } } - if (verbose_level & 0x1) + + if (verbose_level > 0) printf("total data size is %zu\n", (*total_size)); RTE_ASSERT((*total_size) <= ACTION_RAW_ENCAP_MAX_DATA); memmove(data, (data_tail - (*total_size)), *total_size); diff --git a/app/test-pmd/config.c b/app/test-pmd/config.c index 968d2164ab35..8e83b78721fc 100644 --- a/app/test-pmd/config.c +++ b/app/test-pmd/config.c @@ -6250,26 +6250,37 @@ configure_rxtx_dump_callbacks(uint16_t verbose) return; #endif - RTE_ETH_FOREACH_DEV(portid) - { - if (verbose == 1 || verbose > 2) + RTE_ETH_FOREACH_DEV(portid) { + switch (verbose) { + case VERBOSE_OFF: + remove_rx_dump_callbacks(portid); + remove_tx_dump_callbacks(portid); + break; + case VERBOSE_RX: add_rx_dump_callbacks(portid); - else + remove_tx_dump_callbacks(portid); + break; + case VERBOSE_TX: + add_tx_dump_callbacks(portid); remove_rx_dump_callbacks(portid); - if (verbose >= 2) + break; + default: + add_rx_dump_callbacks(portid); add_tx_dump_callbacks(portid); - else - remove_tx_dump_callbacks(portid); + } } } void set_verbose_level(uint16_t vb_level) { - printf("Change verbose level from %u to %u\n", - (unsigned int) verbose_level, (unsigned int) vb_level); - verbose_level = vb_level; - configure_rxtx_dump_callbacks(verbose_level); + if (vb_level < VERBOSE_MAX) { + printf("Change verbose level from %u to %u\n", verbose_level, vb_level); + verbose_level = vb_level; + configure_rxtx_dump_callbacks(verbose_level); + } else { + fprintf(stderr, "Verbose level %u is out of range\n", vb_level); + } } void diff --git a/app/test-pmd/testpmd.h b/app/test-pmd/testpmd.h index 55df12033a39..26801226bb47 100644 --- a/app/test-pmd/testpmd.h +++ b/app/test-pmd/testpmd.h @@ -489,6 +489,17 @@ enum dcb_mode_enable extern uint8_t xstats_hide_zero; /**< Hide zero values for xstats display */ +enum verbose_mode { + VERBOSE_OFF = 0, + VERBOSE_RX, + VERBOSE_TX, + VERBOSE_BOTH, + VERBOSE_DISSECT, + VERBOSE_HEX, + VERBOSE_MAX +}; + + /* globals used for configuration */ extern uint8_t record_core_cycles; /**< Enables measurement of CPU cycles */ extern uint8_t record_burst_stats; /**< Enables display of RX and TX bursts */ diff --git a/app/test-pmd/util.c b/app/test-pmd/util.c index 5aa69ed545af..f9dfa4d7ec07 100644 --- a/app/test-pmd/util.c +++ b/app/test-pmd/util.c @@ -9,6 +9,11 @@ #include #include #include +#include +#include +#include +#include +#include #include #include #include @@ -16,6 +21,7 @@ #include "testpmd.h" #define MAX_STRING_LEN 8192 +#define MAX_DUMP_LEN 1024 #define MKDUMPSTR(buf, buf_size, cur_len, ...) \ do { \ @@ -67,9 +73,10 @@ get_timestamp(const struct rte_mbuf *mbuf) timestamp_dynfield_offset, rte_mbuf_timestamp_t *); } -static inline void -dump_pkt_burst(uint16_t port_id, uint16_t queue, struct rte_mbuf *pkts[], - uint16_t nb_pkts, int is_rx) +/* More verbose older style packet decode */ +static void +dump_pkt_verbose(uint16_t port_id, uint16_t queue, struct rte_mbuf *pkts[], + uint16_t nb_pkts, int is_rx) { struct rte_mbuf *mb; const struct rte_ether_hdr *eth_hdr; @@ -297,6 +304,348 @@ dump_pkt_burst(uint16_t port_id, uint16_t queue, struct rte_mbuf *pkts[], } } +static void +dissect_arp(const struct rte_mbuf *mb, uint16_t offset) +{ + const struct rte_arp_hdr *arp; + struct rte_arp_hdr _arp; + uint16_t ar_op; + char buf[128]; + + arp = rte_pktmbuf_read(mb, offset, sizeof(*arp), &_arp); + if (unlikely(arp == NULL)) { + printf("truncated ARP! "); + return; + } + + ar_op = RTE_BE_TO_CPU_16(arp->arp_opcode); + switch (ar_op) { + case RTE_ARP_OP_REQUEST: + inet_ntop(AF_INET, &arp->arp_data.arp_tip, buf, sizeof(buf)); + printf("Who has %s? ", buf); + + rte_ether_format_addr(buf, sizeof(buf), &arp->arp_data.arp_sha); + printf("Tell %s ", buf); + break; + case RTE_ARP_OP_REPLY: + inet_ntop(AF_INET, &arp->arp_data.arp_sip, buf, sizeof(buf)); + printf("%s is at", buf); + + rte_ether_format_addr(buf, sizeof(buf), &arp->arp_data.arp_sha); + printf("%s ", buf); + break; + case RTE_ARP_OP_INVREQUEST: + rte_ether_format_addr(buf, sizeof(buf), &arp->arp_data.arp_tha); + printf("Who is %s? ", buf); + + rte_ether_format_addr(buf, sizeof(buf), &arp->arp_data.arp_sha); + printf("Tell %s ", buf); + break; + + case RTE_ARP_OP_INVREPLY: + rte_ether_format_addr(buf, sizeof(buf), &arp->arp_data.arp_sha); + printf("%s is at ", buf); + + inet_ntop(AF_INET, &arp->arp_data.arp_sip, buf, sizeof(buf)); + printf("%s ", buf); + break; + default: + printf("Unknown ARP %#x ", ar_op); + break; + } +} + +static void +dissect_udp(const struct rte_mbuf *mb, uint16_t offset) +{ + const struct rte_udp_hdr *udph; + struct rte_udp_hdr _udp; + uint16_t src_port, dst_port; + + udph = rte_pktmbuf_read(mb, offset, sizeof(*udph), &_udp); + if (unlikely(udph == NULL)) { + printf("truncated UDP! "); + return; + } + + src_port = RTE_BE_TO_CPU_16(udph->src_port); + dst_port = RTE_BE_TO_CPU_16(udph->dst_port); + + /* TODO handle vxlan */ + + printf("UDP %u %u → %u ", + RTE_BE_TO_CPU_16(udph->dgram_len), + src_port, dst_port); + +} + +static void +dissect_tcp(const struct rte_mbuf *mb, uint16_t offset) +{ + const struct rte_tcp_hdr *tcph; + struct rte_tcp_hdr _tcp; + uint16_t src_port, dst_port; + + tcph = rte_pktmbuf_read(mb, offset, sizeof(*tcph), &_tcp); + if (unlikely(tcph == NULL)) { + printf("truncated TCP! "); + return; + } + + src_port = RTE_BE_TO_CPU_16(tcph->src_port); + dst_port = RTE_BE_TO_CPU_16(tcph->dst_port); + + printf("TCP %u → %u", + src_port, dst_port); +#define PRINT_TCP_FLAG(flag) \ + if (tcph->tcp_flags & RTE_TCP_ ## flag ## _FLAG) \ + printf(" [" #flag" ]") + + PRINT_TCP_FLAG(URG); + PRINT_TCP_FLAG(ACK); + PRINT_TCP_FLAG(RST); + PRINT_TCP_FLAG(SYN); + PRINT_TCP_FLAG(FIN); +#undef PRINT_TCP_FLAG + + printf("Seq=%u Ack=%u Win=%u ", + RTE_BE_TO_CPU_16(tcph->sent_seq), + RTE_BE_TO_CPU_16(tcph->recv_ack), + RTE_BE_TO_CPU_16(tcph->rx_win)); +} + +static void +dissect_icmp(const struct rte_mbuf *mb, uint16_t offset) +{ + const struct rte_icmp_hdr *icmp; + struct rte_icmp_hdr _icmp; + static const char * const icmp_types[256] = { + [RTE_IP_ICMP_ECHO_REPLY] = "ICMP Reply", + [RTE_IP_ICMP_ECHO_REQUEST] = "ICMP Request", + [RTE_ICMP6_ECHO_REPLY] = "ICMPv6 Reply", + [RTE_ICMP6_ECHO_REQUEST] = "ICMPv6 Request", + [133] = "ICMPv6 Router Solicitation", + [134] = "ICMPv6 Router Solicitation", + }; + + + icmp = rte_pktmbuf_read(mb, offset, sizeof(*icmp), &_icmp); + if (unlikely(icmp == NULL)) { + printf("truncated ICMP! "); + } else { + const char *name = icmp_types[icmp->icmp_type]; + + if (name != NULL) + printf("%s ", name); + else + printf("ICMP type %u ", icmp->icmp_type); + } +} + +static void +dissect_ipv4(const struct rte_mbuf *mb, uint16_t offset) +{ + const struct rte_ipv4_hdr *ip_hdr; + struct rte_ipv4_hdr _ip_hdr; + char sbuf[INET_ADDRSTRLEN], dbuf[INET_ADDRSTRLEN]; + + ip_hdr = rte_pktmbuf_read(mb, offset, sizeof(*ip_hdr), &_ip_hdr); + if (unlikely(ip_hdr == NULL)) { + printf("truncated IP! "); + return; + } + + inet_ntop(AF_INET, &ip_hdr->src_addr, sbuf, sizeof(sbuf)); + inet_ntop(AF_INET, &ip_hdr->dst_addr, dbuf, sizeof(dbuf)); + printf("%s → %s ", sbuf, dbuf); + + offset += ip_hdr->ihl * 4; + switch (ip_hdr->next_proto_id) { + case IPPROTO_UDP: + return dissect_udp(mb, offset); + case IPPROTO_TCP: + return dissect_tcp(mb, offset); + case IPPROTO_ICMP: + return dissect_icmp(mb, offset); + default: + /* TODO dissect tunnels */ + printf("IP proto %#x ", ip_hdr->next_proto_id); + } +} + +static void +dissect_ipv6(const struct rte_mbuf *mb, uint16_t offset) +{ + const struct rte_ipv6_hdr *ip6_hdr; + struct rte_ipv6_hdr _ip6_hdr; + char sbuf[INET6_ADDRSTRLEN], dbuf[INET6_ADDRSTRLEN]; + uint16_t proto; + unsigned int i; + + ip6_hdr = rte_pktmbuf_read(mb, offset, sizeof(*ip6_hdr), &_ip6_hdr); + if (unlikely(ip6_hdr == NULL)) { + printf("truncated IPv6! "); + return; + } + offset += sizeof(*ip6_hdr); + + inet_ntop(AF_INET6, ip6_hdr->src_addr, sbuf, sizeof(sbuf)); + inet_ntop(AF_INET6, ip6_hdr->dst_addr, dbuf, sizeof(dbuf)); + printf("%s → %s ", sbuf, dbuf); + +#define MAX_EXT_HDRS 5 + proto = ip6_hdr->proto; + for (i = 0; i < MAX_EXT_HDRS; i++) { + switch (proto) { + case IPPROTO_UDP: + return dissect_udp(mb, offset); + case IPPROTO_TCP: + return dissect_tcp(mb, offset); + case IPPROTO_ICMPV6: + return dissect_icmp(mb, offset); + + case IPPROTO_HOPOPTS: + case IPPROTO_ROUTING: + case IPPROTO_DSTOPTS: + { + const struct rte_ipv6_routing_ext *xh; + struct rte_ipv6_routing_ext _xh; + + xh = rte_pktmbuf_read(mb, offset, sizeof(*xh), &_xh); + if (unlikely(xh == NULL)) { + printf("truncated IPV6 option! "); + return; + } + offset += (xh->hdr_len + 1) * 8; + proto = xh->next_hdr; + continue; + } + + case IPPROTO_FRAGMENT: + printf("FRAG "); + return; + + case IPPROTO_NONE: + printf("NONE "); + return; + + default: + printf("IPv6 proto %u ", proto); + return; + } + } + + printf("Too many extensions! "); +} + +static void +dissect_eth(const struct rte_mbuf *mb, uint16_t offset) +{ + const struct rte_ether_hdr *eth_hdr; + struct rte_ether_hdr _eth_hdr; + uint16_t eth_type; + char sbuf[RTE_ETHER_ADDR_FMT_SIZE], dbuf[RTE_ETHER_ADDR_FMT_SIZE]; + + eth_hdr = rte_pktmbuf_read(mb, offset, sizeof(struct rte_ether_hdr), &_eth_hdr); + if (unlikely(eth_hdr == NULL)) { + printf("missing Eth header! offset=%u", offset); + return; + } + + offset += sizeof(*eth_hdr); + eth_type = RTE_BE_TO_CPU_16(eth_hdr->ether_type); + if (eth_type == RTE_ETHER_TYPE_VLAN || eth_type == RTE_ETHER_TYPE_QINQ) { + const struct rte_vlan_hdr *vh + = (const struct rte_vlan_hdr *)(eth_hdr + 1); + eth_type = vh->eth_proto; + offset += sizeof(*vh); + + printf("%s %#x ", eth_type == RTE_ETHER_TYPE_VLAN ? "VLAN" : "QINQ", + RTE_BE_TO_CPU_16(vh->vlan_tci)); + } + + switch (eth_type) { + case RTE_ETHER_TYPE_ARP: + rte_ether_format_addr(sbuf, sizeof(sbuf), ð_hdr->src_addr); + rte_ether_format_addr(sbuf, sizeof(dbuf), ð_hdr->dst_addr); + printf("%s → %s ARP ", sbuf, dbuf); + + dissect_arp(mb, offset); + break; + case RTE_ETHER_TYPE_IPV4: + dissect_ipv4(mb, offset); + break; + + case RTE_ETHER_TYPE_IPV6: + dissect_ipv6(mb, offset); + break; + default: + printf("Ethernet proto %#x ", eth_type); + } +} + +/* Brief tshark style one line output which is + * number time_delta Source Destination Protocol len info + */ +static void +dump_pkt_brief(uint16_t queue, struct rte_mbuf *pkts[], uint16_t nb_pkts) +{ + static uint64_t start_cycles; + static uint64_t packet_count; + uint64_t now; + uint64_t count; + double interval; + uint16_t i; + + if (!nb_pkts) + return; + + now = rte_rdtsc(); + if (start_cycles == 0) + start_cycles = now; + interval = (double)(now - start_cycles) / (double)rte_get_tsc_hz(); + + count = __atomic_fetch_add(&packet_count, nb_pkts, __ATOMIC_RELAXED); + + for (i = 0; i < nb_pkts; i++) { + const struct rte_mbuf *mb = pkts[i]; + + printf("%6"PRIu64" %11.9f %4u:%-3u ", count + i, interval, mb->port, queue); + dissect_eth(mb, 0); + putchar('\n'); + } + fflush(stdout); +} + +/* Hex dump of packet data */ +static void +dump_pkt_hex(struct rte_mbuf *pkts[], uint16_t nb_pkts) +{ + uint16_t i; + + for (i = 0; i < nb_pkts; i++) + rte_pktmbuf_dump(stdout, pkts[i], MAX_DUMP_LEN); + + fflush(stdout); +} + +static uint16_t +dump_pkt_burst(uint16_t port_id, uint16_t queue, struct rte_mbuf *pkts[], + uint16_t nb_pkts, int is_rx) +{ + switch (verbose_level) { + case VERBOSE_RX ... VERBOSE_BOTH: + dump_pkt_verbose(port_id, queue, pkts, nb_pkts, is_rx); + break; + case VERBOSE_DISSECT: + dump_pkt_brief(queue, pkts, nb_pkts); + break; + case VERBOSE_HEX: + dump_pkt_hex(pkts, nb_pkts); + } + return nb_pkts; +} + uint16_t dump_rx_pkts(uint16_t port_id, uint16_t queue, struct rte_mbuf *pkts[], uint16_t nb_pkts, __rte_unused uint16_t max_pkts, diff --git a/doc/guides/testpmd_app_ug/testpmd_funcs.rst b/doc/guides/testpmd_app_ug/testpmd_funcs.rst index 2fbf9220d8a9..f8b75b09afd0 100644 --- a/doc/guides/testpmd_app_ug/testpmd_funcs.rst +++ b/doc/guides/testpmd_app_ug/testpmd_funcs.rst @@ -677,7 +677,10 @@ Available levels are as following: * ``0`` silent except for error. * ``1`` fully verbose except for Tx packets. * ``2`` fully verbose except for Rx packets. -* ``> 2`` fully verbose. +* ``3`` fully verbose except for Tx and Rx packets. +* ``4`` dissected protocol information for Tx and Rx packets. +* ``5`` hex dump of packets + set log ~~~~~~~ -- 2.43.0