From cc9b40d3a14338a738639684560d81e7716cfe7e Mon Sep 17 00:00:00 2001 From: Christian Legnitto Date: Thu, 2 Jan 2025 15:50:12 -0400 Subject: [PATCH 1/2] Add tracing to rustc_codegen_spirv Fixes https://github.com/Rust-GPU/rust-gpu/issues/192 --- .github/workflows/lint.sh | 10 +- Cargo.lock | 232 ++++++++++++++++++++------ Cargo.toml | 2 + crates/rustc_codegen_spirv/Cargo.toml | 3 + crates/rustc_codegen_spirv/src/lib.rs | 74 ++++++++ deny.toml | 2 + 6 files changed, 271 insertions(+), 52 deletions(-) diff --git a/.github/workflows/lint.sh b/.github/workflows/lint.sh index 31941a5084..66f2d362d5 100755 --- a/.github/workflows/lint.sh +++ b/.github/workflows/lint.sh @@ -49,10 +49,16 @@ clippy_no_features examples/shaders/simplest-shader # which could be disastrous because env vars access can't be tracked by # `rustc`, unlike its CLI flags (which are integrated with incremental). if ( - egrep -r '::\s*env|env\s*::' crates/rustc_codegen_spirv/src/ | + egrep -r '::\s*env|env\s*::' crates/rustc_codegen_spirv/src | # HACK(eddyb) exclude the one place in `rustc_codegen_spirv` # needing access to an env var (only for codegen args `--help`). - egrep -v '^crates/rustc_codegen_spirv/src/codegen_cx/mod.rs: let help_flag_comes_from_spirv_builder_env_var = std::env::var\(spirv_builder_env_var\)$' + egrep -v '^crates/rustc_codegen_spirv/src/codegen_cx/mod.rs: let help_flag_comes_from_spirv_builder_env_var = std::env::var\(spirv_builder_env_var\)$' | + # HACK(LegNeato) exclude logging. This mirrors `rustc` (`RUSTC_LOG`) and + #`rustdoc` (`RUSTDOC_LOG`). + # There is not a risk of this being disastrous as it does not change the build settings. + egrep -v '^crates/rustc_codegen_spirv/src/lib.rs:.*(RUSTGPU_LOG|RUSTGPU_LOG_FORMAT|RUSTGPU_LOG_COLOR).*$' | + egrep -v '^crates/rustc_codegen_spirv/src/lib.rs: use std::env::{self, VarError};$' + ); then echo '^^^' echo '!!! Found disallowed `std::env` usage in `rustc_codegen_spirv` !!!' diff --git a/Cargo.lock b/Cargo.lock index 7d2bd39a42..da6f67b17b 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -156,9 +156,9 @@ dependencies = [ [[package]] name = "anyhow" -version = "1.0.94" +version = "1.0.95" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c1fd03a028ef38ba2276dce7e33fcd6369c158a1bca17946c4b1b701891c1ff7" +checksum = "34ac096ce696dc2fcabef30516bb13c0a68a11d30131d3df6f04711467681b04" [[package]] name = "ar" @@ -284,18 +284,18 @@ checksum = "79296716171880943b8470b5f8d03aa55eb2e645a4874bdbb28adb49162e012c" [[package]] name = "bytemuck" -version = "1.20.0" +version = "1.21.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "8b37c88a63ffd85d15b406896cc343916d7cf57838a847b3a6f2ca5d39a5695a" +checksum = "ef657dfab802224e671f5818e9a4935f9b1957ed18e58292690cc39e7a4092a3" dependencies = [ "bytemuck_derive", ] [[package]] name = "bytemuck_derive" -version = "1.8.0" +version = "1.8.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "bcfcc3cd946cb52f0bbfdbbcfa2f4e24f75ebb6c0e1002f7c25904fada18b9ec" +checksum = "3fa76293b4f7bb636ab88fd78228235b5248b4d05cc589aed610f954af5d7c7a" dependencies = [ "proc-macro2", "quote", @@ -336,9 +336,9 @@ dependencies = [ [[package]] name = "cc" -version = "1.2.4" +version = "1.2.6" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "9157bbaa6b165880c27a4293a474c91cdcf265cc68cc829bf10be0964a391caf" +checksum = "8d6dbb628b8f8555f86d0323c2eb39e3ec81901f4b83e091db8a6a76d316a333" dependencies = [ "jobserver", "libc", @@ -598,18 +598,18 @@ dependencies = [ [[package]] name = "crossbeam-channel" -version = "0.5.13" +version = "0.5.14" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "33480d6946193aa8033910124896ca395333cae7e2d1113d1fef6c3272217df2" +checksum = "06ba6d68e24814cb8de6bb986db8222d3a027d15872cabc0d18817bc3c0e4471" dependencies = [ "crossbeam-utils", ] [[package]] name = "crossbeam-deque" -version = "0.8.5" +version = "0.8.6" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "613f8cc01fe9cf1a3eb3d7f488fd2fa8388403e97039e2f73692932e291a770d" +checksum = "9dd111b7b7f7d55b72c0a6ae361660ee5853c9af73f70c3c2ef6858b950e2e51" dependencies = [ "crossbeam-epoch", "crossbeam-utils", @@ -745,9 +745,9 @@ dependencies = [ [[package]] name = "env_filter" -version = "0.1.2" +version = "0.1.3" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "4f2c92ceda6ceec50f43169f9ee8424fe2db276791afde7b2cd8bc084cb376ab" +checksum = "186e05a59d4c50738528153b83b0b0194d3a29507dfec16eccd4b342903397d0" dependencies = [ "log", "regex", @@ -755,9 +755,9 @@ dependencies = [ [[package]] name = "env_logger" -version = "0.11.5" +version = "0.11.6" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "e13fa619b91fb2381732789fc5de83b45675e882f66623b7d8cb4f643017018d" +checksum = "dcaee3d8e3cfc3fd92428d477bc97fc29ec8716d180c0d74c643bb26166660e0" dependencies = [ "anstream", "anstyle", @@ -877,9 +877,9 @@ dependencies = [ [[package]] name = "foldhash" -version = "0.1.3" +version = "0.1.4" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "f81ec6369c545a7d40e4589b5597581fa1c441fe1cce96dd1de43159910a36a2" +checksum = "a0d2fde1f7b3d48b8395d5f2de76c18a528bd6a9cdde438df747bfcba3e05d6f" [[package]] name = "foreign-types" @@ -1122,13 +1122,13 @@ dependencies = [ [[package]] name = "gpu-descriptor" -version = "0.3.0" +version = "0.3.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "9c08c1f623a8d0b722b8b99f821eb0ba672a1618f0d3b16ddbee1cedd2dd8557" +checksum = "dcf29e94d6d243368b7a56caa16bc213e4f9f8ed38c4d9557069527b5d5281ca" dependencies = [ "bitflags 2.6.0", "gpu-descriptor-types", - "hashbrown 0.14.5", + "hashbrown 0.15.2", ] [[package]] @@ -1344,9 +1344,9 @@ checksum = "bbd2bcb4c963f2ddae06a2efc7e9f3591312473c50c6685e1f298068316e66fe" [[package]] name = "libc" -version = "0.2.168" +version = "0.2.169" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "5aaeb2981e0606ca11d79718f8bb01164f1d6ed75080182d3abf017e6d244b6d" +checksum = "b5aba8db14291edd000dfcc4d620c7ebfb122c613afb886ca8803fa4e128a20a" [[package]] name = "libloading" @@ -1418,6 +1418,15 @@ dependencies = [ "libc", ] +[[package]] +name = "matchers" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8263075bb86c5a1b1427b5ae862e8889656f126e9f77c484496e8b47cf5c5558" +dependencies = [ + "regex-automata 0.1.10", +] + [[package]] name = "memchr" version = "2.7.4" @@ -1485,9 +1494,9 @@ dependencies = [ [[package]] name = "miniz_oxide" -version = "0.8.0" +version = "0.8.2" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "e2d80299ef12ff69b16a84bb182e3b9df68b5a91574d3d4fa6e41b65deec4df1" +checksum = "4ffbe83022cedc1d264172192511ae958937694cd57ce297164951b8b3568394" dependencies = [ "adler2", ] @@ -1630,6 +1639,25 @@ dependencies = [ "instant", ] +[[package]] +name = "nu-ansi-term" +version = "0.46.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "77a8165726e8236064dbb45459242600304b42a5ea24ee2948e18e023bf7ba84" +dependencies = [ + "overload", + "winapi", +] + +[[package]] +name = "nu-ansi-term" +version = "0.50.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d4a28e057d01f97e61255210fcff094d74ed0466038633e95017f5beb68e4399" +dependencies = [ + "windows-sys 0.52.0", +] + [[package]] name = "num-conv" version = "0.1.0" @@ -1891,9 +1919,9 @@ dependencies = [ [[package]] name = "object" -version = "0.36.5" +version = "0.36.7" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "aedf0a2d09c573ed1d8d85b30c119153926a2b36dce0ab28322c09a117a4683e" +checksum = "62948e14d923ea95ea2c7c86c71013138b66525b86bdc08d2dcc262bdb497b87" dependencies = [ "crc32fast", "flate2", @@ -1922,6 +1950,12 @@ dependencies = [ "sdl2-sys", ] +[[package]] +name = "overload" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b15813163c1d831bf4a13c3610c05c0d03b39feb07f7e09fa234dac9b15aaf39" + [[package]] name = "owned_ttf_parser" version = "0.25.0" @@ -2117,9 +2151,9 @@ dependencies = [ [[package]] name = "quote" -version = "1.0.37" +version = "1.0.38" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b5b9d34b8991d19d98081b46eacdd8eb58c6f2b201139f7c5f643cc155a633af" +checksum = "0e4dccaaaf89514f546c693ddc140f729f958c247918a13380cccc6078391acc" dependencies = [ "proc-macro2", ] @@ -2233,8 +2267,17 @@ checksum = "b544ef1b4eac5dc2db33ea63606ae9ffcfac26c1416a2806ae0bf5f56b201191" dependencies = [ "aho-corasick", "memchr", - "regex-automata", - "regex-syntax", + "regex-automata 0.4.9", + "regex-syntax 0.8.5", +] + +[[package]] +name = "regex-automata" +version = "0.1.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6c230d73fb8d8c1b9c0b3135c5142a8acee3a0558fb8db5cf1cb65f8d7862132" +dependencies = [ + "regex-syntax 0.6.29", ] [[package]] @@ -2245,9 +2288,15 @@ checksum = "809e8dc61f6de73b46c85f4c96486310fe304c434cfa43669d7b40f711150908" dependencies = [ "aho-corasick", "memchr", - "regex-syntax", + "regex-syntax 0.8.5", ] +[[package]] +name = "regex-syntax" +version = "0.6.29" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f162c6dd7b008981e4d40210aca20b4bd0f9b60ca9271061b07f78537722f2e1" + [[package]] name = "regex-syntax" version = "0.8.5" @@ -2308,6 +2357,9 @@ dependencies = [ "spirt", "spirv-tools", "thorin-dwp", + "tracing", + "tracing-subscriber", + "tracing-tree", ] [[package]] @@ -2357,9 +2409,9 @@ dependencies = [ [[package]] name = "rustversion" -version = "1.0.18" +version = "1.0.19" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "0e819f2bc632f285be6d7cd36e25940d45b2391dd6d9b939e79de557f7014248" +checksum = "f7c45b9784283f1b2e7fb61b42047c2fd678ef0960d4f6f1eba131594cc369d4" [[package]] name = "ruzstd" @@ -2445,24 +2497,24 @@ dependencies = [ [[package]] name = "semver" -version = "1.0.23" +version = "1.0.24" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "61697e0a1c7e512e84a621326239844a24d8207b4669b41bc18b32ea5cbf988b" +checksum = "3cb6eb87a131f756572d7fb904f6e7b68633f09cca868c5df1c4b8d1a694bbba" [[package]] name = "serde" -version = "1.0.216" +version = "1.0.217" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "0b9781016e935a97e8beecf0c933758c97a5520d32930e460142b4cd80c6338e" +checksum = "02fc4265df13d6fa1d00ecff087228cc0a2b5f3c0e87e258d8b94a156e984c70" dependencies = [ "serde_derive", ] [[package]] name = "serde_derive" -version = "1.0.216" +version = "1.0.217" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "46f859dbbf73865c6627ed570e78961cd3ac92407a2d117204c49232485da55e" +checksum = "5a9bf7cf98d04a2b28aead066b7496853d4779c9cc183c440dbac457641e19a0" dependencies = [ "proc-macro2", "quote", @@ -2471,9 +2523,9 @@ dependencies = [ [[package]] name = "serde_json" -version = "1.0.133" +version = "1.0.134" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c7fceb2473b9166b2294ef05efcb65a3db80803f0b03ef86a5fc88a2b85ee377" +checksum = "d00f4175c42ee48b15416f6193a959ba3a0d67fc699a0db9ad12df9f83991c7d" dependencies = [ "itoa", "memchr", @@ -2481,6 +2533,15 @@ dependencies = [ "serde", ] +[[package]] +name = "sharded-slab" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6" +dependencies = [ + "lazy_static", +] + [[package]] name = "shared" version = "0.0.0" @@ -2709,9 +2770,9 @@ dependencies = [ [[package]] name = "syn" -version = "2.0.90" +version = "2.0.94" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "919d3b74a5dd0ccd15aeb8f93e7006bd9e14c295087c9896a110f490752bcf31" +checksum = "987bc0be1cdea8b10216bd06e2ca407d40b9543468fafd3ddfb02f36e77f71f3" dependencies = [ "proc-macro2", "quote", @@ -2796,6 +2857,16 @@ dependencies = [ "tracing", ] +[[package]] +name = "thread_local" +version = "1.1.8" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8b9ef9bad013ada3808854ceac7b46812a6465ba368859a37e2100283d2d719c" +dependencies = [ + "cfg-if", + "once_cell", +] + [[package]] name = "time" version = "0.3.37" @@ -2898,6 +2969,61 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "e672c95779cf947c5311f83787af4fa8fffd12fb27e4993211a84bdfd9610f9c" dependencies = [ "once_cell", + "valuable", +] + +[[package]] +name = "tracing-log" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3" +dependencies = [ + "log", + "once_cell", + "tracing-core", +] + +[[package]] +name = "tracing-serde" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "704b1aeb7be0d0a84fc9828cae51dab5970fee5088f83d1dd7ee6f6246fc6ff1" +dependencies = [ + "serde", + "tracing-core", +] + +[[package]] +name = "tracing-subscriber" +version = "0.3.19" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e8189decb5ac0fa7bc8b96b7cb9b2701d60d48805aca84a238004d665fcc4008" +dependencies = [ + "matchers", + "nu-ansi-term 0.46.0", + "once_cell", + "regex", + "serde", + "serde_json", + "sharded-slab", + "smallvec", + "thread_local", + "tracing", + "tracing-core", + "tracing-log", + "tracing-serde", +] + +[[package]] +name = "tracing-tree" +version = "0.3.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b56c62d2c80033cb36fae448730a2f2ef99410fe3ecbffc916681a32f6807dbe" +dependencies = [ + "nu-ansi-term 0.50.1", + "tracing-core", + "tracing-log", + "tracing-subscriber", ] [[package]] @@ -2946,6 +3072,12 @@ version = "0.2.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "06abde3611657adf66d383f00b093d7faecc7fa57071cce2578660c9f1010821" +[[package]] +name = "valuable" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "830b7e5d4d90034032940e4ace0d9a9a057e7a45cd94e6c007832e39edb82f6d" + [[package]] name = "version-compare" version = "0.1.1" @@ -3043,9 +3175,9 @@ checksum = "943aab3fdaaa029a6e0271b35ea10b72b943135afe9bffca82384098ad0e06a6" [[package]] name = "wasmparser" -version = "0.218.0" +version = "0.222.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b09e46c7fceceaa72b2dd1a8a137ea7fd8f93dfaa69806010a709918e496c5dc" +checksum = "4adf50fde1b1a49c1add6a80d47aea500c88db70551805853aa8b88f3ea27ab5" dependencies = [ "bitflags 2.6.0", ] @@ -3661,9 +3793,9 @@ checksum = "589f6da84c646204747d1270a2a5661ea66ed1cced2631d546fdfb155959f9ec" [[package]] name = "winit" -version = "0.30.5" +version = "0.30.7" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "0be9e76a1f1077e04a411f0b989cbd3c93339e1771cb41e71ac4aee95bfd2c67" +checksum = "dba50bc8ef4b6f1a75c9274fb95aa9a8f63fbc66c56f391bd85cf68d51e7b1a3" dependencies = [ "ahash", "android-activity", @@ -3714,9 +3846,9 @@ dependencies = [ [[package]] name = "winnow" -version = "0.6.20" +version = "0.6.21" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "36c1fec1a2bb5866f07c25f68c26e565c4c200aebb96d7e55710c19d3e8ac49b" +checksum = "e6f5bb5257f2407a5425c6e749bfd9692192a73e70a6060516ac04f889087d68" dependencies = [ "memchr", ] diff --git a/Cargo.toml b/Cargo.toml index 4fe02da511..d733803889 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -46,6 +46,8 @@ spirv-std-macros = { path = "./crates/spirv-std/macros", version = "=0.9.0" } spirv-tools = { version = "0.10", default-features = false } rustc_codegen_spirv = { path = "./crates/rustc_codegen_spirv", version = "=0.9.0", default-features = false } rustc_codegen_spirv-types = { path = "./crates/rustc_codegen_spirv-types", version = "=0.9.0" } +tracing = "0.1" +tracing-subscriber = { version = "0.3.3", features = ["env-filter", "json"] } # External dependencies that need to be mentioned more than once. num-traits = { version = "0.2.15", default-features = false } diff --git a/crates/rustc_codegen_spirv/Cargo.toml b/crates/rustc_codegen_spirv/Cargo.toml index 0fdca9a155..a76d9fb9d1 100644 --- a/crates/rustc_codegen_spirv/Cargo.toml +++ b/crates/rustc_codegen_spirv/Cargo.toml @@ -57,6 +57,9 @@ spirt = "0.4.0" spirv-tools.workspace = true lazy_static = "1.4.0" itertools = "0.10.5" +tracing.workspace = true +tracing-subscriber.workspace = true +tracing-tree = "0.3.0" [dev-dependencies] pipe = "0.4" diff --git a/crates/rustc_codegen_spirv/src/lib.rs b/crates/rustc_codegen_spirv/src/lib.rs index f5ab65665d..9f20513fa4 100644 --- a/crates/rustc_codegen_spirv/src/lib.rs +++ b/crates/rustc_codegen_spirv/src/lib.rs @@ -247,6 +247,11 @@ impl ThinBufferMethods for SpirvThinBuffer { struct SpirvCodegenBackend; impl CodegenBackend for SpirvCodegenBackend { + fn init(&self, sess: &Session) { + // Set up logging/tracing. See https://github.com/Rust-GPU/rust-gpu/issues/192. + init_logging(sess); + } + fn locale_resource(&self) -> &'static str { rustc_errors::DEFAULT_LOCALE_RESOURCE } @@ -551,3 +556,72 @@ pub fn __rustc_codegen_backend() -> Box { Box::new(SpirvCodegenBackend) } + +// Set up logging/tracing. See https://github.com/Rust-GPU/rust-gpu/issues/192. +fn init_logging(sess: &Session) { + use std::env::{self, VarError}; + use std::io::{self, IsTerminal}; + use tracing_subscriber::layer::SubscriberExt; + + // Set up the default subscriber with optional filtering. + let filter = tracing_subscriber::EnvFilter::from_env("RUSTGPU_LOG"); + #[cfg(not(rustc_codegen_spirv_disable_pqp_cg_ssa))] + let filter = filter.add_directive("rustc_codegen_spirv::maybe_pqp_cg_ssa=off".parse().unwrap()); + let subscriber = tracing_subscriber::Registry::default().with(filter); + + #[derive(Debug, Default)] + enum OutputFormat { + #[default] + Tree, + Flat, + Json, + } + + let output_format = match env::var("RUSTGPU_LOG_FORMAT").as_deref() { + Ok("tree") | Err(VarError::NotPresent) => OutputFormat::Tree, + Ok("flat") => OutputFormat::Flat, + Ok("json") => OutputFormat::Json, + Ok(value) => sess.dcx().fatal(format!( + "invalid output format value '{value}': expected one of tree, flat, or json", + )), + Err(VarError::NotUnicode(value)) => sess.dcx().fatal(format!( + "invalid output format value '{}': expected one of tree, flat, or json", + value.to_string_lossy() + )), + }; + + let subscriber: Box = match output_format { + OutputFormat::Tree => { + // TODO(@LegNeato): Query dcx color support when rustc exposes it. + let color_logs = match env::var("RUSTGPU_LOG_COLOR").as_deref() { + Ok("always") => true, + Ok("never") => false, + Ok("auto") | Err(VarError::NotPresent) => io::stderr().is_terminal(), + Ok(value) => sess.dcx().fatal(format!( + "invalid log color value '{value}': expected one of always, never, or auto", + )), + Err(VarError::NotUnicode(value)) => sess.dcx().fatal(format!( + "invalid log color value '{}': expected one of always, never, or auto", + value.to_string_lossy() + )), + }; + + let tree_layer = tracing_tree::HierarchicalLayer::default() + .with_writer(io::stderr) + .with_ansi(color_logs) + .with_targets(true) + .with_wraparound(10) + .with_verbose_exit(true) + .with_verbose_entry(true) + .with_indent_amount(2); + + #[cfg(debug_assertions)] + let tree_layer = tree_layer.with_thread_ids(true).with_thread_names(true); + + Box::new(subscriber.with(tree_layer)) + } + OutputFormat::Flat => Box::new(subscriber), + OutputFormat::Json => Box::new(subscriber.with(tracing_subscriber::fmt::layer().json())), + }; + tracing::subscriber::set_global_default(subscriber).unwrap(); +} diff --git a/deny.toml b/deny.toml index 0dac316c90..96c376090f 100644 --- a/deny.toml +++ b/deny.toml @@ -56,6 +56,8 @@ skip-tree = [ { name = "minifb", version = "=0.25.0", depth = 3 }, # HACK(eddyb) `num_cpus` (a `tester` dep) uses older `hermit-abi`. { name = "num_cpus", version = "=1.16.0", depth = 2 }, + # HACK(LegNeato) `tracing-tree` uses newer dependencies of `tracing`. + { name = "tracing-tree", version = "=0.3.1" }, ] From 0616f07eb112de82240a4e70a317a9a6aa0c3063 Mon Sep 17 00:00:00 2001 From: Christian Legnitto Date: Fri, 3 Jan 2025 15:33:25 -0400 Subject: [PATCH 2/2] Replace printing codegen args with `tracing`. This removes the following options and replaces them with `tracing`: * `--specializer-debug` => RUSTGPU_LOG=rustc_codegen_spirv::specializer=debug * `--print-zombie` => RUSTGPU_LOG=print_zombie=debug * `--print-all-zombie` => RUSTGPU_LOG=print_all_zombie=debug --- .../rustc_codegen_spirv/src/codegen_cx/mod.rs | 14 -- crates/rustc_codegen_spirv/src/linker/mod.rs | 5 +- .../src/linker/specializer.rs | 147 ++++++++---------- .../rustc_codegen_spirv/src/linker/zombies.rs | 30 ++-- docs/src/SUMMARY.md | 4 +- docs/src/codegen-args.md | 19 --- docs/src/tracing.md | 23 +++ 7 files changed, 105 insertions(+), 137 deletions(-) create mode 100644 docs/src/tracing.md diff --git a/crates/rustc_codegen_spirv/src/codegen_cx/mod.rs b/crates/rustc_codegen_spirv/src/codegen_cx/mod.rs index f806a5e3a3..bd5f4935b3 100644 --- a/crates/rustc_codegen_spirv/src/codegen_cx/mod.rs +++ b/crates/rustc_codegen_spirv/src/codegen_cx/mod.rs @@ -469,23 +469,12 @@ impl CodegenArgs { "spirt-keep-unstructured-cfg-in-dumps", "include initial unstructured CFG when dumping SPIR-T", ); - opts.optflag( - "", - "specializer-debug", - "enable debug logging for the specializer", - ); opts.optopt( "", "specializer-dump-instances", "dump all instances inferred by the specializer, to FILE", "FILE", ); - opts.optflag("", "print-all-zombie", "prints all removed zombies"); - opts.optflag( - "", - "print-zombie", - "prints everything removed (even transitively) due to zombies", - ); } // NOTE(eddyb) these are debugging options that used to be env vars @@ -639,10 +628,7 @@ impl CodegenArgs { .opt_present("spirt-keep-debug-sources-in-dumps"), spirt_keep_unstructured_cfg_in_dumps: matches .opt_present("spirt-keep-unstructured-cfg-in-dumps"), - specializer_debug: matches.opt_present("specializer-debug"), specializer_dump_instances: matches_opt_path("specializer-dump-instances"), - print_all_zombie: matches.opt_present("print-all-zombie"), - print_zombie: matches.opt_present("print-zombie"), }; Ok(Self { diff --git a/crates/rustc_codegen_spirv/src/linker/mod.rs b/crates/rustc_codegen_spirv/src/linker/mod.rs index 036c1d920b..ff22e37928 100644 --- a/crates/rustc_codegen_spirv/src/linker/mod.rs +++ b/crates/rustc_codegen_spirv/src/linker/mod.rs @@ -63,10 +63,7 @@ pub struct Options { pub spirt_strip_custom_debuginfo_from_dumps: bool, pub spirt_keep_debug_sources_in_dumps: bool, pub spirt_keep_unstructured_cfg_in_dumps: bool, - pub specializer_debug: bool, pub specializer_dump_instances: Option, - pub print_all_zombie: bool, - pub print_zombie: bool, } pub enum LinkResult { @@ -316,7 +313,7 @@ pub fn link( } let _timer = sess.timer("link_report_and_remove_zombies"); - zombies::report_and_remove_zombies(sess, opts, &mut output)?; + zombies::report_and_remove_zombies(sess, &mut output)?; } if opts.infer_storage_classes { diff --git a/crates/rustc_codegen_spirv/src/linker/specializer.rs b/crates/rustc_codegen_spirv/src/linker/specializer.rs index 84114325d5..01c4c9f9b1 100644 --- a/crates/rustc_codegen_spirv/src/linker/specializer.rs +++ b/crates/rustc_codegen_spirv/src/linker/specializer.rs @@ -60,6 +60,7 @@ use smallvec::SmallVec; use std::collections::{BTreeMap, VecDeque}; use std::ops::{Range, RangeTo}; use std::{fmt, io, iter, mem, slice}; +use tracing::{debug, error}; // FIXME(eddyb) move this elsewhere. struct FmtBy) -> fmt::Result>(F); @@ -110,12 +111,10 @@ pub fn specialize( module: Module, specialization: impl Specialization, ) -> Module { - // FIXME(eddyb) use `log`/`tracing` instead. - let debug = opts.specializer_debug; let dump_instances = &opts.specializer_dump_instances; let mut debug_names = FxHashMap::default(); - if debug || dump_instances.is_some() { + if dump_instances.is_some() { debug_names = module .debug_names .iter() @@ -131,10 +130,7 @@ pub fn specialize( let mut specializer = Specializer { specialization, - - debug, debug_names, - generics: IndexMap::new(), int_consts: FxHashMap::default(), }; @@ -188,27 +184,21 @@ pub fn specialize( // For non-"generic" functions, we can apply `replacements` right away, // though not before finishing inference for all functions first // (because `expander` needs to borrow `specializer` immutably). - if debug { - eprintln!("non-generic replacements:"); - } + debug!("non-generic replacements:"); for (func_idx, replacements) in non_generic_replacements { let mut func = mem::replace( &mut expander.builder.module_mut().functions[func_idx], Function::new(), ); - if debug { - let empty = replacements.with_instance.is_empty() - && replacements.with_concrete_or_param.is_empty(); - if !empty { - eprintln!(" in %{}:", func.def_id().unwrap()); - } + let empty = + replacements.with_instance.is_empty() && replacements.with_concrete_or_param.is_empty(); + if !empty { + debug!(" in %{}:", func.def_id().unwrap()); } for (loc, operand) in replacements.to_concrete(&[], |instance| expander.alloc_instance_id(instance)) { - if debug { - eprintln!(" {operand} -> {loc:?}"); - } + debug!(" {operand} -> {loc:?}"); func.index_set(loc, operand.into()); } expander.builder.module_mut().functions[func_idx] = func; @@ -537,9 +527,6 @@ struct Generic { struct Specializer { specialization: S, - // FIXME(eddyb) use `log`/`tracing` instead. - debug: bool, - // HACK(eddyb) if debugging is requested, this is used to quickly get `OpName`s. debug_names: FxHashMap, @@ -1512,24 +1499,24 @@ impl InferError { // FIXME(eddyb) better error reporting than this. match self { Self::Conflict(a, b) => { - eprintln!("inference conflict: {a:?} vs {b:?}"); + error!("inference conflict: {a:?} vs {b:?}"); } } - eprint!(" in "); + error!(" in "); // FIXME(eddyb) deduplicate this with other instruction printing logic. if let Some(result_id) = inst.result_id { - eprint!("%{result_id} = "); + error!("%{result_id} = "); } - eprint!("Op{:?}", inst.class.opcode); + error!("Op{:?}", inst.class.opcode); for operand in inst .result_type .map(Operand::IdRef) .iter() .chain(inst.operands.iter()) { - eprint!(" {operand}"); + error!(" {operand}"); } - eprintln!(); + error!(""); std::process::exit(1); } @@ -1937,38 +1924,36 @@ impl<'a, S: Specialization> InferCx<'a, S> { }; let debug_dump_if_enabled = |cx: &Self, prefix| { - if cx.specializer.debug { - let result_type = match inst.class.opcode { - // HACK(eddyb) workaround for `OpFunction`, see earlier HACK comment. - Op::Function => Some( - InferOperand::from_operand_and_generic_args( - &Operand::IdRef(inst.result_type.unwrap()), - inputs_generic_args.clone(), - cx, - ) - .0, - ), - _ => type_of_result.clone(), - }; - let inputs = InferOperandList { - operands: &inst.operands, - all_generic_args: inputs_generic_args.clone(), - transform: None, - }; + let result_type = match inst.class.opcode { + // HACK(eddyb) workaround for `OpFunction`, see earlier HACK comment. + Op::Function => Some( + InferOperand::from_operand_and_generic_args( + &Operand::IdRef(inst.result_type.unwrap()), + inputs_generic_args.clone(), + cx, + ) + .0, + ), + _ => type_of_result.clone(), + }; + let inputs = InferOperandList { + operands: &inst.operands, + all_generic_args: inputs_generic_args.clone(), + transform: None, + }; - if inst_loc != InstructionLocation::Module { - eprint!(" "); - } - eprint!("{prefix}"); - if let Some(result_id) = inst.result_id { - eprint!("%{result_id} = "); - } - eprint!("Op{:?}", inst.class.opcode); - for operand in result_type.into_iter().chain(inputs.iter(cx)) { - eprint!(" {}", operand.display_with_infer_cx(cx)); - } - eprintln!(); + if inst_loc != InstructionLocation::Module { + debug!(" "); + } + debug!("{prefix}"); + if let Some(result_id) = inst.result_id { + debug!("%{result_id} = "); + } + debug!("Op{:?}", inst.class.opcode); + for operand in result_type.into_iter().chain(inputs.iter(cx)) { + debug!(" {}", operand.display_with_infer_cx(cx)); } + debug!(""); }; // If we have some instruction signatures for `inst`, enforce them. @@ -1998,12 +1983,10 @@ impl<'a, S: Specialization> InferCx<'a, S> { ), }; - if self.specializer.debug { - if inst_loc != InstructionLocation::Module { - eprint!(" "); - } - eprintln!(" found {:?}", m.debug_with_infer_cx(self)); + if inst_loc != InstructionLocation::Module { + debug!(" "); } + debug!(" found {:?}", m.debug_with_infer_cx(self)); if let Err(e) = self.equate_match_findings(m) { e.report(inst); @@ -2032,14 +2015,12 @@ impl<'a, S: Specialization> InferCx<'a, S> { fn instantiate_function(&mut self, func: &'a Function) { let func_id = func.def_id().unwrap(); - if self.specializer.debug { - eprintln!(); - eprint!("specializer::instantiate_function(%{func_id}"); - if let Some(name) = self.specializer.debug_names.get(&func_id) { - eprint!(" {name}"); - } - eprintln!("):"); + debug!(""); + debug!("specializer::instantiate_function(%{func_id}"); + if let Some(name) = self.specializer.debug_names.get(&func_id) { + debug!(" {name}"); } + debug!("):"); // Instantiate the defining `OpFunction` first, so that the first // inference variables match the parameters from the `Generic` @@ -2047,9 +2028,7 @@ impl<'a, S: Specialization> InferCx<'a, S> { assert!(self.infer_var_values.is_empty()); self.instantiate_instruction(func.def.as_ref().unwrap(), InstructionLocation::Module); - if self.specializer.debug { - eprintln!("infer body {{"); - } + debug!("infer body {{"); // If the `OpTypeFunction` is indeed "generic", we have to extract the // return / parameter types for `OpReturnValue` and `OpFunctionParameter`. @@ -2074,14 +2053,12 @@ impl<'a, S: Specialization> InferCx<'a, S> { let (i, param) = params.next().unwrap(); assert_eq!(param.class.opcode, Op::FunctionParameter); - if self.specializer.debug { - eprintln!( - " %{} = Op{:?} {}", - param.result_id.unwrap(), - param.class.opcode, - param_ty.display_with_infer_cx(self) - ); - } + debug!( + " %{} = Op{:?} {}", + param.result_id.unwrap(), + param.class.opcode, + param_ty.display_with_infer_cx(self) + ); self.record_instantiated_operand( OperandLocation { @@ -2133,13 +2110,11 @@ impl<'a, S: Specialization> InferCx<'a, S> { } } - if self.specializer.debug { - eprint!("}}"); - if let Some(func_ty) = self.type_of_result.get(&func_id) { - eprint!(" -> %{}: {}", func_id, func_ty.display_with_infer_cx(self)); - } - eprintln!(); + debug!("}}"); + if let Some(func_ty) = self.type_of_result.get(&func_id) { + debug!(" -> %{}: {}", func_id, func_ty.display_with_infer_cx(self)); } + debug!(""); } /// Helper for `into_replacements`, that computes a single `ConcreteOrParam`. diff --git a/crates/rustc_codegen_spirv/src/linker/zombies.rs b/crates/rustc_codegen_spirv/src/linker/zombies.rs index 9b9423a4b9..207548c38f 100644 --- a/crates/rustc_codegen_spirv/src/linker/zombies.rs +++ b/crates/rustc_codegen_spirv/src/linker/zombies.rs @@ -10,6 +10,7 @@ use rustc_errors::Diag; use rustc_session::Session; use rustc_span::{DUMMY_SP, Span}; use smallvec::SmallVec; +use tracing::{Level, debug}; #[derive(Copy, Clone)] struct Zombie<'a> { @@ -321,11 +322,7 @@ impl<'a> ZombieReporter<'a> { } } -pub fn report_and_remove_zombies( - sess: &Session, - opts: &super::Options, - module: &mut Module, -) -> super::Result<()> { +pub fn report_and_remove_zombies(sess: &Session, module: &mut Module) -> super::Result<()> { let mut zombies = Zombies { // FIXME(eddyb) avoid repeating this across different passes/helpers. custom_ext_inst_set_import: module @@ -345,9 +342,7 @@ pub fn report_and_remove_zombies( while zombies.spread(module) {} let result = ZombieReporter::new(sess, module, &zombies).report_all(); - - // FIXME(eddyb) use `log`/`tracing` instead. - if opts.print_all_zombie { + if tracing::enabled!(target: "print_all_zombie", Level::DEBUG) { let mut span_regen = SpanRegenerator::new(sess.source_map(), module); for &zombie_id in zombies.id_to_zombie_kind.keys() { let mut zombie_leaf_id = zombie_id; @@ -362,15 +357,21 @@ pub fn report_and_remove_zombies( } let reason = span_regen.zombie_for_id(zombie_leaf_id).unwrap().reason; - eprint!("zombie'd %{zombie_id} because {reason}"); + debug!( + target: "print_all_zombie", + "zombie'd %{zombie_id} because {reason}" + ); if !infection_chain.is_empty() { - eprint!(" (infected via {:?})", infection_chain); + debug!( + target: "print_all_zombie", + " (infected via {:?})", infection_chain + ); } - eprintln!(); + debug!(target: "print_all_zombie", ""); } } - if opts.print_zombie { + if tracing::enabled!(target: "print_zombie", Level::DEBUG) { let mut span_regen = SpanRegenerator::new(sess.source_map(), module); let names = get_names(module); for f in &module.functions { @@ -386,7 +387,10 @@ pub fn report_and_remove_zombies( let name = get_name(&names, f.def_id().unwrap()); let reason = span_regen.zombie_for_id(zombie_leaf_id).unwrap().reason; - eprintln!("function removed {name:?} because {reason:?}"); + debug!( + target: "print_zombie", + "function removed {name:?} because {reason:?}" + ); } } } diff --git a/docs/src/SUMMARY.md b/docs/src/SUMMARY.md index 8bd8c2dcb6..7ae6a80bc8 100644 --- a/docs/src/SUMMARY.md +++ b/docs/src/SUMMARY.md @@ -4,8 +4,10 @@ - [Contributing to Rust-GPU]() - [Building](./building-rust-gpu.md) - [Testing](./testing.md) + - [Debugging](./tracing) + - [Tracing](./tracing.md) + - [Minimizing bugs in SPIR-V](./spirv-minimization.md) - ["Codegen args" (flags/options) supported by the Rust-GPU codegen backend](./codegen-args.md) - - [Minimizing bugs in SPIR-V](./spirv-minimization.md) - [Publishing Rust-GPU on crates.io](./publishing-rust-gpu.md) - [Platform Support](./platform-support.md) - [Writing Shader Crates](./writing-shader-crates.md) diff --git a/docs/src/codegen-args.md b/docs/src/codegen-args.md index 18794a7dfe..df3bc061bc 100644 --- a/docs/src/codegen-args.md +++ b/docs/src/codegen-args.md @@ -93,29 +93,10 @@ splitting option, hence it takes a directory instead of a file path. This is the binary before `spirv-opt` is executed, so it may be useful to output this to check if an issue is in Rust-GPU, or in `spirv-opt`. -### `--specializer-debug` - -Enables debug logging for the specializer. - -_**FIXME(@eddyb)** use `log`/`tracing` instead for this purpose_ - ### `--specializer-dump-instances FILE` Dumps to `FILE` all instances inferred by the specializer. -### `--print-zombie` - -Prints to rustc stdout which functions were removed due to being zombies, and why. - -_**FIXME(@eddyb)** use `log`/`tracing` instead for this purpose_ - -### `--print-all-zombie` - -Prints to rustc stdout *everything* that was removed due to being zombies, why, and if it was an -original zombie or if it was infected. (prints a lot!) - -_**FIXME(@eddyb)** use `log`/`tracing` instead for this purpose_ - ### `--no-spirv-val` Disables running `spirv-val` on the final output. Spooky scary option, can cause invalid modules! diff --git a/docs/src/tracing.md b/docs/src/tracing.md new file mode 100644 index 0000000000..fab61effce --- /dev/null +++ b/docs/src/tracing.md @@ -0,0 +1,23 @@ +# Tracing + +`rust-gpu` has a lot of [debug!](https://docs.rs/tracing/0.1/tracing/macro.debug.html) +(or trace!) calls, which print out logging information at many points. These are very +useful to at least narrow down the location of a bug if not to find it entirely, or just +to orient yourself as to why the compiler backend is doing a particular thing. + +To see the logs, you need to set the `RUSTGPU_LOG` environment variable to your log filter (note the "GPU" in the name). The full syntax of the log filters can be found in the [rustdoc of tracing-subscriber](https://docs.rs/tracing-subscriber/0.2.24/tracing_subscriber/filter/struct.EnvFilter.html#directives). + +Use `RUSTGPU_LOG_FORMAT` to control log output format (`"tree"`, `"flat"`, or `"json"`) and `RUSTGPU_LOG_COLOR` to manage color output (`"always"`, `"never"`, or `"auto"`). + +To trace non-`rust-gpu` parts of the compiler, set the standard [`RUSTC_LOG`](https://rustc-dev-guide.rust-lang.org/tracing.html) environment variable. + +## Replacements for old codegen arguments + +Before `rust-gpu` supported tracing, there were special [codegen +arguments](./codegen-args.md) to aid observability. As of +[PR#196](https://github.com/Rust-GPU/rust-gpu/pull/196) the they +have been removed and replaced with the following: + +- `--specializer-debug` → `RUSTGPU_LOG=rustc_codegen_spirv::specializer=debug` +- `--print-zombie` → `RUSTGPU_LOG=print_zombie=debug` +- `--print-all-zombie` → `RUSTGPU_LOG=print_all_zombie=debug`