[PATCH 0/8] New/improved KernelShark plugins

[PATCH 0/8] New/improved KernelShark plugins

[Yordan Karadzhov]

This series of patches combines a development which originally aimed to
make the drawing logic of the Sched event plugin more robust and easy
to understand. It turned out that this is not possible without
introducing custom KernelShark entries for "Missed events".

Yordan Karadzhov (8):
  kernel-shark-qt: Reset the second pass hash when reloading Sched
    plugin
  kernel-shark-qt: Improve the plotting logic of the Sched event plugin
  kernel-shark-qt: Update the visualization model before plotting new
    graphs
  kernel-shark-qt: Add "Missed events" custom kshark_entry
  kernel-shark-qt: Add instrumentation for "Missed events" to the model
  kernel-shark-qt: Add tot_count field to the model descriptor
  kernel-shark-qt: Add "Missed events" plugin for KernelShark
  kernel-shark-qt: Update Sched Events plugin

 kernel-shark-qt/src/KsGLWidget.cpp           |   2 +
 kernel-shark-qt/src/libkshark-model.c        |  67 +++++++
 kernel-shark-qt/src/libkshark-model.h        |  15 ++
 kernel-shark-qt/src/libkshark.c              | 196 +++++++++++++++----
 kernel-shark-qt/src/libkshark.h              |  16 ++
 kernel-shark-qt/src/plugins/CMakeLists.txt   |   6 +-
 kernel-shark-qt/src/plugins/MissedEvents.cpp | 149 ++++++++++++++
 kernel-shark-qt/src/plugins/SchedEvents.cpp  | 171 +++++++---------
 kernel-shark-qt/src/plugins/missed_events.c  |  41 ++++
 kernel-shark-qt/src/plugins/missed_events.h  |  30 +++
 kernel-shark-qt/src/plugins/sched_events.c   |  54 +++--
 kernel-shark-qt/src/plugins/sched_events.h   |  15 +-
 12 files changed, 615 insertions(+), 147 deletions(-)
 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

-- 
2.17.1

[PATCH 1/8] kernel-shark-qt: Reset the second pass hash when reloading Sched plugin

[Yordan Karadzhov]

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 <ykaradzhov@vmware.com>
---
 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<int> 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);
-- 
2.17.1

[PATCH 2/8] kernel-shark-qt: Improve the plotting logic of the Sched event plugin

[Yordan Karadzhov]

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 <ykaradzhov@vmware.com>
---
 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<void(int)> 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);
 
-- 
2.17.1

[PATCH 3/8] kernel-shark-qt: Update the visualization model before plotting new graphs

[Yordan Karadzhov]

Updating the model before creating new graphs guaranties that all
previously plotted graphs are wiped out.

Signed-off-by: Yordan Karadzhov <ykaradzhov@vmware.com>
---
 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<int> cpuList, QVector<int> taskList)
 		_graphs.append(graph);
 	};
 
+	_model.update();
+
 	/* Create CPU graphs according to the cpuList. */
 	for (auto const &cpu: cpuList)
 		lamAddGraph(_newCPUGraph(cpu));
-- 
2.17.1

[PATCH 4/8] kernel-shark-qt: Add "Missed events" custom kshark_entry

[Yordan Karadzhov]

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 <ykaradzhov@vmware.com>
---
 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 <stdlib.h>
 #include <stdio.h>
 #include <assert.h>
-#include <errno.h>
 
 // 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 <stdint.h>
 #include <pthread.h>
+#include <errno.h>
 
 // Json-C
 #include <json.h>
@@ -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*,
-- 
2.17.1

[PATCH 5/8] kernel-shark-qt: Add instrumentation for "Missed events" to the model

[Yordan Karadzhov]

This patch adds to the Visualization model instruments, used for
finding and plotting "Missed events".

