* [PATCHSET 0/6] perf lock: Add contention subcommand (v1)
@ 2022-07-21 4:36 Namhyung Kim
2022-07-21 4:36 ` [PATCH 1/6] perf lock: Fix a copy-n-paste bug Namhyung Kim
` (6 more replies)
0 siblings, 7 replies; 15+ messages in thread
From: Namhyung Kim @ 2022-07-21 4:36 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo, Jiri Olsa
Cc: Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers, linux-perf-users,
Will Deacon, Waiman Long, Boqun Feng, Davidlohr Bueso
Hello,
It's to add a new subcommand 'contention' (shortly 'con') to perf lock.
The new subcommand is to handle the new lock:contention_{begin,end}
tracepoints and shows lock type and caller address like below:
$ perf lock contention
contended total wait max wait avg wait type caller
238 1.41 ms 29.20 us 5.94 us spinlock update_blocked_averages+0x4c
1 902.08 us 902.08 us 902.08 us rwsem:R do_user_addr_fault+0x1dd
81 330.30 us 17.24 us 4.08 us spinlock _nohz_idle_balance+0x172
2 89.54 us 61.26 us 44.77 us spinlock do_anonymous_page+0x16d
24 78.36 us 12.27 us 3.27 us mutex pipe_read+0x56
2 71.58 us 59.56 us 35.79 us spinlock __handle_mm_fault+0x6aa
6 25.68 us 6.89 us 4.28 us spinlock do_idle+0x28d
1 18.46 us 18.46 us 18.46 us rtmutex exec_fw_cmd+0x21b
3 15.25 us 6.26 us 5.08 us spinlock tick_do_update_jiffies64+0x2c
...
where rwsem:R stands for read access (down_read) for a rw-semaphore.
Other types of lock access is obvious and it doesn't detect optimistic
spinning on mutex yet. This is just a base work for lock contention
analysis and more will come later.
You can get this from 'perf/lock-subcmd-v1' branch on
git://git.kernel.org/pub/scm/linux/kernel/git/namhyung/linux-perf.git
Thanks,
Namhyung
Namhyung Kim (6):
perf lock: Fix a copy-n-paste bug
perf lock: Add flags field in the lock_stat
perf lock: Add lock aggregation enum
perf lock: Add 'contention' subcommand
perf lock: Add -k and -F options to 'contention' subcommand
perf lock: Support -t option for 'contention' subcommand
tools/perf/Documentation/perf-lock.txt | 23 +-
tools/perf/builtin-lock.c | 403 ++++++++++++++++++++++---
2 files changed, 391 insertions(+), 35 deletions(-)
base-commit: 41d0914d861e82b4eeec16dd0f6109c311cf4c7e
--
2.37.0.170.g444d1eabd0-goog
^ permalink raw reply [flat|nested] 15+ messages in thread
* [PATCH 1/6] perf lock: Fix a copy-n-paste bug
2022-07-21 4:36 [PATCHSET 0/6] perf lock: Add contention subcommand (v1) Namhyung Kim
@ 2022-07-21 4:36 ` Namhyung Kim
2022-07-21 19:09 ` Arnaldo Carvalho de Melo
2022-07-21 4:36 ` [PATCH 2/6] perf lock: Add flags field in the lock_stat Namhyung Kim
` (5 subsequent siblings)
6 siblings, 1 reply; 15+ messages in thread
From: Namhyung Kim @ 2022-07-21 4:36 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo, Jiri Olsa
Cc: Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers, linux-perf-users,
Will Deacon, Waiman Long, Boqun Feng, Davidlohr Bueso
It should be lock_text_end instead of _start.
Fixes: 0d2997f750d1 ("perf lock: Look up callchain for the contended locks")
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/builtin-lock.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
index c5ca34741561..0aae88fdf93a 100644
--- a/tools/perf/builtin-lock.c
+++ b/tools/perf/builtin-lock.c
@@ -892,7 +892,7 @@ static bool is_lock_function(u64 addr)
sym = machine__find_kernel_symbol_by_name(machine,
"__lock_text_end",
&kmap);
- lock_text_start = kmap->unmap_ip(kmap, sym->start);
+ lock_text_end = kmap->unmap_ip(kmap, sym->start);
}
/* failed to get kernel symbols */
--
2.37.0.170.g444d1eabd0-goog
^ permalink raw reply related [flat|nested] 15+ messages in thread
* [PATCH 2/6] perf lock: Add flags field in the lock_stat
2022-07-21 4:36 [PATCHSET 0/6] perf lock: Add contention subcommand (v1) Namhyung Kim
2022-07-21 4:36 ` [PATCH 1/6] perf lock: Fix a copy-n-paste bug Namhyung Kim
@ 2022-07-21 4:36 ` Namhyung Kim
2022-07-21 4:36 ` [PATCH 3/6] perf lock: Add lock aggregation enum Namhyung Kim
` (4 subsequent siblings)
6 siblings, 0 replies; 15+ messages in thread
From: Namhyung Kim @ 2022-07-21 4:36 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo, Jiri Olsa
Cc: Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers, linux-perf-users,
Will Deacon, Waiman Long, Boqun Feng, Davidlohr Bueso
For lock contention tracepoint analysis, it needs to keep the flags.
As nr_readlock and nr_trylock fields are not used for it, let's make
it a union.
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/builtin-lock.c | 22 +++++++++++++---------
1 file changed, 13 insertions(+), 9 deletions(-)
diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
index 0aae88fdf93a..1de459198b99 100644
--- a/tools/perf/builtin-lock.c
+++ b/tools/perf/builtin-lock.c
@@ -59,7 +59,10 @@ struct lock_stat {
unsigned int nr_contended;
unsigned int nr_release;
- unsigned int nr_readlock;
+ union {
+ unsigned int nr_readlock;
+ unsigned int flags;
+ };
unsigned int nr_trylock;
/* these times are in nano sec. */
@@ -516,7 +519,7 @@ static struct lock_stat *lock_stat_find(u64 addr)
return NULL;
}
-static struct lock_stat *lock_stat_findnew(u64 addr, const char *name)
+static struct lock_stat *lock_stat_findnew(u64 addr, const char *name, int flags)
{
struct hlist_head *entry = lockhashentry(addr);
struct lock_stat *ret, *new;
@@ -531,13 +534,13 @@ static struct lock_stat *lock_stat_findnew(u64 addr, const char *name)
goto alloc_failed;
new->addr = addr;
- new->name = zalloc(sizeof(char) * strlen(name) + 1);
+ new->name = strdup(name);
if (!new->name) {
free(new);
goto alloc_failed;
}
- strcpy(new->name, name);
+ new->flags = flags;
new->wait_time_min = ULLONG_MAX;
hlist_add_head(&new->hash_entry, entry);
@@ -624,7 +627,7 @@ static int report_lock_acquire_event(struct evsel *evsel,
if (show_thread_stats)
addr = sample->tid;
- ls = lock_stat_findnew(addr, name);
+ ls = lock_stat_findnew(addr, name, 0);
if (!ls)
return -ENOMEM;
@@ -696,7 +699,7 @@ static int report_lock_acquired_event(struct evsel *evsel,
if (show_thread_stats)
addr = sample->tid;
- ls = lock_stat_findnew(addr, name);
+ ls = lock_stat_findnew(addr, name, 0);
if (!ls)
return -ENOMEM;
@@ -758,7 +761,7 @@ static int report_lock_contended_event(struct evsel *evsel,
if (show_thread_stats)
addr = sample->tid;
- ls = lock_stat_findnew(addr, name);
+ ls = lock_stat_findnew(addr, name, 0);
if (!ls)
return -ENOMEM;
@@ -813,7 +816,7 @@ static int report_lock_release_event(struct evsel *evsel,
if (show_thread_stats)
addr = sample->tid;
- ls = lock_stat_findnew(addr, name);
+ ls = lock_stat_findnew(addr, name, 0);
if (!ls)
return -ENOMEM;
@@ -985,11 +988,12 @@ static int report_lock_contention_begin_event(struct evsel *evsel,
if (!ls) {
char buf[128];
const char *caller = buf;
+ unsigned int flags = evsel__intval(evsel, sample, "flags");
if (lock_contention_caller(evsel, sample, buf, sizeof(buf)) < 0)
caller = "Unknown";
- ls = lock_stat_findnew(addr, caller);
+ ls = lock_stat_findnew(addr, caller, flags);
if (!ls)
return -ENOMEM;
}
--
2.37.0.170.g444d1eabd0-goog
^ permalink raw reply related [flat|nested] 15+ messages in thread
* [PATCH 3/6] perf lock: Add lock aggregation enum
2022-07-21 4:36 [PATCHSET 0/6] perf lock: Add contention subcommand (v1) Namhyung Kim
2022-07-21 4:36 ` [PATCH 1/6] perf lock: Fix a copy-n-paste bug Namhyung Kim
2022-07-21 4:36 ` [PATCH 2/6] perf lock: Add flags field in the lock_stat Namhyung Kim
@ 2022-07-21 4:36 ` Namhyung Kim
2022-07-21 19:02 ` Arnaldo Carvalho de Melo
2022-07-21 4:36 ` [PATCH 4/6] perf lock: Add 'contention' subcommand Namhyung Kim
` (3 subsequent siblings)
6 siblings, 1 reply; 15+ messages in thread
From: Namhyung Kim @ 2022-07-21 4:36 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo, Jiri Olsa
Cc: Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers, linux-perf-users,
Will Deacon, Waiman Long, Boqun Feng, Davidlohr Bueso
Introduce the aggr_mode variable to prepare the later code change.
The default is LOCK_AGGR_ADDR which aggregate the result for the lock
instances. When -t/--threads option is given, it'd be set to
LOCK_AGGR_TASK. The LOCK_AGGR_CALLER is for the contention analysis
and it'd aggregate the stat by comparing the callstacks.
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/builtin-lock.c | 112 +++++++++++++++++++++++++++++++-------
1 file changed, 93 insertions(+), 19 deletions(-)
diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
index 1de459198b99..551bad905139 100644
--- a/tools/perf/builtin-lock.c
+++ b/tools/perf/builtin-lock.c
@@ -126,6 +126,12 @@ static struct rb_root thread_stats;
static bool combine_locks;
static bool show_thread_stats;
+static enum {
+ LOCK_AGGR_ADDR,
+ LOCK_AGGR_TASK,
+ LOCK_AGGR_CALLER,
+} aggr_mode = LOCK_AGGR_ADDR;
+
/*
* CONTENTION_STACK_DEPTH
* Number of stack trace entries to find callers
@@ -622,12 +628,22 @@ static int report_lock_acquire_event(struct evsel *evsel,
const char *name = evsel__strval(evsel, sample, "name");
u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
int flag = evsel__intval(evsel, sample, "flags");
+ u64 key;
- /* abuse ls->addr for tid */
- if (show_thread_stats)
- addr = sample->tid;
+ switch (aggr_mode) {
+ case LOCK_AGGR_ADDR:
+ key = addr;
+ break;
+ case LOCK_AGGR_TASK:
+ key = sample->tid;
+ break;
+ case LOCK_AGGR_CALLER:
+ default:
+ pr_err("Invalid aggregation mode: %d\n", aggr_mode);
+ return -EINVAL;
+ }
- ls = lock_stat_findnew(addr, name, 0);
+ ls = lock_stat_findnew(key, name, 0);
if (!ls)
return -ENOMEM;
@@ -695,11 +711,22 @@ static int report_lock_acquired_event(struct evsel *evsel,
u64 contended_term;
const char *name = evsel__strval(evsel, sample, "name");
u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
+ u64 key;
- if (show_thread_stats)
- addr = sample->tid;
+ switch (aggr_mode) {
+ case LOCK_AGGR_ADDR:
+ key = addr;
+ break;
+ case LOCK_AGGR_TASK:
+ key = sample->tid;
+ break;
+ case LOCK_AGGR_CALLER:
+ default:
+ pr_err("Invalid aggregation mode: %d\n", aggr_mode);
+ return -EINVAL;
+ }
- ls = lock_stat_findnew(addr, name, 0);
+ ls = lock_stat_findnew(key, name, 0);
if (!ls)
return -ENOMEM;
@@ -757,11 +784,22 @@ static int report_lock_contended_event(struct evsel *evsel,
struct lock_seq_stat *seq;
const char *name = evsel__strval(evsel, sample, "name");
u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
+ u64 key;
- if (show_thread_stats)
- addr = sample->tid;
+ switch (aggr_mode) {
+ case LOCK_AGGR_ADDR:
+ key = addr;
+ break;
+ case LOCK_AGGR_TASK:
+ key = sample->tid;
+ break;
+ case LOCK_AGGR_CALLER:
+ default:
+ pr_err("Invalid aggregation mode: %d\n", aggr_mode);
+ return -EINVAL;
+ }
- ls = lock_stat_findnew(addr, name, 0);
+ ls = lock_stat_findnew(key, name, 0);
if (!ls)
return -ENOMEM;
@@ -812,11 +850,22 @@ static int report_lock_release_event(struct evsel *evsel,
struct lock_seq_stat *seq;
const char *name = evsel__strval(evsel, sample, "name");
u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
+ u64 key;
- if (show_thread_stats)
- addr = sample->tid;
+ switch (aggr_mode) {
+ case LOCK_AGGR_ADDR:
+ key = addr;
+ break;
+ case LOCK_AGGR_TASK:
+ key = sample->tid;
+ break;
+ case LOCK_AGGR_CALLER:
+ default:
+ pr_err("Invalid aggregation mode: %d\n", aggr_mode);
+ return -EINVAL;
+ }
- ls = lock_stat_findnew(addr, name, 0);
+ ls = lock_stat_findnew(key, name, 0);
if (!ls)
return -ENOMEM;
@@ -980,11 +1029,22 @@ static int report_lock_contention_begin_event(struct evsel *evsel,
struct thread_stat *ts;
struct lock_seq_stat *seq;
u64 addr = evsel__intval(evsel, sample, "lock_addr");
+ u64 key;
- if (show_thread_stats)
- addr = sample->tid;
+ switch (aggr_mode) {
+ case LOCK_AGGR_ADDR:
+ key = addr;
+ break;
+ case LOCK_AGGR_TASK:
+ key = sample->tid;
+ break;
+ case LOCK_AGGR_CALLER:
+ default:
+ pr_err("Invalid aggregation mode: %d\n", aggr_mode);
+ return -EINVAL;
+ }
- ls = lock_stat_find(addr);
+ ls = lock_stat_find(key);
if (!ls) {
char buf[128];
const char *caller = buf;
@@ -993,7 +1053,7 @@ static int report_lock_contention_begin_event(struct evsel *evsel,
if (lock_contention_caller(evsel, sample, buf, sizeof(buf)) < 0)
caller = "Unknown";
- ls = lock_stat_findnew(addr, caller, flags);
+ ls = lock_stat_findnew(key, caller, flags);
if (!ls)
return -ENOMEM;
}
@@ -1050,9 +1110,20 @@ static int report_lock_contention_end_event(struct evsel *evsel,
struct lock_seq_stat *seq;
u64 contended_term;
u64 addr = evsel__intval(evsel, sample, "lock_addr");
+ u64 key;
- if (show_thread_stats)
- addr = sample->tid;
+ switch (aggr_mode) {
+ case LOCK_AGGR_ADDR:
+ key = addr;
+ break;
+ case LOCK_AGGR_TASK:
+ key = sample->tid;
+ break;
+ case LOCK_AGGR_CALLER:
+ default:
+ pr_err("Invalid aggregation mode: %d\n", aggr_mode);
+ return -EINVAL;
+ }
ls = lock_stat_find(addr);
if (!ls)
@@ -1416,6 +1487,9 @@ static int __cmd_report(bool display_info)
if (select_key())
goto out_delete;
+ if (show_thread_stats)
+ aggr_mode = LOCK_AGGR_TASK;
+
err = perf_session__process_events(session);
if (err)
goto out_delete;
--
2.37.0.170.g444d1eabd0-goog
^ permalink raw reply related [flat|nested] 15+ messages in thread
* [PATCH 4/6] perf lock: Add 'contention' subcommand
2022-07-21 4:36 [PATCHSET 0/6] perf lock: Add contention subcommand (v1) Namhyung Kim
` (2 preceding siblings ...)
2022-07-21 4:36 ` [PATCH 3/6] perf lock: Add lock aggregation enum Namhyung Kim
@ 2022-07-21 4:36 ` Namhyung Kim
2022-07-21 4:36 ` [PATCH 5/6] perf lock: Add -k and -F options to " Namhyung Kim
` (2 subsequent siblings)
6 siblings, 0 replies; 15+ messages in thread
From: Namhyung Kim @ 2022-07-21 4:36 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo, Jiri Olsa
Cc: Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers, linux-perf-users,
Will Deacon, Waiman Long, Boqun Feng, Davidlohr Bueso
The 'perf lock contention' processes the lock contention events and
displays the result like perf lock report. Right now, there's not
much difference between the two but the lock contention specific
features will come soon.
$ perf lock contention
contended total wait max wait avg wait type caller
238 1.41 ms 29.20 us 5.94 us spinlock update_blocked_averages+0x4c
1 902.08 us 902.08 us 902.08 us rwsem:R do_user_addr_fault+0x1dd
81 330.30 us 17.24 us 4.08 us spinlock _nohz_idle_balance+0x172
2 89.54 us 61.26 us 44.77 us spinlock do_anonymous_page+0x16d
24 78.36 us 12.27 us 3.27 us mutex pipe_read+0x56
2 71.58 us 59.56 us 35.79 us spinlock __handle_mm_fault+0x6aa
6 25.68 us 6.89 us 4.28 us spinlock do_idle+0x28d
1 18.46 us 18.46 us 18.46 us rtmutex exec_fw_cmd+0x21b
3 15.25 us 6.26 us 5.08 us spinlock tick_do_update_jiffies64+0x2c
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/Documentation/perf-lock.txt | 4 +-
tools/perf/builtin-lock.c | 214 ++++++++++++++++++++++++-
2 files changed, 215 insertions(+), 3 deletions(-)
diff --git a/tools/perf/Documentation/perf-lock.txt b/tools/perf/Documentation/perf-lock.txt
index 4b8568f0c53b..da0bcbc676a3 100644
--- a/tools/perf/Documentation/perf-lock.txt
+++ b/tools/perf/Documentation/perf-lock.txt
@@ -8,7 +8,7 @@ perf-lock - Analyze lock events
SYNOPSIS
--------
[verse]
-'perf lock' {record|report|script|info}
+'perf lock' {record|report|script|info|contention}
DESCRIPTION
-----------
@@ -27,6 +27,8 @@ and statistics with this 'perf lock' command.
'perf lock info' shows metadata like threads or addresses
of lock instances.
+ 'perf lock contention' shows contention statistics.
+
COMMON OPTIONS
--------------
diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
index 551bad905139..64f635273660 100644
--- a/tools/perf/builtin-lock.c
+++ b/tools/perf/builtin-lock.c
@@ -145,6 +145,18 @@ static enum {
*/
#define CONTENTION_STACK_SKIP 3
+/*
+ * flags for lock:contention_begin
+ * Imported from include/trace/events/lock.h.
+ */
+#define LCB_F_SPIN (1U << 0)
+#define LCB_F_READ (1U << 1)
+#define LCB_F_WRITE (1U << 2)
+#define LCB_F_RT (1U << 3)
+#define LCB_F_PERCPU (1U << 4)
+#define LCB_F_MUTEX (1U << 5)
+
+
static u64 sched_text_start;
static u64 sched_text_end;
static u64 lock_text_start;
@@ -1022,6 +1034,51 @@ static int lock_contention_caller(struct evsel *evsel, struct perf_sample *sampl
return -1;
}
+static u64 callchain_id(struct evsel *evsel, struct perf_sample *sample)
+{
+ struct callchain_cursor *cursor = &callchain_cursor;
+ struct thread *thread;
+ u64 hash = 0;
+ int skip = 0;
+ int ret;
+
+ thread = machine__findnew_thread(&session->machines.host,
+ -1, sample->pid);
+ if (thread == NULL)
+ return -1;
+
+ /* use caller function name from the callchain */
+ ret = thread__resolve_callchain(thread, cursor, evsel, sample,
+ NULL, NULL, CONTENTION_STACK_DEPTH);
+ thread__put(thread);
+
+ if (ret != 0)
+ return -1;
+
+ callchain_cursor_commit(cursor);
+
+ while (true) {
+ struct callchain_cursor_node *node;
+
+ node = callchain_cursor_current(cursor);
+ if (node == NULL)
+ break;
+
+ /* skip first few entries - for lock functions */
+ if (++skip <= CONTENTION_STACK_SKIP)
+ goto next;
+
+ if (node->ms.sym && is_lock_function(node->ip))
+ goto next;
+
+ hash ^= hash_long((unsigned long)node->ip, 64);
+
+next:
+ callchain_cursor_advance(cursor);
+ }
+ return hash;
+}
+
static int report_lock_contention_begin_event(struct evsel *evsel,
struct perf_sample *sample)
{
@@ -1039,6 +1096,8 @@ static int report_lock_contention_begin_event(struct evsel *evsel,
key = sample->tid;
break;
case LOCK_AGGR_CALLER:
+ key = callchain_id(evsel, sample);
+ break;
default:
pr_err("Invalid aggregation mode: %d\n", aggr_mode);
return -EINVAL;
@@ -1120,12 +1179,14 @@ static int report_lock_contention_end_event(struct evsel *evsel,
key = sample->tid;
break;
case LOCK_AGGR_CALLER:
+ key = callchain_id(evsel, sample);
+ break;
default:
pr_err("Invalid aggregation mode: %d\n", aggr_mode);
return -EINVAL;
}
- ls = lock_stat_find(addr);
+ ls = lock_stat_find(key);
if (!ls)
return 0;
@@ -1183,6 +1244,12 @@ static struct trace_lock_handler report_lock_ops = {
.contention_end_event = report_lock_contention_end_event,
};
+static struct trace_lock_handler contention_lock_ops = {
+ .contention_begin_event = report_lock_contention_begin_event,
+ .contention_end_event = report_lock_contention_end_event,
+};
+
+
static struct trace_lock_handler *trace_handler;
static int evsel__process_lock_acquire(struct evsel *evsel, struct perf_sample *sample)
@@ -1428,6 +1495,67 @@ static void sort_result(void)
}
}
+static const char *get_type_str(struct lock_stat *st)
+{
+ static const struct {
+ unsigned int flags;
+ const char *name;
+ } table[] = {
+ { 0, "semaphore" },
+ { LCB_F_SPIN, "spinlock" },
+ { LCB_F_SPIN | LCB_F_READ, "rwlock:R" },
+ { LCB_F_SPIN | LCB_F_WRITE, "rwlock:W"},
+ { LCB_F_READ, "rwsem:R" },
+ { LCB_F_WRITE, "rwsem:W" },
+ { LCB_F_RT, "rtmutex" },
+ { LCB_F_RT | LCB_F_READ, "rwlock-rt:R" },
+ { LCB_F_RT | LCB_F_WRITE, "rwlock-rt:W"},
+ { LCB_F_PERCPU | LCB_F_READ, "pcpu-sem:R" },
+ { LCB_F_PERCPU | LCB_F_WRITE, "pcpu-sem:W" },
+ { LCB_F_MUTEX, "mutex" },
+ { LCB_F_MUTEX | LCB_F_SPIN, "mutex" },
+ };
+
+ for (unsigned int i = 0; i < ARRAY_SIZE(table); i++) {
+ if (table[i].flags == st->flags)
+ return table[i].name;
+ }
+ return "unknown";
+}
+
+static void sort_contention_result(void)
+{
+ sort_result();
+}
+
+static void print_contention_result(void)
+{
+ struct lock_stat *st;
+ struct lock_key *key;
+ int bad, total;
+
+ list_for_each_entry(key, &lock_keys, list)
+ pr_info("%*s ", key->len, key->header);
+
+ pr_info(" %10s %s\n\n", "type", "caller");
+
+ bad = total = 0;
+ while ((st = pop_from_result())) {
+ total++;
+ if (st->broken)
+ bad++;
+
+ list_for_each_entry(key, &lock_keys, list) {
+ key->print(key, st);
+ pr_info(" ");
+ }
+
+ pr_info(" %10s %s\n", get_type_str(st), st->name);
+ }
+
+ 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 */
@@ -1508,6 +1636,68 @@ static int __cmd_report(bool display_info)
return err;
}
+static int __cmd_contention(void)
+{
+ int err = -EINVAL;
+ struct perf_tool eops = {
+ .sample = process_sample_event,
+ .comm = perf_event__process_comm,
+ .mmap = perf_event__process_mmap,
+ .ordered_events = true,
+ };
+ struct perf_data data = {
+ .path = input_name,
+ .mode = PERF_DATA_MODE_READ,
+ .force = force,
+ };
+
+ session = perf_session__new(&data, &eops);
+ if (IS_ERR(session)) {
+ pr_err("Initializing perf session failed\n");
+ return PTR_ERR(session);
+ }
+
+ /* for lock function check */
+ symbol_conf.sort_by_name = true;
+ symbol__init(&session->header.env);
+
+ if (!perf_session__has_traces(session, "lock record"))
+ goto out_delete;
+
+ if (!evlist__find_evsel_by_str(session->evlist, "lock:contention_begin")) {
+ pr_err("lock contention evsel not found\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("contended,wait_total,wait_max,avg_wait"))
+ goto out_delete;
+
+ sort_key = "wait_total";
+ if (select_key())
+ goto out_delete;
+
+ aggr_mode = LOCK_AGGR_CALLER;
+
+ err = perf_session__process_events(session);
+ if (err)
+ goto out_delete;
+
+ setup_pager();
+
+ sort_contention_result();
+ print_contention_result();
+
+out_delete:
+ perf_session__delete(session);
+ return err;
+}
+
+
static int __cmd_record(int argc, const char **argv)
{
const char *record_args[] = {
@@ -1626,12 +1816,17 @@ int cmd_lock(int argc, const char **argv)
OPT_PARENT(lock_options)
};
+ const struct option contention_options[] = {
+ OPT_PARENT(lock_options)
+ };
+
const char * const info_usage[] = {
"perf lock info [<options>]",
NULL
};
const char *const lock_subcommands[] = { "record", "report", "script",
- "info", NULL };
+ "info", "contention",
+ "contention", NULL };
const char *lock_usage[] = {
NULL,
NULL
@@ -1640,6 +1835,10 @@ int cmd_lock(int argc, const char **argv)
"perf lock report [<options>]",
NULL
};
+ const char * const contention_usage[] = {
+ "perf lock contention [<options>]",
+ NULL
+ };
unsigned int i;
int rc = 0;
@@ -1675,6 +1874,17 @@ int cmd_lock(int argc, const char **argv)
/* recycling report_lock_ops */
trace_handler = &report_lock_ops;
rc = __cmd_report(true);
+ } else if (strlen(argv[0]) > 2 && strstarts("contention", argv[0])) {
+ trace_handler = &contention_lock_ops;
+ if (argc) {
+ argc = parse_options(argc, argv, contention_options,
+ contention_usage, 0);
+ if (argc) {
+ usage_with_options(contention_usage,
+ contention_options);
+ }
+ }
+ rc = __cmd_contention();
} else {
usage_with_options(lock_usage, lock_options);
}
--
2.37.0.170.g444d1eabd0-goog
^ permalink raw reply related [flat|nested] 15+ messages in thread
* [PATCH 5/6] perf lock: Add -k and -F options to 'contention' subcommand
2022-07-21 4:36 [PATCHSET 0/6] perf lock: Add contention subcommand (v1) Namhyung Kim
` (3 preceding siblings ...)
2022-07-21 4:36 ` [PATCH 4/6] perf lock: Add 'contention' subcommand Namhyung Kim
@ 2022-07-21 4:36 ` Namhyung Kim
2022-07-21 4:36 ` [PATCH 6/6] perf lock: Support -t option for " Namhyung Kim
2022-08-03 9:51 ` [PATCHSET 0/6] perf lock: Add contention subcommand (v1) Ingo Molnar
6 siblings, 0 replies; 15+ messages in thread
From: Namhyung Kim @ 2022-07-21 4:36 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo, Jiri Olsa
Cc: Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers, linux-perf-users,
Will Deacon, Waiman Long, Boqun Feng, Davidlohr Bueso
Like perf lock report, add -k/--key and -F/--field options to control
output formatting and sorting. Note that it has slightly different
default options as some fields are not available and to optimize the
screen space.
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/Documentation/perf-lock.txt | 15 ++++++++
tools/perf/builtin-lock.c | 51 ++++++++++++++++++++------
2 files changed, 55 insertions(+), 11 deletions(-)
diff --git a/tools/perf/Documentation/perf-lock.txt b/tools/perf/Documentation/perf-lock.txt
index da0bcbc676a3..ae78e04346bd 100644
--- a/tools/perf/Documentation/perf-lock.txt
+++ b/tools/perf/Documentation/perf-lock.txt
@@ -105,6 +105,21 @@ INFO OPTIONS
--map::
dump map of lock instances (address:name table)
+CONTENTION OPTIONS
+--------------
+
+-k::
+--key=<value>::
+ Sorting key. Possible values: contended, wait_total (default),
+ wait_max, wait_min, avg_wait.
+
+-F::
+--field=<value>::
+ Output fields. By default it shows all but the wait_min fields
+ and users can customize that using this. Possible values:
+ contended, wait_total, wait_max, wait_min, avg_wait.
+
+
SEE ALSO
--------
linkperf:perf[1]
diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
index 64f635273660..ad3b191db2e7 100644
--- a/tools/perf/builtin-lock.c
+++ b/tools/perf/builtin-lock.c
@@ -362,7 +362,7 @@ static const char *output_fields;
#define DEF_KEY_LOCK(name, header, fn_suffix, len) \
{ #name, header, len, lock_stat_key_ ## fn_suffix, lock_stat_key_print_ ## fn_suffix, {} }
-struct lock_key keys[] = {
+static struct lock_key report_keys[] = {
DEF_KEY_LOCK(acquired, "acquired", nr_acquired, 10),
DEF_KEY_LOCK(contended, "contended", nr_contended, 10),
DEF_KEY_LOCK(avg_wait, "avg wait", avg_wait_time, 12),
@@ -374,9 +374,24 @@ struct lock_key keys[] = {
{ }
};
-static int select_key(void)
+static struct lock_key contention_keys[] = {
+ DEF_KEY_LOCK(contended, "contended", nr_contended, 10),
+ DEF_KEY_LOCK(wait_total, "total wait", wait_time_total, 12),
+ DEF_KEY_LOCK(wait_max, "max wait", wait_time_max, 12),
+ DEF_KEY_LOCK(wait_min, "min wait", wait_time_min, 12),
+ DEF_KEY_LOCK(avg_wait, "avg wait", avg_wait_time, 12),
+
+ /* extra comparisons much complicated should be here */
+ { }
+};
+
+static int select_key(bool contention)
{
int i;
+ struct lock_key *keys = report_keys;
+
+ if (contention)
+ keys = contention_keys;
for (i = 0; keys[i].name; i++) {
if (!strcmp(keys[i].name, sort_key)) {
@@ -394,9 +409,13 @@ static int select_key(void)
return -1;
}
-static int add_output_field(struct list_head *head, char *name)
+static int add_output_field(bool contention, char *name)
{
int i;
+ struct lock_key *keys = report_keys;
+
+ if (contention)
+ keys = contention_keys;
for (i = 0; keys[i].name; i++) {
if (strcmp(keys[i].name, name))
@@ -404,7 +423,7 @@ static int add_output_field(struct list_head *head, char *name)
/* prevent double link */
if (list_empty(&keys[i].list))
- list_add_tail(&keys[i].list, head);
+ list_add_tail(&keys[i].list, &lock_keys);
return 0;
}
@@ -413,10 +432,14 @@ static int add_output_field(struct list_head *head, char *name)
return -1;
}
-static int setup_output_field(const char *str)
+static int setup_output_field(bool contention, const char *str)
{
char *tok, *tmp, *orig;
int i, ret = 0;
+ struct lock_key *keys = report_keys;
+
+ if (contention)
+ keys = contention_keys;
/* no output field given: use all of them */
if (str == NULL) {
@@ -433,7 +456,7 @@ static int setup_output_field(const char *str)
return -ENOMEM;
while ((tok = strsep(&tmp, ",")) != NULL){
- ret = add_output_field(&lock_keys, tok);
+ ret = add_output_field(contention, tok);
if (ret < 0)
break;
}
@@ -1609,10 +1632,10 @@ static int __cmd_report(bool display_info)
goto out_delete;
}
- if (setup_output_field(output_fields))
+ if (setup_output_field(false, output_fields))
goto out_delete;
- if (select_key())
+ if (select_key(false))
goto out_delete;
if (show_thread_stats)
@@ -1674,11 +1697,10 @@ static int __cmd_contention(void)
goto out_delete;
}
- if (setup_output_field("contended,wait_total,wait_max,avg_wait"))
+ if (setup_output_field(true, output_fields))
goto out_delete;
- sort_key = "wait_total";
- if (select_key())
+ if (select_key(true))
goto out_delete;
aggr_mode = LOCK_AGGR_CALLER;
@@ -1817,6 +1839,10 @@ int cmd_lock(int argc, const char **argv)
};
const struct option contention_options[] = {
+ OPT_STRING('k', "key", &sort_key, "wait_total",
+ "key for sorting (contended / wait_total / wait_max / wait_min / avg_wait)"),
+ OPT_STRING('F', "field", &output_fields, "contended,wait_total,wait_max,avg_wait",
+ "output fields (contended / wait_total / wait_max / wait_min / avg_wait)"),
OPT_PARENT(lock_options)
};
@@ -1876,6 +1902,9 @@ int cmd_lock(int argc, const char **argv)
rc = __cmd_report(true);
} else if (strlen(argv[0]) > 2 && strstarts("contention", argv[0])) {
trace_handler = &contention_lock_ops;
+ sort_key = "wait_total";
+ output_fields = "contended,wait_total,wait_max,avg_wait";
+
if (argc) {
argc = parse_options(argc, argv, contention_options,
contention_usage, 0);
--
2.37.0.170.g444d1eabd0-goog
^ permalink raw reply related [flat|nested] 15+ messages in thread
* [PATCH 6/6] perf lock: Support -t option for 'contention' subcommand
2022-07-21 4:36 [PATCHSET 0/6] perf lock: Add contention subcommand (v1) Namhyung Kim
` (4 preceding siblings ...)
2022-07-21 4:36 ` [PATCH 5/6] perf lock: Add -k and -F options to " Namhyung Kim
@ 2022-07-21 4:36 ` Namhyung Kim
2022-08-03 9:51 ` [PATCHSET 0/6] perf lock: Add contention subcommand (v1) Ingo Molnar
6 siblings, 0 replies; 15+ messages in thread
From: Namhyung Kim @ 2022-07-21 4:36 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo, Jiri Olsa
Cc: Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers, linux-perf-users,
Will Deacon, Waiman Long, Boqun Feng, Davidlohr Bueso
Like perf lock report, it can report lock contention stat of each task.
$ perf lock contention -t
contended total wait max wait avg wait pid comm
5 945.20 us 902.08 us 189.04 us 316167 EventManager_De
33 98.17 us 6.78 us 2.97 us 766063 kworker/0:1-get
7 92.47 us 61.26 us 13.21 us 316170 EventManager_De
14 76.31 us 12.87 us 5.45 us 12949 timedcall
24 76.15 us 12.27 us 3.17 us 767992 sched-pipe
15 75.62 us 11.93 us 5.04 us 15127 switchto-defaul
24 71.84 us 5.59 us 2.99 us 629168 kworker/u513:2-
17 67.41 us 7.94 us 3.96 us 13504 coroner-
1 59.56 us 59.56 us 59.56 us 316165 EventManager_De
14 56.21 us 6.89 us 4.01 us 0 swapper
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/Documentation/perf-lock.txt | 4 ++++
tools/perf/builtin-lock.c | 22 ++++++++++++++++++++--
2 files changed, 24 insertions(+), 2 deletions(-)
diff --git a/tools/perf/Documentation/perf-lock.txt b/tools/perf/Documentation/perf-lock.txt
index ae78e04346bd..8f4e34f924d5 100644
--- a/tools/perf/Documentation/perf-lock.txt
+++ b/tools/perf/Documentation/perf-lock.txt
@@ -119,6 +119,10 @@ CONTENTION OPTIONS
and users can customize that using this. Possible values:
contended, wait_total, wait_max, wait_min, avg_wait.
+-t::
+--threads::
+ Show per-thread lock contention stat
+
SEE ALSO
--------
diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
index ad3b191db2e7..041801d8b6ac 100644
--- a/tools/perf/builtin-lock.c
+++ b/tools/perf/builtin-lock.c
@@ -1560,7 +1560,10 @@ static void print_contention_result(void)
list_for_each_entry(key, &lock_keys, list)
pr_info("%*s ", key->len, key->header);
- pr_info(" %10s %s\n\n", "type", "caller");
+ if (show_thread_stats)
+ pr_info(" %10s %s\n\n", "pid", "comm");
+ else
+ pr_info(" %10s %s\n\n", "type", "caller");
bad = total = 0;
while ((st = pop_from_result())) {
@@ -1573,6 +1576,16 @@ static void print_contention_result(void)
pr_info(" ");
}
+ if (show_thread_stats) {
+ struct thread *t;
+ int pid = st->addr;
+
+ /* st->addr contains tid of thread */
+ t = perf_session__findnew(session, pid);
+ pr_info(" %10d %s\n", pid, thread__comm_str(t));
+ continue;
+ }
+
pr_info(" %10s %s\n", get_type_str(st), st->name);
}
@@ -1703,7 +1716,10 @@ static int __cmd_contention(void)
if (select_key(true))
goto out_delete;
- aggr_mode = LOCK_AGGR_CALLER;
+ if (show_thread_stats)
+ aggr_mode = LOCK_AGGR_TASK;
+ else
+ aggr_mode = LOCK_AGGR_CALLER;
err = perf_session__process_events(session);
if (err)
@@ -1843,6 +1859,8 @@ int cmd_lock(int argc, const char **argv)
"key for sorting (contended / wait_total / wait_max / wait_min / avg_wait)"),
OPT_STRING('F', "field", &output_fields, "contended,wait_total,wait_max,avg_wait",
"output fields (contended / wait_total / wait_max / wait_min / avg_wait)"),
+ OPT_BOOLEAN('t', "threads", &show_thread_stats,
+ "show per-thread lock stats"),
OPT_PARENT(lock_options)
};
--
2.37.0.170.g444d1eabd0-goog
^ permalink raw reply related [flat|nested] 15+ messages in thread
* Re: [PATCH 3/6] perf lock: Add lock aggregation enum
2022-07-21 4:36 ` [PATCH 3/6] perf lock: Add lock aggregation enum Namhyung Kim
@ 2022-07-21 19:02 ` Arnaldo Carvalho de Melo
2022-07-21 19:05 ` Arnaldo Carvalho de Melo
0 siblings, 1 reply; 15+ messages in thread
From: Arnaldo Carvalho de Melo @ 2022-07-21 19:02 UTC (permalink / raw)
To: Namhyung Kim
Cc: Jiri Olsa, Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers,
linux-perf-users, Will Deacon, Waiman Long, Boqun Feng,
Davidlohr Bueso
Em Wed, Jul 20, 2022 at 09:36:41PM -0700, Namhyung Kim escreveu:
> Introduce the aggr_mode variable to prepare the later code change.
> The default is LOCK_AGGR_ADDR which aggregate the result for the lock
> instances. When -t/--threads option is given, it'd be set to
> LOCK_AGGR_TASK. The LOCK_AGGR_CALLER is for the contention analysis
> and it'd aggregate the stat by comparing the callstacks.
builtin-lock.c: In function ‘report_lock_contention_end_event’:
builtin-lock.c:1113:13: error: variable ‘key’ set but not used [-Werror=unused-but-set-variable]
1113 | u64 key;
| ^~~
cc1: all warnings being treated as errors
trying to fix
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> ---
> tools/perf/builtin-lock.c | 112 +++++++++++++++++++++++++++++++-------
> 1 file changed, 93 insertions(+), 19 deletions(-)
>
> diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
> index 1de459198b99..551bad905139 100644
> --- a/tools/perf/builtin-lock.c
> +++ b/tools/perf/builtin-lock.c
> @@ -126,6 +126,12 @@ static struct rb_root thread_stats;
> static bool combine_locks;
> static bool show_thread_stats;
>
> +static enum {
> + LOCK_AGGR_ADDR,
> + LOCK_AGGR_TASK,
> + LOCK_AGGR_CALLER,
> +} aggr_mode = LOCK_AGGR_ADDR;
> +
> /*
> * CONTENTION_STACK_DEPTH
> * Number of stack trace entries to find callers
> @@ -622,12 +628,22 @@ static int report_lock_acquire_event(struct evsel *evsel,
> const char *name = evsel__strval(evsel, sample, "name");
> u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
> int flag = evsel__intval(evsel, sample, "flags");
> + u64 key;
>
> - /* abuse ls->addr for tid */
> - if (show_thread_stats)
> - addr = sample->tid;
> + switch (aggr_mode) {
> + case LOCK_AGGR_ADDR:
> + key = addr;
> + break;
> + case LOCK_AGGR_TASK:
> + key = sample->tid;
> + break;
> + case LOCK_AGGR_CALLER:
> + default:
> + pr_err("Invalid aggregation mode: %d\n", aggr_mode);
> + return -EINVAL;
> + }
>
> - ls = lock_stat_findnew(addr, name, 0);
> + ls = lock_stat_findnew(key, name, 0);
> if (!ls)
> return -ENOMEM;
>
> @@ -695,11 +711,22 @@ static int report_lock_acquired_event(struct evsel *evsel,
> u64 contended_term;
> const char *name = evsel__strval(evsel, sample, "name");
> u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
> + u64 key;
>
> - if (show_thread_stats)
> - addr = sample->tid;
> + switch (aggr_mode) {
> + case LOCK_AGGR_ADDR:
> + key = addr;
> + break;
> + case LOCK_AGGR_TASK:
> + key = sample->tid;
> + break;
> + case LOCK_AGGR_CALLER:
> + default:
> + pr_err("Invalid aggregation mode: %d\n", aggr_mode);
> + return -EINVAL;
> + }
>
> - ls = lock_stat_findnew(addr, name, 0);
> + ls = lock_stat_findnew(key, name, 0);
> if (!ls)
> return -ENOMEM;
>
> @@ -757,11 +784,22 @@ static int report_lock_contended_event(struct evsel *evsel,
> struct lock_seq_stat *seq;
> const char *name = evsel__strval(evsel, sample, "name");
> u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
> + u64 key;
>
> - if (show_thread_stats)
> - addr = sample->tid;
> + switch (aggr_mode) {
> + case LOCK_AGGR_ADDR:
> + key = addr;
> + break;
> + case LOCK_AGGR_TASK:
> + key = sample->tid;
> + break;
> + case LOCK_AGGR_CALLER:
> + default:
> + pr_err("Invalid aggregation mode: %d\n", aggr_mode);
> + return -EINVAL;
> + }
>
> - ls = lock_stat_findnew(addr, name, 0);
> + ls = lock_stat_findnew(key, name, 0);
> if (!ls)
> return -ENOMEM;
>
> @@ -812,11 +850,22 @@ static int report_lock_release_event(struct evsel *evsel,
> struct lock_seq_stat *seq;
> const char *name = evsel__strval(evsel, sample, "name");
> u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
> + u64 key;
>
> - if (show_thread_stats)
> - addr = sample->tid;
> + switch (aggr_mode) {
> + case LOCK_AGGR_ADDR:
> + key = addr;
> + break;
> + case LOCK_AGGR_TASK:
> + key = sample->tid;
> + break;
> + case LOCK_AGGR_CALLER:
> + default:
> + pr_err("Invalid aggregation mode: %d\n", aggr_mode);
> + return -EINVAL;
> + }
>
> - ls = lock_stat_findnew(addr, name, 0);
> + ls = lock_stat_findnew(key, name, 0);
> if (!ls)
> return -ENOMEM;
>
> @@ -980,11 +1029,22 @@ static int report_lock_contention_begin_event(struct evsel *evsel,
> struct thread_stat *ts;
> struct lock_seq_stat *seq;
> u64 addr = evsel__intval(evsel, sample, "lock_addr");
> + u64 key;
>
> - if (show_thread_stats)
> - addr = sample->tid;
> + switch (aggr_mode) {
> + case LOCK_AGGR_ADDR:
> + key = addr;
> + break;
> + case LOCK_AGGR_TASK:
> + key = sample->tid;
> + break;
> + case LOCK_AGGR_CALLER:
> + default:
> + pr_err("Invalid aggregation mode: %d\n", aggr_mode);
> + return -EINVAL;
> + }
>
> - ls = lock_stat_find(addr);
> + ls = lock_stat_find(key);
> if (!ls) {
> char buf[128];
> const char *caller = buf;
> @@ -993,7 +1053,7 @@ static int report_lock_contention_begin_event(struct evsel *evsel,
> if (lock_contention_caller(evsel, sample, buf, sizeof(buf)) < 0)
> caller = "Unknown";
>
> - ls = lock_stat_findnew(addr, caller, flags);
> + ls = lock_stat_findnew(key, caller, flags);
> if (!ls)
> return -ENOMEM;
> }
> @@ -1050,9 +1110,20 @@ static int report_lock_contention_end_event(struct evsel *evsel,
> struct lock_seq_stat *seq;
> u64 contended_term;
> u64 addr = evsel__intval(evsel, sample, "lock_addr");
> + u64 key;
>
> - if (show_thread_stats)
> - addr = sample->tid;
> + switch (aggr_mode) {
> + case LOCK_AGGR_ADDR:
> + key = addr;
> + break;
> + case LOCK_AGGR_TASK:
> + key = sample->tid;
> + break;
> + case LOCK_AGGR_CALLER:
> + default:
> + pr_err("Invalid aggregation mode: %d\n", aggr_mode);
> + return -EINVAL;
> + }
>
> ls = lock_stat_find(addr);
> if (!ls)
> @@ -1416,6 +1487,9 @@ static int __cmd_report(bool display_info)
> if (select_key())
> goto out_delete;
>
> + if (show_thread_stats)
> + aggr_mode = LOCK_AGGR_TASK;
> +
> err = perf_session__process_events(session);
> if (err)
> goto out_delete;
> --
> 2.37.0.170.g444d1eabd0-goog
--
- Arnaldo
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [PATCH 3/6] perf lock: Add lock aggregation enum
2022-07-21 19:02 ` Arnaldo Carvalho de Melo
@ 2022-07-21 19:05 ` Arnaldo Carvalho de Melo
2022-07-25 16:56 ` Namhyung Kim
0 siblings, 1 reply; 15+ messages in thread
From: Arnaldo Carvalho de Melo @ 2022-07-21 19:05 UTC (permalink / raw)
To: Namhyung Kim
Cc: Jiri Olsa, Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers,
linux-perf-users, Will Deacon, Waiman Long, Boqun Feng,
Davidlohr Bueso
Em Thu, Jul 21, 2022 at 04:02:58PM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Wed, Jul 20, 2022 at 09:36:41PM -0700, Namhyung Kim escreveu:
> > Introduce the aggr_mode variable to prepare the later code change.
> > The default is LOCK_AGGR_ADDR which aggregate the result for the lock
> > instances. When -t/--threads option is given, it'd be set to
> > LOCK_AGGR_TASK. The LOCK_AGGR_CALLER is for the contention analysis
> > and it'd aggregate the stat by comparing the callstacks.
>
> builtin-lock.c: In function ‘report_lock_contention_end_event’:
> builtin-lock.c:1113:13: error: variable ‘key’ set but not used [-Werror=unused-but-set-variable]
> 1113 | u64 key;
> | ^~~
> cc1: all warnings being treated as errors
>
>
> trying to fix
Please take a look at this:
builtin-lock.c: In function ‘report_lock_contention_end_event’:
builtin-lock.c:1113:13: error: variable ‘key’ set but not used [-Werror=unused-but-set-variable]
1113 | u64 key;
| ^~~
cc1: all warnings being treated as errors
make[3]: *** [/var/home/acme/git/perf/tools/build/Makefile.build:96: /tmp/build/perf/builtin-lock.o] Error 1
make[2]: *** [Makefile.perf:660: /tmp/build/perf/perf-in.o] Error 2
make[1]: *** [Makefile.perf:240: sub-make] Error 2
make: *** [Makefile:113: install-bin] Error 2
make: Leaving directory '/var/home/acme/git/perf/tools/perf'
Performance counter stats for 'make -k BUILD_BPF_SKEL=1 CORESIGHT=1 PYTHON=python3 O=/tmp/build/perf -C tools/perf install-bin':
6,642,782,729 cycles:u
12,246,940,928 instructions:u # 1.84 insn per cycle
2.513486078 seconds time elapsed
1.649124000 seconds user
1.272055000 seconds sys
⬢[acme@toolbox perf]$ gcc -v
Using built-in specs.
COLLECT_GCC=/usr/bin/gcc
COLLECT_LTO_WRAPPER=/usr/libexec/gcc/x86_64-redhat-linux/12/lto-wrapper
OFFLOAD_TARGET_NAMES=nvptx-none
OFFLOAD_TARGET_DEFAULT=1
Target: x86_64-redhat-linux
Configured with: ../configure --enable-bootstrap --enable-languages=c,c++,fortran,objc,obj-c++,ada,go,d,lto --prefix=/usr --mandir=/usr/share/man --infodir=/usr/share/info --with-bugurl=http://bugzilla.redhat.com/bugzilla --enable-shared --enable-threads=posix --enable-checking=release --enable-multilib --with-system-zlib --enable-__cxa_atexit --disable-libunwind-exceptions --enable-gnu-unique-object --enable-linker-build-id --with-gcc-major-version-only --enable-libstdcxx-backtrace --with-linker-hash-style=gnu --enable-plugin --enable-initfini-array --with-isl=/builddir/build/BUILD/gcc-12.1.1-20220507/obj-x86_64-redhat-linux/isl-install --enable-offload-targets=nvptx-none --without-cuda-driver --enable-offload-defaulted --enable-gnu-indirect-function --enable-cet --with-tune=generic --with-arch_32=i686 --build=x86_64-redhat-linux --with-build-config=bootstrap-lto --enable-link-serialization=1
Thread model: posix
Supported LTO compression algorithms: zlib zstd
gcc version 12.1.1 20220507 (Red Hat 12.1.1-1) (GCC)
⬢[acme@toolbox perf]$ cat /etc/fedora-release
Fedora release 36 (Thirty Six)
⬢[acme@toolbox perf]$
> > Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> > ---
> > tools/perf/builtin-lock.c | 112 +++++++++++++++++++++++++++++++-------
> > 1 file changed, 93 insertions(+), 19 deletions(-)
> >
> > diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
> > index 1de459198b99..551bad905139 100644
> > --- a/tools/perf/builtin-lock.c
> > +++ b/tools/perf/builtin-lock.c
> > @@ -126,6 +126,12 @@ static struct rb_root thread_stats;
> > static bool combine_locks;
> > static bool show_thread_stats;
> >
> > +static enum {
> > + LOCK_AGGR_ADDR,
> > + LOCK_AGGR_TASK,
> > + LOCK_AGGR_CALLER,
> > +} aggr_mode = LOCK_AGGR_ADDR;
> > +
> > /*
> > * CONTENTION_STACK_DEPTH
> > * Number of stack trace entries to find callers
> > @@ -622,12 +628,22 @@ static int report_lock_acquire_event(struct evsel *evsel,
> > const char *name = evsel__strval(evsel, sample, "name");
> > u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
> > int flag = evsel__intval(evsel, sample, "flags");
> > + u64 key;
> >
> > - /* abuse ls->addr for tid */
> > - if (show_thread_stats)
> > - addr = sample->tid;
> > + switch (aggr_mode) {
> > + case LOCK_AGGR_ADDR:
> > + key = addr;
> > + break;
> > + case LOCK_AGGR_TASK:
> > + key = sample->tid;
> > + break;
> > + case LOCK_AGGR_CALLER:
> > + default:
> > + pr_err("Invalid aggregation mode: %d\n", aggr_mode);
> > + return -EINVAL;
> > + }
> >
> > - ls = lock_stat_findnew(addr, name, 0);
> > + ls = lock_stat_findnew(key, name, 0);
> > if (!ls)
> > return -ENOMEM;
> >
> > @@ -695,11 +711,22 @@ static int report_lock_acquired_event(struct evsel *evsel,
> > u64 contended_term;
> > const char *name = evsel__strval(evsel, sample, "name");
> > u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
> > + u64 key;
> >
> > - if (show_thread_stats)
> > - addr = sample->tid;
> > + switch (aggr_mode) {
> > + case LOCK_AGGR_ADDR:
> > + key = addr;
> > + break;
> > + case LOCK_AGGR_TASK:
> > + key = sample->tid;
> > + break;
> > + case LOCK_AGGR_CALLER:
> > + default:
> > + pr_err("Invalid aggregation mode: %d\n", aggr_mode);
> > + return -EINVAL;
> > + }
> >
> > - ls = lock_stat_findnew(addr, name, 0);
> > + ls = lock_stat_findnew(key, name, 0);
> > if (!ls)
> > return -ENOMEM;
> >
> > @@ -757,11 +784,22 @@ static int report_lock_contended_event(struct evsel *evsel,
> > struct lock_seq_stat *seq;
> > const char *name = evsel__strval(evsel, sample, "name");
> > u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
> > + u64 key;
> >
> > - if (show_thread_stats)
> > - addr = sample->tid;
> > + switch (aggr_mode) {
> > + case LOCK_AGGR_ADDR:
> > + key = addr;
> > + break;
> > + case LOCK_AGGR_TASK:
> > + key = sample->tid;
> > + break;
> > + case LOCK_AGGR_CALLER:
> > + default:
> > + pr_err("Invalid aggregation mode: %d\n", aggr_mode);
> > + return -EINVAL;
> > + }
> >
> > - ls = lock_stat_findnew(addr, name, 0);
> > + ls = lock_stat_findnew(key, name, 0);
> > if (!ls)
> > return -ENOMEM;
> >
> > @@ -812,11 +850,22 @@ static int report_lock_release_event(struct evsel *evsel,
> > struct lock_seq_stat *seq;
> > const char *name = evsel__strval(evsel, sample, "name");
> > u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
> > + u64 key;
> >
> > - if (show_thread_stats)
> > - addr = sample->tid;
> > + switch (aggr_mode) {
> > + case LOCK_AGGR_ADDR:
> > + key = addr;
> > + break;
> > + case LOCK_AGGR_TASK:
> > + key = sample->tid;
> > + break;
> > + case LOCK_AGGR_CALLER:
> > + default:
> > + pr_err("Invalid aggregation mode: %d\n", aggr_mode);
> > + return -EINVAL;
> > + }
> >
> > - ls = lock_stat_findnew(addr, name, 0);
> > + ls = lock_stat_findnew(key, name, 0);
> > if (!ls)
> > return -ENOMEM;
> >
> > @@ -980,11 +1029,22 @@ static int report_lock_contention_begin_event(struct evsel *evsel,
> > struct thread_stat *ts;
> > struct lock_seq_stat *seq;
> > u64 addr = evsel__intval(evsel, sample, "lock_addr");
> > + u64 key;
> >
> > - if (show_thread_stats)
> > - addr = sample->tid;
> > + switch (aggr_mode) {
> > + case LOCK_AGGR_ADDR:
> > + key = addr;
> > + break;
> > + case LOCK_AGGR_TASK:
> > + key = sample->tid;
> > + break;
> > + case LOCK_AGGR_CALLER:
> > + default:
> > + pr_err("Invalid aggregation mode: %d\n", aggr_mode);
> > + return -EINVAL;
> > + }
> >
> > - ls = lock_stat_find(addr);
> > + ls = lock_stat_find(key);
> > if (!ls) {
> > char buf[128];
> > const char *caller = buf;
> > @@ -993,7 +1053,7 @@ static int report_lock_contention_begin_event(struct evsel *evsel,
> > if (lock_contention_caller(evsel, sample, buf, sizeof(buf)) < 0)
> > caller = "Unknown";
> >
> > - ls = lock_stat_findnew(addr, caller, flags);
> > + ls = lock_stat_findnew(key, caller, flags);
> > if (!ls)
> > return -ENOMEM;
> > }
> > @@ -1050,9 +1110,20 @@ static int report_lock_contention_end_event(struct evsel *evsel,
> > struct lock_seq_stat *seq;
> > u64 contended_term;
> > u64 addr = evsel__intval(evsel, sample, "lock_addr");
> > + u64 key;
> >
> > - if (show_thread_stats)
> > - addr = sample->tid;
> > + switch (aggr_mode) {
> > + case LOCK_AGGR_ADDR:
> > + key = addr;
> > + break;
> > + case LOCK_AGGR_TASK:
> > + key = sample->tid;
> > + break;
> > + case LOCK_AGGR_CALLER:
> > + default:
> > + pr_err("Invalid aggregation mode: %d\n", aggr_mode);
> > + return -EINVAL;
> > + }
> >
> > ls = lock_stat_find(addr);
> > if (!ls)
> > @@ -1416,6 +1487,9 @@ static int __cmd_report(bool display_info)
> > if (select_key())
> > goto out_delete;
> >
> > + if (show_thread_stats)
> > + aggr_mode = LOCK_AGGR_TASK;
> > +
> > err = perf_session__process_events(session);
> > if (err)
> > goto out_delete;
> > --
> > 2.37.0.170.g444d1eabd0-goog
>
> --
>
> - Arnaldo
--
- Arnaldo
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [PATCH 1/6] perf lock: Fix a copy-n-paste bug
2022-07-21 4:36 ` [PATCH 1/6] perf lock: Fix a copy-n-paste bug Namhyung Kim
@ 2022-07-21 19:09 ` Arnaldo Carvalho de Melo
0 siblings, 0 replies; 15+ messages in thread
From: Arnaldo Carvalho de Melo @ 2022-07-21 19:09 UTC (permalink / raw)
To: Namhyung Kim
Cc: Jiri Olsa, Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers,
linux-perf-users, Will Deacon, Waiman Long, Boqun Feng,
Davidlohr Bueso
Em Wed, Jul 20, 2022 at 09:36:39PM -0700, Namhyung Kim escreveu:
> It should be lock_text_end instead of _start.
>
> Fixes: 0d2997f750d1 ("perf lock: Look up callchain for the contended locks")
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Got this first one procesed, pushed out toa acme/perf/core, please take
a look at the other patches.
- Arnaldo
> ---
> tools/perf/builtin-lock.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
> index c5ca34741561..0aae88fdf93a 100644
> --- a/tools/perf/builtin-lock.c
> +++ b/tools/perf/builtin-lock.c
> @@ -892,7 +892,7 @@ static bool is_lock_function(u64 addr)
> sym = machine__find_kernel_symbol_by_name(machine,
> "__lock_text_end",
> &kmap);
> - lock_text_start = kmap->unmap_ip(kmap, sym->start);
> + lock_text_end = kmap->unmap_ip(kmap, sym->start);
> }
>
> /* failed to get kernel symbols */
> --
> 2.37.0.170.g444d1eabd0-goog
--
- Arnaldo
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [PATCH 3/6] perf lock: Add lock aggregation enum
2022-07-21 19:05 ` Arnaldo Carvalho de Melo
@ 2022-07-25 16:56 ` Namhyung Kim
0 siblings, 0 replies; 15+ messages in thread
From: Namhyung Kim @ 2022-07-25 16:56 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Jiri Olsa, Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers,
linux-perf-users, Will Deacon, Waiman Long, Boqun Feng,
Davidlohr Bueso
Hi Arnaldo,
On Thu, Jul 21, 2022 at 12:05 PM Arnaldo Carvalho de Melo
<acme@kernel.org> wrote:
>
> Em Thu, Jul 21, 2022 at 04:02:58PM -0300, Arnaldo Carvalho de Melo escreveu:
> > Em Wed, Jul 20, 2022 at 09:36:41PM -0700, Namhyung Kim escreveu:
> > > Introduce the aggr_mode variable to prepare the later code change.
> > > The default is LOCK_AGGR_ADDR which aggregate the result for the lock
> > > instances. When -t/--threads option is given, it'd be set to
> > > LOCK_AGGR_TASK. The LOCK_AGGR_CALLER is for the contention analysis
> > > and it'd aggregate the stat by comparing the callstacks.
> >
> > builtin-lock.c: In function ‘report_lock_contention_end_event’:
> > builtin-lock.c:1113:13: error: variable ‘key’ set but not used [-Werror=unused-but-set-variable]
> > 1113 | u64 key;
> > | ^~~
> > cc1: all warnings being treated as errors
> >
> >
> > trying to fix
>
> Please take a look at this:
>
> builtin-lock.c: In function ‘report_lock_contention_end_event’:
> builtin-lock.c:1113:13: error: variable ‘key’ set but not used [-Werror=unused-but-set-variable]
> 1113 | u64 key;
> | ^~~
> cc1: all warnings being treated as errors
Ooops, sorry. Will fix!
Thanks,
Namhyung
> make[3]: *** [/var/home/acme/git/perf/tools/build/Makefile.build:96: /tmp/build/perf/builtin-lock.o] Error 1
> make[2]: *** [Makefile.perf:660: /tmp/build/perf/perf-in.o] Error 2
> make[1]: *** [Makefile.perf:240: sub-make] Error 2
> make: *** [Makefile:113: install-bin] Error 2
> make: Leaving directory '/var/home/acme/git/perf/tools/perf'
>
> Performance counter stats for 'make -k BUILD_BPF_SKEL=1 CORESIGHT=1 PYTHON=python3 O=/tmp/build/perf -C tools/perf install-bin':
>
> 6,642,782,729 cycles:u
> 12,246,940,928 instructions:u # 1.84 insn per cycle
>
> 2.513486078 seconds time elapsed
>
> 1.649124000 seconds user
> 1.272055000 seconds sys
>
>
> ⬢[acme@toolbox perf]$ gcc -v
> Using built-in specs.
> COLLECT_GCC=/usr/bin/gcc
> COLLECT_LTO_WRAPPER=/usr/libexec/gcc/x86_64-redhat-linux/12/lto-wrapper
> OFFLOAD_TARGET_NAMES=nvptx-none
> OFFLOAD_TARGET_DEFAULT=1
> Target: x86_64-redhat-linux
> Configured with: ../configure --enable-bootstrap --enable-languages=c,c++,fortran,objc,obj-c++,ada,go,d,lto --prefix=/usr --mandir=/usr/share/man --infodir=/usr/share/info --with-bugurl=http://bugzilla.redhat.com/bugzilla --enable-shared --enable-threads=posix --enable-checking=release --enable-multilib --with-system-zlib --enable-__cxa_atexit --disable-libunwind-exceptions --enable-gnu-unique-object --enable-linker-build-id --with-gcc-major-version-only --enable-libstdcxx-backtrace --with-linker-hash-style=gnu --enable-plugin --enable-initfini-array --with-isl=/builddir/build/BUILD/gcc-12.1.1-20220507/obj-x86_64-redhat-linux/isl-install --enable-offload-targets=nvptx-none --without-cuda-driver --enable-offload-defaulted --enable-gnu-indirect-function --enable-cet --with-tune=generic --with-arch_32=i686 --build=x86_64-redhat-linux --with-build-config=bootstrap-lto --enable-link-serialization=1
> Thread model: posix
> Supported LTO compression algorithms: zlib zstd
> gcc version 12.1.1 20220507 (Red Hat 12.1.1-1) (GCC)
> ⬢[acme@toolbox perf]$ cat /etc/fedora-release
> Fedora release 36 (Thirty Six)
> ⬢[acme@toolbox perf]$
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [PATCHSET 0/6] perf lock: Add contention subcommand (v1)
2022-07-21 4:36 [PATCHSET 0/6] perf lock: Add contention subcommand (v1) Namhyung Kim
` (5 preceding siblings ...)
2022-07-21 4:36 ` [PATCH 6/6] perf lock: Support -t option for " Namhyung Kim
@ 2022-08-03 9:51 ` Ingo Molnar
2022-08-04 4:55 ` Namhyung Kim
6 siblings, 1 reply; 15+ messages in thread
From: Ingo Molnar @ 2022-08-03 9:51 UTC (permalink / raw)
To: Namhyung Kim
Cc: Arnaldo Carvalho de Melo, Jiri Olsa, Peter Zijlstra, LKML,
Ian Rogers, linux-perf-users, Will Deacon, Waiman Long,
Boqun Feng, Davidlohr Bueso
* Namhyung Kim <namhyung@kernel.org> wrote:
> Hello,
>
> It's to add a new subcommand 'contention' (shortly 'con') to perf lock.
>
> The new subcommand is to handle the new lock:contention_{begin,end}
> tracepoints and shows lock type and caller address like below:
>
> $ perf lock contention
> contended total wait max wait avg wait type caller
>
> 238 1.41 ms 29.20 us 5.94 us spinlock update_blocked_averages+0x4c
> 1 902.08 us 902.08 us 902.08 us rwsem:R do_user_addr_fault+0x1dd
> 81 330.30 us 17.24 us 4.08 us spinlock _nohz_idle_balance+0x172
> 2 89.54 us 61.26 us 44.77 us spinlock do_anonymous_page+0x16d
> 24 78.36 us 12.27 us 3.27 us mutex pipe_read+0x56
> 2 71.58 us 59.56 us 35.79 us spinlock __handle_mm_fault+0x6aa
> 6 25.68 us 6.89 us 4.28 us spinlock do_idle+0x28d
> 1 18.46 us 18.46 us 18.46 us rtmutex exec_fw_cmd+0x21b
> 3 15.25 us 6.26 us 5.08 us spinlock tick_do_update_jiffies64+0x2c
> ...
Wouldn't it also be useful to display a lock contention percentage value,
the ratio of fastpath vs. contended/wait events?
That's usually the first-approximation metric to see how contended
different locks are, and the average wait time quantifies it.
Thanks,
Ingo
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [PATCHSET 0/6] perf lock: Add contention subcommand (v1)
2022-08-03 9:51 ` [PATCHSET 0/6] perf lock: Add contention subcommand (v1) Ingo Molnar
@ 2022-08-04 4:55 ` Namhyung Kim
2022-08-04 8:37 ` Ingo Molnar
0 siblings, 1 reply; 15+ messages in thread
From: Namhyung Kim @ 2022-08-04 4:55 UTC (permalink / raw)
To: Ingo Molnar
Cc: Arnaldo Carvalho de Melo, Jiri Olsa, Peter Zijlstra, LKML,
Ian Rogers, linux-perf-users, Will Deacon, Waiman Long,
Boqun Feng, Davidlohr Bueso
Hi Ingo,
On Wed, Aug 3, 2022 at 2:51 AM Ingo Molnar <mingo@kernel.org> wrote:
>
>
> * Namhyung Kim <namhyung@kernel.org> wrote:
>
> > Hello,
> >
> > It's to add a new subcommand 'contention' (shortly 'con') to perf lock.
> >
> > The new subcommand is to handle the new lock:contention_{begin,end}
> > tracepoints and shows lock type and caller address like below:
> >
> > $ perf lock contention
> > contended total wait max wait avg wait type caller
> >
> > 238 1.41 ms 29.20 us 5.94 us spinlock update_blocked_averages+0x4c
> > 1 902.08 us 902.08 us 902.08 us rwsem:R do_user_addr_fault+0x1dd
> > 81 330.30 us 17.24 us 4.08 us spinlock _nohz_idle_balance+0x172
> > 2 89.54 us 61.26 us 44.77 us spinlock do_anonymous_page+0x16d
> > 24 78.36 us 12.27 us 3.27 us mutex pipe_read+0x56
> > 2 71.58 us 59.56 us 35.79 us spinlock __handle_mm_fault+0x6aa
> > 6 25.68 us 6.89 us 4.28 us spinlock do_idle+0x28d
> > 1 18.46 us 18.46 us 18.46 us rtmutex exec_fw_cmd+0x21b
> > 3 15.25 us 6.26 us 5.08 us spinlock tick_do_update_jiffies64+0x2c
> > ...
>
> Wouldn't it also be useful to display a lock contention percentage value,
> the ratio of fastpath vs. contended/wait events?
>
> That's usually the first-approximation metric to see how contended
> different locks are, and the average wait time quantifies it.
Yeah, that'd be nice to have. But it requires some action in the fast path
which I don't want because I'd like to use this in production. So these
new tracepoints were added only in the slow path.
Instead, I think we can display the ratio of (total) contended time vs.
wall clock time. What do you think?
Thanks,
Namhyung
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [PATCHSET 0/6] perf lock: Add contention subcommand (v1)
2022-08-04 4:55 ` Namhyung Kim
@ 2022-08-04 8:37 ` Ingo Molnar
2022-08-04 21:02 ` Namhyung Kim
0 siblings, 1 reply; 15+ messages in thread
From: Ingo Molnar @ 2022-08-04 8:37 UTC (permalink / raw)
To: Namhyung Kim
Cc: Arnaldo Carvalho de Melo, Jiri Olsa, Peter Zijlstra, LKML,
Ian Rogers, linux-perf-users, Will Deacon, Waiman Long,
Boqun Feng, Davidlohr Bueso
* Namhyung Kim <namhyung@kernel.org> wrote:
> Hi Ingo,
>
> On Wed, Aug 3, 2022 at 2:51 AM Ingo Molnar <mingo@kernel.org> wrote:
> >
> >
> > * Namhyung Kim <namhyung@kernel.org> wrote:
> >
> > > Hello,
> > >
> > > It's to add a new subcommand 'contention' (shortly 'con') to perf lock.
> > >
> > > The new subcommand is to handle the new lock:contention_{begin,end}
> > > tracepoints and shows lock type and caller address like below:
> > >
> > > $ perf lock contention
> > > contended total wait max wait avg wait type caller
> > >
> > > 238 1.41 ms 29.20 us 5.94 us spinlock update_blocked_averages+0x4c
> > > 1 902.08 us 902.08 us 902.08 us rwsem:R do_user_addr_fault+0x1dd
> > > 81 330.30 us 17.24 us 4.08 us spinlock _nohz_idle_balance+0x172
> > > 2 89.54 us 61.26 us 44.77 us spinlock do_anonymous_page+0x16d
> > > 24 78.36 us 12.27 us 3.27 us mutex pipe_read+0x56
> > > 2 71.58 us 59.56 us 35.79 us spinlock __handle_mm_fault+0x6aa
> > > 6 25.68 us 6.89 us 4.28 us spinlock do_idle+0x28d
> > > 1 18.46 us 18.46 us 18.46 us rtmutex exec_fw_cmd+0x21b
> > > 3 15.25 us 6.26 us 5.08 us spinlock tick_do_update_jiffies64+0x2c
> > > ...
> >
> > Wouldn't it also be useful to display a lock contention percentage value,
> > the ratio of fastpath vs. contended/wait events?
> >
> > That's usually the first-approximation metric to see how contended
> > different locks are, and the average wait time quantifies it.
>
> Yeah, that'd be nice to have. But it requires some action in the fast
> path which I don't want because I'd like to use this in production. So
> these new tracepoints were added only in the slow path.
Yeah. Might make sense to re-measure the impact of possibly doing that
though: most of the locking fast-patch is out of line already and could be
instrumented, with only a handful of inlined primitives -
CONFIG_UNINLINE_SPIN_UNLOCK in particular.
How many additional inlined NOP sequences does this add in a defconfig
kernel? How much is the bloat, and would it be acceptable for production
kernels?
The other question is to keep tracing overhead low in production systems.
For that we'd have to implement some concept of 'sampling tracepoints',
which generate only one event for every 128 fast path invocations or so,
but stay out of the way & don't slow down the system otherwise.
OTOH frequently used locking fastpaths are measured via regular PMU
sampling based profiling already.
> Instead, I think we can display the ratio of (total) contended time vs.
> wall clock time. What do you think?
That looks useful too - but also the time spent waiting/spinning in a
thread vs. the time spent actually running and executing real stuff.
That ratio could easily get over 100%, for wait-dominated workloads - so
ordering by that ratio would highlight the tasks that make the least amount
of real progress. Measuring the ratio based only on wall clock time would
hide this aspect.
Thanks,
Ingo
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [PATCHSET 0/6] perf lock: Add contention subcommand (v1)
2022-08-04 8:37 ` Ingo Molnar
@ 2022-08-04 21:02 ` Namhyung Kim
0 siblings, 0 replies; 15+ messages in thread
From: Namhyung Kim @ 2022-08-04 21:02 UTC (permalink / raw)
To: Ingo Molnar
Cc: Arnaldo Carvalho de Melo, Jiri Olsa, Peter Zijlstra, LKML,
Ian Rogers, linux-perf-users, Will Deacon, Waiman Long,
Boqun Feng, Davidlohr Bueso
On Thu, Aug 4, 2022 at 1:37 AM Ingo Molnar <mingo@kernel.org> wrote:
>
>
> * Namhyung Kim <namhyung@kernel.org> wrote:
>
> > Hi Ingo,
> >
> > On Wed, Aug 3, 2022 at 2:51 AM Ingo Molnar <mingo@kernel.org> wrote:
> > >
> > >
> > > * Namhyung Kim <namhyung@kernel.org> wrote:
> > >
> > > > Hello,
> > > >
> > > > It's to add a new subcommand 'contention' (shortly 'con') to perf lock.
> > > >
> > > > The new subcommand is to handle the new lock:contention_{begin,end}
> > > > tracepoints and shows lock type and caller address like below:
> > > >
> > > > $ perf lock contention
> > > > contended total wait max wait avg wait type caller
> > > >
> > > > 238 1.41 ms 29.20 us 5.94 us spinlock update_blocked_averages+0x4c
> > > > 1 902.08 us 902.08 us 902.08 us rwsem:R do_user_addr_fault+0x1dd
> > > > 81 330.30 us 17.24 us 4.08 us spinlock _nohz_idle_balance+0x172
> > > > 2 89.54 us 61.26 us 44.77 us spinlock do_anonymous_page+0x16d
> > > > 24 78.36 us 12.27 us 3.27 us mutex pipe_read+0x56
> > > > 2 71.58 us 59.56 us 35.79 us spinlock __handle_mm_fault+0x6aa
> > > > 6 25.68 us 6.89 us 4.28 us spinlock do_idle+0x28d
> > > > 1 18.46 us 18.46 us 18.46 us rtmutex exec_fw_cmd+0x21b
> > > > 3 15.25 us 6.26 us 5.08 us spinlock tick_do_update_jiffies64+0x2c
> > > > ...
> > >
> > > Wouldn't it also be useful to display a lock contention percentage value,
> > > the ratio of fastpath vs. contended/wait events?
> > >
> > > That's usually the first-approximation metric to see how contended
> > > different locks are, and the average wait time quantifies it.
> >
> > Yeah, that'd be nice to have. But it requires some action in the fast
> > path which I don't want because I'd like to use this in production. So
> > these new tracepoints were added only in the slow path.
>
> Yeah. Might make sense to re-measure the impact of possibly doing that
> though: most of the locking fast-patch is out of line already and could be
> instrumented, with only a handful of inlined primitives -
> CONFIG_UNINLINE_SPIN_UNLOCK in particular.
I'll take a look and measure overhead with tracepoints in the fast path.
>
> How many additional inlined NOP sequences does this add in a defconfig
> kernel? How much is the bloat, and would it be acceptable for production
> kernels?
Last time I measured that it added around 1.3KB of code with the
tracepoints but they are all in the slow path. So it'd be ok for production.
>
> The other question is to keep tracing overhead low in production systems.
>
> For that we'd have to implement some concept of 'sampling tracepoints',
> which generate only one event for every 128 fast path invocations or so,
> but stay out of the way & don't slow down the system otherwise.
Yeah, it looks like we can do it with perf tools using a custom period like
`-c 128` option. But I'm not sure how it can deal with the slow path in
sync. IOW the fast path and the slow path will fire separately.
>
> OTOH frequently used locking fastpaths are measured via regular PMU
> sampling based profiling already.
Sure. Also note that the recent off-cpu profiling (perf record --off-cpu)
would be helpful to see impact of the sleeping locks.
>
> > Instead, I think we can display the ratio of (total) contended time vs.
> > wall clock time. What do you think?
>
> That looks useful too - but also the time spent waiting/spinning in a
> thread vs. the time spent actually running and executing real stuff.
>
> That ratio could easily get over 100%, for wait-dominated workloads - so
> ordering by that ratio would highlight the tasks that make the least amount
> of real progress. Measuring the ratio based only on wall clock time would
> hide this aspect.
Do you talk about per-thread stats? It has the -t/--threads option but it
doesn't work with this BPF program yet. Will work on it.
By default it shows per-lock (well.. actually per-callstack) contention stat.
We use caller symbols because there're no symbols for locks in general.
It'd be nice if we could merge the stats for the same lock (class) from
different call stacks.
Thanks,
Namhyung
^ permalink raw reply [flat|nested] 15+ messages in thread
end of thread, other threads:[~2022-08-04 21:02 UTC | newest]
Thread overview: 15+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-07-21 4:36 [PATCHSET 0/6] perf lock: Add contention subcommand (v1) Namhyung Kim
2022-07-21 4:36 ` [PATCH 1/6] perf lock: Fix a copy-n-paste bug Namhyung Kim
2022-07-21 19:09 ` Arnaldo Carvalho de Melo
2022-07-21 4:36 ` [PATCH 2/6] perf lock: Add flags field in the lock_stat Namhyung Kim
2022-07-21 4:36 ` [PATCH 3/6] perf lock: Add lock aggregation enum Namhyung Kim
2022-07-21 19:02 ` Arnaldo Carvalho de Melo
2022-07-21 19:05 ` Arnaldo Carvalho de Melo
2022-07-25 16:56 ` Namhyung Kim
2022-07-21 4:36 ` [PATCH 4/6] perf lock: Add 'contention' subcommand Namhyung Kim
2022-07-21 4:36 ` [PATCH 5/6] perf lock: Add -k and -F options to " Namhyung Kim
2022-07-21 4:36 ` [PATCH 6/6] perf lock: Support -t option for " Namhyung Kim
2022-08-03 9:51 ` [PATCHSET 0/6] perf lock: Add contention subcommand (v1) Ingo Molnar
2022-08-04 4:55 ` Namhyung Kim
2022-08-04 8:37 ` Ingo Molnar
2022-08-04 21:02 ` Namhyung Kim
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).