结构化日志

为了确保所有日志记录都包含 request_id, 我们必须：

重写请求处理管道中的所有上游组件 (例如 actix-web 的 Logger)
更改我们从订阅处理程序调用的所有下游函数的签名；如果它们要发出日志语句，则需要包含 request_id, 因此需要将其作为参数传递下去。

那么我们导入到项目中的 crate 发出的日志记录呢？我们也应该重写这些 crate 吗?

显然，这种方法无法扩展。

让我们退一步思考：我们的代码是什么样的?

我们有一个总体任务（HTTP 请求），它被分解为一系列子任务（例如，解析输入、进行查询等），这些子任务又可以递归地分解为更小的子例程。

每个工作单元都有一个持续时间（即开始和结束）。

每个工作单元都有一个与其关联的上下文（例如，新订阅者的姓名和电子邮件地址、request_id），这些上下文自然会被其所有子工作单元共享。

毫无疑问，我们正面临困境:日志语句是在特定时间点发生的孤立事件，而我们却固执地试图用它来表示树状处理流水线。日志是一种错误的抽象。

那么，我们应该使用什么呢?

`tracing` Crate

tracing crate 可以帮助我们

tracing 扩展了日志式诊断，允许库和应用程序记录结构化事件，并附加有关时间性和因果关系的信息——与日志消息不同，跟踪中的跨度具有开始和结束时间，可以通过执行流进入和退出，并且可以存在于类似跨度的嵌套树中。

这真是天籁之音。

实际效果如何?

从 log 迁移到 tracing

只有一种方法可以找到答案——让我们将订阅处理程序转换为使用 tracing 而不是 log 进行检测。

让我们将 tracing 添加到依赖项中:

cargo add tracing --features=log

迁移的第一步非常简单：搜索函数主体中所有出现的 log:: 字符串，并将其替换为 tracing。

pub async fn subscribe(form: web::Form<FormData>, pool: web::Data<PgPool>) -> HttpResponse {
    let request_id = Uuid::new_v4();
    tracing::info!(
        "request_id {} - Adding '{}' '{}' as a new subscriber.",
        request_id,
        form.email,
        form.name,
    );
    tracing::info!("request_id {request_id} - Saving new subscriber details in the database");
    match sqlx::query!(/* [...] */)
    .execute(pool.get_ref())
    .await
    {
        Ok(_) => {
            tracing::info!("request_id {request_id} - New subscriber details have been saved");
            HttpResponse::Ok().finish()
        }
        Err(e) => {
            println!("request_id {request_id} - Failed to execute query: {e}");
            HttpResponse::InternalServerError().finish()
        }
    }
}

这样就好了。

如果您运行该应用程序并发出 POST /subscriptions 请求,

您将在控制台中看到完全相同的日志。完全相同。

很酷，不是吗?

这得益于我们在 Cargo.toml 中启用的 tracing log 功能标志。它确保每次使用 tracing 的宏创建事件或跨度时，都会发出相应的日志事件,

以便日志的记录器（在本例中为 env_logger）能够捕获它。

tracing 的 Span

现在，我们可以开始利用跟踪的 Span 来更好地捕获程序的结构。

我们需要创建一个代表整个 HTTP 请求的 span:

//! src/routes/subscriptions.rs
// [...]
pub async fn subscribe(form: web::Form<FormData>, pool: web::Data<PgPool>) -> HttpResponse {
    let request_id = Uuid::new_v4();
    // Spans, like logs, have an associated level
    // `into_span` creates a span at the into-level
    let request_span = tracing::info_span!(
        "Adding a new subscriber.",
        %request_id,
        subscriber_email = %form.email,
        subscriber_name = %form.name,
    );

    // Using `enter` in an async function is a recipe for disaster!
    // Bear with me for now, but don't do this at home.
    // See the floowing secion on `Instrumenting Futures`
    let _request_span_guard = request_span.enter();

    // [...]
    // `_request_span_guard` is dropped at the end of `subscribe`
    // That's when we "exit" the span
}

这里有很多事情要做——让我们分解一下。

