To kick-off this blog, we are going to discuss a small utility we use in Graph Node that might have value for other Rust projects. It is the ‘Stopwatch’, a simple but effective benchmarking tool to measure which part of the code is the bottleneck.

When benchmarking a program locally, you can use a stack-tracing tool (if your OS supports it), my favorite Rust one is Flamegraph. And you do not need to change your code to use it. But these are mostly meant for manual usage, and we wanted something we could leave always on in production, gathering data to be analyzed whenever desired.

We are particularly interested in the total time the program spent running a particular function. The simplest stopwatch might look like:

You can run this on the playground and it will print the measurements:

This seems to work well enough, but this approach will soon get you into trouble with double counting. For example what if bar calls foo? If you modify bar to be:

Running it you will see timings like these:

The time spent in foo is correct but the call to it inside bar will be counted for both functions, and results in the stopwatch accounting for a total time that is larger than the real total time. To prevent double counting, we need a stopwatch that can keep track of the stack of functions being executed, and pause the time for bar when foo is entered.

A better Stopwatch would be:

We can see it keeps track of the elapsed time internally, only requiring section ids as input. The section_stack allows to readily start the time for the previous section when the current section ends, so that all time is accounted for but no time is double counted. You can see it in action in this playground. And it will correctly print:

This is already good enough, but it can still get better depending on your use case. This is a utility that seems too small for its own crate, and different projects will have different customization needs. For our Stopwatch we also added a convenient section guard, so you can write:

And the “foo” section will implicitly end when the guard is dropped.

For The Graph, we use a stopwatch to measure where data sets, known as subgraphs, spend their time while being indexed. We report the results to Prometheus, as you can see here. The Prometheus metrics are then consumed by a Grafana panel:

You can dive into the full source code for the Stopwatch here.

Edge & Node is hiring Rust Engineers! See here for details.

Edge & Node is a software development company and the initial team behind The Graph. We create and support protocols and dApps that are building the decentralized future. Learn more about the Edge & Node vision at edgeandnode.com and follow us on Twitter and LinkedIn.