RE: [PATCH V9 8/8] perf tools: handle PERF_RECORD_LOST_SAMPLES

From: Liang, Kan
Date: Mon May 11 2015 - 16:41:26 EST



>
> Em Sun, May 10, 2015 at 03:13:15PM -0400, Kan Liang escreveu:
> > From: Kan Liang <kan.liang@xxxxxxxxx>
> >
> > This patch modified the perf tool to handle the new RECORD type,
> > PERF_RECORD_LOST_SAMPLES.
> > The number of lost-sample events is stored in
> > .nr_events[PERF_RECORD_LOST_SAMPLES]. While the exact number of
> > samples which the kernel dropped is stored in total_lost_samples.
> > When the percentage of dropped samples is greater than 5%, a warning
> > will be sent out.
> >
> > Here are some examples:
> >
> > Eg 1, Recording different frequently-occurring events is safe with the
> > patch. Only a very low drop rate is associated with such actions.
> >
> > $ perf record -e '{cycles:p,instructions:p}' -c 20003 --no-time
> > ~/tchain ~/tchain [perf record: Woken up 148 times to write data]
> > [perf record: Captured and wrote 36.922 MB perf.data (1206322
> > samples)]
> >
> > $ perf report -D | tail
> > SAMPLE events: 120243
> > MMAP2 events: 5
> > LOST_SAMPLES events: 24
> > FINISHED_ROUND events: 15
> > cycles:p stats:
> > TOTAL events: 59348
> > SAMPLE events: 59348
> > instructions:p stats:
> > TOTAL events: 60895
> > SAMPLE events: 60895
>
> The example doesn't show which of cycles:p or instructions:p got lost, isn't
> that possible? Guess not from the patch, but should, no? I.e. what is
> PERF_SAMPLE_ID for then?


Yes, it's possible to know the lost samples number for cycles:p or
instructions:p. But I didn't implement it in the summary of perf report -D.
I think a total lost_samples number is enough for user. What they really
care about should be the total samples drop rate.
(If they really want to know the number of which event got lost, they can
search LOST_SAMPLES in perf report -D. sample->id is dumped with lost
number.)

Thanks,
Kan

