Rust：自定義日誌中使用 tracing 之二

大家好，我是螃蟹哥。

在上一篇文章中 [1] 用於記錄事件。但是我們錯過了 tracing[2] 用於記錄事件。但我們錯過了 tracing[3] 生態系統的一大部分：跨度（spans）。

爲了記錄程序的執行流程，tracing引入了 spans[4] 的概念。與代表_時刻_的日誌線不同，跨度代表具有開始和結束_的時間段_。當程序開始在上下文中執行或執行工作單元時，它進入該上下文的跨度，當它在該上下文中停止執行時，它_退出_該跨度。

–tracing文檔

讓我們看看是否可以將一些上下文添加到我們的日誌輸出中。

更多基礎工作

如果我們要圍繞跨度進行一些探索，我們需要一些跨度。讓我們創建一個外跨度和一個內跨度。從概念上講，跨度和事件創建嵌套的東西

所以讓我們更新 main.rs。span.enter()[5] 使用保護模式保持輸入的跨度，直到它超出作用域，然後退出。所以在我們的 main 中，我們在函數的末尾依次退出內部和外部。

use tracing::{debug_span, info, info_span};
use tracing_subscriber::prelude::*;

mod custom_layer;
use custom_layer::CustomLayer;

fn main() {
    tracing_subscriber::registry().with(CustomLayer).init();

    let outer_span = info_span!("outer", level = 0);
    let _outer_entered = outer_span.enter();

    let inner_span = debug_span!("inner", level = 1);
    let _inner_entered = inner_span.enter();

    info!(a_bool = true, answer = 42, message = "first example");
}

examples/figure_5/main.rs[6]

回到我們的事件處理程序，我們能夠獲得這個上下文。如果存在的話，ctx.event_span(event)[7] 會給我們事件的父跨度。我們可以使用它，但還有更好的東西：ctx.event_scope(event)[8] 將給出所有跨度的迭代器。

在我們的例子中，它會先給我們 “內跨度”，然後是 “外跨度”。

如果我們想要它們反過來，scope.from_root()[9] 將它們翻轉並給我們從外向內的跨度。在我們的例子中，“外跨度” 然後是 “內跨度”。

順便說一句，要使用 ctx.event_scope()，我們的訂閱者需要實現LookupRef。

impl<S> Layer<S> for CustomLayer
where
    S: tracing::Subscriber,
    // Scary! But there's no need to even understand it. We just need it.
    S: for<'lookup> tracing_subscriber::registry::LookupSpan<'lookup>,
{
    fn on_event(&self, event: &tracing::Event<'_>, ctx: tracing_subscriber::layer::Context<'_, S>) {
        // What's the parent span look like?
        let parent_span = ctx.event_span(event).unwrap();
        println!("parent span");
        println!("  name={}", parent_span.name());
        println!("  target={}", parent_span.metadata().target());

        println!();

        // What's about all of the spans that are in scope?
        let scope = ctx.event_scope(event).unwrap();
        for span in scope.from_root() {
            println!("an ancestor span");
            println!("  name={}", span.name());
            println!("  target={}", span.metadata().target());
        }
    }
}

examples/figure_5/custom_layer.rs[10]

執行 cargo run 的結果：

parent span
  name=inner
  target=figure_5

an ancestor span
  name=outer
  target=figure_5
an ancestor span
  name=inner
  target=figure_5
cargo run --example figure_5

我們可以解決這個問題。但是就像在第一篇文章中一樣，我們沒有任何字段數據。真正使上下文有用的是現場數據。

當然，我們記得第一篇文章中的訪問者，所以這應該很容易，對吧?

跨度數據在哪裏？

好吧，我們知道訪客。但是我們從ctx.event_scope那裏拿回來的東西 [11] 沒有任何方法可以訪問他們的字段。這是怎麼回事？

你可能還記得_爲什麼_我們必須使用訪問者來獲取事件數據：因爲 tracing[12] 從不保留字段數據。如果它不保留數據，我們不應該指望它擁有很久很久以前輸入的跨度的數據。

但並不是所有的都丟失了。是時候開始探索 Layer[13] 的其他 trait 方法了。具體來說，讓我們看看在on_new_span創建新跨度時調用哪個 —— 正如你可能從名稱中猜到的那樣。

impl<S> Layer<S> for CustomLayer
where
    S: tracing::Subscriber,
    S: for<'lookup> tracing_subscriber::registry::LookupSpan<'lookup>,
{
    fn on_new_span(
        &self,
        attrs: &tracing::span::Attributes<'_>,
        id: &tracing::span::Id,
        ctx: tracing_subscriber::layer::Context<'_, S>,
    ) {
        let span = ctx.span(id).unwrap();
        println!("Got on_new_span!");
        println!("  level={:?}", span.metadata().level());
        println!("  target={:?}", span.metadata().target());
        println!("  name={:?}", span.metadata().name());

        // Our old friend, `println!` exploration.
        let mut visitor = PrintlnVisitor;
        attrs.record(&mut visitor);
    }
}

