perf hists browser: Warn about lost events

Just like the old perf top --tui and the --stdio version.

But because we have the initial menu to choose which event to show in a
session with multiple events we can see how many chunks were lost in
each of the event types, clarifying which events are being affected the
most.

Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-47yyqbubmjzch2chezmb21m6@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>

diff --git a/tools/perf/builtin-top.c b/tools/perf/builtin-top.c
index 31aa82c..8577bfe 100644 (file)
--- a/tools/perf/builtin-top.c
+++ b/tools/perf/builtin-top.c
@@ -89,6 +89,7 @@ static bool                   vmlinux_warned;
 static bool                    inherit                         =  false;
 static int                     realtime_prio                   =      0;
 static bool                    group                           =  false;
+static bool                    sample_id_all_avail             =   true;
 static unsigned int            mmap_pages                      =    128;
 
 static bool                    dump_symtab                     =  false;
@@ -289,11 +290,13 @@ static void print_sym_table(void)
 
        printf("%-*.*s\n", win_width, win_width, graph_dotted_line);
 
-       if (top.total_lost_warned != top.session->hists.stats.total_lost) {
-               top.total_lost_warned = top.session->hists.stats.total_lost;
-               color_fprintf(stdout, PERF_COLOR_RED, "WARNING:");
-               printf(" LOST %" PRIu64 " events, Check IO/CPU overload\n",
-                      top.total_lost_warned);
+       if (top.sym_evsel->hists.stats.nr_lost_warned !=
+           top.sym_evsel->hists.stats.nr_events[PERF_RECORD_LOST]) {
+               top.sym_evsel->hists.stats.nr_lost_warned =
+                       top.sym_evsel->hists.stats.nr_events[PERF_RECORD_LOST];
+               color_fprintf(stdout, PERF_COLOR_RED,
+                             "WARNING: LOST %d chunks, Check IO/CPU overload",
+                             top.sym_evsel->hists.stats.nr_lost_warned);
                ++printed;
        }
 
@@ -671,6 +674,7 @@ static int symbol_filter(struct map *map __used, struct symbol *sym)
 }
 
 static void perf_event__process_sample(const union perf_event *event,
+                                      struct perf_evsel *evsel,
                                       struct perf_sample *sample,
                                       struct perf_session *session)
 {
@@ -770,12 +774,8 @@ static void perf_event__process_sample(const union perf_event *event,
        }
 
        if (al.sym == NULL || !al.sym->ignore) {
-               struct perf_evsel *evsel;
                struct hist_entry *he;
 
-               evsel = perf_evlist__id2evsel(top.evlist, sample->id);
-               assert(evsel != NULL);
-
                if ((sort__has_parent || symbol_conf.use_callchain) &&
                    sample->callchain) {
                        err = perf_session__resolve_callchain(session, al.thread,
@@ -807,6 +807,7 @@ static void perf_event__process_sample(const union perf_event *event,
 static void perf_session__mmap_read_idx(struct perf_session *self, int idx)
 {
        struct perf_sample sample;
+       struct perf_evsel *evsel;
        union perf_event *event;
        int ret;
 
@@ -817,10 +818,16 @@ static void perf_session__mmap_read_idx(struct perf_session *self, int idx)
                        continue;
                }
 
+               evsel = perf_evlist__id2evsel(self->evlist, sample.id);
+               assert(evsel != NULL);
+
                if (event->header.type == PERF_RECORD_SAMPLE)
-                       perf_event__process_sample(event, &sample, self);
-               else
+                       perf_event__process_sample(event, evsel, &sample, self);
+               else if (event->header.type < PERF_RECORD_MAX) {
+                       hists__inc_nr_events(&evsel->hists, event->header.type);
                        perf_event__process(event, &sample, self);
+               } else
+                       ++self->hists.stats.nr_unknown_events;
        }
 }
 
@@ -864,6 +871,8 @@ static void start_counters(struct perf_evlist *evlist)
                attr->mmap = 1;
                attr->comm = 1;
                attr->inherit = inherit;
+retry_sample_id:
+               attr->sample_id_all = sample_id_all_avail ? 1 : 0;
 try_again:
                if (perf_evsel__open(counter, top.evlist->cpus,
                                     top.evlist->threads, group,
@@ -873,6 +882,12 @@ try_again:
                        if (err == EPERM || err == EACCES) {
                                ui__error_paranoid();
                                goto out_err;
+                       } else if (err == EINVAL && sample_id_all_avail) {
+                               /*
+                                * Old kernel, no attr->sample_id_type_all field
+                                */
+                               sample_id_all_avail = false;
+                               goto retry_sample_id;
                        }
                        /*
                         * If it's cycles then fall back to hrtimer

diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
index ff93ddc..c86c1d2 100644 (file)
--- a/tools/perf/util/hist.h
+++ b/tools/perf/util/hist.h
@@ -28,6 +28,7 @@ struct events_stats {
        u64 total_lost;
        u64 total_invalid_chains;
        u32 nr_events[PERF_RECORD_HEADER_MAX];
+       u32 nr_lost_warned;
        u32 nr_unknown_events;
        u32 nr_invalid_chains;
        u32 nr_unknown_id;

diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index 91c6442..da354fe 100644 (file)
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -738,10 +738,27 @@ static int perf_session_deliver_event(struct perf_session *session,
 
        dump_event(session, event, file_offset, sample);
 
+       evsel = perf_evlist__id2evsel(session->evlist, sample->id);
+       if (evsel != NULL && event->header.type != PERF_RECORD_SAMPLE) {
+               /*
+                * XXX We're leaving PERF_RECORD_SAMPLE unnacounted here
+                * because the tools right now may apply filters, discarding
+                * some of the samples. For consistency, in the future we
+                * should have something like nr_filtered_samples and remove
+                * the sample->period from total_sample_period, etc, KISS for
+                * now tho.
+                *
+                * Also testing against NULL allows us to handle files without
+                * attr.sample_id_all and/or without PERF_SAMPLE_ID. In the
+                * future probably it'll be a good idea to restrict event
+                * processing via perf_session to files with both set.
+                */
+               hists__inc_nr_events(&evsel->hists, event->header.type);
+       }
+
        switch (event->header.type) {
        case PERF_RECORD_SAMPLE:
                dump_sample(session, event, sample);
-               evsel = perf_evlist__id2evsel(session->evlist, sample->id);
                if (evsel == NULL) {
                        ++session->hists.stats.nr_unknown_id;
                        return -1;
@@ -874,11 +891,11 @@ static void perf_session__warn_about_errors(const struct perf_session *session,
                                            const struct perf_event_ops *ops)
 {
        if (ops->lost == perf_event__process_lost &&
-           session->hists.stats.total_lost != 0) {
-               ui__warning("Processed %" PRIu64 " events and LOST %" PRIu64
-                           "!\n\nCheck IO/CPU overload!\n\n",
-                           session->hists.stats.total_period,
-                           session->hists.stats.total_lost);
+           session->hists.stats.nr_events[PERF_RECORD_LOST] != 0) {
+               ui__warning("Processed %d events and lost %d chunks!\n\n"
+                           "Check IO/CPU overload!\n\n",
+                           session->hists.stats.nr_events[0],
+                           session->hists.stats.nr_events[PERF_RECORD_LOST]);
        }
 
        if (session->hists.stats.nr_unknown_events != 0) {

diff --git a/tools/perf/util/top.h b/tools/perf/util/top.h
index 01d1057..3996509 100644 (file)
--- a/tools/perf/util/top.h
+++ b/tools/perf/util/top.h
@@ -19,7 +19,6 @@ struct perf_top {
        u64                kernel_samples, us_samples;
        u64                exact_samples;
        u64                guest_us_samples, guest_kernel_samples;
-       u64                total_lost_warned;
        int                print_entries, count_filter, delay_secs;
        int                freq;
        pid_t              target_pid, target_tid;

diff --git a/tools/perf/util/ui/browser.c b/tools/perf/util/ui/browser.c
index d2051be..5568291 100644 (file)
--- a/tools/perf/util/ui/browser.c
+++ b/tools/perf/util/ui/browser.c
@@ -176,16 +176,29 @@ void ui_browser__handle_resize(struct ui_browser *browser)
        ui_browser__refresh(browser);
 }
 
-int ui_browser__warning(struct ui_browser *browser, const char *format, ...)
+int ui_browser__warning(struct ui_browser *browser, int timeout,
+                       const char *format, ...)
 {
        va_list args;
-       int key;
+       char *text;
+       int key = 0, err;
 
        va_start(args, format);
-       while ((key = __ui__warning("Warning!", format, args)) == K_RESIZE)
-               ui_browser__handle_resize(browser);
+       err = vasprintf(&text, format, args);
        va_end(args);
 
+       if (err < 0) {
+               va_start(args, format);
+               ui_helpline__vpush(format, args);
+               va_end(args);
+       } else {
+               while ((key == ui__question_window("Warning!", text,
+                                                  "Press any key...",
+                                                  timeout)) == K_RESIZE)
+                       ui_browser__handle_resize(browser);
+               free(text);
+       }
+
        return key;
 }
 

diff --git a/tools/perf/util/ui/browser.h b/tools/perf/util/ui/browser.h
index fb1c598..84d761b 100644 (file)
--- a/tools/perf/util/ui/browser.h
+++ b/tools/perf/util/ui/browser.h
@@ -45,7 +45,8 @@ int ui_browser__run(struct ui_browser *browser, int delay_secs);
 void ui_browser__update_nr_entries(struct ui_browser *browser, u32 nr_entries);
 void ui_browser__handle_resize(struct ui_browser *browser);
 
-int ui_browser__warning(struct ui_browser *browser, const char *format, ...);
+int ui_browser__warning(struct ui_browser *browser, int timeout,
+                       const char *format, ...);
 int ui_browser__help_window(struct ui_browser *browser, const char *text);
 bool ui_browser__dialog_yesno(struct ui_browser *browser, const char *text);
 

diff --git a/tools/perf/util/ui/browsers/hists.c b/tools/perf/util/ui/browsers/hists.c
index b8733c0..d0c94b4 100644 (file)
--- a/tools/perf/util/ui/browsers/hists.c
+++ b/tools/perf/util/ui/browsers/hists.c
@@ -295,6 +295,15 @@ static void hist_browser__set_folding(struct hist_browser *self, bool unfold)
        ui_browser__reset_index(&self->b);
 }
 
+static void ui_browser__warn_lost_events(struct ui_browser *browser)
+{
+       ui_browser__warning(browser, 4,
+               "Events are being lost, check IO/CPU overload!\n\n"
+               "You may want to run 'perf' using a RT scheduler policy:\n\n"
+               " perf top -r 80\n\n"
+               "Or reduce the sampling frequency.");
+}
+
 static int hist_browser__run(struct hist_browser *self, const char *ev_name,
                             void(*timer)(void *arg), void *arg, int delay_secs)
 {
@@ -318,8 +327,15 @@ static int hist_browser__run(struct hist_browser *self, const char *ev_name,
                case K_TIMER:
                        timer(arg);
                        ui_browser__update_nr_entries(&self->b, self->hists->nr_entries);
-                       hists__browser_title(self->hists, title, sizeof(title),
-                                            ev_name);
+
+                       if (self->hists->stats.nr_lost_warned !=
+                           self->hists->stats.nr_events[PERF_RECORD_LOST]) {
+                               self->hists->stats.nr_lost_warned =
+                                       self->hists->stats.nr_events[PERF_RECORD_LOST];
+                               ui_browser__warn_lost_events(&self->b);
+                       }
+
+                       hists__browser_title(self->hists, title, sizeof(title), ev_name);
                        ui_browser__show_title(&self->b, title);
                        continue;
                case 'D': { /* Debug */
@@ -883,7 +899,7 @@ static int perf_evsel__hists_browse(struct perf_evsel *evsel, int nr_events,
                        goto out_free_stack;
                case 'a':
                        if (!browser->has_symbols) {
-                               ui_browser__warning(&browser->b,
+                               ui_browser__warning(&browser->b, delay_secs * 2,
                        "Annotation is only available for symbolic views, "
                        "include \"sym\" in --sort to use it.");
                                continue;
@@ -1061,6 +1077,7 @@ out:
 struct perf_evsel_menu {
        struct ui_browser b;
        struct perf_evsel *selection;
+       bool lost_events, lost_events_warned;
 };
 
 static void perf_evsel_menu__write(struct ui_browser *browser,
@@ -1073,14 +1090,29 @@ static void perf_evsel_menu__write(struct ui_browser *browser,
        unsigned long nr_events = evsel->hists.stats.nr_events[PERF_RECORD_SAMPLE];
        const char *ev_name = event_name(evsel);
        char bf[256], unit;
+       const char *warn = " ";
+       size_t printed;
 
        ui_browser__set_color(browser, current_entry ? HE_COLORSET_SELECTED :
                                                       HE_COLORSET_NORMAL);
 
        nr_events = convert_unit(nr_events, &unit);
-       snprintf(bf, sizeof(bf), "%lu%c%s%s", nr_events,
-                unit, unit == ' ' ? "" : " ", ev_name);
-       slsmg_write_nstring(bf, browser->width);
+       printed = snprintf(bf, sizeof(bf), "%lu%c%s%s", nr_events,
+                          unit, unit == ' ' ? "" : " ", ev_name);
+       slsmg_printf("%s", bf);
+
+       nr_events = evsel->hists.stats.nr_events[PERF_RECORD_LOST];
+       if (nr_events != 0) {
+               menu->lost_events = true;
+               if (!current_entry)
+                       ui_browser__set_color(browser, HE_COLORSET_TOP);
+               nr_events = convert_unit(nr_events, &unit);
+               snprintf(bf, sizeof(bf), ": %ld%c%schunks LOST!", nr_events,
+                        unit, unit == ' ' ? "" : " ");
+               warn = bf;
+       }
+
+       slsmg_write_nstring(warn, browser->width - printed);
 
        if (current_entry)
                menu->selection = evsel;
@@ -1105,6 +1137,11 @@ static int perf_evsel_menu__run(struct perf_evsel_menu *menu,
                switch (key) {
                case K_TIMER:
                        timer(arg);
+
+                       if (!menu->lost_events_warned && menu->lost_events) {
+                               ui_browser__warn_lost_events(&menu->b);
+                               menu->lost_events_warned = true;
+                       }
                        continue;
                case K_RIGHT:
                case K_ENTER: