aboutsummaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorSteven Rostedt (Google) <rostedt@goodmis.org>2024-01-11 17:13:05 -0500
committerSteven Rostedt (Google) <rostedt@goodmis.org>2024-01-11 17:50:25 -0500
commit7f078cfd20721234c7f2543ef235b79bf7e2e894 (patch)
treeb0d69ff3378045f92860bc28c38df7878bdc8341
parent1571b67c3ca2e1b6ad5f38559a4c224f710ca4fe (diff)
downloadtrace-cmd-7f078cfd20721234c7f2543ef235b79bf7e2e894.tar.gz
libtracecmd: Break function graph line if exit is on another CPU
The function graph tracer has two events. One for the entry of a function, and one for the exit. The ftrace tracing plugin will check the next event, and if the exit event of a function follows directly after the entry of the same function, it will combine them to look like: 123.456 us | func(); If some other event were to be between the events, then it will break it up: | func() { 54.321 us | other_func(); 123.456 us | } But this could hide that a function migrated across CPUs. For example: migrate-14353 [001] dN.1. 66420.851920: funcgraph_entry: + 43.090 us | exit_to_user_mode_prepare(); Hides that the migrate program migrated between the entry of exit_to_user_mode_prepare() and the exit, where looking at each event there is: migrate-14353 [001] dN.1. 66420.851920: funcgraph_entry: | exit_to_user_mode_prepare() { migrate-14353 [003] d.... 66420.851963: funcgraph_exit: + 43.090 us | } Where it migrated from CPU 1 to 3. Worse, it confuses the idle for which CPUs they were run on and for how long: <idle>-0 [007] ...2. 66420.073288: funcgraph_entry: ! 268.817 us | do_idle(); <idle>-0 [004] ...2. 66420.073315: funcgraph_entry: ! 258.832 us | do_idle(); <idle>-0 [005] ...2. 66420.073323: funcgraph_entry: ! 157.311 us | do_idle(); Instead of: <idle>-0 [007] ...2. 66420.073288: funcgraph_entry: | do_idle() { <idle>-0 [004] ...1. 66420.073315: funcgraph_exit: ! 268.817 us | } <idle>-0 [004] ...2. 66420.073315: funcgraph_entry: | do_idle() { <idle>-0 [005] ...1. 66420.073322: funcgraph_exit: ! 258.832 us | } <idle>-0 [005] ...2. 66420.073323: funcgraph_entry: | do_idle() { <idle>-0 [000] ...1. 66420.073330: funcgraph_exit: ! 157.311 us | } Where the first one shows 268.817us for CPU 7 when it was really for CPU 4. Link: https://lore.kernel.org/linux-trace-devel/20240111171305.0bb529f0@gandalf.local.home Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
-rw-r--r--lib/trace-cmd/trace-ftrace.c8
1 files changed, 8 insertions, 0 deletions
diff --git a/lib/trace-cmd/trace-ftrace.c b/lib/trace-cmd/trace-ftrace.c
index f74f7c2e..89e46c3d 100644
--- a/lib/trace-cmd/trace-ftrace.c
+++ b/lib/trace-cmd/trace-ftrace.c
@@ -283,6 +283,14 @@ fgraph_ent_handler(struct trace_seq *s, struct tep_record *record,
return trace_seq_putc(s, '!');
rec = tracecmd_peek_next_data(tracecmd_curr_thread_handle, &cpu);
+
+ /*
+ * If the next event is on another CPU, show it.
+ * Even if the next event is the return of this function.
+ */
+ if (cpu != record->cpu)
+ rec = NULL;
+
if (rec)
rec = get_return_for_leaf(s, cpu, pid, val, rec, finfo);