[XRay][tools] Function call stack based analysis tooling for XRay traces

This change introduces a subcommand to the llvm-xray tool called
"stacks" which allows for analysing XRay traces provided as inputs and
accounting time to stacks instead of just individual functions. This
gives us a more precise view of where in a program the latency is
actually attributed.

The tool uses a trie data structure to keep track of the caller-callee
relationships as we process the XRay traces. In particular, we keep
track of the function call stack as we enter functions. While we're
doing this we're adding nodes in a trie and indicating a "calls"
relatinship between the caller (current top of the stack) and the callee
(the new top of the stack). When we push function ids onto the stack, we
keep track of the timestamp (TSC) for the enter event.

When exiting functions, we are able to account the duration by getting
the difference between the timestamp of the exit event and the
corresponding entry event in the stack. This works even if we somehow
miss the exit events for intermediary functions (i.e. if the exit event
is not cleanly associated with the enter event at the top of the stack).

The output of the tool currently provides just the top N leaf functions
that contribute the most latency, and the top N stacks that have the
most frequency. In the future we can provide more sophisticated query
mechanisms and potentially an export to database feature to make offline
analysis of the stack traces possible with existing tools.

llvm-svn: 312426

4 files changed, 137 insertions, 0 deletions

diff --git a/llvm/test/tools/llvm-xray/X86/stack-empty-case.yaml b/llvm/test/tools/llvm-xray/X86/stack-empty-case.yaml
new file mode 100644
index 00000000000..732caf3381f
--- /dev/null
+++ b/llvm/test/tools/llvm-xray/X86/stack-empty-case.yaml
@@ -0,0 +1,13 @@
+#RUN: (llvm-xray stack %s 2>&1 || echo "Checking Command Failed") | FileCheck %s
+---
+header:
+  version: 1
+  type: 0
+  constant-tsc: true
+  nonstop-tsc: true
+  cycle-frequency: 2601000000
+records:
+...
+# CHECK:     llvm-xray: No instrumented calls were accounted in the input file.
+# CHECK:     Checking Command Failed
+# CHECK-NOT: {{[0-9A-Z]+}}
diff --git a/llvm/test/tools/llvm-xray/X86/stack-keep-going.yaml b/llvm/test/tools/llvm-xray/X86/stack-keep-going.yaml
new file mode 100644
index 00000000000..96da7346ae0
--- /dev/null
+++ b/llvm/test/tools/llvm-xray/X86/stack-keep-going.yaml
@@ -0,0 +1,28 @@
+#RUN: (llvm-xray stack %s 2>&1 1>&- || echo "Check Command Failed") | FileCheck --check-prefix HALT %s
+#RUN: (llvm-xray stack -k %s 2>&1 && echo "Check Command Succeeded") | FileCheck --check-prefix KEEP-GOING-SUCCEEDS %s
+#RUN: llvm-xray stack -k %s | FileCheck --check-prefix KEEP-GOING %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: 1, func-id: 4, cpu: 1, thread: 111, kind: function-exit, tsc: 10301 }
+  - { type: 0, func-id: 1, cpu: 1, thread: 111, kind: function-enter, tsc: 10401 }
+  - { type: 0, func-id: 2, cpu: 1, thread: 111, kind: function-enter, tsc: 10501 }
+  - { type: 0, func-id: 3, cpu: 1, thread: 111, kind: function-enter, tsc: 10601 }
+  - { type: 1, func-id: 3, cpu: 1, thread: 111, kind: function-exit, tsc: 10701 }
+  - { type: 1, func-id: 2, cpu: 1, thread: 111, kind: function-exit, tsc: 10751 }
+  - { type: 1, func-id: 1, cpu: 1, thread: 111, kind: function-exit, tsc: 10775 }
+...
+
+#HALT: llvm-xray: Found record {FuncId: "#4", ThreadId: "111", RecordType: "Fn Exit"} with no matching function entry
+#HALT: Check Command Failed
+#KEEP-GOING-SUCCEEDS: Found record {FuncId: "#4", ThreadId: "111", RecordType: "Fn Exit"} with no matching function entry
+#KEEP-GOING-SUCCEEDS: Check Command Succeeded
+#KEEP-GOING: Unique Stacks: 2
+# Note the interesting case here that the stack { fn-1 } is a prefix of { fn-1, fn-2, fn-3 } but they
+# are still counted as unique stacks.
diff --git a/llvm/test/tools/llvm-xray/X86/stack-multithread.yaml b/llvm/test/tools/llvm-xray/X86/stack-multithread.yaml
new file mode 100644
index 00000000000..95be7f77081
--- /dev/null
+++ b/llvm/test/tools/llvm-xray/X86/stack-multithread.yaml
@@ -0,0 +1,83 @@
+#RUN: llvm-xray stack -per-thread-stacks %s | FileCheck %s --check-prefix PER-THREAD
+#RUN: llvm-xray stack -aggregate-threads %s | FileCheck %s --check-prefix AGGREGATE
+
+---
+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-enter, tsc: 10100 }
+  - { type: 1, func-id: 1, cpu: 1, thread: 111, kind: function-exit, tsc: 10101 }
+  - { type: 1, func-id: 1, cpu: 1, thread: 111, kind: function-exit, tsc: 10301 }
+  - { type: 0, func-id: 1, cpu: 1, thread: 111, kind: function-enter, tsc: 10401 }
+  - { type: 0, func-id: 2, cpu: 1, thread: 111, kind: function-enter, tsc: 10501 }
+  - { type: 0, func-id: 3, cpu: 1, thread: 111, kind: function-enter, tsc: 10601 }
+  - { type: 1, func-id: 3, cpu: 1, thread: 111, kind: function-exit, tsc: 10701 }
+  - { type: 1, func-id: 2, cpu: 1, thread: 111, kind: function-exit, tsc: 10751 }
+  - { type: 1, func-id: 1, cpu: 1, thread: 111, kind: function-exit, tsc: 10775 }
+  - { type: 0, func-id: 1, cpu: 1, thread: 123, kind: function-enter, tsc: 10401 }
+  - { type: 0, func-id: 2, cpu: 1, thread: 123, kind: function-enter, tsc: 10501 }
+  - { type: 0, func-id: 3, cpu: 1, thread: 123, kind: function-enter, tsc: 10701 }
+  - { type: 1, func-id: 3, cpu: 1, thread: 123, kind: function-exit, tsc: 10801 }
+  - { type: 1, func-id: 2, cpu: 1, thread: 123, kind: function-exit, tsc: 10951 }
+  - { type: 1, func-id: 1, cpu: 1, thread: 123, kind: function-exit, tsc: 11075 }
+  - { type: 0, func-id: 2, cpu: 1, thread: 200, kind: function-enter, tsc: 0 }
+  - { type: 0, func-id: 3, cpu: 1, thread: 200, kind: function-enter, tsc: 10 }
+  - { type: 1, func-id: 3, cpu: 1, thread: 200, kind: function-exit, tsc: 20 }
+  - { type: 1, func-id: 2, cpu: 1, thread: 200, kind: function-exit, tsc: 30 }
+...
+# PER-THREAD: Thread 123
+# PER-THREAD: Unique Stacks: 1
+# PER-THREAD: Top 10 Stacks by leaf sum:
+# PER-THREAD: Sum: 100
+# PER-THREAD: lvl   function{{[[:space:]]+}}count{{[[:space:]]+}}sum
+# PER-THREAD: #0    #1{{[[:space:]]+}}1{{[[:space:]]+}}674
+# PER-THREAD: #1    #2{{[[:space:]]+}}1{{[[:space:]]+}}450
+# PER-THREAD: #2    #3{{[[:space:]]+}}1{{[[:space:]]+}}100
+# PER-THREAD: Top 10 Stacks by leaf count:
+# PER-THREAD: #0    #1{{[[:space:]]+}}1{{[[:space:]]+}}674
+# PER-THREAD: #1    #2{{[[:space:]]+}}1{{[[:space:]]+}}450
+# PER-THREAD: #2    #3{{[[:space:]]+}}1{{[[:space:]]+}}100
+# PER-THREAD: lvl   function{{[[:space:]]+}}count{{[[:space:]]+}}sum
+
+# AGGREGATE: Unique Stacks: 3
+# AGGREGATE: Top 10 Stacks by leaf sum:
+# AGGREGATE: Sum: 200
+
+# AGGREGATE: lvl   function{{[[:space:]]+}}count{{[[:space:]]+}}sum
+# AGGREGATE: #0    #1{{[[:space:]]+}}3{{[[:space:]]+}}1348
+# AGGREGATE: #1    #2{{[[:space:]]+}}2{{[[:space:]]+}}700
+# AGGREGATE: #2    #3{{[[:space:]]+}}2{{[[:space:]]+}}200
+
+# AGGREGATE: Sum: 10
+# AGGREGATE: lvl   function{{[[:space:]]+}}count{{[[:space:]]+}}sum
+# AGGREGATE: #0    #2{{[[:space:]]+}}1{{[[:space:]]+}}30
+# AGGREGATE: #1    #3{{[[:space:]]+}}1{{[[:space:]]+}}10
+
+# AGGREGATE: Sum: 1
+# AGGREGATE: lvl   function{{[[:space:]]+}}count{{[[:space:]]+}}sum
+# AGGREGATE: #0    #1{{[[:space:]]+}}2{{[[:space:]]+}}674
+# AGGREGATE: #1    #1{{[[:space:]]+}}1{{[[:space:]]+}}1
+
+
+# AGGREGATE: Top 10 Stacks by leaf count:
+
+# AGGREGATE: Count: 2
+# AGGREGATE: lvl   function{{[[:space:]]+}}count{{[[:space:]]+}}sum
+# AGGREGATE: #0    #1{{[[:space:]]+}}3{{[[:space:]]+}}1348
+# AGGREGATE: #1    #2{{[[:space:]]+}}2{{[[:space:]]+}}700
+# AGGREGATE: #2    #3{{[[:space:]]+}}2{{[[:space:]]+}}200
+
+# AGGREGATE: Count: 1
+# AGGREGATE: lvl   function{{[[:space:]]+}}count{{[[:space:]]+}}sum
+# AGGREGATE: #0    #2{{[[:space:]]+}}1{{[[:space:]]+}}30
+# AGGREGATE: #1    #3{{[[:space:]]+}}1{{[[:space:]]+}}10
+
+# AGGREGATE: Count: 1
+# AGGREGATE: lvl   function{{[[:space:]]+}}count{{[[:space:]]+}}sum
+# AGGREGATE: #0    #1{{[[:space:]]+}}2{{[[:space:]]+}}674
+# AGGREGATE: #1    #1{{[[:space:]]+}}1{{[[:space:]]+}}1
diff --git a/llvm/test/tools/llvm-xray/X86/stack-simple-case.yaml b/llvm/test/tools/llvm-xray/X86/stack-simple-case.yaml
new file mode 100644
index 00000000000..9749e43c60a
--- /dev/null
+++ b/llvm/test/tools/llvm-xray/X86/stack-simple-case.yaml
@@ -0,0 +1,13 @@
+#RUN: llvm-xray stack %s | 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: Unique Stacks: 1