Replace uses of eprintln! with log (#1017)

DJMcNab · web-flow · commit 10129d5069df · 2025-05-21T10:31:47.000Z
Fixes #1010
diff --git a/Cargo.lock b/Cargo.lock
diff --git a/vello/src/debug/validate.rs b/vello/src/debug/validate.rs
@@ -58,7 +58,7 @@ pub(crate) fn validate_line_soup(lines: &[LineSoup]) -> Vec<LineEndpoint> {
         }
     }
     if !points.is_empty() {
-        eprintln!("Unpaired points are present: {:#?}", points);
+        log::warn!("Unpaired points are present: {:#?}", points);
     }
     points.into_iter().collect()
 }
diff --git a/vello/src/lib.rs b/vello/src/lib.rs
@@ -98,7 +98,6 @@
     clippy::cast_possible_truncation,
     clippy::missing_assert_message,
     clippy::shadow_unrelated,
-    clippy::print_stderr,
     reason = "Deferred"
 )]
 #![allow(
@@ -581,7 +580,7 @@ impl Renderer {
             static HAS_WARNED: AtomicBool = AtomicBool::new(false);
             if !HAS_WARNED.swap(true, std::sync::atomic::Ordering::Release) {
                 log::warn!(
-                    "Requested debug layers {debug:?} but `debug_layers` feature is not enabled.",
+                    "Requested debug layers {debug:?} but `debug_layers` feature is not enabled",
                     debug = debug_layers
                 );
             }
diff --git a/vello/src/scene.rs b/vello/src/scene.rs
@@ -805,7 +805,8 @@ impl ColorPainter for DrawColorGlyphs<'_> {
 
     fn push_clip_glyph(&mut self, glyph_id: GlyphId) {
         let Some(outline) = self.outlines.get(glyph_id) else {
-            eprintln!("Didn't get expected outline");
+            log::warn!("Color Glyph (emoji) rendering: Color Glyph references missing outline");
+            // TODO: In theory, we should record the name of the emoji font used, etc. here
             return;
         };
 
@@ -887,7 +888,7 @@ impl ColorPainter for DrawColorGlyphs<'_> {
         brush: skrifa::color::Brush<'_>,
     ) {
         let Some(outline) = self.outlines.get(glyph_id) else {
-            eprintln!("Didn't get expected outline");
+            log::warn!("Color Glyph (emoji) rendering: Color Glyph references missing outline");
             return;
         };
 
diff --git a/vello/src/wgpu_engine.rs b/vello/src/wgpu_engine.rs
@@ -179,7 +179,7 @@ impl WgpuEngine {
                     std::thread::available_parallelism().map_or(2, |it| it.get().max(4) - 2)
                 })
                 .min(new_shaders.len());
-            eprintln!("Initialising in parallel using {num_threads} threads");
+            log::info!("Initialising shader modules in parallel using {num_threads} threads");
             let remainder = new_shaders.split_off(num_threads);
             let (tx, rx) = std::sync::mpsc::channel::<(ShaderId, WgpuShader)>();
 
diff --git a/vello_shaders/Cargo.toml b/vello_shaders/Cargo.toml
@@ -17,7 +17,7 @@ targets = []
 
 [features]
 default = ["wgsl", "cpu"]
-compile = ["dep:naga", "dep:thiserror"]
+compile = ["dep:naga", "dep:thiserror", "dep:log"]
 
 # Target shading language variants of the vello shaders to link into the library.
 wgsl = []
@@ -34,7 +34,9 @@ bytemuck = { workspace = true, optional = true }
 naga = { version = "24.0.0", features = ["wgsl-in"], optional = true }
 thiserror = { workspace = true, optional = true }
 vello_encoding = { workspace = true, optional = true }
+log = { workspace = true, optional = true }
 
 [build-dependencies]
 naga = { version = "24.0.0", features = ["wgsl-in"] }
 thiserror = { workspace = true }
+log = { workspace = true }
diff --git a/vello_shaders/build.rs b/vello_shaders/build.rs
@@ -12,12 +12,14 @@ mod compile;
 mod types;
 
 use std::env;
-use std::fmt::Write;
+use std::fmt::{self, Write as _};
 use std::path::Path;
 
 use compile::ShaderInfo;
 
 fn main() {
+    log::set_logger(&BUILD_SCRIPT_LOGGER).unwrap();
+    log::set_max_level(log::LevelFilter::Info);
     let out_dir = env::var_os("OUT_DIR").unwrap();
     let dest_path = Path::new(&out_dir).join("shaders.rs");
 
@@ -26,10 +28,11 @@ fn main() {
     let mut shaders = match ShaderInfo::from_default() {
         Ok(s) => s,
         Err(err) => {
-            let formatted = err.to_string();
-            for line in formatted.lines() {
-                println!("cargo:warning={line}");
-            }
+            let mut target = String::new();
+            // Ideally, we'd write into stdout directly here, but the duck-typing of `write!`
+            // makes that a bit annoying - we'd have to implement `CargoWarningAdapter` for both `io::Write` and `fmt::Write`
+            writeln!(CargoWarningAdapter::new(&mut target), "{err}").unwrap();
+            print!("{target}");
             return;
         }
     };
@@ -43,7 +46,7 @@ fn main() {
     std::fs::write(dest_path, &buf).unwrap();
 }
 
-fn write_types(buf: &mut String, shaders: &[(String, ShaderInfo)]) -> Result<(), std::fmt::Error> {
+fn write_types(buf: &mut String, shaders: &[(String, ShaderInfo)]) -> Result<(), fmt::Error> {
     writeln!(buf, "pub struct Shaders<'a> {{")?;
     for (name, _) in shaders {
         writeln!(buf, "    pub {name}: ComputeShader<'a>,")?;
@@ -52,10 +55,7 @@ fn write_types(buf: &mut String, shaders: &[(String, ShaderInfo)]) -> Result<(),
     Ok(())
 }
 
-fn write_shaders(
-    buf: &mut String,
-    shaders: &[(String, ShaderInfo)],
-) -> Result<(), std::fmt::Error> {
+fn write_shaders(buf: &mut String, shaders: &[(String, ShaderInfo)]) -> Result<(), fmt::Error> {
     writeln!(buf, "mod generated {{")?;
     writeln!(buf, "    use super::*;")?;
     writeln!(buf, "    use BindType::*;")?;
@@ -110,12 +110,12 @@ fn write_shaders(
 }
 
 #[cfg(not(feature = "msl"))]
-fn write_msl(_: &mut String, _: &ShaderInfo) -> Result<(), std::fmt::Error> {
+fn write_msl(_: &mut String, _: &ShaderInfo) -> Result<(), fmt::Error> {
     Ok(())
 }
 
 #[cfg(feature = "msl")]
-fn write_msl(buf: &mut String, info: &ShaderInfo) -> Result<(), std::fmt::Error> {
+fn write_msl(buf: &mut String, info: &ShaderInfo) -> Result<(), fmt::Error> {
     let mut index_iter = compile::msl::BindingIndexIterator::default();
     let indices = info
         .bindings
@@ -136,3 +136,74 @@ fn write_msl(buf: &mut String, info: &ShaderInfo) -> Result<(), std::fmt::Error>
     writeln!(buf, "            }},")?;
     Ok(())
 }
+
+/// A very simple logger for build scripts, which ensures that warnings and above
+/// are visible to the user.
+///
+/// We don't use an external crate here to keep build times down.
+struct BuildScriptLog;
+
+static BUILD_SCRIPT_LOGGER: BuildScriptLog = BuildScriptLog;
+
+impl log::Log for BuildScriptLog {
+    fn enabled(&self, _: &log::Metadata<'_>) -> bool {
+        true
+    }
+
+    fn log(&self, record: &log::Record<'_>) {
+        // "more serious" levels are lower
+        if record.level() <= log::Level::Warn {
+            let mut target = String::new();
+            write!(
+                CargoWarningAdapter::new(&mut target),
+                "{}: {}",
+                record.level(),
+                record.args()
+            )
+            .unwrap();
+            println!("{target}");
+        } else {
+            // If the user wants more verbose output from the build script, they would pass
+            // `-vv` to `cargo build`. In that case, we should provide all of the logs that
+            // people chose to provide.
+            // TODO: Maybe this should fall back to `env_logger`?
+            eprintln!("{}: {}", record.level(), record.args());
+        }
+    }
+
+    fn flush(&self) {
+        // Nothing to do; we use `println` which is "self-flushing"
+    }
+}
+
+/// An adapter for `fmt::Write` which prepends `cargo:warning=` to each line, ensuring that every
+/// output line is shown to build script users.
+struct CargoWarningAdapter<W: fmt::Write> {
+    writer: W,
+    needs_warning: bool,
+}
+
+impl<W: fmt::Write> CargoWarningAdapter<W> {
+    fn new(writer: W) -> Self {
+        Self {
+            writer,
+            needs_warning: true,
+        }
+    }
+}
+
+impl<W: fmt::Write> fmt::Write for CargoWarningAdapter<W> {
+    fn write_str(&mut self, s: &str) -> fmt::Result {
+        for line in s.split_inclusive('\n') {
+            if self.needs_warning {
+                write!(&mut self.writer, "cargo:warning=")?;
+                self.needs_warning = false;
+            }
+            write!(&mut self.writer, "{line}")?;
+            if line.ends_with('\n') {
+                self.needs_warning = true;
+            }
+        }
+        Ok(())
+    }
+}
diff --git a/vello_shaders/src/compile/mod.rs b/vello_shaders/src/compile/mod.rs
@@ -213,7 +213,8 @@ impl ShaderInfo {
                         for permutation in permutations {
                             let mut defines = defines.clone();
                             defines.extend(permutation.defines.iter().cloned());
-                            let source = preprocess::preprocess(&contents, &defines, &imports);
+                            let source =
+                                preprocess::preprocess(&contents, shader_name, &defines, &imports);
                             match Self::new(&permutation.name, source, "main") {
                                 Ok(shader_info) => {
                                     info.insert(permutation.name.clone(), shader_info);
@@ -224,7 +225,8 @@ impl ShaderInfo {
                             }
                         }
                     } else {
-                        let source = preprocess::preprocess(&contents, &defines, &imports);
+                        let source =
+                            preprocess::preprocess(&contents, shader_name, &defines, &imports);
                         match Self::new(shader_name, source, "main") {
                             Ok(shader_info) => {
                                 info.insert(shader_name.to_string(), shader_info);
diff --git a/vello_shaders/src/compile/preprocess.rs b/vello_shaders/src/compile/preprocess.rs
@@ -36,6 +36,7 @@ pub struct StackItem {
 
 pub fn preprocess(
     input: &str,
+    shader_name: &str,
     defines: &HashSet<String>,
     imports: &HashMap<String, String>,
 ) -> String {
@@ -68,9 +69,9 @@ pub fn preprocess(
                 item @ ("ifdef" | "ifndef" | "else" | "endif" | "enable")
                     if !directive_is_at_start =>
                 {
-                    eprintln!(
+                    log::warn!(
                         "#{item} directives must be the first non_whitespace items on \
-                               their line, ignoring (line {line_number})"
+                               their line, ignoring (line {line_number} of {shader_name}.wgsl)"
                     );
                     break;
                 }
@@ -89,8 +90,8 @@ pub fn preprocess(
                     let item = stack.last_mut();
                     if let Some(item) = item {
                         if item.else_passed {
-                            eprintln!(
-                                "Second else for same ifdef/ifndef (line {line_number}); \
+                            log::warn!(
+                                "Second else for same ifdef/ifndef (line {line_number} of {shader_name}.wgsl); \
                                        ignoring second else"
                             );
                         } else {
@@ -100,23 +101,23 @@ pub fn preprocess(
                     }
                     let remainder = directive_start[directive_len..].trim();
                     if !remainder.is_empty() {
-                        eprintln!(
+                        log::warn!(
                             "#else directives don't take an argument. `{remainder}` will not \
-                                   be in output (line {line_number})"
+                                   be in output (line {line_number} of {shader_name}.wgsl)"
                         );
                     }
                     // Don't add this line to the output; it should be empty (see warning above)
                     continue 'all_lines;
                 }
                 "endif" => {
                     if stack.pop().is_none() {
-                        eprintln!("Mismatched endif (line {line_number})");
+                        log::warn!("Mismatched endif (line {line_number} of {shader_name}.wgsl)");
                     }
                     let remainder = directive_start[directive_len..].trim();
                     if !remainder.is_empty() && !remainder.starts_with("//") {
-                        eprintln!(
+                        log::warn!(
                             "#endif directives don't take an argument. `{remainder}` will \
-                                   not be in output (line {line_number})"
+                                   not be in output (line {line_number} of {shader_name}.wgsl)"
                         );
                     }
                     // Don't add this line to the output; it should be empty (see warning above)
@@ -130,7 +131,9 @@ pub fn preprocess(
                     {
                         import_name_start
                     } else {
-                        eprintln!("#import needs a non_whitespace argument (line {line_number})");
+                        log::warn!(
+                            "#import needs a non_whitespace argument (line {line_number} of {shader_name}.wgsl)"
+                        );
                         continue 'all_lines;
                     };
                     let import_name_start = &directive_end[import_name_start..];
@@ -146,10 +149,12 @@ pub fn preprocess(
                         // However, in practise there will only ever be at most 2 stack items, so
                         // it's reasonable to just recompute it every time
                         if stack.iter().all(|item| item.active) {
-                            output.push_str(&preprocess(import, defines, imports));
+                            output.push_str(&preprocess(import, shader_name, defines, imports));
                         }
                     } else {
-                        eprintln!("Unknown import `{import_name}` (line {line_number})");
+                        log::warn!(
+                            "Unknown import `{import_name}` (line {line_number} of {shader_name}.wgsl)"
+                        );
                     }
                     continue;
                 }
@@ -164,7 +169,9 @@ pub fn preprocess(
                     continue 'all_lines;
                 }
                 val => {
-                    eprintln!("Unknown preprocessor directive `{val}` (line {line_number})");
+                    log::warn!(
+                        "Unknown preprocessor directive `{val}` (line {line_number} of {shader_name}.wgsl)"
+                    );
                 }
             }
         }
diff --git a/vello_shaders/src/lib.rs b/vello_shaders/src/lib.rs
@@ -37,7 +37,6 @@
     unnameable_types,
     clippy::cast_possible_truncation,
     clippy::missing_assert_message,
-    clippy::print_stderr,
     clippy::print_stdout,
     clippy::shadow_unrelated,
     clippy::todo,

Original file line number	Diff line number	Diff line change
`@@ -58,7 +58,7 @@ pub(crate) fn validate_line_soup(lines: &[LineSoup]) -> Vec<LineEndpoint> {`
`58`	`58`	`}`
`59`	`59`	`}`
`60`	`60`	`if !points.is_empty() {`
`61`		`- eprintln!("Unpaired points are present: {:#?}", points);`
	`61`	`+ log::warn!("Unpaired points are present: {:#?}", points);`
`62`	`62`	`}`
`63`	`63`	`points.into_iter().collect()`
`64`	`64`	`}`