我们使用 info_span! 宏创建一个新的 span，并将一些值附加到其上下文中: request_id、form.email 和 form.name。

我们不再使用字符串插值：跟踪允许我们将结构化信息关联到 span，作为键值对的集合32。我们可以显式命名它们（例如，将 form.email 命名为subscriber_email）, 也可以隐式使用变量名作为键（例如，单独的 request_id 等同于 request_id = request_id）。

请注意，我们在所有 span 前面都添加了 % 符号: 我们告诉 tracing 使用它们的 Display 实现进行日志记录。您可以在它们的文档中找到有关其他可用选项的更多详细信息。

info_span 返回新创建的 span，但我们必须使用 .enter() 方法显式进入其中才能激活它。

.enter() 返回 Entered 的一个实例，它是一个守卫：只要守卫变量未被丢弃，所有下游 span 和日志事件都将被注册为已进入 span 的子级。这是一种典型的 Rust 模式，通常被称为资源获取即初始化 (RAII)：编译器会跟踪所有变量的生命周期，当它们超出作用域时，会插入对其析构函数的调用，Drop::drop。

Drop trait 的默认实现只负责释放该变量所拥有的资源。不过，我们可以指定一个自定义的 Drop 实现，以便在 drop 时执行其他清理操作——例如，当 Entered 守卫被 drop 时退出 span:

//! `tracing`'s source code
impl<'a> Drop for Entered<'a> {
    #[inline]
    fn drop(&mut self) {
        // Dropping the guard exits the span.
        //
        // Running this behaviour on drop rather than with an explicit function
        // call means that spans may still be exited when unwinding.
        if let Some(inner) = self.span.inner.as_ref() {
            inner.subscriber.exit(&inner.id);
        }
    }
}
if_log_enabled! {{
    if let Some(ref meta) = self.span.meta {
        self.span.log(
            ACTIVITY_LOG_TARGET,
            log::Level::Trace,
            format_args!("<- {}", meta.name())
        );
    }
}}

检查依赖项的源代码通常可以发现一些有用信息——我们刚刚发现，如果启用了日志功能标志，当 span 退出时，跟踪将会发出跟踪级别的日志。

让我们立即尝试一下:

RUST_LOG=trace cargo run

[.. INFO zero2prod] Adding a new subscriber.; request_id=f349b0fe..
subscriber_email=ursulale_guin@gmail.com subscriber_name=le guin
[.. TRACE zero2prod] -> Adding a new subscriber.
[.. INFO zero2prod] request_id f349b0fe.. - Saving new subscriber details
in the database
[.. INFO zero2prod] request_id f349b0fe.. - New subscriber details have
been saved
[.. TRACE zero2prod] <- Adding a new subscriber.
[.. TRACE zero2prod] -- Adding a new subscriber.
[.. INFO actix_web] .. "POST /subscriptions HTTP/1.1" 200 ..

注意，我们在 span 上下文中捕获的所有信息是如何在发出的日志行中报告的。

我们可以使用发出的日志密切跟踪 span 的生命周期:

创建 span 时记录添加新订阅者的操作；
进入 span (->)；
执行 INSERT 查询；
退出 span (<-)；
最终关闭 span (--)。

等等，退出 span 和关闭 span 有什么区别?

很高兴你问这个问题!

你可以多次进入（和退出）一个 span。而关闭 span 是最终操作: 它发生在 span 本身被丢弃时。

当你有一个可以暂停然后恢复的工作单元时，这非常方便——例如一个异步任务！

tracing 的 Subscriber

我们着手从日志迁移到跟踪，是因为我们需要一个更好的抽象来有效地检测我们的代码。我们特别希望将 request_id 附加到与同一传入 HTTP 请求相关的所有日志中。

虽然我保证跟踪会解决我们的问题，但看看那些日志：request_id 只打印在第一个日志语句中，我们把它明确地附加到 span 上下文中。

为什么呢?

嗯，我们还没有完成迁移。

虽然我们已经将所有检测代码从 log 迁移到了 tracing，但我们仍然使用 env_logger 来处理所有事情!

