DPDK patches and discussions
 help / color / mirror / Atom feed
* [dpdk-dev] [PATCH] app/testpmd: fix testpmd packets dump overlapping
@ 2020-11-12  8:36 Jiawei Wang
  2020-11-12 16:44 ` Ferruh Yigit
  2020-11-14 12:01 ` [dpdk-dev] [PATCH v2] " Jiawei Wang
  0 siblings, 2 replies; 22+ messages in thread
From: Jiawei Wang @ 2020-11-12  8:36 UTC (permalink / raw)
  To: wenzhuo.lu, beilei.xing, bernard.iremonger, orika, thomas, rasland; +Cc: dev

When testpmd enabled the verbosity for the received packets, if two packets
was received at the same time, for example, sampling packet and normal
packet, the dump output of these packets may be overlapping due to multiple
core handled the multiple queues simultaneously.

The patch uses one string buffer that collects all the packet dump output
into this buffer and then printout it at last, that guarantee to printout
separately the dump output per packet.

Fixes: d862c45 ("app/testpmd: move dumping packets to a separate function")

Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
---
 app/test-pmd/util.c | 238 ++++++++++++++++++++++++++++++++++++++--------------
 1 file changed, 177 insertions(+), 61 deletions(-)

diff --git a/app/test-pmd/util.c b/app/test-pmd/util.c
index 649bf8f..47b75b0 100644
--- a/app/test-pmd/util.c
+++ b/app/test-pmd/util.c
@@ -12,15 +12,20 @@
 #include <rte_vxlan.h>
 #include <rte_ethdev.h>
 #include <rte_flow.h>
+#include <rte_log.h>
 
 #include "testpmd.h"
 
-static inline void
-print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr)
+#define MAX_STRING_LEN 8192
+
+static inline int
+print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr,
+		 char print_buf[], int buf_size)
 {
 	char buf[RTE_ETHER_ADDR_FMT_SIZE];
+
 	rte_ether_format_addr(buf, RTE_ETHER_ADDR_FMT_SIZE, eth_addr);
-	printf("%s%s", what, buf);
+	return snprintf(print_buf, buf_size, "%s%s", what, buf);
 }
 
 static inline bool
@@ -74,13 +79,18 @@
 	uint32_t vx_vni;
 	const char *reason;
 	int dynf_index;
+	int buf_size = MAX_STRING_LEN * nb_pkts;
+	char print_buf[buf_size];
+	int cur_len = 0;
 
+	memset(print_buf, 0, sizeof(print_buf));
 	if (!nb_pkts)
 		return;
-	printf("port %u/queue %u: %s %u packets\n",
-		port_id, queue,
-	       is_rx ? "received" : "sent",
-	       (unsigned int) nb_pkts);
+	cur_len += snprintf(print_buf + cur_len, buf_size - cur_len,
+			    "port %u/queue %u: %s %u packets\n",
+			    port_id, queue,
+			    is_rx ? "received" : "sent",
+			    (unsigned int) nb_pkts);
 	for (i = 0; i < nb_pkts; i++) {
 		int ret;
 		struct rte_flow_error error;
@@ -93,95 +103,183 @@
 		is_encapsulation = RTE_ETH_IS_TUNNEL_PKT(packet_type);
 		ret = rte_flow_get_restore_info(port_id, mb, &info, &error);
 		if (!ret) {
-			printf("restore info:");
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    "restore info:");
 			if (info.flags & RTE_FLOW_RESTORE_INFO_TUNNEL) {
 				struct port_flow_tunnel *port_tunnel;
 
 				port_tunnel = port_flow_locate_tunnel
 					      (port_id, &info.tunnel);
-				printf(" - tunnel");
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - tunnel");
 				if (port_tunnel)
-					printf(" #%u", port_tunnel->id);
+					cur_len += snprintf(print_buf + cur_len,
+							    buf_size-cur_len,
+							    " #%u",
+							    port_tunnel->id);
 				else
-					printf(" %s", "-none-");
-				printf(" type %s",
-					port_flow_tunnel_type(&info.tunnel));
+					cur_len += snprintf(print_buf + cur_len,
+							    buf_size - cur_len,
+							    " %s",
+							    "-none-");
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " type %s",
+						    port_flow_tunnel_type
+						    (&info.tunnel));
 			} else {
-				printf(" - no tunnel info");
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - no tunnel info");
 			}
 			if (info.flags & RTE_FLOW_RESTORE_INFO_ENCAPSULATED)
-				printf(" - outer header present");
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - outer header present");
 			else
-				printf(" - no outer header");
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - no outer header");
 			if (info.flags & RTE_FLOW_RESTORE_INFO_GROUP_ID)
-				printf(" - miss group %u", info.group_id);
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - miss group %u",
+						    info.group_id);
 			else
-				printf(" - no miss group");
-			printf("\n");
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - no miss group");
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len, "\n");
 		}
-		print_ether_addr("  src=", &eth_hdr->s_addr);
-		print_ether_addr(" - dst=", &eth_hdr->d_addr);
-		printf(" - type=0x%04x - length=%u - nb_segs=%d",
-		       eth_type, (unsigned int) mb->pkt_len,
-		       (int)mb->nb_segs);
+		cur_len += print_ether_addr("  src=", &eth_hdr->s_addr,
+					    print_buf + cur_len,
+					    buf_size);
+		cur_len += print_ether_addr(" - dst=", &eth_hdr->d_addr,
+					    print_buf + cur_len,
+					    buf_size);
+		cur_len += snprintf(print_buf + cur_len, buf_size - cur_len,
+				    " - type=0x%04x - length=%u - nb_segs=%d",
+				    eth_type, (unsigned int) mb->pkt_len,
+				    (int)mb->nb_segs);
 		ol_flags = mb->ol_flags;
 		if (ol_flags & PKT_RX_RSS_HASH) {
-			printf(" - RSS hash=0x%x", (unsigned int) mb->hash.rss);
-			printf(" - RSS queue=0x%x", (unsigned int) queue);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - RSS hash=0x%x",
+					    (unsigned int) mb->hash.rss);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - RSS queue=0x%x",
+					    (unsigned int) queue);
 		}
 		if (ol_flags & PKT_RX_FDIR) {
-			printf(" - FDIR matched ");
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - FDIR matched ");
 			if (ol_flags & PKT_RX_FDIR_ID)
-				printf("ID=0x%x",
-				       mb->hash.fdir.hi);
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    "ID=0x%x",
+						    mb->hash.fdir.hi);
 			else if (ol_flags & PKT_RX_FDIR_FLX)
-				printf("flex bytes=0x%08x %08x",
-				       mb->hash.fdir.hi, mb->hash.fdir.lo);
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    "flex bytes=0x%08x %08x",
+						    mb->hash.fdir.hi,
+						    mb->hash.fdir.lo);
 			else
-				printf("hash=0x%x ID=0x%x ",
-				       mb->hash.fdir.hash, mb->hash.fdir.id);
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    "hash=0x%x ID=0x%x ",
+						    mb->hash.fdir.hash,
+						    mb->hash.fdir.id);
 		}
 		if (is_timestamp_enabled(mb))
-			printf(" - timestamp %"PRIu64" ", get_timestamp(mb));
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - timestamp %"PRIu64" ",
+					    get_timestamp(mb));
 		if (ol_flags & PKT_RX_QINQ)
-			printf(" - QinQ VLAN tci=0x%x, VLAN tci outer=0x%x",
-			       mb->vlan_tci, mb->vlan_tci_outer);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - QinQ VLAN tci=0x%x, "
+					    "VLAN tci outer=0x%x",
+					    mb->vlan_tci,
+					    mb->vlan_tci_outer);
 		else if (ol_flags & PKT_RX_VLAN)
-			printf(" - VLAN tci=0x%x", mb->vlan_tci);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - VLAN tci=0x%x",
+					    mb->vlan_tci);
 		if (!is_rx && (ol_flags & PKT_TX_DYNF_METADATA))
-			printf(" - Tx metadata: 0x%x",
-			       *RTE_FLOW_DYNF_METADATA(mb));
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - Tx metadata: 0x%x",
+					    *RTE_FLOW_DYNF_METADATA(mb));
 		if (is_rx && (ol_flags & PKT_RX_DYNF_METADATA))
-			printf(" - Rx metadata: 0x%x",
-			       *RTE_FLOW_DYNF_METADATA(mb));
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - Rx metadata: 0x%x",
+					    *RTE_FLOW_DYNF_METADATA(mb));
 		for (dynf_index = 0; dynf_index < 64; dynf_index++) {
 			if (dynf_names[dynf_index][0] != '\0')
-				printf(" - dynf %s: %d",
-				       dynf_names[dynf_index],
-				       !!(ol_flags & (1UL << dynf_index)));
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - dynf %s: %d",
+						    dynf_names[dynf_index],
+						    !!(ol_flags &
+						    (1UL << dynf_index)));
 		}
 		if (mb->packet_type) {
 			rte_get_ptype_name(mb->packet_type, buf, sizeof(buf));
-			printf(" - hw ptype: %s", buf);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - hw ptype: %s", buf);
 		}
 		sw_packet_type = rte_net_get_ptype(mb, &hdr_lens,
 					RTE_PTYPE_ALL_MASK);
 		rte_get_ptype_name(sw_packet_type, buf, sizeof(buf));
-		printf(" - sw ptype: %s", buf);
+		cur_len += snprintf(print_buf + cur_len,
+				    buf_size - cur_len,
+				    " - sw ptype: %s", buf);
 		if (sw_packet_type & RTE_PTYPE_L2_MASK)
-			printf(" - l2_len=%d", hdr_lens.l2_len);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - l2_len=%d",
+					    hdr_lens.l2_len);
 		if (sw_packet_type & RTE_PTYPE_L3_MASK)
-			printf(" - l3_len=%d", hdr_lens.l3_len);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - l3_len=%d",
+					    hdr_lens.l3_len);
 		if (sw_packet_type & RTE_PTYPE_L4_MASK)
-			printf(" - l4_len=%d", hdr_lens.l4_len);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - l4_len=%d",
+					    hdr_lens.l4_len);
 		if (sw_packet_type & RTE_PTYPE_TUNNEL_MASK)
-			printf(" - tunnel_len=%d", hdr_lens.tunnel_len);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - tunnel_len=%d",
+					    hdr_lens.tunnel_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L2_MASK)
-			printf(" - inner_l2_len=%d", hdr_lens.inner_l2_len);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - inner_l2_len=%d",
+					    hdr_lens.inner_l2_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L3_MASK)
-			printf(" - inner_l3_len=%d", hdr_lens.inner_l3_len);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - inner_l3_len=%d",
+					    hdr_lens.inner_l3_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L4_MASK)
-			printf(" - inner_l4_len=%d", hdr_lens.inner_l4_len);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - inner_l4_len=%d",
+					    hdr_lens.inner_l4_len);
 		if (is_encapsulation) {
 			struct rte_ipv4_hdr *ipv4_hdr;
 			struct rte_ipv6_hdr *ipv6_hdr;
@@ -218,19 +316,37 @@
 				l2_len + l3_len + l4_len);
 				udp_port = RTE_BE_TO_CPU_16(udp_hdr->dst_port);
 				vx_vni = rte_be_to_cpu_32(vxlan_hdr->vx_vni);
-				printf(" - VXLAN packet: packet type =%d, "
-				       "Destination UDP port =%d, VNI = %d",
-				       packet_type, udp_port, vx_vni >> 8);
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - VXLAN packet: packet "
+						    "type =%d, Destination UDP "
+						    "port =%d, VNI = %d",
+						    packet_type, udp_port,
+						    vx_vni >> 8);
 			}
 		}
-		printf(" - %s queue=0x%x", is_rx ? "Receive" : "Send",
-			(unsigned int) queue);
-		printf("\n");
+		cur_len += snprintf(print_buf + cur_len,
+				    buf_size - cur_len,
+				    " - %s queue=0x%x",
+				    is_rx ? "Receive" : "Send",
+				    (unsigned int) queue);
+		cur_len += snprintf(print_buf + cur_len,
+				    buf_size - cur_len, "\n");
 		rte_get_rx_ol_flag_list(mb->ol_flags, buf, sizeof(buf));
-		printf("  ol_flags: %s\n", buf);
+		cur_len += snprintf(print_buf + cur_len,
+				    buf_size - cur_len,
+				    "  ol_flags: %s\n", buf);
 		if (rte_mbuf_check(mb, 1, &reason) < 0)
-			printf("INVALID mbuf: %s\n", reason);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    "INVALID mbuf: %s\n",
+					    reason);
 	}
+	if (cur_len >= buf_size)
+		TESTPMD_LOG(ERR, "no enough buffer (size: %d) to store "
+			    "the current dump output (size: %d)\n",
+			    buf_size, cur_len);
+	TESTPMD_LOG(INFO, "%s", print_buf);
 }
 
 uint16_t
-- 
1.8.3.1


^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH] app/testpmd: fix testpmd packets dump overlapping
  2020-11-12  8:36 [dpdk-dev] [PATCH] app/testpmd: fix testpmd packets dump overlapping Jiawei Wang
@ 2020-11-12 16:44 ` Ferruh Yigit
  2020-11-13 16:30   ` Jiawei(Jonny) Wang
  2020-11-14 12:01 ` [dpdk-dev] [PATCH v2] " Jiawei Wang
  1 sibling, 1 reply; 22+ messages in thread
From: Ferruh Yigit @ 2020-11-12 16:44 UTC (permalink / raw)
  To: Jiawei Wang, wenzhuo.lu, beilei.xing, bernard.iremonger, orika,
	thomas, rasland
  Cc: dev

On 11/12/2020 8:36 AM, Jiawei Wang wrote:
> When testpmd enabled the verbosity for the received packets, if two packets
> was received at the same time, for example, sampling packet and normal
> packet, the dump output of these packets may be overlapping due to multiple
> core handled the multiple queues simultaneously.
> 

Hi Jiawei,

Is the problem observer only when having sampling? Do you observe the problem 
when multiple cores Rx?

> The patch uses one string buffer that collects all the packet dump output
> into this buffer and then printout it at last, that guarantee to printout
> separately the dump output per packet.
> 
> Fixes: d862c45 ("app/testpmd: move dumping packets to a separate function")
> 
> Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
> ---
>   app/test-pmd/util.c | 238 ++++++++++++++++++++++++++++++++++++++--------------
>   1 file changed, 177 insertions(+), 61 deletions(-)
> 
> diff --git a/app/test-pmd/util.c b/app/test-pmd/util.c
> index 649bf8f..47b75b0 100644
> --- a/app/test-pmd/util.c
> +++ b/app/test-pmd/util.c
> @@ -12,15 +12,20 @@
>   #include <rte_vxlan.h>
>   #include <rte_ethdev.h>
>   #include <rte_flow.h>
> +#include <rte_log.h>
>   
>   #include "testpmd.h"
>   
> -static inline void
> -print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr)
> +#define MAX_STRING_LEN 8192
> +
> +static inline int
> +print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr,
> +		 char print_buf[], int buf_size)
>   {
>   	char buf[RTE_ETHER_ADDR_FMT_SIZE];
> +
>   	rte_ether_format_addr(buf, RTE_ETHER_ADDR_FMT_SIZE, eth_addr);
> -	printf("%s%s", what, buf);
> +	return snprintf(print_buf, buf_size, "%s%s", what, buf);
>   }
>   
>   static inline bool
> @@ -74,13 +79,18 @@
>   	uint32_t vx_vni;
>   	const char *reason;
>   	int dynf_index;
> +	int buf_size = MAX_STRING_LEN * nb_pkts;
> +	char print_buf[buf_size];

This is a large value to allocate from stack, specially with larger burst size. 
Allocating from heap is an option but it has a cost.

So what do you think print per packet, instead of print per burst? This also 
prevents display latency of the packet log.

> +	int cur_len = 0;
>   
> +	memset(print_buf, 0, sizeof(print_buf));
>   	if (!nb_pkts)
>   		return;
> -	printf("port %u/queue %u: %s %u packets\n",
> -		port_id, queue,
> -	       is_rx ? "received" : "sent",
> -	       (unsigned int) nb_pkts);
> +	cur_len += snprintf(print_buf + cur_len, buf_size - cur_len,
> +			    "port %u/queue %u: %s %u packets\n",
> +			    port_id, queue,
> +			    is_rx ? "received" : "sent",
> +			    (unsigned int) nb_pkts);
>   	for (i = 0; i < nb_pkts; i++) {
>   		int ret;
>   		struct rte_flow_error error;
> @@ -93,95 +103,183 @@
>   		is_encapsulation = RTE_ETH_IS_TUNNEL_PKT(packet_type);
>   		ret = rte_flow_get_restore_info(port_id, mb, &info, &error);
>   		if (!ret) {
> -			printf("restore info:");
> +			cur_len += snprintf(print_buf + cur_len,
> +					    buf_size - cur_len,
> +					    "restore info:");

This is not safe.
'snprintf' returns size of the required buffer size, not written chars, this can 
make "buf_size - cur_len" a negative value at some point, and since 'size' type 
is unsigned negative value will be converted into a very large number and this 
will corrupt the stack.

<...>

> +	if (cur_len >= buf_size)
> +		TESTPMD_LOG(ERR, "no enough buffer (size: %d) to store "
> +			    "the current dump output (size: %d)\n",
> +			    buf_size, cur_len);

Instead of this error log, which I believe not very useful, why not append some 
chars at the end of the actual buffer to say it is truncated, something like

  if (truncated)
    TESTPMD_LOG(INFO, "%s ...", print_buf);
  else
    TESTPMD_LOG(INFO, "%s", print_buf);

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH] app/testpmd: fix testpmd packets dump overlapping
  2020-11-12 16:44 ` Ferruh Yigit
