[llvm-dev] RFC: XRay -- A Function Call Tracing System

[Dean Michael Berris via llvm-dev]

TL;DR: At Google we use a call tracing system called XRay which inserts
patchable instrumentation points into function entries and exits. If the
community is interested, we'd like to contribute this system to the LLVM
project. Many more details are contained in the whitepaper at:
https://storage.googleapis.com/xray-downloads/whitepaper/XRayAFunctionCallTracingSystem.pdf

Who's "we": dberris at google.com, echristo at google.com

Overview

At Google we use XRay to build binaries that have "nop sleds" at function
call entry and exits that we can patch at runtime to insert instrumentation
calls. We use this to generate sufficiently accurate function call timings
to help track down the source of production service latency. Alternate uses
include getting function call statistics (histogram of function timings),
and generating function call traces (sample of call stacks) to analyse call
graphs (for example, analysing calls to malloc()/free()).

We have also developed analysis tools for this data, and are continuing to
build on top of them with the intent of making them available outside of
Google in the long term.

The key features of this system are:

   -

   Enable/disable the instrumentation at runtime.
   -

   Control which functions get the instrumentation points at compile time.
   We do this through some configurable heuristics (i.e. only functions with
   >N instructions or that have loop constructs) and whitelists/blacklists
   (i.e. always instrument functions X, Y, Z and never instrument functions A,
   B, C).
   -

   Source-level annotations (__attribute__(...), [[...]]) to specify
   whether or not a function should be instrumentable at a fine-grained level.


Currently this works on x86-64, but we are going to make this work on a few
other platforms as well.

Proposal

The approach involves the following:


   1.

   *Clang+LLVM:* Add support for a C++ function attribute (
   `[[clang::function-instrument=xray-{always,never}]]`) to indicate whether a
   function should either always or never be instrumentable. The intent is to
   propagate this attribute as text attributes on LLVM functions until we can
   consolidate the function instrumentation implementations to use this
   attribute too.
   2.

   *Clang:* Add flags (`-fxray-instrument=`) to enable and control this
   behaviour. Further configuration flags will enable users to specify
   functions to always/never instrument, and add thresholds for some
   heuristics.
   3.

   *LLVM:* Add new LLVM pseudo instructions for indicating where the
   instrumentation sleds should be placed, and what kind of sleds these are.
   For entry sleds, we can use the `PATCHABLE_OP` instruction, and a new
   instruction for patching exits (`PATCHABLE_RET`?) that get handled by the
   assembly printer per platform. Currently only implemented for x86_64.
   4.

   *LLVM:* Use a separate section to map the instrumentation sled
   locations. This will work even in non-debug builds and the sections will be
   merged by the linker.
   5.

   *compiler-rt:* Implement a few functions in compiler-rt under either
   profiling or under a new library (we'd like to call it "xray") that look
   like the following:
   `__xray_patch(...)` <- takes a function pointer, installs some code at
   runtime in the instrumentation points; the provided function will be
   user-provided.
   `__xray_cleanup()` <- removes the instrumentation code and turns them
   back into the "nop sleds".
   `__xray_dump_table(...)` <- provides a means of inspecting the mapping
   between instrumentation points and function names, useful for
   post-processing.


As a proof of concept usage of this, we're contributing a tool to do
function call accounting for a binary. It will use the XRay compiler-rt
library to install function call logging to an in-memory circular buffer,
and dump out the log to a file at program completion (or triggered with a
signal handler) in a simple trace format. There’s also a command-line tool
for interpreting this data to generate useful statistics.

We're committed to bringing more of the runtime library into LLVM with
consultation and collaboration with the larger community. This includes
things like:


   -

   Support for adding context-specific annotations (e.g. for RPCs, memory
   allocation/deallocation tracing, etc.)
   -

   Accurate function call logging and heuristics around this to handle
   programs that do a lot of work.
   -

   A data analysis framework for dealing with a trace format.


As an initial step, the high level idea is to build the infrastructure
(steps 1-5) into LLVM first to allow us and the community at large to build
upon this (bring this to other platforms, make it more efficient, add
features that matter when debugging performance issues with C++ binaries,
etc.). The next step is potentially to create a project in LLVM dedicated
to the tooling around XRay -- this will contain a library for function call
logging/tracing, documentation, and libraries for reading/manipulating the
trace format that XRay can generate.

Key questions:


   -

   Is this something the LLVM community is interested in having?
   -

   Do you have feedback on the proposed approach?
   -

   Do you see any large complications/blockers to getting this supported as
   part of LLVM?


Alternatives/Related Art

We also looked at other tools that do things similar to what's being
proposed here, and we'd like to say a few words about the differences:

Pintools: This works at too low a level (binaries, machine code) which
usually doesn't provide as much information or control to the programmer
doing the debugging. There are also significant overheads involved in
making this work in a production environment.

Intel PT: Although very powerful, the level of detail it provides is very
different (and is actually complementary) to doing strictly function call
tracing. It also requires hardware and kernel support. XRay is purely in
userland.

dtrace: It requires kernel support to get going, as opposed to a purely
userland solution. Although what's being proposed is purely a subset of the
functionality available to dtrace, we find that the idea itself (function
call tracing) has merit and would like to cite the existence of dtrace as
"proof of validity" to the overall approach. :)

Valgrind: There are similarities for what Valgrind does with XRay without
needing the instrumentation points to be inserted. Dynamic code rewriting
is certainly one possible approach to solving this problem. When we measure
the costs of using Valgrind compared to XRay we've found that the targeted
nature of XRay's instrumentation (and logging) tended to perform better and
more tolerable in production.

DynamoRIO: DR does much of what Valgrind does in a very flexible and
configurable manner. We think XRay can be implemented as a purely
runtime-dynamic rewriting approach but the costs of maintaining alternate
versions of the code in memory and the effects on indirect function calls
makes this less efficient than the combination of static instrumentation
points and targeted runtime patching.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.llvm.org/pipermail/llvm-dev/attachments/20160429/97a035b9/attachment.html>