linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH] tracing: Fix memleak due to race between current_tracer and trace
@ 2023-08-08  9:29 Zheng Yejian
  2023-08-16  1:45 ` Zheng Yejian
  0 siblings, 1 reply; 6+ messages in thread
From: Zheng Yejian @ 2023-08-08  9:29 UTC (permalink / raw)
  To: rostedt, mhiramat
  Cc: fweisbec, mingo, linux-kernel, linux-trace-kernel, zhengyejian1

Kmemleak report a leak in graph_trace_open():

  unreferenced object 0xffff0040b95f4a00 (size 128):
    comm "cat", pid 204981, jiffies 4301155872 (age 99771.964s)
    hex dump (first 32 bytes):
      e0 05 e7 b4 ab 7d 00 00 0b 00 01 00 00 00 00 00 .....}..........
      f4 00 01 10 00 a0 ff ff 00 00 00 00 65 00 10 00 ............e...
    backtrace:
      [<000000005db27c8b>] kmem_cache_alloc_trace+0x348/0x5f0
      [<000000007df90faa>] graph_trace_open+0xb0/0x344
      [<00000000737524cd>] __tracing_open+0x450/0xb10
      [<0000000098043327>] tracing_open+0x1a0/0x2a0
      [<00000000291c3876>] do_dentry_open+0x3c0/0xdc0
      [<000000004015bcd6>] vfs_open+0x98/0xd0
      [<000000002b5f60c9>] do_open+0x520/0x8d0
      [<00000000376c7820>] path_openat+0x1c0/0x3e0
      [<00000000336a54b5>] do_filp_open+0x14c/0x324
      [<000000002802df13>] do_sys_openat2+0x2c4/0x530
      [<0000000094eea458>] __arm64_sys_openat+0x130/0x1c4
      [<00000000a71d7881>] el0_svc_common.constprop.0+0xfc/0x394
      [<00000000313647bf>] do_el0_svc+0xac/0xec
      [<000000002ef1c651>] el0_svc+0x20/0x30
      [<000000002fd4692a>] el0_sync_handler+0xb0/0xb4
      [<000000000c309c35>] el0_sync+0x160/0x180

The root cause is descripted as follows:

  __tracing_open() {  // 1. File 'trace' is being opened;
    ...
    *iter->trace = *tr->current_trace;  // 2. Tracer 'function_graph' is
                                        //    currently set;
    ...
    iter->trace->open(iter);  // 3. Call graph_trace_open() here,
                              //    and memory are allocated in it;
    ...
  }

  s_start() {  // 4. The opened file is being read;
    ...
    *iter->trace = *tr->current_trace;  // 5. If tracer is switched to
                                        //    'nop' or others, then memory
                                        //    in step 3 are leaked!!!
    ...
  }

To fix it, in s_start(), close tracer before switching then reopen the
new tracer after switching.

Fixes: d7350c3f4569 ("tracing/core: make the read callbacks reentrants")
Signed-off-by: Zheng Yejian <zhengyejian1@huawei.com>
---
 kernel/trace/trace.c | 9 ++++++++-
 1 file changed, 8 insertions(+), 1 deletion(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index b8870078ef58..d50a0227baa3 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4213,8 +4213,15 @@ static void *s_start(struct seq_file *m, loff_t *pos)
 	 * will point to the same string as current_trace->name.
 	 */
 	mutex_lock(&trace_types_lock);
-	if (unlikely(tr->current_trace && iter->trace->name != tr->current_trace->name))
+	if (unlikely(tr->current_trace && iter->trace->name != tr->current_trace->name)) {
+		/* Close iter->trace before switching to the new current tracer */
+		if (iter->trace->close)
+			iter->trace->close(iter);
 		*iter->trace = *tr->current_trace;
+		/* Reopen the new current tracer */
+		if (iter->trace->open)
+			iter->trace->open(iter);
+	}
 	mutex_unlock(&trace_types_lock);
 
 #ifdef CONFIG_TRACER_MAX_TRACE
-- 
2.25.1


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

* Re: [PATCH] tracing: Fix memleak due to race between current_tracer and trace
  2023-08-08  9:29 [PATCH] tracing: Fix memleak due to race between current_tracer and trace Zheng Yejian
@ 2023-08-16  1:45 ` Zheng Yejian
  2023-08-16  4:27   ` Zheng Yejian
  0 siblings, 1 reply; 6+ messages in thread
From: Zheng Yejian @ 2023-08-16  1:45 UTC (permalink / raw)
  To: rostedt, mhiramat; +Cc: fweisbec, mingo, linux-kernel, linux-trace-kernel

On 2023/8/8 17:29, Zheng Yejian wrote:
> Kmemleak report a leak in graph_trace_open():
> 
>    unreferenced object 0xffff0040b95f4a00 (size 128):
>      comm "cat", pid 204981, jiffies 4301155872 (age 99771.964s)
>      hex dump (first 32 bytes):
>        e0 05 e7 b4 ab 7d 00 00 0b 00 01 00 00 00 00 00 .....}..........
>        f4 00 01 10 00 a0 ff ff 00 00 00 00 65 00 10 00 ............e...
>      backtrace:
>        [<000000005db27c8b>] kmem_cache_alloc_trace+0x348/0x5f0
>        [<000000007df90faa>] graph_trace_open+0xb0/0x344
>        [<00000000737524cd>] __tracing_open+0x450/0xb10
>        [<0000000098043327>] tracing_open+0x1a0/0x2a0
>        [<00000000291c3876>] do_dentry_open+0x3c0/0xdc0
>        [<000000004015bcd6>] vfs_open+0x98/0xd0
>        [<000000002b5f60c9>] do_open+0x520/0x8d0
>        [<00000000376c7820>] path_openat+0x1c0/0x3e0
>        [<00000000336a54b5>] do_filp_open+0x14c/0x324
>        [<000000002802df13>] do_sys_openat2+0x2c4/0x530
>        [<0000000094eea458>] __arm64_sys_openat+0x130/0x1c4
>        [<00000000a71d7881>] el0_svc_common.constprop.0+0xfc/0x394
>        [<00000000313647bf>] do_el0_svc+0xac/0xec
>        [<000000002ef1c651>] el0_svc+0x20/0x30
>        [<000000002fd4692a>] el0_sync_handler+0xb0/0xb4
>        [<000000000c309c35>] el0_sync+0x160/0x180
> 
> The root cause is descripted as follows:
> 
>    __tracing_open() {  // 1. File 'trace' is being opened;
>      ...
>      *iter->trace = *tr->current_trace;  // 2. Tracer 'function_graph' is
>                                          //    currently set;
>      ...
>      iter->trace->open(iter);  // 3. Call graph_trace_open() here,
>                                //    and memory are allocated in it;
>      ...
>    }
> 
>    s_start() {  // 4. The opened file is being read;
>      ...
>      *iter->trace = *tr->current_trace;  // 5. If tracer is switched to
>                                          //    'nop' or others, then memory
>                                          //    in step 3 are leaked!!!
>      ...
>    }
> 
> To fix it, in s_start(), close tracer before switching then reopen the
> new tracer after switching.
> 
> Fixes: d7350c3f4569 ("tracing/core: make the read callbacks reentrants")
> Signed-off-by: Zheng Yejian <zhengyejian1@huawei.com>
> ---
>   kernel/trace/trace.c | 9 ++++++++-
>   1 file changed, 8 insertions(+), 1 deletion(-)
> 
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index b8870078ef58..d50a0227baa3 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -4213,8 +4213,15 @@ static void *s_start(struct seq_file *m, loff_t *pos)
>   	 * will point to the same string as current_trace->name.
>   	 */
>   	mutex_lock(&trace_types_lock);
> -	if (unlikely(tr->current_trace && iter->trace->name != tr->current_trace->name))
> +	if (unlikely(tr->current_trace && iter->trace->name != tr->current_trace->name)) {
> +		/* Close iter->trace before switching to the new current tracer */
> +		if (iter->trace->close)
> +			iter->trace->close(iter);

Hi, kasan report an issue related to this patch in v5.10, I'll handle
it and then send V2 if the patch needs to be changed.

   BUG: KASAN: use-after-free in graph_trace_close+0x78/0x7c
   Read of size 8 at addr ffff204054ca8f00 by task cat/193541
   [...]
   Call trace:
    dump_backtrace+0x0/0x3e4
    show_stack+0x20/0x2c
    dump_stack+0x140/0x198
    print_address_description.constprop.0+0x2c/0x1fc
    __kasan_report+0xe0/0x140
    kasan_report+0x44/0x5c
    __asan_report_load8_noabort+0x34/0x60
    graph_trace_close+0x78/0x7c
    wakeup_trace_close+0x3c/0x54
    s_start+0x4f4/0x794
    seq_read_iter+0x210/0xd90
    seq_read+0x288/0x410
    vfs_read+0x13c/0x41c
    ksys_read+0xf4/0x1e0
    __arm64_sys_read+0x74/0xa4
    el0_svc_common.constprop.0+0xfc/0x394
    do_el0_svc+0xac/0xec
    el0_svc+0x20/0x30
    el0_sync_handler+0xb0/0xb4
    el0_sync+0x160/0x180

   Allocated by task 193541:
    kasan_save_stack+0x28/0x60
    __kasan_kmalloc.constprop.0+0xa4/0xd0
    kasan_kmalloc+0x10/0x20
    kmem_cache_alloc_trace+0x2ec/0x5f0
    graph_trace_open+0xb0/0x344
    __tracing_open+0x450/0xb10
    tracing_open+0x1a0/0x2a0
    do_dentry_open+0x3c0/0xdc0
    vfs_open+0x98/0xd0
    do_open+0x520/0x8d0

>   		*iter->trace = *tr->current_trace;
> +		/* Reopen the new current tracer */
> +		if (iter->trace->open)
> +			iter->trace->open(iter);
> +	}
>   	mutex_unlock(&trace_types_lock);
>   
>   #ifdef CONFIG_TRACER_MAX_TRACE


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

* Re: [PATCH] tracing: Fix memleak due to race between current_tracer and trace
  2023-08-16  1:45 ` Zheng Yejian
