1
0
Fork 0
mirror of synced 2025-03-06 20:59:54 +01:00

Tracing fixes for 6.13:

- Fix a regression in the irqsoff and wakeup latency tracing
 
   The function graph tracer infrastructure has become generic so that
   fprobes and BPF can be based on it. As it use to only handle function
   graph tracing, it would always calculate the time the function entered
   so that it could then calculate the time it exits and give the length of
   time the function executed for. But this is not needed for the other
   users (fprobes and BPF) and reading the clock adds a non-negligible
   overhead, so the calculation was moved into the function graph tracer
   logic.
 
   But the irqsoff and wakeup latency tracers, when the "display-graph"
   option was set, would use the function graph tracer to calculate the
   times of functions during the latency. The movement of the calltime
   calculation made the value zero for these tracers, and the output
   no longer showed the length of time of each tracer, but instead the
   absolute timestamp of when the function returned (rettime - calltime
   where calltime is now zero).
 
   Have the irqsoff and wakeup latency tracers also do the calltime
   calculation as the function graph tracer does and report the proper
   length of the function timings.
 
 - Update the tracing display to reflect the new preempt lazy model
 
   When the system is configured with preempt lazy, the output of the
   trace data would state "unknown" for the current preemption model.
   Because the lazy preemption model was just added, make it known
   to the tracing subsystem too. This is just a one line change.
 
 - Document multiple function graph having slightly different timings
 
   Now that function graph tracer infrastructure is separate, this also
   allows the function graph tracer to run in multiple instances (it wasn't
   able to do so before). If two instances ran the function graph tracer and
   traced the same functions, the timings for them will be slightly
   different because each does their own timings and collects the timestamps
   differently. Document this to not have people be confused by it.
 -----BEGIN PGP SIGNATURE-----
 
 iIoEABYIADIWIQRRSw7ePDh/lE+zeZMp5XQQmuv6qgUCZ4kcvhQccm9zdGVkdEBn
 b29kbWlzLm9yZwAKCRAp5XQQmuv6qnaPAPwPrZraRcXCF2SvWfF6aJ/hSVzy7XgM
 mj7FDlkw57QlVgD/cy/g8czLQ38hAqNULP+tvPc6mPSHptV8yOTKaWuVFgg=
 =N7/a
 -----END PGP SIGNATURE-----

Merge tag 'trace-v6.13-rc7' of git://git.kernel.org/pub/scm/linux/kernel/git/trace/linux-trace

