Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 1 | ==================== |
| 2 | XRay Instrumentation |
| 3 | ==================== |
| 4 | |
| 5 | :Version: 1 as of 2016-11-08 |
| 6 | |
| 7 | .. contents:: |
| 8 | :local: |
| 9 | |
| 10 | |
| 11 | Introduction |
| 12 | ============ |
| 13 | |
| 14 | XRay is a function call tracing system which combines compiler-inserted |
| 15 | instrumentation points and a runtime library that can dynamically enable and |
| 16 | disable the instrumentation. |
| 17 | |
| 18 | More high level information about XRay can be found in the `XRay whitepaper`_. |
| 19 | |
| 20 | This document describes how to use XRay as implemented in LLVM. |
| 21 | |
| 22 | XRay in LLVM |
| 23 | ============ |
| 24 | |
| 25 | XRay consists of three main parts: |
| 26 | |
| 27 | - Compiler-inserted instrumentation points. |
| 28 | - A runtime library for enabling/disabling tracing at runtime. |
| 29 | - A suite of tools for analysing the traces. |
| 30 | |
David Carlier | 00c4d03 | 2018-07-26 04:44:31 +0000 | [diff] [blame] | 31 | **NOTE:** As of July 25, 2018 , XRay is only available for the following |
Dean Michael Berris | 7577713 | 2017-02-28 22:01:26 +0000 | [diff] [blame] | 32 | architectures running Linux: x86_64, arm7 (no thumb), aarch64, powerpc64le, |
David Carlier | 00c4d03 | 2018-07-26 04:44:31 +0000 | [diff] [blame] | 33 | mips, mipsel, mips64, mips64el, NetBSD: x86_64, FreeBSD: x86_64 and |
| 34 | OpenBSD: x86_64. |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 35 | |
| 36 | The compiler-inserted instrumentation points come in the form of nop-sleds in |
| 37 | the final generated binary, and an ELF section named ``xray_instr_map`` which |
| 38 | contains entries pointing to these instrumentation points. The runtime library |
| 39 | relies on being able to access the entries of the ``xray_instr_map``, and |
| 40 | overwrite the instrumentation points at runtime. |
| 41 | |
| 42 | Using XRay |
| 43 | ========== |
| 44 | |
| 45 | You can use XRay in a couple of ways: |
| 46 | |
| 47 | - Instrumenting your C/C++/Objective-C/Objective-C++ application. |
| 48 | - Generating LLVM IR with the correct function attributes. |
| 49 | |
| 50 | The rest of this section covers these main ways and later on how to customise |
| 51 | what XRay does in an XRay-instrumented binary. |
| 52 | |
| 53 | Instrumenting your C/C++/Objective-C Application |
| 54 | ------------------------------------------------ |
| 55 | |
| 56 | The easiest way of getting XRay instrumentation for your application is by |
| 57 | enabling the ``-fxray-instrument`` flag in your clang invocation. |
| 58 | |
| 59 | For example: |
| 60 | |
| 61 | :: |
| 62 | |
Ed Maste | 828cfc4 | 2018-03-08 13:52:04 +0000 | [diff] [blame] | 63 | clang -fxray-instrument ... |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 64 | |
| 65 | By default, functions that have at least 200 instructions will get XRay |
| 66 | instrumentation points. You can tweak that number through the |
| 67 | ``-fxray-instruction-threshold=`` flag: |
| 68 | |
| 69 | :: |
| 70 | |
Ed Maste | 828cfc4 | 2018-03-08 13:52:04 +0000 | [diff] [blame] | 71 | clang -fxray-instrument -fxray-instruction-threshold=1 ... |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 72 | |
| 73 | You can also specifically instrument functions in your binary to either always |
| 74 | or never be instrumented using source-level attributes. You can do it using the |
| 75 | GCC-style attributes or C++11-style attributes. |
| 76 | |
| 77 | .. code-block:: c++ |
| 78 | |
Fangrui Song | c66b956 | 2017-11-27 16:59:26 +0000 | [diff] [blame] | 79 | [[clang::xray_always_instrument]] void always_instrumented(); |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 80 | |
| 81 | [[clang::xray_never_instrument]] void never_instrumented(); |
| 82 | |
Fangrui Song | c66b956 | 2017-11-27 16:59:26 +0000 | [diff] [blame] | 83 | void alt_always_instrumented() __attribute__((xray_always_instrument)); |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 84 | |
| 85 | void alt_never_instrumented() __attribute__((xray_never_instrument)); |
| 86 | |
| 87 | When linking a binary, you can either manually link in the `XRay Runtime |
| 88 | Library`_ or use ``clang`` to link it in automatically with the |
Dean Michael Berris | 7577713 | 2017-02-28 22:01:26 +0000 | [diff] [blame] | 89 | ``-fxray-instrument`` flag. Alternatively, you can statically link-in the XRay |
| 90 | runtime library from compiler-rt -- those archive files will take the name of |
| 91 | `libclang_rt.xray-{arch}` where `{arch}` is the mnemonic supported by clang |
| 92 | (x86_64, arm7, etc.). |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 93 | |
| 94 | LLVM Function Attribute |
| 95 | ----------------------- |
| 96 | |
| 97 | If you're using LLVM IR directly, you can add the ``function-instrument`` |
| 98 | string attribute to your functions, to get the similar effect that the |
| 99 | C/C++/Objective-C source-level attributes would get: |
| 100 | |
| 101 | .. code-block:: llvm |
| 102 | |
| 103 | define i32 @always_instrument() uwtable "function-instrument"="xray-always" { |
Dean Michael Berris | 2adde22 | 2016-11-09 02:12:13 +0000 | [diff] [blame] | 104 | ; ... |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 105 | } |
| 106 | |
| 107 | define i32 @never_instrument() uwtable "function-instrument"="xray-never" { |
Dean Michael Berris | 2adde22 | 2016-11-09 02:12:13 +0000 | [diff] [blame] | 108 | ; ... |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 109 | } |
| 110 | |
| 111 | You can also set the ``xray-instruction-threshold`` attribute and provide a |
| 112 | numeric string value for how many instructions should be in the function before |
| 113 | it gets instrumented. |
| 114 | |
| 115 | .. code-block:: llvm |
| 116 | |
| 117 | define i32 @maybe_instrument() uwtable "xray-instruction-threshold"="2" { |
Dean Michael Berris | 2adde22 | 2016-11-09 02:12:13 +0000 | [diff] [blame] | 118 | ; ... |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 119 | } |
| 120 | |
Dean Michael Berris | 0379e10 | 2018-04-09 04:02:09 +0000 | [diff] [blame] | 121 | Special Case File |
| 122 | ----------------- |
| 123 | |
| 124 | Attributes can be imbued through the use of special case files instead of |
| 125 | adding them to the original source files. You can use this to mark certain |
| 126 | functions and classes to be never, always, or instrumented with first-argument |
| 127 | logging from a file. The file's format is described below: |
| 128 | |
| 129 | .. code-block:: bash |
| 130 | |
| 131 | # Comments are supported |
| 132 | [always] |
| 133 | fun:always_instrument |
| 134 | fun:log_arg1=arg1 # Log the first argument for the function |
| 135 | |
| 136 | [never] |
| 137 | fun:never_instrument |
| 138 | |
| 139 | These files can be provided through the ``-fxray-attr-list=`` flag to clang. |
| 140 | You may have multiple files loaded through multiple instances of the flag. |
| 141 | |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 142 | XRay Runtime Library |
| 143 | -------------------- |
| 144 | |
| 145 | The XRay Runtime Library is part of the compiler-rt project, which implements |
| 146 | the runtime components that perform the patching and unpatching of inserted |
| 147 | instrumentation points. When you use ``clang`` to link your binaries and the |
| 148 | ``-fxray-instrument`` flag, it will automatically link in the XRay runtime. |
| 149 | |
| 150 | The default implementation of the XRay runtime will enable XRay instrumentation |
| 151 | before ``main`` starts, which works for applications that have a short |
| 152 | lifetime. This implementation also records all function entry and exit events |
| 153 | which may result in a lot of records in the resulting trace. |
| 154 | |
| 155 | Also by default the filename of the XRay trace is ``xray-log.XXXXXX`` where the |
| 156 | ``XXXXXX`` part is randomly generated. |
| 157 | |
| 158 | These options can be controlled through the ``XRAY_OPTIONS`` environment |
| 159 | variable, where we list down the options and their defaults below. |
| 160 | |
| 161 | +-------------------+-----------------+---------------+------------------------+ |
| 162 | | Option | Type | Default | Description | |
| 163 | +===================+=================+===============+========================+ |
Dean Michael Berris | 7577713 | 2017-02-28 22:01:26 +0000 | [diff] [blame] | 164 | | patch_premain | ``bool`` | ``false`` | Whether to patch | |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 165 | | | | | instrumentation points | |
| 166 | | | | | before main. | |
| 167 | +-------------------+-----------------+---------------+------------------------+ |
Dean Michael Berris | f5f5294 | 2017-12-05 12:43:12 +0000 | [diff] [blame] | 168 | | xray_mode | ``const char*`` | ``""`` | Default mode to | |
| 169 | | | | | install and initialize | |
| 170 | | | | | before ``main``. | |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 171 | +-------------------+-----------------+---------------+------------------------+ |
| 172 | | xray_logfile_base | ``const char*`` | ``xray-log.`` | Filename base for the | |
| 173 | | | | | XRay logfile. | |
| 174 | +-------------------+-----------------+---------------+------------------------+ |
Dean Michael Berris | 69956ec | 2017-12-13 06:37:13 +0000 | [diff] [blame] | 175 | | verbosity | ``int`` | ``0`` | Runtime verbosity | |
| 176 | | | | | level. | |
| 177 | +-------------------+-----------------+---------------+------------------------+ |
Dean Michael Berris | 7577713 | 2017-02-28 22:01:26 +0000 | [diff] [blame] | 178 | |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 179 | |
| 180 | If you choose to not use the default logging implementation that comes with the |
| 181 | XRay runtime and/or control when/how the XRay instrumentation runs, you may use |
| 182 | the XRay APIs directly for doing so. To do this, you'll need to include the |
Dean Michael Berris | de00b9f | 2018-05-04 06:01:12 +0000 | [diff] [blame] | 183 | ``xray_log_interface.h`` from the compiler-rt ``xray`` directory. The important API |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 184 | functions we list below: |
| 185 | |
Dean Michael Berris | de00b9f | 2018-05-04 06:01:12 +0000 | [diff] [blame] | 186 | - ``__xray_log_register_mode(...)``: Register a logging implementation against |
| 187 | a string Mode identifier. The implementation is an instance of |
| 188 | ``XRayLogImpl`` defined in ``xray/xray_log_interface.h``. |
| 189 | - ``__xray_log_select_mode(...)``: Select the mode to install, associated with |
| 190 | a string Mode identifier. Only implementations registered with |
| 191 | ``__xray_log_register_mode(...)`` can be chosen with this function. |
| 192 | - ``__xray_log_init_mode(...)``: This function allows for initializing and |
| 193 | re-initializing an installed logging implementation. See |
| 194 | ``xray/xray_log_interface.h`` for details, part of the XRay compiler-rt |
| 195 | installation. |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 196 | |
Dean Michael Berris | de00b9f | 2018-05-04 06:01:12 +0000 | [diff] [blame] | 197 | Once a logging implementation has been initialized, it can be "stopped" by |
| 198 | finalizing the implementation through the ``__xray_log_finalize()`` function. |
| 199 | The finalization routine is the opposite of the initialization. When finalized, |
| 200 | an implementation's data can be cleared out through the |
| 201 | ``__xray_log_flushLog()`` function. For implementations that support in-memory |
| 202 | processing, these should register an iterator function to provide access to the |
| 203 | data via the ``__xray_log_set_buffer_iterator(...)`` which allows code calling |
| 204 | the ``__xray_log_process_buffers(...)`` function to deal with the data in |
| 205 | memory. |
Dean Michael Berris | 30d8d08 | 2016-11-16 02:18:23 +0000 | [diff] [blame] | 206 | |
Dean Michael Berris | de00b9f | 2018-05-04 06:01:12 +0000 | [diff] [blame] | 207 | All of this is better explained in the ``xray/xray_log_interface.h`` header. |
| 208 | |
| 209 | Basic Mode |
| 210 | ---------- |
| 211 | |
| 212 | XRay supports a basic logging mode which will trace the application's |
| 213 | execution, and periodically append to a single log. This mode can be |
| 214 | installed/enabled by setting ``xray_mode=xray-basic`` in the ``XRAY_OPTIONS`` |
| 215 | environment variable. Combined with ``patch_premain=true`` this can allow for |
| 216 | tracing applications from start to end. |
| 217 | |
| 218 | Like all the other modes installed through ``__xray_log_select_mode(...)``, the |
| 219 | implementation can be configured through the ``__xray_log_init_mode(...)`` |
| 220 | function, providing the mode string and the flag options. Basic-mode specific |
| 221 | defaults can be provided in the ``XRAY_BASIC_OPTIONS`` environment variable. |
Dean Michael Berris | 30d8d08 | 2016-11-16 02:18:23 +0000 | [diff] [blame] | 222 | |
Dean Michael Berris | 7577713 | 2017-02-28 22:01:26 +0000 | [diff] [blame] | 223 | Flight Data Recorder Mode |
| 224 | ------------------------- |
| 225 | |
| 226 | XRay supports a logging mode which allows the application to only capture a |
| 227 | fixed amount of memory's worth of events. Flight Data Recorder (FDR) mode works |
| 228 | very much like a plane's "black box" which keeps recording data to memory in a |
| 229 | fixed-size circular queue of buffers, and have the data available |
| 230 | programmatically until the buffers are finalized and flushed. To use FDR mode |
Dean Michael Berris | de00b9f | 2018-05-04 06:01:12 +0000 | [diff] [blame] | 231 | on your application, you may set the ``xray_mode`` variable to ``xray-fdr`` in |
| 232 | the ``XRAY_OPTIONS`` environment variable. Additional options to the FDR mode |
| 233 | implementation can be provided in the ``XRAY_FDR_OPTIONS`` environment |
| 234 | variable. Programmatic configuration can be done by calling |
| 235 | ``__xray_log_init_mode("xray-fdr", <configuration string>)`` once it has been |
| 236 | selected/installed. |
Dean Michael Berris | 7577713 | 2017-02-28 22:01:26 +0000 | [diff] [blame] | 237 | |
Keith Wyss | 630a4ac | 2017-08-02 21:47:27 +0000 | [diff] [blame] | 238 | When the buffers are flushed to disk, the result is a binary trace format |
| 239 | described by `XRay FDR format <XRayFDRFormat.html>`_ |
| 240 | |
Dean Michael Berris | 7577713 | 2017-02-28 22:01:26 +0000 | [diff] [blame] | 241 | When FDR mode is on, it will keep writing and recycling memory buffers until |
| 242 | the logging implementation is finalized -- at which point it can be flushed and |
| 243 | re-initialised later. To do this programmatically, we follow the workflow |
| 244 | provided below: |
| 245 | |
| 246 | .. code-block:: c++ |
| 247 | |
| 248 | // Patch the sleds, if we haven't yet. |
| 249 | auto patch_status = __xray_patch(); |
| 250 | |
| 251 | // Maybe handle the patch_status errors. |
| 252 | |
| 253 | // When we want to flush the log, we need to finalize it first, to give |
| 254 | // threads a chance to return buffers to the queue. |
| 255 | auto finalize_status = __xray_log_finalize(); |
| 256 | if (finalize_status != XRAY_LOG_FINALIZED) { |
| 257 | // maybe retry, or bail out. |
| 258 | } |
| 259 | |
| 260 | // At this point, we are sure that the log is finalized, so we may try |
| 261 | // flushing the log. |
| 262 | auto flush_status = __xray_log_flushLog(); |
| 263 | if (flush_status != XRAY_LOG_FLUSHED) { |
| 264 | // maybe retry, or bail out. |
| 265 | } |
| 266 | |
| 267 | The default settings for the FDR mode implementation will create logs named |
Dean Michael Berris | de00b9f | 2018-05-04 06:01:12 +0000 | [diff] [blame] | 268 | similarly to the basic log implementation, but will have a different log |
Dean Michael Berris | 7577713 | 2017-02-28 22:01:26 +0000 | [diff] [blame] | 269 | format. All the trace analysis tools (and the trace reading library) will |
| 270 | support all versions of the FDR mode format as we add more functionality and |
| 271 | record types in the future. |
| 272 | |
Dean Michael Berris | de00b9f | 2018-05-04 06:01:12 +0000 | [diff] [blame] | 273 | **NOTE:** We do not promise perpetual support for when we update the log |
| 274 | versions we support going forward. Deprecation of the formats will be |
Dean Michael Berris | 7577713 | 2017-02-28 22:01:26 +0000 | [diff] [blame] | 275 | announced and discussed on the developers mailing list. |
| 276 | |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 277 | Trace Analysis Tools |
| 278 | -------------------- |
| 279 | |
| 280 | We currently have the beginnings of a trace analysis tool in LLVM, which can be |
| 281 | found in the ``tools/llvm-xray`` directory. The ``llvm-xray`` tool currently |
| 282 | supports the following subcommands: |
| 283 | |
| 284 | - ``extract``: Extract the instrumentation map from a binary, and return it as |
| 285 | YAML. |
Dean Michael Berris | 7577713 | 2017-02-28 22:01:26 +0000 | [diff] [blame] | 286 | - ``account``: Performs basic function call accounting statistics with various |
| 287 | options for sorting, and output formats (supports CSV, YAML, and |
| 288 | console-friendly TEXT). |
Dean Michael Berris | fe376dc | 2017-11-30 05:35:51 +0000 | [diff] [blame] | 289 | - ``convert``: Converts an XRay log file from one format to another. We can |
Dean Michael Berris | de00b9f | 2018-05-04 06:01:12 +0000 | [diff] [blame] | 290 | convert from binary XRay traces (both basic and FDR mode) to YAML, |
Dean Michael Berris | fe376dc | 2017-11-30 05:35:51 +0000 | [diff] [blame] | 291 | `flame-graph <https://github.com/brendangregg/FlameGraph>`_ friendly text |
| 292 | formats, as well as `Chrome Trace Viewer (catapult) |
| 293 | <https://github.com/catapult-project/catapult>` formats. |
Dean Michael Berris | 7577713 | 2017-02-28 22:01:26 +0000 | [diff] [blame] | 294 | - ``graph``: Generates a DOT graph of the function call relationships between |
| 295 | functions found in an XRay trace. |
Keith Wyss | 4dea1f2 | 2017-10-19 22:35:09 +0000 | [diff] [blame] | 296 | - ``stack``: Reconstructs function call stacks from a timeline of function |
| 297 | calls in an XRay trace. |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 298 | |
Dean Michael Berris | 7577713 | 2017-02-28 22:01:26 +0000 | [diff] [blame] | 299 | These subcommands use various library components found as part of the XRay |
| 300 | libraries, distributed with the LLVM distribution. These are: |
| 301 | |
| 302 | - ``llvm/XRay/Trace.h`` : A trace reading library for conveniently loading |
| 303 | an XRay trace of supported forms, into a convenient in-memory representation. |
| 304 | All the analysis tools that deal with traces use this implementation. |
| 305 | - ``llvm/XRay/Graph.h`` : A semi-generic graph type used by the graph |
| 306 | subcommand to conveniently represent a function call graph with statistics |
| 307 | associated with edges and vertices. |
| 308 | - ``llvm/XRay/InstrumentationMap.h``: A convenient tool for analyzing the |
| 309 | instrumentation map in XRay-instrumented object files and binaries. The |
Keith Wyss | 4dea1f2 | 2017-10-19 22:35:09 +0000 | [diff] [blame] | 310 | ``extract`` and ``stack`` subcommands uses this particular library. |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 311 | |
| 312 | Future Work |
| 313 | =========== |
| 314 | |
| 315 | There are a number of ongoing efforts for expanding the toolset building around |
| 316 | the XRay instrumentation system. |
| 317 | |
Keith Wyss | 4dea1f2 | 2017-10-19 22:35:09 +0000 | [diff] [blame] | 318 | Trace Analysis Tools |
| 319 | -------------------- |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 320 | |
Keith Wyss | 4dea1f2 | 2017-10-19 22:35:09 +0000 | [diff] [blame] | 321 | - Work is in progress to integrate with or develop tools to visualize findings |
| 322 | from an XRay trace. Particularly, the ``stack`` tool is being expanded to |
| 323 | output formats that allow graphing and exploring the duration of time in each |
| 324 | call stack. |
| 325 | - With a large instrumented binary, the size of generated XRay traces can |
| 326 | quickly become unwieldy. We are working on integrating pruning techniques and |
| 327 | heuristics for the analysis tools to sift through the traces and surface only |
| 328 | relevant information. |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 329 | |
| 330 | More Platforms |
| 331 | -------------- |
| 332 | |
Dean Michael Berris | 7577713 | 2017-02-28 22:01:26 +0000 | [diff] [blame] | 333 | We're looking forward to contributions to port XRay to more architectures and |
| 334 | operating systems. |
Dean Michael Berris | f70da78 | 2016-11-09 00:24:58 +0000 | [diff] [blame] | 335 | |
| 336 | .. References... |
| 337 | |
| 338 | .. _`XRay whitepaper`: http://research.google.com/pubs/pub45287.html |
| 339 | |