트레이싱을 사용하여 컴파일러 디버깅하기

컴파일러에는 debug!(또는 trace!) 호출이 많이 있으며, 이 호출들은 여러 지점에서 로깅 정보를 출력합니다. 이러한 호출은 버그를 완전히 찾아내지는 못하더라도 최소한 버그의 위치를 좁히는 데, 또는 단순히 컴파일러가 왜 특정한 동작을 하는지 파악하는 데 매우 유용합니다.

로그를 보려면 RUSTC_LOG 환경 변수를 원하는 로그 필터로 설정해야 합니다. 로그 필터의 전체 구문은 tracing-subscriber의 rustdoc에서 확인할 수 있습니다.

환경 변수

다음은 rustc가 트레이싱 출력을 사용자 지정하기 위해 받아들이는 환경 변수의 개요입니다. 이 변수들의 정의는 대부분 compiler/rustc_log/src/lib.rs에서 찾을 수 있습니다.

함수 수준 필터

rustc의 많은 함수에는 다음과 같은 어노테이션이 붙어 있습니다

#[instrument(level = "debug", skip(self))]
fn foo(&self, bar: Type) {}

이를 통해 다음을 사용하여

RUSTC_LOG=[foo]

아래 작업을 한꺼번에 수행할 수 있습니다

• foo에 대한 모든 함수 호출을 로그로 남깁니다
• 인자를 로그로 남깁니다(skip 목록에 있는 인자는 제외합니다).
• 함수가 반환될 때까지 (컴파일러의 다른 어느 곳에서 발생하든) 모든 것을 로그로 남깁니다.

모든 것을 원하지는 않습니다

함수의 스코프에 따라서는 함수 본문의 모든 내용을 로그로 남기고 싶지 않을 수도 있습니다. 예를 들어, do_mir_borrowck 함수는 사소한 코드를 빌림 검사할 때에도 수백 줄을 출력합니다.

모든 필터를 조합할 수 있으므로, 예를 들어 다음과 같이 크레이트/모듈 경로를 추가할 수 있습니다.

RUSTC_LOG=rustc_borrowck[do_mir_borrowck]

모든 호출을 원하지는 않습니다

libcore를 컴파일하는 경우라면 모든 borrowck 덤프가 아니라 특정 함수 하나에 대한 덤프만 원할 가능성이 높습니다. 함수 호출의 인자에 정규식을 적용하여 함수 호출을 필터링할 수 있습니다.

RUSTC_LOG=[do_mir_borrowck{id=\.\*from_utf8_unchecked\.\*}]

위와 같이 하면 from_utf8_unchecked를 빌림 검사하는 로그만 얻을 수 있습니다. 무시된 do_mir_borrowck마다 짧은 메시지는 여전히 출력되지만, 해당 호출 내부의 내용은 전혀 출력되지 않는다는 점에 유의하십시오. 이는 실제로 일어나는 호출을 살펴보는 데 도움이 되며, 정규식을 잘못 입력한 경우 이를 수정하는 데에도 도움이 됩니다.

쿼리 수준 필터

모든 쿼리에는 로깅 스팬이 자동으로 태그되므로, 쿼리 실행 중의 모든 로그 메시지를 표시할 수 있습니다. 예를 들어, 타입 검사 중의 모든 것을 로그로 남기려면 다음과 같이 합니다.

RUSTC_LOG=[typeck]

쿼리 인자는 tracing 필드로 포함되므로, 인자의 디버그 표시를 기준으로 필터링할 수 있습니다. 예를 들어, typeck 쿼리에는 검사 대상을 나타내는 key: LocalDefId 인자가 있습니다. 정규식으로 해당 LocalDefId를 매칭하여 특정 함수의 타입 검사를 로그로 남길 수 있습니다.

RUSTC_LOG=[typeck{key=.*name_of_item.*}]

쿼리마다 인자가 다릅니다. 쿼리 목록과 각 쿼리의 인자는 rustc_middle/src/queries.rs에서 찾을 수 있습니다.

광범위한 모듈 수준 필터

log 크레이트의 필터와 비슷한 필터를 사용할 수도 있으며, 이 필터는 특정 모듈 내의 모든 것을 활성화합니다. 이 방식은 대개 출력이 너무 많고 구조화되어 있지 않으므로 함수 수준 필터를 사용할 것을 권장합니다.

