Linux-Trace-Devel Archive on lore.kernel.org
 help / Atom feed
* [PATCH v2 0/6][POC] trace-cmd: Timetamps sync using PTP-like algorithm, relying on vsock events.
@ 2019-02-01 13:45 Tzvetomir Stoyanov
  2019-02-01 13:45 ` [PATCH v2 1/6] trace-cmd: Implemented new lib API: tracecmd_local_events_system() Tzvetomir Stoyanov
                   ` (5 more replies)
  0 siblings, 6 replies; 8+ messages in thread
From: Tzvetomir Stoyanov @ 2019-02-01 13:45 UTC (permalink / raw)
  To: rostedt; +Cc: linux-trace-devel

[ V2 changes: 
   Addressed Steven Rostedt comments.
   Modified timestamps sync algorithm to gain more accuracy, with the 
   help of Yordan Karadzhov and Slavomir Kaslev. ]

This patch series is a POC for timestamps sync between guest and host machines.
It implelents PTP-like algorithm, using vsock events for getting the current time.

The patch series depends on Slavomir's changes, introduced by the patch series
"Add VM kernel tracing over vsock sockets"

Tzvetomir Stoyanov (6):
  trace-cmd: Implemented new lib API: tracecmd_local_events_system()
  trace-cmd: Added support for negative time offsets in trace.dat file
  trace-cmd: Fixed logic in tracecmd_read_page_record()
  trace-cmd: Added implementation of htonll() and ntohll()
  trace-cmd: Refactored make_instances() and tracecmd_remove_instances()
  trace-cmd [POC]: Implemented timestamps synch PTP-like algorithm,
    using vsock events.

 include/trace-cmd/trace-cmd.h  |   8 +-
 lib/trace-cmd/trace-input.c    |  18 +-
 lib/trace-cmd/trace-util.c     |  99 ++++++---
 tracecmd/include/trace-local.h |   5 +
 tracecmd/include/trace-msg.h   |  10 +
 tracecmd/trace-listen.c        |   3 +
 tracecmd/trace-msg.c           | 307 +++++++++++++++++++++++++-
 tracecmd/trace-read.c          |   4 +-
 tracecmd/trace-record.c        | 381 +++++++++++++++++++++++++--------
 9 files changed, 690 insertions(+), 145 deletions(-)

-- 
2.20.1


^ permalink raw reply	[flat|nested] 8+ messages in thread

* [PATCH v2 1/6] trace-cmd: Implemented new lib API: tracecmd_local_events_system()
  2019-02-01 13:45 [PATCH v2 0/6][POC] trace-cmd: Timetamps sync using PTP-like algorithm, relying on vsock events Tzvetomir Stoyanov
@ 2019-02-01 13:45 ` Tzvetomir Stoyanov
  2019-02-01 13:45 ` [PATCH v2 2/6] trace-cmd: Added support for negative time offsets in trace.dat file Tzvetomir Stoyanov
                   ` (4 subsequent siblings)
  5 siblings, 0 replies; 8+ messages in thread
From: Tzvetomir Stoyanov @ 2019-02-01 13:45 UTC (permalink / raw)
  To: rostedt; +Cc: linux-trace-devel

The new tracecmd lib API tracecmd_local_events_system() creates
a tep handler and initializes it with the events of the
specified subsystems.

Signed-off-by: Tzvetomir Stoyanov <tstoyanov@vmware.com>
---
 include/trace-cmd/trace-cmd.h |  2 +
 lib/trace-cmd/trace-util.c    | 99 +++++++++++++++++++++++------------
 2 files changed, 68 insertions(+), 33 deletions(-)

diff --git a/include/trace-cmd/trace-cmd.h b/include/trace-cmd/trace-cmd.h
index 238e16b..86de654 100644
--- a/include/trace-cmd/trace-cmd.h
+++ b/include/trace-cmd/trace-cmd.h
@@ -32,6 +32,8 @@ void tracecmd_unload_plugins(struct tep_plugin_list *list, struct tep_handle *pe
 char **tracecmd_event_systems(const char *tracing_dir);
 char **tracecmd_system_events(const char *tracing_dir, const char *system);
 struct tep_handle *tracecmd_local_events(const char *tracing_dir);
+struct tep_handle *tracecmd_local_events_system(const char *tracing_dir,
+						char **sys_names);
 int tracecmd_fill_local_events(const char *tracing_dir, struct tep_handle *pevent);
 char **tracecmd_local_plugins(const char *tracing_dir);
 
diff --git a/lib/trace-cmd/trace-util.c b/lib/trace-cmd/trace-util.c
index b5aea39..650575c 100644
--- a/lib/trace-cmd/trace-util.c
+++ b/lib/trace-cmd/trace-util.c
@@ -1119,43 +1119,15 @@ static int read_header(struct tep_handle *pevent, const char *events_dir)
 	return ret;
 }
 
-/**
- * tracecmd_local_events - create a pevent from the events on system
- * @tracing_dir: The directory that contains the events.
- *
- * Returns a pevent structure that contains the pevents local to
- * the system.
- */
-struct tep_handle *tracecmd_local_events(const char *tracing_dir)
-{
-	struct tep_handle *pevent = NULL;
-
-	pevent = tep_alloc();
-	if (!pevent)
-		return NULL;
-
-	if (tracecmd_fill_local_events(tracing_dir, pevent)) {
-		tep_free(pevent);
-		pevent = NULL;
-	}
-
-	return pevent;
-}
-
-/**
- * tracecmd_fill_local_events - Fill a pevent with the events on system
- * @tracing_dir: The directory that contains the events.
- * @pevent: Allocated pevent which will be filled
- *
- * Returns whether the operation succeeded
- */
-int tracecmd_fill_local_events(const char *tracing_dir, struct tep_handle *pevent)
+static int tracecmd_fill_local_events_system(const char *tracing_dir,
+					     struct tep_handle *pevent,
+					     char **sys_names)
 {
+	int ret, i, failure = 0;
 	struct dirent *dent;
 	char *events_dir;
 	struct stat st;
 	DIR *dir;
-	int ret, failure = 0;
 
 	if (!tracing_dir)
 		return -1;
@@ -1189,7 +1161,16 @@ int tracecmd_fill_local_events(const char *tracing_dir, struct tep_handle *peven
 		if (strcmp(name, ".") == 0 ||
 		    strcmp(name, "..") == 0)
 			continue;
-
+		if (sys_names) {
+			i=0;
+			while (sys_names[i]) {
+				if (strcmp(name, sys_names[i]) == 0)
+					break;
+				i++;
+			}
+			if (sys_names[i] == NULL)
+				continue;
+		}
 		sys = append_file(events_dir, name);
 		ret = stat(sys, &st);
 		if (ret < 0 || !S_ISDIR(st.st_mode)) {
@@ -1217,6 +1198,58 @@ int tracecmd_fill_local_events(const char *tracing_dir, struct tep_handle *peven
 	return ret;
 }
 
+/**
+ * tracecmd_local_events_system - create a tep from the events of the specified subsystem.
+ *
+ * @tracing_dir: The directory that contains the events.
+ * @sys_name: Array of system names, to load the events from.
+ * The last element from the array must be NULL
+ *
+ * Returns a tep structure that contains the tep local to
+ * the system.
+ */
+struct tep_handle *tracecmd_local_events_system(const char *tracing_dir,
+						char **sys_names)
+{
+	struct tep_handle *tep = NULL;
+
+	tep = tep_alloc();
+	if (!tep)
+		return NULL;
+
+	if (tracecmd_fill_local_events_system(tracing_dir, tep, sys_names)) {
+		tep_free(tep);
+		tep = NULL;
+	}
+
+	return tep;
+}
+
+/**
+ * tracecmd_local_events - create a pevent from the events on system
+ * @tracing_dir: The directory that contains the events.
+ *
+ * Returns a pevent structure that contains the pevents local to
+ * the system.
+ */
+struct tep_handle *tracecmd_local_events(const char *tracing_dir)
+{
+	return tracecmd_local_events_system(tracing_dir, NULL);
+}
+
+/**
+ * tracecmd_fill_local_events - Fill a pevent with the events on system
+ * @tracing_dir: The directory that contains the events.
+ * @pevent: Allocated pevent which will be filled
+ *
+ * Returns whether the operation succeeded
+ */
+int tracecmd_fill_local_events(const char *tracing_dir,
+			       struct tep_handle *pevent)
+{
+	return tracecmd_fill_local_events_system(tracing_dir, pevent, NULL);
+}
+
 /**
  * tracecmd_local_plugins - returns an array of available tracer plugins
  * @tracing_dir: The directory that contains the tracing directory
-- 
2.20.1


^ permalink raw reply	[flat|nested] 8+ messages in thread

* [PATCH v2 2/6] trace-cmd: Added support for negative time offsets in trace.dat file
  2019-02-01 13:45 [PATCH v2 0/6][POC] trace-cmd: Timetamps sync using PTP-like algorithm, relying on vsock events Tzvetomir Stoyanov
  2019-02-01 13:45 ` [PATCH v2 1/6] trace-cmd: Implemented new lib API: tracecmd_local_events_system() Tzvetomir Stoyanov
