linux-trace-devel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
From: "Tzvetomir Stoyanov (VMware)" <tz.stoyanov@gmail.com>
To: rostedt@goodmis.org
Cc: linux-trace-devel@vger.kernel.org
Subject: [PATCH v4 06/23] trace-cmd: Add new trace-cmd clock tsc2nsec
Date: Thu, 25 Mar 2021 08:40:38 +0200	[thread overview]
Message-ID: <20210325064055.539554-7-tz.stoyanov@gmail.com> (raw)
In-Reply-To: <20210325064055.539554-1-tz.stoyanov@gmail.com>

A new clock is added to "trace-cmd record" command:
 trace-cmd record -C tsc2nsec ...
which uses x86-tsc ftrace clock and converts the timestamps from tsc to
nanoseconds, using data from perf kernel interface.
A new options is added also:
 trace-cmd record --tsc2nsec ...
which does not change the current trace clock, just convert whatever it
is to nanoseconds, using the same data from perf kernel interface.

Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
---
 tracecmd/include/trace-local.h |   7 ++
 tracecmd/trace-record.c        | 152 ++++++++++++++++++++++++++++++++-
 2 files changed, 155 insertions(+), 4 deletions(-)

diff --git a/tracecmd/include/trace-local.h b/tracecmd/include/trace-local.h
index 6e39d27d..7773e9fc 100644
--- a/tracecmd/include/trace-local.h
+++ b/tracecmd/include/trace-local.h
@@ -172,6 +172,7 @@ enum buffer_instance_flags {
 	BUFFER_FL_GUEST		= 1 << 2,
 	BUFFER_FL_AGENT		= 1 << 3,
 	BUFFER_FL_HAS_CLOCK	= 1 << 4,
+	BUFFER_FL_TSC2NSEC	= 1 << 5,
 };
 
 struct func_list {
@@ -199,6 +200,12 @@ struct filter_pids {
 	int exclude;
 };
 
+struct tsc_nsec {
+	int mult;
+	int shift;
+	unsigned long long offset;
+};
+
 struct buffer_instance {
 	struct buffer_instance	*next;
 	char			*name;
diff --git a/tracecmd/trace-record.c b/tracecmd/trace-record.c
index c7197ba0..49fa46d9 100644
--- a/tracecmd/trace-record.c
+++ b/tracecmd/trace-record.c
@@ -57,6 +57,8 @@
 #define MAX_LATENCY	"tracing_max_latency"
 #define STAMP		"stamp"
 #define FUNC_STACK_TRACE "func_stack_trace"
+#define TSC_CLOCK	"x86-tsc"
+#define TSCNSEC_CLOCK	"tsc2nsec"
 
 enum trace_type {
 	TRACE_TYPE_RECORD	= 1,
@@ -197,6 +199,7 @@ struct common_record_context {
 	const char *output;
 	char *date2ts;
 	char *user;
+	struct tsc_nsec tsc2nsec;
 	int data_flags;
 
 	int record_all;
@@ -4443,11 +4446,12 @@ static int find_ts(struct tep_event *event, struct tep_record *record,
 	return 0;
 }
 
-static unsigned long long find_time_stamp(struct tep_handle *tep)
+static unsigned long long find_time_stamp(struct tep_handle *tep,
+					  struct tracefs_instance *instance)
 {
 	unsigned long long ts = 0;
 
-	if (!tracefs_iterate_raw_events(tep, NULL, NULL, 0, find_ts, &ts))
+	if (!tracefs_iterate_raw_events(tep, instance, NULL, 0, find_ts, &ts))
 		return ts;
 
 	return 0;
@@ -4527,7 +4531,7 @@ static char *get_date_to_ts(void)
 		clock_gettime(CLOCK_REALTIME, &end);
 
 		tracecmd_disable_tracing();
-		ts = find_time_stamp(tep);
+		ts = find_time_stamp(tep, NULL);
 		if (!ts)
 			continue;
 
@@ -5388,6 +5392,7 @@ void init_top_instance(void)
 }
 
 enum {
+	OPT_tsc2nsec		= 240,
 	OPT_fork		= 241,
 	OPT_tsyncinterval	= 242,
 	OPT_user		= 243,
@@ -5711,6 +5716,61 @@ static bool clock_is_supported(struct tracefs_instance *instance, const char *cl
 	return ret != NULL;
 }
 
+#ifdef PERF
+static int get_tsc_nsec(int *shift, int *mult)
+{
+	static int cpu_shift, cpu_mult;
+	static int supported;
+	int cpus = tracecmd_count_cpus();
+	struct trace_perf perf;
+	int i;
+
+	if (supported)
+		goto out;
+
+	supported = -1;
+	if (trace_perf_init(&perf, 1, 0, getpid()))
+		return -1;
+	if (trace_perf_open(&perf))
+		return -1;
+	cpu_shift = perf.mmap->time_shift;
+	cpu_mult = perf.mmap->time_mult;
+	for (i = 1; i < cpus; i++) {
+		trace_perf_close(&perf);
+		if (trace_perf_init(&perf, 1, i, getpid()))
+			break;
+		if (trace_perf_open(&perf))
+			break;
+		if (perf.mmap->time_shift != cpu_shift ||
+		    perf.mmap->time_mult != cpu_mult) {
+			warning("Found different TSC multiplier and shift for CPU %d: %d;%d instead of %d;%d",
+				i, perf.mmap->time_mult, perf.mmap->time_shift, cpu_mult, cpu_shift);
+			break;
+		}
+	}
+	trace_perf_close(&perf);
+	if (i < cpus)
+		return -1;
+
+	supported = 1;
+out:
+	if (supported < 0)
+		return -1;
+
+	if (shift)
+		*shift = cpu_shift;
+	if (mult)
+		*mult = cpu_mult;
+
+	return 0;
+}
+#else
+static int get_tsc_nsec(int *shift, int *mult)
+{
+	return -1;
+}
+#endif
+
 static void parse_record_options(int argc,
 				 char **argv,
 				 enum trace_cmd curr_cmd,
@@ -5760,6 +5820,7 @@ static void parse_record_options(int argc,
 			{"module", required_argument, NULL, OPT_module},
 			{"tsync-interval", required_argument, NULL, OPT_tsyncinterval},
 			{"fork", no_argument, NULL, OPT_fork},
+			{"tsc2nsec", no_argument, NULL, OPT_tsc2nsec},
 			{NULL, 0, NULL, 0}
 		};
 
@@ -5905,7 +5966,21 @@ static void parse_record_options(int argc,
 			break;
 		case 'C':
 			check_instance_die(ctx->instance, "-C");
-			ctx->instance->clock = optarg;
+			if (strcmp(optarg, TSCNSEC_CLOCK) == 0) {
+				ret = get_tsc_nsec(&ctx->tsc2nsec.shift,
+						   &ctx->tsc2nsec.mult);
+				if (ret)
+					die("TSC to nanosecond is not supported");
+				ctx->instance->flags |= BUFFER_FL_TSC2NSEC;
+				ctx->instance->clock = TSC_CLOCK;
+			} else {
+				ctx->instance->clock = optarg;
+			}
+			if (!clock_is_supported(NULL, ctx->instance->clock))
+				die("Clock %s is not supported", ctx->instance->clock);
+			ctx->instance->clock = strdup(ctx->instance->clock);
+			if (!ctx->instance->clock)
+				die("Failed allocation");
 			ctx->instance->flags |= BUFFER_FL_HAS_CLOCK;
 			if (is_top_instance(ctx->instance))
 				guest_sync_set = true;
@@ -6160,6 +6235,13 @@ static void parse_record_options(int argc,
 				die("--fork option used for 'start' command only");
 			fork_process = true;
 			break;
+		case OPT_tsc2nsec:
+			ret = get_tsc_nsec(&ctx->tsc2nsec.shift,
+					   &ctx->tsc2nsec.mult);
+			if (ret)
+				die("TSC to nanosecond is not supported");
+			ctx->instance->flags |= BUFFER_FL_TSC2NSEC;
+			break;
 		case OPT_quiet:
 		case 'q':
 			quiet = true;
@@ -6307,6 +6389,65 @@ static bool has_local_instances(void)
 	return false;
 }
 
+/*
+ * Get the current clock value
+ */
+#define CLOCK_INST_NAME	"_clock_instance_"
+static unsigned long long get_clock_now(const char *clock)
+{
+	struct tracefs_instance *ts_instance = NULL;
+	unsigned long long ts = 0;
+	struct tep_handle *tep;
+	int tfd;
+	int ret;
+
+	/* Set up a tep to read the raw format */
+	tep = get_ftrace_tep();
+	if (!tep)
+		return 0;
+	ts_instance = tracefs_instance_create(CLOCK_INST_NAME);
+	if (!ts_instance)
+		goto out;
+	if (clock) {
+		ret = tracefs_instance_file_write(ts_instance, "trace_clock", clock);
+		if (ret < strlen(clock))
+			goto out;
+	}
+	tfd = tracefs_instance_file_open(ts_instance, "trace_marker", O_WRONLY);
+	if (tfd < 0)
+		goto out;
+	tracefs_trace_on(ts_instance);
+	ret = write(tfd, STAMP, 5);
+	tracefs_trace_off(ts_instance);
+	ts = find_time_stamp(tep, ts_instance);
+	close(tfd);
+
+out:
+	if (ts_instance) {
+		if (tracefs_instance_is_new(ts_instance))
+			tracefs_instance_destroy(ts_instance);
+		tracefs_instance_free(ts_instance);
+	}
+	tep_free(tep);
+
+	return ts;
+}
+
+static void get_tsc_offset(struct common_record_context *ctx)
+{
+	struct buffer_instance *instance;
+
+	for_all_instances(instance) {
+		if (is_guest(instance) || !instance->clock)
+			continue;
+
+		ctx->tsc2nsec.offset = get_clock_now(instance->clock);
+		return;
+	}
+
+	ctx->tsc2nsec.offset = get_clock_now(NULL);
+}
+
 /*
  * This function contains common code for the following commands:
  * record, start, stream, profile.
@@ -6365,6 +6506,9 @@ static void record_trace(int argc, char **argv,
 	for_all_instances(instance)
 		set_clock(instance);
 
+	if (ctx->tsc2nsec.mult)
+		get_tsc_offset(ctx);
+
 	/* Record records the date first */
 	if (ctx->date &&
 	    ((IS_RECORD(ctx) && has_local_instances()) || IS_RECORD_AGENT(ctx)))
-- 
2.30.2


  parent reply	other threads:[~2021-03-25  6:42 UTC|newest]

Thread overview: 26+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2021-03-25  6:40 [PATCH v4 00/23] TSC trace clock to nanosecond conversion Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 01/23] trace-cmd: Add initial perf interface in trace-cmd library Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 02/23] trace-cmd: Extend trace-cmd dump subcommand to display the clock Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 03/23] trace-cmd: Save only the selected clock in the trace.dat file Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 04/23] trace-cmd: Internal refactoring, move logic for local tep handler in its own function Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 05/23] trace-cmd: Add new local function to check if a trace clock is supported Tzvetomir Stoyanov (VMware)
2021-03-26 21:21   ` Steven Rostedt
2021-03-25  6:40 ` Tzvetomir Stoyanov (VMware) [this message]
2021-03-25  6:40 ` [PATCH v4 07/23] trace-cmd: Define a new option for tsc2nsec conversion Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 08/23] trace-cmd: Save information for tsc to nanoseconds conversion in trace file Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 09/23] trace-cmd: Read information for tsc to nanoseconds conversion from " Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 10/23] trace-cmd: Save tsc2nsec clock in trace.dat file Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 11/23] trace-cmd: Append new options into guest trace file at the end of the tracing session Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 12/23] trace-cmd: Remove unneeded multiply in events timestamp reading Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 13/23] trace-cmd: Perform all timestamp corrections in a single function Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 14/23] trace-cmd: Convert tsc timestamps to nanosecods when reading trace data from a file Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 15/23] trace-cmd: Set order and priorities when applying timestamp corrections Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 16/23] trace-cmd: Add a new flag to disable any " Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 17/23] trace-cmd: Change "--nodate" option to affect "--date" option only Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 18/23] trace-cmd: Add new parameter "--raw-ts" to "trace-cmd report" command Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 19/23] trace-cmd: Print times in TimeShift options as unsigned in trace-cmd dump Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 20/23] trace-cmd: Use tsc clock for host-guest tracing, if available Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 21/23] trace-cmd: Get current clock for host-guest tracing session Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 22/23] trace-cmd: Save the trace clocks in TRACECLOCK option Tzvetomir Stoyanov (VMware)
2021-03-25  6:40 ` [PATCH v4 23/23] trace-cmd: Read at least 8 bytes trace-id option Tzvetomir Stoyanov (VMware)
2021-03-26 21:18   ` 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=20210325064055.539554-7-tz.stoyanov@gmail.com \
    --to=tz.stoyanov@gmail.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 a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).