From patchwork Fri Apr 16 10:34:07 2021 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: "Tzvetomir Stoyanov (VMware)" X-Patchwork-Id: 12207381 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-15.7 required=3.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID,DKIM_VALID_AU,FREEMAIL_FORGED_FROMDOMAIN,FREEMAIL_FROM, HEADER_FROM_DIFFERENT_DOMAINS,INCLUDES_CR_TRAILER,INCLUDES_PATCH, MAILING_LIST_MULTI,SPF_HELO_NONE,SPF_PASS,USER_AGENT_GIT autolearn=ham autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id 05841C433ED for ; Fri, 16 Apr 2021 10:34:18 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by mail.kernel.org (Postfix) with ESMTP id D915B6115B for ; Fri, 16 Apr 2021 10:34:17 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S240017AbhDPKel (ORCPT ); Fri, 16 Apr 2021 06:34:41 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:47340 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S235193AbhDPKek (ORCPT ); Fri, 16 Apr 2021 06:34:40 -0400 Received: from mail-wm1-x32f.google.com (mail-wm1-x32f.google.com [IPv6:2a00:1450:4864:20::32f]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id C1AD5C061574 for ; Fri, 16 Apr 2021 03:34:13 -0700 (PDT) Received: by mail-wm1-x32f.google.com with SMTP id n10-20020a05600c4f8ab0290130f0d3cba3so2165970wmq.1 for ; Fri, 16 Apr 2021 03:34:13 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=from:to:cc:subject:date:message-id:in-reply-to:references :mime-version:content-transfer-encoding; bh=fZya1XWI/NQzc9cB2n37tHHzTY1PSChLFJmnzXElAGg=; b=Bln8HVoBGsNLA6KFB3FjRYooxtwa9JaNK1rDjYBUmLkAXbm1JfRWvAyHeQD5nBYnNF MMYpUjlTt5msfvQxUOzchkBSb4yyAiNtAcK8xOyfucsK/hifPhvFS9k6IyvYBGE+8/wM CBgJ2SErssEKv9DCPYVQw3kCVToZkMIW7c0BYEN3jrdfOZV1Z5nSc27/OppXRUXaNNZb uB0YNtW6fAV8ak2NFwjnS+BQBFulVGAgQN7JSSrDmxqxu7n1bkgbiS25yzsPZUP6zehP L3/bNMwk0rSv9AGVIi1z1WIkD4E7aJ2+h4f3IzXtwpww3tULwBw9L64mJ1pNysltlwek RYbg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:from:to:cc:subject:date:message-id:in-reply-to :references:mime-version:content-transfer-encoding; bh=fZya1XWI/NQzc9cB2n37tHHzTY1PSChLFJmnzXElAGg=; b=lEKzA325dRo4BNl3UQjVlB2/6c6S2mvAHNoKeUEw65PnrV3ZuvRmLCsTaNYVdDapWD hRAF39SoD3rxRTNJGX+QjWpE1npKaOmkaLxqyX2esZ0iy4WqrsfHdMqm90o/EQ4ibNwz SzoHcIcR/U4UQPbRkS7U/stp6nxsWfbhTwis8BHjc8myJvP3/8QbJazYdCTcbtany6ly 2knCFJrwIvJ5pQg330Jf9IaSNrJ2/AXvL2pymzeUd/IlE0g2cbLmUTOREiI5ouiGDBPM 3vF8ZIONrpFIWuMwjeaSxZYrfrUdZvQ3LdLQDHou3ZW4XbMU9wh1JlVdVaO9iPCLXZU7 aaqA== X-Gm-Message-State: AOAM532i4RbNebBdqas+xUzAzsO9NPguLDEvTdSo3jkHUWLD2AGRJ7G2 BHXjHPP6eePIFPsPXw9qFSEyMVS1D6+F+g== X-Google-Smtp-Source: ABdhPJzhQh65sCWxB8acPQFYa4lnSi3Pn6R9ZQAU23KReJXm8lBz9bgOI6DqLs8oRzj8lKQBp17zQw== X-Received: by 2002:a1c:1f92:: with SMTP id f140mr7356868wmf.108.1618569252463; Fri, 16 Apr 2021 03:34:12 -0700 (PDT) Received: from oberon.zico.biz ([83.222.187.186]) by smtp.gmail.com with ESMTPSA id v8sm9652139wrt.71.2021.04.16.03.34.11 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Fri, 16 Apr 2021 03:34:12 -0700 (PDT) From: "Tzvetomir Stoyanov (VMware)" To: rostedt@goodmis.org Cc: linux-trace-devel@vger.kernel.org Subject: [PATCH v2 1/3] trace-cmd library: Add new trace-cmd library APIs for guest ts corrections Date: Fri, 16 Apr 2021 13:34:07 +0300 Message-Id: <20210416103409.24597-2-tz.stoyanov@gmail.com> X-Mailer: git-send-email 2.30.2 In-Reply-To: <20210416103409.24597-1-tz.stoyanov@gmail.com> References: <20210416103409.24597-1-tz.stoyanov@gmail.com> MIME-Version: 1.0 Precedence: bulk List-ID: X-Mailing-List: linux-trace-devel@vger.kernel.org The logic for converting guest to host timestamps is local to the trace-cmd library and is used only when a trace file is opened. In order to reuse that logic, a new APIs are added: tracecmd_tsync_get_proto_flags() tracecmd_tsync_get_offsets() tracecmd_guest_ts_calc() struct ts_offset_sample struct tracecmd_ts_corrections Signed-off-by: Tzvetomir Stoyanov (VMware) --- .../include/private/trace-cmd-private.h | 18 ++- lib/trace-cmd/trace-input.c | 106 ++-------------- lib/trace-cmd/trace-timesync.c | 113 ++++++++++++++---- 3 files changed, 116 insertions(+), 121 deletions(-) diff --git a/lib/trace-cmd/include/private/trace-cmd-private.h b/lib/trace-cmd/include/private/trace-cmd-private.h index 42e739fa..56f82244 100644 --- a/lib/trace-cmd/include/private/trace-cmd-private.h +++ b/lib/trace-cmd/include/private/trace-cmd-private.h @@ -443,6 +443,17 @@ enum tracecmd_time_sync_role { /* Timestamp synchronization flags */ #define TRACECMD_TSYNC_FLAG_INTERPOLATE 0x1 +struct ts_offset_sample { + long long time; + long long offset; + long long scaling; +}; + +struct tracecmd_ts_corrections { + int ts_samples_count; + struct ts_offset_sample *ts_samples; +}; + void tracecmd_tsync_init(void); int tracecmd_tsync_proto_getall(struct tracecmd_tsync_protos **protos, const char *clock, int role); bool tsync_proto_is_supported(const char *proto_name); @@ -456,8 +467,8 @@ tracecmd_tsync_with_guest(unsigned long long trace_id, int loop_interval, int guest_cpus, const char *proto_name, const char *clock); int tracecmd_tsync_with_guest_stop(struct tracecmd_time_sync *tsync); int tracecmd_tsync_get_offsets(struct tracecmd_time_sync *tsync, int cpu, - int *count, long long **ts, - long long **offsets, long long **scalings); + struct tracecmd_ts_corrections *offsets); +int tracecmd_tsync_get_proto_flags(struct tracecmd_time_sync *tsync, unsigned int *flags); int tracecmd_tsync_get_session_params(struct tracecmd_time_sync *tsync, char **selected_proto, unsigned int *tsync_port); @@ -465,6 +476,9 @@ void tracecmd_tsync_free(struct tracecmd_time_sync *tsync); int tracecmd_write_guest_time_shift(struct tracecmd_output *handle, struct tracecmd_time_sync *tsync); +unsigned long long tracecmd_guest_ts_calc(unsigned long long ts, + struct tracecmd_ts_corrections *tsync, int flags); + /* --- Plugin handling --- */ extern struct tep_plugin_option trace_ftrace_options[]; diff --git a/lib/trace-cmd/trace-input.c b/lib/trace-cmd/trace-input.c index b17b36e0..974879e8 100644 --- a/lib/trace-cmd/trace-input.c +++ b/lib/trace-cmd/trace-input.c @@ -78,12 +78,6 @@ struct input_buffer_instance { size_t offset; }; -struct ts_offset_sample { - long long time; - long long offset; - long long scaling; -}; - struct guest_trace_info { struct guest_trace_info *next; char *name; @@ -92,19 +86,12 @@ struct guest_trace_info { int *cpu_pid; }; -struct timesync_offsets { - int ts_samples_count; - struct ts_offset_sample *ts_samples; -}; - struct host_trace_info { - unsigned long long peer_trace_id; - unsigned int flags; - bool sync_enable; - int ts_samples_count; - struct ts_offset_sample *ts_samples; - int cpu_count; - struct timesync_offsets *ts_offsets; + unsigned long long peer_trace_id; + unsigned int flags; + bool sync_enable; + int cpu_count; + struct tracecmd_ts_corrections *ts_offsets; }; struct tsc2nsec { @@ -1227,81 +1214,6 @@ static unsigned long long mul_u64_u32_shr(unsigned long long a, return ret; } -static inline unsigned long long -timestamp_correction_calc(unsigned long long ts, unsigned int flags, - struct ts_offset_sample *min, - struct ts_offset_sample *max) -{ - long long scaling; - long long tscor; - - if (flags & TRACECMD_TSYNC_FLAG_INTERPOLATE) { - long long delta = max->time - min->time; - long long offset = ((long long)ts - min->time) * - (max->offset - min->offset); - - scaling = (min->scaling + max->scaling) / 2; - tscor = min->offset + (offset + delta / 2) / delta; - - } else { - scaling = min->scaling; - tscor = min->offset; - } - - ts *= scaling; - if (tscor < 0) - return ts - llabs(tscor); - - return ts + tscor; -} - -static unsigned long long timestamp_host_sync(unsigned long long ts, int cpu, - struct tracecmd_input *handle) -{ - struct timesync_offsets *tsync; - int min, mid, max; - - if (cpu >= handle->host.cpu_count) - return ts; - tsync = &handle->host.ts_offsets[cpu]; - - /* We have one sample, nothing to calc here */ - if (tsync->ts_samples_count == 1) - return ts + tsync->ts_samples[0].offset; - - /* We have two samples, nothing to search here */ - if (tsync->ts_samples_count == 2) - return timestamp_correction_calc(ts, handle->host.flags, - &tsync->ts_samples[0], - &tsync->ts_samples[1]); - - /* We have more than two samples */ - if (ts <= tsync->ts_samples[0].time) - return timestamp_correction_calc(ts, handle->host.flags, - &tsync->ts_samples[0], - &tsync->ts_samples[1]); - else if (ts >= tsync->ts_samples[tsync->ts_samples_count-1].time) - return timestamp_correction_calc(ts, handle->host.flags, - &tsync->ts_samples[tsync->ts_samples_count-2], - &tsync->ts_samples[tsync->ts_samples_count-1]); - min = 0; - max = tsync->ts_samples_count-1; - mid = (min + max)/2; - while (min <= max) { - if (ts < tsync->ts_samples[mid].time) - max = mid - 1; - else if (ts > tsync->ts_samples[mid].time) - min = mid + 1; - else - break; - mid = (min + max)/2; - } - - return timestamp_correction_calc(ts, handle->host.flags, - &tsync->ts_samples[mid], - &tsync->ts_samples[mid+1]); -} - static unsigned long long timestamp_calc(unsigned long long ts, int cpu, struct tracecmd_input *handle) { @@ -1310,8 +1222,8 @@ static unsigned long long timestamp_calc(unsigned long long ts, int cpu, return ts; /* Guest trace file, sync with host timestamps */ - if (handle->host.sync_enable) - ts = timestamp_host_sync(ts, cpu, handle); + if (handle->host.sync_enable && cpu < handle->host.cpu_count) + ts = tracecmd_guest_ts_calc(ts, &handle->host.ts_offsets[cpu], handle->host.flags); if (handle->ts2secs) { /* user specified clock frequency */ @@ -2329,7 +2241,7 @@ static int tsync_offset_cmp(const void *a, const void *b) } while (0) static int tsync_offset_load(struct tep_handle *tep, - struct timesync_offsets *ts_offsets, char *buf, int size) + struct tracecmd_ts_corrections *ts_offsets, char *buf, int size) { int start_size = size; int i, j; @@ -2357,7 +2269,7 @@ static int tsync_cpu_offsets_load(struct tracecmd_input *handle, char *buf, int safe_read(handle->host.cpu_count, 4); handle->host.ts_offsets = calloc(handle->host.cpu_count, - sizeof(struct timesync_offsets)); + sizeof(struct tracecmd_ts_corrections)); if (!handle->host.ts_offsets) return -ENOMEM; for (i = 0; i < handle->host.cpu_count; i++) { diff --git a/lib/trace-cmd/trace-timesync.c b/lib/trace-cmd/trace-timesync.c index 19ca19d7..791a0964 100644 --- a/lib/trace-cmd/trace-timesync.c +++ b/lib/trace-cmd/trace-timesync.c @@ -133,36 +133,101 @@ bool __hidden tsync_proto_is_supported(const char *proto_name) * * @tsync: Pointer to time sync context * @cpu: CPU for which to get the calculated offsets - * @count: Returns the number of calculated time offsets - * @ts: Array of size @count containing timestamps of callculated offsets - * @offsets: array of size @count, containing offsets for each timestamp - * @scalings: array of size @count, containing scaling ratios for each timestamp + * @offsets: Returns the calculated timestamp offsets for the given @cpu * * Retuns -1 in case of an error, or 0 otherwise */ int tracecmd_tsync_get_offsets(struct tracecmd_time_sync *tsync, int cpu, - int *count, long long **ts, - long long **offsets, long long **scalings) + struct tracecmd_ts_corrections *offsets) { struct clock_sync_context *tsync_context; + int i; if (!tsync || !tsync->context) return -1; tsync_context = (struct clock_sync_context *)tsync->context; if (cpu >= tsync_context->cpu_count || !tsync_context->offsets) return -1; - if (count) - *count = tsync_context->offsets[cpu].sync_count; - if (ts) - *ts = tsync_context->offsets[cpu].sync_ts; - if (offsets) - *offsets = tsync_context->offsets[cpu].sync_offsets; - if (scalings) - *scalings = tsync_context->offsets[cpu].sync_scalings; + if (offsets) { + offsets->ts_samples = calloc(tsync_context->offsets[cpu].sync_count, + sizeof(struct ts_offset_sample)); + if (!offsets->ts_samples) + return -1; + offsets->ts_samples_count = tsync_context->offsets[cpu].sync_count; + for (i = 0; i < offsets->ts_samples_count; i++) { + offsets->ts_samples[i].time = tsync_context->offsets[cpu].sync_ts[i]; + offsets->ts_samples[i].offset = tsync_context->offsets[cpu].sync_offsets[i]; + offsets->ts_samples[i].scaling = tsync_context->offsets[cpu].sync_scalings[i]; + } + } return 0; } +static inline unsigned long long correction_calc(unsigned long long ts, unsigned int flags, + struct ts_offset_sample *min, + struct ts_offset_sample *max) +{ + long long scaling; + long long tscor; + + if (flags & TRACECMD_TSYNC_FLAG_INTERPOLATE) { + long long delta = max->time - min->time; + long long offset = ((long long)ts - min->time) * + (max->offset - min->offset); + + scaling = (min->scaling + max->scaling) / 2; + tscor = min->offset + (offset + delta / 2) / delta; + + } else { + scaling = min->scaling; + tscor = min->offset; + } + + ts *= scaling; + if (tscor < 0) + return ts - llabs(tscor); + + return ts + tscor; +} + + +unsigned long long tracecmd_guest_ts_calc(unsigned long long ts, + struct tracecmd_ts_corrections *tsync, int flags) +{ + int min, mid, max; + + /* We have one sample, nothing to calc here */ + if (tsync->ts_samples_count == 1) + return ts + tsync->ts_samples[0].offset; + + /* We have two samples, nothing to search here */ + if (tsync->ts_samples_count == 2) + return correction_calc(ts, flags, &tsync->ts_samples[0], &tsync->ts_samples[1]); + + /* We have more than two samples */ + if (ts <= tsync->ts_samples[0].time) + return correction_calc(ts, flags, &tsync->ts_samples[0], &tsync->ts_samples[1]); + else if (ts >= tsync->ts_samples[tsync->ts_samples_count-1].time) + return correction_calc(ts, flags, + &tsync->ts_samples[tsync->ts_samples_count-2], + &tsync->ts_samples[tsync->ts_samples_count-1]); + min = 0; + max = tsync->ts_samples_count-1; + mid = (min + max)/2; + while (min <= max) { + if (ts < tsync->ts_samples[mid].time) + max = mid - 1; + else if (ts > tsync->ts_samples[mid].time) + min = mid + 1; + else + break; + mid = (min + max)/2; + } + + return correction_calc(ts, flags, &tsync->ts_samples[mid], &tsync->ts_samples[mid+1]); +} + /** * tsync_get_proto_flags - Get protocol flags * @@ -171,8 +236,7 @@ int tracecmd_tsync_get_offsets(struct tracecmd_time_sync *tsync, int cpu, * * Retuns -1 in case of an error, or 0 otherwise */ -static int tsync_get_proto_flags(struct tracecmd_time_sync *tsync, - unsigned int *flags) +int tracecmd_tsync_get_proto_flags(struct tracecmd_time_sync *tsync, unsigned int *flags) { struct tsync_proto *protocol; @@ -924,6 +988,7 @@ error: int tracecmd_write_guest_time_shift(struct tracecmd_output *handle, struct tracecmd_time_sync *tsync) { + struct clock_sync_context *tsync_context; struct iovec *vector = NULL; unsigned int flags; long long *scalings = NULL; @@ -934,13 +999,15 @@ int tracecmd_write_guest_time_shift(struct tracecmd_output *handle, int i, j; int ret = -1; - if (!tsync->vcpu_count) + if (!tsync || !tsync->context || !tsync->vcpu_count) return -1; + tsync_context = (struct clock_sync_context *)tsync->context; + vcount = 3 + (4 * tsync->vcpu_count); vector = calloc(vcount, sizeof(struct iovec)); if (!vector) return -1; - ret = tsync_get_proto_flags(tsync, &flags); + ret = tracecmd_tsync_get_proto_flags(tsync, &flags); if (ret < 0) goto out; @@ -952,11 +1019,13 @@ int tracecmd_write_guest_time_shift(struct tracecmd_output *handle, vector[j].iov_len = 4; vector[j++].iov_base = &tsync->vcpu_count; for (i = 0; i < tsync->vcpu_count; i++) { - if (j >= vcount) + if (j >= vcount || i >= tsync_context->cpu_count) break; - ret = tracecmd_tsync_get_offsets(tsync, i, &count, - &ts, &offsets, &scalings); - if (ret < 0 || !count || !ts || !offsets || !scalings) + count = tsync_context->offsets[i].sync_count; + ts = tsync_context->offsets[i].sync_ts; + offsets = tsync_context->offsets[i].sync_offsets; + scalings = tsync_context->offsets[i].sync_scalings; + if (!count || !ts || !offsets || !scalings) break; vector[j].iov_len = 4; vector[j++].iov_base = &count; From patchwork Fri Apr 16 10:34:08 2021 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: "Tzvetomir Stoyanov (VMware)" X-Patchwork-Id: 12207379 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-15.7 required=3.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID,DKIM_VALID_AU,FREEMAIL_FORGED_FROMDOMAIN,FREEMAIL_FROM, HEADER_FROM_DIFFERENT_DOMAINS,INCLUDES_CR_TRAILER,INCLUDES_PATCH, MAILING_LIST_MULTI,SPF_HELO_NONE,SPF_PASS,USER_AGENT_GIT autolearn=ham autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id 9E6F1C43460 for ; Fri, 16 Apr 2021 10:34:16 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by mail.kernel.org (Postfix) with ESMTP id 73B6061166 for ; Fri, 16 Apr 2021 10:34:16 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S239981AbhDPKej (ORCPT ); Fri, 16 Apr 2021 06:34:39 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:47342 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S235193AbhDPKej (ORCPT ); Fri, 16 Apr 2021 06:34:39 -0400 Received: from mail-wr1-x435.google.com (mail-wr1-x435.google.com [IPv6:2a00:1450:4864:20::435]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 76B92C061756 for ; Fri, 16 Apr 2021 03:34:14 -0700 (PDT) Received: by mail-wr1-x435.google.com with SMTP id 12so26213002wrz.7 for ; Fri, 16 Apr 2021 03:34:14 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=from:to:cc:subject:date:message-id:in-reply-to:references :mime-version:content-transfer-encoding; bh=gUodvn4gT7Nvx4P5LWgrs3io/c+FH7XPpUCLhsJ+bak=; b=flnFpW7GLOyt/In3+jY8oKwTbOtE0AvUib3sBRyEOc9fBD3ucrH+SfrOaDy+jWpLi+ IQDiZeIT9KAVosUHTCu160L2LNg2kaaur8QTn1CErxTK+alawQf26uuHr83AN1XtCvqH T6yOOE4Ti4Ub+nNCAnz0Cg/MRqOtw49rkhNRPjroM3TJrAL9AQCaOstcgRrRMfmgI07L XMtQKg8HtmLkrX9jFcDvTEf8pIL9eqyCRzJs3koOTTK9L9mhpv1qOwGf7zMxkhj4MrsY waJ4CF9EtQoZfdxOrIX2XaToM2t7HbJysrCE2Q2+lwgJZVS9pO9DOh1JKWbpCtpR/uQC O+Yw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:from:to:cc:subject:date:message-id:in-reply-to :references:mime-version:content-transfer-encoding; bh=gUodvn4gT7Nvx4P5LWgrs3io/c+FH7XPpUCLhsJ+bak=; b=IxXmPt8VMfnTYzIF2srGgv2kkvRH9Lbrzc6Rko4a2yJJfMZ33YqbdEUfAl/HYyc+5r A9+4vZC36GXTuOzwu04LpPVsoJHwGGiyk2y3dW4t/HrnsvxJL4NQAZUw7b0X1bXWWD4e ZMreS83SSBKH3NAwkKqUi7osjNEEX3swbVXaOXClOwEFOHPGKV23uUW1M983r/hCvR6J X6NVnsEWC+yHiMOAMSGETqb7mstXsVzpi0+ryvQ2LpRGt6RlqGOG7FNYdwcV1UbJBqgd TBWsRln5u1QK7HfkbemR/xzbY/vdKxr8WlO2w2oO6xcADp3ecEjcLjXGw8Qt6ESKf1a+ fTHQ== X-Gm-Message-State: AOAM5305WY9cdil4tGm2k+fB9SoFychEfda1c0LgKLKNkp68D+Yrzw/O cczrU35TBugjFt3Oa2uwBQeM2LtdRAvlOA== X-Google-Smtp-Source: ABdhPJzk2YzNbvLRM1B12JJ+t1WMB0Qi0vmXnsv+b+UbEZXEdGyT1CirWx3lLoBf8fz6W8FmVqo/2g== X-Received: by 2002:a05:6000:a:: with SMTP id h10mr8289662wrx.297.1618569253285; Fri, 16 Apr 2021 03:34:13 -0700 (PDT) Received: from oberon.zico.biz ([83.222.187.186]) by smtp.gmail.com with ESMTPSA id v8sm9652139wrt.71.2021.04.16.03.34.12 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Fri, 16 Apr 2021 03:34:12 -0700 (PDT) From: "Tzvetomir Stoyanov (VMware)" To: rostedt@goodmis.org Cc: linux-trace-devel@vger.kernel.org Subject: [PATCH v2 2/3] trace-cmd library: Add check before applying tsc2nsec offset Date: Fri, 16 Apr 2021 13:34:08 +0300 Message-Id: <20210416103409.24597-3-tz.stoyanov@gmail.com> X-Mailer: git-send-email 2.30.2 In-Reply-To: <20210416103409.24597-1-tz.stoyanov@gmail.com> References: <20210416103409.24597-1-tz.stoyanov@gmail.com> MIME-Version: 1.0 Precedence: bulk List-ID: X-Mailing-List: linux-trace-devel@vger.kernel.org When converting TSC timestamps to nanoseconds, an offset is used. That offset is subtracted from each TSC timestamp, before the conversion. However, if the timestamp is lower that the offset this causes an overflow, as both timestamp and offset are unsigned long integers. A check is added to verify the subtraction will not cause an overflow. In case of an overflow, the timestamp is set to 0 and a warning message is printed. Signed-off-by: Tzvetomir Stoyanov (VMware) --- lib/trace-cmd/trace-input.c | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/lib/trace-cmd/trace-input.c b/lib/trace-cmd/trace-input.c index 974879e8..991abd5f 100644 --- a/lib/trace-cmd/trace-input.c +++ b/lib/trace-cmd/trace-input.c @@ -1230,8 +1230,14 @@ static unsigned long long timestamp_calc(unsigned long long ts, int cpu, ts *= handle->ts2secs; } else if (handle->tsc_calc.mult) { /* auto calculated TSC clock frequency */ - ts -= handle->tsc_calc.offset; - ts = mul_u64_u32_shr(ts, handle->tsc_calc.mult, handle->tsc_calc.shift); + if (ts > handle->tsc_calc.offset) { + ts -= handle->tsc_calc.offset; + ts = mul_u64_u32_shr(ts, handle->tsc_calc.mult, handle->tsc_calc.shift); + } else { + tracecmd_warning("Timestamp $llu is before the initial offset %llu, set it to 0", + ts, handle->tsc_calc.offset); + ts = 0; + } } /* User specified time offset with --ts-offset or --date options */ From patchwork Fri Apr 16 10:34:09 2021 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: "Tzvetomir Stoyanov (VMware)" X-Patchwork-Id: 12207383 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-15.7 required=3.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID,DKIM_VALID_AU,FREEMAIL_FORGED_FROMDOMAIN,FREEMAIL_FROM, HEADER_FROM_DIFFERENT_DOMAINS,INCLUDES_CR_TRAILER,INCLUDES_PATCH, MAILING_LIST_MULTI,SPF_HELO_NONE,SPF_PASS,USER_AGENT_GIT autolearn=ham autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id 88AABC433B4 for ; Fri, 16 Apr 2021 10:34:18 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by mail.kernel.org (Postfix) with ESMTP id 6BDCF61073 for ; Fri, 16 Apr 2021 10:34:18 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S235193AbhDPKem (ORCPT ); Fri, 16 Apr 2021 06:34:42 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:47346 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S240007AbhDPKel (ORCPT ); Fri, 16 Apr 2021 06:34:41 -0400 Received: from mail-wr1-x42a.google.com (mail-wr1-x42a.google.com [IPv6:2a00:1450:4864:20::42a]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 75444C061756 for ; Fri, 16 Apr 2021 03:34:15 -0700 (PDT) Received: by mail-wr1-x42a.google.com with SMTP id g9so10176037wrx.0 for ; Fri, 16 Apr 2021 03:34:15 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=from:to:cc:subject:date:message-id:in-reply-to:references :mime-version:content-transfer-encoding; bh=o6r6K3NRWZE89fABpGKkl6juSjH9qaNs6FdwgA1CtqQ=; b=X9SjI2ho50GK2ABBnJudj2nksR+KzquctAeGsSuDCSFk4dtJBq9YwNYpCcKnoGZC4X E2hE4maHVhzCzmiYL0UOSym94bwvMvg83tlNT0NDC9xGjRXUsuUrxJ7zc37L3YnCWSvG IrQsLjjEU8V/vFF7MH/fIXLackhkxp/q2MBUpymGaBMnOjKgDzqxLi9JtdFx4pS3kdbn NoXfTXPT85CL+f/dR5HhcGKXgR+nkp0UfhJY41BWWZ5TnAMYKYp/Coas3HBLCPvMaHSU 3GwrWrVTrVVfSw7ouiFD56k+kNwyHP3fS5gZUL+VQrwReQjsoPXBMh8euHT5nvM2TUm4 dpKw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:from:to:cc:subject:date:message-id:in-reply-to :references:mime-version:content-transfer-encoding; bh=o6r6K3NRWZE89fABpGKkl6juSjH9qaNs6FdwgA1CtqQ=; b=E568rupl0pbfT+FlzJG5wMGmjjcggSBwacp2xDeNAh/UxwUFCZWxTQfoSjxDE0B2KR TS2XcD6def0cc436eLybn6s16T5qvG1eyYhYCsEaYMPBEFnmbFaE2oJOgijEKxrzQ8xr dlqb9UyX5x/Wp9SWVcMdikJ3uKZn379ainIIymrEuyOPwsJSHFEJdApSsoqa8ptWCfm5 jO16zQQyh72QCgJ0+EB4wcTxWziy+UPUVD6JpKMWuEMgn2pVKPU3eWUYspz3gzwzbsKj W1N4mynftf24zBva/5+6qn6815juqvaED8qVYtZ/C1CxeH9SIbHZliLtQ1OTkA/yVtxV hU/Q== X-Gm-Message-State: AOAM531ww1f0mL/PIy0veP3FoHVI8oMIPZNctX0U37IpQ2f4vrtdmczJ j+C/RqD069KWDf6rKYPYH0w= X-Google-Smtp-Source: ABdhPJz10L8JK1rYf13d6IU1YxHFW03k7qqGuTeJze5tUVaR2/hTxI+sTV1T/Tlq8URrTo8I2sDA7Q== X-Received: by 2002:a05:6000:1816:: with SMTP id m22mr8427919wrh.260.1618569254206; Fri, 16 Apr 2021 03:34:14 -0700 (PDT) Received: from oberon.zico.biz ([83.222.187.186]) by smtp.gmail.com with ESMTPSA id v8sm9652139wrt.71.2021.04.16.03.34.13 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Fri, 16 Apr 2021 03:34:13 -0700 (PDT) From: "Tzvetomir Stoyanov (VMware)" To: rostedt@goodmis.org Cc: linux-trace-devel@vger.kernel.org Subject: [PATCH v2 3/3] trace-cmd: Get the timestamp of the first recorded event as TSC offset Date: Fri, 16 Apr 2021 13:34:09 +0300 Message-Id: <20210416103409.24597-4-tz.stoyanov@gmail.com> X-Mailer: git-send-email 2.30.2 In-Reply-To: <20210416103409.24597-1-tz.stoyanov@gmail.com> References: <20210416103409.24597-1-tz.stoyanov@gmail.com> MIME-Version: 1.0 Precedence: bulk List-ID: X-Mailing-List: linux-trace-devel@vger.kernel.org When converting TSC timestamps to nanoseconds, an offset is used. That offset is subtracted from each TSC timestamp, before the conversion. At the end of the trace, the lowest recorded TSC timestamp is selected as TSC offset, that will be used for tsc2nsec conversion. Signed-off-by: Tzvetomir Stoyanov (VMware) --- tracecmd/include/trace-local.h | 1 + tracecmd/trace-record.c | 152 ++++++++++++++++++++++++++------- 2 files changed, 122 insertions(+), 31 deletions(-) diff --git a/tracecmd/include/trace-local.h b/tracecmd/include/trace-local.h index 1218de12..d504ea14 100644 --- a/tracecmd/include/trace-local.h +++ b/tracecmd/include/trace-local.h @@ -213,6 +213,7 @@ struct buffer_instance { char *name; struct tracefs_instance *tracefs; unsigned long long trace_id; + unsigned long long first_ts; char *cpumask; char *output_file; struct event_list *events; diff --git a/tracecmd/trace-record.c b/tracecmd/trace-record.c index fd03a605..b78b8af9 100644 --- a/tracecmd/trace-record.c +++ b/tracecmd/trace-record.c @@ -40,6 +40,7 @@ #ifdef VSOCK #include #endif +#include #include "tracefs.h" #include "version.h" @@ -685,34 +686,6 @@ add_tsc2nsec(struct tracecmd_output *handle, struct tsc_nsec *tsc2nsec) tracecmd_add_option_v(handle, TRACECMD_OPTION_TSC2NSEC, vector, 3); } -static void host_tsync_complete(struct common_record_context *ctx, - struct buffer_instance *instance) -{ - struct tracecmd_output *handle = NULL; - int fd = -1; - int ret; - - ret = tracecmd_tsync_with_guest_stop(instance->tsync); - if (!ret) { - fd = open(instance->output_file, O_RDWR); - if (fd < 0) - die("error opening %s", instance->output_file); - handle = tracecmd_get_output_handle_fd(fd); - if (!handle) - die("cannot create output handle"); - - if (ctx->tsc2nsec.mult) - add_tsc2nsec(handle, &ctx->tsc2nsec); - - tracecmd_write_guest_time_shift(handle, instance->tsync); - tracecmd_append_options(handle); - tracecmd_output_close(handle); - } - - tracecmd_tsync_free(instance->tsync); - instance->tsync = NULL; -} - static void tell_guests_to_stop(struct common_record_context *ctx) { struct buffer_instance *instance; @@ -725,7 +698,7 @@ static void tell_guests_to_stop(struct common_record_context *ctx) for_all_instances(instance) { if (is_guest(instance)) - host_tsync_complete(ctx, instance); + tracecmd_tsync_with_guest_stop(instance->tsync); } /* Wait for guests to acknowledge */ @@ -4183,7 +4156,105 @@ static void add_options(struct tracecmd_output *handle, struct common_record_con free(clocks); } -static void write_guest_file(struct buffer_instance *instance) +int get_first_ts(struct kbuffer *kbuf, char *page, int psize, const char *file, unsigned long long *ts) +{ + int rsize; + int ret = -1; + char *data; + int fd; + + fd = open(file, O_RDONLY); + if (fd < 0) + return -1; + + rsize = read(fd, page, psize); + if (rsize <= 0) + goto error; + + kbuffer_load_subbuffer(kbuf, page); + if (kbuffer_subbuffer_size(kbuf) > rsize) + goto error; + + data = kbuffer_read_event(kbuf, ts); + if (!data) + goto error; + + ret = 0; +error: + close(fd); + return ret; +} + +int get_first_ts_instance(struct buffer_instance *instance) +{ + struct tracecmd_ts_corrections corrections; + unsigned long long first_ts = 0; + enum kbuffer_long_size long_size; + enum kbuffer_endian endian; + struct kbuffer *kbuf = NULL; + unsigned long long ts; + unsigned int flags; + int first_ts_cpu; + bool first = true; + char *page; + char *file; + int psize; + int ret; + int i; + + psize = getpagesize(); + page = calloc(1, psize); + if (!page) + return -1; + + if (tracecmd_host_bigendian()) + endian = KBUFFER_ENDIAN_BIG; + else + endian = KBUFFER_ENDIAN_LITTLE; + if (sizeof(long) == 8) + long_size = KBUFFER_LSIZE_8; + else + long_size = KBUFFER_LSIZE_4; + + kbuf = kbuffer_alloc(long_size, endian); + if (!kbuf) + goto out; + + for (i = 0; i < instance->cpu_count; i++) { + file = get_temp_file(instance, i); + if (!file) + continue; + if (!get_first_ts(kbuf, page, psize, file, &ts)) { + if (first || ts < first_ts) { + first_ts = ts; + first_ts_cpu = i; + first = false; + } + } + put_temp_file(file); + } + if (!first) { + if (is_guest(instance)) { + ret = tracecmd_tsync_get_proto_flags(instance->tsync, &flags); + if (ret) + goto out; + ret = tracecmd_tsync_get_offsets(instance->tsync, first_ts_cpu, &corrections); + if (ret) + goto out; + instance->first_ts = tracecmd_guest_ts_calc(first_ts, &corrections, flags); + free(corrections.ts_samples); + } else { + instance->first_ts = first_ts; + } + } + +out: + kbuffer_free(kbuf); + free(page); + return first ? -1 : 0; +} + +static void write_guest_file(struct common_record_context *ctx, struct buffer_instance *instance) { struct tracecmd_output *handle; int cpu_count = instance->cpu_count; @@ -4201,6 +4272,12 @@ static void write_guest_file(struct buffer_instance *instance) die("error writing to %s", file); if (instance->flags & BUFFER_FL_TSC2NSEC) tracecmd_set_out_clock(handle, TSCNSEC_CLOCK); + + if (ctx->tsc2nsec.mult) + add_tsc2nsec(handle, &ctx->tsc2nsec); + tracecmd_write_guest_time_shift(handle, instance->tsync); + tracecmd_append_options(handle); + temp_files = malloc(sizeof(*temp_files) * cpu_count); if (!temp_files) die("failed to allocate temp_files for %d cpus", @@ -4219,6 +4296,9 @@ static void write_guest_file(struct buffer_instance *instance) for (i = 0; i < cpu_count; i++) put_temp_file(temp_files[i]); free(temp_files); + + tracecmd_tsync_free(instance->tsync); + instance->tsync = NULL; } static void record_data(struct common_record_context *ctx) @@ -4229,11 +4309,21 @@ static void record_data(struct common_record_context *ctx) bool local = false; int max_cpu_count = local_cpu_count; char **temp_files; + int ret; int i; + if (ctx->tsc2nsec.mult) { + for_all_instances(instance) { + ret = get_first_ts_instance(instance); + if (!ret && + (!ctx->tsc2nsec.offset || ctx->tsc2nsec.offset > instance->first_ts)) + ctx->tsc2nsec.offset = instance->first_ts; + } + } + for_all_instances(instance) { if (is_guest(instance)) - write_guest_file(instance); + write_guest_file(ctx, instance); else if (host && instance->msg_handle) finish_network(instance->msg_handle); else