examples/figure_6/custom_layer.rs[14]

Got on_new_span!
  level=Level(Info)
  target="figure_7"
  
  field=level value=0
Got on_new_span!
  level=Level(Debug)
  target="figure_7"
  
  field=level value=1
cargo run --example figure_6

這是我們的數據。現在關鍵是：我們只有一次機會訪問一個跨度中的數據——當它被創建時。tracing[15] 不保留它供我們以後的訪問。如果我們記錄跨度，那很好。如果我們稍後在記錄事件時嘗試獲取跨度數據，則不太好，因爲跨度數據不再存在。

如果tracing不爲我們存儲數據，那麼我們開發人員該怎麼辦？

自己存儲跨度數據

我們真正想做的是在我們看到時捕獲跨度數據，然後將其存儲在某個地方，以便我們以後可以獲取它。

雖然 tracing 不會存儲數據本身，但tracing-subscriber讓我們自己存儲數據變得非常容易。它稱之爲 “擴展”，我們看到的每個跨度都有一種方法可以將擴展附加到它上面。

BTreeMap<String, serde_json::Value>從技術上講，我們可以將上一篇文章存儲在擴展中。但是因爲擴展數據由註冊表中的所有層共享，所以只存儲我們自己創建的私有類型被認爲是一種很好的形式。所以我們將圍繞它創建一個 newtype 包裝器。

#[derive(Debug)]
struct CustomFieldStorage(BTreeMap<String, serde_json::Value>);

examples/figure_8/custom_layer.rs[16]

每當我們看到一個新的跨度時，我們都會構建我們的 JSON 字段對象並將其存儲在擴展數據中。

fn on_new_span(
    &self,
    attrs: &tracing::span::Attributes<'_>,
    id: &tracing::span::Id,
    ctx: tracing_subscriber::layer::Context<'_, S>,
) {
    // Build our json object from the field values like we have been
    let mut fields = BTreeMap::new();
    let mut visitor = JsonVisitor(&mut fields);
    attrs.record(&mut visitor);

    // And stuff it in our newtype.
    let storage = CustomFieldStorage(fields);

    // Get a reference to the internal span data
    let span = ctx.span(id).unwrap();
    // Get the special place where tracing stores custom data
    let mut extensions = span.extensions_mut();
    // And store our data
    extensions.insert::<CustomFieldStorage>(storage);
}

examples/figure_8/custom_layer.rs[17]

現在，在我們有一個跨度的任何地方（就像在我們的on_event方法中一樣），我們可以獲取我們存儲的數據。

// Get the special place where tracing stores custom data
let extensions = span.extensions();
// And get the custom data we stored out of it
let storage: &CustomFieldStorage = extensions.get::<CustomFieldStorage>().unwrap();
// And because `CustomFieldStorage` is just a newtype around our JSON object, we
// can get the JSON object that we stored.
let field_data: &BTreeMap<String, serde_json::Value> = &storage.0;

examples/figure_8/custom_layer.rs[18]

一個幾乎全功能的 JSON 記錄器

因此，我們將迄今爲止所學的知識與我們已有的 JSON 記錄器混合起來，我們應該能夠將上下文跨度數據添加到我們的記錄器中。十分簡單。

fn on_event(&self, event: &tracing::Event<'_>, ctx: tracing_subscriber::layer::Context<'_, S>) {
    // All of the span context
    let scope = ctx.event_scope(event).unwrap();
    let mut spans = vec![];
    for span in scope.from_root() {
        let extensions = span.extensions();
        let storage = extensions.get::<CustomFieldStorage>().unwrap();
        let field_data: &BTreeMap<String, serde_json::Value> = &storage.0;
        spans.push(serde_json::json!({
            "target": span.metadata().target(),
            "name": span.name(),
            "level": format!("{:?}", span.metadata().level()),
            "fields": field_data,
        }));
    }

    // The fields of the event
    let mut fields = BTreeMap::new();
    let mut visitor = JsonVisitor(&mut fields);
    event.record(&mut visitor);

    // And create our output
    let output = serde_json::json!({
        "target": event.metadata().target(),
        "name": event.metadata().name(),
        "level": format!("{:?}", event.metadata().level()),
        "fields": fields,
        "spans": spans,
    });
    println!("{}", serde_json::to_string_pretty(&output).unwrap());
}

examples/figure_9/custom_layer.rs[19]

讓我們運行它以便確定一下。

{
  "fields": {
    "a_bool": true,
    "answer": 42,
    "message": "first example"
  },
  "level": "Level(Info)",
  "name": "event examples/figure_9/main.rs:16",
  "spans": [
    {
      "fields": {
        "level": 0
      },
      "level": "Level(Info)",
      "name": "outer",
      "target": "figure_9"
    },
    {
      "fields": {
        "level": 1
      },
      "level": "Level(Debug)",
      "name": "inner",
      "target": "figure_9"
    }
  ],
  "target": "figure_9"
}
cargo run --example figure_9