//! src/main.rs
// [...]

#[tokio::main]
async fn main() -> std::io::Result<()> {
    env_logger::Builder::from_env(Env::default().default_filter_or("info")).init();

    // [...]
}

env_logger 的日志记录器实现了 log 的 Log 特性——它对 tracing 的 Span 所暴露的丰富结构一无所知！ tracing 与 log 的兼容性非常出色，现在是时候用 tracing 原生解决方案替换 env_logger 了。

tracing crate 遵循 log 使用的相同外观模式——您可以自由地使用它的宏来检测您的代码，但应用程序负责明确如何处理该 Span 遥测数据。

Subscriber 是 log 的 Log 的 tracing 对应物：Subscriber 特性的实现暴露了各种方法来管理 Span 生命周期的每个阶段——创建、进入/退出、闭包等等。

//! `tracing`'s source code
pub trait Subscriber: 'static {
    fn new_span(&self, span: &span::Attributes<'_>) -> span::Id;
    fn event(&self, event: &Event<'_>);
    fn enter(&self, span: &span::Id);
    fn exit(&self, span: &span::Id);
    fn clone_span(&self, id: &span::Id) -> span::Id;
    // [...]
}

跟踪文档的质量令人叹为观止——我强烈建议您亲自查看 Subscriber 的文档，以正确理解每个方法的作用。

tracing-subscriber

tracing 不提供任何开箱即用的 subscriber。

我们需要研究 tracing-subscriber（这是 tracing 项目内部维护的另一个 crate）, 以便找到一些基本的订阅器来启动它。让我们将它添加到我们的依赖项中:

cargo add tracing-subscriber --features=registry,env-filter

tracing-subscriber 的功能远不止提供一些便捷的订阅器。

它引入了另一个关键特性：Layer。

Layer 使得构建跨度数据的处理管道成为可能：我们不必提供一个包罗万象的订阅器来完成我们想要的一切；相反，我们可以组合多个较小的层来获得所需的处理管道。

这大大减少了整个追踪生态系统中的重复工作：人们专注于通过大量创建新的层来添加新功能，而不是试图构建功能最齐全的订阅器。

分层方法的基石是 Registry。

Registry 实现了 Subscriber 特性，并处理了所有棘手的问题:

Registry 实际上并不记录自身 trace: 相反，它收集并存储暴露给任何包裹它的层的 span 数据 [...]。Registry 负责存储 span 元数据，记录 span 之间的关系，并跟踪哪些 span 处于活动状态，哪些 span 已关闭。

下游层可以搭载 Registry 的功能并专注于其目的: 过滤需要处理的 span、格式化 span 数据、将 span 数据发送到远程系统等。

tracing-bunyan-formatter

我们希望创建一个与旧版 env_logger 功能相同的订阅器。

我们将通过组合三个层来实现此目标:

tracing_subscriber::filter::EnvFilter 根据日志级别和来源丢弃 span，就像我们在 env_logger 中通过 RUST_LOG 环境变量所做的那样；
tracing_bunyan_formatter::JsonStorageLayer 处理 span 数据，并将相关元数据以易于理解的 JSON 格式存储，以供下游层使用。它尤其会将上下文从父 span 传播到其子 span；
tracing_bunyan_formatter::BunyanFormatterLayer 构建于 JsonStorageLayer 之上，并以兼容 bunyan 的 JSON 格式输出日志记录。

让我们将 tracing_bunyan_formatter 添加到我们的依赖项中:

cargo add tracing_bunyan_formatter

现在我们可以将所有内容整合到我们的 main 方法中:

//! src/main.rs
use tracing::subscriber::set_global_default;
use tracing_bunyan_formatter::{BunyanFormattingLayer, JsonStorageLayer};
use tracing_subscriber::{layer::SubscriberExt, EnvFilter, Registry};

// [...]

#[tokio::main]
async fn main() -> std::io::Result<()> {
    // We removed the `env_logger` line we had before!
    
    // We are falling back to printing all spans at into-level or above
    // if the RUST_LOG environment variable has not been set.
    let env_filter = EnvFilter::try_from_default_env()
        .unwrap_or_else(|_| EnvFilter::new("info"));
    let formatting_layer = BunyanFormattingLayer::new(
        "zero2prod".into(),
        std::io::stdout
    );

    // The `with` method is provided by `SubscriberExt`, an extension
    // trait for `Subscriber` exposed by `tracing_subscriber`
    let subscriber = Registry::default()
        .with(env_filter)
        .with(JsonStorageLayer)
        .with(formatting_layer);

    // `set_global_default` can be used by applications to specify
    // what subscriber should be used to process spans
    set_global_default(subscriber).expect("Failed to set subscriber");
    // [...]
}

如果你使用 cargo run 启动应用程序并发出请求，你会看到这些日志（为了更容易阅读，这里格式化后打印）:

{
  "msg": "[ADDING A NEW SUBSCRIBER - START]",
  "subscriber_name": "le guin",
  "request_id": "30f8cce1-f587-4104-92f2-5448e1cc21f6",
  "subscriber_email": "ursula_le_guin@gmail.com"
  ...
}
{
  "msg": "[SAVING NEW SUBSCRIBER DETAILS IN THE DATABASE - START]",
  "subscriber_name": "le guin",
  "request_id": "30f8cce1-f587-4104-92f2-5448e1cc21f6",
  "subscriber_email": "ursula_le_guin@gmail.com"
  ...
}
{
  "msg": "[SAVING NEW SUBSCRIBER DETAILS IN THE DATABASE - END]",
  "elapsed_milliseconds": 4,
  "subscriber_name": "le guin",
  "request_id": "30f8cce1-f587-4104-92f2-5448e1cc21f6",
  "subscriber_email": "ursula_le_guin@gmail.com"
  ...
}
{
  "msg": "[ADDING A NEW SUBSCRIBER - END]",
  "elapsed_milliseconds": 5
  "subscriber_name": "le guin",
  "request_id": "30f8cce1-f587-4104-92f2-5448e1cc21f6",
  "subscriber_email": "ursula_le_guin@gmail.com",
  ...
}

我们成功了：所有附加到原始上下文的内容都已传播到其所有子跨度。

tracing-bunyan-formatter 还提供了开箱即用的持续时间：每次关闭跨度时，都会在控制台上打印一条 JSON 消息，并附加 elapsed_millisecond 属性。

JSON 格式在搜索方面非常友好：像 ElasticSearch 这样的引擎可以轻松提取所有这些记录，推断出模式并索引 request_id、name 和 email 字段。它释放了查询引擎的全部功能来筛选我们的日志!

这比我们以前的方法好得多：为了执行复杂的搜索，我们必须使用自定义的正则表达式，因此大大限制了我们可以轻松向日志提出的问题范围。

删除没有用到的依赖

如果你快速浏览一下我们所有的文件，你会发现我们目前还没有在任何地方使用 log 或 env_logger。我们应该将它们从 Cargo.toml 文件中删除。

在大型项目中，重构后很难发现某个依赖项已不再使用。

幸运的是，工具再次派上用场——让我们安装 cargo-udeps (未使用的依赖项):

cargo install cargo-udeps

cargo-udeps 会扫描你的 Cargo.toml 文件，并检查 [dependencies] 下列出的所有 crate 是否已在项目中实际使用。查看 cargo-deps 的“战利品陈列柜”，了解一系列热门 Rust 项目，这些项目都曾使用 cargo-udeps 识别未使用的依赖项并缩短构建时间。

现在就在我们的项目上运行它吧!

# cargo-udeps requires the nightly compiler.
# We add +nightly to our cargo invocation
# to tell cargo explicitly what toolchain we want to use.
cargo +nightly udeps

输出应该是

zero2prod
  dependencies
    "env-logger"

不幸的是，它没有识别到 log。让我们从 Cargo.toml 文件中删除这两项。

清理仪表代码 - tracing::instrument

我们重构了初始化逻辑。现在来看看我们的插桩代码。

是时候再次回归 subscribe 了。

//! src/routes/subscriptions.rs
// [...]
pub async fn subscribe(form: web::Form<FormData>, pool: web::Data<PgPool>) -> HttpResponse {
    let request_id = Uuid::new_v4();
    let request_span = tracing::info_span!(
        "Adding a new subscriber.",
        %request_id,
        subscriber_email = %form.email,
        subscriber_name = %form.name,
    );
    let _request_span_guard = request_span.enter();

    // We do not call `.enter` on query_span!
    // `.instrument` takes care of it at the right moments
    // in the query future lifetime
    let query_span = tracing::info_span!("Saving new subscriber details in the database");

    match sqlx::query!(
        r#"
        INSERT INTO subscriptions (id, email, name, subscribed_at)
        VALUES ($1, $2, $3, $4)
        "#,
        Uuid::new_v4(),
        form.email,
        form.name,
        Utc::now()
    )
    .execute(pool.get_ref())
    // First we attach the instrumentation, then we `.await` it
    .instrument(query_span)
    .await
    {
        Ok(_) => {
            tracing::info!("request_id {request_id} - New subscriber details have been saved");
            HttpResponse::Ok().finish()
        }
        Err(e) => {
            println!("request_id {request_id} - Failed to execute query: {e}");
            HttpResponse::InternalServerError().finish()
        }
    }
}

公平地说，日志记录给我们的订阅函数带来了一些噪音。

让我们看看能否稍微减少一下。

我们将从 request_span 开始: 我们希望订阅函数中的所有操作都在 request_span 的上下文中发生。换句话说，我们希望将订阅函数包装在一个 span 中。

这种需求相当普遍: 将每个子任务提取到其各自的函数中是构建例程的常用方法，可以提高可读性并简化测试的编写；因此，我们经常会希望将 span 附加到函数声明中。

tracing 通过其 tracing::instrument 过程宏来满足这种特定的用例。让我们看看它的实际效果:

//! src/rotues/subscriptions.rs
// [...]
#[tracing::instrument(
    name = "Adding a new subscriber",
    skip(form, pool),
    fields(
        request_id = %Uuid::new_v4(),
        subscriber_email = %form.email,
        subscriber_name = %form.name,
    )
)]
pub async fn subscribe(form: web::Form<FormData>, pool: web::Data<PgPool>) -> HttpResponse {
    let query_span = tracing::info_span!("Saving new subscriber details in the database");

    match sqlx::query!(/* [...] */)
    .execute(pool.get_ref())
    .instrument(query_span)
    .await
    {
        Ok(_) => {
            HttpResponse::Ok().finish()
        }
        Err(e) => {
            tracing::error!("Failed to execute query: {e}");
            HttpResponse::InternalServerError().finish()
        }
    }
}