@ 2019-02-01 13:45 ` Tzvetomir Stoyanov
  2019-02-01 13:45 ` [PATCH v2 3/6] trace-cmd: Fixed logic in tracecmd_read_page_record() Tzvetomir Stoyanov
                   ` (3 subsequent siblings)
  5 siblings, 0 replies; 8+ messages in thread
From: Tzvetomir Stoyanov @ 2019-02-01 13:45 UTC (permalink / raw)
  To: rostedt; +Cc: linux-trace-devel

When synchronizing timestamps between different machines, there are cases
when the time offset is negative. This patch changes the way time offset is
written and read from trace.dat file - as signed decimal, instead of hex.

Signed-off-by: Tzvetomir Stoyanov <tstoyanov@vmware.com>
---
 include/trace-cmd/trace-cmd.h |   2 +-
 lib/trace-cmd/trace-input.c   |   6 +-
 tracecmd/trace-read.c         |   4 +-
 tracecmd/trace-record.c       | 120 +++++++++++++++++-----------------
 4 files changed, 66 insertions(+), 66 deletions(-)

diff --git a/include/trace-cmd/trace-cmd.h b/include/trace-cmd/trace-cmd.h
index 86de654..da225b4 100644
--- a/include/trace-cmd/trace-cmd.h
+++ b/include/trace-cmd/trace-cmd.h
@@ -126,7 +126,7 @@ int tracecmd_is_buffer_instance(struct tracecmd_input *handle);
 void tracecmd_create_top_instance(char *name);
 void tracecmd_remove_instances(void);
 
-void tracecmd_set_ts_offset(struct tracecmd_input *handle, unsigned long long offset);
+void tracecmd_set_ts_offset(struct tracecmd_input *handle, long long offset);
 void tracecmd_set_ts2secs(struct tracecmd_input *handle, unsigned long long hz);
 
 void tracecmd_print_events(struct tracecmd_input *handle, const char *regex);
diff --git a/lib/trace-cmd/trace-input.c b/lib/trace-cmd/trace-input.c
index b628570..33ad7d1 100644
--- a/lib/trace-cmd/trace-input.c
+++ b/lib/trace-cmd/trace-input.c
@@ -100,7 +100,7 @@ struct tracecmd_input {
 	bool			read_page;
 	bool			use_pipe;
 	struct cpu_data 	*cpu_data;
-	unsigned long long	ts_offset;
+	long long		ts_offset;
 	double			ts2secs;
 	char *			cpustats;
 	char *			uname;
@@ -2091,7 +2091,7 @@ static int init_cpu(struct tracecmd_input *handle, int cpu)
 }
 
 void tracecmd_set_ts_offset(struct tracecmd_input *handle,
-			    unsigned long long offset)
+			    long long offset)
 {
 	handle->ts_offset = offset;
 }
@@ -2108,7 +2108,7 @@ void tracecmd_set_ts2secs(struct tracecmd_input *handle,
 
 static int handle_options(struct tracecmd_input *handle)
 {
-	unsigned long long offset;
+	long long offset;
 	unsigned short option;
 	unsigned int size;
 	char *cpustats = NULL;
diff --git a/tracecmd/trace-read.c b/tracecmd/trace-read.c
index 804022a..e309672 100644
--- a/tracecmd/trace-read.c
+++ b/tracecmd/trace-read.c
@@ -58,7 +58,7 @@ static struct list_head handle_list;
 struct input_files {
 	struct list_head	list;
 	const char		*file;
-	unsigned long long	tsoffset;
+	long long		tsoffset;
 	unsigned long long	ts2secs;
 };
 static struct list_head input_files;
@@ -1413,7 +1413,7 @@ void trace_report (int argc, char **argv)
 	struct input_files *inputs;
 	struct handle_list *handles;
 	enum output_type otype;
-	unsigned long long tsoffset = 0;
+	long long tsoffset = 0;
 	unsigned long long ts2secs = 0;
 	unsigned long long ts2sc;
 	int show_stat = 0;
diff --git a/tracecmd/trace-record.c b/tracecmd/trace-record.c
index cd80462..5b763ad 100644
--- a/tracecmd/trace-record.c
+++ b/tracecmd/trace-record.c
@@ -201,6 +201,12 @@ enum trace_cmd {
 	CMD_record_agent,
 };
 
+enum {
+	DATA_FL_NONE		= 0,
+	DATA_FL_DATE		= 1,
+	DATA_FL_OFFSET		= 2,
+};
+
 struct common_record_context {
 	enum trace_cmd curr_cmd;
 	struct buffer_instance *instance;
@@ -3230,7 +3236,60 @@ again:
 	return msg_handle;
 }
 
-static void add_options(struct tracecmd_output *handle, struct common_record_context *ctx);
+static void add_option_hooks(struct tracecmd_output *handle)
+{
+	struct hook_list *hook;
+	int len;
+
+	for (hook = hooks; hook; hook = hook->next) {
+		len = strlen(hook->hook);
+		tracecmd_add_option(handle, TRACECMD_OPTION_HOOK,
+				    len + 1, hook->hook);
+	}
+}
+
+static void add_uname(struct tracecmd_output *handle)
+{
+	struct utsname buf;
+	char *str;
+	int len;
+	int ret;
+
+	ret = uname(&buf);
+	/* if this fails for some reason, just ignore it */
+	if (ret < 0)
+		return;
+
+	len = strlen(buf.sysname) + strlen(buf.nodename) +
+		strlen(buf.release) + strlen(buf.machine) + 4;
+	str = malloc(len);
+	if (!str)
+		return;
+	sprintf(str, "%s %s %s %s", buf.sysname, buf.nodename, buf.release, buf.machine);
+	tracecmd_add_option(handle, TRACECMD_OPTION_UNAME, len, str);
+	free(str);
+}
+
+static void add_options(struct tracecmd_output *handle,
+			struct common_record_context *ctx)
+{
+	int type = 0;
+
+	if (ctx->date2ts) {
+		if (ctx->data_flags & DATA_FL_DATE)
+			type = TRACECMD_OPTION_DATE;
+		else if (ctx->data_flags & DATA_FL_OFFSET)
+			type = TRACECMD_OPTION_OFFSET;
+	}
+
+	if (type)
+		tracecmd_add_option(handle, type,
+				    strlen(ctx->date2ts)+1, ctx->date2ts);
+
+	tracecmd_add_option(handle, TRACECMD_OPTION_TRACECLOCK, 0, NULL);
+	add_option_hooks(handle);
+	add_uname(handle);
+}
 
 static struct tracecmd_msg_handle *
 setup_connection(struct buffer_instance *instance, struct common_record_context *ctx)
@@ -3457,40 +3516,6 @@ add_buffer_stat(struct tracecmd_output *handle, struct buffer_instance *instance
 				    instance->s_save[i].buffer);
 }
 
-static void add_option_hooks(struct tracecmd_output *handle)
-{
-	struct hook_list *hook;
-	int len;
-
-	for (hook = hooks; hook; hook = hook->next) {
-		len = strlen(hook->hook);
-		tracecmd_add_option(handle, TRACECMD_OPTION_HOOK,
-				    len + 1, hook->hook);
-	}
-}
-
-static void add_uname(struct tracecmd_output *handle)
-{
-	struct utsname buf;
-	char *str;
-	int len;
-	int ret;
-
-	ret = uname(&buf);
-	/* if this fails for some reason, just ignore it */
-	if (ret < 0)
-		return;
-
-	len = strlen(buf.sysname) + strlen(buf.nodename) +
-		strlen(buf.release) + strlen(buf.machine) + 4;
-	str = malloc(len);
-	if (!str)
-		return;
-	sprintf(str, "%s %s %s %s", buf.sysname, buf.nodename, buf.release, buf.machine);
-	tracecmd_add_option(handle, TRACECMD_OPTION_UNAME, len, str);
-	free(str);
-}
-
 static void print_stat(struct buffer_instance *instance)
 {
 	int cpu;
@@ -3505,31 +3530,6 @@ static void print_stat(struct buffer_instance *instance)
 		trace_seq_do_printf(&instance->s_print[cpu]);
 }
 
-enum {
-	DATA_FL_NONE		= 0,
-	DATA_FL_DATE		= 1,
-	DATA_FL_OFFSET		= 2,
-};
-
-static void add_options(struct tracecmd_output *handle, struct common_record_context *ctx)
-{
-	int type = 0;
-
-	if (ctx->date2ts) {
-		if (ctx->data_flags & DATA_FL_DATE)
-			type = TRACECMD_OPTION_DATE;
-		else if (ctx->data_flags & DATA_FL_OFFSET)
-			type = TRACECMD_OPTION_OFFSET;
-	}
-
-	if (type)
-		tracecmd_add_option(handle, type, strlen(ctx->date2ts)+1, ctx->date2ts);
-
-	tracecmd_add_option(handle, TRACECMD_OPTION_TRACECLOCK, 0, NULL);
-	add_option_hooks(handle);
-	add_uname(handle);
-}
-
 static void write_guest_file(struct buffer_instance *instance)
 {
 	struct tracecmd_output *handle;
-- 
2.20.1


^ permalink raw reply	[flat|nested] 8+ messages in thread

* [PATCH v2 3/6] trace-cmd: Fixed logic in tracecmd_read_page_record()
  2019-02-01 13:45 [PATCH v2 0/6][POC] trace-cmd: Timetamps sync using PTP-like algorithm, relying on vsock events Tzvetomir Stoyanov
  2019-02-01 13:45 ` [PATCH v2 1/6] trace-cmd: Implemented new lib API: tracecmd_local_events_system() Tzvetomir Stoyanov
  2019-02-01 13:45 ` [PATCH v2 2/6] trace-cmd: Added support for negative time offsets in trace.dat file Tzvetomir Stoyanov
@ 2019-02-01 13:45 ` Tzvetomir Stoyanov
  2019-02-01 13:45 ` [PATCH v2 4/6] trace-cmd: Added implementation of htonll() and ntohll() Tzvetomir Stoyanov
                   ` (2 subsequent siblings)
  5 siblings, 0 replies; 8+ messages in thread
From: Tzvetomir Stoyanov @ 2019-02-01 13:45 UTC (permalink / raw)
  To: rostedt; +Cc: linux-trace-devel

Fixed the logic in tracecmd_read_page_record() when
searching for the next event in the event from the
ring buffer. In the current logic, in the case when
last_record is not NULL (we are searching for the second one)
the check "if (ptr != last_record->data)" always fails.

Signed-off-by: Tzvetomir Stoyanov <tstoyanov@vmware.com>
---
 lib/trace-cmd/trace-input.c | 12 ++++++++----
 1 file changed, 8 insertions(+), 4 deletions(-)

diff --git a/lib/trace-cmd/trace-input.c b/lib/trace-cmd/trace-input.c
index 33ad7d1..5d64ca8 100644
--- a/lib/trace-cmd/trace-input.c
+++ b/lib/trace-cmd/trace-input.c
@@ -1688,18 +1688,22 @@ tracecmd_read_page_record(struct tep_handle *pevent, void *page, int size,
 			goto out_free;
 		}
 
-		do {
+		ptr = kbuffer_read_event(kbuf, &ts);
+		while (ptr < last_record->data) {
 			ptr = kbuffer_next_event(kbuf, NULL);
 			if (!ptr)
 				break;
-		} while (ptr < last_record->data);
+			if (ptr == last_record->data)
+				break;
+		}
 		if (ptr != last_record->data) {
 			warning("tracecmd_read_page_record: could not find last_record");
 			goto out_free;
 		}
-	}
+		ptr = kbuffer_next_event(kbuf, &ts);
+	} else
+		ptr = kbuffer_read_event(kbuf, &ts);
 
-	ptr = kbuffer_read_event(kbuf, &ts);
 	if (!ptr)
 		goto out_free;
 
-- 
2.20.1


^ permalink raw reply	[flat|nested] 8+ messages in thread

* [PATCH v2 4/6] trace-cmd: Added implementation of htonll() and ntohll()
  2019-02-01 13:45 [PATCH v2 0/6][POC] trace-cmd: Timetamps sync using PTP-like algorithm, relying on vsock events Tzvetomir Stoyanov
                   ` (2 preceding siblings ...)
  2019-02-01 13:45 ` [PATCH v2 3/6] trace-cmd: Fixed logic in tracecmd_read_page_record() Tzvetomir Stoyanov
