Rust 語言的全鏈路追蹤庫 tracing

在一個應用程序或庫的開發過程中，除了其本身的邏輯以外，開發人員還需要做很多額外的工作，以保證編寫的代碼可以正確的運行，或者在出錯時可以快速定位到錯誤的位置以及原因，這就需要引入一些額外的工具，trace 就是其中特別好用的一種，下文我將會簡單介紹 trace，並以 Rust 爲例，演示 trace 在 Rust 中的使用方法。

1 可觀測性

Logs、Metrics 和 Traces 並稱爲可觀測性三大支柱，通過分析它們輸出的數據，開發人員能夠更好的觀測到系統的運行狀況，更快的定位問題，從而提高系統的可靠性。

日誌 (Logs)

日誌作爲最常用的可觀測性數據源之一，相信多數開發者都比較熟悉。其本質上就是一種帶有時間戳的離散事件記錄，通常用於記錄系統的運行狀態，日誌的使用十分簡單，只需要在代碼中需要報告信息的點添加一行代碼，就可以將這些信息輸出到控制檯或文件中，但是日誌也有很大的缺點，它的輸出是離散的，這意味着在記錄的時候，無法將日誌信息相互關聯，也無法知道日誌信息的上下文，尤其是在多線程的環境下，最終輸出的信息比較混亂，不便於檢索和分析。

指標 (Metrics)

指標是一種定量衡量，例如平均值、比率和百分比等。其值始終爲數字而非文本，可以通過數學方法統計和分析，其主要用於描述系統運行狀態的數據，比如 CPU 的使用率、內存的使用率、磁盤的使用率等，這些數據可以用來監控系統的運行狀態，也可以用來預警。

追蹤 (Traces)

追蹤是一種用於記錄系統中一次請求的完整生命週期的數據，它可以記錄下一個請求從開始到結束的所有信息，包括請求的發起者、接收者、請求的路徑、請求的狀態、請求的耗時、請求的錯誤信息等，這些信息可以用來分析系統的性能瓶頸，也可以用來分析系統的錯誤。追蹤本質上也是一種日誌，他與日誌的數據結構十分相似，但是它能夠提供比日誌更豐富的信息。特別是在分佈式系統中，追蹤能夠跨越多個服務，彙總出一次請求的完整信息，讓開發人員能夠更方便的找到系統中的問題。

2 Rust 中的 Trace

Rust 社區中比較有名的 trace 實現有三個：

接下來就以 tracing 爲例，介紹一下 trace 的核心概念以及使用方法：

Span

Span 可以說是 trace 中最關鍵的概念之一，它表示的是一個過程，也就是一段時間內發生的所有事件的集合，其數據結構中包含着 Span 的開始時間和結束時間，在分析數據是可以藉助工具直觀的看到某次請求或操作的耗時情況。在同一個 trace 流程中的所有 Span 都共享這相同的 Trace Id ，每個 Span 也有着自己的 Span Id，並且 Span 還支持嵌套，嵌套的 Span 中也會保存着相應的父子關係，最終可以靠這些信息，將請求的完整生命週期串聯起來，並且不會與相同時間段內的其他請求產生干擾。

use tracing::{span, Level};

fn main() {
    let span = span!(Level::INFO, "span");
    let _enter = span.enter();
    // enter 後進入該 span 的上下文
    // 可以記錄信息到 span 中
} // 離開作用域後，_enter 被 drop，對應的 span 在此結束

以上代碼是創建並使用一個 Span 最簡單的方式，除此以外還有幾種不同的方式

#[instrument] // tracing 會爲當前函數自動創建 span ，該 span 名與函數相同，並且整個函數都在該 span 的上下文內
fn do_something() {
    // some event
    let span = span!(Level::INFO, "external function");
    span.in_scope(|| some_external_function()); //對於無法添加 #[instrument] 的外部函數，也可以使用 in_scope 方法讓其在 span 的上下文中執行
}

#[instrument] // 此方法同樣對異步函數適用
async fn do_something_async() {
    let future = async {
        // some async code
    };
    let span = span!(Level::INFO, "future");
    future.instrument(span).await; // 也可以在 future .await 之前將 span 附加給 future
}

// async 代碼中要避免以下情況
async fn some_async_code() {
    let span = span!(Level::INFO, "span");
    let _enter = span.enter();
    // 此處進入 span 的上下文，直到 _enter 被 drop 後纔會結束
    async_fn().await; // .await 時，task 可能會讓出當前線程的執行權，而此時 _enter 還沒有 drop，因此可能會錯誤的記錄到其他 task 的 enent.
}

Event

Event 與日誌類似，表示的是某一個時間點發生的事件，但與日誌不同的是，Event 可以將信息記錄到 Span 的上下文中，這樣在分析數據時，可以直接查看 Span 中發生的所有事件。

use tracing::{event, info, span, Level};

