From patchwork Mon Mar 23 13:37:00 2020 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Norbert Manthey X-Patchwork-Id: 11452989 Return-Path: Received: from mail.kernel.org (pdx-korg-mail-1.web.codeaurora.org [172.30.200.123]) by pdx-korg-patchwork-2.web.codeaurora.org (Postfix) with ESMTP id DDAA21667 for ; Mon, 23 Mar 2020 13:40:26 +0000 (UTC) Received: from lists.xenproject.org (lists.xenproject.org [192.237.175.120]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by mail.kernel.org (Postfix) with ESMTPS id B7F5820735 for ; Mon, 23 Mar 2020 13:40:26 +0000 (UTC) Authentication-Results: mail.kernel.org; dkim=fail reason="signature verification failed" (1024-bit key) header.d=amazon.de header.i=@amazon.de header.b="iem70URK" DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org B7F5820735 Authentication-Results: mail.kernel.org; dmarc=fail (p=quarantine dis=none) header.from=amazon.de Authentication-Results: mail.kernel.org; spf=pass smtp.mailfrom=xen-devel-bounces@lists.xenproject.org Received: from localhost ([127.0.0.1] helo=lists.xenproject.org) by lists.xenproject.org with esmtp (Exim 4.89) (envelope-from ) id 1jGNI5-0000if-B7; Mon, 23 Mar 2020 13:38:53 +0000 Received: from us1-rack-iad1.inumbo.com ([172.99.69.81]) by lists.xenproject.org with esmtp (Exim 4.89) (envelope-from ) id 1jGNI3-0000iD-Vn for xen-devel@lists.xenproject.org; Mon, 23 Mar 2020 13:38:52 +0000 X-Inumbo-ID: a1b85a8c-6d0b-11ea-a6c1-bc764e2007e4 Received: from smtp-fw-6001.amazon.com (unknown [52.95.48.154]) by us1-rack-iad1.inumbo.com (Halon) with ESMTPS id a1b85a8c-6d0b-11ea-a6c1-bc764e2007e4; Mon, 23 Mar 2020 13:38:51 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=amazon.de; i=@amazon.de; q=dns/txt; s=amazon201209; t=1584970731; x=1616506731; h=from:to:cc:subject:date:message-id:in-reply-to: references:mime-version; bh=z8dz4h3mXSy6ZGzFUZMYSMXvNQuf3lLok71VJ3FGFcY=; b=iem70URKFdKotb6tO9x7kVxrh1HB1WydP99qTU+NrVzheg5IyNkTtN5I aSTQtuFOg4Nmn37ymwi3SHa/VheZ9R/5LdVg8M4SzPz1Kx/3M0cRf7zUS R+hQqRLfV1/Ce+dvyA9P0TXOpJJrjgxuv+QHegkeN5pLl0a5Nay6mhm9E 0=; IronPort-SDR: EROhmyWDUx4u3ocGRSjK9aiuFqfgYKmlV7Dc3n43iYLwwMMAws6EKWk623Utqsx8KWG/wGHwcc CB/a75aD9tXg== X-IronPort-AV: E=Sophos;i="5.72,296,1580774400"; d="scan'208";a="23770896" Received: from iad12-co-svc-p1-lb1-vlan3.amazon.com (HELO email-inbound-relay-1d-2c665b5d.us-east-1.amazon.com) ([10.43.8.6]) by smtp-border-fw-out-6001.iad6.amazon.com with ESMTP; 23 Mar 2020 13:38:39 +0000 Received: from EX13MTAUEA002.ant.amazon.com (iad55-ws-svc-p15-lb9-vlan3.iad.amazon.com [10.40.159.166]) by email-inbound-relay-1d-2c665b5d.us-east-1.amazon.com (Postfix) with ESMTPS id 833F2A21A8; Mon, 23 Mar 2020 13:38:39 +0000 (UTC) Received: from EX13D05EUB003.ant.amazon.com (10.43.166.253) by EX13MTAUEA002.ant.amazon.com (10.43.61.77) with Microsoft SMTP Server (TLS) id 15.0.1236.3; Mon, 23 Mar 2020 13:38:39 +0000 Received: from EX13MTAUWC001.ant.amazon.com (10.43.162.135) by EX13D05EUB003.ant.amazon.com (10.43.166.253) with Microsoft SMTP Server (TLS) id 15.0.1497.2; Mon, 23 Mar 2020 13:38:38 +0000 Received: from u6fc700a6f3c650.ant.amazon.com (10.95.138.2) by mail-relay.amazon.com (10.43.162.232) with Microsoft SMTP Server id 15.0.1367.3 via Frontend Transport; Mon, 23 Mar 2020 13:38:35 +0000 From: Norbert Manthey To: Andrew Cooper , Date: Mon, 23 Mar 2020 14:37:00 +0100 Message-ID: <20200323133701.21728-4-nmanthey@amazon.de> X-Mailer: git-send-email 2.17.1 In-Reply-To: <20200323133701.21728-1-nmanthey@amazon.de> References: <20200323133701.21728-1-nmanthey@amazon.de> MIME-Version: 1.0 Precedence: Bulk Subject: [Xen-devel] [PATCH XTF benchmark v1 3/4] time: provide measurement template X-BeenThere: xen-devel@lists.xenproject.org X-Mailman-Version: 2.1.23 List-Id: Xen developer discussion List-Unsubscribe: , List-Post: List-Help: List-Subscribe: , Cc: Pawel Wieczorkiewicz , Norbert Manthey Errors-To: xen-devel-bounces@lists.xenproject.org Sender: "Xen-devel" The added function measure_performance allows to measure the run time of a function, by computing the average time it takes to call that function a given number of retries. The measured total time is returned in nano seconds. Furthermore, the value is printed via printk in a fixed format, to allow processing the output further. This format is, where average-time provides ns with ps granularity: perf test_name ns Signed-off-by: Norbert Manthey --- common/time.c | 76 ++++++++++++++++++++++++++++++++++++++++++++++ include/xtf/time.h | 15 +++++++++ 2 files changed, 91 insertions(+) diff --git a/common/time.c b/common/time.c --- a/common/time.c +++ b/common/time.c @@ -192,6 +192,82 @@ void msleep(uint64_t t) mspin_sleep(t); } +unsigned long cycles2nsec(uint64_t cycles) +{ + return scale_delta(cycles, + shared_info.vcpu_info[0].time.tsc_to_system_mul, + shared_info.vcpu_info[0].time.tsc_shift); +} + +unsigned long measure_performance(const char* test_name, + const char* function_name, + function_under_test_t call, + unsigned long measure_seconds, + unsigned long callibration_calls, + int print_times) +{ + unsigned long start, end; // time stamps for before and after the execution + unsigned long calibration_ns, total_measured_ns, avg_ns, avg_ps_fraction; + unsigned long counter; + unsigned long measure_calls; + int rc = 0; + + + /* Calibrate by measuring time for given amount of callibration calls*/ + printk("Calibrate %s by calling %lu times\n", function_name, + callibration_calls); + start = rdtscp(); + for(counter = 0; counter < callibration_calls; ++ counter) + { + rc = call(); + } + end = rdtscp(); + + /* Calculate the total number in nano seconds */ + calibration_ns = cycles2nsec(end - start); + + /* Calculate number of calls for about measure_seconds based on + (callibration_calls / calibration_ns) equals + (measure_calls / (measure_seconds * 1000 * 1000 * 1000)) */ + measure_calls = ((measure_seconds * 1000UL * 1000UL * 1000UL) + / calibration_ns) * callibration_calls; + + printk("Measure %s by calling %lu times\n", function_name, measure_calls); + + /* Perform all calls, measure start and end time */ + start = rdtscp(); + for(counter = 0; counter < measure_calls; ++ counter) + { + rc = call(); + } + end = rdtscp(); + + /* Calculate the total number in nano seconds */ + total_measured_ns = cycles2nsec(end - start); + avg_ns = total_measured_ns / measure_calls; + avg_ps_fraction = (total_measured_ns / (measure_calls/1000)) % 1000; + + if(print_times) + { + /* Show the result of the last query */ + printk("%s's last return value: %d\n", function_name, rc); + + /* Print average time and total time */ + printk("Avg %s call time: avg: %ld.%s%ld ns total: %ld ns\n", + function_name, avg_ns, + avg_ps_fraction < 10 ? "00" : (avg_ps_fraction < 100 ? "0" : ""), + avg_ps_fraction, total_measured_ns); + + /* Print performance value */ + printk("perf %s %ld.%s%ld ns\n", test_name, avg_ns, + avg_ps_fraction < 10 ? "00" : (avg_ps_fraction < 100 ? "0" : ""), + avg_ps_fraction); + } + + /* Return average run time in pico seconds */ + return avg_ns * 1000 + avg_ps_fraction; +} + /* * Local variables: * mode: C diff --git a/include/xtf/time.h b/include/xtf/time.h --- a/include/xtf/time.h +++ b/include/xtf/time.h @@ -53,6 +53,21 @@ int gettimeofday(struct timeval *tp); /* This returns the current epoch time */ #define NOW() current_time() +unsigned long cycles2nsec(uint64_t cycles); + +/* Signature of a function to be called for measurement */ +typedef int (*function_under_test_t)(void); + +/* Measure the time it takes to call the passed function. Measure for a given + amount of time after calibrating for a given amount of calls. Returns the + average run time of the measure call in pico seconds. */ +unsigned long measure_performance(const char* test_name, + const char* function_name, + function_under_test_t call, + unsigned long measure_seconds, + unsigned long callibration_calls, + int print_times); + #endif /* XTF_TIME_H */ /*