로그 필터로 debug만 지정하면 모든 debug! 이상의 출력(예: info!도 포함됩니다)을 얻을 수 있고, path::to::module을 지정하면 특정 모듈의 모든 출력(trace! 포함)을 얻을 수 있으며, path::to::module=debug를 지정하면 특정 모듈의 debug! 이상의 출력을 얻을 수 있습니다.

예를 들어, 특정 모듈의 debug! 이상의 출력을 얻으려면 RUSTC_LOG=path::to::module=debug rustc my-file.rs로 컴파일러를 실행하면 됩니다. 그러면 모든 debug! 출력이 표준 오류에 나타납니다.

경로의 일부만 사용해도 필터가 여전히 동작한다는 점에 유의하십시오. 예를 들어, rustdoc::passes::collect_intra_doc_links의 info! 출력만 보고 싶다면 RUSTDOC_LOG=rustdoc::passes::collect_intra_doc_links=info를 사용할 수도 있고, 또는 RUSTDOC_LOG=rustdoc::passes::collect_intra=info를 사용할 수도 있습니다.

rustdoc을 개발하는 경우에는 대신 RUSTDOC_LOG를 사용하십시오. Miri를 개발하는 경우에는 대신 MIRI_LOG를 사용하십시오. 이제 감이 잡히실 것입니다 :)

사용할 수 있는 전체 구문을 확인하려면 tracing 크레이트의 문서, 특히 debug!에 대한 문서를 참고하십시오. (참고: 컴파일러와 달리 tracing 크레이트와 그 예제는 RUSTC_LOG 환경 변수를 사용합니다. rustc, rustdoc 및 기타 도구는 자체 환경 변수를 설정합니다.)

매우 엄격한 필터를 사용하지 않는 한 로거가 많은 출력을 내보낸다는 점에 유의하여, 가능한 한 가장 구체적인 모듈을 지정하십시오(여러 개라면 쉼표로 구분). 일반적으로 표준 에러를 파일로 파이프하고 텍스트 편집기로 로그 출력을 살펴보는 것이 좋습니다.

이를 종합하면 다음과 같습니다:

# This puts the output of all debug calls in `rustc_middle/src/traits` into
# standard error, which might fill your console backscroll.
$ RUSTC_LOG=rustc_middle::traits=debug rustc +stage1 my-file.rs

# This puts the output of all debug calls in `rustc_middle/src/traits` in
# `traits-log`, so you can then see it with a text editor.
$ RUSTC_LOG=rustc_middle::traits=debug rustc +stage1 my-file.rs 2>traits-log

# Not recommended! This will show the output of all `debug!` calls
# in the Rust compiler, and there are a *lot* of them, so it will be
# hard to find anything.
$ RUSTC_LOG=debug rustc +stage1 my-file.rs 2>all-log

# This will show the output of all `info!` calls in `rustc_codegen_ssa`.
#
# There's an `info!` statement in `codegen_instance` that outputs
# every function that is codegen'd. This is useful to find out
# which function triggers an LLVM assertion, and this is an `info!`
# log rather than a `debug!` log so it will work on the official
# compilers.
$ RUSTC_LOG=rustc_codegen_ssa=info rustc +stage1 my-file.rs

# This will show all logs in `rustc_codegen_ssa` and `rustc_resolve`.
$ RUSTC_LOG=rustc_codegen_ssa,rustc_resolve rustc +stage1 my-file.rs

# This will show the output of all `info!` calls made by rustdoc
# or any rustc library it calls.
$ RUSTDOC_LOG=info rustdoc +stage1 my-file.rs

# This will only show `debug!` calls made by rustdoc directly,
# not any `rustc*` crate.
$ RUSTDOC_LOG=rustdoc=debug rustdoc +stage1 my-file.rs

로그 색상