@ 2019-02-01 13:45 ` Tzvetomir Stoyanov
  2019-02-01 13:45 ` [PATCH v2 5/6] trace-cmd: Refactored make_instances() and tracecmd_remove_instances() Tzvetomir Stoyanov
  2019-02-01 13:45 ` [PATCH v2 6/6] trace-cmd [POC]: Implemented timestamps synch PTP-like algorithm, using vsock events Tzvetomir Stoyanov
  5 siblings, 0 replies; 8+ messages in thread
From: Tzvetomir Stoyanov @ 2019-02-01 13:45 UTC (permalink / raw)
  To: rostedt; +Cc: linux-trace-devel

Added implementation of htonll() and ntohll() as
macros, if they are not already defined.

Signed-off-by: Tzvetomir Stoyanov <tstoyanov@vmware.com>
---
 tracecmd/include/trace-msg.h | 10 ++++++++++
 1 file changed, 10 insertions(+)

diff --git a/tracecmd/include/trace-msg.h b/tracecmd/include/trace-msg.h
index b7fe10b..445f799 100644
--- a/tracecmd/include/trace-msg.h
+++ b/tracecmd/include/trace-msg.h
@@ -15,4 +15,14 @@ extern unsigned int page_size;
 void plog(const char *fmt, ...);
 void pdie(const char *fmt, ...);
 
+#ifndef htonll
+# if __BYTE_ORDER == __LITTLE_ENDIAN
+#define htonll(x) __bswap_64(x)
+#define ntohll(x) __bswap_64(x)
+#else
+#define htonll(x) (x)
+#define ntohll(x) (x)
+#endif
+#endif
+
 #endif /* _TRACE_MSG_H_ */
-- 
2.20.1


^ permalink raw reply	[flat|nested] 8+ messages in thread

* [PATCH v2 5/6] trace-cmd: Refactored make_instances() and tracecmd_remove_instances()
  2019-02-01 13:45 [PATCH v2 0/6][POC] trace-cmd: Timetamps sync using PTP-like algorithm, relying on vsock events Tzvetomir Stoyanov
                   ` (3 preceding siblings ...)
  2019-02-01 13:45 ` [PATCH v2 4/6] trace-cmd: Added implementation of htonll() and ntohll() Tzvetomir Stoyanov
@ 2019-02-01 13:45 ` Tzvetomir Stoyanov
  2019-02-01 13:45 ` [PATCH v2 6/6] trace-cmd [POC]: Implemented timestamps synch PTP-like algorithm, using vsock events Tzvetomir Stoyanov
  5 siblings, 0 replies; 8+ messages in thread
From: Tzvetomir Stoyanov @ 2019-02-01 13:45 UTC (permalink / raw)
  To: rostedt; +Cc: linux-trace-devel

In order to reuse the code which creates / deletes tracing instances,
these two functions are refactotred. A new ones are implemented:
make_one_instances() and tracecmd_remove_one_instance().

Signed-off-by: Tzvetomir Stoyanov <tstoyanov@vmware.com>
---
 tracecmd/trace-record.c | 54 +++++++++++++++++++++++------------------
 1 file changed, 31 insertions(+), 23 deletions(-)

diff --git a/tracecmd/trace-record.c b/tracecmd/trace-record.c
index 5b763ad..6d67858 100644
--- a/tracecmd/trace-record.c
+++ b/tracecmd/trace-record.c
@@ -4256,49 +4256,57 @@ static void clear_func_filters(void)
 	}
 }
 
-static void make_instances(void)
+static void make_one_instance(struct buffer_instance *instance)
 {
-	struct buffer_instance *instance;
 	struct stat st;
 	char *path;
 	int ret;
 
+	path = get_instance_dir(instance);
+	ret = stat(path, &st);
+	if (ret < 0) {
+		ret = mkdir(path, 0777);
+		if (ret < 0)
+			die("mkdir %s", path);
+	} else
+		/* Don't delete instances that already exist */
+		instance->flags |= BUFFER_FL_KEEP;
+	tracecmd_put_tracing_file(path);
+
+}
+
+static void make_instances(void)
+{
+	struct buffer_instance *instance;
+
 	for_each_instance(instance) {
 		if (instance->flags & BUFFER_FL_GUEST)
 			continue;
+		make_one_instance(instance);
+	}
+}
 
-		path = get_instance_dir(instance);
-		ret = stat(path, &st);
-		if (ret < 0) {
-			ret = mkdir(path, 0777);
-			if (ret < 0)
-				die("mkdir %s", path);
-		} else
-			/* Don't delete instances that already exist */
-			instance->flags |= BUFFER_FL_KEEP;
-		tracecmd_put_tracing_file(path);
+static void tracecmd_remove_one_instance(struct buffer_instance *instance)
+{
+	char *path;
+
+	if (instance->tracing_on_fd > 0) {
+		close(instance->tracing_on_fd);
+		instance->tracing_on_fd = 0;
 	}
+	path = get_instance_dir(instance);
+	tracecmd_put_tracing_file(path);
 }
 
 void tracecmd_remove_instances(void)
 {
 	struct buffer_instance *instance;
-	char *path;
-	int ret;
 
 	for_each_instance(instance) {
 		/* Only delete what we created */
 		if (instance->flags & (BUFFER_FL_KEEP | BUFFER_FL_GUEST))
 			continue;
-		if (instance->tracing_on_fd > 0) {
-			close(instance->tracing_on_fd);
-			instance->tracing_on_fd = 0;
-		}
-		path = get_instance_dir(instance);
-		ret = rmdir(path);
-		if (ret < 0)
-			die("rmdir %s", path);
-		tracecmd_put_tracing_file(path);
+		tracecmd_remove_one_instance(instance);
 	}
 }
 
-- 
2.20.1


^ permalink raw reply	[flat|nested] 8+ messages in thread

* [PATCH v2 6/6] trace-cmd [POC]: Implemented timestamps synch PTP-like algorithm, using vsock events.
  2019-02-01 13:45 [PATCH v2 0/6][POC] trace-cmd: Timetamps sync using PTP-like algorithm, relying on vsock events Tzvetomir Stoyanov
                   ` (4 preceding siblings ...)
  2019-02-01 13:45 ` [PATCH v2 5/6] trace-cmd: Refactored make_instances() and tracecmd_remove_instances() Tzvetomir Stoyanov
@ 2019-02-01 13:45 ` Tzvetomir Stoyanov
  2019-02-02  8:05   ` Slavomir Kaslev
  5 siblings, 1 reply; 8+ messages in thread
From: Tzvetomir Stoyanov @ 2019-02-01 13:45 UTC (permalink / raw)
  To: rostedt; +Cc: linux-trace-devel

This is a POC patch, implementing a PTP-like algorithm for syncing timestamps between
host and guest machines, using vsock trace events to catch the host / guest time.

Signed-off-by: Tzvetomir Stoyanov <tstoyanov@vmware.com>
---
 include/trace-cmd/trace-cmd.h  |   4 +
 tracecmd/include/trace-local.h |   5 +
 tracecmd/trace-listen.c        |   3 +
 tracecmd/trace-msg.c           | 307 +++++++++++++++++++++++++++++++--
 tracecmd/trace-record.c        | 207 +++++++++++++++++++++-
 5 files changed, 507 insertions(+), 19 deletions(-)

diff --git a/include/trace-cmd/trace-cmd.h b/include/trace-cmd/trace-cmd.h
index da225b4..7f7e1fc 100644
--- a/include/trace-cmd/trace-cmd.h
+++ b/include/trace-cmd/trace-cmd.h
@@ -351,6 +351,10 @@ int tracecmd_msg_recv_trace_resp(struct tracecmd_msg_handle *msg_handle,
 				 int *nr_cpus, int *page_size,
 				 unsigned int **ports);
 
+int tracecmd_msg_rcv_time_sync(struct tracecmd_msg_handle *msg_handle);
+int tracecmd_msg_snd_time_sync(struct tracecmd_msg_handle *msg_handle,
+			       char *clock_str, long long *toffset);
+
 int tracecmd_msg_wait_close(struct tracecmd_msg_handle *msg_handle);
 
 /* --- Plugin handling --- */
diff --git a/tracecmd/include/trace-local.h b/tracecmd/include/trace-local.h
index 823d323..c502c70 100644
--- a/tracecmd/include/trace-local.h
+++ b/tracecmd/include/trace-local.h
@@ -225,6 +225,11 @@ void show_instance_file(struct buffer_instance *instance, const char *name);
 
 int count_cpus(void);
 
+struct buffer_instance *clock_synch_enable(int fd, char *clock,
+					   int *tx_event, int *rx_event);
+void clock_synch_disable(int fd, struct buffer_instance *instance);
+struct tep_handle *clock_synch_get_tep(struct buffer_instance *instance);
+
 /* No longer in event-utils.h */
 void __noreturn die(const char *fmt, ...); /* Can be overriden */
 void *malloc_or_die(unsigned int size); /* Can be overridden */
diff --git a/tracecmd/trace-listen.c b/tracecmd/trace-listen.c
index 9b50147..7783a68 100644
--- a/tracecmd/trace-listen.c
+++ b/tracecmd/trace-listen.c
@@ -404,6 +404,9 @@ static int communicate_with_client(struct tracecmd_msg_handle *msg_handle)
 
 		msg_handle->version = V3_PROTOCOL;
 
+		/* time sync with the v3 client */
+		tracecmd_msg_rcv_time_sync(msg_handle);
+
 		/* read the CPU count, the page size, and options */
 		if ((pagesize = tracecmd_msg_initial_setting(msg_handle)) < 0)
 			goto out;
diff --git a/tracecmd/trace-msg.c b/tracecmd/trace-msg.c
index 46b18aa..e264f10 100644
--- a/tracecmd/trace-msg.c
+++ b/tracecmd/trace-msg.c
@@ -18,9 +18,11 @@
 #include <stdarg.h>
 #include <string.h>
 #include <unistd.h>
+#include <time.h>
 #include <arpa/inet.h>
 #include <sys/types.h>
 #include <linux/types.h>
+#include <linux/vm_sockets.h>
 
 #include "trace-cmd-local.h"
 #include "trace-local.h"
@@ -28,6 +30,8 @@
 
 typedef __u32 u32;
 typedef __be32 be32;
+typedef __u64 u64;
+typedef __s64 s64;
 
 static inline void dprint(const char *fmt, ...)
 {
@@ -50,11 +54,20 @@ static inline void dprint(const char *fmt, ...)
 
 unsigned int page_size;
 
+/* Try a few times to get an accurate time sync */
+#define TSYNC_TRIES 5000
+#define TSYNC_TRESCH 10000
+
 struct tracecmd_msg_server {
 	struct tracecmd_msg_handle handle;
 	int			done;
 };
 
+struct clock_synch_event {
+	int			id;
+	unsigned long long	ts;
+};
+
 static struct tracecmd_msg_server *
 make_server(struct tracecmd_msg_handle *msg_handle)
 {
@@ -90,6 +103,16 @@ struct tracecmd_msg_trace_resp {
 	be32 page_size;
 } __attribute__((packed));
 
+struct tracecmd_msg_time_sync_init {
+	char clock[32];
+	s64  toffset;
+} __attribute__((packed));
+
+struct tracecmd_msg_time_sync {
+	u64 tlocal_rx;
+	u64 tlocal_tx;
+} __attribute__((packed));
+
 struct tracecmd_msg_header {
 	be32	size;
 	be32	cmd;
@@ -97,13 +120,15 @@ struct tracecmd_msg_header {
 } __attribute__((packed));
 
 #define MSG_MAP								\
-	C(CLOSE,	0,	0),					\
-	C(TINIT,	1,	sizeof(struct tracecmd_msg_tinit)),	\
-	C(RINIT,	2,	sizeof(struct tracecmd_msg_rinit)),	\
-	C(SEND_DATA,	3,	0),					\
-	C(FIN_DATA,	4,	0),					\
-	C(TRACE_REQ,	5,	sizeof(struct tracecmd_msg_trace_req)),	\
-	C(TRACE_RESP,	6,	sizeof(struct tracecmd_msg_trace_resp)),
+	C(CLOSE,		0, 0),					\
+	C(TINIT,		1, sizeof(struct tracecmd_msg_tinit)),	\
+	C(RINIT,		2, sizeof(struct tracecmd_msg_rinit)),	\
+	C(SEND_DATA,		3, 0),					\
+	C(FIN_DATA,		4, 0),					\
+	C(TRACE_REQ,		5, sizeof(struct tracecmd_msg_trace_req)),\
+	C(TRACE_RESP,		6, sizeof(struct tracecmd_msg_trace_resp)),\
+	C(TIME_SYNC_INIT,	7, sizeof(struct tracecmd_msg_time_sync_init)),\
+	C(TIME_SYNC,		8, sizeof(struct tracecmd_msg_time_sync)),
 
 #undef C
 #define C(a,b,c)	MSG_##a = b
@@ -133,10 +158,12 @@ static const char *cmd_to_name(int cmd)
 struct tracecmd_msg {
 	struct tracecmd_msg_header		hdr;
 	union {
-		struct tracecmd_msg_tinit	tinit;
-		struct tracecmd_msg_rinit	rinit;
-		struct tracecmd_msg_trace_req	trace_req;
-		struct tracecmd_msg_trace_resp	trace_resp;
+		struct tracecmd_msg_tinit		tinit;
+		struct tracecmd_msg_rinit		rinit;
+		struct tracecmd_msg_trace_req		trace_req;
+		struct tracecmd_msg_trace_resp		trace_resp;
+		struct tracecmd_msg_time_sync_init	time_sync_init;
+		struct tracecmd_msg_time_sync		time_sync;
 	};
 	union {
 		struct tracecmd_msg_opt		*opt;
@@ -825,6 +852,264 @@ out:
 	return ret;
 }
 
+static int
+find_events_in_page(struct tep_handle *pevent, void *page,
+		    int size, struct clock_synch_event *events)
+{
+	struct tep_event *event = NULL;
+	struct tep_record *last_record = NULL;
+	struct tep_record *record;
+	int id, i, j, cnt = 0;
+
+	if (size <= 0)
+		return 0;
+	for (i = 0; events[i].id; i++) {
+		if (!events[i].ts)
+			cnt++;
+	}
+
+	while (cnt) {
+		event = NULL;
+		record = tracecmd_read_page_record(pevent, page, size,
+						   last_record);
+		if (!record)
+			break;
+		free_record(last_record);
+		id = tep_data_type(pevent, record);
+		for (i = 0; events[i].id; i++)
+			if (!events[i].ts && events[i].id == id) {
+				event = tep_data_event_from_type(pevent, id);
+				break;
+			}
+		if (event) {
+			for (j = 0; j < i; j++)
+				if (events[j].ts && events[j].ts > record->ts)
+					break;
+			if (j == i) {
+				events[i].ts = record->ts;
+				cnt--;
+			}
+		}
+		last_record = record;
+	}
+	free_record(last_record);
+
+	return cnt;
+}
+
+static int clock_synch_find_events(struct tep_handle *tep,
+				   struct buffer_instance *instance,
+				   struct clock_synch_event *events)
+{
+	struct dirent *dent;
+	int ts = 0;
+	void *page;
+	char *path;
+	char *file;
+	DIR *dir;
+	int len;
+	int fd;
+	int r;
+
+	page_size = getpagesize();
+
+	path = get_instance_file(instance, "per_cpu");
+	if (!path)
+		return ts;
+
+	dir = opendir(path);
+	if (!dir)
+		goto out;
+
+	len = strlen(path);
+	file = malloc(len + strlen("trace_pipe_raw") + 32);
+	page = malloc(page_size);
+	if (!file || !page)
+		die("Failed to allocate time_stamp info");
+
+	while ((dent = readdir(dir))) {
+
+		const char *name = dent->d_name;
+
+		if (strncmp(name, "cpu", 3) != 0)
+			continue;
+		sprintf(file, "%s/%s/trace_pipe_raw", path, name);
+		fd = open(file, O_RDONLY | O_NONBLOCK);
+		if (fd < 0)
+			continue;
+		do {
+			r = read(fd, page, page_size);
+			if (r > 0) {
+				ts = find_events_in_page(tep, page, r, events);
+				if (!ts)
+					break;
+			}
+		} while (r > 0);
+		close(fd);
+	}
+
+	free(file);
+	free(page);
+	closedir(dir);
+
+ out:
+	tracecmd_put_tracing_file(path);
+	return ts;
+}
+
+extern struct tep_handle *clock_synch_get_tep(struct buffer_instance *instance);
+
+int tracecmd_msg_rcv_time_sync(struct tracecmd_msg_handle *msg_handle)
+{
+	struct buffer_instance *vinst;
+	struct tracecmd_msg msg;
+	struct tep_handle *tep;
+	int ret;
+	char *clock;
+	struct clock_synch_event events[3];
+
+	ret = tracecmd_msg_recv(msg_handle->fd, &msg);
+	if (ret < 0 || ntohl(msg.hdr.cmd) != MSG_TIME_SYNC_INIT)
+		return 0;
+	if (!msg.time_sync_init.clock[0])
+		return 0;
+
+	clock = strdup(msg.time_sync_init.clock);
+	events[2].id = 0;
+	vinst = clock_synch_enable(msg_handle->fd, clock,
+				   &events[1].id, &events[0].id);
+	tep = clock_synch_get_tep(vinst);
+	tracecmd_msg_init(MSG_TIME_SYNC_INIT, &msg);
+	tracecmd_msg_send(msg_handle->fd, &msg);
+
+	do {
+		events[0].ts = 0;
+		events[1].ts = 0;
+		ret = tracecmd_msg_recv(msg_handle->fd, &msg);
+		if (ret < 0 || ntohl(msg.hdr.cmd) != MSG_TIME_SYNC)
+			break;
+
+		tracecmd_msg_send(msg_handle->fd, &msg);
+		clock_synch_find_events(tep, vinst, events);
+		tracecmd_msg_init(MSG_TIME_SYNC, &msg);
+		msg.time_sync.tlocal_tx = htonll(events[1].ts);
+		msg.time_sync.tlocal_rx = htonll(events[0].ts);
+		tracecmd_msg_send(msg_handle->fd, &msg);
+	} while (true);
+	clock_synch_disable(msg_handle->fd, vinst);
+	msg_free(&msg);
+	tep_free(tep);
+	free(clock);
+	return ret;
+}
+
+int tracecmd_msg_snd_time_sync(struct tracecmd_msg_handle *msg_handle,
+			       char *clock_str, long long *toffset)
+{
+	static struct buffer_instance *vinst;
+	struct clock_synch_event events[4];
+	long long *offsets, *replies;
+	struct tracecmd_msg msg_resp;
+	struct tracecmd_msg msg_req;
+	int sync_loop = TSYNC_TRIES;
+	long long ms_diff, sm_diff;
+	int j= 0, i = 0, ret = 0;
+	struct tep_handle *tep;
+	long long m_t1, m_t4;
+	long long s_t2, s_t3;
+	long long t_offs = 0;
+	long long min_p=0;
+	char *clock;
+
+	clock = clock_str;
+	if (!clock)
+		clock = "local";
+
+	tracecmd_msg_init(MSG_TIME_SYNC_INIT, &msg_req);
+	if (toffset == NULL) {
+		msg_req.time_sync_init.clock[0] = 0;
+		tracecmd_msg_send(msg_handle->fd, &msg_req);
+		return 0;
+	}
+	offsets = calloc(sizeof(long long), TSYNC_TRIES);
+	replies = calloc(sizeof(long long), TSYNC_TRIES);
+	if (!offsets || !replies) {
+		free(offsets);
+		free(replies);
+		return 0;
+	}
+
+	strncpy(msg_req.time_sync_init.clock, clock, 16);
+	tracecmd_msg_send(msg_handle->fd, &msg_req);
+	ret = tracecmd_msg_recv(msg_handle->fd, &msg_resp);
+	if (ret < 0 || ntohl(msg_resp.hdr.cmd) != MSG_TIME_SYNC_INIT) {
+		free(offsets);
+		free(replies);
+		return 0;
+	}
+	events[3].id = 0;
+	vinst = clock_synch_enable(msg_handle->fd, clock_str,
+				   &events[0].id, &events[1].id);
+	tep = clock_synch_get_tep(vinst);
+	*toffset = 0;
+
+	do {
+		memset(&msg_resp, 0, sizeof(msg_resp));
+		events[0].ts = 0;
+		events[1].ts = 0;
+		events[2].ts = 0;
+		tracecmd_msg_init(MSG_TIME_SYNC, &msg_req);
+
+		tracecmd_msg_send(msg_handle->fd, &msg_req);
+		ret = tracecmd_msg_recv(msg_handle->fd, &msg_resp);
+		if (ret < 0 || ntohl(msg_resp.hdr.cmd) != MSG_TIME_SYNC)
+			break;
+		ret = tracecmd_msg_recv(msg_handle->fd, &msg_resp);
+		if (ret < 0 || ntohl(msg_resp.hdr.cmd) != MSG_TIME_SYNC)
+			break;
+		clock_synch_find_events(tep, vinst, events);
+		m_t1 = events[0].ts;
+		m_t4 = events[1].ts;
+		s_t2 = htonll(msg_resp.time_sync.tlocal_rx);
+		s_t3 = ntohll(msg_resp.time_sync.tlocal_tx);
+		if (!m_t1 || !m_t4 || !s_t2 || !s_t3)
+			continue;
+		if ( m_t1 >= m_t4) 
+			continue;
+		ms_diff = s_t2 - m_t1;
+		sm_diff = m_t4 - s_t3;
+		offsets[i] = (ms_diff - sm_diff)/2;
+		replies[i] = abs(sm_diff);
+		if (!min_p || min_p > replies[i])
+			min_p = replies[i];
+		i++;
+	} while (--sync_loop);
+	clock_synch_disable(msg_handle->fd, vinst);
+
+	for (i=0; i<TSYNC_TRIES; i++) {
+		if (replies[i] && replies[i] < (TSYNC_TRESCH+min_p)) {
+			t_offs += offsets[i];
+			j++;
+		}
+	}
+	if(j)
+		t_offs /= j;
+
+	tracecmd_msg_init(MSG_TIME_SYNC_INIT, &msg_req);
+	msg_req.time_sync_init.clock[0] = 0;
+	msg_req.time_sync_init.toffset = t_offs;
+	tracecmd_msg_send(msg_handle->fd, &msg_req);
+
+	msg_free(&msg_req);
+	msg_free(&msg_resp);
+	free(offsets);
+	free(replies);
+
+	*toffset = t_offs;
+
+	return ret;
+}
+
 static int make_trace_resp(struct tracecmd_msg *msg,
 			   int page_size, int nr_cpus, unsigned int *ports)
 {
diff --git a/tracecmd/trace-record.c b/tracecmd/trace-record.c
index 6d67858..af442fe 100644
--- a/tracecmd/trace-record.c
+++ b/tracecmd/trace-record.c
@@ -3157,7 +3157,41 @@ static void check_protocol_version(struct tracecmd_msg_handle *msg_handle)
 	}
 }
 
-static struct tracecmd_msg_handle *setup_network(struct buffer_instance *instance)
+static void sync_time_with_listener_v3(struct tracecmd_msg_handle *msg_handle,
+				       struct common_record_context *ctx)
+{
+	struct buffer_instance	*instance;
+	long long toffset = 0;
+	char *clock = NULL;
+
+	instance = ctx->instance;
+	while (instance) {
+		clock = instance->clock;
+		if (clock)
+			break;
+		instance = instance->next;
+	}
+
+	if (ctx->data_flags & DATA_FL_DATE ||
+	    ctx->data_flags & DATA_FL_OFFSET) {
+		tracecmd_msg_snd_time_sync(msg_handle, clock, NULL);
+		return;
+	}
+
+	tracecmd_msg_snd_time_sync(msg_handle, clock, &toffset);
+
+	free(ctx->date2ts);
+	/* 20 digits + \0 */
+	ctx->date2ts = malloc(21);
+	if (ctx->date2ts) {
+		snprintf(ctx->date2ts, 21, "%lld", toffset);
+		ctx->data_flags |= DATA_FL_OFFSET;
+	}
+
+}
+
+static struct tracecmd_msg_handle *setup_network(struct buffer_instance *instance,
+						 struct common_record_context *ctx)
 {
 	struct tracecmd_msg_handle *msg_handle = NULL;
 	struct addrinfo hints;
@@ -3292,12 +3326,13 @@ static void add_options(struct tracecmd_output *handle,
 }
 
 static struct tracecmd_msg_handle *
-setup_connection(struct buffer_instance *instance, struct common_record_context *ctx)
+setup_connection(struct buffer_instance *instance,
+		 struct common_record_context *ctx)
 {
 	struct tracecmd_msg_handle *msg_handle;
 	struct tracecmd_output *network_handle;
 
-	msg_handle = setup_network(instance);
+	msg_handle = setup_network(instance, ctx);
 
 	/* Now create the handle through this socket */
 	if (msg_handle->version == V3_PROTOCOL) {
@@ -3324,7 +3359,8 @@ static void finish_network(struct tracecmd_msg_handle *msg_handle)
 	free(host);
 }
 
-static void connect_to_agent(struct buffer_instance *instance)
+static void connect_to_agent(struct buffer_instance *instance,
+			     struct common_record_context *ctx)
 {
 	struct tracecmd_msg_handle *msg_handle;
 	int sd, nr_cpus, page_size;
@@ -3350,9 +3386,12 @@ static void connect_to_agent(struct buffer_instance *instance)
 
 	/* the msg_handle now points to the guest fd */
 	instance->msg_handle = msg_handle;
+
+	tracecmd_msg_rcv_time_sync(msg_handle);
 }
 
-static void setup_guest(struct buffer_instance *instance)
+static void setup_guest(struct buffer_instance *instance,
+			struct common_record_context *ctx)
 {
 	struct tracecmd_msg_handle *msg_handle = instance->msg_handle;
 	char *file;
@@ -3374,10 +3413,13 @@ static void setup_guest(struct buffer_instance *instance)
 	close(fd);
 }
 
-static void setup_agent(struct buffer_instance *instance, struct common_record_context *ctx)
+static void setup_agent(struct buffer_instance *instance,
+			struct common_record_context *ctx)
 {
 	struct tracecmd_output *network_handle;
 
+	sync_time_with_listener_v3(instance->msg_handle, ctx);
+
 	network_handle = tracecmd_create_init_fd_msg(instance->msg_handle,
 						     listed_events);
 	add_options(network_handle, ctx);
@@ -3397,7 +3439,7 @@ void start_threads(enum trace_type type, struct common_record_context *ctx)
 	for_all_instances(instance) {
 		/* Start the connection now to find out how many CPUs we need */
 		if (instance->flags & BUFFER_FL_GUEST)
-			connect_to_agent(instance);
+			connect_to_agent(instance, ctx);
 		total_cpu_count += instance->cpu_count;
 	}
 
@@ -3413,7 +3455,7 @@ void start_threads(enum trace_type type, struct common_record_context *ctx)
 		if (instance->flags & BUFFER_FL_AGENT) {
 			setup_agent(instance, ctx);
 		} else if (instance->flags & BUFFER_FL_GUEST) {
-			setup_guest(instance);
+			setup_guest(instance, ctx);
 		} else if (host) {
 			instance->msg_handle = setup_connection(instance, ctx);
 			if (!instance->msg_handle)
@@ -5769,3 +5811,152 @@ int trace_record_agent(struct tracecmd_msg_handle *msg_handle,
 	free(argv_plus);
 	return 0;
 }
+
+static void get_vsocket_params(int fd, int *lcid,
+			       int *lport, int *rcid, int *rport)
+{
+	struct sockaddr_vm addr;
+	socklen_t addr_len = sizeof(addr);
+
+	memset(&addr, 0, sizeof(addr));
+	if (getsockname(fd, (struct sockaddr *)&addr, &addr_len))
+		return;
+	if (addr.svm_family != AF_VSOCK)
+		return;
+	*lport = addr.svm_port;
+	*lcid = addr.svm_cid;
+
+	memset(&addr, 0, sizeof(addr));
+	addr_len = sizeof(addr);
+	if (getpeername(fd, (struct sockaddr *)&addr, &addr_len))
+		return;
+	if (addr.svm_family != AF_VSOCK)
+		return;
+
+	*rport = addr.svm_port;
+	*rcid = addr.svm_cid;
+}
+
+static void set_clock_synch_events(int cfd, struct buffer_instance *instance,
+				   bool enable, int *tx_event, int *rx_event)
+{
+	int lcid, lport, rcid, rport;
+	char buffer[255];
+	FILE *fp;
+	char *path;
+	int fd;
+
+	path = get_instance_file(instance, "events/vsock/enable");
+	fd = open(path, O_WRONLY);
+	if (fd < 0)
+		return;
+	if (enable)
+		write(fd, "1", 2);
+	else
+		write(fd, "0", 2);
+	close(fd);
+	tracecmd_put_tracing_file(path);
+
+	if (enable) {
+		get_vsocket_params(cfd, &lcid, &lport, &rcid, &rport);
+
+		snprintf(buffer, 255,
+			"src_cid==%d && src_port==%d && dst_cid==%d && dst_port==%d && len!=0",
+			rcid, rport, lcid, lport);
+		path = get_instance_file(instance,
+					 "events/vsock/virtio_transport_recv_pkt/filter");
+		fd = open(path, O_WRONLY);
+		write(fd, buffer, strlen(buffer)+1);
+		close(fd);
+		tracecmd_put_tracing_file(path);
+
+		snprintf(buffer, 255,
+			"src_cid==%d && src_port==%d && dst_cid==%d && dst_port==%d && len!=0",
+			lcid, lport, rcid, rport);
+		path = get_instance_file(instance,
+					 "events/vsock/virtio_transport_alloc_pkt/filter");
+		fd = open(path, O_WRONLY);
+		write(fd, buffer, strlen(buffer)+1);
+		close(fd);
+		tracecmd_put_tracing_file(path);
+
+		if (tx_event) {
+			path = get_instance_file(instance,
+						 "events/vsock/virtio_transport_alloc_pkt/id");
+			fp = fopen(path, "r");
+			fgets(buffer, 255, (FILE *) fp);
+			*tx_event = atoi(buffer);
+			fclose(fp);
+			tracecmd_put_tracing_file(path);
+		}
+		if (rx_event) {
+			path = get_instance_file(instance,
+						 "events/vsock/virtio_transport_recv_pkt/id");
+			fp = fopen(path, "r");
+			fgets(buffer, 255, (FILE *) fp);
+			*rx_event = atoi(buffer);
+			fclose(fp);
+			tracecmd_put_tracing_file(path);
+		}
+	}
+
+	path = get_instance_file(instance, "events/vsock/enable");
+
+	if (enable)
+		write_tracing_on(instance, 1);
+	else
+		write_tracing_on(instance, 0);
+}
+
+static void vsock_trace_reset(struct buffer_instance *vinst)
+{
+	char *path;
+	int fd;
+
+	path = get_instance_file(vinst, "trace");
+	fd = open(path, O_WRONLY);
+	tracecmd_put_tracing_file(path);
+	write(fd, "0", 2);
+	close(fd);
+}
+
+struct tep_handle *clock_synch_get_tep(struct buffer_instance *instance)
+{
+	struct tep_handle *tep = NULL;
+	char *systems[] = {"vsock", "kvm", NULL};
+	char *path;
+
+	path = get_instance_dir(instance);
+	tep = tracecmd_local_events_system(path, systems);
+	tracecmd_put_tracing_file(path);
+
+	tep_set_file_bigendian(tep, tracecmd_host_bigendian());
+	tep_set_host_bigendian(tep, tracecmd_host_bigendian());
+
+	return tep;
+}
+
+struct buffer_instance *clock_synch_enable(int fd, char *clock,
+					   int *tx_event, int *rx_event)
+{
+	char inst_name[256];
+	struct buffer_instance *vinst;
+
+	snprintf(inst_name, 256, "clock_synch-%d", rand()%100);
+	vinst = create_instance(strdup(inst_name));
+	init_instance(vinst);
+	vinst->cpu_count = local_cpu_count;
+	make_one_instance(vinst);
+	vsock_trace_reset(vinst);
+	vinst->clock = strdup(clock);
+	set_clock(vinst);
+	set_clock_synch_events(fd, vinst, true, tx_event, rx_event);
+	return vinst;
+}
+
+void clock_synch_disable(int fd, struct buffer_instance *instance)
+{
+	set_clock_synch_events(fd, instance, false, NULL, NULL);
+	tracecmd_remove_one_instance(instance);
+	/* todo: clean up the instance */
+}
-- 
2.20.1


^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: [PATCH v2 6/6] trace-cmd [POC]: Implemented timestamps synch PTP-like algorithm, using vsock events.
  2019-02-01 13:45 ` [PATCH v2 6/6] trace-cmd [POC]: Implemented timestamps synch PTP-like algorithm, using vsock events Tzvetomir Stoyanov
