부트스트랩 디버깅

부트스트랩을 디버깅(및 프로파일링)하는 주요 방법은 두 가지입니다. 첫 번째는 println 로깅을 통한 방법이고, 두 번째는 tracing 기능을 통한 방법입니다.

`println` 로깅

부트스트랩은 방대한 비구조화 로깅을 제공합니다. 대부분은 --verbose 플래그를 지정해야 출력됩니다(더 자세한 정보를 보려면 -vv를 전달하십시오).

실행된 Cargo 명령의 상세 출력과 그 밖의 자세한 로그를 보려면 부트스트랩을 호출할 때 -v 또는 -vv를 전달하십시오. 이 로그는 구조화되어 있지 않으며 양이 너무 많을 수 있다는 점에 유의하십시오.

$ ./x dist rustc --dry-run -vv
learning about cargo
running: RUSTC_BOOTSTRAP="1" "/home/jyn/src/rust2/build/x86_64-unknown-linux-gnu/stage0/bin/cargo" "metadata" "--format-version" "1" "--no-deps" "--manifest-path" "/home/jyn/src/rust2/Cargo.toml" (failure_mode=Exit) (created at src/bootstrap/src/core/metadata.rs:81:25, executed at src/bootstrap/src/core/metadata.rs:92:50)
running: RUSTC_BOOTSTRAP="1" "/home/jyn/src/rust2/build/x86_64-unknown-linux-gnu/stage0/bin/cargo" "metadata" "--format-version" "1" "--no-deps" "--manifest-path" "/home/jyn/src/rust2/library/Cargo.toml" (failure_mode=Exit) (created at src/bootstrap/src/core/metadata.rs:81:25, executed at src/bootstrap/src/core/metadata.rs:92:50)
...

부트스트랩의 `tracing`

부트스트랩에는 조건부 tracing 기능이 있으며, 이 기능은 다음을 제공합니다.

tracing 이벤트와 스팬을 사용한 구조화된 로깅을 활성화합니다.
실행된 단계와 명령의 계층 구조 및 소요 시간을 시각화하는 데 사용할 수 있는 Chrome 트레이스 파일을 생성합니다.
- 생성된 chrome-trace.json 파일은 Chrome의 chrome://tracing 탭에서 열거나, 예를 들어 Perfetto를 사용하여 열 수 있습니다.
실행된 단계 간의 의존성을 시각화하는 GraphViz 그래프를 생성합니다.
- 생성된 step-graph-*.dot 파일은 예를 들어 xdot으로 열어 단계 그래프를 시각화하거나, dot -Tsvg 등을 사용하여 GraphViz 파일을 SVG 파일로 변환할 수 있습니다.
어떤 명령이 실행되었는지, 그 실행 중 몇 번이 캐시되었는지, 어떤 명령의 실행이 가장 느렸는지를 보여 주는 명령 실행 요약을 생성합니다.
- 생성된 command-stats.txt 파일은 사람이 읽기 쉬운 간단한 형식으로 되어 있습니다.

구조화된 로그는 표준 오류 출력(stderr)에 기록되고, 나머지 출력은 <build-dir>/bootstrap-trace/<pid> 디렉터리의 파일에 저장됩니다. 편의를 위해 부트스트랩은 가장 최근에 생성된 트레이스 출력 디렉터리를 가리키는 심볼릭 링크도 <build-dir>/bootstrap-trace/latest에 생성합니다.

부트스트랩을 --dry-run으로 실행하면 트레이싱 출력 디렉터리가 달라질 수 있다는 점에 유의하십시오. 부트스트랩은 실행이 끝날 때 트레이싱 출력 파일이 저장된 경로를 항상 출력합니다.

`tracing` 출력 활성화

조건부 tracing 기능을 활성화하려면 BOOTSTRAP_TRACING 환경 변수를 설정하여 부트스트랩을 실행하십시오.

$ BOOTSTRAP_TRACING=trace ./x build library --stage 1

출력 예시¹:

$ BOOTSTRAP_TRACING=trace ./x build library --stage 1 --dry-run
Building bootstrap
    Finished `dev` profile [unoptimized] target(s) in 0.05s
15:56:52.477  INFO > tool::LibcxxVersionTool {target: x86_64-unknown-linux-gnu} (builder/mod.rs:1715)
15:56:52.575  INFO > compile::Assemble {target_compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }} (builder/mod.rs:1715)
15:56:52.575  INFO > tool::Compiletest {compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, target: x86_64-unknown-linux-gnu} (builder/mod.rs:1715)
15:56:52.576  INFO  > tool::ToolBuild {build_compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, target: x86_64-unknown-linux-gnu, tool: "compiletest", path: "src/tools/compiletest", mode: ToolBootstrap, source_type: InTree, extra_features: [], allow_features: "internal_output_capture", cargo_args: [], artifact_kind: Binary} (builder/mod.rs:1715)
15:56:52.576  INFO   > builder::Libdir {compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, target: x86_64-unknown-linux-gnu} (builder/mod.rs:1715)
15:56:52.576  INFO    > compile::Sysroot {compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, force_recompile: false} (builder/mod.rs:1715)
15:56:52.578  INFO > compile::Assemble {target_compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }} (builder/mod.rs:1715)
15:56:52.578  INFO > tool::Compiletest {compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, target: x86_64-unknown-linux-gnu} (builder/mod.rs:1715)
15:56:52.578  INFO  > tool::ToolBuild {build_compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, target: x86_64-unknown-linux-gnu, tool: "compiletest", path: "src/tools/compiletest", mode: ToolBootstrap, source_type: InTree, extra_features: [], allow_features: "internal_output_capture", cargo_args: [], artifact_kind: Binary} (builder/mod.rs:1715)
15:56:52.578  INFO   > builder::Libdir {compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, target: x86_64-unknown-linux-gnu} (builder/mod.rs:1715)
15:56:52.578  INFO    > compile::Sysroot {compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, force_recompile: false} (builder/mod.rs:1715)
    Finished `release` profile [optimized] target(s) in 0.11s
