: perf: reduce data loss when profiling highly parallel CPU bound workloads

PATCH Superseded Alexey Budankov 1 participant 4 messages Oct 5, 2018 perf events

Share & tools

Alexey Budankov

author

2018-10-05 13:35 UTC #0 lore raw

v10 cover : perf: reduce data loss when profiling highly parallel CPU bound workloads

Currently in record mode the tool implements trace writing serially. The algorithm loops over mapped per-cpu data buffers and stores ready data chunks into a trace file using write() system call.

At some circumstances the kernel may lack free space in a buffer because the other buffer's half is not yet written to disk due to some other buffer's data writing by the tool at the moment.

Thus serial trace writing implementation may cause the kernel to loose profiling data and that is what observed when profiling highly parallel CPU bound workloads on machines with big number of cores.

Experiment with profiling matrix multiplication code executing 128 threads on Intel Xeon Phi (KNM) with 272 cores, like below, demonstrates data loss metrics value of 98%:

/usr/bin/time perf record -o /tmp/perf-ser.data -a -N -B -T -R -g \
    --call-graph dwarf,1024 --user-regs=IP,SP,BP --switch-events \
    -e cycles,instructions,ref-cycles,software/period=1,name=cs,config=0x3/Duk -- \
    matrix.gcc

Data loss metrics is the ratio lost_time/elapsed_time where lost_time is the sum of time intervals containing PERF_RECORD_LOST records and elapsed_time is the elapsed application run time under profiling.

Applying asynchronous trace streaming thru Posix AIO API [1] lowers data loss metrics value providing 2x improvement (from 98% to ~1%)

Asynchronous trace streaming is currently limited to glibc linkage. musl libc [5] also provides Posix AIO API implementation, however the patchkit is not tested with it. There may be other libc libraries linked by Perf tool that currently lack Posix AIO API support [2], [3], [4] so NO_AIO define may be used to limit Perf tool binary to serial streaming only.

---
Alexey Budankov (3):
perf util: map data buffer for preserving collected data perf record: enable asynchronous trace writing perf record: extend trace writing to multi AIO

 tools/perf/Documentation/perf-record.txt |   6 +
 tools/perf/Makefile.config               |   5 +
 tools/perf/Makefile.perf                 |   7 +-
 tools/perf/builtin-record.c              | 202 ++++++++++++++++++++++++++++++-
 tools/perf/perf.h                        |   3 +
 tools/perf/util/evlist.c                 |   8 +-
 tools/perf/util/evlist.h                 |   2 +-
 tools/perf/util/mmap.c                   | 151 ++++++++++++++++++++++-
 tools/perf/util/mmap.h                   |  16 +++
 9 files changed, 388 insertions(+), 12 deletions(-)

---
Changes in v10:
- moved specific code to perf_mmap__aio_mmap(), perf_mmap__aio_munmap();
- adjusted error reporting by using %m
- avoided lseek() setting file pos back in case of record__aio_write() failure
- compacted code selecting between serial and AIO streaming
- optimized call places of record__mmap_read_sync()
- added description of aio-cblocks option into perf-record.txt
Changes in v9:
- enable AIO streaming only when --aio-cblocks option is specified explicitly
- enable AIO based implementation when linking with glibc only
- define NO_AIO to limit Perf binary to serial implementation
Changes in v8:
- run the whole thing thru checkpatch.pl and corrected found issues except lines longer than 80 symbols
- corrected comments alignment and formatting
- moved multi AIO implementation into 3rd patch in the series
- implemented explicit cblocks array allocation
- split AIO completion check into separate record__aio_complete()
- set nr_cblocks default to 1 and max allowed value to 4
Changes in v7:
- implemented handling record.aio setting from perfconfig file
Changes in v6:
- adjusted setting of priorities for cblocks;
- handled errno == EAGAIN case from aio_write() return;
Changes in v5:
- resolved livelock on perf record -e intel_pt// -- dd if=/dev/zero of=/dev/null count=100000
- data loss metrics decreased from 25% to 2x in trialed configuration;
- reshaped layout of data structures;
- implemented --aio option;
- avoided nanosleep() prior calling aio_suspend();
- switched to per-cpu aio multi buffer record__aio_sync();
- record_mmap_read_sync() now does global sync just before
switching trace file or collection stop;
Changes in v4:
- converted mmap()/munmap() to malloc()/free() for mmap->data buffer management
- converted void *bf to struct perf_mmap *md in signatures
- written comment in perf_mmap__push() just before perf_mmap__get();
- written comment in record__mmap_read_sync() on possible restarting
of aio_write() operation and releasing perf_mmap object after all;
- added perf_mmap__put() for the cases of failed aio_write();
Changes in v3:
- written comments about nanosleep(0.5ms) call prior aio_suspend()
to cope with intrusiveness of its implementation in glibc;
- written comments about rationale behind coping profiling data
into mmap->data buffer;
Changes in v2:
- converted zalloc() to calloc() for allocation of mmap_aio array,
- cleared typo and adjusted fallback branch code;

