License cleanup: add SPDX GPL-2.0 license identifier to files with no license
Many source files in the tree are missing licensing information, which
makes it harder for compliance tools to determine the correct license.
By default all files without license information are under the default
license of the kernel, which is GPL version 2.
Update the files which contain no license information with the 'GPL-2.0'
SPDX license identifier. The SPDX identifier is a legally binding
shorthand, which can be used instead of the full boiler plate text.
This patch is based on work done by Thomas Gleixner and Kate Stewart and
Philippe Ombredanne.
How this work was done:
Patches were generated and checked against linux-4.14-rc6 for a subset of
the use cases:
- file had no licensing information it it.
- file was a */uapi/* one with no licensing information in it,
- file was a */uapi/* one with existing licensing information,
Further patches will be generated in subsequent months to fix up cases
where non-standard license headers were used, and references to license
had to be inferred by heuristics based on keywords.
The analysis to determine which SPDX License Identifier to be applied to
a file was done in a spreadsheet of side by side results from of the
output of two independent scanners (ScanCode & Windriver) producing SPDX
tag:value files created by Philippe Ombredanne. Philippe prepared the
base worksheet, and did an initial spot review of a few 1000 files.
The 4.13 kernel was the starting point of the analysis with 60,537 files
assessed. Kate Stewart did a file by file comparison of the scanner
results in the spreadsheet to determine which SPDX license identifier(s)
to be applied to the file. She confirmed any determination that was not
immediately clear with lawyers working with the Linux Foundation.
Criteria used to select files for SPDX license identifier tagging was:
- Files considered eligible had to be source code files.
- Make and config files were included as candidates if they contained >5
lines of source
- File already had some variant of a license header in it (even if <5
lines).
All documentation files were explicitly excluded.
The following heuristics were used to determine which SPDX license
identifiers to apply.
- when both scanners couldn't find any license traces, file was
considered to have no license information in it, and the top level
COPYING file license applied.
For non */uapi/* files that summary was:
SPDX license identifier # files
---------------------------------------------------|-------
GPL-2.0 11139
and resulted in the first patch in this series.
If that file was a */uapi/* path one, it was "GPL-2.0 WITH
Linux-syscall-note" otherwise it was "GPL-2.0". Results of that was:
SPDX license identifier # files
---------------------------------------------------|-------
GPL-2.0 WITH Linux-syscall-note 930
and resulted in the second patch in this series.
- if a file had some form of licensing information in it, and was one
of the */uapi/* ones, it was denoted with the Linux-syscall-note if
any GPL family license was found in the file or had no licensing in
it (per prior point). Results summary:
SPDX license identifier # files
---------------------------------------------------|------
GPL-2.0 WITH Linux-syscall-note 270
GPL-2.0+ WITH Linux-syscall-note 169
((GPL-2.0 WITH Linux-syscall-note) OR BSD-2-Clause) 21
((GPL-2.0 WITH Linux-syscall-note) OR BSD-3-Clause) 17
LGPL-2.1+ WITH Linux-syscall-note 15
GPL-1.0+ WITH Linux-syscall-note 14
((GPL-2.0+ WITH Linux-syscall-note) OR BSD-3-Clause) 5
LGPL-2.0+ WITH Linux-syscall-note 4
LGPL-2.1 WITH Linux-syscall-note 3
((GPL-2.0 WITH Linux-syscall-note) OR MIT) 3
((GPL-2.0 WITH Linux-syscall-note) AND MIT) 1
and that resulted in the third patch in this series.
- when the two scanners agreed on the detected license(s), that became
the concluded license(s).
- when there was disagreement between the two scanners (one detected a
license but the other didn't, or they both detected different
licenses) a manual inspection of the file occurred.
- In most cases a manual inspection of the information in the file
resulted in a clear resolution of the license that should apply (and
which scanner probably needed to revisit its heuristics).
- When it was not immediately clear, the license identifier was
confirmed with lawyers working with the Linux Foundation.
- If there was any question as to the appropriate license identifier,
the file was flagged for further research and to be revisited later
in time.
In total, over 70 hours of logged manual review was done on the
spreadsheet to determine the SPDX license identifiers to apply to the
source files by Kate, Philippe, Thomas and, in some cases, confirmation
by lawyers working with the Linux Foundation.
Kate also obtained a third independent scan of the 4.13 code base from
FOSSology, and compared selected files where the other two scanners
disagreed against that SPDX file, to see if there was new insights. The
Windriver scanner is based on an older version of FOSSology in part, so
they are related.
Thomas did random spot checks in about 500 files from the spreadsheets
for the uapi headers and agreed with SPDX license identifier in the
files he inspected. For the non-uapi files Thomas did random spot checks
in about 15000 files.
In initial set of patches against 4.14-rc6, 3 files were found to have
copy/paste license identifier errors, and have been fixed to reflect the
correct identifier.
Additionally Philippe spent 10 hours this week doing a detailed manual
inspection and review of the 12,461 patched files from the initial patch
version early this week with:
- a full scancode scan run, collecting the matched texts, detected
license ids and scores
- reviewing anything where there was a license detected (about 500+
files) to ensure that the applied SPDX license was correct
- reviewing anything where there was no detection but the patch license
was not GPL-2.0 WITH Linux-syscall-note to ensure that the applied
SPDX license was correct
This produced a worksheet with 20 files needing minor correction. This
worksheet was then exported into 3 different .csv files for the
different types of files to be modified.
These .csv files were then reviewed by Greg. Thomas wrote a script to
parse the csv files and add the proper SPDX tag to the file, in the
format that the file expected. This script was further refined by Greg
based on the output to detect more types of files automatically and to
distinguish between header and source .c files (which need different
comment types.) Finally Greg ran the script using the .csv files to
generate the patches.
Reviewed-by: Kate Stewart <kstewart@linuxfoundation.org>
Reviewed-by: Philippe Ombredanne <pombredanne@nexb.com>
Reviewed-by: Thomas Gleixner <tglx@linutronix.de>
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
2017-11-01 15:07:57 +01:00
|
|
|
// SPDX-License-Identifier: GPL-2.0
|
2008-11-25 21:07:04 +01:00
|
|
|
/*
|
|
|
|
|
*
|
|
|
|
|
* Function graph tracer.
|
2009-01-22 17:04:53 -08:00
|
|
|
* Copyright (c) 2008-2009 Frederic Weisbecker <fweisbec@gmail.com>
|
2008-11-25 21:07:04 +01:00
|
|
|
* Mostly borrowed from function tracer which
|
|
|
|
|
* is Copyright (c) Steven Rostedt <srostedt@redhat.com>
|
|
|
|
|
*
|
|
|
|
|
*/
|
|
|
|
|
#include <linux/uaccess.h>
|
|
|
|
|
#include <linux/ftrace.h>
|
2016-03-25 14:22:05 -07:00
|
|
|
#include <linux/interrupt.h>
|
include cleanup: Update gfp.h and slab.h includes to prepare for breaking implicit slab.h inclusion from percpu.h
percpu.h is included by sched.h and module.h and thus ends up being
included when building most .c files. percpu.h includes slab.h which
in turn includes gfp.h making everything defined by the two files
universally available and complicating inclusion dependencies.
percpu.h -> slab.h dependency is about to be removed. Prepare for
this change by updating users of gfp and slab facilities include those
headers directly instead of assuming availability. As this conversion
needs to touch large number of source files, the following script is
used as the basis of conversion.
http://userweb.kernel.org/~tj/misc/slabh-sweep.py
The script does the followings.
* Scan files for gfp and slab usages and update includes such that
only the necessary includes are there. ie. if only gfp is used,
gfp.h, if slab is used, slab.h.
* When the script inserts a new include, it looks at the include
blocks and try to put the new include such that its order conforms
to its surrounding. It's put in the include block which contains
core kernel includes, in the same order that the rest are ordered -
alphabetical, Christmas tree, rev-Xmas-tree or at the end if there
doesn't seem to be any matching order.
* If the script can't find a place to put a new include (mostly
because the file doesn't have fitting include block), it prints out
an error message indicating which .h file needs to be added to the
file.
The conversion was done in the following steps.
1. The initial automatic conversion of all .c files updated slightly
over 4000 files, deleting around 700 includes and adding ~480 gfp.h
and ~3000 slab.h inclusions. The script emitted errors for ~400
files.
2. Each error was manually checked. Some didn't need the inclusion,
some needed manual addition while adding it to implementation .h or
embedding .c file was more appropriate for others. This step added
inclusions to around 150 files.
3. The script was run again and the output was compared to the edits
from #2 to make sure no file was left behind.
4. Several build tests were done and a couple of problems were fixed.
e.g. lib/decompress_*.c used malloc/free() wrappers around slab
APIs requiring slab.h to be added manually.
5. The script was run on all .h files but without automatically
editing them as sprinkling gfp.h and slab.h inclusions around .h
files could easily lead to inclusion dependency hell. Most gfp.h
inclusion directives were ignored as stuff from gfp.h was usually
wildly available and often used in preprocessor macros. Each
slab.h inclusion directive was examined and added manually as
necessary.
6. percpu.h was updated not to include slab.h.
7. Build test were done on the following configurations and failures
were fixed. CONFIG_GCOV_KERNEL was turned off for all tests (as my
distributed build env didn't work with gcov compiles) and a few
more options had to be turned off depending on archs to make things
build (like ipr on powerpc/64 which failed due to missing writeq).
* x86 and x86_64 UP and SMP allmodconfig and a custom test config.
* powerpc and powerpc64 SMP allmodconfig
* sparc and sparc64 SMP allmodconfig
* ia64 SMP allmodconfig
* s390 SMP allmodconfig
* alpha SMP allmodconfig
* um on x86_64 SMP allmodconfig
8. percpu.h modifications were reverted so that it could be applied as
a separate patch and serve as bisection point.
Given the fact that I had only a couple of failures from tests on step
6, I'm fairly confident about the coverage of this conversion patch.
If there is a breakage, it's likely to be something in one of the arch
headers which should be easily discoverable easily on most builds of
the specific arch.
Signed-off-by: Tejun Heo <tj@kernel.org>
Guess-its-ok-by: Christoph Lameter <cl@linux-foundation.org>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Lee Schermerhorn <Lee.Schermerhorn@hp.com>
2010-03-24 17:04:11 +09:00
|
|
|
#include <linux/slab.h>
|
2008-11-25 21:07:04 +01:00
|
|
|
#include <linux/fs.h>
|
|
|
|
|
|
|
|
|
|
#include "trace.h"
|
2008-12-23 23:24:12 -05:00
|
|
|
#include "trace_output.h"
|
2008-11-25 21:07:04 +01:00
|
|
|
|
2010-09-14 18:58:33 -04:00
|
|
|
/* When set, irq functions will be ignored */
|
|
|
|
|
static int ftrace_graph_skip_irqs;
|
|
|
|
|
|
2009-11-24 13:57:38 +01:00
|
|
|
struct fgraph_cpu_data {
|
2009-03-19 13:24:42 -04:00
|
|
|
pid_t last_pid;
|
|
|
|
|
int depth;
|
2010-09-07 16:53:44 +02:00
|
|
|
int depth_irq;
|
2009-11-24 13:57:38 +01:00
|
|
|
int ignore;
|
2010-02-26 17:08:16 -05:00
|
|
|
unsigned long enter_funcs[FTRACE_RETFUNC_DEPTH];
|
2009-11-24 13:57:38 +01:00
|
|
|
};
|
|
|
|
|
|
|
|
|
|
struct fgraph_data {
|
2010-08-11 12:47:59 +09:00
|
|
|
struct fgraph_cpu_data __percpu *cpu_data;
|
2009-11-24 13:57:38 +01:00
|
|
|
|
|
|
|
|
/* Place to preserve last processed entry. */
|
2024-09-14 20:29:12 -07:00
|
|
|
union {
|
|
|
|
|
struct ftrace_graph_ent_entry ent;
|
|
|
|
|
struct fgraph_retaddr_ent_entry rent;
|
|
|
|
|
} ent;
|
2009-11-24 13:57:38 +01:00
|
|
|
struct ftrace_graph_ret_entry ret;
|
|
|
|
|
int failed;
|
|
|
|
|
int cpu;
|
2009-03-19 13:24:42 -04:00
|
|
|
};
|
|
|
|
|
|
2008-11-26 00:57:25 +01:00
|
|
|
#define TRACE_GRAPH_INDENT 2
|
2008-11-25 21:07:04 +01:00
|
|
|
|
2016-12-08 19:28:28 -05:00
|
|
|
unsigned int fgraph_max_depth;
|
2013-01-16 10:49:37 -05:00
|
|
|
|
2008-11-25 21:07:04 +01:00
|
|
|
static struct tracer_opt trace_opts[] = {
|
2009-01-22 17:04:53 -08:00
|
|
|
/* Display overruns? (for self-debug purpose) */
|
2008-11-28 00:42:46 +01:00
|
|
|
{ TRACER_OPT(funcgraph-overrun, TRACE_GRAPH_PRINT_OVERRUN) },
|
|
|
|
|
/* Display CPU ? */
|
|
|
|
|
{ TRACER_OPT(funcgraph-cpu, TRACE_GRAPH_PRINT_CPU) },
|
|
|
|
|
/* Display Overhead ? */
|
|
|
|
|
{ TRACER_OPT(funcgraph-overhead, TRACE_GRAPH_PRINT_OVERHEAD) },
|
2008-12-03 02:30:37 +01:00
|
|
|
/* Display proc name/pid */
|
|
|
|
|
{ TRACER_OPT(funcgraph-proc, TRACE_GRAPH_PRINT_PROC) },
|
2009-01-22 17:04:53 -08:00
|
|
|
/* Display duration of execution */
|
|
|
|
|
{ TRACER_OPT(funcgraph-duration, TRACE_GRAPH_PRINT_DURATION) },
|
|
|
|
|
/* Display absolute time of an entry */
|
|
|
|
|
{ TRACER_OPT(funcgraph-abstime, TRACE_GRAPH_PRINT_ABS_TIME) },
|
2010-09-07 16:53:44 +02:00
|
|
|
/* Display interrupts */
|
|
|
|
|
{ TRACER_OPT(funcgraph-irqs, TRACE_GRAPH_PRINT_IRQS) },
|
2014-05-20 17:10:51 -05:00
|
|
|
/* Display function name after trailing } */
|
|
|
|
|
{ TRACER_OPT(funcgraph-tail, TRACE_GRAPH_PRINT_TAIL) },
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
#ifdef CONFIG_FUNCTION_GRAPH_RETVAL
|
|
|
|
|
/* Display function return value ? */
|
|
|
|
|
{ TRACER_OPT(funcgraph-retval, TRACE_GRAPH_PRINT_RETVAL) },
|
|
|
|
|
/* Display function return value in hexadecimal format ? */
|
|
|
|
|
{ TRACER_OPT(funcgraph-retval-hex, TRACE_GRAPH_PRINT_RETVAL_HEX) },
|
2024-09-14 20:29:12 -07:00
|
|
|
#endif
|
|
|
|
|
#ifdef CONFIG_FUNCTION_GRAPH_RETADDR
|
|
|
|
|
/* Display function return address ? */
|
|
|
|
|
{ TRACER_OPT(funcgraph-retaddr, TRACE_GRAPH_PRINT_RETADDR) },
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
#endif
|
2015-09-29 19:06:50 -04:00
|
|
|
/* Include sleep time (scheduled out) between entry and return */
|
|
|
|
|
{ TRACER_OPT(sleep-time, TRACE_GRAPH_SLEEP_TIME) },
|
2018-11-23 13:06:07 -05:00
|
|
|
|
|
|
|
|
#ifdef CONFIG_FUNCTION_PROFILER
|
2015-09-29 19:06:50 -04:00
|
|
|
/* Include time within nested functions */
|
|
|
|
|
{ TRACER_OPT(graph-time, TRACE_GRAPH_GRAPH_TIME) },
|
2018-11-23 13:06:07 -05:00
|
|
|
#endif
|
|
|
|
|
|
2008-11-25 21:07:04 +01:00
|
|
|
{ } /* Empty entry */
|
|
|
|
|
};
|
|
|
|
|
|
|
|
|
|
static struct tracer_flags tracer_flags = {
|
2014-05-20 17:10:51 -05:00
|
|
|
/* Don't display overruns, proc, or tail by default */
|
2009-01-22 17:04:53 -08:00
|
|
|
.val = TRACE_GRAPH_PRINT_CPU | TRACE_GRAPH_PRINT_OVERHEAD |
|
2015-09-29 19:06:50 -04:00
|
|
|
TRACE_GRAPH_PRINT_DURATION | TRACE_GRAPH_PRINT_IRQS |
|
|
|
|
|
TRACE_GRAPH_SLEEP_TIME | TRACE_GRAPH_GRAPH_TIME,
|
2008-11-25 21:07:04 +01:00
|
|
|
.opts = trace_opts
|
|
|
|
|
};
|
|
|
|
|
|
2024-10-10 23:59:09 +09:00
|
|
|
static bool tracer_flags_is_set(u32 flags)
|
2024-09-14 20:29:12 -07:00
|
|
|
{
|
2024-10-10 23:59:09 +09:00
|
|
|
return (tracer_flags.val & flags) == flags;
|
2024-09-14 20:29:12 -07:00
|
|
|
}
|
|
|
|
|
|
2011-06-03 16:58:48 +02:00
|
|
|
/*
|
|
|
|
|
* DURATION column is being also used to display IRQ signs,
|
|
|
|
|
* following values are used by print_graph_irq and others
|
|
|
|
|
* to fill in space into DURATION column.
|
|
|
|
|
*/
|
|
|
|
|
enum {
|
2013-11-06 14:50:06 -05:00
|
|
|
FLAGS_FILL_FULL = 1 << TRACE_GRAPH_PRINT_FILL_SHIFT,
|
|
|
|
|
FLAGS_FILL_START = 2 << TRACE_GRAPH_PRINT_FILL_SHIFT,
|
|
|
|
|
FLAGS_FILL_END = 3 << TRACE_GRAPH_PRINT_FILL_SHIFT,
|
2011-06-03 16:58:48 +02:00
|
|
|
};
|
|
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
static void
|
2015-09-30 09:42:05 -04:00
|
|
|
print_graph_duration(struct trace_array *tr, unsigned long long duration,
|
|
|
|
|
struct trace_seq *s, u32 flags);
|
2008-11-25 21:07:04 +01:00
|
|
|
|
2010-04-02 19:01:22 +02:00
|
|
|
int __trace_graph_entry(struct trace_array *tr,
|
2009-07-29 18:59:58 +02:00
|
|
|
struct ftrace_graph_ent *trace,
|
2021-01-25 20:45:08 +01:00
|
|
|
unsigned int trace_ctx)
|
2009-07-29 18:59:58 +02:00
|
|
|
{
|
|
|
|
|
struct ring_buffer_event *event;
|
2019-12-13 13:58:57 -05:00
|
|
|
struct trace_buffer *buffer = tr->array_buffer.buffer;
|
2009-07-29 18:59:58 +02:00
|
|
|
struct ftrace_graph_ent_entry *entry;
|
|
|
|
|
|
2009-09-02 14:17:06 -04:00
|
|
|
event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_ENT,
|
2021-01-25 20:45:08 +01:00
|
|
|
sizeof(*entry), trace_ctx);
|
2009-07-29 18:59:58 +02:00
|
|
|
if (!event)
|
|
|
|
|
return 0;
|
|
|
|
|
entry = ring_buffer_event_data(event);
|
|
|
|
|
entry->graph_ent = *trace;
|
2024-09-11 09:00:26 +08:00
|
|
|
trace_buffer_unlock_commit_nostack(buffer, event);
|
2009-07-29 18:59:58 +02:00
|
|
|
|
|
|
|
|
return 1;
|
|
|
|
|
}
|
|
|
|
|
|
2024-09-14 20:29:12 -07:00
|
|
|
#ifdef CONFIG_FUNCTION_GRAPH_RETADDR
|
|
|
|
|
int __trace_graph_retaddr_entry(struct trace_array *tr,
|
|
|
|
|
struct ftrace_graph_ent *trace,
|
|
|
|
|
unsigned int trace_ctx,
|
|
|
|
|
unsigned long retaddr)
|
|
|
|
|
{
|
|
|
|
|
struct ring_buffer_event *event;
|
|
|
|
|
struct trace_buffer *buffer = tr->array_buffer.buffer;
|
|
|
|
|
struct fgraph_retaddr_ent_entry *entry;
|
|
|
|
|
|
|
|
|
|
event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_RETADDR_ENT,
|
|
|
|
|
sizeof(*entry), trace_ctx);
|
|
|
|
|
if (!event)
|
|
|
|
|
return 0;
|
|
|
|
|
entry = ring_buffer_event_data(event);
|
|
|
|
|
entry->graph_ent.func = trace->func;
|
|
|
|
|
entry->graph_ent.depth = trace->depth;
|
|
|
|
|
entry->graph_ent.retaddr = retaddr;
|
2024-10-10 19:40:20 -04:00
|
|
|
trace_buffer_unlock_commit_nostack(buffer, event);
|
2024-09-14 20:29:12 -07:00
|
|
|
|
|
|
|
|
return 1;
|
|
|
|
|
}
|
|
|
|
|
#else
|
|
|
|
|
int __trace_graph_retaddr_entry(struct trace_array *tr,
|
|
|
|
|
struct ftrace_graph_ent *trace,
|
|
|
|
|
unsigned int trace_ctx,
|
|
|
|
|
unsigned long retaddr)
|
|
|
|
|
{
|
|
|
|
|
return 1;
|
|
|
|
|
}
|
|
|
|
|
#endif
|
|
|
|
|
|
2010-09-14 18:58:33 -04:00
|
|
|
static inline int ftrace_graph_ignore_irqs(void)
|
|
|
|
|
{
|
2011-06-14 19:02:29 -04:00
|
|
|
if (!ftrace_graph_skip_irqs || trace_recursion_test(TRACE_IRQ_BIT))
|
2010-09-14 18:58:33 -04:00
|
|
|
return 0;
|
|
|
|
|
|
2021-09-30 08:03:42 +08:00
|
|
|
return in_hardirq();
|
2010-09-14 18:58:33 -04:00
|
|
|
}
|
|
|
|
|
|
2024-09-14 17:48:08 -04:00
|
|
|
struct fgraph_times {
|
|
|
|
|
unsigned long long calltime;
|
|
|
|
|
unsigned long long sleeptime; /* may be optional! */
|
|
|
|
|
};
|
|
|
|
|
|
2024-06-03 15:07:11 -04:00
|
|
|
int trace_graph_entry(struct ftrace_graph_ent *trace,
|
2024-12-26 14:11:40 +09:00
|
|
|
struct fgraph_ops *gops,
|
|
|
|
|
struct ftrace_regs *fregs)
|
2009-07-29 18:59:58 +02:00
|
|
|
{
|
2024-06-03 15:07:22 -04:00
|
|
|
unsigned long *task_var = fgraph_get_task_var(gops);
|
2024-06-03 15:07:12 -04:00
|
|
|
struct trace_array *tr = gops->private;
|
2009-07-29 18:59:58 +02:00
|
|
|
struct trace_array_cpu *data;
|
2024-09-14 17:48:08 -04:00
|
|
|
struct fgraph_times *ftimes;
|
2021-01-25 20:45:08 +01:00
|
|
|
unsigned int trace_ctx;
|
2009-07-29 18:59:58 +02:00
|
|
|
long disabled;
|
fgraph: Remove unnecessary disabling of interrupts and recursion
The function graph tracer disables interrupts as well as prevents
recursion via NMIs when recording the graph tracer code. There's no reason
to do this today. That disabling goes back to 2008 when the function graph
tracer was first introduced and recursion protection wasn't part of the
code.
Today, there's no reason to disable interrupts or prevent the code from
recursing as the infrastructure can easily handle it.
Before this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 4.240
Time: 4.236
Time: 4.106
Time: 4.014
Time: 4.314
Time: 3.830
Time: 4.063
Time: 4.323
Time: 3.763
Time: 3.727
Performance counter stats for '/work/c/hackbench 10' (10 runs):
33,937.20 msec task-clock # 7.008 CPUs utilized ( +- 1.85% )
18,220 context-switches # 536.874 /sec ( +- 6.41% )
624 cpu-migrations # 18.387 /sec ( +- 9.07% )
11,319 page-faults # 333.528 /sec ( +- 1.97% )
76,657,643,617 cycles # 2.259 GHz ( +- 0.40% )
141,403,302,768 instructions # 1.84 insn per cycle ( +- 0.37% )
25,518,463,888 branches # 751.932 M/sec ( +- 0.35% )
156,151,050 branch-misses # 0.61% of all branches ( +- 0.63% )
4.8423 +- 0.0892 seconds time elapsed ( +- 1.84% )
After this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 3.340
Time: 3.192
Time: 3.129
Time: 2.579
Time: 2.589
Time: 2.798
Time: 2.791
Time: 2.955
Time: 3.044
Time: 3.065
Performance counter stats for './hackbench 10' (10 runs):
24,416.30 msec task-clock # 6.996 CPUs utilized ( +- 2.74% )
16,764 context-switches # 686.590 /sec ( +- 5.85% )
469 cpu-migrations # 19.208 /sec ( +- 6.14% )
11,519 page-faults # 471.775 /sec ( +- 1.92% )
53,895,628,450 cycles # 2.207 GHz ( +- 0.52% )
105,552,664,638 instructions # 1.96 insn per cycle ( +- 0.47% )
17,808,672,667 branches # 729.376 M/sec ( +- 0.48% )
133,075,435 branch-misses # 0.75% of all branches ( +- 0.59% )
3.490 +- 0.112 seconds time elapsed ( +- 3.22% )
Also removed unneeded "unlikely()" around the retaddr code.
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Cc: Andrew Morton <akpm@linux-foundation.org>
Link: https://lore.kernel.org/20241223184941.204074053@goodmis.org
Fixes: 9cd2992f2d6c8 ("fgraph: Have set_graph_notrace only affect function_graph tracer") # Performance only
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2024-12-23 13:46:19 -05:00
|
|
|
int ret = 0;
|
2009-07-29 18:59:58 +02:00
|
|
|
int cpu;
|
|
|
|
|
|
2024-06-03 15:07:22 -04:00
|
|
|
if (*task_var & TRACE_GRAPH_NOTRACE)
|
2018-11-14 13:14:58 -05:00
|
|
|
return 0;
|
|
|
|
|
|
2019-07-30 22:08:50 +08:00
|
|
|
/*
|
|
|
|
|
* Do not trace a function if it's filtered by set_graph_notrace.
|
|
|
|
|
* Make the index of ret stack negative to indicate that it should
|
|
|
|
|
* ignore further functions. But it needs its own ret stack entry
|
|
|
|
|
* to recover the original index in order to continue tracing after
|
|
|
|
|
* returning from the function.
|
|
|
|
|
*/
|
2018-11-14 13:14:58 -05:00
|
|
|
if (ftrace_graph_notrace_addr(trace->func)) {
|
2025-02-08 00:15:11 -05:00
|
|
|
*task_var |= TRACE_GRAPH_NOTRACE;
|
2018-11-14 13:14:58 -05:00
|
|
|
/*
|
|
|
|
|
* Need to return 1 to have the return called
|
|
|
|
|
* that will clear the NOTRACE bit.
|
|
|
|
|
*/
|
|
|
|
|
return 1;
|
|
|
|
|
}
|
|
|
|
|
|
2016-04-22 18:11:33 -04:00
|
|
|
if (!ftrace_trace_task(tr))
|
2009-07-29 18:59:58 +02:00
|
|
|
return 0;
|
|
|
|
|
|
2024-06-03 15:07:20 -04:00
|
|
|
if (ftrace_graph_ignore_func(gops, trace))
|
2016-12-08 19:28:28 -05:00
|
|
|
return 0;
|
|
|
|
|
|
|
|
|
|
if (ftrace_graph_ignore_irqs())
|
2009-07-29 18:59:58 +02:00
|
|
|
return 0;
|
|
|
|
|
|
2024-09-14 17:48:08 -04:00
|
|
|
if (fgraph_sleep_time) {
|
|
|
|
|
/* Only need to record the calltime */
|
|
|
|
|
ftimes = fgraph_reserve_data(gops->idx, sizeof(ftimes->calltime));
|
|
|
|
|
} else {
|
|
|
|
|
ftimes = fgraph_reserve_data(gops->idx, sizeof(*ftimes));
|
|
|
|
|
if (ftimes)
|
|
|
|
|
ftimes->sleeptime = current->ftrace_sleeptime;
|
2024-09-14 17:48:07 -04:00
|
|
|
}
|
2024-09-14 17:48:08 -04:00
|
|
|
if (!ftimes)
|
|
|
|
|
return 0;
|
|
|
|
|
|
|
|
|
|
ftimes->calltime = trace_clock_local();
|
2024-09-14 17:48:07 -04:00
|
|
|
|
2016-06-17 22:44:54 -07:00
|
|
|
/*
|
|
|
|
|
* Stop here if tracing_threshold is set. We only write function return
|
|
|
|
|
* events to the ring buffer.
|
|
|
|
|
*/
|
|
|
|
|
if (tracing_thresh)
|
|
|
|
|
return 1;
|
|
|
|
|
|
fgraph: Remove unnecessary disabling of interrupts and recursion
The function graph tracer disables interrupts as well as prevents
recursion via NMIs when recording the graph tracer code. There's no reason
to do this today. That disabling goes back to 2008 when the function graph
tracer was first introduced and recursion protection wasn't part of the
code.
Today, there's no reason to disable interrupts or prevent the code from
recursing as the infrastructure can easily handle it.
Before this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 4.240
Time: 4.236
Time: 4.106
Time: 4.014
Time: 4.314
Time: 3.830
Time: 4.063
Time: 4.323
Time: 3.763
Time: 3.727
Performance counter stats for '/work/c/hackbench 10' (10 runs):
33,937.20 msec task-clock # 7.008 CPUs utilized ( +- 1.85% )
18,220 context-switches # 536.874 /sec ( +- 6.41% )
624 cpu-migrations # 18.387 /sec ( +- 9.07% )
11,319 page-faults # 333.528 /sec ( +- 1.97% )
76,657,643,617 cycles # 2.259 GHz ( +- 0.40% )
141,403,302,768 instructions # 1.84 insn per cycle ( +- 0.37% )
25,518,463,888 branches # 751.932 M/sec ( +- 0.35% )
156,151,050 branch-misses # 0.61% of all branches ( +- 0.63% )
4.8423 +- 0.0892 seconds time elapsed ( +- 1.84% )
After this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 3.340
Time: 3.192
Time: 3.129
Time: 2.579
Time: 2.589
Time: 2.798
Time: 2.791
Time: 2.955
Time: 3.044
Time: 3.065
Performance counter stats for './hackbench 10' (10 runs):
24,416.30 msec task-clock # 6.996 CPUs utilized ( +- 2.74% )
16,764 context-switches # 686.590 /sec ( +- 5.85% )
469 cpu-migrations # 19.208 /sec ( +- 6.14% )
11,519 page-faults # 471.775 /sec ( +- 1.92% )
53,895,628,450 cycles # 2.207 GHz ( +- 0.52% )
105,552,664,638 instructions # 1.96 insn per cycle ( +- 0.47% )
17,808,672,667 branches # 729.376 M/sec ( +- 0.48% )
133,075,435 branch-misses # 0.75% of all branches ( +- 0.59% )
3.490 +- 0.112 seconds time elapsed ( +- 3.22% )
Also removed unneeded "unlikely()" around the retaddr code.
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Cc: Andrew Morton <akpm@linux-foundation.org>
Link: https://lore.kernel.org/20241223184941.204074053@goodmis.org
Fixes: 9cd2992f2d6c8 ("fgraph: Have set_graph_notrace only affect function_graph tracer") # Performance only
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2024-12-23 13:46:19 -05:00
|
|
|
preempt_disable_notrace();
|
2009-07-29 18:59:58 +02:00
|
|
|
cpu = raw_smp_processor_id();
|
2020-01-09 18:53:48 -05:00
|
|
|
data = per_cpu_ptr(tr->array_buffer.data, cpu);
|
fgraph: Remove unnecessary disabling of interrupts and recursion
The function graph tracer disables interrupts as well as prevents
recursion via NMIs when recording the graph tracer code. There's no reason
to do this today. That disabling goes back to 2008 when the function graph
tracer was first introduced and recursion protection wasn't part of the
code.
Today, there's no reason to disable interrupts or prevent the code from
recursing as the infrastructure can easily handle it.
Before this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 4.240
Time: 4.236
Time: 4.106
Time: 4.014
Time: 4.314
Time: 3.830
Time: 4.063
Time: 4.323
Time: 3.763
Time: 3.727
Performance counter stats for '/work/c/hackbench 10' (10 runs):
33,937.20 msec task-clock # 7.008 CPUs utilized ( +- 1.85% )
18,220 context-switches # 536.874 /sec ( +- 6.41% )
624 cpu-migrations # 18.387 /sec ( +- 9.07% )
11,319 page-faults # 333.528 /sec ( +- 1.97% )
76,657,643,617 cycles # 2.259 GHz ( +- 0.40% )
141,403,302,768 instructions # 1.84 insn per cycle ( +- 0.37% )
25,518,463,888 branches # 751.932 M/sec ( +- 0.35% )
156,151,050 branch-misses # 0.61% of all branches ( +- 0.63% )
4.8423 +- 0.0892 seconds time elapsed ( +- 1.84% )
After this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 3.340
Time: 3.192
Time: 3.129
Time: 2.579
Time: 2.589
Time: 2.798
Time: 2.791
Time: 2.955
Time: 3.044
Time: 3.065
Performance counter stats for './hackbench 10' (10 runs):
24,416.30 msec task-clock # 6.996 CPUs utilized ( +- 2.74% )
16,764 context-switches # 686.590 /sec ( +- 5.85% )
469 cpu-migrations # 19.208 /sec ( +- 6.14% )
11,519 page-faults # 471.775 /sec ( +- 1.92% )
53,895,628,450 cycles # 2.207 GHz ( +- 0.52% )
105,552,664,638 instructions # 1.96 insn per cycle ( +- 0.47% )
17,808,672,667 branches # 729.376 M/sec ( +- 0.48% )
133,075,435 branch-misses # 0.75% of all branches ( +- 0.59% )
3.490 +- 0.112 seconds time elapsed ( +- 3.22% )
Also removed unneeded "unlikely()" around the retaddr code.
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Cc: Andrew Morton <akpm@linux-foundation.org>
Link: https://lore.kernel.org/20241223184941.204074053@goodmis.org
Fixes: 9cd2992f2d6c8 ("fgraph: Have set_graph_notrace only affect function_graph tracer") # Performance only
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2024-12-23 13:46:19 -05:00
|
|
|
disabled = atomic_read(&data->disabled);
|
|
|
|
|
if (likely(!disabled)) {
|
|
|
|
|
trace_ctx = tracing_gen_ctx();
|
|
|
|
|
if (IS_ENABLED(CONFIG_FUNCTION_GRAPH_RETADDR) &&
|
|
|
|
|
tracer_flags_is_set(TRACE_GRAPH_PRINT_RETADDR)) {
|
2024-10-10 23:59:09 +09:00
|
|
|
unsigned long retaddr = ftrace_graph_top_ret_addr(current);
|
|
|
|
|
ret = __trace_graph_retaddr_entry(tr, trace, trace_ctx, retaddr);
|
fgraph: Remove unnecessary disabling of interrupts and recursion
The function graph tracer disables interrupts as well as prevents
recursion via NMIs when recording the graph tracer code. There's no reason
to do this today. That disabling goes back to 2008 when the function graph
tracer was first introduced and recursion protection wasn't part of the
code.
Today, there's no reason to disable interrupts or prevent the code from
recursing as the infrastructure can easily handle it.
Before this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 4.240
Time: 4.236
Time: 4.106
Time: 4.014
Time: 4.314
Time: 3.830
Time: 4.063
Time: 4.323
Time: 3.763
Time: 3.727
Performance counter stats for '/work/c/hackbench 10' (10 runs):
33,937.20 msec task-clock # 7.008 CPUs utilized ( +- 1.85% )
18,220 context-switches # 536.874 /sec ( +- 6.41% )
624 cpu-migrations # 18.387 /sec ( +- 9.07% )
11,319 page-faults # 333.528 /sec ( +- 1.97% )
76,657,643,617 cycles # 2.259 GHz ( +- 0.40% )
141,403,302,768 instructions # 1.84 insn per cycle ( +- 0.37% )
25,518,463,888 branches # 751.932 M/sec ( +- 0.35% )
156,151,050 branch-misses # 0.61% of all branches ( +- 0.63% )
4.8423 +- 0.0892 seconds time elapsed ( +- 1.84% )
After this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 3.340
Time: 3.192
Time: 3.129
Time: 2.579
Time: 2.589
Time: 2.798
Time: 2.791
Time: 2.955
Time: 3.044
Time: 3.065
Performance counter stats for './hackbench 10' (10 runs):
24,416.30 msec task-clock # 6.996 CPUs utilized ( +- 2.74% )
16,764 context-switches # 686.590 /sec ( +- 5.85% )
469 cpu-migrations # 19.208 /sec ( +- 6.14% )
11,519 page-faults # 471.775 /sec ( +- 1.92% )
53,895,628,450 cycles # 2.207 GHz ( +- 0.52% )
105,552,664,638 instructions # 1.96 insn per cycle ( +- 0.47% )
17,808,672,667 branches # 729.376 M/sec ( +- 0.48% )
133,075,435 branch-misses # 0.75% of all branches ( +- 0.59% )
3.490 +- 0.112 seconds time elapsed ( +- 3.22% )
Also removed unneeded "unlikely()" around the retaddr code.
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Cc: Andrew Morton <akpm@linux-foundation.org>
Link: https://lore.kernel.org/20241223184941.204074053@goodmis.org
Fixes: 9cd2992f2d6c8 ("fgraph: Have set_graph_notrace only affect function_graph tracer") # Performance only
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2024-12-23 13:46:19 -05:00
|
|
|
} else {
|
2024-09-14 20:29:12 -07:00
|
|
|
ret = __trace_graph_entry(tr, trace, trace_ctx);
|
fgraph: Remove unnecessary disabling of interrupts and recursion
The function graph tracer disables interrupts as well as prevents
recursion via NMIs when recording the graph tracer code. There's no reason
to do this today. That disabling goes back to 2008 when the function graph
tracer was first introduced and recursion protection wasn't part of the
code.
Today, there's no reason to disable interrupts or prevent the code from
recursing as the infrastructure can easily handle it.
Before this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 4.240
Time: 4.236
Time: 4.106
Time: 4.014
Time: 4.314
Time: 3.830
Time: 4.063
Time: 4.323
Time: 3.763
Time: 3.727
Performance counter stats for '/work/c/hackbench 10' (10 runs):
33,937.20 msec task-clock # 7.008 CPUs utilized ( +- 1.85% )
18,220 context-switches # 536.874 /sec ( +- 6.41% )
624 cpu-migrations # 18.387 /sec ( +- 9.07% )
11,319 page-faults # 333.528 /sec ( +- 1.97% )
76,657,643,617 cycles # 2.259 GHz ( +- 0.40% )
141,403,302,768 instructions # 1.84 insn per cycle ( +- 0.37% )
25,518,463,888 branches # 751.932 M/sec ( +- 0.35% )
156,151,050 branch-misses # 0.61% of all branches ( +- 0.63% )
4.8423 +- 0.0892 seconds time elapsed ( +- 1.84% )
After this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 3.340
Time: 3.192
Time: 3.129
Time: 2.579
Time: 2.589
Time: 2.798
Time: 2.791
Time: 2.955
Time: 3.044
Time: 3.065
Performance counter stats for './hackbench 10' (10 runs):
24,416.30 msec task-clock # 6.996 CPUs utilized ( +- 2.74% )
16,764 context-switches # 686.590 /sec ( +- 5.85% )
469 cpu-migrations # 19.208 /sec ( +- 6.14% )
11,519 page-faults # 471.775 /sec ( +- 1.92% )
53,895,628,450 cycles # 2.207 GHz ( +- 0.52% )
105,552,664,638 instructions # 1.96 insn per cycle ( +- 0.47% )
17,808,672,667 branches # 729.376 M/sec ( +- 0.48% )
133,075,435 branch-misses # 0.75% of all branches ( +- 0.59% )
3.490 +- 0.112 seconds time elapsed ( +- 3.22% )
Also removed unneeded "unlikely()" around the retaddr code.
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Cc: Andrew Morton <akpm@linux-foundation.org>
Link: https://lore.kernel.org/20241223184941.204074053@goodmis.org
Fixes: 9cd2992f2d6c8 ("fgraph: Have set_graph_notrace only affect function_graph tracer") # Performance only
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2024-12-23 13:46:19 -05:00
|
|
|
}
|
2009-07-29 18:59:58 +02:00
|
|
|
}
|
fgraph: Remove unnecessary disabling of interrupts and recursion
The function graph tracer disables interrupts as well as prevents
recursion via NMIs when recording the graph tracer code. There's no reason
to do this today. That disabling goes back to 2008 when the function graph
tracer was first introduced and recursion protection wasn't part of the
code.
Today, there's no reason to disable interrupts or prevent the code from
recursing as the infrastructure can easily handle it.
Before this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 4.240
Time: 4.236
Time: 4.106
Time: 4.014
Time: 4.314
Time: 3.830
Time: 4.063
Time: 4.323
Time: 3.763
Time: 3.727
Performance counter stats for '/work/c/hackbench 10' (10 runs):
33,937.20 msec task-clock # 7.008 CPUs utilized ( +- 1.85% )
18,220 context-switches # 536.874 /sec ( +- 6.41% )
624 cpu-migrations # 18.387 /sec ( +- 9.07% )
11,319 page-faults # 333.528 /sec ( +- 1.97% )
76,657,643,617 cycles # 2.259 GHz ( +- 0.40% )
141,403,302,768 instructions # 1.84 insn per cycle ( +- 0.37% )
25,518,463,888 branches # 751.932 M/sec ( +- 0.35% )
156,151,050 branch-misses # 0.61% of all branches ( +- 0.63% )
4.8423 +- 0.0892 seconds time elapsed ( +- 1.84% )
After this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 3.340
Time: 3.192
Time: 3.129
Time: 2.579
Time: 2.589
Time: 2.798
Time: 2.791
Time: 2.955
Time: 3.044
Time: 3.065
Performance counter stats for './hackbench 10' (10 runs):
24,416.30 msec task-clock # 6.996 CPUs utilized ( +- 2.74% )
16,764 context-switches # 686.590 /sec ( +- 5.85% )
469 cpu-migrations # 19.208 /sec ( +- 6.14% )
11,519 page-faults # 471.775 /sec ( +- 1.92% )
53,895,628,450 cycles # 2.207 GHz ( +- 0.52% )
105,552,664,638 instructions # 1.96 insn per cycle ( +- 0.47% )
17,808,672,667 branches # 729.376 M/sec ( +- 0.48% )
133,075,435 branch-misses # 0.75% of all branches ( +- 0.59% )
3.490 +- 0.112 seconds time elapsed ( +- 3.22% )
Also removed unneeded "unlikely()" around the retaddr code.
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Cc: Andrew Morton <akpm@linux-foundation.org>
Link: https://lore.kernel.org/20241223184941.204074053@goodmis.org
Fixes: 9cd2992f2d6c8 ("fgraph: Have set_graph_notrace only affect function_graph tracer") # Performance only
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2024-12-23 13:46:19 -05:00
|
|
|
preempt_enable_notrace();
|
2009-07-29 18:59:58 +02:00
|
|
|
|
|
|
|
|
return ret;
|
|
|
|
|
}
|
|
|
|
|
|
2010-09-23 14:00:52 +02:00
|
|
|
static void
|
|
|
|
|
__trace_graph_function(struct trace_array *tr,
|
2021-01-25 20:45:08 +01:00
|
|
|
unsigned long ip, unsigned int trace_ctx)
|
2010-09-23 14:00:52 +02:00
|
|
|
{
|
|
|
|
|
u64 time = trace_clock_local();
|
|
|
|
|
struct ftrace_graph_ent ent = {
|
|
|
|
|
.func = ip,
|
|
|
|
|
.depth = 0,
|
|
|
|
|
};
|
|
|
|
|
struct ftrace_graph_ret ret = {
|
|
|
|
|
.func = ip,
|
|
|
|
|
.depth = 0,
|
|
|
|
|
};
|
|
|
|
|
|
2021-01-25 20:45:08 +01:00
|
|
|
__trace_graph_entry(tr, &ent, trace_ctx);
|
2025-01-21 19:44:36 -05:00
|
|
|
__trace_graph_return(tr, &ret, trace_ctx, time, time);
|
2010-09-23 14:00:52 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
void
|
|
|
|
|
trace_graph_function(struct trace_array *tr,
|
|
|
|
|
unsigned long ip, unsigned long parent_ip,
|
2021-01-25 20:45:08 +01:00
|
|
|
unsigned int trace_ctx)
|
2010-09-23 14:00:52 +02:00
|
|
|
{
|
2021-01-25 20:45:08 +01:00
|
|
|
__trace_graph_function(tr, ip, trace_ctx);
|
2010-09-23 14:00:52 +02:00
|
|
|
}
|
|
|
|
|
|
2010-04-02 19:01:22 +02:00
|
|
|
void __trace_graph_return(struct trace_array *tr,
|
2025-01-21 19:44:36 -05:00
|
|
|
struct ftrace_graph_ret *trace,
|
|
|
|
|
unsigned int trace_ctx,
|
|
|
|
|
u64 calltime, u64 rettime)
|
2009-07-29 18:59:58 +02:00
|
|
|
{
|
|
|
|
|
struct ring_buffer_event *event;
|
2019-12-13 13:58:57 -05:00
|
|
|
struct trace_buffer *buffer = tr->array_buffer.buffer;
|
2009-07-29 18:59:58 +02:00
|
|
|
struct ftrace_graph_ret_entry *entry;
|
|
|
|
|
|
2009-09-02 14:17:06 -04:00
|
|
|
event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_RET,
|
2021-01-25 20:45:08 +01:00
|
|
|
sizeof(*entry), trace_ctx);
|
2009-07-29 18:59:58 +02:00
|
|
|
if (!event)
|
|
|
|
|
return;
|
|
|
|
|
entry = ring_buffer_event_data(event);
|
|
|
|
|
entry->ret = *trace;
|
2025-01-21 19:44:36 -05:00
|
|
|
entry->calltime = calltime;
|
|
|
|
|
entry->rettime = rettime;
|
2024-09-11 09:00:26 +08:00
|
|
|
trace_buffer_unlock_commit_nostack(buffer, event);
|
2009-07-29 18:59:58 +02:00
|
|
|
}
|
|
|
|
|
|
2024-09-14 17:48:07 -04:00
|
|
|
static void handle_nosleeptime(struct ftrace_graph_ret *trace,
|
2024-09-14 17:48:08 -04:00
|
|
|
struct fgraph_times *ftimes,
|
|
|
|
|
int size)
|
2024-09-14 17:48:07 -04:00
|
|
|
{
|
2024-09-14 17:48:08 -04:00
|
|
|
if (fgraph_sleep_time || size < sizeof(*ftimes))
|
2024-09-14 17:48:07 -04:00
|
|
|
return;
|
|
|
|
|
|
2024-09-14 17:48:08 -04:00
|
|
|
ftimes->calltime += current->ftrace_sleeptime - ftimes->sleeptime;
|
2024-09-14 17:48:07 -04:00
|
|
|
}
|
|
|
|
|
|
2024-06-03 15:07:11 -04:00
|
|
|
void trace_graph_return(struct ftrace_graph_ret *trace,
|
2024-12-26 14:12:09 +09:00
|
|
|
struct fgraph_ops *gops, struct ftrace_regs *fregs)
|
2009-07-29 18:59:58 +02:00
|
|
|
{
|
2024-06-03 15:07:22 -04:00
|
|
|
unsigned long *task_var = fgraph_get_task_var(gops);
|
2024-06-03 15:07:12 -04:00
|
|
|
struct trace_array *tr = gops->private;
|
2009-07-29 18:59:58 +02:00
|
|
|
struct trace_array_cpu *data;
|
2024-09-14 17:48:08 -04:00
|
|
|
struct fgraph_times *ftimes;
|
2021-01-25 20:45:08 +01:00
|
|
|
unsigned int trace_ctx;
|
2025-01-21 19:44:36 -05:00
|
|
|
u64 calltime, rettime;
|
2009-07-29 18:59:58 +02:00
|
|
|
long disabled;
|
2024-09-14 17:48:08 -04:00
|
|
|
int size;
|
2009-07-29 18:59:58 +02:00
|
|
|
int cpu;
|
|
|
|
|
|
2025-01-21 19:44:36 -05:00
|
|
|
rettime = trace_clock_local();
|
|
|
|
|
|
2024-06-03 15:07:20 -04:00
|
|
|
ftrace_graph_addr_finish(gops, trace);
|
tracing/fgraph: Fix set_graph_function from showing interrupts
The tracefs file set_graph_function is used to only function graph functions
that are listed in that file (or all functions if the file is empty). The
way this is implemented is that the function graph tracer looks at every
function, and if the current depth is zero and the function matches
something in the file then it will trace that function. When other functions
are called, the depth will be greater than zero (because the original
function will be at depth zero), and all functions will be traced where the
depth is greater than zero.
The issue is that when a function is first entered, and the handler that
checks this logic is called, the depth is set to zero. If an interrupt comes
in and a function in the interrupt handler is traced, its depth will be
greater than zero and it will automatically be traced, even if the original
function was not. But because the logic only looks at depth it may trace
interrupts when it should not be.
The recent design change of the function graph tracer to fix other bugs
caused the depth to be zero while the function graph callback handler is
being called for a longer time, widening the race of this happening. This
bug was actually there for a longer time, but because the race window was so
small it seldom happened. The Fixes tag below is for the commit that widen
the race window, because that commit belongs to a series that will also help
fix the original bug.
Cc: stable@kernel.org
Fixes: 39eb456dacb5 ("function_graph: Use new curr_ret_depth to manage depth instead of curr_ret_stack")
Reported-by: Joe Lawrence <joe.lawrence@redhat.com>
Tested-by: Joe Lawrence <joe.lawrence@redhat.com>
Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
2018-11-29 08:50:27 -05:00
|
|
|
|
2024-06-03 15:07:22 -04:00
|
|
|
if (*task_var & TRACE_GRAPH_NOTRACE) {
|
|
|
|
|
*task_var &= ~TRACE_GRAPH_NOTRACE;
|
2018-11-14 13:14:58 -05:00
|
|
|
return;
|
|
|
|
|
}
|
|
|
|
|
|
2024-09-14 17:48:08 -04:00
|
|
|
ftimes = fgraph_retrieve_data(gops->idx, &size);
|
|
|
|
|
if (!ftimes)
|
|
|
|
|
return;
|
|
|
|
|
|
|
|
|
|
handle_nosleeptime(trace, ftimes, size);
|
|
|
|
|
|
2025-01-21 19:44:36 -05:00
|
|
|
calltime = ftimes->calltime;
|
2024-09-14 17:48:07 -04:00
|
|
|
|
fgraph: Remove unnecessary disabling of interrupts and recursion
The function graph tracer disables interrupts as well as prevents
recursion via NMIs when recording the graph tracer code. There's no reason
to do this today. That disabling goes back to 2008 when the function graph
tracer was first introduced and recursion protection wasn't part of the
code.
Today, there's no reason to disable interrupts or prevent the code from
recursing as the infrastructure can easily handle it.
Before this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 4.240
Time: 4.236
Time: 4.106
Time: 4.014
Time: 4.314
Time: 3.830
Time: 4.063
Time: 4.323
Time: 3.763
Time: 3.727
Performance counter stats for '/work/c/hackbench 10' (10 runs):
33,937.20 msec task-clock # 7.008 CPUs utilized ( +- 1.85% )
18,220 context-switches # 536.874 /sec ( +- 6.41% )
624 cpu-migrations # 18.387 /sec ( +- 9.07% )
11,319 page-faults # 333.528 /sec ( +- 1.97% )
76,657,643,617 cycles # 2.259 GHz ( +- 0.40% )
141,403,302,768 instructions # 1.84 insn per cycle ( +- 0.37% )
25,518,463,888 branches # 751.932 M/sec ( +- 0.35% )
156,151,050 branch-misses # 0.61% of all branches ( +- 0.63% )
4.8423 +- 0.0892 seconds time elapsed ( +- 1.84% )
After this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 3.340
Time: 3.192
Time: 3.129
Time: 2.579
Time: 2.589
Time: 2.798
Time: 2.791
Time: 2.955
Time: 3.044
Time: 3.065
Performance counter stats for './hackbench 10' (10 runs):
24,416.30 msec task-clock # 6.996 CPUs utilized ( +- 2.74% )
16,764 context-switches # 686.590 /sec ( +- 5.85% )
469 cpu-migrations # 19.208 /sec ( +- 6.14% )
11,519 page-faults # 471.775 /sec ( +- 1.92% )
53,895,628,450 cycles # 2.207 GHz ( +- 0.52% )
105,552,664,638 instructions # 1.96 insn per cycle ( +- 0.47% )
17,808,672,667 branches # 729.376 M/sec ( +- 0.48% )
133,075,435 branch-misses # 0.75% of all branches ( +- 0.59% )
3.490 +- 0.112 seconds time elapsed ( +- 3.22% )
Also removed unneeded "unlikely()" around the retaddr code.
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Cc: Andrew Morton <akpm@linux-foundation.org>
Link: https://lore.kernel.org/20241223184941.204074053@goodmis.org
Fixes: 9cd2992f2d6c8 ("fgraph: Have set_graph_notrace only affect function_graph tracer") # Performance only
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2024-12-23 13:46:19 -05:00
|
|
|
preempt_disable_notrace();
|
2009-07-29 18:59:58 +02:00
|
|
|
cpu = raw_smp_processor_id();
|
2020-01-09 18:53:48 -05:00
|
|
|
data = per_cpu_ptr(tr->array_buffer.data, cpu);
|
fgraph: Remove unnecessary disabling of interrupts and recursion
The function graph tracer disables interrupts as well as prevents
recursion via NMIs when recording the graph tracer code. There's no reason
to do this today. That disabling goes back to 2008 when the function graph
tracer was first introduced and recursion protection wasn't part of the
code.
Today, there's no reason to disable interrupts or prevent the code from
recursing as the infrastructure can easily handle it.
Before this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 4.240
Time: 4.236
Time: 4.106
Time: 4.014
Time: 4.314
Time: 3.830
Time: 4.063
Time: 4.323
Time: 3.763
Time: 3.727
Performance counter stats for '/work/c/hackbench 10' (10 runs):
33,937.20 msec task-clock # 7.008 CPUs utilized ( +- 1.85% )
18,220 context-switches # 536.874 /sec ( +- 6.41% )
624 cpu-migrations # 18.387 /sec ( +- 9.07% )
11,319 page-faults # 333.528 /sec ( +- 1.97% )
76,657,643,617 cycles # 2.259 GHz ( +- 0.40% )
141,403,302,768 instructions # 1.84 insn per cycle ( +- 0.37% )
25,518,463,888 branches # 751.932 M/sec ( +- 0.35% )
156,151,050 branch-misses # 0.61% of all branches ( +- 0.63% )
4.8423 +- 0.0892 seconds time elapsed ( +- 1.84% )
After this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 3.340
Time: 3.192
Time: 3.129
Time: 2.579
Time: 2.589
Time: 2.798
Time: 2.791
Time: 2.955
Time: 3.044
Time: 3.065
Performance counter stats for './hackbench 10' (10 runs):
24,416.30 msec task-clock # 6.996 CPUs utilized ( +- 2.74% )
16,764 context-switches # 686.590 /sec ( +- 5.85% )
469 cpu-migrations # 19.208 /sec ( +- 6.14% )
11,519 page-faults # 471.775 /sec ( +- 1.92% )
53,895,628,450 cycles # 2.207 GHz ( +- 0.52% )
105,552,664,638 instructions # 1.96 insn per cycle ( +- 0.47% )
17,808,672,667 branches # 729.376 M/sec ( +- 0.48% )
133,075,435 branch-misses # 0.75% of all branches ( +- 0.59% )
3.490 +- 0.112 seconds time elapsed ( +- 3.22% )
Also removed unneeded "unlikely()" around the retaddr code.
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Cc: Andrew Morton <akpm@linux-foundation.org>
Link: https://lore.kernel.org/20241223184941.204074053@goodmis.org
Fixes: 9cd2992f2d6c8 ("fgraph: Have set_graph_notrace only affect function_graph tracer") # Performance only
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2024-12-23 13:46:19 -05:00
|
|
|
disabled = atomic_read(&data->disabled);
|
|
|
|
|
if (likely(!disabled)) {
|
|
|
|
|
trace_ctx = tracing_gen_ctx();
|
2025-01-21 19:44:36 -05:00
|
|
|
__trace_graph_return(tr, trace, trace_ctx, calltime, rettime);
|
2009-07-29 18:59:58 +02:00
|
|
|
}
|
fgraph: Remove unnecessary disabling of interrupts and recursion
The function graph tracer disables interrupts as well as prevents
recursion via NMIs when recording the graph tracer code. There's no reason
to do this today. That disabling goes back to 2008 when the function graph
tracer was first introduced and recursion protection wasn't part of the
code.
Today, there's no reason to disable interrupts or prevent the code from
recursing as the infrastructure can easily handle it.
Before this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 4.240
Time: 4.236
Time: 4.106
Time: 4.014
Time: 4.314
Time: 3.830
Time: 4.063
Time: 4.323
Time: 3.763
Time: 3.727
Performance counter stats for '/work/c/hackbench 10' (10 runs):
33,937.20 msec task-clock # 7.008 CPUs utilized ( +- 1.85% )
18,220 context-switches # 536.874 /sec ( +- 6.41% )
624 cpu-migrations # 18.387 /sec ( +- 9.07% )
11,319 page-faults # 333.528 /sec ( +- 1.97% )
76,657,643,617 cycles # 2.259 GHz ( +- 0.40% )
141,403,302,768 instructions # 1.84 insn per cycle ( +- 0.37% )
25,518,463,888 branches # 751.932 M/sec ( +- 0.35% )
156,151,050 branch-misses # 0.61% of all branches ( +- 0.63% )
4.8423 +- 0.0892 seconds time elapsed ( +- 1.84% )
After this change:
~# echo function_graph > /sys/kernel/tracing/current_tracer
~# perf stat -r 10 ./hackbench 10
Time: 3.340
Time: 3.192
Time: 3.129
Time: 2.579
Time: 2.589
Time: 2.798
Time: 2.791
Time: 2.955
Time: 3.044
Time: 3.065
Performance counter stats for './hackbench 10' (10 runs):
24,416.30 msec task-clock # 6.996 CPUs utilized ( +- 2.74% )
16,764 context-switches # 686.590 /sec ( +- 5.85% )
469 cpu-migrations # 19.208 /sec ( +- 6.14% )
11,519 page-faults # 471.775 /sec ( +- 1.92% )
53,895,628,450 cycles # 2.207 GHz ( +- 0.52% )
105,552,664,638 instructions # 1.96 insn per cycle ( +- 0.47% )
17,808,672,667 branches # 729.376 M/sec ( +- 0.48% )
133,075,435 branch-misses # 0.75% of all branches ( +- 0.59% )
3.490 +- 0.112 seconds time elapsed ( +- 3.22% )
Also removed unneeded "unlikely()" around the retaddr code.
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Cc: Andrew Morton <akpm@linux-foundation.org>
Link: https://lore.kernel.org/20241223184941.204074053@goodmis.org
Fixes: 9cd2992f2d6c8 ("fgraph: Have set_graph_notrace only affect function_graph tracer") # Performance only
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2024-12-23 13:46:19 -05:00
|
|
|
preempt_enable_notrace();
|
2009-07-29 18:59:58 +02:00
|
|
|
}
|
|
|
|
|
|
2024-06-03 15:07:11 -04:00
|
|
|
static void trace_graph_thresh_return(struct ftrace_graph_ret *trace,
|
2024-12-26 14:12:09 +09:00
|
|
|
struct fgraph_ops *gops,
|
|
|
|
|
struct ftrace_regs *fregs)
|
2010-02-25 15:36:43 -08:00
|
|
|
{
|
2024-09-14 17:48:08 -04:00
|
|
|
struct fgraph_times *ftimes;
|
|
|
|
|
int size;
|
|
|
|
|
|
2024-06-03 15:07:20 -04:00
|
|
|
ftrace_graph_addr_finish(gops, trace);
|
tracing/fgraph: Fix set_graph_function from showing interrupts
The tracefs file set_graph_function is used to only function graph functions
that are listed in that file (or all functions if the file is empty). The
way this is implemented is that the function graph tracer looks at every
function, and if the current depth is zero and the function matches
something in the file then it will trace that function. When other functions
are called, the depth will be greater than zero (because the original
function will be at depth zero), and all functions will be traced where the
depth is greater than zero.
The issue is that when a function is first entered, and the handler that
checks this logic is called, the depth is set to zero. If an interrupt comes
in and a function in the interrupt handler is traced, its depth will be
greater than zero and it will automatically be traced, even if the original
function was not. But because the logic only looks at depth it may trace
interrupts when it should not be.
The recent design change of the function graph tracer to fix other bugs
caused the depth to be zero while the function graph callback handler is
being called for a longer time, widening the race of this happening. This
bug was actually there for a longer time, but because the race window was so
small it seldom happened. The Fixes tag below is for the commit that widen
the race window, because that commit belongs to a series that will also help
fix the original bug.
Cc: stable@kernel.org
Fixes: 39eb456dacb5 ("function_graph: Use new curr_ret_depth to manage depth instead of curr_ret_stack")
Reported-by: Joe Lawrence <joe.lawrence@redhat.com>
Tested-by: Joe Lawrence <joe.lawrence@redhat.com>
Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
2018-11-29 08:50:27 -05:00
|
|
|
|
2018-11-14 13:14:58 -05:00
|
|
|
if (trace_recursion_test(TRACE_GRAPH_NOTRACE_BIT)) {
|
|
|
|
|
trace_recursion_clear(TRACE_GRAPH_NOTRACE_BIT);
|
|
|
|
|
return;
|
|
|
|
|
}
|
|
|
|
|
|
2024-09-14 17:48:08 -04:00
|
|
|
ftimes = fgraph_retrieve_data(gops->idx, &size);
|
|
|
|
|
if (!ftimes)
|
|
|
|
|
return;
|
|
|
|
|
|
|
|
|
|
handle_nosleeptime(trace, ftimes, size);
|
|
|
|
|
|
2010-02-25 15:36:43 -08:00
|
|
|
if (tracing_thresh &&
|
2025-01-21 19:44:36 -05:00
|
|
|
(trace_clock_local() - ftimes->calltime < tracing_thresh))
|
2010-02-25 15:36:43 -08:00
|
|
|
return;
|
|
|
|
|
else
|
2024-12-26 14:12:09 +09:00
|
|
|
trace_graph_return(trace, gops, fregs);
|
2010-02-25 15:36:43 -08:00
|
|
|
}
|
|
|
|
|
|
2018-11-15 14:06:47 -05:00
|
|
|
static struct fgraph_ops funcgraph_ops = {
|
|
|
|
|
.entryfunc = &trace_graph_entry,
|
|
|
|
|
.retfunc = &trace_graph_return,
|
|
|
|
|
};
|
|
|
|
|
|
2024-06-03 15:07:16 -04:00
|
|
|
int allocate_fgraph_ops(struct trace_array *tr, struct ftrace_ops *ops)
|
2024-06-03 15:07:12 -04:00
|
|
|
{
|
|
|
|
|
struct fgraph_ops *gops;
|
|
|
|
|
|
|
|
|
|
gops = kzalloc(sizeof(*gops), GFP_KERNEL);
|
|
|
|
|
if (!gops)
|
|
|
|
|
return -ENOMEM;
|
|
|
|
|
|
|
|
|
|
gops->entryfunc = &trace_graph_entry;
|
|
|
|
|
gops->retfunc = &trace_graph_return;
|
|
|
|
|
|
|
|
|
|
tr->gops = gops;
|
|
|
|
|
gops->private = tr;
|
2024-06-03 15:07:16 -04:00
|
|
|
|
|
|
|
|
fgraph_init_ops(&gops->ops, ops);
|
|
|
|
|
|
2024-06-03 15:07:12 -04:00
|
|
|
return 0;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
void free_fgraph_ops(struct trace_array *tr)
|
|
|
|
|
{
|
|
|
|
|
kfree(tr->gops);
|
|
|
|
|
}
|
|
|
|
|
|
2024-06-03 15:07:16 -04:00
|
|
|
__init void init_array_fgraph_ops(struct trace_array *tr, struct ftrace_ops *ops)
|
2024-06-03 15:07:12 -04:00
|
|
|
{
|
|
|
|
|
tr->gops = &funcgraph_ops;
|
|
|
|
|
funcgraph_ops.private = tr;
|
2024-06-03 15:07:16 -04:00
|
|
|
fgraph_init_ops(&tr->gops->ops, ops);
|
2024-06-03 15:07:12 -04:00
|
|
|
}
|
|
|
|
|
|
2008-11-25 21:07:04 +01:00
|
|
|
static int graph_trace_init(struct trace_array *tr)
|
|
|
|
|
{
|
2009-07-29 18:59:58 +02:00
|
|
|
int ret;
|
|
|
|
|
|
2024-06-03 15:07:12 -04:00
|
|
|
tr->gops->entryfunc = trace_graph_entry;
|
|
|
|
|
|
2010-02-25 15:36:43 -08:00
|
|
|
if (tracing_thresh)
|
2024-06-03 15:07:12 -04:00
|
|
|
tr->gops->retfunc = trace_graph_thresh_return;
|
2010-02-25 15:36:43 -08:00
|
|
|
else
|
2024-06-03 15:07:12 -04:00
|
|
|
tr->gops->retfunc = trace_graph_return;
|
|
|
|
|
|
|
|
|
|
/* Make gops functions are visible before we start tracing */
|
|
|
|
|
smp_mb();
|
|
|
|
|
|
|
|
|
|
ret = register_ftrace_graph(tr->gops);
|
2008-11-26 00:16:26 -05:00
|
|
|
if (ret)
|
|
|
|
|
return ret;
|
|
|
|
|
tracing_start_cmdline_record();
|
|
|
|
|
|
|
|
|
|
return 0;
|
2008-11-25 21:07:04 +01:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
static void graph_trace_reset(struct trace_array *tr)
|
|
|
|
|
{
|
2008-11-26 00:16:26 -05:00
|
|
|
tracing_stop_cmdline_record();
|
2024-06-03 15:07:12 -04:00
|
|
|
unregister_ftrace_graph(tr->gops);
|
2008-11-25 21:07:04 +01:00
|
|
|
}
|
|
|
|
|
|
2014-07-18 18:07:49 -04:00
|
|
|
static int graph_trace_update_thresh(struct trace_array *tr)
|
2014-07-18 15:17:27 +04:00
|
|
|
{
|
|
|
|
|
graph_trace_reset(tr);
|
|
|
|
|
return graph_trace_init(tr);
|
|
|
|
|
}
|
|
|
|
|
|
2009-07-28 20:26:06 +08:00
|
|
|
static int max_bytes_for_cpu;
|
2008-11-28 00:42:46 +01:00
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
static void print_graph_cpu(struct trace_seq *s, int cpu)
|
2008-11-28 00:42:46 +01:00
|
|
|
{
|
2008-11-28 09:55:16 +01:00
|
|
|
/*
|
|
|
|
|
* Start with a space character - to make it stand out
|
|
|
|
|
* to the right a bit when trace output is pasted into
|
|
|
|
|
* email:
|
|
|
|
|
*/
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_printf(s, " %*d) ", max_bytes_for_cpu, cpu);
|
2008-11-28 00:42:46 +01:00
|
|
|
}
|
|
|
|
|
|
2008-12-03 02:30:37 +01:00
|
|
|
#define TRACE_GRAPH_PROCINFO_LENGTH 14
|
|
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
static void print_graph_proc(struct trace_seq *s, pid_t pid)
|
2008-12-03 02:30:37 +01:00
|
|
|
{
|
2009-03-16 19:20:15 -04:00
|
|
|
char comm[TASK_COMM_LEN];
|
2008-12-03 02:30:37 +01:00
|
|
|
/* sign + log10(MAX_INT) + '\0' */
|
|
|
|
|
char pid_str[11];
|
2009-03-16 19:20:15 -04:00
|
|
|
int spaces = 0;
|
|
|
|
|
int len;
|
|
|
|
|
int i;
|
2008-12-03 02:30:37 +01:00
|
|
|
|
2009-03-16 19:20:15 -04:00
|
|
|
trace_find_cmdline(pid, comm);
|
2008-12-03 02:30:37 +01:00
|
|
|
comm[7] = '\0';
|
|
|
|
|
sprintf(pid_str, "%d", pid);
|
|
|
|
|
|
|
|
|
|
/* 1 stands for the "-" character */
|
|
|
|
|
len = strlen(comm) + strlen(pid_str) + 1;
|
|
|
|
|
|
|
|
|
|
if (len < TRACE_GRAPH_PROCINFO_LENGTH)
|
|
|
|
|
spaces = TRACE_GRAPH_PROCINFO_LENGTH - len;
|
|
|
|
|
|
|
|
|
|
/* First spaces to align center */
|
2014-11-12 14:57:38 -05:00
|
|
|
for (i = 0; i < spaces / 2; i++)
|
|
|
|
|
trace_seq_putc(s, ' ');
|
2008-12-03 02:30:37 +01:00
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_printf(s, "%s-%s", comm, pid_str);
|
2008-12-03 02:30:37 +01:00
|
|
|
|
|
|
|
|
/* Last spaces to align center */
|
2014-11-12 14:57:38 -05:00
|
|
|
for (i = 0; i < spaces - (spaces / 2); i++)
|
|
|
|
|
trace_seq_putc(s, ' ');
|
2008-12-03 02:30:37 +01:00
|
|
|
}
|
|
|
|
|
|
2008-11-28 00:42:46 +01:00
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
static void print_graph_lat_fmt(struct trace_seq *s, struct trace_entry *entry)
|
2009-09-11 00:30:26 -04:00
|
|
|
{
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_putc(s, ' ');
|
|
|
|
|
trace_print_lat_fmt(s, entry);
|
2019-01-01 23:46:12 +08:00
|
|
|
trace_seq_puts(s, " | ");
|
2009-09-11 00:30:26 -04:00
|
|
|
}
|
|
|
|
|
|
2008-11-26 00:57:25 +01:00
|
|
|
/* If the pid changed since the last trace, output this event */
|
2014-11-12 14:57:38 -05:00
|
|
|
static void
|
2009-03-19 13:24:42 -04:00
|
|
|
verif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data)
|
2008-11-26 00:57:25 +01:00
|
|
|
{
|
2008-11-28 09:55:16 +01:00
|
|
|
pid_t prev_pid;
|
2009-01-22 17:04:53 -08:00
|
|
|
pid_t *last_pid;
|
2008-11-26 00:16:26 -05:00
|
|
|
|
2009-03-19 13:24:42 -04:00
|
|
|
if (!data)
|
2014-11-12 14:57:38 -05:00
|
|
|
return;
|
2008-11-26 00:57:25 +01:00
|
|
|
|
2009-11-24 13:57:38 +01:00
|
|
|
last_pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid);
|
2008-11-26 00:16:26 -05:00
|
|
|
|
2009-01-22 17:04:53 -08:00
|
|
|
if (*last_pid == pid)
|
2014-11-12 14:57:38 -05:00
|
|
|
return;
|
2009-01-22 17:04:53 -08:00
|
|
|
|
|
|
|
|
prev_pid = *last_pid;
|
|
|
|
|
*last_pid = pid;
|
|
|
|
|
|
|
|
|
|
if (prev_pid == -1)
|
2014-11-12 14:57:38 -05:00
|
|
|
return;
|
2008-11-28 09:55:16 +01:00
|
|
|
/*
|
|
|
|
|
* Context-switch trace line:
|
|
|
|
|
|
|
|
|
|
------------------------------------------
|
|
|
|
|
| 1) migration/0--1 => sshd-1755
|
|
|
|
|
------------------------------------------
|
|
|
|
|
|
|
|
|
|
*/
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_puts(s, " ------------------------------------------\n");
|
|
|
|
|
print_graph_cpu(s, cpu);
|
|
|
|
|
print_graph_proc(s, prev_pid);
|
|
|
|
|
trace_seq_puts(s, " => ");
|
|
|
|
|
print_graph_proc(s, pid);
|
|
|
|
|
trace_seq_puts(s, "\n ------------------------------------------\n\n");
|
2008-11-26 00:57:25 +01:00
|
|
|
}
|
|
|
|
|
|
2009-02-06 18:30:44 +01:00
|
|
|
static struct ftrace_graph_ret_entry *
|
|
|
|
|
get_return_for_leaf(struct trace_iterator *iter,
|
2008-11-27 01:46:33 +01:00
|
|
|
struct ftrace_graph_ent_entry *curr)
|
2008-11-26 00:57:25 +01:00
|
|
|
{
|
2009-11-24 13:57:38 +01:00
|
|
|
struct fgraph_data *data = iter->private;
|
|
|
|
|
struct ring_buffer_iter *ring_iter = NULL;
|
2008-11-27 01:46:33 +01:00
|
|
|
struct ring_buffer_event *event;
|
|
|
|
|
struct ftrace_graph_ret_entry *next;
|
|
|
|
|
|
2009-11-24 13:57:38 +01:00
|
|
|
/*
|
|
|
|
|
* If the previous output failed to write to the seq buffer,
|
|
|
|
|
* then we just reuse the data from before.
|
|
|
|
|
*/
|
|
|
|
|
if (data && data->failed) {
|
2024-09-14 20:29:12 -07:00
|
|
|
curr = &data->ent.ent;
|
2009-11-24 13:57:38 +01:00
|
|
|
next = &data->ret;
|
|
|
|
|
} else {
|
2008-11-27 01:46:33 +01:00
|
|
|
|
2012-06-27 20:46:14 -04:00
|
|
|
ring_iter = trace_buffer_iter(iter, iter->cpu);
|
2009-11-24 13:57:38 +01:00
|
|
|
|
|
|
|
|
/* First peek to compare current entry and the next one */
|
|
|
|
|
if (ring_iter)
|
|
|
|
|
event = ring_buffer_iter_peek(ring_iter, NULL);
|
|
|
|
|
else {
|
|
|
|
|
/*
|
|
|
|
|
* We need to consume the current entry to see
|
|
|
|
|
* the next one.
|
|
|
|
|
*/
|
2020-01-09 18:53:48 -05:00
|
|
|
ring_buffer_consume(iter->array_buffer->buffer, iter->cpu,
|
ring-buffer: Add place holder recording of dropped events
Currently, when the ring buffer drops events, it does not record
the fact that it did so. It does inform the writer that the event
was dropped by returning a NULL event, but it does not put in any
place holder where the event was dropped.
This is not a trivial thing to add because the ring buffer mostly
runs in overwrite (flight recorder) mode. That is, when the ring
buffer is full, new data will overwrite old data.
In a produce/consumer mode, where new data is simply dropped when
the ring buffer is full, it is trivial to add the placeholder
for dropped events. When there's more room to write new data, then
a special event can be added to notify the reader about the dropped
events.
But in overwrite mode, any new write can overwrite events. A place
holder can not be inserted into the ring buffer since there never
may be room. A reader could also come in at anytime and miss the
placeholder.
Luckily, the way the ring buffer works, the read side can find out
if events were lost or not, and how many events. Everytime a write
takes place, if it overwrites the header page (the next read) it
updates a "overrun" variable that keeps track of the number of
lost events. When a reader swaps out a page from the ring buffer,
it can record this number, perfom the swap, and then check to
see if the number changed, and take the diff if it has, which would be
the number of events dropped. This can be stored by the reader
and returned to callers of the reader.
Since the reader page swap will fail if the writer moved the head
page since the time the reader page set up the swap, this gives room
to record the overruns without worrying about races. If the reader
sets up the pages, records the overrun, than performs the swap,
if the swap succeeds, then the overrun variable has not been
updated since the setup before the swap.
For binary readers of the ring buffer, a flag is set in the header
of each sub page (sub buffer) of the ring buffer. This flag is embedded
in the size field of the data on the sub buffer, in the 31st bit (the size
can be 32 or 64 bits depending on the architecture), but only 27
bits needs to be used for the actual size (less actually).
We could add a new field in the sub buffer header to also record the
number of events dropped since the last read, but this will change the
format of the binary ring buffer a bit too much. Perhaps this change can
be made if the information on the number of events dropped is considered
important enough.
Note, the notification of dropped events is only used by consuming reads
or peeking at the ring buffer. Iterating over the ring buffer does not
keep this information because the necessary data is only available when
a page swap is made, and the iterator does not swap out pages.
Cc: Robert Richter <robert.richter@amd.com>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: Li Zefan <lizf@cn.fujitsu.com>
Cc: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: "Luis Claudio R. Goncalves" <lclaudio@uudg.org>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
2010-03-31 13:21:56 -04:00
|
|
|
NULL, NULL);
|
2020-01-09 18:53:48 -05:00
|
|
|
event = ring_buffer_peek(iter->array_buffer->buffer, iter->cpu,
|
ring-buffer: Add place holder recording of dropped events
Currently, when the ring buffer drops events, it does not record
the fact that it did so. It does inform the writer that the event
was dropped by returning a NULL event, but it does not put in any
place holder where the event was dropped.
This is not a trivial thing to add because the ring buffer mostly
runs in overwrite (flight recorder) mode. That is, when the ring
buffer is full, new data will overwrite old data.
In a produce/consumer mode, where new data is simply dropped when
the ring buffer is full, it is trivial to add the placeholder
for dropped events. When there's more room to write new data, then
a special event can be added to notify the reader about the dropped
events.
But in overwrite mode, any new write can overwrite events. A place
holder can not be inserted into the ring buffer since there never
may be room. A reader could also come in at anytime and miss the
placeholder.
Luckily, the way the ring buffer works, the read side can find out
if events were lost or not, and how many events. Everytime a write
takes place, if it overwrites the header page (the next read) it
updates a "overrun" variable that keeps track of the number of
lost events. When a reader swaps out a page from the ring buffer,
it can record this number, perfom the swap, and then check to
see if the number changed, and take the diff if it has, which would be
the number of events dropped. This can be stored by the reader
and returned to callers of the reader.
Since the reader page swap will fail if the writer moved the head
page since the time the reader page set up the swap, this gives room
to record the overruns without worrying about races. If the reader
sets up the pages, records the overrun, than performs the swap,
if the swap succeeds, then the overrun variable has not been
updated since the setup before the swap.
For binary readers of the ring buffer, a flag is set in the header
of each sub page (sub buffer) of the ring buffer. This flag is embedded
in the size field of the data on the sub buffer, in the 31st bit (the size
can be 32 or 64 bits depending on the architecture), but only 27
bits needs to be used for the actual size (less actually).
We could add a new field in the sub buffer header to also record the
number of events dropped since the last read, but this will change the
format of the binary ring buffer a bit too much. Perhaps this change can
be made if the information on the number of events dropped is considered
important enough.
Note, the notification of dropped events is only used by consuming reads
or peeking at the ring buffer. Iterating over the ring buffer does not
keep this information because the necessary data is only available when
a page swap is made, and the iterator does not swap out pages.
Cc: Robert Richter <robert.richter@amd.com>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: Li Zefan <lizf@cn.fujitsu.com>
Cc: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: "Luis Claudio R. Goncalves" <lclaudio@uudg.org>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
2010-03-31 13:21:56 -04:00
|
|
|
NULL, NULL);
|
2009-11-24 13:57:38 +01:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
if (!event)
|
|
|
|
|
return NULL;
|
|
|
|
|
|
|
|
|
|
next = ring_buffer_event_data(event);
|
|
|
|
|
|
|
|
|
|
if (data) {
|
|
|
|
|
/*
|
|
|
|
|
* Save current and next entries for later reference
|
|
|
|
|
* if the output fails.
|
|
|
|
|
*/
|
2024-09-14 20:29:12 -07:00
|
|
|
if (unlikely(curr->ent.type == TRACE_GRAPH_RETADDR_ENT))
|
|
|
|
|
data->ent.rent = *(struct fgraph_retaddr_ent_entry *)curr;
|
|
|
|
|
else
|
|
|
|
|
data->ent.ent = *curr;
|
2010-07-27 16:06:34 +08:00
|
|
|
/*
|
|
|
|
|
* If the next event is not a return type, then
|
|
|
|
|
* we only care about what type it is. Otherwise we can
|
|
|
|
|
* safely copy the entire event.
|
|
|
|
|
*/
|
|
|
|
|
if (next->ent.type == TRACE_GRAPH_RET)
|
|
|
|
|
data->ret = *next;
|
|
|
|
|
else
|
|
|
|
|
data->ret.ent.type = next->ent.type;
|
2009-11-24 13:57:38 +01:00
|
|
|
}
|
2009-02-06 18:30:44 +01:00
|
|
|
}
|
2008-11-27 01:46:33 +01:00
|
|
|
|
|
|
|
|
if (next->ent.type != TRACE_GRAPH_RET)
|
2009-02-06 18:30:44 +01:00
|
|
|
return NULL;
|
2008-11-27 01:46:33 +01:00
|
|
|
|
|
|
|
|
if (curr->ent.pid != next->ent.pid ||
|
|
|
|
|
curr->graph_ent.func != next->ret.func)
|
2009-02-06 18:30:44 +01:00
|
|
|
return NULL;
|
2008-11-27 01:46:33 +01:00
|
|
|
|
2009-02-06 18:30:44 +01:00
|
|
|
/* this is a leaf, now advance the iterator */
|
|
|
|
|
if (ring_iter)
|
2020-03-17 17:32:25 -04:00
|
|
|
ring_buffer_iter_advance(ring_iter);
|
2009-02-06 18:30:44 +01:00
|
|
|
|
|
|
|
|
return next;
|
2008-11-27 01:46:33 +01:00
|
|
|
}
|
|
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
static void print_graph_abs_time(u64 t, struct trace_seq *s)
|
2009-02-18 04:25:25 +01:00
|
|
|
{
|
|
|
|
|
unsigned long usecs_rem;
|
|
|
|
|
|
|
|
|
|
usecs_rem = do_div(t, NSEC_PER_SEC);
|
|
|
|
|
usecs_rem /= 1000;
|
|
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_printf(s, "%5lu.%06lu | ",
|
|
|
|
|
(unsigned long)t, usecs_rem);
|
2009-02-18 04:25:25 +01:00
|
|
|
}
|
|
|
|
|
|
2019-01-01 23:46:10 +08:00
|
|
|
static void
|
|
|
|
|
print_graph_rel_time(struct trace_iterator *iter, struct trace_seq *s)
|
|
|
|
|
{
|
|
|
|
|
unsigned long long usecs;
|
|
|
|
|
|
2020-01-09 18:53:48 -05:00
|
|
|
usecs = iter->ts - iter->array_buffer->time_start;
|
2019-01-01 23:46:10 +08:00
|
|
|
do_div(usecs, NSEC_PER_USEC);
|
|
|
|
|
|
|
|
|
|
trace_seq_printf(s, "%9llu us | ", usecs);
|
|
|
|
|
}
|
|
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
static void
|
2009-02-18 04:25:25 +01:00
|
|
|
print_graph_irq(struct trace_iterator *iter, unsigned long addr,
|
2010-04-02 19:01:21 +02:00
|
|
|
enum trace_type type, int cpu, pid_t pid, u32 flags)
|
2008-12-09 23:55:25 +01:00
|
|
|
{
|
2015-09-30 09:42:05 -04:00
|
|
|
struct trace_array *tr = iter->tr;
|
2009-02-18 04:25:25 +01:00
|
|
|
struct trace_seq *s = &iter->seq;
|
2014-11-06 15:25:09 -02:00
|
|
|
struct trace_entry *ent = iter->ent;
|
2008-12-09 23:55:25 +01:00
|
|
|
|
2024-08-13 13:11:06 -04:00
|
|
|
addr += iter->tr->text_delta;
|
|
|
|
|
|
2008-12-09 23:55:25 +01:00
|
|
|
if (addr < (unsigned long)__irqentry_text_start ||
|
|
|
|
|
addr >= (unsigned long)__irqentry_text_end)
|
2014-11-12 14:57:38 -05:00
|
|
|
return;
|
2008-12-09 23:55:25 +01:00
|
|
|
|
2015-09-30 09:42:05 -04:00
|
|
|
if (tr->trace_flags & TRACE_ITER_CONTEXT_INFO) {
|
2011-06-03 16:58:51 +02:00
|
|
|
/* Absolute time */
|
2014-11-12 14:57:38 -05:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
|
|
|
|
|
print_graph_abs_time(iter->ts, s);
|
2009-02-18 04:25:25 +01:00
|
|
|
|
2019-01-01 23:46:10 +08:00
|
|
|
/* Relative time */
|
|
|
|
|
if (flags & TRACE_GRAPH_PRINT_REL_TIME)
|
|
|
|
|
print_graph_rel_time(iter, s);
|
|
|
|
|
|
2011-06-03 16:58:51 +02:00
|
|
|
/* Cpu */
|
2014-11-12 14:57:38 -05:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_CPU)
|
|
|
|
|
print_graph_cpu(s, cpu);
|
2009-09-11 00:30:26 -04:00
|
|
|
|
2011-06-03 16:58:51 +02:00
|
|
|
/* Proc */
|
|
|
|
|
if (flags & TRACE_GRAPH_PRINT_PROC) {
|
2014-11-12 14:57:38 -05:00
|
|
|
print_graph_proc(s, pid);
|
|
|
|
|
trace_seq_puts(s, " | ");
|
2011-06-03 16:58:51 +02:00
|
|
|
}
|
2014-11-06 15:25:09 -02:00
|
|
|
|
|
|
|
|
/* Latency format */
|
2015-09-30 09:42:05 -04:00
|
|
|
if (tr->trace_flags & TRACE_ITER_LATENCY_FMT)
|
2014-11-12 14:57:38 -05:00
|
|
|
print_graph_lat_fmt(s, ent);
|
2009-01-22 17:04:53 -08:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
/* No overhead */
|
2015-09-30 09:42:05 -04:00
|
|
|
print_graph_duration(tr, 0, s, flags | FLAGS_FILL_START);
|
2009-01-22 17:04:53 -08:00
|
|
|
|
|
|
|
|
if (type == TRACE_GRAPH_ENT)
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_puts(s, "==========>");
|
2009-01-22 17:04:53 -08:00
|
|
|
else
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_puts(s, "<==========");
|
2009-01-22 17:04:53 -08:00
|
|
|
|
2015-09-30 09:42:05 -04:00
|
|
|
print_graph_duration(tr, 0, s, flags | FLAGS_FILL_END);
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_putc(s, '\n');
|
2008-12-09 23:55:25 +01:00
|
|
|
}
|
2008-11-27 01:46:33 +01:00
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
void
|
2009-03-23 23:12:58 -04:00
|
|
|
trace_print_graph_duration(unsigned long long duration, struct trace_seq *s)
|
2008-11-27 01:46:33 +01:00
|
|
|
{
|
|
|
|
|
unsigned long nsecs_rem = do_div(duration, 1000);
|
2008-12-03 02:32:12 +01:00
|
|
|
/* log10(ULONG_MAX) + '\0' */
|
2014-11-05 16:18:44 +09:00
|
|
|
char usecs_str[21];
|
2008-12-03 02:32:12 +01:00
|
|
|
char nsecs_str[5];
|
2014-11-12 14:57:38 -05:00
|
|
|
int len;
|
2008-12-03 02:32:12 +01:00
|
|
|
int i;
|
|
|
|
|
|
2014-11-05 16:18:44 +09:00
|
|
|
sprintf(usecs_str, "%lu", (unsigned long) duration);
|
2008-12-03 02:32:12 +01:00
|
|
|
|
|
|
|
|
/* Print msecs */
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_printf(s, "%s", usecs_str);
|
2008-12-03 02:32:12 +01:00
|
|
|
|
2014-11-05 16:18:44 +09:00
|
|
|
len = strlen(usecs_str);
|
2008-12-03 02:32:12 +01:00
|
|
|
|
|
|
|
|
/* Print nsecs (we don't want to exceed 7 numbers) */
|
|
|
|
|
if (len < 7) {
|
2010-09-29 10:08:23 +02:00
|
|
|
size_t slen = min_t(size_t, sizeof(nsecs_str), 8UL - len);
|
|
|
|
|
|
|
|
|
|
snprintf(nsecs_str, slen, "%03lu", nsecs_rem);
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_printf(s, ".%s", nsecs_str);
|
2015-07-16 21:58:52 -04:00
|
|
|
len += strlen(nsecs_str) + 1;
|
2008-12-03 02:32:12 +01:00
|
|
|
}
|
|
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_puts(s, " us ");
|
2008-12-03 02:32:12 +01:00
|
|
|
|
|
|
|
|
/* Print remaining spaces to fit the row's width */
|
2015-07-16 21:58:52 -04:00
|
|
|
for (i = len; i < 8; i++)
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_putc(s, ' ');
|
2009-03-23 23:12:58 -04:00
|
|
|
}
|
|
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
static void
|
2015-09-30 09:42:05 -04:00
|
|
|
print_graph_duration(struct trace_array *tr, unsigned long long duration,
|
|
|
|
|
struct trace_seq *s, u32 flags)
|
2009-03-23 23:12:58 -04:00
|
|
|
{
|
2011-06-03 16:58:51 +02:00
|
|
|
if (!(flags & TRACE_GRAPH_PRINT_DURATION) ||
|
2015-09-30 09:42:05 -04:00
|
|
|
!(tr->trace_flags & TRACE_ITER_CONTEXT_INFO))
|
2014-11-12 14:57:38 -05:00
|
|
|
return;
|
2011-06-03 16:58:48 +02:00
|
|
|
|
|
|
|
|
/* No real adata, just filling the column with spaces */
|
2013-11-06 14:50:06 -05:00
|
|
|
switch (flags & TRACE_GRAPH_PRINT_FILL_MASK) {
|
|
|
|
|
case FLAGS_FILL_FULL:
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_puts(s, " | ");
|
|
|
|
|
return;
|
2013-11-06 14:50:06 -05:00
|
|
|
case FLAGS_FILL_START:
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_puts(s, " ");
|
|
|
|
|
return;
|
2013-11-06 14:50:06 -05:00
|
|
|
case FLAGS_FILL_END:
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_puts(s, " |");
|
|
|
|
|
return;
|
2011-06-03 16:58:48 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
/* Signal a overhead of time execution to the output */
|
2014-11-24 09:34:19 +09:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_OVERHEAD)
|
|
|
|
|
trace_seq_printf(s, "%c ", trace_find_mark(duration));
|
|
|
|
|
else
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_puts(s, " ");
|
2011-06-03 16:58:48 +02:00
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_print_graph_duration(duration, s);
|
|
|
|
|
trace_seq_puts(s, "| ");
|
2008-11-27 01:46:33 +01:00
|
|
|
}
|
|
|
|
|
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
#ifdef CONFIG_FUNCTION_GRAPH_RETVAL
|
|
|
|
|
#define __TRACE_GRAPH_PRINT_RETVAL TRACE_GRAPH_PRINT_RETVAL
|
2024-09-14 20:29:12 -07:00
|
|
|
#else
|
|
|
|
|
#define __TRACE_GRAPH_PRINT_RETVAL 0
|
|
|
|
|
#endif
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
|
2024-09-14 20:29:12 -07:00
|
|
|
#ifdef CONFIG_FUNCTION_GRAPH_RETADDR
|
|
|
|
|
#define __TRACE_GRAPH_PRINT_RETADDR TRACE_GRAPH_PRINT_RETADDR
|
|
|
|
|
static void print_graph_retaddr(struct trace_seq *s, struct fgraph_retaddr_ent_entry *entry,
|
|
|
|
|
u32 trace_flags, bool comment)
|
|
|
|
|
{
|
|
|
|
|
if (comment)
|
|
|
|
|
trace_seq_puts(s, " /*");
|
|
|
|
|
|
|
|
|
|
trace_seq_puts(s, " <-");
|
|
|
|
|
seq_print_ip_sym(s, entry->graph_ent.retaddr, trace_flags | TRACE_ITER_SYM_OFFSET);
|
|
|
|
|
|
|
|
|
|
if (comment)
|
|
|
|
|
trace_seq_puts(s, " */");
|
|
|
|
|
}
|
|
|
|
|
#else
|
|
|
|
|
#define __TRACE_GRAPH_PRINT_RETADDR 0
|
|
|
|
|
#define print_graph_retaddr(_seq, _entry, _tflags, _comment) do { } while (0)
|
|
|
|
|
#endif
|
|
|
|
|
|
|
|
|
|
#if defined(CONFIG_FUNCTION_GRAPH_RETVAL) || defined(CONFIG_FUNCTION_GRAPH_RETADDR)
|
|
|
|
|
|
|
|
|
|
static void print_graph_retval(struct trace_seq *s, struct ftrace_graph_ent_entry *entry,
|
|
|
|
|
struct ftrace_graph_ret *graph_ret, void *func,
|
|
|
|
|
u32 opt_flags, u32 trace_flags)
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
{
|
|
|
|
|
unsigned long err_code = 0;
|
2024-09-14 20:29:12 -07:00
|
|
|
unsigned long retval = 0;
|
|
|
|
|
bool print_retaddr = false;
|
|
|
|
|
bool print_retval = false;
|
|
|
|
|
bool hex_format = !!(opt_flags & TRACE_GRAPH_PRINT_RETVAL_HEX);
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
|
2024-09-14 20:29:12 -07:00
|
|
|
#ifdef CONFIG_FUNCTION_GRAPH_RETVAL
|
|
|
|
|
retval = graph_ret->retval;
|
|
|
|
|
print_retval = !!(opt_flags & TRACE_GRAPH_PRINT_RETVAL);
|
|
|
|
|
#endif
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
|
2024-09-14 20:29:12 -07:00
|
|
|
#ifdef CONFIG_FUNCTION_GRAPH_RETADDR
|
|
|
|
|
print_retaddr = !!(opt_flags & TRACE_GRAPH_PRINT_RETADDR);
|
|
|
|
|
#endif
|
|
|
|
|
|
|
|
|
|
if (print_retval && retval && !hex_format) {
|
|
|
|
|
/* Check if the return value matches the negative format */
|
|
|
|
|
if (IS_ENABLED(CONFIG_64BIT) && (retval & BIT(31)) &&
|
|
|
|
|
(((u64)retval) >> 32) == 0) {
|
|
|
|
|
err_code = sign_extend64(retval, 31);
|
|
|
|
|
} else {
|
|
|
|
|
err_code = retval;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
if (!IS_ERR_VALUE(err_code))
|
|
|
|
|
err_code = 0;
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
}
|
|
|
|
|
|
2024-09-14 20:29:12 -07:00
|
|
|
if (entry) {
|
|
|
|
|
if (entry->ent.type != TRACE_GRAPH_RETADDR_ENT)
|
|
|
|
|
print_retaddr = false;
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
|
2024-09-14 20:29:12 -07:00
|
|
|
trace_seq_printf(s, "%ps();", func);
|
|
|
|
|
if (print_retval || print_retaddr)
|
|
|
|
|
trace_seq_puts(s, " /*");
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
else
|
2024-09-14 20:29:12 -07:00
|
|
|
trace_seq_putc(s, '\n');
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
} else {
|
2024-09-14 20:29:12 -07:00
|
|
|
print_retaddr = false;
|
|
|
|
|
trace_seq_printf(s, "} /* %ps", func);
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
}
|
2024-09-14 20:29:12 -07:00
|
|
|
|
|
|
|
|
if (print_retaddr)
|
|
|
|
|
print_graph_retaddr(s, (struct fgraph_retaddr_ent_entry *)entry,
|
|
|
|
|
trace_flags, false);
|
|
|
|
|
|
|
|
|
|
if (print_retval) {
|
|
|
|
|
if (hex_format || (err_code == 0))
|
|
|
|
|
trace_seq_printf(s, " ret=0x%lx", retval);
|
|
|
|
|
else
|
|
|
|
|
trace_seq_printf(s, " ret=%ld", err_code);
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
if (!entry || print_retval || print_retaddr)
|
|
|
|
|
trace_seq_puts(s, " */\n");
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
#else
|
|
|
|
|
|
2024-09-14 20:29:12 -07:00
|
|
|
#define print_graph_retval(_seq, _ent, _ret, _func, _opt_flags, _trace_flags) do {} while (0)
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
|
|
|
|
|
#endif
|
|
|
|
|
|
2008-11-27 01:46:33 +01:00
|
|
|
/* Case of a leaf function on its call entry */
|
|
|
|
|
static enum print_line_t
|
|
|
|
|
print_graph_entry_leaf(struct trace_iterator *iter,
|
2009-02-06 18:30:44 +01:00
|
|
|
struct ftrace_graph_ent_entry *entry,
|
2010-04-02 19:01:21 +02:00
|
|
|
struct ftrace_graph_ret_entry *ret_entry,
|
|
|
|
|
struct trace_seq *s, u32 flags)
|
2008-11-27 01:46:33 +01:00
|
|
|
{
|
2009-03-19 13:24:42 -04:00
|
|
|
struct fgraph_data *data = iter->private;
|
2015-09-30 09:42:05 -04:00
|
|
|
struct trace_array *tr = iter->tr;
|
2008-11-27 01:46:33 +01:00
|
|
|
struct ftrace_graph_ret *graph_ret;
|
|
|
|
|
struct ftrace_graph_ent *call;
|
|
|
|
|
unsigned long long duration;
|
2024-08-13 13:11:06 -04:00
|
|
|
unsigned long func;
|
2018-01-31 23:48:49 +08:00
|
|
|
int cpu = iter->cpu;
|
2008-11-28 00:42:46 +01:00
|
|
|
int i;
|
2008-11-26 00:57:25 +01:00
|
|
|
|
2008-11-27 01:46:33 +01:00
|
|
|
graph_ret = &ret_entry->ret;
|
|
|
|
|
call = &entry->graph_ent;
|
2025-01-21 19:44:36 -05:00
|
|
|
duration = ret_entry->rettime - ret_entry->calltime;
|
2008-11-26 00:16:27 -05:00
|
|
|
|
2024-08-13 13:11:06 -04:00
|
|
|
func = call->func + iter->tr->text_delta;
|
|
|
|
|
|
2009-03-19 13:24:42 -04:00
|
|
|
if (data) {
|
2010-02-26 17:08:16 -05:00
|
|
|
struct fgraph_cpu_data *cpu_data;
|
|
|
|
|
|
|
|
|
|
cpu_data = per_cpu_ptr(data->cpu_data, cpu);
|
2009-03-19 13:24:42 -04:00
|
|
|
|
|
|
|
|
/*
|
|
|
|
|
* Comments display at + 1 to depth. Since
|
|
|
|
|
* this is a leaf function, keep the comments
|
|
|
|
|
* equal to this depth.
|
|
|
|
|
*/
|
2010-02-26 17:08:16 -05:00
|
|
|
cpu_data->depth = call->depth - 1;
|
|
|
|
|
|
|
|
|
|
/* No need to keep this function around for this depth */
|
2016-12-08 20:54:49 -05:00
|
|
|
if (call->depth < FTRACE_RETFUNC_DEPTH &&
|
|
|
|
|
!WARN_ON_ONCE(call->depth < 0))
|
2010-02-26 17:08:16 -05:00
|
|
|
cpu_data->enter_funcs[call->depth] = 0;
|
2009-03-19 13:24:42 -04:00
|
|
|
}
|
|
|
|
|
|
2011-06-03 16:58:48 +02:00
|
|
|
/* Overhead and duration */
|
2015-09-30 09:42:05 -04:00
|
|
|
print_graph_duration(tr, duration, s, flags);
|
2008-11-28 00:42:46 +01:00
|
|
|
|
2008-11-27 01:46:33 +01:00
|
|
|
/* Function */
|
2014-11-12 14:57:38 -05:00
|
|
|
for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++)
|
|
|
|
|
trace_seq_putc(s, ' ');
|
2008-11-26 00:57:25 +01:00
|
|
|
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
/*
|
2024-09-14 20:29:12 -07:00
|
|
|
* Write out the function return value or return address
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
*/
|
2024-09-14 20:29:12 -07:00
|
|
|
if (flags & (__TRACE_GRAPH_PRINT_RETVAL | __TRACE_GRAPH_PRINT_RETADDR)) {
|
|
|
|
|
print_graph_retval(s, entry, graph_ret,
|
|
|
|
|
(void *)graph_ret->func + iter->tr->text_delta,
|
|
|
|
|
flags, tr->trace_flags);
|
|
|
|
|
} else {
|
2024-08-13 13:11:06 -04:00
|
|
|
trace_seq_printf(s, "%ps();\n", (void *)func);
|
2024-09-14 20:29:12 -07:00
|
|
|
}
|
2008-11-27 01:46:33 +01:00
|
|
|
|
2018-01-31 23:48:49 +08:00
|
|
|
print_graph_irq(iter, graph_ret->func, TRACE_GRAPH_RET,
|
|
|
|
|
cpu, iter->ent->pid, flags);
|
|
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
return trace_handle_return(s);
|
2008-11-26 00:57:25 +01:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
static enum print_line_t
|
2009-03-19 13:24:42 -04:00
|
|
|
print_graph_entry_nested(struct trace_iterator *iter,
|
|
|
|
|
struct ftrace_graph_ent_entry *entry,
|
2010-04-02 19:01:21 +02:00
|
|
|
struct trace_seq *s, int cpu, u32 flags)
|
2008-11-26 00:57:25 +01:00
|
|
|
{
|
2008-11-27 01:46:33 +01:00
|
|
|
struct ftrace_graph_ent *call = &entry->graph_ent;
|
2009-03-19 13:24:42 -04:00
|
|
|
struct fgraph_data *data = iter->private;
|
2015-09-30 09:42:05 -04:00
|
|
|
struct trace_array *tr = iter->tr;
|
2024-08-13 13:11:06 -04:00
|
|
|
unsigned long func;
|
2009-03-19 13:24:42 -04:00
|
|
|
int i;
|
|
|
|
|
|
|
|
|
|
if (data) {
|
2010-02-26 17:08:16 -05:00
|
|
|
struct fgraph_cpu_data *cpu_data;
|
2009-03-19 13:24:42 -04:00
|
|
|
int cpu = iter->cpu;
|
|
|
|
|
|
2010-02-26 17:08:16 -05:00
|
|
|
cpu_data = per_cpu_ptr(data->cpu_data, cpu);
|
|
|
|
|
cpu_data->depth = call->depth;
|
|
|
|
|
|
|
|
|
|
/* Save this function pointer to see if the exit matches */
|
2016-12-08 20:54:49 -05:00
|
|
|
if (call->depth < FTRACE_RETFUNC_DEPTH &&
|
|
|
|
|
!WARN_ON_ONCE(call->depth < 0))
|
2010-02-26 17:08:16 -05:00
|
|
|
cpu_data->enter_funcs[call->depth] = call->func;
|
2009-03-19 13:24:42 -04:00
|
|
|
}
|
2008-11-27 01:46:33 +01:00
|
|
|
|
2009-01-22 17:04:53 -08:00
|
|
|
/* No time */
|
2015-09-30 09:42:05 -04:00
|
|
|
print_graph_duration(tr, 0, s, flags | FLAGS_FILL_FULL);
|
2008-12-09 23:55:25 +01:00
|
|
|
|
2008-11-27 01:46:33 +01:00
|
|
|
/* Function */
|
2014-11-12 14:57:38 -05:00
|
|
|
for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++)
|
|
|
|
|
trace_seq_putc(s, ' ');
|
2008-11-27 01:46:33 +01:00
|
|
|
|
2024-08-13 13:11:06 -04:00
|
|
|
func = call->func + iter->tr->text_delta;
|
|
|
|
|
|
2024-09-14 20:29:12 -07:00
|
|
|
trace_seq_printf(s, "%ps() {", (void *)func);
|
|
|
|
|
if (flags & __TRACE_GRAPH_PRINT_RETADDR &&
|
|
|
|
|
entry->ent.type == TRACE_GRAPH_RETADDR_ENT)
|
|
|
|
|
print_graph_retaddr(s, (struct fgraph_retaddr_ent_entry *)entry,
|
|
|
|
|
tr->trace_flags, true);
|
|
|
|
|
trace_seq_putc(s, '\n');
|
2014-11-12 14:57:38 -05:00
|
|
|
|
|
|
|
|
if (trace_seq_has_overflowed(s))
|
2008-11-27 01:46:33 +01:00
|
|
|
return TRACE_TYPE_PARTIAL_LINE;
|
|
|
|
|
|
2009-02-06 18:30:44 +01:00
|
|
|
/*
|
|
|
|
|
* we already consumed the current entry to check the next one
|
|
|
|
|
* and see if this is a leaf.
|
|
|
|
|
*/
|
|
|
|
|
return TRACE_TYPE_NO_CONSUME;
|
2008-11-27 01:46:33 +01:00
|
|
|
}
|
|
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
static void
|
2009-03-19 11:29:23 -04:00
|
|
|
print_graph_prologue(struct trace_iterator *iter, struct trace_seq *s,
|
2010-04-02 19:01:21 +02:00
|
|
|
int type, unsigned long addr, u32 flags)
|
2008-11-27 01:46:33 +01:00
|
|
|
{
|
2009-03-19 13:24:42 -04:00
|
|
|
struct fgraph_data *data = iter->private;
|
2008-11-27 01:46:33 +01:00
|
|
|
struct trace_entry *ent = iter->ent;
|
2015-09-30 09:42:05 -04:00
|
|
|
struct trace_array *tr = iter->tr;
|
2009-03-19 11:29:23 -04:00
|
|
|
int cpu = iter->cpu;
|
2008-11-26 00:57:25 +01:00
|
|
|
|
2008-11-28 00:42:46 +01:00
|
|
|
/* Pid */
|
2014-11-12 14:57:38 -05:00
|
|
|
verif_pid(s, ent->pid, cpu, data);
|
2008-11-26 00:16:27 -05:00
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
if (type)
|
2009-03-19 11:29:23 -04:00
|
|
|
/* Interrupt */
|
2014-11-12 14:57:38 -05:00
|
|
|
print_graph_irq(iter, addr, type, cpu, ent->pid, flags);
|
2009-01-22 17:04:53 -08:00
|
|
|
|
2015-09-30 09:42:05 -04:00
|
|
|
if (!(tr->trace_flags & TRACE_ITER_CONTEXT_INFO))
|
2014-11-12 14:57:38 -05:00
|
|
|
return;
|
2011-06-03 16:58:51 +02:00
|
|
|
|
2009-01-22 17:04:53 -08:00
|
|
|
/* Absolute time */
|
2014-11-12 14:57:38 -05:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
|
|
|
|
|
print_graph_abs_time(iter->ts, s);
|
2009-01-22 17:04:53 -08:00
|
|
|
|
2019-01-01 23:46:10 +08:00
|
|
|
/* Relative time */
|
|
|
|
|
if (flags & TRACE_GRAPH_PRINT_REL_TIME)
|
|
|
|
|
print_graph_rel_time(iter, s);
|
|
|
|
|
|
2008-11-28 00:42:46 +01:00
|
|
|
/* Cpu */
|
2014-11-12 14:57:38 -05:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_CPU)
|
|
|
|
|
print_graph_cpu(s, cpu);
|
2008-12-03 02:30:37 +01:00
|
|
|
|
|
|
|
|
/* Proc */
|
2010-04-02 19:01:21 +02:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_PROC) {
|
2014-11-12 14:57:38 -05:00
|
|
|
print_graph_proc(s, ent->pid);
|
|
|
|
|
trace_seq_puts(s, " | ");
|
2008-11-28 00:42:46 +01:00
|
|
|
}
|
2008-11-26 00:57:25 +01:00
|
|
|
|
2009-09-11 00:30:26 -04:00
|
|
|
/* Latency format */
|
2015-09-30 09:42:05 -04:00
|
|
|
if (tr->trace_flags & TRACE_ITER_LATENCY_FMT)
|
2014-11-12 14:57:38 -05:00
|
|
|
print_graph_lat_fmt(s, ent);
|
2009-09-11 00:30:26 -04:00
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
return;
|
2009-03-19 11:29:23 -04:00
|
|
|
}
|
|
|
|
|
|
2010-09-07 16:53:44 +02:00
|
|
|
/*
|
|
|
|
|
* Entry check for irq code
|
|
|
|
|
*
|
|
|
|
|
* returns 1 if
|
|
|
|
|
* - we are inside irq code
|
2011-03-30 22:57:33 -03:00
|
|
|
* - we just entered irq code
|
2010-09-07 16:53:44 +02:00
|
|
|
*
|
2021-03-23 18:49:35 +01:00
|
|
|
* returns 0 if
|
2010-09-07 16:53:44 +02:00
|
|
|
* - funcgraph-interrupts option is set
|
|
|
|
|
* - we are not inside irq code
|
|
|
|
|
*/
|
|
|
|
|
static int
|
|
|
|
|
check_irq_entry(struct trace_iterator *iter, u32 flags,
|
|
|
|
|
unsigned long addr, int depth)
|
|
|
|
|
{
|
|
|
|
|
int cpu = iter->cpu;
|
2010-09-24 17:41:02 +02:00
|
|
|
int *depth_irq;
|
2010-09-07 16:53:44 +02:00
|
|
|
struct fgraph_data *data = iter->private;
|
|
|
|
|
|
2024-08-13 13:11:06 -04:00
|
|
|
addr += iter->tr->text_delta;
|
|
|
|
|
|
2010-09-24 17:41:02 +02:00
|
|
|
/*
|
|
|
|
|
* If we are either displaying irqs, or we got called as
|
|
|
|
|
* a graph event and private data does not exist,
|
|
|
|
|
* then we bypass the irq check.
|
|
|
|
|
*/
|
|
|
|
|
if ((flags & TRACE_GRAPH_PRINT_IRQS) ||
|
|
|
|
|
(!data))
|
2010-09-07 16:53:44 +02:00
|
|
|
return 0;
|
|
|
|
|
|
2010-09-24 17:41:02 +02:00
|
|
|
depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq);
|
|
|
|
|
|
2010-09-07 16:53:44 +02:00
|
|
|
/*
|
|
|
|
|
* We are inside the irq code
|
|
|
|
|
*/
|
|
|
|
|
if (*depth_irq >= 0)
|
|
|
|
|
return 1;
|
|
|
|
|
|
|
|
|
|
if ((addr < (unsigned long)__irqentry_text_start) ||
|
|
|
|
|
(addr >= (unsigned long)__irqentry_text_end))
|
|
|
|
|
return 0;
|
|
|
|
|
|
|
|
|
|
/*
|
|
|
|
|
* We are entering irq code.
|
|
|
|
|
*/
|
|
|
|
|
*depth_irq = depth;
|
|
|
|
|
return 1;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
/*
|
|
|
|
|
* Return check for irq code
|
|
|
|
|
*
|
|
|
|
|
* returns 1 if
|
|
|
|
|
* - we are inside irq code
|
|
|
|
|
* - we just left irq code
|
|
|
|
|
*
|
|
|
|
|
* returns 0 if
|
|
|
|
|
* - funcgraph-interrupts option is set
|
|
|
|
|
* - we are not inside irq code
|
|
|
|
|
*/
|
|
|
|
|
static int
|
|
|
|
|
check_irq_return(struct trace_iterator *iter, u32 flags, int depth)
|
|
|
|
|
{
|
|
|
|
|
int cpu = iter->cpu;
|
2010-09-24 17:41:02 +02:00
|
|
|
int *depth_irq;
|
2010-09-07 16:53:44 +02:00
|
|
|
struct fgraph_data *data = iter->private;
|
|
|
|
|
|
2010-09-24 17:41:02 +02:00
|
|
|
/*
|
|
|
|
|
* If we are either displaying irqs, or we got called as
|
|
|
|
|
* a graph event and private data does not exist,
|
|
|
|
|
* then we bypass the irq check.
|
|
|
|
|
*/
|
|
|
|
|
if ((flags & TRACE_GRAPH_PRINT_IRQS) ||
|
|
|
|
|
(!data))
|
2010-09-07 16:53:44 +02:00
|
|
|
return 0;
|
|
|
|
|
|
2010-09-24 17:41:02 +02:00
|
|
|
depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq);
|
|
|
|
|
|
2010-09-07 16:53:44 +02:00
|
|
|
/*
|
|
|
|
|
* We are not inside the irq code.
|
|
|
|
|
*/
|
|
|
|
|
if (*depth_irq == -1)
|
|
|
|
|
return 0;
|
|
|
|
|
|
|
|
|
|
/*
|
|
|
|
|
* We are inside the irq code, and this is returning entry.
|
|
|
|
|
* Let's not trace it and clear the entry depth, since
|
|
|
|
|
* we are out of irq code.
|
|
|
|
|
*
|
|
|
|
|
* This condition ensures that we 'leave the irq code' once
|
|
|
|
|
* we are out of the entry depth. Thus protecting us from
|
|
|
|
|
* the RETURN entry loss.
|
|
|
|
|
*/
|
|
|
|
|
if (*depth_irq >= depth) {
|
|
|
|
|
*depth_irq = -1;
|
|
|
|
|
return 1;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
/*
|
|
|
|
|
* We are inside the irq code, and this is not the entry.
|
|
|
|
|
*/
|
|
|
|
|
return 1;
|
|
|
|
|
}
|
|
|
|
|
|
2009-03-19 11:29:23 -04:00
|
|
|
static enum print_line_t
|
|
|
|
|
print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
|
2010-04-02 19:01:21 +02:00
|
|
|
struct trace_iterator *iter, u32 flags)
|
2009-03-19 11:29:23 -04:00
|
|
|
{
|
2009-11-24 13:57:38 +01:00
|
|
|
struct fgraph_data *data = iter->private;
|
2009-03-19 11:29:23 -04:00
|
|
|
struct ftrace_graph_ent *call = &field->graph_ent;
|
|
|
|
|
struct ftrace_graph_ret_entry *leaf_ret;
|
2009-11-24 13:57:38 +01:00
|
|
|
static enum print_line_t ret;
|
|
|
|
|
int cpu = iter->cpu;
|
2009-03-19 11:29:23 -04:00
|
|
|
|
2010-09-07 16:53:44 +02:00
|
|
|
if (check_irq_entry(iter, flags, call->func, call->depth))
|
|
|
|
|
return TRACE_TYPE_HANDLED;
|
|
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
print_graph_prologue(iter, s, TRACE_GRAPH_ENT, call->func, flags);
|
2009-03-19 11:29:23 -04:00
|
|
|
|
2009-02-06 18:30:44 +01:00
|
|
|
leaf_ret = get_return_for_leaf(iter, field);
|
|
|
|
|
if (leaf_ret)
|
2010-04-02 19:01:21 +02:00
|
|
|
ret = print_graph_entry_leaf(iter, field, leaf_ret, s, flags);
|
2008-11-27 01:46:33 +01:00
|
|
|
else
|
2010-04-02 19:01:21 +02:00
|
|
|
ret = print_graph_entry_nested(iter, field, s, cpu, flags);
|
2008-11-27 01:46:33 +01:00
|
|
|
|
2009-11-24 13:57:38 +01:00
|
|
|
if (data) {
|
|
|
|
|
/*
|
|
|
|
|
* If we failed to write our output, then we need to make
|
|
|
|
|
* note of it. Because we already consumed our entry.
|
|
|
|
|
*/
|
|
|
|
|
if (s->full) {
|
|
|
|
|
data->failed = 1;
|
|
|
|
|
data->cpu = cpu;
|
|
|
|
|
} else
|
|
|
|
|
data->failed = 0;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
return ret;
|
2008-11-27 01:46:33 +01:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
static enum print_line_t
|
2025-01-21 19:44:36 -05:00
|
|
|
print_graph_return(struct ftrace_graph_ret_entry *retentry, struct trace_seq *s,
|
2010-04-02 19:01:21 +02:00
|
|
|
struct trace_entry *ent, struct trace_iterator *iter,
|
|
|
|
|
u32 flags)
|
2008-11-27 01:46:33 +01:00
|
|
|
{
|
2025-01-21 19:44:36 -05:00
|
|
|
struct ftrace_graph_ret *trace = &retentry->ret;
|
|
|
|
|
u64 calltime = retentry->calltime;
|
|
|
|
|
u64 rettime = retentry->rettime;
|
|
|
|
|
unsigned long long duration = rettime - calltime;
|
2009-03-19 13:24:42 -04:00
|
|
|
struct fgraph_data *data = iter->private;
|
2015-09-30 09:42:05 -04:00
|
|
|
struct trace_array *tr = iter->tr;
|
2024-08-13 13:11:06 -04:00
|
|
|
unsigned long func;
|
2009-03-19 13:24:42 -04:00
|
|
|
pid_t pid = ent->pid;
|
|
|
|
|
int cpu = iter->cpu;
|
2010-02-26 17:08:16 -05:00
|
|
|
int func_match = 1;
|
2009-03-19 13:24:42 -04:00
|
|
|
int i;
|
|
|
|
|
|
2024-08-13 13:11:06 -04:00
|
|
|
func = trace->func + iter->tr->text_delta;
|
|
|
|
|
|
2010-09-07 16:53:44 +02:00
|
|
|
if (check_irq_return(iter, flags, trace->depth))
|
|
|
|
|
return TRACE_TYPE_HANDLED;
|
|
|
|
|
|
2009-03-19 13:24:42 -04:00
|
|
|
if (data) {
|
2010-02-26 17:08:16 -05:00
|
|
|
struct fgraph_cpu_data *cpu_data;
|
|
|
|
|
int cpu = iter->cpu;
|
|
|
|
|
|
|
|
|
|
cpu_data = per_cpu_ptr(data->cpu_data, cpu);
|
2009-03-19 13:24:42 -04:00
|
|
|
|
|
|
|
|
/*
|
|
|
|
|
* Comments display at + 1 to depth. This is the
|
|
|
|
|
* return from a function, we now want the comments
|
|
|
|
|
* to display at the same level of the bracket.
|
|
|
|
|
*/
|
2010-02-26 17:08:16 -05:00
|
|
|
cpu_data->depth = trace->depth - 1;
|
|
|
|
|
|
2016-12-08 20:54:49 -05:00
|
|
|
if (trace->depth < FTRACE_RETFUNC_DEPTH &&
|
|
|
|
|
!WARN_ON_ONCE(trace->depth < 0)) {
|
2010-02-26 17:08:16 -05:00
|
|
|
if (cpu_data->enter_funcs[trace->depth] != trace->func)
|
|
|
|
|
func_match = 0;
|
|
|
|
|
cpu_data->enter_funcs[trace->depth] = 0;
|
|
|
|
|
}
|
2009-03-19 13:24:42 -04:00
|
|
|
}
|
2008-11-27 01:46:33 +01:00
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
print_graph_prologue(iter, s, 0, 0, flags);
|
2008-11-27 01:46:33 +01:00
|
|
|
|
2011-06-03 16:58:48 +02:00
|
|
|
/* Overhead and duration */
|
2015-09-30 09:42:05 -04:00
|
|
|
print_graph_duration(tr, duration, s, flags);
|
2008-11-28 00:42:46 +01:00
|
|
|
|
2008-11-27 01:46:33 +01:00
|
|
|
/* Closing brace */
|
2014-11-12 14:57:38 -05:00
|
|
|
for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++)
|
|
|
|
|
trace_seq_putc(s, ' ');
|
2008-11-26 00:57:25 +01:00
|
|
|
|
2010-02-26 17:08:16 -05:00
|
|
|
/*
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
* Always write out the function name and its return value if the
|
2024-09-14 20:29:12 -07:00
|
|
|
* funcgraph-retval option is enabled.
|
2010-02-26 17:08:16 -05:00
|
|
|
*/
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
if (flags & __TRACE_GRAPH_PRINT_RETVAL) {
|
2024-09-14 20:29:12 -07:00
|
|
|
print_graph_retval(s, NULL, trace, (void *)func, flags, tr->trace_flags);
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
} else {
|
|
|
|
|
/*
|
|
|
|
|
* If the return function does not have a matching entry,
|
|
|
|
|
* then the entry was lost. Instead of just printing
|
|
|
|
|
* the '}' and letting the user guess what function this
|
|
|
|
|
* belongs to, write out the function name. Always do
|
|
|
|
|
* that if the funcgraph-tail option is enabled.
|
|
|
|
|
*/
|
|
|
|
|
if (func_match && !(flags & TRACE_GRAPH_PRINT_TAIL))
|
|
|
|
|
trace_seq_puts(s, "}\n");
|
|
|
|
|
else
|
2024-08-13 13:11:06 -04:00
|
|
|
trace_seq_printf(s, "} /* %ps */\n", (void *)func);
|
function_graph: Support recording and printing the return value of function
Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ret' and printing it when outputting
the trace log.
We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.
Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.
This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.
Here is an example:
I attempted to attach the demo process to a cpu cgroup, but it failed:
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument
The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4) = -1 EINVAL (Invalid argument)
...
To capture trace logs during a write system call, use the following
commands:
cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log
To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.
For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.
...
1) | cgroup_migrate() {
1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
1) | cgroup_migrate_execute() {
1) | cpu_cgroup_can_attach() {
1) | cgroup_taskset_first() {
1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
1) 4.369 us | } /* cgroup_migrate_execute = -22 */
1) 7.143 us | } /* cgroup_migrate = -22 */
...
Link: https://lkml.kernel.org/r/1fc502712c981e0e6742185ba242992170ac9da8.1680954589.git.pengdonglin@sangfor.com.cn
Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
2023-04-08 05:42:15 -07:00
|
|
|
}
|
2008-11-27 01:46:33 +01:00
|
|
|
|
|
|
|
|
/* Overrun */
|
2014-11-12 14:57:38 -05:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_OVERRUN)
|
2020-10-28 08:19:24 -04:00
|
|
|
trace_seq_printf(s, " (Overruns: %u)\n",
|
2014-11-12 14:57:38 -05:00
|
|
|
trace->overrun);
|
2008-12-09 23:55:25 +01:00
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
print_graph_irq(iter, trace->func, TRACE_GRAPH_RET,
|
|
|
|
|
cpu, pid, flags);
|
2008-12-09 23:55:25 +01:00
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
return trace_handle_return(s);
|
2008-11-26 00:57:25 +01:00
|
|
|
}
|
2008-11-25 21:07:04 +01:00
|
|
|
|
2008-12-03 23:45:11 +01:00
|
|
|
static enum print_line_t
|
2010-04-02 19:01:21 +02:00
|
|
|
print_graph_comment(struct trace_seq *s, struct trace_entry *ent,
|
|
|
|
|
struct trace_iterator *iter, u32 flags)
|
2008-12-03 23:45:11 +01:00
|
|
|
{
|
2015-09-30 09:42:05 -04:00
|
|
|
struct trace_array *tr = iter->tr;
|
|
|
|
|
unsigned long sym_flags = (tr->trace_flags & TRACE_ITER_SYM_MASK);
|
2009-03-19 13:24:42 -04:00
|
|
|
struct fgraph_data *data = iter->private;
|
2009-03-19 15:14:46 -04:00
|
|
|
struct trace_event *event;
|
2009-03-19 13:24:42 -04:00
|
|
|
int depth = 0;
|
2008-12-03 23:45:11 +01:00
|
|
|
int ret;
|
2009-03-19 13:24:42 -04:00
|
|
|
int i;
|
|
|
|
|
|
|
|
|
|
if (data)
|
2009-11-24 13:57:38 +01:00
|
|
|
depth = per_cpu_ptr(data->cpu_data, iter->cpu)->depth;
|
2009-01-22 17:04:53 -08:00
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
print_graph_prologue(iter, s, 0, 0, flags);
|
2009-02-18 04:25:25 +01:00
|
|
|
|
2009-01-22 17:04:53 -08:00
|
|
|
/* No time */
|
2015-09-30 09:42:05 -04:00
|
|
|
print_graph_duration(tr, 0, s, flags | FLAGS_FILL_FULL);
|
2008-12-03 23:45:11 +01:00
|
|
|
|
|
|
|
|
/* Indentation */
|
2009-03-19 13:24:42 -04:00
|
|
|
if (depth > 0)
|
2014-11-12 14:57:38 -05:00
|
|
|
for (i = 0; i < (depth + 1) * TRACE_GRAPH_INDENT; i++)
|
|
|
|
|
trace_seq_putc(s, ' ');
|
2008-12-03 23:45:11 +01:00
|
|
|
|
|
|
|
|
/* The comment */
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_puts(s, "/* ");
|
2009-03-06 17:21:49 +01:00
|
|
|
|
2009-03-19 15:14:46 -04:00
|
|
|
switch (iter->ent->type) {
|
2016-09-01 11:43:54 +09:00
|
|
|
case TRACE_BPUTS:
|
|
|
|
|
ret = trace_print_bputs_msg_only(iter);
|
|
|
|
|
if (ret != TRACE_TYPE_HANDLED)
|
|
|
|
|
return ret;
|
|
|
|
|
break;
|
2009-03-19 15:14:46 -04:00
|
|
|
case TRACE_BPRINT:
|
|
|
|
|
ret = trace_print_bprintk_msg_only(iter);
|
|
|
|
|
if (ret != TRACE_TYPE_HANDLED)
|
|
|
|
|
return ret;
|
|
|
|
|
break;
|
|
|
|
|
case TRACE_PRINT:
|
|
|
|
|
ret = trace_print_printk_msg_only(iter);
|
|
|
|
|
if (ret != TRACE_TYPE_HANDLED)
|
|
|
|
|
return ret;
|
|
|
|
|
break;
|
|
|
|
|
default:
|
|
|
|
|
event = ftrace_find_event(ent->type);
|
|
|
|
|
if (!event)
|
|
|
|
|
return TRACE_TYPE_UNHANDLED;
|
|
|
|
|
|
2010-04-22 18:46:14 -04:00
|
|
|
ret = event->funcs->trace(iter, sym_flags, event);
|
2009-03-19 15:14:46 -04:00
|
|
|
if (ret != TRACE_TYPE_HANDLED)
|
|
|
|
|
return ret;
|
|
|
|
|
}
|
2008-12-03 23:45:11 +01:00
|
|
|
|
2014-11-14 15:49:41 -05:00
|
|
|
if (trace_seq_has_overflowed(s))
|
|
|
|
|
goto out;
|
|
|
|
|
|
2008-12-24 01:43:25 +01:00
|
|
|
/* Strip ending newline */
|
2014-06-25 15:54:42 -04:00
|
|
|
if (s->buffer[s->seq.len - 1] == '\n') {
|
|
|
|
|
s->buffer[s->seq.len - 1] = '\0';
|
|
|
|
|
s->seq.len--;
|
2008-12-24 01:43:25 +01:00
|
|
|
}
|
|
|
|
|
|
2014-11-12 14:57:38 -05:00
|
|
|
trace_seq_puts(s, " */\n");
|
2014-11-14 15:49:41 -05:00
|
|
|
out:
|
2014-11-12 14:57:38 -05:00
|
|
|
return trace_handle_return(s);
|
2008-12-03 23:45:11 +01:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
|
2008-11-25 21:07:04 +01:00
|
|
|
enum print_line_t
|
2011-06-03 16:58:47 +02:00
|
|
|
print_graph_function_flags(struct trace_iterator *iter, u32 flags)
|
2008-11-25 21:07:04 +01:00
|
|
|
{
|
2009-11-24 13:57:38 +01:00
|
|
|
struct ftrace_graph_ent_entry *field;
|
|
|
|
|
struct fgraph_data *data = iter->private;
|
2008-11-25 21:07:04 +01:00
|
|
|
struct trace_entry *entry = iter->ent;
|
2009-03-19 15:14:46 -04:00
|
|
|
struct trace_seq *s = &iter->seq;
|
2009-11-24 13:57:38 +01:00
|
|
|
int cpu = iter->cpu;
|
|
|
|
|
int ret;
|
|
|
|
|
|
|
|
|
|
if (data && per_cpu_ptr(data->cpu_data, cpu)->ignore) {
|
|
|
|
|
per_cpu_ptr(data->cpu_data, cpu)->ignore = 0;
|
|
|
|
|
return TRACE_TYPE_HANDLED;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
/*
|
|
|
|
|
* If the last output failed, there's a possibility we need
|
|
|
|
|
* to print out the missing entry which would never go out.
|
|
|
|
|
*/
|
|
|
|
|
if (data && data->failed) {
|
2024-09-14 20:29:12 -07:00
|
|
|
field = &data->ent.ent;
|
2009-11-24 13:57:38 +01:00
|
|
|
iter->cpu = data->cpu;
|
2010-04-02 19:01:21 +02:00
|
|
|
ret = print_graph_entry(field, s, iter, flags);
|
2009-11-24 13:57:38 +01:00
|
|
|
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;
|
|
|
|
|
}
|
2008-11-25 21:07:04 +01:00
|
|
|
|
2008-11-26 00:57:25 +01:00
|
|
|
switch (entry->type) {
|
|
|
|
|
case TRACE_GRAPH_ENT: {
|
2009-07-28 20:11:24 +08:00
|
|
|
/*
|
|
|
|
|
* print_graph_entry() may consume the current event,
|
|
|
|
|
* thus @field may become invalid, so we need to save it.
|
|
|
|
|
* sizeof(struct ftrace_graph_ent_entry) is very small,
|
|
|
|
|
* it can be safely saved at the stack.
|
|
|
|
|
*/
|
2009-11-24 13:57:38 +01:00
|
|
|
struct ftrace_graph_ent_entry saved;
|
2008-11-25 21:07:04 +01:00
|
|
|
trace_assign_type(field, entry);
|
2009-07-28 20:11:24 +08:00
|
|
|
saved = *field;
|
2010-04-02 19:01:21 +02:00
|
|
|
return print_graph_entry(&saved, s, iter, flags);
|
2008-11-26 00:57:25 +01:00
|
|
|
}
|
2024-09-14 20:29:12 -07:00
|
|
|
#ifdef CONFIG_FUNCTION_GRAPH_RETADDR
|
|
|
|
|
case TRACE_GRAPH_RETADDR_ENT: {
|
|
|
|
|
struct fgraph_retaddr_ent_entry saved;
|
|
|
|
|
struct fgraph_retaddr_ent_entry *rfield;
|
|
|
|
|
|
|
|
|
|
trace_assign_type(rfield, entry);
|
|
|
|
|
saved = *rfield;
|
|
|
|
|
return print_graph_entry((struct ftrace_graph_ent_entry *)&saved, s, iter, flags);
|
|
|
|
|
}
|
|
|
|
|
#endif
|
2008-11-26 00:57:25 +01:00
|
|
|
case TRACE_GRAPH_RET: {
|
|
|
|
|
struct ftrace_graph_ret_entry *field;
|
|
|
|
|
trace_assign_type(field, entry);
|
2025-01-21 19:44:36 -05:00
|
|
|
return print_graph_return(field, s, entry, iter, flags);
|
2008-11-26 00:57:25 +01:00
|
|
|
}
|
2010-04-02 19:01:22 +02:00
|
|
|
case TRACE_STACK:
|
|
|
|
|
case TRACE_FN:
|
|
|
|
|
/* dont trace stack and functions as comments */
|
|
|
|
|
return TRACE_TYPE_UNHANDLED;
|
|
|
|
|
|
2008-11-26 00:57:25 +01:00
|
|
|
default:
|
2010-04-02 19:01:21 +02:00
|
|
|
return print_graph_comment(s, entry, iter, flags);
|
2008-11-25 21:07:04 +01:00
|
|
|
}
|
2009-03-19 15:14:46 -04:00
|
|
|
|
|
|
|
|
return TRACE_TYPE_HANDLED;
|
2008-11-25 21:07:04 +01:00
|
|
|
}
|
|
|
|
|
|
2010-04-02 19:01:21 +02:00
|
|
|
static enum print_line_t
|
|
|
|
|
print_graph_function(struct trace_iterator *iter)
|
|
|
|
|
{
|
2011-06-03 16:58:47 +02:00
|
|
|
return print_graph_function_flags(iter, tracer_flags.val);
|
2010-04-02 19:01:21 +02:00
|
|
|
}
|
|
|
|
|
|
2010-04-02 19:01:20 +02:00
|
|
|
static enum print_line_t
|
2010-04-22 18:46:14 -04:00
|
|
|
print_graph_function_event(struct trace_iterator *iter, int flags,
|
|
|
|
|
struct trace_event *event)
|
2010-04-02 19:01:20 +02:00
|
|
|
{
|
|
|
|
|
return print_graph_function(iter);
|
|
|
|
|
}
|
|
|
|
|
|
2010-04-02 19:01:21 +02:00
|
|
|
static void print_lat_header(struct seq_file *s, u32 flags)
|
2009-09-11 00:30:26 -04:00
|
|
|
{
|
|
|
|
|
static const char spaces[] = " " /* 16 spaces */
|
|
|
|
|
" " /* 4 spaces */
|
|
|
|
|
" "; /* 17 spaces */
|
|
|
|
|
int size = 0;
|
|
|
|
|
|
2010-04-02 19:01:21 +02:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
|
2009-09-11 00:30:26 -04:00
|
|
|
size += 16;
|
2019-01-01 23:46:10 +08:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_REL_TIME)
|
|
|
|
|
size += 16;
|
2010-04-02 19:01:21 +02:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_CPU)
|
2009-09-11 00:30:26 -04:00
|
|
|
size += 4;
|
2010-04-02 19:01:21 +02:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_PROC)
|
2009-09-11 00:30:26 -04:00
|
|
|
size += 17;
|
|
|
|
|
|
|
|
|
|
seq_printf(s, "#%.*s _-----=> irqs-off \n", size, spaces);
|
|
|
|
|
seq_printf(s, "#%.*s / _----=> need-resched \n", size, spaces);
|
|
|
|
|
seq_printf(s, "#%.*s| / _---=> hardirq/softirq \n", size, spaces);
|
|
|
|
|
seq_printf(s, "#%.*s|| / _--=> preempt-depth \n", size, spaces);
|
2011-06-03 16:58:50 +02:00
|
|
|
seq_printf(s, "#%.*s||| / \n", size, spaces);
|
2009-09-11 00:30:26 -04:00
|
|
|
}
|
|
|
|
|
|
2015-09-30 09:42:05 -04:00
|
|
|
static void __print_graph_headers_flags(struct trace_array *tr,
|
|
|
|
|
struct seq_file *s, u32 flags)
|
2008-12-08 01:56:06 +01:00
|
|
|
{
|
2015-09-30 09:42:05 -04:00
|
|
|
int lat = tr->trace_flags & TRACE_ITER_LATENCY_FMT;
|
2009-09-11 00:30:26 -04:00
|
|
|
|
|
|
|
|
if (lat)
|
2010-04-02 19:01:21 +02:00
|
|
|
print_lat_header(s, flags);
|
2009-09-11 00:30:26 -04:00
|
|
|
|
2008-12-08 01:56:06 +01:00
|
|
|
/* 1st line */
|
2014-11-08 21:42:12 +01:00
|
|
|
seq_putc(s, '#');
|
2010-04-02 19:01:21 +02:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
|
2014-11-08 21:42:10 +01:00
|
|
|
seq_puts(s, " TIME ");
|
2019-01-01 23:46:10 +08:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_REL_TIME)
|
|
|
|
|
seq_puts(s, " REL TIME ");
|
2010-04-02 19:01:21 +02:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_CPU)
|
2014-11-08 21:42:10 +01:00
|
|
|
seq_puts(s, " CPU");
|
2010-04-02 19:01:21 +02:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_PROC)
|
2014-11-08 21:42:10 +01:00
|
|
|
seq_puts(s, " TASK/PID ");
|
2009-09-11 00:30:26 -04:00
|
|
|
if (lat)
|
2019-01-01 23:46:12 +08:00
|
|
|
seq_puts(s, "|||| ");
|
2010-04-02 19:01:21 +02:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_DURATION)
|
2014-11-08 21:42:10 +01:00
|
|
|
seq_puts(s, " DURATION ");
|
|
|
|
|
seq_puts(s, " FUNCTION CALLS\n");
|
2008-12-08 01:56:06 +01:00
|
|
|
|
|
|
|
|
/* 2nd line */
|
2014-11-08 21:42:12 +01:00
|
|
|
seq_putc(s, '#');
|
2010-04-02 19:01:21 +02:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
|
2014-11-08 21:42:10 +01:00
|
|
|
seq_puts(s, " | ");
|
2019-01-01 23:46:10 +08:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_REL_TIME)
|
|
|
|
|
seq_puts(s, " | ");
|
2010-04-02 19:01:21 +02:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_CPU)
|
2014-11-08 21:42:10 +01:00
|
|
|
seq_puts(s, " | ");
|
2010-04-02 19:01:21 +02:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_PROC)
|
2014-11-08 21:42:10 +01:00
|
|
|
seq_puts(s, " | | ");
|
2009-09-11 00:30:26 -04:00
|
|
|
if (lat)
|
2019-01-01 23:46:12 +08:00
|
|
|
seq_puts(s, "|||| ");
|
2010-04-02 19:01:21 +02:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_DURATION)
|
2014-11-08 21:42:10 +01:00
|
|
|
seq_puts(s, " | | ");
|
|
|
|
|
seq_puts(s, " | | | |\n");
|
2008-12-08 01:56:06 +01:00
|
|
|
}
|
2009-01-22 17:04:53 -08:00
|
|
|
|
2014-07-18 18:07:49 -04:00
|
|
|
static void print_graph_headers(struct seq_file *s)
|
2010-04-02 19:01:21 +02:00
|
|
|
{
|
|
|
|
|
print_graph_headers_flags(s, tracer_flags.val);
|
|
|
|
|
}
|
|
|
|
|
|
2010-09-23 14:00:52 +02:00
|
|
|
void print_graph_headers_flags(struct seq_file *s, u32 flags)
|
|
|
|
|
{
|
|
|
|
|
struct trace_iterator *iter = s->private;
|
2015-09-30 09:42:05 -04:00
|
|
|
struct trace_array *tr = iter->tr;
|
2010-09-23 14:00:52 +02:00
|
|
|
|
2015-09-30 09:42:05 -04:00
|
|
|
if (!(tr->trace_flags & TRACE_ITER_CONTEXT_INFO))
|
2011-06-03 16:58:51 +02:00
|
|
|
return;
|
|
|
|
|
|
2015-09-30 09:42:05 -04:00
|
|
|
if (tr->trace_flags & TRACE_ITER_LATENCY_FMT) {
|
2010-09-23 14:00:52 +02:00
|
|
|
/* print nothing if the buffers are empty */
|
|
|
|
|
if (trace_empty(iter))
|
|
|
|
|
return;
|
|
|
|
|
|
|
|
|
|
print_trace_header(s, iter);
|
2011-06-03 16:58:47 +02:00
|
|
|
}
|
2010-09-23 14:00:52 +02:00
|
|
|
|
2015-09-30 09:42:05 -04:00
|
|
|
__print_graph_headers_flags(tr, s, flags);
|
2010-09-23 14:00:52 +02:00
|
|
|
}
|
|
|
|
|
|
2010-04-02 19:01:22 +02:00
|
|
|
void graph_trace_open(struct trace_iterator *iter)
|
2009-01-22 17:04:53 -08:00
|
|
|
{
|
2009-03-19 13:24:42 -04:00
|
|
|
/* pid and depth on the last trace processed */
|
2009-11-24 13:57:38 +01:00
|
|
|
struct fgraph_data *data;
|
2015-04-13 22:30:12 +02:00
|
|
|
gfp_t gfpflags;
|
2009-01-22 17:04:53 -08:00
|
|
|
int cpu;
|
|
|
|
|
|
2009-11-24 13:57:38 +01:00
|
|
|
iter->private = NULL;
|
|
|
|
|
|
2015-04-13 22:30:12 +02:00
|
|
|
/* We can be called in atomic context via ftrace_dump() */
|
|
|
|
|
gfpflags = (in_atomic() || irqs_disabled()) ? GFP_ATOMIC : GFP_KERNEL;
|
|
|
|
|
|
|
|
|
|
data = kzalloc(sizeof(*data), gfpflags);
|
2009-03-19 13:24:42 -04:00
|
|
|
if (!data)
|
2009-11-24 13:57:38 +01:00
|
|
|
goto out_err;
|
|
|
|
|
|
2015-04-13 22:30:12 +02:00
|
|
|
data->cpu_data = alloc_percpu_gfp(struct fgraph_cpu_data, gfpflags);
|
2009-11-24 13:57:38 +01:00
|
|
|
if (!data->cpu_data)
|
|
|
|
|
goto out_err_free;
|
|
|
|
|
|
|
|
|
|
for_each_possible_cpu(cpu) {
|
|
|
|
|
pid_t *pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid);
|
|
|
|
|
int *depth = &(per_cpu_ptr(data->cpu_data, cpu)->depth);
|
|
|
|
|
int *ignore = &(per_cpu_ptr(data->cpu_data, cpu)->ignore);
|
2010-09-07 16:53:44 +02:00
|
|
|
int *depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq);
|
|
|
|
|
|
2009-11-24 13:57:38 +01:00
|
|
|
*pid = -1;
|
|
|
|
|
*depth = 0;
|
|
|
|
|
*ignore = 0;
|
2010-09-07 16:53:44 +02:00
|
|
|
*depth_irq = -1;
|
2009-11-24 13:57:38 +01:00
|
|
|
}
|
2009-01-22 17:04:53 -08:00
|
|
|
|
2009-03-19 13:24:42 -04:00
|
|
|
iter->private = data;
|
2009-11-24 13:57:38 +01:00
|
|
|
|
|
|
|
|
return;
|
|
|
|
|
|
|
|
|
|
out_err_free:
|
|
|
|
|
kfree(data);
|
|
|
|
|
out_err:
|
2016-03-22 14:28:09 -07:00
|
|
|
pr_warn("function graph tracer: not enough memory\n");
|
2009-01-22 17:04:53 -08:00
|
|
|
}
|
|
|
|
|
|
2010-04-02 19:01:22 +02:00
|
|
|
void graph_trace_close(struct trace_iterator *iter)
|
2009-01-22 17:04:53 -08:00
|
|
|
{
|
2009-11-24 13:57:38 +01:00
|
|
|
struct fgraph_data *data = iter->private;
|
|
|
|
|
|
|
|
|
|
if (data) {
|
|
|
|
|
free_percpu(data->cpu_data);
|
|
|
|
|
kfree(data);
|
|
|
|
|
}
|
2009-01-22 17:04:53 -08:00
|
|
|
}
|
|
|
|
|
|
2014-01-10 11:13:54 -05:00
|
|
|
static int
|
|
|
|
|
func_graph_set_flag(struct trace_array *tr, u32 old_flags, u32 bit, int set)
|
2010-09-14 18:58:33 -04:00
|
|
|
{
|
|
|
|
|
if (bit == TRACE_GRAPH_PRINT_IRQS)
|
|
|
|
|
ftrace_graph_skip_irqs = !set;
|
|
|
|
|
|
2015-09-29 19:06:50 -04:00
|
|
|
if (bit == TRACE_GRAPH_SLEEP_TIME)
|
|
|
|
|
ftrace_graph_sleep_time_control(set);
|
|
|
|
|
|
|
|
|
|
if (bit == TRACE_GRAPH_GRAPH_TIME)
|
|
|
|
|
ftrace_graph_graph_time_control(set);
|
|
|
|
|
|
2010-09-14 18:58:33 -04:00
|
|
|
return 0;
|
|
|
|
|
}
|
|
|
|
|
|
2010-04-22 18:46:14 -04:00
|
|
|
static struct trace_event_functions graph_functions = {
|
|
|
|
|
.trace = print_graph_function_event,
|
|
|
|
|
};
|
|
|
|
|
|
2010-04-02 19:01:20 +02:00
|
|
|
static struct trace_event graph_trace_entry_event = {
|
|
|
|
|
.type = TRACE_GRAPH_ENT,
|
2010-04-22 18:46:14 -04:00
|
|
|
.funcs = &graph_functions,
|
2010-04-02 19:01:20 +02:00
|
|
|
};
|
|
|
|
|
|
2024-09-14 20:29:12 -07:00
|
|
|
#ifdef CONFIG_FUNCTION_GRAPH_RETADDR
|
|
|
|
|
static struct trace_event graph_trace_retaddr_entry_event = {
|
|
|
|
|
.type = TRACE_GRAPH_RETADDR_ENT,
|
|
|
|
|
.funcs = &graph_functions,
|
|
|
|
|
};
|
|
|
|
|
#endif
|
|
|
|
|
|
2010-04-02 19:01:20 +02:00
|
|
|
static struct trace_event graph_trace_ret_event = {
|
|
|
|
|
.type = TRACE_GRAPH_RET,
|
2010-04-22 18:46:14 -04:00
|
|
|
.funcs = &graph_functions
|
2010-04-02 19:01:20 +02:00
|
|
|
};
|
|
|
|
|
|
2013-07-18 14:41:51 -04:00
|
|
|
static struct tracer graph_trace __tracer_data = {
|
2009-03-10 14:10:56 -04:00
|
|
|
.name = "function_graph",
|
2014-07-18 15:17:27 +04:00
|
|
|
.update_thresh = graph_trace_update_thresh,
|
2009-01-22 17:04:53 -08:00
|
|
|
.open = graph_trace_open,
|
2009-11-24 13:57:38 +01:00
|
|
|
.pipe_open = graph_trace_open,
|
2009-01-22 17:04:53 -08:00
|
|
|
.close = graph_trace_close,
|
2009-11-24 13:57:38 +01:00
|
|
|
.pipe_close = graph_trace_close,
|
2009-03-10 14:10:56 -04:00
|
|
|
.init = graph_trace_init,
|
|
|
|
|
.reset = graph_trace_reset,
|
2008-12-08 01:56:06 +01:00
|
|
|
.print_line = print_graph_function,
|
|
|
|
|
.print_header = print_graph_headers,
|
2008-11-25 21:07:04 +01:00
|
|
|
.flags = &tracer_flags,
|
2010-09-14 18:58:33 -04:00
|
|
|
.set_flag = func_graph_set_flag,
|
2024-06-03 15:07:12 -04:00
|
|
|
.allow_instances = true,
|
2009-02-07 21:33:57 +01:00
|
|
|
#ifdef CONFIG_FTRACE_SELFTEST
|
|
|
|
|
.selftest = trace_selftest_startup_function_graph,
|
|
|
|
|
#endif
|
2008-11-25 21:07:04 +01:00
|
|
|
};
|
|
|
|
|
|
2013-01-16 10:49:37 -05:00
|
|
|
|
|
|
|
|
static ssize_t
|
|
|
|
|
graph_depth_write(struct file *filp, const char __user *ubuf, size_t cnt,
|
|
|
|
|
loff_t *ppos)
|
|
|
|
|
{
|
|
|
|
|
unsigned long val;
|
|
|
|
|
int ret;
|
|
|
|
|
|
|
|
|
|
ret = kstrtoul_from_user(ubuf, cnt, 10, &val);
|
|
|
|
|
if (ret)
|
|
|
|
|
return ret;
|
|
|
|
|
|
2016-12-08 19:28:28 -05:00
|
|
|
fgraph_max_depth = val;
|
2013-01-16 10:49:37 -05:00
|
|
|
|
|
|
|
|
*ppos += cnt;
|
|
|
|
|
|
|
|
|
|
return cnt;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
static ssize_t
|
|
|
|
|
graph_depth_read(struct file *filp, char __user *ubuf, size_t cnt,
|
|
|
|
|
loff_t *ppos)
|
|
|
|
|
{
|
|
|
|
|
char buf[15]; /* More than enough to hold UINT_MAX + "\n"*/
|
|
|
|
|
int n;
|
|
|
|
|
|
2016-12-08 19:28:28 -05:00
|
|
|
n = sprintf(buf, "%d\n", fgraph_max_depth);
|
2013-01-16 10:49:37 -05:00
|
|
|
|
|
|
|
|
return simple_read_from_buffer(ubuf, cnt, ppos, buf, n);
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
static const struct file_operations graph_depth_fops = {
|
|
|
|
|
.open = tracing_open_generic,
|
|
|
|
|
.write = graph_depth_write,
|
|
|
|
|
.read = graph_depth_read,
|
|
|
|
|
.llseek = generic_file_llseek,
|
|
|
|
|
};
|
|
|
|
|
|
2015-01-20 12:13:40 -05:00
|
|
|
static __init int init_graph_tracefs(void)
|
2013-01-16 10:49:37 -05:00
|
|
|
{
|
2020-07-12 09:10:36 +08:00
|
|
|
int ret;
|
2013-01-16 10:49:37 -05:00
|
|
|
|
2020-07-12 09:10:36 +08:00
|
|
|
ret = tracing_init_dentry();
|
|
|
|
|
if (ret)
|
2013-01-16 10:49:37 -05:00
|
|
|
return 0;
|
|
|
|
|
|
2021-08-18 11:24:51 -04:00
|
|
|
trace_create_file("max_graph_depth", TRACE_MODE_WRITE, NULL,
|
2013-01-16 10:49:37 -05:00
|
|
|
NULL, &graph_depth_fops);
|
|
|
|
|
|
|
|
|
|
return 0;
|
|
|
|
|
}
|
2015-01-20 12:13:40 -05:00
|
|
|
fs_initcall(init_graph_tracefs);
|
2013-01-16 10:49:37 -05:00
|
|
|
|
2008-11-25 21:07:04 +01:00
|
|
|
static __init int init_graph_trace(void)
|
|
|
|
|
{
|
2017-09-08 16:14:18 -07:00
|
|
|
max_bytes_for_cpu = snprintf(NULL, 0, "%u", nr_cpu_ids - 1);
|
2009-07-28 20:26:06 +08:00
|
|
|
|
2015-05-05 09:39:12 -04:00
|
|
|
if (!register_trace_event(&graph_trace_entry_event)) {
|
2016-03-22 14:28:09 -07:00
|
|
|
pr_warn("Warning: could not register graph trace events\n");
|
2010-04-02 19:01:20 +02:00
|
|
|
return 1;
|
|
|
|
|
}
|
|
|
|
|
|
2024-09-14 20:29:12 -07:00
|
|
|
#ifdef CONFIG_FUNCTION_GRAPH_RETADDR
|
|
|
|
|
if (!register_trace_event(&graph_trace_retaddr_entry_event)) {
|
|
|
|
|
pr_warn("Warning: could not register graph trace retaddr events\n");
|
|
|
|
|
return 1;
|
|
|
|
|
}
|
|
|
|
|
#endif
|
|
|
|
|
|
2015-05-05 09:39:12 -04:00
|
|
|
if (!register_trace_event(&graph_trace_ret_event)) {
|
2016-03-22 14:28:09 -07:00
|
|
|
pr_warn("Warning: could not register graph trace events\n");
|
2010-04-02 19:01:20 +02:00
|
|
|
return 1;
|
|
|
|
|
}
|
|
|
|
|
|
2008-11-25 21:07:04 +01:00
|
|
|
return register_tracer(&graph_trace);
|
|
|
|
|
}
|
|
|
|
|
|
2012-10-05 12:13:07 -04:00
|
|
|
core_initcall(init_graph_trace);
|