Received: by 2002:ad5:474a:0:0:0:0:0 with SMTP id i10csp3550051imu; Fri, 30 Nov 2018 02:07:14 -0800 (PST) X-Google-Smtp-Source: AFSGD/Vw9yQUo9DleF5ELtfTDvzJsWzirx/W4hDDyeah55dAga+5xJRZzK54JAmKnLkeVrb+Upwb X-Received: by 2002:a63:42c1:: with SMTP id p184mr4277898pga.202.1543572434136; Fri, 30 Nov 2018 02:07:14 -0800 (PST) ARC-Seal: i=1; a=rsa-sha256; t=1543572434; cv=none; d=google.com; s=arc-20160816; b=WvuNJzOSMF3xoBcZYYB4kCREK/GlfGb7Bq84zA0f+Ir4rJtlz4XeWZ6g9+yMQbMq8J /WanBaE2XHSs6tHzOi0xYDpXtXQmYApYT+F7QrnMs0mj09Wod8he2+Ue+xd6oHar+cwF vh/0BWEuiIan7ykDFgCvT3GkN/bzYtrwNh6TJBnaQxY6agEHNI8B+mh1x3cMS8MwBMoq RGO6iyXOKKqR8xBxh9dr+Tx6ZbJEZ2RMuF98UrmwmpsqztlZaX0JmIloW4ISPfegm+K2 KJzrUQcYIlBhUka3evx18JuBHQWIl4d8txQQp0T5lGZW7xOwmT/eV4ofYtdDwLNz9wLJ jdAA== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:sender:message-id:date:subject:cc:to:from :dkim-signature; bh=qMuVDKOBd0O55VlM4Kp3hwxT+oQFuIsRKiWVIynp1Xc=; b=YzBn289ZPJgrT6UfsXzFuIieav/5ktZNVlXKfVi+t7JjT7kchWTDn2eV8aKMxVhiLM y5ocD4fdUsEN2/m3/QKN39GnuUUFValXu9FaqjohmDtTobGnsN5l+RWSM3RcAI46OLiU DifVYmBc6BQS72OPF9SDUXL4y0qpUoaFPKfvdwEAUwFLekfcYMp7CJzCPWEyTg9QKf0Q um2urLG2Efu2gCL7GOpT6YpMdtrKtnqysSY3Qg6QU+m2coa+Bd5uxEkmDOu/KWACyMU+ KTwk32NMXYAvmEwfQeELNN5RlAftMbJ58Ok4XFk7Fzi9YytLXR5Jm7sV0Hdi9hPpLg/p zwgA== ARC-Authentication-Results: i=1; mx.google.com; dkim=pass header.i=@linaro.org header.s=google header.b=X2SZV7wU; spf=pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=linaro.org Return-Path: Received: from vger.kernel.org (vger.kernel.org. [209.132.180.67]) by mx.google.com with ESMTP id e4si4628831pgk.127.2018.11.30.02.06.58; Fri, 30 Nov 2018 02:07:14 -0800 (PST) Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67; Authentication-Results: mx.google.com; dkim=pass header.i=@linaro.org header.s=google header.b=X2SZV7wU; spf=pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=linaro.org Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1726640AbeK3VPI (ORCPT + 99 others); Fri, 30 Nov 2018 16:15:08 -0500 Received: from mail-wm1-f67.google.com ([209.85.128.67]:52002 "EHLO mail-wm1-f67.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1726557AbeK3VPI (ORCPT ); Fri, 30 Nov 2018 16:15:08 -0500 Received: by mail-wm1-f67.google.com with SMTP id s14so5176651wmh.1 for ; Fri, 30 Nov 2018 02:06:20 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=linaro.org; s=google; h=from:to:cc:subject:date:message-id; bh=qMuVDKOBd0O55VlM4Kp3hwxT+oQFuIsRKiWVIynp1Xc=; b=X2SZV7wUn/L/0YJqEzbFPQt50lJR5Imdy3CVRJLQeJ4Kwsv8XkhCVfl87xbnS16Nt1 8hfmLr0faK2H72ciyaIHjSvNiN2v/RnAW4wBXmIn7tWpJa1wZViiTjG7L/I2jueInfJX iOWOMAzv6falCCDOd/k03zwDimGPsRovZ56nI= 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; bh=qMuVDKOBd0O55VlM4Kp3hwxT+oQFuIsRKiWVIynp1Xc=; b=AqHzOoyespaJyC5k2q5XzoY/MVHMsM1FWNdq5jaI2SZLn+uSIAhcFftIfWlwEi1yoE GGaaGdUEl3XIW8Wbt3i5ycirbUOPajtQAbFhP9SNy+DKRKXmyvw9BJlwD90NXMY/j1sG AImoYC6a+757ydR9taIRYjZ1Z1PQM/NzNiHIqnYvDFM8g8yz1glozjh58EMvOrhIYaVD cTIrolvXSHVU4B6SVW/hOYuOnS9XXqfBqBKLEqTc/GlTqGZ7TxCst5KnG8wwwysOG7pS WFffhuR4nejtjXBzZnqBA9iMEWC+yaVBLFkFGrN8pPET7uptdiRtcl9BMUybAYrAbEQY XT+A== X-Gm-Message-State: AA+aEWZzsWyeQWaDl7xVYYeXXPljJ+9sWtUDwjqMRxddt+YUsnEDJyJe mLF67W8rx1oCtpPDN0joInaXUQ== X-Received: by 2002:a1c:5506:: with SMTP id j6mr5318224wmb.44.1543572380080; Fri, 30 Nov 2018 02:06:20 -0800 (PST) Received: from localhost.localdomain ([209.250.228.18]) by smtp.gmail.com with ESMTPSA id h2sm3262265wrv.87.2018.11.30.02.06.16 (version=TLS1_2 cipher=ECDHE-RSA-AES128-SHA bits=128/128); Fri, 30 Nov 2018 02:06:19 -0800 (PST) From: Leo Yan To: Arnaldo Carvalho de Melo , Jiri Olsa , Alexander Shishkin , Andi Kleen , linux-kernel@vger.kernel.org Cc: Leo Yan , Daniel Thompson Subject: [PATCH] perf evsel: Correct clock unit to nanosecond Date: Fri, 30 Nov 2018 18:06:05 +0800 Message-Id: <1543572365-11706-1-git-send-email-leo.yan@linaro.org> X-Mailer: git-send-email 2.7.4 Sender: linux-kernel-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Since commit 0aa802a79469 ("perf stat: Get rid of extra clock display function"), the cpu and task clock unit has been changed from nanosecond value to millisecond value. This introduces confusion for CPU run time statistics, we can see in below flow the clock value is scaled from nanosecond value to millisecond value; but this is contradiction with statistics type 'STAT_NSECS', which always takes clock as nanosecond unit. perf_stat__update_shadow_stats() `-> count *= counter->scale; update_runtime_stat(st, STAT_NSECS, 0, cpu, count); And when 'perf stat' calculates frequencies for cpu cycles and other events, it uses event count to divide clock and it expects divisor unit has nanosecond value, but actually the clock value has been scaled to millisecond value. At the end we can exaggerate values in below output result (e.g. 500M/sec for context-switches, cycle is 1079636.500 GHz). # perf stat -- sleep 1 Performance counter stats for 'sleep 1': 2.29 msec task-clock # 0.002 CPUs utilized 1 context-switches # 500.000 M/sec 1 cpu-migrations # 500.000 M/sec 53 page-faults # 26500.000 M/sec 2,159,273 cycles # 1079636.500 GHz 1,281,566 instructions # 0.59 insn per cycle 171,153 branches # 85576500.000 M/sec 17,870 branch-misses # 10.44% of all branches To fix this issue, this patch changes back clock unit to nanosecond level, as result we can see the correct frequency calculation: # perf stat -- sleep 1 Performance counter stats for 'sleep 1': 2,461,180 nsec task-clock # 0.002 CPUs utilized 1 context-switches # 0.406 K/sec 0 cpu-migrations # 0.000 K/sec 54 page-faults # 0.022 M/sec 2,320,634 cycles # 0.943 GHz 1,284,442 instructions # 0.55 insn per cycle 171,425 branches # 69.652 M/sec 17,970 branch-misses # 10.48% of all branches This patch has side effect for changing unit field for perf command. This is tested with below two cases: one is for normal output format and another is for cvs output format. Before: # perf stat -e cpu-clock,task-clock -C 0 sleep 3 Performance counter stats for 'CPU(s) 0': 3,003.50 msec cpu-clock # 1.000 CPUs utilized 3,003.50 msec task-clock # 1.000 CPUs utilized 3.003697880 seconds time elapsed Now: # perf stat -e cpu-clock,task-clock -C 0 sleep 3 Performance counter stats for 'CPU(s) 0': 3,003,684,880 nsec cpu-clock # 1.000 CPUs utilized 3,003,682,780 nsec task-clock # 1.000 CPUs utilized 3.003881982 seconds time elapsed Before: # perf stat -e cpu-clock,task-clock -C 0 -x, sleep 3 3003.64,msec,cpu-clock,3003644320,100.00,1.000,CPUs utilized 3003.64,msec,task-clock,3003643300,100.00,1.000,CPUs utilized Now: # perf stat -e cpu-clock,task-clock -C 0 -x, sleep 3 3003501460,nsec,cpu-clock,3003501660,100.00,1.000,CPUs utilized 3003499500,nsec,task-clock,3003499500,100.00,1.000,CPUs utilized Cc: Daniel Thompson Signed-off-by: Leo Yan --- tools/perf/util/evsel.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/tools/perf/util/evsel.c b/tools/perf/util/evsel.c index dbc0466..90a5381 100644 --- a/tools/perf/util/evsel.c +++ b/tools/perf/util/evsel.c @@ -267,10 +267,10 @@ struct perf_evsel *perf_evsel__new_idx(struct perf_event_attr *attr, int idx) * The evsel->unit points to static alias->unit * so it's ok to use static string in here. */ - static const char *unit = "msec"; + static const char *unit = "nsec"; evsel->unit = unit; - evsel->scale = 1e-6; + evsel->scale = 1; } return evsel; -- 2.7.4