* [PATCH v3 0/7] perf report: Add latency and parallelism profiling
@ 2025-01-27 9:58 Dmitry Vyukov
2025-01-27 9:58 ` [PATCH v3 1/7] perf report: Add machine parallelism Dmitry Vyukov
` (7 more replies)
0 siblings, 8 replies; 20+ messages in thread
From: Dmitry Vyukov @ 2025-01-27 9:58 UTC (permalink / raw)
To: namhyung, irogers
Cc: linux-perf-users, linux-kernel, Dmitry Vyukov,
Arnaldo Carvalho de Melo
There are two notions of time: wall-clock time and CPU time.
For a single-threaded program, or a program running on a single-core
machine, these notions are the same. However, for a multi-threaded/
multi-process program running on a multi-core machine, these notions are
significantly different. Each second of wall-clock time we have
number-of-cores seconds of CPU time.
Currently perf only allows to profile CPU time. Perf (and all other
existing profilers to the be best of my knowledge) does not allow to
profile wall-clock time.
Optimizing CPU overhead is useful to improve 'throughput', while
optimizing wall-clock overhead is useful to improve 'latency'.
These profiles are complementary and are not interchangeable.
Examples of where latency profile is needed:
- optimzing build latency
- optimizing server request latency
- optimizing ML training/inference latency
- optimizing running time of any command line program
CPU profile is useless for these use cases at best (if a user understands
the difference), or misleading at worst (if a user tries to use a wrong
profile for a job).
This series add latency and parallelization profiling.
See the added documentation and flags descriptions for details.
Brief outline of the implementation:
- add context switch collection during record
- calculate number of threads running on CPUs (parallelism level)
during report
- divide each sample weight by the parallelism level
This effectively models that we were taking 1 sample per unit of
wall-clock time.
We still default to the CPU profile, so it's up to users to learn
about the second profiling mode and use it when appropriate.
Changes in v3:
- rebase and split into patches
- rename 'wallclock' to 'latency' everywhere
- don't enable latency profiling by default,
instead add record/report --latency flag
Dmitry Vyukov (7):
perf report: Add machine parallelism
perf report: Add parallelism sort key
perf report: Switch filtered from u8 to u16
perf report: Add parallelism filter
perf report: Add latency output field
perf report: Add --latency flag
perf report: Add latency and parallelism profiling documentation
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
Cc: Ian Rogers <irogers@google.com>
Cc: linux-perf-users@vger.kernel.org
Cc: linux-kernel@vger.kernel.org
.../callchain-overhead-calculation.txt | 5 +-
.../cpu-and-latency-overheads.txt | 85 ++++++++++++++++++
tools/perf/Documentation/perf-report.txt | 49 ++++++----
tools/perf/Documentation/tips.txt | 3 +
tools/perf/builtin-record.c | 20 +++++
tools/perf/builtin-report.c | 39 ++++++++
tools/perf/ui/browsers/hists.c | 27 +++---
tools/perf/ui/hist.c | 64 +++++++++----
tools/perf/util/addr_location.c | 1 +
tools/perf/util/addr_location.h | 7 +-
tools/perf/util/event.c | 11 +++
tools/perf/util/events_stats.h | 2 +
tools/perf/util/hist.c | 90 +++++++++++++++----
tools/perf/util/hist.h | 26 +++++-
tools/perf/util/machine.c | 7 ++
tools/perf/util/machine.h | 6 ++
tools/perf/util/session.c | 12 +++
tools/perf/util/session.h | 1 +
tools/perf/util/sort.c | 69 ++++++++++++--
tools/perf/util/sort.h | 3 +-
tools/perf/util/symbol.c | 34 +++++++
tools/perf/util/symbol_conf.h | 8 +-
22 files changed, 498 insertions(+), 71 deletions(-)
create mode 100644 tools/perf/Documentation/cpu-and-latency-overheads.txt
base-commit: 91b7747dc70d64b5ec56ffe493310f207e7ffc99
--
2.48.1.262.g85cc9f2d1e-goog
^ permalink raw reply [flat|nested] 20+ messages in thread
* [PATCH v3 1/7] perf report: Add machine parallelism
2025-01-27 9:58 [PATCH v3 0/7] perf report: Add latency and parallelism profiling Dmitry Vyukov
@ 2025-01-27 9:58 ` Dmitry Vyukov
2025-01-27 9:58 ` [PATCH v3 2/7] perf report: Add parallelism sort key Dmitry Vyukov
` (6 subsequent siblings)
7 siblings, 0 replies; 20+ messages in thread
From: Dmitry Vyukov @ 2025-01-27 9:58 UTC (permalink / raw)
To: namhyung, irogers
Cc: linux-perf-users, linux-kernel, Dmitry Vyukov,
Arnaldo Carvalho de Melo
Add calculation of the current parallelism level (number of threads actively
running on CPUs). The parallelism level can be shown in reports on its own,
and to calculate latency overheads.
Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
Cc: Ian Rogers <irogers@google.com>
Cc: linux-perf-users@vger.kernel.org
Cc: linux-kernel@vger.kernel.org
---
tools/perf/builtin-report.c | 1 +
tools/perf/util/addr_location.c | 1 +
tools/perf/util/addr_location.h | 2 ++
tools/perf/util/event.c | 3 +++
tools/perf/util/machine.c | 7 +++++++
tools/perf/util/machine.h | 6 ++++++
6 files changed, 20 insertions(+)
diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
index f5fbd670d619a..0d9bd090eda71 100644
--- a/tools/perf/builtin-report.c
+++ b/tools/perf/builtin-report.c
@@ -1568,6 +1568,7 @@ int cmd_report(int argc, const char **argv)
report.tool.cgroup = perf_event__process_cgroup;
report.tool.exit = perf_event__process_exit;
report.tool.fork = perf_event__process_fork;
+ report.tool.context_switch = perf_event__process_switch;
report.tool.lost = perf_event__process_lost;
report.tool.read = process_read_event;
report.tool.attr = process_attr;
diff --git a/tools/perf/util/addr_location.c b/tools/perf/util/addr_location.c
index 51825ef8c0ab7..007a2f5df9a6a 100644
--- a/tools/perf/util/addr_location.c
+++ b/tools/perf/util/addr_location.c
@@ -17,6 +17,7 @@ void addr_location__init(struct addr_location *al)
al->cpumode = 0;
al->cpu = 0;
al->socket = 0;
+ al->parallelism = 1;
}
/*
diff --git a/tools/perf/util/addr_location.h b/tools/perf/util/addr_location.h
index d8ac0428dff23..36aaa45445f24 100644
--- a/tools/perf/util/addr_location.h
+++ b/tools/perf/util/addr_location.h
@@ -21,6 +21,8 @@ struct addr_location {
u8 cpumode;
s32 cpu;
s32 socket;
+ /* Same as machine.parallelism but within [1, nr_cpus]. */
+ int parallelism;
};
void addr_location__init(struct addr_location *al);
diff --git a/tools/perf/util/event.c b/tools/perf/util/event.c
index aac96d5d19170..3d3ac58e1c660 100644
--- a/tools/perf/util/event.c
+++ b/tools/perf/util/event.c
@@ -767,6 +767,9 @@ int machine__resolve(struct machine *machine, struct addr_location *al,
al->socket = env->cpu[al->cpu].socket_id;
}
+ /* Account for possible out-of-order switch events. */
+ al->parallelism = min(max(machine->parallelism, 1), machine__nr_cpus_avail(machine));
+
if (al->map) {
if (symbol_conf.dso_list &&
(!dso || !(strlist__has_entry(symbol_conf.dso_list,
diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
index 2d51badfbf2e2..0e65c5377f983 100644
--- a/tools/perf/util/machine.c
+++ b/tools/perf/util/machine.c
@@ -94,6 +94,8 @@ int machine__init(struct machine *machine, const char *root_dir, pid_t pid)
machine->comm_exec = false;
machine->kernel_start = 0;
machine->vmlinux_map = NULL;
+ /* There is no initial context switch in, so we start at 1. */
+ machine->parallelism = 1;
machine->root_dir = strdup(root_dir);
if (machine->root_dir == NULL)
@@ -677,8 +679,11 @@ int machine__process_aux_output_hw_id_event(struct machine *machine __maybe_unus
int machine__process_switch_event(struct machine *machine __maybe_unused,
union perf_event *event)
{
+ bool out = event->header.misc & PERF_RECORD_MISC_SWITCH_OUT;
+
if (dump_trace)
perf_event__fprintf_switch(event, stdout);
+ machine->parallelism += out ? -1 : 1;
return 0;
}
@@ -1900,6 +1905,8 @@ int machine__process_exit_event(struct machine *machine, union perf_event *event
if (dump_trace)
perf_event__fprintf_task(event, stdout);
+ /* There is no context switch out before exit, so we decrement here. */
+ machine->parallelism--;
if (thread != NULL) {
if (symbol_conf.keep_exited_threads)
thread__set_exited(thread, /*exited=*/true);
diff --git a/tools/perf/util/machine.h b/tools/perf/util/machine.h
index 2e5a4cb342d82..a5f28652873ce 100644
--- a/tools/perf/util/machine.h
+++ b/tools/perf/util/machine.h
@@ -50,6 +50,12 @@ struct machine {
u64 text_start;
u64 text_end;
} sched, lock, traceiter, trace;
+ /*
+ * The current parallelism level (number of threads that run on CPUs).
+ * This value can be less than 1, or larger than the total number
+ * of CPUs, if events are poorly ordered.
+ */
+ int parallelism;
pid_t *current_tid;
size_t current_tid_sz;
union { /* Tool specific area */
--
2.48.1.262.g85cc9f2d1e-goog
^ permalink raw reply related [flat|nested] 20+ messages in thread
* [PATCH v3 2/7] perf report: Add parallelism sort key
2025-01-27 9:58 [PATCH v3 0/7] perf report: Add latency and parallelism profiling Dmitry Vyukov
2025-01-27 9:58 ` [PATCH v3 1/7] perf report: Add machine parallelism Dmitry Vyukov
@ 2025-01-27 9:58 ` Dmitry Vyukov
2025-01-29 4:42 ` Namhyung Kim
2025-01-27 9:58 ` [PATCH v3 3/7] perf report: Switch filtered from u8 to u16 Dmitry Vyukov
` (5 subsequent siblings)
7 siblings, 1 reply; 20+ messages in thread
From: Dmitry Vyukov @ 2025-01-27 9:58 UTC (permalink / raw)
To: namhyung, irogers
Cc: linux-perf-users, linux-kernel, Dmitry Vyukov,
Arnaldo Carvalho de Melo
Show parallelism level in profiles if requested by user.
Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
Cc: Ian Rogers <irogers@google.com>
Cc: linux-perf-users@vger.kernel.org
Cc: linux-kernel@vger.kernel.org
---
tools/perf/builtin-report.c | 11 +++++++++++
tools/perf/util/hist.c | 2 ++
tools/perf/util/hist.h | 3 +++
tools/perf/util/session.c | 12 ++++++++++++
tools/perf/util/session.h | 1 +
tools/perf/util/sort.c | 23 +++++++++++++++++++++++
tools/perf/util/sort.h | 1 +
7 files changed, 53 insertions(+)
diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
index 0d9bd090eda71..14d49f0625881 100644
--- a/tools/perf/builtin-report.c
+++ b/tools/perf/builtin-report.c
@@ -1720,6 +1720,17 @@ int cmd_report(int argc, const char **argv)
symbol_conf.annotate_data_sample = true;
}
+ if (report.disable_order || !perf_session__has_switch_events(session)) {
+ if ((sort_order && strstr(sort_order, "parallelism")) ||
+ (field_order && strstr(field_order, "parallelism"))) {
+ if (report.disable_order)
+ ui__error("Use of parallelism is incompatible with --disable-order.\n");
+ else
+ ui__error("Use of parallelism requires --switch-events during record.\n");
+ return -1;
+ }
+ }
+
if (sort_order && strstr(sort_order, "ipc")) {
parse_options_usage(report_usage, options, "s", 1);
goto error;
diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index 0f30f843c566d..cafd693568189 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -207,6 +207,7 @@ void hists__calc_col_len(struct hists *hists, struct hist_entry *h)
hists__new_col_len(hists, HISTC_CGROUP, 6);
hists__new_col_len(hists, HISTC_CGROUP_ID, 20);
+ hists__new_col_len(hists, HISTC_PARALLELISM, 11);
hists__new_col_len(hists, HISTC_CPU, 3);
hists__new_col_len(hists, HISTC_SOCKET, 6);
hists__new_col_len(hists, HISTC_MEM_LOCKED, 6);
@@ -741,6 +742,7 @@ __hists__add_entry(struct hists *hists,
.ip = al->addr,
.level = al->level,
.code_page_size = sample->code_page_size,
+ .parallelism = al->parallelism,
.stat = {
.nr_events = 1,
.period = sample->period,
diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
index 46c8373e31465..a6e662d77dc24 100644
--- a/tools/perf/util/hist.h
+++ b/tools/perf/util/hist.h
@@ -42,6 +42,7 @@ enum hist_column {
HISTC_CGROUP_ID,
HISTC_CGROUP,
HISTC_PARENT,
+ HISTC_PARALLELISM,
HISTC_CPU,
HISTC_SOCKET,
HISTC_SRCLINE,
@@ -228,6 +229,7 @@ struct hist_entry {
u64 transaction;
s32 socket;
s32 cpu;
+ int parallelism;
u64 code_page_size;
u64 weight;
u64 ins_lat;
@@ -580,6 +582,7 @@ bool perf_hpp__is_thread_entry(struct perf_hpp_fmt *fmt);
bool perf_hpp__is_comm_entry(struct perf_hpp_fmt *fmt);
bool perf_hpp__is_dso_entry(struct perf_hpp_fmt *fmt);
bool perf_hpp__is_sym_entry(struct perf_hpp_fmt *fmt);
+bool perf_hpp__is_parallelism_entry(struct perf_hpp_fmt *fmt);
struct perf_hpp_fmt *perf_hpp_fmt__dup(struct perf_hpp_fmt *fmt);
diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index c06e3020a9769..00fcf8d8ac255 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -2403,6 +2403,18 @@ bool perf_session__has_traces(struct perf_session *session, const char *msg)
return false;
}
+bool perf_session__has_switch_events(struct perf_session *session)
+{
+ struct evsel *evsel;
+
+ evlist__for_each_entry(session->evlist, evsel) {
+ if (evsel->core.attr.context_switch)
+ return true;
+ }
+
+ return false;
+}
+
int map__set_kallsyms_ref_reloc_sym(struct map *map, const char *symbol_name, u64 addr)
{
char *bracket;
diff --git a/tools/perf/util/session.h b/tools/perf/util/session.h
index bcf1bcf06959b..db1c120a9e67f 100644
--- a/tools/perf/util/session.h
+++ b/tools/perf/util/session.h
@@ -141,6 +141,7 @@ int perf_session__resolve_callchain(struct perf_session *session,
struct symbol **parent);
bool perf_session__has_traces(struct perf_session *session, const char *msg);
+bool perf_session__has_switch_events(struct perf_session *session);
void perf_event__attr_swap(struct perf_event_attr *attr);
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index 3dd33721823f3..7eef43f5be360 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -892,6 +892,27 @@ struct sort_entry sort_cpu = {
.se_width_idx = HISTC_CPU,
};
+/* --sort parallelism */
+
+static int64_t
+sort__parallelism_cmp(struct hist_entry *left, struct hist_entry *right)
+{
+ return right->parallelism - left->parallelism;
+}
+
+static int hist_entry__parallelism_snprintf(struct hist_entry *he, char *bf,
+ size_t size, unsigned int width)
+{
+ return repsep_snprintf(bf, size, "%*d", width, he->parallelism);
+}
+
+struct sort_entry sort_parallelism = {
+ .se_header = "Parallelism",
+ .se_cmp = sort__parallelism_cmp,
+ .se_snprintf = hist_entry__parallelism_snprintf,
+ .se_width_idx = HISTC_PARALLELISM,
+};
+
/* --sort cgroup_id */
static int64_t _sort__cgroup_dev_cmp(u64 left_dev, u64 right_dev)
@@ -2534,6 +2555,7 @@ static struct sort_dimension common_sort_dimensions[] = {
DIM(SORT_ANNOTATE_DATA_TYPE_OFFSET, "typeoff", sort_type_offset),
DIM(SORT_SYM_OFFSET, "symoff", sort_sym_offset),
DIM(SORT_ANNOTATE_DATA_TYPE_CACHELINE, "typecln", sort_type_cacheline),
+ DIM(SORT_PARALLELISM, "parallelism", sort_parallelism),
};
#undef DIM
@@ -2735,6 +2757,7 @@ MK_SORT_ENTRY_CHK(thread)
MK_SORT_ENTRY_CHK(comm)
MK_SORT_ENTRY_CHK(dso)
MK_SORT_ENTRY_CHK(sym)
+MK_SORT_ENTRY_CHK(parallelism)
static bool __sort__hpp_equal(struct perf_hpp_fmt *a, struct perf_hpp_fmt *b)
diff --git a/tools/perf/util/sort.h b/tools/perf/util/sort.h
index a8572574e1686..11fb15f914093 100644
--- a/tools/perf/util/sort.h
+++ b/tools/perf/util/sort.h
@@ -72,6 +72,7 @@ enum sort_type {
SORT_ANNOTATE_DATA_TYPE_OFFSET,
SORT_SYM_OFFSET,
SORT_ANNOTATE_DATA_TYPE_CACHELINE,
+ SORT_PARALLELISM,
/* branch stack specific sort keys */
__SORT_BRANCH_STACK,
--
2.48.1.262.g85cc9f2d1e-goog
^ permalink raw reply related [flat|nested] 20+ messages in thread
* [PATCH v3 3/7] perf report: Switch filtered from u8 to u16
2025-01-27 9:58 [PATCH v3 0/7] perf report: Add latency and parallelism profiling Dmitry Vyukov
2025-01-27 9:58 ` [PATCH v3 1/7] perf report: Add machine parallelism Dmitry Vyukov
2025-01-27 9:58 ` [PATCH v3 2/7] perf report: Add parallelism sort key Dmitry Vyukov
@ 2025-01-27 9:58 ` Dmitry Vyukov
2025-01-27 9:58 ` [PATCH v3 4/7] perf report: Add parallelism filter Dmitry Vyukov
` (4 subsequent siblings)
7 siblings, 0 replies; 20+ messages in thread
From: Dmitry Vyukov @ 2025-01-27 9:58 UTC (permalink / raw)
To: namhyung, irogers
Cc: linux-perf-users, linux-kernel, Dmitry Vyukov,
Arnaldo Carvalho de Melo
We already have all u8 bits taken, adding one more filter leads to unpleasant
failure mode, where code compiles w/o warnings, but the last filters silently
don't work. Add a typedef and switch to u16.
Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
Cc: Ian Rogers <irogers@google.com>
Cc: linux-perf-users@vger.kernel.org
Cc: linux-kernel@vger.kernel.org
---
tools/perf/util/addr_location.h | 3 ++-
tools/perf/util/hist.c | 2 +-
tools/perf/util/hist.h | 4 +++-
3 files changed, 6 insertions(+), 3 deletions(-)
diff --git a/tools/perf/util/addr_location.h b/tools/perf/util/addr_location.h
index 36aaa45445f24..f83d74e370b2f 100644
--- a/tools/perf/util/addr_location.h
+++ b/tools/perf/util/addr_location.h
@@ -3,6 +3,7 @@
#define __PERF_ADDR_LOCATION 1
#include <linux/types.h>
+#include "hist.h"
struct thread;
struct maps;
@@ -17,7 +18,7 @@ struct addr_location {
const char *srcline;
u64 addr;
char level;
- u8 filtered;
+ filter_mask_t filtered;
u8 cpumode;
s32 cpu;
s32 socket;
diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index cafd693568189..6b8f8da8d3b66 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -585,7 +585,7 @@ static struct hist_entry *hist_entry__new(struct hist_entry *template,
return he;
}
-static u8 symbol__parent_filter(const struct symbol *parent)
+static filter_mask_t symbol__parent_filter(const struct symbol *parent)
{
if (symbol_conf.exclude_other && parent == NULL)
return 1 << HIST_FILTER__PARENT;
diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
index a6e662d77dc24..4035106a74087 100644
--- a/tools/perf/util/hist.h
+++ b/tools/perf/util/hist.h
@@ -33,6 +33,8 @@ enum hist_filter {
HIST_FILTER__C2C,
};
+typedef u16 filter_mask_t;
+
enum hist_column {
HISTC_SYMBOL,
HISTC_TIME,
@@ -244,7 +246,7 @@ struct hist_entry {
bool leaf;
char level;
- u8 filtered;
+ filter_mask_t filtered;
u16 callchain_size;
union {
--
2.48.1.262.g85cc9f2d1e-goog
^ permalink raw reply related [flat|nested] 20+ messages in thread
* [PATCH v3 4/7] perf report: Add parallelism filter
2025-01-27 9:58 [PATCH v3 0/7] perf report: Add latency and parallelism profiling Dmitry Vyukov
` (2 preceding siblings ...)
2025-01-27 9:58 ` [PATCH v3 3/7] perf report: Switch filtered from u8 to u16 Dmitry Vyukov
@ 2025-01-27 9:58 ` Dmitry Vyukov
2025-01-27 9:58 ` [PATCH v3 5/7] perf report: Add latency output field Dmitry Vyukov
` (3 subsequent siblings)
7 siblings, 0 replies; 20+ messages in thread
From: Dmitry Vyukov @ 2025-01-27 9:58 UTC (permalink / raw)
To: namhyung, irogers
Cc: linux-perf-users, linux-kernel, Dmitry Vyukov,
Arnaldo Carvalho de Melo
Add parallelism filter that can be used to look at specific parallelism
levels only. The format is the same as cpu lists. For example:
Only single-threaded samples: --parallelism=1
Low parallelism only: --parallelism=1-4
High parallelism only: --parallelism=64-128
Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
Cc: Ian Rogers <irogers@google.com>
Cc: linux-perf-users@vger.kernel.org
Cc: linux-kernel@vger.kernel.org
---
tools/perf/builtin-report.c | 5 ++++-
tools/perf/util/event.c | 2 ++
tools/perf/util/hist.c | 31 +++++++++++++++++++++++++++++++
tools/perf/util/hist.h | 6 +++++-
tools/perf/util/sort.c | 11 +++++++++++
tools/perf/util/symbol.c | 34 ++++++++++++++++++++++++++++++++++
tools/perf/util/symbol_conf.h | 4 ++++
7 files changed, 91 insertions(+), 2 deletions(-)
diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
index 14d49f0625881..2a19abdc869a1 100644
--- a/tools/perf/builtin-report.c
+++ b/tools/perf/builtin-report.c
@@ -1390,6 +1390,8 @@ int cmd_report(int argc, const char **argv)
symbol__config_symfs),
OPT_STRING('C', "cpu", &report.cpu_list, "cpu",
"list of cpus to profile"),
+ OPT_STRING(0, "parallelism", &symbol_conf.parallelism_list_str, "parallelism",
+ "only consider these parallelism levels (cpu set format)"),
OPT_BOOLEAN('I', "show-info", &report.show_full_info,
"Display extended information about perf.data file"),
OPT_BOOLEAN(0, "source", &annotate_opts.annotate_src,
@@ -1721,7 +1723,8 @@ int cmd_report(int argc, const char **argv)
}
if (report.disable_order || !perf_session__has_switch_events(session)) {
- if ((sort_order && strstr(sort_order, "parallelism")) ||
+ if (symbol_conf.parallelism_list_str ||
+ (sort_order && strstr(sort_order, "parallelism")) ||
(field_order && strstr(field_order, "parallelism"))) {
if (report.disable_order)
ui__error("Use of parallelism is incompatible with --disable-order.\n");
diff --git a/tools/perf/util/event.c b/tools/perf/util/event.c
index 3d3ac58e1c660..bea9698e0c6bf 100644
--- a/tools/perf/util/event.c
+++ b/tools/perf/util/event.c
@@ -769,6 +769,8 @@ int machine__resolve(struct machine *machine, struct addr_location *al,
/* Account for possible out-of-order switch events. */
al->parallelism = min(max(machine->parallelism, 1), machine__nr_cpus_avail(machine));
+ if (test_bit(al->parallelism, symbol_conf.parallelism_filter))
+ al->filtered |= (1 << HIST_FILTER__PARALLELISM);
if (al->map) {
if (symbol_conf.dso_list &&
diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index 6b8f8da8d3b66..446342246f5ee 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -43,6 +43,8 @@ static bool hists__filter_entry_by_symbol(struct hists *hists,
struct hist_entry *he);
static bool hists__filter_entry_by_socket(struct hists *hists,
struct hist_entry *he);
+static bool hists__filter_entry_by_parallelism(struct hists *hists,
+ struct hist_entry *he);
u16 hists__col_len(struct hists *hists, enum hist_column col)
{
@@ -1457,6 +1459,10 @@ static void hist_entry__check_and_remove_filter(struct hist_entry *he,
if (symbol_conf.sym_list == NULL)
return;
break;
+ case HIST_FILTER__PARALLELISM:
+ if (__bitmap_weight(symbol_conf.parallelism_filter, MAX_NR_CPUS + 1) == 0)
+ return;
+ break;
case HIST_FILTER__PARENT:
case HIST_FILTER__GUEST:
case HIST_FILTER__HOST:
@@ -1515,6 +1521,9 @@ static void hist_entry__apply_hierarchy_filters(struct hist_entry *he)
hist_entry__check_and_remove_filter(he, HIST_FILTER__SYMBOL,
perf_hpp__is_sym_entry);
+ hist_entry__check_and_remove_filter(he, HIST_FILTER__PARALLELISM,
+ perf_hpp__is_parallelism_entry);
+
hists__apply_filters(he->hists, he);
}
@@ -1711,6 +1720,7 @@ static void hists__apply_filters(struct hists *hists, struct hist_entry *he)
hists__filter_entry_by_thread(hists, he);
hists__filter_entry_by_symbol(hists, he);
hists__filter_entry_by_socket(hists, he);
+ hists__filter_entry_by_parallelism(hists, he);
}
int hists__collapse_resort(struct hists *hists, struct ui_progress *prog)
@@ -2197,6 +2207,16 @@ static bool hists__filter_entry_by_socket(struct hists *hists,
return false;
}
+static bool hists__filter_entry_by_parallelism(struct hists *hists,
+ struct hist_entry *he)
+{
+ if (test_bit(he->parallelism, hists->parallelism_filter)) {
+ he->filtered |= (1 << HIST_FILTER__PARALLELISM);
+ return true;
+ }
+ return false;
+}
+
typedef bool (*filter_fn_t)(struct hists *hists, struct hist_entry *he);
static void hists__filter_by_type(struct hists *hists, int type, filter_fn_t filter)
@@ -2366,6 +2386,16 @@ void hists__filter_by_socket(struct hists *hists)
hists__filter_entry_by_socket);
}
+void hists__filter_by_parallelism(struct hists *hists)
+{
+ if (symbol_conf.report_hierarchy)
+ hists__filter_hierarchy(hists, HIST_FILTER__PARALLELISM,
+ hists->parallelism_filter);
+ else
+ hists__filter_by_type(hists, HIST_FILTER__PARALLELISM,
+ hists__filter_entry_by_parallelism);
+}
+
void events_stats__inc(struct events_stats *stats, u32 type)
{
++stats->nr_events[0];
@@ -2872,6 +2902,7 @@ int __hists__init(struct hists *hists, struct perf_hpp_list *hpp_list)
hists->entries = RB_ROOT_CACHED;
mutex_init(&hists->lock);
hists->socket_filter = -1;
+ hists->parallelism_filter = symbol_conf.parallelism_filter;
hists->hpp_list = hpp_list;
INIT_LIST_HEAD(&hists->hpp_formats);
return 0;
diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
index 4035106a74087..c2236e0d89f2a 100644
--- a/tools/perf/util/hist.h
+++ b/tools/perf/util/hist.h
@@ -31,6 +31,7 @@ enum hist_filter {
HIST_FILTER__HOST,
HIST_FILTER__SOCKET,
HIST_FILTER__C2C,
+ HIST_FILTER__PARALLELISM,
};
typedef u16 filter_mask_t;
@@ -112,6 +113,7 @@ struct hists {
const struct dso *dso_filter;
const char *uid_filter_str;
const char *symbol_filter_str;
+ unsigned long *parallelism_filter;
struct mutex lock;
struct hists_stats stats;
u64 event_stream;
@@ -388,11 +390,13 @@ void hists__filter_by_dso(struct hists *hists);
void hists__filter_by_thread(struct hists *hists);
void hists__filter_by_symbol(struct hists *hists);
void hists__filter_by_socket(struct hists *hists);
+void hists__filter_by_parallelism(struct hists *hists);
static inline bool hists__has_filter(struct hists *hists)
{
return hists->thread_filter || hists->dso_filter ||
- hists->symbol_filter_str || (hists->socket_filter > -1);
+ hists->symbol_filter_str || (hists->socket_filter > -1) ||
+ hists->parallelism_filter;
}
u16 hists__col_len(struct hists *hists, enum hist_column col);
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index 7eef43f5be360..3055496358ebb 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -900,6 +900,16 @@ sort__parallelism_cmp(struct hist_entry *left, struct hist_entry *right)
return right->parallelism - left->parallelism;
}
+static int hist_entry__parallelism_filter(struct hist_entry *he, int type, const void *arg)
+{
+ const unsigned long *parallelism_filter = arg;
+
+ if (type != HIST_FILTER__PARALLELISM)
+ return -1;
+
+ return test_bit(he->parallelism, parallelism_filter);
+}
+
static int hist_entry__parallelism_snprintf(struct hist_entry *he, char *bf,
size_t size, unsigned int width)
{
@@ -909,6 +919,7 @@ static int hist_entry__parallelism_snprintf(struct hist_entry *he, char *bf,
struct sort_entry sort_parallelism = {
.se_header = "Parallelism",
.se_cmp = sort__parallelism_cmp,
+ .se_filter = hist_entry__parallelism_filter,
.se_snprintf = hist_entry__parallelism_snprintf,
.se_width_idx = HISTC_PARALLELISM,
};
diff --git a/tools/perf/util/symbol.c b/tools/perf/util/symbol.c
index 49b08adc6ee34..315f74b5bac06 100644
--- a/tools/perf/util/symbol.c
+++ b/tools/perf/util/symbol.c
@@ -18,6 +18,7 @@
#include "annotate.h"
#include "build-id.h"
#include "cap.h"
+#include "cpumap.h"
#include "dso.h"
#include "util.h" // lsdir()
#include "debug.h"
@@ -2471,6 +2472,36 @@ int symbol__annotation_init(void)
return 0;
}
+static int setup_parallelism_bitmap(void)
+{
+ struct perf_cpu_map *map;
+ struct perf_cpu cpu;
+ int i, err = -1;
+
+ if (symbol_conf.parallelism_list_str == NULL)
+ return 0;
+
+ map = perf_cpu_map__new(symbol_conf.parallelism_list_str);
+ if (map == NULL) {
+ pr_err("failed to parse parallelism filter list\n");
+ return -1;
+ }
+
+ bitmap_fill(symbol_conf.parallelism_filter, MAX_NR_CPUS + 1);
+ perf_cpu_map__for_each_cpu(cpu, i, map) {
+ if (cpu.cpu <= 0 || cpu.cpu > MAX_NR_CPUS) {
+ pr_err("Requested parallelism level %d is invalid.\n", cpu.cpu);
+ goto out_delete_map;
+ }
+ __clear_bit(cpu.cpu, symbol_conf.parallelism_filter);
+ }
+
+ err = 0;
+out_delete_map:
+ perf_cpu_map__put(map);
+ return err;
+}
+
int symbol__init(struct perf_env *env)
{
const char *symfs;
@@ -2490,6 +2521,9 @@ int symbol__init(struct perf_env *env)
return -1;
}
+ if (setup_parallelism_bitmap())
+ return -1;
+
if (setup_list(&symbol_conf.dso_list,
symbol_conf.dso_list_str, "dso") < 0)
return -1;
diff --git a/tools/perf/util/symbol_conf.h b/tools/perf/util/symbol_conf.h
index a9c51acc722fe..c5b2e56127e22 100644
--- a/tools/perf/util/symbol_conf.h
+++ b/tools/perf/util/symbol_conf.h
@@ -3,6 +3,8 @@
#define __PERF_SYMBOL_CONF 1
#include <stdbool.h>
+#include <linux/bitmap.h>
+#include "perf.h"
struct strlist;
struct intlist;
@@ -62,6 +64,7 @@ struct symbol_conf {
*pid_list_str,
*tid_list_str,
*sym_list_str,
+ *parallelism_list_str,
*col_width_list_str,
*bt_stop_list_str;
const char *addr2line_path;
@@ -82,6 +85,7 @@ struct symbol_conf {
int pad_output_len_dso;
int group_sort_idx;
int addr_range;
+ DECLARE_BITMAP(parallelism_filter, MAX_NR_CPUS + 1);
};
extern struct symbol_conf symbol_conf;
--
2.48.1.262.g85cc9f2d1e-goog
^ permalink raw reply related [flat|nested] 20+ messages in thread
* [PATCH v3 5/7] perf report: Add latency output field
2025-01-27 9:58 [PATCH v3 0/7] perf report: Add latency and parallelism profiling Dmitry Vyukov
` (3 preceding siblings ...)
2025-01-27 9:58 ` [PATCH v3 4/7] perf report: Add parallelism filter Dmitry Vyukov
@ 2025-01-27 9:58 ` Dmitry Vyukov
2025-01-29 4:56 ` Namhyung Kim
2025-01-27 9:58 ` [PATCH v3 6/7] perf report: Add --latency flag Dmitry Vyukov
` (2 subsequent siblings)
7 siblings, 1 reply; 20+ messages in thread
From: Dmitry Vyukov @ 2025-01-27 9:58 UTC (permalink / raw)
To: namhyung, irogers
Cc: linux-perf-users, linux-kernel, Dmitry Vyukov,
Arnaldo Carvalho de Melo
Latency output field is similar to overhead, but represents overhead for
latency rather than CPU consumption. It's re-scaled from overhead by dividing
weight by the current parallelism level at the time of the sample.
It effectively models profiling with 1 sample taken per unit of wall-clock
time rather than unit of CPU time.
Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
Cc: Ian Rogers <irogers@google.com>
Cc: linux-perf-users@vger.kernel.org
Cc: linux-kernel@vger.kernel.org
---
tools/perf/ui/browsers/hists.c | 27 ++++++++++------
tools/perf/ui/hist.c | 29 ++++++++++-------
tools/perf/util/addr_location.h | 2 ++
tools/perf/util/event.c | 6 ++++
tools/perf/util/events_stats.h | 2 ++
tools/perf/util/hist.c | 55 ++++++++++++++++++++++++---------
tools/perf/util/hist.h | 12 +++++++
tools/perf/util/sort.c | 2 ++
8 files changed, 100 insertions(+), 35 deletions(-)
diff --git a/tools/perf/ui/browsers/hists.c b/tools/perf/ui/browsers/hists.c
index 49ba82bf33918..35c10509b797f 100644
--- a/tools/perf/ui/browsers/hists.c
+++ b/tools/perf/ui/browsers/hists.c
@@ -1226,7 +1226,7 @@ int __hpp__slsmg_color_printf(struct perf_hpp *hpp, const char *fmt, ...)
return ret;
}
-#define __HPP_COLOR_PERCENT_FN(_type, _field) \
+#define __HPP_COLOR_PERCENT_FN(_type, _field, _fmttype) \
static u64 __hpp_get_##_field(struct hist_entry *he) \
{ \
return he->stat._field; \
@@ -1238,10 +1238,10 @@ hist_browser__hpp_color_##_type(struct perf_hpp_fmt *fmt, \
struct hist_entry *he) \
{ \
return hpp__fmt(fmt, hpp, he, __hpp_get_##_field, " %*.2f%%", \
- __hpp__slsmg_color_printf, true); \
+ __hpp__slsmg_color_printf, _fmttype); \
}
-#define __HPP_COLOR_ACC_PERCENT_FN(_type, _field) \
+#define __HPP_COLOR_ACC_PERCENT_FN(_type, _field, _fmttype) \
static u64 __hpp_get_acc_##_field(struct hist_entry *he) \
{ \
return he->stat_acc->_field; \
@@ -1262,15 +1262,18 @@ hist_browser__hpp_color_##_type(struct perf_hpp_fmt *fmt, \
return ret; \
} \
return hpp__fmt(fmt, hpp, he, __hpp_get_acc_##_field, \
- " %*.2f%%", __hpp__slsmg_color_printf, true); \
+ " %*.2f%%", __hpp__slsmg_color_printf, \
+ _fmttype); \
}
-__HPP_COLOR_PERCENT_FN(overhead, period)
-__HPP_COLOR_PERCENT_FN(overhead_sys, period_sys)
-__HPP_COLOR_PERCENT_FN(overhead_us, period_us)
-__HPP_COLOR_PERCENT_FN(overhead_guest_sys, period_guest_sys)
-__HPP_COLOR_PERCENT_FN(overhead_guest_us, period_guest_us)
-__HPP_COLOR_ACC_PERCENT_FN(overhead_acc, period)
+__HPP_COLOR_PERCENT_FN(overhead, period, PERF_HPP_FMT_TYPE__PERCENT)
+__HPP_COLOR_PERCENT_FN(latency, latency, PERF_HPP_FMT_TYPE__LATENCY)
+__HPP_COLOR_PERCENT_FN(overhead_sys, period_sys, PERF_HPP_FMT_TYPE__PERCENT)
+__HPP_COLOR_PERCENT_FN(overhead_us, period_us, PERF_HPP_FMT_TYPE__PERCENT)
+__HPP_COLOR_PERCENT_FN(overhead_guest_sys, period_guest_sys, PERF_HPP_FMT_TYPE__PERCENT)
+__HPP_COLOR_PERCENT_FN(overhead_guest_us, period_guest_us, PERF_HPP_FMT_TYPE__PERCENT)
+__HPP_COLOR_ACC_PERCENT_FN(overhead_acc, period, PERF_HPP_FMT_TYPE__PERCENT)
+__HPP_COLOR_ACC_PERCENT_FN(latency_acc, latency, PERF_HPP_FMT_TYPE__LATENCY)
#undef __HPP_COLOR_PERCENT_FN
#undef __HPP_COLOR_ACC_PERCENT_FN
@@ -1279,6 +1282,8 @@ void hist_browser__init_hpp(void)
{
perf_hpp__format[PERF_HPP__OVERHEAD].color =
hist_browser__hpp_color_overhead;
+ perf_hpp__format[PERF_HPP__LATENCY].color =
+ hist_browser__hpp_color_latency;
perf_hpp__format[PERF_HPP__OVERHEAD_SYS].color =
hist_browser__hpp_color_overhead_sys;
perf_hpp__format[PERF_HPP__OVERHEAD_US].color =
@@ -1289,6 +1294,8 @@ void hist_browser__init_hpp(void)
hist_browser__hpp_color_overhead_guest_us;
perf_hpp__format[PERF_HPP__OVERHEAD_ACC].color =
hist_browser__hpp_color_overhead_acc;
+ perf_hpp__format[PERF_HPP__LATENCY_ACC].color =
+ hist_browser__hpp_color_latency_acc;
res_sample_init();
}
diff --git a/tools/perf/ui/hist.c b/tools/perf/ui/hist.c
index 34fda1d5eccb4..22e31d835301e 100644
--- a/tools/perf/ui/hist.c
+++ b/tools/perf/ui/hist.c
@@ -27,9 +27,10 @@ static int __hpp__fmt_print(struct perf_hpp *hpp, struct hists *hists, u64 val,
int nr_samples, const char *fmt, int len,
hpp_snprint_fn print_fn, enum perf_hpp_fmt_type fmtype)
{
- if (fmtype == PERF_HPP_FMT_TYPE__PERCENT) {
+ if (fmtype == PERF_HPP_FMT_TYPE__PERCENT || fmtype == PERF_HPP_FMT_TYPE__LATENCY) {
double percent = 0.0;
- u64 total = hists__total_period(hists);
+ u64 total = fmtype == PERF_HPP_FMT_TYPE__PERCENT ? hists__total_period(hists) :
+ hists__total_latency(hists);
if (total)
percent = 100.0 * val / total;
@@ -128,7 +129,7 @@ int hpp__fmt(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
print_fn, fmtype);
}
- if (fmtype == PERF_HPP_FMT_TYPE__PERCENT)
+ if (fmtype == PERF_HPP_FMT_TYPE__PERCENT || fmtype == PERF_HPP_FMT_TYPE__LATENCY)
len -= 2; /* 2 for a space and a % sign */
else
len -= 1;
@@ -472,11 +473,13 @@ __HPP_ENTRY_AVERAGE_FN(_type, _field) \
__HPP_SORT_AVERAGE_FN(_type, _field)
HPP_PERCENT_FNS(overhead, period)
+HPP_PERCENT_FNS(latency, latency)
HPP_PERCENT_FNS(overhead_sys, period_sys)
HPP_PERCENT_FNS(overhead_us, period_us)
HPP_PERCENT_FNS(overhead_guest_sys, period_guest_sys)
HPP_PERCENT_FNS(overhead_guest_us, period_guest_us)
HPP_PERCENT_ACC_FNS(overhead_acc, period)
+HPP_PERCENT_ACC_FNS(latency_acc, latency)
HPP_RAW_FNS(samples, nr_events)
HPP_RAW_FNS(period, period)
@@ -548,11 +551,13 @@ static bool hpp__equal(struct perf_hpp_fmt *a, struct perf_hpp_fmt *b)
struct perf_hpp_fmt perf_hpp__format[] = {
HPP__COLOR_PRINT_FNS("Overhead", overhead, OVERHEAD),
+ HPP__COLOR_PRINT_FNS("Latency", latency, LATENCY),
HPP__COLOR_PRINT_FNS("sys", overhead_sys, OVERHEAD_SYS),
HPP__COLOR_PRINT_FNS("usr", overhead_us, OVERHEAD_US),
HPP__COLOR_PRINT_FNS("guest sys", overhead_guest_sys, OVERHEAD_GUEST_SYS),
HPP__COLOR_PRINT_FNS("guest usr", overhead_guest_us, OVERHEAD_GUEST_US),
HPP__COLOR_ACC_PRINT_FNS("Children", overhead_acc, OVERHEAD_ACC),
+ HPP__COLOR_ACC_PRINT_FNS("Latency", latency_acc, LATENCY_ACC),
HPP__PRINT_FNS("Samples", samples, SAMPLES),
HPP__PRINT_FNS("Period", period, PERIOD),
HPP__PRINT_FNS("Weight1", weight1, WEIGHT1),
@@ -601,6 +606,11 @@ static void fmt_free(struct perf_hpp_fmt *fmt)
fmt->free(fmt);
}
+static bool fmt_equal(struct perf_hpp_fmt *a, struct perf_hpp_fmt *b)
+{
+ return a->equal && a->equal(a, b);
+}
+
void perf_hpp__init(void)
{
int i;
@@ -671,30 +681,26 @@ static void perf_hpp__column_unregister(struct perf_hpp_fmt *format)
void perf_hpp__cancel_cumulate(void)
{
- struct perf_hpp_fmt *fmt, *acc, *ovh, *tmp;
+ struct perf_hpp_fmt *fmt, *acc, *ovh, *acc_lat, *tmp;
if (is_strict_order(field_order))
return;
ovh = &perf_hpp__format[PERF_HPP__OVERHEAD];
acc = &perf_hpp__format[PERF_HPP__OVERHEAD_ACC];
+ acc_lat = &perf_hpp__format[PERF_HPP__LATENCY_ACC];
perf_hpp_list__for_each_format_safe(&perf_hpp_list, fmt, tmp) {
- if (acc->equal(acc, fmt)) {
+ if (fmt_equal(acc, fmt) || fmt_equal(acc_lat, fmt)) {
perf_hpp__column_unregister(fmt);
continue;
}
- if (ovh->equal(ovh, fmt))
+ if (fmt_equal(ovh, fmt))
fmt->name = "Overhead";
}
}
-static bool fmt_equal(struct perf_hpp_fmt *a, struct perf_hpp_fmt *b)
-{
- return a->equal && a->equal(a, b);
-}
-
void perf_hpp__setup_output_field(struct perf_hpp_list *list)
{
struct perf_hpp_fmt *fmt;
@@ -819,6 +825,7 @@ void perf_hpp__reset_width(struct perf_hpp_fmt *fmt, struct hists *hists)
switch (fmt->idx) {
case PERF_HPP__OVERHEAD:
+ case PERF_HPP__LATENCY:
case PERF_HPP__OVERHEAD_SYS:
case PERF_HPP__OVERHEAD_US:
case PERF_HPP__OVERHEAD_ACC:
diff --git a/tools/perf/util/addr_location.h b/tools/perf/util/addr_location.h
index f83d74e370b2f..663e9a55d8ed3 100644
--- a/tools/perf/util/addr_location.h
+++ b/tools/perf/util/addr_location.h
@@ -24,6 +24,8 @@ struct addr_location {
s32 socket;
/* Same as machine.parallelism but within [1, nr_cpus]. */
int parallelism;
+ /* See he_stat.latency. */
+ u64 latency;
};
void addr_location__init(struct addr_location *al);
diff --git a/tools/perf/util/event.c b/tools/perf/util/event.c
index bea9698e0c6bf..36e576f141473 100644
--- a/tools/perf/util/event.c
+++ b/tools/perf/util/event.c
@@ -771,6 +771,12 @@ int machine__resolve(struct machine *machine, struct addr_location *al,
al->parallelism = min(max(machine->parallelism, 1), machine__nr_cpus_avail(machine));
if (test_bit(al->parallelism, symbol_conf.parallelism_filter))
al->filtered |= (1 << HIST_FILTER__PARALLELISM);
+ /*
+ * Multiply it by some const to avoid precision loss or dealing
+ * with floats. The multiplier does not matter otherwise since
+ * we only print it as percents.
+ */
+ al->latency = sample->period * 1000 / al->parallelism;
if (al->map) {
if (symbol_conf.dso_list &&
diff --git a/tools/perf/util/events_stats.h b/tools/perf/util/events_stats.h
index eabd7913c3092..dcff697ed2529 100644
--- a/tools/perf/util/events_stats.h
+++ b/tools/perf/util/events_stats.h
@@ -57,6 +57,8 @@ struct events_stats {
struct hists_stats {
u64 total_period;
u64 total_non_filtered_period;
+ u64 total_latency;
+ u64 total_non_filtered_latency;
u32 nr_samples;
u32 nr_non_filtered_samples;
u32 nr_lost_samples;
diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index 446342246f5ee..a29324e33ed04 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -305,9 +305,10 @@ static long hist_time(unsigned long htime)
return htime;
}
-static void he_stat__add_period(struct he_stat *he_stat, u64 period)
+static void he_stat__add_period(struct he_stat *he_stat, u64 period, u64 latency)
{
he_stat->period += period;
+ he_stat->latency += latency;
he_stat->nr_events += 1;
}
@@ -322,6 +323,7 @@ static void he_stat__add_stat(struct he_stat *dest, struct he_stat *src)
dest->weight2 += src->weight2;
dest->weight3 += src->weight3;
dest->nr_events += src->nr_events;
+ dest->latency += src->latency;
}
static void he_stat__decay(struct he_stat *he_stat)
@@ -331,6 +333,7 @@ static void he_stat__decay(struct he_stat *he_stat)
he_stat->weight1 = (he_stat->weight1 * 7) / 8;
he_stat->weight2 = (he_stat->weight2 * 7) / 8;
he_stat->weight3 = (he_stat->weight3 * 7) / 8;
+ he_stat->latency = (he_stat->latency * 7) / 8;
}
static void hists__delete_entry(struct hists *hists, struct hist_entry *he);
@@ -338,7 +341,7 @@ static void hists__delete_entry(struct hists *hists, struct hist_entry *he);
static bool hists__decay_entry(struct hists *hists, struct hist_entry *he)
{
u64 prev_period = he->stat.period;
- u64 diff;
+ u64 prev_latency = he->stat.latency;
if (prev_period == 0)
return true;
@@ -348,12 +351,16 @@ static bool hists__decay_entry(struct hists *hists, struct hist_entry *he)
he_stat__decay(he->stat_acc);
decay_callchain(he->callchain);
- diff = prev_period - he->stat.period;
-
if (!he->depth) {
- hists->stats.total_period -= diff;
- if (!he->filtered)
- hists->stats.total_non_filtered_period -= diff;
+ u64 period_diff = prev_period - he->stat.period;
+ u64 latency_diff = prev_latency - he->stat.latency;
+
+ hists->stats.total_period -= period_diff;
+ hists->stats.total_latency -= latency_diff;
+ if (!he->filtered) {
+ hists->stats.total_non_filtered_period -= period_diff;
+ hists->stats.total_non_filtered_latency -= latency_diff;
+ }
}
if (!he->leaf) {
@@ -368,7 +375,7 @@ static bool hists__decay_entry(struct hists *hists, struct hist_entry *he)
}
}
- return he->stat.period == 0;
+ return he->stat.period == 0 && he->stat.latency == 0;
}
static void hists__delete_entry(struct hists *hists, struct hist_entry *he)
@@ -594,14 +601,17 @@ static filter_mask_t symbol__parent_filter(const struct symbol *parent)
return 0;
}
-static void hist_entry__add_callchain_period(struct hist_entry *he, u64 period)
+static void hist_entry__add_callchain_period(struct hist_entry *he, u64 period, u64 latency)
{
if (!hist_entry__has_callchains(he) || !symbol_conf.use_callchain)
return;
he->hists->callchain_period += period;
- if (!he->filtered)
+ he->hists->callchain_latency += latency;
+ if (!he->filtered) {
he->hists->callchain_non_filtered_period += period;
+ he->hists->callchain_non_filtered_latency += latency;
+ }
}
static struct hist_entry *hists__findnew_entry(struct hists *hists,
@@ -614,6 +624,7 @@ static struct hist_entry *hists__findnew_entry(struct hists *hists,
struct hist_entry *he;
int64_t cmp;
u64 period = entry->stat.period;
+ u64 latency = entry->stat.latency;
bool leftmost = true;
p = &hists->entries_in->rb_root.rb_node;
@@ -632,10 +643,10 @@ static struct hist_entry *hists__findnew_entry(struct hists *hists,
if (!cmp) {
if (sample_self) {
he_stat__add_stat(&he->stat, &entry->stat);
- hist_entry__add_callchain_period(he, period);
+ hist_entry__add_callchain_period(he, period, latency);
}
if (symbol_conf.cumulate_callchain)
- he_stat__add_period(he->stat_acc, period);
+ he_stat__add_period(he->stat_acc, period, latency);
block_info__delete(entry->block_info);
@@ -672,7 +683,7 @@ static struct hist_entry *hists__findnew_entry(struct hists *hists,
return NULL;
if (sample_self)
- hist_entry__add_callchain_period(he, period);
+ hist_entry__add_callchain_period(he, period, latency);
hists->nr_entries++;
rb_link_node(&he->rb_node_in, parent, p);
@@ -751,6 +762,7 @@ __hists__add_entry(struct hists *hists,
.weight1 = sample->weight,
.weight2 = sample->ins_lat,
.weight3 = sample->p_stage_cyc,
+ .latency = al->latency,
},
.parent = sym_parent,
.filtered = symbol__parent_filter(sym_parent) | al->filtered,
@@ -1768,12 +1780,14 @@ static void hists__reset_filter_stats(struct hists *hists)
{
hists->nr_non_filtered_entries = 0;
hists->stats.total_non_filtered_period = 0;
+ hists->stats.total_non_filtered_latency = 0;
}
void hists__reset_stats(struct hists *hists)
{
hists->nr_entries = 0;
hists->stats.total_period = 0;
+ hists->stats.total_latency = 0;
hists__reset_filter_stats(hists);
}
@@ -1782,6 +1796,7 @@ static void hists__inc_filter_stats(struct hists *hists, struct hist_entry *h)
{
hists->nr_non_filtered_entries++;
hists->stats.total_non_filtered_period += h->stat.period;
+ hists->stats.total_non_filtered_latency += h->stat.latency;
}
void hists__inc_stats(struct hists *hists, struct hist_entry *h)
@@ -1791,6 +1806,7 @@ void hists__inc_stats(struct hists *hists, struct hist_entry *h)
hists->nr_entries++;
hists->stats.total_period += h->stat.period;
+ hists->stats.total_latency += h->stat.latency;
}
static void hierarchy_recalc_total_periods(struct hists *hists)
@@ -1802,6 +1818,8 @@ static void hierarchy_recalc_total_periods(struct hists *hists)
hists->stats.total_period = 0;
hists->stats.total_non_filtered_period = 0;
+ hists->stats.total_latency = 0;
+ hists->stats.total_non_filtered_latency = 0;
/*
* recalculate total period using top-level entries only
@@ -1813,8 +1831,11 @@ static void hierarchy_recalc_total_periods(struct hists *hists)
node = rb_next(node);
hists->stats.total_period += he->stat.period;
- if (!he->filtered)
+ hists->stats.total_latency += he->stat.latency;
+ if (!he->filtered) {
hists->stats.total_non_filtered_period += he->stat.period;
+ hists->stats.total_non_filtered_latency += he->stat.latency;
+ }
}
}
@@ -2791,6 +2812,12 @@ u64 hists__total_period(struct hists *hists)
hists->stats.total_period;
}
+u64 hists__total_latency(struct hists *hists)
+{
+ return symbol_conf.filter_relative ? hists->stats.total_non_filtered_latency :
+ hists->stats.total_latency;
+}
+
int __hists__scnprintf_title(struct hists *hists, char *bf, size_t size, bool show_freq)
{
char unit;
diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
index c2236e0d89f2a..91159f16c60b2 100644
--- a/tools/perf/util/hist.h
+++ b/tools/perf/util/hist.h
@@ -109,6 +109,8 @@ struct hists {
u64 nr_non_filtered_entries;
u64 callchain_period;
u64 callchain_non_filtered_period;
+ u64 callchain_latency;
+ u64 callchain_non_filtered_latency;
struct thread *thread_filter;
const struct dso *dso_filter;
const char *uid_filter_str;
@@ -170,6 +172,12 @@ struct res_sample {
struct he_stat {
u64 period;
+ /*
+ * Period re-scaled from CPU time to wall-clock time (divided by the
+ * parallelism at the time of the sample). This represents effect of
+ * the event on latency rather than CPU consumption.
+ */
+ u64 latency;
u64 period_sys;
u64 period_us;
u64 period_guest_sys;
@@ -374,6 +382,7 @@ void hists__output_recalc_col_len(struct hists *hists, int max_rows);
struct hist_entry *hists__get_entry(struct hists *hists, int idx);
u64 hists__total_period(struct hists *hists);
+u64 hists__total_latency(struct hists *hists);
void hists__reset_stats(struct hists *hists);
void hists__inc_stats(struct hists *hists, struct hist_entry *h);
void hists__inc_nr_events(struct hists *hists);
@@ -555,11 +564,13 @@ extern struct perf_hpp_fmt perf_hpp__format[];
enum {
/* Matches perf_hpp__format array. */
PERF_HPP__OVERHEAD,
+ PERF_HPP__LATENCY,
PERF_HPP__OVERHEAD_SYS,
PERF_HPP__OVERHEAD_US,
PERF_HPP__OVERHEAD_GUEST_SYS,
PERF_HPP__OVERHEAD_GUEST_US,
PERF_HPP__OVERHEAD_ACC,
+ PERF_HPP__LATENCY_ACC,
PERF_HPP__SAMPLES,
PERF_HPP__PERIOD,
PERF_HPP__WEIGHT1,
@@ -615,6 +626,7 @@ void hists__reset_column_width(struct hists *hists);
enum perf_hpp_fmt_type {
PERF_HPP_FMT_TYPE__RAW,
PERF_HPP_FMT_TYPE__PERCENT,
+ PERF_HPP_FMT_TYPE__LATENCY,
PERF_HPP_FMT_TYPE__AVERAGE,
};
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index 3055496358ebb..bc4c3acfe7552 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -2628,11 +2628,13 @@ struct hpp_dimension {
static struct hpp_dimension hpp_sort_dimensions[] = {
DIM(PERF_HPP__OVERHEAD, "overhead"),
+ DIM(PERF_HPP__LATENCY, "latency"),
DIM(PERF_HPP__OVERHEAD_SYS, "overhead_sys"),
DIM(PERF_HPP__OVERHEAD_US, "overhead_us"),
DIM(PERF_HPP__OVERHEAD_GUEST_SYS, "overhead_guest_sys"),
DIM(PERF_HPP__OVERHEAD_GUEST_US, "overhead_guest_us"),
DIM(PERF_HPP__OVERHEAD_ACC, "overhead_children"),
+ DIM(PERF_HPP__LATENCY_ACC, "latency_children"),
DIM(PERF_HPP__SAMPLES, "sample"),
DIM(PERF_HPP__PERIOD, "period"),
DIM(PERF_HPP__WEIGHT1, "weight1"),
--
2.48.1.262.g85cc9f2d1e-goog
^ permalink raw reply related [flat|nested] 20+ messages in thread
* [PATCH v3 6/7] perf report: Add --latency flag
2025-01-27 9:58 [PATCH v3 0/7] perf report: Add latency and parallelism profiling Dmitry Vyukov
` (4 preceding siblings ...)
2025-01-27 9:58 ` [PATCH v3 5/7] perf report: Add latency output field Dmitry Vyukov
@ 2025-01-27 9:58 ` Dmitry Vyukov
2025-01-29 5:03 ` Namhyung Kim
2025-01-27 9:58 ` [PATCH v3 7/7] perf report: Add latency and parallelism profiling documentation Dmitry Vyukov
2025-01-29 5:05 ` [PATCH v3 0/7] perf report: Add latency and parallelism profiling Namhyung Kim
7 siblings, 1 reply; 20+ messages in thread
From: Dmitry Vyukov @ 2025-01-27 9:58 UTC (permalink / raw)
To: namhyung, irogers
Cc: linux-perf-users, linux-kernel, Dmitry Vyukov,
Arnaldo Carvalho de Melo
Add record/report --latency flag that allows to capture and show
latency-centric profiles rather than the default CPU-consumption-centric
profiles. For latency profiles record captures context switch events,
and report shows Latency as the first column.
Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
Cc: Ian Rogers <irogers@google.com>
Cc: linux-perf-users@vger.kernel.org
Cc: linux-kernel@vger.kernel.org
---
tools/perf/builtin-record.c | 20 +++++++++++++++++
tools/perf/builtin-report.c | 32 +++++++++++++++++++++++----
tools/perf/ui/hist.c | 41 ++++++++++++++++++++++++++++-------
tools/perf/util/hist.h | 1 +
tools/perf/util/sort.c | 33 +++++++++++++++++++++++-----
tools/perf/util/sort.h | 2 +-
tools/perf/util/symbol_conf.h | 4 +++-
7 files changed, 113 insertions(+), 20 deletions(-)
diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index 5db1aedf48df9..e219639ac401b 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -161,6 +161,7 @@ struct record {
struct evlist *sb_evlist;
pthread_t thread_id;
int realtime_prio;
+ bool latency;
bool switch_output_event_set;
bool no_buildid;
bool no_buildid_set;
@@ -3371,6 +3372,9 @@ static struct option __record_options[] = {
parse_events_option),
OPT_CALLBACK(0, "filter", &record.evlist, "filter",
"event filter", parse_filter),
+ OPT_BOOLEAN(0, "latency", &record.latency,
+ "Enable data collection for latency profiling.\n"
+ "\t\t\t Use perf report --latency for latency-centric profile."),
OPT_CALLBACK_NOOPT(0, "exclude-perf", &record.evlist,
NULL, "don't record events from perf itself",
exclude_perf),
@@ -4017,6 +4021,22 @@ int cmd_record(int argc, const char **argv)
}
+ if (record.latency) {
+ /*
+ * There is no fundamental reason why latency profiling
+ * can't work for system-wide mode, but exact semantics
+ * and details are to be defined.
+ * See the following thread for details:
+ * https://lore.kernel.org/all/Z4XDJyvjiie3howF@google.com/
+ */
+ if (record.opts.target.system_wide) {
+ pr_err("Failed: latency profiling is not supported with system-wide collection.\n");
+ err = -EINVAL;
+ goto out_opts;
+ }
+ record.opts.record_switch_events = true;
+ }
+
if (rec->buildid_mmap) {
if (!perf_can_record_build_id()) {
pr_err("Failed: no support to record build id in mmap events, update your kernel.\n");
diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
index 2a19abdc869a1..69de6dbefecfa 100644
--- a/tools/perf/builtin-report.c
+++ b/tools/perf/builtin-report.c
@@ -112,6 +112,8 @@ struct report {
u64 nr_entries;
u64 queue_size;
u64 total_cycles;
+ u64 total_samples;
+ u64 singlethreaded_samples;
int socket_filter;
DECLARE_BITMAP(cpu_bitmap, MAX_NR_CPUS);
struct branch_type_stat brtype_stat;
@@ -331,6 +333,10 @@ static int process_sample_event(const struct perf_tool *tool,
&rep->total_cycles, evsel);
}
+ rep->total_samples++;
+ if (al.parallelism == 1)
+ rep->singlethreaded_samples++;
+
ret = hist_entry_iter__add(&iter, &al, rep->max_stack, rep);
if (ret < 0)
pr_debug("problem adding hist entry, skipping event\n");
@@ -1079,6 +1085,11 @@ static int __cmd_report(struct report *rep)
return ret;
}
+ /* Don't show Latency column for non-parallel profiles by default. */
+ if (rep->singlethreaded_samples * 100 / rep->total_samples >= 99 &&
+ !symbol_conf.prefer_latency)
+ perf_hpp__cancel_latency();
+
evlist__check_mem_load_aux(session->evlist);
if (rep->stats_mode)
@@ -1468,6 +1479,10 @@ int cmd_report(int argc, const char **argv)
"Disable raw trace ordering"),
OPT_BOOLEAN(0, "skip-empty", &report.skip_empty,
"Do not display empty (or dummy) events in the output"),
+ OPT_BOOLEAN(0, "latency", &symbol_conf.prefer_latency,
+ "Show latency-centric profile rather than the default\n"
+ "\t\t\t CPU-consumption-centric profile\n"
+ "\t\t\t (requires perf record --latency flag)."),
OPT_END()
};
struct perf_data data = {
@@ -1722,16 +1737,25 @@ int cmd_report(int argc, const char **argv)
symbol_conf.annotate_data_sample = true;
}
+ symbol_conf.enable_latency = true;
if (report.disable_order || !perf_session__has_switch_events(session)) {
if (symbol_conf.parallelism_list_str ||
- (sort_order && strstr(sort_order, "parallelism")) ||
- (field_order && strstr(field_order, "parallelism"))) {
+ symbol_conf.prefer_latency ||
+ (sort_order && (strstr(sort_order, "latency") ||
+ strstr(sort_order, "parallelism"))) ||
+ (field_order && (strstr(field_order, "latency") ||
+ strstr(field_order, "parallelism")))) {
if (report.disable_order)
- ui__error("Use of parallelism is incompatible with --disable-order.\n");
+ ui__error("Use of latency profile or parallelism is incompatible with --disable-order.\n");
else
- ui__error("Use of parallelism requires --switch-events during record.\n");
+ ui__error("Use of latency profile or parallelism requires --latency flag during record.\n");
return -1;
}
+ /*
+ * If user did not ask for anything related to
+ * latency/parallelism explicitly, just don't show it.
+ */
+ symbol_conf.enable_latency = false;
}
if (sort_order && strstr(sort_order, "ipc")) {
diff --git a/tools/perf/ui/hist.c b/tools/perf/ui/hist.c
index 22e31d835301e..d87046052b432 100644
--- a/tools/perf/ui/hist.c
+++ b/tools/perf/ui/hist.c
@@ -632,27 +632,36 @@ void perf_hpp__init(void)
return;
if (symbol_conf.cumulate_callchain) {
- hpp_dimension__add_output(PERF_HPP__OVERHEAD_ACC);
+ /* Use idempotent addition to avoid more complex logic. */
+ if (symbol_conf.prefer_latency)
+ hpp_dimension__add_output(PERF_HPP__LATENCY_ACC, true);
+ hpp_dimension__add_output(PERF_HPP__OVERHEAD_ACC, true);
+ if (symbol_conf.enable_latency)
+ hpp_dimension__add_output(PERF_HPP__LATENCY_ACC, true);
perf_hpp__format[PERF_HPP__OVERHEAD].name = "Self";
}
- hpp_dimension__add_output(PERF_HPP__OVERHEAD);
+ if (symbol_conf.prefer_latency)
+ hpp_dimension__add_output(PERF_HPP__LATENCY, true);
+ hpp_dimension__add_output(PERF_HPP__OVERHEAD, true);
+ if (symbol_conf.enable_latency)
+ hpp_dimension__add_output(PERF_HPP__LATENCY, true);
if (symbol_conf.show_cpu_utilization) {
- hpp_dimension__add_output(PERF_HPP__OVERHEAD_SYS);
- hpp_dimension__add_output(PERF_HPP__OVERHEAD_US);
+ hpp_dimension__add_output(PERF_HPP__OVERHEAD_SYS, false);
+ hpp_dimension__add_output(PERF_HPP__OVERHEAD_US, false);
if (perf_guest) {
- hpp_dimension__add_output(PERF_HPP__OVERHEAD_GUEST_SYS);
- hpp_dimension__add_output(PERF_HPP__OVERHEAD_GUEST_US);
+ hpp_dimension__add_output(PERF_HPP__OVERHEAD_GUEST_SYS, false);
+ hpp_dimension__add_output(PERF_HPP__OVERHEAD_GUEST_US, false);
}
}
if (symbol_conf.show_nr_samples)
- hpp_dimension__add_output(PERF_HPP__SAMPLES);
+ hpp_dimension__add_output(PERF_HPP__SAMPLES, false);
if (symbol_conf.show_total_period)
- hpp_dimension__add_output(PERF_HPP__PERIOD);
+ hpp_dimension__add_output(PERF_HPP__PERIOD, false);
}
void perf_hpp_list__column_register(struct perf_hpp_list *list,
@@ -701,6 +710,22 @@ void perf_hpp__cancel_cumulate(void)
}
}
+void perf_hpp__cancel_latency(void)
+{
+ struct perf_hpp_fmt *fmt, *lat, *acc, *tmp;
+
+ if (is_strict_order(field_order) || is_strict_order(sort_order))
+ return;
+
+ lat = &perf_hpp__format[PERF_HPP__LATENCY];
+ acc = &perf_hpp__format[PERF_HPP__LATENCY_ACC];
+
+ perf_hpp_list__for_each_format_safe(&perf_hpp_list, fmt, tmp) {
+ if (fmt_equal(lat, fmt) || fmt_equal(acc, fmt))
+ perf_hpp__column_unregister(fmt);
+ }
+}
+
void perf_hpp__setup_output_field(struct perf_hpp_list *list)
{
struct perf_hpp_fmt *fmt;
diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
index 91159f16c60b2..29d4c7a3d1747 100644
--- a/tools/perf/util/hist.h
+++ b/tools/perf/util/hist.h
@@ -582,6 +582,7 @@ enum {
void perf_hpp__init(void);
void perf_hpp__cancel_cumulate(void);
+void perf_hpp__cancel_latency(void);
void perf_hpp__setup_output_field(struct perf_hpp_list *list);
void perf_hpp__reset_output_field(struct perf_hpp_list *list);
void perf_hpp__append_sort_keys(struct perf_hpp_list *list);
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index bc4c3acfe7552..2b6023de7a53a 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -2622,6 +2622,7 @@ struct hpp_dimension {
const char *name;
struct perf_hpp_fmt *fmt;
int taken;
+ int was_taken;
};
#define DIM(d, n) { .name = n, .fmt = &perf_hpp__format[d], }
@@ -3513,6 +3514,7 @@ static int __hpp_dimension__add(struct hpp_dimension *hd,
return -1;
hd->taken = 1;
+ hd->was_taken = 1;
perf_hpp_list__register_sort_field(list, fmt);
return 0;
}
@@ -3547,10 +3549,15 @@ static int __hpp_dimension__add_output(struct perf_hpp_list *list,
return 0;
}
-int hpp_dimension__add_output(unsigned col)
+int hpp_dimension__add_output(unsigned col, bool implicit)
{
+ struct hpp_dimension *hd;
+
BUG_ON(col >= PERF_HPP__MAX_INDEX);
- return __hpp_dimension__add_output(&perf_hpp_list, &hpp_sort_dimensions[col]);
+ hd = &hpp_sort_dimensions[col];
+ if (implicit && !hd->was_taken)
+ return 0;
+ return __hpp_dimension__add_output(&perf_hpp_list, hd);
}
int sort_dimension__add(struct perf_hpp_list *list, const char *tok,
@@ -3809,10 +3816,24 @@ static char *setup_overhead(char *keys)
if (sort__mode == SORT_MODE__DIFF)
return keys;
- keys = prefix_if_not_in("overhead", keys);
-
- if (symbol_conf.cumulate_callchain)
- keys = prefix_if_not_in("overhead_children", keys);
+ if (symbol_conf.prefer_latency) {
+ keys = prefix_if_not_in("overhead", keys);
+ keys = prefix_if_not_in("latency", keys);
+ if (symbol_conf.cumulate_callchain) {
+ keys = prefix_if_not_in("overhead_children", keys);
+ keys = prefix_if_not_in("latency_children", keys);
+ }
+ } else if (!keys || (!strstr(keys, "overhead") &&
+ !strstr(keys, "latency"))) {
+ if (symbol_conf.enable_latency)
+ keys = prefix_if_not_in("latency", keys);
+ keys = prefix_if_not_in("overhead", keys);
+ if (symbol_conf.cumulate_callchain) {
+ if (symbol_conf.enable_latency)
+ keys = prefix_if_not_in("latency_children", keys);
+ keys = prefix_if_not_in("overhead_children", keys);
+ }
+ }
return keys;
}
diff --git a/tools/perf/util/sort.h b/tools/perf/util/sort.h
index 11fb15f914093..180d36a2bea35 100644
--- a/tools/perf/util/sort.h
+++ b/tools/perf/util/sort.h
@@ -141,7 +141,7 @@ int report_parse_ignore_callees_opt(const struct option *opt, const char *arg, i
bool is_strict_order(const char *order);
-int hpp_dimension__add_output(unsigned col);
+int hpp_dimension__add_output(unsigned col, bool implicit);
void reset_dimensions(void);
int sort_dimension__add(struct perf_hpp_list *list, const char *tok,
struct evlist *evlist,
diff --git a/tools/perf/util/symbol_conf.h b/tools/perf/util/symbol_conf.h
index c5b2e56127e22..cd9aa82c7d5ad 100644
--- a/tools/perf/util/symbol_conf.h
+++ b/tools/perf/util/symbol_conf.h
@@ -49,7 +49,9 @@ struct symbol_conf {
keep_exited_threads,
annotate_data_member,
annotate_data_sample,
- skip_empty;
+ skip_empty,
+ enable_latency,
+ prefer_latency;
const char *vmlinux_name,
*kallsyms_name,
*source_prefix,
--
2.48.1.262.g85cc9f2d1e-goog
^ permalink raw reply related [flat|nested] 20+ messages in thread
* [PATCH v3 7/7] perf report: Add latency and parallelism profiling documentation
2025-01-27 9:58 [PATCH v3 0/7] perf report: Add latency and parallelism profiling Dmitry Vyukov
` (5 preceding siblings ...)
2025-01-27 9:58 ` [PATCH v3 6/7] perf report: Add --latency flag Dmitry Vyukov
@ 2025-01-27 9:58 ` Dmitry Vyukov
2025-01-29 5:05 ` [PATCH v3 0/7] perf report: Add latency and parallelism profiling Namhyung Kim
7 siblings, 0 replies; 20+ messages in thread
From: Dmitry Vyukov @ 2025-01-27 9:58 UTC (permalink / raw)
To: namhyung, irogers
Cc: linux-perf-users, linux-kernel, Dmitry Vyukov,
Arnaldo Carvalho de Melo
Describe latency and parallelism profiling, related flags, and differences
with the currently only supported CPU-consumption-centric profiling.
Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
Cc: Ian Rogers <irogers@google.com>
Cc: linux-perf-users@vger.kernel.org
Cc: linux-kernel@vger.kernel.org
---
.../callchain-overhead-calculation.txt | 5 +-
.../cpu-and-latency-overheads.txt | 85 +++++++++++++++++++
tools/perf/Documentation/perf-report.txt | 49 +++++++----
tools/perf/Documentation/tips.txt | 3 +
4 files changed, 123 insertions(+), 19 deletions(-)
diff --git a/tools/perf/Documentation/callchain-overhead-calculation.txt b/tools/perf/Documentation/callchain-overhead-calculation.txt
index 1a757927195ed..e0202bf5bd1a0 100644
--- a/tools/perf/Documentation/callchain-overhead-calculation.txt
+++ b/tools/perf/Documentation/callchain-overhead-calculation.txt
@@ -1,7 +1,8 @@
Overhead calculation
--------------------
-The overhead can be shown in two columns as 'Children' and 'Self' when
-perf collects callchains. The 'self' overhead is simply calculated by
+The CPU overhead can be shown in two columns as 'Children' and 'Self'
+when perf collects callchains (and corresponding 'Wall' columns for
+wall-clock overhead). The 'self' overhead is simply calculated by
adding all period values of the entry - usually a function (symbol).
This is the value that perf shows traditionally and sum of all the
'self' overhead values should be 100%.
diff --git a/tools/perf/Documentation/cpu-and-latency-overheads.txt b/tools/perf/Documentation/cpu-and-latency-overheads.txt
new file mode 100644
index 0000000000000..3b6d637054651
--- /dev/null
+++ b/tools/perf/Documentation/cpu-and-latency-overheads.txt
@@ -0,0 +1,85 @@
+CPU and latency overheads
+-------------------------
+There are two notions of time: wall-clock time and CPU time.
+For a single-threaded program, or a program running on a single-core machine,
+these notions are the same. However, for a multi-threaded/multi-process program
+running on a multi-core machine, these notions are significantly different.
+Each second of wall-clock time we have number-of-cores seconds of CPU time.
+Perf can measure overhead for both of these times (shown in 'overhead' and
+'latency' columns for CPU and wall-clock time correspondingly).
+
+Optimizing CPU overhead is useful to improve 'throughput', while optimizing
+latency overhead is useful to improve 'latency'. It's important to understand
+which one is useful in a concrete situation at hand. For example, the former
+may be useful to improve max throughput of a CI build server that runs on 100%
+CPU utilization, while the latter may be useful to improve user-perceived
+latency of a single interactive program build.
+These overheads may be significantly different in some cases. For example,
+consider a program that executes function 'foo' for 9 seconds with 1 thread,
+and then executes function 'bar' for 1 second with 128 threads (consumes
+128 seconds of CPU time). The CPU overhead is: 'foo' - 6.6%, 'bar' - 93.4%.
+While the latency overhead is: 'foo' - 90%, 'bar' - 10%. If we try to optimize
+running time of the program looking at the (wrong in this case) CPU overhead,
+we would concentrate on the function 'bar', but it can yield only 10% running
+time improvement at best.
+
+By default, perf shows only CPU overhead. To show latency overhead, use
+'perf record --latency' and 'perf report':
+
+-----------------------------------
+Overhead Latency Command
+ 93.88% 25.79% cc1
+ 1.90% 39.87% gzip
+ 0.99% 10.16% dpkg-deb
+ 0.57% 1.00% as
+ 0.40% 0.46% sh
+-----------------------------------
+
+To sort by latency overhead, use 'perf report --latency':
+
+-----------------------------------
+Latency Overhead Command
+ 39.87% 1.90% gzip
+ 25.79% 93.88% cc1
+ 10.16% 0.99% dpkg-deb
+ 4.17% 0.29% git
+ 2.81% 0.11% objtool
+-----------------------------------
+
+To get insight into the difference between the overheads, you may check
+parallelization histogram with '--sort=latency,parallelism,comm,symbol --hierarchy'
+flags. It shows fraction of (wall-clock) time the workload utilizes different
+numbers of cores ('Parallelism' column). For example, in the following case
+the workload utilizes only 1 core most of the time, but also has some
+highly-parallel phases, which explains significant difference between
+CPU and wall-clock overheads:
+
+-----------------------------------
+ Latency Overhead Parallelism / Command / Symbol
++ 56.98% 2.29% 1
++ 16.94% 1.36% 2
++ 4.00% 20.13% 125
++ 3.66% 18.25% 124
++ 3.48% 17.66% 126
++ 3.26% 0.39% 3
++ 2.61% 12.93% 123
+-----------------------------------
+
+By expanding corresponding lines, you may see what commands/functions run
+at the given parallelism level:
+
+-----------------------------------
+ Latency Overhead Parallelism / Command / Symbol
+- 56.98% 2.29% 1
+ 32.80% 1.32% gzip
+ 4.46% 0.18% cc1
+ 2.81% 0.11% objtool
+ 2.43% 0.10% dpkg-source
+ 2.22% 0.09% ld
+ 2.10% 0.08% dpkg-genchanges
+-----------------------------------
+
+To see the normal function-level profile for particular parallelism levels
+(number of threads actively running on CPUs), you may use '--parallelism'
+filter. For example, to see the profile only for low parallelism phases
+of a workload use '--latency --parallelism=1-2' flags.
diff --git a/tools/perf/Documentation/perf-report.txt b/tools/perf/Documentation/perf-report.txt
index 87f8645194062..7e0ba990d71e8 100644
--- a/tools/perf/Documentation/perf-report.txt
+++ b/tools/perf/Documentation/perf-report.txt
@@ -44,7 +44,7 @@ OPTIONS
--comms=::
Only consider symbols in these comms. CSV that understands
file://filename entries. This option will affect the percentage of
- the overhead column. See --percentage for more info.
+ the overhead and latency columns. See --percentage for more info.
--pid=::
Only show events for given process ID (comma separated list).
@@ -54,12 +54,12 @@ OPTIONS
--dsos=::
Only consider symbols in these dsos. CSV that understands
file://filename entries. This option will affect the percentage of
- the overhead column. See --percentage for more info.
+ the overhead and latency columns. See --percentage for more info.
-S::
--symbols=::
Only consider these symbols. CSV that understands
file://filename entries. This option will affect the percentage of
- the overhead column. See --percentage for more info.
+ the overhead and latency columns. See --percentage for more info.
--symbol-filter=::
Only show symbols that match (partially) with this filter.
@@ -68,6 +68,16 @@ OPTIONS
--hide-unresolved::
Only display entries resolved to a symbol.
+--parallelism::
+ Only consider these parallelism levels. Parallelism level is the number
+ of threads that actively run on CPUs at the time of sample. The flag
+ accepts single number, comma-separated list, and ranges (for example:
+ "1", "7,8", "1,64-128"). This is useful in understanding what a program
+ is doing during sequential/low-parallelism phases as compared to
+ high-parallelism phases. This option will affect the percentage of
+ the overhead and latency columns. See --percentage for more info.
+ Also see the `CPU and latency overheads' section for more details.
+
-s::
--sort=::
Sort histogram entries by given key(s) - multiple keys can be specified
@@ -87,6 +97,7 @@ OPTIONS
entries are displayed as "[other]".
- cpu: cpu number the task ran at the time of sample
- socket: processor socket number the task ran at the time of sample
+ - parallelism: number of running threads at the time of sample
- srcline: filename and line number executed at the time of sample. The
DWARF debugging info must be provided.
- srcfile: file name of the source file of the samples. Requires dwarf
@@ -97,12 +108,14 @@ OPTIONS
- cgroup_id: ID derived from cgroup namespace device and inode numbers.
- cgroup: cgroup pathname in the cgroupfs.
- transaction: Transaction abort flags.
- - overhead: Overhead percentage of sample
- - overhead_sys: Overhead percentage of sample running in system mode
- - overhead_us: Overhead percentage of sample running in user mode
- - overhead_guest_sys: Overhead percentage of sample running in system mode
+ - overhead: CPU overhead percentage of sample.
+ - latency: latency (wall-clock) overhead percentage of sample.
+ See the `CPU and latency overheads' section for more details.
+ - overhead_sys: CPU overhead percentage of sample running in system mode
+ - overhead_us: CPU overhead percentage of sample running in user mode
+ - overhead_guest_sys: CPU overhead percentage of sample running in system mode
on guest machine
- - overhead_guest_us: Overhead percentage of sample running in user mode on
+ - overhead_guest_us: CPU overhead percentage of sample running in user mode on
guest machine
- sample: Number of sample
- period: Raw number of event count of sample
@@ -125,8 +138,8 @@ OPTIONS
- weight2: Average value of event specific weight (2nd field of weight_struct).
- weight3: Average value of event specific weight (3rd field of weight_struct).
- By default, comm, dso and symbol keys are used.
- (i.e. --sort comm,dso,symbol)
+ By default, overhead, comm, dso and symbol keys are used.
+ (i.e. --sort overhead,comm,dso,symbol).
If --branch-stack option is used, following sort keys are also
available:
@@ -201,9 +214,9 @@ OPTIONS
--fields=::
Specify output field - multiple keys can be specified in CSV format.
Following fields are available:
- overhead, overhead_sys, overhead_us, overhead_children, sample, period,
- weight1, weight2, weight3, ins_lat, p_stage_cyc and retire_lat. The
- last 3 names are alias for the corresponding weights. When the weight
+ overhead, latency, overhead_sys, overhead_us, overhead_children, sample,
+ period, weight1, weight2, weight3, ins_lat, p_stage_cyc and retire_lat.
+ The last 3 names are alias for the corresponding weights. When the weight
fields are used, they will show the average value of the weight.
Also it can contain any sort key(s).
@@ -289,7 +302,7 @@ OPTIONS
Accumulate callchain of children to parent entry so that then can
show up in the output. The output will have a new "Children" column
and will be sorted on the data. It requires callchains are recorded.
- See the `overhead calculation' section for more details. Enabled by
+ See the `Overhead calculation' section for more details. Enabled by
default, disable with --no-children.
--max-stack::
@@ -442,9 +455,9 @@ OPTIONS
--call-graph option for details.
--percentage::
- Determine how to display the overhead percentage of filtered entries.
- Filters can be applied by --comms, --dsos and/or --symbols options and
- Zoom operations on the TUI (thread, dso, etc).
+ Determine how to display the CPU and latency overhead percentage
+ of filtered entries. Filters can be applied by --comms, --dsos, --symbols
+ and/or --parallelism options and Zoom operations on the TUI (thread, dso, etc).
"relative" means it's relative to filtered entries only so that the
sum of shown entries will be always 100%. "absolute" means it retains
@@ -627,6 +640,8 @@ include::itrace.txt[]
--skip-empty::
Do not print 0 results in the --stat output.
+include::cpu-and-latency-overheads.txt[]
+
include::callchain-overhead-calculation.txt[]
SEE ALSO
diff --git a/tools/perf/Documentation/tips.txt b/tools/perf/Documentation/tips.txt
index 67b326ba00407..f6f71e70ff2cb 100644
--- a/tools/perf/Documentation/tips.txt
+++ b/tools/perf/Documentation/tips.txt
@@ -62,3 +62,6 @@ To show context switches in perf report sample context add --switch-events to pe
To show time in nanoseconds in record/report add --ns
To compare hot regions in two workloads use perf record -b -o file ... ; perf diff --stream file1 file2
To compare scalability of two workload samples use perf diff -c ratio file1 file2
+For latency profiling, try: perf record/report --latency
+For parallelism histogram, try: perf report --hierarchy --sort latency,parallelism,comm,symbol
+To analyze particular parallelism levels, try: perf report --latency --parallelism=32-64
--
2.48.1.262.g85cc9f2d1e-goog
^ permalink raw reply related [flat|nested] 20+ messages in thread
* Re: [PATCH v3 2/7] perf report: Add parallelism sort key
2025-01-27 9:58 ` [PATCH v3 2/7] perf report: Add parallelism sort key Dmitry Vyukov
@ 2025-01-29 4:42 ` Namhyung Kim
2025-01-29 7:18 ` Dmitry Vyukov
0 siblings, 1 reply; 20+ messages in thread
From: Namhyung Kim @ 2025-01-29 4:42 UTC (permalink / raw)
To: Dmitry Vyukov
Cc: irogers, linux-perf-users, linux-kernel, Arnaldo Carvalho de Melo
On Mon, Jan 27, 2025 at 10:58:49AM +0100, Dmitry Vyukov wrote:
> Show parallelism level in profiles if requested by user.
>
> Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
> Cc: Namhyung Kim <namhyung@kernel.org>
> Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
> Cc: Ian Rogers <irogers@google.com>
> Cc: linux-perf-users@vger.kernel.org
> Cc: linux-kernel@vger.kernel.org
> ---
> tools/perf/builtin-report.c | 11 +++++++++++
> tools/perf/util/hist.c | 2 ++
> tools/perf/util/hist.h | 3 +++
> tools/perf/util/session.c | 12 ++++++++++++
> tools/perf/util/session.h | 1 +
> tools/perf/util/sort.c | 23 +++++++++++++++++++++++
> tools/perf/util/sort.h | 1 +
> 7 files changed, 53 insertions(+)
>
> diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
> index 0d9bd090eda71..14d49f0625881 100644
> --- a/tools/perf/builtin-report.c
> +++ b/tools/perf/builtin-report.c
> @@ -1720,6 +1720,17 @@ int cmd_report(int argc, const char **argv)
> symbol_conf.annotate_data_sample = true;
> }
>
> + if (report.disable_order || !perf_session__has_switch_events(session)) {
> + if ((sort_order && strstr(sort_order, "parallelism")) ||
> + (field_order && strstr(field_order, "parallelism"))) {
> + if (report.disable_order)
> + ui__error("Use of parallelism is incompatible with --disable-order.\n");
> + else
> + ui__error("Use of parallelism requires --switch-events during record.\n");
> + return -1;
> + }
> + }
> +
> if (sort_order && strstr(sort_order, "ipc")) {
> parse_options_usage(report_usage, options, "s", 1);
> goto error;
> diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
> index 0f30f843c566d..cafd693568189 100644
> --- a/tools/perf/util/hist.c
> +++ b/tools/perf/util/hist.c
> @@ -207,6 +207,7 @@ void hists__calc_col_len(struct hists *hists, struct hist_entry *h)
>
> hists__new_col_len(hists, HISTC_CGROUP, 6);
> hists__new_col_len(hists, HISTC_CGROUP_ID, 20);
> + hists__new_col_len(hists, HISTC_PARALLELISM, 11);
> hists__new_col_len(hists, HISTC_CPU, 3);
> hists__new_col_len(hists, HISTC_SOCKET, 6);
> hists__new_col_len(hists, HISTC_MEM_LOCKED, 6);
> @@ -741,6 +742,7 @@ __hists__add_entry(struct hists *hists,
> .ip = al->addr,
> .level = al->level,
> .code_page_size = sample->code_page_size,
> + .parallelism = al->parallelism,
> .stat = {
> .nr_events = 1,
> .period = sample->period,
> diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
> index 46c8373e31465..a6e662d77dc24 100644
> --- a/tools/perf/util/hist.h
> +++ b/tools/perf/util/hist.h
> @@ -42,6 +42,7 @@ enum hist_column {
> HISTC_CGROUP_ID,
> HISTC_CGROUP,
> HISTC_PARENT,
> + HISTC_PARALLELISM,
> HISTC_CPU,
> HISTC_SOCKET,
> HISTC_SRCLINE,
> @@ -228,6 +229,7 @@ struct hist_entry {
> u64 transaction;
> s32 socket;
> s32 cpu;
> + int parallelism;
Can you make it u16 and move to around cpumode to remove paddings?
Thanks,
Namhyung
> u64 code_page_size;
> u64 weight;
> u64 ins_lat;
> @@ -580,6 +582,7 @@ bool perf_hpp__is_thread_entry(struct perf_hpp_fmt *fmt);
> bool perf_hpp__is_comm_entry(struct perf_hpp_fmt *fmt);
> bool perf_hpp__is_dso_entry(struct perf_hpp_fmt *fmt);
> bool perf_hpp__is_sym_entry(struct perf_hpp_fmt *fmt);
> +bool perf_hpp__is_parallelism_entry(struct perf_hpp_fmt *fmt);
>
> struct perf_hpp_fmt *perf_hpp_fmt__dup(struct perf_hpp_fmt *fmt);
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v3 5/7] perf report: Add latency output field
2025-01-27 9:58 ` [PATCH v3 5/7] perf report: Add latency output field Dmitry Vyukov
@ 2025-01-29 4:56 ` Namhyung Kim
2025-01-29 6:55 ` Dmitry Vyukov
0 siblings, 1 reply; 20+ messages in thread
From: Namhyung Kim @ 2025-01-29 4:56 UTC (permalink / raw)
To: Dmitry Vyukov
Cc: irogers, linux-perf-users, linux-kernel, Arnaldo Carvalho de Melo
On Mon, Jan 27, 2025 at 10:58:52AM +0100, Dmitry Vyukov wrote:
> Latency output field is similar to overhead, but represents overhead for
> latency rather than CPU consumption. It's re-scaled from overhead by dividing
> weight by the current parallelism level at the time of the sample.
> It effectively models profiling with 1 sample taken per unit of wall-clock
> time rather than unit of CPU time.
>
> Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
> Cc: Namhyung Kim <namhyung@kernel.org>
> Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
> Cc: Ian Rogers <irogers@google.com>
> Cc: linux-perf-users@vger.kernel.org
> Cc: linux-kernel@vger.kernel.org
> ---
> tools/perf/ui/browsers/hists.c | 27 ++++++++++------
> tools/perf/ui/hist.c | 29 ++++++++++-------
> tools/perf/util/addr_location.h | 2 ++
> tools/perf/util/event.c | 6 ++++
> tools/perf/util/events_stats.h | 2 ++
> tools/perf/util/hist.c | 55 ++++++++++++++++++++++++---------
> tools/perf/util/hist.h | 12 +++++++
> tools/perf/util/sort.c | 2 ++
> 8 files changed, 100 insertions(+), 35 deletions(-)
>
> diff --git a/tools/perf/ui/browsers/hists.c b/tools/perf/ui/browsers/hists.c
> index 49ba82bf33918..35c10509b797f 100644
> --- a/tools/perf/ui/browsers/hists.c
> +++ b/tools/perf/ui/browsers/hists.c
> @@ -1226,7 +1226,7 @@ int __hpp__slsmg_color_printf(struct perf_hpp *hpp, const char *fmt, ...)
> return ret;
> }
>
> -#define __HPP_COLOR_PERCENT_FN(_type, _field) \
> +#define __HPP_COLOR_PERCENT_FN(_type, _field, _fmttype) \
> static u64 __hpp_get_##_field(struct hist_entry *he) \
> { \
> return he->stat._field; \
> @@ -1238,10 +1238,10 @@ hist_browser__hpp_color_##_type(struct perf_hpp_fmt *fmt, \
> struct hist_entry *he) \
> { \
> return hpp__fmt(fmt, hpp, he, __hpp_get_##_field, " %*.2f%%", \
> - __hpp__slsmg_color_printf, true); \
> + __hpp__slsmg_color_printf, _fmttype); \
> }
>
> -#define __HPP_COLOR_ACC_PERCENT_FN(_type, _field) \
> +#define __HPP_COLOR_ACC_PERCENT_FN(_type, _field, _fmttype) \
> static u64 __hpp_get_acc_##_field(struct hist_entry *he) \
> { \
> return he->stat_acc->_field; \
> @@ -1262,15 +1262,18 @@ hist_browser__hpp_color_##_type(struct perf_hpp_fmt *fmt, \
> return ret; \
> } \
> return hpp__fmt(fmt, hpp, he, __hpp_get_acc_##_field, \
> - " %*.2f%%", __hpp__slsmg_color_printf, true); \
> + " %*.2f%%", __hpp__slsmg_color_printf, \
> + _fmttype); \
> }
>
> -__HPP_COLOR_PERCENT_FN(overhead, period)
> -__HPP_COLOR_PERCENT_FN(overhead_sys, period_sys)
> -__HPP_COLOR_PERCENT_FN(overhead_us, period_us)
> -__HPP_COLOR_PERCENT_FN(overhead_guest_sys, period_guest_sys)
> -__HPP_COLOR_PERCENT_FN(overhead_guest_us, period_guest_us)
> -__HPP_COLOR_ACC_PERCENT_FN(overhead_acc, period)
> +__HPP_COLOR_PERCENT_FN(overhead, period, PERF_HPP_FMT_TYPE__PERCENT)
> +__HPP_COLOR_PERCENT_FN(latency, latency, PERF_HPP_FMT_TYPE__LATENCY)
> +__HPP_COLOR_PERCENT_FN(overhead_sys, period_sys, PERF_HPP_FMT_TYPE__PERCENT)
> +__HPP_COLOR_PERCENT_FN(overhead_us, period_us, PERF_HPP_FMT_TYPE__PERCENT)
> +__HPP_COLOR_PERCENT_FN(overhead_guest_sys, period_guest_sys, PERF_HPP_FMT_TYPE__PERCENT)
> +__HPP_COLOR_PERCENT_FN(overhead_guest_us, period_guest_us, PERF_HPP_FMT_TYPE__PERCENT)
> +__HPP_COLOR_ACC_PERCENT_FN(overhead_acc, period, PERF_HPP_FMT_TYPE__PERCENT)
> +__HPP_COLOR_ACC_PERCENT_FN(latency_acc, latency, PERF_HPP_FMT_TYPE__LATENCY)
>
> #undef __HPP_COLOR_PERCENT_FN
> #undef __HPP_COLOR_ACC_PERCENT_FN
> @@ -1279,6 +1282,8 @@ void hist_browser__init_hpp(void)
> {
> perf_hpp__format[PERF_HPP__OVERHEAD].color =
> hist_browser__hpp_color_overhead;
> + perf_hpp__format[PERF_HPP__LATENCY].color =
> + hist_browser__hpp_color_latency;
> perf_hpp__format[PERF_HPP__OVERHEAD_SYS].color =
> hist_browser__hpp_color_overhead_sys;
> perf_hpp__format[PERF_HPP__OVERHEAD_US].color =
> @@ -1289,6 +1294,8 @@ void hist_browser__init_hpp(void)
> hist_browser__hpp_color_overhead_guest_us;
> perf_hpp__format[PERF_HPP__OVERHEAD_ACC].color =
> hist_browser__hpp_color_overhead_acc;
> + perf_hpp__format[PERF_HPP__LATENCY_ACC].color =
> + hist_browser__hpp_color_latency_acc;
>
> res_sample_init();
> }
> diff --git a/tools/perf/ui/hist.c b/tools/perf/ui/hist.c
> index 34fda1d5eccb4..22e31d835301e 100644
> --- a/tools/perf/ui/hist.c
> +++ b/tools/perf/ui/hist.c
> @@ -27,9 +27,10 @@ static int __hpp__fmt_print(struct perf_hpp *hpp, struct hists *hists, u64 val,
> int nr_samples, const char *fmt, int len,
> hpp_snprint_fn print_fn, enum perf_hpp_fmt_type fmtype)
> {
> - if (fmtype == PERF_HPP_FMT_TYPE__PERCENT) {
> + if (fmtype == PERF_HPP_FMT_TYPE__PERCENT || fmtype == PERF_HPP_FMT_TYPE__LATENCY) {
> double percent = 0.0;
> - u64 total = hists__total_period(hists);
> + u64 total = fmtype == PERF_HPP_FMT_TYPE__PERCENT ? hists__total_period(hists) :
> + hists__total_latency(hists);
>
> if (total)
> percent = 100.0 * val / total;
> @@ -128,7 +129,7 @@ int hpp__fmt(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
> print_fn, fmtype);
> }
>
> - if (fmtype == PERF_HPP_FMT_TYPE__PERCENT)
> + if (fmtype == PERF_HPP_FMT_TYPE__PERCENT || fmtype == PERF_HPP_FMT_TYPE__LATENCY)
> len -= 2; /* 2 for a space and a % sign */
> else
> len -= 1;
> @@ -472,11 +473,13 @@ __HPP_ENTRY_AVERAGE_FN(_type, _field) \
> __HPP_SORT_AVERAGE_FN(_type, _field)
>
> HPP_PERCENT_FNS(overhead, period)
> +HPP_PERCENT_FNS(latency, latency)
> HPP_PERCENT_FNS(overhead_sys, period_sys)
> HPP_PERCENT_FNS(overhead_us, period_us)
> HPP_PERCENT_FNS(overhead_guest_sys, period_guest_sys)
> HPP_PERCENT_FNS(overhead_guest_us, period_guest_us)
> HPP_PERCENT_ACC_FNS(overhead_acc, period)
> +HPP_PERCENT_ACC_FNS(latency_acc, latency)
>
> HPP_RAW_FNS(samples, nr_events)
> HPP_RAW_FNS(period, period)
> @@ -548,11 +551,13 @@ static bool hpp__equal(struct perf_hpp_fmt *a, struct perf_hpp_fmt *b)
>
> struct perf_hpp_fmt perf_hpp__format[] = {
> HPP__COLOR_PRINT_FNS("Overhead", overhead, OVERHEAD),
> + HPP__COLOR_PRINT_FNS("Latency", latency, LATENCY),
> HPP__COLOR_PRINT_FNS("sys", overhead_sys, OVERHEAD_SYS),
> HPP__COLOR_PRINT_FNS("usr", overhead_us, OVERHEAD_US),
> HPP__COLOR_PRINT_FNS("guest sys", overhead_guest_sys, OVERHEAD_GUEST_SYS),
> HPP__COLOR_PRINT_FNS("guest usr", overhead_guest_us, OVERHEAD_GUEST_US),
> HPP__COLOR_ACC_PRINT_FNS("Children", overhead_acc, OVERHEAD_ACC),
> + HPP__COLOR_ACC_PRINT_FNS("Latency", latency_acc, LATENCY_ACC),
Hmm.. two latency fields have the same name. Maybe better to
distinguish them but "Children Latency" or "Total Latency" would be
too long.. :(
I think it's mostly ok since users will see them together with overhead
columns and it'll give the context ("Children" or "Self"). But it can
e called with -F or -s option to manually select those columns only.
Thanks,
Namhyung
> HPP__PRINT_FNS("Samples", samples, SAMPLES),
> HPP__PRINT_FNS("Period", period, PERIOD),
> HPP__PRINT_FNS("Weight1", weight1, WEIGHT1),
> fmt->free(fmt);
> }
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v3 6/7] perf report: Add --latency flag
2025-01-27 9:58 ` [PATCH v3 6/7] perf report: Add --latency flag Dmitry Vyukov
@ 2025-01-29 5:03 ` Namhyung Kim
2025-01-29 7:12 ` Dmitry Vyukov
0 siblings, 1 reply; 20+ messages in thread
From: Namhyung Kim @ 2025-01-29 5:03 UTC (permalink / raw)
To: Dmitry Vyukov
Cc: irogers, linux-perf-users, linux-kernel, Arnaldo Carvalho de Melo
On Mon, Jan 27, 2025 at 10:58:53AM +0100, Dmitry Vyukov wrote:
> Add record/report --latency flag that allows to capture and show
> latency-centric profiles rather than the default CPU-consumption-centric
> profiles. For latency profiles record captures context switch events,
> and report shows Latency as the first column.
It'd be nice if you could add a small example output in the commit
message.
>
> Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
> Cc: Namhyung Kim <namhyung@kernel.org>
> Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
> Cc: Ian Rogers <irogers@google.com>
> Cc: linux-perf-users@vger.kernel.org
> Cc: linux-kernel@vger.kernel.org
> ---
[SNIP]
> diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
> index bc4c3acfe7552..2b6023de7a53a 100644
> --- a/tools/perf/util/sort.c
> +++ b/tools/perf/util/sort.c
> @@ -2622,6 +2622,7 @@ struct hpp_dimension {
> const char *name;
> struct perf_hpp_fmt *fmt;
> int taken;
> + int was_taken;
> };
>
> #define DIM(d, n) { .name = n, .fmt = &perf_hpp__format[d], }
> @@ -3513,6 +3514,7 @@ static int __hpp_dimension__add(struct hpp_dimension *hd,
> return -1;
>
> hd->taken = 1;
> + hd->was_taken = 1;
> perf_hpp_list__register_sort_field(list, fmt);
> return 0;
> }
> @@ -3547,10 +3549,15 @@ static int __hpp_dimension__add_output(struct perf_hpp_list *list,
> return 0;
> }
>
> -int hpp_dimension__add_output(unsigned col)
> +int hpp_dimension__add_output(unsigned col, bool implicit)
> {
> + struct hpp_dimension *hd;
> +
> BUG_ON(col >= PERF_HPP__MAX_INDEX);
> - return __hpp_dimension__add_output(&perf_hpp_list, &hpp_sort_dimensions[col]);
> + hd = &hpp_sort_dimensions[col];
> + if (implicit && !hd->was_taken)
> + return 0;
I don't understand why you need 'was_taken' field. Can it use the
'taken' field?
> + return __hpp_dimension__add_output(&perf_hpp_list, hd);
> }
>
> int sort_dimension__add(struct perf_hpp_list *list, const char *tok,
> @@ -3809,10 +3816,24 @@ static char *setup_overhead(char *keys)
> if (sort__mode == SORT_MODE__DIFF)
> return keys;
>
> - keys = prefix_if_not_in("overhead", keys);
> -
> - if (symbol_conf.cumulate_callchain)
> - keys = prefix_if_not_in("overhead_children", keys);
> + if (symbol_conf.prefer_latency) {
> + keys = prefix_if_not_in("overhead", keys);
> + keys = prefix_if_not_in("latency", keys);
> + if (symbol_conf.cumulate_callchain) {
> + keys = prefix_if_not_in("overhead_children", keys);
> + keys = prefix_if_not_in("latency_children", keys);
> + }
> + } else if (!keys || (!strstr(keys, "overhead") &&
> + !strstr(keys, "latency"))) {
> + if (symbol_conf.enable_latency)
> + keys = prefix_if_not_in("latency", keys);
> + keys = prefix_if_not_in("overhead", keys);
> + if (symbol_conf.cumulate_callchain) {
> + if (symbol_conf.enable_latency)
> + keys = prefix_if_not_in("latency_children", keys);
> + keys = prefix_if_not_in("overhead_children", keys);
> + }
> + }
Do you really need this complexity? I think it's better to fix the order
of columns in both case.
Thanks,
Namhyung
>
> return keys;
> }
> diff --git a/tools/perf/util/sort.h b/tools/perf/util/sort.h
> index 11fb15f914093..180d36a2bea35 100644
> --- a/tools/perf/util/sort.h
> +++ b/tools/perf/util/sort.h
> @@ -141,7 +141,7 @@ int report_parse_ignore_callees_opt(const struct option *opt, const char *arg, i
>
> bool is_strict_order(const char *order);
>
> -int hpp_dimension__add_output(unsigned col);
> +int hpp_dimension__add_output(unsigned col, bool implicit);
> void reset_dimensions(void);
> int sort_dimension__add(struct perf_hpp_list *list, const char *tok,
> struct evlist *evlist,
> diff --git a/tools/perf/util/symbol_conf.h b/tools/perf/util/symbol_conf.h
> index c5b2e56127e22..cd9aa82c7d5ad 100644
> --- a/tools/perf/util/symbol_conf.h
> +++ b/tools/perf/util/symbol_conf.h
> @@ -49,7 +49,9 @@ struct symbol_conf {
> keep_exited_threads,
> annotate_data_member,
> annotate_data_sample,
> - skip_empty;
> + skip_empty,
> + enable_latency,
> + prefer_latency;
> const char *vmlinux_name,
> *kallsyms_name,
> *source_prefix,
> --
> 2.48.1.262.g85cc9f2d1e-goog
>
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v3 0/7] perf report: Add latency and parallelism profiling
2025-01-27 9:58 [PATCH v3 0/7] perf report: Add latency and parallelism profiling Dmitry Vyukov
` (6 preceding siblings ...)
2025-01-27 9:58 ` [PATCH v3 7/7] perf report: Add latency and parallelism profiling documentation Dmitry Vyukov
@ 2025-01-29 5:05 ` Namhyung Kim
7 siblings, 0 replies; 20+ messages in thread
From: Namhyung Kim @ 2025-01-29 5:05 UTC (permalink / raw)
To: Dmitry Vyukov
Cc: irogers, linux-perf-users, linux-kernel, Arnaldo Carvalho de Melo
On Mon, Jan 27, 2025 at 10:58:47AM +0100, Dmitry Vyukov wrote:
> There are two notions of time: wall-clock time and CPU time.
> For a single-threaded program, or a program running on a single-core
> machine, these notions are the same. However, for a multi-threaded/
> multi-process program running on a multi-core machine, these notions are
> significantly different. Each second of wall-clock time we have
> number-of-cores seconds of CPU time.
>
> Currently perf only allows to profile CPU time. Perf (and all other
> existing profilers to the be best of my knowledge) does not allow to
> profile wall-clock time.
>
> Optimizing CPU overhead is useful to improve 'throughput', while
> optimizing wall-clock overhead is useful to improve 'latency'.
> These profiles are complementary and are not interchangeable.
> Examples of where latency profile is needed:
> - optimzing build latency
> - optimizing server request latency
> - optimizing ML training/inference latency
> - optimizing running time of any command line program
>
> CPU profile is useless for these use cases at best (if a user understands
> the difference), or misleading at worst (if a user tries to use a wrong
> profile for a job).
>
> This series add latency and parallelization profiling.
> See the added documentation and flags descriptions for details.
>
> Brief outline of the implementation:
> - add context switch collection during record
> - calculate number of threads running on CPUs (parallelism level)
> during report
> - divide each sample weight by the parallelism level
> This effectively models that we were taking 1 sample per unit of
> wall-clock time.
>
> We still default to the CPU profile, so it's up to users to learn
> about the second profiling mode and use it when appropriate.
>
> Changes in v3:
> - rebase and split into patches
> - rename 'wallclock' to 'latency' everywhere
> - don't enable latency profiling by default,
> instead add record/report --latency flag
Thanks for doing this, much better now. I've added some comments in
the thread.
Thanks,
Namhyung
>
> Dmitry Vyukov (7):
> perf report: Add machine parallelism
> perf report: Add parallelism sort key
> perf report: Switch filtered from u8 to u16
> perf report: Add parallelism filter
> perf report: Add latency output field
> perf report: Add --latency flag
> perf report: Add latency and parallelism profiling documentation
>
> Cc: Namhyung Kim <namhyung@kernel.org>
> Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
> Cc: Ian Rogers <irogers@google.com>
> Cc: linux-perf-users@vger.kernel.org
> Cc: linux-kernel@vger.kernel.org
>
> .../callchain-overhead-calculation.txt | 5 +-
> .../cpu-and-latency-overheads.txt | 85 ++++++++++++++++++
> tools/perf/Documentation/perf-report.txt | 49 ++++++----
> tools/perf/Documentation/tips.txt | 3 +
> tools/perf/builtin-record.c | 20 +++++
> tools/perf/builtin-report.c | 39 ++++++++
> tools/perf/ui/browsers/hists.c | 27 +++---
> tools/perf/ui/hist.c | 64 +++++++++----
> tools/perf/util/addr_location.c | 1 +
> tools/perf/util/addr_location.h | 7 +-
> tools/perf/util/event.c | 11 +++
> tools/perf/util/events_stats.h | 2 +
> tools/perf/util/hist.c | 90 +++++++++++++++----
> tools/perf/util/hist.h | 26 +++++-
> tools/perf/util/machine.c | 7 ++
> tools/perf/util/machine.h | 6 ++
> tools/perf/util/session.c | 12 +++
> tools/perf/util/session.h | 1 +
> tools/perf/util/sort.c | 69 ++++++++++++--
> tools/perf/util/sort.h | 3 +-
> tools/perf/util/symbol.c | 34 +++++++
> tools/perf/util/symbol_conf.h | 8 +-
> 22 files changed, 498 insertions(+), 71 deletions(-)
> create mode 100644 tools/perf/Documentation/cpu-and-latency-overheads.txt
>
>
> base-commit: 91b7747dc70d64b5ec56ffe493310f207e7ffc99
> --
> 2.48.1.262.g85cc9f2d1e-goog
>
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v3 5/7] perf report: Add latency output field
2025-01-29 4:56 ` Namhyung Kim
@ 2025-01-29 6:55 ` Dmitry Vyukov
2025-01-30 5:33 ` Namhyung Kim
0 siblings, 1 reply; 20+ messages in thread
From: Dmitry Vyukov @ 2025-01-29 6:55 UTC (permalink / raw)
To: Namhyung Kim
Cc: irogers, linux-perf-users, linux-kernel, Arnaldo Carvalho de Melo
On Wed, 29 Jan 2025 at 05:56, Namhyung Kim <namhyung@kernel.org> wrote:
>
> On Mon, Jan 27, 2025 at 10:58:52AM +0100, Dmitry Vyukov wrote:
> > Latency output field is similar to overhead, but represents overhead for
> > latency rather than CPU consumption. It's re-scaled from overhead by dividing
> > weight by the current parallelism level at the time of the sample.
> > It effectively models profiling with 1 sample taken per unit of wall-clock
> > time rather than unit of CPU time.
> >
> > Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
> > Cc: Namhyung Kim <namhyung@kernel.org>
> > Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
> > Cc: Ian Rogers <irogers@google.com>
> > Cc: linux-perf-users@vger.kernel.org
> > Cc: linux-kernel@vger.kernel.org
> > ---
> > tools/perf/ui/browsers/hists.c | 27 ++++++++++------
> > tools/perf/ui/hist.c | 29 ++++++++++-------
> > tools/perf/util/addr_location.h | 2 ++
> > tools/perf/util/event.c | 6 ++++
> > tools/perf/util/events_stats.h | 2 ++
> > tools/perf/util/hist.c | 55 ++++++++++++++++++++++++---------
> > tools/perf/util/hist.h | 12 +++++++
> > tools/perf/util/sort.c | 2 ++
> > 8 files changed, 100 insertions(+), 35 deletions(-)
> >
> > diff --git a/tools/perf/ui/browsers/hists.c b/tools/perf/ui/browsers/hists.c
> > index 49ba82bf33918..35c10509b797f 100644
> > --- a/tools/perf/ui/browsers/hists.c
> > +++ b/tools/perf/ui/browsers/hists.c
> > @@ -1226,7 +1226,7 @@ int __hpp__slsmg_color_printf(struct perf_hpp *hpp, const char *fmt, ...)
> > return ret;
> > }
> >
> > -#define __HPP_COLOR_PERCENT_FN(_type, _field) \
> > +#define __HPP_COLOR_PERCENT_FN(_type, _field, _fmttype) \
> > static u64 __hpp_get_##_field(struct hist_entry *he) \
> > { \
> > return he->stat._field; \
> > @@ -1238,10 +1238,10 @@ hist_browser__hpp_color_##_type(struct perf_hpp_fmt *fmt, \
> > struct hist_entry *he) \
> > { \
> > return hpp__fmt(fmt, hpp, he, __hpp_get_##_field, " %*.2f%%", \
> > - __hpp__slsmg_color_printf, true); \
> > + __hpp__slsmg_color_printf, _fmttype); \
> > }
> >
> > -#define __HPP_COLOR_ACC_PERCENT_FN(_type, _field) \
> > +#define __HPP_COLOR_ACC_PERCENT_FN(_type, _field, _fmttype) \
> > static u64 __hpp_get_acc_##_field(struct hist_entry *he) \
> > { \
> > return he->stat_acc->_field; \
> > @@ -1262,15 +1262,18 @@ hist_browser__hpp_color_##_type(struct perf_hpp_fmt *fmt, \
> > return ret; \
> > } \
> > return hpp__fmt(fmt, hpp, he, __hpp_get_acc_##_field, \
> > - " %*.2f%%", __hpp__slsmg_color_printf, true); \
> > + " %*.2f%%", __hpp__slsmg_color_printf, \
> > + _fmttype); \
> > }
> >
> > -__HPP_COLOR_PERCENT_FN(overhead, period)
> > -__HPP_COLOR_PERCENT_FN(overhead_sys, period_sys)
> > -__HPP_COLOR_PERCENT_FN(overhead_us, period_us)
> > -__HPP_COLOR_PERCENT_FN(overhead_guest_sys, period_guest_sys)
> > -__HPP_COLOR_PERCENT_FN(overhead_guest_us, period_guest_us)
> > -__HPP_COLOR_ACC_PERCENT_FN(overhead_acc, period)
> > +__HPP_COLOR_PERCENT_FN(overhead, period, PERF_HPP_FMT_TYPE__PERCENT)
> > +__HPP_COLOR_PERCENT_FN(latency, latency, PERF_HPP_FMT_TYPE__LATENCY)
> > +__HPP_COLOR_PERCENT_FN(overhead_sys, period_sys, PERF_HPP_FMT_TYPE__PERCENT)
> > +__HPP_COLOR_PERCENT_FN(overhead_us, period_us, PERF_HPP_FMT_TYPE__PERCENT)
> > +__HPP_COLOR_PERCENT_FN(overhead_guest_sys, period_guest_sys, PERF_HPP_FMT_TYPE__PERCENT)
> > +__HPP_COLOR_PERCENT_FN(overhead_guest_us, period_guest_us, PERF_HPP_FMT_TYPE__PERCENT)
> > +__HPP_COLOR_ACC_PERCENT_FN(overhead_acc, period, PERF_HPP_FMT_TYPE__PERCENT)
> > +__HPP_COLOR_ACC_PERCENT_FN(latency_acc, latency, PERF_HPP_FMT_TYPE__LATENCY)
> >
> > #undef __HPP_COLOR_PERCENT_FN
> > #undef __HPP_COLOR_ACC_PERCENT_FN
> > @@ -1279,6 +1282,8 @@ void hist_browser__init_hpp(void)
> > {
> > perf_hpp__format[PERF_HPP__OVERHEAD].color =
> > hist_browser__hpp_color_overhead;
> > + perf_hpp__format[PERF_HPP__LATENCY].color =
> > + hist_browser__hpp_color_latency;
> > perf_hpp__format[PERF_HPP__OVERHEAD_SYS].color =
> > hist_browser__hpp_color_overhead_sys;
> > perf_hpp__format[PERF_HPP__OVERHEAD_US].color =
> > @@ -1289,6 +1294,8 @@ void hist_browser__init_hpp(void)
> > hist_browser__hpp_color_overhead_guest_us;
> > perf_hpp__format[PERF_HPP__OVERHEAD_ACC].color =
> > hist_browser__hpp_color_overhead_acc;
> > + perf_hpp__format[PERF_HPP__LATENCY_ACC].color =
> > + hist_browser__hpp_color_latency_acc;
> >
> > res_sample_init();
> > }
> > diff --git a/tools/perf/ui/hist.c b/tools/perf/ui/hist.c
> > index 34fda1d5eccb4..22e31d835301e 100644
> > --- a/tools/perf/ui/hist.c
> > +++ b/tools/perf/ui/hist.c
> > @@ -27,9 +27,10 @@ static int __hpp__fmt_print(struct perf_hpp *hpp, struct hists *hists, u64 val,
> > int nr_samples, const char *fmt, int len,
> > hpp_snprint_fn print_fn, enum perf_hpp_fmt_type fmtype)
> > {
> > - if (fmtype == PERF_HPP_FMT_TYPE__PERCENT) {
> > + if (fmtype == PERF_HPP_FMT_TYPE__PERCENT || fmtype == PERF_HPP_FMT_TYPE__LATENCY) {
> > double percent = 0.0;
> > - u64 total = hists__total_period(hists);
> > + u64 total = fmtype == PERF_HPP_FMT_TYPE__PERCENT ? hists__total_period(hists) :
> > + hists__total_latency(hists);
> >
> > if (total)
> > percent = 100.0 * val / total;
> > @@ -128,7 +129,7 @@ int hpp__fmt(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
> > print_fn, fmtype);
> > }
> >
> > - if (fmtype == PERF_HPP_FMT_TYPE__PERCENT)
> > + if (fmtype == PERF_HPP_FMT_TYPE__PERCENT || fmtype == PERF_HPP_FMT_TYPE__LATENCY)
> > len -= 2; /* 2 for a space and a % sign */
> > else
> > len -= 1;
> > @@ -472,11 +473,13 @@ __HPP_ENTRY_AVERAGE_FN(_type, _field) \
> > __HPP_SORT_AVERAGE_FN(_type, _field)
> >
> > HPP_PERCENT_FNS(overhead, period)
> > +HPP_PERCENT_FNS(latency, latency)
> > HPP_PERCENT_FNS(overhead_sys, period_sys)
> > HPP_PERCENT_FNS(overhead_us, period_us)
> > HPP_PERCENT_FNS(overhead_guest_sys, period_guest_sys)
> > HPP_PERCENT_FNS(overhead_guest_us, period_guest_us)
> > HPP_PERCENT_ACC_FNS(overhead_acc, period)
> > +HPP_PERCENT_ACC_FNS(latency_acc, latency)
> >
> > HPP_RAW_FNS(samples, nr_events)
> > HPP_RAW_FNS(period, period)
> > @@ -548,11 +551,13 @@ static bool hpp__equal(struct perf_hpp_fmt *a, struct perf_hpp_fmt *b)
> >
> > struct perf_hpp_fmt perf_hpp__format[] = {
> > HPP__COLOR_PRINT_FNS("Overhead", overhead, OVERHEAD),
> > + HPP__COLOR_PRINT_FNS("Latency", latency, LATENCY),
> > HPP__COLOR_PRINT_FNS("sys", overhead_sys, OVERHEAD_SYS),
> > HPP__COLOR_PRINT_FNS("usr", overhead_us, OVERHEAD_US),
> > HPP__COLOR_PRINT_FNS("guest sys", overhead_guest_sys, OVERHEAD_GUEST_SYS),
> > HPP__COLOR_PRINT_FNS("guest usr", overhead_guest_us, OVERHEAD_GUEST_US),
> > HPP__COLOR_ACC_PRINT_FNS("Children", overhead_acc, OVERHEAD_ACC),
> > + HPP__COLOR_ACC_PRINT_FNS("Latency", latency_acc, LATENCY_ACC),
>
> Hmm.. two latency fields have the same name. Maybe better to
> distinguish them but "Children Latency" or "Total Latency" would be
> too long.. :(
>
> I think it's mostly ok since users will see them together with overhead
> columns and it'll give the context ("Children" or "Self"). But it can
> e called with -F or -s option to manually select those columns only.
Yes, the motivation for calling them the same was the column name length.
And, with the default flags it looks reasonable:
Children Latency Self Latency Command
The fields seem to be selected based on the names in sort.c rather
than these names, e.g. I can do:
perf report -F latency_children,overhead_children,latency,overhead,symbol
and get:
Samples: 45K of event 'cycles:Pu', Event count (approx.): 10457486861
Latency Children Latency Overhead Symbol
+ 19.35% 18.69% 0.00% 0.00% [k] 0000000000000000
+ 4.86% 4.21% 4.86% 4.21% [.] htab_find_slot_with_hash
+ 4.15% 4.48% 0.00% 0.00% [.] 0xffffffff9ce012a6
So it seems to be possible to select these columns as needed.
> Thanks,
> Namhyung
>
>
> > HPP__PRINT_FNS("Samples", samples, SAMPLES),
> > HPP__PRINT_FNS("Period", period, PERIOD),
> > HPP__PRINT_FNS("Weight1", weight1, WEIGHT1),
>
> > fmt->free(fmt);
> > }
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v3 6/7] perf report: Add --latency flag
2025-01-29 5:03 ` Namhyung Kim
@ 2025-01-29 7:12 ` Dmitry Vyukov
2025-01-30 6:30 ` Namhyung Kim
0 siblings, 1 reply; 20+ messages in thread
From: Dmitry Vyukov @ 2025-01-29 7:12 UTC (permalink / raw)
To: Namhyung Kim
Cc: irogers, linux-perf-users, linux-kernel, Arnaldo Carvalho de Melo
On Wed, 29 Jan 2025 at 06:03, Namhyung Kim <namhyung@kernel.org> wrote:
>
> On Mon, Jan 27, 2025 at 10:58:53AM +0100, Dmitry Vyukov wrote:
> > Add record/report --latency flag that allows to capture and show
> > latency-centric profiles rather than the default CPU-consumption-centric
> > profiles. For latency profiles record captures context switch events,
> > and report shows Latency as the first column.
>
> It'd be nice if you could add a small example output in the commit
> message.
>
> >
> > Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
> > Cc: Namhyung Kim <namhyung@kernel.org>
> > Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
> > Cc: Ian Rogers <irogers@google.com>
> > Cc: linux-perf-users@vger.kernel.org
> > Cc: linux-kernel@vger.kernel.org
> > ---
> [SNIP]
> > diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
> > index bc4c3acfe7552..2b6023de7a53a 100644
> > --- a/tools/perf/util/sort.c
> > +++ b/tools/perf/util/sort.c
> > @@ -2622,6 +2622,7 @@ struct hpp_dimension {
> > const char *name;
> > struct perf_hpp_fmt *fmt;
> > int taken;
> > + int was_taken;
> > };
> >
> > #define DIM(d, n) { .name = n, .fmt = &perf_hpp__format[d], }
> > @@ -3513,6 +3514,7 @@ static int __hpp_dimension__add(struct hpp_dimension *hd,
> > return -1;
> >
> > hd->taken = 1;
> > + hd->was_taken = 1;
> > perf_hpp_list__register_sort_field(list, fmt);
> > return 0;
> > }
> > @@ -3547,10 +3549,15 @@ static int __hpp_dimension__add_output(struct perf_hpp_list *list,
> > return 0;
> > }
> >
> > -int hpp_dimension__add_output(unsigned col)
> > +int hpp_dimension__add_output(unsigned col, bool implicit)
> > {
> > + struct hpp_dimension *hd;
> > +
> > BUG_ON(col >= PERF_HPP__MAX_INDEX);
> > - return __hpp_dimension__add_output(&perf_hpp_list, &hpp_sort_dimensions[col]);
> > + hd = &hpp_sort_dimensions[col];
> > + if (implicit && !hd->was_taken)
> > + return 0;
>
> I don't understand why you need 'was_taken' field. Can it use the
> 'taken' field?
I've started getting failed asserts in
perf_hpp__cancel_cumulate/latency when removing columns still linked
into sort order list.
I've figured out that columns we implicitly add in setup_overhead and
perf_hpp__init must match exactly. If we add one in setup_overhead,
but not in perf_hpp__init, then it starts failing.
Taken does not work b/c there is reset_dimensions call between these
functions, so they actually add the same columns twice to field/sort
lists (and that prevents failures in
perf_hpp__cancel_cumulate/latency).
Initially I've just tried to match logic in setup_overhead and in
perf_hpp__init. But it turned out quite messy, duplicate logic, and
e.g. in setup_overhead we look at sort_order, but in perf_hpp__init we
already can't look at it b/c we already altered it in setup_overhead.
That logic would also be quite fragile. Adding was_taken looks like
the simplest, most reliable, and less fragile with respect to future
changes approach.
> > + return __hpp_dimension__add_output(&perf_hpp_list, hd);
> > }
> >
> > int sort_dimension__add(struct perf_hpp_list *list, const char *tok,
> > @@ -3809,10 +3816,24 @@ static char *setup_overhead(char *keys)
> > if (sort__mode == SORT_MODE__DIFF)
> > return keys;
> >
> > - keys = prefix_if_not_in("overhead", keys);
> > -
> > - if (symbol_conf.cumulate_callchain)
> > - keys = prefix_if_not_in("overhead_children", keys);
> > + if (symbol_conf.prefer_latency) {
> > + keys = prefix_if_not_in("overhead", keys);
> > + keys = prefix_if_not_in("latency", keys);
> > + if (symbol_conf.cumulate_callchain) {
> > + keys = prefix_if_not_in("overhead_children", keys);
> > + keys = prefix_if_not_in("latency_children", keys);
> > + }
> > + } else if (!keys || (!strstr(keys, "overhead") &&
> > + !strstr(keys, "latency"))) {
> > + if (symbol_conf.enable_latency)
> > + keys = prefix_if_not_in("latency", keys);
> > + keys = prefix_if_not_in("overhead", keys);
> > + if (symbol_conf.cumulate_callchain) {
> > + if (symbol_conf.enable_latency)
> > + keys = prefix_if_not_in("latency_children", keys);
> > + keys = prefix_if_not_in("overhead_children", keys);
> > + }
> > + }
>
> Do you really need this complexity? I think it's better to fix the order
> of columns in both case.
This is sort order which affects ordering of row, and order of rows is
basically the most important thing for a profiler. If we fix the
order, it will be showing completely different things.
"latency" and "overhead" are equivalent with respect to their
fundamentality for a profile. So we shouldn't be adding any of them,
if any of them are already explicitly specified by the user.
For example, the command from tips.txt:
perf report --hierarchy --sort latency,parallelism,comm,symbol
if we prepend "overhead", it all falls apart.
Or for 2 default modes (normals and latency) we want "overhead" or
"latency" to come first. Prepending "latency" for the current CPU mode
would lead to completely different ordering.
> Thanks,
> Namhyung
>
> >
> > return keys;
> > }
> > diff --git a/tools/perf/util/sort.h b/tools/perf/util/sort.h
> > index 11fb15f914093..180d36a2bea35 100644
> > --- a/tools/perf/util/sort.h
> > +++ b/tools/perf/util/sort.h
> > @@ -141,7 +141,7 @@ int report_parse_ignore_callees_opt(const struct option *opt, const char *arg, i
> >
> > bool is_strict_order(const char *order);
> >
> > -int hpp_dimension__add_output(unsigned col);
> > +int hpp_dimension__add_output(unsigned col, bool implicit);
> > void reset_dimensions(void);
> > int sort_dimension__add(struct perf_hpp_list *list, const char *tok,
> > struct evlist *evlist,
> > diff --git a/tools/perf/util/symbol_conf.h b/tools/perf/util/symbol_conf.h
> > index c5b2e56127e22..cd9aa82c7d5ad 100644
> > --- a/tools/perf/util/symbol_conf.h
> > +++ b/tools/perf/util/symbol_conf.h
> > @@ -49,7 +49,9 @@ struct symbol_conf {
> > keep_exited_threads,
> > annotate_data_member,
> > annotate_data_sample,
> > - skip_empty;
> > + skip_empty,
> > + enable_latency,
> > + prefer_latency;
> > const char *vmlinux_name,
> > *kallsyms_name,
> > *source_prefix,
> > --
> > 2.48.1.262.g85cc9f2d1e-goog
> >
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v3 2/7] perf report: Add parallelism sort key
2025-01-29 4:42 ` Namhyung Kim
@ 2025-01-29 7:18 ` Dmitry Vyukov
2025-01-30 5:28 ` Namhyung Kim
0 siblings, 1 reply; 20+ messages in thread
From: Dmitry Vyukov @ 2025-01-29 7:18 UTC (permalink / raw)
To: Namhyung Kim
Cc: irogers, linux-perf-users, linux-kernel, Arnaldo Carvalho de Melo
On Wed, 29 Jan 2025 at 05:42, Namhyung Kim <namhyung@kernel.org> wrote:
>
> On Mon, Jan 27, 2025 at 10:58:49AM +0100, Dmitry Vyukov wrote:
> > Show parallelism level in profiles if requested by user.
> >
> > Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
> > Cc: Namhyung Kim <namhyung@kernel.org>
> > Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
> > Cc: Ian Rogers <irogers@google.com>
> > Cc: linux-perf-users@vger.kernel.org
> > Cc: linux-kernel@vger.kernel.org
> > ---
> > tools/perf/builtin-report.c | 11 +++++++++++
> > tools/perf/util/hist.c | 2 ++
> > tools/perf/util/hist.h | 3 +++
> > tools/perf/util/session.c | 12 ++++++++++++
> > tools/perf/util/session.h | 1 +
> > tools/perf/util/sort.c | 23 +++++++++++++++++++++++
> > tools/perf/util/sort.h | 1 +
> > 7 files changed, 53 insertions(+)
> >
> > diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
> > index 0d9bd090eda71..14d49f0625881 100644
> > --- a/tools/perf/builtin-report.c
> > +++ b/tools/perf/builtin-report.c
> > @@ -1720,6 +1720,17 @@ int cmd_report(int argc, const char **argv)
> > symbol_conf.annotate_data_sample = true;
> > }
> >
> > + if (report.disable_order || !perf_session__has_switch_events(session)) {
> > + if ((sort_order && strstr(sort_order, "parallelism")) ||
> > + (field_order && strstr(field_order, "parallelism"))) {
> > + if (report.disable_order)
> > + ui__error("Use of parallelism is incompatible with --disable-order.\n");
> > + else
> > + ui__error("Use of parallelism requires --switch-events during record.\n");
> > + return -1;
> > + }
> > + }
> > +
> > if (sort_order && strstr(sort_order, "ipc")) {
> > parse_options_usage(report_usage, options, "s", 1);
> > goto error;
> > diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
> > index 0f30f843c566d..cafd693568189 100644
> > --- a/tools/perf/util/hist.c
> > +++ b/tools/perf/util/hist.c
> > @@ -207,6 +207,7 @@ void hists__calc_col_len(struct hists *hists, struct hist_entry *h)
> >
> > hists__new_col_len(hists, HISTC_CGROUP, 6);
> > hists__new_col_len(hists, HISTC_CGROUP_ID, 20);
> > + hists__new_col_len(hists, HISTC_PARALLELISM, 11);
> > hists__new_col_len(hists, HISTC_CPU, 3);
> > hists__new_col_len(hists, HISTC_SOCKET, 6);
> > hists__new_col_len(hists, HISTC_MEM_LOCKED, 6);
> > @@ -741,6 +742,7 @@ __hists__add_entry(struct hists *hists,
> > .ip = al->addr,
> > .level = al->level,
> > .code_page_size = sample->code_page_size,
> > + .parallelism = al->parallelism,
> > .stat = {
> > .nr_events = 1,
> > .period = sample->period,
> > diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
> > index 46c8373e31465..a6e662d77dc24 100644
> > --- a/tools/perf/util/hist.h
> > +++ b/tools/perf/util/hist.h
> > @@ -42,6 +42,7 @@ enum hist_column {
> > HISTC_CGROUP_ID,
> > HISTC_CGROUP,
> > HISTC_PARENT,
> > + HISTC_PARALLELISM,
> > HISTC_CPU,
> > HISTC_SOCKET,
> > HISTC_SRCLINE,
> > @@ -228,6 +229,7 @@ struct hist_entry {
> > u64 transaction;
> > s32 socket;
> > s32 cpu;
> > + int parallelism;
>
> Can you make it u16 and move to around cpumode to remove paddings?
It generally should be the same size as cpu/socket/etc. And these are
32-bits throughout the codebase (the previous fields). Are there any
checks that MAX_NR_CPUS<64K?
> Thanks,
> Namhyung
>
>
> > u64 code_page_size;
> > u64 weight;
> > u64 ins_lat;
> > @@ -580,6 +582,7 @@ bool perf_hpp__is_thread_entry(struct perf_hpp_fmt *fmt);
> > bool perf_hpp__is_comm_entry(struct perf_hpp_fmt *fmt);
> > bool perf_hpp__is_dso_entry(struct perf_hpp_fmt *fmt);
> > bool perf_hpp__is_sym_entry(struct perf_hpp_fmt *fmt);
> > +bool perf_hpp__is_parallelism_entry(struct perf_hpp_fmt *fmt);
> >
> > struct perf_hpp_fmt *perf_hpp_fmt__dup(struct perf_hpp_fmt *fmt);
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v3 2/7] perf report: Add parallelism sort key
2025-01-29 7:18 ` Dmitry Vyukov
@ 2025-01-30 5:28 ` Namhyung Kim
2025-02-03 14:40 ` Dmitry Vyukov
0 siblings, 1 reply; 20+ messages in thread
From: Namhyung Kim @ 2025-01-30 5:28 UTC (permalink / raw)
To: Dmitry Vyukov
Cc: irogers, linux-perf-users, linux-kernel, Arnaldo Carvalho de Melo
On Wed, Jan 29, 2025 at 08:18:34AM +0100, Dmitry Vyukov wrote:
> On Wed, 29 Jan 2025 at 05:42, Namhyung Kim <namhyung@kernel.org> wrote:
> >
> > On Mon, Jan 27, 2025 at 10:58:49AM +0100, Dmitry Vyukov wrote:
> > > Show parallelism level in profiles if requested by user.
> > >
> > > Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
> > > Cc: Namhyung Kim <namhyung@kernel.org>
> > > Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
> > > Cc: Ian Rogers <irogers@google.com>
> > > Cc: linux-perf-users@vger.kernel.org
> > > Cc: linux-kernel@vger.kernel.org
> > > ---
> > > tools/perf/builtin-report.c | 11 +++++++++++
> > > tools/perf/util/hist.c | 2 ++
> > > tools/perf/util/hist.h | 3 +++
> > > tools/perf/util/session.c | 12 ++++++++++++
> > > tools/perf/util/session.h | 1 +
> > > tools/perf/util/sort.c | 23 +++++++++++++++++++++++
> > > tools/perf/util/sort.h | 1 +
> > > 7 files changed, 53 insertions(+)
> > >
> > > diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
> > > index 0d9bd090eda71..14d49f0625881 100644
> > > --- a/tools/perf/builtin-report.c
> > > +++ b/tools/perf/builtin-report.c
> > > @@ -1720,6 +1720,17 @@ int cmd_report(int argc, const char **argv)
> > > symbol_conf.annotate_data_sample = true;
> > > }
> > >
> > > + if (report.disable_order || !perf_session__has_switch_events(session)) {
> > > + if ((sort_order && strstr(sort_order, "parallelism")) ||
> > > + (field_order && strstr(field_order, "parallelism"))) {
> > > + if (report.disable_order)
> > > + ui__error("Use of parallelism is incompatible with --disable-order.\n");
> > > + else
> > > + ui__error("Use of parallelism requires --switch-events during record.\n");
> > > + return -1;
> > > + }
> > > + }
> > > +
> > > if (sort_order && strstr(sort_order, "ipc")) {
> > > parse_options_usage(report_usage, options, "s", 1);
> > > goto error;
> > > diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
> > > index 0f30f843c566d..cafd693568189 100644
> > > --- a/tools/perf/util/hist.c
> > > +++ b/tools/perf/util/hist.c
> > > @@ -207,6 +207,7 @@ void hists__calc_col_len(struct hists *hists, struct hist_entry *h)
> > >
> > > hists__new_col_len(hists, HISTC_CGROUP, 6);
> > > hists__new_col_len(hists, HISTC_CGROUP_ID, 20);
> > > + hists__new_col_len(hists, HISTC_PARALLELISM, 11);
> > > hists__new_col_len(hists, HISTC_CPU, 3);
> > > hists__new_col_len(hists, HISTC_SOCKET, 6);
> > > hists__new_col_len(hists, HISTC_MEM_LOCKED, 6);
> > > @@ -741,6 +742,7 @@ __hists__add_entry(struct hists *hists,
> > > .ip = al->addr,
> > > .level = al->level,
> > > .code_page_size = sample->code_page_size,
> > > + .parallelism = al->parallelism,
> > > .stat = {
> > > .nr_events = 1,
> > > .period = sample->period,
> > > diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
> > > index 46c8373e31465..a6e662d77dc24 100644
> > > --- a/tools/perf/util/hist.h
> > > +++ b/tools/perf/util/hist.h
> > > @@ -42,6 +42,7 @@ enum hist_column {
> > > HISTC_CGROUP_ID,
> > > HISTC_CGROUP,
> > > HISTC_PARENT,
> > > + HISTC_PARALLELISM,
> > > HISTC_CPU,
> > > HISTC_SOCKET,
> > > HISTC_SRCLINE,
> > > @@ -228,6 +229,7 @@ struct hist_entry {
> > > u64 transaction;
> > > s32 socket;
> > > s32 cpu;
> > > + int parallelism;
> >
> > Can you make it u16 and move to around cpumode to remove paddings?
>
> It generally should be the same size as cpu/socket/etc. And these are
> 32-bits throughout the codebase (the previous fields). Are there any
> checks that MAX_NR_CPUS<64K?
I don't think there's such a check. But practically it used be 4K and
you can add the check. :)
Anyway hist_entry is getting bigger and we may need to shrink it later.
I don't stringly insist on u16 though. It's up to you.
Thanks,
Namhyung
> >
> >
> > > u64 code_page_size;
> > > u64 weight;
> > > u64 ins_lat;
> > > @@ -580,6 +582,7 @@ bool perf_hpp__is_thread_entry(struct perf_hpp_fmt *fmt);
> > > bool perf_hpp__is_comm_entry(struct perf_hpp_fmt *fmt);
> > > bool perf_hpp__is_dso_entry(struct perf_hpp_fmt *fmt);
> > > bool perf_hpp__is_sym_entry(struct perf_hpp_fmt *fmt);
> > > +bool perf_hpp__is_parallelism_entry(struct perf_hpp_fmt *fmt);
> > >
> > > struct perf_hpp_fmt *perf_hpp_fmt__dup(struct perf_hpp_fmt *fmt);
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v3 5/7] perf report: Add latency output field
2025-01-29 6:55 ` Dmitry Vyukov
@ 2025-01-30 5:33 ` Namhyung Kim
0 siblings, 0 replies; 20+ messages in thread
From: Namhyung Kim @ 2025-01-30 5:33 UTC (permalink / raw)
To: Dmitry Vyukov
Cc: irogers, linux-perf-users, linux-kernel, Arnaldo Carvalho de Melo
On Wed, Jan 29, 2025 at 07:55:55AM +0100, Dmitry Vyukov wrote:
> On Wed, 29 Jan 2025 at 05:56, Namhyung Kim <namhyung@kernel.org> wrote:
> >
> > On Mon, Jan 27, 2025 at 10:58:52AM +0100, Dmitry Vyukov wrote:
> > > Latency output field is similar to overhead, but represents overhead for
> > > latency rather than CPU consumption. It's re-scaled from overhead by dividing
> > > weight by the current parallelism level at the time of the sample.
> > > It effectively models profiling with 1 sample taken per unit of wall-clock
> > > time rather than unit of CPU time.
> > >
> > > Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
> > > Cc: Namhyung Kim <namhyung@kernel.org>
> > > Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
> > > Cc: Ian Rogers <irogers@google.com>
> > > Cc: linux-perf-users@vger.kernel.org
> > > Cc: linux-kernel@vger.kernel.org
> > > ---
> > > tools/perf/ui/browsers/hists.c | 27 ++++++++++------
> > > tools/perf/ui/hist.c | 29 ++++++++++-------
> > > tools/perf/util/addr_location.h | 2 ++
> > > tools/perf/util/event.c | 6 ++++
> > > tools/perf/util/events_stats.h | 2 ++
> > > tools/perf/util/hist.c | 55 ++++++++++++++++++++++++---------
> > > tools/perf/util/hist.h | 12 +++++++
> > > tools/perf/util/sort.c | 2 ++
> > > 8 files changed, 100 insertions(+), 35 deletions(-)
> > >
> > > diff --git a/tools/perf/ui/browsers/hists.c b/tools/perf/ui/browsers/hists.c
> > > index 49ba82bf33918..35c10509b797f 100644
> > > --- a/tools/perf/ui/browsers/hists.c
> > > +++ b/tools/perf/ui/browsers/hists.c
> > > @@ -1226,7 +1226,7 @@ int __hpp__slsmg_color_printf(struct perf_hpp *hpp, const char *fmt, ...)
> > > return ret;
> > > }
> > >
> > > -#define __HPP_COLOR_PERCENT_FN(_type, _field) \
> > > +#define __HPP_COLOR_PERCENT_FN(_type, _field, _fmttype) \
> > > static u64 __hpp_get_##_field(struct hist_entry *he) \
> > > { \
> > > return he->stat._field; \
> > > @@ -1238,10 +1238,10 @@ hist_browser__hpp_color_##_type(struct perf_hpp_fmt *fmt, \
> > > struct hist_entry *he) \
> > > { \
> > > return hpp__fmt(fmt, hpp, he, __hpp_get_##_field, " %*.2f%%", \
> > > - __hpp__slsmg_color_printf, true); \
> > > + __hpp__slsmg_color_printf, _fmttype); \
> > > }
> > >
> > > -#define __HPP_COLOR_ACC_PERCENT_FN(_type, _field) \
> > > +#define __HPP_COLOR_ACC_PERCENT_FN(_type, _field, _fmttype) \
> > > static u64 __hpp_get_acc_##_field(struct hist_entry *he) \
> > > { \
> > > return he->stat_acc->_field; \
> > > @@ -1262,15 +1262,18 @@ hist_browser__hpp_color_##_type(struct perf_hpp_fmt *fmt, \
> > > return ret; \
> > > } \
> > > return hpp__fmt(fmt, hpp, he, __hpp_get_acc_##_field, \
> > > - " %*.2f%%", __hpp__slsmg_color_printf, true); \
> > > + " %*.2f%%", __hpp__slsmg_color_printf, \
> > > + _fmttype); \
> > > }
> > >
> > > -__HPP_COLOR_PERCENT_FN(overhead, period)
> > > -__HPP_COLOR_PERCENT_FN(overhead_sys, period_sys)
> > > -__HPP_COLOR_PERCENT_FN(overhead_us, period_us)
> > > -__HPP_COLOR_PERCENT_FN(overhead_guest_sys, period_guest_sys)
> > > -__HPP_COLOR_PERCENT_FN(overhead_guest_us, period_guest_us)
> > > -__HPP_COLOR_ACC_PERCENT_FN(overhead_acc, period)
> > > +__HPP_COLOR_PERCENT_FN(overhead, period, PERF_HPP_FMT_TYPE__PERCENT)
> > > +__HPP_COLOR_PERCENT_FN(latency, latency, PERF_HPP_FMT_TYPE__LATENCY)
> > > +__HPP_COLOR_PERCENT_FN(overhead_sys, period_sys, PERF_HPP_FMT_TYPE__PERCENT)
> > > +__HPP_COLOR_PERCENT_FN(overhead_us, period_us, PERF_HPP_FMT_TYPE__PERCENT)
> > > +__HPP_COLOR_PERCENT_FN(overhead_guest_sys, period_guest_sys, PERF_HPP_FMT_TYPE__PERCENT)
> > > +__HPP_COLOR_PERCENT_FN(overhead_guest_us, period_guest_us, PERF_HPP_FMT_TYPE__PERCENT)
> > > +__HPP_COLOR_ACC_PERCENT_FN(overhead_acc, period, PERF_HPP_FMT_TYPE__PERCENT)
> > > +__HPP_COLOR_ACC_PERCENT_FN(latency_acc, latency, PERF_HPP_FMT_TYPE__LATENCY)
> > >
> > > #undef __HPP_COLOR_PERCENT_FN
> > > #undef __HPP_COLOR_ACC_PERCENT_FN
> > > @@ -1279,6 +1282,8 @@ void hist_browser__init_hpp(void)
> > > {
> > > perf_hpp__format[PERF_HPP__OVERHEAD].color =
> > > hist_browser__hpp_color_overhead;
> > > + perf_hpp__format[PERF_HPP__LATENCY].color =
> > > + hist_browser__hpp_color_latency;
> > > perf_hpp__format[PERF_HPP__OVERHEAD_SYS].color =
> > > hist_browser__hpp_color_overhead_sys;
> > > perf_hpp__format[PERF_HPP__OVERHEAD_US].color =
> > > @@ -1289,6 +1294,8 @@ void hist_browser__init_hpp(void)
> > > hist_browser__hpp_color_overhead_guest_us;
> > > perf_hpp__format[PERF_HPP__OVERHEAD_ACC].color =
> > > hist_browser__hpp_color_overhead_acc;
> > > + perf_hpp__format[PERF_HPP__LATENCY_ACC].color =
> > > + hist_browser__hpp_color_latency_acc;
> > >
> > > res_sample_init();
> > > }
> > > diff --git a/tools/perf/ui/hist.c b/tools/perf/ui/hist.c
> > > index 34fda1d5eccb4..22e31d835301e 100644
> > > --- a/tools/perf/ui/hist.c
> > > +++ b/tools/perf/ui/hist.c
> > > @@ -27,9 +27,10 @@ static int __hpp__fmt_print(struct perf_hpp *hpp, struct hists *hists, u64 val,
> > > int nr_samples, const char *fmt, int len,
> > > hpp_snprint_fn print_fn, enum perf_hpp_fmt_type fmtype)
> > > {
> > > - if (fmtype == PERF_HPP_FMT_TYPE__PERCENT) {
> > > + if (fmtype == PERF_HPP_FMT_TYPE__PERCENT || fmtype == PERF_HPP_FMT_TYPE__LATENCY) {
> > > double percent = 0.0;
> > > - u64 total = hists__total_period(hists);
> > > + u64 total = fmtype == PERF_HPP_FMT_TYPE__PERCENT ? hists__total_period(hists) :
> > > + hists__total_latency(hists);
> > >
> > > if (total)
> > > percent = 100.0 * val / total;
> > > @@ -128,7 +129,7 @@ int hpp__fmt(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
> > > print_fn, fmtype);
> > > }
> > >
> > > - if (fmtype == PERF_HPP_FMT_TYPE__PERCENT)
> > > + if (fmtype == PERF_HPP_FMT_TYPE__PERCENT || fmtype == PERF_HPP_FMT_TYPE__LATENCY)
> > > len -= 2; /* 2 for a space and a % sign */
> > > else
> > > len -= 1;
> > > @@ -472,11 +473,13 @@ __HPP_ENTRY_AVERAGE_FN(_type, _field) \
> > > __HPP_SORT_AVERAGE_FN(_type, _field)
> > >
> > > HPP_PERCENT_FNS(overhead, period)
> > > +HPP_PERCENT_FNS(latency, latency)
> > > HPP_PERCENT_FNS(overhead_sys, period_sys)
> > > HPP_PERCENT_FNS(overhead_us, period_us)
> > > HPP_PERCENT_FNS(overhead_guest_sys, period_guest_sys)
> > > HPP_PERCENT_FNS(overhead_guest_us, period_guest_us)
> > > HPP_PERCENT_ACC_FNS(overhead_acc, period)
> > > +HPP_PERCENT_ACC_FNS(latency_acc, latency)
> > >
> > > HPP_RAW_FNS(samples, nr_events)
> > > HPP_RAW_FNS(period, period)
> > > @@ -548,11 +551,13 @@ static bool hpp__equal(struct perf_hpp_fmt *a, struct perf_hpp_fmt *b)
> > >
> > > struct perf_hpp_fmt perf_hpp__format[] = {
> > > HPP__COLOR_PRINT_FNS("Overhead", overhead, OVERHEAD),
> > > + HPP__COLOR_PRINT_FNS("Latency", latency, LATENCY),
> > > HPP__COLOR_PRINT_FNS("sys", overhead_sys, OVERHEAD_SYS),
> > > HPP__COLOR_PRINT_FNS("usr", overhead_us, OVERHEAD_US),
> > > HPP__COLOR_PRINT_FNS("guest sys", overhead_guest_sys, OVERHEAD_GUEST_SYS),
> > > HPP__COLOR_PRINT_FNS("guest usr", overhead_guest_us, OVERHEAD_GUEST_US),
> > > HPP__COLOR_ACC_PRINT_FNS("Children", overhead_acc, OVERHEAD_ACC),
> > > + HPP__COLOR_ACC_PRINT_FNS("Latency", latency_acc, LATENCY_ACC),
> >
> > Hmm.. two latency fields have the same name. Maybe better to
> > distinguish them but "Children Latency" or "Total Latency" would be
> > too long.. :(
> >
> > I think it's mostly ok since users will see them together with overhead
> > columns and it'll give the context ("Children" or "Self"). But it can
> > e called with -F or -s option to manually select those columns only.
>
> Yes, the motivation for calling them the same was the column name length.
>
> And, with the default flags it looks reasonable:
>
> Children Latency Self Latency Command
>
> The fields seem to be selected based on the names in sort.c rather
> than these names, e.g. I can do:
>
> perf report -F latency_children,overhead_children,latency,overhead,symbol
>
> and get:
>
> Samples: 45K of event 'cycles:Pu', Event count (approx.): 10457486861
> Latency Children Latency Overhead Symbol
> + 19.35% 18.69% 0.00% 0.00% [k] 0000000000000000
> + 4.86% 4.21% 4.86% 4.21% [.] htab_find_slot_with_hash
> + 4.15% 4.48% 0.00% 0.00% [.] 0xffffffff9ce012a6
>
> So it seems to be possible to select these columns as needed.
Right, it's possible to use -F latency,latency_children,symbol and get:
Samples: 45K of event 'cycles:Pu', Event count (approx.): 10457486861
Latency Latency Symbol
+ 0.00% 19.35% [k] 0000000000000000
+ 4.86% 4.86% [.] htab_find_slot_with_hash
+ 0.00% 4.15% [.] 0xffffffff9ce012a6
Thanks,
Namhyung
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v3 6/7] perf report: Add --latency flag
2025-01-29 7:12 ` Dmitry Vyukov
@ 2025-01-30 6:30 ` Namhyung Kim
2025-02-03 14:45 ` Dmitry Vyukov
0 siblings, 1 reply; 20+ messages in thread
From: Namhyung Kim @ 2025-01-30 6:30 UTC (permalink / raw)
To: Dmitry Vyukov
Cc: irogers, linux-perf-users, linux-kernel, Arnaldo Carvalho de Melo
On Wed, Jan 29, 2025 at 08:12:51AM +0100, Dmitry Vyukov wrote:
> On Wed, 29 Jan 2025 at 06:03, Namhyung Kim <namhyung@kernel.org> wrote:
> >
> > On Mon, Jan 27, 2025 at 10:58:53AM +0100, Dmitry Vyukov wrote:
> > > Add record/report --latency flag that allows to capture and show
> > > latency-centric profiles rather than the default CPU-consumption-centric
> > > profiles. For latency profiles record captures context switch events,
> > > and report shows Latency as the first column.
> >
> > It'd be nice if you could add a small example output in the commit
> > message.
> >
> > >
> > > Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
> > > Cc: Namhyung Kim <namhyung@kernel.org>
> > > Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
> > > Cc: Ian Rogers <irogers@google.com>
> > > Cc: linux-perf-users@vger.kernel.org
> > > Cc: linux-kernel@vger.kernel.org
> > > ---
> > [SNIP]
> > > diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
> > > index bc4c3acfe7552..2b6023de7a53a 100644
> > > --- a/tools/perf/util/sort.c
> > > +++ b/tools/perf/util/sort.c
> > > @@ -2622,6 +2622,7 @@ struct hpp_dimension {
> > > const char *name;
> > > struct perf_hpp_fmt *fmt;
> > > int taken;
> > > + int was_taken;
> > > };
> > >
> > > #define DIM(d, n) { .name = n, .fmt = &perf_hpp__format[d], }
> > > @@ -3513,6 +3514,7 @@ static int __hpp_dimension__add(struct hpp_dimension *hd,
> > > return -1;
> > >
> > > hd->taken = 1;
> > > + hd->was_taken = 1;
> > > perf_hpp_list__register_sort_field(list, fmt);
> > > return 0;
> > > }
> > > @@ -3547,10 +3549,15 @@ static int __hpp_dimension__add_output(struct perf_hpp_list *list,
> > > return 0;
> > > }
> > >
> > > -int hpp_dimension__add_output(unsigned col)
> > > +int hpp_dimension__add_output(unsigned col, bool implicit)
> > > {
> > > + struct hpp_dimension *hd;
> > > +
> > > BUG_ON(col >= PERF_HPP__MAX_INDEX);
> > > - return __hpp_dimension__add_output(&perf_hpp_list, &hpp_sort_dimensions[col]);
> > > + hd = &hpp_sort_dimensions[col];
> > > + if (implicit && !hd->was_taken)
> > > + return 0;
> >
> > I don't understand why you need 'was_taken' field. Can it use the
> > 'taken' field?
>
> I've started getting failed asserts in
> perf_hpp__cancel_cumulate/latency when removing columns still linked
> into sort order list.
Ok.
>
> I've figured out that columns we implicitly add in setup_overhead and
> perf_hpp__init must match exactly. If we add one in setup_overhead,
> but not in perf_hpp__init, then it starts failing.
Right, I don't remember why we don't have unregister_sort_field or let
the perf_hpp__column_unregister() remove it from the sort_list too.
>
> Taken does not work b/c there is reset_dimensions call between these
> functions, so they actually add the same columns twice to field/sort
> lists (and that prevents failures in
> perf_hpp__cancel_cumulate/latency).
I see.
>
> Initially I've just tried to match logic in setup_overhead and in
> perf_hpp__init. But it turned out quite messy, duplicate logic, and
> e.g. in setup_overhead we look at sort_order, but in perf_hpp__init we
> already can't look at it b/c we already altered it in setup_overhead.
> That logic would also be quite fragile. Adding was_taken looks like
> the simplest, most reliable, and less fragile with respect to future
> changes approach.
Maybe just remove it from the sort_list. There should be no reason to
keep it in the list.
>
>
> > > + return __hpp_dimension__add_output(&perf_hpp_list, hd);
> > > }
> > >
> > > int sort_dimension__add(struct perf_hpp_list *list, const char *tok,
> > > @@ -3809,10 +3816,24 @@ static char *setup_overhead(char *keys)
> > > if (sort__mode == SORT_MODE__DIFF)
> > > return keys;
> > >
> > > - keys = prefix_if_not_in("overhead", keys);
> > > -
> > > - if (symbol_conf.cumulate_callchain)
> > > - keys = prefix_if_not_in("overhead_children", keys);
> > > + if (symbol_conf.prefer_latency) {
> > > + keys = prefix_if_not_in("overhead", keys);
> > > + keys = prefix_if_not_in("latency", keys);
> > > + if (symbol_conf.cumulate_callchain) {
> > > + keys = prefix_if_not_in("overhead_children", keys);
> > > + keys = prefix_if_not_in("latency_children", keys);
> > > + }
> > > + } else if (!keys || (!strstr(keys, "overhead") &&
> > > + !strstr(keys, "latency"))) {
> > > + if (symbol_conf.enable_latency)
> > > + keys = prefix_if_not_in("latency", keys);
> > > + keys = prefix_if_not_in("overhead", keys);
> > > + if (symbol_conf.cumulate_callchain) {
> > > + if (symbol_conf.enable_latency)
> > > + keys = prefix_if_not_in("latency_children", keys);
> > > + keys = prefix_if_not_in("overhead_children", keys);
> > > + }
> > > + }
> >
> > Do you really need this complexity? I think it's better to fix the order
> > of columns in both case.
>
> This is sort order which affects ordering of row, and order of rows is
> basically the most important thing for a profiler. If we fix the
> order, it will be showing completely different things.
>
> "latency" and "overhead" are equivalent with respect to their
> fundamentality for a profile. So we shouldn't be adding any of them,
> if any of them are already explicitly specified by the user.
>
> For example, the command from tips.txt:
>
> perf report --hierarchy --sort latency,parallelism,comm,symbol
>
> if we prepend "overhead", it all falls apart.
>
> Or for 2 default modes (normals and latency) we want "overhead" or
> "latency" to come first. Prepending "latency" for the current CPU mode
> would lead to completely different ordering.
I see. You want to sort by overhead in the default mode even if it has
implicitly-added latency field, and to sort by latency if --latency is
given explicitly.
I think it can be done with the following command line.
$ perf report -F overhead,latency,parallelism,comm,sym -s overhead
or
$ perf report -F overhead,latency,parallelism,comm,sym -s latency
IOW, you can keep the same output column ordering and sort the result
differently. But I'm not sure if it'd make the code simpler. :)
Thanks,
Namhyung
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v3 2/7] perf report: Add parallelism sort key
2025-01-30 5:28 ` Namhyung Kim
@ 2025-02-03 14:40 ` Dmitry Vyukov
0 siblings, 0 replies; 20+ messages in thread
From: Dmitry Vyukov @ 2025-02-03 14:40 UTC (permalink / raw)
To: Namhyung Kim
Cc: irogers, linux-perf-users, linux-kernel, Arnaldo Carvalho de Melo
On Thu, 30 Jan 2025 at 06:28, Namhyung Kim <namhyung@kernel.org> wrote:
>
> On Wed, Jan 29, 2025 at 08:18:34AM +0100, Dmitry Vyukov wrote:
> > On Wed, 29 Jan 2025 at 05:42, Namhyung Kim <namhyung@kernel.org> wrote:
> > >
> > > On Mon, Jan 27, 2025 at 10:58:49AM +0100, Dmitry Vyukov wrote:
> > > > Show parallelism level in profiles if requested by user.
> > > >
> > > > Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
> > > > Cc: Namhyung Kim <namhyung@kernel.org>
> > > > Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
> > > > Cc: Ian Rogers <irogers@google.com>
> > > > Cc: linux-perf-users@vger.kernel.org
> > > > Cc: linux-kernel@vger.kernel.org
> > > > ---
> > > > tools/perf/builtin-report.c | 11 +++++++++++
> > > > tools/perf/util/hist.c | 2 ++
> > > > tools/perf/util/hist.h | 3 +++
> > > > tools/perf/util/session.c | 12 ++++++++++++
> > > > tools/perf/util/session.h | 1 +
> > > > tools/perf/util/sort.c | 23 +++++++++++++++++++++++
> > > > tools/perf/util/sort.h | 1 +
> > > > 7 files changed, 53 insertions(+)
> > > >
> > > > diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
> > > > index 0d9bd090eda71..14d49f0625881 100644
> > > > --- a/tools/perf/builtin-report.c
> > > > +++ b/tools/perf/builtin-report.c
> > > > @@ -1720,6 +1720,17 @@ int cmd_report(int argc, const char **argv)
> > > > symbol_conf.annotate_data_sample = true;
> > > > }
> > > >
> > > > + if (report.disable_order || !perf_session__has_switch_events(session)) {
> > > > + if ((sort_order && strstr(sort_order, "parallelism")) ||
> > > > + (field_order && strstr(field_order, "parallelism"))) {
> > > > + if (report.disable_order)
> > > > + ui__error("Use of parallelism is incompatible with --disable-order.\n");
> > > > + else
> > > > + ui__error("Use of parallelism requires --switch-events during record.\n");
> > > > + return -1;
> > > > + }
> > > > + }
> > > > +
> > > > if (sort_order && strstr(sort_order, "ipc")) {
> > > > parse_options_usage(report_usage, options, "s", 1);
> > > > goto error;
> > > > diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
> > > > index 0f30f843c566d..cafd693568189 100644
> > > > --- a/tools/perf/util/hist.c
> > > > +++ b/tools/perf/util/hist.c
> > > > @@ -207,6 +207,7 @@ void hists__calc_col_len(struct hists *hists, struct hist_entry *h)
> > > >
> > > > hists__new_col_len(hists, HISTC_CGROUP, 6);
> > > > hists__new_col_len(hists, HISTC_CGROUP_ID, 20);
> > > > + hists__new_col_len(hists, HISTC_PARALLELISM, 11);
> > > > hists__new_col_len(hists, HISTC_CPU, 3);
> > > > hists__new_col_len(hists, HISTC_SOCKET, 6);
> > > > hists__new_col_len(hists, HISTC_MEM_LOCKED, 6);
> > > > @@ -741,6 +742,7 @@ __hists__add_entry(struct hists *hists,
> > > > .ip = al->addr,
> > > > .level = al->level,
> > > > .code_page_size = sample->code_page_size,
> > > > + .parallelism = al->parallelism,
> > > > .stat = {
> > > > .nr_events = 1,
> > > > .period = sample->period,
> > > > diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
> > > > index 46c8373e31465..a6e662d77dc24 100644
> > > > --- a/tools/perf/util/hist.h
> > > > +++ b/tools/perf/util/hist.h
> > > > @@ -42,6 +42,7 @@ enum hist_column {
> > > > HISTC_CGROUP_ID,
> > > > HISTC_CGROUP,
> > > > HISTC_PARENT,
> > > > + HISTC_PARALLELISM,
> > > > HISTC_CPU,
> > > > HISTC_SOCKET,
> > > > HISTC_SRCLINE,
> > > > @@ -228,6 +229,7 @@ struct hist_entry {
> > > > u64 transaction;
> > > > s32 socket;
> > > > s32 cpu;
> > > > + int parallelism;
> > >
> > > Can you make it u16 and move to around cpumode to remove paddings?
> >
> > It generally should be the same size as cpu/socket/etc. And these are
> > 32-bits throughout the codebase (the previous fields). Are there any
> > checks that MAX_NR_CPUS<64K?
>
> I don't think there's such a check. But practically it used be 4K and
> you can add the check. :)
>
> Anyway hist_entry is getting bigger and we may need to shrink it later.
> I don't stringly insist on u16 though. It's up to you.
Added this commit to v4:
perf hist: Shrink struct hist_entry size
https://lore.kernel.org/linux-perf-users/75dd56a2d467515dc354d8fc8d5acd841d63b565.1738592865.git.dvyukov@google.com/T/#u
It cuts 8 bytes, which I hope is enough to compensate for my 4 added bytes :)
However, it's 584 bytes, so it saves like 1%.
If hist_entry size is a problem I think the following approaches will
have more impact (not saying I want to do it as part of this series
:)):
1. Make hist_entry layout dynamic (like the kernel perf event data) to
completely exclude unused parts when they are unused.
2. Add slab allocator for hist_entry which won't round up allocation size.
E.g. if you take default TCMalloc size classes, that's 576 and then
640. So this messing with padding actually doesn't save anything. We
shave off 1%, but the actual heap block is still 10% wasted.
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v3 6/7] perf report: Add --latency flag
2025-01-30 6:30 ` Namhyung Kim
@ 2025-02-03 14:45 ` Dmitry Vyukov
0 siblings, 0 replies; 20+ messages in thread
From: Dmitry Vyukov @ 2025-02-03 14:45 UTC (permalink / raw)
To: Namhyung Kim
Cc: irogers, linux-perf-users, linux-kernel, Arnaldo Carvalho de Melo
On Thu, 30 Jan 2025 at 07:30, Namhyung Kim <namhyung@kernel.org> wrote:
>
> On Wed, Jan 29, 2025 at 08:12:51AM +0100, Dmitry Vyukov wrote:
> > On Wed, 29 Jan 2025 at 06:03, Namhyung Kim <namhyung@kernel.org> wrote:
> > >
> > > On Mon, Jan 27, 2025 at 10:58:53AM +0100, Dmitry Vyukov wrote:
> > > > Add record/report --latency flag that allows to capture and show
> > > > latency-centric profiles rather than the default CPU-consumption-centric
> > > > profiles. For latency profiles record captures context switch events,
> > > > and report shows Latency as the first column.
> > >
> > > It'd be nice if you could add a small example output in the commit
> > > message.
> > >
> > > >
> > > > Signed-off-by: Dmitry Vyukov <dvyukov@google.com>
> > > > Cc: Namhyung Kim <namhyung@kernel.org>
> > > > Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
> > > > Cc: Ian Rogers <irogers@google.com>
> > > > Cc: linux-perf-users@vger.kernel.org
> > > > Cc: linux-kernel@vger.kernel.org
> > > > ---
> > > [SNIP]
> > > > diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
> > > > index bc4c3acfe7552..2b6023de7a53a 100644
> > > > --- a/tools/perf/util/sort.c
> > > > +++ b/tools/perf/util/sort.c
> > > > @@ -2622,6 +2622,7 @@ struct hpp_dimension {
> > > > const char *name;
> > > > struct perf_hpp_fmt *fmt;
> > > > int taken;
> > > > + int was_taken;
> > > > };
> > > >
> > > > #define DIM(d, n) { .name = n, .fmt = &perf_hpp__format[d], }
> > > > @@ -3513,6 +3514,7 @@ static int __hpp_dimension__add(struct hpp_dimension *hd,
> > > > return -1;
> > > >
> > > > hd->taken = 1;
> > > > + hd->was_taken = 1;
> > > > perf_hpp_list__register_sort_field(list, fmt);
> > > > return 0;
> > > > }
> > > > @@ -3547,10 +3549,15 @@ static int __hpp_dimension__add_output(struct perf_hpp_list *list,
> > > > return 0;
> > > > }
> > > >
> > > > -int hpp_dimension__add_output(unsigned col)
> > > > +int hpp_dimension__add_output(unsigned col, bool implicit)
> > > > {
> > > > + struct hpp_dimension *hd;
> > > > +
> > > > BUG_ON(col >= PERF_HPP__MAX_INDEX);
> > > > - return __hpp_dimension__add_output(&perf_hpp_list, &hpp_sort_dimensions[col]);
> > > > + hd = &hpp_sort_dimensions[col];
> > > > + if (implicit && !hd->was_taken)
> > > > + return 0;
> > >
> > > I don't understand why you need 'was_taken' field. Can it use the
> > > 'taken' field?
> >
> > I've started getting failed asserts in
> > perf_hpp__cancel_cumulate/latency when removing columns still linked
> > into sort order list.
>
> Ok.
>
> >
> > I've figured out that columns we implicitly add in setup_overhead and
> > perf_hpp__init must match exactly. If we add one in setup_overhead,
> > but not in perf_hpp__init, then it starts failing.
>
> Right, I don't remember why we don't have unregister_sort_field or let
> the perf_hpp__column_unregister() remove it from the sort_list too.
>
> >
> > Taken does not work b/c there is reset_dimensions call between these
> > functions, so they actually add the same columns twice to field/sort
> > lists (and that prevents failures in
> > perf_hpp__cancel_cumulate/latency).
>
> I see.
>
> >
> > Initially I've just tried to match logic in setup_overhead and in
> > perf_hpp__init. But it turned out quite messy, duplicate logic, and
> > e.g. in setup_overhead we look at sort_order, but in perf_hpp__init we
> > already can't look at it b/c we already altered it in setup_overhead.
> > That logic would also be quite fragile. Adding was_taken looks like
> > the simplest, most reliable, and less fragile with respect to future
> > changes approach.
>
> Maybe just remove it from the sort_list. There should be no reason to
> keep it in the list.
I've tried that (and removing setup_overhead entirely), but none of
that yielded the same result.
E.g.:
perf report --sort latency,symbol
currently gives intended:
Latency Symbol
4.37% [k] native_queued_spin_lock_slowpath
2.71% [.] _PyEval_EvalFrameDefault
2.18% [.] iterative_hash
2.00% [k] clear_page_erms
but if I remove was_taken logic and make perf_hpp__column_unregister()
remove from the sort list, I get:
Overhead Latency Symbol
38.17% 4.37% [k] native_queued_spin_lock_slowpath
0.86% 2.71% [.] _PyEval_EvalFrameDefault
0.47% 2.18% [.] iterative_hash
0.68% 2.00% [k] clear_page_erms
So, so far the current version of the code is unfortunately the
simplest version with intended behavior that I come up with.
> > > > + return __hpp_dimension__add_output(&perf_hpp_list, hd);
> > > > }
> > > >
> > > > int sort_dimension__add(struct perf_hpp_list *list, const char *tok,
> > > > @@ -3809,10 +3816,24 @@ static char *setup_overhead(char *keys)
> > > > if (sort__mode == SORT_MODE__DIFF)
> > > > return keys;
> > > >
> > > > - keys = prefix_if_not_in("overhead", keys);
> > > > -
> > > > - if (symbol_conf.cumulate_callchain)
> > > > - keys = prefix_if_not_in("overhead_children", keys);
> > > > + if (symbol_conf.prefer_latency) {
> > > > + keys = prefix_if_not_in("overhead", keys);
> > > > + keys = prefix_if_not_in("latency", keys);
> > > > + if (symbol_conf.cumulate_callchain) {
> > > > + keys = prefix_if_not_in("overhead_children", keys);
> > > > + keys = prefix_if_not_in("latency_children", keys);
> > > > + }
> > > > + } else if (!keys || (!strstr(keys, "overhead") &&
> > > > + !strstr(keys, "latency"))) {
> > > > + if (symbol_conf.enable_latency)
> > > > + keys = prefix_if_not_in("latency", keys);
> > > > + keys = prefix_if_not_in("overhead", keys);
> > > > + if (symbol_conf.cumulate_callchain) {
> > > > + if (symbol_conf.enable_latency)
> > > > + keys = prefix_if_not_in("latency_children", keys);
> > > > + keys = prefix_if_not_in("overhead_children", keys);
> > > > + }
> > > > + }
> > >
> > > Do you really need this complexity? I think it's better to fix the order
> > > of columns in both case.
> >
> > This is sort order which affects ordering of row, and order of rows is
> > basically the most important thing for a profiler. If we fix the
> > order, it will be showing completely different things.
> >
> > "latency" and "overhead" are equivalent with respect to their
> > fundamentality for a profile. So we shouldn't be adding any of them,
> > if any of them are already explicitly specified by the user.
> >
> > For example, the command from tips.txt:
> >
> > perf report --hierarchy --sort latency,parallelism,comm,symbol
> >
> > if we prepend "overhead", it all falls apart.
> >
> > Or for 2 default modes (normals and latency) we want "overhead" or
> > "latency" to come first. Prepending "latency" for the current CPU mode
> > would lead to completely different ordering.
>
> I see. You want to sort by overhead in the default mode even if it has
> implicitly-added latency field, and to sort by latency if --latency is
> given explicitly.
>
> I think it can be done with the following command line.
>
> $ perf report -F overhead,latency,parallelism,comm,sym -s overhead
>
> or
>
> $ perf report -F overhead,latency,parallelism,comm,sym -s latency
>
> IOW, you can keep the same output column ordering and sort the result
> differently. But I'm not sure if it'd make the code simpler. :)
>
> Thanks,
> Namhyung
>
^ permalink raw reply [flat|nested] 20+ messages in thread
end of thread, other threads:[~2025-02-03 14:45 UTC | newest]
Thread overview: 20+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2025-01-27 9:58 [PATCH v3 0/7] perf report: Add latency and parallelism profiling Dmitry Vyukov
2025-01-27 9:58 ` [PATCH v3 1/7] perf report: Add machine parallelism Dmitry Vyukov
2025-01-27 9:58 ` [PATCH v3 2/7] perf report: Add parallelism sort key Dmitry Vyukov
2025-01-29 4:42 ` Namhyung Kim
2025-01-29 7:18 ` Dmitry Vyukov
2025-01-30 5:28 ` Namhyung Kim
2025-02-03 14:40 ` Dmitry Vyukov
2025-01-27 9:58 ` [PATCH v3 3/7] perf report: Switch filtered from u8 to u16 Dmitry Vyukov
2025-01-27 9:58 ` [PATCH v3 4/7] perf report: Add parallelism filter Dmitry Vyukov
2025-01-27 9:58 ` [PATCH v3 5/7] perf report: Add latency output field Dmitry Vyukov
2025-01-29 4:56 ` Namhyung Kim
2025-01-29 6:55 ` Dmitry Vyukov
2025-01-30 5:33 ` Namhyung Kim
2025-01-27 9:58 ` [PATCH v3 6/7] perf report: Add --latency flag Dmitry Vyukov
2025-01-29 5:03 ` Namhyung Kim
2025-01-29 7:12 ` Dmitry Vyukov
2025-01-30 6:30 ` Namhyung Kim
2025-02-03 14:45 ` Dmitry Vyukov
2025-01-27 9:58 ` [PATCH v3 7/7] perf report: Add latency and parallelism profiling documentation Dmitry Vyukov
2025-01-29 5:05 ` [PATCH v3 0/7] perf report: Add latency and parallelism profiling 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).