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
|
|
|
// SPDX-License-Identifier: GPL-2.0
|
|
|
|
/*
|
|
|
|
* builtin-kwork.c
|
|
|
|
*
|
|
|
|
* Copyright (c) 2022 Huawei Inc, Yang Jihong <yangjihong1@huawei.com>
|
|
|
|
*/
|
|
|
|
|
|
|
|
#include "builtin.h"
|
|
|
|
|
|
|
|
#include "util/data.h"
|
|
|
|
#include "util/kwork.h"
|
|
|
|
#include "util/debug.h"
|
|
|
|
#include "util/symbol.h"
|
|
|
|
#include "util/thread.h"
|
|
|
|
#include "util/string2.h"
|
|
|
|
#include "util/callchain.h"
|
|
|
|
#include "util/evsel_fprintf.h"
|
|
|
|
|
|
|
|
#include <subcmd/pager.h>
|
|
|
|
#include <subcmd/parse-options.h>
|
|
|
|
|
|
|
|
#include <errno.h>
|
|
|
|
#include <inttypes.h>
|
|
|
|
#include <linux/err.h>
|
|
|
|
#include <linux/time64.h>
|
|
|
|
#include <linux/zalloc.h>
|
|
|
|
|
2022-07-09 01:50:18 +00:00
|
|
|
const struct evsel_str_handler irq_tp_handlers[] = {
|
|
|
|
{ "irq:irq_handler_entry", NULL, },
|
|
|
|
{ "irq:irq_handler_exit", NULL, },
|
|
|
|
};
|
|
|
|
|
|
|
|
static struct kwork_class kwork_irq = {
|
|
|
|
.name = "irq",
|
|
|
|
.type = KWORK_CLASS_IRQ,
|
|
|
|
.nr_tracepoints = 2,
|
|
|
|
.tp_handlers = irq_tp_handlers,
|
|
|
|
};
|
|
|
|
|
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
|
|
|
const struct evsel_str_handler softirq_tp_handlers[] = {
|
|
|
|
{ "irq:softirq_raise", NULL, },
|
|
|
|
{ "irq:softirq_entry", NULL, },
|
|
|
|
{ "irq:softirq_exit", NULL, },
|
|
|
|
};
|
|
|
|
|
|
|
|
static struct kwork_class kwork_softirq = {
|
|
|
|
.name = "softirq",
|
|
|
|
.type = KWORK_CLASS_SOFTIRQ,
|
|
|
|
.nr_tracepoints = 3,
|
|
|
|
.tp_handlers = softirq_tp_handlers,
|
|
|
|
};
|
|
|
|
|
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
|
|
|
const struct evsel_str_handler workqueue_tp_handlers[] = {
|
|
|
|
{ "workqueue:workqueue_activate_work", NULL, },
|
|
|
|
{ "workqueue:workqueue_execute_start", NULL, },
|
|
|
|
{ "workqueue:workqueue_execute_end", NULL, },
|
|
|
|
};
|
|
|
|
|
|
|
|
static struct kwork_class kwork_workqueue = {
|
|
|
|
.name = "workqueue",
|
|
|
|
.type = KWORK_CLASS_WORKQUEUE,
|
|
|
|
.nr_tracepoints = 3,
|
|
|
|
.tp_handlers = workqueue_tp_handlers,
|
|
|
|
};
|
|
|
|
|
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
|
|
|
static struct kwork_class *kwork_class_supported_list[KWORK_CLASS_MAX] = {
|
2022-07-09 01:50:18 +00:00
|
|
|
[KWORK_CLASS_IRQ] = &kwork_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] = &kwork_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] = &kwork_workqueue,
|
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
|
|
|
};
|
|
|
|
|
|
|
|
static void setup_event_list(struct perf_kwork *kwork,
|
|
|
|
const struct option *options,
|
|
|
|
const char * const usage_msg[])
|
|
|
|
{
|
|
|
|
int i;
|
|
|
|
struct kwork_class *class;
|
|
|
|
char *tmp, *tok, *str;
|
|
|
|
|
|
|
|
if (kwork->event_list_str == NULL)
|
|
|
|
goto null_event_list_str;
|
|
|
|
|
|
|
|
str = strdup(kwork->event_list_str);
|
|
|
|
for (tok = strtok_r(str, ", ", &tmp);
|
|
|
|
tok; tok = strtok_r(NULL, ", ", &tmp)) {
|
|
|
|
for (i = 0; i < KWORK_CLASS_MAX; i++) {
|
|
|
|
class = kwork_class_supported_list[i];
|
|
|
|
if (strcmp(tok, class->name) == 0) {
|
|
|
|
list_add_tail(&class->list, &kwork->class_list);
|
|
|
|
break;
|
|
|
|
}
|
|
|
|
}
|
|
|
|
if (i == KWORK_CLASS_MAX) {
|
|
|
|
usage_with_options_msg(usage_msg, options,
|
|
|
|
"Unknown --event key: `%s'", tok);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
free(str);
|
|
|
|
|
|
|
|
null_event_list_str:
|
|
|
|
/*
|
|
|
|
* config all kwork events if not specified
|
|
|
|
*/
|
|
|
|
if (list_empty(&kwork->class_list)) {
|
|
|
|
for (i = 0; i < KWORK_CLASS_MAX; i++) {
|
|
|
|
list_add_tail(&kwork_class_supported_list[i]->list,
|
|
|
|
&kwork->class_list);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
pr_debug("Config event list:");
|
|
|
|
list_for_each_entry(class, &kwork->class_list, list)
|
|
|
|
pr_debug(" %s", class->name);
|
|
|
|
pr_debug("\n");
|
|
|
|
}
|
|
|
|
|
|
|
|
static int perf_kwork__record(struct perf_kwork *kwork,
|
|
|
|
int argc, const char **argv)
|
|
|
|
{
|
|
|
|
const char **rec_argv;
|
|
|
|
unsigned int rec_argc, i, j;
|
|
|
|
struct kwork_class *class;
|
|
|
|
|
|
|
|
const char *const record_args[] = {
|
|
|
|
"record",
|
|
|
|
"-a",
|
|
|
|
"-R",
|
|
|
|
"-m", "1024",
|
|
|
|
"-c", "1",
|
|
|
|
};
|
|
|
|
|
|
|
|
rec_argc = ARRAY_SIZE(record_args) + argc - 1;
|
|
|
|
|
|
|
|
list_for_each_entry(class, &kwork->class_list, list)
|
|
|
|
rec_argc += 2 * class->nr_tracepoints;
|
|
|
|
|
|
|
|
rec_argv = calloc(rec_argc + 1, sizeof(char *));
|
|
|
|
if (rec_argv == NULL)
|
|
|
|
return -ENOMEM;
|
|
|
|
|
|
|
|
for (i = 0; i < ARRAY_SIZE(record_args); i++)
|
|
|
|
rec_argv[i] = strdup(record_args[i]);
|
|
|
|
|
|
|
|
list_for_each_entry(class, &kwork->class_list, list) {
|
|
|
|
for (j = 0; j < class->nr_tracepoints; j++) {
|
|
|
|
rec_argv[i++] = strdup("-e");
|
|
|
|
rec_argv[i++] = strdup(class->tp_handlers[j].name);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
for (j = 1; j < (unsigned int)argc; j++, i++)
|
|
|
|
rec_argv[i] = argv[j];
|
|
|
|
|
|
|
|
BUG_ON(i != rec_argc);
|
|
|
|
|
|
|
|
pr_debug("record comm: ");
|
|
|
|
for (j = 0; j < rec_argc; j++)
|
|
|
|
pr_debug("%s ", rec_argv[j]);
|
|
|
|
pr_debug("\n");
|
|
|
|
|
|
|
|
return cmd_record(i, rec_argv);
|
|
|
|
}
|
|
|
|
|
|
|
|
int cmd_kwork(int argc, const char **argv)
|
|
|
|
{
|
|
|
|
static struct perf_kwork kwork = {
|
|
|
|
.class_list = LIST_HEAD_INIT(kwork.class_list),
|
|
|
|
.force = false,
|
|
|
|
.event_list_str = NULL,
|
|
|
|
};
|
|
|
|
const struct option kwork_options[] = {
|
|
|
|
OPT_INCR('v', "verbose", &verbose,
|
|
|
|
"be more verbose (show symbol address, etc)"),
|
|
|
|
OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace,
|
|
|
|
"dump raw trace in ASCII"),
|
|
|
|
OPT_STRING('k', "kwork", &kwork.event_list_str, "kwork",
|
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
|
|
|
"list of kwork to profile (irq, softirq, workqueue, etc)"),
|
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
|
|
|
OPT_BOOLEAN('f', "force", &kwork.force, "don't complain, do it"),
|
|
|
|
OPT_END()
|
|
|
|
};
|
|
|
|
const char *kwork_usage[] = {
|
|
|
|
NULL,
|
|
|
|
NULL
|
|
|
|
};
|
|
|
|
const char *const kwork_subcommands[] = {
|
|
|
|
"record", NULL
|
|
|
|
};
|
|
|
|
|
|
|
|
argc = parse_options_subcommand(argc, argv, kwork_options,
|
|
|
|
kwork_subcommands, kwork_usage,
|
|
|
|
PARSE_OPT_STOP_AT_NON_OPTION);
|
|
|
|
if (!argc)
|
|
|
|
usage_with_options(kwork_usage, kwork_options);
|
|
|
|
|
|
|
|
setup_event_list(&kwork, kwork_options, kwork_usage);
|
|
|
|
|
|
|
|
if (strlen(argv[0]) > 2 && strstarts("record", argv[0]))
|
|
|
|
return perf_kwork__record(&kwork, argc, argv);
|
|
|
|
else
|
|
|
|
usage_with_options(kwork_usage, kwork_options);
|
|
|
|
|
|
|
|
return 0;
|
|
|
|
}
|