기본적으로 rustc(그리고 rustdoc이나 Miri 같은 다른 도구)는 로그 출력에 ANSI 색상을 언제 사용할지 알아서 판단합니다. 터미널로 출력하는 경우에는 색상을 사용하고, 파일로 출력하거나 다른 곳으로 파이프되는 경우에는 사용하지 않습니다. 하지만 매우 엄격한 필터를 사용하지 않는 한 터미널에서 로그 출력을 읽기 어려우므로, 출력을 less 같은 페이저로 파이프하고 싶을 수 있습니다. 그러나 그렇게 하면 색상이 전혀 표시되지 않아 찾고 있는 내용을 골라내기가 어렵습니다!

로그 출력에 색상을 사용할지 여부는 RUSTC_LOG_COLOR 환경 변수(rustdoc은 RUSTDOC_LOG_COLOR, Miri는 MIRI_LOG_COLOR 등)로 재정의할 수 있습니다. 옵션은 auto(기본값), always, never 세 가지입니다. 따라서 less로 파이프할 때 색상을 활성화하려면 다음과 비슷한 명령을 사용하십시오:

# The `-R` switch tells less to print ANSI colors without escaping them.
$ RUSTC_LOG=debug RUSTC_LOG_COLOR=always rustc +stage1 ... | less -R

MIRI_LOG_COLOR는 Miri에서 나온 로그에만 색상을 입히며, Miri가 호출하는 rustc 함수의 로그에는 색상을 입히지 않는다는 점에 유의하십시오. rustc의 로그에 색상을 입히려면 RUSTC_LOG_COLOR를 사용하십시오.

결과 바이너리에서 debug! 및 trace! 호출을 유지하거나 제거하는 방법

error!, warn!, info! 호출은 컴파일러의 모든 빌드에 포함되지만, debug!와 trace! 호출은 bootstrap.toml에서 rust.debug-logging=true가 켜져 있는 경우에만 프로그램에 포함됩니다(기본값은 꺼져 있습니다). 따라서 DEBUG 로그가 보이지 않는다면, 특히 RUSTC_LOG=rustc rustc some.rs로 컴파일러를 실행했는데 INFO 로그만 보인다면, bootstrap.toml에서 rust.debug-logging=true가 켜져 있는지 확인하십시오.

로깅 에티켓과 관례

debug! 호출은 기본적으로 제거되므로, 대부분의 경우 “불필요한” debug! 호출을 추가하고 커밋하는 코드에 남겨 두더라도 성능은 걱정하지 않아도 됩니다. 이러한 호출은 우리가 배포하는 결과물의 성능을 떨어뜨리지 않습니다.

그렇기는 하지만 트레이싱 호출이 과도해질 수도 있으며, 특히 근처의 다른 호출이나 여기서 호출되는 함수 안의 호출과 중복되는 경우가 그렇습니다. 여기에는 완벽한 균형점이 없으며, debug! 문을 남겨 두도록 허용할지, 아니면 병합 전에 제거하도록 요청할지는 리뷰어의 재량에 맡겨집니다.

출력이 매우 많은 로그에는 debug!보다 trace!를 사용하는 것이 더 나을 수 있습니다.

느슨하게 지켜지는 관례로, 함수 foo의 시작 부분에서는 debug!("foo(...)") 대신 #[instrument(level = "debug")](이 속성의 문서도 참고하십시오)를 사용합니다. 함수 내부에서는 debug!("xyz = {:?}", variable.field)보다 debug!(?variable.field)를, debug!("bar = {:?}", var.method(arg))보다 debug!(bar = ?var.method(arg))를 사용하는 것이 좋습니다. 이 구문에 대한 문서는 여기에서 확인할 수 있습니다.

한 가지 주의해야 할 점은 로그 안의 비용이 큰 연산입니다.

rustc::foo 모듈에 다음과 같은 문이 있다고 합시다

debug!(x = ?random_operation(tcx));

그러면 누군가 RUSTC_LOG=rustc::foo로 디버그 rustc를 실행할 때 random_operation()이 실행됩니다. 이 디버그 문을 활성화하지 않는 RUSTC_LOG 필터는 random_operation을 실행하지 않습니다.

따라서 그곳에는 비용이 너무 크거나 충돌을 일으킬 가능성이 있는 것을 넣지 마십시오. 그렇게 하면 해당 모듈에 로깅을 사용하려는 모든 사람에게 불편을 주게 됩니다. 누군가 로깅을 사용해 다른 버그를 찾으려 하기 전까지는 아무도 그 사실을 모를 것입니다.