[PATCH] ethdev: prefer offload names in logs

[PATCH] ethdev: prefer offload names in logs

[David Marchand]

Displaying a bitmask is terrible for users.
Prefer offload names when refusing some offloads in
rte_eth_dev_configure.

Before:
Ethdev port_id=0 requested Rx offloads 0x621 doesn't match Rx offloads
	capabilities 0x0 in rte_eth_dev_configure()

After:
Ethdev port_id=0 requested Rx offloads 'VLAN_STRIP,QINQ_STRIP,VLAN_FILTER,
	VLAN_EXTEND' in rte_eth_dev_configure(). Device supports '' Rx
	offloads but does not support 'VLAN_STRIP,QINQ_STRIP,VLAN_FILTER,
	VLAN_EXTEND'.

Signed-off-by: David Marchand <david.marchand@redhat.com>
---
 lib/ethdev/rte_ethdev.c | 80 ++++++++++++++++++++++++++++++++++-------
 1 file changed, 68 insertions(+), 12 deletions(-)

diff --git a/lib/ethdev/rte_ethdev.c b/lib/ethdev/rte_ethdev.c
index 4d03255683..ba5cfeecd9 100644
--- a/lib/ethdev/rte_ethdev.c
+++ b/lib/ethdev/rte_ethdev.c
@@ -1026,6 +1026,42 @@ rte_eth_dev_tx_offload_name(uint64_t offload)
 	return name;
 }
 
