RustのスタックトレースをRuby風に加工する

はじめに

こんにちは、バックエンドエンジニアのよしかわです。

今回の題材はRustのスタックトレースの加工です。Google CloudのError Reportingはスタックトレースを利用してエラーのグルーピングなどを行ってくれますが、Rustはその対応言語に入っていません(参考: Error Reporting におけるエラーの報告とグループ化について調べてみた)。そこで窮余の策としてRustのスタックトレースをError Reportingが解析できるフォーマットへ加工できないか試してみました。以下でその内容を簡単にご紹介します。

加工先フォーマットの選定

スタックトレースはRuby風に加工することにしました。Error Reportingが解析可能な下記7種類のうち、Rubyのものが誤解しづらさと解析しやすさの観点で都合が良さそうだったからです。

Java: Must be the return value of Throwable.printStackTrace().

Python: Must be the return value of traceback.format_exc().

JavaScript: Must be the value of error.stack as returned by V8.

Ruby: Must contain frames returned by Exception.backtrace.

C#: Must be the return value of Exception.ToString().

PHP: Must be prefixed with "PHP (Notice|Parse error|Fatal error|Warning): " and contain the result of (string)$exception.

Go: Must be the return value of runtime.Stack().

https://cloud.google.com/error-reporting/reference/rest/v1beta1/projects.events/report#reportederrorevent

誤解しづらさ

加工後のスタックトレースがRust以外の言語のものと誤解されるのと混乱の元になるので避けたいところです。例えばもしPHP風やGo風に加工するとなるとPHP Fatal errorやgoroutineなどの語を出力に含めざるを得ず誤解を招きそうです。もちろんRuby風にすればRubyっぽさは出てしまいますがPHP風やGo風に比べれば混乱させづらいのではないかと思います。

解析しやすさ

スタックトレースを他言語風にしたとしても区切り文字(::)などの部分で多少の違いは残りますが、そうした違いによるError Reportingの解析失敗も望ましくありません。Error Reportingの詳細な仕様は分からないので実動作を見てみたところ、試した範囲ではRuby風やPython風だと解析が成功しやすい印象でした。Ruby風ならファイル中の位置が /file/to/path:42 のような形式で表されるのでError Reporting以外のツールとの相性も良いのではないかと思います。

実動作はCloud Shell上で gcloud beta error-reporting events reportコマンドを実行すると手軽に試せます。以下にいくつか例を挙げてみます。

例1: JavaScript風 (解析失敗)

$ gcloud beta error-reporting events report --service=test --message="$(cat <<'EOF'
Error: something wrong
  at v8_style_backtrace::g (/Users/yoshikawa/v8-style-backtrace/src/main.rs:41:28)
  at v8_style_backtrace::f (/Users/yoshikawa/v8-style-backtrace/src/main.rs:35:5)
  at v8_style_backtrace::main (/Users/yoshikawa/v8-style-backtrace/src/main.rs:31:5)
EOF
)"

例2: Python風 (解析成功)

gcloud beta error-reporting events report --service=test --message="$(cat <<'EOF'
Traceback (most recent call last):
  File "/Users/yoshikawa/python-style-backtrace/src/main.rs", line 31, in python_style_backtrace::main
  File "/Users/yoshikawa/python-style-backtrace/src/main.rs", line 35, in python_style_backtrace::f
  File "/Users/yoshikawa/python-style-backtrace/src/main.rs", line 41, in python_style_backtrace::g
Error: something wrong
EOF
)"

例3: Ruby風 (解析成功)

gcloud beta error-reporting events report --service=test --message="$(cat <<'EOF'
something wrong
  /Users/yoshikawa/ruby-style-backtrace/src/main.rs:41:in `ruby_style_backtrace::g'
  /Users/yoshikawa/ruby-style-backtrace/src/main.rs:35:in `ruby_style_backtrace::f'
  /Users/yoshikawa/ruby-style-backtrace/src/main.rs:31:in `ruby_style_backtrace::main'
EOF
)"

Ruby風に加工する実装

実装にはbacktraceクレートを用いました。できれば std::backtrace::Backtrace を用いて済ませたかったのですが、今回の処理に必要なフレーム情報の取得手段がなかったのであきらめました。

具体的な実装は以下の通りです。

[package]
name = "ruby-style-backtrace"
version = "0.1.0"
edition = "2021"

[dependencies]
backtrace = "0.3.71"

use std::fmt::{Debug, Formatter};

use backtrace::Backtrace;

struct RubyStyleBacktrace(Backtrace);

impl Debug for RubyStyleBacktrace {
    fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {
        let symbols = self.0.frames().iter().flat_map(|frame| frame.symbols());

        for s in symbols {
            let filename = s
                .filename()
                .map_or_else(|| "<unknown>".into(), |p| p.to_string_lossy());
            write!(f, "  {filename}")?;
            if let Some(lineno) = s.lineno() {
                write!(f, ":{lineno}")?;
            }
            if let Some(name) = s.name() {
                writeln!(f, ":in `{name:#}'")?;
            } else {
                writeln!(f, ":in unknown method")?;
            }
        }

        Ok(())
    }
}

実際の出力は次のようなコードで確認できます。

fn main() {
    f();
}

fn f() {
    g();
}

fn g() {
    eprintln!(
        "something wrong\n{:?}",
        RubyStyleBacktrace(Backtrace::new()),
    );
}

