perf lock: Allow concurrent record and report
Commit Message
To support live monitoring of kernel lock contention without BPF,
it should support something like below:
# perf lock record -a -o- sleep 1 | perf lock contention -i-
contended total wait max wait avg wait type caller
2 10.27 us 6.17 us 5.13 us spinlock load_balance+0xc03
1 5.29 us 5.29 us 5.29 us rwlock:W ep_scan_ready_list+0x54
1 4.12 us 4.12 us 4.12 us spinlock smpboot_thread_fn+0x116
1 3.28 us 3.28 us 3.28 us mutex pipe_read+0x50
To do that, it needs to handle HEAD_ATTR, HEADER_EVENT_UPDATE and
HEADER_TRACING_DATA which are generated only for the pipe mode.
And setting event handler also should be delayed until it gets the
event information.
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/builtin-lock.c | 68 +++++++++++++++--------
tools/perf/tests/shell/lock_contention.sh | 15 ++++-
2 files changed, 60 insertions(+), 23 deletions(-)
Comments
On Thu, Nov 3, 2022 at 10:14 PM Namhyung Kim <namhyung@kernel.org> wrote:
>
> To support live monitoring of kernel lock contention without BPF,
> it should support something like below:
>
> # perf lock record -a -o- sleep 1 | perf lock contention -i-
> contended total wait max wait avg wait type caller
>
> 2 10.27 us 6.17 us 5.13 us spinlock load_balance+0xc03
> 1 5.29 us 5.29 us 5.29 us rwlock:W ep_scan_ready_list+0x54
> 1 4.12 us 4.12 us 4.12 us spinlock smpboot_thread_fn+0x116
> 1 3.28 us 3.28 us 3.28 us mutex pipe_read+0x50
>
> To do that, it needs to handle HEAD_ATTR, HEADER_EVENT_UPDATE and
> HEADER_TRACING_DATA which are generated only for the pipe mode.
> And setting event handler also should be delayed until it gets the
> event information.
>
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Acked-by: Ian Rogers <irogers@google.com>
Thanks,
Ian
> ---
> tools/perf/builtin-lock.c | 68 +++++++++++++++--------
> tools/perf/tests/shell/lock_contention.sh | 15 ++++-
> 2 files changed, 60 insertions(+), 23 deletions(-)
>
> diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
> index 6f79175365a8..0d280093b19a 100644
> --- a/tools/perf/builtin-lock.c
> +++ b/tools/perf/builtin-lock.c
> @@ -1390,6 +1390,34 @@ static int dump_info(void)
> return rc;
> }
>
> +static const struct evsel_str_handler lock_tracepoints[] = {
> + { "lock:lock_acquire", evsel__process_lock_acquire, }, /* CONFIG_LOCKDEP */
> + { "lock:lock_acquired", evsel__process_lock_acquired, }, /* CONFIG_LOCKDEP, CONFIG_LOCK_STAT */
> + { "lock:lock_contended", evsel__process_lock_contended, }, /* CONFIG_LOCKDEP, CONFIG_LOCK_STAT */
> + { "lock:lock_release", evsel__process_lock_release, }, /* CONFIG_LOCKDEP */
> +};
> +
> +static const struct evsel_str_handler contention_tracepoints[] = {
> + { "lock:contention_begin", evsel__process_contention_begin, },
> + { "lock:contention_end", evsel__process_contention_end, },
> +};
> +
> +static int process_event_update(struct perf_tool *tool,
> + union perf_event *event,
> + struct evlist **pevlist)
> +{
> + int ret;
> +
> + ret = perf_event__process_event_update(tool, event, pevlist);
> + if (ret < 0)
> + return ret;
> +
> + /* this can return -EEXIST since we call it for each evsel */
> + perf_session__set_tracepoints_handlers(session, lock_tracepoints);
> + perf_session__set_tracepoints_handlers(session, contention_tracepoints);
> + return 0;
> +}
> +
> typedef int (*tracepoint_handler)(struct evsel *evsel,
> struct perf_sample *sample);
>
> @@ -1545,28 +1573,19 @@ static void print_contention_result(struct lock_contention *con)
> print_bad_events(bad, total);
> }
>
> -static const struct evsel_str_handler lock_tracepoints[] = {
> - { "lock:lock_acquire", evsel__process_lock_acquire, }, /* CONFIG_LOCKDEP */
> - { "lock:lock_acquired", evsel__process_lock_acquired, }, /* CONFIG_LOCKDEP, CONFIG_LOCK_STAT */
> - { "lock:lock_contended", evsel__process_lock_contended, }, /* CONFIG_LOCKDEP, CONFIG_LOCK_STAT */
> - { "lock:lock_release", evsel__process_lock_release, }, /* CONFIG_LOCKDEP */
> -};
> -
> -static const struct evsel_str_handler contention_tracepoints[] = {
> - { "lock:contention_begin", evsel__process_contention_begin, },
> - { "lock:contention_end", evsel__process_contention_end, },
> -};
> -
> static bool force;
>
> static int __cmd_report(bool display_info)
> {
> int err = -EINVAL;
> struct perf_tool eops = {
> + .attr = perf_event__process_attr,
> + .event_update = process_event_update,
> .sample = process_sample_event,
> .comm = perf_event__process_comm,
> .mmap = perf_event__process_mmap,
> .namespaces = perf_event__process_namespaces,
> + .tracing_data = perf_event__process_tracing_data,
> .ordered_events = true,
> };
> struct perf_data data = {
> @@ -1585,17 +1604,19 @@ static int __cmd_report(bool display_info)
> symbol_conf.sort_by_name = true;
> symbol__init(&session->header.env);
>
> - if (!perf_session__has_traces(session, "lock record"))
> - goto out_delete;
> + if (!data.is_pipe) {
> + if (!perf_session__has_traces(session, "lock record"))
> + goto out_delete;
>
> - if (perf_session__set_tracepoints_handlers(session, lock_tracepoints)) {
> - pr_err("Initializing perf session tracepoint handlers failed\n");
> - goto out_delete;
> - }
> + if (perf_session__set_tracepoints_handlers(session, lock_tracepoints)) {
> + pr_err("Initializing perf session tracepoint handlers failed\n");
> + goto out_delete;
> + }
>
> - if (perf_session__set_tracepoints_handlers(session, contention_tracepoints)) {
> - pr_err("Initializing perf session tracepoint handlers failed\n");
> - goto out_delete;
> + if (perf_session__set_tracepoints_handlers(session, contention_tracepoints)) {
> + pr_err("Initializing perf session tracepoint handlers failed\n");
> + goto out_delete;
> + }
> }
>
> if (setup_output_field(false, output_fields))
> @@ -1633,9 +1654,12 @@ static int __cmd_contention(int argc, const char **argv)
> {
> int err = -EINVAL;
> struct perf_tool eops = {
> + .attr = perf_event__process_attr,
> + .event_update = process_event_update,
> .sample = process_sample_event,
> .comm = perf_event__process_comm,
> .mmap = perf_event__process_mmap,
> + .tracing_data = perf_event__process_tracing_data,
> .ordered_events = true,
> };
> struct perf_data data = {
> @@ -1698,7 +1722,7 @@ static int __cmd_contention(int argc, const char **argv)
> pr_err("lock contention BPF setup failed\n");
> goto out_delete;
> }
> - } else {
> + } else if (!data.is_pipe) {
> if (!perf_session__has_traces(session, "lock record"))
> goto out_delete;
>
> diff --git a/tools/perf/tests/shell/lock_contention.sh b/tools/perf/tests/shell/lock_contention.sh
> index 04bf604e3c6f..f7bd0d8eb5c3 100755
> --- a/tools/perf/tests/shell/lock_contention.sh
> +++ b/tools/perf/tests/shell/lock_contention.sh
> @@ -53,7 +53,7 @@ test_bpf()
>
> if ! perf lock con -b true > /dev/null 2>&1 ; then
> echo "[Skip] No BPF support"
> - exit
> + return
> fi
>
> # the perf lock contention output goes to the stderr
> @@ -65,9 +65,22 @@ test_bpf()
> fi
> }
>
> +test_record_concurrent()
> +{
> + echo "Testing perf lock record and perf lock contention at the same time"
> + perf lock record -o- -- perf bench sched messaging 2> /dev/null | \
> + perf lock contention -i- -E 1 -q 2> ${result}
> + if [ $(cat "${result}" | wc -l) != "1" ]; then
> + echo "[Fail] Recorded result count is not 1:" $(cat "${result}" | wc -l)
> + err=1
> + exit
> + fi
> +}
> +
> check
>
> test_record
> test_bpf
> +test_record_concurrent
>
> exit ${err}
> --
> 2.38.1.431.g37b22c650d-goog
>
Em Tue, Nov 08, 2022 at 03:26:01PM -0800, Ian Rogers escreveu:
> On Thu, Nov 3, 2022 at 10:14 PM Namhyung Kim <namhyung@kernel.org> wrote:
> >
> > To support live monitoring of kernel lock contention without BPF,
> > it should support something like below:
> >
> > # perf lock record -a -o- sleep 1 | perf lock contention -i-
> > contended total wait max wait avg wait type caller
> >
> > 2 10.27 us 6.17 us 5.13 us spinlock load_balance+0xc03
> > 1 5.29 us 5.29 us 5.29 us rwlock:W ep_scan_ready_list+0x54
> > 1 4.12 us 4.12 us 4.12 us spinlock smpboot_thread_fn+0x116
> > 1 3.28 us 3.28 us 3.28 us mutex pipe_read+0x50
> >
> > To do that, it needs to handle HEAD_ATTR, HEADER_EVENT_UPDATE and
> > HEADER_TRACING_DATA which are generated only for the pipe mode.
> > And setting event handler also should be delayed until it gets the
> > event information.
> >
> > Signed-off-by: Namhyung Kim <namhyung@kernel.org>
>
> Acked-by: Ian Rogers <irogers@google.com>
Thanks, applied.
- Arnaldo
@@ -1390,6 +1390,34 @@ static int dump_info(void)
return rc;
}
+static const struct evsel_str_handler lock_tracepoints[] = {
+ { "lock:lock_acquire", evsel__process_lock_acquire, }, /* CONFIG_LOCKDEP */
+ { "lock:lock_acquired", evsel__process_lock_acquired, }, /* CONFIG_LOCKDEP, CONFIG_LOCK_STAT */
+ { "lock:lock_contended", evsel__process_lock_contended, }, /* CONFIG_LOCKDEP, CONFIG_LOCK_STAT */
+ { "lock:lock_release", evsel__process_lock_release, }, /* CONFIG_LOCKDEP */
+};
+
+static const struct evsel_str_handler contention_tracepoints[] = {
+ { "lock:contention_begin", evsel__process_contention_begin, },
+ { "lock:contention_end", evsel__process_contention_end, },
+};
+
+static int process_event_update(struct perf_tool *tool,
+ union perf_event *event,
+ struct evlist **pevlist)
+{
+ int ret;
+
+ ret = perf_event__process_event_update(tool, event, pevlist);
+ if (ret < 0)
+ return ret;
+
+ /* this can return -EEXIST since we call it for each evsel */
+ perf_session__set_tracepoints_handlers(session, lock_tracepoints);
+ perf_session__set_tracepoints_handlers(session, contention_tracepoints);
+ return 0;
+}
+
typedef int (*tracepoint_handler)(struct evsel *evsel,
struct perf_sample *sample);
@@ -1545,28 +1573,19 @@ static void print_contention_result(struct lock_contention *con)
print_bad_events(bad, total);
}
-static const struct evsel_str_handler lock_tracepoints[] = {
- { "lock:lock_acquire", evsel__process_lock_acquire, }, /* CONFIG_LOCKDEP */
- { "lock:lock_acquired", evsel__process_lock_acquired, }, /* CONFIG_LOCKDEP, CONFIG_LOCK_STAT */
- { "lock:lock_contended", evsel__process_lock_contended, }, /* CONFIG_LOCKDEP, CONFIG_LOCK_STAT */
- { "lock:lock_release", evsel__process_lock_release, }, /* CONFIG_LOCKDEP */
-};
-
-static const struct evsel_str_handler contention_tracepoints[] = {
- { "lock:contention_begin", evsel__process_contention_begin, },
- { "lock:contention_end", evsel__process_contention_end, },
-};
-
static bool force;
static int __cmd_report(bool display_info)
{
int err = -EINVAL;
struct perf_tool eops = {
+ .attr = perf_event__process_attr,
+ .event_update = process_event_update,
.sample = process_sample_event,
.comm = perf_event__process_comm,
.mmap = perf_event__process_mmap,
.namespaces = perf_event__process_namespaces,
+ .tracing_data = perf_event__process_tracing_data,
.ordered_events = true,
};
struct perf_data data = {
@@ -1585,17 +1604,19 @@ static int __cmd_report(bool display_info)
symbol_conf.sort_by_name = true;
symbol__init(&session->header.env);
- if (!perf_session__has_traces(session, "lock record"))
- goto out_delete;
+ if (!data.is_pipe) {
+ if (!perf_session__has_traces(session, "lock record"))
+ goto out_delete;
- if (perf_session__set_tracepoints_handlers(session, lock_tracepoints)) {
- pr_err("Initializing perf session tracepoint handlers failed\n");
- goto out_delete;
- }
+ if (perf_session__set_tracepoints_handlers(session, lock_tracepoints)) {
+ pr_err("Initializing perf session tracepoint handlers failed\n");
+ goto out_delete;
+ }
- if (perf_session__set_tracepoints_handlers(session, contention_tracepoints)) {
- pr_err("Initializing perf session tracepoint handlers failed\n");
- goto out_delete;
+ if (perf_session__set_tracepoints_handlers(session, contention_tracepoints)) {
+ pr_err("Initializing perf session tracepoint handlers failed\n");
+ goto out_delete;
+ }
}
if (setup_output_field(false, output_fields))
@@ -1633,9 +1654,12 @@ static int __cmd_contention(int argc, const char **argv)
{
int err = -EINVAL;
struct perf_tool eops = {
+ .attr = perf_event__process_attr,
+ .event_update = process_event_update,
.sample = process_sample_event,
.comm = perf_event__process_comm,
.mmap = perf_event__process_mmap,
+ .tracing_data = perf_event__process_tracing_data,
.ordered_events = true,
};
struct perf_data data = {
@@ -1698,7 +1722,7 @@ static int __cmd_contention(int argc, const char **argv)
pr_err("lock contention BPF setup failed\n");
goto out_delete;
}
- } else {
+ } else if (!data.is_pipe) {
if (!perf_session__has_traces(session, "lock record"))
goto out_delete;
@@ -53,7 +53,7 @@ test_bpf()
if ! perf lock con -b true > /dev/null 2>&1 ; then
echo "[Skip] No BPF support"
- exit
+ return
fi
# the perf lock contention output goes to the stderr
@@ -65,9 +65,22 @@ test_bpf()
fi
}
+test_record_concurrent()
+{
+ echo "Testing perf lock record and perf lock contention at the same time"
+ perf lock record -o- -- perf bench sched messaging 2> /dev/null | \
+ perf lock contention -i- -E 1 -q 2> ${result}
+ if [ $(cat "${result}" | wc -l) != "1" ]; then
+ echo "[Fail] Recorded result count is not 1:" $(cat "${result}" | wc -l)
+ err=1
+ exit
+ fi
+}
+
check
test_record
test_bpf
+test_record_concurrent
exit ${err}