Rust(Rocket)でtracingを使った詳細なエラーログ出力とエラーハンドリングの改善をしてみました

2023/12/06

Rust の Web フレームワークのRocket で作っている Web アプリで、tracing を使った詳細なエラーログ出力とエラーハンドリングの改善をしてみました。

目次

前提

クリーンアーキテクチャっぽい構成を想定しています。controller, use_case, repository があります。repository では sqlx で PostgreSQL を使います。

リポジトリ

リポジトリは下記です。

https://github.com/edo1z/rust-rocket-sqlx-sample

tracing を使った詳細なエラーログ出力

エラー発生箇所のファイルパス、行番号、エラー発生までの経緯(どのファイルのどの関数を辿ったのか)などを、出力するために、tracing クレートを利用しました。

ログ出力例

結果的にこのようなログが出力されるようになりました。

2023-12-05T07:43:24.644738Z ERROR user_controller/update{id=12}:user_use_case/update{id=12}:user_repo/update{id=12}: rust_rocket_sqlx_sample::repositories::user_repo: [DbRepoError::SqlxError] no rows returned by a query that expected to return at least one row (src/repositories/user_repo.rs:85)

user_controllerupdate関数(引数 id が 12)から、user_use_caseupdate関数(引数が 12)に行き、そこから、user_repoupdate関数(引数が 12)に行って、そこでエラーが発生しているということが分かりまっす。そして、エラー発生箇所は、user_repo.rs の 85 行目であり、エラーはDbRepoError::SqlxErrorであり、データがなかったことが分かります。分かりやすくなりました!

コードサンプル

repository の関数はこんな感じになっております。

src/repositories/user_repo.rs
#[instrument(name = "user_repo/update", skip_all, fields(id = %id))]
async fn update(
    &self,
    con: &mut PgConnection,
    id: i32,
    name: &String,
) -> Result<User, DbRepoError> {
    query_as!(
        User,
        "UPDATE users SET name = $1 WHERE id = $2 RETURNING *",
        name,
        id
    )
    .fetch_one(&mut *con)
    .await
    .map_err(|e| log_into!(e, DbRepoError))
}

instrument 属性

最初の行のinstrument属性は、tracing の機能で、これを書いておくと、エラーログ出力時に、ログ発生の経緯にこの関数の name や、引数が出力されます。controller, use_case, repository に全部書いておくと、全部順番に出力されるので、一目でログ出力時の実行順序が分かります。ただ、ログに引数の値を出力させるというのは、かなり危険な香りがしますので、基本的にはskip_allを設定して、表示させても問題なく、且つ、表示させたいものは、個別にfieldsで設定するという方針にしています。これは、危ないから使わないという選択肢もあるのかもなーとは思いました。どうもデフォルトで OFF には簡単にはできなそうだったのですが、もしデフォルト OFF ができると、より安心かなあと思っております。

log_into!マクロ

最後の行の、log_into!マクロは下記になっております。

src/error/logging.rs
#[macro_export]
macro_rules! log_into {
    ($error:expr, $target_type:ty) => {{
        let converted_error: $target_type = $error.into();
        tracing::error!("{} ({}:{})", converted_error, file!(), line!());
        converted_error
    }};
}

エラーをtarget_typeの別のエラーに変換して、そのエラーをファイルパスと行番号と共に、tracing のerror!を使ってログ出力するマクロになります。ただの関数ですと、ファイルパス・行番号はこの関数のファイルパス及び行番号になりますので、それもあって、マクロにしております。もしファイルパス・行番号が不要であれば、自動でエラーは変換できるので、このようなマクロを使う必要はありません。

エラーハンドリングの改善

use_case で repository 等で発生したエラーの詳細を把握し、細かくエラーハンドリングできるようにしつつ、なるべくシンプルにしたいと考えていまして、現状としては、結構いい感じな気がしてます。

ポイント ① DbRepoError でラップ

DbRepoErrorは下記です。thiserror クレートという便利ツールを使うことで、記述量が激減しました。fromアトリビュートを設定することで、sqlx::ErrorDbRepoError::SqlxErrorに自動変換されます。これで、各エラーの詳細を残しつつ、DbRepoErrorとして use_case に渡せるようになりました。