@ 2020-11-13 16:30   ` Jiawei(Jonny) Wang
  0 siblings, 0 replies; 22+ messages in thread
From: Jiawei(Jonny) Wang @ 2020-11-13 16:30 UTC (permalink / raw)
  To: Ferruh Yigit, wenzhuo.lu, beilei.xing, bernard.iremonger,
	Ori Kam, NBU-Contact-Thomas Monjalon, Raslan Darawsheh
  Cc: dev

Hi Ferruh, 

Thanks for your comments.

> -----Original Message-----
> From: Ferruh Yigit <ferruh.yigit@intel.com>
> Sent: Friday, November 13, 2020 12:45 AM
> To: Jiawei(Jonny) Wang <jiaweiw@nvidia.com>; wenzhuo.lu@intel.com;
> beilei.xing@intel.com; bernard.iremonger@intel.com; Ori Kam
> <orika@nvidia.com>; NBU-Contact-Thomas Monjalon
> <thomas@monjalon.net>; Raslan Darawsheh <rasland@nvidia.com>
> Cc: dev@dpdk.org
> Subject: Re: [dpdk-dev] [PATCH] app/testpmd: fix testpmd packets dump
> overlapping
> 
> On 11/12/2020 8:36 AM, Jiawei Wang wrote:
> > When testpmd enabled the verbosity for the received packets, if two
> > packets was received at the same time, for example, sampling packet
> > and normal packet, the dump output of these packets may be overlapping
> > due to multiple core handled the multiple queues simultaneously.
> >
> 
> Hi Jiawei,
> 
> Is the problem observer only when having sampling? Do you observe the
> problem when multiple cores Rx?
We saw this problem happened easily with sampling.
And yes, I also can see the overlapping when multiple core RX if Traffic generator using test-pmd with --txonly-multi-flow.
> 
> > The patch uses one string buffer that collects all the packet dump
> > output into this buffer and then printout it at last, that guarantee
> > to printout separately the dump output per packet.
> >
> > Fixes: d862c45 ("app/testpmd: move dumping packets to a separate
> > function")
> >
> > Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
> > ---
> >   app/test-pmd/util.c | 238
> ++++++++++++++++++++++++++++++++++++++--------------
> >   1 file changed, 177 insertions(+), 61 deletions(-)
> >
> > diff --git a/app/test-pmd/util.c b/app/test-pmd/util.c index
> > 649bf8f..47b75b0 100644
> > --- a/app/test-pmd/util.c
> > +++ b/app/test-pmd/util.c
> > @@ -12,15 +12,20 @@
> >   #include <rte_vxlan.h>
> >   #include <rte_ethdev.h>
> >   #include <rte_flow.h>
> > +#include <rte_log.h>
> >
> >   #include "testpmd.h"
> >
> > -static inline void
> > -print_ether_addr(const char *what, const struct rte_ether_addr
> > *eth_addr)
> > +#define MAX_STRING_LEN 8192
> > +
> > +static inline int
> > +print_ether_addr(const char *what, const struct rte_ether_addr
> *eth_addr,
> > +		 char print_buf[], int buf_size)
> >   {
> >   	char buf[RTE_ETHER_ADDR_FMT_SIZE];
> > +
> >   	rte_ether_format_addr(buf, RTE_ETHER_ADDR_FMT_SIZE,
> eth_addr);
> > -	printf("%s%s", what, buf);
> > +	return snprintf(print_buf, buf_size, "%s%s", what, buf);
> >   }
> >
> >   static inline bool
> > @@ -74,13 +79,18 @@
> >   	uint32_t vx_vni;
> >   	const char *reason;
> >   	int dynf_index;
> > +	int buf_size = MAX_STRING_LEN * nb_pkts;
> > +	char print_buf[buf_size];
> 
> This is a large value to allocate from stack, specially with larger burst size.
> Allocating from heap is an option but it has a cost.
> 
> So what do you think print per packet, instead of print per burst? This also
> prevents display latency of the packet log.
Good idea, then we only need keep MAX_STRING_LEN stack size, each packet of burst can reuse the stack.
> 
> > +	int cur_len = 0;
> >
> > +	memset(print_buf, 0, sizeof(print_buf));
> >   	if (!nb_pkts)
> >   		return;
> > -	printf("port %u/queue %u: %s %u packets\n",
> > -		port_id, queue,
> > -	       is_rx ? "received" : "sent",
> > -	       (unsigned int) nb_pkts);
> > +	cur_len += snprintf(print_buf + cur_len, buf_size - cur_len,
> > +			    "port %u/queue %u: %s %u packets\n",
> > +			    port_id, queue,
> > +			    is_rx ? "received" : "sent",
> > +			    (unsigned int) nb_pkts);
> >   	for (i = 0; i < nb_pkts; i++) {
> >   		int ret;
> >   		struct rte_flow_error error;
> > @@ -93,95 +103,183 @@
> >   		is_encapsulation = RTE_ETH_IS_TUNNEL_PKT(packet_type);
> >   		ret = rte_flow_get_restore_info(port_id, mb, &info, &error);
> >   		if (!ret) {
> > -			printf("restore info:");
> > +			cur_len += snprintf(print_buf + cur_len,
> > +					    buf_size - cur_len,
> > +					    "restore info:");
> 
> This is not safe.
> 'snprintf' returns size of the required buffer size, not written chars, this can
> make "buf_size - cur_len" a negative value at some point, and since 'size'
> type is unsigned negative value will be converted into a very large number
> and this will corrupt the stack.
> 
Yes, so we need add the checking for each snprintf calls, if truncated happened, then print the current buffer  and dump will exit.
> <...>
> 
> > +	if (cur_len >= buf_size)
> > +		TESTPMD_LOG(ERR, "no enough buffer (size: %d) to store "
> > +			    "the current dump output (size: %d)\n",
> > +			    buf_size, cur_len);
> 
> Instead of this error log, which I believe not very useful, why not append
> some chars at the end of the actual buffer to say it is truncated, something
> like
> 
>   if (truncated)
>     TESTPMD_LOG(INFO, "%s ...", print_buf);
>   else
>     TESTPMD_LOG(INFO, "%s", print_buf);
ok, I will remove the err log and append the message like " the dump output was truncated ...".

I will send V2 patch for above changes.

Thanks.
Jonny

^ permalink raw reply	[flat|nested] 22+ messages in thread

* [dpdk-dev] [PATCH v2] app/testpmd: fix testpmd packets dump overlapping
  2020-11-12  8:36 [dpdk-dev] [PATCH] app/testpmd: fix testpmd packets dump overlapping Jiawei Wang
  2020-11-12 16:44 ` Ferruh Yigit
@ 2020-11-14 12:01 ` Jiawei Wang
  2020-11-17 12:06   ` Ferruh Yigit
  2020-11-20 17:35   ` [dpdk-dev] [PATCH v3] " Jiawei Wang
  1 sibling, 2 replies; 22+ messages in thread
From: Jiawei Wang @ 2020-11-14 12:01 UTC (permalink / raw)
  To: wenzhuo.lu, beilei.xing, bernard.iremonger, orika, thomas, rasland; +Cc: dev

When testpmd enabled the verbosity for the received packets, if two packets
was received at the same time, for example, sampling packet and normal
packet, the dump output of these packets may be overlapping due to multiple
core handled the multiple queues simultaneously.

The patch uses one string buffer that collects all the packet dump output
into this buffer and then printout it at last, that guarantee to printout
separately the dump output per packet.

Fixes: d862c45 ("app/testpmd: move dumping packets to a separate function")

Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
---
v2:
* Print dump output of per packet instead of per burst.
* Add the checking for return value of 'snprintf' and exit if required size exceed the print buffer size.
* Update the log messages.
---
 app/test-pmd/util.c | 378 ++++++++++++++++++++++++++++++++++++++++------------
 1 file changed, 295 insertions(+), 83 deletions(-)

diff --git a/app/test-pmd/util.c b/app/test-pmd/util.c
index 649bf8f..ffae590 100644
--- a/app/test-pmd/util.c
+++ b/app/test-pmd/util.c
@@ -12,15 +12,20 @@
 #include <rte_vxlan.h>
 #include <rte_ethdev.h>
 #include <rte_flow.h>
+#include <rte_log.h>
 
 #include "testpmd.h"
 
-static inline void
-print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr)
+#define MAX_STRING_LEN 8192
+
+static inline int
+print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr,
+		 char print_buf[], int buf_size)
 {
 	char buf[RTE_ETHER_ADDR_FMT_SIZE];
+
 	rte_ether_format_addr(buf, RTE_ETHER_ADDR_FMT_SIZE, eth_addr);
-	printf("%s%s", what, buf);
+	return snprintf(print_buf, buf_size, "%s%s", what, buf);
 }
 
 static inline bool
@@ -74,13 +79,18 @@
 	uint32_t vx_vni;
 	const char *reason;
 	int dynf_index;
+	int buf_size = MAX_STRING_LEN;
+	char print_buf[buf_size];
+	int cur_len = 0;
 
+	memset(print_buf, 0, sizeof(print_buf));
 	if (!nb_pkts)
 		return;
-	printf("port %u/queue %u: %s %u packets\n",
-		port_id, queue,
-	       is_rx ? "received" : "sent",
-	       (unsigned int) nb_pkts);
+	cur_len += snprintf(print_buf + cur_len, buf_size - cur_len,
+			    "port %u/queue %u: %s %u packets\n",
+			    port_id, queue,
+			    is_rx ? "received" : "sent",
+			    (unsigned int) nb_pkts);
 	for (i = 0; i < nb_pkts; i++) {
 		int ret;
 		struct rte_flow_error error;
@@ -93,95 +103,269 @@
 		is_encapsulation = RTE_ETH_IS_TUNNEL_PKT(packet_type);
 		ret = rte_flow_get_restore_info(port_id, mb, &info, &error);
 		if (!ret) {
-			printf("restore info:");
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    "restore info:");
+			if (cur_len >= buf_size)
+				goto error;
 			if (info.flags & RTE_FLOW_RESTORE_INFO_TUNNEL) {
 				struct port_flow_tunnel *port_tunnel;
 
 				port_tunnel = port_flow_locate_tunnel
 					      (port_id, &info.tunnel);
-				printf(" - tunnel");
-				if (port_tunnel)
-					printf(" #%u", port_tunnel->id);
-				else
-					printf(" %s", "-none-");
-				printf(" type %s",
-					port_flow_tunnel_type(&info.tunnel));
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - tunnel");
+				if (cur_len >= buf_size)
+					goto error;
+				if (port_tunnel) {
+					cur_len += snprintf(print_buf + cur_len,
+							    buf_size-cur_len,
+							    " #%u",
+							    port_tunnel->id);
+					if (cur_len >= buf_size)
+						goto error;
+				} else {
+					cur_len += snprintf(print_buf + cur_len,
+							    buf_size - cur_len,
+							    " %s",
+							    "-none-");
+					if (cur_len >= buf_size)
+						goto error;
+				}
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " type %s",
+						    port_flow_tunnel_type
+						    (&info.tunnel));
+				if (cur_len >= buf_size)
+					goto error;
 			} else {
-				printf(" - no tunnel info");
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - no tunnel info");
+				if (cur_len >= buf_size)
+					goto error;
 			}
-			if (info.flags & RTE_FLOW_RESTORE_INFO_ENCAPSULATED)
-				printf(" - outer header present");
-			else
-				printf(" - no outer header");
-			if (info.flags & RTE_FLOW_RESTORE_INFO_GROUP_ID)
-				printf(" - miss group %u", info.group_id);
-			else
-				printf(" - no miss group");
-			printf("\n");
+			if (info.flags & RTE_FLOW_RESTORE_INFO_ENCAPSULATED) {
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - outer header present");
+				if (cur_len >= buf_size)
+					goto error;
+			} else {
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - no outer header");
+				if (cur_len >= buf_size)
+					goto error;
+			}
+			if (info.flags & RTE_FLOW_RESTORE_INFO_GROUP_ID) {
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - miss group %u",
+						    info.group_id);
+				if (cur_len >= buf_size)
+					goto error;
+			} else {
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - no miss group");
+				if (cur_len >= buf_size)
+					goto error;
+			}
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len, "\n");
+			if (cur_len >= buf_size)
+				goto error;
 		}
-		print_ether_addr("  src=", &eth_hdr->s_addr);
-		print_ether_addr(" - dst=", &eth_hdr->d_addr);
-		printf(" - type=0x%04x - length=%u - nb_segs=%d",
-		       eth_type, (unsigned int) mb->pkt_len,
-		       (int)mb->nb_segs);
+		cur_len += print_ether_addr("  src=", &eth_hdr->s_addr,
+					    print_buf + cur_len,
+					    buf_size);
+		if (cur_len >= buf_size)
+			goto error;
+		cur_len += print_ether_addr(" - dst=", &eth_hdr->d_addr,
+					    print_buf + cur_len,
+					    buf_size);
+		if (cur_len >= buf_size)
+			goto error;
+		cur_len += snprintf(print_buf + cur_len, buf_size - cur_len,
+				    " - type=0x%04x - length=%u - nb_segs=%d",
+				    eth_type, (unsigned int) mb->pkt_len,
+				    (int)mb->nb_segs);
+		if (cur_len >= buf_size)
+			goto error;
 		ol_flags = mb->ol_flags;
 		if (ol_flags & PKT_RX_RSS_HASH) {
-			printf(" - RSS hash=0x%x", (unsigned int) mb->hash.rss);
-			printf(" - RSS queue=0x%x", (unsigned int) queue);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - RSS hash=0x%x",
+					    (unsigned int) mb->hash.rss);
+			if (cur_len >= buf_size)
+				goto error;
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - RSS queue=0x%x",
+					    (unsigned int) queue);
+			if (cur_len >= buf_size)
+				goto error;
 		}
 		if (ol_flags & PKT_RX_FDIR) {
-			printf(" - FDIR matched ");
-			if (ol_flags & PKT_RX_FDIR_ID)
-				printf("ID=0x%x",
-				       mb->hash.fdir.hi);
-			else if (ol_flags & PKT_RX_FDIR_FLX)
-				printf("flex bytes=0x%08x %08x",
-				       mb->hash.fdir.hi, mb->hash.fdir.lo);
-			else
-				printf("hash=0x%x ID=0x%x ",
-				       mb->hash.fdir.hash, mb->hash.fdir.id);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - FDIR matched ");
+			if (cur_len >= buf_size)
+				goto error;
+			if (ol_flags & PKT_RX_FDIR_ID) {
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    "ID=0x%x",
+						    mb->hash.fdir.hi);
+				if (cur_len >= buf_size)
+					goto error;
+			} else if (ol_flags & PKT_RX_FDIR_FLX) {
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    "flex bytes=0x%08x %08x",
+						    mb->hash.fdir.hi,
+						    mb->hash.fdir.lo);
+				if (cur_len >= buf_size)
+					goto error;
+			} else {
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    "hash=0x%x ID=0x%x ",
+						    mb->hash.fdir.hash,
+						    mb->hash.fdir.id);
+				if (cur_len >= buf_size)
+					goto error;
+			}
+		}
+		if (is_timestamp_enabled(mb)) {
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - timestamp %"PRIu64" ",
+					    get_timestamp(mb));
+			if (cur_len >= buf_size)
+				goto error;
+		}
+		if (ol_flags & PKT_RX_QINQ) {
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - QinQ VLAN tci=0x%x, "
+					    "VLAN tci outer=0x%x",
+					    mb->vlan_tci,
+					    mb->vlan_tci_outer);
+			if (cur_len >= buf_size)
+				goto error;
+		} else if (ol_flags & PKT_RX_VLAN) {
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - VLAN tci=0x%x",
+					    mb->vlan_tci);
+			if (cur_len >= buf_size)
+				goto error;
+		}
+		if (!is_rx && (ol_flags & PKT_TX_DYNF_METADATA)) {
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - Tx metadata: 0x%x",
+					    *RTE_FLOW_DYNF_METADATA(mb));
+			if (cur_len >= buf_size)
+				goto error;
+		}
+		if (is_rx && (ol_flags & PKT_RX_DYNF_METADATA)) {
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - Rx metadata: 0x%x",
+					    *RTE_FLOW_DYNF_METADATA(mb));
+			if (cur_len >= buf_size)
+				goto error;
 		}
-		if (is_timestamp_enabled(mb))
-			printf(" - timestamp %"PRIu64" ", get_timestamp(mb));
-		if (ol_flags & PKT_RX_QINQ)
-			printf(" - QinQ VLAN tci=0x%x, VLAN tci outer=0x%x",
-			       mb->vlan_tci, mb->vlan_tci_outer);
-		else if (ol_flags & PKT_RX_VLAN)
-			printf(" - VLAN tci=0x%x", mb->vlan_tci);
-		if (!is_rx && (ol_flags & PKT_TX_DYNF_METADATA))
-			printf(" - Tx metadata: 0x%x",
-			       *RTE_FLOW_DYNF_METADATA(mb));
-		if (is_rx && (ol_flags & PKT_RX_DYNF_METADATA))
-			printf(" - Rx metadata: 0x%x",
-			       *RTE_FLOW_DYNF_METADATA(mb));
 		for (dynf_index = 0; dynf_index < 64; dynf_index++) {
-			if (dynf_names[dynf_index][0] != '\0')
-				printf(" - dynf %s: %d",
-				       dynf_names[dynf_index],
-				       !!(ol_flags & (1UL << dynf_index)));
+			if (dynf_names[dynf_index][0] != '\0') {
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - dynf %s: %d",
+						    dynf_names[dynf_index],
+						    !!(ol_flags &
+						    (1UL << dynf_index)));
+				if (cur_len >= buf_size)
+					goto error;
+			}
 		}
 		if (mb->packet_type) {
 			rte_get_ptype_name(mb->packet_type, buf, sizeof(buf));
-			printf(" - hw ptype: %s", buf);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - hw ptype: %s", buf);
+			if (cur_len >= buf_size)
+				goto error;
 		}
 		sw_packet_type = rte_net_get_ptype(mb, &hdr_lens,
 					RTE_PTYPE_ALL_MASK);
 		rte_get_ptype_name(sw_packet_type, buf, sizeof(buf));
-		printf(" - sw ptype: %s", buf);
-		if (sw_packet_type & RTE_PTYPE_L2_MASK)
-			printf(" - l2_len=%d", hdr_lens.l2_len);
-		if (sw_packet_type & RTE_PTYPE_L3_MASK)
-			printf(" - l3_len=%d", hdr_lens.l3_len);
-		if (sw_packet_type & RTE_PTYPE_L4_MASK)
-			printf(" - l4_len=%d", hdr_lens.l4_len);
-		if (sw_packet_type & RTE_PTYPE_TUNNEL_MASK)
-			printf(" - tunnel_len=%d", hdr_lens.tunnel_len);
-		if (sw_packet_type & RTE_PTYPE_INNER_L2_MASK)
-			printf(" - inner_l2_len=%d", hdr_lens.inner_l2_len);
-		if (sw_packet_type & RTE_PTYPE_INNER_L3_MASK)
-			printf(" - inner_l3_len=%d", hdr_lens.inner_l3_len);
-		if (sw_packet_type & RTE_PTYPE_INNER_L4_MASK)
-			printf(" - inner_l4_len=%d", hdr_lens.inner_l4_len);
+		cur_len += snprintf(print_buf + cur_len,
+				    buf_size - cur_len,
+				    " - sw ptype: %s", buf);
+		if (cur_len >= buf_size)
+			goto error;
+		if (sw_packet_type & RTE_PTYPE_L2_MASK) {
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - l2_len=%d",
+					    hdr_lens.l2_len);
+			if (cur_len >= buf_size)
+				goto error;
+		}
+		if (sw_packet_type & RTE_PTYPE_L3_MASK) {
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - l3_len=%d",
+					    hdr_lens.l3_len);
+			if (cur_len >= buf_size)
+				goto error;
+		}
+		if (sw_packet_type & RTE_PTYPE_L4_MASK) {
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - l4_len=%d",
+					    hdr_lens.l4_len);
+			if (cur_len >= buf_size)
+				goto error;
+		}
+		if (sw_packet_type & RTE_PTYPE_TUNNEL_MASK) {
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - tunnel_len=%d",
+					    hdr_lens.tunnel_len);
+			if (cur_len >= buf_size)
+				goto error;
+		}
+		if (sw_packet_type & RTE_PTYPE_INNER_L2_MASK) {
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - inner_l2_len=%d",
+					    hdr_lens.inner_l2_len);
+			if (cur_len >= buf_size)
+				goto error;
+		}
+		if (sw_packet_type & RTE_PTYPE_INNER_L3_MASK) {
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - inner_l3_len=%d",
+					    hdr_lens.inner_l3_len);
+			if (cur_len >= buf_size)
+				goto error;
+		}
+		if (sw_packet_type & RTE_PTYPE_INNER_L4_MASK) {
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    " - inner_l4_len=%d",
+					    hdr_lens.inner_l4_len);
+			if (cur_len >= buf_size)
+				goto error;
+		}
 		if (is_encapsulation) {
 			struct rte_ipv4_hdr *ipv4_hdr;
 			struct rte_ipv6_hdr *ipv6_hdr;
@@ -218,19 +402,47 @@
 				l2_len + l3_len + l4_len);
 				udp_port = RTE_BE_TO_CPU_16(udp_hdr->dst_port);
 				vx_vni = rte_be_to_cpu_32(vxlan_hdr->vx_vni);
-				printf(" - VXLAN packet: packet type =%d, "
-				       "Destination UDP port =%d, VNI = %d",
-				       packet_type, udp_port, vx_vni >> 8);
+				cur_len += snprintf(print_buf + cur_len,
+						    buf_size - cur_len,
+						    " - VXLAN packet: packet "
+						    "type =%d, Destination UDP "
+						    "port =%d, VNI = %d",
+						    packet_type, udp_port,
+						    vx_vni >> 8);
+				if (cur_len >= buf_size)
+					goto error;
 			}
 		}
-		printf(" - %s queue=0x%x", is_rx ? "Receive" : "Send",
-			(unsigned int) queue);
-		printf("\n");
+		cur_len += snprintf(print_buf + cur_len,
+				    buf_size - cur_len,
+				    " - %s queue=0x%x",
+				    is_rx ? "Receive" : "Send",
+				    (unsigned int) queue);
+		if (cur_len >= buf_size)
+			goto error;
+		cur_len += snprintf(print_buf + cur_len,
+				    buf_size - cur_len, "\n");
+		if (cur_len >= buf_size)
+			goto error;
 		rte_get_rx_ol_flag_list(mb->ol_flags, buf, sizeof(buf));
-		printf("  ol_flags: %s\n", buf);
+		cur_len += snprintf(print_buf + cur_len,
+				    buf_size - cur_len,
+				    "  ol_flags: %s\n", buf);
+		if (cur_len >= buf_size)
+			goto error;
 		if (rte_mbuf_check(mb, 1, &reason) < 0)
-			printf("INVALID mbuf: %s\n", reason);
+			cur_len += snprintf(print_buf + cur_len,
+					    buf_size - cur_len,
+					    "INVALID mbuf: %s\n",
+					    reason);
+		if (cur_len >= buf_size)
+			goto error;
+		TESTPMD_LOG(INFO, "%s", print_buf);
+		cur_len = 0;
 	}
+	return;
+error:
+	TESTPMD_LOG(INFO, "%s the output was truncated ...\n", print_buf);
 }
 
 uint16_t
-- 
1.8.3.1


^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH v2] app/testpmd: fix testpmd packets dump overlapping
  2020-11-14 12:01 ` [dpdk-dev] [PATCH v2] " Jiawei Wang
