[dpdk-dev] [PATCH] log: Properly reset log_history_size in rte_log_dump_history()

[dpdk-dev] [PATCH] log: Properly reset log_history_size in rte_log_dump_history()

[Jan Blunck]

In rte_log_dump_history() the log_history list is reinitialized without
resetting the log_history_size. In the next call to rte_log_add_in_history()
the log_history_size > RTE_LOG_HISTORY and the code unconditionally tries
to remove the first entry:

Program received signal SIGSEGV, Segmentation fault.
rte_log_add_in_history (
    buf=buf@entry=0x7f02035cd000 "DATAPLANE: 9:dp0s7 link RTM_NEWLINK [dp0s7] <UP,BROADCAST,RUNNING,MULTICAST,LOWER_UP>\nCAST,LOWER_UP>\n", size=size@entry=86)
    at /usr/src/packages/BUILD/lib/librte_eal/common/eal_common_log.c:122

Signed-off-by: Jan Blunck <jblunck@infradead.org>
---
 lib/librte_eal/common/eal_common_log.c | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/lib/librte_eal/common/eal_common_log.c b/lib/librte_eal/common/eal_common_log.c
index fe3d7d5..cb4311c 100644
--- a/lib/librte_eal/common/eal_common_log.c
+++ b/lib/librte_eal/common/eal_common_log.c
@@ -119,7 +119,8 @@ rte_log_add_in_history(const char *buf, size_t size)
 	/* get a buffer for adding in history */
 	if (log_history_size > RTE_LOG_HISTORY) {
 		hist_buf = STAILQ_FIRST(&log_history);
-		STAILQ_REMOVE_HEAD(&log_history, next);
+		if (hist_buf)
+			STAILQ_REMOVE_HEAD(&log_history, next);
 	}
 	else {
 		if (rte_mempool_mc_get(log_history_mp, &obj) < 0)
@@ -234,6 +235,7 @@ rte_log_dump_history(FILE *out)
 	rte_spinlock_lock(&log_list_lock);
 	tmp_log_history = log_history;
 	STAILQ_INIT(&log_history);
+	log_history_size = 0;
 	rte_spinlock_unlock(&log_list_lock);
 
 	for (i=0; i<RTE_LOG_HISTORY; i++) {
-- 
2.1.4

Re: [dpdk-dev] [PATCH] log: Properly reset log_history_size in rte_log_dump_history()

[Olivier MATZ]

Hi Jan,

On 05/29/2015 12:34 PM, Jan Blunck wrote:
> In rte_log_dump_history() the log_history list is reinitialized without
> resetting the log_history_size. In the next call to rte_log_add_in_history()
> the log_history_size > RTE_LOG_HISTORY and the code unconditionally tries
> to remove the first entry:
> 
> Program received signal SIGSEGV, Segmentation fault.
> rte_log_add_in_history (
>     buf=buf@entry=0x7f02035cd000 "DATAPLANE: 9:dp0s7 link RTM_NEWLINK [dp0s7] <UP,BROADCAST,RUNNING,MULTICAST,LOWER_UP>\nCAST,LOWER_UP>\n", size=size@entry=86)
>     at /usr/src/packages/BUILD/lib/librte_eal/common/eal_common_log.c:122
> 
> Signed-off-by: Jan Blunck <jblunck@infradead.org>
> ---
>  lib/librte_eal/common/eal_common_log.c | 4 +++-
>  1 file changed, 3 insertions(+), 1 deletion(-)
> 
> diff --git a/lib/librte_eal/common/eal_common_log.c b/lib/librte_eal/common/eal_common_log.c
> index fe3d7d5..cb4311c 100644
> --- a/lib/librte_eal/common/eal_common_log.c
> +++ b/lib/librte_eal/common/eal_common_log.c
> @@ -119,7 +119,8 @@ rte_log_add_in_history(const char *buf, size_t size)
>  	/* get a buffer for adding in history */
>  	if (log_history_size > RTE_LOG_HISTORY) {
>  		hist_buf = STAILQ_FIRST(&log_history);
> -		STAILQ_REMOVE_HEAD(&log_history, next);
> +		if (hist_buf)
> +			STAILQ_REMOVE_HEAD(&log_history, next);

Shouldn't we decrease log_history_size here?



Also, it's probably a bit off-topic, but I think the function that
adds in history could be optimized a bit to avoid doing the copy with
the lock held. Maybe something like this is feasible:

rte_mempool_mc_get() into hist_buf
memcpy(hist_buf->buf, buf, size);
rte_spinlock_lock(&log_list_lock
if (log_history_size > RTE_LOG_HISTORY) {
    STAILQ_REMOVE_HEAD
    log_history_size --
}
STAILQ_INSERT_TAIL
log_history_size ++
rte_spinlock_unlock(&log_list_lock)

Feel free to implement it if you feel it's better. It would also
require to increase the number of objects in the pool to
RTE_LOG_HISTORY*2 + RTE_MAX_LCORE

Regards,
Olivier



>  	}
>  	else {
>  		if (rte_mempool_mc_get(log_history_mp, &obj) < 0)
> @@ -234,6 +235,7 @@ rte_log_dump_history(FILE *out)
>  	rte_spinlock_lock(&log_list_lock);
>  	tmp_log_history = log_history;
>  	STAILQ_INIT(&log_history);
> +	log_history_size = 0;
>  	rte_spinlock_unlock(&log_list_lock);
>  
>  	for (i=0; i<RTE_LOG_HISTORY; i++) {
> 

[dpdk-dev] [PATCH v2] log: Properly reset log_history_size in rte_log_dump_history()

[Jan Blunck]

In rte_log_dump_history() the log_history list is reinitialized without
resetting the log_history_size. In the next call to rte_log_add_in_history()
the log_history_size > RTE_LOG_HISTORY and the code unconditionally tries
to remove the first entry:

Program received signal SIGSEGV, Segmentation fault.
rte_log_add_in_history (
    buf=buf@entry=0x7f02035cd000 "DATAPLANE: 9:dp0s7 link RTM_NEWLINK [dp0s7] <UP,BROADCAST,RUNNING,MULTICAST,LOWER_UP>\nCAST,LOWER_UP>\n", size=size@entry=86)
    at /usr/src/packages/BUILD/lib/librte_eal/common/eal_common_log.c:122

Signed-off-by: Jan Blunck <jblunck@infradead.org>
---
 lib/librte_eal/common/eal_common_log.c | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

diff --git a/lib/librte_eal/common/eal_common_log.c b/lib/librte_eal/common/eal_common_log.c
index fe3d7d5..39d6e3f 100644
--- a/lib/librte_eal/common/eal_common_log.c
+++ b/lib/librte_eal/common/eal_common_log.c
@@ -119,7 +119,10 @@ rte_log_add_in_history(const char *buf, size_t size)
 	/* get a buffer for adding in history */
 	if (log_history_size > RTE_LOG_HISTORY) {
 		hist_buf = STAILQ_FIRST(&log_history);
-		STAILQ_REMOVE_HEAD(&log_history, next);
+		if (hist_buf) {
+			STAILQ_REMOVE_HEAD(&log_history, next);
+			log_history_size--;
+		}
 	}
 	else {
 		if (rte_mempool_mc_get(log_history_mp, &obj) < 0)
@@ -234,6 +237,7 @@ rte_log_dump_history(FILE *out)
 	rte_spinlock_lock(&log_list_lock);
 	tmp_log_history = log_history;
 	STAILQ_INIT(&log_history);
+	log_history_size = 0;
 	rte_spinlock_unlock(&log_list_lock);
 
 	for (i=0; i<RTE_LOG_HISTORY; i++) {
-- 
2.1.4

Re: [dpdk-dev] [PATCH] log: Properly reset log_history_size in rte_log_dump_history()

[Jan Blunck]

On Mon, Jun 1, 2015 at 10:31 AM, Olivier MATZ <olivier.matz@6wind.com>
wrote:

> Hi Jan,
>
> On 05/29/2015 12:34 PM, Jan Blunck wrote:
> > In rte_log_dump_history() the log_history list is reinitialized without
> > resetting the log_history_size. In the next call to
> rte_log_add_in_history()
> > the log_history_size > RTE_LOG_HISTORY and the code unconditionally tries
> > to remove the first entry:
> >
> > Program received signal SIGSEGV, Segmentation fault.
> > rte_log_add_in_history (
> >     buf=buf@entry=0x7f02035cd000 "DATAPLANE: 9:dp0s7 link RTM_NEWLINK
> [dp0s7] <UP,BROADCAST,RUNNING,MULTICAST,LOWER_UP>\nCAST,LOWER_UP>\n",
> size=size@entry=86)
> >     at /usr/src/packages/BUILD/lib/librte_eal/common/eal_common_log.c:122
> >
> > Signed-off-by: Jan Blunck <jblunck@infradead.org>
> > ---
> >  lib/librte_eal/common/eal_common_log.c | 4 +++-
> >  1 file changed, 3 insertions(+), 1 deletion(-)
> >
> > diff --git a/lib/librte_eal/common/eal_common_log.c
> b/lib/librte_eal/common/eal_common_log.c
> > index fe3d7d5..cb4311c 100644
> > --- a/lib/librte_eal/common/eal_common_log.c
> > +++ b/lib/librte_eal/common/eal_common_log.c
> > @@ -119,7 +119,8 @@ rte_log_add_in_history(const char *buf, size_t size)
> >       /* get a buffer for adding in history */
> >       if (log_history_size > RTE_LOG_HISTORY) {
> >               hist_buf = STAILQ_FIRST(&log_history);
> > -             STAILQ_REMOVE_HEAD(&log_history, next);
> > +             if (hist_buf)
> > +                     STAILQ_REMOVE_HEAD(&log_history, next);
>
> Shouldn't we decrease log_history_size here?
>
>
Thanks for catching that one.


>
>
> Also, it's probably a bit off-topic, but I think the function that
> adds in history could be optimized a bit to avoid doing the copy with
> the lock held. Maybe something like this is feasible:
>
> rte_mempool_mc_get() into hist_buf
> memcpy(hist_buf->buf, buf, size);
> rte_spinlock_lock(&log_list_lock
> if (log_history_size > RTE_LOG_HISTORY) {
>     STAILQ_REMOVE_HEAD
>     log_history_size --
> }
> STAILQ_INSERT_TAIL
> log_history_size ++
> rte_spinlock_unlock(&log_list_lock)
>
> Feel free to implement it if you feel it's better. It would also
> require to increase the number of objects in the pool to
> RTE_LOG_HISTORY*2 + RTE_MAX_LCORE
>
>
Makes sense. I'll take a look into that one later.

Thanks,
Jan


> Regards,
> Olivier
>
>
>
> >       }
> >       else {
> >               if (rte_mempool_mc_get(log_history_mp, &obj) < 0)
> > @@ -234,6 +235,7 @@ rte_log_dump_history(FILE *out)
> >       rte_spinlock_lock(&log_list_lock);
> >       tmp_log_history = log_history;
> >       STAILQ_INIT(&log_history);
> > +     log_history_size = 0;
> >       rte_spinlock_unlock(&log_list_lock);
> >
> >       for (i=0; i<RTE_LOG_HISTORY; i++) {
> >
>

Re: [dpdk-dev] [PATCH v2] log: Properly reset log_history_size in rte_log_dump_history()

[Olivier MATZ]

On 06/01/2015 11:30 AM, Jan Blunck wrote:
> In rte_log_dump_history() the log_history list is reinitialized without
> resetting the log_history_size. In the next call to rte_log_add_in_history()
> the log_history_size > RTE_LOG_HISTORY and the code unconditionally tries
> to remove the first entry:
> 
> Program received signal SIGSEGV, Segmentation fault.
> rte_log_add_in_history (
>     buf=buf@entry=0x7f02035cd000 "DATAPLANE: 9:dp0s7 link RTM_NEWLINK [dp0s7] <UP,BROADCAST,RUNNING,MULTICAST,LOWER_UP>\nCAST,LOWER_UP>\n", size=size@entry=86)
>     at /usr/src/packages/BUILD/lib/librte_eal/common/eal_common_log.c:122
> 
> Signed-off-by: Jan Blunck <jblunck@infradead.org>

Acked-by: Olivier Matz <olivier.matz@6wind.com>



> ---
>  lib/librte_eal/common/eal_common_log.c | 6 +++++-
>  1 file changed, 5 insertions(+), 1 deletion(-)
> 
> diff --git a/lib/librte_eal/common/eal_common_log.c b/lib/librte_eal/common/eal_common_log.c
> index fe3d7d5..39d6e3f 100644
> --- a/lib/librte_eal/common/eal_common_log.c
> +++ b/lib/librte_eal/common/eal_common_log.c
> @@ -119,7 +119,10 @@ rte_log_add_in_history(const char *buf, size_t size)
>  	/* get a buffer for adding in history */
>  	if (log_history_size > RTE_LOG_HISTORY) {
>  		hist_buf = STAILQ_FIRST(&log_history);
> -		STAILQ_REMOVE_HEAD(&log_history, next);
> +		if (hist_buf) {
> +			STAILQ_REMOVE_HEAD(&log_history, next);
> +			log_history_size--;
> +		}
>  	}
>  	else {
>  		if (rte_mempool_mc_get(log_history_mp, &obj) < 0)
> @@ -234,6 +237,7 @@ rte_log_dump_history(FILE *out)
>  	rte_spinlock_lock(&log_list_lock);
>  	tmp_log_history = log_history;
>  	STAILQ_INIT(&log_history);
> +	log_history_size = 0;
>  	rte_spinlock_unlock(&log_list_lock);
>  
>  	for (i=0; i<RTE_LOG_HISTORY; i++) {
> 

Re: [dpdk-dev] [PATCH v2] log: Properly reset log_history_size in rte_log_dump_history()

[Thomas Monjalon]

2015-06-01 11:46, Olivier MATZ:
> On 06/01/2015 11:30 AM, Jan Blunck wrote:
> > In rte_log_dump_history() the log_history list is reinitialized without
> > resetting the log_history_size. In the next call to rte_log_add_in_history()
> > the log_history_size > RTE_LOG_HISTORY and the code unconditionally tries
> > to remove the first entry:
> > 
> > Program received signal SIGSEGV, Segmentation fault.
> > rte_log_add_in_history (
> >     buf=buf@entry=0x7f02035cd000 "DATAPLANE: 9:dp0s7 link RTM_NEWLINK [dp0s7] <UP,BROADCAST,RUNNING,MULTICAST,LOWER_UP>\nCAST,LOWER_UP>\n", size=size@entry=86)
> >     at /usr/src/packages/BUILD/lib/librte_eal/common/eal_common_log.c:122
> > 
> > Signed-off-by: Jan Blunck <jblunck@infradead.org>
> 
> Acked-by: Olivier Matz <olivier.matz@6wind.com>

Applied, thanks

Note: this is a good example of patch title renaming.
As it is a fix, it should start with "fix".
And in general, function name is not a good candidate for a short title.
It becomes:
	log: fix crash after dump
shorter and clearer ;)