@ 2023-08-16  4:27   ` Zheng Yejian
  2023-08-16  5:43     ` [PATCH v2] " Zheng Yejian
  0 siblings, 1 reply; 6+ messages in thread
From: Zheng Yejian @ 2023-08-16  4:27 UTC (permalink / raw)
  To: rostedt, mhiramat; +Cc: fweisbec, linux-kernel, linux-trace-kernel

On 2023/8/16 09:45, Zheng Yejian wrote:
> On 2023/8/8 17:29, Zheng Yejian wrote:
>> Kmemleak report a leak in graph_trace_open():
>>
>>    unreferenced object 0xffff0040b95f4a00 (size 128):
>>      comm "cat", pid 204981, jiffies 4301155872 (age 99771.964s)
>>      hex dump (first 32 bytes):
>>        e0 05 e7 b4 ab 7d 00 00 0b 00 01 00 00 00 00 00 .....}..........
>>        f4 00 01 10 00 a0 ff ff 00 00 00 00 65 00 10 00 ............e...
>>      backtrace:
>>        [<000000005db27c8b>] kmem_cache_alloc_trace+0x348/0x5f0
>>        [<000000007df90faa>] graph_trace_open+0xb0/0x344
>>        [<00000000737524cd>] __tracing_open+0x450/0xb10
>>        [<0000000098043327>] tracing_open+0x1a0/0x2a0
>>        [<00000000291c3876>] do_dentry_open+0x3c0/0xdc0
>>        [<000000004015bcd6>] vfs_open+0x98/0xd0
>>        [<000000002b5f60c9>] do_open+0x520/0x8d0
>>        [<00000000376c7820>] path_openat+0x1c0/0x3e0
>>        [<00000000336a54b5>] do_filp_open+0x14c/0x324
>>        [<000000002802df13>] do_sys_openat2+0x2c4/0x530
>>        [<0000000094eea458>] __arm64_sys_openat+0x130/0x1c4
>>        [<00000000a71d7881>] el0_svc_common.constprop.0+0xfc/0x394
>>        [<00000000313647bf>] do_el0_svc+0xac/0xec
>>        [<000000002ef1c651>] el0_svc+0x20/0x30
>>        [<000000002fd4692a>] el0_sync_handler+0xb0/0xb4
>>        [<000000000c309c35>] el0_sync+0x160/0x180
>>
>> The root cause is descripted as follows:
>>
>>    __tracing_open() {  // 1. File 'trace' is being opened;
>>      ...
>>      *iter->trace = *tr->current_trace;  // 2. Tracer 'function_graph' is
>>                                          //    currently set;
>>      ...
>>      iter->trace->open(iter);  // 3. Call graph_trace_open() here,
>>                                //    and memory are allocated in it;
>>      ...
>>    }
>>
>>    s_start() {  // 4. The opened file is being read;
>>      ...
>>      *iter->trace = *tr->current_trace;  // 5. If tracer is switched to
>>                                          //    'nop' or others, then 
>> memory
>>                                          //    in step 3 are leaked!!!
>>      ...
>>    }
>>
>> To fix it, in s_start(), close tracer before switching then reopen the
>> new tracer after switching.
>>
>> Fixes: d7350c3f4569 ("tracing/core: make the read callbacks reentrants")
>> Signed-off-by: Zheng Yejian <zhengyejian1@huawei.com>
>> ---
>>   kernel/trace/trace.c | 9 ++++++++-
>>   1 file changed, 8 insertions(+), 1 deletion(-)
>>
>> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
>> index b8870078ef58..d50a0227baa3 100644
>> --- a/kernel/trace/trace.c
>> +++ b/kernel/trace/trace.c
>> @@ -4213,8 +4213,15 @@ static void *s_start(struct seq_file *m, loff_t 
>> *pos)
>>        * will point to the same string as current_trace->name.
>>        */
>>       mutex_lock(&trace_types_lock);
>> -    if (unlikely(tr->current_trace && iter->trace->name != 
>> tr->current_trace->name))
>> +    if (unlikely(tr->current_trace && iter->trace->name != 
>> tr->current_trace->name)) {
>> +        /* Close iter->trace before switching to the new current 
>> tracer */
>> +        if (iter->trace->close)
>> +            iter->trace->close(iter);
> 
> Hi, kasan report an issue related to this patch in v5.10, I'll handle
> it and then send V2 if the patch needs to be changed.
> 
>    BUG: KASAN: use-after-free in graph_trace_close+0x78/0x7c
>    Read of size 8 at addr ffff204054ca8f00 by task cat/193541
>    [...]
>    Call trace:
>     dump_backtrace+0x0/0x3e4
>     show_stack+0x20/0x2c
>     dump_stack+0x140/0x198
>     print_address_description.constprop.0+0x2c/0x1fc
>     __kasan_report+0xe0/0x140
>     kasan_report+0x44/0x5c
>     __asan_report_load8_noabort+0x34/0x60
>     graph_trace_close+0x78/0x7c
>     wakeup_trace_close+0x3c/0x54
>     s_start+0x4f4/0x794
>     seq_read_iter+0x210/0xd90
>     seq_read+0x288/0x410
>     vfs_read+0x13c/0x41c
>     ksys_read+0xf4/0x1e0
>     __arm64_sys_read+0x74/0xa4
>     el0_svc_common.constprop.0+0xfc/0x394
>     do_el0_svc+0xac/0xec
>     el0_svc+0x20/0x30
>     el0_sync_handler+0xb0/0xb4
>     el0_sync+0x160/0x180
> 
>    Allocated by task 193541:
>     kasan_save_stack+0x28/0x60
>     __kasan_kmalloc.constprop.0+0xa4/0xd0
>     kasan_kmalloc+0x10/0x20
>     kmem_cache_alloc_trace+0x2ec/0x5f0
>     graph_trace_open+0xb0/0x344
>     __tracing_open+0x450/0xb10
>     tracing_open+0x1a0/0x2a0
>     do_dentry_open+0x3c0/0xdc0
>     vfs_open+0x98/0xd0
>     do_open+0x520/0x8d0
> 

The root cause should be that:
   1. As __tracing_open() being called, function graph tracer is set,
      then graph_trace_open() is called;
   2. As s_start() being called, switch to wakeup tracer, then
      graph_trace_close() is called, here 'iter->private' is not cleared.
      Then wakeup_trace_open() is called, and if graph_trace_open() is
      not called by it due to is_graph(iter->tr) returns false;
   3. As next time s_start() being called, if tracer switched again then
      wakeup_trace_close() is called and it mistakenly close the
      'iter->private' in step 2 which finally causes kasan do the report.

So we may also need to set 'iter->private' to be NULL in
graph_trace_close(), I'll send v2 soon.

--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -1244,6 +1244,7 @@ void graph_trace_close(struct trace_iterator *iter)
         if (data) {
                 free_percpu(data->cpu_data);
                 kfree(data);
+               iter->private = NULL;
         }
  }

