test-pmd: add more packet decode options (verbose)

Message ID 20240312220129.70667-1-stephen@networkplumber.org (mailing list archive)
State New
Delegated to: Ferruh Yigit
Headers
Series test-pmd: add more packet decode options (verbose) |

Checks

Context Check Description
ci/loongarch-compilation success Compilation OK
ci/checkpatch warning coding style issues
ci/loongarch-unit-testing success Unit Testing PASS
ci/Intel-compilation success Compilation OK
ci/intel-Testing success Testing PASS
ci/intel-Functional success Functional PASS
ci/github-robot: build success github build: passed
ci/iol-intel-Performance success Performance Testing PASS
ci/iol-intel-Functional success Functional Testing PASS
ci/iol-mellanox-Performance success Performance Testing PASS
ci/iol-abi-testing success Testing PASS
ci/iol-unit-arm64-testing success Testing PASS
ci/iol-compile-arm64-testing success Testing PASS
ci/iol-unit-amd64-testing success Testing PASS
ci/iol-compile-amd64-testing warning Testing issues
ci/iol-sample-apps-testing success Testing PASS
ci/iol-broadcom-Performance success Performance Testing PASS
ci/iol-broadcom-Functional success Functional Testing PASS

Commit Message

Stephen Hemminger March 12, 2024, 10:01 p.m. UTC
  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 <stephen@networkplumber.org>
---
 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(-)
  

Comments

Stephen Hemminger March 13, 2024, 9:49 p.m. UTC | #1
On Tue, 12 Mar 2024 15:01:27 -0700
Stephen Hemminger <stephen@networkplumber.org> wrote:

> 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 <stephen@networkplumber.org>

The build on mingw (ie. GCC on Windows) fails because of mismatch
in the function prototype. It is already fixed upstream in mingw
could the CI infrastructure please be updated. 

The commit upstream that fixed the bug was almost 5 years ago.

commit 1b5ae4b567ee1699f69cd918ae2bc693898edbb2
Author: Martin Storsjö <martin@martin.st>
Date:   Mon Apr 22 15:09:14 2019 +0300

    headers: Use proper types for InetNtopA/W
    
    PCVOID is not commonly defined, only LPCVOID.
    
    Signed-off-by: Martin Storsjö <martin@martin.st>


This commit is in the 7.0 release.
The current version of MinGw is 11.0 which is what CI should be using!

Unfortunately, DPDK documentation and build does not have a version listed.
  

Patch

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 <rte_net.h>
 #include <rte_mbuf.h>
 #include <rte_ether.h>
+#include <rte_arp.h>
+#include <rte_icmp.h>
+#include <rte_ip.h>
+#include <rte_tcp.h>
+#include <rte_udp.h>
 #include <rte_vxlan.h>
 #include <rte_ethdev.h>
 #include <rte_flow.h>
@@ -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), &eth_hdr->src_addr);
+		rte_ether_format_addr(sbuf, sizeof(dbuf), &eth_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
 ~~~~~~~