perf kwork: New tool to trace time properties of kernel work (such as softirq, and workqueue)
The 'perf kwork' tool is used to trace time properties of kernel work
(such as irq, softirq, and workqueue), including runtime, latency, and
timehist, using the infrastructure in the perf tools to allow tracing
extra targets.
This is the first commit to reuse the 'perf record' framework code to
implement a simple record function, kwork is not supported currently.
Test cases:
# perf
usage: perf [--version] [--help] [OPTIONS] COMMAND [ARGS]
The most commonly used perf commands are:
<SNIP>
iostat Show I/O performance metrics
kallsyms Searches running kernel for symbols
kmem Tool to trace/measure kernel memory properties
kvm Tool to trace/measure kvm guest os
kwork Tool to trace/measure kernel work properties (latencies)
list List all symbolic event types
lock Analyze lock events
mem Profile memory accesses
record Run a command and record its profile into perf.data
<SNIP>
See 'perf help COMMAND' for more information on a specific command.
# perf kwork
Usage: perf kwork [<options>] {record}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork record -- sleep 1
[ perf record: Woken up 0 times to write data ]
[ perf record: Captured and wrote 1.787 MB perf.data ]
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-2-yangjihong1@huawei.com
[ Add {} for multiline if blocks ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:17 +00:00
|
|
|
#ifndef PERF_UTIL_KWORK_H
|
|
|
|
#define PERF_UTIL_KWORK_H
|
|
|
|
|
|
|
|
#include "util/tool.h"
|
|
|
|
#include "util/time-utils.h"
|
|
|
|
|
|
|
|
#include <linux/bitmap.h>
|
2022-10-27 19:49:58 +00:00
|
|
|
#include <linux/list.h>
|
|
|
|
#include <linux/rbtree.h>
|
|
|
|
#include <linux/types.h>
|
|
|
|
|
|
|
|
struct perf_sample;
|
|
|
|
struct perf_session;
|
perf kwork: New tool to trace time properties of kernel work (such as softirq, and workqueue)
The 'perf kwork' tool is used to trace time properties of kernel work
(such as irq, softirq, and workqueue), including runtime, latency, and
timehist, using the infrastructure in the perf tools to allow tracing
extra targets.
This is the first commit to reuse the 'perf record' framework code to
implement a simple record function, kwork is not supported currently.
Test cases:
# perf
usage: perf [--version] [--help] [OPTIONS] COMMAND [ARGS]
The most commonly used perf commands are:
<SNIP>
iostat Show I/O performance metrics
kallsyms Searches running kernel for symbols
kmem Tool to trace/measure kernel memory properties
kvm Tool to trace/measure kvm guest os
kwork Tool to trace/measure kernel work properties (latencies)
list List all symbolic event types
lock Analyze lock events
mem Profile memory accesses
record Run a command and record its profile into perf.data
<SNIP>
See 'perf help COMMAND' for more information on a specific command.
# perf kwork
Usage: perf kwork [<options>] {record}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork record -- sleep 1
[ perf record: Woken up 0 times to write data ]
[ perf record: Captured and wrote 1.787 MB perf.data ]
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-2-yangjihong1@huawei.com
[ Add {} for multiline if blocks ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:17 +00:00
|
|
|
|
|
|
|
enum kwork_class_type {
|
2022-07-09 01:50:18 +00:00
|
|
|
KWORK_CLASS_IRQ,
|
perf kwork: Add softirq kwork record support
Record softirq events irq:softirq_raise, irq:softirq_entry &
irq:softirq_exit.
Test cases:
Record all events:
# perf kwork record -o perf_kwork.date -- sleep 1
[ perf record: Woken up 0 times to write data ]
[ perf record: Captured and wrote 0.897 MB perf_kwork.date ]
#
# perf evlist -i perf_kwork.date
irq:irq_handler_entry
irq:irq_handler_exit
irq:softirq_raise
irq:softirq_entry
irq:softirq_exit
dummy:HG
# Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events
Record softirq events:
# perf kwork -k softirq record -o perf_kwork.date -- sleep 1
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.141 MB perf_kwork.date ]
#
# perf evlist -i perf_kwork.date
irq:softirq_raise
irq:softirq_entry
irq:softirq_exit
dummy:HG
# Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events
Committer testing:
# perf kwork record sleep 1
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 3.078 MB perf.data (17433 samples) ]
# perf evlist -v
irq:irq_handler_entry: type: 2, size: 128, config: 0x97, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID, disabled: 1, inherit: 1, sample_id_all: 1, exclude_guest: 1
irq:irq_handler_exit: type: 2, size: 128, config: 0x96, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID, disabled: 1, inherit: 1, sample_id_all: 1, exclude_guest: 1
irq:softirq_raise: type: 2, size: 128, config: 0x93, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID, disabled: 1, inherit: 1, sample_id_all: 1, exclude_guest: 1
irq:softirq_entry: type: 2, size: 128, config: 0x95, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID, disabled: 1, inherit: 1, sample_id_all: 1, exclude_guest: 1
irq:softirq_exit: type: 2, size: 128, config: 0x94, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID, disabled: 1, inherit: 1, sample_id_all: 1, exclude_guest: 1
dummy:HG: type: 1, size: 128, config: 0x9, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|RAW|IDENTIFIER, read_format: ID, inherit: 1, mmap: 1, comm: 1, task: 1, sample_id_all: 1, mmap2: 1, comm_exec: 1, ksymbol: 1, bpf_event: 1
# Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events
# perf script | head
migration/12 73 [012] 25884.940992: irq:softirq_raise: vec=9 [action=RCU]
migration/12 73 [012] 25884.940994: irq:softirq_entry: vec=9 [action=RCU]
migration/12 73 [012] 25884.940995: irq:softirq_exit: vec=9 [action=RCU]
swapper 0 [004] 25884.940995: irq:softirq_raise: vec=9 [action=RCU]
swapper 0 [004] 25884.940998: irq:softirq_entry: vec=9 [action=RCU]
swapper 0 [004] 25884.940999: irq:softirq_exit: vec=9 [action=RCU]
cc1 71212 [021] 25884.941990: irq:softirq_raise: vec=9 [action=RCU]
swapper 0 [004] 25884.941991: irq:softirq_raise: vec=9 [action=RCU]
cc1 71212 [021] 25884.941992: irq:softirq_raise: vec=7 [action=SCHED]
perf-exec 71208 [013] 25884.941992: irq:softirq_raise: vec=9 [action=RCU]
#
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-4-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:19 +00:00
|
|
|
KWORK_CLASS_SOFTIRQ,
|
perf kwork: Add workqueue kwork record support
Record workqueue events workqueue:workqueue_activate_work,
workqueue:workqueue_execute_start & workqueue:workqueue_execute_end
Tese cases:
Record all events:
# perf kwork record -o perf_kwork.date -- sleep 1
[ perf record: Woken up 0 times to write data ]
[ perf record: Captured and wrote 0.857 MB perf_kwork.date ]
#
# perf evlist -i perf_kwork.date
irq:irq_handler_entry
irq:irq_handler_exit
irq:softirq_raise
irq:softirq_entry
irq:softirq_exit
workqueue:workqueue_activate_work
workqueue:workqueue_execute_start
workqueue:workqueue_execute_end
dummy:HG
# Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events
Record workqueue events:
# perf kwork -k workqueue record -o perf_kwork.date -- sleep 1
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.081 MB perf_kwork.date ]
#
# perf evlist -i perf_kwork.date
workqueue:workqueue_activate_work
workqueue:workqueue_execute_start
workqueue:workqueue_execute_end
dummy:HG
# Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events
Committer testing:
# perf kwork record sleep 1
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 3.430 MB perf.data (24130 samples) ]
# perf evlist -v
irq:irq_handler_entry: type: 2, size: 128, config: 0x97, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID, disabled: 1, inherit: 1, sample_id_all: 1, exclude_guest: 1
irq:irq_handler_exit: type: 2, size: 128, config: 0x96, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID, disabled: 1, inherit: 1, sample_id_all: 1, exclude_guest: 1
irq:softirq_raise: type: 2, size: 128, config: 0x93, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID, disabled: 1, inherit: 1, sample_id_all: 1, exclude_guest: 1
irq:softirq_entry: type: 2, size: 128, config: 0x95, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID, disabled: 1, inherit: 1, sample_id_all: 1, exclude_guest: 1
irq:softirq_exit: type: 2, size: 128, config: 0x94, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID, disabled: 1, inherit: 1, sample_id_all: 1, exclude_guest: 1
workqueue:workqueue_activate_work: type: 2, size: 128, config: 0x106, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID, disabled: 1, inherit: 1, sample_id_all: 1, exclude_guest: 1
workqueue:workqueue_execute_start: type: 2, size: 128, config: 0x105, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID, disabled: 1, inherit: 1, sample_id_all: 1, exclude_guest: 1
workqueue:workqueue_execute_end: type: 2, size: 128, config: 0x104, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID, disabled: 1, inherit: 1, sample_id_all: 1, exclude_guest: 1
dummy:HG: type: 1, size: 128, config: 0x9, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|RAW|IDENTIFIER, read_format: ID, inherit: 1, mmap: 1, comm: 1, task: 1, sample_id_all: 1, mmap2: 1, comm_exec: 1, ksymbol: 1, bpf_event: 1
# Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events
# perf script | grep workqueue | head
swapper 0 [018] 26035.043289: workqueue:workqueue_activate_work: work struct 0xffff8b8ffeeae368
kworker/18:2-ev 70440 [018] 26035.043293: workqueue:workqueue_execute_start: work struct 0xffff8b8ffeeae368: function free_work
kworker/18:2-ev 70440 [018] 26035.043301: workqueue:workqueue_execute_end: work struct 0xffff8b8ffeeae368: function free_work
swapper 0 [021] 26035.044704: workqueue:workqueue_activate_work: work struct 0xffff8b8ffef6e368
kworker/21:0-ev 4080535 [021] 26035.044709: workqueue:workqueue_execute_start: work struct 0xffff8b8ffef6e368: function free_work
kworker/21:0-ev 4080535 [021] 26035.044716: workqueue:workqueue_execute_end: work struct 0xffff8b8ffef6e368: function free_work
swapper 0 [018] 26035.045230: workqueue:workqueue_activate_work: work struct 0xffff8b8ffeeae368
kworker/18:2-ev 70440 [018] 26035.045232: workqueue:workqueue_execute_start: work struct 0xffff8b8ffeeae368: function free_work
kworker/18:2-ev 70440 [018] 26035.045235: workqueue:workqueue_execute_end: work struct 0xffff8b8ffeeae368: function free_work
swapper 0 [001] 26035.052046: workqueue:workqueue_activate_work: work struct 0xffff8b8108901590
#
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-5-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:20 +00:00
|
|
|
KWORK_CLASS_WORKQUEUE,
|
perf kwork: Add sched record support
The kwork_class type of sched is added to support recording and parsing of
sched_switch events.
As follows:
# perf kwork -h
Usage: perf kwork [<options>] {record|report|latency|timehist}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, sched, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork -k sched record true
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.083 MB perf.data (47 samples) ]
# perf evlist
sched:sched_switch
dummy:HG
# Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events
Reviewed-by: Ian Rogers <irogers@google.com>
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ravi Bangoria <ravi.bangoria@amd.com>
Cc: Sandipan Das <sandipan.das@amd.com>
Link: https://lore.kernel.org/r/20230812084917.169338-8-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2023-08-12 08:49:08 +00:00
|
|
|
KWORK_CLASS_SCHED,
|
perf kwork: New tool to trace time properties of kernel work (such as softirq, and workqueue)
The 'perf kwork' tool is used to trace time properties of kernel work
(such as irq, softirq, and workqueue), including runtime, latency, and
timehist, using the infrastructure in the perf tools to allow tracing
extra targets.
This is the first commit to reuse the 'perf record' framework code to
implement a simple record function, kwork is not supported currently.
Test cases:
# perf
usage: perf [--version] [--help] [OPTIONS] COMMAND [ARGS]
The most commonly used perf commands are:
<SNIP>
iostat Show I/O performance metrics
kallsyms Searches running kernel for symbols
kmem Tool to trace/measure kernel memory properties
kvm Tool to trace/measure kvm guest os
kwork Tool to trace/measure kernel work properties (latencies)
list List all symbolic event types
lock Analyze lock events
mem Profile memory accesses
record Run a command and record its profile into perf.data
<SNIP>
See 'perf help COMMAND' for more information on a specific command.
# perf kwork
Usage: perf kwork [<options>] {record}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork record -- sleep 1
[ perf record: Woken up 0 times to write data ]
[ perf record: Captured and wrote 1.787 MB perf.data ]
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-2-yangjihong1@huawei.com
[ Add {} for multiline if blocks ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:17 +00:00
|
|
|
KWORK_CLASS_MAX,
|
|
|
|
};
|
|
|
|
|
perf kwork: Implement 'report' subcommand
Implements framework of 'perf kwork report', which is used to report
time properties such as run time and frequency:
Test cases:
# perf kwork
Usage: perf kwork [<options>] {record|report}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork report -h
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -S
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
Total count : 0
Total runtime (msec) : 0.000 (0.000% load average)
Total time span (msec) : 0.000
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -C 0,100
Requested CPU 100 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork report -s runtime1
Error: Unknown --sort key: `runtime1'
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork report --time 00FFF,
Invalid time span
Since there are no report supported events, the output is empty.
Briefly describe the data structure:
1. "class" indicates event type. For example, irq and softiq correspond
to different types.
2. "cluster" refers to a specific event corresponding to a type. For
example, RCU and TIMER in softirq correspond to different clusters,
which contains three types of events: raise, entry, and exit.
3. "atom" includes time of each sample and sample of the previous phase.
(For example, exit corresponds to entry, which is used for timehist.)
Committer notes:
- Add {} for multiline if blocks.
- report_print_work() should either return that ret variable that
accounts how many bytes were printed or stop accounting and be void.
Do the former for now to avoid this:
builtin-kwork.c:534:6: error: variable 'ret' set but not used [-Werror,-Wunused-but-set-variable]
int ret = 0;
^
1 error generated.
When building with:
⬢[acme@toolbox perf]$ clang --version
clang version 13.0.0 (https://github.com/llvm/llvm-project e8991caea8690ec2d17b0b7e1c29bf0da6609076)
Also:
- if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
+ if (dst_type < KWORK_TRACE_MAX) {
Several versions of clang and at least this gcc:
3 51.40 alpine:3.9 : FAIL gcc version 8.3.0 (Alpine 8.3.0)
builtin-kwork.c:411:16: error: comparison of unsigned enum expression >= 0 is
always true [-Werror,-Wtautological-compare]
if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
As the first entry in a enum is zero.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-7-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:22 +00:00
|
|
|
enum kwork_report_type {
|
|
|
|
KWORK_REPORT_RUNTIME,
|
perf kwork: Implement perf kwork latency
Implements framework of perf kwork latency, which is used to report time
properties such as delay time and frequency.
Test cases:
# perf kwork lat -h
Usage: perf kwork latency [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): avg, max, count
--time <str> Time span for analysis (start,stop)
# perf kwork lat -C 199
Requested CPU 199 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork lat -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork lat -s avg1
Error: Unknown --sort key: `avg1'
Usage: perf kwork latency [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): avg, max, count
--time <str> Time span for analysis (start,stop)
# perf kwork lat --time FFFF,
Invalid time span
# perf kwork lat
Kwork Name | Cpu | Avg delay | Count | Max delay | Max delay start | Max delay end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
INFO: 36.570% skipped events (31537 including 0 raise, 31537 entry, 0 exit)
Since there are no latency-enabled events, the output is empty.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-11-yangjihong1@huawei.com
[ Add {} for multiline if blocks ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:26 +00:00
|
|
|
KWORK_REPORT_LATENCY,
|
2022-07-09 01:50:29 +00:00
|
|
|
KWORK_REPORT_TIMEHIST,
|
perf kwork top: Introduce new top utility
Some common tools for collecting statistics on CPU usage, such as top,
obtain statistics from timer interrupt sampling, and then periodically
read statistics from /proc/stat.
This method has some deviations:
1. In the tick interrupt, the time between the last tick and the current
tick is counted in the current task. However, the task may be running
only part of the time.
2. For each task, the top tool periodically reads the /proc/{PID}/status
information. For tasks with a short life cycle, it may be missed.
In conclusion, the top tool cannot accurately collect statistics on the
CPU usage and running time of tasks.
The statistical method based on sched_switch tracepoint can accurately
calculate the CPU usage of all tasks. This method is applicable to
scenarios where performance comparison data is of high precision.
Example usage:
# perf kwork
Usage: perf kwork [<options>] {record|report|latency|timehist|top}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, sched, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork -k sched record -- perf bench sched messaging -g 1 -l 10000
# Running 'sched/messaging' benchmark:
# 20 sender and receiver processes per group
# 1 groups == 40 processes run
Total time: 14.074 [sec]
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 15.886 MB perf.data (129472 samples) ]
# perf kwork top
Total : 115708.178 ms, 8 cpus
%Cpu(s): 9.78% id
%Cpu0 [||||||||||||||||||||||||||| 90.55%]
%Cpu1 [||||||||||||||||||||||||||| 90.51%]
%Cpu2 [|||||||||||||||||||||||||| 88.57%]
%Cpu3 [||||||||||||||||||||||||||| 91.18%]
%Cpu4 [||||||||||||||||||||||||||| 91.09%]
%Cpu5 [||||||||||||||||||||||||||| 90.88%]
%Cpu6 [|||||||||||||||||||||||||| 88.64%]
%Cpu7 [||||||||||||||||||||||||||| 90.28%]
PID %CPU RUNTIME COMMMAND
----------------------------------------------------
4113 22.23 3221.547 ms sched-messaging
4105 21.61 3131.495 ms sched-messaging
4119 21.53 3120.937 ms sched-messaging
4103 21.39 3101.614 ms sched-messaging
4106 21.37 3095.209 ms sched-messaging
4104 21.25 3077.269 ms sched-messaging
4115 21.21 3073.188 ms sched-messaging
4109 21.18 3069.022 ms sched-messaging
4111 20.78 3010.033 ms sched-messaging
4114 20.74 3007.073 ms sched-messaging
4108 20.73 3002.137 ms sched-messaging
4107 20.47 2967.292 ms sched-messaging
4117 20.39 2955.335 ms sched-messaging
4112 20.34 2947.080 ms sched-messaging
4118 20.32 2942.519 ms sched-messaging
4121 20.23 2929.865 ms sched-messaging
4110 20.22 2930.078 ms sched-messaging
4122 20.15 2919.542 ms sched-messaging
4120 19.77 2866.032 ms sched-messaging
4116 19.72 2857.660 ms sched-messaging
4127 16.19 2346.334 ms sched-messaging
4142 15.86 2297.600 ms sched-messaging
4141 15.62 2262.646 ms sched-messaging
4136 15.41 2231.408 ms sched-messaging
4130 15.38 2227.008 ms sched-messaging
4129 15.31 2217.692 ms sched-messaging
4126 15.21 2201.711 ms sched-messaging
4139 15.19 2200.722 ms sched-messaging
4137 15.10 2188.633 ms sched-messaging
4134 15.06 2182.082 ms sched-messaging
4132 15.02 2177.530 ms sched-messaging
4131 14.73 2131.973 ms sched-messaging
4125 14.68 2125.439 ms sched-messaging
4128 14.66 2122.255 ms sched-messaging
4123 14.65 2122.113 ms sched-messaging
4135 14.56 2107.144 ms sched-messaging
4133 14.51 2103.549 ms sched-messaging
4124 14.27 2066.671 ms sched-messaging
4140 14.17 2052.251 ms sched-messaging
4138 13.81 2000.361 ms sched-messaging
0 11.42 1652.009 ms swapper/2
0 11.35 1641.694 ms swapper/6
0 9.71 1405.108 ms swapper/7
0 9.48 1372.338 ms swapper/1
0 9.44 1366.013 ms swapper/0
0 9.11 1318.382 ms swapper/5
0 8.90 1287.582 ms swapper/4
0 8.81 1274.356 ms swapper/3
4100 2.61 379.328 ms perf
4101 1.16 169.487 ms perf-exec
151 0.65 94.741 ms systemd-resolve
249 0.36 53.030 ms sd-resolve
153 0.14 21.405 ms systemd-timesyn
1 0.10 16.200 ms systemd
16 0.09 15.785 ms rcu_preempt
4102 0.06 9.727 ms perf
4095 0.03 5.464 ms kworker/7:1
98 0.02 3.231 ms jbd2/sda-8
353 0.02 4.115 ms sshd
75 0.02 3.889 ms kworker/2:1
73 0.01 1.552 ms kworker/5:1
64 0.01 1.591 ms kworker/4:1
74 0.01 1.952 ms kworker/3:1
61 0.01 2.608 ms kcompactd0
397 0.01 1.602 ms kworker/1:1
69 0.01 1.817 ms kworker/1:1H
10 0.01 2.553 ms kworker/u16:0
2909 0.01 2.684 ms kworker/0:2
1211 0.00 0.426 ms kworker/7:0
97 0.00 0.153 ms kworker/7:1H
51 0.00 0.100 ms ksoftirqd/7
120 0.00 0.856 ms systemd-journal
76 0.00 1.414 ms kworker/6:1
46 0.00 0.246 ms ksoftirqd/6
45 0.00 0.164 ms migration/6
41 0.00 0.098 ms ksoftirqd/5
40 0.00 0.207 ms migration/5
86 0.00 1.339 ms kworker/4:1H
36 0.00 0.252 ms ksoftirqd/4
35 0.00 0.090 ms migration/4
31 0.00 0.156 ms ksoftirqd/3
30 0.00 0.073 ms migration/3
26 0.00 0.180 ms ksoftirqd/2
25 0.00 0.085 ms migration/2
21 0.00 0.106 ms ksoftirqd/1
20 0.00 0.118 ms migration/1
302 0.00 1.440 ms systemd-logind
17 0.00 0.132 ms migration/0
15 0.00 0.255 ms ksoftirqd/0
Reviewed-by: Ian Rogers <irogers@google.com>
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ravi Bangoria <ravi.bangoria@amd.com>
Cc: Sandipan Das <sandipan.das@amd.com>
Link: https://lore.kernel.org/r/20230812084917.169338-10-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2023-08-12 08:49:10 +00:00
|
|
|
KWORK_REPORT_TOP,
|
perf kwork: Implement 'report' subcommand
Implements framework of 'perf kwork report', which is used to report
time properties such as run time and frequency:
Test cases:
# perf kwork
Usage: perf kwork [<options>] {record|report}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork report -h
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -S
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
Total count : 0
Total runtime (msec) : 0.000 (0.000% load average)
Total time span (msec) : 0.000
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -C 0,100
Requested CPU 100 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork report -s runtime1
Error: Unknown --sort key: `runtime1'
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork report --time 00FFF,
Invalid time span
Since there are no report supported events, the output is empty.
Briefly describe the data structure:
1. "class" indicates event type. For example, irq and softiq correspond
to different types.
2. "cluster" refers to a specific event corresponding to a type. For
example, RCU and TIMER in softirq correspond to different clusters,
which contains three types of events: raise, entry, and exit.
3. "atom" includes time of each sample and sample of the previous phase.
(For example, exit corresponds to entry, which is used for timehist.)
Committer notes:
- Add {} for multiline if blocks.
- report_print_work() should either return that ret variable that
accounts how many bytes were printed or stop accounting and be void.
Do the former for now to avoid this:
builtin-kwork.c:534:6: error: variable 'ret' set but not used [-Werror,-Wunused-but-set-variable]
int ret = 0;
^
1 error generated.
When building with:
⬢[acme@toolbox perf]$ clang --version
clang version 13.0.0 (https://github.com/llvm/llvm-project e8991caea8690ec2d17b0b7e1c29bf0da6609076)
Also:
- if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
+ if (dst_type < KWORK_TRACE_MAX) {
Several versions of clang and at least this gcc:
3 51.40 alpine:3.9 : FAIL gcc version 8.3.0 (Alpine 8.3.0)
builtin-kwork.c:411:16: error: comparison of unsigned enum expression >= 0 is
always true [-Werror,-Wtautological-compare]
if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
As the first entry in a enum is zero.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-7-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:22 +00:00
|
|
|
};
|
|
|
|
|
|
|
|
enum kwork_trace_type {
|
perf kwork: Implement perf kwork latency
Implements framework of perf kwork latency, which is used to report time
properties such as delay time and frequency.
Test cases:
# perf kwork lat -h
Usage: perf kwork latency [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): avg, max, count
--time <str> Time span for analysis (start,stop)
# perf kwork lat -C 199
Requested CPU 199 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork lat -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork lat -s avg1
Error: Unknown --sort key: `avg1'
Usage: perf kwork latency [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): avg, max, count
--time <str> Time span for analysis (start,stop)
# perf kwork lat --time FFFF,
Invalid time span
# perf kwork lat
Kwork Name | Cpu | Avg delay | Count | Max delay | Max delay start | Max delay end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
INFO: 36.570% skipped events (31537 including 0 raise, 31537 entry, 0 exit)
Since there are no latency-enabled events, the output is empty.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-11-yangjihong1@huawei.com
[ Add {} for multiline if blocks ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:26 +00:00
|
|
|
KWORK_TRACE_RAISE,
|
perf kwork: Implement 'report' subcommand
Implements framework of 'perf kwork report', which is used to report
time properties such as run time and frequency:
Test cases:
# perf kwork
Usage: perf kwork [<options>] {record|report}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork report -h
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -S
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
Total count : 0
Total runtime (msec) : 0.000 (0.000% load average)
Total time span (msec) : 0.000
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -C 0,100
Requested CPU 100 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork report -s runtime1
Error: Unknown --sort key: `runtime1'
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork report --time 00FFF,
Invalid time span
Since there are no report supported events, the output is empty.
Briefly describe the data structure:
1. "class" indicates event type. For example, irq and softiq correspond
to different types.
2. "cluster" refers to a specific event corresponding to a type. For
example, RCU and TIMER in softirq correspond to different clusters,
which contains three types of events: raise, entry, and exit.
3. "atom" includes time of each sample and sample of the previous phase.
(For example, exit corresponds to entry, which is used for timehist.)
Committer notes:
- Add {} for multiline if blocks.
- report_print_work() should either return that ret variable that
accounts how many bytes were printed or stop accounting and be void.
Do the former for now to avoid this:
builtin-kwork.c:534:6: error: variable 'ret' set but not used [-Werror,-Wunused-but-set-variable]
int ret = 0;
^
1 error generated.
When building with:
⬢[acme@toolbox perf]$ clang --version
clang version 13.0.0 (https://github.com/llvm/llvm-project e8991caea8690ec2d17b0b7e1c29bf0da6609076)
Also:
- if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
+ if (dst_type < KWORK_TRACE_MAX) {
Several versions of clang and at least this gcc:
3 51.40 alpine:3.9 : FAIL gcc version 8.3.0 (Alpine 8.3.0)
builtin-kwork.c:411:16: error: comparison of unsigned enum expression >= 0 is
always true [-Werror,-Wtautological-compare]
if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
As the first entry in a enum is zero.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-7-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:22 +00:00
|
|
|
KWORK_TRACE_ENTRY,
|
|
|
|
KWORK_TRACE_EXIT,
|
|
|
|
KWORK_TRACE_MAX,
|
|
|
|
};
|
|
|
|
|
|
|
|
/*
|
|
|
|
* data structure:
|
|
|
|
*
|
|
|
|
* +==================+ +============+ +======================+
|
|
|
|
* | class | | work | | atom |
|
|
|
|
* +==================+ +============+ +======================+
|
|
|
|
* +------------+ | +-----+ | | +------+ | | +-------+ +-----+ |
|
|
|
|
* | perf_kwork | +-> | irq | --------|+-> | eth0 | --+-> | raise | - | ... | --+ +-----------+
|
|
|
|
* +-----+------+ || +-----+ ||| +------+ ||| +-------+ +-----+ | | | |
|
|
|
|
* | || ||| ||| | +-> | atom_page |
|
|
|
|
* | || ||| ||| +-------+ +-----+ | | |
|
|
|
|
* | class_list ||| |+-> | entry | - | ... | ----> | |
|
|
|
|
* | || ||| ||| +-------+ +-----+ | | |
|
|
|
|
* | || ||| ||| | +-> | |
|
|
|
|
* | || ||| ||| +-------+ +-----+ | | | |
|
|
|
|
* | || ||| |+-> | exit | - | ... | --+ +-----+-----+
|
|
|
|
* | || ||| | | +-------+ +-----+ | |
|
|
|
|
* | || ||| | | | |
|
|
|
|
* | || ||| +-----+ | | | |
|
|
|
|
* | || |+-> | ... | | | | |
|
|
|
|
* | || | | +-----+ | | | |
|
|
|
|
* | || | | | | | |
|
|
|
|
* | || +---------+ | | +-----+ | | +-------+ +-----+ | |
|
|
|
|
* | +-> | softirq | -------> | RCU | ---+-> | raise | - | ... | --+ +-----+-----+
|
|
|
|
* | || +---------+ | | +-----+ ||| +-------+ +-----+ | | | |
|
|
|
|
* | || | | ||| | +-> | atom_page |
|
|
|
|
* | || | | ||| +-------+ +-----+ | | |
|
|
|
|
* | || | | |+-> | entry | - | ... | ----> | |
|
|
|
|
* | || | | ||| +-------+ +-----+ | | |
|
|
|
|
* | || | | ||| | +-> | |
|
|
|
|
* | || | | ||| +-------+ +-----+ | | | |
|
|
|
|
* | || | | |+-> | exit | - | ... | --+ +-----+-----+
|
|
|
|
* | || | | | | +-------+ +-----+ | |
|
|
|
|
* | || | | | | | |
|
|
|
|
* | || +-----------+ | | +-----+ | | | |
|
|
|
|
* | +-> | workqueue | -----> | ... | | | | |
|
|
|
|
* | | +-----------+ | | +-----+ | | | |
|
|
|
|
* | +==================+ +============+ +======================+ |
|
|
|
|
* | |
|
|
|
|
* +----> atom_page_list ---------------------------------------------------------+
|
|
|
|
*
|
|
|
|
*/
|
|
|
|
|
|
|
|
struct kwork_atom {
|
|
|
|
struct list_head list;
|
|
|
|
u64 time;
|
|
|
|
struct kwork_atom *prev;
|
|
|
|
|
|
|
|
void *page_addr;
|
|
|
|
unsigned long bit_inpage;
|
|
|
|
};
|
|
|
|
|
|
|
|
#define NR_ATOM_PER_PAGE 128
|
|
|
|
struct kwork_atom_page {
|
|
|
|
struct list_head list;
|
|
|
|
struct kwork_atom atoms[NR_ATOM_PER_PAGE];
|
|
|
|
DECLARE_BITMAP(bitmap, NR_ATOM_PER_PAGE);
|
|
|
|
};
|
|
|
|
|
2023-08-12 08:49:05 +00:00
|
|
|
struct perf_kwork;
|
perf kwork: Implement 'report' subcommand
Implements framework of 'perf kwork report', which is used to report
time properties such as run time and frequency:
Test cases:
# perf kwork
Usage: perf kwork [<options>] {record|report}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork report -h
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -S
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
Total count : 0
Total runtime (msec) : 0.000 (0.000% load average)
Total time span (msec) : 0.000
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -C 0,100
Requested CPU 100 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork report -s runtime1
Error: Unknown --sort key: `runtime1'
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork report --time 00FFF,
Invalid time span
Since there are no report supported events, the output is empty.
Briefly describe the data structure:
1. "class" indicates event type. For example, irq and softiq correspond
to different types.
2. "cluster" refers to a specific event corresponding to a type. For
example, RCU and TIMER in softirq correspond to different clusters,
which contains three types of events: raise, entry, and exit.
3. "atom" includes time of each sample and sample of the previous phase.
(For example, exit corresponds to entry, which is used for timehist.)
Committer notes:
- Add {} for multiline if blocks.
- report_print_work() should either return that ret variable that
accounts how many bytes were printed or stop accounting and be void.
Do the former for now to avoid this:
builtin-kwork.c:534:6: error: variable 'ret' set but not used [-Werror,-Wunused-but-set-variable]
int ret = 0;
^
1 error generated.
When building with:
⬢[acme@toolbox perf]$ clang --version
clang version 13.0.0 (https://github.com/llvm/llvm-project e8991caea8690ec2d17b0b7e1c29bf0da6609076)
Also:
- if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
+ if (dst_type < KWORK_TRACE_MAX) {
Several versions of clang and at least this gcc:
3 51.40 alpine:3.9 : FAIL gcc version 8.3.0 (Alpine 8.3.0)
builtin-kwork.c:411:16: error: comparison of unsigned enum expression >= 0 is
always true [-Werror,-Wtautological-compare]
if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
As the first entry in a enum is zero.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-7-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:22 +00:00
|
|
|
struct kwork_class;
|
|
|
|
struct kwork_work {
|
|
|
|
/*
|
|
|
|
* class field
|
|
|
|
*/
|
|
|
|
struct rb_node node;
|
|
|
|
struct kwork_class *class;
|
|
|
|
|
|
|
|
/*
|
|
|
|
* work field
|
|
|
|
*/
|
|
|
|
u64 id;
|
|
|
|
int cpu;
|
|
|
|
char *name;
|
|
|
|
|
|
|
|
/*
|
|
|
|
* atom field
|
|
|
|
*/
|
|
|
|
u64 nr_atoms;
|
|
|
|
struct list_head atom_list[KWORK_TRACE_MAX];
|
|
|
|
|
|
|
|
/*
|
|
|
|
* runtime report
|
|
|
|
*/
|
|
|
|
u64 max_runtime;
|
|
|
|
u64 max_runtime_start;
|
|
|
|
u64 max_runtime_end;
|
|
|
|
u64 total_runtime;
|
perf kwork: Implement perf kwork latency
Implements framework of perf kwork latency, which is used to report time
properties such as delay time and frequency.
Test cases:
# perf kwork lat -h
Usage: perf kwork latency [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): avg, max, count
--time <str> Time span for analysis (start,stop)
# perf kwork lat -C 199
Requested CPU 199 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork lat -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork lat -s avg1
Error: Unknown --sort key: `avg1'
Usage: perf kwork latency [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): avg, max, count
--time <str> Time span for analysis (start,stop)
# perf kwork lat --time FFFF,
Invalid time span
# perf kwork lat
Kwork Name | Cpu | Avg delay | Count | Max delay | Max delay start | Max delay end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
INFO: 36.570% skipped events (31537 including 0 raise, 31537 entry, 0 exit)
Since there are no latency-enabled events, the output is empty.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-11-yangjihong1@huawei.com
[ Add {} for multiline if blocks ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:26 +00:00
|
|
|
|
|
|
|
/*
|
|
|
|
* latency report
|
|
|
|
*/
|
|
|
|
u64 max_latency;
|
|
|
|
u64 max_latency_start;
|
|
|
|
u64 max_latency_end;
|
|
|
|
u64 total_latency;
|
perf kwork top: Introduce new top utility
Some common tools for collecting statistics on CPU usage, such as top,
obtain statistics from timer interrupt sampling, and then periodically
read statistics from /proc/stat.
This method has some deviations:
1. In the tick interrupt, the time between the last tick and the current
tick is counted in the current task. However, the task may be running
only part of the time.
2. For each task, the top tool periodically reads the /proc/{PID}/status
information. For tasks with a short life cycle, it may be missed.
In conclusion, the top tool cannot accurately collect statistics on the
CPU usage and running time of tasks.
The statistical method based on sched_switch tracepoint can accurately
calculate the CPU usage of all tasks. This method is applicable to
scenarios where performance comparison data is of high precision.
Example usage:
# perf kwork
Usage: perf kwork [<options>] {record|report|latency|timehist|top}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, sched, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork -k sched record -- perf bench sched messaging -g 1 -l 10000
# Running 'sched/messaging' benchmark:
# 20 sender and receiver processes per group
# 1 groups == 40 processes run
Total time: 14.074 [sec]
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 15.886 MB perf.data (129472 samples) ]
# perf kwork top
Total : 115708.178 ms, 8 cpus
%Cpu(s): 9.78% id
%Cpu0 [||||||||||||||||||||||||||| 90.55%]
%Cpu1 [||||||||||||||||||||||||||| 90.51%]
%Cpu2 [|||||||||||||||||||||||||| 88.57%]
%Cpu3 [||||||||||||||||||||||||||| 91.18%]
%Cpu4 [||||||||||||||||||||||||||| 91.09%]
%Cpu5 [||||||||||||||||||||||||||| 90.88%]
%Cpu6 [|||||||||||||||||||||||||| 88.64%]
%Cpu7 [||||||||||||||||||||||||||| 90.28%]
PID %CPU RUNTIME COMMMAND
----------------------------------------------------
4113 22.23 3221.547 ms sched-messaging
4105 21.61 3131.495 ms sched-messaging
4119 21.53 3120.937 ms sched-messaging
4103 21.39 3101.614 ms sched-messaging
4106 21.37 3095.209 ms sched-messaging
4104 21.25 3077.269 ms sched-messaging
4115 21.21 3073.188 ms sched-messaging
4109 21.18 3069.022 ms sched-messaging
4111 20.78 3010.033 ms sched-messaging
4114 20.74 3007.073 ms sched-messaging
4108 20.73 3002.137 ms sched-messaging
4107 20.47 2967.292 ms sched-messaging
4117 20.39 2955.335 ms sched-messaging
4112 20.34 2947.080 ms sched-messaging
4118 20.32 2942.519 ms sched-messaging
4121 20.23 2929.865 ms sched-messaging
4110 20.22 2930.078 ms sched-messaging
4122 20.15 2919.542 ms sched-messaging
4120 19.77 2866.032 ms sched-messaging
4116 19.72 2857.660 ms sched-messaging
4127 16.19 2346.334 ms sched-messaging
4142 15.86 2297.600 ms sched-messaging
4141 15.62 2262.646 ms sched-messaging
4136 15.41 2231.408 ms sched-messaging
4130 15.38 2227.008 ms sched-messaging
4129 15.31 2217.692 ms sched-messaging
4126 15.21 2201.711 ms sched-messaging
4139 15.19 2200.722 ms sched-messaging
4137 15.10 2188.633 ms sched-messaging
4134 15.06 2182.082 ms sched-messaging
4132 15.02 2177.530 ms sched-messaging
4131 14.73 2131.973 ms sched-messaging
4125 14.68 2125.439 ms sched-messaging
4128 14.66 2122.255 ms sched-messaging
4123 14.65 2122.113 ms sched-messaging
4135 14.56 2107.144 ms sched-messaging
4133 14.51 2103.549 ms sched-messaging
4124 14.27 2066.671 ms sched-messaging
4140 14.17 2052.251 ms sched-messaging
4138 13.81 2000.361 ms sched-messaging
0 11.42 1652.009 ms swapper/2
0 11.35 1641.694 ms swapper/6
0 9.71 1405.108 ms swapper/7
0 9.48 1372.338 ms swapper/1
0 9.44 1366.013 ms swapper/0
0 9.11 1318.382 ms swapper/5
0 8.90 1287.582 ms swapper/4
0 8.81 1274.356 ms swapper/3
4100 2.61 379.328 ms perf
4101 1.16 169.487 ms perf-exec
151 0.65 94.741 ms systemd-resolve
249 0.36 53.030 ms sd-resolve
153 0.14 21.405 ms systemd-timesyn
1 0.10 16.200 ms systemd
16 0.09 15.785 ms rcu_preempt
4102 0.06 9.727 ms perf
4095 0.03 5.464 ms kworker/7:1
98 0.02 3.231 ms jbd2/sda-8
353 0.02 4.115 ms sshd
75 0.02 3.889 ms kworker/2:1
73 0.01 1.552 ms kworker/5:1
64 0.01 1.591 ms kworker/4:1
74 0.01 1.952 ms kworker/3:1
61 0.01 2.608 ms kcompactd0
397 0.01 1.602 ms kworker/1:1
69 0.01 1.817 ms kworker/1:1H
10 0.01 2.553 ms kworker/u16:0
2909 0.01 2.684 ms kworker/0:2
1211 0.00 0.426 ms kworker/7:0
97 0.00 0.153 ms kworker/7:1H
51 0.00 0.100 ms ksoftirqd/7
120 0.00 0.856 ms systemd-journal
76 0.00 1.414 ms kworker/6:1
46 0.00 0.246 ms ksoftirqd/6
45 0.00 0.164 ms migration/6
41 0.00 0.098 ms ksoftirqd/5
40 0.00 0.207 ms migration/5
86 0.00 1.339 ms kworker/4:1H
36 0.00 0.252 ms ksoftirqd/4
35 0.00 0.090 ms migration/4
31 0.00 0.156 ms ksoftirqd/3
30 0.00 0.073 ms migration/3
26 0.00 0.180 ms ksoftirqd/2
25 0.00 0.085 ms migration/2
21 0.00 0.106 ms ksoftirqd/1
20 0.00 0.118 ms migration/1
302 0.00 1.440 ms systemd-logind
17 0.00 0.132 ms migration/0
15 0.00 0.255 ms ksoftirqd/0
Reviewed-by: Ian Rogers <irogers@google.com>
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ravi Bangoria <ravi.bangoria@amd.com>
Cc: Sandipan Das <sandipan.das@amd.com>
Link: https://lore.kernel.org/r/20230812084917.169338-10-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2023-08-12 08:49:10 +00:00
|
|
|
|
|
|
|
/*
|
|
|
|
* top report
|
|
|
|
*/
|
|
|
|
u32 cpu_usage;
|
perf kwork top: Implements BPF-based cpu usage statistics
Use BPF to collect statistics on the CPU usage based on perf BPF skeletons.
Example usage:
# perf kwork top -h
Usage: perf kwork top [<options>]
-b, --use-bpf Use BPF to measure task cpu usage
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): rate, runtime, tid
--time <str> Time span for analysis (start,stop)
#
# perf kwork -k sched top -b
Starting trace, Hit <Ctrl+C> to stop and report
^C
Total : 160702.425 ms, 8 cpus
%Cpu(s): 36.00% id, 0.00% hi, 0.00% si
%Cpu0 [|||||||||||||||||| 61.66%]
%Cpu1 [|||||||||||||||||| 61.27%]
%Cpu2 [||||||||||||||||||| 66.40%]
%Cpu3 [|||||||||||||||||| 61.28%]
%Cpu4 [|||||||||||||||||| 61.82%]
%Cpu5 [||||||||||||||||||||||| 77.41%]
%Cpu6 [|||||||||||||||||| 61.73%]
%Cpu7 [|||||||||||||||||| 63.25%]
PID SPID %CPU RUNTIME COMMMAND
-------------------------------------------------------------
0 0 38.72 8089.463 ms [swapper/1]
0 0 38.71 8084.547 ms [swapper/3]
0 0 38.33 8007.532 ms [swapper/0]
0 0 38.26 7992.985 ms [swapper/6]
0 0 38.17 7971.865 ms [swapper/4]
0 0 36.74 7447.765 ms [swapper/7]
0 0 33.59 6486.942 ms [swapper/2]
0 0 22.58 3771.268 ms [swapper/5]
9545 9351 2.48 447.136 ms sched-messaging
9574 9351 2.09 418.583 ms sched-messaging
9724 9351 2.05 372.407 ms sched-messaging
9531 9351 2.01 368.804 ms sched-messaging
9512 9351 2.00 362.250 ms sched-messaging
9514 9351 1.95 357.767 ms sched-messaging
9538 9351 1.86 384.476 ms sched-messaging
9712 9351 1.84 386.490 ms sched-messaging
9723 9351 1.83 380.021 ms sched-messaging
9722 9351 1.82 382.738 ms sched-messaging
9517 9351 1.81 354.794 ms sched-messaging
9559 9351 1.79 344.305 ms sched-messaging
9725 9351 1.77 365.315 ms sched-messaging
<SNIP>
# perf kwork -k sched top -b -n perf
Starting trace, Hit <Ctrl+C> to stop and report
^C
Total : 151563.332 ms, 8 cpus
%Cpu(s): 26.49% id, 0.00% hi, 0.00% si
%Cpu0 [ 0.01%]
%Cpu1 [ 0.00%]
%Cpu2 [ 0.00%]
%Cpu3 [ 0.00%]
%Cpu4 [ 0.00%]
%Cpu5 [ 0.00%]
%Cpu6 [ 0.00%]
%Cpu7 [ 0.00%]
PID SPID %CPU RUNTIME COMMMAND
-------------------------------------------------------------
9754 9754 0.01 2.303 ms perf
#
# perf kwork -k sched top -b -C 2,3,4
Starting trace, Hit <Ctrl+C> to stop and report
^C
Total : 48016.721 ms, 3 cpus
%Cpu(s): 27.82% id, 0.00% hi, 0.00% si
%Cpu2 [|||||||||||||||||||||| 74.68%]
%Cpu3 [||||||||||||||||||||| 71.06%]
%Cpu4 [||||||||||||||||||||| 70.91%]
PID SPID %CPU RUNTIME COMMMAND
-------------------------------------------------------------
0 0 29.08 4734.998 ms [swapper/4]
0 0 28.93 4710.029 ms [swapper/3]
0 0 25.31 3912.363 ms [swapper/2]
10248 10158 1.62 264.931 ms sched-messaging
10253 10158 1.62 265.136 ms sched-messaging
10158 10158 1.60 263.013 ms bash
10360 10158 1.49 243.639 ms sched-messaging
10413 10158 1.48 238.604 ms sched-messaging
10531 10158 1.47 234.067 ms sched-messaging
10400 10158 1.47 240.631 ms sched-messaging
10355 10158 1.47 230.586 ms sched-messaging
10377 10158 1.43 234.835 ms sched-messaging
10526 10158 1.42 232.045 ms sched-messaging
10298 10158 1.41 222.396 ms sched-messaging
10410 10158 1.38 221.853 ms sched-messaging
10364 10158 1.38 226.042 ms sched-messaging
10480 10158 1.36 213.633 ms sched-messaging
10370 10158 1.36 223.620 ms sched-messaging
10553 10158 1.34 217.169 ms sched-messaging
10291 10158 1.34 211.516 ms sched-messaging
10251 10158 1.34 218.813 ms sched-messaging
10522 10158 1.33 218.498 ms sched-messaging
10288 10158 1.33 216.787 ms sched-messaging
<SNIP>
Reviewed-by: Ian Rogers <irogers@google.com>
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ravi Bangoria <ravi.bangoria@amd.com>
Cc: Sandipan Das <sandipan.das@amd.com>
Link: https://lore.kernel.org/r/20230812084917.169338-15-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2023-08-12 08:49:15 +00:00
|
|
|
u32 tgid;
|
|
|
|
bool is_kthread;
|
perf kwork: Implement 'report' subcommand
Implements framework of 'perf kwork report', which is used to report
time properties such as run time and frequency:
Test cases:
# perf kwork
Usage: perf kwork [<options>] {record|report}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork report -h
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -S
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
Total count : 0
Total runtime (msec) : 0.000 (0.000% load average)
Total time span (msec) : 0.000
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -C 0,100
Requested CPU 100 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork report -s runtime1
Error: Unknown --sort key: `runtime1'
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork report --time 00FFF,
Invalid time span
Since there are no report supported events, the output is empty.
Briefly describe the data structure:
1. "class" indicates event type. For example, irq and softiq correspond
to different types.
2. "cluster" refers to a specific event corresponding to a type. For
example, RCU and TIMER in softirq correspond to different clusters,
which contains three types of events: raise, entry, and exit.
3. "atom" includes time of each sample and sample of the previous phase.
(For example, exit corresponds to entry, which is used for timehist.)
Committer notes:
- Add {} for multiline if blocks.
- report_print_work() should either return that ret variable that
accounts how many bytes were printed or stop accounting and be void.
Do the former for now to avoid this:
builtin-kwork.c:534:6: error: variable 'ret' set but not used [-Werror,-Wunused-but-set-variable]
int ret = 0;
^
1 error generated.
When building with:
⬢[acme@toolbox perf]$ clang --version
clang version 13.0.0 (https://github.com/llvm/llvm-project e8991caea8690ec2d17b0b7e1c29bf0da6609076)
Also:
- if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
+ if (dst_type < KWORK_TRACE_MAX) {
Several versions of clang and at least this gcc:
3 51.40 alpine:3.9 : FAIL gcc version 8.3.0 (Alpine 8.3.0)
builtin-kwork.c:411:16: error: comparison of unsigned enum expression >= 0 is
always true [-Werror,-Wtautological-compare]
if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
As the first entry in a enum is zero.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-7-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:22 +00:00
|
|
|
};
|
|
|
|
|
perf kwork: New tool to trace time properties of kernel work (such as softirq, and workqueue)
The 'perf kwork' tool is used to trace time properties of kernel work
(such as irq, softirq, and workqueue), including runtime, latency, and
timehist, using the infrastructure in the perf tools to allow tracing
extra targets.
This is the first commit to reuse the 'perf record' framework code to
implement a simple record function, kwork is not supported currently.
Test cases:
# perf
usage: perf [--version] [--help] [OPTIONS] COMMAND [ARGS]
The most commonly used perf commands are:
<SNIP>
iostat Show I/O performance metrics
kallsyms Searches running kernel for symbols
kmem Tool to trace/measure kernel memory properties
kvm Tool to trace/measure kvm guest os
kwork Tool to trace/measure kernel work properties (latencies)
list List all symbolic event types
lock Analyze lock events
mem Profile memory accesses
record Run a command and record its profile into perf.data
<SNIP>
See 'perf help COMMAND' for more information on a specific command.
# perf kwork
Usage: perf kwork [<options>] {record}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork record -- sleep 1
[ perf record: Woken up 0 times to write data ]
[ perf record: Captured and wrote 1.787 MB perf.data ]
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-2-yangjihong1@huawei.com
[ Add {} for multiline if blocks ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:17 +00:00
|
|
|
struct kwork_class {
|
|
|
|
struct list_head list;
|
|
|
|
const char *name;
|
|
|
|
enum kwork_class_type type;
|
|
|
|
|
|
|
|
unsigned int nr_tracepoints;
|
|
|
|
const struct evsel_str_handler *tp_handlers;
|
perf kwork: Implement 'report' subcommand
Implements framework of 'perf kwork report', which is used to report
time properties such as run time and frequency:
Test cases:
# perf kwork
Usage: perf kwork [<options>] {record|report}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork report -h
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -S
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
Total count : 0
Total runtime (msec) : 0.000 (0.000% load average)
Total time span (msec) : 0.000
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -C 0,100
Requested CPU 100 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork report -s runtime1
Error: Unknown --sort key: `runtime1'
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork report --time 00FFF,
Invalid time span
Since there are no report supported events, the output is empty.
Briefly describe the data structure:
1. "class" indicates event type. For example, irq and softiq correspond
to different types.
2. "cluster" refers to a specific event corresponding to a type. For
example, RCU and TIMER in softirq correspond to different clusters,
which contains three types of events: raise, entry, and exit.
3. "atom" includes time of each sample and sample of the previous phase.
(For example, exit corresponds to entry, which is used for timehist.)
Committer notes:
- Add {} for multiline if blocks.
- report_print_work() should either return that ret variable that
accounts how many bytes were printed or stop accounting and be void.
Do the former for now to avoid this:
builtin-kwork.c:534:6: error: variable 'ret' set but not used [-Werror,-Wunused-but-set-variable]
int ret = 0;
^
1 error generated.
When building with:
⬢[acme@toolbox perf]$ clang --version
clang version 13.0.0 (https://github.com/llvm/llvm-project e8991caea8690ec2d17b0b7e1c29bf0da6609076)
Also:
- if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
+ if (dst_type < KWORK_TRACE_MAX) {
Several versions of clang and at least this gcc:
3 51.40 alpine:3.9 : FAIL gcc version 8.3.0 (Alpine 8.3.0)
builtin-kwork.c:411:16: error: comparison of unsigned enum expression >= 0 is
always true [-Werror,-Wtautological-compare]
if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
As the first entry in a enum is zero.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-7-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:22 +00:00
|
|
|
|
|
|
|
struct rb_root_cached work_root;
|
|
|
|
|
|
|
|
int (*class_init)(struct kwork_class *class,
|
|
|
|
struct perf_session *session);
|
|
|
|
|
2023-08-12 08:49:05 +00:00
|
|
|
void (*work_init)(struct perf_kwork *kwork,
|
|
|
|
struct kwork_class *class,
|
perf kwork: Implement 'report' subcommand
Implements framework of 'perf kwork report', which is used to report
time properties such as run time and frequency:
Test cases:
# perf kwork
Usage: perf kwork [<options>] {record|report}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork report -h
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -S
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
Total count : 0
Total runtime (msec) : 0.000 (0.000% load average)
Total time span (msec) : 0.000
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -C 0,100
Requested CPU 100 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork report -s runtime1
Error: Unknown --sort key: `runtime1'
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork report --time 00FFF,
Invalid time span
Since there are no report supported events, the output is empty.
Briefly describe the data structure:
1. "class" indicates event type. For example, irq and softiq correspond
to different types.
2. "cluster" refers to a specific event corresponding to a type. For
example, RCU and TIMER in softirq correspond to different clusters,
which contains three types of events: raise, entry, and exit.
3. "atom" includes time of each sample and sample of the previous phase.
(For example, exit corresponds to entry, which is used for timehist.)
Committer notes:
- Add {} for multiline if blocks.
- report_print_work() should either return that ret variable that
accounts how many bytes were printed or stop accounting and be void.
Do the former for now to avoid this:
builtin-kwork.c:534:6: error: variable 'ret' set but not used [-Werror,-Wunused-but-set-variable]
int ret = 0;
^
1 error generated.
When building with:
⬢[acme@toolbox perf]$ clang --version
clang version 13.0.0 (https://github.com/llvm/llvm-project e8991caea8690ec2d17b0b7e1c29bf0da6609076)
Also:
- if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
+ if (dst_type < KWORK_TRACE_MAX) {
Several versions of clang and at least this gcc:
3 51.40 alpine:3.9 : FAIL gcc version 8.3.0 (Alpine 8.3.0)
builtin-kwork.c:411:16: error: comparison of unsigned enum expression >= 0 is
always true [-Werror,-Wtautological-compare]
if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
As the first entry in a enum is zero.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-7-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:22 +00:00
|
|
|
struct kwork_work *work,
|
2023-08-12 08:49:05 +00:00
|
|
|
enum kwork_trace_type src_type,
|
perf kwork: Implement 'report' subcommand
Implements framework of 'perf kwork report', which is used to report
time properties such as run time and frequency:
Test cases:
# perf kwork
Usage: perf kwork [<options>] {record|report}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork report -h
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -S
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
Total count : 0
Total runtime (msec) : 0.000 (0.000% load average)
Total time span (msec) : 0.000
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -C 0,100
Requested CPU 100 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork report -s runtime1
Error: Unknown --sort key: `runtime1'
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork report --time 00FFF,
Invalid time span
Since there are no report supported events, the output is empty.
Briefly describe the data structure:
1. "class" indicates event type. For example, irq and softiq correspond
to different types.
2. "cluster" refers to a specific event corresponding to a type. For
example, RCU and TIMER in softirq correspond to different clusters,
which contains three types of events: raise, entry, and exit.
3. "atom" includes time of each sample and sample of the previous phase.
(For example, exit corresponds to entry, which is used for timehist.)
Committer notes:
- Add {} for multiline if blocks.
- report_print_work() should either return that ret variable that
accounts how many bytes were printed or stop accounting and be void.
Do the former for now to avoid this:
builtin-kwork.c:534:6: error: variable 'ret' set but not used [-Werror,-Wunused-but-set-variable]
int ret = 0;
^
1 error generated.
When building with:
⬢[acme@toolbox perf]$ clang --version
clang version 13.0.0 (https://github.com/llvm/llvm-project e8991caea8690ec2d17b0b7e1c29bf0da6609076)
Also:
- if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
+ if (dst_type < KWORK_TRACE_MAX) {
Several versions of clang and at least this gcc:
3 51.40 alpine:3.9 : FAIL gcc version 8.3.0 (Alpine 8.3.0)
builtin-kwork.c:411:16: error: comparison of unsigned enum expression >= 0 is
always true [-Werror,-Wtautological-compare]
if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
As the first entry in a enum is zero.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-7-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:22 +00:00
|
|
|
struct evsel *evsel,
|
|
|
|
struct perf_sample *sample,
|
|
|
|
struct machine *machine);
|
|
|
|
|
|
|
|
void (*work_name)(struct kwork_work *work,
|
|
|
|
char *buf, int len);
|
|
|
|
};
|
|
|
|
|
|
|
|
struct trace_kwork_handler {
|
perf kwork: Implement perf kwork latency
Implements framework of perf kwork latency, which is used to report time
properties such as delay time and frequency.
Test cases:
# perf kwork lat -h
Usage: perf kwork latency [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): avg, max, count
--time <str> Time span for analysis (start,stop)
# perf kwork lat -C 199
Requested CPU 199 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork lat -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork lat -s avg1
Error: Unknown --sort key: `avg1'
Usage: perf kwork latency [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): avg, max, count
--time <str> Time span for analysis (start,stop)
# perf kwork lat --time FFFF,
Invalid time span
# perf kwork lat
Kwork Name | Cpu | Avg delay | Count | Max delay | Max delay start | Max delay end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
INFO: 36.570% skipped events (31537 including 0 raise, 31537 entry, 0 exit)
Since there are no latency-enabled events, the output is empty.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-11-yangjihong1@huawei.com
[ Add {} for multiline if blocks ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:26 +00:00
|
|
|
int (*raise_event)(struct perf_kwork *kwork,
|
|
|
|
struct kwork_class *class, struct evsel *evsel,
|
|
|
|
struct perf_sample *sample, struct machine *machine);
|
|
|
|
|
perf kwork: Implement 'report' subcommand
Implements framework of 'perf kwork report', which is used to report
time properties such as run time and frequency:
Test cases:
# perf kwork
Usage: perf kwork [<options>] {record|report}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork report -h
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -S
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
Total count : 0
Total runtime (msec) : 0.000 (0.000% load average)
Total time span (msec) : 0.000
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -C 0,100
Requested CPU 100 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork report -s runtime1
Error: Unknown --sort key: `runtime1'
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork report --time 00FFF,
Invalid time span
Since there are no report supported events, the output is empty.
Briefly describe the data structure:
1. "class" indicates event type. For example, irq and softiq correspond
to different types.
2. "cluster" refers to a specific event corresponding to a type. For
example, RCU and TIMER in softirq correspond to different clusters,
which contains three types of events: raise, entry, and exit.
3. "atom" includes time of each sample and sample of the previous phase.
(For example, exit corresponds to entry, which is used for timehist.)
Committer notes:
- Add {} for multiline if blocks.
- report_print_work() should either return that ret variable that
accounts how many bytes were printed or stop accounting and be void.
Do the former for now to avoid this:
builtin-kwork.c:534:6: error: variable 'ret' set but not used [-Werror,-Wunused-but-set-variable]
int ret = 0;
^
1 error generated.
When building with:
⬢[acme@toolbox perf]$ clang --version
clang version 13.0.0 (https://github.com/llvm/llvm-project e8991caea8690ec2d17b0b7e1c29bf0da6609076)
Also:
- if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
+ if (dst_type < KWORK_TRACE_MAX) {
Several versions of clang and at least this gcc:
3 51.40 alpine:3.9 : FAIL gcc version 8.3.0 (Alpine 8.3.0)
builtin-kwork.c:411:16: error: comparison of unsigned enum expression >= 0 is
always true [-Werror,-Wtautological-compare]
if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
As the first entry in a enum is zero.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-7-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:22 +00:00
|
|
|
int (*entry_event)(struct perf_kwork *kwork,
|
|
|
|
struct kwork_class *class, struct evsel *evsel,
|
|
|
|
struct perf_sample *sample, struct machine *machine);
|
|
|
|
|
|
|
|
int (*exit_event)(struct perf_kwork *kwork,
|
|
|
|
struct kwork_class *class, struct evsel *evsel,
|
|
|
|
struct perf_sample *sample, struct machine *machine);
|
perf kwork: Add sched record support
The kwork_class type of sched is added to support recording and parsing of
sched_switch events.
As follows:
# perf kwork -h
Usage: perf kwork [<options>] {record|report|latency|timehist}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, sched, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork -k sched record true
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.083 MB perf.data (47 samples) ]
# perf evlist
sched:sched_switch
dummy:HG
# Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events
Reviewed-by: Ian Rogers <irogers@google.com>
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ravi Bangoria <ravi.bangoria@amd.com>
Cc: Sandipan Das <sandipan.das@amd.com>
Link: https://lore.kernel.org/r/20230812084917.169338-8-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2023-08-12 08:49:08 +00:00
|
|
|
|
|
|
|
int (*sched_switch_event)(struct perf_kwork *kwork,
|
|
|
|
struct kwork_class *class, struct evsel *evsel,
|
|
|
|
struct perf_sample *sample, struct machine *machine);
|
perf kwork: New tool to trace time properties of kernel work (such as softirq, and workqueue)
The 'perf kwork' tool is used to trace time properties of kernel work
(such as irq, softirq, and workqueue), including runtime, latency, and
timehist, using the infrastructure in the perf tools to allow tracing
extra targets.
This is the first commit to reuse the 'perf record' framework code to
implement a simple record function, kwork is not supported currently.
Test cases:
# perf
usage: perf [--version] [--help] [OPTIONS] COMMAND [ARGS]
The most commonly used perf commands are:
<SNIP>
iostat Show I/O performance metrics
kallsyms Searches running kernel for symbols
kmem Tool to trace/measure kernel memory properties
kvm Tool to trace/measure kvm guest os
kwork Tool to trace/measure kernel work properties (latencies)
list List all symbolic event types
lock Analyze lock events
mem Profile memory accesses
record Run a command and record its profile into perf.data
<SNIP>
See 'perf help COMMAND' for more information on a specific command.
# perf kwork
Usage: perf kwork [<options>] {record}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork record -- sleep 1
[ perf record: Woken up 0 times to write data ]
[ perf record: Captured and wrote 1.787 MB perf.data ]
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-2-yangjihong1@huawei.com
[ Add {} for multiline if blocks ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:17 +00:00
|
|
|
};
|
|
|
|
|
perf kwork top: Introduce new top utility
Some common tools for collecting statistics on CPU usage, such as top,
obtain statistics from timer interrupt sampling, and then periodically
read statistics from /proc/stat.
This method has some deviations:
1. In the tick interrupt, the time between the last tick and the current
tick is counted in the current task. However, the task may be running
only part of the time.
2. For each task, the top tool periodically reads the /proc/{PID}/status
information. For tasks with a short life cycle, it may be missed.
In conclusion, the top tool cannot accurately collect statistics on the
CPU usage and running time of tasks.
The statistical method based on sched_switch tracepoint can accurately
calculate the CPU usage of all tasks. This method is applicable to
scenarios where performance comparison data is of high precision.
Example usage:
# perf kwork
Usage: perf kwork [<options>] {record|report|latency|timehist|top}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, sched, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork -k sched record -- perf bench sched messaging -g 1 -l 10000
# Running 'sched/messaging' benchmark:
# 20 sender and receiver processes per group
# 1 groups == 40 processes run
Total time: 14.074 [sec]
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 15.886 MB perf.data (129472 samples) ]
# perf kwork top
Total : 115708.178 ms, 8 cpus
%Cpu(s): 9.78% id
%Cpu0 [||||||||||||||||||||||||||| 90.55%]
%Cpu1 [||||||||||||||||||||||||||| 90.51%]
%Cpu2 [|||||||||||||||||||||||||| 88.57%]
%Cpu3 [||||||||||||||||||||||||||| 91.18%]
%Cpu4 [||||||||||||||||||||||||||| 91.09%]
%Cpu5 [||||||||||||||||||||||||||| 90.88%]
%Cpu6 [|||||||||||||||||||||||||| 88.64%]
%Cpu7 [||||||||||||||||||||||||||| 90.28%]
PID %CPU RUNTIME COMMMAND
----------------------------------------------------
4113 22.23 3221.547 ms sched-messaging
4105 21.61 3131.495 ms sched-messaging
4119 21.53 3120.937 ms sched-messaging
4103 21.39 3101.614 ms sched-messaging
4106 21.37 3095.209 ms sched-messaging
4104 21.25 3077.269 ms sched-messaging
4115 21.21 3073.188 ms sched-messaging
4109 21.18 3069.022 ms sched-messaging
4111 20.78 3010.033 ms sched-messaging
4114 20.74 3007.073 ms sched-messaging
4108 20.73 3002.137 ms sched-messaging
4107 20.47 2967.292 ms sched-messaging
4117 20.39 2955.335 ms sched-messaging
4112 20.34 2947.080 ms sched-messaging
4118 20.32 2942.519 ms sched-messaging
4121 20.23 2929.865 ms sched-messaging
4110 20.22 2930.078 ms sched-messaging
4122 20.15 2919.542 ms sched-messaging
4120 19.77 2866.032 ms sched-messaging
4116 19.72 2857.660 ms sched-messaging
4127 16.19 2346.334 ms sched-messaging
4142 15.86 2297.600 ms sched-messaging
4141 15.62 2262.646 ms sched-messaging
4136 15.41 2231.408 ms sched-messaging
4130 15.38 2227.008 ms sched-messaging
4129 15.31 2217.692 ms sched-messaging
4126 15.21 2201.711 ms sched-messaging
4139 15.19 2200.722 ms sched-messaging
4137 15.10 2188.633 ms sched-messaging
4134 15.06 2182.082 ms sched-messaging
4132 15.02 2177.530 ms sched-messaging
4131 14.73 2131.973 ms sched-messaging
4125 14.68 2125.439 ms sched-messaging
4128 14.66 2122.255 ms sched-messaging
4123 14.65 2122.113 ms sched-messaging
4135 14.56 2107.144 ms sched-messaging
4133 14.51 2103.549 ms sched-messaging
4124 14.27 2066.671 ms sched-messaging
4140 14.17 2052.251 ms sched-messaging
4138 13.81 2000.361 ms sched-messaging
0 11.42 1652.009 ms swapper/2
0 11.35 1641.694 ms swapper/6
0 9.71 1405.108 ms swapper/7
0 9.48 1372.338 ms swapper/1
0 9.44 1366.013 ms swapper/0
0 9.11 1318.382 ms swapper/5
0 8.90 1287.582 ms swapper/4
0 8.81 1274.356 ms swapper/3
4100 2.61 379.328 ms perf
4101 1.16 169.487 ms perf-exec
151 0.65 94.741 ms systemd-resolve
249 0.36 53.030 ms sd-resolve
153 0.14 21.405 ms systemd-timesyn
1 0.10 16.200 ms systemd
16 0.09 15.785 ms rcu_preempt
4102 0.06 9.727 ms perf
4095 0.03 5.464 ms kworker/7:1
98 0.02 3.231 ms jbd2/sda-8
353 0.02 4.115 ms sshd
75 0.02 3.889 ms kworker/2:1
73 0.01 1.552 ms kworker/5:1
64 0.01 1.591 ms kworker/4:1
74 0.01 1.952 ms kworker/3:1
61 0.01 2.608 ms kcompactd0
397 0.01 1.602 ms kworker/1:1
69 0.01 1.817 ms kworker/1:1H
10 0.01 2.553 ms kworker/u16:0
2909 0.01 2.684 ms kworker/0:2
1211 0.00 0.426 ms kworker/7:0
97 0.00 0.153 ms kworker/7:1H
51 0.00 0.100 ms ksoftirqd/7
120 0.00 0.856 ms systemd-journal
76 0.00 1.414 ms kworker/6:1
46 0.00 0.246 ms ksoftirqd/6
45 0.00 0.164 ms migration/6
41 0.00 0.098 ms ksoftirqd/5
40 0.00 0.207 ms migration/5
86 0.00 1.339 ms kworker/4:1H
36 0.00 0.252 ms ksoftirqd/4
35 0.00 0.090 ms migration/4
31 0.00 0.156 ms ksoftirqd/3
30 0.00 0.073 ms migration/3
26 0.00 0.180 ms ksoftirqd/2
25 0.00 0.085 ms migration/2
21 0.00 0.106 ms ksoftirqd/1
20 0.00 0.118 ms migration/1
302 0.00 1.440 ms systemd-logind
17 0.00 0.132 ms migration/0
15 0.00 0.255 ms ksoftirqd/0
Reviewed-by: Ian Rogers <irogers@google.com>
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ravi Bangoria <ravi.bangoria@amd.com>
Cc: Sandipan Das <sandipan.das@amd.com>
Link: https://lore.kernel.org/r/20230812084917.169338-10-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2023-08-12 08:49:10 +00:00
|
|
|
struct __top_cpus_runtime {
|
|
|
|
u64 load;
|
|
|
|
u64 idle;
|
2023-08-12 08:49:12 +00:00
|
|
|
u64 irq;
|
2023-08-12 08:49:13 +00:00
|
|
|
u64 softirq;
|
perf kwork top: Introduce new top utility
Some common tools for collecting statistics on CPU usage, such as top,
obtain statistics from timer interrupt sampling, and then periodically
read statistics from /proc/stat.
This method has some deviations:
1. In the tick interrupt, the time between the last tick and the current
tick is counted in the current task. However, the task may be running
only part of the time.
2. For each task, the top tool periodically reads the /proc/{PID}/status
information. For tasks with a short life cycle, it may be missed.
In conclusion, the top tool cannot accurately collect statistics on the
CPU usage and running time of tasks.
The statistical method based on sched_switch tracepoint can accurately
calculate the CPU usage of all tasks. This method is applicable to
scenarios where performance comparison data is of high precision.
Example usage:
# perf kwork
Usage: perf kwork [<options>] {record|report|latency|timehist|top}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, sched, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork -k sched record -- perf bench sched messaging -g 1 -l 10000
# Running 'sched/messaging' benchmark:
# 20 sender and receiver processes per group
# 1 groups == 40 processes run
Total time: 14.074 [sec]
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 15.886 MB perf.data (129472 samples) ]
# perf kwork top
Total : 115708.178 ms, 8 cpus
%Cpu(s): 9.78% id
%Cpu0 [||||||||||||||||||||||||||| 90.55%]
%Cpu1 [||||||||||||||||||||||||||| 90.51%]
%Cpu2 [|||||||||||||||||||||||||| 88.57%]
%Cpu3 [||||||||||||||||||||||||||| 91.18%]
%Cpu4 [||||||||||||||||||||||||||| 91.09%]
%Cpu5 [||||||||||||||||||||||||||| 90.88%]
%Cpu6 [|||||||||||||||||||||||||| 88.64%]
%Cpu7 [||||||||||||||||||||||||||| 90.28%]
PID %CPU RUNTIME COMMMAND
----------------------------------------------------
4113 22.23 3221.547 ms sched-messaging
4105 21.61 3131.495 ms sched-messaging
4119 21.53 3120.937 ms sched-messaging
4103 21.39 3101.614 ms sched-messaging
4106 21.37 3095.209 ms sched-messaging
4104 21.25 3077.269 ms sched-messaging
4115 21.21 3073.188 ms sched-messaging
4109 21.18 3069.022 ms sched-messaging
4111 20.78 3010.033 ms sched-messaging
4114 20.74 3007.073 ms sched-messaging
4108 20.73 3002.137 ms sched-messaging
4107 20.47 2967.292 ms sched-messaging
4117 20.39 2955.335 ms sched-messaging
4112 20.34 2947.080 ms sched-messaging
4118 20.32 2942.519 ms sched-messaging
4121 20.23 2929.865 ms sched-messaging
4110 20.22 2930.078 ms sched-messaging
4122 20.15 2919.542 ms sched-messaging
4120 19.77 2866.032 ms sched-messaging
4116 19.72 2857.660 ms sched-messaging
4127 16.19 2346.334 ms sched-messaging
4142 15.86 2297.600 ms sched-messaging
4141 15.62 2262.646 ms sched-messaging
4136 15.41 2231.408 ms sched-messaging
4130 15.38 2227.008 ms sched-messaging
4129 15.31 2217.692 ms sched-messaging
4126 15.21 2201.711 ms sched-messaging
4139 15.19 2200.722 ms sched-messaging
4137 15.10 2188.633 ms sched-messaging
4134 15.06 2182.082 ms sched-messaging
4132 15.02 2177.530 ms sched-messaging
4131 14.73 2131.973 ms sched-messaging
4125 14.68 2125.439 ms sched-messaging
4128 14.66 2122.255 ms sched-messaging
4123 14.65 2122.113 ms sched-messaging
4135 14.56 2107.144 ms sched-messaging
4133 14.51 2103.549 ms sched-messaging
4124 14.27 2066.671 ms sched-messaging
4140 14.17 2052.251 ms sched-messaging
4138 13.81 2000.361 ms sched-messaging
0 11.42 1652.009 ms swapper/2
0 11.35 1641.694 ms swapper/6
0 9.71 1405.108 ms swapper/7
0 9.48 1372.338 ms swapper/1
0 9.44 1366.013 ms swapper/0
0 9.11 1318.382 ms swapper/5
0 8.90 1287.582 ms swapper/4
0 8.81 1274.356 ms swapper/3
4100 2.61 379.328 ms perf
4101 1.16 169.487 ms perf-exec
151 0.65 94.741 ms systemd-resolve
249 0.36 53.030 ms sd-resolve
153 0.14 21.405 ms systemd-timesyn
1 0.10 16.200 ms systemd
16 0.09 15.785 ms rcu_preempt
4102 0.06 9.727 ms perf
4095 0.03 5.464 ms kworker/7:1
98 0.02 3.231 ms jbd2/sda-8
353 0.02 4.115 ms sshd
75 0.02 3.889 ms kworker/2:1
73 0.01 1.552 ms kworker/5:1
64 0.01 1.591 ms kworker/4:1
74 0.01 1.952 ms kworker/3:1
61 0.01 2.608 ms kcompactd0
397 0.01 1.602 ms kworker/1:1
69 0.01 1.817 ms kworker/1:1H
10 0.01 2.553 ms kworker/u16:0
2909 0.01 2.684 ms kworker/0:2
1211 0.00 0.426 ms kworker/7:0
97 0.00 0.153 ms kworker/7:1H
51 0.00 0.100 ms ksoftirqd/7
120 0.00 0.856 ms systemd-journal
76 0.00 1.414 ms kworker/6:1
46 0.00 0.246 ms ksoftirqd/6
45 0.00 0.164 ms migration/6
41 0.00 0.098 ms ksoftirqd/5
40 0.00 0.207 ms migration/5
86 0.00 1.339 ms kworker/4:1H
36 0.00 0.252 ms ksoftirqd/4
35 0.00 0.090 ms migration/4
31 0.00 0.156 ms ksoftirqd/3
30 0.00 0.073 ms migration/3
26 0.00 0.180 ms ksoftirqd/2
25 0.00 0.085 ms migration/2
21 0.00 0.106 ms ksoftirqd/1
20 0.00 0.118 ms migration/1
302 0.00 1.440 ms systemd-logind
17 0.00 0.132 ms migration/0
15 0.00 0.255 ms ksoftirqd/0
Reviewed-by: Ian Rogers <irogers@google.com>
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ravi Bangoria <ravi.bangoria@amd.com>
Cc: Sandipan Das <sandipan.das@amd.com>
Link: https://lore.kernel.org/r/20230812084917.169338-10-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2023-08-12 08:49:10 +00:00
|
|
|
u64 total;
|
|
|
|
};
|
|
|
|
|
|
|
|
struct kwork_top_stat {
|
|
|
|
DECLARE_BITMAP(all_cpus_bitmap, MAX_NR_CPUS);
|
|
|
|
struct __top_cpus_runtime *cpus_runtime;
|
|
|
|
};
|
|
|
|
|
perf kwork: New tool to trace time properties of kernel work (such as softirq, and workqueue)
The 'perf kwork' tool is used to trace time properties of kernel work
(such as irq, softirq, and workqueue), including runtime, latency, and
timehist, using the infrastructure in the perf tools to allow tracing
extra targets.
This is the first commit to reuse the 'perf record' framework code to
implement a simple record function, kwork is not supported currently.
Test cases:
# perf
usage: perf [--version] [--help] [OPTIONS] COMMAND [ARGS]
The most commonly used perf commands are:
<SNIP>
iostat Show I/O performance metrics
kallsyms Searches running kernel for symbols
kmem Tool to trace/measure kernel memory properties
kvm Tool to trace/measure kvm guest os
kwork Tool to trace/measure kernel work properties (latencies)
list List all symbolic event types
lock Analyze lock events
mem Profile memory accesses
record Run a command and record its profile into perf.data
<SNIP>
See 'perf help COMMAND' for more information on a specific command.
# perf kwork
Usage: perf kwork [<options>] {record}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork record -- sleep 1
[ perf record: Woken up 0 times to write data ]
[ perf record: Captured and wrote 1.787 MB perf.data ]
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-2-yangjihong1@huawei.com
[ Add {} for multiline if blocks ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:17 +00:00
|
|
|
struct perf_kwork {
|
|
|
|
/*
|
|
|
|
* metadata
|
|
|
|
*/
|
perf kwork: Implement 'report' subcommand
Implements framework of 'perf kwork report', which is used to report
time properties such as run time and frequency:
Test cases:
# perf kwork
Usage: perf kwork [<options>] {record|report}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork report -h
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -S
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
Total count : 0
Total runtime (msec) : 0.000 (0.000% load average)
Total time span (msec) : 0.000
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -C 0,100
Requested CPU 100 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork report -s runtime1
Error: Unknown --sort key: `runtime1'
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork report --time 00FFF,
Invalid time span
Since there are no report supported events, the output is empty.
Briefly describe the data structure:
1. "class" indicates event type. For example, irq and softiq correspond
to different types.
2. "cluster" refers to a specific event corresponding to a type. For
example, RCU and TIMER in softirq correspond to different clusters,
which contains three types of events: raise, entry, and exit.
3. "atom" includes time of each sample and sample of the previous phase.
(For example, exit corresponds to entry, which is used for timehist.)
Committer notes:
- Add {} for multiline if blocks.
- report_print_work() should either return that ret variable that
accounts how many bytes were printed or stop accounting and be void.
Do the former for now to avoid this:
builtin-kwork.c:534:6: error: variable 'ret' set but not used [-Werror,-Wunused-but-set-variable]
int ret = 0;
^
1 error generated.
When building with:
⬢[acme@toolbox perf]$ clang --version
clang version 13.0.0 (https://github.com/llvm/llvm-project e8991caea8690ec2d17b0b7e1c29bf0da6609076)
Also:
- if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
+ if (dst_type < KWORK_TRACE_MAX) {
Several versions of clang and at least this gcc:
3 51.40 alpine:3.9 : FAIL gcc version 8.3.0 (Alpine 8.3.0)
builtin-kwork.c:411:16: error: comparison of unsigned enum expression >= 0 is
always true [-Werror,-Wtautological-compare]
if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
As the first entry in a enum is zero.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-7-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:22 +00:00
|
|
|
struct perf_tool tool;
|
perf kwork: New tool to trace time properties of kernel work (such as softirq, and workqueue)
The 'perf kwork' tool is used to trace time properties of kernel work
(such as irq, softirq, and workqueue), including runtime, latency, and
timehist, using the infrastructure in the perf tools to allow tracing
extra targets.
This is the first commit to reuse the 'perf record' framework code to
implement a simple record function, kwork is not supported currently.
Test cases:
# perf
usage: perf [--version] [--help] [OPTIONS] COMMAND [ARGS]
The most commonly used perf commands are:
<SNIP>
iostat Show I/O performance metrics
kallsyms Searches running kernel for symbols
kmem Tool to trace/measure kernel memory properties
kvm Tool to trace/measure kvm guest os
kwork Tool to trace/measure kernel work properties (latencies)
list List all symbolic event types
lock Analyze lock events
mem Profile memory accesses
record Run a command and record its profile into perf.data
<SNIP>
See 'perf help COMMAND' for more information on a specific command.
# perf kwork
Usage: perf kwork [<options>] {record}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork record -- sleep 1
[ perf record: Woken up 0 times to write data ]
[ perf record: Captured and wrote 1.787 MB perf.data ]
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-2-yangjihong1@huawei.com
[ Add {} for multiline if blocks ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:17 +00:00
|
|
|
struct list_head class_list;
|
perf kwork: Implement 'report' subcommand
Implements framework of 'perf kwork report', which is used to report
time properties such as run time and frequency:
Test cases:
# perf kwork
Usage: perf kwork [<options>] {record|report}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork report -h
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -S
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
Total count : 0
Total runtime (msec) : 0.000 (0.000% load average)
Total time span (msec) : 0.000
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -C 0,100
Requested CPU 100 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork report -s runtime1
Error: Unknown --sort key: `runtime1'
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork report --time 00FFF,
Invalid time span
Since there are no report supported events, the output is empty.
Briefly describe the data structure:
1. "class" indicates event type. For example, irq and softiq correspond
to different types.
2. "cluster" refers to a specific event corresponding to a type. For
example, RCU and TIMER in softirq correspond to different clusters,
which contains three types of events: raise, entry, and exit.
3. "atom" includes time of each sample and sample of the previous phase.
(For example, exit corresponds to entry, which is used for timehist.)
Committer notes:
- Add {} for multiline if blocks.
- report_print_work() should either return that ret variable that
accounts how many bytes were printed or stop accounting and be void.
Do the former for now to avoid this:
builtin-kwork.c:534:6: error: variable 'ret' set but not used [-Werror,-Wunused-but-set-variable]
int ret = 0;
^
1 error generated.
When building with:
⬢[acme@toolbox perf]$ clang --version
clang version 13.0.0 (https://github.com/llvm/llvm-project e8991caea8690ec2d17b0b7e1c29bf0da6609076)
Also:
- if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
+ if (dst_type < KWORK_TRACE_MAX) {
Several versions of clang and at least this gcc:
3 51.40 alpine:3.9 : FAIL gcc version 8.3.0 (Alpine 8.3.0)
builtin-kwork.c:411:16: error: comparison of unsigned enum expression >= 0 is
always true [-Werror,-Wtautological-compare]
if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
As the first entry in a enum is zero.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-7-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:22 +00:00
|
|
|
struct list_head atom_page_list;
|
|
|
|
struct list_head sort_list, cmp_id;
|
|
|
|
struct rb_root_cached sorted_work_root;
|
|
|
|
const struct trace_kwork_handler *tp_handler;
|
|
|
|
|
|
|
|
/*
|
|
|
|
* profile filters
|
|
|
|
*/
|
|
|
|
const char *profile_name;
|
|
|
|
|
|
|
|
const char *cpu_list;
|
|
|
|
DECLARE_BITMAP(cpu_bitmap, MAX_NR_CPUS);
|
|
|
|
|
|
|
|
const char *time_str;
|
|
|
|
struct perf_time_interval ptime;
|
perf kwork: New tool to trace time properties of kernel work (such as softirq, and workqueue)
The 'perf kwork' tool is used to trace time properties of kernel work
(such as irq, softirq, and workqueue), including runtime, latency, and
timehist, using the infrastructure in the perf tools to allow tracing
extra targets.
This is the first commit to reuse the 'perf record' framework code to
implement a simple record function, kwork is not supported currently.
Test cases:
# perf
usage: perf [--version] [--help] [OPTIONS] COMMAND [ARGS]
The most commonly used perf commands are:
<SNIP>
iostat Show I/O performance metrics
kallsyms Searches running kernel for symbols
kmem Tool to trace/measure kernel memory properties
kvm Tool to trace/measure kvm guest os
kwork Tool to trace/measure kernel work properties (latencies)
list List all symbolic event types
lock Analyze lock events
mem Profile memory accesses
record Run a command and record its profile into perf.data
<SNIP>
See 'perf help COMMAND' for more information on a specific command.
# perf kwork
Usage: perf kwork [<options>] {record}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork record -- sleep 1
[ perf record: Woken up 0 times to write data ]
[ perf record: Captured and wrote 1.787 MB perf.data ]
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-2-yangjihong1@huawei.com
[ Add {} for multiline if blocks ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:17 +00:00
|
|
|
|
|
|
|
/*
|
|
|
|
* options for command
|
|
|
|
*/
|
|
|
|
bool force;
|
|
|
|
const char *event_list_str;
|
perf kwork: Implement 'report' subcommand
Implements framework of 'perf kwork report', which is used to report
time properties such as run time and frequency:
Test cases:
# perf kwork
Usage: perf kwork [<options>] {record|report}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork report -h
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -S
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
Total count : 0
Total runtime (msec) : 0.000 (0.000% load average)
Total time span (msec) : 0.000
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -C 0,100
Requested CPU 100 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork report -s runtime1
Error: Unknown --sort key: `runtime1'
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork report --time 00FFF,
Invalid time span
Since there are no report supported events, the output is empty.
Briefly describe the data structure:
1. "class" indicates event type. For example, irq and softiq correspond
to different types.
2. "cluster" refers to a specific event corresponding to a type. For
example, RCU and TIMER in softirq correspond to different clusters,
which contains three types of events: raise, entry, and exit.
3. "atom" includes time of each sample and sample of the previous phase.
(For example, exit corresponds to entry, which is used for timehist.)
Committer notes:
- Add {} for multiline if blocks.
- report_print_work() should either return that ret variable that
accounts how many bytes were printed or stop accounting and be void.
Do the former for now to avoid this:
builtin-kwork.c:534:6: error: variable 'ret' set but not used [-Werror,-Wunused-but-set-variable]
int ret = 0;
^
1 error generated.
When building with:
⬢[acme@toolbox perf]$ clang --version
clang version 13.0.0 (https://github.com/llvm/llvm-project e8991caea8690ec2d17b0b7e1c29bf0da6609076)
Also:
- if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
+ if (dst_type < KWORK_TRACE_MAX) {
Several versions of clang and at least this gcc:
3 51.40 alpine:3.9 : FAIL gcc version 8.3.0 (Alpine 8.3.0)
builtin-kwork.c:411:16: error: comparison of unsigned enum expression >= 0 is
always true [-Werror,-Wtautological-compare]
if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
As the first entry in a enum is zero.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-7-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:22 +00:00
|
|
|
enum kwork_report_type report;
|
|
|
|
|
|
|
|
/*
|
|
|
|
* options for subcommand
|
|
|
|
*/
|
|
|
|
bool summary;
|
|
|
|
const char *sort_order;
|
2022-07-09 01:50:29 +00:00
|
|
|
bool show_callchain;
|
|
|
|
unsigned int max_stack;
|
perf kwork: Implement BPF trace
'perf record' generates perf.data, which generates extra interrupts
for hard disk, amount of data to be collected increases with time.
Using eBPF trace can process the data in kernel, which solves the
preceding two problems.
Add -b/--use-bpf option for latency and report to support
tracing kwork events using eBPF:
1. Create bpf prog and attach to tracepoints,
2. Start tracing after command is entered,
3. After user hit "ctrl+c", stop tracing and report,
4. Support CPU and name filtering.
This commit implements the framework code and
does not add specific event support.
Test cases:
# perf kwork rep -h
Usage: perf kwork report [<options>]
-b, --use-bpf Use BPF to measure kwork runtime
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork lat -h
Usage: perf kwork latency [<options>]
-b, --use-bpf Use BPF to measure kwork latency
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): avg, max, count
--time <str> Time span for analysis (start,stop)
# perf kwork lat -b
Unsupported bpf trace class irq
# perf kwork rep -b
Unsupported bpf trace class irq
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-15-yangjihong1@huawei.com
[ Simplify work_findnew() ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:30 +00:00
|
|
|
bool use_bpf;
|
perf kwork: Implement 'report' subcommand
Implements framework of 'perf kwork report', which is used to report
time properties such as run time and frequency:
Test cases:
# perf kwork
Usage: perf kwork [<options>] {record|report}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork report -h
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -S
Kwork Name | Cpu | Total Runtime | Count | Max runtime | Max runtime start | Max runtime end |
--------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------------------------
Total count : 0
Total runtime (msec) : 0.000 (0.000% load average)
Total time span (msec) : 0.000
--------------------------------------------------------------------------------------------------------------------------------
# perf kwork report -C 0,100
Requested CPU 100 too large. Consider raising MAX_NR_CPUS
Invalid cpu bitmap
# perf kwork report -s runtime1
Error: Unknown --sort key: `runtime1'
Usage: perf kwork report [<options>]
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork report -i perf_no_exist.data
failed to open perf_no_exist.data: No such file or directory
# perf kwork report --time 00FFF,
Invalid time span
Since there are no report supported events, the output is empty.
Briefly describe the data structure:
1. "class" indicates event type. For example, irq and softiq correspond
to different types.
2. "cluster" refers to a specific event corresponding to a type. For
example, RCU and TIMER in softirq correspond to different clusters,
which contains three types of events: raise, entry, and exit.
3. "atom" includes time of each sample and sample of the previous phase.
(For example, exit corresponds to entry, which is used for timehist.)
Committer notes:
- Add {} for multiline if blocks.
- report_print_work() should either return that ret variable that
accounts how many bytes were printed or stop accounting and be void.
Do the former for now to avoid this:
builtin-kwork.c:534:6: error: variable 'ret' set but not used [-Werror,-Wunused-but-set-variable]
int ret = 0;
^
1 error generated.
When building with:
⬢[acme@toolbox perf]$ clang --version
clang version 13.0.0 (https://github.com/llvm/llvm-project e8991caea8690ec2d17b0b7e1c29bf0da6609076)
Also:
- if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
+ if (dst_type < KWORK_TRACE_MAX) {
Several versions of clang and at least this gcc:
3 51.40 alpine:3.9 : FAIL gcc version 8.3.0 (Alpine 8.3.0)
builtin-kwork.c:411:16: error: comparison of unsigned enum expression >= 0 is
always true [-Werror,-Wtautological-compare]
if ((dst_type >= 0) && (dst_type < KWORK_TRACE_MAX)) {
As the first entry in a enum is zero.
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-7-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:22 +00:00
|
|
|
|
|
|
|
/*
|
|
|
|
* statistics
|
|
|
|
*/
|
|
|
|
u64 timestart;
|
|
|
|
u64 timeend;
|
|
|
|
|
|
|
|
unsigned long nr_events;
|
|
|
|
unsigned long nr_lost_chunks;
|
|
|
|
unsigned long nr_lost_events;
|
|
|
|
|
|
|
|
u64 all_runtime;
|
|
|
|
u64 all_count;
|
|
|
|
u64 nr_skipped_events[KWORK_TRACE_MAX + 1];
|
perf kwork top: Introduce new top utility
Some common tools for collecting statistics on CPU usage, such as top,
obtain statistics from timer interrupt sampling, and then periodically
read statistics from /proc/stat.
This method has some deviations:
1. In the tick interrupt, the time between the last tick and the current
tick is counted in the current task. However, the task may be running
only part of the time.
2. For each task, the top tool periodically reads the /proc/{PID}/status
information. For tasks with a short life cycle, it may be missed.
In conclusion, the top tool cannot accurately collect statistics on the
CPU usage and running time of tasks.
The statistical method based on sched_switch tracepoint can accurately
calculate the CPU usage of all tasks. This method is applicable to
scenarios where performance comparison data is of high precision.
Example usage:
# perf kwork
Usage: perf kwork [<options>] {record|report|latency|timehist|top}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile (irq, softirq, workqueue, sched, etc)
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork -k sched record -- perf bench sched messaging -g 1 -l 10000
# Running 'sched/messaging' benchmark:
# 20 sender and receiver processes per group
# 1 groups == 40 processes run
Total time: 14.074 [sec]
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 15.886 MB perf.data (129472 samples) ]
# perf kwork top
Total : 115708.178 ms, 8 cpus
%Cpu(s): 9.78% id
%Cpu0 [||||||||||||||||||||||||||| 90.55%]
%Cpu1 [||||||||||||||||||||||||||| 90.51%]
%Cpu2 [|||||||||||||||||||||||||| 88.57%]
%Cpu3 [||||||||||||||||||||||||||| 91.18%]
%Cpu4 [||||||||||||||||||||||||||| 91.09%]
%Cpu5 [||||||||||||||||||||||||||| 90.88%]
%Cpu6 [|||||||||||||||||||||||||| 88.64%]
%Cpu7 [||||||||||||||||||||||||||| 90.28%]
PID %CPU RUNTIME COMMMAND
----------------------------------------------------
4113 22.23 3221.547 ms sched-messaging
4105 21.61 3131.495 ms sched-messaging
4119 21.53 3120.937 ms sched-messaging
4103 21.39 3101.614 ms sched-messaging
4106 21.37 3095.209 ms sched-messaging
4104 21.25 3077.269 ms sched-messaging
4115 21.21 3073.188 ms sched-messaging
4109 21.18 3069.022 ms sched-messaging
4111 20.78 3010.033 ms sched-messaging
4114 20.74 3007.073 ms sched-messaging
4108 20.73 3002.137 ms sched-messaging
4107 20.47 2967.292 ms sched-messaging
4117 20.39 2955.335 ms sched-messaging
4112 20.34 2947.080 ms sched-messaging
4118 20.32 2942.519 ms sched-messaging
4121 20.23 2929.865 ms sched-messaging
4110 20.22 2930.078 ms sched-messaging
4122 20.15 2919.542 ms sched-messaging
4120 19.77 2866.032 ms sched-messaging
4116 19.72 2857.660 ms sched-messaging
4127 16.19 2346.334 ms sched-messaging
4142 15.86 2297.600 ms sched-messaging
4141 15.62 2262.646 ms sched-messaging
4136 15.41 2231.408 ms sched-messaging
4130 15.38 2227.008 ms sched-messaging
4129 15.31 2217.692 ms sched-messaging
4126 15.21 2201.711 ms sched-messaging
4139 15.19 2200.722 ms sched-messaging
4137 15.10 2188.633 ms sched-messaging
4134 15.06 2182.082 ms sched-messaging
4132 15.02 2177.530 ms sched-messaging
4131 14.73 2131.973 ms sched-messaging
4125 14.68 2125.439 ms sched-messaging
4128 14.66 2122.255 ms sched-messaging
4123 14.65 2122.113 ms sched-messaging
4135 14.56 2107.144 ms sched-messaging
4133 14.51 2103.549 ms sched-messaging
4124 14.27 2066.671 ms sched-messaging
4140 14.17 2052.251 ms sched-messaging
4138 13.81 2000.361 ms sched-messaging
0 11.42 1652.009 ms swapper/2
0 11.35 1641.694 ms swapper/6
0 9.71 1405.108 ms swapper/7
0 9.48 1372.338 ms swapper/1
0 9.44 1366.013 ms swapper/0
0 9.11 1318.382 ms swapper/5
0 8.90 1287.582 ms swapper/4
0 8.81 1274.356 ms swapper/3
4100 2.61 379.328 ms perf
4101 1.16 169.487 ms perf-exec
151 0.65 94.741 ms systemd-resolve
249 0.36 53.030 ms sd-resolve
153 0.14 21.405 ms systemd-timesyn
1 0.10 16.200 ms systemd
16 0.09 15.785 ms rcu_preempt
4102 0.06 9.727 ms perf
4095 0.03 5.464 ms kworker/7:1
98 0.02 3.231 ms jbd2/sda-8
353 0.02 4.115 ms sshd
75 0.02 3.889 ms kworker/2:1
73 0.01 1.552 ms kworker/5:1
64 0.01 1.591 ms kworker/4:1
74 0.01 1.952 ms kworker/3:1
61 0.01 2.608 ms kcompactd0
397 0.01 1.602 ms kworker/1:1
69 0.01 1.817 ms kworker/1:1H
10 0.01 2.553 ms kworker/u16:0
2909 0.01 2.684 ms kworker/0:2
1211 0.00 0.426 ms kworker/7:0
97 0.00 0.153 ms kworker/7:1H
51 0.00 0.100 ms ksoftirqd/7
120 0.00 0.856 ms systemd-journal
76 0.00 1.414 ms kworker/6:1
46 0.00 0.246 ms ksoftirqd/6
45 0.00 0.164 ms migration/6
41 0.00 0.098 ms ksoftirqd/5
40 0.00 0.207 ms migration/5
86 0.00 1.339 ms kworker/4:1H
36 0.00 0.252 ms ksoftirqd/4
35 0.00 0.090 ms migration/4
31 0.00 0.156 ms ksoftirqd/3
30 0.00 0.073 ms migration/3
26 0.00 0.180 ms ksoftirqd/2
25 0.00 0.085 ms migration/2
21 0.00 0.106 ms ksoftirqd/1
20 0.00 0.118 ms migration/1
302 0.00 1.440 ms systemd-logind
17 0.00 0.132 ms migration/0
15 0.00 0.255 ms ksoftirqd/0
Reviewed-by: Ian Rogers <irogers@google.com>
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ravi Bangoria <ravi.bangoria@amd.com>
Cc: Sandipan Das <sandipan.das@amd.com>
Link: https://lore.kernel.org/r/20230812084917.169338-10-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2023-08-12 08:49:10 +00:00
|
|
|
|
|
|
|
/*
|
|
|
|
* perf kwork top data
|
|
|
|
*/
|
|
|
|
struct kwork_top_stat top_stat;
|
perf kwork: New tool to trace time properties of kernel work (such as softirq, and workqueue)
The 'perf kwork' tool is used to trace time properties of kernel work
(such as irq, softirq, and workqueue), including runtime, latency, and
timehist, using the infrastructure in the perf tools to allow tracing
extra targets.
This is the first commit to reuse the 'perf record' framework code to
implement a simple record function, kwork is not supported currently.
Test cases:
# perf
usage: perf [--version] [--help] [OPTIONS] COMMAND [ARGS]
The most commonly used perf commands are:
<SNIP>
iostat Show I/O performance metrics
kallsyms Searches running kernel for symbols
kmem Tool to trace/measure kernel memory properties
kvm Tool to trace/measure kvm guest os
kwork Tool to trace/measure kernel work properties (latencies)
list List all symbolic event types
lock Analyze lock events
mem Profile memory accesses
record Run a command and record its profile into perf.data
<SNIP>
See 'perf help COMMAND' for more information on a specific command.
# perf kwork
Usage: perf kwork [<options>] {record}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork record -- sleep 1
[ perf record: Woken up 0 times to write data ]
[ perf record: Captured and wrote 1.787 MB perf.data ]
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-2-yangjihong1@huawei.com
[ Add {} for multiline if blocks ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:17 +00:00
|
|
|
};
|
|
|
|
|
perf kwork: Implement BPF trace
'perf record' generates perf.data, which generates extra interrupts
for hard disk, amount of data to be collected increases with time.
Using eBPF trace can process the data in kernel, which solves the
preceding two problems.
Add -b/--use-bpf option for latency and report to support
tracing kwork events using eBPF:
1. Create bpf prog and attach to tracepoints,
2. Start tracing after command is entered,
3. After user hit "ctrl+c", stop tracing and report,
4. Support CPU and name filtering.
This commit implements the framework code and
does not add specific event support.
Test cases:
# perf kwork rep -h
Usage: perf kwork report [<options>]
-b, --use-bpf Use BPF to measure kwork runtime
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork lat -h
Usage: perf kwork latency [<options>]
-b, --use-bpf Use BPF to measure kwork latency
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): avg, max, count
--time <str> Time span for analysis (start,stop)
# perf kwork lat -b
Unsupported bpf trace class irq
# perf kwork rep -b
Unsupported bpf trace class irq
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-15-yangjihong1@huawei.com
[ Simplify work_findnew() ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:30 +00:00
|
|
|
struct kwork_work *perf_kwork_add_work(struct perf_kwork *kwork,
|
|
|
|
struct kwork_class *class,
|
|
|
|
struct kwork_work *key);
|
|
|
|
|
|
|
|
#ifdef HAVE_BPF_SKEL
|
|
|
|
|
|
|
|
int perf_kwork__trace_prepare_bpf(struct perf_kwork *kwork);
|
|
|
|
int perf_kwork__report_read_bpf(struct perf_kwork *kwork);
|
|
|
|
void perf_kwork__report_cleanup_bpf(void);
|
|
|
|
|
|
|
|
void perf_kwork__trace_start(void);
|
|
|
|
void perf_kwork__trace_finish(void);
|
|
|
|
|
perf kwork top: Implements BPF-based cpu usage statistics
Use BPF to collect statistics on the CPU usage based on perf BPF skeletons.
Example usage:
# perf kwork top -h
Usage: perf kwork top [<options>]
-b, --use-bpf Use BPF to measure task cpu usage
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): rate, runtime, tid
--time <str> Time span for analysis (start,stop)
#
# perf kwork -k sched top -b
Starting trace, Hit <Ctrl+C> to stop and report
^C
Total : 160702.425 ms, 8 cpus
%Cpu(s): 36.00% id, 0.00% hi, 0.00% si
%Cpu0 [|||||||||||||||||| 61.66%]
%Cpu1 [|||||||||||||||||| 61.27%]
%Cpu2 [||||||||||||||||||| 66.40%]
%Cpu3 [|||||||||||||||||| 61.28%]
%Cpu4 [|||||||||||||||||| 61.82%]
%Cpu5 [||||||||||||||||||||||| 77.41%]
%Cpu6 [|||||||||||||||||| 61.73%]
%Cpu7 [|||||||||||||||||| 63.25%]
PID SPID %CPU RUNTIME COMMMAND
-------------------------------------------------------------
0 0 38.72 8089.463 ms [swapper/1]
0 0 38.71 8084.547 ms [swapper/3]
0 0 38.33 8007.532 ms [swapper/0]
0 0 38.26 7992.985 ms [swapper/6]
0 0 38.17 7971.865 ms [swapper/4]
0 0 36.74 7447.765 ms [swapper/7]
0 0 33.59 6486.942 ms [swapper/2]
0 0 22.58 3771.268 ms [swapper/5]
9545 9351 2.48 447.136 ms sched-messaging
9574 9351 2.09 418.583 ms sched-messaging
9724 9351 2.05 372.407 ms sched-messaging
9531 9351 2.01 368.804 ms sched-messaging
9512 9351 2.00 362.250 ms sched-messaging
9514 9351 1.95 357.767 ms sched-messaging
9538 9351 1.86 384.476 ms sched-messaging
9712 9351 1.84 386.490 ms sched-messaging
9723 9351 1.83 380.021 ms sched-messaging
9722 9351 1.82 382.738 ms sched-messaging
9517 9351 1.81 354.794 ms sched-messaging
9559 9351 1.79 344.305 ms sched-messaging
9725 9351 1.77 365.315 ms sched-messaging
<SNIP>
# perf kwork -k sched top -b -n perf
Starting trace, Hit <Ctrl+C> to stop and report
^C
Total : 151563.332 ms, 8 cpus
%Cpu(s): 26.49% id, 0.00% hi, 0.00% si
%Cpu0 [ 0.01%]
%Cpu1 [ 0.00%]
%Cpu2 [ 0.00%]
%Cpu3 [ 0.00%]
%Cpu4 [ 0.00%]
%Cpu5 [ 0.00%]
%Cpu6 [ 0.00%]
%Cpu7 [ 0.00%]
PID SPID %CPU RUNTIME COMMMAND
-------------------------------------------------------------
9754 9754 0.01 2.303 ms perf
#
# perf kwork -k sched top -b -C 2,3,4
Starting trace, Hit <Ctrl+C> to stop and report
^C
Total : 48016.721 ms, 3 cpus
%Cpu(s): 27.82% id, 0.00% hi, 0.00% si
%Cpu2 [|||||||||||||||||||||| 74.68%]
%Cpu3 [||||||||||||||||||||| 71.06%]
%Cpu4 [||||||||||||||||||||| 70.91%]
PID SPID %CPU RUNTIME COMMMAND
-------------------------------------------------------------
0 0 29.08 4734.998 ms [swapper/4]
0 0 28.93 4710.029 ms [swapper/3]
0 0 25.31 3912.363 ms [swapper/2]
10248 10158 1.62 264.931 ms sched-messaging
10253 10158 1.62 265.136 ms sched-messaging
10158 10158 1.60 263.013 ms bash
10360 10158 1.49 243.639 ms sched-messaging
10413 10158 1.48 238.604 ms sched-messaging
10531 10158 1.47 234.067 ms sched-messaging
10400 10158 1.47 240.631 ms sched-messaging
10355 10158 1.47 230.586 ms sched-messaging
10377 10158 1.43 234.835 ms sched-messaging
10526 10158 1.42 232.045 ms sched-messaging
10298 10158 1.41 222.396 ms sched-messaging
10410 10158 1.38 221.853 ms sched-messaging
10364 10158 1.38 226.042 ms sched-messaging
10480 10158 1.36 213.633 ms sched-messaging
10370 10158 1.36 223.620 ms sched-messaging
10553 10158 1.34 217.169 ms sched-messaging
10291 10158 1.34 211.516 ms sched-messaging
10251 10158 1.34 218.813 ms sched-messaging
10522 10158 1.33 218.498 ms sched-messaging
10288 10158 1.33 216.787 ms sched-messaging
<SNIP>
Reviewed-by: Ian Rogers <irogers@google.com>
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ravi Bangoria <ravi.bangoria@amd.com>
Cc: Sandipan Das <sandipan.das@amd.com>
Link: https://lore.kernel.org/r/20230812084917.169338-15-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2023-08-12 08:49:15 +00:00
|
|
|
int perf_kwork__top_prepare_bpf(struct perf_kwork *kwork);
|
|
|
|
int perf_kwork__top_read_bpf(struct perf_kwork *kwork);
|
|
|
|
void perf_kwork__top_cleanup_bpf(void);
|
|
|
|
|
|
|
|
void perf_kwork__top_start(void);
|
|
|
|
void perf_kwork__top_finish(void);
|
|
|
|
|
perf kwork: Implement BPF trace
'perf record' generates perf.data, which generates extra interrupts
for hard disk, amount of data to be collected increases with time.
Using eBPF trace can process the data in kernel, which solves the
preceding two problems.
Add -b/--use-bpf option for latency and report to support
tracing kwork events using eBPF:
1. Create bpf prog and attach to tracepoints,
2. Start tracing after command is entered,
3. After user hit "ctrl+c", stop tracing and report,
4. Support CPU and name filtering.
This commit implements the framework code and
does not add specific event support.
Test cases:
# perf kwork rep -h
Usage: perf kwork report [<options>]
-b, --use-bpf Use BPF to measure kwork runtime
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork lat -h
Usage: perf kwork latency [<options>]
-b, --use-bpf Use BPF to measure kwork latency
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): avg, max, count
--time <str> Time span for analysis (start,stop)
# perf kwork lat -b
Unsupported bpf trace class irq
# perf kwork rep -b
Unsupported bpf trace class irq
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-15-yangjihong1@huawei.com
[ Simplify work_findnew() ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:30 +00:00
|
|
|
#else /* !HAVE_BPF_SKEL */
|
|
|
|
|
|
|
|
static inline int
|
|
|
|
perf_kwork__trace_prepare_bpf(struct perf_kwork *kwork __maybe_unused)
|
|
|
|
{
|
|
|
|
return -1;
|
|
|
|
}
|
|
|
|
|
|
|
|
static inline int
|
|
|
|
perf_kwork__report_read_bpf(struct perf_kwork *kwork __maybe_unused)
|
|
|
|
{
|
|
|
|
return -1;
|
|
|
|
}
|
|
|
|
|
|
|
|
static inline void perf_kwork__report_cleanup_bpf(void) {}
|
|
|
|
|
|
|
|
static inline void perf_kwork__trace_start(void) {}
|
|
|
|
static inline void perf_kwork__trace_finish(void) {}
|
|
|
|
|
perf kwork top: Implements BPF-based cpu usage statistics
Use BPF to collect statistics on the CPU usage based on perf BPF skeletons.
Example usage:
# perf kwork top -h
Usage: perf kwork top [<options>]
-b, --use-bpf Use BPF to measure task cpu usage
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): rate, runtime, tid
--time <str> Time span for analysis (start,stop)
#
# perf kwork -k sched top -b
Starting trace, Hit <Ctrl+C> to stop and report
^C
Total : 160702.425 ms, 8 cpus
%Cpu(s): 36.00% id, 0.00% hi, 0.00% si
%Cpu0 [|||||||||||||||||| 61.66%]
%Cpu1 [|||||||||||||||||| 61.27%]
%Cpu2 [||||||||||||||||||| 66.40%]
%Cpu3 [|||||||||||||||||| 61.28%]
%Cpu4 [|||||||||||||||||| 61.82%]
%Cpu5 [||||||||||||||||||||||| 77.41%]
%Cpu6 [|||||||||||||||||| 61.73%]
%Cpu7 [|||||||||||||||||| 63.25%]
PID SPID %CPU RUNTIME COMMMAND
-------------------------------------------------------------
0 0 38.72 8089.463 ms [swapper/1]
0 0 38.71 8084.547 ms [swapper/3]
0 0 38.33 8007.532 ms [swapper/0]
0 0 38.26 7992.985 ms [swapper/6]
0 0 38.17 7971.865 ms [swapper/4]
0 0 36.74 7447.765 ms [swapper/7]
0 0 33.59 6486.942 ms [swapper/2]
0 0 22.58 3771.268 ms [swapper/5]
9545 9351 2.48 447.136 ms sched-messaging
9574 9351 2.09 418.583 ms sched-messaging
9724 9351 2.05 372.407 ms sched-messaging
9531 9351 2.01 368.804 ms sched-messaging
9512 9351 2.00 362.250 ms sched-messaging
9514 9351 1.95 357.767 ms sched-messaging
9538 9351 1.86 384.476 ms sched-messaging
9712 9351 1.84 386.490 ms sched-messaging
9723 9351 1.83 380.021 ms sched-messaging
9722 9351 1.82 382.738 ms sched-messaging
9517 9351 1.81 354.794 ms sched-messaging
9559 9351 1.79 344.305 ms sched-messaging
9725 9351 1.77 365.315 ms sched-messaging
<SNIP>
# perf kwork -k sched top -b -n perf
Starting trace, Hit <Ctrl+C> to stop and report
^C
Total : 151563.332 ms, 8 cpus
%Cpu(s): 26.49% id, 0.00% hi, 0.00% si
%Cpu0 [ 0.01%]
%Cpu1 [ 0.00%]
%Cpu2 [ 0.00%]
%Cpu3 [ 0.00%]
%Cpu4 [ 0.00%]
%Cpu5 [ 0.00%]
%Cpu6 [ 0.00%]
%Cpu7 [ 0.00%]
PID SPID %CPU RUNTIME COMMMAND
-------------------------------------------------------------
9754 9754 0.01 2.303 ms perf
#
# perf kwork -k sched top -b -C 2,3,4
Starting trace, Hit <Ctrl+C> to stop and report
^C
Total : 48016.721 ms, 3 cpus
%Cpu(s): 27.82% id, 0.00% hi, 0.00% si
%Cpu2 [|||||||||||||||||||||| 74.68%]
%Cpu3 [||||||||||||||||||||| 71.06%]
%Cpu4 [||||||||||||||||||||| 70.91%]
PID SPID %CPU RUNTIME COMMMAND
-------------------------------------------------------------
0 0 29.08 4734.998 ms [swapper/4]
0 0 28.93 4710.029 ms [swapper/3]
0 0 25.31 3912.363 ms [swapper/2]
10248 10158 1.62 264.931 ms sched-messaging
10253 10158 1.62 265.136 ms sched-messaging
10158 10158 1.60 263.013 ms bash
10360 10158 1.49 243.639 ms sched-messaging
10413 10158 1.48 238.604 ms sched-messaging
10531 10158 1.47 234.067 ms sched-messaging
10400 10158 1.47 240.631 ms sched-messaging
10355 10158 1.47 230.586 ms sched-messaging
10377 10158 1.43 234.835 ms sched-messaging
10526 10158 1.42 232.045 ms sched-messaging
10298 10158 1.41 222.396 ms sched-messaging
10410 10158 1.38 221.853 ms sched-messaging
10364 10158 1.38 226.042 ms sched-messaging
10480 10158 1.36 213.633 ms sched-messaging
10370 10158 1.36 223.620 ms sched-messaging
10553 10158 1.34 217.169 ms sched-messaging
10291 10158 1.34 211.516 ms sched-messaging
10251 10158 1.34 218.813 ms sched-messaging
10522 10158 1.33 218.498 ms sched-messaging
10288 10158 1.33 216.787 ms sched-messaging
<SNIP>
Reviewed-by: Ian Rogers <irogers@google.com>
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ravi Bangoria <ravi.bangoria@amd.com>
Cc: Sandipan Das <sandipan.das@amd.com>
Link: https://lore.kernel.org/r/20230812084917.169338-15-yangjihong1@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2023-08-12 08:49:15 +00:00
|
|
|
static inline int
|
|
|
|
perf_kwork__top_prepare_bpf(struct perf_kwork *kwork __maybe_unused)
|
|
|
|
{
|
|
|
|
return -1;
|
|
|
|
}
|
|
|
|
|
|
|
|
static inline int
|
|
|
|
perf_kwork__top_read_bpf(struct perf_kwork *kwork __maybe_unused)
|
|
|
|
{
|
|
|
|
return -1;
|
|
|
|
}
|
|
|
|
|
|
|
|
static inline void perf_kwork__top_cleanup_bpf(void) {}
|
|
|
|
|
|
|
|
static inline void perf_kwork__top_start(void) {}
|
|
|
|
static inline void perf_kwork__top_finish(void) {}
|
|
|
|
|
perf kwork: Implement BPF trace
'perf record' generates perf.data, which generates extra interrupts
for hard disk, amount of data to be collected increases with time.
Using eBPF trace can process the data in kernel, which solves the
preceding two problems.
Add -b/--use-bpf option for latency and report to support
tracing kwork events using eBPF:
1. Create bpf prog and attach to tracepoints,
2. Start tracing after command is entered,
3. After user hit "ctrl+c", stop tracing and report,
4. Support CPU and name filtering.
This commit implements the framework code and
does not add specific event support.
Test cases:
# perf kwork rep -h
Usage: perf kwork report [<options>]
-b, --use-bpf Use BPF to measure kwork runtime
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): runtime, max, count
-S, --with-summary Show summary with statistics
--time <str> Time span for analysis (start,stop)
# perf kwork lat -h
Usage: perf kwork latency [<options>]
-b, --use-bpf Use BPF to measure kwork latency
-C, --cpu <cpu> list of cpus to profile
-i, --input <file> input file name
-n, --name <name> event name to profile
-s, --sort <key[,key2...]>
sort by key(s): avg, max, count
--time <str> Time span for analysis (start,stop)
# perf kwork lat -b
Unsupported bpf trace class irq
# perf kwork rep -b
Unsupported bpf trace class irq
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-15-yangjihong1@huawei.com
[ Simplify work_findnew() ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:30 +00:00
|
|
|
#endif /* HAVE_BPF_SKEL */
|
|
|
|
|
perf kwork: New tool to trace time properties of kernel work (such as softirq, and workqueue)
The 'perf kwork' tool is used to trace time properties of kernel work
(such as irq, softirq, and workqueue), including runtime, latency, and
timehist, using the infrastructure in the perf tools to allow tracing
extra targets.
This is the first commit to reuse the 'perf record' framework code to
implement a simple record function, kwork is not supported currently.
Test cases:
# perf
usage: perf [--version] [--help] [OPTIONS] COMMAND [ARGS]
The most commonly used perf commands are:
<SNIP>
iostat Show I/O performance metrics
kallsyms Searches running kernel for symbols
kmem Tool to trace/measure kernel memory properties
kvm Tool to trace/measure kvm guest os
kwork Tool to trace/measure kernel work properties (latencies)
list List all symbolic event types
lock Analyze lock events
mem Profile memory accesses
record Run a command and record its profile into perf.data
<SNIP>
See 'perf help COMMAND' for more information on a specific command.
# perf kwork
Usage: perf kwork [<options>] {record}
-D, --dump-raw-trace dump raw trace in ASCII
-f, --force don't complain, do it
-k, --kwork <kwork> list of kwork to profile
-v, --verbose be more verbose (show symbol address, etc)
# perf kwork record -- sleep 1
[ perf record: Woken up 0 times to write data ]
[ perf record: Captured and wrote 1.787 MB perf.data ]
Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Clarke <pc@us.ibm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220709015033.38326-2-yangjihong1@huawei.com
[ Add {} for multiline if blocks ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2022-07-09 01:50:17 +00:00
|
|
|
#endif /* PERF_UTIL_KWORK_H */
|