-- Zheng Yejian

>>           *iter->trace = *tr->current_trace;
>> +        /* Reopen the new current tracer */
>> +        if (iter->trace->open)
>> +            iter->trace->open(iter);
>> +    }
>>       mutex_unlock(&trace_types_lock);
>>   #ifdef CONFIG_TRACER_MAX_TRACE
> 
> 


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

* [PATCH v2] tracing: Fix memleak due to race between current_tracer and trace
  2023-08-16  4:27   ` Zheng Yejian
@ 2023-08-16  5:43     ` Zheng Yejian
  2023-08-16 13:49       ` Steven Rostedt
  0 siblings, 1 reply; 6+ messages in thread
From: Zheng Yejian @ 2023-08-16  5:43 UTC (permalink / raw)
  To: zhengyejian1
  Cc: fweisbec, linux-kernel, linux-trace-kernel, mhiramat, rostedt

Kmemleak report a leak in graph_trace_open():

  unreferenced object 0xffff0040b95f4a00 (size 128):
    comm "cat", pid 204981, jiffies 4301155872 (age 99771.964s)
    hex dump (first 32 bytes):
      e0 05 e7 b4 ab 7d 00 00 0b 00 01 00 00 00 00 00 .....}..........
      f4 00 01 10 00 a0 ff ff 00 00 00 00 65 00 10 00 ............e...
    backtrace:
      [<000000005db27c8b>] kmem_cache_alloc_trace+0x348/0x5f0
      [<000000007df90faa>] graph_trace_open+0xb0/0x344
      [<00000000737524cd>] __tracing_open+0x450/0xb10
      [<0000000098043327>] tracing_open+0x1a0/0x2a0
      [<00000000291c3876>] do_dentry_open+0x3c0/0xdc0
      [<000000004015bcd6>] vfs_open+0x98/0xd0
      [<000000002b5f60c9>] do_open+0x520/0x8d0
      [<00000000376c7820>] path_openat+0x1c0/0x3e0
      [<00000000336a54b5>] do_filp_open+0x14c/0x324
      [<000000002802df13>] do_sys_openat2+0x2c4/0x530
      [<0000000094eea458>] __arm64_sys_openat+0x130/0x1c4
      [<00000000a71d7881>] el0_svc_common.constprop.0+0xfc/0x394
      [<00000000313647bf>] do_el0_svc+0xac/0xec
      [<000000002ef1c651>] el0_svc+0x20/0x30
      [<000000002fd4692a>] el0_sync_handler+0xb0/0xb4
      [<000000000c309c35>] el0_sync+0x160/0x180

The root cause is descripted as follows:

  __tracing_open() {  // 1. File 'trace' is being opened;
    ...
    *iter->trace = *tr->current_trace;  // 2. Tracer 'function_graph' is
                                        //    currently set;
    ...
    iter->trace->open(iter);  // 3. Call graph_trace_open() here,
                              //    and memory are allocated in it;
    ...
  }

  s_start() {  // 4. The opened file is being read;
    ...
    *iter->trace = *tr->current_trace;  // 5. If tracer is switched to
                                        //    'nop' or others, then memory
                                        //    in step 3 are leaked!!!
    ...
  }

To fix it, in s_start(), close tracer before switching then reopen the
new tracer after switching. And some tracers like 'wakeup' may not update
'iter->private' in some cases when reopen, so clear 'iter->private' in
graph_trace_close() to avoid it being mistakenly closed again.

Fixes: d7350c3f4569 ("tracing/core: make the read callbacks reentrants")
Signed-off-by: Zheng Yejian <zhengyejian1@huawei.com>
---

v2:
  - Fix an use-after-free issue which is due to some tracers like 'wakeup'
    may not update 'iter->private' in some cases when reopen, so clear
    'iter->private' in graph_trace_close() to avoid it being mistakenly
    closed again. Also update the commit message.
    Link: https://lore.kernel.org/all/8c853c0c-84f0-c8be-3020-561db6f87081@huawei.com/

v1:
  - Link: https://lore.kernel.org/all/20230808092905.2936459-1-zhengyejian1@huawei.com/

 kernel/trace/trace.c                 | 9 ++++++++-
 kernel/trace/trace_functions_graph.c | 1 +
 2 files changed, 9 insertions(+), 1 deletion(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index b8870078ef58..d50a0227baa3 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4213,8 +4213,15 @@ static void *s_start(struct seq_file *m, loff_t *pos)
 	 * will point to the same string as current_trace->name.
 	 */
 	mutex_lock(&trace_types_lock);
-	if (unlikely(tr->current_trace && iter->trace->name != tr->current_trace->name))
+	if (unlikely(tr->current_trace && iter->trace->name != tr->current_trace->name)) {
+		/* Close iter->trace before switching to the new current tracer */
+		if (iter->trace->close)
+			iter->trace->close(iter);
 		*iter->trace = *tr->current_trace;
+		/* Reopen the new current tracer */
+		if (iter->trace->open)
+			iter->trace->open(iter);
+	}
 	mutex_unlock(&trace_types_lock);
 
 #ifdef CONFIG_TRACER_MAX_TRACE
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index c35fbaab2a47..4d4808186a0f 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -1317,6 +1317,7 @@ void graph_trace_close(struct trace_iterator *iter)
 	if (data) {
 		free_percpu(data->cpu_data);
 		kfree(data);
+		iter->private = NULL;
 	}
 }
 
-- 
2.25.1


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

* Re: [PATCH v2] tracing: Fix memleak due to race between current_tracer and trace
  2023-08-16  5:43     ` [PATCH v2] " Zheng Yejian