@ 2020-11-17 12:06   ` Ferruh Yigit
  2020-11-18 18:09     ` Jiawei(Jonny) Wang
  2020-11-20 17:35   ` [dpdk-dev] [PATCH v3] " Jiawei Wang
  1 sibling, 1 reply; 22+ messages in thread
From: Ferruh Yigit @ 2020-11-17 12:06 UTC (permalink / raw)
  To: Jiawei Wang, wenzhuo.lu, beilei.xing, bernard.iremonger, orika,
	thomas, rasland
  Cc: dev

On 11/14/2020 12:01 PM, Jiawei Wang wrote:
> When testpmd enabled the verbosity for the received packets, if two packets
> was received at the same time, for example, sampling packet and normal
> packet, the dump output of these packets may be overlapping due to multiple
> core handled the multiple queues simultaneously.
> 
> The patch uses one string buffer that collects all the packet dump output
> into this buffer and then printout it at last, that guarantee to printout
> separately the dump output per packet.
> 
> Fixes: d862c45 ("app/testpmd: move dumping packets to a separate function")
> 
> Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
> ---
> v2:
> * Print dump output of per packet instead of per burst.
> * Add the checking for return value of 'snprintf' and exit if required size exceed the print buffer size.
> * Update the log messages.
> ---
>   app/test-pmd/util.c | 378 ++++++++++++++++++++++++++++++++++++++++------------
>   1 file changed, 295 insertions(+), 83 deletions(-)
> 
> diff --git a/app/test-pmd/util.c b/app/test-pmd/util.c
> index 649bf8f..ffae590 100644
> --- a/app/test-pmd/util.c
> +++ b/app/test-pmd/util.c
> @@ -12,15 +12,20 @@
>   #include <rte_vxlan.h>
>   #include <rte_ethdev.h>
>   #include <rte_flow.h>
> +#include <rte_log.h>
>   
>   #include "testpmd.h"
>   
> -static inline void
> -print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr)
> +#define MAX_STRING_LEN 8192

Isn't '8192' too large for a single packet, what do you think for '2048'?

<...>

> @@ -93,95 +103,269 @@
>   		is_encapsulation = RTE_ETH_IS_TUNNEL_PKT(packet_type);
>   		ret = rte_flow_get_restore_info(port_id, mb, &info, &error);
>   		if (!ret) {
> -			printf("restore info:");
> +			cur_len += snprintf(print_buf + cur_len,
> +					    buf_size - cur_len,
> +					    "restore info:");

What do you think having a macro like below to simplfy the code:

  #define FOO(buf, buf_size, cur_len, ...) \
  do { \
         if (cur_len >= buf_size) break; \
         cur_len += snprintf(buf + cur_len, buf_size - cur_len, __VA_ARGS__); \
  } while (0)

It can be used as:
  FOO(print_buf, buf_size, cur_len, "restore info:");

> +			if (cur_len >= buf_size)
> +				goto error;

This 'goto' goes out of the loop, not sure about breking the loop and not 
processing all packets if buffer is out of space for one of the packets.
Anyway if you switch to macro above, the 'goto' is removed completely.

<...>

> +		if (cur_len >= buf_size)
> +			goto error;
> +		TESTPMD_LOG(INFO, "%s", print_buf);

Using 'TESTPMD_LOG' appends "testpmd: " at the beggining of the each line, for 
this case it is noise I think, what do you think turning back to printf() as 
done originally?

> +		cur_len = 0;
>   	}
> +	return;
> +error:
> +	TESTPMD_LOG(INFO, "%s the output was truncated ...\n", print_buf);

What do you think having something shorter to notify the truncation, I think 
some special chars can work better, something like "...", "@@", "-->", "???" ?

>   }
>   
>   uint16_t
> 


^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH v2] app/testpmd: fix testpmd packets dump overlapping
  2020-11-17 12:06   ` Ferruh Yigit
@ 2020-11-18 18:09     ` Jiawei(Jonny) Wang
  2020-11-19 10:30       ` Ferruh Yigit
  0 siblings, 1 reply; 22+ messages in thread
From: Jiawei(Jonny) Wang @ 2020-11-18 18:09 UTC (permalink / raw)
  To: Ferruh Yigit, wenzhuo.lu, beilei.xing, bernard.iremonger,
	Ori Kam, NBU-Contact-Thomas Monjalon, Raslan Darawsheh
  Cc: dev

Hi Ferruh,

> -----Original Message-----
> From: Ferruh Yigit <ferruh.yigit@intel.com>
> Sent: Tuesday, November 17, 2020 8:07 PM
> To: Jiawei(Jonny) Wang <jiaweiw@nvidia.com>; wenzhuo.lu@intel.com;
> beilei.xing@intel.com; bernard.iremonger@intel.com; Ori Kam
> <orika@nvidia.com>; NBU-Contact-Thomas Monjalon
> <thomas@monjalon.net>; Raslan Darawsheh <rasland@nvidia.com>
> Cc: dev@dpdk.org
> Subject: Re: [dpdk-dev] [PATCH v2] app/testpmd: fix testpmd packets dump
> overlapping
> 
> On 11/14/2020 12:01 PM, Jiawei Wang wrote:
> > When testpmd enabled the verbosity for the received packets, if two
> > packets was received at the same time, for example, sampling packet
> > and normal packet, the dump output of these packets may be overlapping
> > due to multiple core handled the multiple queues simultaneously.
> >
> > The patch uses one string buffer that collects all the packet dump
> > output into this buffer and then printout it at last, that guarantee
> > to printout separately the dump output per packet.
> >
> > Fixes: d862c45 ("app/testpmd: move dumping packets to a separate
> > function")
> >
> > Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
> > ---
> > v2:
> > * Print dump output of per packet instead of per burst.
> > * Add the checking for return value of 'snprintf' and exit if required size
> exceed the print buffer size.
> > * Update the log messages.
> > ---
> >   app/test-pmd/util.c | 378
> ++++++++++++++++++++++++++++++++++++++++------------
> >   1 file changed, 295 insertions(+), 83 deletions(-)
> >
> > diff --git a/app/test-pmd/util.c b/app/test-pmd/util.c index
> > 649bf8f..ffae590 100644
> > --- a/app/test-pmd/util.c
> > +++ b/app/test-pmd/util.c
> > @@ -12,15 +12,20 @@
> >   #include <rte_vxlan.h>
> >   #include <rte_ethdev.h>
> >   #include <rte_flow.h>
> > +#include <rte_log.h>
> >
> >   #include "testpmd.h"
> >
> > -static inline void
> > -print_ether_addr(const char *what, const struct rte_ether_addr
> > *eth_addr)
> > +#define MAX_STRING_LEN 8192
> 
> Isn't '8192' too large for a single packet, what do you think for '2048'?
> 
2K is ok for the normal case, here consider the case that registered mbuf dynamic flags names, 
Then total maximum length can reach to   64* RTE_MBUF_DYN_NAMESIZE = 4096
 // char dynf_names[64][RTE_MBUF_DYN_NAMESIZE];
So 2048 is not enough if all dynf_names be configured as maximum length of dyn_names.

How about the 5K? I think should be enough for now.
> <...>
> 
> > @@ -93,95 +103,269 @@
> >   		is_encapsulation = RTE_ETH_IS_TUNNEL_PKT(packet_type);
> >   		ret = rte_flow_get_restore_info(port_id, mb, &info, &error);
> >   		if (!ret) {
> > -			printf("restore info:");
> > +			cur_len += snprintf(print_buf + cur_len,
> > +					    buf_size - cur_len,
> > +					    "restore info:");
> 
> What do you think having a macro like below to simplfy the code:
> 
>   #define FOO(buf, buf_size, cur_len, ...) \
>   do { \
>          if (cur_len >= buf_size) break; \
>          cur_len += snprintf(buf + cur_len, buf_size - cur_len, __VA_ARGS__); \
>   } while (0)
> 
> It can be used as:
>   FOO(print_buf, buf_size, cur_len, "restore info:");
> 
Agree, will move these common code into a MARCO, 
I will use the  "MKDUMPSTR" as MARCO name,  means that  making a dump string buffer.

> > +			if (cur_len >= buf_size)
> > +				goto error;
> 
> This 'goto' goes out of the loop, not sure about breking the loop and not
> processing all packets if buffer is out of space for one of the packets.
> Anyway if you switch to macro above, the 'goto' is removed completely.
> 
Use 'break' only break the do{} while and continue to following processing, but won't filled anymore into printbuf since it will break firstly in the MARCO checking.
Or could use 'goto lable' instead 'break' in the marco?
> <...>
> 
> > +		if (cur_len >= buf_size)
> > +			goto error;
> > +		TESTPMD_LOG(INFO, "%s", print_buf);
> 
> Using 'TESTPMD_LOG' appends "testpmd: " at the beggining of the each line,
> for this case it is noise I think, what do you think turning back to printf() as
> done originally?
> 
ok, will use the printf.
> > +		cur_len = 0;
> >   	}
> > +	return;
> > +error:
> > +	TESTPMD_LOG(INFO, "%s the output was truncated ...\n", print_buf);
> 
> What do you think having something shorter to notify the truncation, I think
> some special chars can work better, something like "...", "@@", "-->", "???" ?
> 
ok, I will use simple chars  for truncated case like below:
		if (cur_len >= buf_size)
			printf("%s ...\n", print_buf);
	
> >   }
> >
> >   uint16_t
> >

Thanks for your comments, I will do the changes and send V3 patch.

Thanks.
Jonny

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH v2] app/testpmd: fix testpmd packets dump overlapping
  2020-11-18 18:09     ` Jiawei(Jonny) Wang
@ 2020-11-19 10:30       ` Ferruh Yigit
  0 siblings, 0 replies; 22+ messages in thread
From: Ferruh Yigit @ 2020-11-19 10:30 UTC (permalink / raw)
  To: Jiawei(Jonny) Wang, wenzhuo.lu, beilei.xing, bernard.iremonger,
	Ori Kam, NBU-Contact-Thomas Monjalon, Raslan Darawsheh
  Cc: dev

