LoginSignup
20
11

More than 5 years have passed since last update.

@tatsuya6502(Tatsuya Kawano)

Rustコンパイラのデバッグログを取得する

Last updated at Posted at 2018-03-31

Rust コンパイラ（rustc）の振る舞いを確認するために debug レベルのログを取得する方法を説明します。

これらのログが必要になる機会はほとんどないと思いますが、今回、自分が必要になったので、その方法を記事として残しておきます。ちなみに必要になった理由は、型強制の中の method receiver coercion が、自分が理解した通りの順番で行われているのか確認したかったからでした。

準備：Rustツールチェインをソースコードからビルドする

コンパイラのデバッグログはコンパイラの開発者にとっては便利ですが、一般のユーザーが使うことはまずありません。そのため、Stable 版はもちろん、Nightly 版のコンパイラでもデバッグログをオフにしてビルドされています。

つまりコンパイラのデバッグログを取得するには、コンパイラを含む Rust ツールチェインをソースコードからビルドする必要があります。といっても特に難しいことはありません。基本的にこちらに書かれている手順でビルドすれば OK です。

ただ、デフォルトの設定ではデバッグログがオフになっているので、./x.py build を実行する前に以下のページを参考に config.toml ファイルを作成して、debug-assertions という設定を true にします。

また、rustup を使用している場合、sudo ./x.py install は実行せず、代わりに rustup toolchain link ... を実行します。

Linux x86_64でのビルド例

私は今回 Arch Linux x86_64 を使用しました。

# 必要なツールをインストールする。（gccとclangはどちらか一方でOK）
$ sudo pacman -S gcc clang python2 make cmake curl git

# Rustのソースコードを取得する
$ git clone https://github.com/rust-lang/rust.git
$ cd rust

# config.tomlを用意する
$ cp -p config.toml{.example,}
$ vi config.toml
# [rust]セクションのdebug-assertionsをtrueに変更する。

# Rustツールチェインをビルドする。
# 初回はLLVMをビルドするので数時間かかると思って気長に待つ。
$ ./x.py build

ビルドできたら rustup から使えるようにします。

# ツールチェインをlocalという名前で登録する。
$ rustup toolchain link local ./build/x86_64-unknown-linux-gnu/stage2

# 試しにrustcのバージョンを表示してみる。
$ rustc +local -V
rustc 1.26.0-dev

コンパイラのデバッグログを取得する

デバッグログを取得するには RUST_LOG 環境変数を使います。たとえば以下のようにすると、全てのモジュールのデバッグログが出力されます。

$ RUST_LOG=debug cargo +local build

ただこれだと凄まじい量のログが出力されます。Hello Worldで120万行ほどです。ですから以下のことをするのがおすすめです。

  • ログを標準エラー出力からファイルへリダイレクトする
  • 対象のモジュールを指定する
$ RUST_LOG=rustc_typeck::check::method=debug \
  cargo +local build 2> build.log

デバッグログ利用の実例

私が今回コンパイラのデバッグログを見たかった理由は、型強制の中の method receiver coercion が自分の理解している通りの順番で行われているか確認したかったからでした。今回調べたことを実例として紹介します。

Rust には型強制（type coercion）という暗黙の型変換があり、コードの簡潔性に大きく貢献しています。型強制にはいくつかの種類があり、すでに、こちらの記事でわかりやすく解説されています。

私が今回確認したかったのは、メソッドレシーバの型強制が起こる正確な順番です。たとえば、以下のコード片について考えます。

let v: Vec<u8> = vec![3, 4, 5];

// メソッドレシーバVec<u8>が、&[u8]へ型強制されることで、
// スライスのfirst(&self)メソッドが使われる。
let _ = v.first();

// もし型強制がなかったらこう書かなければならない。
// let _ = (&v[..]).first();

さて、v.first() で起こる Vec<u8> → &[u8] の型強制ですが、1ステップでは実現できません。最低でも2ステップ必要なのですが、それはどういう順番でしょうか？

  1. Vec<u8> →（Deref）→ [u8] →（レシーバの参照化）→ &[u8]
  2. Vec<u8> →（レシーバの参照化）→ &Vec<u8> →（Deref）→ &[u8]

