All of lore.kernel.org
 help / color / mirror / Atom feed
From: Yordan Karadzhov <ykaradzhov@vmware.com>
To: "rostedt@goodmis.org" <rostedt@goodmis.org>
Cc: "linux-trace-devel@vger.kernel.org" <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	[thread overview]
Message-ID: <20181107161410.22507-5-ykaradzhov@vmware.com> (raw)
In-Reply-To: <20181107161410.22507-1-ykaradzhov@vmware.com>

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

  parent reply	other threads:[~2018-11-08  1:45 UTC|newest]

Thread overview: 13+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2018-11-07 16:14 [PATCH 0/8] New/improved KernelShark plugins Yordan Karadzhov
2018-11-07 16:14 ` [PATCH 1/8] kernel-shark-qt: Reset the second pass hash when reloading Sched plugin Yordan Karadzhov
2018-11-07 16:14 ` [PATCH 2/8] kernel-shark-qt: Improve the plotting logic of the Sched event plugin Yordan Karadzhov
2018-11-07 16:14 ` [PATCH 3/8] kernel-shark-qt: Update the visualization model before plotting new graphs Yordan Karadzhov
2018-11-07 16:14 ` Yordan Karadzhov [this message]
2018-11-07 16:14 ` [PATCH 5/8] kernel-shark-qt: Add instrumentation for "Missed events" to the model Yordan Karadzhov
2018-11-07 16:14 ` [PATCH 6/8] kernel-shark-qt: Add tot_count field to the model descriptor Yordan Karadzhov
2018-11-09  2:12   ` Steven Rostedt
2018-11-07 16:14 ` [PATCH 7/8] kernel-shark-qt: Add "Missed events" plugin for KernelShark Yordan Karadzhov
2018-11-07 16:14 ` [PATCH 8/8] kernel-shark-qt: Update Sched Events plugin Yordan Karadzhov
2018-11-09  2:16   ` Steven Rostedt
2018-11-09  2:35   ` Steven Rostedt
2018-11-09  2:37     ` Steven Rostedt

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20181107161410.22507-5-ykaradzhov@vmware.com \
    --to=ykaradzhov@vmware.com \
    --cc=linux-trace-devel@vger.kernel.org \
    --cc=rostedt@goodmis.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.