fn main() {
    event!(Level::INFO, "event"); // 在 span 的上下文之外記錄一個 Leval 爲 INFO 的 event

    let span = span!(Level::INFO, "span");
    let _enter = span.enter();

    event!(Level::INFO, "event"); // 在 span 的上下文內記錄 event

    info!("something with info level"); // 也可以使用和 log 相同的形式記錄 event
}

Collector

以上的示例不會有任何可見的輸出，因爲我們還沒有配置 Collector，tracing 中所有的 Span 和 Event 都是通過 Collector 來收集的，Collector 會將 Span 和 Event 以一定的格式輸出到指定的地方，比如 stdout、stderr、文件、網絡等。tracing-subscriber 的 fmt 模塊提供了一個 Collector ，可以方便的輸出事件信息。

use tracing::info;
use tracing_subscriber;

fn main() {
    // 初始化全局 Collector
    tracing_subscriber::fmt::init();

    info!("Hello, world!");
}

運行上面這段代碼，可以在終端中看到一條 INFO 級別的事件，如果需要將 Trace 信息發送到其他地方，就要用到其他的 Collector 實現，比如 tracing-appender 這個 crate，可以將 Trace 信息輸出到文件中。

3 在 Rust 中使用

tracing 的完整示例

use std::{thread::sleep, time::Duration};

use tracing::{debug, info, info_span, instrument};

#[instrument]
fn expensive_work(secs: u64) {
    debug!("doing expensive work");
    sleep(Duration::from_secs(secs));
    debug!("done with expensive work");
}

fn main() {
    tracing_subscriber::fmt()
        // enable everything
        .with_max_level(tracing::Level::TRACE)
        // sets this to be the default, global collector for this application.
        .init();
    let span = info_span!("root");
    let _enter = span.enter();

    info!("some info in the root span");

    expensive_work(1);
}

運行以上代碼將會的到以下輸出

2022-12-01T02:50:59.425475Z  INFO root: tracing_example: some info in the root span
2022-12-01T02:50:59.425518Z DEBUG root:expensive_work{secs=1}: tracing_example: doing expensive work
2022-12-01T02:51:00.425722Z DEBUG root:expensive_work{secs=1}: tracing_example: done with expensive work

每個事件都已相同的格式輸出，此輸出模式下，與 log 的輸出十分相似，

但 tracing 輸出的內容多出了 Span 相關的信息。由 instrument 生成的 Span 還自動添加了函數的參數信息。下面介紹的 OpenTelemetry 和 Jaeger，還可以讓我們更加直觀的查看 Span 之間的時間關係。

4 Trace 的標準化

想要讓 Trace 跨越多個服務，集成到多種不同的語言，那就必須要規定大家相互調用的規範，要遵守一套相同的協議，才能讓 Trace 的數據在不同的系統中都能夠正常傳遞，Trace 早期誕生了兩種規範，分別是 OpenTracing 和 OpenCensus，後來爲了規範的統一，OpenTracing 和 OpenCensus 合併成了 OpenTelemetry，現在已經成爲了 Trace 的事實標準。OpenTelemetry 提供了不同語言的 SDK，可以方便的集成到不同的系統中，對於 Rust ，它提供了一系列相關的 crate 用於集成。tracing 也提供了 tracing-OpenTelemetry 用來將其收集到的信息發送到兼容 OpenTelemetry 的分佈式追蹤系統中。

5 Trace 數據的可視化分析

Jaeger 是受到 Dapper 和 OpenZipkin 啓發的開源分佈式跟蹤系統，由 Uber 開發，現已捐贈給 CNCF。Jaeger 通過收集 Trace 數據，將其可視化展示，方便開發者分析系統的問題。下圖爲 Jaeger 部署的示例。

要將 Trace 數據發送給 Jaeger，需要在我們的應用中添加 jaeger-client 。OpenTelemetry 提供的 crate 中，就包括了響應的 jaeger-clinet 實現: opentelemetry-jaeger。它會將 Span 信息以 UDP 包的形式發送到 jaeger-agent，jaeger-agent 將一段時間內的數據打包分批發送到 jaeger-collector，再由 jaeger-collector 把數據存入數據庫內，我們在 jaeger 的 UI 中就可以查詢到這些數據。

OpenTelemetry 的倉庫中也提供了以上流程的示例，我們可以直接運行這個示例，然後在 jaeger 的前端我們就可以得到下圖的內容:

有了這些數據，開發人員就能夠快速定位到請求的主要耗時部分，也能夠通過其中包含的事件獲取到請求內的消息記錄。

6 總結

對於大多數同步程序，用 Log 就能夠滿足需求，並且使用起來也足夠簡單，但是一旦涉及到異步程序或其他的一些複雜情況，Log 就會變得不那麼好用了，一段時間內的 Log 信息可能來自於多個不同的處理流程，難以快速方便的獲取我們需要的信息，而 Trace 則能夠很好的解決這個問題。

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

猜你喜歡