[PATCH dpdk] log: fix double free on cleanup

[PATCH dpdk] log: fix double free on cleanup

[Robin Jarry]

Fix the following crash when closing a log file after rte_eal_cleanup():

    double free or corruption (!prev)

    Thread 1 "grout" received signal SIGABRT, Aborted.
    __pthread_kill_implementation (threadid=<optimized out>,
    signo=signo@entry=6, no_tid=no_tid@entry=0) at pthread_kill.c:44
    ...
    #10 _IO_new_fclose (fp=0xb63090) at iofclose.c:74
    #11 0x000000000049c04e in dpdk_fini () at ../main/dpdk.c:204
    #12 0x0000000000402ab8 in main (...) at ../main/main.c:217
    (gdb) up 11
    #11 0x000000000049c04e in dpdk_fini () at ../main/dpdk.c:204
    202             rte_eal_cleanup();
    203             if (log_stream != NULL)
    204                     fclose(log_stream);

When the application has passed a custom file via rte_openlog_stream()
DPDK should not call fclose() on it.

Add an internal is_internal_file field to track whether the file has
been allocated by DPDK (syslog or journald) to determine if it should be
closed or not.

Fixes: 985130369be3 ("log: rework syslog handling")
Signed-off-by: Robin Jarry <rjarry@redhat.com>
---
 lib/log/log.c | 14 ++++++++------
 1 file changed, 8 insertions(+), 6 deletions(-)

