[llvm] r291749 - [XRay] Implement the `llvm-xray account` subcommand
Dean Michael Berris via llvm-commits
llvm-commits at lists.llvm.org
Wed Jan 11 23:38:13 PST 2017
Author: dberris
Date: Thu Jan 12 01:38:13 2017
New Revision: 291749
URL: http://llvm.org/viewvc/llvm-project?rev=291749&view=rev
Log:
[XRay] Implement the `llvm-xray account` subcommand
Summary:
This is the third of a multi-part change to implement subcommands for
the `llvm-xray` tool.
Here we define the `account` subcommand which does simple function call
accounting, generating basic statistics on function calls we find in an
XRay log/trace. We support text output and csv output for this
subcommand.
This change also supports sorting, summing, and filtering the top N
results.
Part of this tool will later be turned into a library that could be used
for basic function call accounting.
Depends on D24376.
Reviewers: dblaikie, echristo
Subscribers: mehdi_amini, dberris, beanz, llvm-commits
Differential Revision: https://reviews.llvm.org/D24377
Added:
llvm/trunk/test/tools/llvm-xray/X86/Inputs/simple-instrmap.yaml
llvm/trunk/test/tools/llvm-xray/X86/account-deduce-tail-call.yaml
llvm/trunk/test/tools/llvm-xray/X86/account-keep-going.yaml
llvm/trunk/test/tools/llvm-xray/X86/account-simple-case.yaml
llvm/trunk/test/tools/llvm-xray/X86/account-simple-sorting.yaml
llvm/trunk/tools/llvm-xray/xray-account.cc
llvm/trunk/tools/llvm-xray/xray-account.h
llvm/trunk/tools/llvm-xray/xray-record-yaml.h
Modified:
llvm/trunk/tools/llvm-xray/CMakeLists.txt
Added: llvm/trunk/test/tools/llvm-xray/X86/Inputs/simple-instrmap.yaml
URL: http://llvm.org/viewvc/llvm-project/llvm/trunk/test/tools/llvm-xray/X86/Inputs/simple-instrmap.yaml?rev=291749&view=auto
==============================================================================
--- llvm/trunk/test/tools/llvm-xray/X86/Inputs/simple-instrmap.yaml (added)
+++ llvm/trunk/test/tools/llvm-xray/X86/Inputs/simple-instrmap.yaml Thu Jan 12 01:38:13 2017
@@ -0,0 +1,10 @@
+# This is a simple instrumentation map with bogus addresses and offsets, but
+# follow the recommended format.
+---
+- { id: 1, address: 0x1, function: 0x1, kind: function-enter, always-instrument: true}
+- { id: 1, address: 0x2, function: 0x1, kind: function-exit, always-instrument: true}
+- { id: 2, address: 0x2, function: 0x2, kind: function-enter, always-instrument: true}
+- { id: 2, address: 0x3, function: 0x2, kind: function-exit, always-instrument: true}
+- { id: 3, address: 0x3, function: 0x3, kind: function-enter, always-instrument: true}
+- { id: 3, address: 0x4, function: 0x3, kind: function-exit, always-instrument: true}
+...
Added: llvm/trunk/test/tools/llvm-xray/X86/account-deduce-tail-call.yaml
URL: http://llvm.org/viewvc/llvm-project/llvm/trunk/test/tools/llvm-xray/X86/account-deduce-tail-call.yaml?rev=291749&view=auto
==============================================================================
--- llvm/trunk/test/tools/llvm-xray/X86/account-deduce-tail-call.yaml (added)
+++ llvm/trunk/test/tools/llvm-xray/X86/account-deduce-tail-call.yaml Thu Jan 12 01:38:13 2017
@@ -0,0 +1,36 @@
+#RUN: llvm-xray account %s -o - -m %S/Inputs/simple-instrmap.yaml -t yaml -d | FileCheck %s
+---
+header:
+ version: 1
+ type: 0
+ constant-tsc: true
+ nonstop-tsc: true
+ cycle-frequency: 0
+records:
+# Here we reconstruct the following call trace:
+#
+# f1()
+# f2()
+# f3()
+#
+# But we find that we're missing an exit record for f2() because it's
+# tail-called f3(). We make sure that if we see a trace like this that we can
+# deduce tail calls, and account the time (potentially wrongly) to f2() when
+# f1() exits. That is because we don't go back to f3()'s entry record to
+# properly do the math on the timing of f2().
+#
+# Note that by default, tail/sibling call deduction is disabled, and is enabled
+# with a flag "-d" or "-deduce-sibling-calls".
+#
+ - { type: 0, func-id: 1, cpu: 1, thread: 111, kind: function-enter, tsc: 10000 }
+ - { type: 0, func-id: 2, cpu: 1, thread: 111, kind: function-enter, tsc: 10001 }
+ - { type: 0, func-id: 3, cpu: 1, thread: 111, kind: function-enter, tsc: 10002 }
+ - { type: 0, func-id: 3, cpu: 1, thread: 111, kind: function-exit, tsc: 10003 }
+ - { type: 0, func-id: 1, cpu: 1, thread: 111, kind: function-exit, tsc: 10004 }
+...
+
+#CHECK: Functions with latencies: 3
+#CHECK-NEXT: funcid count [ min, med, 90p, 99p, max] sum function
+#CHECK-NEXT: 1 1 [ 4.{{.*}}, 4.{{.*}}, 4.{{.*}}, 4.{{.*}}, 4.{{.*}}] {{.*}} {{.*}}
+#CHECK-NEXT: 2 1 [ 3.{{.*}}, 3.{{.*}}, 3.{{.*}}, 3.{{.*}}, 3.{{.*}}] {{.*}} {{.*}}
+#CHECK-NEXT: 3 1 [ 1.{{.*}}, 1.{{.*}}, 1.{{.*}}, 1.{{.*}}, 1.{{.*}}] {{.*}} {{.*}}
Added: llvm/trunk/test/tools/llvm-xray/X86/account-keep-going.yaml
URL: http://llvm.org/viewvc/llvm-project/llvm/trunk/test/tools/llvm-xray/X86/account-keep-going.yaml?rev=291749&view=auto
==============================================================================
--- llvm/trunk/test/tools/llvm-xray/X86/account-keep-going.yaml (added)
+++ llvm/trunk/test/tools/llvm-xray/X86/account-keep-going.yaml Thu Jan 12 01:38:13 2017
@@ -0,0 +1,20 @@
+#RUN: llvm-xray account %s -o - -m %S/Inputs/simple-instrmap.yaml -t yaml -k | FileCheck %s
+---
+header:
+ version: 1
+ type: 0
+ constant-tsc: true
+ nonstop-tsc: true
+ cycle-frequency: 0
+records:
+# We want to test the case for when we see spurious exits, but keep going
+# anyway ignoring the records in the process.
+ - { type: 0, func-id: 1, cpu: 1, thread: 111, kind: function-enter, tsc: 10000 }
+ - { type: 0, func-id: 2, cpu: 1, thread: 111, kind: function-enter, tsc: 10001 }
+ - { type: 0, func-id: 3, cpu: 1, thread: 111, kind: function-enter, tsc: 10002 }
+ - { type: 0, func-id: 3, cpu: 1, thread: 111, kind: function-exit, tsc: 10003 }
+ - { type: 0, func-id: 1, cpu: 1, thread: 111, kind: function-exit, tsc: 10004 }
+...
+#CHECK: Functions with latencies: 1
+#CHECK-NEXT: funcid count [ min, med, 90p, 99p, max] sum function
+#CHECK-NEXT: 3 1 [ 1.{{.*}}, 1.{{.*}}, 1.{{.*}}, 1.{{.*}}, 1.{{.*}}] {{.*}} {{.*}}
Added: llvm/trunk/test/tools/llvm-xray/X86/account-simple-case.yaml
URL: http://llvm.org/viewvc/llvm-project/llvm/trunk/test/tools/llvm-xray/X86/account-simple-case.yaml?rev=291749&view=auto
==============================================================================
--- llvm/trunk/test/tools/llvm-xray/X86/account-simple-case.yaml (added)
+++ llvm/trunk/test/tools/llvm-xray/X86/account-simple-case.yaml Thu Jan 12 01:38:13 2017
@@ -0,0 +1,18 @@
+#RUN: llvm-xray account %s -o - -m %S/Inputs/simple-instrmap.yaml -t yaml | FileCheck %s
+---
+header:
+ version: 1
+ type: 0
+ constant-tsc: true
+ nonstop-tsc: true
+ cycle-frequency: 2601000000
+records:
+ - { type: 0, func-id: 1, cpu: 1, thread: 111, kind: function-enter,
+ tsc: 10001 }
+ - { type: 0, func-id: 1, cpu: 1, thread: 111, kind: function-exit,
+ tsc: 10100 }
+...
+
+#CHECK: Functions with latencies: 1
+#CHECK-NEXT: funcid count [ min, med, 90p, 99p, max] sum function
+#CHECK-NEXT: 1 1 [ {{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
Added: llvm/trunk/test/tools/llvm-xray/X86/account-simple-sorting.yaml
URL: http://llvm.org/viewvc/llvm-project/llvm/trunk/test/tools/llvm-xray/X86/account-simple-sorting.yaml?rev=291749&view=auto
==============================================================================
--- llvm/trunk/test/tools/llvm-xray/X86/account-simple-sorting.yaml (added)
+++ llvm/trunk/test/tools/llvm-xray/X86/account-simple-sorting.yaml Thu Jan 12 01:38:13 2017
@@ -0,0 +1,85 @@
+#RUN: llvm-xray account %s -o - -m %S/Inputs/simple-instrmap.yaml -t yaml | FileCheck --check-prefix DEFAULT %s
+#RUN: llvm-xray account %s -o - -m %S/Inputs/simple-instrmap.yaml -t yaml -s count | FileCheck --check-prefix COUNT-ASC %s
+#RUN: llvm-xray account %s -o - -m %S/Inputs/simple-instrmap.yaml -t yaml -s min | FileCheck --check-prefix MIN-ASC %s
+#RUN: llvm-xray account %s -o - -m %S/Inputs/simple-instrmap.yaml -t yaml -s max | FileCheck --check-prefix MAX-ASC %s
+#RUN: llvm-xray account %s -o - -m %S/Inputs/simple-instrmap.yaml -t yaml -s sum | FileCheck --check-prefix SUM-ASC %s
+
+#RUN: llvm-xray account %s -o - -m %S/Inputs/simple-instrmap.yaml -t yaml -s count -r dsc | FileCheck --check-prefix COUNT-DSC %s
+#RUN: llvm-xray account %s -o - -m %S/Inputs/simple-instrmap.yaml -t yaml -s min -r dsc | FileCheck --check-prefix MIN-DSC %s
+#RUN: llvm-xray account %s -o - -m %S/Inputs/simple-instrmap.yaml -t yaml -s max -r dsc | FileCheck --check-prefix MAX-DSC %s
+#RUN: llvm-xray account %s -o - -m %S/Inputs/simple-instrmap.yaml -t yaml -s sum -r dsc | FileCheck --check-prefix SUM-DSC %s
+---
+header:
+ version: 1
+ type: 0
+ constant-tsc: true
+ nonstop-tsc: true
+ cycle-frequency: 1
+records:
+ # Function id: 1
+ - { type: 0, func-id: 1, cpu: 1, thread: 111, kind: function-enter,
+ tsc: 10001 }
+ - { type: 0, func-id: 1, cpu: 1, thread: 111, kind: function-exit,
+ tsc: 10100 }
+ - { type: 0, func-id: 1, cpu: 1, thread: 111, kind: function-enter,
+ tsc: 10101 }
+ - { type: 0, func-id: 1, cpu: 1, thread: 111, kind: function-exit,
+ tsc: 10200 }
+ - { type: 0, func-id: 1, cpu: 1, thread: 111, kind: function-enter,
+ tsc: 10201 }
+ - { type: 0, func-id: 1, cpu: 1, thread: 111, kind: function-exit,
+ tsc: 10300 }
+ # Function id: 2
+ - { type: 0, func-id: 2, cpu: 1, thread: 222, kind: function-enter,
+ tsc: 10001 }
+ - { type: 0, func-id: 2, cpu: 1, thread: 222, kind: function-exit,
+ tsc: 10002 }
+ - { type: 0, func-id: 2, cpu: 1, thread: 222, kind: function-enter,
+ tsc: 10101 }
+ - { type: 0, func-id: 2, cpu: 1, thread: 222, kind: function-exit,
+ tsc: 10102 }
+
+#DEFAULT: Functions with latencies: 2
+#DEFAULT-NEXT: funcid count [ min, med, 90p, 99p, max] sum function
+#DEFAULT-NEXT: 1 3 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+#DEFAULT-NEXT: 2 2 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+
+#COUNT-ASC: Functions with latencies: 2
+#COUNT-ASC-NEXT: funcid count [ min, med, 90p, 99p, max] sum function
+#COUNT-ASC-NEXT: 2 2 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+#COUNT-ASC-NEXT: 1 3 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+
+#COUNT-DSC: Functions with latencies: 2
+#COUNT-DSC-NEXT: funcid count [ min, med, 90p, 99p, max] sum function
+#COUNT-DSC-NEXT: 1 3 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+#COUNT-DSC-NEXT: 2 2 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+
+#MIN-ASC: Functions with latencies: 2
+#MIN-ASC-NEXT: funcid count [ min, med, 90p, 99p, max] sum function
+#MIN-ASC-NEXT: 2 2 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+#MIN-ASC-NEXT: 1 3 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+
+#MIN-DSC: Functions with latencies: 2
+#MIN-DSC-NEXT: funcid count [ min, med, 90p, 99p, max] sum function
+#MIN-DSC-NEXT: 1 3 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+#MIN-DSC-NEXT: 2 2 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+
+#MAX-ASC: Functions with latencies: 2
+#MAX-ASC-NEXT: funcid count [ min, med, 90p, 99p, max] sum function
+#MAX-ASC-NEXT: 2 2 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+#MAX-ASC-NEXT: 1 3 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+
+#MAX-DSC: Functions with latencies: 2
+#MAX-DSC-NEXT: funcid count [ min, med, 90p, 99p, max] sum function
+#MAX-DSC-NEXT: 1 3 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+#MAX-DSC-NEXT: 2 2 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+
+#SUM-ASC: Functions with latencies: 2
+#SUM-ASC-NEXT: funcid count [ min, med, 90p, 99p, max] sum function
+#SUM-ASC-NEXT: 2 2 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+#SUM-ASC-NEXT: 1 3 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+
+#SUM-DSC: Functions with latencies: 2
+#SUM-DSC-NEXT: funcid count [ min, med, 90p, 99p, max] sum function
+#SUM-DSC-NEXT: 1 3 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
+#SUM-DSC-NEXT: 2 2 [{{.*}}, {{.*}}, {{.*}}, {{.*}}, {{.*}}] {{.*}} {{.*}}
Modified: llvm/trunk/tools/llvm-xray/CMakeLists.txt
URL: http://llvm.org/viewvc/llvm-project/llvm/trunk/tools/llvm-xray/CMakeLists.txt?rev=291749&r1=291748&r2=291749&view=diff
==============================================================================
--- llvm/trunk/tools/llvm-xray/CMakeLists.txt (original)
+++ llvm/trunk/tools/llvm-xray/CMakeLists.txt Thu Jan 12 01:38:13 2017
@@ -8,6 +8,7 @@ set(LLVM_LINK_COMPONENTS
set(LLVM_XRAY_TOOLS
func-id-helper.cc
+ xray-account.cc
xray-converter.cc
xray-extract.cc
xray-extract.cc
Added: llvm/trunk/tools/llvm-xray/xray-account.cc
URL: http://llvm.org/viewvc/llvm-project/llvm/trunk/tools/llvm-xray/xray-account.cc?rev=291749&view=auto
==============================================================================
--- llvm/trunk/tools/llvm-xray/xray-account.cc (added)
+++ llvm/trunk/tools/llvm-xray/xray-account.cc Thu Jan 12 01:38:13 2017
@@ -0,0 +1,484 @@
+//===- xray-account.h - XRay Function Call Accounting ---------------------===//
+//
+// The LLVM Compiler Infrastructure
+//
+// This file is distributed under the University of Illinois Open Source
+// License. See LICENSE.TXT for details.
+//
+//===----------------------------------------------------------------------===//
+//
+// This file implements basic function call accounting from an XRay trace.
+//
+//===----------------------------------------------------------------------===//
+
+#include <algorithm>
+#include <cassert>
+#include <system_error>
+#include <utility>
+
+#include "xray-account.h"
+#include "xray-extract.h"
+#include "xray-registry.h"
+#include "llvm/Support/ErrorHandling.h"
+#include "llvm/Support/FormatVariadic.h"
+#include "llvm/XRay/Trace.h"
+
+using namespace llvm;
+using namespace llvm::xray;
+
+static cl::SubCommand Account("account", "Function call accounting");
+static cl::opt<std::string> AccountInput(cl::Positional,
+ cl::desc("<xray log file>"),
+ cl::Required, cl::sub(Account));
+static cl::opt<bool>
+ AccountKeepGoing("keep-going", cl::desc("Keep going on errors encountered"),
+ cl::sub(Account), cl::init(false));
+static cl::alias AccountKeepGoing2("k", cl::aliasopt(AccountKeepGoing),
+ cl::desc("Alias for -keep_going"),
+ cl::sub(Account));
+static cl::opt<bool> AccountDeduceSiblingCalls(
+ "deduce-sibling-calls",
+ cl::desc("Deduce sibling calls when unrolling function call stacks"),
+ cl::sub(Account), cl::init(false));
+static cl::alias
+ AccountDeduceSiblingCalls2("d", cl::aliasopt(AccountDeduceSiblingCalls),
+ cl::desc("Alias for -deduce_sibling_calls"),
+ cl::sub(Account));
+static cl::opt<std::string>
+ AccountOutput("output", cl::value_desc("output file"), cl::init("-"),
+ cl::desc("output file; use '-' for stdout"),
+ cl::sub(Account));
+static cl::alias AccountOutput2("o", cl::aliasopt(AccountOutput),
+ cl::desc("Alias for -output"),
+ cl::sub(Account));
+enum class AccountOutputFormats { TEXT, CSV };
+static cl::opt<AccountOutputFormats>
+ AccountOutputFormat("format", cl::desc("output format"),
+ cl::values(clEnumValN(AccountOutputFormats::TEXT,
+ "text", "report stats in text"),
+ clEnumValN(AccountOutputFormats::CSV, "csv",
+ "report stats in csv")),
+ cl::sub(Account));
+static cl::alias AccountOutputFormat2("f", cl::desc("Alias of -format"),
+ cl::aliasopt(AccountOutputFormat),
+ cl::sub(Account));
+
+enum class SortField {
+ FUNCID,
+ COUNT,
+ MIN,
+ MED,
+ PCT90,
+ PCT99,
+ MAX,
+ SUM,
+ FUNC,
+};
+
+static cl::opt<SortField> AccountSortOutput(
+ "sort", cl::desc("sort output by this field"), cl::value_desc("field"),
+ cl::sub(Account), cl::init(SortField::FUNCID),
+ cl::values(clEnumValN(SortField::FUNCID, "funcid", "function id"),
+ clEnumValN(SortField::COUNT, "count", "funciton call counts"),
+ clEnumValN(SortField::MIN, "min", "minimum function durations"),
+ clEnumValN(SortField::MED, "med", "median function durations"),
+ clEnumValN(SortField::PCT90, "90p", "90th percentile durations"),
+ clEnumValN(SortField::PCT99, "99p", "99th percentile durations"),
+ clEnumValN(SortField::MAX, "max", "maximum function durations"),
+ clEnumValN(SortField::SUM, "sum", "sum of call durations"),
+ clEnumValN(SortField::FUNC, "func", "function names")));
+static cl::alias AccountSortOutput2("s", cl::aliasopt(AccountSortOutput),
+ cl::desc("Alias for -sort"),
+ cl::sub(Account));
+
+enum class SortDirection {
+ ASCENDING,
+ DESCENDING,
+};
+static cl::opt<SortDirection> AccountSortOrder(
+ "sortorder", cl::desc("sort ordering"), cl::init(SortDirection::ASCENDING),
+ cl::values(clEnumValN(SortDirection::ASCENDING, "asc", "ascending"),
+ clEnumValN(SortDirection::DESCENDING, "dsc", "descending")),
+ cl::sub(Account));
+static cl::alias AccountSortOrder2("r", cl::aliasopt(AccountSortOrder),
+ cl::desc("Alias for -sortorder"),
+ cl::sub(Account));
+
+static cl::opt<int> AccountTop("top", cl::desc("only show the top N results"),
+ cl::value_desc("N"), cl::sub(Account),
+ cl::init(-1));
+static cl::alias AccountTop2("p", cl::desc("Alias for -top"),
+ cl::aliasopt(AccountTop), cl::sub(Account));
+
+static cl::opt<std::string>
+ AccountInstrMap("instr_map",
+ cl::desc("binary with the instrumentation map, or "
+ "a separate instrumentation map"),
+ cl::value_desc("binary with xray_instr_map"),
+ cl::sub(Account), cl::init(""));
+static cl::alias AccountInstrMap2("m", cl::aliasopt(AccountInstrMap),
+ cl::desc("Alias for -instr_map"),
+ cl::sub(Account));
+static cl::opt<InstrumentationMapExtractor::InputFormats> InstrMapFormat(
+ "instr-map-format", cl::desc("format of instrumentation map"),
+ cl::values(clEnumValN(InstrumentationMapExtractor::InputFormats::ELF, "elf",
+ "instrumentation map in an ELF header"),
+ clEnumValN(InstrumentationMapExtractor::InputFormats::YAML,
+ "yaml", "instrumentation map in YAML")),
+ cl::sub(Account), cl::init(InstrumentationMapExtractor::InputFormats::ELF));
+static cl::alias InstrMapFormat2("t", cl::aliasopt(InstrMapFormat),
+ cl::desc("Alias for -instr-map-format"),
+ cl::sub(Account));
+
+namespace {
+
+template <class T, class U> void setMinMax(std::pair<T, T> &MM, U &&V) {
+ if (MM.first == 0 || MM.second == 0)
+ MM = std::make_pair(std::forward<U>(V), std::forward<U>(V));
+ else
+ MM = std::make_pair(std::min(MM.first, V), std::max(MM.second, V));
+}
+
+template <class T> T diff(T L, T R) { return std::max(L, R) - std::min(L, R); }
+
+} // namespace
+
+bool LatencyAccountant::accountRecord(const XRayRecord &Record) {
+ setMinMax(PerThreadMinMaxTSC[Record.TId], Record.TSC);
+ setMinMax(PerCPUMinMaxTSC[Record.CPU], Record.TSC);
+
+ if (CurrentMaxTSC == 0)
+ CurrentMaxTSC = Record.TSC;
+
+ if (Record.TSC < CurrentMaxTSC)
+ return false;
+
+ auto &ThreadStack = PerThreadFunctionStack[Record.TId];
+ switch (Record.Type) {
+ case RecordTypes::ENTER: {
+ // Function Enter
+ ThreadStack.emplace_back(Record.FuncId, Record.TSC);
+ break;
+ }
+ case RecordTypes::EXIT: {
+ // Function Exit
+ if (ThreadStack.back().first == Record.FuncId) {
+ const auto &Top = ThreadStack.back();
+ recordLatency(Top.first, diff(Top.second, Record.TSC));
+ ThreadStack.pop_back();
+ break;
+ }
+
+ if (!DeduceSiblingCalls)
+ return false;
+
+ // Look for the parent up the stack.
+ auto Parent =
+ std::find_if(ThreadStack.rbegin(), ThreadStack.rend(),
+ [&](const std::pair<const int32_t, uint64_t> &E) {
+ return E.first == Record.FuncId;
+ });
+ if (Parent == ThreadStack.rend())
+ return false;
+
+ // Account time for this apparently sibling call exit up the stack.
+ // Considering the following case:
+ //
+ // f()
+ // g()
+ // h()
+ //
+ // We might only ever see the following entries:
+ //
+ // -> f()
+ // -> g()
+ // -> h()
+ // <- h()
+ // <- f()
+ //
+ // Now we don't see the exit to g() because some older version of the XRay
+ // runtime wasn't instrumenting tail exits. If we don't deduce tail calls,
+ // we may potentially never account time for g() -- and this code would have
+ // already bailed out, because `<- f()` doesn't match the current "top" of
+ // stack where we're waiting for the exit to `g()` instead. This is not
+ // ideal and brittle -- so instead we provide a potentially inaccurate
+ // accounting of g() instead, computing it from the exit of f().
+ //
+ // While it might be better that we account the time between `-> g()` and
+ // `-> h()` as the proper accounting of time for g() here, this introduces
+ // complexity to do correctly (need to backtrack, etc.).
+ //
+ // FIXME: Potentially implement the more complex deduction algorithm?
+ auto I = std::next(Parent).base();
+ for (auto &E : make_range(I, ThreadStack.end())) {
+ recordLatency(E.first, diff(E.second, Record.TSC));
+ }
+ ThreadStack.erase(I, ThreadStack.end());
+ break;
+ }
+ }
+
+ return true;
+}
+
+namespace {
+
+// We consolidate the data into a struct which we can output in various forms.
+struct ResultRow {
+ uint64_t Count;
+ double Min;
+ double Median;
+ double Pct90;
+ double Pct99;
+ double Max;
+ double Sum;
+ std::string DebugInfo;
+ std::string Function;
+};
+
+ResultRow getStats(std::vector<uint64_t> &Timings) {
+ assert(!Timings.empty());
+ ResultRow R;
+ R.Sum = std::accumulate(Timings.begin(), Timings.end(), 0.0);
+ auto MinMax = std::minmax_element(Timings.begin(), Timings.end());
+ R.Min = *MinMax.first;
+ R.Max = *MinMax.second;
+ auto MedianOff = Timings.size() / 2;
+ std::nth_element(Timings.begin(), Timings.begin() + MedianOff, Timings.end());
+ R.Median = Timings[MedianOff];
+ auto Pct90Off = std::floor(Timings.size() * 0.9);
+ std::nth_element(Timings.begin(), Timings.begin() + Pct90Off, Timings.end());
+ R.Pct90 = Timings[Pct90Off];
+ auto Pct99Off = std::floor(Timings.size() * 0.99);
+ std::nth_element(Timings.begin(), Timings.begin() + Pct90Off, Timings.end());
+ R.Pct99 = Timings[Pct99Off];
+ R.Count = Timings.size();
+ return R;
+}
+
+} // namespace
+
+template <class F>
+void LatencyAccountant::exportStats(const XRayFileHeader &Header, F Fn) const {
+ using TupleType = std::tuple<int32_t, uint64_t, ResultRow>;
+ std::vector<TupleType> Results;
+ Results.reserve(FunctionLatencies.size());
+ for (auto FT : FunctionLatencies) {
+ const auto &FuncId = FT.first;
+ auto &Timings = FT.second;
+ Results.emplace_back(FuncId, Timings.size(), getStats(Timings));
+ auto &Row = std::get<2>(Results.back());
+ if (Header.CycleFrequency) {
+ double CycleFrequency = Header.CycleFrequency;
+ Row.Min /= CycleFrequency;
+ Row.Median /= CycleFrequency;
+ Row.Pct90 /= CycleFrequency;
+ Row.Pct99 /= CycleFrequency;
+ Row.Max /= CycleFrequency;
+ Row.Sum /= CycleFrequency;
+ }
+
+ Row.Function = FuncIdHelper.SymbolOrNumber(FuncId);
+ Row.DebugInfo = FuncIdHelper.FileLineAndColumn(FuncId);
+ }
+
+ // Sort the data according to user-provided flags.
+ switch (AccountSortOutput) {
+ case SortField::FUNCID:
+ std::sort(Results.begin(), Results.end(),
+ [](const TupleType &L, const TupleType &R) {
+ if (AccountSortOrder == SortDirection::ASCENDING)
+ return std::get<0>(L) < std::get<0>(R);
+ if (AccountSortOrder == SortDirection::DESCENDING)
+ return std::get<0>(L) > std::get<0>(R);
+ llvm_unreachable("Unknown sort direction");
+ });
+ break;
+ case SortField::COUNT:
+ std::sort(Results.begin(), Results.end(),
+ [](const TupleType &L, const TupleType &R) {
+ if (AccountSortOrder == SortDirection::ASCENDING)
+ return std::get<1>(L) < std::get<1>(R);
+ if (AccountSortOrder == SortDirection::DESCENDING)
+ return std::get<1>(L) > std::get<1>(R);
+ llvm_unreachable("Unknown sort direction");
+ });
+ break;
+ default:
+ // Here we need to look into the ResultRow for the rest of the data that
+ // we want to sort by.
+ std::sort(Results.begin(), Results.end(),
+ [&](const TupleType &L, const TupleType &R) {
+ auto &LR = std::get<2>(L);
+ auto &RR = std::get<2>(R);
+ switch (AccountSortOutput) {
+ case SortField::COUNT:
+ if (AccountSortOrder == SortDirection::ASCENDING)
+ return LR.Count < RR.Count;
+ if (AccountSortOrder == SortDirection::DESCENDING)
+ return LR.Count > RR.Count;
+ llvm_unreachable("Unknown sort direction");
+ case SortField::MIN:
+ if (AccountSortOrder == SortDirection::ASCENDING)
+ return LR.Min < RR.Min;
+ if (AccountSortOrder == SortDirection::DESCENDING)
+ return LR.Min > RR.Min;
+ llvm_unreachable("Unknown sort direction");
+ case SortField::MED:
+ if (AccountSortOrder == SortDirection::ASCENDING)
+ return LR.Median < RR.Median;
+ if (AccountSortOrder == SortDirection::DESCENDING)
+ return LR.Median > RR.Median;
+ llvm_unreachable("Unknown sort direction");
+ case SortField::PCT90:
+ if (AccountSortOrder == SortDirection::ASCENDING)
+ return LR.Pct90 < RR.Pct90;
+ if (AccountSortOrder == SortDirection::DESCENDING)
+ return LR.Pct90 > RR.Pct90;
+ llvm_unreachable("Unknown sort direction");
+ case SortField::PCT99:
+ if (AccountSortOrder == SortDirection::ASCENDING)
+ return LR.Pct99 < RR.Pct99;
+ if (AccountSortOrder == SortDirection::DESCENDING)
+ return LR.Pct99 > RR.Pct99;
+ llvm_unreachable("Unknown sort direction");
+ case SortField::MAX:
+ if (AccountSortOrder == SortDirection::ASCENDING)
+ return LR.Max < RR.Max;
+ if (AccountSortOrder == SortDirection::DESCENDING)
+ return LR.Max > RR.Max;
+ llvm_unreachable("Unknown sort direction");
+ case SortField::SUM:
+ if (AccountSortOrder == SortDirection::ASCENDING)
+ return LR.Sum < RR.Sum;
+ if (AccountSortOrder == SortDirection::DESCENDING)
+ return LR.Sum > RR.Sum;
+ llvm_unreachable("Unknown sort direction");
+ default:
+ llvm_unreachable("Unsupported sort order");
+ }
+ });
+ break;
+ }
+
+ if (AccountTop > 0)
+ Results.erase(Results.begin() + AccountTop.getValue(), Results.end());
+
+ for (const auto &R : Results)
+ Fn(std::get<0>(R), std::get<1>(R), std::get<2>(R));
+}
+
+void LatencyAccountant::exportStatsAsText(raw_ostream &OS,
+ const XRayFileHeader &Header) const {
+ OS << "Functions with latencies: " << FunctionLatencies.size() << "\n";
+
+ // We spend some effort to make the text output more readable, so we do the
+ // following formatting decisions for each of the fields:
+ //
+ // - funcid: 32-bit, but we can determine the largest number and be
+ // between
+ // a minimum of 5 characters, up to 9 characters, right aligned.
+ // - count: 64-bit, but we can determine the largest number and be
+ // between
+ // a minimum of 5 characters, up to 9 characters, right aligned.
+ // - min, median, 90pct, 99pct, max: double precision, but we want to keep
+ // the values in seconds, with microsecond precision (0.000'001), so we
+ // have at most 6 significant digits, with the whole number part to be
+ // at
+ // least 1 character. For readability we'll right-align, with full 9
+ // characters each.
+ // - debug info, function name: we format this as a concatenation of the
+ // debug info and the function name.
+ //
+ static constexpr char StatsHeaderFormat[] =
+ "{0,+9} {1,+10} [{2,+9}, {3,+9}, {4,+9}, {5,+9}, {6,+9}] {7,+9}";
+ static constexpr char StatsFormat[] =
+ R"({0,+9} {1,+10} [{2,+9:f6}, {3,+9:f6}, {4,+9:f6}, {5,+9:f6}, {6,+9:f6}] {7,+9:f6})";
+ OS << llvm::formatv(StatsHeaderFormat, "funcid", "count", "min", "med", "90p",
+ "99p", "max", "sum")
+ << llvm::formatv(" {0,-12}\n", "function");
+ exportStats(Header, [&](int32_t FuncId, size_t Count, const ResultRow &Row) {
+ OS << llvm::formatv(StatsFormat, FuncId, Count, Row.Min, Row.Median,
+ Row.Pct90, Row.Pct99, Row.Max, Row.Sum)
+ << " " << Row.DebugInfo << ": " << Row.Function << "\n";
+ });
+}
+
+void LatencyAccountant::exportStatsAsCSV(raw_ostream &OS,
+ const XRayFileHeader &Header) const {
+ OS << "funcid,count,min,median,90%ile,99%ile,max,sum,debug,function\n";
+ exportStats(Header, [&](int32_t FuncId, size_t Count, const ResultRow &Row) {
+ OS << FuncId << ',' << Count << ',' << Row.Min << ',' << Row.Median << ','
+ << Row.Pct90 << ',' << Row.Pct99 << ',' << Row.Max << "," << Row.Sum
+ << ",\"" << Row.DebugInfo << "\",\"" << Row.Function << "\"\n";
+ });
+}
+
+using namespace llvm::xray;
+
+static CommandRegistration Unused(&Account, []() -> Error {
+ int Fd;
+ auto EC = sys::fs::openFileForRead(AccountInput, Fd);
+ if (EC)
+ return make_error<StringError>(
+ Twine("Cannot open file '") + AccountInput + "'", EC);
+
+ Error Err = Error::success();
+ xray::InstrumentationMapExtractor Extractor(AccountInstrMap, InstrMapFormat,
+ Err);
+ if (auto E = handleErrors(
+ std::move(Err), [&](std::unique_ptr<StringError> E) -> Error {
+ if (E->convertToErrorCode() == std::errc::no_such_file_or_directory)
+ return Error::success();
+ return Error(std::move(E));
+ }))
+ return E;
+
+ raw_fd_ostream OS(AccountOutput, EC, sys::fs::OpenFlags::F_Text);
+ if (EC)
+ return make_error<StringError>(
+ Twine("Cannot open file '") + AccountOutput + "' for writing.", EC);
+
+ const auto &FunctionAddresses = Extractor.getFunctionAddresses();
+ symbolize::LLVMSymbolizer::Options Opts(
+ symbolize::FunctionNameKind::LinkageName, true, true, false, "");
+ symbolize::LLVMSymbolizer Symbolizer(Opts);
+ llvm::xray::FuncIdConversionHelper FuncIdHelper(AccountInstrMap, Symbolizer,
+ FunctionAddresses);
+ xray::LatencyAccountant FCA(FuncIdHelper, AccountDeduceSiblingCalls);
+ if (auto TraceOrErr = loadTraceFile(AccountInput)) {
+ auto &T = *TraceOrErr;
+ for (const auto &Record : T) {
+ if (FCA.accountRecord(Record))
+ continue;
+ for (const auto &ThreadStack : FCA.getPerThreadFunctionStack()) {
+ errs() << "Thread ID: " << ThreadStack.first << "\n";
+ auto Level = ThreadStack.second.size();
+ for (const auto &Entry : llvm::reverse(ThreadStack.second))
+ errs() << "#" << Level-- << "\t"
+ << FuncIdHelper.SymbolOrNumber(Entry.first) << '\n';
+ }
+ if (!AccountKeepGoing)
+ return make_error<StringError>(
+ Twine("Failed accounting function calls in file '") + AccountInput +
+ "'.",
+ std::make_error_code(std::errc::bad_message));
+ }
+ switch (AccountOutputFormat) {
+ case AccountOutputFormats::TEXT:
+ FCA.exportStatsAsText(OS, T.getFileHeader());
+ break;
+ case AccountOutputFormats::CSV:
+ FCA.exportStatsAsCSV(OS, T.getFileHeader());
+ break;
+ }
+ } else {
+ return joinErrors(
+ make_error<StringError>(
+ Twine("Failed loading input file '") + AccountInput + "'",
+ std::make_error_code(std::errc::protocol_error)),
+ TraceOrErr.takeError());
+ }
+
+ return Error::success();
+});
Added: llvm/trunk/tools/llvm-xray/xray-account.h
URL: http://llvm.org/viewvc/llvm-project/llvm/trunk/tools/llvm-xray/xray-account.h?rev=291749&view=auto
==============================================================================
--- llvm/trunk/tools/llvm-xray/xray-account.h (added)
+++ llvm/trunk/tools/llvm-xray/xray-account.h Thu Jan 12 01:38:13 2017
@@ -0,0 +1,104 @@
+//===- xray-account.h - XRay Function Call Accounting ---------------------===//
+//
+// The LLVM Compiler Infrastructure
+//
+// This file is distributed under the University of Illinois Open Source
+// License. See LICENSE.TXT for details.
+//
+//===----------------------------------------------------------------------===//
+//
+// This file defines the interface for performing some basic function call
+// accounting from an XRay trace.
+//
+//===----------------------------------------------------------------------===//
+#ifndef LLVM_TOOLS_LLVM_XRAY_XRAY_ACCOUNT_H
+#define LLVM_TOOLS_LLVM_XRAY_XRAY_ACCOUNT_H
+
+#include <map>
+#include <utility>
+#include <vector>
+
+#include "func-id-helper.h"
+#include "llvm/Support/raw_ostream.h"
+#include "llvm/XRay/XRayRecord.h"
+
+namespace llvm {
+namespace xray {
+
+class LatencyAccountant {
+public:
+ typedef std::map<int32_t, std::vector<uint64_t>> FunctionLatencyMap;
+ typedef std::map<pid_t, std::pair<uint64_t, uint64_t>> PerThreadMinMaxTSCMap;
+ typedef std::map<uint8_t, std::pair<uint64_t, uint64_t>> PerCPUMinMaxTSCMap;
+ typedef std::vector<std::pair<int32_t, uint64_t>> FunctionStack;
+ typedef std::map<pid_t, FunctionStack> PerThreadFunctionStackMap;
+
+private:
+ PerThreadFunctionStackMap PerThreadFunctionStack;
+ FunctionLatencyMap FunctionLatencies;
+ PerThreadMinMaxTSCMap PerThreadMinMaxTSC;
+ PerCPUMinMaxTSCMap PerCPUMinMaxTSC;
+ FuncIdConversionHelper &FuncIdHelper;
+
+ bool DeduceSiblingCalls = false;
+ uint64_t CurrentMaxTSC = 0;
+
+ void recordLatency(int32_t FuncId, uint64_t Latency) {
+ FunctionLatencies[FuncId].push_back(Latency);
+ }
+
+public:
+ explicit LatencyAccountant(FuncIdConversionHelper &FuncIdHelper,
+ bool DeduceSiblingCalls)
+ : FuncIdHelper(FuncIdHelper), DeduceSiblingCalls(DeduceSiblingCalls) {}
+
+ const FunctionLatencyMap &getFunctionLatencies() const {
+ return FunctionLatencies;
+ }
+
+ const PerThreadMinMaxTSCMap &getPerThreadMinMaxTSC() const {
+ return PerThreadMinMaxTSC;
+ }
+
+ const PerCPUMinMaxTSCMap &getPerCPUMinMaxTSC() const {
+ return PerCPUMinMaxTSC;
+ }
+
+ /// Returns false in case we fail to account the provided record. This happens
+ /// in the following cases:
+ ///
+ /// - An exit record does not match any entry records for the same function.
+ /// If we've been set to deduce sibling calls, we try walking up the stack
+ /// and recording times for the higher level functions.
+ /// - A record has a TSC that's before the latest TSC that has been
+ /// recorded. We still record the TSC for the min-max.
+ ///
+ bool accountRecord(const XRayRecord &Record);
+
+ const FunctionStack *getThreadFunctionStack(pid_t TId) const {
+ auto I = PerThreadFunctionStack.find(TId);
+ if (I == PerThreadFunctionStack.end())
+ return nullptr;
+ return &I->second;
+ }
+
+ const PerThreadFunctionStackMap &getPerThreadFunctionStack() const {
+ return PerThreadFunctionStack;
+ }
+
+ // Output Functions
+ // ================
+
+ void exportStatsAsText(raw_ostream &OS, const XRayFileHeader &Header) const;
+ void exportStatsAsCSV(raw_ostream &OS, const XRayFileHeader &Header) const;
+
+private:
+ // Internal helper to implement common parts of the exportStatsAs...
+ // functions.
+ template <class F> void exportStats(const XRayFileHeader &Header, F fn) const;
+};
+
+} // namespace xray
+} // namespace llvm
+
+#endif // LLVM_TOOLS_LLVM_XRAY_XRAY_ACCOUNT_H
Added: llvm/trunk/tools/llvm-xray/xray-record-yaml.h
URL: http://llvm.org/viewvc/llvm-project/llvm/trunk/tools/llvm-xray/xray-record-yaml.h?rev=291749&view=auto
==============================================================================
--- llvm/trunk/tools/llvm-xray/xray-record-yaml.h (added)
+++ llvm/trunk/tools/llvm-xray/xray-record-yaml.h Thu Jan 12 01:38:13 2017
@@ -0,0 +1,102 @@
+//===- xray-record-yaml.h - XRay Record YAML Support Definitions ----------===//
+//
+// The LLVM Compiler Infrastructure
+//
+// This file is distributed under the University of Illinois Open Source
+// License. See LICENSE.TXT for details.
+//
+//===----------------------------------------------------------------------===//
+//
+// Types and traits specialisations for YAML I/O of XRay log entries.
+//
+//===----------------------------------------------------------------------===//
+#ifndef LLVM_TOOLS_LLVM_XRAY_XRAY_RECORD_YAML_H
+#define LLVM_TOOLS_LLVM_XRAY_XRAY_RECORD_YAML_H
+
+#include <type_traits>
+
+#include "xray-record.h"
+#include "llvm/Support/YAMLTraits.h"
+
+namespace llvm {
+namespace xray {
+
+struct YAMLXRayFileHeader {
+ uint16_t Version;
+ uint16_t Type;
+ bool ConstantTSC;
+ bool NonstopTSC;
+ uint64_t CycleFrequency;
+};
+
+struct YAMLXRayRecord {
+ uint16_t RecordType;
+ uint8_t CPU;
+ RecordTypes Type;
+ int32_t FuncId;
+ std::string Function;
+ uint64_t TSC;
+ uint32_t TId;
+};
+
+struct YAMLXRayTrace {
+ YAMLXRayFileHeader Header;
+ std::vector<YAMLXRayRecord> Records;
+};
+
+using XRayRecordStorage =
+ std::aligned_storage<sizeof(XRayRecord), alignof(XRayRecord)>::type;
+
+} // namespace xray
+
+namespace yaml {
+
+// YAML Traits
+// -----------
+template <> struct ScalarEnumerationTraits<xray::RecordTypes> {
+ static void enumeration(IO &IO, xray::RecordTypes &Type) {
+ IO.enumCase(Type, "function-enter", xray::RecordTypes::ENTER);
+ IO.enumCase(Type, "function-exit", xray::RecordTypes::EXIT);
+ }
+};
+
+template <> struct MappingTraits<xray::YAMLXRayFileHeader> {
+ static void mapping(IO &IO, xray::YAMLXRayFileHeader &Header) {
+ IO.mapRequired("version", Header.Version);
+ IO.mapRequired("type", Header.Type);
+ IO.mapRequired("constant-tsc", Header.ConstantTSC);
+ IO.mapRequired("nonstop-tsc", Header.NonstopTSC);
+ IO.mapRequired("cycle-frequency", Header.CycleFrequency);
+ }
+};
+
+template <> struct MappingTraits<xray::YAMLXRayRecord> {
+ static void mapping(IO &IO, xray::YAMLXRayRecord &Record) {
+ // FIXME: Make this type actually be descriptive
+ IO.mapRequired("type", Record.RecordType);
+ IO.mapRequired("func-id", Record.FuncId);
+ IO.mapOptional("function", Record.Function);
+ IO.mapRequired("cpu", Record.CPU);
+ IO.mapRequired("thread", Record.TId);
+ IO.mapRequired("kind", Record.Type);
+ IO.mapRequired("tsc", Record.TSC);
+ }
+
+ static constexpr bool flow = true;
+};
+
+template <> struct MappingTraits<xray::YAMLXRayTrace> {
+ static void mapping(IO &IO, xray::YAMLXRayTrace &Trace) {
+ // A trace file contains two parts, the header and the list of all the
+ // trace records.
+ IO.mapRequired("header", Trace.Header);
+ IO.mapRequired("records", Trace.Records);
+ }
+};
+
+} // namespace yaml
+} // namespace llvm
+
+LLVM_YAML_IS_SEQUENCE_VECTOR(xray::YAMLXRayRecord)
+
+#endif // LLVM_TOOLS_LLVM_XRAY_XRAY_RECORD_YAML_H
More information about the llvm-commits
mailing list