On 11/18/2020 6:09 PM, Jiawei(Jonny) Wang wrote:
> Hi Ferruh,
> 
>> -----Original Message-----
>> From: Ferruh Yigit <ferruh.yigit@intel.com>
>> Sent: Tuesday, November 17, 2020 8:07 PM
>> To: Jiawei(Jonny) Wang <jiaweiw@nvidia.com>; wenzhuo.lu@intel.com;
>> beilei.xing@intel.com; bernard.iremonger@intel.com; Ori Kam
>> <orika@nvidia.com>; NBU-Contact-Thomas Monjalon
>> <thomas@monjalon.net>; Raslan Darawsheh <rasland@nvidia.com>
>> Cc: dev@dpdk.org
>> Subject: Re: [dpdk-dev] [PATCH v2] app/testpmd: fix testpmd packets dump
>> overlapping
>>
>> On 11/14/2020 12:01 PM, Jiawei Wang wrote:
>>> When testpmd enabled the verbosity for the received packets, if two
>>> packets was received at the same time, for example, sampling packet
>>> and normal packet, the dump output of these packets may be overlapping
>>> due to multiple core handled the multiple queues simultaneously.
>>>
>>> The patch uses one string buffer that collects all the packet dump
>>> output into this buffer and then printout it at last, that guarantee
>>> to printout separately the dump output per packet.
>>>
>>> Fixes: d862c45 ("app/testpmd: move dumping packets to a separate
>>> function")
>>>
>>> Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
>>> ---
>>> v2:
>>> * Print dump output of per packet instead of per burst.
>>> * Add the checking for return value of 'snprintf' and exit if required size
>> exceed the print buffer size.
>>> * Update the log messages.
>>> ---
>>>    app/test-pmd/util.c | 378
>> ++++++++++++++++++++++++++++++++++++++++------------
>>>    1 file changed, 295 insertions(+), 83 deletions(-)
>>>
>>> diff --git a/app/test-pmd/util.c b/app/test-pmd/util.c index
>>> 649bf8f..ffae590 100644
>>> --- a/app/test-pmd/util.c
>>> +++ b/app/test-pmd/util.c
>>> @@ -12,15 +12,20 @@
>>>    #include <rte_vxlan.h>
>>>    #include <rte_ethdev.h>
>>>    #include <rte_flow.h>
>>> +#include <rte_log.h>
>>>
>>>    #include "testpmd.h"
>>>
>>> -static inline void
>>> -print_ether_addr(const char *what, const struct rte_ether_addr
>>> *eth_addr)
>>> +#define MAX_STRING_LEN 8192
>>
>> Isn't '8192' too large for a single packet, what do you think for '2048'?
>>
> 2K is ok for the normal case, here consider the case that registered mbuf dynamic flags names,
> Then total maximum length can reach to   64* RTE_MBUF_DYN_NAMESIZE = 4096
>   // char dynf_names[64][RTE_MBUF_DYN_NAMESIZE];
> So 2048 is not enough if all dynf_names be configured as maximum length of dyn_names.
> 
> How about the 5K? I think should be enough for now.

OK, and no need to be tight, if there are cases requesting longer string perhaps 
can keep the size as it is.

>> <...>
>>
>>> @@ -93,95 +103,269 @@
>>>    		is_encapsulation = RTE_ETH_IS_TUNNEL_PKT(packet_type);
>>>    		ret = rte_flow_get_restore_info(port_id, mb, &info, &error);
>>>    		if (!ret) {
>>> -			printf("restore info:");
>>> +			cur_len += snprintf(print_buf + cur_len,
>>> +					    buf_size - cur_len,
>>> +					    "restore info:");
>>
>> What do you think having a macro like below to simplfy the code:
>>
>>    #define FOO(buf, buf_size, cur_len, ...) \
>>    do { \
>>           if (cur_len >= buf_size) break; \
>>           cur_len += snprintf(buf + cur_len, buf_size - cur_len, __VA_ARGS__); \
>>    } while (0)
>>
>> It can be used as:
>>    FOO(print_buf, buf_size, cur_len, "restore info:");
>>
> Agree, will move these common code into a MARCO,
> I will use the  "MKDUMPSTR" as MARCO name,  means that  making a dump string buffer.
> 

Ack

>>> +			if (cur_len >= buf_size)
>>> +				goto error;
>>
>> This 'goto' goes out of the loop, not sure about breking the loop and not
>> processing all packets if buffer is out of space for one of the packets.
>> Anyway if you switch to macro above, the 'goto' is removed completely.
>>
> Use 'break' only break the do{} while and continue to following processing, but won't filled anymore into printbuf since it will break firstly in the MARCO checking.
> Or could use 'goto lable' instead 'break' in the marco?

I think cleaner to not have the 'goto', yes processing will continue but no 
space left case expected to happen very rare.

^ permalink raw reply	[flat|nested] 22+ messages in thread

* [dpdk-dev] [PATCH v3] app/testpmd: fix testpmd packets dump overlapping
  2020-11-14 12:01 ` [dpdk-dev] [PATCH v2] " Jiawei Wang
  2020-11-17 12:06   ` Ferruh Yigit
@ 2020-11-20 17:35   ` Jiawei Wang
  2020-11-20 17:50     ` Ferruh Yigit
  2020-11-23  8:29     ` [dpdk-dev] [PATCH v4] " Jiawei Wang
  1 sibling, 2 replies; 22+ messages in thread
From: Jiawei Wang @ 2020-11-20 17:35 UTC (permalink / raw)
  To: ferruh.yigit, wenzhuo.lu, beilei.xing, bernard.iremonger, orika,
	viacheslavo, thomas, rasland
  Cc: dev

When testpmd enabled the verbosity for the received packets, if two packets
were received at the same time, for example, sampling packet and normal
packet, the dump output of these packets may be overlapping due to multiple
core handling the multiple queues simultaneously.

The patch uses one string buffer that collects all the packet dump output
into this buffer and then printouts it at last, that guarantees to printout
separately the dump output per packet.

Fixes: d862c45 ("app/testpmd: move dumping packets to a separate function")

Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
---
v3:
* Use the marco instead of function calls to simplfy code.
* Use the shorter chars '...' append into the dump to notify the truncation.
* Update the commit message.
* Rebase.

v2:
* Print dump output of per packet instead of per burst.
* Add the checking for return value of 'snprintf' and exit if required size exceed the print buffer size.
* Update the log messages.
---
 app/test-pmd/util.c | 177 ++++++++++++++++++++++++++++++++++------------------
 1 file changed, 117 insertions(+), 60 deletions(-)

diff --git a/app/test-pmd/util.c b/app/test-pmd/util.c
index 649bf8f..c92811f 100644
--- a/app/test-pmd/util.c
+++ b/app/test-pmd/util.c
@@ -15,12 +15,23 @@
 
 #include "testpmd.h"
 
+#define MAX_STRING_LEN 8192
+
+#define MKDUMPSTR(buf, buf_size, cur_len, ...) \
+do { \
+	if (cur_len >= buf_size) \
+		break; \
+	cur_len += snprintf(buf + cur_len, buf_size - cur_len, __VA_ARGS__); \
+} while (0)
+
 static inline void
-print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr)
+print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr,
+		 char print_buf[], int buf_size, int *cur_len)
 {
 	char buf[RTE_ETHER_ADDR_FMT_SIZE];
+
 	rte_ether_format_addr(buf, RTE_ETHER_ADDR_FMT_SIZE, eth_addr);
-	printf("%s%s", what, buf);
+	MKDUMPSTR(print_buf, buf_size, *cur_len, "%s%s", what, buf);
 }
 
 static inline bool
@@ -74,13 +85,16 @@
 	uint32_t vx_vni;
 	const char *reason;
 	int dynf_index;
+	int buf_size = MAX_STRING_LEN;
+	char print_buf[buf_size];
+	int cur_len = 0;
 
+	memset(print_buf, 0, sizeof(print_buf));
 	if (!nb_pkts)
 		return;
-	printf("port %u/queue %u: %s %u packets\n",
-		port_id, queue,
-	       is_rx ? "received" : "sent",
-	       (unsigned int) nb_pkts);
+	MKDUMPSTR(print_buf, buf_size, cur_len,
+		  "port %u/queue %u: %s %u packets\n", port_id, queue,
+		  is_rx ? "received" : "sent", (unsigned int) nb_pkts);
 	for (i = 0; i < nb_pkts; i++) {
 		int ret;
 		struct rte_flow_error error;
@@ -93,95 +107,128 @@
 		is_encapsulation = RTE_ETH_IS_TUNNEL_PKT(packet_type);
 		ret = rte_flow_get_restore_info(port_id, mb, &info, &error);
 		if (!ret) {
-			printf("restore info:");
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  "restore info:");
 			if (info.flags & RTE_FLOW_RESTORE_INFO_TUNNEL) {
 				struct port_flow_tunnel *port_tunnel;
 
 				port_tunnel = port_flow_locate_tunnel
 					      (port_id, &info.tunnel);
-				printf(" - tunnel");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - tunnel");
 				if (port_tunnel)
-					printf(" #%u", port_tunnel->id);
+					MKDUMPSTR(print_buf, buf_size, cur_len,
+						  " #%u", port_tunnel->id);
 				else
-					printf(" %s", "-none-");
-				printf(" type %s",
-					port_flow_tunnel_type(&info.tunnel));
+					MKDUMPSTR(print_buf, buf_size, cur_len,
+						  " %s", "-none-");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " type %s", port_flow_tunnel_type
+					  (&info.tunnel));
 			} else {
-				printf(" - no tunnel info");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no tunnel info");
 			}
 			if (info.flags & RTE_FLOW_RESTORE_INFO_ENCAPSULATED)
-				printf(" - outer header present");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - outer header present");
 			else
-				printf(" - no outer header");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no outer header");
 			if (info.flags & RTE_FLOW_RESTORE_INFO_GROUP_ID)
-				printf(" - miss group %u", info.group_id);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - miss group %u", info.group_id);
 			else
-				printf(" - no miss group");
-			printf("\n");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no miss group");
+			MKDUMPSTR(print_buf, buf_size, cur_len, "\n");
 		}
-		print_ether_addr("  src=", &eth_hdr->s_addr);
-		print_ether_addr(" - dst=", &eth_hdr->d_addr);
-		printf(" - type=0x%04x - length=%u - nb_segs=%d",
-		       eth_type, (unsigned int) mb->pkt_len,
-		       (int)mb->nb_segs);
+		print_ether_addr("  src=", &eth_hdr->s_addr,
+				 print_buf, buf_size, &cur_len);
+		print_ether_addr(" - dst=", &eth_hdr->d_addr,
+				 print_buf, buf_size, &cur_len);
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  " - type=0x%04x - length=%u - nb_segs=%d",
+			  eth_type, (unsigned int) mb->pkt_len,
+			  (int)mb->nb_segs);
 		ol_flags = mb->ol_flags;
 		if (ol_flags & PKT_RX_RSS_HASH) {
-			printf(" - RSS hash=0x%x", (unsigned int) mb->hash.rss);
-			printf(" - RSS queue=0x%x", (unsigned int) queue);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - RSS hash=0x%x",
+				  (unsigned int) mb->hash.rss);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - RSS queue=0x%x", (unsigned int) queue);
 		}
 		if (ol_flags & PKT_RX_FDIR) {
-			printf(" - FDIR matched ");
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - FDIR matched ");
 			if (ol_flags & PKT_RX_FDIR_ID)
-				printf("ID=0x%x",
-				       mb->hash.fdir.hi);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "ID=0x%x", mb->hash.fdir.hi);
 			else if (ol_flags & PKT_RX_FDIR_FLX)
-				printf("flex bytes=0x%08x %08x",
-				       mb->hash.fdir.hi, mb->hash.fdir.lo);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "flex bytes=0x%08x %08x",
+					  mb->hash.fdir.hi, mb->hash.fdir.lo);
 			else
-				printf("hash=0x%x ID=0x%x ",
-				       mb->hash.fdir.hash, mb->hash.fdir.id);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "hash=0x%x ID=0x%x ",
+					  mb->hash.fdir.hash, mb->hash.fdir.id);
 		}
 		if (is_timestamp_enabled(mb))
-			printf(" - timestamp %"PRIu64" ", get_timestamp(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - timestamp %"PRIu64" ", get_timestamp(mb));
 		if (ol_flags & PKT_RX_QINQ)
-			printf(" - QinQ VLAN tci=0x%x, VLAN tci outer=0x%x",
-			       mb->vlan_tci, mb->vlan_tci_outer);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - QinQ VLAN tci=0x%x, VLAN tci outer=0x%x",
+				  mb->vlan_tci, mb->vlan_tci_outer);
 		else if (ol_flags & PKT_RX_VLAN)
-			printf(" - VLAN tci=0x%x", mb->vlan_tci);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - VLAN tci=0x%x", mb->vlan_tci);
 		if (!is_rx && (ol_flags & PKT_TX_DYNF_METADATA))
-			printf(" - Tx metadata: 0x%x",
-			       *RTE_FLOW_DYNF_METADATA(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - Tx metadata: 0x%x",
+				  *RTE_FLOW_DYNF_METADATA(mb));
 		if (is_rx && (ol_flags & PKT_RX_DYNF_METADATA))
-			printf(" - Rx metadata: 0x%x",
-			       *RTE_FLOW_DYNF_METADATA(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - Rx metadata: 0x%x",
+				  *RTE_FLOW_DYNF_METADATA(mb));
 		for (dynf_index = 0; dynf_index < 64; dynf_index++) {
 			if (dynf_names[dynf_index][0] != '\0')
-				printf(" - dynf %s: %d",
-				       dynf_names[dynf_index],
-				       !!(ol_flags & (1UL << dynf_index)));
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - dynf %s: %d",
+					  dynf_names[dynf_index],
+					  !!(ol_flags & (1UL << dynf_index)));
 		}
 		if (mb->packet_type) {
 			rte_get_ptype_name(mb->packet_type, buf, sizeof(buf));
-			printf(" - hw ptype: %s", buf);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - hw ptype: %s", buf);
 		}
 		sw_packet_type = rte_net_get_ptype(mb, &hdr_lens,
 					RTE_PTYPE_ALL_MASK);
 		rte_get_ptype_name(sw_packet_type, buf, sizeof(buf));
-		printf(" - sw ptype: %s", buf);
+		MKDUMPSTR(print_buf, buf_size, cur_len, " - sw ptype: %s", buf);
 		if (sw_packet_type & RTE_PTYPE_L2_MASK)
-			printf(" - l2_len=%d", hdr_lens.l2_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l2_len=%d",
+				  hdr_lens.l2_len);
 		if (sw_packet_type & RTE_PTYPE_L3_MASK)
-			printf(" - l3_len=%d", hdr_lens.l3_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l3_len=%d",
+				  hdr_lens.l3_len);
 		if (sw_packet_type & RTE_PTYPE_L4_MASK)
-			printf(" - l4_len=%d", hdr_lens.l4_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l4_len=%d",
+				  hdr_lens.l4_len);
 		if (sw_packet_type & RTE_PTYPE_TUNNEL_MASK)
-			printf(" - tunnel_len=%d", hdr_lens.tunnel_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - tunnel_len=%d", hdr_lens.tunnel_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L2_MASK)
-			printf(" - inner_l2_len=%d", hdr_lens.inner_l2_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l2_len=%d", hdr_lens.inner_l2_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L3_MASK)
-			printf(" - inner_l3_len=%d", hdr_lens.inner_l3_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l3_len=%d", hdr_lens.inner_l3_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L4_MASK)
-			printf(" - inner_l4_len=%d", hdr_lens.inner_l4_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l4_len=%d", hdr_lens.inner_l4_len);
 		if (is_encapsulation) {
 			struct rte_ipv4_hdr *ipv4_hdr;
 			struct rte_ipv6_hdr *ipv6_hdr;
@@ -218,18 +265,28 @@
 				l2_len + l3_len + l4_len);
 				udp_port = RTE_BE_TO_CPU_16(udp_hdr->dst_port);
 				vx_vni = rte_be_to_cpu_32(vxlan_hdr->vx_vni);
-				printf(" - VXLAN packet: packet type =%d, "
-				       "Destination UDP port =%d, VNI = %d",
-				       packet_type, udp_port, vx_vni >> 8);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - VXLAN packet: packet type =%d, "
+					  "Destination UDP port =%d, VNI = %d",
+					  packet_type, udp_port, vx_vni >> 8);
 			}
 		}
-		printf(" - %s queue=0x%x", is_rx ? "Receive" : "Send",
-			(unsigned int) queue);
-		printf("\n");
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  " - %s queue=0x%x", is_rx ? "Receive" : "Send",
+			  (unsigned int) queue);
+		MKDUMPSTR(print_buf, buf_size, cur_len, "\n");
 		rte_get_rx_ol_flag_list(mb->ol_flags, buf, sizeof(buf));
-		printf("  ol_flags: %s\n", buf);
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  "  ol_flags: %s\n", buf);
 		if (rte_mbuf_check(mb, 1, &reason) < 0)
-			printf("INVALID mbuf: %s\n", reason);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  "INVALID mbuf: %s\n", reason);
+		if (cur_len >= buf_size) {
+			printf("%s ...\n", print_buf);
+			break;
+		}
+		printf("%s", print_buf);
+		cur_len = 0;
 	}
 }
 
-- 
1.8.3.1


^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH v3] app/testpmd: fix testpmd packets dump overlapping
  2020-11-20 17:35   ` [dpdk-dev] [PATCH v3] " Jiawei Wang
@ 2020-11-20 17:50     ` Ferruh Yigit
  2020-11-23  6:13       ` Jiawei(Jonny) Wang
  2020-11-23  8:29     ` [dpdk-dev] [PATCH v4] " Jiawei Wang
  1 sibling, 1 reply; 22+ messages in thread
From: Ferruh Yigit @ 2020-11-20 17:50 UTC (permalink / raw)
  To: Jiawei Wang, wenzhuo.lu, beilei.xing, bernard.iremonger, orika,
	viacheslavo, thomas, rasland
  Cc: dev

On 11/20/2020 5:35 PM, Jiawei Wang wrote:
> When testpmd enabled the verbosity for the received packets, if two packets
> were received at the same time, for example, sampling packet and normal
> packet, the dump output of these packets may be overlapping due to multiple
> core handling the multiple queues simultaneously.
> 
> The patch uses one string buffer that collects all the packet dump output
> into this buffer and then printouts it at last, that guarantees to printout
> separately the dump output per packet.
> 
> Fixes: d862c45 ("app/testpmd: move dumping packets to a separate function")
> 
> Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>

<...>

> @@ -74,13 +85,16 @@
>   	uint32_t vx_vni;
>   	const char *reason;
>   	int dynf_index;
> +	int buf_size = MAX_STRING_LEN;
> +	char print_buf[buf_size];
> +	int cur_len = 0;
>   
> +	memset(print_buf, 0, sizeof(print_buf));

Should 'print_buf' cleaned per each packet below, if not can we drop 'memset' 
completely?

<...>

> +		if (cur_len >= buf_size) {
> +			printf("%s ...\n", print_buf);
> +			break;

Why break here? Wouldn't just append some chars to indicate trancation and 
continue be OK?




^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH v3] app/testpmd: fix testpmd packets dump overlapping
  2020-11-20 17:50     ` Ferruh Yigit
@ 2020-11-23  6:13       ` Jiawei(Jonny) Wang
  2020-11-23 10:22         ` Ferruh Yigit
  0 siblings, 1 reply; 22+ messages in thread
From: Jiawei(Jonny) Wang @ 2020-11-23  6:13 UTC (permalink / raw)
  To: Ferruh Yigit, wenzhuo.lu, beilei.xing, bernard.iremonger,
	Ori Kam, Slava Ovsiienko, NBU-Contact-Thomas Monjalon,
	Raslan Darawsheh
  Cc: dev

Hi Ferruh,

> -----Original Message-----
> From: Ferruh Yigit <ferruh.yigit@intel.com>
> Sent: Saturday, November 21, 2020 1:50 AM
> To: Jiawei(Jonny) Wang <jiaweiw@nvidia.com>; wenzhuo.lu@intel.com;
> beilei.xing@intel.com; bernard.iremonger@intel.com; Ori Kam
> <orika@nvidia.com>; Slava Ovsiienko <viacheslavo@nvidia.com>; NBU-
> Contact-Thomas Monjalon <thomas@monjalon.net>; Raslan Darawsheh
> <rasland@nvidia.com>
> Cc: dev@dpdk.org
> Subject: Re: [PATCH v3] app/testpmd: fix testpmd packets dump overlapping
> 
> On 11/20/2020 5:35 PM, Jiawei Wang wrote:
> > When testpmd enabled the verbosity for the received packets, if two
> > packets were received at the same time, for example, sampling packet
> > and normal packet, the dump output of these packets may be overlapping
> > due to multiple core handling the multiple queues simultaneously.
> >
> > The patch uses one string buffer that collects all the packet dump
> > output into this buffer and then printouts it at last, that guarantees
> > to printout separately the dump output per packet.
> >
> > Fixes: d862c45 ("app/testpmd: move dumping packets to a separate
> > function")
> >
> > Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
> 
> <...>
> 
> > @@ -74,13 +85,16 @@
> >   	uint32_t vx_vni;
> >   	const char *reason;
> >   	int dynf_index;
> > +	int buf_size = MAX_STRING_LEN;
> > +	char print_buf[buf_size];
> > +	int cur_len = 0;
> >
> > +	memset(print_buf, 0, sizeof(print_buf));
> 
> Should 'print_buf' cleaned per each packet below, if not can we drop 'memset'
> completely?
> 
Since the 'snprintf' always append the a terminating null character('\0') after the written string,
and in the code the following character be appended start from previous null character, so only one 
'\0' will be appended in the last 'snprintf' calls, 
	snprintf(buf + cur_len, buf_size - cur_len ..
At the last 'printf("%s") will print the string buffer up to a terminating null character ('\0').
so it's ok even not 'memset' calls to clean 'print_buf' per each packets. 
> <...>
> 
> > +		if (cur_len >= buf_size) {
> > +			printf("%s ...\n", print_buf);
> > +			break;
> 
> Why break here? Wouldn't just append some chars to indicate trancation and
> continue be OK?
> 
> 
Yes, doesn't  need 'break'  here.


^ permalink raw reply	[flat|nested] 22+ messages in thread

* [dpdk-dev] [PATCH v4] app/testpmd: fix testpmd packets dump overlapping
  2020-11-20 17:35   ` [dpdk-dev] [PATCH v3] " Jiawei Wang
  2020-11-20 17:50     ` Ferruh Yigit
@ 2020-11-23  8:29     ` Jiawei Wang
  2020-11-23 11:00       ` [dpdk-dev] [PATCH v5] " Jiawei Wang
  1 sibling, 1 reply; 22+ messages in thread
From: Jiawei Wang @ 2020-11-23  8:29 UTC (permalink / raw)
  To: ferruh.yigit, wenzhuo.lu, beilei.xing, bernard.iremonger, orika,
	viacheslavo, thomas, rasland
  Cc: dev

When testpmd enabled the verbosity for the received packets, if two packets
were received at the same time, for example, sampling packet and normal
packet, the dump output of these packets may be overlapping due to multiple
core handling the multiple queues simultaneously.

The patch uses one string buffer that collects all the packet dump output
into this buffer and then printouts it at last, that guarantees to printout
separately the dump output per packet.

Fixes: d862c45 ("app/testpmd: move dumping packets to a separate function")

Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
Acked-by: Viacheslav Ovsiienko <viacheslavo@nvidia.com>
---
v4:
* Remove 'break' the loop if trancation and contiue to handle next packet.

v3:
* Use the marco instead of function calls to simplfy code.
* Use the shorter chars '...' append into the dump to notify the truncation.
* Update the commit message.
* Rebase.

v2:
* Print dump output of per packet instead of per burst.
* Add the checking for return value of 'snprintf' and exit if required size exceed the print buffer size.
* Update the log messages.
---
 app/test-pmd/util.c | 176 ++++++++++++++++++++++++++++++++++------------------
 1 file changed, 116 insertions(+), 60 deletions(-)

diff --git a/app/test-pmd/util.c b/app/test-pmd/util.c
index 649bf8f..fc7edf1 100644
--- a/app/test-pmd/util.c
+++ b/app/test-pmd/util.c
@@ -15,12 +15,23 @@
 
 #include "testpmd.h"
 
+#define MAX_STRING_LEN 8192
+
+#define MKDUMPSTR(buf, buf_size, cur_len, ...) \
+do { \
+	if (cur_len >= buf_size) \
+		break; \
+	cur_len += snprintf(buf + cur_len, buf_size - cur_len, __VA_ARGS__); \
+} while (0)
+
 static inline void
-print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr)
+print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr,
+		 char print_buf[], int buf_size, int *cur_len)
 {
 	char buf[RTE_ETHER_ADDR_FMT_SIZE];
+
 	rte_ether_format_addr(buf, RTE_ETHER_ADDR_FMT_SIZE, eth_addr);
-	printf("%s%s", what, buf);
+	MKDUMPSTR(print_buf, buf_size, *cur_len, "%s%s", what, buf);
 }
 
 static inline bool
@@ -74,13 +85,16 @@
 	uint32_t vx_vni;
 	const char *reason;
 	int dynf_index;
+	int buf_size = MAX_STRING_LEN;
+	char print_buf[buf_size];
+	int cur_len = 0;
 
+	memset(print_buf, 0, sizeof(print_buf));
 	if (!nb_pkts)
 		return;
-	printf("port %u/queue %u: %s %u packets\n",
-		port_id, queue,
-	       is_rx ? "received" : "sent",
-	       (unsigned int) nb_pkts);
+	MKDUMPSTR(print_buf, buf_size, cur_len,
+		  "port %u/queue %u: %s %u packets\n", port_id, queue,
+		  is_rx ? "received" : "sent", (unsigned int) nb_pkts);
 	for (i = 0; i < nb_pkts; i++) {
 		int ret;
 		struct rte_flow_error error;
@@ -93,95 +107,128 @@
 		is_encapsulation = RTE_ETH_IS_TUNNEL_PKT(packet_type);
 		ret = rte_flow_get_restore_info(port_id, mb, &info, &error);
 		if (!ret) {
-			printf("restore info:");
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  "restore info:");
 			if (info.flags & RTE_FLOW_RESTORE_INFO_TUNNEL) {
 				struct port_flow_tunnel *port_tunnel;
 
 				port_tunnel = port_flow_locate_tunnel
 					      (port_id, &info.tunnel);
-				printf(" - tunnel");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - tunnel");
 				if (port_tunnel)
-					printf(" #%u", port_tunnel->id);
+					MKDUMPSTR(print_buf, buf_size, cur_len,
+						  " #%u", port_tunnel->id);
 				else
-					printf(" %s", "-none-");
-				printf(" type %s",
-					port_flow_tunnel_type(&info.tunnel));
+					MKDUMPSTR(print_buf, buf_size, cur_len,
+						  " %s", "-none-");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " type %s", port_flow_tunnel_type
+					  (&info.tunnel));
 			} else {
-				printf(" - no tunnel info");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no tunnel info");
 			}
 			if (info.flags & RTE_FLOW_RESTORE_INFO_ENCAPSULATED)
-				printf(" - outer header present");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - outer header present");
 			else
-				printf(" - no outer header");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no outer header");
 			if (info.flags & RTE_FLOW_RESTORE_INFO_GROUP_ID)
-				printf(" - miss group %u", info.group_id);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - miss group %u", info.group_id);
 			else
-				printf(" - no miss group");
-			printf("\n");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no miss group");
+			MKDUMPSTR(print_buf, buf_size, cur_len, "\n");
 		}
-		print_ether_addr("  src=", &eth_hdr->s_addr);
-		print_ether_addr(" - dst=", &eth_hdr->d_addr);
-		printf(" - type=0x%04x - length=%u - nb_segs=%d",
-		       eth_type, (unsigned int) mb->pkt_len,
-		       (int)mb->nb_segs);
+		print_ether_addr("  src=", &eth_hdr->s_addr,
+				 print_buf, buf_size, &cur_len);
+		print_ether_addr(" - dst=", &eth_hdr->d_addr,
+				 print_buf, buf_size, &cur_len);
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  " - type=0x%04x - length=%u - nb_segs=%d",
+			  eth_type, (unsigned int) mb->pkt_len,
+			  (int)mb->nb_segs);
 		ol_flags = mb->ol_flags;
 		if (ol_flags & PKT_RX_RSS_HASH) {
-			printf(" - RSS hash=0x%x", (unsigned int) mb->hash.rss);
-			printf(" - RSS queue=0x%x", (unsigned int) queue);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - RSS hash=0x%x",
+				  (unsigned int) mb->hash.rss);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - RSS queue=0x%x", (unsigned int) queue);
 		}
 		if (ol_flags & PKT_RX_FDIR) {
-			printf(" - FDIR matched ");
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - FDIR matched ");
 			if (ol_flags & PKT_RX_FDIR_ID)
-				printf("ID=0x%x",
-				       mb->hash.fdir.hi);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "ID=0x%x", mb->hash.fdir.hi);
 			else if (ol_flags & PKT_RX_FDIR_FLX)
