feat! change logging to use log/env_logger instead of tracing

We don't use async in Subplot, and the mental overhead of learning
tracing and the code overhead to add support for logging custom
values (implementing the Value trait for Subplot internal types) does
not seem worthwhile.

Sponsored-by: author

1 files changed, 25 insertions, 58 deletions

diff --git a/src/doc.rs b/src/doc.rs
index 5c81e27..2ff1484 100644
--- a/src/doc.rs
+++ b/src/doc.rs
@@ -23,7 +23,7 @@ use std::str::FromStr;
 
 use pandoc_ast::{MutVisitor, Pandoc};
 
-use tracing::{event, instrument, span, Level};
+use log::{error, trace};
 
 /// The set of known (special) classes which subplot will always recognise
 /// as being valid.
@@ -102,7 +102,6 @@ impl<'a> Document {
         }
     }
 
-    #[instrument(level = "trace", skip(ast))]
     fn from_ast<P>(
         basedir: P,
         markdowns: Vec<PathBuf>,
@@ -115,7 +114,7 @@ impl<'a> Document {
     {
         let meta = Metadata::new(basedir, &ast, template)?;
         let mut linter = LintingVisitor::default();
-        event!(Level::TRACE, "Walking AST for linting...");
+        trace!("Walking AST for linting...");
         linter.walk_pandoc(&mut ast);
         if !linter.issues.is_empty() {
             // Currently we can't really return more than one error so return one
@@ -123,12 +122,11 @@ impl<'a> Document {
         }
         let files = DataFiles::new(&mut ast);
         let doc = Document::new(markdowns, ast, meta, files, style);
-        event!(Level::TRACE, "Loaded from JSON OK");
+        trace!("Loaded from JSON OK");
         Ok(doc)
     }
 
     /// Construct a Document from a JSON AST
-    #[instrument(level = "trace", skip(json))]
     pub fn from_json<P>(
         basedir: P,
         markdowns: Vec<PathBuf>,
@@ -139,7 +137,7 @@ impl<'a> Document {
     where
         P: AsRef<Path> + Debug,
     {
-        event!(Level::TRACE, "Parsing document...");
+        trace!("Parsing document...");
         let ast: Pandoc = serde_json::from_str(json)?;
         Self::from_ast(basedir, markdowns, ast, style, template)
     }
@@ -149,7 +147,6 @@ impl<'a> Document {
     /// The file can be in any format Pandoc understands. This runs
     /// Pandoc to parse the file into an AST, so it can be a little
     /// slow.
-    #[instrument(level = "trace")]
     pub fn from_file(
         basedir: &Path,
         filename: &Path,
@@ -170,13 +167,13 @@ impl<'a> Document {
         // Add external Pandoc filters.
         crate::policy::add_citeproc(&mut pandoc);
 
-        event!(Level::TRACE, ?filename, "Invoking Pandoc to parse document");
+        trace!("Invoking Pandoc to parse document {:?}", filename);
         let output = match pandoc.execute()? {
             pandoc::PandocOutput::ToBuffer(o) => o,
             _ => return Err(SubplotError::NotJson),
         };
         let doc = Document::from_json(basedir, markdowns, &output, style, template)?;
-        event!(Level::TRACE, "Loaded document OK");
+        trace!("Loaded document OK");
         Ok(doc)
     }
 
@@ -185,23 +182,18 @@ impl<'a> Document {
     /// The file can be in the CommonMark format, with some
     /// extensions. This uses the pulldown-cmark crate to parse the
     /// file into an AST.
-    #[instrument(level = "trace")]
     pub fn from_file_with_pullmark(
         basedir: &Path,
         filename: &Path,
         style: Style,
         template: Option<&str>,
     ) -> Result<Document> {
-        event!(
-            Level::TRACE,
-            ?filename,
-            "Parsing document with pullmark-cmark"
-        );
+        trace!("Parsing document with pullmark-cmark from {:?}", filename);
         let filename = filename.to_path_buf();
         let markdown = std::fs::read_to_string(&filename)?;
         let ast = ast::AbstractSyntaxTree::from_str(&markdown)?;
 
-        event!(Level::TRACE, "Parsed document OK");
+        trace!("Parsed document OK");
         Self::from_ast(basedir, vec![filename], ast.to_pandoc(), style, template)
     }
 
@@ -269,13 +261,12 @@ impl<'a> Document {
     }
 
     /// Check the document for common problems.
-    #[instrument(level = "trace", skip(self))]
     pub fn lint(&self) -> Result<()> {
-        event!(Level::TRACE, "Linting document");
+        trace!("Linting document");
         self.check_doc_has_title()?;
         self.check_filenames_are_unique()?;
         self.check_block_classes()?;
-        event!(Level::TRACE, "No linting problems found");
+        trace!("No linting problems found");
         Ok(())
     }
 
@@ -334,14 +325,13 @@ impl<'a> Document {
 
     /// Check that all named files (in matched steps) are actually present in the
     /// document.
-    #[instrument(level = "trace", skip(self))]
     pub fn check_named_files_exist(&mut self, template: &str) -> Result<bool> {
         let filenames: HashSet<_> = self
             .files()
             .iter()
             .map(|f| f.filename().to_lowercase())
             .collect();
-        event!(Level::TRACE, ?filenames, "Checking that files exist");
+        trace!("Checking that files exist");
         let mut okay = true;
         let scenarios = match self.matched_scenarios(template) {
             Ok(scenarios) => scenarios,
@@ -365,14 +355,13 @@ impl<'a> Document {
     }
 
     /// Check that all embedded files are used by matched steps.
-    #[instrument(level = "trace", skip(self))]
     pub fn check_embedded_files_are_used(&mut self, template: &str) -> Result<bool> {
         let mut filenames: HashSet<_> = self
             .files()
             .iter()
             .map(|f| f.filename().to_lowercase())
             .collect();
-        event!(Level::TRACE, ?filenames, "Checking that files are used");
+        trace!("Checking that files are used");
         let scenarios = match self.matched_scenarios(template) {
             Ok(scenarios) => scenarios,
             Err(_) => return Ok(true), // We can't do the check, so say it's okay.
@@ -403,21 +392,16 @@ impl<'a> Document {
     }
 
     /// Check that all matched steps actually have function implementations
-    #[instrument(level = "trace", skip(self))]
     pub fn check_matched_steps_have_impl(&mut self, template: &str) -> bool {
-        event!(Level::TRACE, "Checking that steps have implementations");
+        trace!("Checking that steps have implementations");
         let mut okay = true;
         let scenarios = match self.matched_scenarios(template) {
             Ok(scenarios) => scenarios,
             Err(_) => return true, // No matches means no missing impls
         };
-        event!(Level::TRACE, count = scenarios.len(), "Found scenarios");
+        trace!("Found {} scenarios", scenarios.len());
         for scenario in scenarios {
-            event!(
-                Level::TRACE,
-                title = scenario.title(),
-                "Checking that steps in scenario"
-            );
+            trace!("Checking that steps in scenario");
             let mut said_scenario = false;
             for step in scenario.steps() {
                 if step.function().is_none() {
@@ -427,11 +411,7 @@ impl<'a> Document {
                         said_scenario = true;
                     }
                     eprintln!("  Step missing implementation: '{}'", step.text());
-                    event!(
-                        Level::ERROR,
-                        step = step.text(),
-                        "Missing step implementation"
-                    );
+                    trace!("Missing step implementation: {:?}", step.text());
                     okay = false;
                 }
             }
@@ -465,11 +445,9 @@ impl<'a> Document {
     }
 
     /// Return matched scenarios in a document.
-    #[instrument(skip(self))]
     pub fn matched_scenarios(&mut self, template: &str) -> Result<Vec<MatchedScenario>> {
         let scenarios = self.scenarios()?;
-        event!(
-            Level::TRACE,
+        trace!(
             "Found {} scenarios, checking their bindings",
             scenarios.len()
         );
@@ -496,24 +474,20 @@ impl<'a> Document {
 /// Load a `Document` from a file.
 ///
 /// This version uses Pandoc to parse the Markdown.
-#[instrument(level = "trace")]
 pub fn load_document<P>(filename: P, style: Style, template: Option<&str>) -> Result<Document>
 where
     P: AsRef<Path> + Debug,
 {
     let filename = filename.as_ref();
     let base_path = get_basedir_from(filename);
-    event!(
-        Level::TRACE,
-        ?filename,
-        ?base_path,
+    trace!(
         "Loading document based at `{}` called `{}` with {:?}",
         base_path.display(),
         filename.display(),
         style
     );
     let doc = Document::from_file(&base_path, filename, style, template)?;
-    event!(Level::TRACE, "Loaded doc from file OK");
+    trace!("Loaded doc from file OK");
 
     Ok(doc)
 }
@@ -521,7 +495,6 @@ where
 /// Load a `Document` from a file.
 ///
 /// This version uses the `cmark-pullmark` crate to parse Markdown.
-#[instrument(level = "trace")]
 pub fn load_document_with_pullmark<P>(
     filename: P,
     style: Style,
@@ -532,10 +505,7 @@ where
 {
     let filename = filename.as_ref();
     let base_path = get_basedir_from(filename);
-    event!(
-        Level::TRACE,
-        ?filename,
-        ?base_path,
+    trace!(
         "Loading document based at `{}` called `{}` with {:?} using pullmark-cmark",
         base_path.display(),
         filename.display(),
@@ -543,22 +513,19 @@ where
     );
     crate::resource::add_search_path(filename.parent().unwrap());
     let doc = Document::from_file_with_pullmark(&base_path, filename, style, template)?;
-    event!(Level::TRACE, "Loaded doc from file OK");
+    trace!("Loaded doc from file OK");
     Ok(doc)
 }
 
 /// Generate code for one document.
 pub fn codegen(filename: &Path, output: &Path, template: Option<&str>) -> Result<CodegenOutput> {
-    let span = span!(Level::TRACE, "codegen");
-    let _enter = span.enter();
-
     let mut doc = load_document_with_pullmark(filename, Style::default(), template)?;
     doc.lint()?;
     let template = template
         .map(Ok)
         .unwrap_or_else(|| doc.template())?
         .to_string();
-    event!(Level::TRACE, ?template);
+    trace!("Template: {:?}", template);
     if !doc.meta().templates().any(|t| t == template) {
         return Err(SubplotError::TemplateSupportNotPresent);
     }
@@ -566,15 +533,15 @@ pub fn codegen(filename: &Path, output: &Path, template: Option<&str>) -> Result
         || !doc.check_matched_steps_have_impl(&template)
         || !doc.check_embedded_files_are_used(&template)?
     {
-        event!(Level::ERROR, "Found problems in document, cannot continue");
+        error!("Found problems in document, cannot continue");
         eprintln!("Unable to continue");
         std::process::exit(1);
     }
 
-    event!(Level::TRACE, "Generating code");
+    trace!("Generating code");
 
     generate_test_program(&mut doc, output, &template)?;
-    event!(Level::TRACE, "Finished generating code");
+    trace!("Finished generating code");
 
     Ok(CodegenOutput::new(template, doc))
 }