Signed-off-by: Yordan Karadzhov <ykaradzhov@vmware.com>
---
 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)
 {
-- 
2.17.1

[PATCH 6/8] kernel-shark-qt: Add tot_count field to the model descriptor

[Yordan Karadzhov]

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 <ykaradzhov@vmware.com>
---
 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.
-- 
2.17.1

Re: [PATCH 6/8] kernel-shark-qt: Add tot_count field to the model descriptor

[Steven Rostedt]

On Wed, 7 Nov 2018 16:14:38 +0000
Yordan Karadzhov <ykaradzhov@vmware.com> wrote:

> The tot_count field of the Visualization model descriptor provides
> fast access to the total number of entries being currently visualized.

I'm pulling these patches as is, but just for the future, it's best to
add a bit more about "why" a change like this is added. You could add
something like:

 "This will be useful for the sched event plugin for knowing when to
 plot wakeup latency"

Or something like that.

-- Steve


> 
> Signed-off-by: Yordan Karadzhov <ykaradzhov@vmware.com>
>

[PATCH 7/8] kernel-shark-qt: Add "Missed events" plugin for KernelShark

[Yordan Karadzhov]

The "Missed events" plugin displays a special marker that indicates
the position (in time) of the missed (overwritten) data.

Signed-off-by: Yordan Karadzhov <ykaradzhov@vmware.com>
---
 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 <ykaradzhov@vmware.com>
+ */
+
+/**
+ *  @file    MissedEvents.cpp
+ *  @brief   Plugin for visualization of events, missed due to overflow of the ring buffer.
+ */
+
+// C++
+#include<iostream>
+
+// 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 <ykaradzhov@vmware.com>
+ */
+
+/**
+ *  @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 <ykaradzov@vmware.com>
+ */
+
+/**
+ *  @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
-- 
2.17.1

[PATCH 8/8] kernel-shark-qt: Update Sched Events plugin

[Yordan Karadzhov]

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 <ykaradzhov@vmware.com>
---
 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<void(int)> 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,
-- 
2.17.1

Re: [PATCH 8/8] kernel-shark-qt: Update Sched Events plugin

[Steven Rostedt]

On Wed, 7 Nov 2018 16:14:40 +0000
Yordan Karadzhov <ykaradzhov@vmware.com> wrote:

> 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.

Again, we are missing the "why". A description here should explain why
this was done. Something like "The sched plugin would get confused
because of missed events, where we could have missed events hiding
wakeups, and only have the sched switch, or a wakeup with a missing
sched switch would break the plotting of the latency".


> 
> Signed-off-by: Yordan Karadzhov <ykaradzhov@vmware.com>
> ---
>  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<void(int)> 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.

Is this a comment to me?

I guess we need a way to save config options, and this could be a
variable. Or we can experiment with different numbers.

-- Steve


> +	 */
> +	if (argvCpp->_histo->tot_count > PLUGIN_MAX_ENTRIES)
> +		return;
>  	try {
>  		pluginDraw(plugin_ctx, kshark_ctx,
>  			   argvCpp->_histo, col,

Re: [PATCH 8/8] kernel-shark-qt: Update Sched Events plugin

[Steven Rostedt]

On Wed, 7 Nov 2018 16:14:40 +0000
Yordan Karadzhov <ykaradzhov@vmware.com> wrote:

> 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.
> 

I also noticed that it appears that you are drawing the red box for
every sched switch. The red box is only suppose to be drawn if the
previous state is R. The red box should not be drawn for any other
state (because they were blocked, and not preempted).

-- Steve

Re: [PATCH 8/8] kernel-shark-qt: Update Sched Events plugin

[Steven Rostedt]

On Thu, 8 Nov 2018 21:35:27 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Wed, 7 Nov 2018 16:14:40 +0000
> Yordan Karadzhov <ykaradzhov@vmware.com> wrote:
> 
> > 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.
> >   
> 
> I also noticed that it appears that you are drawing the red box for
> every sched switch. The red box is only suppose to be drawn if the
> previous state is R. The red box should not be drawn for any other
> state (because they were blocked, and not preempted).
> 

In other words, a red box should never connect to a green one.

-- Steve