tracing: Make formatting better and document

Signed-off-by: Daniel Silverstone <dsilvers@digital-scurf.org>

2 files changed, 65 insertions, 20 deletions

diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md
index 58a76f9..dc8ff9e 100644
--- a/CONTRIBUTING.md
+++ b/CONTRIBUTING.md
@@ -28,9 +28,9 @@ and branch we can pull from.
 change the git repository, the full Subplot test suite must pass. To
 run it, use the following command:
 
-~~~sh
+```sh
 $ ./check -v
-~~~
+```
 
 If you only touch documentation, and don't want to install all the
 build dependencies, you can skip running the tests yourself.
@@ -67,7 +67,7 @@ changes unrelated to the rename.
 **Keep commits in a merge request related:** If a commit adds a new
 feature, it shouldn't also fix a bug in an old feature. If there's a
 need to re-do the new feature, the bug fix will take longer to get
-merged. 
+merged.
 
 **Tell a story with a merge request:** The commits in a merge request
 should be arranged in a way that make the change as a whole easy to
@@ -80,15 +80,36 @@ get there in the best possible way. You should tell the story of
 flying by plane to get somewhere, not how you explored the world and
 eventually invented flying machines to travel faster.
 
-
 # Definition of done
 
 When a change is made to Subplot, it must meet the following minimum
 requirements to be considered "done": finished and not requiring
 further work or attention.
 
-* if review of the change (in an MR or otherwise) has raised any
+- if review of the change (in an MR or otherwise) has raised any
   issues, they have been resolved or filed as issues
-* the change has been merged to the main branch
-* ./check passes after the merge
-* all relevant issues have been updated appropriately or closed
+- the change has been merged to the main branch
+- ./check passes after the merge
+- all relevant issues have been updated appropriately or closed
+
+# Debugging subplot
+
+Ideally as a **user** of subplot you shouldn't need this, all error messages
+should give you sufficient context to chase down your problems. However if you
+are debugging a change to subplot itself then you may need to know how to do the
+following:
+
+1. You can change the logging level of subplot by means of the `SUBPLOT_LOG`
+   environment variable. If you set it to `trace` then it will show you absolutely
+   everything traced inside the program. You can learn about the syntax for
+   this variable on the [EnvFilter][] docs on `docs.rs`.
+2. You can redirect the logging to a file by means of the `SUBPLOT_LOG_FILE`
+   environment variable. Simply set it to the path you want to store logging to.
+   Subplot will _append_ to that file, so it's safe to have it in your environment
+   for multiple runs.
+3. To change the logging format, you can set `SUBPLOT_LOG_FORMAT` to one of:
+   `pretty` to have a multiline pretty format, `default` or `oneline` for a
+   basic one-line-per-event log format and `json` for a one-line-per-event JSON
+   log format.
+
+[envfilter]: https://docs.rs/tracing-subscriber/0.2.20/tracing_subscriber/filter/struct.EnvFilter.html
diff --git a/src/bin/subplot.rs b/src/bin/subplot.rs
index 29ed25e..f4eb678 100644
--- a/src/bin/subplot.rs
+++ b/src/bin/subplot.rs
@@ -8,7 +8,7 @@ use structopt::StructOpt;
 use subplot::{
     generate_test_program, resource, template_spec, DataFile, Document, MarkupOpts, Style,
 };
-use tracing::{event, span, Level};
+use tracing::{event, span, Level, Subscriber};
 
 use std::convert::TryFrom;
 use std::ffi::OsString;
@@ -439,6 +439,12 @@ fn real_main() {
     }
 }
 
+enum LogFormat {
+    Pretty,
+    OneLine,
+    Json,
+}
+
 fn main() {
     let filter = match tracing_subscriber::EnvFilter::try_from_env("SUBPLOT_LOG") {
         Ok(f) => f,
@@ -452,13 +458,27 @@ fn main() {
             }
         }
     };
-    match std::env::var("SUBPLOT_TRACE_LOG").ok().as_deref() {
+    let format = match std::env::var("SUBPLOT_LOG_FORMAT")
+        .map(|v| v.to_ascii_lowercase())
+        .as_deref()
+    {
+        Err(_) | Ok("oneline") | Ok("default") => LogFormat::OneLine,
+        Ok("pretty") => LogFormat::Pretty,
+        Ok("json") => LogFormat::Json,
+        Ok(v) => {
+            eprintln!("Unknown log format: {:?}", v);
+            process::exit(1);
+        }
+    };
+    let subscriber = match std::env::var("SUBPLOT_LOG_FILE").ok().as_deref() {
         None | Some("") | Some("-") => {
-            let subscriber = tracing_subscriber::fmt()
-                .with_env_filter(filter)
-                .pretty()
-                .finish();
-            tracing::subscriber::with_default(subscriber, real_main);
+            let subscriber = tracing_subscriber::fmt().with_env_filter(filter);
+            let subscriber: Box<dyn Subscriber + Send + Sync + 'static> = match format {
+                LogFormat::OneLine => Box::new(subscriber.finish()),
+                LogFormat::Pretty => Box::new(subscriber.pretty().finish()),
+                LogFormat::Json => Box::new(subscriber.json().with_ansi(false).finish()),
+            };
+            subscriber
         }
         Some(fname) => {
             let curdir = std::path::Component::CurDir;
@@ -472,10 +492,14 @@ fn main() {
             let subscriber = tracing_subscriber::fmt()
                 .with_writer(non_blocking)
                 .with_env_filter(filter)
-                .pretty()
-                .with_ansi(false)
-                .finish();
-            tracing::subscriber::with_default(subscriber, real_main);
+                .with_ansi(false);
+            let subscriber: Box<dyn Subscriber + Send + Sync + 'static> = match format {
+                LogFormat::OneLine => Box::new(subscriber.finish()),
+                LogFormat::Pretty => Box::new(subscriber.pretty().finish()),
+                LogFormat::Json => Box::new(subscriber.json().finish()),
+            };
+            subscriber
         }
-    }
+    };
+    tracing::subscriber::with_default(subscriber, real_main);
 }