iwanders/scalopus

A tracing framework for C++ and Python.

Scalopus

This project provides a bridge to utilize Catapult's Trace Viewer found inside Chrom(e/ium) to display traces from an instrumented C++ program. This project was inspired by this slide from the cppcon 2016 "Rainbow Six Siege: Quest for Performance" presentation.

The main focus is on obtaining traces for each scope / stack frame of interest, this provides good information about where time is spent in the program. It requires instrumenting the source code of the program under inspection with tracepoints to indicate which scopes need to be tracked. To get the tracepoints out of the program there are two options LTTng can be used, minimal knowledge or interaction with LTTng is necessary to use Scalopus. Tracepoints can also be transfered over Scalopus' native transports, this elminates the need for LTTng, but is less performant.

The system can be used from either Python 2 or 3 through the use of the Python bindings and the scalopus Python module. See the readme of the scalopus_python folder for details.

The trace viewer used is available in all recent Chrome and Chromium browsers and can be opened by typing chrome://inspect?tracing in the address bar. This is normally used to display traces from Android or from within the browser itself. However, the trace viewer can also load traces from a remote target using the Devtools Protocol's tracing domain. The specification for the trace events of that domain can be found in the Trace Event Format documentation. Major benefit of using this interface is that almost everyone has it already installed and can consume and view traces.

TL;DR

Place trace points in C++ or Python Code, C++ example:

void fooBarBuz()
{
  TRACE_PRETTY_FUNCTION();  // RAII tracepoint using __PRETTY_FUNCTION__
  std::this_thread::sleep_for(std::chrono::milliseconds(200));
}
void c()
{
  TRACE_SCOPE_RAII("void c()");  // RAII tracepoint, name will be "void c()"
  std::this_thread::sleep_for(std::chrono::milliseconds(200));
  std::cout << "  c" << std::endl;
  fooBarBuz();
  std::this_thread::sleep_for(std::chrono::milliseconds(200));
}
// some more here

Start the binary with tracepoints, start scalopus_catapult_server, open chrome://inspect?tracing, click record twice, wait a bit, click stop and see:

View locally by opening chrome://tracing and loading trace_readme_example.json.gz

The scalopus_examples readme shows another, larger example that shows multiple processes and threads. The scalopus_python page shows how this would look using the Python bindings.

Scope tracing

For a brief explanation what we mean by tracing a scope, watch one minute of this video. After watching that video myself and doing some research I discovered that LTTng offers a way to obtain traces through -finstrument-functions and the provided library. This emits a tracepoint for each function that was compiled with the instrumentation flag and the tracepoint itself contains the address of the function. Using the object files you can then figure out which function was associated to that address. This is nice and convenient but it quickly breaks down for non-trivial programs because of the amount of tracepoints that are produced or because resolving the mapping between the function address and the function name becomes tricky.

To make this useful in a production environment we need to be able to manually specify which scopes we are interested in and we need to be able to attach a human readable string to a scope that was opened or closed. Putting this string into the tracepoint is possible, but this will result in a lot of duplicate data being sent through the tracing system and this will be detrimental to performance.

Scalopus aims to solve these problems by:

1. Tracepoints are placed manually in the source code of the program under test, the instrumentation step.
2. Scope tracepoints have a payload of just one 32 bit integer. This (opaque) number is an automatically generated (compile-time constant) 32 bit integer. The developer can specify a human readable string / name that is to be associated with this number.
3. Store this mapping between the tracepoint name and the tracepoint id and provide access to this mapping from outside of the process where the traces are being consumed.

To get the tracepoints out of the program LTTng is a good fit because it is performant and provides very little overhead if tracepoints are not being recorded. Additionally it allows toggling tracepoints by process id and other niceties.

Architecture

A picture is worth a thousand words, so here goes:

The subcomponents of scalopus are clearly separated:

• scalopus_interface Specifies the interfaces how the various components interact with each other.
• scalopus_transport Provides two implementations of the Transport interface.
• scalopus_general This provides the process information endpoint, which allows naming the process and its threads.
• scalopus_tracing This provides means of tracing scopes and the Provider and Source to visualise them.
• scalopus_catapult Provides the chrome devtools protocol endpoint webserver that allows consuming the traces.
• scalopus_examples This provides some examples on how to write instrumented source code.
• scalopus_python This provides Python (2 or 3) bindings for scalopus and a module to make tracepoints easier to work with.

Building

The three required dependencies are embedded in the thirdparty folder and use git submodules. Cmake 3.5.0 or higher is required and a compiler that supports C++14 features.

