From patchwork Wed Nov 7 16:14:32 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Yordan Karadzhov X-Patchwork-Id: 10759677 Return-Path: Received: from mail-bl2nam02on0062.outbound.protection.outlook.com ([104.47.38.62]:11903 "EHLO NAM02-BL2-obe.outbound.protection.outlook.com" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1727630AbeKHBpi (ORCPT ); Wed, 7 Nov 2018 20:45:38 -0500 From: Yordan Karadzhov To: "rostedt@goodmis.org" CC: "linux-trace-devel@vger.kernel.org" Subject: [PATCH 1/8] kernel-shark-qt: Reset the second pass hash when reloading Sched plugin Date: Wed, 7 Nov 2018 16:14:32 +0000 Message-ID: <20181107161410.22507-2-ykaradzhov@vmware.com> References: <20181107161410.22507-1-ykaradzhov@vmware.com> In-Reply-To: <20181107161410.22507-1-ykaradzhov@vmware.com> Content-Language: en-US MIME-Version: 1.0 Sender: linux-trace-devel-owner@vger.kernel.org List-ID: Content-Length: 3139 When the plugin is reloaded, the trace data gets reloaded as well. Hence the second pass over the data has to be repeated. Signed-off-by: Yordan Karadzhov --- kernel-shark-qt/src/plugins/SchedEvents.cpp | 15 ++++++--------- kernel-shark-qt/src/plugins/sched_events.c | 4 ++++ kernel-shark-qt/src/plugins/sched_events.h | 3 +++ 3 files changed, 13 insertions(+), 9 deletions(-) diff --git a/kernel-shark-qt/src/plugins/SchedEvents.cpp b/kernel-shark-qt/src/plugins/SchedEvents.cpp index 7f75baa..5f833df 100644 --- a/kernel-shark-qt/src/plugins/SchedEvents.cpp +++ b/kernel-shark-qt/src/plugins/SchedEvents.cpp @@ -193,8 +193,6 @@ static void pluginDraw(plugin_sched_context *plugin_ctx, return; } -static std::unordered_set secondPassDone; - /* * Ideally, the sched_switch has to be the last trace event recorded before the * task is preempted. Because of this, when the data is loaded (the first pass), @@ -250,8 +248,6 @@ static void secondPass(kshark_entry **data, } } } - - secondPassDone.insert(pid); } /** @@ -298,12 +294,13 @@ void plugin_draw(kshark_cpp_argv *argv_c, int pid, int draw_action) KS_TASK_COLLECTION_MARGIN); } - try { - if (secondPassDone.find(pid) == secondPassDone.end()) { - /* The second pass for this task is not done yet. */ - secondPass(argvCpp->_histo->data, col, pid); - } + if (!tracecmd_filter_id_find(plugin_ctx->second_pass_hash, pid)) { + /* The second pass for this task is not done yet. */ + secondPass(argvCpp->_histo->data, col, pid); + tracecmd_filter_id_add(plugin_ctx->second_pass_hash, pid); + } + try { pluginDraw(plugin_ctx, kshark_ctx, argvCpp->_histo, col, SchedEvent::Switch, pid, diff --git a/kernel-shark-qt/src/plugins/sched_events.c b/kernel-shark-qt/src/plugins/sched_events.c index 80ac214..f23c916 100644 --- a/kernel-shark-qt/src/plugins/sched_events.c +++ b/kernel-shark-qt/src/plugins/sched_events.c @@ -79,6 +79,8 @@ static bool plugin_sched_init_context(struct kshark_context *kshark_ctx) plugin_ctx->sched_wakeup_new_success_field = tep_find_field(event, "success"); + plugin_ctx->second_pass_hash = tracecmd_filter_id_hash_alloc(); + return true; } @@ -279,6 +281,8 @@ static int plugin_sched_close(struct kshark_context *kshark_ctx) plugin_sched_action, plugin_draw); + tracecmd_filter_id_hash_free(plugin_ctx->second_pass_hash); + free(plugin_ctx); plugin_sched_context_handler = NULL; diff --git a/kernel-shark-qt/src/plugins/sched_events.h b/kernel-shark-qt/src/plugins/sched_events.h index 5a9406b..481413f 100644 --- a/kernel-shark-qt/src/plugins/sched_events.h +++ b/kernel-shark-qt/src/plugins/sched_events.h @@ -55,6 +55,9 @@ struct plugin_sched_context { * Pointer to the sched_wakeup_new_success_field format descriptor. */ struct tep_format_field *sched_wakeup_new_success_field; + + /** Hash of the tasks for which the second pass is already done. */ + struct tracecmd_filter_id *second_pass_hash; }; int plugin_get_next_pid(struct tep_record *record); From patchwork Wed Nov 7 16:14:34 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Yordan Karadzhov X-Patchwork-Id: 10759679 Return-Path: Received: from mail-bl2nam02on0062.outbound.protection.outlook.com ([104.47.38.62]:11903 "EHLO NAM02-BL2-obe.outbound.protection.outlook.com" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1727561AbeKHBpk (ORCPT ); Wed, 7 Nov 2018 20:45:40 -0500 From: Yordan Karadzhov To: "rostedt@goodmis.org" CC: "linux-trace-devel@vger.kernel.org" Subject: [PATCH 2/8] kernel-shark-qt: Improve the plotting logic of the Sched event plugin Date: Wed, 7 Nov 2018 16:14:34 +0000 Message-ID: <20181107161410.22507-3-ykaradzhov@vmware.com> References: <20181107161410.22507-1-ykaradzhov@vmware.com> In-Reply-To: <20181107161410.22507-1-ykaradzhov@vmware.com> Content-Language: en-US MIME-Version: 1.0 Sender: linux-trace-devel-owner@vger.kernel.org List-ID: Content-Length: 12446 This patch aims to make the plotting logic of the Sched event plugin more robust and easy to understand. It also provides a proper processing of the case when we have multiple Sched events in one bin. Signed-off-by: Yordan Karadzhov --- kernel-shark-qt/src/plugins/SchedEvents.cpp | 154 +++++++++----------- kernel-shark-qt/src/plugins/sched_events.c | 50 +++++-- kernel-shark-qt/src/plugins/sched_events.h | 12 +- 3 files changed, 116 insertions(+), 100 deletions(-) diff --git a/kernel-shark-qt/src/plugins/SchedEvents.cpp b/kernel-shark-qt/src/plugins/SchedEvents.cpp index 5f833df..1e872aa 100644 --- a/kernel-shark-qt/src/plugins/SchedEvents.cpp +++ b/kernel-shark-qt/src/plugins/SchedEvents.cpp @@ -54,9 +54,11 @@ static void pluginDraw(plugin_sched_context *plugin_ctx, KsPlot::Graph *graph, KsPlot::PlotObjList *shapes) { + const kshark_entry *entryClose, *entryOpen; std::function ifSchedBack; KsPlot::Rectangle *rec = nullptr; int height = graph->getHeight() * .3; + ssize_t indexClose(0), indexOpen(0); auto openBox = [&] (const KsPlot::Point &p) { @@ -67,7 +69,13 @@ static void pluginDraw(plugin_sched_context *plugin_ctx, if (!rec) rec = new KsPlot::Rectangle; + if (e == SchedEvent::Switch) + rec->_color = KsPlot::Color(255, 0, 0); + else + rec->_color = KsPlot::Color(0, 255, 0); + rec->setFill(false); + rec->setPoint(0, p.x() - 1, p.y() - height); rec->setPoint(1, p.x() - 1, p.y() - 1); }; @@ -77,7 +85,7 @@ static void pluginDraw(plugin_sched_context *plugin_ctx, if (rec == nullptr) return; - int boxSize = rec->getPoint(0)->x; + int boxSize = p.x() - rec->getPoint(0)->x; if (boxSize < PLUGIN_MIN_BOX_SIZE) { /* This box is too small. Don't try to plot it. */ delete rec; @@ -92,99 +100,78 @@ static void pluginDraw(plugin_sched_context *plugin_ctx, rec = nullptr; }; - auto lamIfSchSwitchFront = [&] (int bin) - { - /* - * Starting from the first element in this bin, go forward - * in time until you find a trace entry that satisfies the - * condition defined by kshark_match_pid. + for (int bin = 0; bin < graph->size(); ++bin) { + /** + * Plotting the latencies makes sense only in the case of a + * deep zoom. Here we set a naive threshold based on the number + * of entries inside the current bin. This cut seems to work + * well in all cases I tested so far, but it may result in + * unexpected behavior with some unusual trace data-sets. + * TODO: find a better criteria for deciding when to start + * plotting latencies. */ - const kshark_entry *entryF = - ksmodel_get_entry_front(histo, bin, false, - kshark_match_pid, pid, - col, nullptr); - - if (entryF && - entryF->pid == pid && - plugin_ctx->sched_switch_event && - entryF->event_id == plugin_ctx->sched_switch_event->id) { - /* - * entryF is sched_switch_event. Close the box and add - * it to the list of shapes to be ploted. - */ - closeBox(graph->getBin(bin)._base); + if (ksmodel_bin_count(histo, bin) > PLUGIN_MAX_ENTRIES_PER_BIN) { + if (rec) { + delete rec; + rec = nullptr; + } + + continue; } - }; - auto lamIfSchWakeupBack = [&] (int bin) - { /* - * Starting from the last element in this bin, go backward + * Starting from the first element in this bin, go forward * in time until you find a trace entry that satisfies the - * condition defined by plugin_wakeup_match_pid. + * condition defined by kshark_match_pid. */ - const kshark_entry *entryB = - ksmodel_get_entry_back(histo, bin, false, - plugin_wakeup_match_pid, pid, - col, nullptr); + entryClose = ksmodel_get_entry_back(histo, bin, false, + plugin_switch_match_entry_pid, + pid, col, &indexClose); - if (entryB) { + if (e == SchedEvent::Switch) { /* - * entryB is a sched_wakeup_event. Open a - * green box here. + * Starting from the last element in this bin, go backward + * in time until you find a trace entry that satisfies the + * condition defined by plugin_switch_match_pid. */ - openBox(graph->getBin(bin)._base); - - /* Green */ - rec->_color = KsPlot::Color(0, 255, 0); - } - }; - - auto lamIfSchSwitchBack = [&] (int bin) - { - /* - * Starting from the last element in this bin, go backward - * in time until you find a trace entry that satisfies the - * condition defined by plugin_switch_match_pid. - */ - const kshark_entry *entryB = - ksmodel_get_entry_back(histo, bin, false, - plugin_switch_match_pid, pid, - col, nullptr); + entryOpen = + ksmodel_get_entry_back(histo, bin, false, + plugin_switch_match_rec_pid, + pid, col, &indexOpen); - if (entryB && entryB->pid != pid) { + } else { /* - * entryB is a sched_switch_event. Open a - * red box here. + * Starting from the last element in this bin, go backward + * in time until you find a trace entry that satisfies the + * condition defined by plugin_wakeup_match_pid. */ - openBox(graph->getBin(bin)._base); - - /* Red */ - rec->_color = KsPlot::Color(255, 0, 0); + entryOpen = + ksmodel_get_entry_back(histo, bin, false, + plugin_wakeup_match_rec_pid, + pid, col, &indexOpen); } - }; - - if (e == SchedEvent::Switch) - ifSchedBack = lamIfSchSwitchBack; - else - ifSchedBack = lamIfSchWakeupBack; - - for (int bin = 0; bin < graph->size(); ++bin) { - /** - * Plotting the latencies makes sense only in the case of a - * deep zoom. Here we set a naive threshold based on the number - * of entries inside the current bin. This cut seems to work - * well in all cases I tested so far, but it may result in - * unexpected behavior with some unusual trace data-sets. - * TODO: find a better criteria for deciding when to start - * plotting latencies. - */ - if (ksmodel_bin_count(histo, bin) > PLUGIN_MAX_ENTRIES_PER_BIN) - continue; - - lamIfSchSwitchFront(bin); - ifSchedBack(bin); + if (rec) { + if (entryClose) { + /* Close the box in this bin. */ + closeBox(graph->getBin(bin)._base); + if (entryOpen && indexClose < indexOpen) { + /* + * We have a Sched switch entry that + * comes after (in time) the closure of + * the previous box. We have to open a + * new box in this bin. + */ + openBox(graph->getBin(bin)._base); + } + } + } else { + if (entryOpen && + (!entryClose || indexClose < indexOpen)) { + /* Open a new box in this bin. */ + openBox(graph->getBin(bin)._base); + } + } } if (rec) @@ -221,7 +208,8 @@ static void secondPass(kshark_entry **data, kshark_entry_request *req = kshark_entry_request_alloc(first, n, - plugin_switch_match_pid, pid, + plugin_switch_match_rec_pid, + pid, false, KS_GRAPH_VIEW_FILTER_MASK); @@ -303,12 +291,12 @@ void plugin_draw(kshark_cpp_argv *argv_c, int pid, int draw_action) try { pluginDraw(plugin_ctx, kshark_ctx, argvCpp->_histo, col, - SchedEvent::Switch, pid, + SchedEvent::Wakeup, pid, argvCpp->_graph, argvCpp->_shapes); pluginDraw(plugin_ctx, kshark_ctx, argvCpp->_histo, col, - SchedEvent::Wakeup, pid, + SchedEvent::Switch, pid, argvCpp->_graph, argvCpp->_shapes); } catch (const std::exception &exc) { std::cerr << "Exception in SchedEvents\n" << exc.what(); diff --git a/kernel-shark-qt/src/plugins/sched_events.c b/kernel-shark-qt/src/plugins/sched_events.c index f23c916..6045341 100644 --- a/kernel-shark-qt/src/plugins/sched_events.c +++ b/kernel-shark-qt/src/plugins/sched_events.c @@ -105,7 +105,7 @@ int plugin_get_next_pid(struct tep_record *record) * * @param record: Input location for a sched_wakeup record. */ -int plugin_get_wakeup_pid(struct tep_record *record) +int plugin_get_rec_wakeup_pid(struct tep_record *record) { struct plugin_sched_context *plugin_ctx = plugin_sched_context_handler; @@ -137,7 +137,7 @@ static void plugin_register_command(struct kshark_context *kshark_ctx, tep_register_comm(kshark_ctx->pevent, comm, pid); } -static int plugin_get_wakeup_new_pid(struct tep_record *record) +static int plugin_get_rec_wakeup_new_pid(struct tep_record *record) { struct plugin_sched_context *plugin_ctx = plugin_sched_context_handler; @@ -157,12 +157,12 @@ static int plugin_get_wakeup_new_pid(struct tep_record *record) * @param e: kshark_entry to be checked. * @param pid: Matching condition value. * - * @returns True if the Pid of the entry matches the value of "pid". + * @returns True if the Pid of the record matches the value of "pid". * Otherwise false. */ -bool plugin_wakeup_match_pid(struct kshark_context *kshark_ctx, - struct kshark_entry *e, - int pid) +bool plugin_wakeup_match_rec_pid(struct kshark_context *kshark_ctx, + struct kshark_entry *e, + int pid) { struct plugin_sched_context *plugin_ctx; struct tep_record *record = NULL; @@ -182,7 +182,7 @@ bool plugin_wakeup_match_pid(struct kshark_context *kshark_ctx, record->data, &val); if (val) - wakeup_pid = plugin_get_wakeup_pid(record); + wakeup_pid = plugin_get_rec_wakeup_pid(record); } if (plugin_ctx->sched_wakeup_new_event && @@ -194,7 +194,7 @@ bool plugin_wakeup_match_pid(struct kshark_context *kshark_ctx, record->data, &val); if (val) - wakeup_pid = plugin_get_wakeup_new_pid(record); + wakeup_pid = plugin_get_rec_wakeup_new_pid(record); } free_record(record); @@ -212,12 +212,12 @@ bool plugin_wakeup_match_pid(struct kshark_context *kshark_ctx, * @param e: kshark_entry to be checked. * @param pid: Matching condition value. * - * @returns True if the Pid of the entry matches the value of "pid". + * @returns True if the Pid of the record matches the value of "pid". * Otherwise false. */ -bool plugin_switch_match_pid(struct kshark_context *kshark_ctx, - struct kshark_entry *e, - int pid) +bool plugin_switch_match_rec_pid(struct kshark_context *kshark_ctx, + struct kshark_entry *e, + int pid) { struct plugin_sched_context *plugin_ctx; int switch_pid = -1; @@ -239,6 +239,32 @@ bool plugin_switch_match_pid(struct kshark_context *kshark_ctx, return false; } +/** + * @brief Process Id matching function adapted for sched_switch events. + * + * @param kshark_ctx: Input location for the session context pointer. + * @param e: kshark_entry to be checked. + * @param pid: Matching condition value. + * + * @returns True if the Pid of the entry matches the value of "pid". + * Otherwise false. + */ +bool plugin_switch_match_entry_pid(struct kshark_context *kshark_ctx, + struct kshark_entry *e, + int pid) +{ + struct plugin_sched_context *plugin_ctx; + + plugin_ctx = plugin_sched_context_handler; + + if (plugin_ctx->sched_switch_event && + e->event_id == plugin_ctx->sched_switch_event->id && + e->pid == pid) + return true; + + return false; +} + static void plugin_sched_action(struct kshark_context *kshark_ctx, struct tep_record *rec, struct kshark_entry *entry) diff --git a/kernel-shark-qt/src/plugins/sched_events.h b/kernel-shark-qt/src/plugins/sched_events.h index 481413f..2036d5d 100644 --- a/kernel-shark-qt/src/plugins/sched_events.h +++ b/kernel-shark-qt/src/plugins/sched_events.h @@ -62,13 +62,15 @@ struct plugin_sched_context { int plugin_get_next_pid(struct tep_record *record); -int plugin_get_wakeup_pid(struct tep_record *record); +bool plugin_wakeup_match_rec_pid(struct kshark_context *kshark_ctx, + struct kshark_entry *e, int pid); -bool plugin_wakeup_match_pid(struct kshark_context *kshark_ctx, - struct kshark_entry *e, int pid); +bool plugin_switch_match_rec_pid(struct kshark_context *kshark_ctx, + struct kshark_entry *e, int pid); -bool plugin_switch_match_pid(struct kshark_context *kshark_ctx, - struct kshark_entry *e, int pid); +bool plugin_switch_match_entry_pid(struct kshark_context *kshark_ctx, + struct kshark_entry *e, + int pid); void plugin_draw(struct kshark_cpp_argv *argv, int pid, int draw_action); From patchwork Wed Nov 7 16:14:35 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Yordan Karadzhov X-Patchwork-Id: 10759681 Return-Path: Received: from mail-bl2nam02on0062.outbound.protection.outlook.com ([104.47.38.62]:11903 "EHLO NAM02-BL2-obe.outbound.protection.outlook.com" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1727630AbeKHBpl (ORCPT ); Wed, 7 Nov 2018 20:45:41 -0500 From: Yordan Karadzhov To: "rostedt@goodmis.org" CC: "linux-trace-devel@vger.kernel.org" Subject: [PATCH 3/8] kernel-shark-qt: Update the visualization model before plotting new graphs Date: Wed, 7 Nov 2018 16:14:35 +0000 Message-ID: <20181107161410.22507-4-ykaradzhov@vmware.com> References: <20181107161410.22507-1-ykaradzhov@vmware.com> In-Reply-To: <20181107161410.22507-1-ykaradzhov@vmware.com> Content-Language: en-US MIME-Version: 1.0 Sender: linux-trace-devel-owner@vger.kernel.org List-ID: Updating the model before creating new graphs guaranties that all previously plotted graphs are wiped out. Signed-off-by: Yordan Karadzhov --- kernel-shark-qt/src/KsGLWidget.cpp | 2 ++ 1 file changed, 2 insertions(+) diff --git a/kernel-shark-qt/src/KsGLWidget.cpp b/kernel-shark-qt/src/KsGLWidget.cpp index 2a0b16b..92b9224 100644 --- a/kernel-shark-qt/src/KsGLWidget.cpp +++ b/kernel-shark-qt/src/KsGLWidget.cpp @@ -484,6 +484,8 @@ void KsGLWidget::_makeGraphs(QVector cpuList, QVector taskList) _graphs.append(graph); }; + _model.update(); + /* Create CPU graphs according to the cpuList. */ for (auto const &cpu: cpuList) lamAddGraph(_newCPUGraph(cpu)); From patchwork Wed Nov 7 16:14:36 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Yordan Karadzhov X-Patchwork-Id: 10759685 Return-Path: Received: from mail-bl2nam02on0062.outbound.protection.outlook.com ([104.47.38.62]:11903 "EHLO NAM02-BL2-obe.outbound.protection.outlook.com" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1730846AbeKHBpo (ORCPT ); Wed, 7 Nov 2018 20:45:44 -0500 From: Yordan Karadzhov To: "rostedt@goodmis.org" CC: "linux-trace-devel@vger.kernel.org" Subject: [PATCH 4/8] kernel-shark-qt: Add "Missed events" custom kshark_entry Date: Wed, 7 Nov 2018 16:14:36 +0000 Message-ID: <20181107161410.22507-5-ykaradzhov@vmware.com> References: <20181107161410.22507-1-ykaradzhov@vmware.com> In-Reply-To: <20181107161410.22507-1-ykaradzhov@vmware.com> Content-Language: en-US MIME-Version: 1.0 Sender: linux-trace-devel-owner@vger.kernel.org List-ID: Content-Length: 9780 The ring buffer used during the acquisition of the tracing data can overflow. In such a case a fraction of the data is lost. This patch introduces a custom kshark_entry used to indicate that some data has been overwrite (lost). Instruments for insertion and processing of "Missed events" entries are added. Signed-off-by: Yordan Karadzhov --- kernel-shark-qt/src/libkshark.c | 196 ++++++++++++++++++++++++++------ kernel-shark-qt/src/libkshark.h | 16 +++ 2 files changed, 179 insertions(+), 33 deletions(-) diff --git a/kernel-shark-qt/src/libkshark.c b/kernel-shark-qt/src/libkshark.c index 64236a5..1a39968 100644 --- a/kernel-shark-qt/src/libkshark.c +++ b/kernel-shark-qt/src/libkshark.c @@ -16,7 +16,6 @@ #include #include #include -#include // KernelShark #include "libkshark.h" @@ -558,6 +557,52 @@ static void kshark_set_entry_values(struct kshark_context *kshark_ctx, entry->pid = tep_data_pid(kshark_ctx->pevent, record); } +/** Prior time offset of the "missed_events" entry. */ +#define ME_ENTRY_TIME_SHIFT 10 + +static void missed_events_action(struct kshark_context *kshark_ctx, + struct tep_record *record, + struct kshark_entry *entry) +{ + /* + * Use the offset field of the entry to store the number of missed + * events. + */ + entry->offset = record->missed_events; + + entry->cpu = record->cpu; + + /* + * Position the "missed_events" entry a bit before (in time) + * the original record. + */ + entry->ts = record->ts - ME_ENTRY_TIME_SHIFT; + + /* All custom entries must have negative event Identifiers. */ + entry->event_id = KS_EVENT_OVERFLOW; + + entry->visible = 0xFF; + + entry->pid = tep_data_pid(kshark_ctx->pevent, record); +} + +static const char* missed_events_dump(struct kshark_context *kshark_ctx, + const struct kshark_entry *entry, + bool get_info) +{ + int size = 0; + static char *buffer; + + if (get_info) + size = asprintf(&buffer, "missed_events=%i", (int) entry->offset); + else + size = asprintf(&buffer, "missed_events"); + if (size > 0) + return buffer; + + return NULL; +} + /** * rec_list is used to pass the data to the load functions. * The rec_list will contain the list of entries from the source, @@ -649,6 +694,21 @@ static size_t get_records(struct kshark_context *kshark_ctx, struct kshark_entry *entry; int ret; + if (rec->missed_events) { + /* + * Insert a custom "missed_events" entry just + * befor this record. + */ + entry = &temp_rec->entry; + missed_events_action(kshark_ctx, rec, entry); + + temp_next = &temp_rec->next; + ++count; + + /* Now allocate a new rec_list node and comtinue. */ + *temp_next = temp_rec = calloc(1, sizeof(*temp_rec)); + } + entry = &temp_rec->entry; kshark_set_entry_values(kshark_ctx, rec, entry); @@ -1006,6 +1066,9 @@ const char *kshark_get_latency_easy(struct kshark_entry *entry) if (!kshark_instance(&kshark_ctx)) return NULL; + if (entry->event_id < 0) + return NULL; + data = kshark_read_at(kshark_ctx, entry->offset); lat = kshark_get_latency(kshark_ctx->pevent, data); free_record(data); @@ -1048,7 +1111,7 @@ int kshark_get_event_id_easy(struct kshark_entry *entry) free_record(data); } - return event_id; + return (event_id == -1)? EFAULT : event_id; } /** @@ -1070,11 +1133,20 @@ const char *kshark_get_event_name_easy(struct kshark_entry *entry) struct tep_event_format *event; int event_id = kshark_get_event_id_easy(entry); - - if (event_id < 0) + if (event_id == EFAULT) return NULL; kshark_instance(&kshark_ctx); + + if (event_id < 0) { + switch (event_id) { + case KS_EVENT_OVERFLOW: + return missed_events_dump(kshark_ctx, entry, false); + default: + return NULL; + } + } + event = tep_data_event_from_type(kshark_ctx->pevent, event_id); if (event) return event->name; @@ -1105,6 +1177,15 @@ const char *kshark_get_info_easy(struct kshark_entry *entry) if (!kshark_instance(&kshark_ctx)) return NULL; + if (entry->event_id < 0) { + switch (entry->event_id) { + case KS_EVENT_OVERFLOW: + return missed_events_dump(kshark_ctx, entry, true); + default: + return NULL; + } + } + data = kshark_read_at(kshark_ctx, entry->offset); event_id = tep_data_type(kshark_ctx->pevent, data); @@ -1133,6 +1214,43 @@ void kshark_convert_nano(uint64_t time, uint64_t *sec, uint64_t *usec) *usec = (time - s * 1000000000ULL) / 1000; } +/** + * @brief Dump into a string the content a custom entry. The function allocates + * a null terminated string and returns a pointer to this string. + * + * @param kshark_ctx: Input location for the session context pointer. + * @param entry: A Kernel Shark entry to be printed. + * @param info_func: + * + * @returns The returned string contains a semicolon-separated list of data + * fields. The user has to free the returned string. + */ +char* kshark_dump_custom_entry(struct kshark_context *kshark_ctx, + const struct kshark_entry *entry, + kshark_custom_info_func info_func) +{ + const char *event_name, *task, *info; + char *entry_str; + int size = 0; + + task = tep_data_comm_from_pid(kshark_ctx->pevent, entry->pid); + event_name = info_func(kshark_ctx, entry, false); + info = info_func(kshark_ctx, entry, true); + + size = asprintf(&entry_str, "%li; %s-%i; CPU %i; ; %s; %s", + entry->ts, + task, + entry->pid, + entry->cpu, + event_name, + info); + + if (size > 0) + return entry_str; + + return NULL; +} + /** * @brief Dump into a string the content of one entry. The function allocates * a null terminated string and returns a pointer to this string. The @@ -1147,48 +1265,60 @@ char* kshark_dump_entry(const struct kshark_entry *entry) { const char *event_name, *task, *lat, *info; struct kshark_context *kshark_ctx; - struct tep_record *data; - struct tep_event_format *event; char *temp_str, *entry_str; - int event_id, size = 0; + int size = 0; kshark_ctx = NULL; if (!kshark_instance(&kshark_ctx) || !init_thread_seq()) return NULL; - data = kshark_read_at(kshark_ctx, entry->offset); + task = tep_data_comm_from_pid(kshark_ctx->pevent, entry->pid); - event_id = tep_data_type(kshark_ctx->pevent, data); - event = tep_data_event_from_type(kshark_ctx->pevent, event_id); + if (entry->event_id >= 0) { + struct tep_event_format *event; + struct tep_record *data; - event_name = event? event->name : "[UNKNOWN EVENT]"; - task = tep_data_comm_from_pid(kshark_ctx->pevent, entry->pid); - lat = kshark_get_latency(kshark_ctx->pevent, data); + data = kshark_read_at(kshark_ctx, entry->offset); - size = asprintf(&temp_str, "%li %s-%i; CPU %i; %s;", - entry->ts, - task, - entry->pid, - entry->cpu, - lat); + event = tep_data_event_from_type(kshark_ctx->pevent, + entry->event_id); - info = kshark_get_info(kshark_ctx->pevent, data, event); - if (size > 0) { - size = asprintf(&entry_str, "%s %s; %s; 0x%x", - temp_str, - event_name, - info, - entry->visible); + event_name = event? event->name : "[UNKNOWN EVENT]"; + lat = kshark_get_latency(kshark_ctx->pevent, data); - free(temp_str); - } + size = asprintf(&temp_str, "%li; %s-%i; CPU %i; %s;", + entry->ts, + task, + entry->pid, + entry->cpu, + lat); - free_record(data); + info = kshark_get_info(kshark_ctx->pevent, data, event); - if (size > 0) - return entry_str; + if (size > 0) { + size = asprintf(&entry_str, "%s %s; %s; 0x%x", + temp_str, + event_name, + info, + entry->visible); - return NULL; + free(temp_str); + } + + free_record(data); + if (size < 1) + entry_str = NULL; + } else { + switch (entry->event_id) { + case KS_EVENT_OVERFLOW: + entry_str = kshark_dump_custom_entry(kshark_ctx, entry, + missed_events_dump); + default: + entry_str = NULL; + } + } + + return entry_str; } /** @@ -1402,7 +1532,7 @@ get_entry(const struct kshark_entry_request *req, if (index) { if (e) - *index = (e->event_id >= 0)? i : KS_FILTERED_BIN; + *index = (e->cpu != KS_FILTERED_BIN)? i : KS_FILTERED_BIN; else *index = KS_EMPTY_BIN; } diff --git a/kernel-shark-qt/src/libkshark.h b/kernel-shark-qt/src/libkshark.h index 2b39c26..b94bdc3 100644 --- a/kernel-shark-qt/src/libkshark.h +++ b/kernel-shark-qt/src/libkshark.h @@ -15,6 +15,7 @@ // C #include #include +#include // Json-C #include @@ -164,6 +165,18 @@ void kshark_convert_nano(uint64_t time, uint64_t *sec, uint64_t *usec); char* kshark_dump_entry(const struct kshark_entry *entry); +/** + * Custom entry info function type. To be user for dumping info for custom + * KernelShark entryes. + */ +typedef const char *(kshark_custom_info_func)(struct kshark_context *, + const struct kshark_entry *, + bool); + +char* kshark_dump_custom_entry(struct kshark_context *kshark_ctx, + const struct kshark_entry *entry, + kshark_custom_info_func info_func); + struct tep_record *kshark_read_at(struct kshark_context *kshark_ctx, uint64_t offset); @@ -281,6 +294,9 @@ bool kshark_match_cpu(struct kshark_context *kshark_ctx, /** Filtered bin identifier. */ #define KS_FILTERED_BIN -2 +/** Overflow Event identifier. */ +#define KS_EVENT_OVERFLOW (-EOVERFLOW) + /** Matching condition function type. To be user for data requests */ typedef bool (matching_condition_func)(struct kshark_context*, struct kshark_entry*, From patchwork Wed Nov 7 16:14:37 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Yordan Karadzhov X-Patchwork-Id: 10759691 Return-Path: Received: from mail-bl2nam02on0062.outbound.protection.outlook.com ([104.47.38.62]:11903 "EHLO NAM02-BL2-obe.outbound.protection.outlook.com" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1727546AbeKHBq0 (ORCPT ); Wed, 7 Nov 2018 20:46:26 -0500 From: Yordan Karadzhov To: "rostedt@goodmis.org" CC: "linux-trace-devel@vger.kernel.org" Subject: [PATCH 5/8] kernel-shark-qt: Add instrumentation for "Missed events" to the model Date: Wed, 7 Nov 2018 16:14:37 +0000 Message-ID: <20181107161410.22507-6-ykaradzhov@vmware.com> References: <20181107161410.22507-1-ykaradzhov@vmware.com> In-Reply-To: <20181107161410.22507-1-ykaradzhov@vmware.com> Content-Language: en-US MIME-Version: 1.0 Sender: linux-trace-devel-owner@vger.kernel.org List-ID: Content-Length: 3609 This patch adds to the Visualization model instruments, used for finding and plotting "Missed events". Signed-off-by: Yordan Karadzhov --- kernel-shark-qt/src/libkshark-model.c | 60 +++++++++++++++++++++++++++ kernel-shark-qt/src/libkshark-model.h | 12 ++++++ 2 files changed, 72 insertions(+) diff --git a/kernel-shark-qt/src/libkshark-model.c b/kernel-shark-qt/src/libkshark-model.c index 7800090..ef6ad48 100644 --- a/kernel-shark-qt/src/libkshark-model.c +++ b/kernel-shark-qt/src/libkshark-model.c @@ -1222,3 +1222,63 @@ bool ksmodel_task_visible_event_exist(struct kshark_trace_histo *histo, return true; } + +static bool match_cpu_missed_events(struct kshark_context *kshark_ctx, + struct kshark_entry *e, int cpu) +{ + return e->event_id == -EOVERFLOW && e->cpu == cpu; +} + +static bool match_pid_missed_events(struct kshark_context *kshark_ctx, + struct kshark_entry *e, int pid) +{ + return e->event_id == -EOVERFLOW && e->pid == pid; +} + +/** + * @brief In a given CPU and bin, start from the front end of the bin and go towards + * the back end, searching for a Missed Events entry. + * + * @param histo: Input location for the model descriptor. + * @param bin: Bin id. + * @param cpu: CPU Id. + * @param col: Optional input location for Data collection. + * @param index: Optional output location for the index of the requested + * entry inside the array. + * + * @returns Pointer ot a kshark_entry, if an entry has been found. Else NULL. + */ +const struct kshark_entry * +ksmodel_get_cpu_missed_events(struct kshark_trace_histo *histo, + int bin, int cpu, + struct kshark_entry_collection *col, + ssize_t *index) +{ + return ksmodel_get_entry_front(histo, bin, true, + match_cpu_missed_events, cpu, + col, index); +} + +/** + * @brief In a given task and bin, start from the front end of the bin and go towards + * the back end, searching for a Missed Events entry. + * + * @param histo: Input location for the model descriptor. + * @param bin: Bin id. + * @param pid: Process Id of the task. + * @param col: Optional input location for Data collection. + * @param index: Optional output location for the index of the requested + * entry inside the array. + * + * @returns Pointer ot a kshark_entry, if an entry has been found. Else NULL. + */ +const struct kshark_entry * +ksmodel_get_task_missed_events(struct kshark_trace_histo *histo, + int bin, int pid, + struct kshark_entry_collection *col, + ssize_t *index) +{ + return ksmodel_get_entry_front(histo, bin, true, + match_pid_missed_events, pid, + col, index); +} diff --git a/kernel-shark-qt/src/libkshark-model.h b/kernel-shark-qt/src/libkshark-model.h index 1cf68da..db681cc 100644 --- a/kernel-shark-qt/src/libkshark-model.h +++ b/kernel-shark-qt/src/libkshark-model.h @@ -148,6 +148,18 @@ bool ksmodel_task_visible_event_exist(struct kshark_trace_histo *histo, struct kshark_entry_collection *col, ssize_t *index); +const struct kshark_entry * +ksmodel_get_cpu_missed_events(struct kshark_trace_histo *histo, + int bin, int cpu, + struct kshark_entry_collection *col, + ssize_t *index); + +const struct kshark_entry * +ksmodel_get_task_missed_events(struct kshark_trace_histo *histo, + int bin, int pid, + struct kshark_entry_collection *col, + ssize_t *index); + static inline double ksmodel_bin_time(struct kshark_trace_histo *histo, int bin) { From patchwork Wed Nov 7 16:14:38 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Yordan Karadzhov X-Patchwork-Id: 10759683 Return-Path: Received: from mail-eopbgr720066.outbound.protection.outlook.com ([40.107.72.66]:54754 "EHLO NAM05-CO1-obe.outbound.protection.outlook.com" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1727561AbeKHBpl (ORCPT ); Wed, 7 Nov 2018 20:45:41 -0500 From: Yordan Karadzhov To: "rostedt@goodmis.org" CC: "linux-trace-devel@vger.kernel.org" Subject: [PATCH 6/8] kernel-shark-qt: Add tot_count field to the model descriptor Date: Wed, 7 Nov 2018 16:14:38 +0000 Message-ID: <20181107161410.22507-7-ykaradzhov@vmware.com> References: <20181107161410.22507-1-ykaradzhov@vmware.com> In-Reply-To: <20181107161410.22507-1-ykaradzhov@vmware.com> Content-Language: en-US MIME-Version: 1.0 Sender: linux-trace-devel-owner@vger.kernel.org List-ID: Content-Length: 1946 The tot_count field of the Visualization model descriptor provides fast access to the total number of entries being currently visualized. Signed-off-by: Yordan Karadzhov --- kernel-shark-qt/src/libkshark-model.c | 7 +++++++ kernel-shark-qt/src/libkshark-model.h | 3 +++ 2 files changed, 10 insertions(+) diff --git a/kernel-shark-qt/src/libkshark-model.c b/kernel-shark-qt/src/libkshark-model.c index ef6ad48..461f88e 100644 --- a/kernel-shark-qt/src/libkshark-model.c +++ b/kernel-shark-qt/src/libkshark-model.c @@ -298,6 +298,7 @@ static void ksmodel_set_bin_counts(struct kshark_trace_histo *histo) { int i = 0, prev_not_empty; + histo->tot_count = 0; memset(&histo->bin_count[0], 0, (histo->n_bins) * sizeof(histo->bin_count[0])); /* @@ -329,6 +330,10 @@ static void ksmodel_set_bin_counts(struct kshark_trace_histo *histo) histo->bin_count[prev_not_empty] = histo->map[i] - histo->map[prev_not_empty]; + if (prev_not_empty != LOB(histo)) + histo->tot_count += + histo->bin_count[prev_not_empty]; + prev_not_empty = i; } } @@ -350,6 +355,8 @@ static void ksmodel_set_bin_counts(struct kshark_trace_histo *histo) histo->bin_count[prev_not_empty] = histo->map[UOB(histo)] - histo->map[prev_not_empty]; } + + histo->tot_count += histo->bin_count[prev_not_empty]; } /** diff --git a/kernel-shark-qt/src/libkshark-model.h b/kernel-shark-qt/src/libkshark-model.h index db681cc..95c30b6 100644 --- a/kernel-shark-qt/src/libkshark-model.h +++ b/kernel-shark-qt/src/libkshark-model.h @@ -51,6 +51,9 @@ struct kshark_trace_histo { /** Number of entries in each bin. */ size_t *bin_count; + /** Total number of entries in all bin except the overflow bins. */ + int tot_count; + /** * Lower edge of the time-window to be visualized. Only entries having * timestamp >= min will be visualized. From patchwork Wed Nov 7 16:14:39 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Yordan Karadzhov X-Patchwork-Id: 10759687 Return-Path: Received: from mail-bl2nam02on0067.outbound.protection.outlook.com ([104.47.38.67]:36896 "EHLO NAM02-BL2-obe.outbound.protection.outlook.com" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1727630AbeKHBqS (ORCPT ); Wed, 7 Nov 2018 20:46:18 -0500 From: Yordan Karadzhov To: "rostedt@goodmis.org" CC: "linux-trace-devel@vger.kernel.org" Subject: [PATCH 7/8] kernel-shark-qt: Add "Missed events" plugin for KernelShark Date: Wed, 7 Nov 2018 16:14:39 +0000 Message-ID: <20181107161410.22507-8-ykaradzhov@vmware.com> References: <20181107161410.22507-1-ykaradzhov@vmware.com> In-Reply-To: <20181107161410.22507-1-ykaradzhov@vmware.com> Content-Language: en-US MIME-Version: 1.0 Sender: linux-trace-devel-owner@vger.kernel.org List-ID: Content-Length: 7502 The "Missed events" plugin displays a special marker that indicates the position (in time) of the missed (overwritten) data. Signed-off-by: Yordan Karadzhov --- kernel-shark-qt/src/plugins/CMakeLists.txt | 6 +- kernel-shark-qt/src/plugins/MissedEvents.cpp | 149 +++++++++++++++++++ kernel-shark-qt/src/plugins/missed_events.c | 41 +++++ kernel-shark-qt/src/plugins/missed_events.h | 30 ++++ 4 files changed, 225 insertions(+), 1 deletion(-) create mode 100644 kernel-shark-qt/src/plugins/MissedEvents.cpp create mode 100644 kernel-shark-qt/src/plugins/missed_events.c create mode 100644 kernel-shark-qt/src/plugins/missed_events.h diff --git a/kernel-shark-qt/src/plugins/CMakeLists.txt b/kernel-shark-qt/src/plugins/CMakeLists.txt index 2d7251d..853214e 100644 --- a/kernel-shark-qt/src/plugins/CMakeLists.txt +++ b/kernel-shark-qt/src/plugins/CMakeLists.txt @@ -24,7 +24,11 @@ BUILD_PLUGIN(NAME sched_events list(APPEND PLUGIN_LIST "sched_events default") # This plugin will be loaded by default # list(APPEND PLUGIN_LIST "sched_events") # This plugin isn't loaded by default -install(TARGETS sched_events +BUILD_PLUGIN(NAME missed_events + SOURCE missed_events.c MissedEvents.cpp) +list(APPEND PLUGIN_LIST "missed_events default") # This plugin will be loaded by default + +install(TARGETS sched_events missed_events LIBRARY DESTINATION /usr/local/lib/kshark/) set(PLUGINS ${PLUGIN_LIST} PARENT_SCOPE) diff --git a/kernel-shark-qt/src/plugins/MissedEvents.cpp b/kernel-shark-qt/src/plugins/MissedEvents.cpp new file mode 100644 index 0000000..05dfcb5 --- /dev/null +++ b/kernel-shark-qt/src/plugins/MissedEvents.cpp @@ -0,0 +1,149 @@ +// SPDX-License-Identifier: LGPL-2.1 + +/* + * Copyright (C) 2018 VMware Inc, Yordan Karadzhov + */ + +/** + * @file MissedEvents.cpp + * @brief Plugin for visualization of events, missed due to overflow of the ring buffer. + */ + +// C++ +#include + +// KernelShark +#include "libkshark.h" +#include "plugins/missed_events.h" +#include "KsPlotTools.hpp" +#include "KsPlugins.hpp" + +using namespace KsPlot; + +/** + * This class represents the graphical element of the KernelShark marker for + * Missed events. + */ +class MissedEventsMark : public PlotObject { +public: + /** Create a default Missed events marker. */ + MissedEventsMark() : _base(0, 0), _height(0) + { + _color = {0, 0, 255}; + _size = 2; + } + + /** + * @brief Create and position a Missed events marker. + * + * @param p: Base point of the marker. + * @param h: vertical size (height) of the marker. + */ + MissedEventsMark(const Point &p, int h) + : _base(p.x(), p.y()), _height(h) + { + _color = {0, 0, 255}; + _size = 2; + } + + /** Set the Base point of the marker. */ + void setBase(const Point &p) {_base.set(p.x(), p.y());} + + /** Set the vertical size (height) point of the marker. */ + void setHeight(int h) {_height = h;} + +private: + /** Base point of the Mark's line. */ + Point _base; + + /** The vertical size (height) of the Mark. */ + int _height; + + void _draw(const Color &col, float size = 1.) const override; +}; + +void MissedEventsMark::_draw(const Color &col, float size) const +{ + Point p(_base.x(), _base.y() - _height); + drawLine(_base, p, col, size); + + Rectangle rec; + rec.setPoint(0, p.x(), p.y()); + rec.setPoint(1, p.x() - _height / 4, p.y()); + rec.setPoint(2, p.x() - _height / 4, p.y() + _height / 4); + rec.setPoint(3, p.x(), p.y() + _height / 4); + rec._color = col; + rec.draw(); +} + +//! @cond Doxygen_Suppress + +#define PLUGIN_MAX_ENTRIES 10000 + +#define KS_TASK_COLLECTION_MARGIN 25 + +//! @endcond + +static void pluginDraw(kshark_context *kshark_ctx, + KsCppArgV *argvCpp, + int val, int draw_action) +{ + int height = argvCpp->_graph->getHeight(); + const kshark_entry *entry(nullptr); + MissedEventsMark *mark; + ssize_t index; + + int nBins = argvCpp->_graph->size(); + for (int bin = 0; bin < nBins; ++bin) { + if (draw_action == KSHARK_PLUGIN_TASK_DRAW) + entry = ksmodel_get_task_missed_events(argvCpp->_histo, + bin, val, + nullptr, + &index); + if (draw_action == KSHARK_PLUGIN_CPU_DRAW) + entry = ksmodel_get_cpu_missed_events(argvCpp->_histo, + bin, val, + nullptr, + &index); + + if (entry) { + mark = new MissedEventsMark(argvCpp->_graph->getBin(bin)._base, + height); + + argvCpp->_shapes->push_front(mark); + } + } +} + +/** + * @brief Plugin's draw function. + * + * @param argv_c: A C pointer to be converted to KsCppArgV (C++ struct). + * @param val: Process or CPU Id value. + * @param draw_action: Draw action identifier. + */ +void draw_missed_events(kshark_cpp_argv *argv_c, + int val, int draw_action) +{ + kshark_context *kshark_ctx(NULL); + + if (!kshark_instance(&kshark_ctx)) + return; + + KsCppArgV *argvCpp = KS_ARGV_TO_CPP(argv_c); + + /* + * Plotting the "Missed events" makes sense only in the case of a deep + * zoom. Here we set a threshold based on the total number of entries + * being visualized by the model. + * Don't be afraid to play with different values for this threshold. + */ + if (argvCpp->_histo->tot_count > PLUGIN_MAX_ENTRIES) + return; + + try { + pluginDraw(kshark_ctx, argvCpp, val, draw_action); + } catch (const std::exception &exc) { + std::cerr << "Exception in MissedEvents\n" << exc.what(); + } +} diff --git a/kernel-shark-qt/src/plugins/missed_events.c b/kernel-shark-qt/src/plugins/missed_events.c new file mode 100644 index 0000000..cf652bf --- /dev/null +++ b/kernel-shark-qt/src/plugins/missed_events.c @@ -0,0 +1,41 @@ +// SPDX-License-Identifier: LGPL-2.1 + +/* + * Copyright (C) 2018 VMware Inc, Yordan Karadzhov + */ + +/** + * @file missed_events.c + * @brief Plugin for visualization of missed events due to overflow of the + * ring buffer. + */ + +// KernelShark +#include "plugins/missed_events.h" + +static void nop_action(struct kshark_context *kshark_ctx, + struct tep_record *record, + struct kshark_entry *entry) +{} + +/** Load this plugin. */ +int KSHARK_PLUGIN_INITIALIZER(struct kshark_context *kshark_ctx) +{ + kshark_register_event_handler(&kshark_ctx->event_handlers, + KS_EVENT_OVERFLOW, + nop_action, + draw_missed_events); + + return 1; +} + +/** Unload this plugin. */ +int KSHARK_PLUGIN_DEINITIALIZER(struct kshark_context *kshark_ctx) +{ + kshark_unregister_event_handler(&kshark_ctx->event_handlers, + KS_EVENT_OVERFLOW, + nop_action, + draw_missed_events); + + return 1; +} diff --git a/kernel-shark-qt/src/plugins/missed_events.h b/kernel-shark-qt/src/plugins/missed_events.h new file mode 100644 index 0000000..e05d79a --- /dev/null +++ b/kernel-shark-qt/src/plugins/missed_events.h @@ -0,0 +1,30 @@ +/* SPDX-License-Identifier: LGPL-2.1 */ + +/* + * Copyright (C) 2018 VMware Inc, Yordan Karadzhov + */ + +/** + * @file missed_events.h + * @brief Plugin for visualization of missed events due to overflow of the + * ring buffer. + */ + +#ifndef _KS_PLUGIN_M_EVTS_H +#define _KS_PLUGIN_M_EVTS_H + +// KernelShark +#include "libkshark.h" + +#ifdef __cplusplus +extern "C" { +#endif + +void draw_missed_events(struct kshark_cpp_argv *argv, + int pid, int draw_action); + +#ifdef __cplusplus +} +#endif + +#endif From patchwork Wed Nov 7 16:14:40 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Yordan Karadzhov X-Patchwork-Id: 10759689 Return-Path: Received: from mail-bl2nam02on0067.outbound.protection.outlook.com ([104.47.38.67]:36896 "EHLO NAM02-BL2-obe.outbound.protection.outlook.com" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1727977AbeKHBqU (ORCPT ); Wed, 7 Nov 2018 20:46:20 -0500 From: Yordan Karadzhov To: "rostedt@goodmis.org" CC: "linux-trace-devel@vger.kernel.org" Subject: [PATCH 8/8] kernel-shark-qt: Update Sched Events plugin Date: Wed, 7 Nov 2018 16:14:40 +0000 Message-ID: <20181107161410.22507-9-ykaradzhov@vmware.com> References: <20181107161410.22507-1-ykaradzhov@vmware.com> In-Reply-To: <20181107161410.22507-1-ykaradzhov@vmware.com> Content-Language: en-US MIME-Version: 1.0 Sender: linux-trace-devel-owner@vger.kernel.org List-ID: Content-Length: 3945 This patch updates the Sched Events plugin to use the recently introduced "Missed events" entries and tot_count field of the Visualization model descriptor in its plotting logic. Signed-off-by: Yordan Karadzhov --- kernel-shark-qt/src/plugins/SchedEvents.cpp | 46 +++++++++------------ 1 file changed, 20 insertions(+), 26 deletions(-) diff --git a/kernel-shark-qt/src/plugins/SchedEvents.cpp b/kernel-shark-qt/src/plugins/SchedEvents.cpp index 1e872aa..42737e9 100644 --- a/kernel-shark-qt/src/plugins/SchedEvents.cpp +++ b/kernel-shark-qt/src/plugins/SchedEvents.cpp @@ -28,7 +28,7 @@ #define PLUGIN_MIN_BOX_SIZE 4 -#define PLUGIN_MAX_ENTRIES_PER_BIN 500 +#define PLUGIN_MAX_ENTRIES 10000 #define KS_TASK_COLLECTION_MARGIN 25 @@ -54,11 +54,11 @@ static void pluginDraw(plugin_sched_context *plugin_ctx, KsPlot::Graph *graph, KsPlot::PlotObjList *shapes) { - const kshark_entry *entryClose, *entryOpen; + const kshark_entry *entryClose, *entryOpen, *entryME; + ssize_t indexClose(0), indexOpen(0), indexME(0); std::function ifSchedBack; KsPlot::Rectangle *rec = nullptr; int height = graph->getHeight() * .3; - ssize_t indexClose(0), indexOpen(0); auto openBox = [&] (const KsPlot::Point &p) { @@ -101,24 +101,6 @@ static void pluginDraw(plugin_sched_context *plugin_ctx, }; for (int bin = 0; bin < graph->size(); ++bin) { - /** - * Plotting the latencies makes sense only in the case of a - * deep zoom. Here we set a naive threshold based on the number - * of entries inside the current bin. This cut seems to work - * well in all cases I tested so far, but it may result in - * unexpected behavior with some unusual trace data-sets. - * TODO: find a better criteria for deciding when to start - * plotting latencies. - */ - if (ksmodel_bin_count(histo, bin) > PLUGIN_MAX_ENTRIES_PER_BIN) { - if (rec) { - delete rec; - rec = nullptr; - } - - continue; - } - /* * Starting from the first element in this bin, go forward * in time until you find a trace entry that satisfies the @@ -128,6 +110,11 @@ static void pluginDraw(plugin_sched_context *plugin_ctx, plugin_switch_match_entry_pid, pid, col, &indexClose); + entryME = ksmodel_get_task_missed_events(histo, + bin, pid, + col, + &indexME); + if (e == SchedEvent::Switch) { /* * Starting from the last element in this bin, go backward @@ -152,10 +139,12 @@ static void pluginDraw(plugin_sched_context *plugin_ctx, } if (rec) { - if (entryClose) { + if (entryME || entryClose) { /* Close the box in this bin. */ closeBox(graph->getBin(bin)._base); - if (entryOpen && indexClose < indexOpen) { + if (entryOpen && + indexME < indexOpen && + indexClose < indexOpen) { /* * We have a Sched switch entry that * comes after (in time) the closure of @@ -244,9 +233,6 @@ static void secondPass(kshark_entry **data, * @param argv_c: A C pointer to be converted to KsCppArgV (C++ struct). * @param pid: Process Id. * @param draw_action: Draw action identifier. - * - * @returns True if the Pid of the entry matches the value of "pid". - * Otherwise false. */ void plugin_draw(kshark_cpp_argv *argv_c, int pid, int draw_action) { @@ -288,6 +274,14 @@ void plugin_draw(kshark_cpp_argv *argv_c, int pid, int draw_action) tracecmd_filter_id_add(plugin_ctx->second_pass_hash, pid); } + /* + * Plotting the latencies makes sense only in the case of a deep zoom. + * Here we set a threshold based on the total number of entries being + * visualized by the model. + * Don't be afraid to play with different values for this threshold. + */ + if (argvCpp->_histo->tot_count > PLUGIN_MAX_ENTRIES) + return; try { pluginDraw(plugin_ctx, kshark_ctx, argvCpp->_histo, col,