Merge branch 'liw/logging' into 'main'

feat: improve logging via env_logger

Closes #221

See merge request subplot/subplot!269

2 files changed, 53 insertions, 12 deletions

diff --git a/src/bin/subplot.rs b/src/bin/subplot.rs
index 6a41968..479aa79 100644
--- a/src/bin/subplot.rs
+++ b/src/bin/subplot.rs
@@ -3,7 +3,8 @@
 
 use anyhow::Result;
 
-use log::{debug, trace};
+use env_logger::fmt::Color;
+use log::{debug, error, info, trace, warn};
 use structopt::StructOpt;
 use subplot::{
     codegen, load_document, resource, DataFile, Document, MarkupOpts, Style, SubplotError,
@@ -345,7 +346,18 @@ impl Docgen {
             pandoc.set_input_format(pandoc::InputFormat::Json, vec![]);
             pandoc.set_input(pandoc::InputKind::Pipe(doc.ast()?));
             pandoc.set_output(pandoc::OutputKind::File(self.output.clone()));
-            pandoc.execute()?;
+
+            debug!("Executing pandoc to produce {}", self.output.display());
+            let r = pandoc.execute();
+            if let Err(pandoc::PandocError::Err(output)) = r {
+                let code = output.status.code().or(Some(127)).unwrap();
+                let stderr = String::from_utf8_lossy(&output.stderr);
+                error!("Failed to execute Pandoc: exit code {}", code);
+                error!("{}", stderr.strip_suffix('\n').unwrap());
+
+                return Err(anyhow::Error::msg("Pandoc failed"));
+            }
+            r?;
         }
 
         Ok(())
@@ -421,6 +433,7 @@ impl Codegen {
     }
 
     fn run(&self) -> Result<()> {
+        debug!("codegen starts");
         let output = codegen(&self.filename, &self.output, self.template.as_deref())?;
         if self.run {
             let spec = output
@@ -431,7 +444,7 @@ impl Codegen {
                 .spec();
             let run = match spec.run() {
                 None => {
-                    eprintln!(
+                    error!(
                         "Template {} does not specify how to run suites",
                         spec.template_filename().display()
                     );
@@ -442,10 +455,11 @@ impl Codegen {
 
             let status = Command::new(run).arg(&self.output).status()?;
             if !status.success() {
-                eprintln!("Test suite failed!");
+                error!("Test suite failed!");
                 std::process::exit(2);
             }
         }
+        debug!("codegen ends successfully");
         Ok(())
     }
 }
@@ -480,7 +494,7 @@ fn load_linted_doc(
     doc.check_embedded_files_are_used(&template)?;
 
     for w in doc.warnings() {
-        eprintln!("WARNING: {}", w);
+        warn!("{}", w);
     }
 
     if !doc.warnings().is_empty() && !merciful {
@@ -490,8 +504,15 @@ fn load_linted_doc(
     Ok(doc)
 }
 
+fn print_source_errors(e: Option<&dyn std::error::Error>) {
+    if let Some(e) = e {
+        error!("{}", e);
+        print_source_errors(e.source());
+    }
+}
+
 fn real_main() {
-    trace!("Starting Subplot");
+    info!("Starting Subplot");
     let argparser = Toplevel::clap();
     let version = long_version().unwrap();
     let argparser = argparser.long_version(version.as_str());
@@ -500,17 +521,32 @@ fn real_main() {
     args.handle_special_args();
     match args.run() {
         Ok(_) => {
-            trace!("Subplot finished successfully");
+            info!("Subplot finished successfully");
         }
         Err(e) => {
-            debug!("Failed: {:?}", e);
-            eprintln!("Failure: {:?}", e);
+            error!("{}", e);
+            print_source_errors(e.source());
             process::exit(1);
         }
     }
 }
 
 fn main() {
-    env_logger::init_from_env("SUBPLOT_LOG");
+    let env = env_logger::Env::new()
+        .filter_or("SUBPLOT_LOG", "info")
+        .write_style("SUBPLOT_LOG_STYLE");
+    env_logger::Builder::from_env(env)
+        .format_timestamp(None)
+        .format(|buf, record| {
+            let mut level_style = buf.style();
+            level_style.set_color(Color::Red).set_bold(true);
+            writeln!(
+                buf,
+                "{}: {}",
+                level_style.value(record.level()),
+                record.args()
+            )
+        })
+        .init();
     real_main();
 }
diff --git a/src/doc.rs b/src/doc.rs
index 89b9eea..9c5fae8 100644
--- a/src/doc.rs
+++ b/src/doc.rs
@@ -532,7 +532,13 @@ where
 
 /// Generate code for one document.
 pub fn codegen(filename: &Path, output: &Path, template: Option<&str>) -> Result<CodegenOutput> {
-    let mut doc = load_document_with_pullmark(filename, Style::default(), template)?;
+    let r = load_document_with_pullmark(filename, Style::default(), template);
+    let mut doc = match r {
+        Ok(doc) => doc,
+        Err(err) => {
+            return Err(err);
+        }
+    };
     doc.lint()?;
     let template = template
         .map(Ok)
@@ -547,7 +553,6 @@ pub fn codegen(filename: &Path, output: &Path, template: Option<&str>) -> Result
         || !doc.check_embedded_files_are_used(&template)?
     {
         error!("Found problems in document, cannot continue");
-        eprintln!("Unable to continue");
         std::process::exit(1);
     }