---

[1] http://man7.org/linux/man-pages/man7/aio.7.html
[2] https://android.googlesource.com/platform/bionic/+/master/docs/status.md
[3] https://www.uclibc.org/
[4] https://uclibc-ng.org/
[5] https://www.musl-libc.org/

Alexey Budankov

author

2018-10-05 13:48 UTC #1 lore raw

PATCH v9 1/3 : perf util: map data buffer for preserving collected data

The map->data buffer is used to preserve map->base profiling data for writing to disk. AIO map->cblock is used to queue corresponding map->data buffer for asynchronous writing.

Signed-off-by Alexey Budankov <[email protected]>

---
Changes in v10:
- moved specific code to perf_mmap__aio_mmap(), perf_mmap__aio_munmap()
- adjusted error reporting by using %m
Changes in v9:
- implemented NO_AIO and HAVE_AIO_SUPPORT defines to cover cases of libc implementations without Posix AIO API support
Changes in v7:
- implemented handling record.aio setting from perfconfig file
Changes in v6:
- adjusted setting of priorities for cblocks;
Changes in v5:
- reshaped layout of data structures;
- implemented --aio option;
Changes in v4:
- converted mmap()/munmap() to malloc()/free() for mmap->data buffer management
Changes in v2:
- converted zalloc() to calloc() for allocation of mmap_aio array,
- cleared typo and adjusted fallback branch code;

---
 tools/perf/Makefile.config |  5 +++++
 tools/perf/Makefile.perf   |  7 ++++++-
 tools/perf/util/evlist.c   |  4 +++-
 tools/perf/util/mmap.c     | 48 +++++++++++++++++++++++++++++++++++++++++++++-
 tools/perf/util/mmap.h     | 11 +++++++++++
 5 files changed, 72 insertions(+), 3 deletions(-)

tools/perf/Makefile.config +5 -0

index f6d1a03c7523..2e90f4ce9214 100644
@@ -355,6 +355,11 @@ endif # NO_LIBELF
 
 ifeq ($(feature-glibc), 1)
   CFLAGS += -DHAVE_GLIBC_SUPPORT
+  ifndef NO_AIO
+    ifndef BIONIC
+        CFLAGS += -DHAVE_AIO_SUPPORT
+    endif
+  endif
 endif
 
 ifdef NO_DWARF

tools/perf/Makefile.perf +6 -1

index 92514fb3689f..7becc6a72cf2 100644
@@ -97,8 +97,13 @@ include ../scripts/utilities.mak
 # Define LIBCLANGLLVM if you DO want builtin clang and llvm support.
 # When selected, pass LLVM_CONFIG=/path/to/llvm-config to `make' if
 # llvm-config is not in $PATH.
-
+#
 # Define NO_CORESIGHT if you do not want support for CoreSight trace decoding.
+#
+# Define NO_AIO if you do not want support of Posix AIO based trace
+# streaming for record mode. Currently Posix AIO trace streaming is
+# supported only when linking with glibc.
+#
 
 # As per kernel Makefile, avoid funny character set dependencies
 unexport LC_ALL

tools/perf/util/evlist.c +3 -1

