[PATCH] vhost: change mbuf allocation logs to debug

[PATCH] vhost: change mbuf allocation logs to debug

[Allain Legacy]

From: Matt Peters <matt.peters@windriver.com>

The current packet buffer alloc failures of the vhost dequeue operations
can flood the log system with error logs due to logging a runtime error
condition within the data path.  In order to prevent this condition, but
still enable debugging, the logs are being changed to debug logs to ensure
they are not emitted unless the CONFIG_RTE_LIBRTE_VHOST_DEBUG option is
enabled.

Signed-off-by: Matt Peters <matt.peters@windriver.com>
Signed-off-by: Allain Legacy <allain.legacy@windriver.com>
---
 lib/librte_vhost/virtio_net.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/lib/librte_vhost/virtio_net.c b/lib/librte_vhost/virtio_net.c
index 337470d64..850b56082 100644
--- a/lib/librte_vhost/virtio_net.c
+++ b/lib/librte_vhost/virtio_net.c
@@ -901,7 +901,7 @@ copy_desc_to_mbuf(struct virtio_net *dev, struct vring_desc *descs,
 		if (mbuf_avail == 0) {
 			cur = rte_pktmbuf_alloc(mbuf_pool);
 			if (unlikely(cur == NULL)) {
-				RTE_LOG(ERR, VHOST_DATA, "Failed to "
+				LOG_DEBUG(VHOST_DATA, "Failed to "
 					"allocate memory for mbuf.\n");
 				return -1;
 			}
@@ -1129,7 +1129,7 @@ rte_vhost_dequeue_burst(int vid, uint16_t queue_id,
 
 		pkts[i] = rte_pktmbuf_alloc(mbuf_pool);
 		if (unlikely(pkts[i] == NULL)) {
-			RTE_LOG(ERR, VHOST_DATA,
+			LOG_DEBUG(VHOST_DATA,
 				"Failed to allocate memory for mbuf.\n");
 			break;
 		}
-- 
2.12.1

Re: [PATCH] vhost: change mbuf allocation logs to debug

[Yuanhan Liu]

On Mon, Mar 27, 2017 at 12:29:30PM -0400, Allain Legacy wrote:
> From: Matt Peters <matt.peters@windriver.com>
> 
> The current packet buffer alloc failures of the vhost dequeue operations
> can flood the log system with error logs due to logging a runtime error
> condition within the data path.

I agree that we should avoid flood. But somehow I think it's valueable
to print such message. It could simply mean you don't have enough mbuf
created, or, unlikely, mbuf leak happended.

> In order to prevent this condition, but
> still enable debugging, the logs are being changed to debug logs to ensure
> they are not emitted unless the CONFIG_RTE_LIBRTE_VHOST_DEBUG option is
> enabled.

That basically means you will never see them in real life. I'm suggesting
to add a new log API, RTE_LOG_ONCE. Sounds good?

	--yliu
> 
> Signed-off-by: Matt Peters <matt.peters@windriver.com>
> Signed-off-by: Allain Legacy <allain.legacy@windriver.com>
> ---
>  lib/librte_vhost/virtio_net.c | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/lib/librte_vhost/virtio_net.c b/lib/librte_vhost/virtio_net.c
> index 337470d64..850b56082 100644
> --- a/lib/librte_vhost/virtio_net.c
> +++ b/lib/librte_vhost/virtio_net.c
> @@ -901,7 +901,7 @@ copy_desc_to_mbuf(struct virtio_net *dev, struct vring_desc *descs,
>  		if (mbuf_avail == 0) {
>  			cur = rte_pktmbuf_alloc(mbuf_pool);
>  			if (unlikely(cur == NULL)) {
> -				RTE_LOG(ERR, VHOST_DATA, "Failed to "
> +				LOG_DEBUG(VHOST_DATA, "Failed to "
>  					"allocate memory for mbuf.\n");
>  				return -1;
>  			}
> @@ -1129,7 +1129,7 @@ rte_vhost_dequeue_burst(int vid, uint16_t queue_id,
>  
>  		pkts[i] = rte_pktmbuf_alloc(mbuf_pool);
>  		if (unlikely(pkts[i] == NULL)) {
> -			RTE_LOG(ERR, VHOST_DATA,
> +			LOG_DEBUG(VHOST_DATA,
>  				"Failed to allocate memory for mbuf.\n");
>  			break;
>  		}
> -- 
> 2.12.1

Re: [PATCH] vhost: change mbuf allocation logs to debug

[Legacy, Allain]

> -----Original Message-----
> From: Yuanhan Liu [mailto:yuanhan.liu@linux.intel.com]
> Sent: Tuesday, March 28, 2017 2:49 AM
<...>
> > In order to prevent this condition, but
> > still enable debugging, the logs are being changed to debug logs to ensure
> > they are not emitted unless the CONFIG_RTE_LIBRTE_VHOST_DEBUG
> option is
> > enabled.
> 
> That basically means you will never see them in real life. I'm suggesting
> to add a new log API, RTE_LOG_ONCE. Sounds good?


Rather than a log what is really needed here is a stat/counter, but this library does not have the infrastructure in place to support reporting datapath errors via stats back to the application.  Are there any plans to add a stats infrastructure or a desired design for what that would look like?

Re: [PATCH] vhost: change mbuf allocation logs to debug

[Yuanhan Liu]

On Tue, Mar 28, 2017 at 11:39:37AM +0000, Legacy, Allain wrote:
> > -----Original Message-----
> > From: Yuanhan Liu [mailto:yuanhan.liu@linux.intel.com]
> > Sent: Tuesday, March 28, 2017 2:49 AM
> <...>
> > > In order to prevent this condition, but
> > > still enable debugging, the logs are being changed to debug logs to ensure
> > > they are not emitted unless the CONFIG_RTE_LIBRTE_VHOST_DEBUG
> > option is
> > > enabled.
> > 
> > That basically means you will never see them in real life. I'm suggesting
> > to add a new log API, RTE_LOG_ONCE. Sounds good?
> 
> 
> Rather than a log what is really needed here is a stat/counter, but this library does not have the infrastructure in place to support reporting datapath errors via stats back to the application.

Right. It's supposed to be done in vhost-pmd, while the real Rx implementation
is at vhost lib.

>  Are there any plans to add a stats infrastructure or a desired design for what that would look like?

We could have such counter support once we move virtio_net.c to vhost-pmd.
Unluckily, I don't think it will happen soon.

OTOH, it's still good to have RTE_LOG_ONCE. It explicitly tells you something
is wrong, then you could dump those stats for more info.

	--yliu

Re: [PATCH] vhost: change mbuf allocation logs to debug

[Legacy, Allain]

> -----Original Message-----
> From: Yuanhan Liu [mailto:yuanhan.liu@linux.intel.com]
> Sent: Wednesday, March 29, 2017 3:02 AM

<...>
> 
> OTOH, it's still good to have RTE_LOG_ONCE. It explicitly tells you something
> is wrong, then you could dump those stats for more info.

Has the implementation of something like RTE_LOG_ONCE been discussed before?  

Do you have a proposal on what you would find acceptable as an implementation that considers multiples threads, multiple devices, multiple logs per file, etc.?

Re: [PATCH] vhost: change mbuf allocation logs to debug

[Yuanhan Liu]

On Wed, Mar 29, 2017 at 10:45:55PM +0000, Legacy, Allain wrote:
> > -----Original Message-----
> > From: Yuanhan Liu [mailto:yuanhan.liu@linux.intel.com]
> > Sent: Wednesday, March 29, 2017 3:02 AM
> 
> <...>
> > 
> > OTOH, it's still good to have RTE_LOG_ONCE. It explicitly tells you something
> > is wrong, then you could dump those stats for more info.
> 
> Has the implementation of something like RTE_LOG_ONCE been discussed before?  

No. It's just something comes to my mind after saw your patch.

> Do you have a proposal on what you would find acceptable as an implementation that considers multiples threads, multiple devices, multiple logs per file, etc.?

No, that would be way to complex. Something I thought of is quite
simple (like what Linux kernel does):

	#define RTE_LOG_ONCE(...)	do {	\
		static int warned;		\
		if (!warned) {			\
			RTE_LOG(...);		\
			warned = 1;		\
		}				\
	} while (0)


And yes, I know it's far away from being perfect (and accurate, regarding
to multiple devices and so on as you mentioned). Even though, I think
it's much better than showing nothing when something goes wrong.

	--yliu