Pull tracing fixes from Steven Rostedt:

 - Fix a regression in the irqsoff and wakeup latency tracing

   The function graph tracer infrastructure has become generic so that
   fprobes and BPF can be based on it. As it use to only handle function
   graph tracing, it would always calculate the time the function
   entered so that it could then calculate the time it exits and give
   the length of time the function executed for. But this is not needed
   for the other users (fprobes and BPF) and reading the clock adds a
   non-negligible overhead, so the calculation was moved into the
   function graph tracer logic.

   But the irqsoff and wakeup latency tracers, when the "display-graph"
   option was set, would use the function graph tracer to calculate the
   times of functions during the latency. The movement of the calltime
   calculation made the value zero for these tracers, and the output no
   longer showed the length of time of each tracer, but instead the
   absolute timestamp of when the function returned (rettime - calltime
   where calltime is now zero).

   Have the irqsoff and wakeup latency tracers also do the calltime
   calculation as the function graph tracer does and report the proper
   length of the function timings.

 - Update the tracing display to reflect the new preempt lazy model

   When the system is configured with preempt lazy, the output of the
   trace data would state "unknown" for the current preemption model.
   Because the lazy preemption model was just added, make it known to
   the tracing subsystem too. This is just a one line change.

 - Document multiple function graph having slightly different timings

   Now that function graph tracer infrastructure is separate, this also
   allows the function graph tracer to run in multiple instances (it
   wasn't able to do so before). If two instances ran the function graph
   tracer and traced the same functions, the timings for them will be
   slightly different because each does their own timings and collects
   the timestamps differently. Document this to not have people be
   confused by it.

* tag 'trace-v6.13-rc7' of git://git.kernel.org/pub/scm/linux/kernel/git/trace/linux-trace:
  ftrace: Document that multiple function_graph tracing may have different times
  tracing: Print lazy preemption model
  tracing: Fix irqsoff and wakeup latency tracers when using function graph
This commit is contained in:
Linus Torvalds 2025-01-16 16:19:05 -08:00
commit f692a6c690
4 changed files with 35 additions and 0 deletions

View file

@ -810,6 +810,12 @@ Here is the list of current tracers that may be configured.
to draw a graph of function calls similar to C code
source.
Note that the function graph calculates the timings of when the
function starts and returns internally and for each instance. If
there are two instances that run function graph tracer and traces
the same functions, the length of the timings may be slightly off as
each read the timestamp separately and not at the same time.
"blk"
The block tracer. The tracer used by the blktrace user

View file

@ -4122,6 +4122,7 @@ print_trace_header(struct seq_file *m, struct trace_iterator *iter)
preempt_model_none() ? "server" :
preempt_model_voluntary() ? "desktop" :
preempt_model_full() ? "preempt" :
preempt_model_lazy() ? "lazy" :
preempt_model_rt() ? "preempt_rt" :
"unknown",
/* These are reserved for later use */

View file

@ -182,6 +182,7 @@ static int irqsoff_graph_entry(struct ftrace_graph_ent *trace,
struct trace_array_cpu *data;
unsigned long flags;
unsigned int trace_ctx;
u64 *calltime;
int ret;
if (ftrace_graph_ignore_func(gops, trace))
@ -199,6 +200,12 @@ static int irqsoff_graph_entry(struct ftrace_graph_ent *trace,
if (!func_prolog_dec(tr, &data, &flags))
return 0;
calltime = fgraph_reserve_data(gops->idx, sizeof(*calltime));
if (!calltime)
return 0;
*calltime = trace_clock_local();
trace_ctx = tracing_gen_ctx_flags(flags);
ret = __trace_graph_entry(tr, trace, trace_ctx);
atomic_dec(&data->disabled);
@ -213,12 +220,19 @@ static void irqsoff_graph_return(struct ftrace_graph_ret *trace,
struct trace_array_cpu *data;
unsigned long flags;
unsigned int trace_ctx;
u64 *calltime;
int size;
ftrace_graph_addr_finish(gops, trace);
if (!func_prolog_dec(tr, &data, &flags))
return;
calltime = fgraph_retrieve_data(gops->idx, &size);
if (!calltime)
return;
trace->calltime = *calltime;
trace_ctx = tracing_gen_ctx_flags(flags);
__trace_graph_return(tr, trace, trace_ctx);
atomic_dec(&data->disabled);

View file

@ -118,6 +118,7 @@ static int wakeup_graph_entry(struct ftrace_graph_ent *trace,
struct trace_array *tr = wakeup_trace;
struct trace_array_cpu *data;
unsigned int trace_ctx;
u64 *calltime;
int ret = 0;
if (ftrace_graph_ignore_func(gops, trace))
@ -135,6 +136,12 @@ static int wakeup_graph_entry(struct ftrace_graph_ent *trace,
if (!func_prolog_preempt_disable(tr, &data, &trace_ctx))
return 0;
calltime = fgraph_reserve_data(gops->idx, sizeof(*calltime));
if (!calltime)
return 0;
*calltime = trace_clock_local();
ret = __trace_graph_entry(tr, trace, trace_ctx);
atomic_dec(&data->disabled);
preempt_enable_notrace();
@ -148,12 +155,19 @@ static void wakeup_graph_return(struct ftrace_graph_ret *trace,
struct trace_array *tr = wakeup_trace;
struct trace_array_cpu *data;
unsigned int trace_ctx;
u64 *calltime;
int size;
ftrace_graph_addr_finish(gops, trace);
if (!func_prolog_preempt_disable(tr, &data, &trace_ctx))
return;
calltime = fgraph_retrieve_data(gops->idx, &size);
if (!calltime)
return;
trace->calltime = *calltime;
__trace_graph_return(tr, trace, trace_ctx);
atomic_dec(&data->disabled);