[PATCH v16 00/10] perf record --off-cpu: Dump off-cpu samples directly

Howard Chu posted 10 patches 7 months, 2 weeks ago
tools/perf/Documentation/perf-record.txt |   9 ++
tools/perf/builtin-record.c              |  33 +++++++
tools/perf/builtin-script.c              |   4 +-
tools/perf/tests/shell/record_offcpu.sh  |  71 ++++++++++++++
tools/perf/util/bpf_off_cpu.c            | 119 ++++++++++++++---------
tools/perf/util/bpf_skel/off_cpu.bpf.c   |  98 ++++++++++++++++++-
tools/perf/util/evsel.c                  |  41 +++++++-
tools/perf/util/evsel.h                  |   2 +
tools/perf/util/off_cpu.h                |   3 +-
tools/perf/util/record.h                 |   1 +
10 files changed, 324 insertions(+), 57 deletions(-)
[PATCH v16 00/10] perf record --off-cpu: Dump off-cpu samples directly
Posted by Howard Chu 7 months, 2 weeks ago
As mentioned in: https://bugzilla.kernel.org/show_bug.cgi?id=207323

Currently, off-cpu samples are dumped when perf record is exiting. This
results in off-cpu samples being after the regular samples. This patch
series makes possible dumping off-cpu samples on-the-fly, directly into
perf ring buffer. And it dispatches those samples to the correct format
for perf.data consumers.

Before:
```
     migration/0      21 [000] 27981.041319: 2944637851    cycles:P:  ffffffff90d2e8aa record_times+0xa ([kernel.kallsyms])
            perf  770116 [001] 27981.041375:          1    cycles:P:  ffffffff90ee4960 event_function+0xf0 ([kernel.kallsyms])
            perf  770116 [001] 27981.041377:          1    cycles:P:  ffffffff90c184b1 intel_bts_enable_local+0x31 ([kernel.kallsyms])
            perf  770116 [001] 27981.041379:      51611    cycles:P:  ffffffff91a160b0 native_sched_clock+0x30 ([kernel.kallsyms])
     migration/1      26 [001] 27981.041400: 4227682775    cycles:P:  ffffffff90d06a74 wakeup_preempt+0x44 ([kernel.kallsyms])
     migration/2      32 [002] 27981.041477: 4159401534    cycles:P:  ffffffff90d11993 update_load_avg+0x63 ([kernel.kallsyms])

sshd  708098 [000] 18446744069.414584:     286392 offcpu-time: 
	    79a864f1c8bb ppoll+0x4b (/usr/lib/libc.so.6)
	    585690935cca [unknown] (/usr/bin/sshd)
```

After:
```
            perf  774767 [003] 28178.033444:        497           cycles:P:  ffffffff91a160c3 native_sched_clock+0x43 ([kernel.kallsyms])
            perf  774767 [003] 28178.033445:     399440           cycles:P:  ffffffff91c01f8d nmi_restore+0x25 ([kernel.kallsyms])
         swapper       0 [001] 28178.036639:  376650973           cycles:P:  ffffffff91a1ae99 intel_idle+0x59 ([kernel.kallsyms])
         swapper       0 [003] 28178.182921:  348779378           cycles:P:  ffffffff91a1ae99 intel_idle+0x59 ([kernel.kallsyms])
    blueman-tray    1355 [000] 28178.627906:  100184571 offcpu-time: 
	    7528eef1c39d __poll+0x4d (/usr/lib/libc.so.6)
	    7528edf7d8fd [unknown] (/usr/lib/libglib-2.0.so.0.8000.2)
	    7528edf1af95 g_main_context_iteration+0x35 (/usr/lib/libglib-2.0.so.0.8000.2)
	    7528eda4ab86 g_application_run+0x1f6 (/usr/lib/libgio-2.0.so.0.8000.2)
	    7528ee6aa596 [unknown] (/usr/lib/libffi.so.8.1.4)
	    7fff24e862d8 [unknown] ([unknown])


    blueman-tray    1355 [000] 28178.728137:  100187539 offcpu-time: 
	    7528eef1c39d __poll+0x4d (/usr/lib/libc.so.6)
	    7528edf7d8fd [unknown] (/usr/lib/libglib-2.0.so.0.8000.2)
	    7528edf1af95 g_main_context_iteration+0x35 (/usr/lib/libglib-2.0.so.0.8000.2)
	    7528eda4ab86 g_application_run+0x1f6 (/usr/lib/libgio-2.0.so.0.8000.2)
	    7528ee6aa596 [unknown] (/usr/lib/libffi.so.8.1.4)
	    7fff24e862d8 [unknown] ([unknown])


         swapper       0 [000] 28178.463253:  195945410           cycles:P:  ffffffff91a1ae99 intel_idle+0x59 ([kernel.kallsyms])
     dbus-broker     412 [002] 28178.464855:  376737008           cycles:P:  ffffffff91c000a0 entry_SYSCALL_64+0x20 ([kernel.kallsyms])
```