Tracing/profiling output has been written to <src-root>/build/bootstrap-trace/latest
Build completed successfully in 0:00:00

트레이싱 출력 제어

환경 변수 BOOTSTRAP_TRACING은 tracing_subscriber 필터를 받습니다. BOOTSTRAP_TRACING=trace로 설정하면 모든 로그가 활성화되지만, 양이 너무 많을 수 있습니다. 따라서 필터를 사용하여 기록되는 데이터의 양을 줄일 수 있습니다.

원하는 트레이싱 로그의 종류를 제어하는 서로 독립적인 방법이 두 가지 있습니다.

debug나 trace와 같이 로그 레벨을 지정할 수 있습니다.
- 레벨을 선택하면 우선순위 레벨이 그와 같거나 더 높은 모든 이벤트/스팬이 표시됩니다.
로그 대상도 제어할 수 있습니다. 예를 들어 bootstrap, bootstrap::core::config 또는 CONFIG_HANDLING이나 STEP 같은 사용자 정의 대상을 지정할 수 있습니다.
- BOOTSTRAP_TRACING=trace 출력은 상당히 장황할 수 있으므로, 사용자 정의 대상은 관심 있는 스팬의 종류를 제한하는 데 사용됩니다. 현재 다음 사용자 정의 대상을 사용할 수 있습니다.
  - CONFIG_HANDLING: 설정 처리와 관련된 스팬을 표시합니다.
  - STEP: 실행된 모든 단계를 표시합니다. 실행된 명령은 info 이벤트 레벨을 가집니다.
  - COMMAND: 실행된 모든 명령을 표시합니다. 실행된 명령은 trace 이벤트 레벨을 가집니다.
  - IO: 수행된 I/O 작업을 표시합니다. 실행된 명령은 trace 이벤트 레벨을 가집니다.
    - 현재 많은 I/O가 추적되지 않고 있다는 점에 유의하십시오.

물론 이들을 조합할 수도 있습니다(사용자 정의 대상 로그는 일반적으로 TRACE 로그 레벨로도 추가로 제한됩니다).

$ BOOTSTRAP_TRACING=CONFIG_HANDLING=trace,STEP=info,COMMAND=trace ./x build library --stage 1

BOOTSTRAP_TRACING으로 지정한 레벨은 Chrome 추적 파일에 기록될 스팬에도 영향을 준다는 점에 유의하십시오.

BOOTSTRAP_TRACING_SKIP_TIME=1 환경 변수를 전달하여 추적 출력에 타임스탬프가 포함되지 않도록 할 수도 있습니다. 이는 두 버전의 bootstrap 간에 실행된 단계를 비교하거나 diff할 때 유용합니다.

FIXME(#96176): `compiler()`와 `compiler_for()`에 대한 전용 추적

추가 대상인 COMPILER와 COMPILER_FOR는 builder.compiler()와 builder.compiler_for()가 무엇을 하는지 추적하는 데 도움을 주기 위해 사용됩니다. #96176 이슈가 해결되면 이 대상들은 제거되어야 합니다.

bootstrap에서 `tracing` 사용하기

tracing::* 매크로와 tracing::instrument proc-macro 속성은 모두 tracing 기능 뒤에 게이트되어야 합니다. 예시:

#[cfg(feature = "tracing")]
use tracing::instrument;

struct Foo;

impl Step for Foo {
    type Output = ();

    #[cfg_attr(feature = "tracing", instrument(level = "trace", name = "Foo::should_run", skip_all))]
    fn should_run(run: ShouldRun<'_>) -> ShouldRun<'_> {
        trace!(?run, "entered Foo::should_run");

        todo!()
    }

    fn run(self, builder: &Builder<'_>) -> Self::Output {
        trace!(?run, "entered Foo::run");

        todo!()
    }    
}

#[instrument]의 경우 다음을 권장합니다.

세밀한 추적을 위해 trace 레벨 뒤에 게이트하고, 핵심 함수라면 debug 레벨 뒤에 게이트하는 것도 고려하십시오.
예를 들어 서로 다른 단계의 run을 구별할 수 있도록 name = ".."을 통해 계측 이름을 명시적으로 지정하십시오.
추적으로 인해 동작이 달라지지 않도록 주의하십시오. 예를 들어 추적 인프라가 활성화된 경우에만 추가적인 것을 빌드해서는 안 됩니다.

안타깝게도 bootstrap은 rust-analyzer.linkedProjects이므로, https://github.com/rust-lang/rust-analyzer/issues/8521에 설명된 대로 지원이 부족하여 관련 자동 완성을 얻기 위해 tracing 기능을 활성화한 상태로 r-a에게 bootstrap 자체를 검사하거나 빌드하도록 요청할 수 없습니다.

이 출력은 언제든지 변경될 수 있습니다. ↩

Rust 컴파일러 개발 가이드