Rust 語言的全鏈路追蹤庫 tracing使用方法

Posted on by

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

可觀測性

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

日志(Logs)

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

指標(Metrics)

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

追蹤(Traces)

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

Rust 中的 Trace

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

  • tracing 由 tokio 團隊維護，目前使用最廣泛，生態也比較完善
  • rustracing 使用人數相對較少
  • minitrace tikv 團隊打造，性能最好

接下來就以 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 信息輸出到文件中。

在 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 之間的時間關系。

Trace 的標準化

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

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 的前端我們就可以得到下圖的內容:

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

總結

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

到此這篇關於Rust 語言的全鏈路追蹤庫 tracing的文章就介紹到這瞭,更多相關Rust 全鏈路追蹤庫 內容請搜索WalkonNet以前的文章或繼續瀏覽下面的相關文章希望大傢以後多多支持WalkonNet！

推薦閱讀：