In order to use LTTng to get the traces out of the program under test one must install liblttng-ust-dev to consume the traces from lttng the babeltrace package is required:

apt-get install liblttng-ust-dev babeltrace

The Python bindings are built if Pybind11 is found. By default the Python3 bindings are built if Python3 is present. This requires the distutils and setuptools modules to be present and libpython3-dev package must be installed to provide the necessary header files. The Python 2 bindings require libpython-dev to be installed.

apt-get install python3-distutils python3-setuptools libpython3-dev libpython-dev

By default deflate support is enabled in Seasocks, this requires zlib1g-dev:

apt-get install zlib1g-dev

Then, building should be as simple as:

# Clone repo, recursively to ensure git submodules are cloned as well.
git clone --recurse-submodules https://github.com/iwanders/scalopus
# Build:
mkdir build; cd build
cmake ../scalopus/
make -j8
# run tests, this also runs the Python bindings' tests:
ctest .
# to install the Python bindings:
cd scalopus_python
python3 setup.py install # or python2 setup.py install, depending on which one was built.

Quickstart

After building and succesfully being able to run the tests, use the following steps to view some tracepoints:

1. Run ./scalopus_examples/readme_example to start a process that produces tracepoints.
2. Run ./scalopus_catapult/scalopus_catapult_server, this should output something like:

[main] Using port: 9222, 9222 is default, it is default remote debugging port
[main] Using path: ""  (empty defaults to lttng view scalopus_target_session)
[main] Everything started, falling into loop to detect transports. Use ctrl + c to quit.
[BabeltraceParser] Reached end of file, quiting parser function.
[scalopus] Creating transport to: <unix:8343>

3. Go go chrome://inspect?tracing (copy the link, clicking doesn't work), right of Target (120.0.6099.129) click trace, there's a text arrow pointing at the correct trace button. You should now be in the tracing viewer and see This about:tracing is connected to a remote device... at the top. Click record, record, wait a bit and press stop.
4. Profit.

Legal

• The Python bindings are produced using Pybind11. This uses the BSD-3-clause license.
• Json and bson handling is done with the json for modern C++ library. This uses the MIT license.
• The webserver and websocket handling is done with seasocks. This uses the BSD-2-clause license
• The Scalopus project itself is licensed under the BSD-3-clause license.

scalopus's Issues

Events may be lost if thread goes out of scope immediately

There's no guarantee that the thread event ringbuffer (from here) is empty when it is destroyed if the thread goes out of scope and the thread_local ringbuffer gets destroyed.

The cleanup lambda here or destructor of the thread's ringbuffer should check if the ringbuffer is empty, if it is not empty the events should be stored in a non-thread local buffer such that they are not lost but saved until they have been sent by the trace point sender.

This situation can occur if a thread creates events and immediately goes out of scope after. This is not a very common use case, but ideally it should be handled correctly.

CORE-17109, fyi @efernandez

Error trying to open trace_random_callstacks.json.gz

If I try to open trace_random_callstacks.json.gz from chrome://tracing, I get the following error:

While importing:
Error: Couldn't create an importer for the provided eventData.
at Import.createImporter_ (chrome://tracing/tracing.js:2020:2071)
at chrome://tracing/tracing.js:2015:167
at Task.run (chrome://tracing/tracing.js:3262:95)
at runAnother (chrome://tracing/tracing.js:3265:371)
at runTask (chrome://tracing/tracing.js:3027:57)
at processIdleWork (chrome://tracing/tracing.js:3032:116)
at window.requestIdleCallback.timeout (chrome://tracing/tracing.js:3025:81)

Cleanup list

Collecting some things for cleanup:

• Switch integer types to std:: flavours.
• Switch native trace type to enum backed by std::uint8_t instead of separate uint8_t.

Scalopus record script improvements

Improvements for the record script contributed in #9:

• -o filename for writing to a directly named file, detect .gz extension and zip if appropriate. It should still default to stdin.
• Limit recording to number of events. (!) This might required some support from the backend.
• Add logging for -v(v) that displays numbers of traces, etc. (!) Logging should probably be disabled if the script is writing to stdin.

@iwanders Any comments/corrections? This is based on your comment in #9 (comment)

Drop 16.04 github actions.

Build and test 16.04
Started 41m 57s ago
Can't find any online and idle self-hosted runner in the current repository, account/organization that matches the required labels: 'ubuntu-16.04'
Waiting for a self-hosted runner to pickup this job...```

Which makes the github action take forever. Should be ok to drop support for 16.04 as it has hit end of life.