something wrong
  /Users/yoshikawa/.cargo/registry/src/index.crates.io-6f17d22bba15001f/backtrace-0.3.71/src/backtrace/libunwind.rs:105:in `backtrace::backtrace::libunwind::trace'
  /Users/yoshikawa/.cargo/registry/src/index.crates.io-6f17d22bba15001f/backtrace-0.3.71/src/backtrace/mod.rs:66:in `backtrace::backtrace::trace_unsynchronized'
  /Users/yoshikawa/.cargo/registry/src/index.crates.io-6f17d22bba15001f/backtrace-0.3.71/src/backtrace/mod.rs:53:in `backtrace::backtrace::trace'
  /Users/yoshikawa/.cargo/registry/src/index.crates.io-6f17d22bba15001f/backtrace-0.3.71/src/capture.rs:193:in `backtrace::capture::Backtrace::create'
  /Users/yoshikawa/.cargo/registry/src/index.crates.io-6f17d22bba15001f/backtrace-0.3.71/src/capture.rs:158:in `backtrace::capture::Backtrace::new'
  /Users/yoshikawa/ruby-style-backtrace/src/main.rs:41:in `ruby_style_backtrace::g'
  /Users/yoshikawa/ruby-style-backtrace/src/main.rs:35:in `ruby_style_backtrace::f'
  /Users/yoshikawa/ruby-style-backtrace/src/main.rs:31:in `ruby_style_backtrace::main'
  /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/ops/function.rs:250:in `core::ops::function::FnOnce::call_once'
  /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/sys_common/backtrace.rs:155:in `std::sys_common::backtrace::__rust_begin_short_backtrace'
  /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:166:in `std::rt::lang_start::{{closure}}'
  /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/ops/function.rs:284:in `core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once'
  /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:552:in `std::panicking::try::do_call'
  /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:in `std::panicking::try'
  /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:in `std::panic::catch_unwind'
  /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:148:in `std::rt::lang_start_internal::{{closure}}'
  /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:552:in `std::panicking::try::do_call'
  /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:in `std::panicking::try'
  /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:in `std::panic::catch_unwind'
  /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:148:in `std::rt::lang_start_internal'
  /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:165:in `std::rt::lang_start'
  <anonymous>:in `_main'

出力内容の絞り込み

上記の出力は内容が冗長に感じられます。非同期関数の場合はtokioなどランタイム内部の情報も出力に含まれるのでなおさらです。情報を減らすことへの心配はあるものの、出力は以下の部分に絞り込んだ方が便利かもしれません。

something wrong
  /Users/yoshikawa/ruby-style-backtrace/src/main.rs:41:in `ruby_style_backtrace::g'
  /Users/yoshikawa/ruby-style-backtrace/src/main.rs:35:in `ruby_style_backtrace::f'
  /Users/yoshikawa/ruby-style-backtrace/src/main.rs:31:in `ruby_style_backtrace::main'

そのような絞り込みを行いたいとき参考になりそうなのがcolor-backtraceというクレートの下記の機能です。

Print frames of application code vs dependencies in different color

Hide all the frames after the panic was already initiated

Hide language runtime initialization frames

https://github.com/athre0z/color-backtrace/tree/v0.6.1?tab=readme-ov-file#features

残念ながら上記の機能は単独で利用可能な作りになっていないようです。したがって先ほどの RubyStyleBacktrace に絞り込み機能をつけるにはcolor_backtrace::Frame::is_dependency_code を移植する必要があります。具体的には次のような DemangledSymbol を用意します。

use std::path::Path;

use backtrace::BacktraceSymbol;

struct DemangledSymbol<'a> {
    pub name: Option<String>,
    pub filename: Option<&'a Path>,
    pub lineno: Option<u32>,
}

impl<'a> DemangledSymbol<'a> {
    pub fn new(symbol: &'a BacktraceSymbol) -> DemangledSymbol<'a> {
        Self {
            name: symbol.name().map(|name| format!("{:#}", name)),
            filename: symbol.filename(),
            lineno: symbol.lineno(),
        }
    }
}

#[allow(clippy::needless_borrow)]
impl<'a> DemangledSymbol<'a> {
    pub fn is_dependency_code(&self) -> bool {
        // この部分は https://github.com/athre0z/color-backtrace/blob/v0.6.1/src/lib.rs#L170-L212 と同じにする
    }
}

あとはこの DemangledSymbol を使うように RubyStyleBacktrace を変更すれば完成です。

impl Debug for RubyStyleBacktrace {
    fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {
        let symbols = self
            .0
            .frames()
            .iter()
            .flat_map(|frame| frame.symbols())
            .map(|s| DemangledSymbol::new(s))
            .filter(|s| !s.is_dependency_code());

        for s in symbols {
            let filename = s
                .filename
                .map_or_else(|| "<anonymous>".into(), |p| p.to_string_lossy());
            write!(f, "  {filename}")?;
            if let Some(lineno) = s.lineno {
                write!(f, ":{lineno}")?;
            }
            if let Some(name) = s.name {
                writeln!(f, ":in `{name}'")?;
            } else {
                writeln!(f, ":in unknown method")?;
            }
        }

        Ok(())
    }
}

is_dependency_code による絞り込みでは外部のクレートなどの部分は全て削られてしまうので、color_backtrace::Frame::is_runtime_init_codeなども参考に少しカスタマイズしてもよいかもしれません。

おわりに

苦しまぎれではありますがRustのスタックトレースの加工処理についてご紹介しました。今のところ社内でも実戦投入されておらず実用的と言いづらいですが、Rustのスタックトレース事情の紹介記事として何かの参考になれば幸いです。

エモーションテックでは顧客体験・従業員体験の改善をサポートし世の中の体験を変えるプロダクトを開発しており、その中で Rust や Google Cloud も利用しております。もし興味を持っていただけましたら、ぜひ採用ページからご応募をお願いいたします。

hrmos.co

EmotionTechテックブログ

株式会社エモーションテックのProduct Teamのメンバーが、日々の取り組みや技術的なことを発信していくブログです。