Changes in v16:
 - Add Tested-by from Gautam and Acked-by from Namhyung.
 - Rebase on the perf-tools-next branch.
 - Edit the commit message of patch 10.
 - Fix a bug caused by the type change of struct perf_cpu.
 - Rename test_offcpu_over_thresh() to test_offcpu_above_thresh().

Changes in v15:
 - Fix workload recording bug pointed out by Arnaldo.
 - Rename struct stack to struct __stack as suggested by Arnaldo.
 - Delete the extra offcpu workload now that recording workload is fixed,
   use 'sleep 1' for testing instead.
 - Add more tests for the off-cpu-thresh option.

Changes in v14:
 - Change the internal off_cpu_thresh_us to off_cpu_thresh_ns, i.e. use
   nsec instead of usec

Changes in v13:
 - Move the definition of 'off_cpu_thresh_ns' to the same commit as
   dumping off-cpu samples in BPF, and give off_cpu_thresh_ns a default
   value before the --off-cpu-thresh option is parsed.

Changes in v12:
 - Restore patches' bisectability, because the ordering of patches has
   changed.
 - Change 'us = ms * 1000' to 'us = ms * USEC_PER_MSEC'

Changes in v11:
 - Modify the options used in the off-cpu tests, as I changed the unit
   of the off-cpu threshold to milliseconds.

Changes in v10:
 - Move the commit "perf record --off-cpu: Add --off-cpu-thresh option"
   to where the direct sample feature is completed.
 - Make --off-cpu-thresh use milliseconds as the unit.

Changes in v9:
 - Add documentation for the new option '--off-cpu-thresh', and include
   an example of its usage in the commit message
 - Set inherit in evsel__config() to prevent future modifications
 - Support off-cpu sample data collected by perf before this patch series

Changes in v8:
 - Make this series bisectable
 - Rename off_cpu_thresh to off_cpu_thresh_us and offcpu_thresh (in BPF)
   to offcpu_thresh_ns for clarity
 - Add commit messages to 'perf evsel: Expose evsel__is_offcpu_event()
   for future use' commit
 - Correct spelling mistakes in the commit message (s/is should be/should be/)
 - Add kernel-doc comments to off_cpu_dump(), and comments to the empty
   if block
 - Add some comments to off-cpu test
 - Delete an unused variable 'timestamp' in off_cpu_dump()

Changes in v7:
 - Make off-cpu event system-wide
 - Use strtoull instead of strtoul
 - Delete unused variable such as sample_id, and sample_type
 - Use i as index to update BPF perf_event map
 - MAX_OFFCPU_LEN 128 is too big, make it smaller.
 - Delete some bound check as it's always guaranteed
 - Do not set ip_pos in BPF
 - Add a new field for storing stack traces in the tstamp map
 - Dump the off-cpu sample directly or save it in the off_cpu map, not both
 - Delete the sample_type_off_cpu check
 - Use __set_off_cpu_sample() to parse samples instead of a two-pass parsing

