[PATCH] function_graph: Use the saved entry's size when reprinting it

[PATCH] function_graph: Use the saved entry's size when reprinting it

[Donggeun Yoo]

When a graph entry does not fit in the trace_seq, print_graph_entry()
saves it in the iterator's fgraph_data and reprints it on the next read.
The entry has already been consumed from the ring buffer by then, so the
copy is all that is left of it.

The copy is sized with iter->ent_size, which no longer describes the
saved entry but whatever entry the iterator has moved on to. The
argument count is derived from the same field, so a 72 byte entry saved
and then reprinted ahead of a 48 byte return entry loses its arguments.

Record the size next to the failure flag, so that the two are always set
together, and restore it before reprinting.

Fixes: ff5c9c576e75 ("ftrace: Add support for function argument to graph tracer")
Cc: stable@vger.kernel.org
Signed-off-by: Donggeun Yoo <donggeunyoo.kernel@gmail.com>
---
Reproduced under QEMU (x86_64 defconfig plus FTRACE, FUNCTION_GRAPH_TRACER,
DEBUG_INFO_BTF, 2 vCPUs). function_graph with funcgraph-args on, trace_pipe
read in 64K chunks 300 times from a static init:

  before: 271 reprints, 190 of them with a size that did not match the saved
          entry, 184 of those deciding the argument count the wrong way.
          _raw_spin_unlock() takes one argument and printed as
          "_raw_spin_unlock()" 19 times out of 2209.
  after:  same workload, 0 times.

Toggling funcgraph-args and funcgraph-retaddr during the run produces all four
entry sizes (24, 32, 72, 80 here) and they are all reprinted with their own.

No change in tools/testing/selftests/ftrace: 80 passed, 3 failed, 13 unresolved,
81 unsupported both with and without the patch, identical per test. The
in-kernel selftests pass, including "Testing tracer function_graph". A KASAN
build reports nothing on the same workload.

 kernel/trace/trace_functions_graph.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index ff7cb1a76b95..c5befd0c5b9a 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -52,6 +52,7 @@ struct fgraph_data {
 	};
 	struct ftrace_graph_ret_entry	ret;
 	int				failed;
+	int				ent_size;
 	int				cpu;
 };
 
@@ -1274,6 +1275,7 @@ print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
 		if (s->full) {
 			data->failed = 1;
 			data->cpu = cpu;
+			data->ent_size = iter->ent_size;
 		} else
 			data->failed = 0;
 	}
