Rustのプリントデバッグお助けデッキ

ソフトウェアエンジニアのmatsu7874です。UV Study : Rust LT会 ~新米Rustaceanたちへ~ というイベントで『プリントデバッグを失敗させないテクニック』というタイトルで登壇しました。評判が良かったので解説を追加してブログを書いてみます。今日Rustを書き始める人にも分かるように書きます。

プリントデバッグについて話すモチベーション

新しい言語を勉強するときにプリントデバッグをしながら動作を理解していくことがあります。Rustの場合はいくつかハマりポイントがあるため、初心者に対して余計な障壁になる可能性があります。転ばぬ先の杖としてプリントデバッグについて絞って解説をします。

println! eprintln! debug!

Rustでは println!, eprintln!, debug! などのマクロが出力系のマクロとして用意されています。

println!は標準出力、eprintln!とdbg!は標準エラー

マクロの引数に文字列を渡すとその文字列がprintln!は標準出力、eprintln!とdbg!は標準エラーに出力されます。

fn main() {
  println!("Hello, stdout!"); //=> Hello, stdout!
  eprintln!("Hello, stderr!"); //=> Hello, stderr!
  dbg!("Hello, dbg!");   //=> [src/bin/01.rs:4:5] "Hello, dbg!" = "Hello, dbg!"
}

{}で変数の中身も表示できる、が、エラーになるものもある

変数の内容を出力したい場合は下記の例の様に文字列中に{} でプレイスホルダーを書き、そこに表示したい変数を第2引数以降に書きます。

fn main() {
　　let x = 1;
　　println!("{}", x); //=> 1
}

しかし Vec型のように {} では表示できない型もあります。

fn main() {
　　let x = 1;
　　println!("{}", x); //=> 1
　　let v = vec![1, 2, 3];
　　println!("{}", v);
}

error[E0277]: `Vec<{integer}>` doesn't implement `std::fmt::Display`
 --> src/bin/02.rs:5:20
  |