Changes in v6:
 - Make patches bisectable

Changes in v5:
 - Delete unnecessary copy in BPF program
 - Remove sample_embed from perf header, hard code off-cpu stuff instead
 - Move evsel__is_offcpu_event() to evsel.h
 - Minor changes to the test
 - Edit some comments

Changes in v4:
 - Minimize the size of data output by perf_event_output()
 - Keep only one off-cpu event
 - Change off-cpu threshold's unit to microseconds
 - Set a default off-cpu threshold
 - Print the correct error message for the field 'embed' in perf data header

Changes in v3:
 - Add off-cpu-thresh argument
 - Process direct off-cpu samples in post

Changes in v2:
 - Remove unnecessary comments.
 - Rename function off_cpu_change_type to off_cpu_prepare_parse

Howard Chu (10):
  perf evsel: Expose evsel__is_offcpu_event() for future use
  perf record --off-cpu: Parse off-cpu event
  perf record --off-cpu: Preparation of off-cpu BPF program
  perf record --off-cpu: Dump off-cpu samples in BPF
  perf evsel: Assemble offcpu samples
  perf record --off-cpu: Disable perf_event's callchain collection
  perf script: Display off-cpu samples correctly
  perf record --off-cpu: Dump the remaining samples in BPF's stack trace
    map
  perf record --off-cpu: Add --off-cpu-thresh option
  perf test: Add direct off-cpu tests

 tools/perf/Documentation/perf-record.txt |   9 ++
 tools/perf/builtin-record.c              |  33 +++++++
 tools/perf/builtin-script.c              |   4 +-
 tools/perf/tests/shell/record_offcpu.sh  |  71 ++++++++++++++
 tools/perf/util/bpf_off_cpu.c            | 119 ++++++++++++++---------
 tools/perf/util/bpf_skel/off_cpu.bpf.c   |  98 ++++++++++++++++++-
 tools/perf/util/evsel.c                  |  41 +++++++-
 tools/perf/util/evsel.h                  |   2 +
 tools/perf/util/off_cpu.h                |   3 +-
 tools/perf/util/record.h                 |   1 +
 10 files changed, 324 insertions(+), 57 deletions(-)

-- 
2.45.2
Re: [PATCH v16 00/10] perf record --off-cpu: Dump off-cpu samples directly
Posted by Arnaldo Carvalho de Melo 7 months, 1 week ago
On Wed, Apr 30, 2025 at 07:27:58PM -0700, Howard Chu wrote:
> Changes in v16:
>  - Add Tested-by from Gautam and Acked-by from Namhyung.
>  - Rebase on the perf-tools-next branch.
>  - Edit the commit message of patch 10.
>  - Fix a bug caused by the type change of struct perf_cpu.
>  - Rename test_offcpu_over_thresh() to test_offcpu_above_thresh().

Please take a look at the tmp.perf-tools-next branch at:

https://git.kernel.org/pub/scm/linux/kernel/git/perf/perf-tools-next.git

I added some Committer testing with some extra steps to describe how to
reproduce the results and there is one point that I have to retest,
where there is a FIXME in the Committer testing notes, perhaps I made a
mistake or that fix should be moved to after or before some patch,
unsure.

- Arnaldo
Re: [PATCH v16 00/10] perf record --off-cpu: Dump off-cpu samples directly
Posted by Ian Rogers 7 months, 1 week ago
On Mon, May 5, 2025 at 8:56 AM Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
>
> On Wed, Apr 30, 2025 at 07:27:58PM -0700, Howard Chu wrote:
> > Changes in v16:
> >  - Add Tested-by from Gautam and Acked-by from Namhyung.
> >  - Rebase on the perf-tools-next branch.
> >  - Edit the commit message of patch 10.
> >  - Fix a bug caused by the type change of struct perf_cpu.
> >  - Rename test_offcpu_over_thresh() to test_offcpu_above_thresh().
>
> Please take a look at the tmp.perf-tools-next branch at:
>
> https://git.kernel.org/pub/scm/linux/kernel/git/perf/perf-tools-next.git
>
> I added some Committer testing with some extra steps to describe how to
> reproduce the results and there is one point that I have to retest,
> where there is a FIXME in the Committer testing notes, perhaps I made a
> mistake or that fix should be moved to after or before some patch,
> unsure.

