# Distributed Tracing

Using this thread to solidify my understanding of distributed tracing. Also hoping it will be informative to everyone else as well!

## Why do we need tracing? (Non-distributed)
When we have a program running on different threads/tasks, it is challenging to follow the traditional logs, as the logs from the threads are mixed together. It would be helpful, if for e.g., all the log lines in a particular function were grouped together and then printed out. This would allow us to follow the code better. The tokio's tracing crate does just that. They use something called as a [Span](https://docs.rs/tracing/latest/tracing/span/index.html) to group sections of the logs together.

So every log line (called an [Event](https://docs.rs/tracing/latest/tracing/struct.Event.html)) that lies from the beginning of a span till the end of the span is grouped together. This **span which can consist of multiple events/logs** is then sent to a [Subscriber](https://docs.rs/tracing/latest/tracing/trait.Subscriber.html) for it to be printed to a file or maybe forwarded to an OpenTelemetry server.

fn without_macro(&self) {
    let my_var: u64 = 5;
    // a span with a trace level. Captures `my_var` as a valid key-value pair instead
    // of printing it as a string
    let my_span = span!(Level::TRACE, "my_span", my_var);
    
    // `my_span` exists but has not been entered.
    
    // Enter `my_span`...
    let _enter = my_span.enter();
    
    // Capture my_var inside an event
    tracing::info!("This is an event", ?my_var);
    // Dropping the `_enter` guard will exit the span.
}

// The macro can be heavily configured
#[tracing::instrument(skip(self)]
fn with_macro(&self) {
    // The macro creates and enters the span
    tracing::info!(...
}

PS: Correct me if I'm wrong, but currently the `tracing_fmt` Subscriber layer that is responsible for printing the logs to the files, prints each event at the moment they occur instead of grouping them together based on their span. The Span info is still present, but they're not appropriately utilised.

### Linking Spans together
A Span can have zero or one parent Span, i.e., when a span is entered when it's within another span's scope, it becomes the child of the outer span. This would allow us to track, from where a particular function/span was triggered and then follow it..

#[instrument]
fn parent() {
    info!("parent");
    child();
}
#[instrument]
fn child() {
    info!("child");
}

When analyzed using proper tools like Jaeger, OpenSearch, ElasticSearch, etc., they can link spans together to form a **Trace.** Traces can help us understand the flow of a particular execution in our system. Spans also record their beginning and end times, which can help us identify the lagging parts in our code.

## Need for [Distributed Tracing](https://www.elastic.co/blog/distributed-tracing-opentracing-and-elastic-apm)
The linking of spans can be further expanded to scenarios where a request can span multiple Services. These are most commonly used in a microservice architecture, where a request can flow from the Client to `n` number of servers before returning a response. Here the Span's context can be propagated from the Client through all the servers, linking the logs together. This would greatly simplify the amount of time spent on debugging an issue.

### Linking Spans from different services together [(Rust)](https://peterpaul.hashnode.dev/opentelemetry-context-propagation-with-rust)
To link together spans from one service to another, we need a way to propagate the context from the source and then apply this context at the destination. Luckily, there is an OpenTelemetry specification that allows for [Context Propagation](https://opentelemetry.io/docs/reference/specification/context/api-propagators/).

The rust `opentelemetry` crate provides a [TextMapPropagator](https://docs.rs/opentelemetry/0.18.0/opentelemetry/propagation/trait.TextMapPropagator.html) trait that can help us inject and extract the span context however we want. There is a pre-implemented struct called, [TraceContextPropagator](https://docs.rs/opentelemetry/0.18.0/opentelemetry/sdk/propagation/struct.TraceContextPropagator.html) that encodes the context information in the [W3C TraceContext](https://www.w3.org/TR/trace-context/) format. The format simply suggests storing a set of fields as a key-value pair, hence we can use a `HashMap` to achieve it.

pub struct TracingPropagator {
    context: HashMap<String, String>,
}

impl TracingPropagator {
    /// Inject an optl context
    pub fn inject(context: &opentelemetry::Context) -> Self {
        global::get_text_map_propagator(|propagator| {
            let mut tracing_prop = Self::default();
            propagator.inject_context(context, &mut tracing_prop);
            tracing_prop
        })
    }

    // Extract an optl context
    pub fn extract(&self) -> opentelemetry::Context {
        global::get_text_map_propagator(|propagator| propagator.extract(self))
    }
}
impl Injector for TracingPropagator {}
impl Extractor for TracingPropagator {}

We can now inject the Span's context into the `TracingPropagtor` at the source and send it over to the destination where the span can be set as the parent span.

// inject our current span's context and now send over this struct to the other service
let tracing_propgator = TracingPropagator::inject(&Span::current().context());

// extract this context at the dst and set it as its parent span
let tracing_ctx = tracing_prop.extract();
Span::current().set_parent(tracing_ctx);

## Implementing Distributed Tracing for the SafeNetwork
Distributed tracing can drastically reduce the debugging time and provide valuable insights into how a component fits into the larger system. They can for e.g., help us visualize the request from Clients and all the executions triggered on the node side. Not only that, we can also track the chain effect between the nodes that can happen during a major event, like a split/elder change.

The `TracingPropagator` can be sent via the `WireMsgHeader` to the other nodes where it can be set as the parent span at `handle_msg`. Now, any code executed on the dst side can be linked to the chain of events from the source side, providing us with causality for a particular event. Also, the `Cmds` that are generated should carry over the correct span (spawned tasks have to be manually instrumented).

Finally, the produced trace would span over multiple nodes/cmds..
### Some Caveats
- [Async fn should be properly instrumented](https://docs.rs/tracing/latest/tracing/span/struct.Span.html#in-asynchronous-code). TLDR: use the macro if you have any `.await` points
- [Spawned tasks should be properly instrumented](https://docs.rs/tracing/latest/tracing/span/struct.Span.html#method.or_current) ( an [example](https://github.com/tokio-rs/tracing/blob/master/examples/examples/tokio-spawny-thing.rs) )
- Clippy currently has a bug where the `#[instrument]` macro interferes with it, [preventing some errors from being detected.](https://github.com/maidsafe/safe_network/pull/2073)
- If a function is not instrumented or if it's not within another span's scope, then any log/event within the function is not recorded.
- The file logger that we use currently acts just like a standard logger, and hence it can print all the events.
- But the OpenTelemetry Subscriber will not send over events if it is not inside a Span's scope.
- We might need a better way to visualize the traces, currently the view provided by OpenSearch (image 1) would only be helpful if our traces are linear. But in our case, a single trigger might produce a trace with multiple branches across multiple nodes.