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 14:07:57 +00:00
|
|
|
// SPDX-License-Identifier: GPL-2.0
|
2008-11-25 20:07:04 +00:00
|
|
|
/*
|
|
|
|
*
|
|
|
|
* Function graph tracer.
|
2009-01-23 01:04:53 +00:00
|
|
|
* Copyright (c) 2008-2009 Frederic Weisbecker <fweisbec@gmail.com>
|
2008-11-25 20:07:04 +00: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 21:22:05 +00: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 08:04:11 +00:00
|
|
|
#include <linux/slab.h>
|
2008-11-25 20:07:04 +00:00
|
|
|
#include <linux/fs.h>
|
|
|
|
|
|
|
|
#include "trace.h"
|
2008-12-24 04:24:12 +00:00
|
|
|
#include "trace_output.h"
|
2008-11-25 20:07:04 +00:00
|
|
|
|
2010-09-14 22:58:33 +00:00
|
|
|
/* When set, irq functions will be ignored */
|
|
|
|
static int ftrace_graph_skip_irqs;
|
|
|
|
|
2009-11-24 12:57:38 +00:00
|
|
|
struct fgraph_cpu_data {
|
2009-03-19 17:24:42 +00:00
|
|
|
pid_t last_pid;
|
|
|
|
int depth;
|
2010-09-07 14:53:44 +00:00
|
|
|
int depth_irq;
|
2009-11-24 12:57:38 +00:00
|
|
|
int ignore;
|
2010-02-26 22:08:16 +00:00
|
|
|
unsigned long enter_funcs[FTRACE_RETFUNC_DEPTH];
|
2009-11-24 12:57:38 +00:00
|
|
|
};
|
|
|
|
|
|
|
|
struct fgraph_data {
|
2010-08-11 03:47:59 +00:00
|
|
|
struct fgraph_cpu_data __percpu *cpu_data;
|
2009-11-24 12:57:38 +00:00
|
|
|
|
|
|
|
/* Place to preserve last processed entry. */
|
|
|
|
struct ftrace_graph_ent_entry ent;
|
|
|
|
struct ftrace_graph_ret_entry ret;
|
|
|
|
int failed;
|
|
|
|
int cpu;
|
2009-03-19 17:24:42 +00:00
|
|
|
};
|
|
|
|
|
2008-11-25 23:57:25 +00:00
|
|
|
#define TRACE_GRAPH_INDENT 2
|
2008-11-25 20:07:04 +00:00
|
|
|
|
2016-12-09 00:28:28 +00:00
|
|
|
unsigned int fgraph_max_depth;
|
2013-01-16 15:49:37 +00:00
|
|
|
|
2008-11-25 20:07:04 +00:00
|
|
|
static struct tracer_opt trace_opts[] = {
|
2009-01-23 01:04:53 +00:00
|
|
|
/* Display overruns? (for self-debug purpose) */
|
2008-11-27 23:42:46 +00: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 01:30:37 +00:00
|
|
|
/* Display proc name/pid */
|
|
|
|
{ TRACER_OPT(funcgraph-proc, TRACE_GRAPH_PRINT_PROC) },
|
2009-01-23 01:04:53 +00: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 14:53:44 +00:00
|
|
|
/* Display interrupts */
|
|
|
|
{ TRACER_OPT(funcgraph-irqs, TRACE_GRAPH_PRINT_IRQS) },
|
2014-05-20 22:10:51 +00: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 12:42:15 +00: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) },
|
|
|
|
#endif
|
2015-09-29 23:06:50 +00:00
|
|
|
/* Include sleep time (scheduled out) between entry and return */
|
|
|
|
{ TRACER_OPT(sleep-time, TRACE_GRAPH_SLEEP_TIME) },
|
2018-11-23 18:06:07 +00:00
|
|
|
|
|
|
|
#ifdef CONFIG_FUNCTION_PROFILER
|
2015-09-29 23:06:50 +00:00
|
|
|
/* Include time within nested functions */
|
|
|
|
{ TRACER_OPT(graph-time, TRACE_GRAPH_GRAPH_TIME) },
|
2018-11-23 18:06:07 +00:00
|
|
|
#endif
|
|
|
|
|
2008-11-25 20:07:04 +00:00
|
|
|
{ } /* Empty entry */
|
|
|
|
};
|
|
|
|
|
|
|
|
static struct tracer_flags tracer_flags = {
|
2014-05-20 22:10:51 +00:00
|
|
|
/* Don't display overruns, proc, or tail by default */
|
2009-01-23 01:04:53 +00:00
|
|
|
.val = TRACE_GRAPH_PRINT_CPU | TRACE_GRAPH_PRINT_OVERHEAD |
|
2015-09-29 23:06:50 +00:00
|
|
|
TRACE_GRAPH_PRINT_DURATION | TRACE_GRAPH_PRINT_IRQS |
|
|
|
|
TRACE_GRAPH_SLEEP_TIME | TRACE_GRAPH_GRAPH_TIME,
|
2008-11-25 20:07:04 +00:00
|
|
|
.opts = trace_opts
|
|
|
|
};
|
|
|
|
|
2009-07-29 16:59:58 +00:00
|
|
|
static struct trace_array *graph_array;
|
2009-01-23 01:04:53 +00:00
|
|
|
|
2011-06-03 14:58:48 +00: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 19:50:06 +00: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 14:58:48 +00:00
|
|
|
};
|
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
static void
|
2015-09-30 13:42:05 +00:00
|
|
|
print_graph_duration(struct trace_array *tr, unsigned long long duration,
|
|
|
|
struct trace_seq *s, u32 flags);
|
2008-11-25 20:07:04 +00:00
|
|
|
|
2010-04-02 17:01:22 +00:00
|
|
|
int __trace_graph_entry(struct trace_array *tr,
|
2009-07-29 16:59:58 +00:00
|
|
|
struct ftrace_graph_ent *trace,
|
2021-01-25 19:45:08 +00:00
|
|
|
unsigned int trace_ctx)
|
2009-07-29 16:59:58 +00:00
|
|
|
{
|
2015-05-05 15:45:27 +00:00
|
|
|
struct trace_event_call *call = &event_funcgraph_entry;
|
2009-07-29 16:59:58 +00:00
|
|
|
struct ring_buffer_event *event;
|
2019-12-13 18:58:57 +00:00
|
|
|
struct trace_buffer *buffer = tr->array_buffer.buffer;
|
2009-07-29 16:59:58 +00:00
|
|
|
struct ftrace_graph_ent_entry *entry;
|
|
|
|
|
2009-09-02 18:17:06 +00:00
|
|
|
event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_ENT,
|
2021-01-25 19:45:08 +00:00
|
|
|
sizeof(*entry), trace_ctx);
|
2009-07-29 16:59:58 +00:00
|
|
|
if (!event)
|
|
|
|
return 0;
|
|
|
|
entry = ring_buffer_event_data(event);
|
|
|
|
entry->graph_ent = *trace;
|
2013-10-24 13:34:17 +00:00
|
|
|
if (!call_filter_check_discard(call, entry, buffer, event))
|
2016-11-24 01:28:38 +00:00
|
|
|
trace_buffer_unlock_commit_nostack(buffer, event);
|
2009-07-29 16:59:58 +00:00
|
|
|
|
|
|
|
return 1;
|
|
|
|
}
|
|
|
|
|
2010-09-14 22:58:33 +00:00
|
|
|
static inline int ftrace_graph_ignore_irqs(void)
|
|
|
|
{
|
2011-06-14 23:02:29 +00:00
|
|
|
if (!ftrace_graph_skip_irqs || trace_recursion_test(TRACE_IRQ_BIT))
|
2010-09-14 22:58:33 +00:00
|
|
|
return 0;
|
|
|
|
|
2021-09-30 00:03:42 +00:00
|
|
|
return in_hardirq();
|
2010-09-14 22:58:33 +00:00
|
|
|
}
|
|
|
|
|
2009-07-29 16:59:58 +00:00
|
|
|
int trace_graph_entry(struct ftrace_graph_ent *trace)
|
|
|
|
{
|
|
|
|
struct trace_array *tr = graph_array;
|
|
|
|
struct trace_array_cpu *data;
|
|
|
|
unsigned long flags;
|
2021-01-25 19:45:08 +00:00
|
|
|
unsigned int trace_ctx;
|
2009-07-29 16:59:58 +00:00
|
|
|
long disabled;
|
|
|
|
int ret;
|
|
|
|
int cpu;
|
|
|
|
|
2018-11-14 18:14:58 +00:00
|
|
|
if (trace_recursion_test(TRACE_GRAPH_NOTRACE_BIT))
|
|
|
|
return 0;
|
|
|
|
|
2019-07-30 14:08:50 +00: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 18:14:58 +00:00
|
|
|
if (ftrace_graph_notrace_addr(trace->func)) {
|
|
|
|
trace_recursion_set(TRACE_GRAPH_NOTRACE_BIT);
|
|
|
|
/*
|
|
|
|
* Need to return 1 to have the return called
|
|
|
|
* that will clear the NOTRACE bit.
|
|
|
|
*/
|
|
|
|
return 1;
|
|
|
|
}
|
|
|
|
|
2016-04-22 22:11:33 +00:00
|
|
|
if (!ftrace_trace_task(tr))
|
2009-07-29 16:59:58 +00:00
|
|
|
return 0;
|
|
|
|
|
2016-12-09 00:28:28 +00:00
|
|
|
if (ftrace_graph_ignore_func(trace))
|
|
|
|
return 0;
|
|
|
|
|
|
|
|
if (ftrace_graph_ignore_irqs())
|
2009-07-29 16:59:58 +00:00
|
|
|
return 0;
|
|
|
|
|
2016-06-18 05:44:54 +00:00
|
|
|
/*
|
|
|
|
* Stop here if tracing_threshold is set. We only write function return
|
|
|
|
* events to the ring buffer.
|
|
|
|
*/
|
|
|
|
if (tracing_thresh)
|
|
|
|
return 1;
|
|
|
|
|
2009-07-29 16:59:58 +00:00
|
|
|
local_irq_save(flags);
|
|
|
|
cpu = raw_smp_processor_id();
|
2020-01-09 23:53:48 +00:00
|
|
|
data = per_cpu_ptr(tr->array_buffer.data, cpu);
|
2009-07-29 16:59:58 +00:00
|
|
|
disabled = atomic_inc_return(&data->disabled);
|
|
|
|
if (likely(disabled == 1)) {
|
2021-01-25 19:45:08 +00:00
|
|
|
trace_ctx = tracing_gen_ctx_flags(flags);
|
|
|
|
ret = __trace_graph_entry(tr, trace, trace_ctx);
|
2009-07-29 16:59:58 +00:00
|
|
|
} else {
|
|
|
|
ret = 0;
|
|
|
|
}
|
|
|
|
|
|
|
|
atomic_dec(&data->disabled);
|
|
|
|
local_irq_restore(flags);
|
|
|
|
|
|
|
|
return ret;
|
|
|
|
}
|
|
|
|
|
2010-09-23 12:00:52 +00:00
|
|
|
static void
|
|
|
|
__trace_graph_function(struct trace_array *tr,
|
2021-01-25 19:45:08 +00:00
|
|
|
unsigned long ip, unsigned int trace_ctx)
|
2010-09-23 12:00:52 +00:00
|
|
|
{
|
|
|
|
u64 time = trace_clock_local();
|
|
|
|
struct ftrace_graph_ent ent = {
|
|
|
|
.func = ip,
|
|
|
|
.depth = 0,
|
|
|
|
};
|
|
|
|
struct ftrace_graph_ret ret = {
|
|
|
|
.func = ip,
|
|
|
|
.depth = 0,
|
|
|
|
.calltime = time,
|
|
|
|
.rettime = time,
|
|
|
|
};
|
|
|
|
|
2021-01-25 19:45:08 +00:00
|
|
|
__trace_graph_entry(tr, &ent, trace_ctx);
|
|
|
|
__trace_graph_return(tr, &ret, trace_ctx);
|
2010-09-23 12:00:52 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
void
|
|
|
|
trace_graph_function(struct trace_array *tr,
|
|
|
|
unsigned long ip, unsigned long parent_ip,
|
2021-01-25 19:45:08 +00:00
|
|
|
unsigned int trace_ctx)
|
2010-09-23 12:00:52 +00:00
|
|
|
{
|
2021-01-25 19:45:08 +00:00
|
|
|
__trace_graph_function(tr, ip, trace_ctx);
|
2010-09-23 12:00:52 +00:00
|
|
|
}
|
|
|
|
|
2010-04-02 17:01:22 +00:00
|
|
|
void __trace_graph_return(struct trace_array *tr,
|
2009-07-29 16:59:58 +00:00
|
|
|
struct ftrace_graph_ret *trace,
|
2021-01-25 19:45:08 +00:00
|
|
|
unsigned int trace_ctx)
|
2009-07-29 16:59:58 +00:00
|
|
|
{
|
2015-05-05 15:45:27 +00:00
|
|
|
struct trace_event_call *call = &event_funcgraph_exit;
|
2009-07-29 16:59:58 +00:00
|
|
|
struct ring_buffer_event *event;
|
2019-12-13 18:58:57 +00:00
|
|
|
struct trace_buffer *buffer = tr->array_buffer.buffer;
|
2009-07-29 16:59:58 +00:00
|
|
|
struct ftrace_graph_ret_entry *entry;
|
|
|
|
|
2009-09-02 18:17:06 +00:00
|
|
|
event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_RET,
|
2021-01-25 19:45:08 +00:00
|
|
|
sizeof(*entry), trace_ctx);
|
2009-07-29 16:59:58 +00:00
|
|
|
if (!event)
|
|
|
|
return;
|
|
|
|
entry = ring_buffer_event_data(event);
|
|
|
|
entry->ret = *trace;
|
2013-10-24 13:34:17 +00:00
|
|
|
if (!call_filter_check_discard(call, entry, buffer, event))
|
2016-11-24 01:28:38 +00:00
|
|
|
trace_buffer_unlock_commit_nostack(buffer, event);
|
2009-07-29 16:59:58 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
void trace_graph_return(struct ftrace_graph_ret *trace)
|
|
|
|
{
|
|
|
|
struct trace_array *tr = graph_array;
|
|
|
|
struct trace_array_cpu *data;
|
|
|
|
unsigned long flags;
|
2021-01-25 19:45:08 +00:00
|
|
|
unsigned int trace_ctx;
|
2009-07-29 16:59:58 +00:00
|
|
|
long disabled;
|
|
|
|
int cpu;
|
|
|
|
|
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 13:50:27 +00:00
|
|
|
ftrace_graph_addr_finish(trace);
|
|
|
|
|
2018-11-14 18:14:58 +00:00
|
|
|
if (trace_recursion_test(TRACE_GRAPH_NOTRACE_BIT)) {
|
|
|
|
trace_recursion_clear(TRACE_GRAPH_NOTRACE_BIT);
|
|
|
|
return;
|
|
|
|
}
|
|
|
|
|
2009-07-29 16:59:58 +00:00
|
|
|
local_irq_save(flags);
|
|
|
|
cpu = raw_smp_processor_id();
|
2020-01-09 23:53:48 +00:00
|
|
|
data = per_cpu_ptr(tr->array_buffer.data, cpu);
|
2009-07-29 16:59:58 +00:00
|
|
|
disabled = atomic_inc_return(&data->disabled);
|
|
|
|
if (likely(disabled == 1)) {
|
2021-01-25 19:45:08 +00:00
|
|
|
trace_ctx = tracing_gen_ctx_flags(flags);
|
|
|
|
__trace_graph_return(tr, trace, trace_ctx);
|
2009-07-29 16:59:58 +00:00
|
|
|
}
|
|
|
|
atomic_dec(&data->disabled);
|
|
|
|
local_irq_restore(flags);
|
|
|
|
}
|
|
|
|
|
2010-01-14 07:23:15 +00:00
|
|
|
void set_graph_array(struct trace_array *tr)
|
|
|
|
{
|
|
|
|
graph_array = tr;
|
|
|
|
|
|
|
|
/* Make graph_array visible before we start tracing */
|
|
|
|
|
|
|
|
smp_mb();
|
|
|
|
}
|
|
|
|
|
2014-07-18 22:07:49 +00:00
|
|
|
static void trace_graph_thresh_return(struct ftrace_graph_ret *trace)
|
2010-02-25 23:36:43 +00:00
|
|
|
{
|
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 13:50:27 +00:00
|
|
|
ftrace_graph_addr_finish(trace);
|
|
|
|
|
2018-11-14 18:14:58 +00:00
|
|
|
if (trace_recursion_test(TRACE_GRAPH_NOTRACE_BIT)) {
|
|
|
|
trace_recursion_clear(TRACE_GRAPH_NOTRACE_BIT);
|
|
|
|
return;
|
|
|
|
}
|
|
|
|
|
2010-02-25 23:36:43 +00:00
|
|
|
if (tracing_thresh &&
|
|
|
|
(trace->rettime - trace->calltime < tracing_thresh))
|
|
|
|
return;
|
|
|
|
else
|
|
|
|
trace_graph_return(trace);
|
|
|
|
}
|
|
|
|
|
2018-11-15 19:06:47 +00:00
|
|
|
static struct fgraph_ops funcgraph_thresh_ops = {
|
|
|
|
.entryfunc = &trace_graph_entry,
|
|
|
|
.retfunc = &trace_graph_thresh_return,
|
|
|
|
};
|
|
|
|
|
|
|
|
static struct fgraph_ops funcgraph_ops = {
|
|
|
|
.entryfunc = &trace_graph_entry,
|
|
|
|
.retfunc = &trace_graph_return,
|
|
|
|
};
|
|
|
|
|
2008-11-25 20:07:04 +00:00
|
|
|
static int graph_trace_init(struct trace_array *tr)
|
|
|
|
{
|
2009-07-29 16:59:58 +00:00
|
|
|
int ret;
|
|
|
|
|
2010-01-14 07:23:15 +00:00
|
|
|
set_graph_array(tr);
|
2010-02-25 23:36:43 +00:00
|
|
|
if (tracing_thresh)
|
2018-11-15 19:06:47 +00:00
|
|
|
ret = register_ftrace_graph(&funcgraph_thresh_ops);
|
2010-02-25 23:36:43 +00:00
|
|
|
else
|
2018-11-15 19:06:47 +00:00
|
|
|
ret = register_ftrace_graph(&funcgraph_ops);
|
2008-11-26 05:16:26 +00:00
|
|
|
if (ret)
|
|
|
|
return ret;
|
|
|
|
tracing_start_cmdline_record();
|
|
|
|
|
|
|
|
return 0;
|
2008-11-25 20:07:04 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
static void graph_trace_reset(struct trace_array *tr)
|
|
|
|
{
|
2008-11-26 05:16:26 +00:00
|
|
|
tracing_stop_cmdline_record();
|
2018-11-15 19:06:47 +00:00
|
|
|
if (tracing_thresh)
|
|
|
|
unregister_ftrace_graph(&funcgraph_thresh_ops);
|
|
|
|
else
|
|
|
|
unregister_ftrace_graph(&funcgraph_ops);
|
2008-11-25 20:07:04 +00:00
|
|
|
}
|
|
|
|
|
2014-07-18 22:07:49 +00:00
|
|
|
static int graph_trace_update_thresh(struct trace_array *tr)
|
2014-07-18 11:17:27 +00:00
|
|
|
{
|
|
|
|
graph_trace_reset(tr);
|
|
|
|
return graph_trace_init(tr);
|
|
|
|
}
|
|
|
|
|
2009-07-28 12:26:06 +00:00
|
|
|
static int max_bytes_for_cpu;
|
2008-11-27 23:42:46 +00:00
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
static void print_graph_cpu(struct trace_seq *s, int cpu)
|
2008-11-27 23:42:46 +00:00
|
|
|
{
|
2008-11-28 08:55:16 +00: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 19:57:38 +00:00
|
|
|
trace_seq_printf(s, " %*d) ", max_bytes_for_cpu, cpu);
|
2008-11-27 23:42:46 +00:00
|
|
|
}
|
|
|
|
|
2008-12-03 01:30:37 +00:00
|
|
|
#define TRACE_GRAPH_PROCINFO_LENGTH 14
|
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
static void print_graph_proc(struct trace_seq *s, pid_t pid)
|
2008-12-03 01:30:37 +00:00
|
|
|
{
|
2009-03-16 23:20:15 +00:00
|
|
|
char comm[TASK_COMM_LEN];
|
2008-12-03 01:30:37 +00:00
|
|
|
/* sign + log10(MAX_INT) + '\0' */
|
|
|
|
char pid_str[11];
|
2009-03-16 23:20:15 +00:00
|
|
|
int spaces = 0;
|
|
|
|
int len;
|
|
|
|
int i;
|
2008-12-03 01:30:37 +00:00
|
|
|
|
2009-03-16 23:20:15 +00:00
|
|
|
trace_find_cmdline(pid, comm);
|
2008-12-03 01:30:37 +00: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 19:57:38 +00:00
|
|
|
for (i = 0; i < spaces / 2; i++)
|
|
|
|
trace_seq_putc(s, ' ');
|
2008-12-03 01:30:37 +00:00
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_printf(s, "%s-%s", comm, pid_str);
|
2008-12-03 01:30:37 +00:00
|
|
|
|
|
|
|
/* Last spaces to align center */
|
2014-11-12 19:57:38 +00:00
|
|
|
for (i = 0; i < spaces - (spaces / 2); i++)
|
|
|
|
trace_seq_putc(s, ' ');
|
2008-12-03 01:30:37 +00:00
|
|
|
}
|
|
|
|
|
2008-11-27 23:42:46 +00:00
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
static void print_graph_lat_fmt(struct trace_seq *s, struct trace_entry *entry)
|
2009-09-11 04:30:26 +00:00
|
|
|
{
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_putc(s, ' ');
|
|
|
|
trace_print_lat_fmt(s, entry);
|
2019-01-01 15:46:12 +00:00
|
|
|
trace_seq_puts(s, " | ");
|
2009-09-11 04:30:26 +00:00
|
|
|
}
|
|
|
|
|
2008-11-25 23:57:25 +00:00
|
|
|
/* If the pid changed since the last trace, output this event */
|
2014-11-12 19:57:38 +00:00
|
|
|
static void
|
2009-03-19 17:24:42 +00:00
|
|
|
verif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data)
|
2008-11-25 23:57:25 +00:00
|
|
|
{
|
2008-11-28 08:55:16 +00:00
|
|
|
pid_t prev_pid;
|
2009-01-23 01:04:53 +00:00
|
|
|
pid_t *last_pid;
|
2008-11-26 05:16:26 +00:00
|
|
|
|
2009-03-19 17:24:42 +00:00
|
|
|
if (!data)
|
2014-11-12 19:57:38 +00:00
|
|
|
return;
|
2009-01-23 01:04:53 +00:00
|
|
|
|
2009-11-24 12:57:38 +00:00
|
|
|
last_pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid);
|
2009-01-23 01:04:53 +00:00
|
|
|
|
|
|
|
if (*last_pid == pid)
|
2014-11-12 19:57:38 +00:00
|
|
|
return;
|
2008-11-25 20:07:04 +00:00
|
|
|
|
2009-01-23 01:04:53 +00:00
|
|
|
prev_pid = *last_pid;
|
|
|
|
*last_pid = pid;
|
2008-11-28 08:55:16 +00:00
|
|
|
|
2009-01-23 01:04:53 +00:00
|
|
|
if (prev_pid == -1)
|
2014-11-12 19:57:38 +00:00
|
|
|
return;
|
2008-11-28 08:55:16 +00:00
|
|
|
/*
|
|
|
|
* Context-switch trace line:
|
|
|
|
|
|
|
|
------------------------------------------
|
|
|
|
| 1) migration/0--1 => sshd-1755
|
|
|
|
------------------------------------------
|
|
|
|
|
|
|
|
*/
|
2014-11-12 19:57:38 +00: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-25 23:57:25 +00:00
|
|
|
}
|
|
|
|
|
2009-02-06 17:30:44 +00:00
|
|
|
static struct ftrace_graph_ret_entry *
|
|
|
|
get_return_for_leaf(struct trace_iterator *iter,
|
2008-11-27 00:46:33 +00:00
|
|
|
struct ftrace_graph_ent_entry *curr)
|
|
|
|
{
|
2009-11-24 12:57:38 +00:00
|
|
|
struct fgraph_data *data = iter->private;
|
|
|
|
struct ring_buffer_iter *ring_iter = NULL;
|
2008-11-27 00:46:33 +00:00
|
|
|
struct ring_buffer_event *event;
|
|
|
|
struct ftrace_graph_ret_entry *next;
|
|
|
|
|
2009-11-24 12:57:38 +00:00
|
|
|
/*
|
|
|
|
* If the previous output failed to write to the seq buffer,
|
|
|
|
* then we just reuse the data from before.
|
|
|
|
*/
|
|
|
|
if (data && data->failed) {
|
|
|
|
curr = &data->ent;
|
|
|
|
next = &data->ret;
|
|
|
|
} else {
|
2008-11-27 00:46:33 +00:00
|
|
|
|
2012-06-28 00:46:14 +00:00
|
|
|
ring_iter = trace_buffer_iter(iter, iter->cpu);
|
2009-11-24 12:57:38 +00: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 23:53:48 +00: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 17:21:56 +00:00
|
|
|
NULL, NULL);
|
2020-01-09 23:53:48 +00: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 17:21:56 +00:00
|
|
|
NULL, NULL);
|
2009-11-24 12:57:38 +00:00
|
|
|
}
|
2008-11-27 00:46:33 +00:00
|
|
|
|
2009-11-24 12:57:38 +00:00
|
|
|
if (!event)
|
|
|
|
return NULL;
|
|
|
|
|
|
|
|
next = ring_buffer_event_data(event);
|
2008-11-27 00:46:33 +00:00
|
|
|
|
2009-11-24 12:57:38 +00:00
|
|
|
if (data) {
|
|
|
|
/*
|
|
|
|
* Save current and next entries for later reference
|
|
|
|
* if the output fails.
|
|
|
|
*/
|
|
|
|
data->ent = *curr;
|
2010-07-27 08:06:34 +00: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 12:57:38 +00:00
|
|
|
}
|
|
|
|
}
|
2008-11-27 00:46:33 +00:00
|
|
|
|
|
|
|
if (next->ent.type != TRACE_GRAPH_RET)
|
2009-02-06 17:30:44 +00:00
|
|
|
return NULL;
|
2008-11-27 00:46:33 +00:00
|
|
|
|
|
|
|
if (curr->ent.pid != next->ent.pid ||
|
|
|
|
curr->graph_ent.func != next->ret.func)
|
2009-02-06 17:30:44 +00:00
|
|
|
return NULL;
|
2008-11-27 00:46:33 +00:00
|
|
|
|
2009-02-06 17:30:44 +00:00
|
|
|
/* this is a leaf, now advance the iterator */
|
|
|
|
if (ring_iter)
|
2020-03-17 21:32:25 +00:00
|
|
|
ring_buffer_iter_advance(ring_iter);
|
2009-02-06 17:30:44 +00:00
|
|
|
|
|
|
|
return next;
|
2008-11-27 00:46:33 +00:00
|
|
|
}
|
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
static void print_graph_abs_time(u64 t, struct trace_seq *s)
|
2009-02-18 03:25:25 +00:00
|
|
|
{
|
|
|
|
unsigned long usecs_rem;
|
|
|
|
|
|
|
|
usecs_rem = do_div(t, NSEC_PER_SEC);
|
|
|
|
usecs_rem /= 1000;
|
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_printf(s, "%5lu.%06lu | ",
|
|
|
|
(unsigned long)t, usecs_rem);
|
2009-02-18 03:25:25 +00:00
|
|
|
}
|
|
|
|
|
2019-01-01 15:46:10 +00:00
|
|
|
static void
|
|
|
|
print_graph_rel_time(struct trace_iterator *iter, struct trace_seq *s)
|
|
|
|
{
|
|
|
|
unsigned long long usecs;
|
|
|
|
|
2020-01-09 23:53:48 +00:00
|
|
|
usecs = iter->ts - iter->array_buffer->time_start;
|
2019-01-01 15:46:10 +00:00
|
|
|
do_div(usecs, NSEC_PER_USEC);
|
|
|
|
|
|
|
|
trace_seq_printf(s, "%9llu us | ", usecs);
|
|
|
|
}
|
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
static void
|
2009-02-18 03:25:25 +00:00
|
|
|
print_graph_irq(struct trace_iterator *iter, unsigned long addr,
|
2010-04-02 17:01:21 +00:00
|
|
|
enum trace_type type, int cpu, pid_t pid, u32 flags)
|
2008-12-09 22:55:25 +00:00
|
|
|
{
|
2015-09-30 13:42:05 +00:00
|
|
|
struct trace_array *tr = iter->tr;
|
2009-02-18 03:25:25 +00:00
|
|
|
struct trace_seq *s = &iter->seq;
|
2014-11-06 17:25:09 +00:00
|
|
|
struct trace_entry *ent = iter->ent;
|
2008-12-09 22:55:25 +00:00
|
|
|
|
|
|
|
if (addr < (unsigned long)__irqentry_text_start ||
|
|
|
|
addr >= (unsigned long)__irqentry_text_end)
|
2014-11-12 19:57:38 +00:00
|
|
|
return;
|
2008-12-09 22:55:25 +00:00
|
|
|
|
2015-09-30 13:42:05 +00:00
|
|
|
if (tr->trace_flags & TRACE_ITER_CONTEXT_INFO) {
|
2011-06-03 14:58:51 +00:00
|
|
|
/* Absolute time */
|
2014-11-12 19:57:38 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
|
|
|
|
print_graph_abs_time(iter->ts, s);
|
2009-02-18 03:25:25 +00:00
|
|
|
|
2019-01-01 15:46:10 +00:00
|
|
|
/* Relative time */
|
|
|
|
if (flags & TRACE_GRAPH_PRINT_REL_TIME)
|
|
|
|
print_graph_rel_time(iter, s);
|
|
|
|
|
2011-06-03 14:58:51 +00:00
|
|
|
/* Cpu */
|
2014-11-12 19:57:38 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_CPU)
|
|
|
|
print_graph_cpu(s, cpu);
|
2009-09-11 04:30:26 +00:00
|
|
|
|
2011-06-03 14:58:51 +00:00
|
|
|
/* Proc */
|
|
|
|
if (flags & TRACE_GRAPH_PRINT_PROC) {
|
2014-11-12 19:57:38 +00:00
|
|
|
print_graph_proc(s, pid);
|
|
|
|
trace_seq_puts(s, " | ");
|
2011-06-03 14:58:51 +00:00
|
|
|
}
|
2014-11-06 17:25:09 +00:00
|
|
|
|
|
|
|
/* Latency format */
|
2015-09-30 13:42:05 +00:00
|
|
|
if (tr->trace_flags & TRACE_ITER_LATENCY_FMT)
|
2014-11-12 19:57:38 +00:00
|
|
|
print_graph_lat_fmt(s, ent);
|
2009-01-23 01:04:53 +00:00
|
|
|
}
|
2008-12-09 22:55:25 +00:00
|
|
|
|
2009-01-23 01:04:53 +00:00
|
|
|
/* No overhead */
|
2015-09-30 13:42:05 +00:00
|
|
|
print_graph_duration(tr, 0, s, flags | FLAGS_FILL_START);
|
2008-12-09 22:55:25 +00:00
|
|
|
|
2009-01-23 01:04:53 +00:00
|
|
|
if (type == TRACE_GRAPH_ENT)
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_puts(s, "==========>");
|
2009-01-23 01:04:53 +00:00
|
|
|
else
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_puts(s, "<==========");
|
2009-01-23 01:04:53 +00:00
|
|
|
|
2015-09-30 13:42:05 +00:00
|
|
|
print_graph_duration(tr, 0, s, flags | FLAGS_FILL_END);
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_putc(s, '\n');
|
2008-12-09 22:55:25 +00:00
|
|
|
}
|
2008-11-27 00:46:33 +00:00
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
void
|
2009-03-24 03:12:58 +00:00
|
|
|
trace_print_graph_duration(unsigned long long duration, struct trace_seq *s)
|
2008-11-27 00:46:33 +00:00
|
|
|
{
|
|
|
|
unsigned long nsecs_rem = do_div(duration, 1000);
|
2008-12-03 01:32:12 +00:00
|
|
|
/* log10(ULONG_MAX) + '\0' */
|
2014-11-05 07:18:44 +00:00
|
|
|
char usecs_str[21];
|
2008-12-03 01:32:12 +00:00
|
|
|
char nsecs_str[5];
|
2014-11-12 19:57:38 +00:00
|
|
|
int len;
|
2008-12-03 01:32:12 +00:00
|
|
|
int i;
|
|
|
|
|
2014-11-05 07:18:44 +00:00
|
|
|
sprintf(usecs_str, "%lu", (unsigned long) duration);
|
2008-12-03 01:32:12 +00:00
|
|
|
|
|
|
|
/* Print msecs */
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_printf(s, "%s", usecs_str);
|
2008-12-03 01:32:12 +00:00
|
|
|
|
2014-11-05 07:18:44 +00:00
|
|
|
len = strlen(usecs_str);
|
2008-12-03 01:32:12 +00:00
|
|
|
|
|
|
|
/* Print nsecs (we don't want to exceed 7 numbers) */
|
|
|
|
if (len < 7) {
|
2010-09-29 08:08:23 +00:00
|
|
|
size_t slen = min_t(size_t, sizeof(nsecs_str), 8UL - len);
|
|
|
|
|
|
|
|
snprintf(nsecs_str, slen, "%03lu", nsecs_rem);
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_printf(s, ".%s", nsecs_str);
|
2015-07-17 01:58:52 +00:00
|
|
|
len += strlen(nsecs_str) + 1;
|
2008-12-03 01:32:12 +00:00
|
|
|
}
|
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_puts(s, " us ");
|
2008-12-03 01:32:12 +00:00
|
|
|
|
|
|
|
/* Print remaining spaces to fit the row's width */
|
2015-07-17 01:58:52 +00:00
|
|
|
for (i = len; i < 8; i++)
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_putc(s, ' ');
|
2009-03-24 03:12:58 +00:00
|
|
|
}
|
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
static void
|
2015-09-30 13:42:05 +00:00
|
|
|
print_graph_duration(struct trace_array *tr, unsigned long long duration,
|
|
|
|
struct trace_seq *s, u32 flags)
|
2009-03-24 03:12:58 +00:00
|
|
|
{
|
2011-06-03 14:58:51 +00:00
|
|
|
if (!(flags & TRACE_GRAPH_PRINT_DURATION) ||
|
2015-09-30 13:42:05 +00:00
|
|
|
!(tr->trace_flags & TRACE_ITER_CONTEXT_INFO))
|
2014-11-12 19:57:38 +00:00
|
|
|
return;
|
2011-06-03 14:58:48 +00:00
|
|
|
|
|
|
|
/* No real adata, just filling the column with spaces */
|
2013-11-06 19:50:06 +00:00
|
|
|
switch (flags & TRACE_GRAPH_PRINT_FILL_MASK) {
|
|
|
|
case FLAGS_FILL_FULL:
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_puts(s, " | ");
|
|
|
|
return;
|
2013-11-06 19:50:06 +00:00
|
|
|
case FLAGS_FILL_START:
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_puts(s, " ");
|
|
|
|
return;
|
2013-11-06 19:50:06 +00:00
|
|
|
case FLAGS_FILL_END:
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_puts(s, " |");
|
|
|
|
return;
|
2011-06-03 14:58:48 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
/* Signal a overhead of time execution to the output */
|
2014-11-24 00:34:19 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_OVERHEAD)
|
|
|
|
trace_seq_printf(s, "%c ", trace_find_mark(duration));
|
|
|
|
else
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_puts(s, " ");
|
2009-03-24 03:12:58 +00:00
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_print_graph_duration(duration, s);
|
|
|
|
trace_seq_puts(s, "| ");
|
2008-11-27 00:46:33 +00: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 12:42:15 +00:00
|
|
|
#ifdef CONFIG_FUNCTION_GRAPH_RETVAL
|
|
|
|
|
|
|
|
#define __TRACE_GRAPH_PRINT_RETVAL TRACE_GRAPH_PRINT_RETVAL
|
|
|
|
|
|
|
|
static void print_graph_retval(struct trace_seq *s, unsigned long retval,
|
|
|
|
bool leaf, void *func, bool hex_format)
|
|
|
|
{
|
|
|
|
unsigned long err_code = 0;
|
|
|
|
|
|
|
|
if (retval == 0 || hex_format)
|
|
|
|
goto done;
|
|
|
|
|
|
|
|
/* Check if the return value matches the negative format */
|
|
|
|
if (IS_ENABLED(CONFIG_64BIT) && (retval & BIT(31)) &&
|
|
|
|
(((u64)retval) >> 32) == 0) {
|
|
|
|
/* sign extension */
|
|
|
|
err_code = (unsigned long)(s32)retval;
|
|
|
|
} else {
|
|
|
|
err_code = retval;
|
|
|
|
}
|
|
|
|
|
|
|
|
if (!IS_ERR_VALUE(err_code))
|
|
|
|
err_code = 0;
|
|
|
|
|
|
|
|
done:
|
|
|
|
if (leaf) {
|
|
|
|
if (hex_format || (err_code == 0))
|
|
|
|
trace_seq_printf(s, "%ps(); /* = 0x%lx */\n",
|
|
|
|
func, retval);
|
|
|
|
else
|
|
|
|
trace_seq_printf(s, "%ps(); /* = %ld */\n",
|
|
|
|
func, err_code);
|
|
|
|
} else {
|
|
|
|
if (hex_format || (err_code == 0))
|
|
|
|
trace_seq_printf(s, "} /* %ps = 0x%lx */\n",
|
|
|
|
func, retval);
|
|
|
|
else
|
|
|
|
trace_seq_printf(s, "} /* %ps = %ld */\n",
|
|
|
|
func, err_code);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
#else
|
|
|
|
|
|
|
|
#define __TRACE_GRAPH_PRINT_RETVAL 0
|
|
|
|
|
|
|
|
#define print_graph_retval(_seq, _retval, _leaf, _func, _format) do {} while (0)
|
|
|
|
|
|
|
|
#endif
|
|
|
|
|
2008-11-27 00:46:33 +00:00
|
|
|
/* Case of a leaf function on its call entry */
|
2008-11-25 23:57:25 +00:00
|
|
|
static enum print_line_t
|
2008-11-27 00:46:33 +00:00
|
|
|
print_graph_entry_leaf(struct trace_iterator *iter,
|
2009-02-06 17:30:44 +00:00
|
|
|
struct ftrace_graph_ent_entry *entry,
|
2010-04-02 17:01:21 +00:00
|
|
|
struct ftrace_graph_ret_entry *ret_entry,
|
|
|
|
struct trace_seq *s, u32 flags)
|
2008-11-25 20:07:04 +00:00
|
|
|
{
|
2009-03-19 17:24:42 +00:00
|
|
|
struct fgraph_data *data = iter->private;
|
2015-09-30 13:42:05 +00:00
|
|
|
struct trace_array *tr = iter->tr;
|
2008-11-27 00:46:33 +00:00
|
|
|
struct ftrace_graph_ret *graph_ret;
|
|
|
|
struct ftrace_graph_ent *call;
|
|
|
|
unsigned long long duration;
|
2018-01-31 15:48:49 +00:00
|
|
|
int cpu = iter->cpu;
|
2008-11-27 23:42:46 +00:00
|
|
|
int i;
|
2008-11-25 20:07:04 +00:00
|
|
|
|
2008-11-27 00:46:33 +00:00
|
|
|
graph_ret = &ret_entry->ret;
|
|
|
|
call = &entry->graph_ent;
|
|
|
|
duration = graph_ret->rettime - graph_ret->calltime;
|
|
|
|
|
2009-03-19 17:24:42 +00:00
|
|
|
if (data) {
|
2010-02-26 22:08:16 +00:00
|
|
|
struct fgraph_cpu_data *cpu_data;
|
|
|
|
|
|
|
|
cpu_data = per_cpu_ptr(data->cpu_data, cpu);
|
2009-03-19 17:24:42 +00:00
|
|
|
|
|
|
|
/*
|
|
|
|
* Comments display at + 1 to depth. Since
|
|
|
|
* this is a leaf function, keep the comments
|
|
|
|
* equal to this depth.
|
|
|
|
*/
|
2010-02-26 22:08:16 +00:00
|
|
|
cpu_data->depth = call->depth - 1;
|
|
|
|
|
|
|
|
/* No need to keep this function around for this depth */
|
2016-12-09 01:54:49 +00:00
|
|
|
if (call->depth < FTRACE_RETFUNC_DEPTH &&
|
|
|
|
!WARN_ON_ONCE(call->depth < 0))
|
2010-02-26 22:08:16 +00:00
|
|
|
cpu_data->enter_funcs[call->depth] = 0;
|
2009-03-19 17:24:42 +00:00
|
|
|
}
|
|
|
|
|
2011-06-03 14:58:48 +00:00
|
|
|
/* Overhead and duration */
|
2015-09-30 13:42:05 +00:00
|
|
|
print_graph_duration(tr, duration, s, flags);
|
2008-11-27 23:42:46 +00:00
|
|
|
|
2008-11-27 00:46:33 +00:00
|
|
|
/* Function */
|
2014-11-12 19:57:38 +00:00
|
|
|
for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++)
|
|
|
|
trace_seq_putc(s, ' ');
|
2008-11-27 00:46:33 +00: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 12:42:15 +00:00
|
|
|
/*
|
|
|
|
* Write out the function return value if the option function-retval is
|
|
|
|
* enabled.
|
|
|
|
*/
|
|
|
|
if (flags & __TRACE_GRAPH_PRINT_RETVAL)
|
|
|
|
print_graph_retval(s, graph_ret->retval, true, (void *)call->func,
|
|
|
|
!!(flags & TRACE_GRAPH_PRINT_RETVAL_HEX));
|
|
|
|
else
|
|
|
|
trace_seq_printf(s, "%ps();\n", (void *)call->func);
|
2008-11-27 00:46:33 +00:00
|
|
|
|
2018-01-31 15:48:49 +00:00
|
|
|
print_graph_irq(iter, graph_ret->func, TRACE_GRAPH_RET,
|
|
|
|
cpu, iter->ent->pid, flags);
|
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
return trace_handle_return(s);
|
2008-11-27 00:46:33 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
static enum print_line_t
|
2009-03-19 17:24:42 +00:00
|
|
|
print_graph_entry_nested(struct trace_iterator *iter,
|
|
|
|
struct ftrace_graph_ent_entry *entry,
|
2010-04-02 17:01:21 +00:00
|
|
|
struct trace_seq *s, int cpu, u32 flags)
|
2008-11-27 00:46:33 +00:00
|
|
|
{
|
|
|
|
struct ftrace_graph_ent *call = &entry->graph_ent;
|
2009-03-19 17:24:42 +00:00
|
|
|
struct fgraph_data *data = iter->private;
|
2015-09-30 13:42:05 +00:00
|
|
|
struct trace_array *tr = iter->tr;
|
2009-03-19 17:24:42 +00:00
|
|
|
int i;
|
|
|
|
|
|
|
|
if (data) {
|
2010-02-26 22:08:16 +00:00
|
|
|
struct fgraph_cpu_data *cpu_data;
|
2009-03-19 17:24:42 +00:00
|
|
|
int cpu = iter->cpu;
|
|
|
|
|
2010-02-26 22:08:16 +00: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-09 01:54:49 +00:00
|
|
|
if (call->depth < FTRACE_RETFUNC_DEPTH &&
|
|
|
|
!WARN_ON_ONCE(call->depth < 0))
|
2010-02-26 22:08:16 +00:00
|
|
|
cpu_data->enter_funcs[call->depth] = call->func;
|
2009-03-19 17:24:42 +00:00
|
|
|
}
|
2008-11-27 00:46:33 +00:00
|
|
|
|
2009-01-23 01:04:53 +00:00
|
|
|
/* No time */
|
2015-09-30 13:42:05 +00:00
|
|
|
print_graph_duration(tr, 0, s, flags | FLAGS_FILL_FULL);
|
2008-12-09 22:55:25 +00:00
|
|
|
|
2008-11-27 00:46:33 +00:00
|
|
|
/* Function */
|
2014-11-12 19:57:38 +00:00
|
|
|
for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++)
|
|
|
|
trace_seq_putc(s, ' ');
|
|
|
|
|
|
|
|
trace_seq_printf(s, "%ps() {\n", (void *)call->func);
|
2008-11-25 23:57:25 +00:00
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
if (trace_seq_has_overflowed(s))
|
2008-11-27 00:46:33 +00:00
|
|
|
return TRACE_TYPE_PARTIAL_LINE;
|
|
|
|
|
2009-02-06 17:30:44 +00: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-25 23:57:25 +00:00
|
|
|
}
|
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
static void
|
2009-03-19 15:29:23 +00:00
|
|
|
print_graph_prologue(struct trace_iterator *iter, struct trace_seq *s,
|
2010-04-02 17:01:21 +00:00
|
|
|
int type, unsigned long addr, u32 flags)
|
2008-11-27 00:46:33 +00:00
|
|
|
{
|
2009-03-19 17:24:42 +00:00
|
|
|
struct fgraph_data *data = iter->private;
|
2008-11-27 00:46:33 +00:00
|
|
|
struct trace_entry *ent = iter->ent;
|
2015-09-30 13:42:05 +00:00
|
|
|
struct trace_array *tr = iter->tr;
|
2009-03-19 15:29:23 +00:00
|
|
|
int cpu = iter->cpu;
|
2008-11-27 00:46:33 +00:00
|
|
|
|
2008-11-27 23:42:46 +00:00
|
|
|
/* Pid */
|
2014-11-12 19:57:38 +00:00
|
|
|
verif_pid(s, ent->pid, cpu, data);
|
2009-01-23 01:04:53 +00:00
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
if (type)
|
2009-03-19 15:29:23 +00:00
|
|
|
/* Interrupt */
|
2014-11-12 19:57:38 +00:00
|
|
|
print_graph_irq(iter, addr, type, cpu, ent->pid, flags);
|
2008-11-27 00:46:33 +00:00
|
|
|
|
2015-09-30 13:42:05 +00:00
|
|
|
if (!(tr->trace_flags & TRACE_ITER_CONTEXT_INFO))
|
2014-11-12 19:57:38 +00:00
|
|
|
return;
|
2011-06-03 14:58:51 +00:00
|
|
|
|
2009-01-23 01:04:53 +00:00
|
|
|
/* Absolute time */
|
2014-11-12 19:57:38 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
|
|
|
|
print_graph_abs_time(iter->ts, s);
|
2009-01-23 01:04:53 +00:00
|
|
|
|
2019-01-01 15:46:10 +00:00
|
|
|
/* Relative time */
|
|
|
|
if (flags & TRACE_GRAPH_PRINT_REL_TIME)
|
|
|
|
print_graph_rel_time(iter, s);
|
|
|
|
|
2008-11-27 23:42:46 +00:00
|
|
|
/* Cpu */
|
2014-11-12 19:57:38 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_CPU)
|
|
|
|
print_graph_cpu(s, cpu);
|
2008-12-03 01:30:37 +00:00
|
|
|
|
|
|
|
/* Proc */
|
2010-04-02 17:01:21 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_PROC) {
|
2014-11-12 19:57:38 +00:00
|
|
|
print_graph_proc(s, ent->pid);
|
|
|
|
trace_seq_puts(s, " | ");
|
2008-11-27 23:42:46 +00:00
|
|
|
}
|
2008-11-27 00:46:33 +00:00
|
|
|
|
2009-09-11 04:30:26 +00:00
|
|
|
/* Latency format */
|
2015-09-30 13:42:05 +00:00
|
|
|
if (tr->trace_flags & TRACE_ITER_LATENCY_FMT)
|
2014-11-12 19:57:38 +00:00
|
|
|
print_graph_lat_fmt(s, ent);
|
2009-09-11 04:30:26 +00:00
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
return;
|
2009-03-19 15:29:23 +00:00
|
|
|
}
|
|
|
|
|
2010-09-07 14:53:44 +00:00
|
|
|
/*
|
|
|
|
* Entry check for irq code
|
|
|
|
*
|
|
|
|
* returns 1 if
|
|
|
|
* - we are inside irq code
|
2011-03-31 01:57:33 +00:00
|
|
|
* - we just entered irq code
|
2010-09-07 14:53:44 +00:00
|
|
|
*
|
2021-03-23 17:49:35 +00:00
|
|
|
* returns 0 if
|
2010-09-07 14:53:44 +00: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 15:41:02 +00:00
|
|
|
int *depth_irq;
|
2010-09-07 14:53:44 +00:00
|
|
|
struct fgraph_data *data = iter->private;
|
|
|
|
|
2010-09-24 15:41:02 +00: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 14:53:44 +00:00
|
|
|
return 0;
|
|
|
|
|
2010-09-24 15:41:02 +00:00
|
|
|
depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq);
|
|
|
|
|
2010-09-07 14:53:44 +00: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 15:41:02 +00:00
|
|
|
int *depth_irq;
|
2010-09-07 14:53:44 +00:00
|
|
|
struct fgraph_data *data = iter->private;
|
|
|
|
|
2010-09-24 15:41:02 +00: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 14:53:44 +00:00
|
|
|
return 0;
|
|
|
|
|
2010-09-24 15:41:02 +00:00
|
|
|
depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq);
|
|
|
|
|
2010-09-07 14:53:44 +00: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 15:29:23 +00:00
|
|
|
static enum print_line_t
|
|
|
|
print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
|
2010-04-02 17:01:21 +00:00
|
|
|
struct trace_iterator *iter, u32 flags)
|
2009-03-19 15:29:23 +00:00
|
|
|
{
|
2009-11-24 12:57:38 +00:00
|
|
|
struct fgraph_data *data = iter->private;
|
2009-03-19 15:29:23 +00:00
|
|
|
struct ftrace_graph_ent *call = &field->graph_ent;
|
|
|
|
struct ftrace_graph_ret_entry *leaf_ret;
|
2009-11-24 12:57:38 +00:00
|
|
|
static enum print_line_t ret;
|
|
|
|
int cpu = iter->cpu;
|
2009-03-19 15:29:23 +00:00
|
|
|
|
2010-09-07 14:53:44 +00:00
|
|
|
if (check_irq_entry(iter, flags, call->func, call->depth))
|
|
|
|
return TRACE_TYPE_HANDLED;
|
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
print_graph_prologue(iter, s, TRACE_GRAPH_ENT, call->func, flags);
|
2009-03-19 15:29:23 +00:00
|
|
|
|
2009-02-06 17:30:44 +00:00
|
|
|
leaf_ret = get_return_for_leaf(iter, field);
|
|
|
|
if (leaf_ret)
|
2010-04-02 17:01:21 +00:00
|
|
|
ret = print_graph_entry_leaf(iter, field, leaf_ret, s, flags);
|
2008-11-27 00:46:33 +00:00
|
|
|
else
|
2010-04-02 17:01:21 +00:00
|
|
|
ret = print_graph_entry_nested(iter, field, s, cpu, flags);
|
2008-11-27 00:46:33 +00:00
|
|
|
|
2009-11-24 12:57:38 +00: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 00:46:33 +00:00
|
|
|
}
|
|
|
|
|
2008-11-25 23:57:25 +00:00
|
|
|
static enum print_line_t
|
|
|
|
print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
|
2010-04-02 17:01:21 +00:00
|
|
|
struct trace_entry *ent, struct trace_iterator *iter,
|
|
|
|
u32 flags)
|
2008-11-25 23:57:25 +00:00
|
|
|
{
|
2008-11-27 00:46:33 +00:00
|
|
|
unsigned long long duration = trace->rettime - trace->calltime;
|
2009-03-19 17:24:42 +00:00
|
|
|
struct fgraph_data *data = iter->private;
|
2015-09-30 13:42:05 +00:00
|
|
|
struct trace_array *tr = iter->tr;
|
2009-03-19 17:24:42 +00:00
|
|
|
pid_t pid = ent->pid;
|
|
|
|
int cpu = iter->cpu;
|
2010-02-26 22:08:16 +00:00
|
|
|
int func_match = 1;
|
2009-03-19 17:24:42 +00:00
|
|
|
int i;
|
|
|
|
|
2010-09-07 14:53:44 +00:00
|
|
|
if (check_irq_return(iter, flags, trace->depth))
|
|
|
|
return TRACE_TYPE_HANDLED;
|
|
|
|
|
2009-03-19 17:24:42 +00:00
|
|
|
if (data) {
|
2010-02-26 22:08:16 +00:00
|
|
|
struct fgraph_cpu_data *cpu_data;
|
|
|
|
int cpu = iter->cpu;
|
|
|
|
|
|
|
|
cpu_data = per_cpu_ptr(data->cpu_data, cpu);
|
2009-03-19 17:24:42 +00: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 22:08:16 +00:00
|
|
|
cpu_data->depth = trace->depth - 1;
|
|
|
|
|
2016-12-09 01:54:49 +00:00
|
|
|
if (trace->depth < FTRACE_RETFUNC_DEPTH &&
|
|
|
|
!WARN_ON_ONCE(trace->depth < 0)) {
|
2010-02-26 22:08:16 +00:00
|
|
|
if (cpu_data->enter_funcs[trace->depth] != trace->func)
|
|
|
|
func_match = 0;
|
|
|
|
cpu_data->enter_funcs[trace->depth] = 0;
|
|
|
|
}
|
2009-03-19 17:24:42 +00:00
|
|
|
}
|
2008-11-25 23:57:25 +00:00
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
print_graph_prologue(iter, s, 0, 0, flags);
|
2008-11-26 05:16:27 +00:00
|
|
|
|
2011-06-03 14:58:48 +00:00
|
|
|
/* Overhead and duration */
|
2015-09-30 13:42:05 +00:00
|
|
|
print_graph_duration(tr, duration, s, flags);
|
2008-11-27 23:42:46 +00:00
|
|
|
|
2008-11-27 00:46:33 +00:00
|
|
|
/* Closing brace */
|
2014-11-12 19:57:38 +00:00
|
|
|
for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++)
|
|
|
|
trace_seq_putc(s, ' ');
|
2008-11-25 23:57:25 +00:00
|
|
|
|
2010-02-26 22:08:16 +00: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 12:42:15 +00:00
|
|
|
* Always write out the function name and its return value if the
|
|
|
|
* function-retval option is enabled.
|
2010-02-26 22:08:16 +00: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 12:42:15 +00:00
|
|
|
if (flags & __TRACE_GRAPH_PRINT_RETVAL) {
|
|
|
|
print_graph_retval(s, trace->retval, false, (void *)trace->func,
|
|
|
|
!!(flags & TRACE_GRAPH_PRINT_RETVAL_HEX));
|
|
|
|
} 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
|
|
|
|
trace_seq_printf(s, "} /* %ps */\n", (void *)trace->func);
|
|
|
|
}
|
2008-11-25 20:07:04 +00:00
|
|
|
|
2008-11-27 00:46:33 +00:00
|
|
|
/* Overrun */
|
2014-11-12 19:57:38 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_OVERRUN)
|
2020-10-28 12:19:24 +00:00
|
|
|
trace_seq_printf(s, " (Overruns: %u)\n",
|
2014-11-12 19:57:38 +00:00
|
|
|
trace->overrun);
|
2008-12-09 22:55:25 +00:00
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
print_graph_irq(iter, trace->func, TRACE_GRAPH_RET,
|
|
|
|
cpu, pid, flags);
|
2008-12-09 22:55:25 +00:00
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
return trace_handle_return(s);
|
2008-11-25 23:57:25 +00:00
|
|
|
}
|
|
|
|
|
2008-12-03 22:45:11 +00:00
|
|
|
static enum print_line_t
|
2010-04-02 17:01:21 +00:00
|
|
|
print_graph_comment(struct trace_seq *s, struct trace_entry *ent,
|
|
|
|
struct trace_iterator *iter, u32 flags)
|
2008-12-03 22:45:11 +00:00
|
|
|
{
|
2015-09-30 13:42:05 +00:00
|
|
|
struct trace_array *tr = iter->tr;
|
|
|
|
unsigned long sym_flags = (tr->trace_flags & TRACE_ITER_SYM_MASK);
|
2009-03-19 17:24:42 +00:00
|
|
|
struct fgraph_data *data = iter->private;
|
2009-03-19 19:14:46 +00:00
|
|
|
struct trace_event *event;
|
2009-03-19 17:24:42 +00:00
|
|
|
int depth = 0;
|
2008-12-03 22:45:11 +00:00
|
|
|
int ret;
|
2009-03-19 17:24:42 +00:00
|
|
|
int i;
|
|
|
|
|
|
|
|
if (data)
|
2009-11-24 12:57:38 +00:00
|
|
|
depth = per_cpu_ptr(data->cpu_data, iter->cpu)->depth;
|
2009-01-23 01:04:53 +00:00
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
print_graph_prologue(iter, s, 0, 0, flags);
|
2009-02-18 03:25:25 +00:00
|
|
|
|
2009-01-23 01:04:53 +00:00
|
|
|
/* No time */
|
2015-09-30 13:42:05 +00:00
|
|
|
print_graph_duration(tr, 0, s, flags | FLAGS_FILL_FULL);
|
2008-12-03 22:45:11 +00:00
|
|
|
|
|
|
|
/* Indentation */
|
2009-03-19 17:24:42 +00:00
|
|
|
if (depth > 0)
|
2014-11-12 19:57:38 +00:00
|
|
|
for (i = 0; i < (depth + 1) * TRACE_GRAPH_INDENT; i++)
|
|
|
|
trace_seq_putc(s, ' ');
|
2008-12-03 22:45:11 +00:00
|
|
|
|
|
|
|
/* The comment */
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_puts(s, "/* ");
|
2009-03-06 16:21:49 +00:00
|
|
|
|
2009-03-19 19:14:46 +00:00
|
|
|
switch (iter->ent->type) {
|
2016-09-01 02:43:54 +00:00
|
|
|
case TRACE_BPUTS:
|
|
|
|
ret = trace_print_bputs_msg_only(iter);
|
|
|
|
if (ret != TRACE_TYPE_HANDLED)
|
|
|
|
return ret;
|
|
|
|
break;
|
2009-03-19 19:14:46 +00: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 22:46:14 +00:00
|
|
|
ret = event->funcs->trace(iter, sym_flags, event);
|
2009-03-19 19:14:46 +00:00
|
|
|
if (ret != TRACE_TYPE_HANDLED)
|
|
|
|
return ret;
|
|
|
|
}
|
2008-12-03 22:45:11 +00:00
|
|
|
|
2014-11-14 20:49:41 +00:00
|
|
|
if (trace_seq_has_overflowed(s))
|
|
|
|
goto out;
|
|
|
|
|
2008-12-24 00:43:25 +00:00
|
|
|
/* Strip ending newline */
|
2014-06-25 19:54:42 +00:00
|
|
|
if (s->buffer[s->seq.len - 1] == '\n') {
|
|
|
|
s->buffer[s->seq.len - 1] = '\0';
|
|
|
|
s->seq.len--;
|
2008-12-24 00:43:25 +00:00
|
|
|
}
|
|
|
|
|
2014-11-12 19:57:38 +00:00
|
|
|
trace_seq_puts(s, " */\n");
|
2014-11-14 20:49:41 +00:00
|
|
|
out:
|
2014-11-12 19:57:38 +00:00
|
|
|
return trace_handle_return(s);
|
2008-12-03 22:45:11 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
|
2008-11-25 23:57:25 +00:00
|
|
|
enum print_line_t
|
2011-06-03 14:58:47 +00:00
|
|
|
print_graph_function_flags(struct trace_iterator *iter, u32 flags)
|
2008-11-25 23:57:25 +00:00
|
|
|
{
|
2009-11-24 12:57:38 +00:00
|
|
|
struct ftrace_graph_ent_entry *field;
|
|
|
|
struct fgraph_data *data = iter->private;
|
2008-11-25 23:57:25 +00:00
|
|
|
struct trace_entry *entry = iter->ent;
|
2009-03-19 19:14:46 +00:00
|
|
|
struct trace_seq *s = &iter->seq;
|
2009-11-24 12:57:38 +00: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) {
|
|
|
|
field = &data->ent;
|
|
|
|
iter->cpu = data->cpu;
|
2010-04-02 17:01:21 +00:00
|
|
|
ret = print_graph_entry(field, s, iter, flags);
|
2009-11-24 12:57:38 +00: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 20:07:04 +00:00
|
|
|
|
2008-11-25 23:57:25 +00:00
|
|
|
switch (entry->type) {
|
|
|
|
case TRACE_GRAPH_ENT: {
|
2009-07-28 12:11:24 +00: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 12:57:38 +00:00
|
|
|
struct ftrace_graph_ent_entry saved;
|
2008-11-25 23:57:25 +00:00
|
|
|
trace_assign_type(field, entry);
|
2009-07-28 12:11:24 +00:00
|
|
|
saved = *field;
|
2010-04-02 17:01:21 +00:00
|
|
|
return print_graph_entry(&saved, s, iter, flags);
|
2008-11-25 23:57:25 +00:00
|
|
|
}
|
|
|
|
case TRACE_GRAPH_RET: {
|
|
|
|
struct ftrace_graph_ret_entry *field;
|
|
|
|
trace_assign_type(field, entry);
|
2010-04-02 17:01:21 +00:00
|
|
|
return print_graph_return(&field->ret, s, entry, iter, flags);
|
2008-11-25 23:57:25 +00:00
|
|
|
}
|
2010-04-02 17:01:22 +00:00
|
|
|
case TRACE_STACK:
|
|
|
|
case TRACE_FN:
|
|
|
|
/* dont trace stack and functions as comments */
|
|
|
|
return TRACE_TYPE_UNHANDLED;
|
|
|
|
|
2008-11-25 23:57:25 +00:00
|
|
|
default:
|
2010-04-02 17:01:21 +00:00
|
|
|
return print_graph_comment(s, entry, iter, flags);
|
2008-11-25 20:07:04 +00:00
|
|
|
}
|
2009-03-19 19:14:46 +00:00
|
|
|
|
|
|
|
return TRACE_TYPE_HANDLED;
|
2008-11-25 20:07:04 +00:00
|
|
|
}
|
|
|
|
|
2010-04-02 17:01:21 +00:00
|
|
|
static enum print_line_t
|
|
|
|
print_graph_function(struct trace_iterator *iter)
|
|
|
|
{
|
2011-06-03 14:58:47 +00:00
|
|
|
return print_graph_function_flags(iter, tracer_flags.val);
|
2010-04-02 17:01:21 +00:00
|
|
|
}
|
|
|
|
|
2010-04-02 17:01:20 +00:00
|
|
|
static enum print_line_t
|
2010-04-22 22:46:14 +00:00
|
|
|
print_graph_function_event(struct trace_iterator *iter, int flags,
|
|
|
|
struct trace_event *event)
|
2010-04-02 17:01:20 +00:00
|
|
|
{
|
|
|
|
return print_graph_function(iter);
|
|
|
|
}
|
|
|
|
|
2010-04-02 17:01:21 +00:00
|
|
|
static void print_lat_header(struct seq_file *s, u32 flags)
|
2009-09-11 04:30:26 +00:00
|
|
|
{
|
|
|
|
static const char spaces[] = " " /* 16 spaces */
|
|
|
|
" " /* 4 spaces */
|
|
|
|
" "; /* 17 spaces */
|
|
|
|
int size = 0;
|
|
|
|
|
2010-04-02 17:01:21 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
|
2009-09-11 04:30:26 +00:00
|
|
|
size += 16;
|
2019-01-01 15:46:10 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_REL_TIME)
|
|
|
|
size += 16;
|
2010-04-02 17:01:21 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_CPU)
|
2009-09-11 04:30:26 +00:00
|
|
|
size += 4;
|
2010-04-02 17:01:21 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_PROC)
|
2009-09-11 04:30:26 +00: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 14:58:50 +00:00
|
|
|
seq_printf(s, "#%.*s||| / \n", size, spaces);
|
2009-09-11 04:30:26 +00:00
|
|
|
}
|
|
|
|
|
2015-09-30 13:42:05 +00:00
|
|
|
static void __print_graph_headers_flags(struct trace_array *tr,
|
|
|
|
struct seq_file *s, u32 flags)
|
2008-12-08 00:56:06 +00:00
|
|
|
{
|
2015-09-30 13:42:05 +00:00
|
|
|
int lat = tr->trace_flags & TRACE_ITER_LATENCY_FMT;
|
2009-09-11 04:30:26 +00:00
|
|
|
|
|
|
|
if (lat)
|
2010-04-02 17:01:21 +00:00
|
|
|
print_lat_header(s, flags);
|
2009-09-11 04:30:26 +00:00
|
|
|
|
2008-12-08 00:56:06 +00:00
|
|
|
/* 1st line */
|
2014-11-08 20:42:12 +00:00
|
|
|
seq_putc(s, '#');
|
2010-04-02 17:01:21 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
|
2014-11-08 20:42:10 +00:00
|
|
|
seq_puts(s, " TIME ");
|
2019-01-01 15:46:10 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_REL_TIME)
|
|
|
|
seq_puts(s, " REL TIME ");
|
2010-04-02 17:01:21 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_CPU)
|
2014-11-08 20:42:10 +00:00
|
|
|
seq_puts(s, " CPU");
|
2010-04-02 17:01:21 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_PROC)
|
2014-11-08 20:42:10 +00:00
|
|
|
seq_puts(s, " TASK/PID ");
|
2009-09-11 04:30:26 +00:00
|
|
|
if (lat)
|
2019-01-01 15:46:12 +00:00
|
|
|
seq_puts(s, "|||| ");
|
2010-04-02 17:01:21 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_DURATION)
|
2014-11-08 20:42:10 +00:00
|
|
|
seq_puts(s, " DURATION ");
|
|
|
|
seq_puts(s, " FUNCTION CALLS\n");
|
2008-12-08 00:56:06 +00:00
|
|
|
|
|
|
|
/* 2nd line */
|
2014-11-08 20:42:12 +00:00
|
|
|
seq_putc(s, '#');
|
2010-04-02 17:01:21 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
|
2014-11-08 20:42:10 +00:00
|
|
|
seq_puts(s, " | ");
|
2019-01-01 15:46:10 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_REL_TIME)
|
|
|
|
seq_puts(s, " | ");
|
2010-04-02 17:01:21 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_CPU)
|
2014-11-08 20:42:10 +00:00
|
|
|
seq_puts(s, " | ");
|
2010-04-02 17:01:21 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_PROC)
|
2014-11-08 20:42:10 +00:00
|
|
|
seq_puts(s, " | | ");
|
2009-09-11 04:30:26 +00:00
|
|
|
if (lat)
|
2019-01-01 15:46:12 +00:00
|
|
|
seq_puts(s, "|||| ");
|
2010-04-02 17:01:21 +00:00
|
|
|
if (flags & TRACE_GRAPH_PRINT_DURATION)
|
2014-11-08 20:42:10 +00:00
|
|
|
seq_puts(s, " | | ");
|
|
|
|
seq_puts(s, " | | | |\n");
|
2008-12-08 00:56:06 +00:00
|
|
|
}
|
2009-01-23 01:04:53 +00:00
|
|
|
|
2014-07-18 22:07:49 +00:00
|
|
|
static void print_graph_headers(struct seq_file *s)
|
2010-04-02 17:01:21 +00:00
|
|
|
{
|
|
|
|
print_graph_headers_flags(s, tracer_flags.val);
|
|
|
|
}
|
|
|
|
|
2010-09-23 12:00:52 +00:00
|
|
|
void print_graph_headers_flags(struct seq_file *s, u32 flags)
|
|
|
|
{
|
|
|
|
struct trace_iterator *iter = s->private;
|
2015-09-30 13:42:05 +00:00
|
|
|
struct trace_array *tr = iter->tr;
|
2010-09-23 12:00:52 +00:00
|
|
|
|
2015-09-30 13:42:05 +00:00
|
|
|
if (!(tr->trace_flags & TRACE_ITER_CONTEXT_INFO))
|
2011-06-03 14:58:51 +00:00
|
|
|
return;
|
|
|
|
|
2015-09-30 13:42:05 +00:00
|
|
|
if (tr->trace_flags & TRACE_ITER_LATENCY_FMT) {
|
2010-09-23 12:00:52 +00:00
|
|
|
/* print nothing if the buffers are empty */
|
|
|
|
if (trace_empty(iter))
|
|
|
|
return;
|
|
|
|
|
|
|
|
print_trace_header(s, iter);
|
2011-06-03 14:58:47 +00:00
|
|
|
}
|
2010-09-23 12:00:52 +00:00
|
|
|
|
2015-09-30 13:42:05 +00:00
|
|
|
__print_graph_headers_flags(tr, s, flags);
|
2010-09-23 12:00:52 +00:00
|
|
|
}
|
|
|
|
|
2010-04-02 17:01:22 +00:00
|
|
|
void graph_trace_open(struct trace_iterator *iter)
|
2009-01-23 01:04:53 +00:00
|
|
|
{
|
2009-03-19 17:24:42 +00:00
|
|
|
/* pid and depth on the last trace processed */
|
2009-11-24 12:57:38 +00:00
|
|
|
struct fgraph_data *data;
|
2015-04-13 20:30:12 +00:00
|
|
|
gfp_t gfpflags;
|
2009-01-23 01:04:53 +00:00
|
|
|
int cpu;
|
|
|
|
|
2009-11-24 12:57:38 +00:00
|
|
|
iter->private = NULL;
|
|
|
|
|
2015-04-13 20:30:12 +00: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 17:24:42 +00:00
|
|
|
if (!data)
|
2009-11-24 12:57:38 +00:00
|
|
|
goto out_err;
|
|
|
|
|
2015-04-13 20:30:12 +00:00
|
|
|
data->cpu_data = alloc_percpu_gfp(struct fgraph_cpu_data, gfpflags);
|
2009-11-24 12:57:38 +00: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 14:53:44 +00:00
|
|
|
int *depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq);
|
|
|
|
|
2009-11-24 12:57:38 +00:00
|
|
|
*pid = -1;
|
|
|
|
*depth = 0;
|
|
|
|
*ignore = 0;
|
2010-09-07 14:53:44 +00:00
|
|
|
*depth_irq = -1;
|
2009-11-24 12:57:38 +00:00
|
|
|
}
|
2009-01-23 01:04:53 +00:00
|
|
|
|
2009-03-19 17:24:42 +00:00
|
|
|
iter->private = data;
|
2009-11-24 12:57:38 +00:00
|
|
|
|
|
|
|
return;
|
|
|
|
|
|
|
|
out_err_free:
|
|
|
|
kfree(data);
|
|
|
|
out_err:
|
2016-03-22 21:28:09 +00:00
|
|
|
pr_warn("function graph tracer: not enough memory\n");
|
2009-01-23 01:04:53 +00:00
|
|
|
}
|
|
|
|
|
2010-04-02 17:01:22 +00:00
|
|
|
void graph_trace_close(struct trace_iterator *iter)
|
2009-01-23 01:04:53 +00:00
|
|
|
{
|
2009-11-24 12:57:38 +00:00
|
|
|
struct fgraph_data *data = iter->private;
|
|
|
|
|
|
|
|
if (data) {
|
|
|
|
free_percpu(data->cpu_data);
|
|
|
|
kfree(data);
|
|
|
|
}
|
2009-01-23 01:04:53 +00:00
|
|
|
}
|
|
|
|
|
2014-01-10 16:13:54 +00:00
|
|
|
static int
|
|
|
|
func_graph_set_flag(struct trace_array *tr, u32 old_flags, u32 bit, int set)
|
2010-09-14 22:58:33 +00:00
|
|
|
{
|
|
|
|
if (bit == TRACE_GRAPH_PRINT_IRQS)
|
|
|
|
ftrace_graph_skip_irqs = !set;
|
|
|
|
|
2015-09-29 23:06:50 +00: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 22:58:33 +00:00
|
|
|
return 0;
|
|
|
|
}
|
|
|
|
|
2010-04-22 22:46:14 +00:00
|
|
|
static struct trace_event_functions graph_functions = {
|
|
|
|
.trace = print_graph_function_event,
|
|
|
|
};
|
|
|
|
|
2010-04-02 17:01:20 +00:00
|
|
|
static struct trace_event graph_trace_entry_event = {
|
|
|
|
.type = TRACE_GRAPH_ENT,
|
2010-04-22 22:46:14 +00:00
|
|
|
.funcs = &graph_functions,
|
2010-04-02 17:01:20 +00:00
|
|
|
};
|
|
|
|
|
|
|
|
static struct trace_event graph_trace_ret_event = {
|
|
|
|
.type = TRACE_GRAPH_RET,
|
2010-04-22 22:46:14 +00:00
|
|
|
.funcs = &graph_functions
|
2010-04-02 17:01:20 +00:00
|
|
|
};
|
|
|
|
|
2013-07-18 18:41:51 +00:00
|
|
|
static struct tracer graph_trace __tracer_data = {
|
2009-03-10 18:10:56 +00:00
|
|
|
.name = "function_graph",
|
2014-07-18 11:17:27 +00:00
|
|
|
.update_thresh = graph_trace_update_thresh,
|
2009-01-23 01:04:53 +00:00
|
|
|
.open = graph_trace_open,
|
2009-11-24 12:57:38 +00:00
|
|
|
.pipe_open = graph_trace_open,
|
2009-01-23 01:04:53 +00:00
|
|
|
.close = graph_trace_close,
|
2009-11-24 12:57:38 +00:00
|
|
|
.pipe_close = graph_trace_close,
|
2009-03-10 18:10:56 +00:00
|
|
|
.init = graph_trace_init,
|
|
|
|
.reset = graph_trace_reset,
|
2008-12-08 00:56:06 +00:00
|
|
|
.print_line = print_graph_function,
|
|
|
|
.print_header = print_graph_headers,
|
2008-11-25 20:07:04 +00:00
|
|
|
.flags = &tracer_flags,
|
2010-09-14 22:58:33 +00:00
|
|
|
.set_flag = func_graph_set_flag,
|
2009-02-07 20:33:57 +00:00
|
|
|
#ifdef CONFIG_FTRACE_SELFTEST
|
|
|
|
.selftest = trace_selftest_startup_function_graph,
|
|
|
|
#endif
|
2008-11-25 20:07:04 +00:00
|
|
|
};
|
|
|
|
|
2013-01-16 15:49:37 +00: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-09 00:28:28 +00:00
|
|
|
fgraph_max_depth = val;
|
2013-01-16 15:49:37 +00: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-09 00:28:28 +00:00
|
|
|
n = sprintf(buf, "%d\n", fgraph_max_depth);
|
2013-01-16 15:49:37 +00: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 17:13:40 +00:00
|
|
|
static __init int init_graph_tracefs(void)
|
2013-01-16 15:49:37 +00:00
|
|
|
{
|
2020-07-12 01:10:36 +00:00
|
|
|
int ret;
|
2013-01-16 15:49:37 +00:00
|
|
|
|
2020-07-12 01:10:36 +00:00
|
|
|
ret = tracing_init_dentry();
|
|
|
|
if (ret)
|
2013-01-16 15:49:37 +00:00
|
|
|
return 0;
|
|
|
|
|
2021-08-18 15:24:51 +00:00
|
|
|
trace_create_file("max_graph_depth", TRACE_MODE_WRITE, NULL,
|
2013-01-16 15:49:37 +00:00
|
|
|
NULL, &graph_depth_fops);
|
|
|
|
|
|
|
|
return 0;
|
|
|
|
}
|
2015-01-20 17:13:40 +00:00
|
|
|
fs_initcall(init_graph_tracefs);
|
2013-01-16 15:49:37 +00:00
|
|
|
|
2008-11-25 20:07:04 +00:00
|
|
|
static __init int init_graph_trace(void)
|
|
|
|
{
|
2017-09-08 23:14:18 +00:00
|
|
|
max_bytes_for_cpu = snprintf(NULL, 0, "%u", nr_cpu_ids - 1);
|
2009-07-28 12:26:06 +00:00
|
|
|
|
2015-05-05 13:39:12 +00:00
|
|
|
if (!register_trace_event(&graph_trace_entry_event)) {
|
2016-03-22 21:28:09 +00:00
|
|
|
pr_warn("Warning: could not register graph trace events\n");
|
2010-04-02 17:01:20 +00:00
|
|
|
return 1;
|
|
|
|
}
|
|
|
|
|
2015-05-05 13:39:12 +00:00
|
|
|
if (!register_trace_event(&graph_trace_ret_event)) {
|
2016-03-22 21:28:09 +00:00
|
|
|
pr_warn("Warning: could not register graph trace events\n");
|
2010-04-02 17:01:20 +00:00
|
|
|
return 1;
|
|
|
|
}
|
|
|
|
|
2008-11-25 20:07:04 +00:00
|
|
|
return register_tracer(&graph_trace);
|
|
|
|
}
|
|
|
|
|
2012-10-05 16:13:07 +00:00
|
|
|
core_initcall(init_graph_trace);
|