Hi Arnaldo,

so I tried out the tree, perf tests pass as usual, etc. I tried to dig
into your FIXME issue. Initially I thought I had a reproduction but
now I think it was a user error. So I wrote a little script where
we're setting the off CPU threshold to 10 seconds and then looking for
off CPU events that took less than than:
```
for i in $(seq 1 100)
do
  echo -n "Iteration $i of 100 "
  sudo /tmp/perf/perf record --off-cpu --off-cpu-thresh 10000 -a sleep
11 2> /dev/null
  if sudo /tmp/perf/perf script -D |grep -P '.* [0-9]{1,10} offcpu.*'
  then
    echo "BAD"
  else
    echo "GOOD"
  fi
done
```
To remove the BPF map generated events I added:
```
diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index 8898357325cf..6c23b2cf8b66 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -2841,7 +2841,7 @@ static int __cmd_record(struct record *rec, int
argc, const char **argv)
       } else
               status = err;

-       if (rec->off_cpu)
+       if (rec->off_cpu && false)
               rec->bytes_written += off_cpu_write(rec->session);

       record__read_lost_samples(rec);
```
Anyway, running the script for nearly 20 minutes, I couldn't get a
sample below the threshold. Hand testing things also look correct.

Thanks,
Ian
Re: [PATCH v16 00/10] perf record --off-cpu: Dump off-cpu samples directly
Posted by Ian Rogers 7 months, 2 weeks ago
On Wed, Apr 30, 2025 at 7:28 PM Howard Chu <howardchu95@gmail.com> wrote:
>
> As mentioned in: https://bugzilla.kernel.org/show_bug.cgi?id=207323
>
> Currently, off-cpu samples are dumped when perf record is exiting. This
> results in off-cpu samples being after the regular samples. This patch
> series makes possible dumping off-cpu samples on-the-fly, directly into
> perf ring buffer. And it dispatches those samples to the correct format
> for perf.data consumers.
>
> Before:
> ```
>      migration/0      21 [000] 27981.041319: 2944637851    cycles:P:  ffffffff90d2e8aa record_times+0xa ([kernel.kallsyms])
>             perf  770116 [001] 27981.041375:          1    cycles:P:  ffffffff90ee4960 event_function+0xf0 ([kernel.kallsyms])
>             perf  770116 [001] 27981.041377:          1    cycles:P:  ffffffff90c184b1 intel_bts_enable_local+0x31 ([kernel.kallsyms])
>             perf  770116 [001] 27981.041379:      51611    cycles:P:  ffffffff91a160b0 native_sched_clock+0x30 ([kernel.kallsyms])
>      migration/1      26 [001] 27981.041400: 4227682775    cycles:P:  ffffffff90d06a74 wakeup_preempt+0x44 ([kernel.kallsyms])
>      migration/2      32 [002] 27981.041477: 4159401534    cycles:P:  ffffffff90d11993 update_load_avg+0x63 ([kernel.kallsyms])
>
> sshd  708098 [000] 18446744069.414584:     286392 offcpu-time:
>             79a864f1c8bb ppoll+0x4b (/usr/lib/libc.so.6)
>             585690935cca [unknown] (/usr/bin/sshd)
> ```
>
> After:
> ```
>             perf  774767 [003] 28178.033444:        497           cycles:P:  ffffffff91a160c3 native_sched_clock+0x43 ([kernel.kallsyms])
>             perf  774767 [003] 28178.033445:     399440           cycles:P:  ffffffff91c01f8d nmi_restore+0x25 ([kernel.kallsyms])
>          swapper       0 [001] 28178.036639:  376650973           cycles:P:  ffffffff91a1ae99 intel_idle+0x59 ([kernel.kallsyms])
>          swapper       0 [003] 28178.182921:  348779378           cycles:P:  ffffffff91a1ae99 intel_idle+0x59 ([kernel.kallsyms])
>     blueman-tray    1355 [000] 28178.627906:  100184571 offcpu-time:
>             7528eef1c39d __poll+0x4d (/usr/lib/libc.so.6)
>             7528edf7d8fd [unknown] (/usr/lib/libglib-2.0.so.0.8000.2)
>             7528edf1af95 g_main_context_iteration+0x35 (/usr/lib/libglib-2.0.so.0.8000.2)
>             7528eda4ab86 g_application_run+0x1f6 (/usr/lib/libgio-2.0.so.0.8000.2)
>             7528ee6aa596 [unknown] (/usr/lib/libffi.so.8.1.4)
>             7fff24e862d8 [unknown] ([unknown])
>
>
>     blueman-tray    1355 [000] 28178.728137:  100187539 offcpu-time:
>             7528eef1c39d __poll+0x4d (/usr/lib/libc.so.6)
>             7528edf7d8fd [unknown] (/usr/lib/libglib-2.0.so.0.8000.2)
>             7528edf1af95 g_main_context_iteration+0x35 (/usr/lib/libglib-2.0.so.0.8000.2)
>             7528eda4ab86 g_application_run+0x1f6 (/usr/lib/libgio-2.0.so.0.8000.2)
>             7528ee6aa596 [unknown] (/usr/lib/libffi.so.8.1.4)
>             7fff24e862d8 [unknown] ([unknown])
>
>
>          swapper       0 [000] 28178.463253:  195945410           cycles:P:  ffffffff91a1ae99 intel_idle+0x59 ([kernel.kallsyms])
>      dbus-broker     412 [002] 28178.464855:  376737008           cycles:P:  ffffffff91c000a0 entry_SYSCALL_64+0x20 ([kernel.kallsyms])
> ```