@ 2023-08-16 13:49       ` Steven Rostedt
  2023-08-17 12:55         ` [PATCH v3] " Zheng Yejian
  0 siblings, 1 reply; 6+ messages in thread
From: Steven Rostedt @ 2023-08-16 13:49 UTC (permalink / raw)
  To: Zheng Yejian; +Cc: fweisbec, linux-kernel, linux-trace-kernel, mhiramat

On Wed, 16 Aug 2023 13:43:57 +0800
Zheng Yejian <zhengyejian1@huawei.com> wrote:

> Kmemleak report a leak in graph_trace_open():
> 
>   unreferenced object 0xffff0040b95f4a00 (size 128):
>     comm "cat", pid 204981, jiffies 4301155872 (age 99771.964s)
>     hex dump (first 32 bytes):
>       e0 05 e7 b4 ab 7d 00 00 0b 00 01 00 00 00 00 00 .....}..........
>       f4 00 01 10 00 a0 ff ff 00 00 00 00 65 00 10 00 ............e...
>     backtrace:
>       [<000000005db27c8b>] kmem_cache_alloc_trace+0x348/0x5f0
>       [<000000007df90faa>] graph_trace_open+0xb0/0x344
>       [<00000000737524cd>] __tracing_open+0x450/0xb10
>       [<0000000098043327>] tracing_open+0x1a0/0x2a0
>       [<00000000291c3876>] do_dentry_open+0x3c0/0xdc0
>       [<000000004015bcd6>] vfs_open+0x98/0xd0
>       [<000000002b5f60c9>] do_open+0x520/0x8d0
>       [<00000000376c7820>] path_openat+0x1c0/0x3e0
>       [<00000000336a54b5>] do_filp_open+0x14c/0x324
>       [<000000002802df13>] do_sys_openat2+0x2c4/0x530
>       [<0000000094eea458>] __arm64_sys_openat+0x130/0x1c4
>       [<00000000a71d7881>] el0_svc_common.constprop.0+0xfc/0x394
>       [<00000000313647bf>] do_el0_svc+0xac/0xec
>       [<000000002ef1c651>] el0_svc+0x20/0x30
>       [<000000002fd4692a>] el0_sync_handler+0xb0/0xb4
>       [<000000000c309c35>] el0_sync+0x160/0x180
> 
> The root cause is descripted as follows:
> 
>   __tracing_open() {  // 1. File 'trace' is being opened;
>     ...
>     *iter->trace = *tr->current_trace;  // 2. Tracer 'function_graph' is
>                                         //    currently set;
>     ...
>     iter->trace->open(iter);  // 3. Call graph_trace_open() here,
>                               //    and memory are allocated in it;
>     ...
>   }
> 
>   s_start() {  // 4. The opened file is being read;
>     ...
>     *iter->trace = *tr->current_trace;  // 5. If tracer is switched to
>                                         //    'nop' or others, then memory
>                                         //    in step 3 are leaked!!!
>     ...
>   }
> 
> To fix it, in s_start(), close tracer before switching then reopen the
> new tracer after switching. And some tracers like 'wakeup' may not update
> 'iter->private' in some cases when reopen, so clear 'iter->private' in
> graph_trace_close() to avoid it being mistakenly closed again.
> 
> Fixes: d7350c3f4569 ("tracing/core: make the read callbacks reentrants")
> Signed-off-by: Zheng Yejian <zhengyejian1@huawei.com>
> ---
> 
> v2:
>   - Fix an use-after-free issue which is due to some tracers like 'wakeup'
>     may not update 'iter->private' in some cases when reopen, so clear
>     'iter->private' in graph_trace_close() to avoid it being mistakenly
>     closed again. Also update the commit message.
>     Link: https://lore.kernel.org/all/8c853c0c-84f0-c8be-3020-561db6f87081@huawei.com/
> 
> v1:
>   - Link: https://lore.kernel.org/all/20230808092905.2936459-1-zhengyejian1@huawei.com/
> 
>  kernel/trace/trace.c                 | 9 ++++++++-
>  kernel/trace/trace_functions_graph.c | 1 +
>  2 files changed, 9 insertions(+), 1 deletion(-)
> 
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index b8870078ef58..d50a0227baa3 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -4213,8 +4213,15 @@ static void *s_start(struct seq_file *m, loff_t *pos)
>  	 * will point to the same string as current_trace->name.
>  	 */
>  	mutex_lock(&trace_types_lock);
> -	if (unlikely(tr->current_trace && iter->trace->name != tr->current_trace->name))
> +	if (unlikely(tr->current_trace && iter->trace->name != tr->current_trace->name)) {
> +		/* Close iter->trace before switching to the new current tracer */
> +		if (iter->trace->close)
> +			iter->trace->close(iter);
>  		*iter->trace = *tr->current_trace;
> +		/* Reopen the new current tracer */
> +		if (iter->trace->open)
> +			iter->trace->open(iter);
> +	}
>  	mutex_unlock(&trace_types_lock);
>  
>  #ifdef CONFIG_TRACER_MAX_TRACE
> diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> index c35fbaab2a47..4d4808186a0f 100644
> --- a/kernel/trace/trace_functions_graph.c
> +++ b/kernel/trace/trace_functions_graph.c
> @@ -1317,6 +1317,7 @@ void graph_trace_close(struct trace_iterator *iter)
>  	if (data) {
>  		free_percpu(data->cpu_data);
>  		kfree(data);
> +		iter->private = NULL;

This is the wrong place to clear private. It shouldn't be up to
function_graph tracer to know to clear it so that it doesn't break other
tracers.

If the wakeup function requires iter->private to be NULL, then it should
clear it on open.

-- Steve



>  	}
>  }
>  


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