+static char *
+eth_dev_offload_names(uint64_t bitmask, const char *(*offload_name)(uint64_t))
+{
+	uint64_t offload;
+	char *names;
+
+	if (bitmask == 0) {
+		names = strdup("");
+		goto out;
+	}
+
+	offload = RTE_BIT64(__builtin_ctzll(bitmask));
+	names = strdup(offload_name(offload));
+	if (names == NULL)
+		goto out;
+
+	bitmask &= ~offload;
+	while (bitmask != 0) {
+		char *old = names;
+		int ret;
+
+		offload = RTE_BIT64(__builtin_ctzll(bitmask));
+		ret = asprintf(&names, "%s,%s", old, offload_name(offload));
+		free(old);
+		if (ret == -1) {
+			names = NULL;
+			goto out;
+		}
+
+		bitmask &= ~offload;
+	}
+
+out:
+	return names;
+}
+
 const char *
 rte_eth_dev_capability_name(uint64_t capability)
 {
@@ -1332,23 +1368,43 @@ rte_eth_dev_configure(uint16_t port_id, uint16_t nb_rx_q, uint16_t nb_tx_q,
 	/* Any requested offloading must be within its device capabilities */
 	if ((dev_conf->rxmode.offloads & dev_info.rx_offload_capa) !=
 	     dev_conf->rxmode.offloads) {
-		RTE_ETHDEV_LOG(ERR,
-			"Ethdev port_id=%u requested Rx offloads 0x%"PRIx64" doesn't match Rx offloads "
-			"capabilities 0x%"PRIx64" in %s()\n",
-			port_id, dev_conf->rxmode.offloads,
-			dev_info.rx_offload_capa,
-			__func__);
+		char *requested = eth_dev_offload_names(dev_conf->rxmode.offloads,
+			rte_eth_dev_rx_offload_name);
+		char *available = eth_dev_offload_names(dev_info.rx_offload_capa,
+			rte_eth_dev_rx_offload_name);
+		char *unavailable = eth_dev_offload_names(
+			dev_conf->rxmode.offloads & ~dev_info.rx_offload_capa,
+			rte_eth_dev_rx_offload_name);
+
+		RTE_ETHDEV_LOG(ERR, "Ethdev port_id=%u requested Rx offloads '%s' in %s(). "
+			"Device supports '%s' Rx offloads but does not support '%s'.\n",
+			port_id, requested != NULL ? requested : "N/A", __func__,
+			available != NULL ? available : "N/A",
+			unavailable != NULL ? unavailable : "N/A");
+		free(requested);
+		free(available);
+		free(unavailable);
 		ret = -EINVAL;
 		goto rollback;
 	}
 	if ((dev_conf->txmode.offloads & dev_info.tx_offload_capa) !=
 	     dev_conf->txmode.offloads) {
-		RTE_ETHDEV_LOG(ERR,
-			"Ethdev port_id=%u requested Tx offloads 0x%"PRIx64" doesn't match Tx offloads "
-			"capabilities 0x%"PRIx64" in %s()\n",
-			port_id, dev_conf->txmode.offloads,
-			dev_info.tx_offload_capa,
-			__func__);
+		char *requested = eth_dev_offload_names(dev_conf->txmode.offloads,
+			rte_eth_dev_tx_offload_name);
+		char *available = eth_dev_offload_names(dev_info.tx_offload_capa,
+			rte_eth_dev_tx_offload_name);
+		char *unavailable = eth_dev_offload_names(
+			dev_conf->txmode.offloads & ~dev_info.tx_offload_capa,
+			rte_eth_dev_tx_offload_name);
+
+		RTE_ETHDEV_LOG(ERR, "Ethdev port_id=%u requested Tx offloads '%s' in %s(). "
+			"Device supports '%s' Tx offloads but does not support '%s'.\n",
+			port_id, requested != NULL ? requested : "N/A", __func__,
+			available != NULL ? available : "N/A",
+			unavailable != NULL ? unavailable : "N/A");
+		free(requested);
+		free(available);
+		free(unavailable);
 		ret = -EINVAL;
 		goto rollback;
 	}
-- 
2.39.2

Re: [PATCH] ethdev: prefer offload names in logs

[Stephen Hemminger]

On Thu,  9 Mar 2023 09:16:33 +0100
David Marchand <david.marchand@redhat.com> wrote:

> +		RTE_ETHDEV_LOG(ERR, "Ethdev port_id=%u requested Rx offloads '%s' in %s(). "
> +			"Device supports '%s' Rx offloads but does not support '%s'.\n",
> +			port_id, requested != NULL ? requested : "N/A", __func__,
> +			available != NULL ? available : "N/A",
> +			unavailable != NULL ? unavailable : "N/A");
> +		free(requested);

Please shorten message and make sure it does not cross line boundaries.
Best to allow users to do simple search for message.

Re: [PATCH] ethdev: prefer offload names in logs

[Ferruh Yigit]

On 3/9/2023 4:21 PM, Stephen Hemminger wrote:
> On Thu,  9 Mar 2023 09:16:33 +0100
> David Marchand <david.marchand@redhat.com> wrote:
> 
>> +		RTE_ETHDEV_LOG(ERR, "Ethdev port_id=%u requested Rx offloads '%s' in %s(). "
>> +			"Device supports '%s' Rx offloads but does not support '%s'.\n",
>> +			port_id, requested != NULL ? requested : "N/A", __func__,
>> +			available != NULL ? available : "N/A",
>> +			unavailable != NULL ? unavailable : "N/A");
>> +		free(requested);
> 
> Please shorten message and make sure it does not cross line boundaries.
> Best to allow users to do simple search for message.

Agree that using offload names are more user friendly.

To keep the log more reasonable length, what would you think to split
into two, one in ERR level other is in info/debug:
ERR, "Ethdev port_id=%u does not support '%s'.\n", unavailable
DEBUG, "Ethdev port_id=%u requested Rx offloads '%s', device supports
'%s'.\n", requested, available

And I think we can drop __func__, we don't use in many other logs anyway.



Other option can be to provide APIs to print all offloads (similar to
'rte_eth_dev_tx_offload_name()'), so application does its own logging,
and ethdev just prints 'unavailable' part of the log.

Re: [PATCH] ethdev: prefer offload names in logs

[David Marchand]

On Wed, May 17, 2023 at 4:53 PM Ferruh Yigit <ferruh.yigit@amd.com> wrote:
>
> On 3/9/2023 4:21 PM, Stephen Hemminger wrote:
> > On Thu,  9 Mar 2023 09:16:33 +0100
> > David Marchand <david.marchand@redhat.com> wrote:
> >
> >> +            RTE_ETHDEV_LOG(ERR, "Ethdev port_id=%u requested Rx offloads '%s' in %s(). "
> >> +                    "Device supports '%s' Rx offloads but does not support '%s'.\n",
> >> +                    port_id, requested != NULL ? requested : "N/A", __func__,
> >> +                    available != NULL ? available : "N/A",
> >> +                    unavailable != NULL ? unavailable : "N/A");
> >> +            free(requested);
> >
> > Please shorten message and make sure it does not cross line boundaries.
> > Best to allow users to do simple search for message.
>
> Agree that using offload names are more user friendly.
>
> To keep the log more reasonable length, what would you think to split
> into two, one in ERR level other is in info/debug:
> ERR, "Ethdev port_id=%u does not support '%s'.\n", unavailable
> DEBUG, "Ethdev port_id=%u requested Rx offloads '%s', device supports
> '%s'.\n", requested, available
>
> And I think we can drop __func__, we don't use in many other logs anyway.

Splitting seems the simpler and won't require an application involvement.
I would even split the debug message in two (after all, if we have two
logs, why not three :-)).

I'll also revisit the patch wrt allocations.

>
>
>
> Other option can be to provide APIs to print all offloads (similar to
> 'rte_eth_dev_tx_offload_name()'), so application does its own logging,
> and ethdev just prints 'unavailable' part of the log.
>


-- 
David Marchand

Re: [PATCH] ethdev: prefer offload names in logs

[Ferruh Yigit]

On 3/9/2023 8:16 AM, David Marchand wrote:
> +static char *
> +eth_dev_offload_names(uint64_t bitmask, const char *(*offload_name)(uint64_t))
> +{
> +	uint64_t offload;
> +	char *names;
> +
> +	if (bitmask == 0) {
> +		names = strdup("");
> +		goto out;
> +	}
> +
> +	offload = RTE_BIT64(__builtin_ctzll(bitmask));
> +	names = strdup(offload_name(offload));
> +	if (names == NULL)
> +		goto out;
> +
> +	bitmask &= ~offload;
> +	while (bitmask != 0) {
> +		char *old = names;
> +		int ret;
> +
> +		offload = RTE_BIT64(__builtin_ctzll(bitmask));
> +		ret = asprintf(&names, "%s,%s", old, offload_name(offload));
> +		free(old);
> +		if (ret == -1) {
> +			names = NULL;
> +			goto out;
> +		}
> +
> +		bitmask &= ~offload;
> +	}
> +
> +out:
> +	return names;
> +}
> +

Above works fine, not a strong opinion but just a comment,
this function is just for logging and output string will be short lived,
but it does lots of memory alloc and free, and expose lot of failure points.

To simplify, why not just alloc a big enough buffer, fill it in a loop
and never return NULL?
(Can always append "%s," and drop final ',' at the end.)

[PATCH v2] ethdev: prefer offload names in logs

[David Marchand]

Displaying a bitmask is terrible for users.
Prefer offload names when refusing some offloads in
rte_eth_dev_configure.

Before:
Ethdev port_id=0 requested Rx offloads 0x621 doesn't match Rx offloads
	capabilities 0x0 in rte_eth_dev_configure()

After:
Ethdev port_id=0 does not support Rx offloads VLAN_STRIP,QINQ_STRIP,VLAN_FILTER,VLAN_EXTEND
Ethdev port_id=0 was requested Rx offloads VLAN_STRIP,QINQ_STRIP,VLAN_FILTER,VLAN_EXTEND
Ethdev port_id=0 supports Rx offloads none

Signed-off-by: David Marchand <david.marchand@redhat.com>
---
Changes since v1:
- reworked string formatter to avoid dynamic allocations,
- split log message in three, with the most important part logged as
  ERR, and the rest being logged as DEBUG,

---
 lib/ethdev/rte_ethdev.c | 80 ++++++++++++++++++++++++++++++++++-------
 1 file changed, 68 insertions(+), 12 deletions(-)

diff --git a/lib/ethdev/rte_ethdev.c b/lib/ethdev/rte_ethdev.c
index 7317015895..731423ef03 100644
--- a/lib/ethdev/rte_ethdev.c
+++ b/lib/ethdev/rte_ethdev.c
@@ -1047,6 +1047,49 @@ rte_eth_dev_tx_offload_name(uint64_t offload)
 	return name;
 }
 