#[tracing::instrument] 在函数调用开始时创建一个 span，并自动将传递给函数的所有参数附加到 span 的上下文中——在我们的例子中是 form 和 pool。函数参数通常不会显示在日志记录中（例如 pool），或者我们希望更明确地指定应该捕获哪些参数/如何捕获它们（例如，命名 form 的每个字段）——我们可以使用 skip 指令明确地告诉跟踪忽略它们。

name 可用于指定与函数 span 关联的消息 - 如果省略，则默认为函数名称。

我们还可以使用 fields 指令来丰富 span 的上下文。它利用了我们之前在 info_span! 宏中见过的相同语法。结果相当不错：所有插桩关注点在视觉上都被执行关注点分隔开来，

前者由一个过程宏来处理，该宏“修饰”函数声明，而函数体则专注于实际的业务逻辑。

需要指出的是，如果将 tracing::instrument 应用于异步函数，它也会小心地使用 Instrument::instrument。

让我们将查询提取到其自己的函数中，并使用 tracing::instrument 来摆脱 query_span 以及对 .instrument 方法的调用:

//! src/routes/subscription.rs
// [...]

#[tracing::instrument(
    name = "Adding a new subscriber",
    skip(form, pool),
    fields(
        request_id = %Uuid::new_v4(),
        subscriber_email = %form.email,
        subscriber_name = %form.name,
    )
)]
pub async fn subscribe(form: web::Form<FormData>, pool: web::Data<PgPool>) -> HttpResponse {
    match insert_subscriber(&pool, &form).await {
        Ok(_) => HttpResponse::Ok().finish(),
        Err(_) => HttpResponse::InternalServerError().finish(),
    }
}

