Re: [PATCH v2 6/8] perf mmap: Fix perf backward recording
From: Arnaldo Carvalho de Melo
Date: Mon Dec 04 2017 - 10:44:10 EST
Em Mon, Dec 04, 2017 at 02:37:44PM +0900, Namhyung Kim escreveu:
> Hi,
>
> On Sun, Dec 03, 2017 at 02:00:42AM +0000, Wang Nan wrote:
> > perf record backward recording doesn't work as we expected: it never
> > overwrite when ring buffer full.
> >
> > Test:
> >
> > (Run a busy printing task background like this:
> >
> > while True:
> > print 123
> >
> > send SIGUSR2 to perf to capture snapshot.)
> >
> > # ./perf record --overwrite -e raw_syscalls:sys_enter -e raw_syscalls:sys_exit --exclude-perf -a --switch-output
> > [ perf record: dump data: Woken up 1 times ]
> > [ perf record: Dump perf.data.2017110101520743 ]
> > [ perf record: dump data: Woken up 1 times ]
> > [ perf record: Dump perf.data.2017110101521251 ]
> > [ perf record: dump data: Woken up 1 times ]
> > [ perf record: Dump perf.data.2017110101521692 ]
> > ^C[ perf record: Woken up 1 times to write data ]
> > [ perf record: Dump perf.data.2017110101521936 ]
> > [ perf record: Captured and wrote 0.826 MB perf.data.<timestamp> ]
> >
> > # ./perf script -i ./perf.data.2017110101520743 | head -n3
> > perf 2717 [000] 12449.310785: raw_syscalls:sys_enter: NR 16 (5, 2400, 0, 59, 100, 0)
> > perf 2717 [000] 12449.310790: raw_syscalls:sys_enter: NR 7 (4112340, 2, ffffffff, 3df, 100, 0)
> > python 2545 [000] 12449.310800: raw_syscalls:sys_exit: NR 1 = 4
> > # ./perf script -i ./perf.data.2017110101521251 | head -n3
> > perf 2717 [000] 12449.310785: raw_syscalls:sys_enter: NR 16 (5, 2400, 0, 59, 100, 0)
> > perf 2717 [000] 12449.310790: raw_syscalls:sys_enter: NR 7 (4112340, 2, ffffffff, 3df, 100, 0)
> > python 2545 [000] 12449.310800: raw_syscalls:sys_exit: NR 1 = 4
> > # ./perf script -i ./perf.data.2017110101521692 | head -n3
> > perf 2717 [000] 12449.310785: raw_syscalls:sys_enter: NR 16 (5, 2400, 0, 59, 100, 0)
> > perf 2717 [000] 12449.310790: raw_syscalls:sys_enter: NR 7 (4112340, 2, ffffffff, 3df, 100, 0)
> > python 2545 [000] 12449.310800: raw_syscalls:sys_exit: NR 1 = 4
> >
> > Timestamps are never change, but my background task is a dead loop, can
> > easily overwhelme the ring buffer.
> >
> > This patch fix it by force unsetting PROT_WRITE for backward ring
> > buffer, so all backward ring buffer become overwrite ring buffer.
> >
> > Test result:
> >
> > # ./perf record --overwrite -e raw_syscalls:sys_enter -e raw_syscalls:sys_exit --exclude-perf -a --switch-output
> > [ perf record: dump data: Woken up 1 times ]
> > [ perf record: Dump perf.data.2017110101285323 ]
> > [ perf record: dump data: Woken up 1 times ]
> > [ perf record: Dump perf.data.2017110101290053 ]
> > [ perf record: dump data: Woken up 1 times ]
> > [ perf record: Dump perf.data.2017110101290446 ]
> > ^C[ perf record: Woken up 1 times to write data ]
> > [ perf record: Dump perf.data.2017110101290837 ]
> > [ perf record: Captured and wrote 0.826 MB perf.data.<timestamp> ]
> > # ./perf script -i ./perf.data.2017110101285323 | head -n3
> > python 2545 [000] 11064.268083: raw_syscalls:sys_exit: NR 1 = 4
> > python 2545 [000] 11064.268084: raw_syscalls:sys_enter: NR 1 (1, 12cc330, 4, 7fc237280370, 7fc2373d0700, 2c7b0)
> > python 2545 [000] 11064.268086: raw_syscalls:sys_exit: NR 1 = 4
> > # ./perf script -i ./perf.data.2017110101290 | head -n3
> > failed to open ./perf.data.2017110101290: No such file or directory
> > # ./perf script -i ./perf.data.2017110101290053 | head -n3
> > python 2545 [000] 11071.564062: raw_syscalls:sys_enter: NR 1 (1, 12cc330, 4, 7fc237280370, 7fc2373d0700, 2c7b0)
> > python 2545 [000] 11071.564064: raw_syscalls:sys_exit: NR 1 = 4
> > python 2545 [000] 11071.564066: raw_syscalls:sys_enter: NR 1 (1, 12cc330, 4, 7fc237280370, 7fc2373d0700, 2c7b0)
> > # ./perf script -i ./perf.data.2017110101290 | head -n3
> > perf.data.2017110101290053 perf.data.2017110101290446 perf.data.2017110101290837
> > # ./perf script -i ./perf.data.2017110101290446 | head -n3
> > sshd 1321 [000] 11075.499473: raw_syscalls:sys_exit: NR 14 = 0
> > sshd 1321 [000] 11075.499474: raw_syscalls:sys_enter: NR 14 (2, 7ffe98899490, 0, 8, 0, 3000)
> > sshd 1321 [000] 11075.499474: raw_syscalls:sys_exit: NR 14 = 0
> > # ./perf script -i ./perf.data.2017110101290837 | head -n3
> > python 2545 [000] 11079.280844: raw_syscalls:sys_exit: NR 1 = 4
> > python 2545 [000] 11079.280847: raw_syscalls:sys_enter: NR 1 (1, 12cc330, 4, 7fc237280370, 7fc2373d0700, 2c7b0)
> > python 2545 [000] 11079.280850: raw_syscalls:sys_exit: NR 1 = 4
> >
> > Signed-off-by: Wang Nan <wangnan0@xxxxxxxxxx>
> > ---
> > tools/perf/util/evlist.c | 9 +++++----
> > 1 file changed, 5 insertions(+), 4 deletions(-)
> >
> > diff --git a/tools/perf/util/evlist.c b/tools/perf/util/evlist.c
> > index 68c1f95..bb70aef 100644
> > --- a/tools/perf/util/evlist.c
> > +++ b/tools/perf/util/evlist.c
> > @@ -799,7 +799,7 @@ perf_evlist__should_poll(struct perf_evlist *evlist __maybe_unused,
> > }
> >
> > static int perf_evlist__mmap_per_evsel(struct perf_evlist *evlist, int idx,
> > - struct mmap_params *mp, int cpu_idx,
> > + struct mmap_params mp, int cpu_idx,
> > int thread, int *_output, int *_output_backward)
> > {
> > struct perf_evsel *evsel;
> > @@ -824,6 +824,7 @@ static int perf_evlist__mmap_per_evsel(struct perf_evlist *evlist, int idx,
> > if (evlist->bkw_mmap_state == BKW_MMAP_NOTREADY)
> > perf_evlist__toggle_bkw_mmap(evlist, BKW_MMAP_RUNNING);
> > }
> > + mp.prot &= ~PROT_WRITE;
> > }
> >
> > if (evsel->system_wide && thread)
> > @@ -838,7 +839,7 @@ static int perf_evlist__mmap_per_evsel(struct perf_evlist *evlist, int idx,
> > if (*output == -1) {
> > *output = fd;
> >
>
> I still prefer updating mp->prot based on evsel->attr.write_backward
> here (instead of passing mp as value). It'd create a minimal change.
Wang? I applied 1-5 in this series, waiting now for this to settle,
- Arnaldo