[PATCH -next v2] ftrace: Fix potential warning in trace_printk_seq during ftrace_dump

[PATCH -next v2] ftrace: Fix potential warning in trace_printk_seq during ftrace_dump

[Tengda Wu]

When calling ftrace_dump_one() concurrently with reading trace_pipe,
a WARN_ON_ONCE() in trace_printk_seq() can be triggered due to a race
condition.

The issue occurs because:

CPU0 (ftrace_dump)                              CPU1 (reader)
echo z > /proc/sysrq-trigger

!trace_empty(&iter)
trace_iterator_reset(&iter) <- len = size = 0
                                                cat /sys/kernel/tracing/trace_pipe
trace_find_next_entry_inc(&iter)
  __find_next_entry
    ring_buffer_empty_cpu <- all empty
  return NULL

trace_printk_seq(&iter.seq)
  WARN_ON_ONCE(s->seq.len >= s->seq.size)

In the context between trace_empty() and trace_find_next_entry_inc()
during ftrace_dump, the ring buffer data was consumed by other readers.
This caused trace_find_next_entry_inc to return NULL, failing to populate
`iter.seq`. At this point, due to the prior trace_iterator_reset, both
`iter.seq.len` and `iter.seq.size` were set to 0. Since they are equal,
the WARN_ON_ONCE condition is triggered.

Add a non-NULL check on the return value of trace_find_next_entry_inc
prior to invoking trace_printk_seq, ensuring the `iter.seq` is properly
populated before subsequent operations.

Fixes: d769041f8653 ("ring_buffer: implement new locking")
Signed-off-by: Tengda Wu <wutengda@huaweicloud.com>
---
 kernel/trace/trace.c | 8 +++++---
 1 file changed, 5 insertions(+), 3 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 4283ed4e8f59..b4cec22753ea 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -10617,6 +10617,7 @@ static void ftrace_dump_one(struct trace_array *tr, enum ftrace_dump_mode dump_m
 	 */
 
 	while (!trace_empty(&iter)) {
+		void *ent;
 
 		if (!cnt)
 			printk(KERN_TRACE "---------------------------------\n");
@@ -10625,17 +10626,18 @@ static void ftrace_dump_one(struct trace_array *tr, enum ftrace_dump_mode dump_m
 
 		trace_iterator_reset(&iter);
 		iter.iter_flags |= TRACE_FILE_LAT_FMT;
+		ent = trace_find_next_entry_inc(&iter);
 
-		if (trace_find_next_entry_inc(&iter) != NULL) {
+		if (ent) {
 			int ret;
 
 			ret = print_trace_line(&iter);
 			if (ret != TRACE_TYPE_NO_CONSUME)
 				trace_consume(&iter);
+
+			trace_printk_seq(&iter.seq);
 		}
 		touch_nmi_watchdog();
-
-		trace_printk_seq(&iter.seq);
 	}
 
 	if (!cnt)
-- 
2.34.1

Re: [PATCH -next v2] ftrace: Fix potential warning in trace_printk_seq during ftrace_dump

[Steven Rostedt]

On Thu, 21 Aug 2025 02:11:20 +0000
Tengda Wu <wutengda@huaweicloud.com> wrote:

 tested this and was writing the change log for the pull request when I
realized an issue.

> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index 4283ed4e8f59..b4cec22753ea 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -10617,6 +10617,7 @@ static void ftrace_dump_one(struct trace_array *tr, enum ftrace_dump_mode dump_m
>  	 */
>  
>  	while (!trace_empty(&iter)) {
> +		void *ent;
>  
>  		if (!cnt)
>  			printk(KERN_TRACE "---------------------------------\n");
> @@ -10625,17 +10626,18 @@ static void ftrace_dump_one(struct trace_array *tr, enum ftrace_dump_mode dump_m
>  
>  		trace_iterator_reset(&iter);
>  		iter.iter_flags |= TRACE_FILE_LAT_FMT;
> +		ent = trace_find_next_entry_inc(&iter);
>  
> -		if (trace_find_next_entry_inc(&iter) != NULL) {
> +		if (ent) {

Why do we need "ent"?


>  			int ret;
>  
>  			ret = print_trace_line(&iter);
>  			if (ret != TRACE_TYPE_NO_CONSUME)
>  				trace_consume(&iter);
> +
> +			trace_printk_seq(&iter.seq);

Isn't just moving trace_printk_seq() enough?

The code is no different with or without the "ent" as "ent" is not used in
the if block.

-- Steve


>  		}
>  		touch_nmi_watchdog();
> -
> -		trace_printk_seq(&iter.seq);
>  	}
>  
>  	if (!cnt)

Re: [PATCH -next v2] ftrace: Fix potential warning in trace_printk_seq during ftrace_dump

[Tengda Wu]

On 2025/8/21 23:05, Steven Rostedt wrote:
> On Thu, 21 Aug 2025 02:11:20 +0000
> Tengda Wu <wutengda@huaweicloud.com> wrote:
> 
>  tested this and was writing the change log for the pull request when I
> realized an issue.
> 
>> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
>> index 4283ed4e8f59..b4cec22753ea 100644
>> --- a/kernel/trace/trace.c
>> +++ b/kernel/trace/trace.c
>> @@ -10617,6 +10617,7 @@ static void ftrace_dump_one(struct trace_array *tr, enum ftrace_dump_mode dump_m
>>  	 */
>>  
>>  	while (!trace_empty(&iter)) {
>> +		void *ent;
>>  
>>  		if (!cnt)
>>  			printk(KERN_TRACE "---------------------------------\n");
>> @@ -10625,17 +10626,18 @@ static void ftrace_dump_one(struct trace_array *tr, enum ftrace_dump_mode dump_m
>>  
>>  		trace_iterator_reset(&iter);
>>  		iter.iter_flags |= TRACE_FILE_LAT_FMT;
>> +		ent = trace_find_next_entry_inc(&iter);
>>  
>> -		if (trace_find_next_entry_inc(&iter) != NULL) {
>> +		if (ent) {
> 
> Why do we need "ent"?
> 
> 
>>  			int ret;
>>  
>>  			ret = print_trace_line(&iter);
>>  			if (ret != TRACE_TYPE_NO_CONSUME)
>>  				trace_consume(&iter);
>> +
>> +			trace_printk_seq(&iter.seq);
> 
> Isn't just moving trace_printk_seq() enough?
> 
> The code is no different with or without the "ent" as "ent" is not used in
> the if block.
> 
> -- Steve

I apologize, as this is a trace left over from the initial patch modification
process. While working with the original code, I added an `if (ent)` branch
directly to trace_printk_seq and later realized it could be merged with the
previous `if (ent)` branch. However, I forgot to remove the now-redundant ent
after the merge. 

I will correct this immediately and resend a new version.

-- Tengda



> 
> 
>>  		}
>>  		touch_nmi_watchdog();
>> -
>> -		trace_printk_seq(&iter.seq);
>>  	}
>>  
>>  	if (!cnt)