#[tracing::instrument(
    name = "Saving new subscriber details in the database",
    skip(form, pool)
)]
pub async fn insert_subscriber(pool: &PgPool, form: &FormData) -> Result<(), sqlx::Error> {
    sqlx::query!(
        r#"
        INSERT INTO subscriptions (id, email, name, subscribed_at)
        VALUES ($1, $2, $3, $4)
        "#,
        Uuid::new_v4(),
        form.email,
        form.name,
        Utc::now()
    )
    .execute(pool)
    .await
    .inspect_err(|e| {
        tracing::error!("Failed to execute query: {:?}", e);
    })?;

    Ok(())
}

错误事件现在确实落在查询范围内，并且我们实现了更好的关注点分离：

insert_subscriber 负责数据库逻辑，它不感知周围的 Web 框架 - 也就是说，我们不会将 web::Form 或 web::Data 包装器作为输入类型传递
subscribe 通过调用所需的例程来协调要完成的工作，并根据 HTTP 协议的规则和约定将其结果转换为正确的响应

我必须承认我对 tracing::instrument 的无限热爱: 它显著降低了检测代码所需的工作量。

它会将你推向成功的深渊: 做正确的事是最容易的事。

保护你的秘密 - secrecy

#[tracing::instrument] 中其实有一个我不太喜欢的元素：它会自动将传递给函数的所有参数附加到 span 的上下文中——你必须选择不记录函数输入（通过 skip 选项），而不是选择加入。