* [PATCH v3] tracing: Fix memleak due to race between current_tracer and trace
  2023-08-16 13:49       ` Steven Rostedt
@ 2023-08-17 12:55         ` Zheng Yejian
  0 siblings, 0 replies; 6+ messages in thread
From: Zheng Yejian @ 2023-08-17 12:55 UTC (permalink / raw)
  To: rostedt
  Cc: fweisbec, linux-kernel, linux-trace-kernel, mhiramat, zhengyejian1

Kmemleak report a leak in graph_trace_open():

  unreferenced object 0xffff0040b95f4a00 (size 128):
    comm "cat", pid 204981, jiffies 4301155872 (age 99771.964s)
    hex dump (first 32 bytes):
      e0 05 e7 b4 ab 7d 00 00 0b 00 01 00 00 00 00 00 .....}..........
      f4 00 01 10 00 a0 ff ff 00 00 00 00 65 00 10 00 ............e...
    backtrace:
      [<000000005db27c8b>] kmem_cache_alloc_trace+0x348/0x5f0
      [<000000007df90faa>] graph_trace_open+0xb0/0x344
      [<00000000737524cd>] __tracing_open+0x450/0xb10
      [<0000000098043327>] tracing_open+0x1a0/0x2a0
      [<00000000291c3876>] do_dentry_open+0x3c0/0xdc0
      [<000000004015bcd6>] vfs_open+0x98/0xd0
      [<000000002b5f60c9>] do_open+0x520/0x8d0
      [<00000000376c7820>] path_openat+0x1c0/0x3e0
      [<00000000336a54b5>] do_filp_open+0x14c/0x324
      [<000000002802df13>] do_sys_openat2+0x2c4/0x530
      [<0000000094eea458>] __arm64_sys_openat+0x130/0x1c4
      [<00000000a71d7881>] el0_svc_common.constprop.0+0xfc/0x394
      [<00000000313647bf>] do_el0_svc+0xac/0xec
      [<000000002ef1c651>] el0_svc+0x20/0x30
      [<000000002fd4692a>] el0_sync_handler+0xb0/0xb4
      [<000000000c309c35>] el0_sync+0x160/0x180