5 |     println!("{}", v);
  |                    ^ `Vec<{integer}>` cannot be formatted with the default formatter
  |
  = help: the trait `std::fmt::Display` is not implemented for `Vec<{integer}>`
  = note: in format strings you may be able to use `{:?}` (or {:#?} for pretty-print) instead

{:?}でデバッグ表示, {:#?}でpretty-print

デバッグ用のプレイスホルダー{:?}やpretty-print用のプレイスホルダー {:#?} などを使うと表示することができます。こちらは標準ライブラリの全てのstructに用意されています。

let v = vec![1, 2, 3];
println!("{:?}", v); //=> [1, 2, 3]
println!("{:#?}", v);
//=> [
//     1,
//     2,
//     3
// ]

DebugとDisplay

自分で定義したstructも{:?}できないのですか？

自分でstructを定義することもありますが、そのままではデバッグ出力することはできません。Debugを実装してくれという旨のエラーが表示されます。

struct MyS {
  x: usize,
}
fn main() {
  let my_s = MyS { x: 12 };
  println!("{:?}", my_s);
}

error[E0277]: `MyS` doesn't implement `Debug`
 --> src/bin/04.rs:7:22
  |
7 |     println!("{:?}", my_s);
  |                      ^^^^ `MyS` cannot be formatted using `{:?}`
  |
  = help: the trait `Debug` is not implemented for `MyS`
  = note: add `#[derive(Debug)]` to `MyS` or manually `impl Debug for MyS`

help: consider annotating `MyS` with `#[derive(Debug)]`
  |
1 + #[derive(Debug)]
2 | struct MyS {
  |

#[derive(Debug)]アトリビュートをつけると表示できる

Debugというtraitはderiveマクロを使って自動実装できます。次のように書くことで自分で定義した struct MyS をデバッグ出力することができます。

#[derive(Debug)]
struct MyS {
  x: usize,
}
fn main() {
  let my_s = MyS { x: 12 };
  println!("{:?}", my_s); //=> MyS { x: 12 }
}

各フィールドがDebugを実装していればstructは要素のDebugを使える

Debugは再帰的に各要素を見るため、Debugを実装したstructを要素として持つstructにもDebugを自動実装することができます。

#[derive(Debug)]
struct MyS {
  x: usize,
}
#[derive(Debug)]
struct MyWrapper {
  my_s: MyS,
}

fn main() {
  let my_s = MyS { x: 12 };
  println!("{:?}", my_s); //=> MyS { x: 12 }
  let my_w = MyWrapper { my_s };
  println!("{:?}", my_w);  //=> MyWrapper { my_s: MyS { x: 12 } }
}

補足：Debugをつけるデメリットはコンパイルがほんの少し遅くなるだけ

イベントでの発表時に「Debugは常にderiveをつけるのはアンチパターンか？」という質問をいただきました。その場では「若干コンパイルが遅くなる事はあるだろうが常に付けてよい、おすすめ」と回答したのですが、実際どれくらいの影響があるか具体的な数字は答えられませんでした。

手元のMacBook Pro(Apple M1 Pro)で実験をしてみました。1000個のstructを定義した巨大main.rsを用意して #[derive(Debug)]の有無でコンパイル時間がどれだけ変わるかを比較しました。

struct Struct000 {
  field: i32,
}
// 以下001~Nまで並ぶ
fn main() {
  let struct000 = Struct000 { field: 1 };
  println!("struct000.field: {:?}, struct000.field: {:?}", struct000.field, struct000.field);
  // 以下001~999まで並ぶ
}

#[derive(Debug)]
struct Struct000 {
    field: i32,
}
// 以下001~Nまで並ぶ
fn main() {
    let struct000 = Struct000 { field: 1 };
    println!("struct000: {:?}, struct000.field: {:?}", struct000, struct000.field);
    // 以下001~Nまで並ぶ
}

N=1000の場合の time cargo buildの所要時間は下記の表のとおりでした。

	1回目[s]	2回目[s]	3回目[s]
Debugなし	1.32	1.29	1.29
Debugあり	1.71	1.89	1.89

N=100, 500も含めた結果を下記のグラフに示します。

結論として、コンパイル時間は伸びるが、コンパイル時の追加の1秒が問題になる状況以外では常に #[derive(Debug)] を付けておくことは問題にならないと考えられます。

自由に整形したいときはtrait Displayを実装する

Debug( {:?}での出力 )よりも自由に出力フォーマットを決めたい場合はDisplayトレイトを実装します。これは {} の場合に使われるトレイトで、人間用の出力フォーマットを設定するものです。

#[derive(Debug)]
struct Restaurant {
  name: String,
  location: String,
  rating: usize,
}
impl std::fmt::Display for Restaurant {
  fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
    write!(f,"{}({}): {}",
      self.name, self.location,
      "★".repeat(self.rating)
    )
  }
}

let r = Restaurant {
  name: "Diner matsu7874".to_string(),
  location: "Tokyo".to_string(),
  rating: 5,
};
println!("{:?}", r);
//=> Restaurant {
  name: "Diner matsu7874",
  location: "Tokyo",
  rating: 5
}
println!("{}", r);//=> Diner matsu7874(Tokyo): ★★★★★

中間まとめ

dbg!や {:?} で表示するためには std::fmt::Debug が必要で、 {} で表示するためには std::fmt::Displayの実装が必要です。

#[derive(Debug)]
struct struct名{}
impl std::fmt::Display for struct名 {
  fn fmt(&self, f: &mut std::fmt::Formatter)
    -> std::fmt::Result {
    write!(f,"ここに好きな表示形式", /*値を表示する場合はここに値を書く*/)
  }
}

copilotなどがボイラーテンプレートを出力してくれるので細かいシグネチャは覚えなくて良いです。

テストコードのプリントデバッグ

次にテストコードのプリントデバッグについて説明します。

失敗しているテストコードの出力は表示される

テストコード中の出力は失敗したテストの出力だけが表示されます。下記のような間違った実装をcargo testなどで実行すると下記のように eprintlnの出力がターミナルに現れます。

pub fn div(n: u32, d: u32) -> Option<(u32, u32)> {
  Some((0, 0))
}
#[cfg(test)]mod tests {
  #[test]
  fn test_div() {
    let actual = super::div(10, 3);
    eprintln!("actual={:?}", actual);
    let expected = Some((3, 1));
    assert_eq!(actual, expected);
  }
}

test tests::test_div ... FAILED

failures:
---- tests::test_div stdout ----
actual=Some((0, 0))
thread 'tests::test_div' panicked at
src/bin/07.rs:24:9:
assertion `left == right` failed
　　　　left: Some((0, 0))
　　　　right: Some((3, 1))

成功したテストコードの出力は基本的に表示されない

一方で正しいコードを書くと、 test tests::test_div ... ok という結果が表示されるのみで、実装中の eprintln!("n={}, answer={}", n, answer);などの出力内容はターミナルに表示されません。

pub fn div(n: u32, d: u32)　-> Option<(u32, u32)> {
  if d == 0 {
    return None;
  }  
  let mut answer = 0;
  let mut n = n;
  while n >= d {
    n -= d;
    answer += 1;
    eprintln!("n={}, answer={}", n, answer);
  }
  Some((answer, n))
}

#[cfg(test)]
mod tests {
  use super::div;
  #[test]
  fn test_div() {
    let actual = div(10, 3);
    eprintln!("actual={:?}", actual);
    let expected = Some((3, 1));
    assert_eq!(actual, expected);
  }
}

cargo test -- --nocapture で実行すると表示される

テストランナーに握りつぶされている成功するテストコードの出力を見るには cargo test -- --nocapture というように--nocapture がテストの実行バイナリに渡るように実行してやる必要があります。cargoの引数 -- はその後の引数をコンパイルされた実行バイナリ側の引数として渡すための引数です。

$ cargo test -- --nocapture
running 1 test
n=7, answer=1
n=4, answer=2
n=1, answer=3
actual=Some((3, 1))
test tests::test_div ... ok

ビルドスクリプトのプリントデバッグ

Rustではビルド時に実行されるRustプログラムを設定できます。Cargo.tomlのbuild属性として記述するとビルド時に本体のプログラムの前にbuild.rsが実行されるようになります。環境変数の切り替えやコード生成など環境ごとの差分を埋めるような処理をする使い方があるものです。

[package]
name = "print-debug-tutorial"
version = "0.1.0"
edition = "2021"
build = "build.rs"

ビルドスクリプトのbuild.rsの出力も基本的に表示されない

ビルドスクリプトの標準出力・標準エラーも通常は表示されません。下記のようなbuild.rsを用意しても cargo buildではどのように動いているかプリントデバッグでは確認できません。

fn main() {
  println!("build.rs println");
  eprintln!("build.rs eprintln");
  println!("cargo:rustc-env=FROM_BUILD_RS_ENV_A=TRUE");
  println!("cargo:rustc-env=FROM_BUILD_RS_ENV_B=FALSE");
  eprintln!("cargo:rustc-env=FROM_BUILD_RS_ENV_C=FALSE");
}

build.rsの出力は –vvをつけると表示できる

-vv オプションを使うことでビルドスクリプトの出力も表示されるようになります。 -vだけでは表示されません。

$ cargo build –vv
...省略
[print-debug-tutorial 0.1.0] build.rs eprintln
[print-debug-tutorial 0.1.0] cargo:rustc-env=FROM_BUILD_RS_ENV_C=FALSE
[print-debug-tutorial 0.1.0] build.rs println
[print-debug-tutorial 0.1.0] cargo:rustc-env=FROM_BUILD_RS_ENV_A=TRUE
[print-debug-tutorial 0.1.0] cargo:rustc-env=FROM_BUILD_RS_ENV_B=FALSE
...省略

最後に

必要なときに検索して調べられるように存在だけ知っていると良さそうなものを紹介しました。
estieではRustを使ってアプリケーション開発をしています。
ご興味ある方はぜひ下記のURLからカジュアル面談の申込をお願いします！

hrmos.co