src/repositories/error.rs
use thiserror::Error;

#[derive(Debug, Error)]
pub enum DbRepoError {
    #[error("[DbRepoError::SerdeError] {0}")]
    SerdeError(#[from] serde_json::Error),
    #[error("[DbRepoError::SqlxError] {0}")]
    SqlxError(#[from] sqlx::Error),

    #[cfg(test)]
    #[error("Dummy error for testing")]
    DummyTestError,
}

ポイント ② use_case で詳細をハンドリングしつつ AppError に自動変換

AppErrorは現在こちら のようになっております。DbRepoErrorが自動的にAppError::DbErrorに変換されるようになっています。また、Rocket のResponderが実装されており、レスポンスにそのままAppErrorが使えるようになっております。そして、レスポンス時のステータスコードも紐づけされています。その他、anyhow を真似したapp_err関数と、app_err!, app_err_bail!, app_err_ensure!マクロを作成しました。

AppError のコード(一部)

src/error/app_error.rs
#[derive(Debug, Error)]
pub enum AppError {
    #[error("Database Error")]
    DbError(#[from] DbRepoError),
    #[error("Bad Request")]
    BadRequest,
    #[error("Unauthorized")]
    Unauthorized,
    #[error("Forbidden")]
    Forbidden,
    #[error("Not Found")]
    NotFound,
    #[error("Internal Server Error")]
    InternalServerError,
    #[error("{message}")]
    CustomError { status_code: u16, message: String },
}

impl AppError {
    pub fn new(status_code: u16, message: &str) -> Self {
        AppError::CustomError {
            status_code,
            message: message.to_string(),
        }
    }

    pub fn status_code(&self) -> u16 {
        match self {
            AppError::DbError(_) => 500,
            AppError::BadRequest => 400,
            AppError::Unauthorized => 401,
            AppError::Forbidden => 403,
            AppError::NotFound => 404,
            AppError::InternalServerError => 500,
            AppError::CustomError { status_code, .. } => *status_code,
        }
    }
}

use_case のコードサンプル

下記のdeleteは、fromを使って自動変換させています。updateでは、対象データが存在しない場合は、BadRequestエラーを返すようにしています。このように、use_case で、細かいエラーハンドリングが出来るようになりました。

src/use_cases/user_use_case.rs
#[instrument(name = "user_use_case/update", skip_all, fields(id = %id))]
async fn update(
    &self,
    repos: &Repos,
    db_con: &mut DbCon,
    id: i32,
    name: &String,
) -> Result<User, AppError> {
    repos
        .user
        .update(&mut *db_con, id, name)
        .await
        .map_err(|e| {
            if let DbRepoError::SqlxError(sqlx::Error::RowNotFound) = &e {
                AppError::BadRequest
            } else {
                AppError::from(e)
            }
        })
}

#[instrument(name = "user_use_case/delete", skip_all, fields(id = %id))]
async fn delete(&self, repos: &Repos, db_con: &mut DbCon, id: i32) -> Result<(), AppError> {
    repos
        .user
        .delete(&mut *db_con, id)
        .await
        .map_err(|e| AppError::from(e))
}

今後やりたいこと

  • メトリクスの収集
  • Datadog で集計・グラフ表示
  • Datadog 経由で Slack 通知
  • レスポンスの json 化(今エラーメッセージがテキスト)
Rust🦀, Network⚡, PostgreSQL🐘, Unity🎮

Tags

rust  (9)
rocket  (7)
svelte  (5)
c++  (4)
ethereum  (3)
solidity  (3)
vscode  (3)
sqlx  (3)
glfw  (2)
opengl  (2)
nestjs  (2)
graphql  (2)
render  (2)
wsl2  (2)
truffle  (1)
goerli  (1)
geth  (1)
hardhat  (1)
nft  (1)
gui  (1)
tetris  (1)
next.js  (1)
jwt  (1)
nextauth  (1)
node.js  (1)
prisma  (1)
passport  (1)
urql  (1)
codegen  (1)
mdsvex  (1)
markdown  (1)
tmux  (1)
nvim  (1)
axum  (1)
atcoder  (1)
vim  (1)
pacman  (1)
tracing  (1)