你肯定不希望日志中包含机密信息（例如密码）或个人身份信息（例如最终用户的账单地址）。

选择退出是一个危险的默认设置——每次使用 #[tracing::instrument] 向函数添加新输入时，你都需要问自己: 记录这段输入安全吗? 我应该跳过它吗?

如果时间过长，别人就会忘记——你现在要处理一个安全事件。

你可以通过引入一个包装器类型来避免这种情况，该包装器类型明确标记哪些字段被视为敏感字段——secrecy::Secret。

cargo add secrecy --features=serde

我们来看看它的定义:

/// Wrapper type for values that contains secrets, which attempts to limit
/// accidental exposure and ensure secrets are wiped from memory when dropped.
/// (e.g. passwords, cryptographic keys, access tokens or other credentials)
///
/// Access to the secret inner value occurs through the [...]
/// `expose_secret()` method [...]
pub struct Secret<S>
where
    S: Zeroize,
{
    /// Inner secret value
    inner_secret: S,
}

Zeroize trait 提供的内存擦除功能非常实用。

我们正在寻找的关键属性是 SecretBox 的屏蔽 Debug 实现: println!("{:?}", my_secret_string) 输出的是 Secret([REDACTED String]) 而不是实际的 secret 值。这正是我们防止敏感信息通过 #[tracing::instrument] 或其他日志语句意外泄露所需要的。

显式包装器类型还有一个额外的好处: 它可以作为新开发人员的文档，帮助他们熟悉代码库。它明确了在你的领域/根据相关法规，哪些内容被视为敏感信息。

现在我们唯一需要担心的秘密值是数据库密码。让我们写一下:

//! src/configuration.rs
use secrecy::SecretBox;
// [...]

#[derive(serde::Deserialize)]
pub struct DatabaseSettings {
    // [...]
    pub password: SecretBox<String>,
}

SecretBox 不会干扰反序列化 - SecretBox 通过委托给包装类型的反序列化逻辑来实现 serde::Deserialize（如果您像我们一样启用了 serde 功能标志）。

编译器不满意:

