third_party/llvm-7.0/llvm/docs/XRayExample.rst - SwiftShader.git - Git at Google


            
            ===================

            
            Debugging with XRay

            
            ===================


            This document shows an example of how you would go about analyzing applications

            
            built with XRay instrumentation. Here we will attempt to debug ``llc``

            
            compiling some sample LLVM IR generated by Clang.


            .. contents::

            
              :local:


            Building with XRay

            
            ------------------


            To debug an application with XRay instrumentation, we need to build it with a

            
            Clang that supports the ``-fxray-instrument`` option. See `XRay <XRay.html>`_

            
            for more technical details of how XRay works for background information.


            In our example, we need to add ``-fxray-instrument`` to the list of flags

            
            passed to Clang when building a binary. Note that we need to link with Clang as

            
            well to get the XRay runtime linked in appropriately. For building ``llc`` with

            
            XRay, we do something similar below for our LLVM build:


            ::


              $ mkdir -p llvm-build && cd llvm-build

            
              # Assume that the LLVM sources are at ../llvm

            
              $ cmake -GNinja ../llvm -DCMAKE_BUILD_TYPE=Release \

            
                  -DCMAKE_C_FLAGS_RELEASE="-fxray-instrument" -DCMAKE_CXX_FLAGS="-fxray-instrument" \

            
              # Once this finishes, we should build llc

            
              $ ninja llc


            To verify that we have an XRay instrumented binary, we can use ``objdump`` to

            
            look for the ``xray_instr_map`` section.


            ::


              $ objdump -h -j xray_instr_map ./bin/llc

            
              ./bin/llc:     file format elf64-x86-64


              Sections:

            
              Idx Name          Size      VMA               LMA               File off  Algn

            
               14 xray_instr_map 00002fc0  00000000041516c6  00000000041516c6  03d516c6  2**0

            
                                CONTENTS, ALLOC, LOAD, READONLY, DATA


            Getting Traces

            
            --------------


            By default, XRay does not write out the trace files or patch the application

            
            before main starts. If we run ``llc`` it should work like a normally built

            
            binary. If we want to get a full trace of the application's operations (of the

            
            functions we do end up instrumenting with XRay) then we need to enable XRay

            
            at application start. To do this, XRay checks the ``XRAY_OPTIONS`` environment

            
            variable.


            ::


              # The following doesn't create an XRay trace by default.

            
              $ ./bin/llc input.ll


              # We need to set the XRAY_OPTIONS to enable some features.

            
              $ XRAY_OPTIONS="patch_premain=true xray_mode=xray-basic verbosity=1" ./bin/llc input.ll

            
              ==69819==XRay: Log file in 'xray-log.llc.m35qPB'


            At this point we now have an XRay trace we can start analysing.


            The ``llvm-xray`` Tool

            
            ----------------------


            Having a trace then allows us to do basic accounting of the functions that were

            
            instrumented, and how much time we're spending in parts of the code. To make

            
            sense of this data, we use the ``llvm-xray`` tool which has a few subcommands

            
            to help us understand our trace.


            One of the things we can do is to get an accounting of the functions that have

            
            been instrumented. We can see an example accounting with ``llvm-xray account``:


            ::


              $ llvm-xray account xray-log.llc.m35qPB -top=10 -sort=sum -sortorder=dsc -instr_map ./bin/llc

            
              Functions with latencies: 29

            
                 funcid      count [      min,       med,       90p,       99p,       max]       sum  function

            
                    187        360 [ 0.000000,  0.000001,  0.000014,  0.000032,  0.000075]  0.001596  LLLexer.cpp:446:0: llvm::LLLexer::LexIdentifier()

            
                     85        130 [ 0.000000,  0.000000,  0.000018,  0.000023,  0.000156]  0.000799  X86ISelDAGToDAG.cpp:1984:0: (anonymous namespace)::X86DAGToDAGISel::Select(llvm::SDNode*)

            
                    138        130 [ 0.000000,  0.000000,  0.000017,  0.000155,  0.000155]  0.000774  SelectionDAGISel.cpp:2963:0: llvm::SelectionDAGISel::SelectCodeCommon(llvm::SDNode*, unsigned char const*, unsigned int)

            
                    188        103 [ 0.000000,  0.000000,  0.000003,  0.000123,  0.000214]  0.000737  LLParser.cpp:2692:0: llvm::LLParser::ParseValID(llvm::ValID&, llvm::LLParser::PerFunctionState*)

            
                     88          1 [ 0.000562,  0.000562,  0.000562,  0.000562,  0.000562]  0.000562  X86ISelLowering.cpp:83:0: llvm::X86TargetLowering::X86TargetLowering(llvm::X86TargetMachine const&, llvm::X86Subtarget const&)

            
                    125        102 [ 0.000001,  0.000003,  0.000010,  0.000017,  0.000049]  0.000471  Verifier.cpp:3714:0: (anonymous namespace)::Verifier::visitInstruction(llvm::Instruction&)

            
                     90          8 [ 0.000023,  0.000035,  0.000106,  0.000106,  0.000106]  0.000342  X86ISelLowering.cpp:3363:0: llvm::X86TargetLowering::LowerCall(llvm::TargetLowering::CallLoweringInfo&, llvm::SmallVectorImpl<llvm::SDValue>&) const

            
                    124         32 [ 0.000003,  0.000007,  0.000016,  0.000041,  0.000041]  0.000310  Verifier.cpp:1967:0: (anonymous namespace)::Verifier::visitFunction(llvm::Function const&)

            
                    123          1 [ 0.000302,  0.000302,  0.000302,  0.000302,  0.000302]  0.000302  LLVMContextImpl.cpp:54:0: llvm::LLVMContextImpl::~LLVMContextImpl()

            
                    139         46 [ 0.000000,  0.000002,  0.000006,  0.000008,  0.000019]  0.000138  TargetLowering.cpp:506:0: llvm::TargetLowering::SimplifyDemandedBits(llvm::SDValue, llvm::APInt const&, llvm::APInt&, llvm::APInt&, llvm::TargetLowering::TargetLoweringOpt&, unsigned int, bool) const


            This shows us that for our input file, ``llc`` spent the most cumulative time

            
            in the lexer (a total of 1 millisecond). If we wanted for example to work with

            
            this data in a spreadsheet, we can output the results as CSV using the

            
            ``-format=csv`` option to the command for further analysis.


            If we want to get a textual representation of the raw trace we can use the

            
            ``llvm-xray convert`` tool to get YAML output. The first few lines of that

            
            output for an example trace would look like the following:


            ::


              $ llvm-xray convert -f yaml -symbolize -instr_map=./bin/llc xray-log.llc.m35qPB

            
              ---

            
              header:

            
                version:         1

            
                type:            0

            
                constant-tsc:    true

            
                nonstop-tsc:     true

            
                cycle-frequency: 2601000000

            
              records:

            
                - { type: 0, func-id: 110, function: __cxx_global_var_init.8, cpu: 37, thread: 69819, kind: function-enter, tsc: 5434426023268520 }

            
                - { type: 0, func-id: 110, function: __cxx_global_var_init.8, cpu: 37, thread: 69819, kind: function-exit, tsc: 5434426023523052 }

            
                - { type: 0, func-id: 164, function: __cxx_global_var_init, cpu: 37, thread: 69819, kind: function-enter, tsc: 5434426029925386 }

            
                - { type: 0, func-id: 164, function: __cxx_global_var_init, cpu: 37, thread: 69819, kind: function-exit, tsc: 5434426030031128 }

            
                - { type: 0, func-id: 142, function: '(anonymous namespace)::CommandLineParser::ParseCommandLineOptions(int, char const* const*, llvm::StringRef, llvm::raw_ostream*)', cpu: 37, thread: 69819, kind: function-enter, tsc: 5434426046951388 }

            
                - { type: 0, func-id: 142, function: '(anonymous namespace)::CommandLineParser::ParseCommandLineOptions(int, char const* const*, llvm::StringRef, llvm::raw_ostream*)', cpu: 37, thread: 69819, kind: function-exit, tsc: 5434426047282020 }

            
                - { type: 0, func-id: 187, function: 'llvm::LLLexer::LexIdentifier()', cpu: 37, thread: 69819, kind: function-enter, tsc: 5434426047857332 }

            
                - { type: 0, func-id: 187, function: 'llvm::LLLexer::LexIdentifier()', cpu: 37, thread: 69819, kind: function-exit, tsc: 5434426047984152 }

            
                - { type: 0, func-id: 187, function: 'llvm::LLLexer::LexIdentifier()', cpu: 37, thread: 69819, kind: function-enter, tsc: 5434426048036584 }

            
                - { type: 0, func-id: 187, function: 'llvm::LLLexer::LexIdentifier()', cpu: 37, thread: 69819, kind: function-exit, tsc: 5434426048042292 }

            
                - { type: 0, func-id: 187, function: 'llvm::LLLexer::LexIdentifier()', cpu: 37, thread: 69819, kind: function-enter, tsc: 5434426048055056 }

            
                - { type: 0, func-id: 187, function: 'llvm::LLLexer::LexIdentifier()', cpu: 37, thread: 69819, kind: function-exit, tsc: 5434426048067316 }


            Controlling Fidelity

            
            --------------------


            So far in our examples, we haven't been getting full coverage of the functions

            
            we have in the binary. To get that, we need to modify the compiler flags so

            
            that we can instrument more (if not all) the functions we have in the binary.

            
            We have two options for doing that, and we explore both of these below.


            Instruction Threshold

            
            `````````````````````


            The first "blunt" way of doing this is by setting the minimum threshold for

            
            function bodies to 1. We can do that with the

            
            ``-fxray-instruction-threshold=N`` flag when building our binary. We rebuild

            
            ``llc`` with this option and observe the results:


            ::


              $ rm CMakeCache.txt

            
              $ cmake -GNinja ../llvm -DCMAKE_BUILD_TYPE=Release \

            
                  -DCMAKE_C_FLAGS_RELEASE="-fxray-instrument -fxray-instruction-threshold=1" \

            
                  -DCMAKE_CXX_FLAGS="-fxray-instrument -fxray-instruction-threshold=1"

            
              $ ninja llc

            
              $ XRAY_OPTIONS="patch_premain=true" ./bin/llc input.ll

            
              ==69819==XRay: Log file in 'xray-log.llc.5rqxkU'


              $ llvm-xray account xray-log.llc.5rqxkU -top=10 -sort=sum -sortorder=dsc -instr_map ./bin/llc

            
              Functions with latencies: 36652

            
               funcid      count [      min,       med,       90p,       99p,       max]       sum  function

            
                   75          1 [ 0.672368,  0.672368,  0.672368,  0.672368,  0.672368]  0.672368  llc.cpp:271:0: main

            
                   78          1 [ 0.626455,  0.626455,  0.626455,  0.626455,  0.626455]  0.626455  llc.cpp:381:0: compileModule(char**, llvm::LLVMContext&)

            
               139617          1 [ 0.472618,  0.472618,  0.472618,  0.472618,  0.472618]  0.472618  LegacyPassManager.cpp:1723:0: llvm::legacy::PassManager::run(llvm::Module&)

            
               139610          1 [ 0.472618,  0.472618,  0.472618,  0.472618,  0.472618]  0.472618  LegacyPassManager.cpp:1681:0: llvm::legacy::PassManagerImpl::run(llvm::Module&)

            
               139612          1 [ 0.470948,  0.470948,  0.470948,  0.470948,  0.470948]  0.470948  LegacyPassManager.cpp:1564:0: (anonymous namespace)::MPPassManager::runOnModule(llvm::Module&)

            
               139607          2 [ 0.147345,  0.315994,  0.315994,  0.315994,  0.315994]  0.463340  LegacyPassManager.cpp:1530:0: llvm::FPPassManager::runOnModule(llvm::Module&)

            
               139605         21 [ 0.000002,  0.000002,  0.102593,  0.213336,  0.213336]  0.463331  LegacyPassManager.cpp:1491:0: llvm::FPPassManager::runOnFunction(llvm::Function&)

            
               139563      26096 [ 0.000002,  0.000002,  0.000037,  0.000063,  0.000215]  0.225708  LegacyPassManager.cpp:1083:0: llvm::PMDataManager::findAnalysisPass(void const*, bool)

            
               108055        188 [ 0.000002,  0.000120,  0.001375,  0.004523,  0.062624]  0.159279  MachineFunctionPass.cpp:38:0: llvm::MachineFunctionPass::runOnFunction(llvm::Function&)

            
                62635         22 [ 0.000041,  0.000046,  0.000050,  0.126744,  0.126744]  0.127715  X86TargetMachine.cpp:242:0: llvm::X86TargetMachine::getSubtargetImpl(llvm::Function const&) const


            Instrumentation Attributes

            
            ``````````````````````````


            The other way is to use configuration files for selecting which functions

            
            should always be instrumented by the compiler. This gives us a way of ensuring

            
            that certain functions are either always or never instrumented by not having to

            
            add the attribute to the source.


            To use this feature, you can define one file for the functions to always

            
            instrument, and another for functions to never instrument. The format of these

            
            files are exactly the same as the SanitizerLists files that control similar

            
            things for the sanitizer implementations. For example:


            ::


              # xray-attr-list.txt

            
              # always instrument functions that match the following filters:

            
              [always]

            
              fun:main


              # never instrument functions that match the following filters:

            
              [never]

            
              fun:__cxx_*


            Given the file above we can re-build by providing it to the

            
            ``-fxray-attr-list=`` flag to clang. You can have multiple files, each defining

            
            different sets of attribute sets, to be combined into a single list by clang.


            The XRay stack tool

            
            -------------------


            Given a trace, and optionally an instrumentation map, the ``llvm-xray stack``

            
            command can be used to analyze a call stack graph constructed from the function

            
            call timeline.


            The way to use the command is to output the top stacks by call count and time spent.


            ::


              $ llvm-xray stack xray-log.llc.5rqxkU -instr_map ./bin/llc


              Unique Stacks: 3069

            
              Top 10 Stacks by leaf sum:


              Sum: 9633790

            
              lvl   function                                                            count              sum

            
              #0    main                                                                    1         58421550

            
              #1    compileModule(char**, llvm::LLVMContext&)                               1         51440360

            
              #2    llvm::legacy::PassManagerImpl::run(llvm::Module&)                       1         40535375

            
              #3    llvm::FPPassManager::runOnModule(llvm::Module&)                         2         39337525

            
              #4    llvm::FPPassManager::runOnFunction(llvm::Function&)                     6         39331465

            
              #5    llvm::PMDataManager::verifyPreservedAnalysis(llvm::Pass*)             399         16628590

            
              #6    llvm::PMTopLevelManager::findAnalysisPass(void const*)               4584         15155600

            
              #7    llvm::PMDataManager::findAnalysisPass(void const*, bool)            32088          9633790


              ..etc..


            In the default mode, identical stacks on different threads are independently

            
            aggregated. In a multithreaded program, you may end up having identical call

            
            stacks fill your list of top calls.


            To address this, you may specify the ``-aggregate-threads`` or

            
            ``-per-thread-stacks`` flags. ``-per-thread-stacks`` treats the thread id as an

            
            implicit root in each call stack tree, while ``-aggregate-threads`` combines

            
            identical stacks from all threads.


            Flame Graph Generation

            
            ----------------------


            The ``llvm-xray stack`` tool may also be used to generate flamegraphs for

            
            visualizing your instrumented invocations. The tool does not generate the graphs

            
            themselves, but instead generates a format that can be used with Brendan Gregg's

            
            FlameGraph tool, currently available on `github

            
            <https://github.com/brendangregg/FlameGraph>`_.


            To generate output for a flamegraph, a few more options are necessary.


            - ``-all-stacks`` - Emits all of the stacks.

            
            - ``-stack-format`` - Choose the flamegraph output format 'flame'.

            
            - ``-aggregation-type`` - Choose the metric to graph.


            You may pipe the command output directly to the flamegraph tool to obtain an

            
            svg file.


            ::


              $llvm-xray stack xray-log.llc.5rqxkU -instr_map ./bin/llc -stack-format=flame -aggregation-type=time -all-stacks | \

            
              /path/to/FlameGraph/flamegraph.pl > flamegraph.svg


            If you open the svg in a browser, mouse events allow exploring the call stacks.


            Further Exploration

            
            -------------------


            The ``llvm-xray`` tool has a few other subcommands that are in various stages

            
            of being developed. One interesting subcommand that can highlight a few

            
            interesting things is the ``graph`` subcommand. Given for example the following

            
            toy program that we build with XRay instrumentation, we can see how the

            
            generated graph may be a helpful indicator of where time is being spent for the

            
            application.


            .. code-block:: c++


              // sample.cc

            
              #include <iostream>

            
              #include <thread>


              [[clang::xray_always_instrument]] void f() {

            
                std::cerr << '.';

            
              }


              [[clang::xray_always_instrument]] void g() {

            
                for (int i = 0; i < 1 << 10; ++i) {

            
                  std::cerr << '-';

            
                }

            
              }


              int main(int argc, char* argv[]) {

            
                std::thread t1([] {

            
                  for (int i = 0; i < 1 << 10; ++i)

            
                    f();

            
                });

            
                std::thread t2([] {

            
                  g();

            
                });

            
                t1.join();

            
                t2.join();

            
                std::cerr << '\n';

            
              }


            We then build the above with XRay instrumentation:


            ::


              $ clang++ -o sample -O3 sample.cc -std=c++11 -fxray-instrument -fxray-instruction-threshold=1

            
              $ XRAY_OPTIONS="patch_premain=true" ./sample


            We can then explore the graph rendering of the trace generated by this sample

            
            application. We assume you have the graphviz toosl available in your system,

            
            including both ``unflatten`` and ``dot``. If you prefer rendering or exploring

            
            the graph using another tool, then that should be feasible as well. ``llvm-xray

            
            graph`` will create DOT format graphs which should be usable in most graph

            
            rendering applications. One example invocation of the ``llvm-xray graph``

            
            command should yield some interesting insights to the workings of C++

            
            applications:


            ::


              $ llvm-xray graph xray-log.sample.* -m sample -color-edges=sum -edge-label=sum \

            
                  | unflatten -f -l10 | dot -Tsvg -o sample.svg


            Next Steps

            
            ----------


            If you have some interesting analyses you'd like to implement as part of the

            
            llvm-xray tool, please feel free to propose them on the llvm-dev@ mailing list.

            
            The following are some ideas to inspire you in getting involved and potentially

            
            making things better.


              - Implement a query/filtering library that allows for finding patterns in the

            
                XRay traces.

            
              - A conversion from the XRay trace onto something that can be visualised

            
                better by other tools (like the Chrome trace viewer for example).

            
              - Collecting function call stacks and how often they're encountered in the

            
                XRay trace.
	===================
	Debugging with XRay
	===================

	This document shows an example of how you would go about analyzing applications
	built with XRay instrumentation. Here we will attempt to debug ``llc``
	compiling some sample LLVM IR generated by Clang.

	.. contents::
	:local:

	Building with XRay
	------------------

	To debug an application with XRay instrumentation, we need to build it with a
	Clang that supports the ``-fxray-instrument`` option. See `XRay <XRay.html>`_
	for more technical details of how XRay works for background information.

	In our example, we need to add ``-fxray-instrument`` to the list of flags
	passed to Clang when building a binary. Note that we need to link with Clang as
	well to get the XRay runtime linked in appropriately. For building ``llc`` with
	XRay, we do something similar below for our LLVM build:

	::

	$ mkdir -p llvm-build && cd llvm-build
	# Assume that the LLVM sources are at ../llvm
	$ cmake -GNinja ../llvm -DCMAKE_BUILD_TYPE=Release \
	-DCMAKE_C_FLAGS_RELEASE="-fxray-instrument" -DCMAKE_CXX_FLAGS="-fxray-instrument" \
	# Once this finishes, we should build llc
	$ ninja llc


	To verify that we have an XRay instrumented binary, we can use ``objdump`` to
	look for the ``xray_instr_map`` section.

	::

	$ objdump -h -j xray_instr_map ./bin/llc
	./bin/llc: file format elf64-x86-64

	Sections:
	Idx Name Size VMA LMA File off Algn
	14 xray_instr_map 00002fc0 00000000041516c6 00000000041516c6 03d516c6 2**0
	CONTENTS, ALLOC, LOAD, READONLY, DATA

	Getting Traces
	--------------

	By default, XRay does not write out the trace files or patch the application
	before main starts. If we run ``llc`` it should work like a normally built
	binary. If we want to get a full trace of the application's operations (of the
	functions we do end up instrumenting with XRay) then we need to enable XRay
	at application start. To do this, XRay checks the ``XRAY_OPTIONS`` environment
	variable.

	::

	# The following doesn't create an XRay trace by default.
	$ ./bin/llc input.ll

	# We need to set the XRAY_OPTIONS to enable some features.
	$ XRAY_OPTIONS="patch_premain=true xray_mode=xray-basic verbosity=1" ./bin/llc input.ll
	==69819==XRay: Log file in 'xray-log.llc.m35qPB'

	At this point we now have an XRay trace we can start analysing.

	The ``llvm-xray`` Tool
	----------------------

	Having a trace then allows us to do basic accounting of the functions that were
	instrumented, and how much time we're spending in parts of the code. To make
	sense of this data, we use the ``llvm-xray`` tool which has a few subcommands
	to help us understand our trace.

	One of the things we can do is to get an accounting of the functions that have
	been instrumented. We can see an example accounting with ``llvm-xray account``:

	::

	$ llvm-xray account xray-log.llc.m35qPB -top=10 -sort=sum -sortorder=dsc -instr_map ./bin/llc
	Functions with latencies: 29
	funcid count [ min, med, 90p, 99p, max] sum function
	187 360 [ 0.000000, 0.000001, 0.000014, 0.000032, 0.000075] 0.001596 LLLexer.cpp:446:0: llvm::LLLexer::LexIdentifier()
	85 130 [ 0.000000, 0.000000, 0.000018, 0.000023, 0.000156] 0.000799 X86ISelDAGToDAG.cpp:1984:0: (anonymous namespace)::X86DAGToDAGISel::Select(llvm::SDNode*)
	138 130 [ 0.000000, 0.000000, 0.000017, 0.000155, 0.000155] 0.000774 SelectionDAGISel.cpp:2963:0: llvm::SelectionDAGISel::SelectCodeCommon(llvm::SDNode, unsigned char const, unsigned int)
	188 103 [ 0.000000, 0.000000, 0.000003, 0.000123, 0.000214] 0.000737 LLParser.cpp:2692:0: llvm::LLParser::ParseValID(llvm::ValID&, llvm::LLParser::PerFunctionState*)
	88 1 [ 0.000562, 0.000562, 0.000562, 0.000562, 0.000562] 0.000562 X86ISelLowering.cpp:83:0: llvm::X86TargetLowering::X86TargetLowering(llvm::X86TargetMachine const&, llvm::X86Subtarget const&)
	125 102 [ 0.000001, 0.000003, 0.000010, 0.000017, 0.000049] 0.000471 Verifier.cpp:3714:0: (anonymous namespace)::Verifier::visitInstruction(llvm::Instruction&)
	90 8 [ 0.000023, 0.000035, 0.000106, 0.000106, 0.000106] 0.000342 X86ISelLowering.cpp:3363:0: llvm::X86TargetLowering::LowerCall(llvm::TargetLowering::CallLoweringInfo&, llvm::SmallVectorImpl<llvm::SDValue>&) const
	124 32 [ 0.000003, 0.000007, 0.000016, 0.000041, 0.000041] 0.000310 Verifier.cpp:1967:0: (anonymous namespace)::Verifier::visitFunction(llvm::Function const&)
	123 1 [ 0.000302, 0.000302, 0.000302, 0.000302, 0.000302] 0.000302 LLVMContextImpl.cpp:54:0: llvm::LLVMContextImpl::~LLVMContextImpl()
	139 46 [ 0.000000, 0.000002, 0.000006, 0.000008, 0.000019] 0.000138 TargetLowering.cpp:506:0: llvm::TargetLowering::SimplifyDemandedBits(llvm::SDValue, llvm::APInt const&, llvm::APInt&, llvm::APInt&, llvm::TargetLowering::TargetLoweringOpt&, unsigned int, bool) const

	This shows us that for our input file, ``llc`` spent the most cumulative time
	in the lexer (a total of 1 millisecond). If we wanted for example to work with
	this data in a spreadsheet, we can output the results as CSV using the
	``-format=csv`` option to the command for further analysis.

	If we want to get a textual representation of the raw trace we can use the
	``llvm-xray convert`` tool to get YAML output. The first few lines of that
	output for an example trace would look like the following:

	::

	$ llvm-xray convert -f yaml -symbolize -instr_map=./bin/llc xray-log.llc.m35qPB
	---
	header:
	version: 1
	type: 0
	constant-tsc: true
	nonstop-tsc: true
	cycle-frequency: 2601000000
	records:
	- { type: 0, func-id: 110, function: __cxx_global_var_init.8, cpu: 37, thread: 69819, kind: function-enter, tsc: 5434426023268520 }
	- { type: 0, func-id: 110, function: __cxx_global_var_init.8, cpu: 37, thread: 69819, kind: function-exit, tsc: 5434426023523052 }
	- { type: 0, func-id: 164, function: __cxx_global_var_init, cpu: 37, thread: 69819, kind: function-enter, tsc: 5434426029925386 }
	- { type: 0, func-id: 164, function: __cxx_global_var_init, cpu: 37, thread: 69819, kind: function-exit, tsc: 5434426030031128 }
	- { type: 0, func-id: 142, function: '(anonymous namespace)::CommandLineParser::ParseCommandLineOptions(int, char const* const, llvm::StringRef, llvm::raw_ostream)', cpu: 37, thread: 69819, kind: function-enter, tsc: 5434426046951388 }
	- { type: 0, func-id: 142, function: '(anonymous namespace)::CommandLineParser::ParseCommandLineOptions(int, char const* const, llvm::StringRef, llvm::raw_ostream)', cpu: 37, thread: 69819, kind: function-exit, tsc: 5434426047282020 }
	- { type: 0, func-id: 187, function: 'llvm::LLLexer::LexIdentifier()', cpu: 37, thread: 69819, kind: function-enter, tsc: 5434426047857332 }
	- { type: 0, func-id: 187, function: 'llvm::LLLexer::LexIdentifier()', cpu: 37, thread: 69819, kind: function-exit, tsc: 5434426047984152 }
	- { type: 0, func-id: 187, function: 'llvm::LLLexer::LexIdentifier()', cpu: 37, thread: 69819, kind: function-enter, tsc: 5434426048036584 }
	- { type: 0, func-id: 187, function: 'llvm::LLLexer::LexIdentifier()', cpu: 37, thread: 69819, kind: function-exit, tsc: 5434426048042292 }
	- { type: 0, func-id: 187, function: 'llvm::LLLexer::LexIdentifier()', cpu: 37, thread: 69819, kind: function-enter, tsc: 5434426048055056 }
	- { type: 0, func-id: 187, function: 'llvm::LLLexer::LexIdentifier()', cpu: 37, thread: 69819, kind: function-exit, tsc: 5434426048067316 }

	Controlling Fidelity
	--------------------

	So far in our examples, we haven't been getting full coverage of the functions
	we have in the binary. To get that, we need to modify the compiler flags so
	that we can instrument more (if not all) the functions we have in the binary.
	We have two options for doing that, and we explore both of these below.

	Instruction Threshold
	`````````````````````

	The first "blunt" way of doing this is by setting the minimum threshold for
	function bodies to 1. We can do that with the
	``-fxray-instruction-threshold=N`` flag when building our binary. We rebuild
	``llc`` with this option and observe the results:

	::

	$ rm CMakeCache.txt
	$ cmake -GNinja ../llvm -DCMAKE_BUILD_TYPE=Release \
	-DCMAKE_C_FLAGS_RELEASE="-fxray-instrument -fxray-instruction-threshold=1" \
	-DCMAKE_CXX_FLAGS="-fxray-instrument -fxray-instruction-threshold=1"
	$ ninja llc
	$ XRAY_OPTIONS="patch_premain=true" ./bin/llc input.ll
	==69819==XRay: Log file in 'xray-log.llc.5rqxkU'

	$ llvm-xray account xray-log.llc.5rqxkU -top=10 -sort=sum -sortorder=dsc -instr_map ./bin/llc
	Functions with latencies: 36652
	funcid count [ min, med, 90p, 99p, max] sum function
	75 1 [ 0.672368, 0.672368, 0.672368, 0.672368, 0.672368] 0.672368 llc.cpp:271:0: main
	78 1 [ 0.626455, 0.626455, 0.626455, 0.626455, 0.626455] 0.626455 llc.cpp:381:0: compileModule(char**, llvm::LLVMContext&)
	139617 1 [ 0.472618, 0.472618, 0.472618, 0.472618, 0.472618] 0.472618 LegacyPassManager.cpp:1723:0: llvm::legacy::PassManager::run(llvm::Module&)
	139610 1 [ 0.472618, 0.472618, 0.472618, 0.472618, 0.472618] 0.472618 LegacyPassManager.cpp:1681:0: llvm::legacy::PassManagerImpl::run(llvm::Module&)
	139612 1 [ 0.470948, 0.470948, 0.470948, 0.470948, 0.470948] 0.470948 LegacyPassManager.cpp:1564:0: (anonymous namespace)::MPPassManager::runOnModule(llvm::Module&)
	139607 2 [ 0.147345, 0.315994, 0.315994, 0.315994, 0.315994] 0.463340 LegacyPassManager.cpp:1530:0: llvm::FPPassManager::runOnModule(llvm::Module&)
	139605 21 [ 0.000002, 0.000002, 0.102593, 0.213336, 0.213336] 0.463331 LegacyPassManager.cpp:1491:0: llvm::FPPassManager::runOnFunction(llvm::Function&)
	139563 26096 [ 0.000002, 0.000002, 0.000037, 0.000063, 0.000215] 0.225708 LegacyPassManager.cpp:1083:0: llvm::PMDataManager::findAnalysisPass(void const*, bool)
	108055 188 [ 0.000002, 0.000120, 0.001375, 0.004523, 0.062624] 0.159279 MachineFunctionPass.cpp:38:0: llvm::MachineFunctionPass::runOnFunction(llvm::Function&)
	62635 22 [ 0.000041, 0.000046, 0.000050, 0.126744, 0.126744] 0.127715 X86TargetMachine.cpp:242:0: llvm::X86TargetMachine::getSubtargetImpl(llvm::Function const&) const


	Instrumentation Attributes
	``````````````````````````

	The other way is to use configuration files for selecting which functions
	should always be instrumented by the compiler. This gives us a way of ensuring
	that certain functions are either always or never instrumented by not having to
	add the attribute to the source.

	To use this feature, you can define one file for the functions to always
	instrument, and another for functions to never instrument. The format of these
	files are exactly the same as the SanitizerLists files that control similar
	things for the sanitizer implementations. For example:

	::

	# xray-attr-list.txt
	# always instrument functions that match the following filters:
	[always]
	fun:main

	# never instrument functions that match the following filters:
	[never]
	fun:__cxx_*

	Given the file above we can re-build by providing it to the
	``-fxray-attr-list=`` flag to clang. You can have multiple files, each defining
	different sets of attribute sets, to be combined into a single list by clang.

	The XRay stack tool
	-------------------

	Given a trace, and optionally an instrumentation map, the ``llvm-xray stack``
	command can be used to analyze a call stack graph constructed from the function
	call timeline.

	The way to use the command is to output the top stacks by call count and time spent.

	::

	$ llvm-xray stack xray-log.llc.5rqxkU -instr_map ./bin/llc

	Unique Stacks: 3069
	Top 10 Stacks by leaf sum:

	Sum: 9633790
	lvl function count sum
	#0 main 1 58421550
	#1 compileModule(char**, llvm::LLVMContext&) 1 51440360
	#2 llvm::legacy::PassManagerImpl::run(llvm::Module&) 1 40535375
	#3 llvm::FPPassManager::runOnModule(llvm::Module&) 2 39337525
	#4 llvm::FPPassManager::runOnFunction(llvm::Function&) 6 39331465
	#5 llvm::PMDataManager::verifyPreservedAnalysis(llvm::Pass*) 399 16628590
	#6 llvm::PMTopLevelManager::findAnalysisPass(void const*) 4584 15155600
	#7 llvm::PMDataManager::findAnalysisPass(void const*, bool) 32088 9633790

	..etc..

	In the default mode, identical stacks on different threads are independently
	aggregated. In a multithreaded program, you may end up having identical call
	stacks fill your list of top calls.

	To address this, you may specify the ``-aggregate-threads`` or
	``-per-thread-stacks`` flags. ``-per-thread-stacks`` treats the thread id as an
	implicit root in each call stack tree, while ``-aggregate-threads`` combines
	identical stacks from all threads.

	Flame Graph Generation
	----------------------

	The ``llvm-xray stack`` tool may also be used to generate flamegraphs for
	visualizing your instrumented invocations. The tool does not generate the graphs
	themselves, but instead generates a format that can be used with Brendan Gregg's
	FlameGraph tool, currently available on `github
	<https://github.com/brendangregg/FlameGraph>`_.

	To generate output for a flamegraph, a few more options are necessary.

	- ``-all-stacks`` - Emits all of the stacks.
	- ``-stack-format`` - Choose the flamegraph output format 'flame'.
	- ``-aggregation-type`` - Choose the metric to graph.

	You may pipe the command output directly to the flamegraph tool to obtain an
	svg file.

	::

	$llvm-xray stack xray-log.llc.5rqxkU -instr_map ./bin/llc -stack-format=flame -aggregation-type=time -all-stacks \| \
	/path/to/FlameGraph/flamegraph.pl > flamegraph.svg

	If you open the svg in a browser, mouse events allow exploring the call stacks.

	Further Exploration
	-------------------

	The ``llvm-xray`` tool has a few other subcommands that are in various stages
	of being developed. One interesting subcommand that can highlight a few
	interesting things is the ``graph`` subcommand. Given for example the following
	toy program that we build with XRay instrumentation, we can see how the
	generated graph may be a helpful indicator of where time is being spent for the
	application.

	.. code-block:: c++

	// sample.cc
	#include <iostream>
	#include <thread>

	[[clang::xray_always_instrument]] void f() {
	std::cerr << '.';
	}

	[[clang::xray_always_instrument]] void g() {
	for (int i = 0; i < 1 << 10; ++i) {
	std::cerr << '-';
	}
	}

	int main(int argc, char* argv[]) {
	std::thread t1([] {
	for (int i = 0; i < 1 << 10; ++i)
	f();
	});
	std::thread t2([] {
	g();
	});
	t1.join();
	t2.join();
	std::cerr << '\n';
	}

	We then build the above with XRay instrumentation:

	::

	$ clang++ -o sample -O3 sample.cc -std=c++11 -fxray-instrument -fxray-instruction-threshold=1
	$ XRAY_OPTIONS="patch_premain=true" ./sample

	We can then explore the graph rendering of the trace generated by this sample
	application. We assume you have the graphviz toosl available in your system,
	including both ``unflatten`` and ``dot``. If you prefer rendering or exploring
	the graph using another tool, then that should be feasible as well. ``llvm-xray
	graph`` will create DOT format graphs which should be usable in most graph
	rendering applications. One example invocation of the ``llvm-xray graph``
	command should yield some interesting insights to the workings of C++
	applications:

	::

	$ llvm-xray graph xray-log.sample.* -m sample -color-edges=sum -edge-label=sum \
	\| unflatten -f -l10 \| dot -Tsvg -o sample.svg

	Next Steps
	----------

	If you have some interesting analyses you'd like to implement as part of the
	llvm-xray tool, please feel free to propose them on the llvm-dev@ mailing list.
	The following are some ideas to inspire you in getting involved and potentially
	making things better.

	- Implement a query/filtering library that allows for finding patterns in the
	XRay traces.
	- A conversion from the XRay trace onto something that can be visualised
	better by other tools (like the Chrome trace viewer for example).
	- Collecting function call stacks and how often they're encountered in the
	XRay trace.