perf lock: Allow concurrent record and report

Message ID 20221104051440.220989-1-namhyung@kernel.org
State New
Headers
Series perf lock: Allow concurrent record and report |

Commit Message

Namhyung Kim Nov. 4, 2022, 5:14 a.m. UTC
  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

Ian Rogers Nov. 8, 2022, 11:26 p.m. UTC | #1
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
>
  
Arnaldo Carvalho de Melo Nov. 10, 2022, 6:34 p.m. UTC | #2
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
  

Patch

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}