perf trace: Introduce --show-cpu option to display cpu id

When tracing system-wide workloads or specific events, it is highly
valuable to know exactly which CPU executed a specific event. Currently,
perf trace output defaults to omitting CPU information.

Introduce a new "--show-cpu" command-line option. When provided, this
flag extracts the CPU from the perf sample and prints it in a "[000]"
format immediately following the timestamp. This mirrors the behaviour of
other tracing tools like ftrace and perf script. For example:

  # perf trace -e sched:sched_switch --max-events 5 --show-cpu
       0.000 [002] :0/0 sched:sched_switch(prev_comm: "swapper/2", prev_prio: 120, next_comm: "rcu_preempt", next_pid: 16 (rcu_preempt), next_prio: 120)
       0.009 [002] rcu_preempt/16 sched:sched_switch(prev_comm: "rcu_preempt", prev_pid: 16 (rcu_preempt), prev_prio: 120, prev_state: 128, next_comm: "swapper/2", next_prio: 120)
       0.033 [002] :0/0 sched:sched_switch(prev_comm: "swapper/2", prev_prio: 120, next_comm: "kworker/u32:48", next_pid: 35840 (kworker/u32:48-), next_prio: 120)
       0.041 [002] kworker/u32:48/35840 sched:sched_switch(prev_comm: "kworker/u32:48", prev_pid: 35840 (kworker/u32:48-), prev_prio: 120, prev_state: 128, next_comm: "swapper/2", next_prio: 120)
       0.045 [002] :0/0 sched:sched_switch(prev_comm: "swapper/2", prev_prio: 120, next_comm: "kworker/u32:48", next_pid: 35840 (kworker/u32:48-), next_prio: 120)

The feature is implemented strictly as an opt-in toggle to prevent
cluttering the standard output and to preserve backwards compatibility
for scripts parsing the default output format.

Signed-off-by: Aaron Tomlin <atomlin@atomlin.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Daniel Vacek <neelx@suse.com>
Cc: Howard Chu <howardchu95@gmail.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: James Clark <james.clark@linaro.org>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Sean Ashe <sean@ashe.io>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>

diff --git a/tools/perf/Documentation/perf-trace.txt b/tools/perf/Documentation/perf-trace.txt
index 892c82a9bf402db2fc22cf48d8ed8b1e296b64b6..d0b6c771a1b92df5c454259a2508b0f87e31bbe8 100644 (file)
--- a/tools/perf/Documentation/perf-trace.txt
+++ b/tools/perf/Documentation/perf-trace.txt
@@ -199,6 +199,9 @@ the thread executes on the designated CPUs. Default is to monitor all CPUs.
 --show-on-off-events::
        Show the --switch-on/off events too.
 
+--show-cpu::
+       Show cpu id.
+
 --max-stack::
         Set the stack depth limit when parsing the callchain, anything
         beyond the specified depth will be ignored. Note that at this point

diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index e58c49d047a294db3af61ca6f71173e0de5a25aa..e9cc870a5acda45d415a816839dc9aab884011de 100644 (file)
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -217,6 +217,7 @@ struct trace {
        bool                    kernel_syscallchains;
        s16                     args_alignment;
        bool                    show_tstamp;
+       bool                    show_cpu;
        bool                    show_duration;
        bool                    show_zeros;
        bool                    show_arg_names;
@@ -1531,6 +1532,7 @@ static size_t fprintf_duration(unsigned long t, bool calculated, FILE *fp)
  */
 struct thread_trace {
        u64               entry_time;
+       u32               entry_cpu;
        bool              entry_pending;
        unsigned long     nr_events;
        unsigned long     pfmaj, pfmin;
@@ -1893,6 +1895,27 @@ static size_t trace__fprintf_tstamp(struct trace *trace, u64 tstamp, FILE *fp)
        return fprintf(fp, "         ? ");
 }
 
+/**
+ * trace__fprintf_cpu - Print the CPU ID to a given file stream
+ * @cpu: The CPU ID to print
+ * @fp: The file stream to write to
+ *
+ * Formats and prints the specified CPU ID enclosed in brackets
+ * (e.g., "[003] ") to the provided file pointer. It is used to
+ * align and display the CPU ID consistently within the trace output.
+ *
+ * Return: The number of characters printed.
+ */
+static size_t trace__fprintf_cpu(u32 cpu, FILE *fp)
+{
+       size_t printed = 0;
+
+       if (cpu != (u32)-1)
+               printed += fprintf(fp, "[%03u] ", cpu);
+
+       return printed;
+}
+
 static pid_t workload_pid = -1;
 static volatile sig_atomic_t done = false;
 static volatile sig_atomic_t interrupted = false;
@@ -1923,12 +1946,15 @@ static size_t trace__fprintf_comm_tid(struct trace *trace, struct thread *thread
 }
 
 static size_t trace__fprintf_entry_head(struct trace *trace, struct thread *thread,
-                                       u64 duration, bool duration_calculated, u64 tstamp, FILE *fp)
+                                       u64 duration, bool duration_calculated,
+                                       u64 tstamp, u32 cpu, FILE *fp)
 {
        size_t printed = 0;
 
        if (trace->show_tstamp)
                printed = trace__fprintf_tstamp(trace, tstamp, fp);
+       if (trace->show_cpu && cpu != (u32)-1)
+               printed += trace__fprintf_cpu(cpu, fp);
        if (trace->show_duration)
                printed += fprintf_duration(duration, duration_calculated, fp);
        return printed + trace__fprintf_comm_tid(trace, thread, fp);
@@ -2707,7 +2733,9 @@ static int trace__printf_interrupted_entry(struct trace *trace)
        if (!ttrace->entry_pending)
                return 0;
 
-       printed  = trace__fprintf_entry_head(trace, trace->current, 0, false, ttrace->entry_time, trace->output);
+       printed = trace__fprintf_entry_head(trace, trace->current, 0, false,
+                                           ttrace->entry_time, ttrace->entry_cpu,
+                                           trace->output);
        printed += len = fprintf(trace->output, "%s)", ttrace->entry_str);
 
        if (len < trace->args_alignment - 4)
@@ -2825,6 +2853,7 @@ static int trace__sys_enter(struct trace *trace, struct evsel *evsel,
        if (evsel != trace->syscalls.events.sys_enter)
                augmented_args = syscall__augmented_args(sc, sample, &augmented_args_size, trace->raw_augmented_syscalls_args_size);
        ttrace->entry_time = sample->time;
+       ttrace->entry_cpu = sample->cpu;
        msg = ttrace->entry_str;
        printed += scnprintf(msg + printed, trace__entry_str_size - printed, "%s(", sc->name);
 
@@ -2835,7 +2864,9 @@ static int trace__sys_enter(struct trace *trace, struct evsel *evsel,
                if (!(trace->duration_filter || trace->summary_only || trace->failure_only || trace->min_stack)) {
                        int alignment = 0;
 
-                       trace__fprintf_entry_head(trace, thread, 0, false, ttrace->entry_time, trace->output);
+                       trace__fprintf_entry_head(trace, thread, 0, false,
+                                                 ttrace->entry_time,
+                                                 sample->cpu, trace->output);
                        printed = fprintf(trace->output, "%s)", ttrace->entry_str);
                        if (trace->args_alignment > printed)
                                alignment = trace->args_alignment - printed;
@@ -2980,7 +3011,9 @@ static int trace__sys_exit(struct trace *trace, struct evsel *evsel,
        if (trace->summary_only || (ret >= 0 && trace->failure_only))
                goto out;
 
-       trace__fprintf_entry_head(trace, thread, duration, duration_calculated, ttrace->entry_time, trace->output);
+       trace__fprintf_entry_head(trace, thread, duration,
+                                 duration_calculated, ttrace->entry_time,
+                                 sample->cpu, trace->output);
 
        if (ttrace->entry_pending) {
                printed = fprintf(trace->output, "%s", ttrace->entry_str);
@@ -3280,6 +3313,9 @@ static int trace__event_handler(struct trace *trace, struct evsel *evsel,
        trace__printf_interrupted_entry(trace);
        trace__fprintf_tstamp(trace, sample->time, trace->output);
 
+       if (trace->show_cpu)
+               trace__fprintf_cpu(sample->cpu, trace->output);
+
        if (trace->trace_syscalls && trace->show_duration)
                fprintf(trace->output, "(         ): ");
 
@@ -3405,7 +3441,8 @@ static int trace__pgfault(struct trace *trace,
 
        thread__find_symbol(thread, sample->cpumode, sample->ip, &al);
 
-       trace__fprintf_entry_head(trace, thread, 0, true, sample->time, trace->output);
+       trace__fprintf_entry_head(trace, thread, 0, true, sample->time,
+                                 sample->cpu, trace->output);
 
        fprintf(trace->output, "%sfault [",
                evsel->core.attr.config == PERF_COUNT_SW_PAGE_FAULTS_MAJ ?
@@ -5432,6 +5469,7 @@ int cmd_trace(int argc, const char **argv)
        OPT_CALLBACK('m', "mmap-pages", &trace.opts.mmap_pages, "pages",
                     "number of mmap data pages", evlist__parse_mmap_pages),
        OPT_STRING('u', "uid", &trace.uid_str, "user", "user to profile"),
+       OPT_BOOLEAN(0, "show-cpu", &trace.show_cpu, "show cpu id"),
        OPT_CALLBACK(0, "duration", &trace, "float",
                     "show only events with duration > N.M ms",
                     trace__set_duration),
@@ -5566,6 +5604,9 @@ int cmd_trace(int argc, const char **argv)
                        goto out;
        }
 
+       if (trace.show_cpu)
+               trace.opts.sample_cpu = true;
+
        if ((nr_cgroups || trace.cgroup) && !trace.opts.target.system_wide) {
                usage_with_options_msg(trace_usage, trace_options,
                                       "cgroup monitoring only available in system-wide mode");