From: "Steven Rostedt (Google)" <rostedt@xxxxxxxxxxx>
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.
Signed-off-by: Steven Rostedt (Google) <rostedt@xxxxxxxxxxx>
---
lib/trace-cmd/trace-ftrace.c | 8 ++++++++
1 file changed, 8 insertions(+)
diff --git a/lib/trace-cmd/trace-ftrace.c b/lib/trace-cmd/trace-ftrace.c
index f74f7c2e8b96..89e46c3d1cb4 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);
--
2.43.0
|