@@ -1457,6 +1459,7 @@ print_graph_function_flags(struct trace_iterator *iter, u32 flags)
 	if (data && data->failed) {
 		field = &data->ent.ent;
 		iter->cpu = data->cpu;
+		iter->ent_size = data->ent_size;
 		ret = print_graph_entry(field, s, iter, flags);
 		if (ret == TRACE_TYPE_HANDLED && iter->cpu != cpu) {
 			per_cpu_ptr(data->cpu_data, iter->cpu)->ignore = 1;
-- 
2.53.0

Re: [PATCH] function_graph: Use the saved entry's size when reprinting it

[sashiko-bot]

Thank you for your contribution! Sashiko AI review found 3 potential issue(s) to consider:

Pre-existing issues:
- [High] This problem wasn't introduced by this patch, but state desynchronization when reprinting a previously failed trace entry causes the current entry in the ring buffer to be incorrectly consumed and permanently dropped.
- [High] This problem wasn't introduced by this patch, but if the sequence buffer fills up while processing the final event in the ring buffer, `print_graph_entry()` records a failure state without saving the current entry, causing uninitialized or stale data reads.
- [High] This problem wasn't introduced by this patch, but the local variable `ret` in `print_graph_entry()` is declared as `static`, creating a data race when multiple trace instances or concurrent trace pipe readers are active.
--

commit ca8f0abc7d748db3bcb46f95c502d76a2725b949
Author: Donggeun Yoo <donggeunyoo.kernel@gmail.com>

function_graph: Use the saved entry's size when reprinting it

This patch fixes an issue where a saved graph entry was reprinted using the
size of the newly processed entry instead of its own original size. By
explicitly saving and restoring ent_size, it prevents argument loss or
truncation when reprinting.

> diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> index ff7cb1a76b953..c5befd0c5b9a2 100644
> --- a/kernel/trace/trace_functions_graph.c
> +++ b/kernel/trace/trace_functions_graph.c

[ ... ]

> @@ -1274,6 +1275,7 @@ print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
>  		if (s->full) {
>  			data->failed = 1;
>  			data->cpu = cpu;
> +			data->ent_size = iter->ent_size;

[Severity: High]
This isn't a bug introduced by this patch, but if the sequence buffer fills
up while processing the final event in the ring buffer, could this record a
failure state without saving the current entry, causing uninitialized or
stale data reads?

In get_return_for_leaf(), if the ring buffer is empty on peek, it returns
NULL early:

	if (!event)
		return NULL;

	next = ring_buffer_event_data(event);

	if (data) {
		/*
		 * Save current and next entries for later reference
		 * if the output fails.
		 */
		int size = min_t(int, sizeof(data->rent), iter->ent_size);

		memcpy(&data->rent, curr, size);

Because the memcpy() is bypassed on the last event, setting data->failed = 1
unconditionally here on buffer full assumes the entry was successfully saved.
On the next read iteration, the trace output may print uninitialized memory
from data->ent.ent.

[Severity: High]
This is a pre-existing issue, but does declaring ret as a static local
variable in print_graph_entry() create a data race?

static enum print_line_t
print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
			struct trace_iterator *iter, u32 flags)
{
	struct fgraph_data *data = iter->private;
	struct ftrace_graph_ent *call;
	struct ftrace_graph_ret_entry *leaf_ret;
	static enum print_line_t ret;

If multiple userspace processes concurrently read from different instances of
trace_pipe, they execute print_graph_entry() in parallel. If one thread
assigns TRACE_TYPE_PARTIAL_LINE to ret but another thread immediately
overwrites it with TRACE_TYPE_HANDLED, the first thread will incorrectly
return TRACE_TYPE_HANDLED, leading the tracing core to improperly consume an
unprinted event.

>  		} else
>  			data->failed = 0;
>  	}
> @@ -1457,6 +1459,7 @@ print_graph_function_flags(struct trace_iterator *iter, u32 flags)
>  	if (data && data->failed) {
>  		field = &data->ent.ent;
>  		iter->cpu = data->cpu;
> +		iter->ent_size = data->ent_size;
>  		ret = print_graph_entry(field, s, iter, flags);
>  		if (ret == TRACE_TYPE_HANDLED && iter->cpu != cpu) {
>  			per_cpu_ptr(data->cpu_data, iter->cpu)->ignore = 1;

[Severity: High]
This is a pre-existing issue, but could this logic cause trace events to be
permanently dropped without being printed?

For trace_pipe reads, get_return_for_leaf() consumes the current entry from
the ring buffer early to peek at the next one:

			/*
			 * We need to consume the current entry to see
			 * the next one.
			 */
			ring_buffer_consume(iter->array_buffer->buffer, iter->cpu,
					    NULL, NULL);

When reprinting a previously failed trace entry here, if the new event is on
the same CPU (iter->cpu == cpu), the function fails to set
TRACE_TYPE_NO_CONSUME in print_graph_function_flags():

		if (ret == TRACE_TYPE_HANDLED && iter->cpu != cpu) {
			per_cpu_ptr(data->cpu_data, iter->cpu)->ignore = 1;
			ret = TRACE_TYPE_NO_CONSUME;
		}
		iter->cpu = cpu;
		return ret;

Because it returns TRACE_TYPE_HANDLED, the generic iterator assumes the
current entry was handled and consumes it from the ring buffer, permanently
dropping it without printing.

-- 
Sashiko AI review · https://sashiko.dev/#/patchset/20260906034406.1335316-1-donggeunyoo.kernel@gmail.com?part=1

Re: [PATCH] function_graph: Use the saved entry's size when reprinting it

[Donggeun Yoo]

On Sun, Sep 06, 2026 at 04:02:47AM +0000, sashiko-bot@kernel.org wrote:
> - [High] This problem wasn't introduced by this patch, but state
> desynchronization when reprinting a previously failed trace entry causes
> the current entry in the ring buffer to be incorrectly consumed and
> permanently dropped.

print_graph_entry() does not always return TRACE_TYPE_HANDLED.
print_graph_entry_nested() returns TRACE_TYPE_NO_CONSUME, for the reason
given in the comment above it, so the quoted branch is not reached in the
nested case.

For a leaf, print_graph_entry_leaf() has printed the entry and its return
as one line, so the entry left at the head has already been shown and
consuming it is correct, as it is on the normal path. The iter->cpu != cpu
test is what separates the two: on another CPU the head is not the return
of the pair just reprinted, so it is left alone and ignore is set for it
instead.

The other two are pre-existing, and I looked at both while working on this
patch. get_return_for_leaf() returning at !event has already consumed the
entry, so failing there leaves data->failed set over a copy from an earlier
pass. I saw that once in about 30000 replays but could not pin any output
on it, so I have not sent a fix; say the word if you would rather have one
on the reachability argument alone. The static on ret in
print_graph_entry() has no reason to be there, though I found nothing that
misbehaves.

Thanks,
Donggeun