[lttng-dev] Tracing a sequence of events through an application

[Julien Desfossez]

Hi,

> All,
> I'm wondering if this is something anyone has ever done before:
> We have a financial trading application for which we'd like to trace the timing of a sequence of related events with low impact.  For example, tracing a market data feed packet from its reception on the NIC, to its processing in the Market Data portion of the code, and on & on via other layers of the application until it finally reaches the Order Execution portion of the code where it sends out an Order on the stock exchange.  We're wondering if there's a proven reference for using LTTng-UST to enable session tracing which would link related activities in this way, as opposed to just providing aggregate timestamps at various tracepoints within our code.
> Has something like this ever been done before using LTTng-UST? If so, is there a reference available?

For this use-case, you will probably be interested in the "period"
mechanism of lttng-analyses [1]. It gives you a way to express
relationships between events (how to link the beginning and the end of a
period), and have nested periods as well.

When you have written the periods definition, it gives you statistics,
logs and frequency distributions, based on the duration and number of
periods encountered. It also outputs the same statistics and frequency
distribution for each period in relationship with its parent(s), and
will very soon support grouping these results based on the payload (for
example: latency frequency distribution of a particular request when
fieldX = 42).

If you want a quick example, you can have a look at [2].

The limitation of this feature, is that all sub-periods need to be fully
nested within their parents, so your instrumentation needs to be in the
form of "begin A, begin B, end B, end A" where you have a way to link
"begin B" with "begin A" (compared to "state A -> state B"). It works
for both cases, but the first one provides much more context information
since you can link the periods together. So it's not exactly for
sequences of events, but the advantage of working with periods is that
it gives you a lot of automatic analyses and the end.

This feature is currently only in the master branch of lttng-analyses,
but we expect a release by the end of the year, so now is a good time to
start playing with it. After that, we will do blog posts to illustrate
more all that can be done with it. This is a very powerful feature, but
is not necessarily easy to grasp, so take the time to play with it.
Basically, if you can manually follow a period from a trace, you can
express it with this feature.

Otherwise, I know TraceCompass provides a way to define a state machine
to follow sequences of events, but I'm not that familiar with it,
someone else on this ML will be able to give more details.

For your use-case of tracing from the time the packet arrives on the NIC
and follow the request up to user-space, we have developed a tracker for
this problem in the latency-tracker [3]. It only works "online", so it's
not a post-processing solution, but it can be used to detect latencies
at run-time and trigger the capture of tracing snapshots to investigate
further. As far as I know, it is the only solution that can compute the
delay from an interrupt to user-space at run-time, and with a little
help from user-space, it can continue following the processing in
user-space. We did a presentation with Mathieu this year at LinuxCon,
you can watch it here [4]. This project is also still in development in
the master branch, but if you are interested in more details, let me
know.

We would like to have the same analysis in our offline analyses in
lttng-analyses, but haven't had the time/funding for that yet.

I hope this helps, let us know if you have more questions and if it
solves the problem.

Thanks,

Julien

[1] https://github.com/lttng/lttng-analyses#period-options
[2] http://imgur.com/a/bZCgR
[3] https://github.com/efficios/latency-tracker
[4] https://www.youtube.com/watch?v=fTgD7sKoa_g