>
> - Arnaldo
>
> >
> > $ perf report --stdio --group
> > # To display the perf.data header info, please use
> > --header/--header-only options.
> > #
> > #
> > # Total Lost Samples: 24
> > #
> > # Samples: 120K of event 'anon group { cycles:p, instructions:p }'
> > # Event count (approx.): 24048600000
> > #
> > # Overhead Command Shared Object Symbol
> > # ................ ........... ................
> > ..................................
> > #
> > 99.74% 99.86% tchain_edit tchain_edit [.] f3
> > 0.09% 0.02% tchain_edit tchain_edit [.] f2
> > 0.04% 0.00% tchain_edit [kernel.vmlinux] [k] ixgbe_read_reg
> >
> > Eg 2, Recording the same thing multiple times can lead to high drop
> > rate, but it is not a useful configuration.
> >
> > $ perf record -e '{cycles:p,cycles:p}' -c 20003 --no-time ~/tchain
> > [perf record: Woken up 1 times to write data]
> > Warning:
> > Processed 600592 samples and lost 99.73% samples!
> > [perf record: Captured and wrote 0.121 MB perf.data (1629 samples)]
> >
> > Signed-off-by: Kan Liang <kan.liang@xxxxxxxxx>
> > ---
> > tools/perf/builtin-report.c | 1 +
> > tools/perf/util/event.c | 9 +++++++++
> > tools/perf/util/event.h | 17 +++++++++++++++++
> > tools/perf/util/machine.c | 10 ++++++++++
> > tools/perf/util/machine.h | 2 ++
> > tools/perf/util/session.c | 19 +++++++++++++++++++
> > tools/perf/util/tool.h | 1 +
> > 7 files changed, 59 insertions(+)
> >
> > diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
> > index 7c73ae5..485b7e9 100644
> > --- a/tools/perf/builtin-report.c
> > +++ b/tools/perf/builtin-report.c
> > @@ -318,6 +318,7 @@ static int perf_evlist__tty_browse_hists(struct
> > perf_evlist *evlist, {
> > struct perf_evsel *pos;
> >
> > + fprintf(stdout, "#\n# Total Lost Samples: %lu\n#\n",
> > +evlist->stats.total_lost_samples);
> > evlist__for_each(evlist, pos) {
> > struct hists *hists = evsel__hists(pos);
> > const char *evname = perf_evsel__name(pos); diff --git
> > a/tools/perf/util/event.c b/tools/perf/util/event.c index
> > db52609..2daadc8 100644
> > --- a/tools/perf/util/event.c
> > +++ b/tools/perf/util/event.c
> > @@ -25,6 +25,7 @@ static const char *perf_event__names[] = {
> > [PERF_RECORD_SAMPLE] = "SAMPLE",
> > [PERF_RECORD_AUX] = "AUX",
> > [PERF_RECORD_ITRACE_START] = "ITRACE_START",
> > + [PERF_RECORD_LOST_SAMPLES] = "LOST_SAMPLES",
> > [PERF_RECORD_HEADER_ATTR] = "ATTR",
> > [PERF_RECORD_HEADER_EVENT_TYPE] =
> "EVENT_TYPE",
> > [PERF_RECORD_HEADER_TRACING_DATA] = "TRACING_DATA",
> > @@ -713,6 +714,14 @@ int perf_event__process_itrace_start(struct
> perf_tool *tool __maybe_unused,
> > return machine__process_itrace_start_event(machine, event); }
> >
> > +int perf_event__process_lost_samples(struct perf_tool *tool
> __maybe_unused,
> > + union perf_event *event,
> > + struct perf_sample *sample,
> > + struct machine *machine)
> > +{
> > + return machine__process_lost_samples_event(machine, event,
> sample);
> > +}
> > +
> > size_t perf_event__fprintf_mmap(union perf_event *event, FILE *fp) {
> > return fprintf(fp, " %d/%d: [%#" PRIx64 "(%#" PRIx64 ") @ %#"
> PRIx64
> > "]: %c %s\n", diff --git a/tools/perf/util/event.h
> > b/tools/perf/util/event.h index 7eecd5e..e02996a 100644
> > --- a/tools/perf/util/event.h
> > +++ b/tools/perf/util/event.h
> > @@ -52,6 +52,11 @@ struct lost_event {
> > u64 lost;
> > };
> >
> > +struct lost_samples_event {
> > + struct perf_event_header header;
> > + u64 lost;
> > +};
> > +
> > /*
> > * PERF_FORMAT_ENABLED | PERF_FORMAT_RUNNING |
> PERF_FORMAT_ID
> > */
> > @@ -235,6 +240,12 @@ enum auxtrace_error_type {
> > * total_lost tells exactly how many events the kernel in fact lost, i.e. it is
> > * the sum of all struct lost_event.lost fields reported.
> > *
> > + * The kernel discards mixed up samples and sends the number in a
> > + * PERF_RECORD_LOST_SAMPLES event. The number of lost-samples
> events
> > + is stored
> > + * in .nr_events[PERF_RECORD_LOST_SAMPLES] while
> total_lost_samples
> > + tells
> > + * exactly how many samples the kernel in fact dropped, i.e. it is
> > + the sum of
> > + * all struct lost_samples_event.lost fields reported.
> > + *
> > * The total_period is needed because by default auto-freq is used, so
> > * multipling nr_events[PERF_EVENT_SAMPLE] by a frequency isn't
> possible to get
> > * the total number of low level events, it is necessary to to sum
> > all struct @@ -244,6 +255,7 @@ struct events_stats {
> > u64 total_period;
> > u64 total_non_filtered_period;
> > u64 total_lost;
> > + u64 total_lost_samples;
> > u64 total_invalid_chains;
> > u32 nr_events[PERF_RECORD_HEADER_MAX];
> > u32 nr_non_filtered_samples;
> > @@ -342,6 +354,7 @@ union perf_event {
> > struct comm_event comm;
> > struct fork_event fork;
> > struct lost_event lost;
> > + struct lost_samples_event lost_samples;
> > struct read_event read;
> > struct throttle_event throttle;
> > struct sample_event sample;
> > @@ -390,6 +403,10 @@ int perf_event__process_lost(struct perf_tool
> *tool,
> > union perf_event *event,
> > struct perf_sample *sample,
> > struct machine *machine);
> > +int perf_event__process_lost_samples(struct perf_tool *tool,
> > + union perf_event *event,
> > + struct perf_sample *sample,
> > + struct machine *machine);
> > int perf_event__process_aux(struct perf_tool *tool,
> > union perf_event *event,
> > struct perf_sample *sample,
> > diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
> > index 2f47110..991a342 100644
> > --- a/tools/perf/util/machine.c
> > +++ b/tools/perf/util/machine.c
> > @@ -458,6 +458,14 @@ int machine__process_lost_event(struct
> machine *machine __maybe_unused,
> > return 0;
> > }
> >
> > +int machine__process_lost_samples_event(struct machine *machine
> __maybe_unused,
> > + union perf_event *event, struct
> perf_sample *sample) {
> > + dump_printf(": id:%" PRIu64 ": lost samples :%" PRIu64 "\n",
> > + sample->id, event->lost_samples.lost);
> > + return 0;
> > +}
> > +
> > static struct dso*
> > machine__module_dso(struct machine *machine, struct kmod_path *m,
> > const char *filename)
> > @@ -1351,6 +1359,8 @@ int machine__process_event(struct machine
> *machine, union perf_event *event,
> > ret = machine__process_aux_event(machine, event);
> break;
> > case PERF_RECORD_ITRACE_START:
> > ret = machine__process_itrace_start_event(machine,
> event);
> > + case PERF_RECORD_LOST_SAMPLES:
> > + ret = machine__process_lost_samples_event(machine,
> event, sample);
> > +break;
> > break;
> > default:
> > ret = -1;
> > diff --git a/tools/perf/util/machine.h b/tools/perf/util/machine.h
> > index 1d99296..7ba5e8f 100644
> > --- a/tools/perf/util/machine.h
> > +++ b/tools/perf/util/machine.h
> > @@ -81,6 +81,8 @@ int machine__process_fork_event(struct machine
> *machine, union perf_event *event
> > struct perf_sample *sample);
> > int machine__process_lost_event(struct machine *machine, union
> perf_event *event,
> > struct perf_sample *sample);
> > +int machine__process_lost_samples_event(struct machine *machine,
> union perf_event *event,
> > + struct perf_sample *sample);
> > int machine__process_aux_event(struct machine *machine,
> > union perf_event *event);
> > int machine__process_itrace_start_event(struct machine *machine, diff
> > --git a/tools/perf/util/session.c b/tools/perf/util/session.c index
> > e722107..4a5a609 100644
> > --- a/tools/perf/util/session.c
> > +++ b/tools/perf/util/session.c
> > @@ -325,6 +325,8 @@ void perf_tool__fill_defaults(struct perf_tool
> *tool)
> > tool->exit = process_event_stub;
> > if (tool->lost == NULL)
> > tool->lost = perf_event__process_lost;
> > + if (tool->lost_samples == NULL)
> > + tool->lost_samples = perf_event__process_lost_samples;
> > if (tool->aux == NULL)
> > tool->aux = perf_event__process_aux;
> > if (tool->itrace_start == NULL)
> > @@ -606,6 +608,7 @@ static perf_event__swap_op
> perf_event__swap_ops[] = {
> > [PERF_RECORD_SAMPLE] =
> perf_event__all64_swap,
> > [PERF_RECORD_AUX] = perf_event__aux_swap,
> > [PERF_RECORD_ITRACE_START] =
> perf_event__itrace_start_swap,
> > + [PERF_RECORD_LOST_SAMPLES] =
> perf_event__all64_swap,
> > [PERF_RECORD_HEADER_ATTR] =
> perf_event__hdr_attr_swap,
> > [PERF_RECORD_HEADER_EVENT_TYPE] =
> perf_event__event_type_swap,
> > [PERF_RECORD_HEADER_TRACING_DATA] =
> perf_event__tracing_data_swap,
> > @@ -1049,6 +1052,10 @@ static int machines__deliver_event(struct
> machines *machines,
> > if (tool->lost == perf_event__process_lost)
> > evlist->stats.total_lost += event->lost.lost;
> > return tool->lost(tool, event, sample, machine);
> > + case PERF_RECORD_LOST_SAMPLES:
> > + if (tool->lost_samples ==
> perf_event__process_lost_samples)
> > + evlist->stats.total_lost_samples += event-
> >lost_samples.lost;
> > + return tool->lost_samples(tool, event, sample, machine);
> > case PERF_RECORD_READ:
> > return tool->read(tool, event, sample, evsel, machine);
> > case PERF_RECORD_THROTTLE:
> > @@ -1286,6 +1293,18 @@ static void
> perf_session__warn_about_errors(const struct perf_session *session)
> > stats->nr_events[PERF_RECORD_LOST]);
> > }
> >
> > + if (session->tool->lost_samples ==
> perf_event__process_lost_samples) {
> > + double drop_rate;
> > +
> > + drop_rate = (double)stats->total_lost_samples /
> > + (double) (stats-
> >nr_events[PERF_RECORD_SAMPLE] + stats->total_lost_samples);
> > + if (drop_rate > 0.05) {
> > + ui__warning("Processed %lu samples and
> lost %3.2f%% samples!\n\n",
> > + stats-
> >nr_events[PERF_RECORD_SAMPLE] + stats->total_lost_samples,
> > + drop_rate * 100.0);
> > + }
> > + }
> > +
> > if (stats->nr_unknown_events != 0) {
> > ui__warning("Found %u unknown events!\n\n"
> > "Is this an older tool processing a perf.data "
> > diff --git a/tools/perf/util/tool.h b/tools/perf/util/tool.h index
> > 7f282ad..c307dd4 100644
> > --- a/tools/perf/util/tool.h
> > +++ b/tools/perf/util/tool.h
> > @@ -43,6 +43,7 @@ struct perf_tool {
> > fork,
> > exit,
> > lost,
> > + lost_samples,
> > aux,
> > itrace_start,
> > throttle,
> > --
> > 1.8.3.1
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/