Software
February 26, 2024

Tracing in Rust: A Comprehensive Guide

Master Rust tracing: synchronous, asynchronous, multithreaded, and distributed scenarios, with practical examples and essential tips.

Introduction

This article aims to provide a comprehensive overview of edge cases engineers may encounter when instrumenting their Rust code for tracing. While it assumes a basic understanding of tracing concepts such as spans, events, and contexts, it serves as a practical guide to applying tracing in Rust projects.

For further resources on tracing and related topics, consider exploring:

Key Concepts

Before delving into practical examples, let's briefly review some key concepts we'll be using:

  • Traces: collections of Spans
  • Subscribers: implements a way of collecting trace data, such as logging it to standard output
  • Spans: A function that got executed for a period X,
  • Events: should be used to represent points in time within a span
  • Trace Context: set of value that will be propagated between services

The tracing rust library doesn't provide any subscribers implementation, these are available in other crates like tracing-subscriber which we are going to use in this demo.

We will be using the `#[instrument]` macro to instrument functions in this tutorial instead of manually creating and entering spans.

Getting started

Before diving into instrumentation, let's set up the necessary dependencies and initialization code in our project.

Dependencies Installation

Initialization Code

Synchronous tracing

Synchronous tracing involves instrumenting your code to trace the execution of synchronous functions. Here's a simple example:

In this example, we've used the #[instrument] macro to automatically create spans for our functions, and the tracing_subscriber is configured to print these spans and events to stdout.

By running the above code you should see something like the following

2024-02-26T22:11:26.248663Z WARN ThreadId(01) sync_tracing: src/main.rs:44: event 1 2024-02-26T22:11:26.248724Z WARN ThreadId(01) sync_tracing:sync_tracing_sub: src/main.rs:51: event 2

Asynchronous Tracing

Tracing asynchronous code involves capturing the flow of execution within asynchronous functions and futures. Let's look at an example using the tokio runtime.

The tracing `#[instrument]` macros are used to create spans for both the main function and the asynchronous operation.

We have to import `tracing::Instrument` combinator in order to be able to instrument async functions as Span::enter may produce incorrect traces if the returned drop guard is held across an await points.

What's the difference between `tracing::Instrument` and `tracing_futures`?

Despite their apparent functional similarity, both tools perform identical tasks. The implementation itself aligns closely across the two. I've initiated an inquiry within the Tokio project to address the duplication of effort. Regardless of the selection between the two, functionality remains consistent.

What's the difference between `#[instrument]` and calling `.instrument` on an async function?

They both do the same thing, but the first one is automatic as its a procedural macro provided by the `tracing` crate. The second option is manual and provides more flexibility as you can choose where to place the instrumentation in the function or future.

Multithreaded Tracing using channel

Tracing multithreaded code requires a bit more work than just adding the `#[instrument]` macro on functions. We have to explicitly pass the span between the threads.

We are going to create a struct to hold both the Data we are sending across threads as well as the Span from the sending thread.

In this example, we've used Rust's mpsc channels to communicate between threads, ensuring that the span context is passed along with the data.

Distributed Tracing

This is essentially the act of tracking the trace and the corresponding span as the request propagates through the network between the different services.

The challenge here is that we need to make sure we are sending the trace context whenever we are initiating a request to another service.

We need to use opentelemetry::propagation to manage how the trace context is passed between components in a distributed system, aiding in tracking requests seamlessly.

Setup

First we need to set the given TextMapPropagator propagator as the current global propagator.

Next, it's essential to establish our custom PropagationContext structure, enabling us to define both the inject and extract functions. These functions respectively handle the injection and extraction processes. Through the TextMapPropagator, injection into any Injector trait-compatible type is facilitated. Similarly, extraction from any Extractor trait-compatible entity is enabled. Given that the context consists of key-value pairs, employing a HashMap is ideal for storing it.

Demo

The following is an oversimplification of a client/server request, but it should illustrate the concept of sending the trace context with your request

Other tips

  • Usewhen the outer span can be disabled.
  • Use for instrumenting synchronous code in an async environment.

Conclusion

Incorporating tracing into Rust projects enables better observability and debugging capabilities. By understanding and applying the concepts and techniques discussed in this article, engineers can effectively instrument their Rust code for tracing, even in complex scenarios such as asynchronous, multithreaded, and distributed environments.