Tested-by: Ian Rogers <irogers@google.com>

and in the process coming across:
https://lore.kernel.org/lkml/20250501070003.22251-1-irogers@google.com/

Thanks for persisting with this, we're past the 1 year milestone:
https://lore.kernel.org/linux-perf-users/20240424024805.144759-1-howardchu95@gmail.com/

Thanks!
Ian

> Changes in v16:
>  - Add Tested-by from Gautam and Acked-by from Namhyung.
>  - Rebase on the perf-tools-next branch.
>  - Edit the commit message of patch 10.
>  - Fix a bug caused by the type change of struct perf_cpu.
>  - Rename test_offcpu_over_thresh() to test_offcpu_above_thresh().
>
> Changes in v15:
>  - Fix workload recording bug pointed out by Arnaldo.
>  - Rename struct stack to struct __stack as suggested by Arnaldo.
>  - Delete the extra offcpu workload now that recording workload is fixed,
>    use 'sleep 1' for testing instead.
>  - Add more tests for the off-cpu-thresh option.
>
> Changes in v14:
>  - Change the internal off_cpu_thresh_us to off_cpu_thresh_ns, i.e. use
>    nsec instead of usec
>
> Changes in v13:
>  - Move the definition of 'off_cpu_thresh_ns' to the same commit as
>    dumping off-cpu samples in BPF, and give off_cpu_thresh_ns a default
>    value before the --off-cpu-thresh option is parsed.
>
> Changes in v12:
>  - Restore patches' bisectability, because the ordering of patches has
>    changed.
>  - Change 'us = ms * 1000' to 'us = ms * USEC_PER_MSEC'
>
> Changes in v11:
>  - Modify the options used in the off-cpu tests, as I changed the unit
>    of the off-cpu threshold to milliseconds.
>
> Changes in v10:
>  - Move the commit "perf record --off-cpu: Add --off-cpu-thresh option"
>    to where the direct sample feature is completed.
>  - Make --off-cpu-thresh use milliseconds as the unit.
>
> Changes in v9:
>  - Add documentation for the new option '--off-cpu-thresh', and include
>    an example of its usage in the commit message
>  - Set inherit in evsel__config() to prevent future modifications
>  - Support off-cpu sample data collected by perf before this patch series
>
> Changes in v8:
>  - Make this series bisectable
>  - Rename off_cpu_thresh to off_cpu_thresh_us and offcpu_thresh (in BPF)
>    to offcpu_thresh_ns for clarity
>  - Add commit messages to 'perf evsel: Expose evsel__is_offcpu_event()
>    for future use' commit
>  - Correct spelling mistakes in the commit message (s/is should be/should be/)
>  - Add kernel-doc comments to off_cpu_dump(), and comments to the empty
>    if block
>  - Add some comments to off-cpu test
>  - Delete an unused variable 'timestamp' in off_cpu_dump()
>
> Changes in v7:
>  - Make off-cpu event system-wide
>  - Use strtoull instead of strtoul
>  - Delete unused variable such as sample_id, and sample_type
>  - Use i as index to update BPF perf_event map
>  - MAX_OFFCPU_LEN 128 is too big, make it smaller.
>  - Delete some bound check as it's always guaranteed
>  - Do not set ip_pos in BPF
>  - Add a new field for storing stack traces in the tstamp map
>  - Dump the off-cpu sample directly or save it in the off_cpu map, not both
>  - Delete the sample_type_off_cpu check
>  - Use __set_off_cpu_sample() to parse samples instead of a two-pass parsing
>
> Changes in v6:
>  - Make patches bisectable
>
> Changes in v5:
>  - Delete unnecessary copy in BPF program
>  - Remove sample_embed from perf header, hard code off-cpu stuff instead
>  - Move evsel__is_offcpu_event() to evsel.h
>  - Minor changes to the test
>  - Edit some comments
>
> Changes in v4:
>  - Minimize the size of data output by perf_event_output()
>  - Keep only one off-cpu event
>  - Change off-cpu threshold's unit to microseconds
>  - Set a default off-cpu threshold
>  - Print the correct error message for the field 'embed' in perf data header
>
> Changes in v3:
>  - Add off-cpu-thresh argument
>  - Process direct off-cpu samples in post
>
> Changes in v2:
>  - Remove unnecessary comments.
>  - Rename function off_cpu_change_type to off_cpu_prepare_parse
>
> Howard Chu (10):
>   perf evsel: Expose evsel__is_offcpu_event() for future use
>   perf record --off-cpu: Parse off-cpu event
>   perf record --off-cpu: Preparation of off-cpu BPF program
>   perf record --off-cpu: Dump off-cpu samples in BPF
>   perf evsel: Assemble offcpu samples
>   perf record --off-cpu: Disable perf_event's callchain collection
>   perf script: Display off-cpu samples correctly
>   perf record --off-cpu: Dump the remaining samples in BPF's stack trace
>     map
>   perf record --off-cpu: Add --off-cpu-thresh option
>   perf test: Add direct off-cpu tests
>
>  tools/perf/Documentation/perf-record.txt |   9 ++
>  tools/perf/builtin-record.c              |  33 +++++++
>  tools/perf/builtin-script.c              |   4 +-
>  tools/perf/tests/shell/record_offcpu.sh  |  71 ++++++++++++++
>  tools/perf/util/bpf_off_cpu.c            | 119 ++++++++++++++---------
>  tools/perf/util/bpf_skel/off_cpu.bpf.c   |  98 ++++++++++++++++++-
>  tools/perf/util/evsel.c                  |  41 +++++++-
>  tools/perf/util/evsel.h                  |   2 +
>  tools/perf/util/off_cpu.h                |   3 +-
>  tools/perf/util/record.h                 |   1 +
>  10 files changed, 324 insertions(+), 57 deletions(-)
>
> --
> 2.45.2
>