Rust Reference の Method Call Expr を読むと、メソッドの検索の際、以下の順番で型強制が行われるようです。

  1. selfがレシーバの型（T型）のメソッドがあるならそのメソッドを使用する
  2. T型のトレイトメソッドがあるなら、それを使用
  3. &T型のメソッドがあるなら、&Tへ型強制してから使用
  4. &T型のトレイトメソッドがあるなら、&Tへ型強制してから使用
  5. &mut T型のメソッドがあるなら、&mut Tへ型強制してから使用
  6. &mut T型のトレイトメソッドがあるなら、&mut Tへ型強制してから使用
  7. 一致するメソッドが見つからないなら、Derefによる型強制かサイズの不定化を行い、1から6を繰り返す
  • 型が一致しない場合や、逆に型が一致するトレイトメソッドが複数見つかった場合はコンパイルエラーになる。

これによると、先ほどの例は以下の順番で型強制されるようです。

  1. 初回の1から6では該当せず
  2. 7でDerefによる型強制 Vec<u8> → [u8]
  3. 1に戻り、3のレシーバの参照化 [u8] → &[u8] でお目当の first() メソッドを見つける

つまり、この順番のようです。

  1. Vec<u8> →（Deref）→ [u8] →（レシーバの参照化）→ &[u8]

普段 Rust を使っている分には細かな順番を知らなくても不自由ありません。しかし私はここ一年ほど共著で Rust の日本語書籍を執筆しており、そこに書いたことが正しいことをドキュメントで確認するだけでなく、できる限り実際に動かして確認しておきたいと感じていました。上のことを調べてから2ヶ月ほど経ち、少し時間ができたので、本日、実際に確認してみたわけです。

さて、デバッグログの取得に先立って、Rust コンパイラのソースコードを検索し、モジュールの当たりをつけておきます。なお rg（ripgrep）コマンドは Rust で書かれた高速版の egrep です。