-				printf("flex bytes=0x%08x %08x",
-				       mb->hash.fdir.hi, mb->hash.fdir.lo);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "flex bytes=0x%08x %08x",
+					  mb->hash.fdir.hi, mb->hash.fdir.lo);
 			else
-				printf("hash=0x%x ID=0x%x ",
-				       mb->hash.fdir.hash, mb->hash.fdir.id);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "hash=0x%x ID=0x%x ",
+					  mb->hash.fdir.hash, mb->hash.fdir.id);
 		}
 		if (is_timestamp_enabled(mb))
-			printf(" - timestamp %"PRIu64" ", get_timestamp(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - timestamp %"PRIu64" ", get_timestamp(mb));
 		if (ol_flags & PKT_RX_QINQ)
-			printf(" - QinQ VLAN tci=0x%x, VLAN tci outer=0x%x",
-			       mb->vlan_tci, mb->vlan_tci_outer);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - QinQ VLAN tci=0x%x, VLAN tci outer=0x%x",
+				  mb->vlan_tci, mb->vlan_tci_outer);
 		else if (ol_flags & PKT_RX_VLAN)
-			printf(" - VLAN tci=0x%x", mb->vlan_tci);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - VLAN tci=0x%x", mb->vlan_tci);
 		if (!is_rx && (ol_flags & PKT_TX_DYNF_METADATA))
-			printf(" - Tx metadata: 0x%x",
-			       *RTE_FLOW_DYNF_METADATA(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - Tx metadata: 0x%x",
+				  *RTE_FLOW_DYNF_METADATA(mb));
 		if (is_rx && (ol_flags & PKT_RX_DYNF_METADATA))
-			printf(" - Rx metadata: 0x%x",
-			       *RTE_FLOW_DYNF_METADATA(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - Rx metadata: 0x%x",
+				  *RTE_FLOW_DYNF_METADATA(mb));
 		for (dynf_index = 0; dynf_index < 64; dynf_index++) {
 			if (dynf_names[dynf_index][0] != '\0')
-				printf(" - dynf %s: %d",
-				       dynf_names[dynf_index],
-				       !!(ol_flags & (1UL << dynf_index)));
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - dynf %s: %d",
+					  dynf_names[dynf_index],
+					  !!(ol_flags & (1UL << dynf_index)));
 		}
 		if (mb->packet_type) {
 			rte_get_ptype_name(mb->packet_type, buf, sizeof(buf));
-			printf(" - hw ptype: %s", buf);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - hw ptype: %s", buf);
 		}
 		sw_packet_type = rte_net_get_ptype(mb, &hdr_lens,
 					RTE_PTYPE_ALL_MASK);
 		rte_get_ptype_name(sw_packet_type, buf, sizeof(buf));
-		printf(" - sw ptype: %s", buf);
+		MKDUMPSTR(print_buf, buf_size, cur_len, " - sw ptype: %s", buf);
 		if (sw_packet_type & RTE_PTYPE_L2_MASK)
-			printf(" - l2_len=%d", hdr_lens.l2_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l2_len=%d",
+				  hdr_lens.l2_len);
 		if (sw_packet_type & RTE_PTYPE_L3_MASK)
-			printf(" - l3_len=%d", hdr_lens.l3_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l3_len=%d",
+				  hdr_lens.l3_len);
 		if (sw_packet_type & RTE_PTYPE_L4_MASK)
-			printf(" - l4_len=%d", hdr_lens.l4_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l4_len=%d",
+				  hdr_lens.l4_len);
 		if (sw_packet_type & RTE_PTYPE_TUNNEL_MASK)
-			printf(" - tunnel_len=%d", hdr_lens.tunnel_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - tunnel_len=%d", hdr_lens.tunnel_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L2_MASK)
-			printf(" - inner_l2_len=%d", hdr_lens.inner_l2_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l2_len=%d", hdr_lens.inner_l2_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L3_MASK)
-			printf(" - inner_l3_len=%d", hdr_lens.inner_l3_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l3_len=%d", hdr_lens.inner_l3_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L4_MASK)
-			printf(" - inner_l4_len=%d", hdr_lens.inner_l4_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l4_len=%d", hdr_lens.inner_l4_len);
 		if (is_encapsulation) {
 			struct rte_ipv4_hdr *ipv4_hdr;
 			struct rte_ipv6_hdr *ipv6_hdr;
@@ -218,18 +265,27 @@
 				l2_len + l3_len + l4_len);
 				udp_port = RTE_BE_TO_CPU_16(udp_hdr->dst_port);
 				vx_vni = rte_be_to_cpu_32(vxlan_hdr->vx_vni);
-				printf(" - VXLAN packet: packet type =%d, "
-				       "Destination UDP port =%d, VNI = %d",
-				       packet_type, udp_port, vx_vni >> 8);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - VXLAN packet: packet type =%d, "
+					  "Destination UDP port =%d, VNI = %d",
+					  packet_type, udp_port, vx_vni >> 8);
 			}
 		}
-		printf(" - %s queue=0x%x", is_rx ? "Receive" : "Send",
-			(unsigned int) queue);
-		printf("\n");
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  " - %s queue=0x%x", is_rx ? "Receive" : "Send",
+			  (unsigned int) queue);
+		MKDUMPSTR(print_buf, buf_size, cur_len, "\n");
 		rte_get_rx_ol_flag_list(mb->ol_flags, buf, sizeof(buf));
-		printf("  ol_flags: %s\n", buf);
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  "  ol_flags: %s\n", buf);
 		if (rte_mbuf_check(mb, 1, &reason) < 0)
-			printf("INVALID mbuf: %s\n", reason);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  "INVALID mbuf: %s\n", reason);
+		if (cur_len >= buf_size)
+			printf("%s ...\n", print_buf);
+		else
+			printf("%s", print_buf);
+		cur_len = 0;
 	}
 }
 
-- 
1.8.3.1


^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH v3] app/testpmd: fix testpmd packets dump overlapping
  2020-11-23  6:13       ` Jiawei(Jonny) Wang
@ 2020-11-23 10:22         ` Ferruh Yigit
  2020-11-23 11:03           ` Jiawei(Jonny) Wang
  0 siblings, 1 reply; 22+ messages in thread
From: Ferruh Yigit @ 2020-11-23 10:22 UTC (permalink / raw)
  To: Jiawei(Jonny) Wang, wenzhuo.lu, beilei.xing, bernard.iremonger,
	Ori Kam, Slava Ovsiienko, NBU-Contact-Thomas Monjalon,
	Raslan Darawsheh
  Cc: dev

On 11/23/2020 6:13 AM, Jiawei(Jonny) Wang wrote:
> Hi Ferruh,
> 
>> -----Original Message-----
>> From: Ferruh Yigit <ferruh.yigit@intel.com>
>> Sent: Saturday, November 21, 2020 1:50 AM
>> To: Jiawei(Jonny) Wang <jiaweiw@nvidia.com>; wenzhuo.lu@intel.com;
>> beilei.xing@intel.com; bernard.iremonger@intel.com; Ori Kam
>> <orika@nvidia.com>; Slava Ovsiienko <viacheslavo@nvidia.com>; NBU-
>> Contact-Thomas Monjalon <thomas@monjalon.net>; Raslan Darawsheh
>> <rasland@nvidia.com>
>> Cc: dev@dpdk.org
>> Subject: Re: [PATCH v3] app/testpmd: fix testpmd packets dump overlapping
>>
>> On 11/20/2020 5:35 PM, Jiawei Wang wrote:
>>> When testpmd enabled the verbosity for the received packets, if two
>>> packets were received at the same time, for example, sampling packet
>>> and normal packet, the dump output of these packets may be overlapping
>>> due to multiple core handling the multiple queues simultaneously.
>>>
>>> The patch uses one string buffer that collects all the packet dump
>>> output into this buffer and then printouts it at last, that guarantees
>>> to printout separately the dump output per packet.
>>>
>>> Fixes: d862c45 ("app/testpmd: move dumping packets to a separate
>>> function")
>>>
>>> Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
>>
>> <...>
>>
>>> @@ -74,13 +85,16 @@
>>>    	uint32_t vx_vni;
>>>    	const char *reason;
>>>    	int dynf_index;
>>> +	int buf_size = MAX_STRING_LEN;
>>> +	char print_buf[buf_size];
>>> +	int cur_len = 0;
>>>
>>> +	memset(print_buf, 0, sizeof(print_buf));
>>
>> Should 'print_buf' cleaned per each packet below, if not can we drop 'memset'
>> completely?
>>
> Since the 'snprintf' always append the a terminating null character('\0') after the written string,
> and in the code the following character be appended start from previous null character, so only one
> '\0' will be appended in the last 'snprintf' calls,
> 	snprintf(buf + cur_len, buf_size - cur_len ..
> At the last 'printf("%s") will print the string buffer up to a terminating null character ('\0').
> so it's ok even not 'memset' calls to clean 'print_buf' per each packets.

agree, so why not drop the memset completely?

^ permalink raw reply	[flat|nested] 22+ messages in thread

* [dpdk-dev] [PATCH v5] app/testpmd: fix testpmd packets dump overlapping
  2020-11-23  8:29     ` [dpdk-dev] [PATCH v4] " Jiawei Wang
