Re: [RFC/PATCH] perf trace: Add --syscall-period option

[Howard Chu]

Hello Ian,

On Wed, Dec 11, 2024 at 5:34 PM Ian Rogers <irogers@xxxxxxxxxx> wrote:
>
> On Wed, Dec 11, 2024 at 2:52 PM Arnaldo Carvalho de Melo
> <acme@xxxxxxxxxx> wrote:
> >
> > On Wed, Dec 11, 2024 at 02:21:10PM -0800, Namhyung Kim wrote:
> > > This option is to implement the event sampling for system calls.
> > > The period is given in msec as it shows the time in msec.
> > >
> > >   # perf trace -C 0 --syscall-period 100 sleep 1
> > >            ? (         ): fleetspeakd/1828559  ... [continued]: futex())                                            = -1 ETIMEDOUT (Connection timed out)
> > >        0.050 (100.247 ms): gnome-shell/572531 recvmsg(fd: 10<socket:[3355761]>, msg: 0x7ffef8b39d20)                = 40
> > >      100.357 (100.149 ms): pipewire-pulse/572245 read(fd: 5<anon_inode:[eventfd]>, buf: 0x7ffc0b9dc8f0, count: 8)      = 8
> > >      200.553 (100.268 ms): NetworkManager/3424 epoll_wait(epfd: 19<anon_inode:[eventpoll]>, events: 0x5607b85bb880, maxevents: 6) = 0
> > >      300.876 (         ): mon/4932 poll(ufds: 0x7fa392784df0, nfds: 1, timeout_msecs: 100)            ...
> > >      400.901 ( 0.025 ms): TaskCon~ller #/620145 futex(uaddr: 0x7f3fc596fa00, op: WAKE|PRIVATE_FLAG, val: 1)           = 0
> > >      300.876 (100.123 ms): mon/4932  ... [continued]: poll())                                             = 0 (Timeout)
> > >      500.901 ( 0.012 ms): evdefer/2/2335122 futex(uaddr: 0x5640baac5198, op: WAKE|PRIVATE_FLAG, val: 1)           = 0
> > >      602.701 ( 0.017 ms): Compositor/1992200 futex(uaddr: 0x7f1a51dfdd40, op: WAKE|PRIVATE_FLAG, val: 1)           = 0
> > >      705.589 ( 0.017 ms): JS Watchdog/947933 futex(uaddr: 0x7f4cac1d4240, op: WAKE|PRIVATE_FLAG, val: 1)           = 0
> > >      812.667 ( 0.027 ms): fix/1985151 futex(uaddr: 0xc0008f7148, op: WAKE|PRIVATE_FLAG, val: 1)             = 1
> > >      912.807 ( 0.017 ms): Xorg/572315 setitimer(value: 0x7ffc375d6ba0)                                      = 0
> > >
> > > The timestamp is kept in a per-cpu array and the allowed task is saved
> > > in a hash map.
> >
> > Interesting concept, and one that is done just on the BPF part, so I
> > think we should at least warn a user that is running this on a build
> > without BPF skels.
> >
> > Will try it tomorrow,
> >
> > - Arnaldo
> >
> > > Signed-off-by: Namhyung Kim <namhyung@xxxxxxxxxx>
> > > ---
> > >  tools/perf/Documentation/perf-trace.txt       |  6 ++
> > >  tools/perf/builtin-trace.c                    |  5 ++
> > >  .../bpf_skel/augmented_raw_syscalls.bpf.c     | 67 ++++++++++++++++++-
> > >  3 files changed, 76 insertions(+), 2 deletions(-)
> > >
> > > diff --git a/tools/perf/Documentation/perf-trace.txt b/tools/perf/Documentation/perf-trace.txt
> > > index 6e0cc50bbc13fc7f..9f338a8c5357a67e 100644
> > > --- a/tools/perf/Documentation/perf-trace.txt
> > > +++ b/tools/perf/Documentation/perf-trace.txt
> > > @@ -241,6 +241,12 @@ the thread executes on the designated CPUs. Default is to monitor all CPUs.
> > >       printing using the existing 'perf trace' syscall arg beautifiers to map integer
> > >       arguments to strings (pid to comm, syscall id to syscall name, etc).
> > >
> > > +--syscall-period::
> > > +     Trace a system call in the given period (in msec).  This implements
> > > +     sampling for syscalls in order to reduce the monitoring overhead.
> > > +     For example, setting the sysall period to 100 (msec) means it will
> > > +     sample a syscall and next one after 100 msec.
>
> Is this similar to the -D/--delay option to perf-record? Perhaps share the name?

I think this is more like a throttling for the perf trace output,
instead of a one-time delay or a range of enabled time like -D, as the
prev_ts here is continuously updated. This restricts the maximum
sampling frequency to 1 / syscall-period, meaning every syscall is
sampled just after the syscall-period has passed.

Thanks,
Howard