# メソッドレシーバの参照化はautorefdと呼ばれる。
$ rg autorefd src/
src/librustc_typeck/check/method/probe.rs
881:                self.pick_autorefd_method(step, hir::MutImmutable).or_else(|| {
882:                self.pick_autorefd_method(step, hir::MutMutable)
915:    fn pick_autorefd_method(&mut self, step: &CandidateStep<'tcx>, mutbl: hir::Mutability)

メソッドの検索とレシーバの型強制が rustc_typeck::check::method の辺りで行われているのだろうと見当がつきました。

先ほどのコード片を main() 関数に書きます。

src/main.rs
fn main() {
    let v: Vec<u8> = vec![3, 4, 5];
    let _ = v.first();
}

デバッグログ付きでビルドします。

$ RUST_LOG=rustc_typeck::check::method=debug \
  cargo +local build 2> build.log

$ wc -l build.log 
86 build.log

これで80行強のログが得られました。

ログを見ながら rg などで絞り込んでいきます。以下のようにすると流れがわかるようになりました。

$ rg 'probe.*item_name|pick_method|searching|applicable_candidates' \
    build.log     
2:DEBUG 2018-03-31T04:23:57Z: rustc_typeck::check::method::probe: probe(self_ty=[_], item_name=into_vec, scope_expr_id=17)
9:DEBUG 2018-03-31T04:23:57Z: rustc_typeck::check::method::probe: pick_method(self_ty=[_])
...

タイムスタンプなどは邪魔なので cut しました。

$ rg 'probe.*item_name|pick_method|searching|applicable_candidates' \
    build.log \
  | cut -d' ' -f 4-50
probe(self_ty=[_], item_name=into_vec, scope_expr_id=17)
pick_method(self_ty=[_])
searching inherent candidates
applicable_candidates: [(Candidate { xform_self_ty: [_], xform_ret_ty: None, item: AssociatedItem { def_id: DefId(3/0:1720 ~ alloc[7ae7]::slice[0]::{{impl}}[0]::into_vec[0]), name: into_vec, kind: Method, vis: Public, defaultness: Final, container: ImplContainer(DefId(3/0:1664 ~ alloc[7ae7]::slice[0]::{{impl}}[0])), method_has_self_argument: true }, kind: InherentImplCandidate(Slice([_]), []), import_id: None }, Match)]
probe(self_ty=std::vec::Vec<u8>, item_name=first, scope_expr_id=14)
pick_method(self_ty=std::vec::Vec<u8>)
searching inherent candidates
applicable_candidates: []
searching extension candidates
applicable_candidates: []
searching unstable candidates
applicable_candidates: []
pick_method(self_ty=&std::vec::Vec<u8>)
searching inherent candidates
applicable_candidates: []
searching extension candidates
applicable_candidates: []
searching unstable candidates
applicable_candidates: []
pick_method(self_ty=&mut std::vec::Vec<u8>)
searching inherent candidates
applicable_candidates: []
searching extension candidates
applicable_candidates: []
searching unstable candidates
applicable_candidates: []
pick_method(self_ty=[u8])
searching inherent candidates
applicable_candidates: []
searching extension candidates
applicable_candidates: []
searching unstable candidates
applicable_candidates: []
pick_method(self_ty=&[u8])
searching inherent candidates
applicable_candidates: [(Candidate { xform_self_ty: &[_], xform_ret_ty: Some(std::option::Option<&_>), item: AssociatedItem { def_id: DefId(3/0:1667 ~ alloc[7ae7]::slice[0]::{{impl}}[0]::first[0]), name: first, kind: Method, vis: Public, defaultness: Final, container: ImplContainer(DefId(3/0:1664 ~ alloc[7ae7]::slice[0]::{{impl}}[0])), method_has_self_argument: true }, kind: InherentImplCandidate(Slice([_]), []), import_id: None }, Match)]

probe(self_ty=std::vec::Vec<u8>, item_name=first, scope_expr_id=14) 以降が Vec<u8> に対するfirst() メソッドの検索です。

pick_method(self_ty=std::vec::Vec<u8>) で self の型を変えながら、以下のグループに適合する候補がないか探していきます。

  1. inherent（その型に直に impl されたメソッド）
  2. extension（トレイトメソッド）
  3. unstable（おそらく、フィーチャーゲートがかかっていて使えないメソッド。もしかして〜表示用と思われるが定かではない）

最終的に、pick_method(self_ty=&[u8]) で、applicable candidates（適合する候補）として、スライス &[_] の first メソッドが見つかりました。

pick_method に注目してもう一度 rg。

$ rg 'probe.*item_name|pick_method' build.log | cut -d' ' -f4-50
probe(self_ty=[_], item_name=into_vec, scope_expr_id=17)
pick_method(self_ty=[_])
probe(self_ty=std::vec::Vec<u8>, item_name=first, scope_expr_id=14)
pick_method(self_ty=std::vec::Vec<u8>)
pick_method(self_ty=&std::vec::Vec<u8>)
pick_method(self_ty=&mut std::vec::Vec<u8>)
pick_method(self_ty=[u8])
pick_method(self_ty=&[u8])

&std::vec::Vec<u8> では適合候補なしで、その後の [u8] も適合なし。最終的に &[u8] で適合しています。

以上のことから型強制がこの順番で起こることが確認できました。

  • Vec<u8> →（Deref）→ [u8] →（レシーバの参照化）→ &[u8]

まとめ

  • Rust コンパイラ（rustc）の振る舞いを確認するために debug レベルのログを出力する方法がある
  • そのためには Rust ツールチェインをソースコードからビルドする必要がある
  • RUST_LOG=debug では数百万のログが出力されるため、闇雲にログを出力しても成果が少ない。以下の準備をしておくと良い
    • ドキュメント（API doc、Rust Reference、The Book、RFCなど）を読んで、振る舞いに対する仮説を立てる
    • コンパイラのソースコードを検索してモジュールの当たりをつけておく
20
11
2

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
20
11