Re: [PATCH 1/2] perf mmap: Fix perf backward recording

From: Namhyung Kim
Date: Wed Nov 01 2017 - 05:52:06 EST

Hi,

On Wed, Nov 01, 2017 at 05:53:26AM +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 python 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 | 8 +++++++-
> 1 file changed, 7 insertions(+), 1 deletion(-)
>
> diff --git a/tools/perf/util/evlist.c b/tools/perf/util/evlist.c
> index c6c891e..4c5daba 100644
> --- a/tools/perf/util/evlist.c
> +++ b/tools/perf/util/evlist.c
> @@ -799,22 +799,28 @@ 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;
> int revent;
> int evlist_cpu = cpu_map__cpu(evlist->cpus, cpu_idx);
> + struct mmap_params *mp;
>
> evlist__for_each_entry(evlist, evsel) {
> struct perf_mmap *maps = evlist->mmap;
> + struct mmap_params rdonly_mp;
> int *output = _output;
> int fd;
> int cpu;
>
> + mp = _mp;
> if (evsel->attr.write_backward) {
> output = _output_backward;
> maps = evlist->backward_mmap;
> + rdonly_mp = *_mp;
> + rdonly_mp.prot &= ~PROT_WRITE;
> + mp = &rdonly_mp;
>
> if (!maps) {
> maps = perf_evlist__alloc_mmap(evlist);
> --

What about this instead (not tested)?


diff --git a/tools/perf/util/evlist.c b/tools/perf/util/evlist.c
index c6c891e154a6..27ebe355e794 100644
--- a/tools/perf/util/evlist.c
+++ b/tools/perf/util/evlist.c
@@ -838,6 +838,11 @@ static int perf_evlist__mmap_per_evsel(struct perf_evlist *evlist, int idx,
if (*output == -1) {
*output = fd;

+ if (evsel->attr.write_backward)
+ mp->prot = PROT_READ;
+ else
+ mp->prot = PROT_READ | PROT_WRITE;
+
if (perf_mmap__mmap(&maps[idx], mp, *output) < 0)
return -1;
} else {
@@ -1058,9 +1063,7 @@ int perf_evlist__mmap_ex(struct perf_evlist *evlist, unsigned int pages,
struct perf_evsel *evsel;
const struct cpu_map *cpus = evlist->cpus;
const struct thread_map *threads = evlist->threads;
- struct mmap_params mp = {
- .prot = PROT_READ | (overwrite ? 0 : PROT_WRITE),
- };
+ struct mmap_params mp;

if (!evlist->mmap)
evlist->mmap = perf_evlist__alloc_mmap(evlist);