error[E0277]: `SecretBox<std::string::String>` doesn't implement `std::fmt::Display`
  --> src/configuration.rs:22:28
   |
21 |             "postgres://{}:{}@{}:{}/{}",
   |                            -- required by this formatting parameter
22 |             self.username, self.password, self.host, self.port, self.database_name
   |                            ^^^^^^^^^^^^^ `SecretBox<std::string::String>` cannot be formatted 
with the default formatter
   |
   = help: the trait `std::fmt::Display` is not implemented for `SecretBox<std::string::String>`
   = note: in format strings you may be able to use `{:?}` (or {:#?} for pretty-print) instead
   = note: this error originates in the macro `$crate::__export::format_args` which comes from the 
expansion of the macro `format` (in Nightly builds, run with -Z macro-backtrace for more info)

error[E0277]: `SecretBox<std::string::String>` doesn't implement `std::fmt::Display`
  --> src/configuration.rs:29:28
   |
28 |             "postgres://{}:{}@{}:{}",
   |                            -- required by this formatting parameter
29 |             self.username, self.password, self.host, self.port
   |                            ^^^^^^^^^^^^^ `SecretBox<std::string::String>` cannot be formatted 
with the default formatter
   |
   = help: the trait `std::fmt::Display` is not implemented for `SecretBox<std::string::String>`
   = note: in format strings you may be able to use `{:?}` (or {:#?} for pretty-print) instead
   = note: this error originates in the macro `$crate::__export::format_args` which comes from the 
expansion of the macro `format` (in Nightly builds, run with -Z macro-backtrace for more info)

For more information about this error, try `rustc --explain E0277`.
error: could not compile `zero2prod` (lib) due to 2 previous errors

这是一项功能，而非 bug —— secret::SecretBox 没有实现 Display 接口，因此我们需要明确允许暴露已包装的 secret。编译器错误提示我们，由于整个数据库连接字符串嵌入了数据库密码，因此也应该将其标记为 SecretBox:

//! src/configuration.rs
use secrecy::{ExposeSecret, SecretBox};
// [...]

impl DatabaseSettings {
    pub fn connection_string(&self) -> SecretBox<String> {
        SecretBox::new(Box::new(format!(
            "postgres://{}:{}@{}:{}/{}",
            self.username, self.password.expose_secret(), self.host, self.port, self.database_name
        )))
    }

    pub fn connection_string_without_db(&self) -> SecretBox<String> {
        SecretBox::new(Box::new(format!(
            "postgres://{}:{}@{}:{}",
            self.username, self.password.expose_secret(), self.host, self.port
        )))
    }
}

//! src/main.rs
use secrecy::ExposeSecret;
use sqlx::PgPool;
use zero2prod::{configuration::get_configuration, run, telemetry::{get_subscriber, init_subscriber}};

#[tokio::main]
async fn main() -> std::io::Result<()> {
    // [...]
    let connection_pool = PgPool::connect(&configuration.database.connection_string().expose_secret())
        .await
        .expect("Failed to connect to Postgres.");

    // [...]
}

//! tests/health_check.rs
use secrecy::ExposeSecret;
// [...]

pub async fn configure_database(config: &DatabaseSettings) -> PgPool {
    // Create database
    let mut connection = PgConnection::connect(&config.connection_string_without_db().expose_secret())
        .await
        .expect("Failed to connect to Postgres");

    connection
        .execute(format!(r#"CREATE DATABASE "{}";"#, config.database_name).as_str())
        .await
        .expect("Failed to create database.");

    // Migrate database
    let connection_pool = PgPool::connect(&config.connection_string().expose_secret())
        .await
        .expect("Failed to connect to Postgres");

    sqlx::migrate!("./migrations")
        .run(&connection_pool)
        .await
        .expect("Failed to migrate the database");

    connection_pool
}

暂时就是这样——以后，一旦引入敏感值，我们将确保将其包装到 SecretBox 中。

请求Id

我们还有最后一项工作要做：确保特定请求的所有日志，特别是包含返回状态码的记录，都添加了 request_id 属性。怎么做呢?

如果我们的目标是避免接触 actix_web::Logger，最简单的解决方案是添加另一个中间件,RequestIdMiddleware, 它负责:

生成唯一的请求标识符
创建一个新的 span，并将请求标识符作为上下文附加
将其余的中间件链包装到新创建的 span 中

不过，这样会留下很多问题: actix_web::Logger 无法像其他日志那样以相同的结构化 JSON 格式让我们访问其丰富的信息（状态码、处理时间、调用者 IP 等）——我们必须从其消息字符串中解析出所有这些信息。

在这种情况下，我们最好引入一个支持跟踪的解决方案。

让我们将 tracing-actix-web 添加为依赖项之一

cargo add tracing-actix-web

//! src/startup.rs
use std::net::TcpListener;

use actix_web::{dev::Server, web, App, HttpServer};
use sqlx::PgPool;
use tracing_actix_web::TracingLogger;

use crate::routes::{health_check, subscribe};

pub fn run(
    listener: TcpListener,
    db_pool: PgPool,
) -> Result<Server, std::io::Error> {
    let db_pool = web::Data::new(db_pool);

    let server = HttpServer::new(move || {
        App::new()
            // Instead of `Logger::default`
            .wrap(TracingLogger::default())
            .route("/health_check", web::get().to(health_check))
            .route("/subscriptions", web::post().to(subscribe))
            .app_data(db_pool.clone())
    })
    .listen(listener)?
    .run();

    Ok(server)
}

如果您启动应用程序并发出请求，您应该会在所有日志中看到 request_id 以及 request_path 和其他一些有用的信息。

我们快完成了——还有一个未解决的问题需要解决。

让我们仔细看看 POST /subscriptions 请求发出的日志记录:

{
  "msg": "[REQUEST - START]",
  "request_id": "21fec996-ace2-4000-b301-263e319a04c5",
  ...
}
{
  "msg": "[ADDING A NEW SUBSCRIBER - START]",
  "request_id":"aaccef45-5a13-4693-9a69-5",
  ...
}

同一个请求却有两个不同的 request_id!

这个 bug 可以追溯到我们 subscribe 函数中的 #[tracing::instrument] 注解:

//! src/routes/subscriptions.rs
// [...]

#[tracing::instrument(
    name = "Adding a new subscriber",
    skip(form, pool),
    fields(
        request_id = %Uuid::new_v4(),
        subscriber_email = %form.email,
        subscriber_name = %form.name,
    )
)]
pub async fn subscribe(form: web::Form<FormData>, pool: web::Data<PgPool>) -> HttpResponse {
    // [...]
}

我们仍在函数级别生成一个 request_id，它会覆盖来自 TracingLogger 的 request_id。

让我们摆脱它来解决这个问题:

//! src/routes/subscriptions.rs
// [...]

#[tracing::instrument(
    name = "Adding a new subscriber",
    skip(form, pool),
    fields(
        subscriber_email = %form.email,
        subscriber_name = %form.name,
    )
)]
pub async fn subscribe(form: web::Form<FormData>, pool: web::Data<PgPool>) -> HttpResponse {
    // [...]
}

现在一切都很好 - 我们应用程序的每个端点都有一个一致的 request_id。

利用 tracing 生态系统

我们介绍了 tracing 的诸多功能——它显著提升了我们收集的遥测数据的质量，并提高了插桩代码的清晰度。

与此同时，我们几乎没有触及整个 tracing 生态系统在订阅层方面的丰富性。

以下列举一些现成的组件:

tracing-actix-web 与 OpenTelemetry 兼容。如果您插入 tracing-opentelemetry，则可以将 span 发送到与 OpenTelemetry 兼容的服务（例如 Jaeger 或 Honeycomb.io）进行进一步分析；
tracing-error 使用 SpanTrace 丰富了我们的错误类型，从而简化了故障排除。

毫不夸张地说，tracing 是 Rust 生态系统的基础 crate。虽然日志是最小公分母，但 tracing 现已成为整个诊断和插桩生态系统的现代支柱。

在Rust中从零到生产简体中文版