完美！

等等，幾乎功能齊全嗎？

當我爲我的工作這樣做時，我確實成功了。而且效果很好。但後來我發現，要得到一個完全功能的記錄器，還差一小步。

這還不是功能齊全的原因是因爲跨度可以在創建_後_記錄數據。

let outer_span = info_span!("outer", level = 0, other_field = tracing::field::Empty);
let _outer_entered = outer_span.enter();
// Some code...
outer_span.record("other_field", &7);

examples/figure_10/main.rs[20]

如果我們現在按原樣運行我們的記錄器，我們會錯過 "other_field" 因爲當我們收到我們的on_new_span 事件時它不存在。

但是現在我們已經深入研究了層、跨度和擴展的工作原理，這甚至不應該再讓我們分階段了。我們唯一真正需要知道的是，對於這種情況，Layer[21] 也有一種 on_record 方法。其他一切都是我們已經完成的工作的變體。

fn on_record(
    &self,
    id: &tracing::span::Id,
    values: &tracing::span::Record<'_>,
    ctx: tracing_subscriber::layer::Context<'_, S>,
) {
    // Get the span whose data is being recorded
    let span = ctx.span(id).unwrap();

    // Get a mutable reference to the data we created in on_new_span
    let mut extensions_mut = span.extensions_mut();
    let custom_field_storage: &mut CustomFieldStorage =
        extensions_mut.get_mut::<CustomFieldStorage>().unwrap();
    let json_data: &mut BTreeMap<String, serde_json::Value> = &mut custom_field_storage.0;

    // And add to using our old friend the visitor!
    let mut visitor = JsonVisitor(json_data);
    values.record(&mut visitor);
}

examples/figure_10/custom_layer.rs[22]

現在，在兩篇文章之後，我們有了一個功能齊全的自定義 JSON 記錄器。

原文鏈接：https://burgers.io/custom-logging-in-rust-using-tracing-part-2

參考資料

[1]

上一篇文章中: https://mp.weixin.qq.com/s/hEBFIY-I0toUGxh45tTEPQ

[2]

tracing: https://docs.rs/tracing/0.1

[3]

tracing: https://docs.rs/tracing/0.1

[4]

spans: https://docs.rs/tracing/0.1/tracing/span

[5]

span.enter(): https://docs.rs/tracing/0.1.29/tracing/span/struct.Span.html#method.enter

[6]

examples/figure_5/main.rs: https://github.com/bryanburgers/tracing-blog-post/blob/main/examples/figure_5/main.rs

[7]

ctx.event_span(event): https://docs.rs/tracing-subscriber/0.3/tracing_subscriber/layer/struct.Context.html#method.event_span

[8]

ctx.event_scope(event): https://docs.rs/tracing-subscriber/0.3/tracing_subscriber/layer/struct.Context.html#method.event_scope

[9]

scope.from_root(): https://docs.rs/tracing-subscriber/0.3/tracing_subscriber/registry/struct.Scope.html#method.from_root

[10]

examples/figure_5/custom_layer.rs: https://github.com/bryanburgers/tracing-blog-post/blob/main/examples/figure_5/custom_layer.rs

[11]

東西: https://docs.rs/tracing-subscriber/0.3/tracing_subscriber/registry/struct.SpanRef.html

[12]

tracing: https://docs.rs/tracing/0.1

[13]

Layer: https://docs.rs/tracing-subscriber/0.3/tracing_subscriber/layer/trait.Layer.html

[14]

examples/figure_6/custom_layer.rs: https://github.com/bryanburgers/tracing-blog-post/blob/main/examples/figure_6/custom_layer.rs

[15]

tracing: https://docs.rs/tracing/0.1

[16]

examples/figure_8/custom_layer.rs: https://github.com/bryanburgers/tracing-blog-post/blob/main/examples/figure_8/custom_layer.rs

[17]

examples/figure_8/custom_layer.rs: https://github.com/bryanburgers/tracing-blog-post/blob/main/examples/figure_8/custom_layer.rs

[18]

examples/figure_8/custom_layer.rs: https://github.com/bryanburgers/tracing-blog-post/blob/main/examples/figure_8/custom_layer.rs

[19]

examples/figure_9/custom_layer.rs: https://github.com/bryanburgers/tracing-blog-post/blob/main/examples/figure_9/custom_layer.rs

[20]

examples/figure_10/main.rs: https://github.com/bryanburgers/tracing-blog-post/blob/main/examples/figure_10/main.rs

[21]

Layer: https://docs.rs/tracing-subscriber/0.3/tracing_subscriber/layer/trait.Layer.html

[22]

examples/figure_10/custom_layer.rs: https://github.com/bryanburgers/tracing-blog-post/blob/main/examples/figure_10/custom_layer.rs

本文由 Readfog 進行 AMP 轉碼，版權歸原作者所有。
來源：https://mp.weixin.qq.com/s/fRDIdOjsDJcZVXgmULjrtg

猜你喜歡