@ 2020-11-23 11:00       ` Jiawei Wang
  2020-11-23 14:20         ` Ferruh Yigit
  2021-01-06 14:13         ` [dpdk-dev] [PATCH v6] " Jiawei Wang
  0 siblings, 2 replies; 22+ messages in thread
From: Jiawei Wang @ 2020-11-23 11:00 UTC (permalink / raw)
  To: ferruh.yigit, wenzhuo.lu, beilei.xing, bernard.iremonger, orika,
	viacheslavo, thomas, rasland
  Cc: dev

When testpmd enabled the verbosity for the received packets, if two packets
were received at the same time, for example, sampling packet and normal
packet, the dump output of these packets may be overlapping due to multiple
core handling the multiple queues simultaneously.

The patch uses one string buffer that collects all the packet dump output
into this buffer and then printouts it at last, that guarantees to printout
separately the dump output per packet.

Fixes: d862c45 ("app/testpmd: move dumping packets to a separate function")

Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
Acked-by: Viacheslav Ovsiienko <viacheslavo@nvidia.com>
---
v5:
* Remove memset function calls before snprintf calls.

v4:
* Remove 'break' the loop if trancation and contiue to handle next packet.

v3:
* Use the marco instead of function calls to simplfy code.
* Use the shorter chars '...' append into the dump to notify the truncation.
* Update the commit message.
* Rebase.

v2:
* Print dump output of per packet instead of per burst.
* Add the checking for return value of 'snprintf' and exit if required size exceed the print buffer size.
* Update the log messages.
---
 app/test-pmd/util.c | 175 ++++++++++++++++++++++++++++++++++------------------
 1 file changed, 115 insertions(+), 60 deletions(-)

diff --git a/app/test-pmd/util.c b/app/test-pmd/util.c
index 649bf8f..a48c5ff 100644
--- a/app/test-pmd/util.c
+++ b/app/test-pmd/util.c
@@ -15,12 +15,23 @@
 
 #include "testpmd.h"
 
+#define MAX_STRING_LEN 8192
+
+#define MKDUMPSTR(buf, buf_size, cur_len, ...) \
+do { \
+	if (cur_len >= buf_size) \
+		break; \
+	cur_len += snprintf(buf + cur_len, buf_size - cur_len, __VA_ARGS__); \
+} while (0)
+
 static inline void
-print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr)
+print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr,
+		 char print_buf[], int buf_size, int *cur_len)
 {
 	char buf[RTE_ETHER_ADDR_FMT_SIZE];
+
 	rte_ether_format_addr(buf, RTE_ETHER_ADDR_FMT_SIZE, eth_addr);
-	printf("%s%s", what, buf);
+	MKDUMPSTR(print_buf, buf_size, *cur_len, "%s%s", what, buf);
 }
 
 static inline bool
@@ -74,13 +85,15 @@
 	uint32_t vx_vni;
 	const char *reason;
 	int dynf_index;
+	int buf_size = MAX_STRING_LEN;
+	char print_buf[buf_size];
+	int cur_len = 0;
 
 	if (!nb_pkts)
 		return;
-	printf("port %u/queue %u: %s %u packets\n",
-		port_id, queue,
-	       is_rx ? "received" : "sent",
-	       (unsigned int) nb_pkts);
+	MKDUMPSTR(print_buf, buf_size, cur_len,
+		  "port %u/queue %u: %s %u packets\n", port_id, queue,
+		  is_rx ? "received" : "sent", (unsigned int) nb_pkts);
 	for (i = 0; i < nb_pkts; i++) {
 		int ret;
 		struct rte_flow_error error;
@@ -93,95 +106,128 @@
 		is_encapsulation = RTE_ETH_IS_TUNNEL_PKT(packet_type);
 		ret = rte_flow_get_restore_info(port_id, mb, &info, &error);
 		if (!ret) {
-			printf("restore info:");
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  "restore info:");
 			if (info.flags & RTE_FLOW_RESTORE_INFO_TUNNEL) {
 				struct port_flow_tunnel *port_tunnel;
 
 				port_tunnel = port_flow_locate_tunnel
 					      (port_id, &info.tunnel);
-				printf(" - tunnel");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - tunnel");
 				if (port_tunnel)
-					printf(" #%u", port_tunnel->id);
+					MKDUMPSTR(print_buf, buf_size, cur_len,
+						  " #%u", port_tunnel->id);
 				else
-					printf(" %s", "-none-");
-				printf(" type %s",
-					port_flow_tunnel_type(&info.tunnel));
+					MKDUMPSTR(print_buf, buf_size, cur_len,
+						  " %s", "-none-");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " type %s", port_flow_tunnel_type
+					  (&info.tunnel));
 			} else {
-				printf(" - no tunnel info");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no tunnel info");
 			}
 			if (info.flags & RTE_FLOW_RESTORE_INFO_ENCAPSULATED)
-				printf(" - outer header present");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - outer header present");
 			else
-				printf(" - no outer header");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no outer header");
 			if (info.flags & RTE_FLOW_RESTORE_INFO_GROUP_ID)
-				printf(" - miss group %u", info.group_id);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - miss group %u", info.group_id);
 			else
-				printf(" - no miss group");
-			printf("\n");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no miss group");
+			MKDUMPSTR(print_buf, buf_size, cur_len, "\n");
 		}
-		print_ether_addr("  src=", &eth_hdr->s_addr);
-		print_ether_addr(" - dst=", &eth_hdr->d_addr);
-		printf(" - type=0x%04x - length=%u - nb_segs=%d",
-		       eth_type, (unsigned int) mb->pkt_len,
-		       (int)mb->nb_segs);
+		print_ether_addr("  src=", &eth_hdr->s_addr,
+				 print_buf, buf_size, &cur_len);
+		print_ether_addr(" - dst=", &eth_hdr->d_addr,
+				 print_buf, buf_size, &cur_len);
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  " - type=0x%04x - length=%u - nb_segs=%d",
+			  eth_type, (unsigned int) mb->pkt_len,
+			  (int)mb->nb_segs);
 		ol_flags = mb->ol_flags;
 		if (ol_flags & PKT_RX_RSS_HASH) {
-			printf(" - RSS hash=0x%x", (unsigned int) mb->hash.rss);
-			printf(" - RSS queue=0x%x", (unsigned int) queue);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - RSS hash=0x%x",
+				  (unsigned int) mb->hash.rss);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - RSS queue=0x%x", (unsigned int) queue);
 		}
 		if (ol_flags & PKT_RX_FDIR) {
-			printf(" - FDIR matched ");
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - FDIR matched ");
 			if (ol_flags & PKT_RX_FDIR_ID)
-				printf("ID=0x%x",
-				       mb->hash.fdir.hi);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "ID=0x%x", mb->hash.fdir.hi);
 			else if (ol_flags & PKT_RX_FDIR_FLX)
-				printf("flex bytes=0x%08x %08x",
-				       mb->hash.fdir.hi, mb->hash.fdir.lo);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "flex bytes=0x%08x %08x",
+					  mb->hash.fdir.hi, mb->hash.fdir.lo);
 			else
-				printf("hash=0x%x ID=0x%x ",
-				       mb->hash.fdir.hash, mb->hash.fdir.id);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "hash=0x%x ID=0x%x ",
+					  mb->hash.fdir.hash, mb->hash.fdir.id);
 		}
 		if (is_timestamp_enabled(mb))
-			printf(" - timestamp %"PRIu64" ", get_timestamp(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - timestamp %"PRIu64" ", get_timestamp(mb));
 		if (ol_flags & PKT_RX_QINQ)
-			printf(" - QinQ VLAN tci=0x%x, VLAN tci outer=0x%x",
-			       mb->vlan_tci, mb->vlan_tci_outer);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - QinQ VLAN tci=0x%x, VLAN tci outer=0x%x",
+				  mb->vlan_tci, mb->vlan_tci_outer);
 		else if (ol_flags & PKT_RX_VLAN)
-			printf(" - VLAN tci=0x%x", mb->vlan_tci);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - VLAN tci=0x%x", mb->vlan_tci);
 		if (!is_rx && (ol_flags & PKT_TX_DYNF_METADATA))
-			printf(" - Tx metadata: 0x%x",
-			       *RTE_FLOW_DYNF_METADATA(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - Tx metadata: 0x%x",
+				  *RTE_FLOW_DYNF_METADATA(mb));
 		if (is_rx && (ol_flags & PKT_RX_DYNF_METADATA))
-			printf(" - Rx metadata: 0x%x",
-			       *RTE_FLOW_DYNF_METADATA(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - Rx metadata: 0x%x",
+				  *RTE_FLOW_DYNF_METADATA(mb));
 		for (dynf_index = 0; dynf_index < 64; dynf_index++) {
 			if (dynf_names[dynf_index][0] != '\0')
-				printf(" - dynf %s: %d",
-				       dynf_names[dynf_index],
-				       !!(ol_flags & (1UL << dynf_index)));
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - dynf %s: %d",
+					  dynf_names[dynf_index],
+					  !!(ol_flags & (1UL << dynf_index)));
 		}
 		if (mb->packet_type) {
 			rte_get_ptype_name(mb->packet_type, buf, sizeof(buf));
-			printf(" - hw ptype: %s", buf);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - hw ptype: %s", buf);
 		}
 		sw_packet_type = rte_net_get_ptype(mb, &hdr_lens,
 					RTE_PTYPE_ALL_MASK);
 		rte_get_ptype_name(sw_packet_type, buf, sizeof(buf));
-		printf(" - sw ptype: %s", buf);
+		MKDUMPSTR(print_buf, buf_size, cur_len, " - sw ptype: %s", buf);
 		if (sw_packet_type & RTE_PTYPE_L2_MASK)
-			printf(" - l2_len=%d", hdr_lens.l2_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l2_len=%d",
+				  hdr_lens.l2_len);
 		if (sw_packet_type & RTE_PTYPE_L3_MASK)
-			printf(" - l3_len=%d", hdr_lens.l3_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l3_len=%d",
+				  hdr_lens.l3_len);
 		if (sw_packet_type & RTE_PTYPE_L4_MASK)
-			printf(" - l4_len=%d", hdr_lens.l4_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l4_len=%d",
+				  hdr_lens.l4_len);
 		if (sw_packet_type & RTE_PTYPE_TUNNEL_MASK)
-			printf(" - tunnel_len=%d", hdr_lens.tunnel_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - tunnel_len=%d", hdr_lens.tunnel_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L2_MASK)
-			printf(" - inner_l2_len=%d", hdr_lens.inner_l2_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l2_len=%d", hdr_lens.inner_l2_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L3_MASK)
-			printf(" - inner_l3_len=%d", hdr_lens.inner_l3_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l3_len=%d", hdr_lens.inner_l3_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L4_MASK)
-			printf(" - inner_l4_len=%d", hdr_lens.inner_l4_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l4_len=%d", hdr_lens.inner_l4_len);
 		if (is_encapsulation) {
 			struct rte_ipv4_hdr *ipv4_hdr;
 			struct rte_ipv6_hdr *ipv6_hdr;
@@ -218,18 +264,27 @@
 				l2_len + l3_len + l4_len);
 				udp_port = RTE_BE_TO_CPU_16(udp_hdr->dst_port);
 				vx_vni = rte_be_to_cpu_32(vxlan_hdr->vx_vni);
-				printf(" - VXLAN packet: packet type =%d, "
-				       "Destination UDP port =%d, VNI = %d",
-				       packet_type, udp_port, vx_vni >> 8);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - VXLAN packet: packet type =%d, "
+					  "Destination UDP port =%d, VNI = %d",
+					  packet_type, udp_port, vx_vni >> 8);
 			}
 		}
-		printf(" - %s queue=0x%x", is_rx ? "Receive" : "Send",
-			(unsigned int) queue);
-		printf("\n");
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  " - %s queue=0x%x", is_rx ? "Receive" : "Send",
+			  (unsigned int) queue);
+		MKDUMPSTR(print_buf, buf_size, cur_len, "\n");
 		rte_get_rx_ol_flag_list(mb->ol_flags, buf, sizeof(buf));
-		printf("  ol_flags: %s\n", buf);
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  "  ol_flags: %s\n", buf);
 		if (rte_mbuf_check(mb, 1, &reason) < 0)
-			printf("INVALID mbuf: %s\n", reason);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  "INVALID mbuf: %s\n", reason);
+		if (cur_len >= buf_size)
+			printf("%s ...\n", print_buf);
+		else
+			printf("%s", print_buf);
+		cur_len = 0;
 	}
 }
 
-- 
1.8.3.1


^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH v3] app/testpmd: fix testpmd packets dump overlapping
  2020-11-23 10:22         ` Ferruh Yigit
@ 2020-11-23 11:03           ` Jiawei(Jonny) Wang
  0 siblings, 0 replies; 22+ messages in thread
From: Jiawei(Jonny) Wang @ 2020-11-23 11:03 UTC (permalink / raw)
  To: Ferruh Yigit, wenzhuo.lu, beilei.xing, bernard.iremonger,
	Ori Kam, Slava Ovsiienko, NBU-Contact-Thomas Monjalon,
	Raslan Darawsheh
  Cc: dev

Hi Ferruh,

> -----Original Message-----
> From: Ferruh Yigit <ferruh.yigit@intel.com>
> Sent: Monday, November 23, 2020 6:23 PM
> To: Jiawei(Jonny) Wang <jiaweiw@nvidia.com>; wenzhuo.lu@intel.com;
> beilei.xing@intel.com; bernard.iremonger@intel.com; Ori Kam
> <orika@nvidia.com>; Slava Ovsiienko <viacheslavo@nvidia.com>; NBU-
> Contact-Thomas Monjalon <thomas@monjalon.net>; Raslan Darawsheh
> <rasland@nvidia.com>
> Cc: dev@dpdk.org
> Subject: Re: [PATCH v3] app/testpmd: fix testpmd packets dump overlapping
> 
> On 11/23/2020 6:13 AM, Jiawei(Jonny) Wang wrote:
> > Hi Ferruh,
> >
> >> -----Original Message-----
> >> From: Ferruh Yigit <ferruh.yigit@intel.com>
> >> Sent: Saturday, November 21, 2020 1:50 AM
> >> To: Jiawei(Jonny) Wang <jiaweiw@nvidia.com>; wenzhuo.lu@intel.com;
> >> beilei.xing@intel.com; bernard.iremonger@intel.com; Ori Kam
> >> <orika@nvidia.com>; Slava Ovsiienko <viacheslavo@nvidia.com>; NBU-
> >> Contact-Thomas Monjalon <thomas@monjalon.net>; Raslan Darawsheh
> >> <rasland@nvidia.com>
> >> Cc: dev@dpdk.org
> >> Subject: Re: [PATCH v3] app/testpmd: fix testpmd packets dump
> >> overlapping
> >>
> >> On 11/20/2020 5:35 PM, Jiawei Wang wrote:
> >>> When testpmd enabled the verbosity for the received packets, if two
> >>> packets were received at the same time, for example, sampling packet
> >>> and normal packet, the dump output of these packets may be
> >>> overlapping due to multiple core handling the multiple queues
> simultaneously.
> >>>
> >>> The patch uses one string buffer that collects all the packet dump
> >>> output into this buffer and then printouts it at last, that
> >>> guarantees to printout separately the dump output per packet.
> >>>
> >>> Fixes: d862c45 ("app/testpmd: move dumping packets to a separate
> >>> function")
> >>>
> >>> Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
> >>
> >> <...>
> >>
> >>> @@ -74,13 +85,16 @@
> >>>    	uint32_t vx_vni;
> >>>    	const char *reason;
> >>>    	int dynf_index;
> >>> +	int buf_size = MAX_STRING_LEN;
> >>> +	char print_buf[buf_size];
> >>> +	int cur_len = 0;
> >>>
> >>> +	memset(print_buf, 0, sizeof(print_buf));
> >>
> >> Should 'print_buf' cleaned per each packet below, if not can we drop
> 'memset'
> >> completely?
> >>
> > Since the 'snprintf' always append the a terminating null
> > character('\0') after the written string, and in the code the
> > following character be appended start from previous null character, so only
> one '\0' will be appended in the last 'snprintf' calls,
> > 	snprintf(buf + cur_len, buf_size - cur_len ..
> > At the last 'printf("%s") will print the string buffer up to a terminating null
> character ('\0').
> > so it's ok even not 'memset' calls to clean 'print_buf' per each packets.
> 
> agree, so why not drop the memset completely?
Yes, don't need memset before 'snprintf' calls, removed it in the latest patch: https://patchwork.dpdk.org/patch/84465/
Thanks.


^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH v5] app/testpmd: fix testpmd packets dump overlapping
  2020-11-23 11:00       ` [dpdk-dev] [PATCH v5] " Jiawei Wang
@ 2020-11-23 14:20         ` Ferruh Yigit
  2021-01-06 14:13         ` [dpdk-dev] [PATCH v6] " Jiawei Wang
  1 sibling, 0 replies; 22+ messages in thread
From: Ferruh Yigit @ 2020-11-23 14:20 UTC (permalink / raw)
  To: Jiawei Wang, wenzhuo.lu, beilei.xing, bernard.iremonger, orika,
	viacheslavo, thomas, rasland, Andrew Rybchenko
  Cc: dev

On 11/23/2020 11:00 AM, Jiawei Wang wrote:
> When testpmd enabled the verbosity for the received packets, if two packets
> were received at the same time, for example, sampling packet and normal
> packet, the dump output of these packets may be overlapping due to multiple
> core handling the multiple queues simultaneously.
> 
> The patch uses one string buffer that collects all the packet dump output
> into this buffer and then printouts it at last, that guarantees to printout
> separately the dump output per packet.
> 
> Fixes: d862c45 ("app/testpmd: move dumping packets to a separate function")
> 
> Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
> Acked-by: Viacheslav Ovsiienko <viacheslavo@nvidia.com>

