: perf: reduce data loss when profiling highly parallel CPU bound workloads
v7 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.gccData 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
(http://man7.org/linux/man-pages/man7/aio.7.html)
lowers data loss metrics value providing 2x improvement - lowering 98% loss to almost 0%.
---
Alexey Budankov (2):
perf util: map data buffer for preserving collected data perf record: enable asynchronous trace writing
tools/perf/builtin-record.c | 197 +++++++++++++++++++++++++++++++++++++++++++- tools/perf/perf.h | 1 + tools/perf/util/evlist.c | 7 +- tools/perf/util/evlist.h | 3 +- tools/perf/util/mmap.c | 110 +++++++++++++++++++++---- tools/perf/util/mmap.h | 10 ++- 6 files changed, 302 insertions(+), 26 deletions(-)
---
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;
PATCH v7 1/2 : perf util: map data buffer for preserving collected data
The map->data buffers are used to preserve map->base profiling data for writing to disk. AIO map->cblocks are used to queue corresponding map->data buffers for asynchronous writing. map->cblocks objects are located in the last page of every map->data buffer.
---
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/builtin-record.c | 15 ++++++++++++- tools/perf/perf.h | 1 + tools/perf/util/evlist.c | 7 +++--- tools/perf/util/evlist.h | 3 ++- tools/perf/util/mmap.c | 53 +++++++++++++++++++++++++++++++++++++++++++++ tools/perf/util/mmap.h | 6 ++++- 6 files changed, 79 insertions(+), 6 deletions(-)
tools/perf/builtin-record.c +14 -1
@@ -326,7 +326,8 @@ static int record__mmap_evlist(struct record *rec,if (perf_evlist__mmap_ex (evlist, opts->mmap_pages, opts->auxtrace_mmap_pages, - opts->auxtrace_snapshot_mode) <0 ) { + opts->auxtrace_snapshot_mode, + opts->nr_cblocks) <0 ) {if (errno ==EPERM ) {pr_err ("Permission error mapping pages.\n" "Consider increasing "
@@ -1287,6 +1288,8 @@ static int perf_record_config(const char *var, const char *value, void *cb) var ="call-graph.record-mode" ;return perf_default_config (var, value, cb); } +if (!strcmp (var,"record.aio" )) + rec->opts.nr_cblocks =strtol (value,NULL ,0 );return 0 ; }
@@ -1519,6 +1522,7 @@ static struct record record = { .default_per_cpu = true, }, .proc_map_timeout = 500, + .nr_cblocks =2 }, .tool = { .sample = process_sample_event,
@@ -1678,6 +1682,8 @@ static struct option __record_options[] = { "signal"),OPT_BOOLEAN (0 ,"dry-run" , &dry_run,"Parse options then exit" ), +OPT_INTEGER (0 ,"aio" , &record.opts.nr_cblocks, +"asynchronous trace write operations (min: 1, max: 32, default: 2)" ), OPT_END() };
@@ -1870,6 +1876,13 @@ int cmd_record(int argc, const char **argv) goto out; } +if (!(1 <= rec->opts.nr_cblocks && rec->opts.nr_cblocks <=32 )) + rec->opts.nr_cblocks =2 ; + +if (verbose >0 ) +pr_info ("AIO trace writes: %d\n" , rec->opts.nr_cblocks); + + err =__cmd_record (&record, argc, argv); out:perf_evlist__delete (rec->evlist);
tools/perf/perf.h +1 -0
@@ -82,6 +82,7 @@ struct record_opts {bool use_clockid;clockid_t clockid;unsigned int proc_map_timeout; +int nr_cblocks; };struct option ;
tools/perf/util/evlist.c +4 -3
@@ -1018,7 +1018,8 @@ 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) {struct perf_evsel *evsel;const struct cpu_map *cpus = evlist->cpus;
@@ -1028,7 +1029,7 @@ int perf_evlist__mmap_ex(struct perf_evlist *evlist, unsigned int pages,* Its value is decided by evsel's write_backward. * So &mp should not be passed through const pointer. */ -struct mmap_params mp; +struct mmap_params mp = { .nr_cblocks = nr_cblocks };if (!evlist->mmap) evlist->mmap =perf_evlist__alloc_mmap (evlist, false);
@@ -1060,7 +1061,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,2 ); }int perf_evlist__create_maps (struct perf_evlist *evlist,struct target *target)
tools/perf/util/evlist.h +2 -1
@@ -162,7 +162,8 @@ 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 -0
71 lines not on this page · raw message
tools/perf/util/mmap.h +5 -1
@@ -6,6 +6,7 @@#include <linux/types.h> #include <asm/barrier.h> #include <stdbool.h> +#include <aio.h> #include "auxtrace.h" #include "event.h"
@@ -25,6 +26,9 @@ struct perf_mmap {bool overwrite;struct auxtrace_mmap auxtrace_mmap;char event_copy[PERF_SAMPLE_MAX_SIZE ]__aligned(8) ; +void **data; +struct aiocb **cblocks; +int nr_cblocks; };/*
@@ -56,7 +60,7 @@ enum bkw_mmap_state { };struct mmap_params { -int prot, mask; +int prot, mask, nr_cblocks;struct auxtrace_mmap_params auxtrace_mp; };
Re: [PATCH v7 1/2]: perf util: map data buffer for preserving collected data
Quoted 61 lines · Alexey Budankov
The
map->databuffers are used to preservemap->baseprofiling data for writing to disk. AIOmap->cblocksare used to queue correspondingmap->databuffers for asynchronous writing.map->cblocksobjects are located in the last page of everymap->databuffer.Signed-off-by Alexey Budankov <[email protected]>---
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() formmap->databuffer management
Changes in v2:
- convertedzalloc()tocalloc()for allocation ofmmap_aioarray,
- cleared typo and adjusted fallback branch code;--- tools/perf/builtin-record.c | 15 ++++++++++++- tools/perf/perf.h | 1 + tools/perf/util/evlist.c | 7 +++--- tools/perf/util/evlist.h | 3 ++- tools/perf/util/mmap.c | 53 +++++++++++++++++++++++++++++++++++++++++++++ tools/perf/util/mmap.h | 6 ++++- 6 files changed, 79 insertions(+), 6 deletions(-)tools/perf/builtin-record.c +5
-1@@ -326,7 +326,8 @@ static int record__mmap_evlist(struct record *rec,if (perf_evlist__mmap_ex (evlist, opts->mmap_pages, opts->auxtrace_mmap_pages, - opts->auxtrace_snapshot_mode) <0 ) { + opts->auxtrace_snapshot_mode, + opts->nr_cblocks) <0 ) {if (errno ==EPERM ) {pr_err ("Permission error mapping pages.\n" "Consider increasing "@@ -1287,6 +1288,8 @@ static int perf_record_config(const char *var, const char *value, void *cb) var ="call-graph.record-mode" ;return perf_default_config (var, value, cb); } +if (!strcmp (var,"record.aio" )) + rec->opts.nr_cblocks =strtol (value,NULL ,0 );return 0 ; }@@ -1519,6 +1522,7 @@ static struct record record = { .default_per_cpu = true, }, .proc_map_timeout = 500, + .nr_cblocks =2 }, .tool = { .sample = process_sample_event,
tools/perf/builtin-record.c static struct option __record_options[] = { · line 1686
Quoted 5 lines
tools/perf/builtin-record.c +2
-0@@ -1678,6 +1682,8 @@ static struct option __record_options[] = { "signal"),OPT_BOOLEAN (0 ,"dry-run" , &dry_run,"Parse options then exit" ), +OPT_INTEGER (0 ,"aio" , &record.opts.nr_cblocks, + "asynchronous trace write operations (min: 1, max: 32, default: 2)"),
ok, so this got silently added in recent versions and I couldn't find any justification for it.. why do we use more aio blocks for single map now? also why the default is 2?
the option should be more specific like 'aio-blocks'
the change is difficult enough.. we should start simple and add these additions with proper justification in separate patches
thanks,
jirka
Re: [PATCH v7 1/2]: perf util: map data buffer for preserving collected data
Quoted 63 lines · Jiri Olsa
Quoted 62 lines · Alexey Budankov
The
map->databuffers are used to preservemap->baseprofiling data for writing to disk. AIOmap->cblocksare used to queue correspondingmap->databuffers for asynchronous writing.map->cblocksobjects are located in the last page of everymap->databuffer.Signed-off-by Alexey Budankov <[email protected]>---
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() formmap->databuffer management
Changes in v2:
- convertedzalloc()tocalloc()for allocation ofmmap_aioarray,
- cleared typo and adjusted fallback branch code;--- tools/perf/builtin-record.c | 15 ++++++++++++- tools/perf/perf.h | 1 + tools/perf/util/evlist.c | 7 +++--- tools/perf/util/evlist.h | 3 ++- tools/perf/util/mmap.c | 53 +++++++++++++++++++++++++++++++++++++++++++++ tools/perf/util/mmap.h | 6 ++++- 6 files changed, 79 insertions(+), 6 deletions(-)tools/perf/builtin-record.c +5
-1@@ -326,7 +326,8 @@ static int record__mmap_evlist(struct record *rec,if (perf_evlist__mmap_ex (evlist, opts->mmap_pages, opts->auxtrace_mmap_pages, - opts->auxtrace_snapshot_mode) <0 ) { + opts->auxtrace_snapshot_mode, + opts->nr_cblocks) <0 ) {if (errno ==EPERM ) {pr_err ("Permission error mapping pages.\n" "Consider increasing "@@ -1287,6 +1288,8 @@ static int perf_record_config(const char *var, const char *value, void *cb) var ="call-graph.record-mode" ;return perf_default_config (var, value, cb); } +if (!strcmp (var,"record.aio" )) + rec->opts.nr_cblocks =strtol (value,NULL ,0 );return 0 ; }@@ -1519,6 +1522,7 @@ static struct record record = { .default_per_cpu = true, }, .proc_map_timeout = 500, + .nr_cblocks =2 }, .tool = { .sample = process_sample_event,@@ -1678,6 +1682,8 @@ static struct option __record_options[] = { "signal"),
Quoted 8 lines
tools/perf/builtin-record.c static struct option __record_options[] = { · line 1686
Quoted 4 lines
tools/perf/builtin-record.c +2
-0OPT_BOOLEAN (0 ,"dry-run" , &dry_run,"Parse options then exit" ), +OPT_INTEGER (0 ,"aio" , &record.opts.nr_cblocks, + "asynchronous trace write operations (min: 1, max: 32, default: 2)"),ok, so this got silently added in recent versions and I couldn't find any justification for it.. why do we use more aio blocks for single map now? also why the default is 2?
Having more blocks may improve thruput from kernel to userspace for cases when we get more data at map->base but the started AIO is not finished yet. That can easily happen between calls of record__mmap_read_evlist().
Quoted 2 lines
the option should be more specific like 'aio-blocks'
ok.
Quoted 3 lines
the change is difficult enough.. we should start simple and add these additions with proper justification in separate patches
Setting default to 1 gives the simplest solution. I could provide justification where spinning at record__aio_sync() becomes the hotspot.
Quoted 4 lines
thanks,
jirka
Re: [PATCH v7 1/2]: perf util: map data buffer for preserving collected data
In reply to Alexey BudankovOn Wed, Sep 05, 2018 at 10:19:56AM +0300, Alexey Budankov wrote:
SNIP
Quoted 18 lines
tools/perf/util/mmap.c +7
-0@@ -166,6 +174,7 @@ void perf_mmap__munmap(struct perf_mmap *map)int perf_mmap__mmap (struct perf_mmap *map,struct mmap_params *mp,int fd) { +int i;/* * The last one will be done at perf_mmap__consume(), so that we * make sure we don't prevent tools from consuming every last event in @@ -190,6 +199,50 @@ int perf_mmap__mmap(struct perf_mmap *map, struct mmap_params *mp, int fd) map->base =NULL ;return -1 ; } + map->nr_cblocks = mp->nr_cblocks; + map->cblocks =calloc (map->nr_cblocks,sizeof (struct aiocb *)); +if (!map->cblocks) { +pr_debug2 ("failed to allocate perf event data buffers, error %d\n" , + errno); +return -1 ;
tools/perf/util/mmap.c int perf_mmap__mmap(struct perf_mmap *map, struct mmap_params *mp, int fd) · line 217
Quoted 10 lines
tools/perf/util/mmap.c +10
-0+ } + map->data =calloc (map->nr_cblocks,sizeof (void *)); +if (map->data) { +int delta_max =sysconf (_SC_AIO_PRIO_DELTA_MAX); +for (i =0 ; i < map->nr_cblocks; ++i) { + map->data[i] =malloc (perf_mmap__mmap_len (map)); +if (map->data[i]) { +int prio; +unsigned char *data = map->data[i]; + map->cblocks[i] = (struct aiocb *)&data[map->mask +1 ];
the 'struct aiocb' is allocated at the last page of the buffer? is that enough space? could we please make this more transparent and allocate that space separately?
thanks,
jirka
Re: [PATCH v7 1/2]: perf util: map data buffer for preserving collected data
Quoted 28 lines · Jiri Olsa
On Wed, Sep 05, 2018 at 10:19:56AM +0300, Alexey Budankov wrote:
SNIP
Quoted 24 lines
tools/perf/util/mmap.c +13
-0@@ -166,6 +174,7 @@ void perf_mmap__munmap(struct perf_mmap *map)int perf_mmap__mmap (struct perf_mmap *map,struct mmap_params *mp,int fd) { +int i;/* * The last one will be done at perf_mmap__consume(), so that we * make sure we don't prevent tools from consuming every last event in @@ -190,6 +199,50 @@ int perf_mmap__mmap(struct perf_mmap *map, struct mmap_params *mp, int fd) map->base =NULL ;return -1 ; } + map->nr_cblocks = mp->nr_cblocks; + map->cblocks =calloc (map->nr_cblocks,sizeof (struct aiocb *)); +if (!map->cblocks) { +pr_debug2 ("failed to allocate perf event data buffers, error %d\n" , + errno); +return -1 ; + } + map->data =calloc (map->nr_cblocks,sizeof (void *)); +if (map->data) { +int delta_max =sysconf (_SC_AIO_PRIO_DELTA_MAX); +for (i =0 ; i < map->nr_cblocks; ++i) { + map->data[i] =malloc (perf_mmap__mmap_len (map));
Quoted 8 lines
tools/perf/util/mmap.c int perf_mmap__mmap(struct perf_mmap *map, struct mmap_params *mp, int fd) · line 217
Quoted 4 lines
tools/perf/util/mmap.c +4
-0+if (map->data[i]) { +int prio; +unsigned char *data = map->data[i]; + map->cblocks[i] = (struct aiocb *)&data[map->mask +1 ];the 'struct aiocb' is allocated at the last page of the buffer? is that enough space? could we please make this more transparent and allocate that space separately?
Would the array of pointers followed by the array of referenced objects fit?
Quoted 4 lines
thanks,
jirka
PATCH v7 2/2 : perf record: enable asynchronous trace writing
In reply to Alexey Budankovrecord__aio_sync() allocates index of free map->data buffer for a cpu buffer or blocks till completion of any started operation and then proceeds.
Trace file offset is calculated and updated linearly prior enqueuing aio write at record__pushfn().
record__mmap_read_sync() implements a barrier for all incomplete aio write requests per-cpu per aio data.
---
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 | 182 +++++++++++++++++++++++++++++++++++++++++++- tools/perf/util/mmap.c | 57 ++++++++++---- tools/perf/util/mmap.h | 4 +- 3 files changed, 223 insertions(+), 20 deletions(-)
tools/perf/builtin-record.c +179 -3
@@ -121,6 +121,91 @@ static int record__write(struct record *rec, void *bf, size_t size)return 0 ; } +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_sync (struct perf_mmap *md) +{ +void *rem_buf; +off_t rem_off; +size_t rem_size; +ssize_t aio_ret, written; +int i, aio_errno, do_suspend, idx =-1 ; +struct aiocb **cblocks = md->cblocks; +struct timespec timeout = {0 ,1000 *1000 *1 };// 1ms + +for (i =0 ; i < md->nr_cblocks; ++i) +if (cblocks[i]->aio_fildes ==-1 ) +return i; + +do { + do_suspend =0 ; +if (aio_suspend ((const struct aiocb **)cblocks, md->nr_cblocks, &timeout)) { +if (!(errno ==EAGAIN || errno ==EINTR )) +pr_err ("failed to sync perf data, error: %m\n" ); + do_suspend =1 ; +continue ; + } +for (i =0 ; i < md->nr_cblocks; ++i) { + aio_errno =aio_error (cblocks[i]); +if (aio_errno ==EINPROGRESS ) +continue ; + written = aio_ret =aio_return (cblocks[i]); +if (aio_ret <0 ) { +if (aio_errno !=EINTR ) +pr_err ("failed to write perf data, error: %m\n" ); + written =0 ; + } + rem_size = cblocks[i]->aio_nbytes - written; +if (rem_size ==0 ) { + cblocks[i]->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); +if (idx ==-1 ) + idx = i; + }else { +/* aio write request may require restart with the +* reminder if the kernel didn't write whole +* chunk at once. +*/ + rem_off = cblocks[i]->aio_offset + written; + rem_buf = (void *)(cblocks[i]->aio_buf + written); +record__aio_write (cblocks[i], cblocks[i]->aio_fildes, + rem_buf, rem_size, rem_off); + } + } +if (idx ==-1 ) + do_suspend =1 ; + }while (do_suspend); + +return idx; +} + static int process_synthesized_event(struct perf_tool *tool, union perf_event *event, struct perf_sample *sample __maybe_unused,
@@ -130,12 +215,28 @@ static int process_synthesized_event(struct perf_tool *tool,return record__write (rec, event, event->header.size); } -static int record__pushfn (void *to,void *bf,size_t size) +static int record__pushfn (void *to,struct aiocb *cblock,void *data,size_t size) { +off_t off;struct record *rec = to; +int ret, trace_fd = rec->session->data->file.fd; rec->samples++; -return record__write (rec, bf, size); + + off = +lseek (trace_fd,0 ,SEEK_CUR ); +lseek (trace_fd, off + size,SEEK_SET ); + + ret =record__aio_write (cblock, trace_fd, data, size, off); +if (!ret) { + rec->bytes_written += size; +if (switch_output_size (rec)) +trigger_hit (&switch_output_trigger); + }else { +lseek (trace_fd, off,SEEK_SET ); + } + +return ret; }static volatile int done;
@@ -511,6 +612,70 @@ static struct perf_event_header finished_round_event = { .type = PERF_RECORD_FINISHED_ROUND, }; +static void record__aio_complete (struct perf_mmap *md,int i) +{ +int aio_errno; +void *rem_buf; +off_t rem_off; +size_t rem_size; +ssize_t aio_ret, written; +struct aiocb *cblock = md->cblocks[i]; +struct timespec timeout = {0 ,1000 *1000 *1 };// 1ms + +if (cblock->aio_fildes ==-1 ) +return ; + +do { +if (aio_suspend ((const struct aiocb **)&cblock,1 , &timeout)) { +if (!(errno ==EAGAIN || errno ==EINTR )) +pr_err ("failed to sync perf data, error: %m\n" ); +continue ; + } + aio_errno =aio_error (cblock); +if (aio_errno ==EINPROGRESS ) +continue ; + 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); +return ; + }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); + } + }while (1 ); +} + +static void record__mmap_read_sync (struct record *rec) +{ +int i, j; +struct perf_evlist *evlist = rec->evlist; +struct perf_mmap *maps = evlist->mmap; + +for (i =0 ; i < evlist->nr_mmaps; i++) { +struct perf_mmap *map = &maps[i]; +if (map->base) +for (j =0 ; j < map->nr_cblocks; ++j) +record__aio_complete (map, j); + } +} +static int record__mmap_read_evlist (struct record *rec,struct perf_evlist *evlist,bool overwrite) {
@@ -533,7 +698,13 @@ static int record__mmap_read_evlist(struct record *rec, struct perf_evlist *evlistruct auxtrace_mmap *mm = &maps[i].auxtrace_mmap;if (maps[i].base) { -if (perf_mmap__push (&maps[i], rec, record__pushfn) !=0 ) { +/* Call record__aio_sync() to allocate free +* map->data buffer or wait till one of the +* buffers becomes available after previous +* aio write request. +*/ +if (perf_mmap__push (&maps[i], rec,record__aio_sync (&maps[i]), + record__pushfn) !=0 ) { rc =-1 ; goto out; }
@@ -1055,6 +1226,7 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)perf_evlist__toggle_bkw_mmap (rec->evlist,BKW_MMAP_DATA_PENDING );if (record__mmap_read_all (rec) <0 ) { +record__mmap_read_sync (rec);trigger_error (&auxtrace_snapshot_trigger);trigger_error (&switch_output_trigger); err =-1 ;
@@ -1066,6 +1238,7 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)if (!trigger_is_error (&auxtrace_snapshot_trigger))record__read_auxtrace_snapshot (rec);if (trigger_is_error (&auxtrace_snapshot_trigger)) { +record__mmap_read_sync (rec);pr_err ("AUX area tracing snapshot failed\n" ); err =-1 ; goto out_child;
@@ -1084,6 +1257,8 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)*/ if (rec->evlist->bkw_mmap_state ==BKW_MMAP_RUNNING )continue ; + +record__mmap_read_sync (rec);trigger_ready (&switch_output_trigger);/*
@@ -1137,6 +1312,7 @@ static int __cmd_record(struct record *rec, int argc, const char **argv) disabled = true; } } +record__mmap_read_sync (rec);trigger_off (&auxtrace_snapshot_trigger);trigger_off (&switch_output_trigger);
tools/perf/util/mmap.c +42 -15
85 lines not on this page · raw message
tools/perf/util/mmap.h +2 -2
@@ -95,8 +95,8 @@ union perf_event *perf_mmap__read_forward(struct perf_mmap *map);union perf_event *perf_mmap__read_event (struct perf_mmap *map); -int perf_mmap__push (struct perf_mmap *md,void *to, -int push (void *to,void *buf,size_t size)); +int perf_mmap__push (struct perf_mmap *md,void *to,int aio_idx, +int push (void *to,struct aiocb *cblock,void *data,size_t size));size_t perf_mmap__mmap_len (struct perf_mmap *map);
Re: [PATCH v7 2/2]: perf record: enable asynchronous trace writing
On Wed, Sep 05, 2018 at 10:39:25AM +0300, Alexey Budankov wrote:
SNIP
Quoted 9 lines
tools/perf/builtin-record.c +3
-2-static int record__pushfn (void *to,void *bf,size_t size) +static int record__pushfn (void *to,struct aiocb *cblock,void *data,size_t size) { +off_t off;struct record *rec = to; +int ret, trace_fd = rec->session->data->file.fd; rec->samples++; -return record__write (rec, bf, size);
tools/perf/builtin-record.c static int process_synthesized_event(struct perf_tool *tool, · line 234
Quoted 10 lines
tools/perf/builtin-record.c +10
-0+ + off = +lseek (trace_fd,0 ,SEEK_CUR ); +lseek (trace_fd, off + size,SEEK_SET ); + + ret =record__aio_write (cblock, trace_fd, data, size, off); +if (!ret) { + rec->bytes_written += size; +if (switch_output_size (rec)) +trigger_hit (&switch_output_trigger);
why do you need to call switch output from here?
jirka
Re: [PATCH v7 2/2]: perf record: enable asynchronous trace writing
Quoted 11 lines · Jiri Olsa
On Wed, Sep 05, 2018 at 10:39:25AM +0300, Alexey Budankov wrote:
SNIP
Quoted 7 lines
tools/perf/builtin-record.c +3
-1-static int record__pushfn (void *to,void *bf,size_t size) +static int record__pushfn (void *to,struct aiocb *cblock,void *data,size_t size) { +off_t off;struct record *rec = to; +int ret, trace_fd = rec->session->data->file.fd;
Quoted 14 lines
tools/perf/builtin-record.c static int process_synthesized_event(struct perf_tool *tool, · line 234
Quoted 12 lines
tools/perf/builtin-record.c +10
-1rec->samples++; -return record__write (rec, bf, size); + + off = +lseek (trace_fd,0 ,SEEK_CUR ); +lseek (trace_fd, off + size,SEEK_SET ); + + ret =record__aio_write (cblock, trace_fd, data, size, off); +if (!ret) { + rec->bytes_written += size; +if (switch_output_size (rec)) +trigger_hit (&switch_output_trigger);why do you need to call switch output from here?
Just preserved this logic from the serial implementation.
Quoted 3 lines
jirka
Re: [PATCH v7 2/2]: perf record: enable asynchronous trace writing
In reply to Alexey BudankovOn Wed, Sep 05, 2018 at 10:39:25AM +0300, Alexey Budankov wrote:
SNIP
Quoted 10 lines
tools/perf/builtin-record.c +2
-1+ static int process_synthesized_event(struct perf_tool *tool, union perf_event *event, struct perf_sample *sample __maybe_unused,@@ -130,12 +215,28 @@ static int process_synthesized_event(struct perf_tool *tool,return record__write (rec, event, event->header.size); } -static int record__pushfn (void *to,void *bf,size_t size) +static int record__pushfn (void *to,struct aiocb *cblock,void *data,size_t size)
tools/perf/builtin-record.c static int process_synthesized_event(struct perf_tool *tool, · line 227
Quoted 10 lines
tools/perf/builtin-record.c +5
-1{ +off_t off;struct record *rec = to; +int ret, trace_fd = rec->session->data->file.fd; rec->samples++; -return record__write (rec, bf, size); + + off = +lseek (trace_fd,0 ,SEEK_CUR );
please keep that on the same line.. also, please run this patchset through the scripts/checkpatch.pl
don't worry about the 'line over 80 characters' errors, but the rest will be nice to have ;-)
jirka
Re: [PATCH v7 2/2]: perf record: enable asynchronous trace writing
Quoted 28 lines · Jiri Olsa
On Wed, Sep 05, 2018 at 10:39:25AM +0300, Alexey Budankov wrote:
SNIP
Quoted 10 lines
tools/perf/builtin-record.c +2
-1+ static int process_synthesized_event(struct perf_tool *tool, union perf_event *event, struct perf_sample *sample __maybe_unused,@@ -130,12 +215,28 @@ static int process_synthesized_event(struct perf_tool *tool,return record__write (rec, event, event->header.size); } -static int record__pushfn (void *to,void *bf,size_t size) +static int record__pushfn (void *to,struct aiocb *cblock,void *data,size_t size)tools/perf/builtin-record.c static int process_synthesized_event(struct perf_tool *tool, · line 227
Quoted 10 lines
tools/perf/builtin-record.c +5
-1{ +off_t off;struct record *rec = to; +int ret, trace_fd = rec->session->data->file.fd; rec->samples++; -return record__write (rec, bf, size); + + off = +lseek (trace_fd,0 ,SEEK_CUR );please keep that on the same line.. also, please run this patchset through the
scripts/checkpatch.pl
Quoted 2 lines
don't worry about the 'line over 80 characters' errors, but the rest will be nice to have ;-)
ok! :)
Quoted 3 lines
jirka
Re: [PATCH v7 2/2]: perf record: enable asynchronous trace writing
In reply to Alexey BudankovOn Wed, Sep 05, 2018 at 10:39:25AM +0300, Alexey Budankov wrote:
SNIP
Quoted 21 lines
tools/perf/util/mmap.c +3
-3@@ -332,12 +332,12 @@ int perf_mmap__read_init(struct perf_mmap *map)return __perf_mmap__read_init (map); } -int perf_mmap__push (struct perf_mmap *md,void *to, -int push (void *to,void *buf,size_t size)) +int perf_mmap__push (struct perf_mmap *md,void *to,int idx, +int push (void *to,struct aiocb *cblock,void *data,size_t size)) {u64 head =perf_mmap__read_head (md);unsigned char *data = md->base + page_size; -unsigned long size; +unsigned long size, size0 =0 ;void *buf;int rc =0 ;
tools/perf/util/mmap.c int perf_mmap__push(struct perf_mmap *md, void *to, · line 349
Quoted 5 lines
tools/perf/util/mmap.c +2
-0@@ -345,31 +345,58 @@ int perf_mmap__push(struct perf_mmap *md, void *to,if (rc <0 )return (rc == -EAGAIN ) ?0 :-1 ; +/* md->base data is copied into md->data[idx] buffer to +* release space in the kernel buffer as fast as possible,
please start the comment with the extra '/*', like:
/* * md->base data is copied into md->data[idx] buffer to * release space in the kernel buffer as fast as possible, ...
jirka
Re: [PATCH v7 2/2]: perf record: enable asynchronous trace writing
Quoted 33 lines · Jiri Olsa
On Wed, Sep 05, 2018 at 10:39:25AM +0300, Alexey Budankov wrote:
SNIP
Quoted 21 lines
tools/perf/util/mmap.c +3
-3@@ -332,12 +332,12 @@ int perf_mmap__read_init(struct perf_mmap *map)return __perf_mmap__read_init (map); } -int perf_mmap__push (struct perf_mmap *md,void *to, -int push (void *to,void *buf,size_t size)) +int perf_mmap__push (struct perf_mmap *md,void *to,int idx, +int push (void *to,struct aiocb *cblock,void *data,size_t size)) {u64 head =perf_mmap__read_head (md);unsigned char *data = md->base + page_size; -unsigned long size; +unsigned long size, size0 =0 ;void *buf;int rc =0 ;tools/perf/util/mmap.c int perf_mmap__push(struct perf_mmap *md, void *to, · line 349
Quoted 5 lines
tools/perf/util/mmap.c +2
-0@@ -345,31 +345,58 @@ int perf_mmap__push(struct perf_mmap *md, void *to,if (rc <0 )return (rc == -EAGAIN ) ?0 :-1 ; +/* md->base data is copied into md->data[idx] buffer to +* release space in the kernel buffer as fast as possible, please start the comment with the extra '/*', like:
Quoted 4 lines
/* * md->base data is copied into md->data[idx] buffer to * release space in the kernel buffer as fast as possible, ...
Accepted!
Quoted 3 lines
jirka
Re: [PATCH v7 2/2]: perf record: enable asynchronous trace writing
In reply to Alexey BudankovOn Wed, Sep 05, 2018 at 10:39:25AM +0300, Alexey Budankov wrote:
SNIP
tools/perf/builtin-record.c static int record__write(struct record *rec, void *bf, size_t size) · line 150
Quoted 12 lines
tools/perf/builtin-record.c +12
-0+ }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_sync (struct perf_mmap *md) +{
this is almost identical to record__aio_sync function, it looks like we should be able to do the sync with single function.. for both the in-between syncs and the final one
jirka
Re: [PATCH v7 2/2]: perf record: enable asynchronous trace writing
Quoted 13 lines · Jiri Olsa
On Wed, Sep 05, 2018 at 10:39:25AM +0300, Alexey Budankov wrote:
SNIP
Quoted 9 lines
tools/perf/builtin-record.c +9
-0+ }else if (errno !=EAGAIN ) { + cblock->aio_fildes =-1 ; +pr_err ("failed to queue perf data, error: %m\n" ); +break ; + } + }while (1 ); + +return rc; +}
Quoted 8 lines
tools/perf/builtin-record.c static int record__write(struct record *rec, void *bf, size_t size) · line 150
Quoted 3 lines
tools/perf/builtin-record.c +3
-0+ +static int record__aio_sync (struct perf_mmap *md) +{this is almost identical to
record__aio_syncfunction, it looks like we should be able to do the sync with single function.. for both the in-between syncs and the final one
There is some code duplication here. for()'s loop body at record__aio_complete() could probably be separated to a function and then reused by record__aio_sync(). The rest is not obvious at the moment.
Quoted 3 lines
jirka
Quoted 46 lines · Alexey Budankov
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.gccData loss metrics is the ratio lost_time/elapsed_time where
lost_timeis the sum of time intervals containingPERF_RECORD_LOSTrecords andelapsed_timeis the elapsed application run time under profiling.Applying asynchronous trace streaming thru Posix AIO API
(http://man7.org/linux/man-pages/man7/aio.7.html)
lowers data loss metrics value providing 2x improvement - lowering 98% loss to almost 0%.---
Alexey Budankov (2):
perf util: map data buffer for preserving collected data perf record: enable asynchronous trace writingtools/perf/builtin-record.c | 197 +++++++++++++++++++++++++++++++++++++++++++- tools/perf/perf.h | 1 + tools/perf/util/evlist.c | 7 +- tools/perf/util/evlist.h | 3 +- tools/perf/util/mmap.c | 110 +++++++++++++++++++++---- tools/perf/util/mmap.h | 10 ++- 6 files changed, 302 insertions(+), 26 deletions(-)
Quoted 3 lines
---
Changes in v7:
- implemented handling record.aio setting from perfconfig file
can't apply this version on Arnaldo's perf/core...
[jolsa@krava linux-perf]$ git am /tmp/ab/
Applying: perf util: map data buffer for preserving collected data
error: patch failed: tools/perf/util/mmap.c:166
error: tools/perf/util/mmap.c: patch does not apply
thanks,
jirka
Hi,
Quoted 47 lines · Jiri Olsa
Quoted 46 lines · Alexey Budankov
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.gccData loss metrics is the ratio lost_time/elapsed_time where
lost_timeis the sum of time intervals containingPERF_RECORD_LOSTrecords andelapsed_timeis the elapsed application run time under profiling.Applying asynchronous trace streaming thru Posix AIO API
(http://man7.org/linux/man-pages/man7/aio.7.html)
lowers data loss metrics value providing 2x improvement - lowering 98% loss to almost 0%.---
Alexey Budankov (2):
perf util: map data buffer for preserving collected data perf record: enable asynchronous trace writingtools/perf/builtin-record.c | 197 +++++++++++++++++++++++++++++++++++++++++++- tools/perf/perf.h | 1 + tools/perf/util/evlist.c | 7 +- tools/perf/util/evlist.h | 3 +- tools/perf/util/mmap.c | 110 +++++++++++++++++++++---- tools/perf/util/mmap.h | 10 ++- 6 files changed, 302 insertions(+), 26 deletions(-)
Quoted 5 lines
Quoted 3 lines
---
Changes in v7:
- implemented handling record.aio setting from perfconfig filecan't apply this version on Arnaldo's perf/core...
my git remote -v
origin git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip (fetch)
origin git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip (push)
branch is perf/core, according to MAINTAINERS content.
What is Arnaldo's perf/core? This one?
git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux
and branch is perf/core?
Quoted 9 lines
[jolsa@krava linux-perf]$ git am
/tmp/ab/
Applying: perf util: map data buffer for preserving collected data
error: patch failed:tools/perf/util/mmap.c:166
error:tools/perf/util/mmap.c: patch does not applythanks,
jirka
Arnaldo Carvalho de Melo
maintainerEm Wed, Sep 05, 2018 at 08:37:32PM +0300, Alexey Budankov escreveu:
Quoted 8 lines · Jiri Olsa
Quoted 1 line
can't apply this version on Arnaldo's perf/core...
my git remote -v
origin
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip(fetch)
origingit://git.kernel.org/pub/scm/linux/kernel/git/tip/tip(push)
Quoted 7 lines
branch is perf/core, according to
MAINTAINERScontent.What is Arnaldo's perf/core? This one?
git://git.kernel.org/pub/scm/linux/kernel/git/acme/linuxand branch is perf/core?
yes.
- Arnaldo
Hi,
Quoted 11 lines · Arnaldo Carvalho de Melo
Em Wed, Sep 05, 2018 at 08:37:32PM +0300, Alexey Budankov escreveu:
Quoted 9 lines · Jiri Olsa
Quoted 1 line
can't apply this version on Arnaldo's perf/core...
my git remote -v
origin
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip(fetch)
origingit://git.kernel.org/pub/scm/linux/kernel/git/tip/tip(push)branch is perf/core, according to
MAINTAINERScontent.
Quoted 7 lines
Quoted 5 lines
What is Arnaldo's perf/core? This one?
git://git.kernel.org/pub/scm/linux/kernel/git/acme/linuxand branch is perf/core?
yes.
Is this the actual one for the tool development? Am I missing something?
Thanks,
Alexey
Quoted 3 lines
- Arnaldo
Quoted 16 lines · Alexey Budankov
Hi,
Quoted 13 lines · Arnaldo Carvalho de Melo
Em Wed, Sep 05, 2018 at 08:37:32PM +0300, Alexey Budankov escreveu:
Quoted 11 lines · Jiri Olsa
Quoted 1 line
can't apply this version on Arnaldo's perf/core...
my git remote -v
origin
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip(fetch)
origingit://git.kernel.org/pub/scm/linux/kernel/git/tip/tip(push)branch is perf/core, according to
MAINTAINERScontent.What is Arnaldo's perf/core? This one?
Quoted 7 lines
Quoted 5 lines
Quoted 3 lines
git://git.kernel.org/pub/scm/linux/kernel/git/acme/linuxand branch is perf/core?
yes.
Is this the actual one for the tool development? Am I missing something?
yep, Arnaldo takes all and pushes his perf/core to Ingo it's better to always rebase to it
thanks,
jirka
Hi,
Quoted 19 lines · Jiri Olsa
Quoted 18 lines · Alexey Budankov
Hi,
Quoted 15 lines · Arnaldo Carvalho de Melo
Em Wed, Sep 05, 2018 at 08:37:32PM +0300, Alexey Budankov escreveu:
Quoted 13 lines · Jiri Olsa
Quoted 1 line
can't apply this version on Arnaldo's perf/core...
my git remote -v
origin
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip(fetch)
origingit://git.kernel.org/pub/scm/linux/kernel/git/tip/tip(push)branch is perf/core, according to
MAINTAINERScontent.What is Arnaldo's perf/core? This one?
git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux
Quoted 8 lines
Quoted 5 lines
Quoted 3 lines
Quoted 1 line
and branch is perf/core?
yes.
Is this the actual one for the tool development? Am I missing something?
yep, Arnaldo takes all and pushes his perf/core to Ingo it's better to always rebase to it
Good to know. Thanks!
Quoted 4 lines
thanks,
jirka
Hi,
Quoted 11 lines · Arnaldo Carvalho de Melo
Em Wed, Sep 05, 2018 at 08:37:32PM +0300, Alexey Budankov escreveu:
Quoted 9 lines · Jiri Olsa
Quoted 1 line
can't apply this version on Arnaldo's perf/core...
my git remote -v
origin
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip(fetch)
origingit://git.kernel.org/pub/scm/linux/kernel/git/tip/tip(push)branch is perf/core, according to
MAINTAINERScontent.
Quoted 7 lines
Quoted 5 lines
What is Arnaldo's perf/core? This one?
git://git.kernel.org/pub/scm/linux/kernel/git/acme/linuxand branch is perf/core?
yes.
See patch on top of this branch in answer to Jiri.
Quoted 3 lines
- Arnaldo
Hi,
Quoted 51 lines · Jiri Olsa
Quoted 46 lines · Alexey Budankov
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.gccData loss metrics is the ratio lost_time/elapsed_time where
lost_timeis the sum of time intervals containingPERF_RECORD_LOSTrecords andelapsed_timeis the elapsed application run time under profiling.Applying asynchronous trace streaming thru Posix AIO API
(http://man7.org/linux/man-pages/man7/aio.7.html)
lowers data loss metrics value providing 2x improvement - lowering 98% loss to almost 0%.---
Alexey Budankov (2):
perf util: map data buffer for preserving collected data perf record: enable asynchronous trace writingtools/perf/builtin-record.c | 197 +++++++++++++++++++++++++++++++++++++++++++- tools/perf/perf.h | 1 + tools/perf/util/evlist.c | 7 +- tools/perf/util/evlist.h | 3 +- tools/perf/util/mmap.c | 110 +++++++++++++++++++++---- tools/perf/util/mmap.h | 10 ++- 6 files changed, 302 insertions(+), 26 deletions(-)Quoted 3 lines
---
Changes in v7:
- implemented handling record.aio setting from perfconfig file
Quoted 6 lines
can't apply this version on Arnaldo's perf/core...
[jolsa@krava linux-perf]$ git am
/tmp/ab/
Applying: perf util: map data buffer for preserving collected data
error: patch failed:tools/perf/util/mmap.c:166
error:tools/perf/util/mmap.c: patch does not apply
Here it is:
tools/perf/builtin-record.c | 197 +++++++++++++++++++++++++++++++++++++++++++- tools/perf/perf.h | 1 + tools/perf/util/evlist.c | 7 +- tools/perf/util/evlist.h | 3 +- tools/perf/util/mmap.c | 110 +++++++++++++++++++++---- tools/perf/util/mmap.h | 10 ++- 6 files changed, 302 insertions(+), 26 deletions(-)
tools/perf/builtin-record.c +193 -4
@@ -121,6 +121,91 @@ static int record__write(struct record *rec, void *bf, size_t size)return 0 ; } +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_sync (struct perf_mmap *md) +{ +void *rem_buf; +off_t rem_off; +size_t rem_size; +ssize_t aio_ret, written; +int i, aio_errno, do_suspend, idx =-1 ; +struct aiocb **cblocks = md->cblocks; +struct timespec timeout = {0 ,1000 *1000 *1 };// 1ms + +for (i =0 ; i < md->nr_cblocks; ++i) +if (cblocks[i]->aio_fildes ==-1 ) +return i; + +do { + do_suspend =0 ; +if (aio_suspend ((const struct aiocb **)cblocks, md->nr_cblocks, &timeout)) { +if (!(errno ==EAGAIN || errno ==EINTR )) +pr_err ("failed to sync perf data, error: %m\n" ); + do_suspend =1 ; +continue ; + } +for (i =0 ; i < md->nr_cblocks; ++i) { + aio_errno =aio_error (cblocks[i]); +if (aio_errno ==EINPROGRESS ) +continue ; + written = aio_ret =aio_return (cblocks[i]); +if (aio_ret <0 ) { +if (aio_errno !=EINTR ) +pr_err ("failed to write perf data, error: %m\n" ); + written =0 ; + } + rem_size = cblocks[i]->aio_nbytes - written; +if (rem_size ==0 ) { + cblocks[i]->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); +if (idx ==-1 ) + idx = i; + }else { +/* aio write request may require restart with the +* reminder if the kernel didn't write whole +* chunk at once. +*/ + rem_off = cblocks[i]->aio_offset + written; + rem_buf = (void *)(cblocks[i]->aio_buf + written); +record__aio_write (cblocks[i], cblocks[i]->aio_fildes, + rem_buf, rem_size, rem_off); + } + } +if (idx ==-1 ) + do_suspend =1 ; + }while (do_suspend); + +return idx; +} + static int process_synthesized_event(struct perf_tool *tool, union perf_event *event, struct perf_sample *sample __maybe_unused,
@@ -130,12 +215,28 @@ static int process_synthesized_event(struct perf_tool *tool,return record__write (rec, event, event->header.size); } -static int record__pushfn (void *to,void *bf,size_t size) +static int record__pushfn (void *to,struct aiocb *cblock,void *data,size_t size) { +off_t off;struct record *rec = to; +int ret, trace_fd = rec->session->data->file.fd; rec->samples++; -return record__write (rec, bf, size); + + off = +lseek (trace_fd,0 ,SEEK_CUR ); +lseek (trace_fd, off + size,SEEK_SET ); + + ret =record__aio_write (cblock, trace_fd, data, size, off); +if (!ret) { + rec->bytes_written += size; +if (switch_output_size (rec)) +trigger_hit (&switch_output_trigger); + }else { +lseek (trace_fd, off,SEEK_SET ); + } + +return ret; }static volatile int done;
@@ -326,7 +427,8 @@ static int record__mmap_evlist(struct record *rec,if (perf_evlist__mmap_ex (evlist, opts->mmap_pages, opts->auxtrace_mmap_pages, - opts->auxtrace_snapshot_mode) <0 ) { + opts->auxtrace_snapshot_mode, + opts->nr_cblocks) <0 ) {if (errno ==EPERM ) {pr_err ("Permission error mapping pages.\n" "Consider increasing "
@@ -510,6 +612,70 @@ static struct perf_event_header finished_round_event = { .type = PERF_RECORD_FINISHED_ROUND, }; +static void record__aio_complete (struct perf_mmap *md,int i) +{ +int aio_errno; +void *rem_buf; +off_t rem_off; +size_t rem_size; +ssize_t aio_ret, written; +struct aiocb *cblock = md->cblocks[i]; +struct timespec timeout = {0 ,1000 *1000 *1 };// 1ms + +if (cblock->aio_fildes ==-1 ) +return ; + +do { +if (aio_suspend ((const struct aiocb **)&cblock,1 , &timeout)) { +if (!(errno ==EAGAIN || errno ==EINTR )) +pr_err ("failed to sync perf data, error: %m\n" ); +continue ; + } + aio_errno =aio_error (cblock); +if (aio_errno ==EINPROGRESS ) +continue ; + 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); +return ; + }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); + } + }while (1 ); +} + +static void record__mmap_read_sync (struct record *rec) +{ +int i, j; +struct perf_evlist *evlist = rec->evlist; +struct perf_mmap *maps = evlist->mmap; + +for (i =0 ; i < evlist->nr_mmaps; i++) { +struct perf_mmap *map = &maps[i]; +if (map->base) +for (j =0 ; j < map->nr_cblocks; ++j) +record__aio_complete (map, j); + } +} +static int record__mmap_read_evlist (struct record *rec,struct perf_evlist *evlist,bool overwrite) {
@@ -532,7 +698,13 @@ static int record__mmap_read_evlist(struct record *rec, struct perf_evlist *evlistruct auxtrace_mmap *mm = &maps[i].auxtrace_mmap;if (maps[i].base) { -if (perf_mmap__push (&maps[i], rec, record__pushfn) !=0 ) { +/* Call record__aio_sync() to allocate free +* map->data buffer or wait till one of the +* buffers becomes available after previous +* aio write request. +*/ +if (perf_mmap__push (&maps[i], rec,record__aio_sync (&maps[i]), + record__pushfn) !=0 ) { rc =-1 ; goto out; }
@@ -1054,6 +1226,7 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)perf_evlist__toggle_bkw_mmap (rec->evlist,BKW_MMAP_DATA_PENDING );if (record__mmap_read_all (rec) <0 ) { +record__mmap_read_sync (rec);trigger_error (&auxtrace_snapshot_trigger);trigger_error (&switch_output_trigger); err =-1 ;
@@ -1065,6 +1238,7 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)if (!trigger_is_error (&auxtrace_snapshot_trigger))record__read_auxtrace_snapshot (rec);if (trigger_is_error (&auxtrace_snapshot_trigger)) { +record__mmap_read_sync (rec);pr_err ("AUX area tracing snapshot failed\n" ); err =-1 ; goto out_child;
@@ -1083,6 +1257,8 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)*/ if (rec->evlist->bkw_mmap_state ==BKW_MMAP_RUNNING )continue ; + +record__mmap_read_sync (rec);trigger_ready (&switch_output_trigger);/*
@@ -1136,6 +1312,7 @@ static int __cmd_record(struct record *rec, int argc, const char **argv) disabled = true; } } +record__mmap_read_sync (rec);trigger_off (&auxtrace_snapshot_trigger);trigger_off (&switch_output_trigger);
@@ -1287,6 +1464,8 @@ static int perf_record_config(const char *var, const char *value, void *cb) var ="call-graph.record-mode" ;return perf_default_config (var, value, cb); } +if (!strcmp (var,"record.aio" )) + rec->opts.nr_cblocks =strtol (value,NULL ,0 );return 0 ; }
@@ -1519,6 +1698,7 @@ static struct record record = { .default_per_cpu = true, }, .proc_map_timeout = 500, + .nr_cblocks =2 }, .tool = { .sample = process_sample_event,
@@ -1678,6 +1858,8 @@ static struct option __record_options[] = { "signal"),OPT_BOOLEAN (0 ,"dry-run" , &dry_run,"Parse options then exit" ), +OPT_INTEGER (0 ,"aio" , &record.opts.nr_cblocks, +"asynchronous trace write operations (min: 1, max: 32, default: 2)" ), OPT_END() };
@@ -1870,6 +2052,13 @@ int cmd_record(int argc, const char **argv) goto out; } +if (!(1 <= rec->opts.nr_cblocks && rec->opts.nr_cblocks <=32 )) + rec->opts.nr_cblocks =2 ; + +if (verbose >0 ) +pr_info ("AIO trace writes: %d\n" , rec->opts.nr_cblocks); + + err =__cmd_record (&record, argc, argv); out:perf_evlist__delete (rec->evlist);
tools/perf/perf.h +1 -0
@@ -82,6 +82,7 @@ struct record_opts {bool use_clockid;clockid_t clockid;unsigned int proc_map_timeout; +int nr_cblocks; };struct option ;
tools/perf/util/evlist.c +4 -3
@@ -1018,7 +1018,8 @@ 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) {struct perf_evsel *evsel;const struct cpu_map *cpus = evlist->cpus;
@@ -1028,7 +1029,7 @@ int perf_evlist__mmap_ex(struct perf_evlist *evlist, unsigned int pages,* Its value is decided by evsel's write_backward. * So &mp should not be passed through const pointer. */ -struct mmap_params mp; +struct mmap_params mp = { .nr_cblocks = nr_cblocks };if (!evlist->mmap) evlist->mmap =perf_evlist__alloc_mmap (evlist, false);
@@ -1060,7 +1061,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,2 ); }int perf_evlist__create_maps (struct perf_evlist *evlist,struct target *target)
tools/perf/util/evlist.h +2 -1
@@ -162,7 +162,8 @@ 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 +95 -15
156 lines not on this page · raw message
tools/perf/util/mmap.h +7 -3
@@ -6,6 +6,7 @@#include <linux/types.h> #include <asm/barrier.h> #include <stdbool.h> +#include <aio.h> #include "auxtrace.h" #include "event.h"
@@ -26,6 +27,9 @@ struct perf_mmap {bool overwrite;struct auxtrace_mmap auxtrace_mmap;char event_copy[PERF_SAMPLE_MAX_SIZE ]__aligned(8) ; +void **data; +struct aiocb **cblocks; +int nr_cblocks; };/*
@@ -57,7 +61,7 @@ enum bkw_mmap_state { };struct mmap_params { -int prot, mask; +int prot, mask, nr_cblocks;struct auxtrace_mmap_params auxtrace_mp; };
@@ -92,8 +96,8 @@ union perf_event *perf_mmap__read_forward(struct perf_mmap *map);union perf_event *perf_mmap__read_event (struct perf_mmap *map); -int perf_mmap__push (struct perf_mmap *md,void *to, -int push (void *to,void *buf,size_t size)); +int perf_mmap__push (struct perf_mmap *md,void *to,int aio_idx, +int push (void *to,struct aiocb *cblock,void *data,size_t size));size_t perf_mmap__mmap_len (struct perf_mmap *map);
Quoted 4 lines
thanks,
jirka