The root cause is descripted as follows:

  __tracing_open() {  // 1. File 'trace' is being opened;
    ...
    *iter->trace = *tr->current_trace;  // 2. Tracer 'function_graph' is
                                        //    currently set;
    ...
    iter->trace->open(iter);  // 3. Call graph_trace_open() here,
                              //    and memory are allocated in it;
    ...
  }

  s_start() {  // 4. The opened file is being read;
    ...
    *iter->trace = *tr->current_trace;  // 5. If tracer is switched to
                                        //    'nop' or others, then memory
                                        //    in step 3 are leaked!!!
    ...
  }

To fix it, in s_start(), close tracer before switching then reopen the
new tracer after switching. And some tracers like 'wakeup' may not update
'iter->private' in some cases when reopen, then it should be cleared
to avoid being mistakenly closed again.

Fixes: d7350c3f4569 ("tracing/core: make the read callbacks reentrants")
Signed-off-by: Zheng Yejian <zhengyejian1@huawei.com>
---

v3:
  - In wakeup_trace_open() and irqsoff_trace_open(), set 'iter->private' to
    be NULL if graph_trace_open() not called as suggested by Steve.
    Also update the commit message.
    Link: https://lore.kernel.org/all/20230816094927.2b9e9436@gandalf.local.home/#t

