From 7b27509fc62686c53e9301560034e6b0b001174d Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Sat, 29 Oct 2011 12:15:04 -0200 Subject: 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 Cc: Frederic Weisbecker Cc: Mike Galbraith Cc: Paul Mackerras Cc: Peter Zijlstra Cc: Stephane Eranian Link: http://lkml.kernel.org/n/tip-47yyqbubmjzch2chezmb21m6@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-top.c | 37 +++++++++++++++++++--------- tools/perf/util/hist.h | 1 + tools/perf/util/session.c | 29 +++++++++++++++++----- tools/perf/util/top.h | 1 - tools/perf/util/ui/browser.c | 21 +++++++++++++--- tools/perf/util/ui/browser.h | 3 ++- tools/perf/util/ui/browsers/hists.c | 49 ++++++++++++++++++++++++++++++++----- 7 files changed, 112 insertions(+), 29 deletions(-) (limited to 'tools') diff --git a/tools/perf/builtin-top.c b/tools/perf/builtin-top.c index 31aa82c39e2a..8577bfeb087a 100644 --- 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 ff93ddc91c5c..c86c1d27bd1e 100644 --- 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 91c6442ef966..da354fe5e085 100644 --- 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 01d1057f3074..399650967958 100644 --- 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 d2051be04f12..556829124b02 100644 --- 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 fb1c59883e6a..84d761b730c1 100644 --- 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 b8733c0770cd..d0c94b459685 100644 --- 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: -- cgit v1.2.3