+static char *
+eth_dev_offload_names(uint64_t bitmask, char *buf, size_t size,
+	const char *(*offload_name)(uint64_t))
+{
+	unsigned int pos = 0;
+	int ret;
+
+	/* There should be at least enough space to handle those cases */
+	RTE_ASSERT(size >= sizeof("none") && size >= sizeof("..."));
+
+	if (bitmask == 0) {
+		ret = snprintf(&buf[pos], size - pos, "none");
+		if (ret < 0 || pos + ret >= size)
+			ret = 0;
+		pos += ret;
+		goto out;
+	}
+
+	while (bitmask != 0) {
+		uint64_t offload = RTE_BIT64(__builtin_ctzll(bitmask));
+		const char *name = offload_name(offload);
+
+		ret = snprintf(&buf[pos], size - pos, "%s,", name);
+		if (ret < 0 || pos + ret >= size) {
+			if (pos + sizeof("...") >= size)
+				pos = size - sizeof("...");
+			ret = snprintf(&buf[pos], size - pos, "...");
+			if (ret > 0 && pos + ret < size)
+				pos += ret;
+			goto out;
+		}
+
+		pos += ret;
+		bitmask &= ~offload;
+	}
+
+	/* Eliminate trailing comma */
+	pos--;
+out:
+	buf[pos] = '\0';
+	return buf;
+}
+
 const char *
 rte_eth_dev_capability_name(uint64_t capability)
 {
@@ -1353,23 +1396,36 @@ rte_eth_dev_configure(uint16_t port_id, uint16_t nb_rx_q, uint16_t nb_tx_q,
 	/* Any requested offloading must be within its device capabilities */
 	if ((dev_conf->rxmode.offloads & dev_info.rx_offload_capa) !=
 	     dev_conf->rxmode.offloads) {
-		RTE_ETHDEV_LOG(ERR,
-			"Ethdev port_id=%u requested Rx offloads 0x%"PRIx64" doesn't match Rx offloads "
-			"capabilities 0x%"PRIx64" in %s()\n",
-			port_id, dev_conf->rxmode.offloads,
-			dev_info.rx_offload_capa,
-			__func__);
+		char buffer[512];
+
+		RTE_ETHDEV_LOG(ERR, "Ethdev port_id=%u does not support Rx offloads %s\n",
+			port_id, eth_dev_offload_names(
+			dev_conf->rxmode.offloads & ~dev_info.rx_offload_capa,
+			buffer, sizeof(buffer), rte_eth_dev_rx_offload_name));
+		RTE_ETHDEV_LOG(DEBUG, "Ethdev port_id=%u was requested Rx offloads %s\n",
+			port_id, eth_dev_offload_names(dev_conf->rxmode.offloads,
+			buffer, sizeof(buffer), rte_eth_dev_rx_offload_name));
+		RTE_ETHDEV_LOG(DEBUG, "Ethdev port_id=%u supports Rx offloads %s\n",
+			port_id, eth_dev_offload_names(dev_info.rx_offload_capa,
+			buffer, sizeof(buffer), rte_eth_dev_rx_offload_name));
+
 		ret = -EINVAL;
 		goto rollback;
 	}
 	if ((dev_conf->txmode.offloads & dev_info.tx_offload_capa) !=
 	     dev_conf->txmode.offloads) {
-		RTE_ETHDEV_LOG(ERR,
-			"Ethdev port_id=%u requested Tx offloads 0x%"PRIx64" doesn't match Tx offloads "
-			"capabilities 0x%"PRIx64" in %s()\n",
-			port_id, dev_conf->txmode.offloads,
-			dev_info.tx_offload_capa,
-			__func__);
+		char buffer[512];
+
+		RTE_ETHDEV_LOG(ERR, "Ethdev port_id=%u does not support Tx offloads %s\n",
+			port_id, eth_dev_offload_names(
+			dev_conf->txmode.offloads & ~dev_info.tx_offload_capa,
+			buffer, sizeof(buffer), rte_eth_dev_tx_offload_name));
+		RTE_ETHDEV_LOG(DEBUG, "Ethdev port_id=%u was requested Tx offloads %s\n",
+			port_id, eth_dev_offload_names(dev_conf->txmode.offloads,
+			buffer, sizeof(buffer), rte_eth_dev_tx_offload_name));
+		RTE_ETHDEV_LOG(DEBUG, "Ethdev port_id=%u supports Tx offloads %s\n",
+			port_id, eth_dev_offload_names(dev_info.tx_offload_capa,
+			buffer, sizeof(buffer), rte_eth_dev_tx_offload_name));
 		ret = -EINVAL;
 		goto rollback;
 	}
-- 
2.40.1

Re: [PATCH v2] ethdev: prefer offload names in logs

[Ferruh Yigit]

On 6/13/2023 2:24 PM, David Marchand wrote:
> Displaying a bitmask is terrible for users.
> Prefer offload names when refusing some offloads in
> rte_eth_dev_configure.
> 
> Before:
> Ethdev port_id=0 requested Rx offloads 0x621 doesn't match Rx offloads
> 	capabilities 0x0 in rte_eth_dev_configure()
> 
> After:
> Ethdev port_id=0 does not support Rx offloads VLAN_STRIP,QINQ_STRIP,VLAN_FILTER,VLAN_EXTEND
> Ethdev port_id=0 was requested Rx offloads VLAN_STRIP,QINQ_STRIP,VLAN_FILTER,VLAN_EXTEND
> Ethdev port_id=0 supports Rx offloads none
> 
> Signed-off-by: David Marchand <david.marchand@redhat.com>
>

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

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