[PATCH v2 6/8] perf mmap: Fix perf backward recording

From: Wang Nan
Date: Sat Dec 02 2017 - 21:04:03 EST


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;

- if (perf_mmap__mmap(&maps[idx], mp, *output) < 0)
+ if (perf_mmap__mmap(&maps[idx], &mp, *output) < 0)
return -1;
} else {
if (ioctl(fd, PERF_EVENT_IOC_SET_OUTPUT, *output) != 0)
@@ -890,7 +891,7 @@ static int perf_evlist__mmap_per_cpu(struct perf_evlist *evlist,
true);

for (thread = 0; thread < nr_threads; thread++) {
- if (perf_evlist__mmap_per_evsel(evlist, cpu, mp, cpu,
+ if (perf_evlist__mmap_per_evsel(evlist, cpu, *mp, cpu,
thread, &output, &output_backward))
goto out_unmap;
}
@@ -917,7 +918,7 @@ static int perf_evlist__mmap_per_thread(struct perf_evlist *evlist,
auxtrace_mmap_params__set_idx(&mp->auxtrace_mp, evlist, thread,
false);

- if (perf_evlist__mmap_per_evsel(evlist, thread, mp, 0, thread,
+ if (perf_evlist__mmap_per_evsel(evlist, thread, *mp, 0, thread,
&output, &output_backward))
goto out_unmap;
}
--
2.10.1