@ 2019-02-02  8:05   ` Slavomir Kaslev
  0 siblings, 0 replies; 8+ messages in thread
From: Slavomir Kaslev @ 2019-02-02  8:05 UTC (permalink / raw)
  To: Tzvetomir Stoyanov; +Cc: Steven Rostedt, linux-trace-devel

On Fri, Feb 1, 2019 at 4:18 PM Tzvetomir Stoyanov <tstoyanov@vmware.com> wrote:
>
> This is a POC patch, implementing a PTP-like algorithm for syncing timestamps between
> host and guest machines, using vsock trace events to catch the host / guest time.
>
> Signed-off-by: Tzvetomir Stoyanov <tstoyanov@vmware.com>
> ---
>  include/trace-cmd/trace-cmd.h  |   4 +
>  tracecmd/include/trace-local.h |   5 +
>  tracecmd/trace-listen.c        |   3 +
>  tracecmd/trace-msg.c           | 307 +++++++++++++++++++++++++++++++--
>  tracecmd/trace-record.c        | 207 +++++++++++++++++++++-
>  5 files changed, 507 insertions(+), 19 deletions(-)
>
> diff --git a/include/trace-cmd/trace-cmd.h b/include/trace-cmd/trace-cmd.h
> index da225b4..7f7e1fc 100644
> --- a/include/trace-cmd/trace-cmd.h
> +++ b/include/trace-cmd/trace-cmd.h
> @@ -351,6 +351,10 @@ int tracecmd_msg_recv_trace_resp(struct tracecmd_msg_handle *msg_handle,
>                                  int *nr_cpus, int *page_size,
>                                  unsigned int **ports);
>
> +int tracecmd_msg_rcv_time_sync(struct tracecmd_msg_handle *msg_handle);
> +int tracecmd_msg_snd_time_sync(struct tracecmd_msg_handle *msg_handle,
> +                              char *clock_str, long long *toffset);
> +
>  int tracecmd_msg_wait_close(struct tracecmd_msg_handle *msg_handle);
>
>  /* --- Plugin handling --- */
> diff --git a/tracecmd/include/trace-local.h b/tracecmd/include/trace-local.h
> index 823d323..c502c70 100644
> --- a/tracecmd/include/trace-local.h
> +++ b/tracecmd/include/trace-local.h
> @@ -225,6 +225,11 @@ void show_instance_file(struct buffer_instance *instance, const char *name);
>
>  int count_cpus(void);
>
> +struct buffer_instance *clock_synch_enable(int fd, char *clock,
> +                                          int *tx_event, int *rx_event);
> +void clock_synch_disable(int fd, struct buffer_instance *instance);
> +struct tep_handle *clock_synch_get_tep(struct buffer_instance *instance);
> +
>  /* No longer in event-utils.h */
>  void __noreturn die(const char *fmt, ...); /* Can be overriden */
>  void *malloc_or_die(unsigned int size); /* Can be overridden */
> diff --git a/tracecmd/trace-listen.c b/tracecmd/trace-listen.c
> index 9b50147..7783a68 100644
> --- a/tracecmd/trace-listen.c
> +++ b/tracecmd/trace-listen.c
> @@ -404,6 +404,9 @@ static int communicate_with_client(struct tracecmd_msg_handle *msg_handle)
>
>                 msg_handle->version = V3_PROTOCOL;
>
> +               /* time sync with the v3 client */
> +               tracecmd_msg_rcv_time_sync(msg_handle);
> +
>                 /* read the CPU count, the page size, and options */
>                 if ((pagesize = tracecmd_msg_initial_setting(msg_handle)) < 0)
>                         goto out;
> diff --git a/tracecmd/trace-msg.c b/tracecmd/trace-msg.c
> index 46b18aa..e264f10 100644
> --- a/tracecmd/trace-msg.c
> +++ b/tracecmd/trace-msg.c
> @@ -18,9 +18,11 @@
>  #include <stdarg.h>
>  #include <string.h>
>  #include <unistd.h>
> +#include <time.h>
>  #include <arpa/inet.h>
>  #include <sys/types.h>
>  #include <linux/types.h>
> +#include <linux/vm_sockets.h>
>
>  #include "trace-cmd-local.h"
>  #include "trace-local.h"
> @@ -28,6 +30,8 @@
>
>  typedef __u32 u32;
>  typedef __be32 be32;
> +typedef __u64 u64;
> +typedef __s64 s64;
>
>  static inline void dprint(const char *fmt, ...)
>  {
> @@ -50,11 +54,20 @@ static inline void dprint(const char *fmt, ...)
>
>  unsigned int page_size;
>
> +/* Try a few times to get an accurate time sync */
> +#define TSYNC_TRIES 5000
> +#define TSYNC_TRESCH 10000

I think we should drop this fudging constant. Instead of taking
samples with offset in the range [min, min + TSYNC_TRESH], we can take
the smallest say 5% of the samples (also no need for sorting, can be
done in linear time with k-select).

> +
>  struct tracecmd_msg_server {
>         struct tracecmd_msg_handle handle;
>         int                     done;
>  };
>
> +struct clock_synch_event {
> +       int                     id;
> +       unsigned long long      ts;
> +};
> +
>  static struct tracecmd_msg_server *
>  make_server(struct tracecmd_msg_handle *msg_handle)
>  {
> @@ -90,6 +103,16 @@ struct tracecmd_msg_trace_resp {
>         be32 page_size;
>  } __attribute__((packed));
>
> +struct tracecmd_msg_time_sync_init {
> +       char clock[32];
> +       s64  toffset;
> +} __attribute__((packed));
> +
> +struct tracecmd_msg_time_sync {
> +       u64 tlocal_rx;
> +       u64 tlocal_tx;
> +} __attribute__((packed));
> +
>  struct tracecmd_msg_header {
>         be32    size;
>         be32    cmd;
> @@ -97,13 +120,15 @@ struct tracecmd_msg_header {
>  } __attribute__((packed));
>
>  #define MSG_MAP                                                                \
> -       C(CLOSE,        0,      0),                                     \
> -       C(TINIT,        1,      sizeof(struct tracecmd_msg_tinit)),     \
> -       C(RINIT,        2,      sizeof(struct tracecmd_msg_rinit)),     \
> -       C(SEND_DATA,    3,      0),                                     \
> -       C(FIN_DATA,     4,      0),                                     \
> -       C(TRACE_REQ,    5,      sizeof(struct tracecmd_msg_trace_req)), \
> -       C(TRACE_RESP,   6,      sizeof(struct tracecmd_msg_trace_resp)),
> +       C(CLOSE,                0, 0),                                  \
> +       C(TINIT,                1, sizeof(struct tracecmd_msg_tinit)),  \
> +       C(RINIT,                2, sizeof(struct tracecmd_msg_rinit)),  \
> +       C(SEND_DATA,            3, 0),                                  \
> +       C(FIN_DATA,             4, 0),                                  \
> +       C(TRACE_REQ,            5, sizeof(struct tracecmd_msg_trace_req)),\
> +       C(TRACE_RESP,           6, sizeof(struct tracecmd_msg_trace_resp)),\
> +       C(TIME_SYNC_INIT,       7, sizeof(struct tracecmd_msg_time_sync_init)),\
> +       C(TIME_SYNC,            8, sizeof(struct tracecmd_msg_time_sync)),
>
>  #undef C
>  #define C(a,b,c)       MSG_##a = b
> @@ -133,10 +158,12 @@ static const char *cmd_to_name(int cmd)
>  struct tracecmd_msg {
>         struct tracecmd_msg_header              hdr;
>         union {
> -               struct tracecmd_msg_tinit       tinit;
> -               struct tracecmd_msg_rinit       rinit;
> -               struct tracecmd_msg_trace_req   trace_req;
> -               struct tracecmd_msg_trace_resp  trace_resp;
> +               struct tracecmd_msg_tinit               tinit;
> +               struct tracecmd_msg_rinit               rinit;
> +               struct tracecmd_msg_trace_req           trace_req;
> +               struct tracecmd_msg_trace_resp          trace_resp;
> +               struct tracecmd_msg_time_sync_init      time_sync_init;
> +               struct tracecmd_msg_time_sync           time_sync;
>         };
>         union {
>                 struct tracecmd_msg_opt         *opt;
> @@ -825,6 +852,264 @@ out:
>         return ret;
>  }
>
> +static int
> +find_events_in_page(struct tep_handle *pevent, void *page,
> +                   int size, struct clock_synch_event *events)
> +{
> +       struct tep_event *event = NULL;
> +       struct tep_record *last_record = NULL;
> +       struct tep_record *record;
> +       int id, i, j, cnt = 0;
> +
> +       if (size <= 0)
> +               return 0;
> +       for (i = 0; events[i].id; i++) {
> +               if (!events[i].ts)
> +                       cnt++;
> +       }
> +
> +       while (cnt) {
> +               event = NULL;
> +               record = tracecmd_read_page_record(pevent, page, size,
> +                                                  last_record);
> +               if (!record)
> +                       break;
> +               free_record(last_record);
> +               id = tep_data_type(pevent, record);
> +               for (i = 0; events[i].id; i++)
> +                       if (!events[i].ts && events[i].id == id) {
> +                               event = tep_data_event_from_type(pevent, id);
> +                               break;
> +                       }
> +               if (event) {
> +                       for (j = 0; j < i; j++)
> +                               if (events[j].ts && events[j].ts > record->ts)
> +                                       break;
> +                       if (j == i) {
> +                               events[i].ts = record->ts;
> +                               cnt--;
> +                       }
> +               }
> +               last_record = record;
> +       }
> +       free_record(last_record);
> +
> +       return cnt;
> +}
> +
> +static int clock_synch_find_events(struct tep_handle *tep,
> +                                  struct buffer_instance *instance,
> +                                  struct clock_synch_event *events)
> +{
> +       struct dirent *dent;
> +       int ts = 0;
> +       void *page;
> +       char *path;
> +       char *file;
> +       DIR *dir;
> +       int len;
> +       int fd;
> +       int r;
> +
> +       page_size = getpagesize();
> +
> +       path = get_instance_file(instance, "per_cpu");
> +       if (!path)
> +               return ts;
> +
> +       dir = opendir(path);
> +       if (!dir)
> +               goto out;
> +
> +       len = strlen(path);
> +       file = malloc(len + strlen("trace_pipe_raw") + 32);
> +       page = malloc(page_size);
> +       if (!file || !page)
> +               die("Failed to allocate time_stamp info");
> +
> +       while ((dent = readdir(dir))) {
> +
> +               const char *name = dent->d_name;
> +
> +               if (strncmp(name, "cpu", 3) != 0)
> +                       continue;
> +               sprintf(file, "%s/%s/trace_pipe_raw", path, name);
> +               fd = open(file, O_RDONLY | O_NONBLOCK);
> +               if (fd < 0)
> +                       continue;
> +               do {
> +                       r = read(fd, page, page_size);
> +                       if (r > 0) {
> +                               ts = find_events_in_page(tep, page, r, events);
> +                               if (!ts)
> +                                       break;
> +                       }
> +               } while (r > 0);
> +               close(fd);
> +       }
> +
> +       free(file);
> +       free(page);
> +       closedir(dir);
> +
> + out:
> +       tracecmd_put_tracing_file(path);
> +       return ts;
> +}
> +
> +extern struct tep_handle *clock_synch_get_tep(struct buffer_instance *instance);
> +
> +int tracecmd_msg_rcv_time_sync(struct tracecmd_msg_handle *msg_handle)
> +{
> +       struct buffer_instance *vinst;
> +       struct tracecmd_msg msg;
> +       struct tep_handle *tep;
> +       int ret;
> +       char *clock;
> +       struct clock_synch_event events[3];
> +
> +       ret = tracecmd_msg_recv(msg_handle->fd, &msg);
> +       if (ret < 0 || ntohl(msg.hdr.cmd) != MSG_TIME_SYNC_INIT)
> +               return 0;

What happens when we receive a non MSG_TIME_SYNC_INIT command here?

> +       if (!msg.time_sync_init.clock[0])
> +               return 0;
> +
> +       clock = strdup(msg.time_sync_init.clock);
> +       events[2].id = 0;
> +       vinst = clock_synch_enable(msg_handle->fd, clock,
> +                                  &events[1].id, &events[0].id);
> +       tep = clock_synch_get_tep(vinst);
> +       tracecmd_msg_init(MSG_TIME_SYNC_INIT, &msg);
> +       tracecmd_msg_send(msg_handle->fd, &msg);
> +
> +       do {
> +               events[0].ts = 0;
> +               events[1].ts = 0;
> +               ret = tracecmd_msg_recv(msg_handle->fd, &msg);
> +               if (ret < 0 || ntohl(msg.hdr.cmd) != MSG_TIME_SYNC)
> +                       break;
> +
> +               tracecmd_msg_send(msg_handle->fd, &msg);
> +               clock_synch_find_events(tep, vinst, events);
> +               tracecmd_msg_init(MSG_TIME_SYNC, &msg);
> +               msg.time_sync.tlocal_tx = htonll(events[1].ts);
> +               msg.time_sync.tlocal_rx = htonll(events[0].ts);
> +               tracecmd_msg_send(msg_handle->fd, &msg);
> +       } while (true);
> +       clock_synch_disable(msg_handle->fd, vinst);
> +       msg_free(&msg);
> +       tep_free(tep);
> +       free(clock);
> +       return ret;
> +}
> +
> +int tracecmd_msg_snd_time_sync(struct tracecmd_msg_handle *msg_handle,
> +                              char *clock_str, long long *toffset)
> +{
> +       static struct buffer_instance *vinst;
> +       struct clock_synch_event events[4];
> +       long long *offsets, *replies;
> +       struct tracecmd_msg msg_resp;
> +       struct tracecmd_msg msg_req;
> +       int sync_loop = TSYNC_TRIES;
> +       long long ms_diff, sm_diff;
> +       int j= 0, i = 0, ret = 0;
> +       struct tep_handle *tep;
> +       long long m_t1, m_t4;
> +       long long s_t2, s_t3;
> +       long long t_offs = 0;
> +       long long min_p=0;
> +       char *clock;
> +
> +       clock = clock_str;
> +       if (!clock)
> +               clock = "local";
> +
> +       tracecmd_msg_init(MSG_TIME_SYNC_INIT, &msg_req);
> +       if (toffset == NULL) {
> +               msg_req.time_sync_init.clock[0] = 0;
> +               tracecmd_msg_send(msg_handle->fd, &msg_req);
> +               return 0;
> +       }
> +       offsets = calloc(sizeof(long long), TSYNC_TRIES);
> +       replies = calloc(sizeof(long long), TSYNC_TRIES);
> +       if (!offsets || !replies) {
> +               free(offsets);
> +               free(replies);
> +               return 0;
> +       }
> +
> +       strncpy(msg_req.time_sync_init.clock, clock, 16);
> +       tracecmd_msg_send(msg_handle->fd, &msg_req);
> +       ret = tracecmd_msg_recv(msg_handle->fd, &msg_resp);
> +       if (ret < 0 || ntohl(msg_resp.hdr.cmd) != MSG_TIME_SYNC_INIT) {
> +               free(offsets);
> +               free(replies);
> +               return 0;
> +       }
> +       events[3].id = 0;
> +       vinst = clock_synch_enable(msg_handle->fd, clock_str,
> +                                  &events[0].id, &events[1].id);
> +       tep = clock_synch_get_tep(vinst);
> +       *toffset = 0;
> +
> +       do {
> +               memset(&msg_resp, 0, sizeof(msg_resp));
> +               events[0].ts = 0;
> +               events[1].ts = 0;
> +               events[2].ts = 0;
> +               tracecmd_msg_init(MSG_TIME_SYNC, &msg_req);
> +
> +               tracecmd_msg_send(msg_handle->fd, &msg_req);
> +               ret = tracecmd_msg_recv(msg_handle->fd, &msg_resp);
> +               if (ret < 0 || ntohl(msg_resp.hdr.cmd) != MSG_TIME_SYNC)
> +                       break;
> +               ret = tracecmd_msg_recv(msg_handle->fd, &msg_resp);
> +               if (ret < 0 || ntohl(msg_resp.hdr.cmd) != MSG_TIME_SYNC)
> +                       break;
> +               clock_synch_find_events(tep, vinst, events);
> +               m_t1 = events[0].ts;
> +               m_t4 = events[1].ts;
> +               s_t2 = htonll(msg_resp.time_sync.tlocal_rx);
> +               s_t3 = ntohll(msg_resp.time_sync.tlocal_tx);
> +               if (!m_t1 || !m_t4 || !s_t2 || !s_t3)
> +                       continue;
> +               if ( m_t1 >= m_t4)
> +                       continue;
> +               ms_diff = s_t2 - m_t1;
> +               sm_diff = m_t4 - s_t3;
> +               offsets[i] = (ms_diff - sm_diff)/2;
> +               replies[i] = abs(sm_diff);
> +               if (!min_p || min_p > replies[i])
> +                       min_p = replies[i];
> +               i++;
> +       } while (--sync_loop);
> +       clock_synch_disable(msg_handle->fd, vinst);
> +
> +       for (i=0; i<TSYNC_TRIES; i++) {
> +               if (replies[i] && replies[i] < (TSYNC_TRESCH+min_p)) {
> +                       t_offs += offsets[i];
> +                       j++;
> +               }
> +       }
> +       if(j)
> +               t_offs /= j;
> +
> +       tracecmd_msg_init(MSG_TIME_SYNC_INIT, &msg_req);
> +       msg_req.time_sync_init.clock[0] = 0;
> +       msg_req.time_sync_init.toffset = t_offs;
> +       tracecmd_msg_send(msg_handle->fd, &msg_req);
> +
> +       msg_free(&msg_req);
> +       msg_free(&msg_resp);
> +       free(offsets);
> +       free(replies);
> +
> +       *toffset = t_offs;
> +
> +       return ret;
> +}
> +
>  static int make_trace_resp(struct tracecmd_msg *msg,
>                            int page_size, int nr_cpus, unsigned int *ports)
>  {
> diff --git a/tracecmd/trace-record.c b/tracecmd/trace-record.c
> index 6d67858..af442fe 100644
> --- a/tracecmd/trace-record.c
> +++ b/tracecmd/trace-record.c
> @@ -3157,7 +3157,41 @@ static void check_protocol_version(struct tracecmd_msg_handle *msg_handle)
>         }
>  }
>
> -static struct tracecmd_msg_handle *setup_network(struct buffer_instance *instance)
> +static void sync_time_with_listener_v3(struct tracecmd_msg_handle *msg_handle,
> +                                      struct common_record_context *ctx)
> +{
> +       struct buffer_instance  *instance;
> +       long long toffset = 0;
> +       char *clock = NULL;
> +
> +       instance = ctx->instance;
> +       while (instance) {
> +               clock = instance->clock;
> +               if (clock)
> +                       break;
> +               instance = instance->next;
> +       }
> +
> +       if (ctx->data_flags & DATA_FL_DATE ||
> +           ctx->data_flags & DATA_FL_OFFSET) {
> +               tracecmd_msg_snd_time_sync(msg_handle, clock, NULL);
> +               return;
> +       }
> +
> +       tracecmd_msg_snd_time_sync(msg_handle, clock, &toffset);
> +
> +       free(ctx->date2ts);
> +       /* 20 digits + \0 */
> +       ctx->date2ts = malloc(21);
> +       if (ctx->date2ts) {
> +               snprintf(ctx->date2ts, 21, "%lld", toffset);
> +               ctx->data_flags |= DATA_FL_OFFSET;
> +       }
> +
> +}
> +
> +static struct tracecmd_msg_handle *setup_network(struct buffer_instance *instance,
> +                                                struct common_record_context *ctx)
>  {
>         struct tracecmd_msg_handle *msg_handle = NULL;
>         struct addrinfo hints;
> @@ -3292,12 +3326,13 @@ static void add_options(struct tracecmd_output *handle,
>  }
>
>  static struct tracecmd_msg_handle *
> -setup_connection(struct buffer_instance *instance, struct common_record_context *ctx)
> +setup_connection(struct buffer_instance *instance,
> +                struct common_record_context *ctx)
>  {
>         struct tracecmd_msg_handle *msg_handle;
>         struct tracecmd_output *network_handle;
>
> -       msg_handle = setup_network(instance);
> +       msg_handle = setup_network(instance, ctx);
>
>         /* Now create the handle through this socket */
>         if (msg_handle->version == V3_PROTOCOL) {
> @@ -3324,7 +3359,8 @@ static void finish_network(struct tracecmd_msg_handle *msg_handle)
>         free(host);
>  }
>
> -static void connect_to_agent(struct buffer_instance *instance)
> +static void connect_to_agent(struct buffer_instance *instance,
> +                            struct common_record_context *ctx)
>  {
>         struct tracecmd_msg_handle *msg_handle;
>         int sd, nr_cpus, page_size;
> @@ -3350,9 +3386,12 @@ static void connect_to_agent(struct buffer_instance *instance)
>
>         /* the msg_handle now points to the guest fd */
>         instance->msg_handle = msg_handle;
> +
> +       tracecmd_msg_rcv_time_sync(msg_handle);
>  }
>
> -static void setup_guest(struct buffer_instance *instance)
> +static void setup_guest(struct buffer_instance *instance,
> +                       struct common_record_context *ctx)
>  {
>         struct tracecmd_msg_handle *msg_handle = instance->msg_handle;
>         char *file;
> @@ -3374,10 +3413,13 @@ static void setup_guest(struct buffer_instance *instance)
>         close(fd);
>  }
>
> -static void setup_agent(struct buffer_instance *instance, struct common_record_context *ctx)
> +static void setup_agent(struct buffer_instance *instance,
> +                       struct common_record_context *ctx)
>  {
>         struct tracecmd_output *network_handle;
>
> +       sync_time_with_listener_v3(instance->msg_handle, ctx);
> +
>         network_handle = tracecmd_create_init_fd_msg(instance->msg_handle,
>                                                      listed_events);
>         add_options(network_handle, ctx);
> @@ -3397,7 +3439,7 @@ void start_threads(enum trace_type type, struct common_record_context *ctx)
>         for_all_instances(instance) {
>                 /* Start the connection now to find out how many CPUs we need */
>                 if (instance->flags & BUFFER_FL_GUEST)
> -                       connect_to_agent(instance);
> +                       connect_to_agent(instance, ctx);
>                 total_cpu_count += instance->cpu_count;
>         }
>
> @@ -3413,7 +3455,7 @@ void start_threads(enum trace_type type, struct common_record_context *ctx)
>                 if (instance->flags & BUFFER_FL_AGENT) {
>                         setup_agent(instance, ctx);
>                 } else if (instance->flags & BUFFER_FL_GUEST) {
> -                       setup_guest(instance);
> +                       setup_guest(instance, ctx);
>                 } else if (host) {
>                         instance->msg_handle = setup_connection(instance, ctx);
>                         if (!instance->msg_handle)
> @@ -5769,3 +5811,152 @@ int trace_record_agent(struct tracecmd_msg_handle *msg_handle,
>         free(argv_plus);
>         return 0;
>  }
> +
> +static void get_vsocket_params(int fd, int *lcid,
> +                              int *lport, int *rcid, int *rport)
> +{
> +       struct sockaddr_vm addr;
> +       socklen_t addr_len = sizeof(addr);
> +
> +       memset(&addr, 0, sizeof(addr));
> +       if (getsockname(fd, (struct sockaddr *)&addr, &addr_len))
> +               return;
> +       if (addr.svm_family != AF_VSOCK)
> +               return;
> +       *lport = addr.svm_port;
> +       *lcid = addr.svm_cid;
> +
> +       memset(&addr, 0, sizeof(addr));
> +       addr_len = sizeof(addr);
> +       if (getpeername(fd, (struct sockaddr *)&addr, &addr_len))
> +               return;
> +       if (addr.svm_family != AF_VSOCK)
> +               return;
> +
> +       *rport = addr.svm_port;
> +       *rcid = addr.svm_cid;
> +}
> +
> +static void set_clock_synch_events(int cfd, struct buffer_instance *instance,
> +                                  bool enable, int *tx_event, int *rx_event)
> +{
> +       int lcid, lport, rcid, rport;
> +       char buffer[255];
> +       FILE *fp;
> +       char *path;
> +       int fd;
> +
> +       path = get_instance_file(instance, "events/vsock/enable");
> +       fd = open(path, O_WRONLY);
> +       if (fd < 0)
> +               return;
> +       if (enable)
> +               write(fd, "1", 2);
> +       else
> +               write(fd, "0", 2);
> +       close(fd);
> +       tracecmd_put_tracing_file(path);
> +
> +       if (enable) {
> +               get_vsocket_params(cfd, &lcid, &lport, &rcid, &rport);
> +
> +               snprintf(buffer, 255,
> +                       "src_cid==%d && src_port==%d && dst_cid==%d && dst_port==%d && len!=0",
> +                       rcid, rport, lcid, lport);
> +               path = get_instance_file(instance,
> +                                        "events/vsock/virtio_transport_recv_pkt/filter");
> +               fd = open(path, O_WRONLY);
> +               write(fd, buffer, strlen(buffer)+1);
> +               close(fd);
> +               tracecmd_put_tracing_file(path);
> +
> +               snprintf(buffer, 255,
> +                       "src_cid==%d && src_port==%d && dst_cid==%d && dst_port==%d && len!=0",
> +                       lcid, lport, rcid, rport);
> +               path = get_instance_file(instance,
> +                                        "events/vsock/virtio_transport_alloc_pkt/filter");
> +               fd = open(path, O_WRONLY);
> +               write(fd, buffer, strlen(buffer)+1);
> +               close(fd);
> +               tracecmd_put_tracing_file(path);
> +
> +               if (tx_event) {
> +                       path = get_instance_file(instance,
> +                                                "events/vsock/virtio_transport_alloc_pkt/id");
> +                       fp = fopen(path, "r");
> +                       fgets(buffer, 255, (FILE *) fp);
> +                       *tx_event = atoi(buffer);
> +                       fclose(fp);
> +                       tracecmd_put_tracing_file(path);
> +               }
> +               if (rx_event) {
> +                       path = get_instance_file(instance,
> +                                                "events/vsock/virtio_transport_recv_pkt/id");
> +                       fp = fopen(path, "r");
> +                       fgets(buffer, 255, (FILE *) fp);
> +                       *rx_event = atoi(buffer);
> +                       fclose(fp);
> +                       tracecmd_put_tracing_file(path);
> +               }
> +       }
> +
> +       path = get_instance_file(instance, "events/vsock/enable");
> +
> +       if (enable)
> +               write_tracing_on(instance, 1);
> +       else
> +               write_tracing_on(instance, 0);
> +}
> +
> +static void vsock_trace_reset(struct buffer_instance *vinst)
> +{
> +       char *path;
> +       int fd;
> +
> +       path = get_instance_file(vinst, "trace");
> +       fd = open(path, O_WRONLY);
> +       tracecmd_put_tracing_file(path);
> +       write(fd, "0", 2);
> +       close(fd);
> +}
> +
> +struct tep_handle *clock_synch_get_tep(struct buffer_instance *instance)
> +{
> +       struct tep_handle *tep = NULL;
> +       char *systems[] = {"vsock", "kvm", NULL};
> +       char *path;
> +
> +       path = get_instance_dir(instance);
> +       tep = tracecmd_local_events_system(path, systems);
> +       tracecmd_put_tracing_file(path);
> +
> +       tep_set_file_bigendian(tep, tracecmd_host_bigendian());
> +       tep_set_host_bigendian(tep, tracecmd_host_bigendian());
> +
> +       return tep;
> +}
> +
> +struct buffer_instance *clock_synch_enable(int fd, char *clock,
> +                                          int *tx_event, int *rx_event)
> +{
> +       char inst_name[256];
> +       struct buffer_instance *vinst;
> +
> +       snprintf(inst_name, 256, "clock_synch-%d", rand()%100);
> +       vinst = create_instance(strdup(inst_name));
> +       init_instance(vinst);
> +       vinst->cpu_count = local_cpu_count;
> +       make_one_instance(vinst);
> +       vsock_trace_reset(vinst);
> +       vinst->clock = strdup(clock);
> +       set_clock(vinst);
> +       set_clock_synch_events(fd, vinst, true, tx_event, rx_event);
> +       return vinst;
> +}
> +
> +void clock_synch_disable(int fd, struct buffer_instance *instance)
> +{
> +       set_clock_synch_events(fd, instance, false, NULL, NULL);
> +       tracecmd_remove_one_instance(instance);
> +       /* todo: clean up the instance */
> +}
> --
> 2.20.1
>

^ permalink raw reply	[flat|nested] 8+ messages in thread

end of thread, back to index

Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-02-01 13:45 [PATCH v2 0/6][POC] trace-cmd: Timetamps sync using PTP-like algorithm, relying on vsock events Tzvetomir Stoyanov
2019-02-01 13:45 ` [PATCH v2 1/6] trace-cmd: Implemented new lib API: tracecmd_local_events_system() Tzvetomir Stoyanov
2019-02-01 13:45 ` [PATCH v2 2/6] trace-cmd: Added support for negative time offsets in trace.dat file Tzvetomir Stoyanov
2019-02-01 13:45 ` [PATCH v2 3/6] trace-cmd: Fixed logic in tracecmd_read_page_record() Tzvetomir Stoyanov
2019-02-01 13:45 ` [PATCH v2 4/6] trace-cmd: Added implementation of htonll() and ntohll() Tzvetomir Stoyanov
2019-02-01 13:45 ` [PATCH v2 5/6] trace-cmd: Refactored make_instances() and tracecmd_remove_instances() Tzvetomir Stoyanov
2019-02-01 13:45 ` [PATCH v2 6/6] trace-cmd [POC]: Implemented timestamps synch PTP-like algorithm, using vsock events Tzvetomir Stoyanov
2019-02-02  8:05   ` Slavomir Kaslev

Linux-Trace-Devel Archive on lore.kernel.org

Archives are clonable:
	git clone --mirror https://lore.kernel.org/linux-trace-devel/0 linux-trace-devel/git/0.git

	# If you have public-inbox 1.1+ installed, you may
	# initialize and index your mirror using the following commands:
	public-inbox-init -V2 linux-trace-devel linux-trace-devel/ https://lore.kernel.org/linux-trace-devel \
		linux-trace-devel@vger.kernel.org linux-trace-devel@archiver.kernel.org
	public-inbox-index linux-trace-devel


Newsgroup available over NNTP:
	nntp://nntp.lore.kernel.org/org.kernel.vger.linux-trace-devel


AGPL code for this site: git clone https://public-inbox.org/ public-inbox