From patchwork Wed May 17 14:52:59 2017 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-Patchwork-Submitter: =?utf-8?q?Alex_Benn=C3=A9e?= X-Patchwork-Id: 99995 Delivered-To: patch@linaro.org Received: by 10.182.142.97 with SMTP id rv1csp254016obb; Wed, 17 May 2017 07:53:45 -0700 (PDT) X-Received: by 10.200.48.44 with SMTP id f41mr3274643qte.88.1495032825477; Wed, 17 May 2017 07:53:45 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1495032825; cv=none; d=google.com; s=arc-20160816; b=CXN8hS1py1JMlV4CKJ3J4LBceCpoUlDcZRESbMpJ1FpHkJSdlO7Xiygz09bE8uIayD 9VPSflCtxJGd5OXDa6WyX3D7/jmQf6/R39wxrHIKxB6FJ2TMI5u7pyeQ+Cm2HuwIsLV5 8sGdhc6PLaXfIF4p4Rt7G/T2nkIDx73PYpT/glhr48TODxQFcqPBOGXutZkBK252D+7K E5ubOOoqZE1AnkTumoDqmm2SqqS3oJxUWN64oLGEDzmfoKnFCcSsWKe7ACvq+0LDcNT+ 2GG9UqY67zIHRZfBsD441hnXHP3+wEqWNAwPl1zH2K5wpny1ovP7UClpJDc8+/9R7aTx s3ow== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=sender:errors-to:cc:list-subscribe:list-help:list-post:list-archive :list-unsubscribe:list-id:precedence:subject :content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:to:from:dkim-signature:arc-authentication-results; bh=zr8eaC1w14Cw1tsLDUZYCE/XYLWMKJGYH7RPzbyRiBQ=; b=keJwfUa+dNMZ0zr70R/tKNLen6RQScJYR5ewWSkcLi7kAOw5D8v1ANgSwucjL+OexL QbcrH55Y85V5sEGqSjWRAwYV5u8MGCKmpFZTPAmDiOH6H6IaWhYOvBHQHSMz/mMAdkqn td3KMFyzjzTfFOb50yg2AKkSCogHmudwz8tLqF0M7RwmqwVij1A376bADMwZyo/iCeWg NeH1rUQDQXnBCipnzpXTzhZtE98H77com7iuDJVrudk8SV2AFYtEYlG1rZGLR7BUZy47 hnK4irm8UUwEGWM9ceDupYMpULPGu05gneBNkgyyN2IYZGcMsNqsdHFoKAGYmfxeIfQb BRnw== ARC-Authentication-Results: i=1; mx.google.com; dkim=fail header.i=@linaro.org; spf=pass (google.com: domain of qemu-devel-bounces+patch=linaro.org@nongnu.org designates 2001:4830:134:3::11 as permitted sender) smtp.mailfrom=qemu-devel-bounces+patch=linaro.org@nongnu.org; dmarc=fail (p=NONE sp=NONE dis=NONE) header.from=linaro.org Return-Path: Received: from lists.gnu.org (lists.gnu.org. [2001:4830:134:3::11]) by mx.google.com with ESMTPS id t64si2385883qkt.145.2017.05.17.07.53.45 for (version=TLS1 cipher=AES128-SHA bits=128/128); Wed, 17 May 2017 07:53:45 -0700 (PDT) Received-SPF: pass (google.com: domain of qemu-devel-bounces+patch=linaro.org@nongnu.org designates 2001:4830:134:3::11 as permitted sender) client-ip=2001:4830:134:3::11; Authentication-Results: mx.google.com; dkim=fail header.i=@linaro.org; spf=pass (google.com: domain of qemu-devel-bounces+patch=linaro.org@nongnu.org designates 2001:4830:134:3::11 as permitted sender) smtp.mailfrom=qemu-devel-bounces+patch=linaro.org@nongnu.org; dmarc=fail (p=NONE sp=NONE dis=NONE) header.from=linaro.org Received: from localhost ([::1]:49377 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1dB0Ke-0002jv-Tm for patch@linaro.org; Wed, 17 May 2017 10:53:44 -0400 Received: from eggs.gnu.org ([2001:4830:134:3::10]:50780) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1dB0JB-0001qc-K0 for qemu-devel@nongnu.org; Wed, 17 May 2017 10:52:15 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1dB0JA-0004hH-Cr for qemu-devel@nongnu.org; Wed, 17 May 2017 10:52:13 -0400 Received: from mail-wr0-x22b.google.com ([2a00:1450:400c:c0c::22b]:33987) by eggs.gnu.org with esmtps (TLS1.0:RSA_AES_128_CBC_SHA1:16) (Exim 4.71) (envelope-from ) id 1dB0JA-0004gT-3T for qemu-devel@nongnu.org; Wed, 17 May 2017 10:52:12 -0400 Received: by mail-wr0-x22b.google.com with SMTP id l9so12462915wre.1 for ; Wed, 17 May 2017 07:52:11 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=linaro.org; s=google; h=from:to:cc:subject:date:message-id:in-reply-to:references :mime-version:content-transfer-encoding; bh=zr8eaC1w14Cw1tsLDUZYCE/XYLWMKJGYH7RPzbyRiBQ=; b=I/AVSdxStsN51eRIO2vsIOMeQCZeTVLw1kpFwPftxOEg2KFG7V4l6fp46dz86rQl3c fmPtzR4ZGp5DDFt8BBxUCKoOfZoEnfd7YQBGFwA+J5aVuAFDUIegnWQdbjaV44N+zOLs ookJyJVUlo78lQTRbM5aImBFe+pPtxCm5nlMY= 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=zr8eaC1w14Cw1tsLDUZYCE/XYLWMKJGYH7RPzbyRiBQ=; b=uNWcN+Jvi5pBkNK/NxmqqtFhz8ghLa3wk38x3++y8ZFD7sRHj7pl/xGKZkE3609ct2 +dLLnYfCCE0YYWUF/1llxLwph02zx4NkwW5MYwuZ6PMK+wcCbVvTi+Mp1vDg5MntDoQj zfM58DTPEprVRUTdSJUvpefTqgpYj1dd1/wMdR/K/Uj3G3soO4e9NAGfZGwkdHqNuecS 4CWyuRIM+DJAiDXYR9OlqEc71vpNmSHzs7Gycw4KkgMKDOyx7BFdeV3tkYpFjtaE5f96 DV5zRen4Adir1wAJy4k6nPMrGbFvMtGidDmXqjb5/eMstZl+TUznM6QfvBaLHVyVsifO OU9g== X-Gm-Message-State: AODbwcA0Am4Dn5SpGexsPTnLDvDr19UEJpyFeN42GKPXaJ5i/dTQKHxR jDfDFwDwCUeCqGgI X-Received: by 10.223.179.199 with SMTP id x7mr2898073wrd.72.1495032730881; Wed, 17 May 2017 07:52:10 -0700 (PDT) Received: from zen.linaro.local ([81.128.185.34]) by smtp.gmail.com with ESMTPSA id n27sm1530670wra.57.2017.05.17.07.52.04 (version=TLS1_2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Wed, 17 May 2017 07:52:08 -0700 (PDT) Received: from zen.linaroharston (localhost [127.0.0.1]) by zen.linaro.local (Postfix) with ESMTP id E7F7F3E08D5; Wed, 17 May 2017 15:52:59 +0100 (BST) From: =?utf-8?q?Alex_Benn=C3=A9e?= To: pbonzini@redhat.com, stefanha@redhat.com Date: Wed, 17 May 2017 15:52:59 +0100 Message-Id: <20170517145259.28979-7-alex.bennee@linaro.org> X-Mailer: git-send-email 2.11.0 In-Reply-To: <20170517145259.28979-1-alex.bennee@linaro.org> References: <20170517145259.28979-1-alex.bennee@linaro.org> MIME-Version: 1.0 X-detected-operating-system: by eggs.gnu.org: Genre and OS details not recognized. X-Received-From: 2a00:1450:400c:c0c::22b Subject: [Qemu-devel] [PATCH v2 6/6] new script/analyse-tlb-flushes-simpletrace.py X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.21 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: cota@braap.org, =?utf-8?q?Alex_Benn=C3=A9e?= , qemu-devel@nongnu.org Errors-To: qemu-devel-bounces+patch=linaro.org@nongnu.org Sender: "Qemu-devel" This is a simple helper script to extract TLB flush stats from the a simpletrace file and plot the results. Signed-off-by: Alex Bennée --- v2 - re-factored for new trace events - added time and latency graphs --- scripts/analyse-tlb-flushes-simpletrace.py | 144 +++++++++++++++++++++++++++++ 1 file changed, 144 insertions(+) create mode 100755 scripts/analyse-tlb-flushes-simpletrace.py -- 2.11.0 diff --git a/scripts/analyse-tlb-flushes-simpletrace.py b/scripts/analyse-tlb-flushes-simpletrace.py new file mode 100755 index 0000000000..03fab8c86b --- /dev/null +++ b/scripts/analyse-tlb-flushes-simpletrace.py @@ -0,0 +1,144 @@ +#!/usr/bin/env python +# -*- coding: utf-8 -*- +# +# Generate a simple graph of flushes over time +# +# Author: Alex Bennée +# +# analyzer = CpuTLBFlushAnalyser(4) +# simpletrace.process("../trace-events-all", "../trace-22464", analyzer) + +import os +import simpletrace +import argparse +import numpy as np +import matplotlib +# Force matplotlib to not use any Xwindows backend. +matplotlib.use('Agg') +import matplotlib.pyplot as plt + +class FlushType: + Self, Async, Synced = range(3) + +class CpuTLBFlushAnalyser(simpletrace.Analyzer): + "A simpletrace Analyser for extracting flush stats." + + def __init__(self, nvcpus): + self.flush_total = 0 + self.flush_all = 0 + self.nvcpus = nvcpus + self.vcpu_last = [[] for _ in range(nvcpus)] + self.flush_self = [] + self.flush_self_times = [] + self.flush_async = [] + self.flush_async_times = [] + self.flush_synced = [] + self.flush_synced_times = [] + self.flush_work = [] + + self.unmatched_work = [] + + def __save_queue(self, vcpu, record): + self.flush_total += 1 + # FIXME: don't seem to see -1 + if vcpu > 0x7fffffff: + self.flush_all += 1 + for i in range(0, self.nvcpus): + self.vcpu_last[i].append(record) + else: + self.vcpu_last[vcpu].append(record) + + def tlb_flush_self(self, timestamp, fn, vcpu): + self.__save_queue(vcpu, (timestamp[0], FlushType.Self)) + self.flush_self.append((timestamp[0], vcpu)) + + def tlb_flush_async_schedule(self, timestamp, fn, from_vcpu, to_vcpu): + self.__save_queue(to_vcpu, (timestamp[0], FlushType.Async, + to_vcpu, from_vcpu)) + self.flush_async.append((timestamp[0], to_vcpu)) + + def tlb_flush_synced_schedule(self, timestamp, fn, from_vcpu, to_vcpu): + self.__save_queue(to_vcpu, (timestamp[0], FlushType.Synced, + to_vcpu, from_vcpu)) + self.flush_synced.append((timestamp[0], to_vcpu)) + + def tlb_flush_work(self, timestamp, fn, vcpu): + "Check when it was queued and work out how long it took" + + if len(self.vcpu_last[vcpu]): + last = self.vcpu_last[vcpu].pop(0) + latency = timestamp[0] - last[0] + switcher = { + FlushType.Self: lambda a: a.flush_self_times.append(latency), + FlushType.Async: lambda a: a.flush_async_times.append(latency), + FlushType.Synced: lambda a: a.flush_synced_times.append(latency), + } + switcher.get(last[1])(self) + + self.flush_work.append((timestamp[0], vcpu)) + else: + self.unmatched_work.append((timestamp[0], vcpu, fn)) + + + + +def get_args(): + "Grab options" + parser = argparse.ArgumentParser() + parser.add_argument("--output", "-o", type=str, help="Render plot to file") + parser.add_argument("--vcpus", type=int, help="Number of vCPUS") + parser.add_argument("--graph", choices=['time', 'latency'], default='time') + parser.add_argument("events", type=str, help='trace file read from') + parser.add_argument("tracefile", type=str, help='trace file read from') + return parser.parse_args() + +def plot_time_series(time_data, label): + "Plot one timeseries, return star and end time limits" + counts = np.arange(0, len(time_data)) + times = [x[0] for x in time_data] + plt.plot(times, counts, label=label) + return (times[0],times[-1]) + + +if __name__ == '__main__': + args = get_args() + + # Gather data from the trace + analyzer = CpuTLBFlushAnalyser(args.vcpus) + + simpletrace.process(args.events, args.tracefile, analyzer) + + # Print some summary stats + print ("Flushes: self:%d async:%d synced:%d" % + ( len(analyzer.flush_self), + len(analyzer.flush_async), + len(analyzer.flush_synced))) + + if args.graph == 'time': + start_self, end_self = plot_time_series(analyzer.flush_self, "Self") + start_async, end_async = plot_time_series(analyzer.flush_async, "Async") + start_synced, end_synced = plot_time_series(analyzer.flush_synced, "Self") + + # start right at the edge + plt.xlim(xmin=min(start_self, start_async, start_synced)) + elif args.graph == 'latency': + + # Three subplots, the axes array is 1-d + + f, (ax_self, ax_async, ax_synced) = plt.subplots(3, sharex=True) + ax_self.set_title("Distribution") + + ax_self.hist(analyzer.flush_self_times, 10, normed=1, + facecolor='green', alpha=0.5) + ax_self.hist(analyzer.flush_async_times, 10, normed=1, + facecolor='blue', alpha=0.5) + ax_self.hist(analyzer.flush_synced_times, + 10, normed=1, + facecolor='red', alpha=0.5) + else: + raise ValueError("Bad graph type") + + if args.output: + plt.savefig(args.output) + else: + plt.show()