Reviewed-by: Ferruh Yigit <ferruh.yigit@intel.com>

Although this looks safe, this is also not so critical, not sure to get for this 
release or not.

^ permalink raw reply	[flat|nested] 22+ messages in thread

* [dpdk-dev] [PATCH v6] app/testpmd: fix testpmd packets dump overlapping
  2020-11-23 11:00       ` [dpdk-dev] [PATCH v5] " Jiawei Wang
  2020-11-23 14:20         ` Ferruh Yigit
@ 2021-01-06 14:13         ` Jiawei Wang
  2021-01-06 15:54           ` Stephen Hemminger
                             ` (2 more replies)
  1 sibling, 3 replies; 22+ messages in thread
From: Jiawei Wang @ 2021-01-06 14:13 UTC (permalink / raw)
  To: ferruh.yigit, wenzhuo.lu, beilei.xing, bernard.iremonger, orika,
	viacheslavo, thomas, rasland
  Cc: dev

When testpmd enabled the verbosity for the received packets, if two packets
were received at the same time, for example, sampling packet and normal
packet, the dump output of these packets may be overlapping due to multiple
core handling the multiple queues simultaneously.

The patch uses one string buffer that collects all the packet dump output
into this buffer and then printouts it at last, that guarantees to printout
separately the dump output per packet.

Fixes: d862c45 ("app/testpmd: move dumping packets to a separate function")

Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
Acked-by: Viacheslav Ovsiienko <viacheslavo@nvidia.com>
Reviewed-by: Ferruh Yigit <ferruh.yigit@intel.com>
---
v6:
* Rebase the latest code.

v5:
* Remove memset function calls before snprintf calls.

v4:
* Remove 'break' the loop if trancation and contiue to handle next packet.

v3:
* Use the marco instead of function calls to simplfy code.
* Use the shorter chars '...' append into the dump to notify the truncation.
* Update the commit message.
* Rebase.

v2:
* Print dump output of per packet instead of per burst.
* Add the checking for return value of 'snprintf' and exit if required size exceed the print buffer size.
* Update the log messages.
---
 app/test-pmd/util.c | 175 ++++++++++++++++++++++++++++++++++------------------
 1 file changed, 115 insertions(+), 60 deletions(-)

diff --git a/app/test-pmd/util.c b/app/test-pmd/util.c
index 649bf8f..a48c5ff 100644
--- a/app/test-pmd/util.c
+++ b/app/test-pmd/util.c
@@ -15,12 +15,23 @@
 
 #include "testpmd.h"
 
+#define MAX_STRING_LEN 8192
+
+#define MKDUMPSTR(buf, buf_size, cur_len, ...) \
+do { \
+	if (cur_len >= buf_size) \
+		break; \
+	cur_len += snprintf(buf + cur_len, buf_size - cur_len, __VA_ARGS__); \
+} while (0)
+
 static inline void
-print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr)
+print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr,
+		 char print_buf[], int buf_size, int *cur_len)
 {
 	char buf[RTE_ETHER_ADDR_FMT_SIZE];
+
 	rte_ether_format_addr(buf, RTE_ETHER_ADDR_FMT_SIZE, eth_addr);
-	printf("%s%s", what, buf);
+	MKDUMPSTR(print_buf, buf_size, *cur_len, "%s%s", what, buf);
 }
 
 static inline bool
@@ -74,13 +85,15 @@
 	uint32_t vx_vni;
 	const char *reason;
 	int dynf_index;
+	int buf_size = MAX_STRING_LEN;
+	char print_buf[buf_size];
+	int cur_len = 0;
 
 	if (!nb_pkts)
 		return;
-	printf("port %u/queue %u: %s %u packets\n",
-		port_id, queue,
-	       is_rx ? "received" : "sent",
-	       (unsigned int) nb_pkts);
+	MKDUMPSTR(print_buf, buf_size, cur_len,
+		  "port %u/queue %u: %s %u packets\n", port_id, queue,
+		  is_rx ? "received" : "sent", (unsigned int) nb_pkts);
 	for (i = 0; i < nb_pkts; i++) {
 		int ret;
 		struct rte_flow_error error;
@@ -93,95 +106,128 @@
 		is_encapsulation = RTE_ETH_IS_TUNNEL_PKT(packet_type);
 		ret = rte_flow_get_restore_info(port_id, mb, &info, &error);
 		if (!ret) {
-			printf("restore info:");
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  "restore info:");
 			if (info.flags & RTE_FLOW_RESTORE_INFO_TUNNEL) {
 				struct port_flow_tunnel *port_tunnel;
 
 				port_tunnel = port_flow_locate_tunnel
 					      (port_id, &info.tunnel);
-				printf(" - tunnel");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - tunnel");
 				if (port_tunnel)
-					printf(" #%u", port_tunnel->id);
+					MKDUMPSTR(print_buf, buf_size, cur_len,
+						  " #%u", port_tunnel->id);
 				else
-					printf(" %s", "-none-");
-				printf(" type %s",
-					port_flow_tunnel_type(&info.tunnel));
+					MKDUMPSTR(print_buf, buf_size, cur_len,
+						  " %s", "-none-");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " type %s", port_flow_tunnel_type
+					  (&info.tunnel));
 			} else {
-				printf(" - no tunnel info");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no tunnel info");
 			}
 			if (info.flags & RTE_FLOW_RESTORE_INFO_ENCAPSULATED)
-				printf(" - outer header present");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - outer header present");
 			else
-				printf(" - no outer header");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no outer header");
 			if (info.flags & RTE_FLOW_RESTORE_INFO_GROUP_ID)
-				printf(" - miss group %u", info.group_id);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - miss group %u", info.group_id);
 			else
-				printf(" - no miss group");
-			printf("\n");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no miss group");
+			MKDUMPSTR(print_buf, buf_size, cur_len, "\n");
 		}
-		print_ether_addr("  src=", &eth_hdr->s_addr);
-		print_ether_addr(" - dst=", &eth_hdr->d_addr);
-		printf(" - type=0x%04x - length=%u - nb_segs=%d",
-		       eth_type, (unsigned int) mb->pkt_len,
-		       (int)mb->nb_segs);
+		print_ether_addr("  src=", &eth_hdr->s_addr,
+				 print_buf, buf_size, &cur_len);
+		print_ether_addr(" - dst=", &eth_hdr->d_addr,
+				 print_buf, buf_size, &cur_len);
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  " - type=0x%04x - length=%u - nb_segs=%d",
+			  eth_type, (unsigned int) mb->pkt_len,
+			  (int)mb->nb_segs);
 		ol_flags = mb->ol_flags;
 		if (ol_flags & PKT_RX_RSS_HASH) {
-			printf(" - RSS hash=0x%x", (unsigned int) mb->hash.rss);
-			printf(" - RSS queue=0x%x", (unsigned int) queue);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - RSS hash=0x%x",
+				  (unsigned int) mb->hash.rss);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - RSS queue=0x%x", (unsigned int) queue);
 		}
 		if (ol_flags & PKT_RX_FDIR) {
-			printf(" - FDIR matched ");
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - FDIR matched ");
 			if (ol_flags & PKT_RX_FDIR_ID)
-				printf("ID=0x%x",
-				       mb->hash.fdir.hi);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "ID=0x%x", mb->hash.fdir.hi);
 			else if (ol_flags & PKT_RX_FDIR_FLX)
-				printf("flex bytes=0x%08x %08x",
-				       mb->hash.fdir.hi, mb->hash.fdir.lo);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "flex bytes=0x%08x %08x",
+					  mb->hash.fdir.hi, mb->hash.fdir.lo);
 			else
-				printf("hash=0x%x ID=0x%x ",
-				       mb->hash.fdir.hash, mb->hash.fdir.id);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "hash=0x%x ID=0x%x ",
+					  mb->hash.fdir.hash, mb->hash.fdir.id);
 		}
 		if (is_timestamp_enabled(mb))
-			printf(" - timestamp %"PRIu64" ", get_timestamp(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - timestamp %"PRIu64" ", get_timestamp(mb));
 		if (ol_flags & PKT_RX_QINQ)
-			printf(" - QinQ VLAN tci=0x%x, VLAN tci outer=0x%x",
-			       mb->vlan_tci, mb->vlan_tci_outer);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - QinQ VLAN tci=0x%x, VLAN tci outer=0x%x",
+				  mb->vlan_tci, mb->vlan_tci_outer);
 		else if (ol_flags & PKT_RX_VLAN)
-			printf(" - VLAN tci=0x%x", mb->vlan_tci);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - VLAN tci=0x%x", mb->vlan_tci);
 		if (!is_rx && (ol_flags & PKT_TX_DYNF_METADATA))
-			printf(" - Tx metadata: 0x%x",
-			       *RTE_FLOW_DYNF_METADATA(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - Tx metadata: 0x%x",
+				  *RTE_FLOW_DYNF_METADATA(mb));
 		if (is_rx && (ol_flags & PKT_RX_DYNF_METADATA))
-			printf(" - Rx metadata: 0x%x",
-			       *RTE_FLOW_DYNF_METADATA(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - Rx metadata: 0x%x",
+				  *RTE_FLOW_DYNF_METADATA(mb));
 		for (dynf_index = 0; dynf_index < 64; dynf_index++) {
 			if (dynf_names[dynf_index][0] != '\0')
-				printf(" - dynf %s: %d",
-				       dynf_names[dynf_index],
-				       !!(ol_flags & (1UL << dynf_index)));
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - dynf %s: %d",
+					  dynf_names[dynf_index],
+					  !!(ol_flags & (1UL << dynf_index)));
 		}
 		if (mb->packet_type) {
 			rte_get_ptype_name(mb->packet_type, buf, sizeof(buf));
-			printf(" - hw ptype: %s", buf);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - hw ptype: %s", buf);
 		}
 		sw_packet_type = rte_net_get_ptype(mb, &hdr_lens,
 					RTE_PTYPE_ALL_MASK);
 		rte_get_ptype_name(sw_packet_type, buf, sizeof(buf));
-		printf(" - sw ptype: %s", buf);
+		MKDUMPSTR(print_buf, buf_size, cur_len, " - sw ptype: %s", buf);
 		if (sw_packet_type & RTE_PTYPE_L2_MASK)
-			printf(" - l2_len=%d", hdr_lens.l2_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l2_len=%d",
+				  hdr_lens.l2_len);
 		if (sw_packet_type & RTE_PTYPE_L3_MASK)
-			printf(" - l3_len=%d", hdr_lens.l3_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l3_len=%d",
+				  hdr_lens.l3_len);
 		if (sw_packet_type & RTE_PTYPE_L4_MASK)
-			printf(" - l4_len=%d", hdr_lens.l4_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l4_len=%d",
+				  hdr_lens.l4_len);
 		if (sw_packet_type & RTE_PTYPE_TUNNEL_MASK)
-			printf(" - tunnel_len=%d", hdr_lens.tunnel_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - tunnel_len=%d", hdr_lens.tunnel_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L2_MASK)
-			printf(" - inner_l2_len=%d", hdr_lens.inner_l2_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l2_len=%d", hdr_lens.inner_l2_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L3_MASK)
-			printf(" - inner_l3_len=%d", hdr_lens.inner_l3_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l3_len=%d", hdr_lens.inner_l3_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L4_MASK)
-			printf(" - inner_l4_len=%d", hdr_lens.inner_l4_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l4_len=%d", hdr_lens.inner_l4_len);
 		if (is_encapsulation) {
 			struct rte_ipv4_hdr *ipv4_hdr;
 			struct rte_ipv6_hdr *ipv6_hdr;
@@ -218,18 +264,27 @@
 				l2_len + l3_len + l4_len);
 				udp_port = RTE_BE_TO_CPU_16(udp_hdr->dst_port);
 				vx_vni = rte_be_to_cpu_32(vxlan_hdr->vx_vni);
-				printf(" - VXLAN packet: packet type =%d, "
-				       "Destination UDP port =%d, VNI = %d",
-				       packet_type, udp_port, vx_vni >> 8);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - VXLAN packet: packet type =%d, "
+					  "Destination UDP port =%d, VNI = %d",
+					  packet_type, udp_port, vx_vni >> 8);
 			}
 		}
-		printf(" - %s queue=0x%x", is_rx ? "Receive" : "Send",
-			(unsigned int) queue);
-		printf("\n");
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  " - %s queue=0x%x", is_rx ? "Receive" : "Send",
+			  (unsigned int) queue);
+		MKDUMPSTR(print_buf, buf_size, cur_len, "\n");
 		rte_get_rx_ol_flag_list(mb->ol_flags, buf, sizeof(buf));
-		printf("  ol_flags: %s\n", buf);
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  "  ol_flags: %s\n", buf);
 		if (rte_mbuf_check(mb, 1, &reason) < 0)
-			printf("INVALID mbuf: %s\n", reason);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  "INVALID mbuf: %s\n", reason);
+		if (cur_len >= buf_size)
+			printf("%s ...\n", print_buf);
+		else
+			printf("%s", print_buf);
+		cur_len = 0;
 	}
 }
 
-- 
1.8.3.1


^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH v6] app/testpmd: fix testpmd packets dump overlapping
  2021-01-06 14:13         ` [dpdk-dev] [PATCH v6] " Jiawei Wang
@ 2021-01-06 15:54           ` Stephen Hemminger
  2021-01-08  8:31             ` Jiawei(Jonny) Wang
  2021-01-06 15:55           ` Stephen Hemminger
  2021-01-20  6:50           ` [dpdk-dev] [PATCH v7] " Jiawei Wang
  2 siblings, 1 reply; 22+ messages in thread
From: Stephen Hemminger @ 2021-01-06 15:54 UTC (permalink / raw)
  To: Jiawei Wang
  Cc: ferruh.yigit, wenzhuo.lu, beilei.xing, bernard.iremonger, orika,
	viacheslavo, thomas, rasland, dev

On Wed,  6 Jan 2021 16:13:37 +0200
Jiawei Wang <jiaweiw@nvidia.com> wrote:

> +print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr,
> +		 char print_buf[], int buf_size, int *cur_len)

Use size_t instead of int for sizes?
The length can never be negative?

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH v6] app/testpmd: fix testpmd packets dump overlapping
  2021-01-06 14:13         ` [dpdk-dev] [PATCH v6] " Jiawei Wang
  2021-01-06 15:54           ` Stephen Hemminger
@ 2021-01-06 15:55           ` Stephen Hemminger
  2021-01-08  8:31             ` Jiawei(Jonny) Wang
  2021-01-20  6:50           ` [dpdk-dev] [PATCH v7] " Jiawei Wang
  2 siblings, 1 reply; 22+ messages in thread
From: Stephen Hemminger @ 2021-01-06 15:55 UTC (permalink / raw)
  To: Jiawei Wang
  Cc: ferruh.yigit, wenzhuo.lu, beilei.xing, bernard.iremonger, orika,
	viacheslavo, thomas, rasland, dev

On Wed,  6 Jan 2021 16:13:37 +0200
Jiawei Wang <jiaweiw@nvidia.com> wrote:

> +	int buf_size = MAX_STRING_LEN;
> +	char print_buf[buf_size];

Don't use dynamic sized array if you don't have to.
Various static checkers can see look for out of bounds access to
fixed size array.

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH v6] app/testpmd: fix testpmd packets dump overlapping
  2021-01-06 15:54           ` Stephen Hemminger
@ 2021-01-08  8:31             ` Jiawei(Jonny) Wang
  0 siblings, 0 replies; 22+ messages in thread
From: Jiawei(Jonny) Wang @ 2021-01-08  8:31 UTC (permalink / raw)
  To: Stephen Hemminger
  Cc: ferruh.yigit, wenzhuo.lu, beilei.xing, bernard.iremonger,
	Ori Kam, Slava Ovsiienko, NBU-Contact-Thomas Monjalon,
	Raslan Darawsheh, dev



> -----Original Message-----
> From: Stephen Hemminger <stephen@networkplumber.org>
> Sent: Wednesday, January 6, 2021 11:55 PM
> To: Jiawei(Jonny) Wang <jiaweiw@nvidia.com>
> Cc: ferruh.yigit@intel.com; wenzhuo.lu@intel.com; beilei.xing@intel.com;
> bernard.iremonger@intel.com; Ori Kam <orika@nvidia.com>; Slava
> Ovsiienko <viacheslavo@nvidia.com>; NBU-Contact-Thomas Monjalon
> <thomas@monjalon.net>; Raslan Darawsheh <rasland@nvidia.com>;
> dev@dpdk.org
> Subject: Re: [dpdk-dev] [PATCH v6] app/testpmd: fix testpmd packets dump
> overlapping
> 
> On Wed,  6 Jan 2021 16:13:37 +0200
> Jiawei Wang <jiaweiw@nvidia.com> wrote:
> 
> > +print_ether_addr(const char *what, const struct rte_ether_addr
> *eth_addr,
> > +		 char print_buf[], int buf_size, int *cur_len)
> 
> Use size_t instead of int for sizes?
> The length can never be negative?

The buf_size and cur_len always >0, buf_size means that the total size of string buffer, default is 8K,
the cur_len means that the current location of putting the new dump output, start from 0.

Thanks. 

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH v6] app/testpmd: fix testpmd packets dump overlapping
  2021-01-06 15:55           ` Stephen Hemminger