v2:
  - Link: https://lore.kernel.org/all/20230816054357.1188339-1-zhengyejian1@huawei.com/
  - Fix an use-after-free issue which is due to some tracers like 'wakeup'
    may not update 'iter->private' in some cases when reopen, so clear
    'iter->private' in graph_trace_close() to avoid it being mistakenly
    closed again. Also update the commit message.
    Link: https://lore.kernel.org/all/8c853c0c-84f0-c8be-3020-561db6f87081@huawei.com/

v1:
  - Link: https://lore.kernel.org/all/20230808092905.2936459-1-zhengyejian1@huawei.com/

 kernel/trace/trace.c              | 9 ++++++++-
 kernel/trace/trace_irqsoff.c      | 3 ++-
 kernel/trace/trace_sched_wakeup.c | 2 ++
 3 files changed, 12 insertions(+), 2 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index b8870078ef58..d50a0227baa3 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4213,8 +4213,15 @@ static void *s_start(struct seq_file *m, loff_t *pos)
 	 * will point to the same string as current_trace->name.
 	 */
 	mutex_lock(&trace_types_lock);
-	if (unlikely(tr->current_trace && iter->trace->name != tr->current_trace->name))
+	if (unlikely(tr->current_trace && iter->trace->name != tr->current_trace->name)) {
+		/* Close iter->trace before switching to the new current tracer */
+		if (iter->trace->close)
+			iter->trace->close(iter);
 		*iter->trace = *tr->current_trace;
+		/* Reopen the new current tracer */
+		if (iter->trace->open)
+			iter->trace->open(iter);
+	}
 	mutex_unlock(&trace_types_lock);
 
 #ifdef CONFIG_TRACER_MAX_TRACE
diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
index 590b3d51afae..ba37f768e2f2 100644
--- a/kernel/trace/trace_irqsoff.c
+++ b/kernel/trace/trace_irqsoff.c
@@ -231,7 +231,8 @@ static void irqsoff_trace_open(struct trace_iterator *iter)
 {
 	if (is_graph(iter->tr))
 		graph_trace_open(iter);
-
+	else
+		iter->private = NULL;
 }
 
 static void irqsoff_trace_close(struct trace_iterator *iter)
diff --git a/kernel/trace/trace_sched_wakeup.c b/kernel/trace/trace_sched_wakeup.c
index 330aee1c1a49..0469a04a355f 100644
--- a/kernel/trace/trace_sched_wakeup.c
+++ b/kernel/trace/trace_sched_wakeup.c
@@ -168,6 +168,8 @@ static void wakeup_trace_open(struct trace_iterator *iter)
 {
 	if (is_graph(iter->tr))
 		graph_trace_open(iter);
+	else
+		iter->private = NULL;
 }
 
 static void wakeup_trace_close(struct trace_iterator *iter)
-- 
2.25.1


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

end of thread, other threads:[~2023-08-17 12:57 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2023-08-08  9:29 [PATCH] tracing: Fix memleak due to race between current_tracer and trace Zheng Yejian
2023-08-16  1:45 ` Zheng Yejian
2023-08-16  4:27   ` Zheng Yejian
2023-08-16  5:43     ` [PATCH v2] " Zheng Yejian
2023-08-16 13:49       ` Steven Rostedt
2023-08-17 12:55         ` [PATCH v3] " Zheng Yejian

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).