fast / fastrace

A tracing library 10~100x faster than others
https://docs.rs/fastrace/
Apache License 2.0
182 stars 14 forks source link

Is it possible to get properties that has been attached to the span? #11

Open alekseysidorov opened 2 months ago

alekseysidorov commented 2 months ago

In the tracing crate, the log formatter can use span records to append them to the log output. This is useful for structured context logging.

Since the log crate has already stabilized the kv feature, there is an opportunity to implement tracing contextual structured logging on top of the fastrace and log combination.

But it need to expose the record attached to the span. As I understand, in this library such kind of records named properties. So can I get them from Span?

qRoC commented 2 months ago

In the tracing crate, the log formatter can use span records to append them to the log output. This is useful for structured context logging.

No, logs are added to the spans.

You should use reporter for logs output (see ConsoleReporter as example) and implement log::Log to add events to the span:

struct Logger;

impl log::Log for Logger {
    fn log(&self, record: &log::Record<'_>) {
         Event::add_to_local_parent("log", || {
            // ...

            if let Some(message) = record.args().as_str() {
                properties.push(("message", message).into());
            } else {
                properties.push(("message", record.args().to_string()).into());
            }

           // ...
           let mut visitor = KwWriter(&mut  properties); // your visitor
           record.key_values().visit(&mut visitor).expect("visit should not fail");

           properties
         })
    }
}

Also, see examples/log.rs

alekseysidorov commented 2 months ago

Yes, I read this example, but I want someting opposite. For example, I want to get the identifier of the current span and add it to the log record, so I can link the logs to this span.

qRoC commented 2 months ago

To directly correlate logs and traces use SpanContext::from_span/SpanContext::current_local_parent

andylokandy commented 2 months ago

@alekseysidorov I see. Logging alongside a traceid is indeed a highly requested feature and is already supported by fastrace. Logging the key-value properties from a span to the log output is a new but reasonable idea. However, there is a challenge due to the fundamental differences in the mechanisms of fastrace and tracing.

fastrace reports spans to the collector asynchronously, which is a key reason behind its performance. However, this asynchronicity also means that we cannot access span information in a synchronous context (e.g., when logging a message) because the information may not have been reported yet.

As an alternative, I suggest:

  1. Attaching logs to spans as events, as demonstrated in examples/logging.rs.
  2. Defining a reporter that generates log output from the events within the span records.

Additionally, we could explore outputting the logs in a structured of the trace spans: image https://github.com/datafuselabs/databend/pull/14495