diff --git a/lib/log/log.c b/lib/log/log.c
index eb087d601e8b..e1c18a8e5351 100644
--- a/lib/log/log.c
+++ b/lib/log/log.c
@@ -38,6 +38,7 @@ static struct rte_logs {
 	uint32_t type;  /**< Bitfield with enabled logs. */
 	uint32_t level; /**< Log level. */
 	FILE *file;     /**< Output file set by rte_openlog_stream, or NULL. */
+	bool is_internal_file;
 	log_print_t print_func;
 	size_t dynamic_types_len;
 	struct rte_log_dynamic_type *dynamic_types;
@@ -80,8 +81,11 @@ static RTE_DEFINE_PER_LCORE(struct log_cur_msg, log_cur_msg);
 int
 rte_openlog_stream(FILE *f)
 {
+	if (rte_logs.is_internal_file && rte_logs.file != NULL)
+		fclose(rte_logs.file);
 	rte_logs.file = f;
 	rte_logs.print_func = vfprintf;
+	rte_logs.is_internal_file = false;
 	return 0;
 }
 
@@ -520,6 +524,7 @@ eal_log_init(const char *id)
 		/* if either syslog or journal is used, then no special handling */
 		if (logf) {
 			rte_openlog_stream(logf);
+			rte_logs.is_internal_file = true;
 		} else {
 			bool is_terminal = isatty(fileno(stderr));
 			bool use_color = log_color_enabled(is_terminal);
@@ -550,11 +555,8 @@ eal_log_init(const char *id)
 void
 rte_eal_log_cleanup(void)
 {
-	FILE *log_stream = rte_logs.file;
-
-	/* don't close stderr on the application */
-	if (log_stream != NULL)
-		fclose(log_stream);
-
+	if (rte_logs.is_internal_file && rte_logs.file != NULL)
+		fclose(rte_logs.file);
 	rte_logs.file = NULL;
+	rte_logs.is_internal_file = false;
 }
-- 
2.47.1

Re: [PATCH dpdk] log: fix double free on cleanup

[Stephen Hemminger]

On Fri, 29 Nov 2024 17:10:14 +0100
Robin Jarry <rjarry@redhat.com> wrote:

> @@ -550,11 +555,8 @@ eal_log_init(const char *id)
>  void
>  rte_eal_log_cleanup(void)
>  {
> -	FILE *log_stream = rte_logs.file;
> -
> -	/* don't close stderr on the application */
> -	if (log_stream != NULL)
> -		fclose(log_stream);
> -
> +	if (rte_logs.is_internal_file && rte_logs.file != NULL)
> +		fclose(rte_logs.file);
>  	rte_logs.file = NULL;
> +	rte_logs.is_internal_file = false;
>  }

The internal flag is ok, but we still don't want to close
stderr in cleanup. Only places where syslog or journal wrapper is used.

Re: [PATCH dpdk] log: fix double free on cleanup

[Stephen Hemminger]

On Fri, 29 Nov 2024 17:10:14 +0100
Robin Jarry <rjarry@redhat.com> wrote:

> Fix the following crash when closing a log file after rte_eal_cleanup():
> 
>     double free or corruption (!prev)
> 
>     Thread 1 "grout" received signal SIGABRT, Aborted.
>     __pthread_kill_implementation (threadid=<optimized out>,
>     signo=signo@entry=6, no_tid=no_tid@entry=0) at pthread_kill.c:44
>     ...
>     #10 _IO_new_fclose (fp=0xb63090) at iofclose.c:74
>     #11 0x000000000049c04e in dpdk_fini () at ../main/dpdk.c:204
>     #12 0x0000000000402ab8 in main (...) at ../main/main.c:217
>     (gdb) up 11
>     #11 0x000000000049c04e in dpdk_fini () at ../main/dpdk.c:204
>     202             rte_eal_cleanup();
>     203             if (log_stream != NULL)
>     204                     fclose(log_stream);
> 
> When the application has passed a custom file via rte_openlog_stream()
> DPDK should not call fclose() on it.
> 
> Add an internal is_internal_file field to track whether the file has
> been allocated by DPDK (syslog or journald) to determine if it should be
> closed or not.
> 
> Fixes: 985130369be3 ("log: rework syslog handling")
> Signed-off-by: Robin Jarry <rjarry@redhat.com>

Looks good, will look into adding more test cases for this in later release.

Reviewed-by: Stephen Hemminger <stephen@networkplumber.org>

Re: [PATCH dpdk] log: fix double free on cleanup

[Robin Jarry]

Stephen Hemminger, Nov 29, 2024 at 17:54:
> On Fri, 29 Nov 2024 17:10:14 +0100
> Robin Jarry <rjarry@redhat.com> wrote:
>
>> @@ -550,11 +555,8 @@ eal_log_init(const char *id)
>>  void
>>  rte_eal_log_cleanup(void)
>>  {
>> -	FILE *log_stream = rte_logs.file;
>> -
>> -	/* don't close stderr on the application */
>> -	if (log_stream != NULL)
>> -		fclose(log_stream);
>> -
>> +	if (rte_logs.is_internal_file && rte_logs.file != NULL)
>> +		fclose(rte_logs.file);
>>  	rte_logs.file = NULL;
>> +	rte_logs.is_internal_file = false;
>>  }
>
> The internal flag is ok, but we still don't want to close
> stderr in cleanup. Only places where syslog or journal wrapper is used.

There is no chance closing stderr will happen with my patch. stderr is 
only returned by rte_log_get_stream() when rte_logs.file is NULL, but 
rte_logs.file is not modified. It is only modified in eal_log_init() 
when --syslog or when running with journald. In both these cases, a new 
file is opened, not stderr.

Re: [PATCH dpdk] log: fix double free on cleanup

[David Marchand]

On Fri, Nov 29, 2024 at 6:01 PM Stephen Hemminger
<stephen@networkplumber.org> wrote:
> On Fri, 29 Nov 2024 17:10:14 +0100
> Robin Jarry <rjarry@redhat.com> wrote:
>
> > Fix the following crash when closing a log file after rte_eal_cleanup():
> >
> >     double free or corruption (!prev)
> >
> >     Thread 1 "grout" received signal SIGABRT, Aborted.
> >     __pthread_kill_implementation (threadid=<optimized out>,
> >     signo=signo@entry=6, no_tid=no_tid@entry=0) at pthread_kill.c:44
> >     ...
> >     #10 _IO_new_fclose (fp=0xb63090) at iofclose.c:74
> >     #11 0x000000000049c04e in dpdk_fini () at ../main/dpdk.c:204
> >     #12 0x0000000000402ab8 in main (...) at ../main/main.c:217
> >     (gdb) up 11
> >     #11 0x000000000049c04e in dpdk_fini () at ../main/dpdk.c:204
> >     202             rte_eal_cleanup();
> >     203             if (log_stream != NULL)
> >     204                     fclose(log_stream);
> >
> > When the application has passed a custom file via rte_openlog_stream()
> > DPDK should not call fclose() on it.
> >
> > Add an internal is_internal_file field to track whether the file has
> > been allocated by DPDK (syslog or journald) to determine if it should be
> > closed or not.
> >
> > Fixes: 985130369be3 ("log: rework syslog handling")

Added Cc: stable for 24.11 LTS.

> > Signed-off-by: Robin Jarry <rjarry@redhat.com>
> Reviewed-by: Stephen Hemminger <stephen@networkplumber.org>

Applied, thanks for the fix Robin.


-- 
David Marchand