index be440df29615..af2f8c965d7a 100644
@@ -1029,7 +1029,9 @@ int perf_evlist__mmap_ex(struct perf_evlist *evlist, unsigned int pages,
 	 * So &mp should not be passed through const pointer.
 	 */
 	struct mmap_params mp;
-
+#ifdef HAVE_AIO_SUPPORT
+	mp.nr_cblocks = 0;
+#endif
 	if (!evlist->mmap)
 		evlist->mmap = perf_evlist__alloc_mmap(evlist, false);
 	if (!evlist->mmap)

tools/perf/util/mmap.c +47 -1

70 lines not on this page · raw message

tools/perf/util/mmap.h +11 -0

index e603314dc792..1b63b6cc7cf9 100644
@@ -6,6 +6,9 @@
 #include <linux/types.h>
 #include <asm/barrier.h>
 #include <stdbool.h>
+#ifdef HAVE_AIO_SUPPORT
+#include <aio.h>
+#endif
 #include "auxtrace.h"
 #include "event.h"

@@ -26,6 +29,11 @@ struct perf_mmap {
 	bool		 overwrite;
 	struct auxtrace_mmap auxtrace_mmap;
 	char		 event_copy[PERF_SAMPLE_MAX_SIZE] __aligned(8);
+#ifdef HAVE_AIO_SUPPORT
+	void 		 *data;
+	struct aiocb	 cblock;
+	int		 nr_cblocks;
+#endif
 };
 
 /*

@@ -59,6 +67,9 @@ enum bkw_mmap_state {
 struct mmap_params {
 	int			    prot, mask;
 	struct auxtrace_mmap_params auxtrace_mp;
+#ifdef HAVE_AIO_SUPPORT
+	int			    nr_cblocks;
+#endif
 };
 
 int perf_mmap__mmap(struct perf_mmap *map, struct mmap_params *mp, int fd, int cpu);

Alexey Budankov

author

2018-10-05 13:50 UTC #2 lore raw

PATCH v9 2/3 : perf record: enable asynchronous trace writing

In reply to Alexey Budankov

Trace file offset is calculated and updated linearly after enqueuing aio write at record__aio_pushfn().

record__aio_sync() blocks till completion of started AIO operation and then proceeds.

record__mmap_read_sync() implements a barrier for all incomplete aio write requests.

Signed-off-by Alexey Budankov <[email protected]>

---
Changes in v10:
- avoided lseek() setting file pos back in case of record__aio_write() failure
- compacted code selecting between serial and AIO streaming
- optimized call places of record__mmap_read_sync()
Changes in v9:
- enable AIO streaming only when --aio-cblocks option is specified explicitly Changes in v8:
- split AIO completion check into separate record__aio_complete()
Changes in v6:
- handled errno == EAGAIN case from aio_write();
Changes in v5:
- data loss metrics decreased from 25% to 2x in trialed configuration;
- avoided nanosleep() prior calling aio_suspend();
- switched to per cpu multi record__aio_sync() aio
- record_mmap_read_sync() now does global barrier just before
switching trace file or collection stop;
- resolved livelock on perf record -e intel_pt// -- dd if=/dev/zero of=/dev/null count=100000 Changes in v4:
- converted void *bf to struct perf_mmap *md in signatures
- written comment in perf_mmap__push() just before perf_mmap__get();
- written comment in record__mmap_read_sync() on possible restarting
of aio_write() operation and releasing perf_mmap object after all;
- added perf_mmap__put() for the cases of failed aio_write();
Changes in v3:
- written comments about nanosleep(0.5ms) call prior aio_suspend()
to cope with intrusiveness of its implementation in glibc;
- written comments about rationale behind coping profiling data
into mmap->data buffer;

---
 tools/perf/builtin-record.c | 160 ++++++++++++++++++++++++++++++++++++++++++--
 tools/perf/perf.h           |   3 +
 tools/perf/util/mmap.c      |  73 ++++++++++++++++++++
 tools/perf/util/mmap.h      |   4 ++
 4 files changed, 236 insertions(+), 4 deletions(-)

tools/perf/builtin-record.c +156 -4

index 0980dfe3396b..b2d38cb52650 100644
@@ -124,6 +124,117 @@ static int record__write(struct record *rec, struct perf_mmap *map __maybe_unuse
 	return 0;
 }
 
+#ifdef HAVE_AIO_SUPPORT
+static int record__aio_write(struct aiocb *cblock, int trace_fd,
+		void *buf, size_t size, off_t off)
+{
+	int rc;
+
+	cblock->aio_fildes = trace_fd;
+	cblock->aio_buf    = buf;
+	cblock->aio_nbytes = size;
+	cblock->aio_offset = off;
+	cblock->aio_sigevent.sigev_notify = SIGEV_NONE;
+
+	do {
+		rc = aio_write(cblock);
+		if (rc == 0) {
+			break;
+		} else if (errno != EAGAIN) {
+			cblock->aio_fildes = -1;
+			pr_err("failed to queue perf data, error: %m\n");
+			break;
+		}
+	} while (1);
+
+	return rc;
+}
+
+static int record__aio_complete(struct perf_mmap *md, struct aiocb *cblock)
+{
+	void *rem_buf;
+	off_t rem_off;
+	size_t rem_size;
+	int rc, aio_errno;
+	ssize_t aio_ret, written;
+
+	aio_errno = aio_error(cblock);
+	if (aio_errno == EINPROGRESS)
+		return 0;
+
+	written = aio_ret = aio_return(cblock);
+	if (aio_ret < 0) {
+		if (aio_errno != EINTR)
+			pr_err("failed to write perf data, error: %m\n");
+		written = 0;
+	}
+
+	rem_size = cblock->aio_nbytes - written;
+
+	if (rem_size == 0) {
+		cblock->aio_fildes = -1;
+		/*
+		 * md->refcount is incremented in perf_mmap__push() for
+		 * every enqueued aio write request so decrement it because
+		 * the request is now complete.
+		 */
+		perf_mmap__put(md);
+		rc = 1;
+	} else {
+		/*
+		 * aio write request may require restart with the
+		 * reminder if the kernel didn't write whole
+		 * chunk at once.
+		 */
+		rem_off = cblock->aio_offset + written;
+		rem_buf = (void *)(cblock->aio_buf + written);
+		record__aio_write(cblock, cblock->aio_fildes,
+				rem_buf, rem_size, rem_off);
+		rc = 0;
+	}
+
+	return rc;
+}
+
+static void record__aio_sync(struct perf_mmap *md)
+{
+	struct aiocb *cblock = &md->cblock;
+	struct timespec timeout = { 0, 1000 * 1000  * 1 }; // 1ms
+
+	do {
+		if (cblock->aio_fildes == -1 || record__aio_complete(md, cblock))
+			return;
+
+		while (aio_suspend((const struct aiocb**)&cblock, 1, &timeout)) {
+			if (!(errno == EAGAIN || errno == EINTR))
+				pr_err("failed to sync perf data, error: %m\n");
+		}
+	} while (1);
+}
+
+static int record__aio_pushfn(void *to, struct aiocb *cblock, void *bf, size_t size)
+{
+	off_t off;
+	struct record *rec = to;
+	int ret, trace_fd = rec->session->data->file.fd;
+
+	rec->samples++;
+
+	off = lseek(trace_fd, 0, SEEK_CUR);
+	ret = record__aio_write(cblock, trace_fd, bf, size, off);
+	if (!ret) {
+		lseek(trace_fd, off + size, SEEK_SET);
+
+		rec->bytes_written += size;
+
+		if (switch_output_size(rec))
+			trigger_hit(&switch_output_trigger);
+	}
+
+	return ret;
+}
+#endif
+
 static int process_synthesized_event(struct perf_tool *tool,
 				     union perf_event *event,
 				     struct perf_sample *sample __maybe_unused,

@@ -136,7 +247,6 @@ static int process_synthesized_event(struct perf_tool *tool,
 static int record__pushfn(struct perf_mmap *map, void *to, void *bf, size_t size)
 {
 	struct record *rec = to;
-
 	rec->samples++;
 	return record__write(rec, map, bf, size);
 }

@@ -513,6 +623,25 @@ static struct perf_event_header finished_round_event = {
 	.type = PERF_RECORD_FINISHED_ROUND,
 };
 
+#ifdef HAVE_AIO_SUPPORT
+static void record__mmap_read_sync(struct record *rec)
+{
+	int i;
+	struct perf_evlist *evlist = rec->evlist;
+	struct perf_mmap *maps = evlist->mmap;
+
+	if (!rec->opts.nr_cblocks)
+		return;
+
+	for (i = 0; i < evlist->nr_mmaps; i++) {
+		struct perf_mmap *map = &maps[i];
+
+		if (map->base)
+			record__aio_sync(map);
+	}
+}
+#endif
+
 static int record__mmap_read_evlist(struct record *rec, struct perf_evlist *evlist,
 				    bool overwrite)
 {

@@ -535,10 +664,26 @@ static int record__mmap_read_evlist(struct record *rec, struct perf_evlist *evli
 		struct perf_mmap *map = &maps[i];
 
 		if (map->base) {
-			if (perf_mmap__push(map, rec, record__pushfn) != 0) {
-				rc = -1;
-				goto out;
+#ifdef HAVE_AIO_SUPPORT
+			if (!rec->opts.nr_cblocks) {
+#endif
+				if (perf_mmap__push(map, rec, record__pushfn) != 0) {
+					rc = -1;
+					goto out;
+				}
+#ifdef HAVE_AIO_SUPPORT
+			} else {
+				/*
+				 * Call record__aio_sync() to wait till map->data buffer
+				 * becomes available after previous aio write request.
+				 */
+				record__aio_sync(map);
+				if (perf_mmap__aio_push(map, rec, record__aio_pushfn) != 0) {
+					rc = -1;
+					goto out;
+				}
 			}
+#endif
 		}
 
 		if (map->auxtrace_mmap.base && !rec->opts.auxtrace_snapshot_mode &&

@@ -650,6 +795,9 @@ record__switch_output(struct record *rec, bool at_exit)
 	/* Same Size:      "2015122520103046"*/
 	char timestamp[] = "InvalidTimestamp";
 
+#ifdef HAVE_AIO_SUPPORT
+	record__mmap_read_sync(rec);
+#endif
 	record__synthesize(rec, true);
 	if (target__none(&rec->opts.target))
 		record__synthesize_workload(rec, true);

@@ -1157,6 +1305,10 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 		record__synthesize_workload(rec, true);
 
 out_child:
+
+#ifdef HAVE_AIO_SUPPORT
+	record__mmap_read_sync(rec);
+#endif
 	if (forks) {
 		int exit_status;

tools/perf/perf.h +3 -0

index 21bf7f5a3cf5..ef700d8bb610 100644
@@ -82,6 +82,9 @@ struct record_opts {
 	bool         use_clockid;
 	clockid_t    clockid;
 	unsigned int proc_map_timeout;
+#ifdef HAVE_AIO_SUPPORT
+	int	     nr_cblocks;
+#endif
 };
 
 struct option;

tools/perf/util/mmap.c +73 -0

79 lines not on this page · raw message

tools/perf/util/mmap.h +4 -0

index 1b63b6cc7cf9..ac011777c38f 100644
@@ -105,6 +105,10 @@ union perf_event *perf_mmap__read_event(struct perf_mmap *map);
 
 int perf_mmap__push(struct perf_mmap *md, void *to,
 		    int push(struct perf_mmap *map, void *to, void *buf, size_t size));
+#ifdef HAVE_AIO_SUPPORT
+int perf_mmap__aio_push(struct perf_mmap *md, void *to,
+			int push(void *to, struct aiocb *cblock, void *buf, size_t size));
+#endif
 
 size_t perf_mmap__mmap_len(struct perf_mmap *map);

Alexey Budankov

author

2018-10-05 13:51 UTC #3 lore raw

PATCH v9 3/3 : perf record: extend trace writing to multi AIO

In reply to Alexey Budankov

Multi AIO trace writing allows caching more kernel data into userspace memory postponing trace writing for the sake of overall profiling data thruput increase. It could be seen as kernel data buffer extension into userspace memory.

With aio-cblocks option value different from 0, current default value, tool has capability to cache more and more data into user space along with delegating spill to AIO.

That allows avoiding suspend at record__aio_sync() between calls of record__mmap_read_evlist() and increase profiling data thruput for the cost of userspace memory.

Signed-off-by Alexey Budankov <[email protected]>

---
Changes in v10:
- added description of aio-cblocks option into perf-record.txt

---
 tools/perf/Documentation/perf-record.txt |  6 +++
 tools/perf/builtin-record.c              | 58 +++++++++++++++++++-----
 tools/perf/util/evlist.c                 |  6 +--
 tools/perf/util/evlist.h                 |  2 +-
 tools/perf/util/mmap.c                   | 76 ++++++++++++++++++++++----------
 tools/perf/util/mmap.h                   |  7 +--
 6 files changed, 115 insertions(+), 40 deletions(-)

tools/perf/Documentation/perf-record.txt +6 -0

index 246dee081efd..7f43a05908ed 100644
@@ -435,6 +435,12 @@ Specify vmlinux path which has debuginfo.
 --buildid-all::
 Record build-id of all DSOs regardless whether it's actually hit or not.
 
+--aio-cblocks <n>
+Use <n> control blocks for asynchronous (Posix AIO) trace writing (max: 4).
+Default value is 0 that enables serial (none-AIO) trace writing mode.
+AIO mode is supported only when linking Perf tool binary with libc library
+providing implementation for Posix AIO API.
+
 --all-kernel::
 Configure all used events to run in kernel space.

tools/perf/builtin-record.c +48 ~~-10~~

112 lines not on this page · raw message

tools/perf/util/evlist.c +3 -3

index af2f8c965d7a..2dad3a4e50e0 100644
@@ -1018,7 +1018,7 @@ int perf_evlist__parse_mmap_pages(const struct option *opt, const char *str,
  */
 int perf_evlist__mmap_ex(struct perf_evlist *evlist, unsigned int pages,
 			 unsigned int auxtrace_pages,
-			 bool auxtrace_overwrite)
+			 bool auxtrace_overwrite, int nr_cblocks __maybe_unused)
 {
 	struct perf_evsel *evsel;
 	const struct cpu_map *cpus = evlist->cpus;

@@ -1030,7 +1030,7 @@ int perf_evlist__mmap_ex(struct perf_evlist *evlist, unsigned int pages,
 	 */
 	struct mmap_params mp;
 #ifdef HAVE_AIO_SUPPORT
-	mp.nr_cblocks = 0;
+	mp.nr_cblocks = nr_cblocks;
 #endif
 	if (!evlist->mmap)
 		evlist->mmap = perf_evlist__alloc_mmap(evlist, false);

@@ -1062,7 +1062,7 @@ int perf_evlist__mmap_ex(struct perf_evlist *evlist, unsigned int pages,
 
 int perf_evlist__mmap(struct perf_evlist *evlist, unsigned int pages)
 {
-	return perf_evlist__mmap_ex(evlist, pages, 0, false);
+	return perf_evlist__mmap_ex(evlist, pages, 0, false, 0);
 }
 
 int perf_evlist__create_maps(struct perf_evlist *evlist, struct target *target)

tools/perf/util/evlist.h +1 -1

index dc66436add98..2464463879b4 100644
@@ -162,7 +162,7 @@ unsigned long perf_event_mlock_kb_in_pages(void);
 
 int perf_evlist__mmap_ex(struct perf_evlist *evlist, unsigned int pages,
 			 unsigned int auxtrace_pages,
-			 bool auxtrace_overwrite);
+			 bool auxtrace_overwrite, int nr_cblocks);
 int perf_evlist__mmap(struct perf_evlist *evlist, unsigned int pages);
 void perf_evlist__munmap(struct perf_evlist *evlist);

tools/perf/util/mmap.c +53 ~~-23~~

130 lines not on this page · raw message

tools/perf/util/mmap.h +4 -3

index ac011777c38f..68050d48d767 100644
@@ -30,8 +30,9 @@ struct perf_mmap {
 	struct auxtrace_mmap auxtrace_mmap;
 	char		 event_copy[PERF_SAMPLE_MAX_SIZE] __aligned(8);
 #ifdef HAVE_AIO_SUPPORT
-	void 		 *data;
-	struct aiocb	 cblock;
+	void		 **data;
+	struct aiocb	 *cblocks;
+	struct aiocb	 **aiocb;
 	int		 nr_cblocks;
 #endif
 };

@@ -106,7 +107,7 @@ union perf_event *perf_mmap__read_event(struct perf_mmap *map);
 int perf_mmap__push(struct perf_mmap *md, void *to,
 		    int push(struct perf_mmap *map, void *to, void *buf, size_t size));
 #ifdef HAVE_AIO_SUPPORT
-int perf_mmap__aio_push(struct perf_mmap *md, void *to,
+int perf_mmap__aio_push(struct perf_mmap *md, void *to, int idx,
 			int push(void *to, struct aiocb *cblock, void *buf, size_t size));
 #endif