@ 2021-01-08  8:31             ` Jiawei(Jonny) Wang
  0 siblings, 0 replies; 22+ messages in thread
From: Jiawei(Jonny) Wang @ 2021-01-08  8:31 UTC (permalink / raw)
  To: Stephen Hemminger
  Cc: ferruh.yigit, wenzhuo.lu, beilei.xing, bernard.iremonger,
	Ori Kam, Slava Ovsiienko, NBU-Contact-Thomas Monjalon,
	Raslan Darawsheh, dev



> -----Original Message-----
> From: Stephen Hemminger <stephen@networkplumber.org>
> Sent: Wednesday, January 6, 2021 11:56 PM
> To: Jiawei(Jonny) Wang <jiaweiw@nvidia.com>
> Cc: ferruh.yigit@intel.com; wenzhuo.lu@intel.com; beilei.xing@intel.com;
> bernard.iremonger@intel.com; Ori Kam <orika@nvidia.com>; Slava
> Ovsiienko <viacheslavo@nvidia.com>; NBU-Contact-Thomas Monjalon
> <thomas@monjalon.net>; Raslan Darawsheh <rasland@nvidia.com>;
> dev@dpdk.org
> Subject: Re: [dpdk-dev] [PATCH v6] app/testpmd: fix testpmd packets dump
> overlapping
> 
> On Wed,  6 Jan 2021 16:13:37 +0200
> Jiawei Wang <jiaweiw@nvidia.com> wrote:
> 
> > +	int buf_size = MAX_STRING_LEN;
> > +	char print_buf[buf_size];
> 
> Don't use dynamic sized array if you don't have to.
> Various static checkers can see look for out of bounds access to fixed size
> array.

Ok, I will change to :
char print_buf[MAX_STRING_LEN];

Thanks.


^ permalink raw reply	[flat|nested] 22+ messages in thread

* [dpdk-dev] [PATCH v7] app/testpmd: fix testpmd packets dump overlapping
  2021-01-06 14:13         ` [dpdk-dev] [PATCH v6] " Jiawei Wang
  2021-01-06 15:54           ` Stephen Hemminger
  2021-01-06 15:55           ` Stephen Hemminger
@ 2021-01-20  6:50           ` Jiawei Wang
  2021-01-20 17:57             ` Ferruh Yigit
  2 siblings, 1 reply; 22+ messages in thread
From: Jiawei Wang @ 2021-01-20  6:50 UTC (permalink / raw)
  To: ferruh.yigit, wenzhuo.lu, beilei.xing, bernard.iremonger, orika,
	viacheslavo, thomas, rasland
  Cc: dev

When testpmd enabled the verbosity for the received packets, if two packets
were received at the same time, for example, sampling packet and normal
packet, the dump output of these packets may be overlapping due to multiple
core handling the multiple queues simultaneously.

The patch uses one string buffer that collects all the packet dump output
into this buffer and then printouts it at last, that guarantees to printout
separately the dump output per packet.

Fixes: d862c45 ("app/testpmd: move dumping packets to a separate function")

Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
Acked-by: Viacheslav Ovsiienko <viacheslavo@nvidia.com>
Reviewed-by: Ferruh Yigit <ferruh.yigit@intel.com>
---
v7:
* Use the fixed sized array.
* Use the size_t format for length definition.
* Rebase the latest code.

v6:
* Rebase the latest code.

v5:
* Remove memset function calls before snprintf calls.

v4:
* Remove 'break' the loop if trancation and contiue to handle next packet.

v3:
* Use the marco instead of function calls to simplfy code.
* Use the shorter chars '...' append into the dump to notify the truncation.
* Update the commit message.
* Rebase.

v2:
* Print dump output of per packet instead of per burst.
* Add the checking for return value of 'snprintf' and exit if required size exceed the print buffer size.
* Update the log messages.

---
 app/test-pmd/util.c | 175 ++++++++++++++++++++++++++++++++++------------------
 1 file changed, 115 insertions(+), 60 deletions(-)

diff --git a/app/test-pmd/util.c b/app/test-pmd/util.c
index 649bf8f..a9e431a 100644
--- a/app/test-pmd/util.c
+++ b/app/test-pmd/util.c
@@ -15,12 +15,23 @@
 
 #include "testpmd.h"
 
+#define MAX_STRING_LEN 8192
+
+#define MKDUMPSTR(buf, buf_size, cur_len, ...) \
+do { \
+	if (cur_len >= buf_size) \
+		break; \
+	cur_len += snprintf(buf + cur_len, buf_size - cur_len, __VA_ARGS__); \
+} while (0)
+
 static inline void
-print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr)
+print_ether_addr(const char *what, const struct rte_ether_addr *eth_addr,
+		 char print_buf[], size_t buf_size, size_t *cur_len)
 {
 	char buf[RTE_ETHER_ADDR_FMT_SIZE];
+
 	rte_ether_format_addr(buf, RTE_ETHER_ADDR_FMT_SIZE, eth_addr);
-	printf("%s%s", what, buf);
+	MKDUMPSTR(print_buf, buf_size, *cur_len, "%s%s", what, buf);
 }
 
 static inline bool
@@ -74,13 +85,15 @@
 	uint32_t vx_vni;
 	const char *reason;
 	int dynf_index;
+	char print_buf[MAX_STRING_LEN];
+	size_t buf_size = MAX_STRING_LEN;
+	size_t cur_len = 0;
 
 	if (!nb_pkts)
 		return;
-	printf("port %u/queue %u: %s %u packets\n",
-		port_id, queue,
-	       is_rx ? "received" : "sent",
-	       (unsigned int) nb_pkts);
+	MKDUMPSTR(print_buf, buf_size, cur_len,
+		  "port %u/queue %u: %s %u packets\n", port_id, queue,
+		  is_rx ? "received" : "sent", (unsigned int) nb_pkts);
 	for (i = 0; i < nb_pkts; i++) {
 		int ret;
 		struct rte_flow_error error;
@@ -93,95 +106,128 @@
 		is_encapsulation = RTE_ETH_IS_TUNNEL_PKT(packet_type);
 		ret = rte_flow_get_restore_info(port_id, mb, &info, &error);
 		if (!ret) {
-			printf("restore info:");
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  "restore info:");
 			if (info.flags & RTE_FLOW_RESTORE_INFO_TUNNEL) {
 				struct port_flow_tunnel *port_tunnel;
 
 				port_tunnel = port_flow_locate_tunnel
 					      (port_id, &info.tunnel);
-				printf(" - tunnel");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - tunnel");
 				if (port_tunnel)
-					printf(" #%u", port_tunnel->id);
+					MKDUMPSTR(print_buf, buf_size, cur_len,
+						  " #%u", port_tunnel->id);
 				else
-					printf(" %s", "-none-");
-				printf(" type %s",
-					port_flow_tunnel_type(&info.tunnel));
+					MKDUMPSTR(print_buf, buf_size, cur_len,
+						  " %s", "-none-");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " type %s", port_flow_tunnel_type
+					  (&info.tunnel));
 			} else {
-				printf(" - no tunnel info");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no tunnel info");
 			}
 			if (info.flags & RTE_FLOW_RESTORE_INFO_ENCAPSULATED)
-				printf(" - outer header present");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - outer header present");
 			else
-				printf(" - no outer header");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no outer header");
 			if (info.flags & RTE_FLOW_RESTORE_INFO_GROUP_ID)
-				printf(" - miss group %u", info.group_id);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - miss group %u", info.group_id);
 			else
-				printf(" - no miss group");
-			printf("\n");
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - no miss group");
+			MKDUMPSTR(print_buf, buf_size, cur_len, "\n");
 		}
-		print_ether_addr("  src=", &eth_hdr->s_addr);
-		print_ether_addr(" - dst=", &eth_hdr->d_addr);
-		printf(" - type=0x%04x - length=%u - nb_segs=%d",
-		       eth_type, (unsigned int) mb->pkt_len,
-		       (int)mb->nb_segs);
+		print_ether_addr("  src=", &eth_hdr->s_addr,
+				 print_buf, buf_size, &cur_len);
+		print_ether_addr(" - dst=", &eth_hdr->d_addr,
+				 print_buf, buf_size, &cur_len);
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  " - type=0x%04x - length=%u - nb_segs=%d",
+			  eth_type, (unsigned int) mb->pkt_len,
+			  (int)mb->nb_segs);
 		ol_flags = mb->ol_flags;
 		if (ol_flags & PKT_RX_RSS_HASH) {
-			printf(" - RSS hash=0x%x", (unsigned int) mb->hash.rss);
-			printf(" - RSS queue=0x%x", (unsigned int) queue);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - RSS hash=0x%x",
+				  (unsigned int) mb->hash.rss);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - RSS queue=0x%x", (unsigned int) queue);
 		}
 		if (ol_flags & PKT_RX_FDIR) {
-			printf(" - FDIR matched ");
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - FDIR matched ");
 			if (ol_flags & PKT_RX_FDIR_ID)
-				printf("ID=0x%x",
-				       mb->hash.fdir.hi);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "ID=0x%x", mb->hash.fdir.hi);
 			else if (ol_flags & PKT_RX_FDIR_FLX)
-				printf("flex bytes=0x%08x %08x",
-				       mb->hash.fdir.hi, mb->hash.fdir.lo);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "flex bytes=0x%08x %08x",
+					  mb->hash.fdir.hi, mb->hash.fdir.lo);
 			else
-				printf("hash=0x%x ID=0x%x ",
-				       mb->hash.fdir.hash, mb->hash.fdir.id);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  "hash=0x%x ID=0x%x ",
+					  mb->hash.fdir.hash, mb->hash.fdir.id);
 		}
 		if (is_timestamp_enabled(mb))
-			printf(" - timestamp %"PRIu64" ", get_timestamp(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - timestamp %"PRIu64" ", get_timestamp(mb));
 		if (ol_flags & PKT_RX_QINQ)
-			printf(" - QinQ VLAN tci=0x%x, VLAN tci outer=0x%x",
-			       mb->vlan_tci, mb->vlan_tci_outer);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - QinQ VLAN tci=0x%x, VLAN tci outer=0x%x",
+				  mb->vlan_tci, mb->vlan_tci_outer);
 		else if (ol_flags & PKT_RX_VLAN)
-			printf(" - VLAN tci=0x%x", mb->vlan_tci);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - VLAN tci=0x%x", mb->vlan_tci);
 		if (!is_rx && (ol_flags & PKT_TX_DYNF_METADATA))
-			printf(" - Tx metadata: 0x%x",
-			       *RTE_FLOW_DYNF_METADATA(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - Tx metadata: 0x%x",
+				  *RTE_FLOW_DYNF_METADATA(mb));
 		if (is_rx && (ol_flags & PKT_RX_DYNF_METADATA))
-			printf(" - Rx metadata: 0x%x",
-			       *RTE_FLOW_DYNF_METADATA(mb));
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - Rx metadata: 0x%x",
+				  *RTE_FLOW_DYNF_METADATA(mb));
 		for (dynf_index = 0; dynf_index < 64; dynf_index++) {
 			if (dynf_names[dynf_index][0] != '\0')
-				printf(" - dynf %s: %d",
-				       dynf_names[dynf_index],
-				       !!(ol_flags & (1UL << dynf_index)));
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - dynf %s: %d",
+					  dynf_names[dynf_index],
+					  !!(ol_flags & (1UL << dynf_index)));
 		}
 		if (mb->packet_type) {
 			rte_get_ptype_name(mb->packet_type, buf, sizeof(buf));
-			printf(" - hw ptype: %s", buf);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - hw ptype: %s", buf);
 		}
 		sw_packet_type = rte_net_get_ptype(mb, &hdr_lens,
 					RTE_PTYPE_ALL_MASK);
 		rte_get_ptype_name(sw_packet_type, buf, sizeof(buf));
-		printf(" - sw ptype: %s", buf);
+		MKDUMPSTR(print_buf, buf_size, cur_len, " - sw ptype: %s", buf);
 		if (sw_packet_type & RTE_PTYPE_L2_MASK)
-			printf(" - l2_len=%d", hdr_lens.l2_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l2_len=%d",
+				  hdr_lens.l2_len);
 		if (sw_packet_type & RTE_PTYPE_L3_MASK)
-			printf(" - l3_len=%d", hdr_lens.l3_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l3_len=%d",
+				  hdr_lens.l3_len);
 		if (sw_packet_type & RTE_PTYPE_L4_MASK)
-			printf(" - l4_len=%d", hdr_lens.l4_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len, " - l4_len=%d",
+				  hdr_lens.l4_len);
 		if (sw_packet_type & RTE_PTYPE_TUNNEL_MASK)
-			printf(" - tunnel_len=%d", hdr_lens.tunnel_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - tunnel_len=%d", hdr_lens.tunnel_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L2_MASK)
-			printf(" - inner_l2_len=%d", hdr_lens.inner_l2_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l2_len=%d", hdr_lens.inner_l2_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L3_MASK)
-			printf(" - inner_l3_len=%d", hdr_lens.inner_l3_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l3_len=%d", hdr_lens.inner_l3_len);
 		if (sw_packet_type & RTE_PTYPE_INNER_L4_MASK)
-			printf(" - inner_l4_len=%d", hdr_lens.inner_l4_len);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  " - inner_l4_len=%d", hdr_lens.inner_l4_len);
 		if (is_encapsulation) {
 			struct rte_ipv4_hdr *ipv4_hdr;
 			struct rte_ipv6_hdr *ipv6_hdr;
@@ -218,18 +264,27 @@
 				l2_len + l3_len + l4_len);
 				udp_port = RTE_BE_TO_CPU_16(udp_hdr->dst_port);
 				vx_vni = rte_be_to_cpu_32(vxlan_hdr->vx_vni);
-				printf(" - VXLAN packet: packet type =%d, "
-				       "Destination UDP port =%d, VNI = %d",
-				       packet_type, udp_port, vx_vni >> 8);
+				MKDUMPSTR(print_buf, buf_size, cur_len,
+					  " - VXLAN packet: packet type =%d, "
+					  "Destination UDP port =%d, VNI = %d",
+					  packet_type, udp_port, vx_vni >> 8);
 			}
 		}
-		printf(" - %s queue=0x%x", is_rx ? "Receive" : "Send",
-			(unsigned int) queue);
-		printf("\n");
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  " - %s queue=0x%x", is_rx ? "Receive" : "Send",
+			  (unsigned int) queue);
+		MKDUMPSTR(print_buf, buf_size, cur_len, "\n");
 		rte_get_rx_ol_flag_list(mb->ol_flags, buf, sizeof(buf));
-		printf("  ol_flags: %s\n", buf);
+		MKDUMPSTR(print_buf, buf_size, cur_len,
+			  "  ol_flags: %s\n", buf);
 		if (rte_mbuf_check(mb, 1, &reason) < 0)
-			printf("INVALID mbuf: %s\n", reason);
+			MKDUMPSTR(print_buf, buf_size, cur_len,
+				  "INVALID mbuf: %s\n", reason);
+		if (cur_len >= buf_size)
+			printf("%s ...\n", print_buf);
+		else
+			printf("%s", print_buf);
+		cur_len = 0;
 	}
 }
 
-- 
1.8.3.1


^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [dpdk-dev] [PATCH v7] app/testpmd: fix testpmd packets dump overlapping
  2021-01-20  6:50           ` [dpdk-dev] [PATCH v7] " Jiawei Wang
@ 2021-01-20 17:57             ` Ferruh Yigit
  0 siblings, 0 replies; 22+ messages in thread
From: Ferruh Yigit @ 2021-01-20 17:57 UTC (permalink / raw)
  To: Jiawei Wang, wenzhuo.lu, beilei.xing, bernard.iremonger, orika,
	viacheslavo, thomas, rasland
  Cc: dev

On 1/20/2021 6:50 AM, Jiawei Wang wrote:
> When testpmd enabled the verbosity for the received packets, if two packets
> were received at the same time, for example, sampling packet and normal
> packet, the dump output of these packets may be overlapping due to multiple
> core handling the multiple queues simultaneously.
> 
> The patch uses one string buffer that collects all the packet dump output
> into this buffer and then printouts it at last, that guarantees to printout
> separately the dump output per packet.
> 
> Fixes: d862c45 ("app/testpmd: move dumping packets to a separate function")
> 
> Signed-off-by: Jiawei Wang <jiaweiw@nvidia.com>
> Acked-by: Viacheslav Ovsiienko <viacheslavo@nvidia.com>
> Reviewed-by: Ferruh Yigit <ferruh.yigit@intel.com>

Applied to dpdk-next-net/main, thanks.


^ permalink raw reply	[flat|nested] 22+ messages in thread

end of thread, other threads:[~2021-01-20 17:57 UTC | newest]

Thread overview: 22+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-11-12  8:36 [dpdk-dev] [PATCH] app/testpmd: fix testpmd packets dump overlapping Jiawei Wang
2020-11-12 16:44 ` Ferruh Yigit
2020-11-13 16:30   ` Jiawei(Jonny) Wang
2020-11-14 12:01 ` [dpdk-dev] [PATCH v2] " Jiawei Wang
2020-11-17 12:06   ` Ferruh Yigit
2020-11-18 18:09     ` Jiawei(Jonny) Wang
2020-11-19 10:30       ` Ferruh Yigit
2020-11-20 17:35   ` [dpdk-dev] [PATCH v3] " Jiawei Wang
2020-11-20 17:50     ` Ferruh Yigit
2020-11-23  6:13       ` Jiawei(Jonny) Wang
2020-11-23 10:22         ` Ferruh Yigit
2020-11-23 11:03           ` Jiawei(Jonny) Wang
2020-11-23  8:29     ` [dpdk-dev] [PATCH v4] " Jiawei Wang
2020-11-23 11:00       ` [dpdk-dev] [PATCH v5] " Jiawei Wang
2020-11-23 14:20         ` Ferruh Yigit
2021-01-06 14:13         ` [dpdk-dev] [PATCH v6] " Jiawei Wang
2021-01-06 15:54           ` Stephen Hemminger
2021-01-08  8:31             ` Jiawei(Jonny) Wang
2021-01-06 15:55           ` Stephen Hemminger
2021-01-08  8:31             ` Jiawei(Jonny) Wang
2021-01-20  6:50           ` [dpdk-dev] [PATCH v7] " Jiawei Wang
2021-01-20 17:57             ` Ferruh Yigit

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).