* [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support
@ 2026-08-05 21:07 Aaron Tomlin
2026-08-05 21:07 ` [PATCH v8 1/4] perf sched: Suppress latency table output when trace samples are missing Aaron Tomlin
` (5 more replies)
0 siblings, 6 replies; 8+ messages in thread
From: Aaron Tomlin @ 2026-08-05 21:07 UTC (permalink / raw)
To: peterz, mingo, acme, namhyung
Cc: mark.rutland, alexander.shishkin, jolsa, irogers, adrian.hunter,
james.clark, howardchu95, atomlin, neelx, chjohnst, sean, steve,
rishil1999, linux-perf-users, linux-kernel
Hi Namhyung, Ian, Arnaldo,
This patch series improves 'perf sched latency' by suppressing misleading
empty table output, extending pipe mode stream processing, introducing
dynamic unit auto-scaling for latency and runtime statistics, and adding
latency histogram visualisation alongside time-span filtering.
Patch 1 addresses an issue where 'perf sched latency' fell through and
returned success (0) when perf_session__has_traces() failed due to missing
tracepoint events in a perf.data file. This caused empty header tables and
zeroed summary statistics to be rendered. In addition,
thread__get_runtime() in map_switch_event() is guarded against potential
NULL pointer dereferences under memory allocation failures.
Patch 2 extends pipe mode stream support. Because event attributes in pipe
mode are received dynamically during event processing, session->evlist is
not populated prior to event processing.
To handle pipe input correctly:
- Register the missing .attr, .tracing_data, .build_id, and .feature
callbacks in cmd_sched()
- Promote the handlers array to file-scope (latency_handlers[]) and
dynamically assign matching tracepoint handlers (or
process_sched_ignore) inside perf_sched__process_tracepoint_sample()
when evsel->handler is NULL; replace process_sched_wakeup_ignore()
with process_sched_ignore()
- Perform the trace check post-processing when handling pipe data
Patch 3 introduces dynamic auto-scaling for latency and runtime display
columns (Runtime, Avg delay, Max delay). Previously, all values were
unconditionally formatted in milliseconds (ms), making microsecond- or
second-scale latencies difficult to read. Columns are now dynamically
scaled to the most appropriate unit (ns, us, ms, s), column headers are
updated, and format specifiers are aligned character-for-character with
table headers.
Patch 4 adds three new command-line options to 'perf sched latency':
--histogram (-H):
Displays an ASCII bar chart of CPU wait latencies between
snapshots
--hist-mode:
Configures the bucketing scheme to either logarithmic (log) or
100 us equal-width linear (linear) mode
--time:
Filters trace event processing to a specified [start,stop] time
span
Changes since v7:
- Added a guard clause in perf_sched__process_tracepoint_sample() to
reduce loop indentation (Namhyung Kim)
- Converted dummy process_sched_wakeup_ignore() references to
process_sched_ignore and eliminated redundant code (Namhyung Kim)
- Replaced string comparisons with faster integer checks (i.e.,
thread__tid(...) != 0) for swapper (idle thread) handling (Namhyung Kim)
- Added automated test cases for --histogram, --hist-mode, and --time into
tools/perf/tests/shell/sched.sh (Namhyung Kim)
- Link to v7: https://lore.kernel.org/lkml/20260802210914.199941-1-atomlin@atomlin.com/
Changes since v6:
- Fixed O(N) hot-path traversal overhead in
perf_sched__process_tracepoint_sample() for unhandled tracepoints by
assigning a dummy ignore handler (process_sched_ignore)
- Replaced evlist__set_tracepoints_handlers() in sample processing with a
per-evsel lookup to prevent -EEXIST early aborts and avoid dropping
late-arriving pipe events
- Updated commit message for the pipe mode patch to reflect the
single-pass handler assignment logic
- Link to v6: https://lore.kernel.org/lkml/20260801234008.176724-1-atomlin@atomlin.com/
Changes since v5:
- Split pipe mode trace sample handling from Patch 1 into a standalone
patch (Namhyung Kim)
- Added a Fixes: tag to the pipe mode patch referencing commit
27295592c22e ("perf session: Share the common trace sample_check routine
as perf_session__has_traces")
- Updated commit log with before and after illustrations of table header
formatting
- Link to v5: https://lore.kernel.org/lkml/20260730185416.97166-1-atomlin@atomlin.com/
Changes since v4:
- Added the missing .feature callback to sched.tool in cmd_sched()
- Fixed memory leak by reusing uncompleted work atoms when sched_in events
are skipped or lost
- Promoted the handlers array to file-scope (i.e., latency_handlers[]) and
added a dynamic lookup via evlist__set_tracepoints_handlers() inside
perf_sched__process_tracepoint_sample() whenever a sample arrives with
an unattached handler (i.e., evsel->handler == NULL)
- Prevented double-counting wakeups (i.e., ignore sched:sched_wakeup)
in pipe mode and non-pipe modes
- Added missing trailing pipe in output_lat_thread's new auto-scaling
format string
- Stripped redundant prefix strings from each row's format string to
produce a clean, tabular output
- Link to v4: https://lore.kernel.org/lkml/20260729144451.38286-1-atomlin@atomlin.com/
Changes since v3:
- Registered Missing Callbacks. In perf_tool__init configuration inside
cmd_sched(), added the .attr, .tracing_data, and .build_id callbacks.
Without these callbacks, pipe mode drops header attributes entirely,
preventing tracepoints from being populated in session->evlist
- Introduced an explicit post-processing pipe check. This ensures that
pipe mode aborts correctly and does not produce superfluous empty
latency tables when no trace samples are available
- Prevented potential NULL pointer dereference. Added a NULL check for
thread__get_runtime() in map_switch_event() under memory allocation
failures
- Fixed column alignment. Modified format specifiers to align
character-for-character with header column widths across all rows
- Adjusted header label padding. Updated header label padding and column
width delimiters in perf_sched__lat() to match the exact field format
specifiers printed in output_lat_thread()
- Fixed swapper histogram inclusion. Excluded "swapper" (i.e.,
CPU-specific idle thread) from global_hist buckets
- Preserved task state machine across --time bounds. Moved time-window
filtering inside add_sched_in_event() to gate latency statistics
recording without breaking wakeup state tracking across time interval
boundaries
- Link to v3: https://lore.kernel.org/lkml/20260726032533.712462-1-atomlin@atomlin.com/
Changes since v2:
- Ensured vertical pipe separators align across all latency table columns
- Excluded "swapper" (idle thread) latency samples from global_hist
- Preserved task state machine transitions across --time boundaries
- Suppressed empty table headers, total lines, and histogram graphs when
no matching trace samples exist (e.g., when --time, --CPU, or --pids
exclude all samples), outputting "No matching trace samples found."
instead
- Linked to v2: https://lore.kernel.org/lkml/20260725173341.679782-1-atomlin@atomlin.com/
Changes since v1:
- Fixed integer overflow in latency_bucket() (Ian Rogers)
- Linked to v1: https://lore.kernel.org/lkml/20260724142901.634761-1-atomlin@atomlin.com/
Aaron Tomlin (4):
perf sched: Suppress latency table output when trace samples are
missing
perf sched: Handle missing trace samples in pipe mode
perf sched latency: Auto-scale latency and runtime display units
perf sched latency: Add histogram and time interval options
tools/perf/Documentation/perf-sched.txt | 6 +
tools/perf/builtin-sched.c | 347 ++++++++++++++++++++----
tools/perf/tests/shell/sched.sh | 29 ++
3 files changed, 332 insertions(+), 50 deletions(-)
--
2.55.0
^ permalink raw reply [flat|nested] 8+ messages in thread
* [PATCH v8 1/4] perf sched: Suppress latency table output when trace samples are missing
2026-08-05 21:07 [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support Aaron Tomlin
@ 2026-08-05 21:07 ` Aaron Tomlin
2026-08-05 21:07 ` [PATCH v8 2/4] perf sched: Handle missing trace samples in pipe mode Aaron Tomlin
` (4 subsequent siblings)
5 siblings, 0 replies; 8+ messages in thread
From: Aaron Tomlin @ 2026-08-05 21:07 UTC (permalink / raw)
To: peterz, mingo, acme, namhyung
Cc: mark.rutland, alexander.shishkin, jolsa, irogers, adrian.hunter,
james.clark, howardchu95, atomlin, neelx, chjohnst, sean, steve,
rishil1999, linux-perf-users, linux-kernel
When 'perf sched latency' is executed on a perf.data file that lacks
tracepoint samples (i.e., a file recorded without the -R flag or
containing only non-tracepoint events), perf_session__has_traces()
correctly outputs an error message. However, perf_sched__read_events()
subsequently falls through and returns 0 (success).
Consequently, caller functions such as perf_sched__lat() assume event
processing succeeded and proceed to render empty latency header tables
and total summary statistics.
Fix this behaviour by ensuring perf_sched__read_events() aborts early and
returns a suitable error code when perf_session__has_traces() evaluates
to false.
Additionally, validate thread__get_runtime() against NULL in
map_switch_event() to prevent potential null-pointer dereferences.
Fixes: 27295592c22e ("perf session: Share the common trace sample_check routine as perf_session__has_traces")
Signed-off-by: Aaron Tomlin <atomlin@atomlin.com>
---
tools/perf/builtin-sched.c | 23 ++++++++++++-----------
1 file changed, 12 insertions(+), 11 deletions(-)
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index 7fd63a9db457..94a323da0799 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -1833,7 +1833,7 @@ static int map_switch_event(struct perf_sched *sched, struct perf_sample *sampl
sched_out:
if (sched->map.task_name) {
tr = thread__get_runtime(sched->curr_out_thread[this_cpu.cpu]);
- if (strcmp(tr->shortname, "") == 0)
+ if (tr == NULL || strcmp(tr->shortname, "") == 0)
goto out;
if (proceed == 1)
@@ -2001,7 +2001,7 @@ static int perf_sched__read_events(struct perf_sched *sched)
.mode = PERF_DATA_MODE_READ,
.force = sched->force,
};
- int rc = -1;
+ int rc = -1, err;
session = perf_session__new(&data, &sched->tool);
if (IS_ERR(session)) {
@@ -2018,18 +2018,19 @@ static int perf_sched__read_events(struct perf_sched *sched)
if (perf_session__set_tracepoints_handlers(session, handlers))
goto out_delete;
- if (perf_session__has_traces(session, "record -R")) {
- int err = perf_session__process_events(session);
- if (err) {
- pr_err("Failed to process events, error %d", err);
- goto out_delete;
- }
+ if (!perf_session__has_traces(session, "record -R"))
+ goto out_delete;
- sched->nr_events = session->evlist->stats.nr_events[0];
- sched->nr_lost_events = session->evlist->stats.total_lost;
- sched->nr_lost_chunks = session->evlist->stats.nr_events[PERF_RECORD_LOST];
+ err = perf_session__process_events(session);
+ if (err) {
+ pr_err("Failed to process events, error %d", err);
+ goto out_delete;
}
+ sched->nr_events = session->evlist->stats.nr_events[0];
+ sched->nr_lost_events = session->evlist->stats.total_lost;
+ sched->nr_lost_chunks = session->evlist->stats.nr_events[PERF_RECORD_LOST];
+
rc = 0;
out_delete:
perf_session__delete(session);
--
2.55.0
^ permalink raw reply related [flat|nested] 8+ messages in thread
* [PATCH v8 2/4] perf sched: Handle missing trace samples in pipe mode
2026-08-05 21:07 [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support Aaron Tomlin
2026-08-05 21:07 ` [PATCH v8 1/4] perf sched: Suppress latency table output when trace samples are missing Aaron Tomlin
@ 2026-08-05 21:07 ` Aaron Tomlin
2026-08-05 21:07 ` [PATCH v8 3/4] perf sched latency: Auto-scale latency and runtime display units Aaron Tomlin
` (3 subsequent siblings)
5 siblings, 0 replies; 8+ messages in thread
From: Aaron Tomlin @ 2026-08-05 21:07 UTC (permalink / raw)
To: peterz, mingo, acme, namhyung
Cc: mark.rutland, alexander.shishkin, jolsa, irogers, adrian.hunter,
james.clark, howardchu95, atomlin, neelx, chjohnst, sean, steve,
rishil1999, linux-perf-users, linux-kernel
For pipe mode streams, event attributes are received dynamically during
event processing, meaning session->evlist is not populated prior to
perf_session__process_events(). To handle pipe input correctly:
- Register the missing .attr, .tracing_data, .build_id, and .feature
callbacks in cmd_sched()
- Promote the handlers array to file-scope (latency_handlers[]) and
dynamically assign matching tracepoint handlers
(or process_sched_ignore) inside
perf_sched__process_tracepoint_sample() when evsel->handler is NULL;
replace process_sched_wakeup_ignore() with process_sched_ignore()
- Perform the trace check post-processing when handling pipe data
Fixes: 27295592c22e ("perf session: Share the common trace sample_check routine as perf_session__has_traces")
Signed-off-by: Aaron Tomlin <atomlin@atomlin.com>
---
tools/perf/builtin-sched.c | 72 +++++++++++++++++++++++++++-----------
1 file changed, 51 insertions(+), 21 deletions(-)
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index 94a323da0799..d6b4412045e2 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -1581,12 +1581,6 @@ static int process_sched_wakeup_event(const struct perf_tool *tool,
return 0;
}
-static int process_sched_wakeup_ignore(const struct perf_tool *tool __maybe_unused,
- struct perf_sample *sample __maybe_unused,
- struct machine *machine __maybe_unused)
-{
- return 0;
-}
static bool thread__has_color(struct thread *thread)
{
@@ -1938,6 +1932,22 @@ typedef int (*tracepoint_handler)(const struct perf_tool *tool,
struct perf_sample *sample,
struct machine *machine);
+static struct evsel_str_handler latency_handlers[] = {
+ { "sched:sched_switch", process_sched_switch_event, },
+ { "sched:sched_stat_runtime", process_sched_runtime_event, },
+ { "sched:sched_wakeup", process_sched_wakeup_event, },
+ { "sched:sched_waking", process_sched_wakeup_event, },
+ { "sched:sched_wakeup_new", process_sched_wakeup_event, },
+ { "sched:sched_migrate_task", process_sched_migrate_task_event, },
+};
+
+static int process_sched_ignore(const struct perf_tool *tool __maybe_unused,
+ struct perf_sample *sample __maybe_unused,
+ struct machine *machine __maybe_unused)
+{
+ return 0;
+}
+
static int perf_sched__process_tracepoint_sample(const struct perf_tool *tool __maybe_unused,
union perf_event *event __maybe_unused,
struct perf_sample *sample,
@@ -1946,7 +1956,23 @@ static int perf_sched__process_tracepoint_sample(const struct perf_tool *tool __
struct evsel *evsel = sample->evsel;
int err = 0;
- if (evsel->handler != NULL) {
+ if (evsel->handler == NULL) {
+ evsel->handler = process_sched_ignore;
+ for (size_t i = 0; i < ARRAY_SIZE(latency_handlers); i++) {
+ if (!evsel__name_is(evsel, latency_handlers[i].name))
+ continue;
+
+ if (!strcmp(latency_handlers[i].name, "sched:sched_wakeup") &&
+ sample->evsel->evlist &&
+ evlist__find_tracepoint_by_name(sample->evsel->evlist, "sched:sched_waking"))
+ break;
+
+ evsel->handler = latency_handlers[i].handler;
+ break;
+ }
+ }
+
+ if (evsel->handler != process_sched_ignore) {
tracepoint_handler f = evsel->handler;
err = f(tool, sample, machine);
}
@@ -1987,14 +2013,6 @@ static int perf_sched__process_comm(const struct perf_tool *tool __maybe_unused,
static int perf_sched__read_events(struct perf_sched *sched)
{
- struct evsel_str_handler handlers[] = {
- { "sched:sched_switch", process_sched_switch_event, },
- { "sched:sched_stat_runtime", process_sched_runtime_event, },
- { "sched:sched_wakeup", process_sched_wakeup_event, },
- { "sched:sched_waking", process_sched_wakeup_event, },
- { "sched:sched_wakeup_new", process_sched_wakeup_event, },
- { "sched:sched_migrate_task", process_sched_migrate_task_event, },
- };
struct perf_session *session;
struct perf_data data = {
.path = input_name,
@@ -2011,14 +2029,17 @@ static int perf_sched__read_events(struct perf_sched *sched)
symbol__init(perf_session__env(session));
- /* prefer sched_waking if it is captured */
- if (evlist__find_tracepoint_by_name(session->evlist, "sched:sched_waking"))
- handlers[2].handler = process_sched_wakeup_ignore;
+ if (!perf_data__is_pipe(session->data)) {
+ /* prefer sched_waking if it is captured */
+ if (evlist__find_tracepoint_by_name(session->evlist, "sched:sched_waking"))
+ latency_handlers[2].handler = process_sched_ignore;
- if (perf_session__set_tracepoints_handlers(session, handlers))
- goto out_delete;
+ if (perf_session__set_tracepoints_handlers(session, latency_handlers))
+ goto out_delete;
+ }
- if (!perf_session__has_traces(session, "record -R"))
+ if (!perf_data__is_pipe(session->data) &&
+ !perf_session__has_traces(session, "record -R"))
goto out_delete;
err = perf_session__process_events(session);
@@ -2027,6 +2048,11 @@ static int perf_sched__read_events(struct perf_sched *sched)
goto out_delete;
}
+ if (perf_data__is_pipe(session->data) &&
+ !perf_session__has_traces(session, "record -R")) {
+ goto out_delete;
+ }
+
sched->nr_events = session->evlist->stats.nr_events[0];
sched->nr_lost_events = session->evlist->stats.total_lost;
sched->nr_lost_chunks = session->evlist->stats.nr_events[PERF_RECORD_LOST];
@@ -5168,6 +5194,10 @@ int cmd_sched(int argc, const char **argv)
sched.tool.namespaces = perf_event__process_namespaces;
sched.tool.lost = perf_event__process_lost;
sched.tool.fork = perf_sched__process_fork_event;
+ sched.tool.attr = perf_event__process_attr;
+ sched.tool.tracing_data = perf_event__process_tracing_data;
+ sched.tool.build_id = perf_event__process_build_id;
+ sched.tool.feature = perf_event__process_feature;
argc = parse_options_subcommand(argc, argv, sched_options, sched_subcommands,
sched_usage, PARSE_OPT_STOP_AT_NON_OPTION);
--
2.55.0
^ permalink raw reply related [flat|nested] 8+ messages in thread
* [PATCH v8 3/4] perf sched latency: Auto-scale latency and runtime display units
2026-08-05 21:07 [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support Aaron Tomlin
2026-08-05 21:07 ` [PATCH v8 1/4] perf sched: Suppress latency table output when trace samples are missing Aaron Tomlin
2026-08-05 21:07 ` [PATCH v8 2/4] perf sched: Handle missing trace samples in pipe mode Aaron Tomlin
@ 2026-08-05 21:07 ` Aaron Tomlin
2026-08-05 21:07 ` [PATCH v8 4/4] perf sched latency: Add histogram and time interval options Aaron Tomlin
` (2 subsequent siblings)
5 siblings, 0 replies; 8+ messages in thread
From: Aaron Tomlin @ 2026-08-05 21:07 UTC (permalink / raw)
To: peterz, mingo, acme, namhyung
Cc: mark.rutland, alexander.shishkin, jolsa, irogers, adrian.hunter,
james.clark, howardchu95, atomlin, neelx, chjohnst, sean, steve,
rishil1999, linux-perf-users, linux-kernel
Currently, 'perf sched latency' displays task runtime and delay values
exclusively in milliseconds (ms). This can be hard to read when
latencies are very small (in the microsecond or nanosecond range) or
unusually large (seconds).
Introduce auto-scaling for latency and runtime display columns. Values
are dynamically scaled and output with the most appropriate unit:
nanoseconds (ns), microseconds (us), milliseconds (ms), or seconds (s).
Additionally, rename column headers from "Runtime ms", "Avg delay ms",
and "Max delay ms" to "Runtime", "Avg delay", and "Max delay"
respectively, adjust spacing to maintain column alignment and stripe
redundant prefix strings from each row's format string to produce a
clean, tabular output.
For illustrative purposes, a comparison of the latency table header
before and after this change is shown below:
Before:
-------------------------------------------------------------------------------------------------------------------------------------------
Task | Runtime ms | Count | Avg delay ms | Max delay ms | Max delay start | Max delay end |
-------------------------------------------------------------------------------------------------------------------------------------------
kworker/2:2-mm_:154757 | 0.033 ms | 1 | avg: 0.829 ms | max: 0.829 ms | max start: 169486.543205 s | max end: 169486.544034 s
After:
------------------------------------------------------------------------------------------------------------------------------------------
Task | Runtime | Count | Avg delay | Max delay | Max delay start | Max delay end |
------------------------------------------------------------------------------------------------------------------------------------------
kworker/2:2-mm_:154757 | 32.873 us | 1 | 829.347 us | 829.347 us | 169486.543205 s | 169486.544034 s |
Signed-off-by: Aaron Tomlin <atomlin@atomlin.com>
---
tools/perf/builtin-sched.c | 46 ++++++++++++++++++++++++++------------
1 file changed, 32 insertions(+), 14 deletions(-)
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index d6b4412045e2..18282ab669e3 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -246,6 +246,17 @@ struct perf_sched {
struct perf_data *data;
};
+static int scnprintf_latency_unit(char *buf, size_t size, u64 nsecs)
+{
+ if (nsecs < 1000)
+ return scnprintf(buf, size, "%6" PRIu64 " ns", nsecs);
+ if (nsecs < NSEC_PER_MSEC)
+ return scnprintf(buf, size, "%6.3f us", (double)nsecs / NSEC_PER_USEC);
+ if (nsecs < NSEC_PER_SEC)
+ return scnprintf(buf, size, "%6.3f ms", (double)nsecs / NSEC_PER_MSEC);
+ return scnprintf(buf, size, "%6.3f s ", (double)nsecs / NSEC_PER_SEC);
+}
+
/* per thread run time data */
struct thread_runtime {
u64 last_time; /* time of previous sched in/out event */
@@ -1405,6 +1416,8 @@ static void output_lat_thread(struct perf_sched *sched, struct work_atoms *work_
int i;
int ret;
u64 avg;
+ char runtime_lat[32];
+ char avg_lat[32], max_lat[32];
char max_lat_start[32], max_lat_end[32];
if (!work_list->nb_atoms)
@@ -1419,10 +1432,10 @@ static void output_lat_thread(struct perf_sched *sched, struct work_atoms *work_
sched->all_count += work_list->nb_atoms;
if (work_list->num_merged > 1) {
- ret = printf(" %s:(%d) ", thread__comm_str(work_list->thread),
+ ret = printf(" %s:(%d)", thread__comm_str(work_list->thread),
work_list->num_merged);
} else {
- ret = printf(" %s:%d ", thread__comm_str(work_list->thread),
+ ret = printf(" %s:%d", thread__comm_str(work_list->thread),
thread__tid(work_list->thread));
}
@@ -1430,14 +1443,17 @@ static void output_lat_thread(struct perf_sched *sched, struct work_atoms *work_
printf(" ");
avg = work_list->total_lat / work_list->nb_atoms;
+ scnprintf_latency_unit(runtime_lat, sizeof(runtime_lat), work_list->total_runtime);
+ scnprintf_latency_unit(avg_lat, sizeof(avg_lat), avg);
+ scnprintf_latency_unit(max_lat, sizeof(max_lat), work_list->max_lat);
timestamp__scnprintf_usec(work_list->max_lat_start, max_lat_start, sizeof(max_lat_start));
timestamp__scnprintf_usec(work_list->max_lat_end, max_lat_end, sizeof(max_lat_end));
- printf("|%11.3f ms |%9" PRIu64 " | avg:%8.3f ms | max:%8.3f ms | max start: %12s s | max end: %12s s\n",
- (double)work_list->total_runtime / NSEC_PER_MSEC,
- work_list->nb_atoms, (double)avg / NSEC_PER_MSEC,
- (double)work_list->max_lat / NSEC_PER_MSEC,
- max_lat_start, max_lat_end);
+ printf(" |%15s |%9" PRIu64 " |%16s |%16s |%20s s |%20s s |\n",
+ runtime_lat,
+ work_list->nb_atoms, avg_lat, max_lat,
+ max_lat_start, max_lat_end);
+
}
static int pid_cmp(struct work_atoms *l, struct work_atoms *r)
@@ -3625,6 +3641,7 @@ static int perf_sched__lat(struct perf_sched *sched)
{
int rc = -1;
struct rb_node *next;
+ char total_runtime_str[32];
setup_pager();
@@ -3637,9 +3654,9 @@ static int perf_sched__lat(struct perf_sched *sched)
perf_sched__merge_lat(sched);
perf_sched__sort_lat(sched);
- printf("\n -------------------------------------------------------------------------------------------------------------------------------------------\n");
- printf(" Task | Runtime ms | Count | Avg delay ms | Max delay ms | Max delay start | Max delay end |\n");
- printf(" -------------------------------------------------------------------------------------------------------------------------------------------\n");
+ printf("\n ------------------------------------------------------------------------------------------------------------------------------------------\n");
+ printf(" Task | Runtime | Count | Avg delay | Max delay | Max delay start | Max delay end |\n");
+ printf(" ------------------------------------------------------------------------------------------------------------------------------------------\n");
next = rb_first_cached(&sched->sorted_atom_root);
@@ -3651,11 +3668,12 @@ static int perf_sched__lat(struct perf_sched *sched)
next = rb_next(next);
}
- printf(" -----------------------------------------------------------------------------------------------------------------\n");
- printf(" TOTAL: |%11.3f ms |%9" PRIu64 " |\n",
- (double)sched->all_runtime / NSEC_PER_MSEC, sched->all_count);
+ printf(" ------------------------------------------------------------------------------------------------------------------------------------------\n");
+ scnprintf_latency_unit(total_runtime_str, sizeof(total_runtime_str), sched->all_runtime);
+ printf(" TOTAL: |%15s |%9" PRIu64 " |\n",
+ total_runtime_str, sched->all_count);
- printf(" ---------------------------------------------------\n");
+ printf(" ------------------------------------------------------\n");
print_bad_events(sched);
printf("\n");
--
2.55.0
^ permalink raw reply related [flat|nested] 8+ messages in thread
* [PATCH v8 4/4] perf sched latency: Add histogram and time interval options
2026-08-05 21:07 [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support Aaron Tomlin
` (2 preceding siblings ...)
2026-08-05 21:07 ` [PATCH v8 3/4] perf sched latency: Auto-scale latency and runtime display units Aaron Tomlin
@ 2026-08-05 21:07 ` Aaron Tomlin
2026-08-05 22:02 ` [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support Ian Rogers
2026-08-06 5:04 ` Namhyung Kim
5 siblings, 0 replies; 8+ messages in thread
From: Aaron Tomlin @ 2026-08-05 21:07 UTC (permalink / raw)
To: peterz, mingo, acme, namhyung
Cc: mark.rutland, alexander.shishkin, jolsa, irogers, adrian.hunter,
james.clark, howardchu95, atomlin, neelx, chjohnst, sean, steve,
rishil1999, linux-perf-users, linux-kernel
While 'perf sched latency' reports task runtime and delay statistics
(average and maximum delay), it does not provide a visual representation
of how task wait times are distributed across latency ranges between
snapshots (start and finish of the analysis window).
The --histogram option collects CPU wait latencies (time between when
a task becomes runnable and when it gets scheduled onto a CPU) into 22
latency buckets, displaying an ASCII bar chart distribution.
The --hist-mode option configures the bucketing scheme:
- log (default). Logarithmic latency buckets ranging from
sub-microsecond (< 1 us) up to >= 1.05 seconds
- linear. Equal-width linear latency buckets
(i.e., 100 us steps up to >= 2.1 ms)
The --time option allows filtering trace event processing to a
specific time interval [start,stop].
Example histogram output excerpt:
❯ sudo perf sched latency --histogram --CPU 0
CPU Wait Latency Distribution Histogram (between snapshots) (total samples: 36114)
-------------------------------------------------------------------
Latency Range | Count | Pct | Histogram Graph
-------------------------------------------------------------------
< 1 us | 17 | 0.0% | #
2 - 4 us | 673 | 1.9% | #
4 - 8 us | 6237 | 17.3% | ######
8 - 16 us | 3224 | 8.9% | ###
16 - 32 us | 1388 | 3.8% | #
32 - 64 us | 709 | 2.0% | #
64 - 128 us | 690 | 1.9% | #
128 - 256 us | 789 | 2.2% | #
256 - 512 us | 541 | 1.5% | #
512 - 1024 us | 2256 | 6.2% | ##
1 - 2 ms | 3577 | 9.9% | ###
2 - 4 ms | 13259 | 36.7% | ##############
4 - 8 ms | 2523 | 7.0% | ##
8 - 16 ms | 222 | 0.6% | #
16 - 32 ms | 10 | 0.0% | #
>= 1.05 s | 3 | 0.0% | #
-------------------------------------------------------------------
Signed-off-by: Aaron Tomlin <atomlin@atomlin.com>
---
tools/perf/Documentation/perf-sched.txt | 6 +
tools/perf/builtin-sched.c | 210 +++++++++++++++++++++++-
tools/perf/tests/shell/sched.sh | 29 ++++
3 files changed, 239 insertions(+), 6 deletions(-)
diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt
index a4221398e5e0..4da06215163a 100644
--- a/tools/perf/Documentation/perf-sched.txt
+++ b/tools/perf/Documentation/perf-sched.txt
@@ -40,6 +40,12 @@ There are several variants of 'perf sched':
Tasks with the same command name are merged and the merge count is
given within (), However if -p option is used, pid is mentioned.
+ If -H or --histogram option is passed, a CPU wait latency distribution
+ histogram is displayed illustrating how long tasks waited for CPU
+ runtime across latency buckets between snapshots. The --time
+ option (start,stop) limits analysis to a specific snapshot time interval.
+ The --hist-mode option (log or linear) configures the latency bucketing scheme.
+
'perf sched script' to see a detailed trace of the workload that
was recorded (aliased to 'perf script' for now).
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index 18282ab669e3..0b970d52485e 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -59,6 +59,68 @@
#define MAX_PRIO 140
#define SEP_LEN 100
+#define NUM_LAT_BUCKETS 22
+
+enum hist_mode {
+ HIST_MODE_LOG = 0,
+ HIST_MODE_LINEAR,
+};
+
+static const char *lat_bucket_names[NUM_LAT_BUCKETS] = {
+ "< 1 us",
+ "1 - 2 us",
+ "2 - 4 us",
+ "4 - 8 us",
+ "8 - 16 us",
+ "16 - 32 us",
+ "32 - 64 us",
+ "64 - 128 us",
+ "128 - 256 us",
+ "256 - 512 us",
+ "512 - 1024 us",
+ "1 - 2 ms",
+ "2 - 4 ms",
+ "4 - 8 ms",
+ "8 - 16 ms",
+ "16 - 32 ms",
+ "32 - 64 ms",
+ "64 - 128 ms",
+ "128 - 256 ms",
+ "256 - 512 ms",
+ "512 - 1024 ms",
+ ">= 1.05 s"
+};
+
+static const char *linear_bucket_names[NUM_LAT_BUCKETS] = {
+ "< 100 us",
+ "100 - 200 us",
+ "200 - 300 us",
+ "300 - 400 us",
+ "400 - 500 us",
+ "500 - 600 us",
+ "600 - 700 us",
+ "700 - 800 us",
+ "800 - 900 us",
+ "900 - 1000 us",
+ "1.0 - 1.1 ms",
+ "1.1 - 1.2 ms",
+ "1.2 - 1.3 ms",
+ "1.3 - 1.4 ms",
+ "1.4 - 1.5 ms",
+ "1.5 - 1.6 ms",
+ "1.6 - 1.7 ms",
+ "1.7 - 1.8 ms",
+ "1.8 - 1.9 ms",
+ "1.9 - 2.0 ms",
+ "2.0 - 2.1 ms",
+ ">= 2.1 ms"
+};
+
+struct perf_sched;
+static int latency_bucket(struct perf_sched *sched, u64 delta_ns);
+static void print_latency_histogram(struct perf_sched *sched, u64 *hist,
+ u64 total_count, const char *title);
+
static const char *cpu_list;
static struct perf_cpu_map *user_requested_cpus;
static DECLARE_BITMAP(cpu_bitmap, MAX_NR_CPUS);
@@ -124,6 +186,7 @@ struct work_atoms {
u64 nb_atoms;
u64 total_runtime;
int num_merged;
+ u64 hist[NUM_LAT_BUCKETS];
};
typedef int (*sort_fn_t)(struct work_atoms *, struct work_atoms *);
@@ -219,6 +282,10 @@ struct perf_sched {
struct list_head sort_list, cmp_pid;
bool force;
bool skip_merge;
+ bool show_histogram;
+ enum hist_mode hist_mode;
+ const char *hist_mode_str;
+ u64 global_hist[NUM_LAT_BUCKETS];
struct perf_sched_map map;
/* options for timehist command */
@@ -257,6 +324,59 @@ static int scnprintf_latency_unit(char *buf, size_t size, u64 nsecs)
return scnprintf(buf, size, "%6.3f s ", (double)nsecs / NSEC_PER_SEC);
}
+static int latency_bucket(struct perf_sched *sched, u64 delta_ns)
+{
+ u64 delta_us = delta_ns / NSEC_PER_USEC;
+ u64 b;
+
+ if (sched->hist_mode == HIST_MODE_LINEAR) {
+ b = delta_us / 100;
+ } else {
+ if (delta_us == 0)
+ return 0;
+ b = 64 - __builtin_clzll(delta_us);
+ }
+
+ if (b >= NUM_LAT_BUCKETS - 1)
+ return NUM_LAT_BUCKETS - 1;
+ return b;
+}
+
+static void print_latency_histogram(struct perf_sched *sched, u64 *hist,
+ u64 total_count, const char *title)
+{
+ const char **bucket_names = (sched->hist_mode == HIST_MODE_LINEAR) ?
+ linear_bucket_names : lat_bucket_names;
+ int bar_total = 40;
+ char bar[] = "########################################";
+ int i;
+
+ if (total_count == 0)
+ return;
+
+ printf("\n %s (total samples: %" PRIu64 ")\n", title, total_count);
+ printf(" -------------------------------------------------------------------\n");
+ printf(" %-16s | %10s | %6s | %s\n",
+ "Latency Range", "Count", "Pct", "Histogram Graph");
+ printf(" -------------------------------------------------------------------\n");
+
+ for (i = 0; i < NUM_LAT_BUCKETS; i++) {
+ double pct;
+ int bar_len;
+
+ if (hist[i] == 0)
+ continue;
+ pct = (double)hist[i] * 100.0 / total_count;
+ bar_len = (hist[i] * bar_total) / total_count;
+ if (bar_len == 0 && hist[i] > 0)
+ bar_len = 1;
+ printf(" %-16s | %10" PRIu64 " | %5.1f%% | %.*s\n",
+ bucket_names[i], hist[i], pct,
+ bar_len, bar);
+ }
+ printf(" -------------------------------------------------------------------\n");
+}
+
/* per thread run time data */
struct thread_runtime {
u64 last_time; /* time of previous sched in/out event */
@@ -1108,20 +1228,33 @@ add_sched_out_event(struct work_atoms *atoms,
char run_state,
u64 timestamp)
{
- struct work_atom *atom = zalloc(sizeof(*atom));
+ struct work_atom *atom = NULL;
+
+ if (!list_empty(&atoms->work_list)) {
+ atom = list_entry(atoms->work_list.prev, struct work_atom, list);
+ if (atom->state != THREAD_SCHED_IN)
+ goto reuse;
+ }
+
+ atom = zalloc(sizeof(*atom));
if (!atom) {
pr_err("Non memory at %s", __func__);
return -1;
}
+ list_add_tail(&atom->list, &atoms->work_list);
+
+reuse:
atom->sched_out_time = timestamp;
if (run_state == 'R') {
atom->state = THREAD_WAIT_CPU;
atom->wake_up_time = atom->sched_out_time;
+ } else {
+ atom->state = THREAD_SLEEPING;
+ atom->wake_up_time = 0;
}
- list_add_tail(&atom->list, &atoms->work_list);
return 0;
}
@@ -1140,10 +1273,12 @@ add_runtime_event(struct work_atoms *atoms, u64 delta,
}
static void
-add_sched_in_event(struct work_atoms *atoms, u64 timestamp)
+add_sched_in_event(struct perf_sched *sched, struct work_atoms *atoms,
+ u64 timestamp)
{
struct work_atom *atom;
u64 delta;
+ int b;
if (list_empty(&atoms->work_list))
return;
@@ -1158,6 +1293,9 @@ add_sched_in_event(struct work_atoms *atoms, u64 timestamp)
return;
}
+ if (perf_time__skip_sample(&sched->ptime, timestamp))
+ return;
+
atom->state = THREAD_SCHED_IN;
atom->sched_in_time = timestamp;
@@ -1168,7 +1306,13 @@ add_sched_in_event(struct work_atoms *atoms, u64 timestamp)
atoms->max_lat_start = atom->wake_up_time;
atoms->max_lat_end = timestamp;
}
+
atoms->nb_atoms++;
+
+ b = latency_bucket(sched, delta);
+ atoms->hist[b]++;
+ if (thread__tid(atoms->thread) != 0)
+ sched->global_hist[b]++;
}
static void free_work_atoms(struct work_atoms *atoms)
@@ -1252,7 +1396,7 @@ static int latency_switch_event(struct perf_sched *sched,
if (add_sched_out_event(in_events, 'R', timestamp))
goto out_put;
}
- add_sched_in_event(in_events, timestamp);
+ add_sched_in_event(sched, in_events, timestamp);
err = 0;
out_put:
thread__put(sched_out);
@@ -1266,11 +1410,15 @@ static int latency_runtime_event(struct perf_sched *sched,
{
const u32 pid = perf_sample__intval(sample, "pid");
const u64 runtime = perf_sample__intval(sample, "runtime");
- struct thread *thread = machine__findnew_thread(machine, -1, pid);
+ struct thread *thread;
struct work_atoms *atoms;
u64 timestamp = sample->time;
int cpu = sample->cpu, err = -1;
+ if (perf_time__skip_sample(&sched->ptime, timestamp))
+ return 0;
+
+ thread = machine__findnew_thread(machine, -1, pid);
if (thread == NULL)
return -1;
@@ -1425,7 +1573,7 @@ static void output_lat_thread(struct perf_sched *sched, struct work_atoms *work_
/*
* Ignore idle threads:
*/
- if (!strcmp(thread__comm_str(work_list->thread), "swapper"))
+ if (thread__tid(work_list->thread) == 0)
return;
sched->all_runtime += work_list->total_runtime;
@@ -1454,6 +1602,10 @@ static void output_lat_thread(struct perf_sched *sched, struct work_atoms *work_
work_list->nb_atoms, avg_lat, max_lat,
max_lat_start, max_lat_end);
+ if (sched->show_histogram && verbose > 0)
+ print_latency_histogram(sched, work_list->hist,
+ work_list->nb_atoms,
+ "Task Latency Histogram");
}
static int pid_cmp(struct work_atoms *l, struct work_atoms *r)
@@ -3586,6 +3738,8 @@ static void __merge_work_atoms(struct rb_root_cached *root, struct work_atoms *d
this->max_lat_start = data->max_lat_start;
this->max_lat_end = data->max_lat_end;
}
+ for (int i = 0; i < NUM_LAT_BUCKETS; i++)
+ this->hist[i] += data->hist[i];
free_work_atoms(data);
return;
}
@@ -3645,6 +3799,24 @@ static int perf_sched__lat(struct perf_sched *sched)
setup_pager();
+ if (sched->hist_mode_str) {
+ sched->show_histogram = true;
+ if (!strcmp(sched->hist_mode_str, "linear"))
+ sched->hist_mode = HIST_MODE_LINEAR;
+ else if (!strcmp(sched->hist_mode_str, "log"))
+ sched->hist_mode = HIST_MODE_LOG;
+ else {
+ pr_err("Invalid --hist-mode '%s', expected 'log' or 'linear'\n",
+ sched->hist_mode_str);
+ return -EINVAL;
+ }
+ }
+
+ if (sched->time_str && perf_time__parse_str(&sched->ptime, sched->time_str) != 0) {
+ pr_err("Invalid time string\n");
+ return -EINVAL;
+ }
+
if (setup_cpus_switch_event(sched))
return rc;
@@ -3654,6 +3826,21 @@ static int perf_sched__lat(struct perf_sched *sched)
perf_sched__merge_lat(sched);
perf_sched__sort_lat(sched);
+ next = rb_first_cached(&sched->sorted_atom_root);
+ while (next) {
+ struct work_atoms *work_list = rb_entry(next, struct work_atoms, node);
+
+ if (work_list->nb_atoms && thread__tid(work_list->thread) != 0)
+ break;
+ next = rb_next(next);
+ }
+
+ if (!next) {
+ pr_info("No matching trace samples found.\n");
+ rc = 0;
+ goto out_free_atoms;
+ }
+
printf("\n ------------------------------------------------------------------------------------------------------------------------------------------\n");
printf(" Task | Runtime | Count | Avg delay | Max delay | Max delay start | Max delay end |\n");
printf(" ------------------------------------------------------------------------------------------------------------------------------------------\n");
@@ -3678,8 +3865,13 @@ static int perf_sched__lat(struct perf_sched *sched)
print_bad_events(sched);
printf("\n");
+ if (sched->show_histogram)
+ print_latency_histogram(sched, sched->global_hist, sched->all_count,
+ "CPU Wait Latency Distribution Histogram (between snapshots)");
+
rc = 0;
+out_free_atoms:
while ((next = rb_first_cached(&sched->sorted_atom_root))) {
struct work_atoms *data;
@@ -5096,6 +5288,12 @@ int cmd_sched(int argc, const char **argv)
"CPU to profile on"),
OPT_BOOLEAN('p', "pids", &sched.skip_merge,
"latency stats per pid instead of per comm"),
+ OPT_BOOLEAN('H', "histogram", &sched.show_histogram,
+ "show CPU wait latency distribution histogram"),
+ OPT_STRING(0, "hist-mode", &sched.hist_mode_str, "log|linear",
+ "latency bucket mode (log or linear, default: log)"),
+ OPT_STRING(0, "time", &sched.time_str, "str",
+ "Time span for analysis (start,stop)"),
OPT_PARENT(sched_options)
};
const struct option replay_options[] = {
diff --git a/tools/perf/tests/shell/sched.sh b/tools/perf/tests/shell/sched.sh
index b9637069adb1..113df962a51c 100755
--- a/tools/perf/tests/shell/sched.sh
+++ b/tools/perf/tests/shell/sched.sh
@@ -76,6 +76,32 @@ test_sched_latency() {
fi
}
+test_sched_latency_histogram() {
+ echo "Sched latency histogram"
+
+ if ! perf sched latency -H -i "${perfdata}" | grep -q "Latency Distribution Histogram"
+ then
+ echo "Sched latency histogram [Failed missing log histogram]"
+ err=1
+ fi
+
+ if ! perf sched latency --histogram --hist-mode linear -i "${perfdata}" | grep -q "Latency Distribution Histogram"
+ then
+ echo "Sched latency histogram [Failed missing linear histogram]"
+ err=1
+ fi
+}
+
+test_sched_latency_time() {
+ echo "Sched latency time filter"
+
+ if ! perf sched latency --time 0, -i "${perfdata}" | grep -q perf-noploop
+ then
+ echo "Sched latency time filter [Failed missing output]"
+ err=1
+ fi
+}
+
test_sched_script() {
echo "Sched script"
@@ -108,9 +134,12 @@ test_sched_timehist() {
test_sched_record
test_sched_latency
+test_sched_latency_histogram
+test_sched_latency_time
test_sched_script
test_sched_map
test_sched_timehist
cleanup
exit $err
+
--
2.55.0
^ permalink raw reply related [flat|nested] 8+ messages in thread
* Re: [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support
2026-08-05 21:07 [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support Aaron Tomlin
` (3 preceding siblings ...)
2026-08-05 21:07 ` [PATCH v8 4/4] perf sched latency: Add histogram and time interval options Aaron Tomlin
@ 2026-08-05 22:02 ` Ian Rogers
2026-08-06 14:05 ` Aaron Tomlin
2026-08-06 5:04 ` Namhyung Kim
5 siblings, 1 reply; 8+ messages in thread
From: Ian Rogers @ 2026-08-05 22:02 UTC (permalink / raw)
To: Aaron Tomlin
Cc: peterz, mingo, acme, namhyung, mark.rutland, alexander.shishkin,
jolsa, adrian.hunter, james.clark, howardchu95, neelx, chjohnst,
sean, steve, rishil1999, linux-perf-users, linux-kernel
On Wed, Aug 5, 2026 at 2:08 PM Aaron Tomlin <atomlin@atomlin.com> wrote:
>
> Hi Namhyung, Ian, Arnaldo,
>
> This patch series improves 'perf sched latency' by suppressing misleading
> empty table output, extending pipe mode stream processing, introducing
> dynamic unit auto-scaling for latency and runtime statistics, and adding
> latency histogram visualisation alongside time-span filtering.
>
> Patch 1 addresses an issue where 'perf sched latency' fell through and
> returned success (0) when perf_session__has_traces() failed due to missing
> tracepoint events in a perf.data file. This caused empty header tables and
> zeroed summary statistics to be rendered. In addition,
> thread__get_runtime() in map_switch_event() is guarded against potential
> NULL pointer dereferences under memory allocation failures.
>
> Patch 2 extends pipe mode stream support. Because event attributes in pipe
> mode are received dynamically during event processing, session->evlist is
> not populated prior to event processing.
> To handle pipe input correctly:
> - Register the missing .attr, .tracing_data, .build_id, and .feature
> callbacks in cmd_sched()
>
> - Promote the handlers array to file-scope (latency_handlers[]) and
> dynamically assign matching tracepoint handlers (or
> process_sched_ignore) inside perf_sched__process_tracepoint_sample()
> when evsel->handler is NULL; replace process_sched_wakeup_ignore()
> with process_sched_ignore()
>
> - Perform the trace check post-processing when handling pipe data
>
> Patch 3 introduces dynamic auto-scaling for latency and runtime display
> columns (Runtime, Avg delay, Max delay). Previously, all values were
> unconditionally formatted in milliseconds (ms), making microsecond- or
> second-scale latencies difficult to read. Columns are now dynamically
> scaled to the most appropriate unit (ns, us, ms, s), column headers are
> updated, and format specifiers are aligned character-for-character with
> table headers.
>
> Patch 4 adds three new command-line options to 'perf sched latency':
> --histogram (-H):
> Displays an ASCII bar chart of CPU wait latencies between
> snapshots
> --hist-mode:
> Configures the bucketing scheme to either logarithmic (log) or
> 100 us equal-width linear (linear) mode
> --time:
> Filters trace event processing to a specified [start,stop] time
> span
Thanks for these improvements and the tests for coverage! For the series:
Reviewed-by: Ian Rogers <irogers@google.com>
Thanks,
Ian
> Changes since v7:
>
> - Added a guard clause in perf_sched__process_tracepoint_sample() to
> reduce loop indentation (Namhyung Kim)
>
> - Converted dummy process_sched_wakeup_ignore() references to
> process_sched_ignore and eliminated redundant code (Namhyung Kim)
>
> - Replaced string comparisons with faster integer checks (i.e.,
> thread__tid(...) != 0) for swapper (idle thread) handling (Namhyung Kim)
>
> - Added automated test cases for --histogram, --hist-mode, and --time into
> tools/perf/tests/shell/sched.sh (Namhyung Kim)
>
> - Link to v7: https://lore.kernel.org/lkml/20260802210914.199941-1-atomlin@atomlin.com/
>
> Changes since v6:
>
> - Fixed O(N) hot-path traversal overhead in
> perf_sched__process_tracepoint_sample() for unhandled tracepoints by
> assigning a dummy ignore handler (process_sched_ignore)
>
> - Replaced evlist__set_tracepoints_handlers() in sample processing with a
> per-evsel lookup to prevent -EEXIST early aborts and avoid dropping
> late-arriving pipe events
>
> - Updated commit message for the pipe mode patch to reflect the
> single-pass handler assignment logic
>
> - Link to v6: https://lore.kernel.org/lkml/20260801234008.176724-1-atomlin@atomlin.com/
>
> Changes since v5:
>
> - Split pipe mode trace sample handling from Patch 1 into a standalone
> patch (Namhyung Kim)
>
> - Added a Fixes: tag to the pipe mode patch referencing commit
> 27295592c22e ("perf session: Share the common trace sample_check routine
> as perf_session__has_traces")
>
> - Updated commit log with before and after illustrations of table header
> formatting
>
> - Link to v5: https://lore.kernel.org/lkml/20260730185416.97166-1-atomlin@atomlin.com/
>
> Changes since v4:
>
> - Added the missing .feature callback to sched.tool in cmd_sched()
>
> - Fixed memory leak by reusing uncompleted work atoms when sched_in events
> are skipped or lost
>
> - Promoted the handlers array to file-scope (i.e., latency_handlers[]) and
> added a dynamic lookup via evlist__set_tracepoints_handlers() inside
> perf_sched__process_tracepoint_sample() whenever a sample arrives with
> an unattached handler (i.e., evsel->handler == NULL)
>
> - Prevented double-counting wakeups (i.e., ignore sched:sched_wakeup)
> in pipe mode and non-pipe modes
>
> - Added missing trailing pipe in output_lat_thread's new auto-scaling
> format string
>
> - Stripped redundant prefix strings from each row's format string to
> produce a clean, tabular output
>
> - Link to v4: https://lore.kernel.org/lkml/20260729144451.38286-1-atomlin@atomlin.com/
>
> Changes since v3:
>
> - Registered Missing Callbacks. In perf_tool__init configuration inside
> cmd_sched(), added the .attr, .tracing_data, and .build_id callbacks.
> Without these callbacks, pipe mode drops header attributes entirely,
> preventing tracepoints from being populated in session->evlist
>
> - Introduced an explicit post-processing pipe check. This ensures that
> pipe mode aborts correctly and does not produce superfluous empty
> latency tables when no trace samples are available
>
> - Prevented potential NULL pointer dereference. Added a NULL check for
> thread__get_runtime() in map_switch_event() under memory allocation
> failures
>
> - Fixed column alignment. Modified format specifiers to align
> character-for-character with header column widths across all rows
>
> - Adjusted header label padding. Updated header label padding and column
> width delimiters in perf_sched__lat() to match the exact field format
> specifiers printed in output_lat_thread()
>
> - Fixed swapper histogram inclusion. Excluded "swapper" (i.e.,
> CPU-specific idle thread) from global_hist buckets
>
> - Preserved task state machine across --time bounds. Moved time-window
> filtering inside add_sched_in_event() to gate latency statistics
> recording without breaking wakeup state tracking across time interval
> boundaries
>
> - Link to v3: https://lore.kernel.org/lkml/20260726032533.712462-1-atomlin@atomlin.com/
>
> Changes since v2:
>
> - Ensured vertical pipe separators align across all latency table columns
>
> - Excluded "swapper" (idle thread) latency samples from global_hist
>
> - Preserved task state machine transitions across --time boundaries
>
> - Suppressed empty table headers, total lines, and histogram graphs when
> no matching trace samples exist (e.g., when --time, --CPU, or --pids
> exclude all samples), outputting "No matching trace samples found."
> instead
>
> - Linked to v2: https://lore.kernel.org/lkml/20260725173341.679782-1-atomlin@atomlin.com/
>
> Changes since v1:
>
> - Fixed integer overflow in latency_bucket() (Ian Rogers)
>
> - Linked to v1: https://lore.kernel.org/lkml/20260724142901.634761-1-atomlin@atomlin.com/
>
> Aaron Tomlin (4):
> perf sched: Suppress latency table output when trace samples are
> missing
> perf sched: Handle missing trace samples in pipe mode
> perf sched latency: Auto-scale latency and runtime display units
> perf sched latency: Add histogram and time interval options
>
> tools/perf/Documentation/perf-sched.txt | 6 +
> tools/perf/builtin-sched.c | 347 ++++++++++++++++++++----
> tools/perf/tests/shell/sched.sh | 29 ++
> 3 files changed, 332 insertions(+), 50 deletions(-)
>
> --
> 2.55.0
>
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support
2026-08-05 21:07 [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support Aaron Tomlin
` (4 preceding siblings ...)
2026-08-05 22:02 ` [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support Ian Rogers
@ 2026-08-06 5:04 ` Namhyung Kim
5 siblings, 0 replies; 8+ messages in thread
From: Namhyung Kim @ 2026-08-06 5:04 UTC (permalink / raw)
To: Aaron Tomlin
Cc: peterz, mingo, acme, mark.rutland, alexander.shishkin, jolsa,
irogers, adrian.hunter, james.clark, howardchu95, neelx, chjohnst,
sean, steve, rishil1999, linux-perf-users, linux-kernel
Hello,
On Wed, Aug 05, 2026 at 05:07:47PM -0400, Aaron Tomlin wrote:
> Hi Namhyung, Ian, Arnaldo,
>
> This patch series improves 'perf sched latency' by suppressing misleading
> empty table output, extending pipe mode stream processing, introducing
> dynamic unit auto-scaling for latency and runtime statistics, and adding
> latency histogram visualisation alongside time-span filtering.
Thanks for working on this. But it doesn't apply unfortunately.
Can you please rebase on to the current perf-tools-next?
Thanks,
Namhyung
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support
2026-08-05 22:02 ` [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support Ian Rogers
@ 2026-08-06 14:05 ` Aaron Tomlin
0 siblings, 0 replies; 8+ messages in thread
From: Aaron Tomlin @ 2026-08-06 14:05 UTC (permalink / raw)
To: Ian Rogers
Cc: peterz, mingo, acme, namhyung, mark.rutland, alexander.shishkin,
jolsa, adrian.hunter, james.clark, howardchu95, neelx, chjohnst,
sean, steve, rishil1999, linux-perf-users, linux-kernel
On Wed, Aug 05, 2026 at 03:02:06PM -0700, Ian Rogers wrote:
> On Wed, Aug 5, 2026 at 2:08 PM Aaron Tomlin <atomlin@atomlin.com> wrote:
> >
> > Hi Namhyung, Ian, Arnaldo,
> >
> > This patch series improves 'perf sched latency' by suppressing misleading
> > empty table output, extending pipe mode stream processing, introducing
> > dynamic unit auto-scaling for latency and runtime statistics, and adding
> > latency histogram visualisation alongside time-span filtering.
> >
> > Patch 1 addresses an issue where 'perf sched latency' fell through and
> > returned success (0) when perf_session__has_traces() failed due to missing
> > tracepoint events in a perf.data file. This caused empty header tables and
> > zeroed summary statistics to be rendered. In addition,
> > thread__get_runtime() in map_switch_event() is guarded against potential
> > NULL pointer dereferences under memory allocation failures.
> >
> > Patch 2 extends pipe mode stream support. Because event attributes in pipe
> > mode are received dynamically during event processing, session->evlist is
> > not populated prior to event processing.
> > To handle pipe input correctly:
> > - Register the missing .attr, .tracing_data, .build_id, and .feature
> > callbacks in cmd_sched()
> >
> > - Promote the handlers array to file-scope (latency_handlers[]) and
> > dynamically assign matching tracepoint handlers (or
> > process_sched_ignore) inside perf_sched__process_tracepoint_sample()
> > when evsel->handler is NULL; replace process_sched_wakeup_ignore()
> > with process_sched_ignore()
> >
> > - Perform the trace check post-processing when handling pipe data
> >
> > Patch 3 introduces dynamic auto-scaling for latency and runtime display
> > columns (Runtime, Avg delay, Max delay). Previously, all values were
> > unconditionally formatted in milliseconds (ms), making microsecond- or
> > second-scale latencies difficult to read. Columns are now dynamically
> > scaled to the most appropriate unit (ns, us, ms, s), column headers are
> > updated, and format specifiers are aligned character-for-character with
> > table headers.
> >
> > Patch 4 adds three new command-line options to 'perf sched latency':
> > --histogram (-H):
> > Displays an ASCII bar chart of CPU wait latencies between
> > snapshots
> > --hist-mode:
> > Configures the bucketing scheme to either logarithmic (log) or
> > 100 us equal-width linear (linear) mode
> > --time:
> > Filters trace event processing to a specified [start,stop] time
> > span
>
> Thanks for these improvements and the tests for coverage! For the series:
>
> Reviewed-by: Ian Rogers <irogers@google.com>
>
> Thanks,
> Ian
Thank you Ian!
--
Aaron Tomlin
^ permalink raw reply [flat|nested] 8+ messages in thread
end of thread, other threads:[~2026-08-06 14:05 UTC | newest]
Thread overview: 8+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2026-08-05 21:07 [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support Aaron Tomlin
2026-08-05 21:07 ` [PATCH v8 1/4] perf sched: Suppress latency table output when trace samples are missing Aaron Tomlin
2026-08-05 21:07 ` [PATCH v8 2/4] perf sched: Handle missing trace samples in pipe mode Aaron Tomlin
2026-08-05 21:07 ` [PATCH v8 3/4] perf sched latency: Auto-scale latency and runtime display units Aaron Tomlin
2026-08-05 21:07 ` [PATCH v8 4/4] perf sched latency: Add histogram and time interval options Aaron Tomlin
2026-08-05 22:02 ` [PATCH v8 0/4] perf sched latency: Refine outputs, unit scaling, and histogram support Ian Rogers
2026-08-06 14:05 ` Aaron Tomlin
2026-08-06 5:04 ` Namhyung Kim
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox