From 994104d61549e7230ccd167f5784c5f793462c43 Mon Sep 17 00:00:00 2001
From: Pat Hickey <pat@moreproductive.org>
Date: Sat, 30 May 2020 17:55:10 -0700
Subject: [PATCH 01/10] wiggle: add config options for logging

---
 crates/wiggle/generate/src/config.rs | 86 +++++++++++++++++++++++-----
 1 file changed, 73 insertions(+), 13 deletions(-)

diff --git a/crates/wiggle/generate/src/config.rs b/crates/wiggle/generate/src/config.rs
index 6eecf28c96..735cb92546 100644
--- a/crates/wiggle/generate/src/config.rs
+++ b/crates/wiggle/generate/src/config.rs
@@ -18,6 +18,7 @@ pub struct Config {
     pub witx: WitxConf,
     pub ctx: CtxConf,
     pub errors: ErrorConf,
+    pub logging: LoggingConf,
 }
 
 #[derive(Debug, Clone)]
@@ -25,25 +26,45 @@ pub enum ConfigField {
     Witx(WitxConf),
     Ctx(CtxConf),
     Error(ErrorConf),
+    Logging(LoggingConf),
 }
 
-impl ConfigField {
-    pub fn parse_pair(ident: &str, value: ParseStream, err_loc: Span) -> Result<Self> {
-        match ident {
-            "witx" => Ok(ConfigField::Witx(WitxConf::Paths(value.parse()?))),
-            "witx_literal" => Ok(ConfigField::Witx(WitxConf::Literal(value.parse()?))),
-            "ctx" => Ok(ConfigField::Ctx(value.parse()?)),
-            "errors" => Ok(ConfigField::Error(value.parse()?)),
-            _ => Err(Error::new(err_loc, "expected `witx`, `ctx`, or `errors`")),
-        }
-    }
+mod kw {
+    syn::custom_keyword!(witx);
+    syn::custom_keyword!(witx_literal);
+    syn::custom_keyword!(ctx);
+    syn::custom_keyword!(logging);
+    syn::custom_keyword!(errors);
+    syn::custom_keyword!(log);
+    syn::custom_keyword!(tracing);
 }
 
 impl Parse for ConfigField {
     fn parse(input: ParseStream) -> Result<Self> {
-        let id: Ident = input.parse()?;
-        let _colon: Token![:] = input.parse()?;
-        Self::parse_pair(id.to_string().as_ref(), input, id.span())
+        let lookahead = input.lookahead1();
+        if lookahead.peek(kw::witx) {
+            input.parse::<kw::witx>()?;
+            input.parse::<Token![:]>()?;
+            Ok(ConfigField::Witx(WitxConf::Paths(input.parse()?)))
+        } else if lookahead.peek(kw::witx_literal) {
+            input.parse::<kw::witx_literal>()?;
+            input.parse::<Token![:]>()?;
+            Ok(ConfigField::Witx(WitxConf::Literal(input.parse()?)))
+        } else if lookahead.peek(kw::ctx) {
+            input.parse::<kw::ctx>()?;
+            input.parse::<Token![:]>()?;
+            Ok(ConfigField::Ctx(input.parse()?))
+        } else if lookahead.peek(kw::logging) {
+            input.parse::<kw::logging>()?;
+            input.parse::<Token![:]>()?;
+            Ok(ConfigField::Logging(input.parse()?))
+        } else if lookahead.peek(kw::errors) {
+            input.parse::<kw::errors>()?;
+            input.parse::<Token![:]>()?;
+            Ok(ConfigField::Error(input.parse()?))
+        } else {
+            Err(lookahead.error())
+        }
     }
 }
 
@@ -52,6 +73,7 @@ impl Config {
         let mut witx = None;
         let mut ctx = None;
         let mut errors = None;
+        let mut logging = None;
         for f in fields {
             match f {
                 ConfigField::Witx(c) => {
@@ -72,6 +94,12 @@ impl Config {
                     }
                     errors = Some(c);
                 }
+                ConfigField::Logging(c) => {
+                    if logging.is_some() {
+                        return Err(Error::new(err_loc, "duplicate `logging` field"));
+                    }
+                    logging = Some(c);
+                }
             }
         }
         Ok(Config {
@@ -82,6 +110,7 @@ impl Config {
                 .take()
                 .ok_or_else(|| Error::new(err_loc, "`ctx` field required"))?,
             errors: errors.take().unwrap_or_default(),
+            logging: logging.take().unwrap_or_default(),
         })
     }
 
@@ -290,3 +319,34 @@ impl Parse for ErrorConfField {
         })
     }
 }
+
+/// Configure logging statements in generated code
+pub enum LoggingConf {
+    Log { cfg_feature: Option<String> },
+    Tracing,
+}
+
+impl Default for LoggingConf {
+    fn default() -> Self {
+        // For compatibility with existing code. We should probably revise this later.
+        LoggingConf::Log {
+            cfg_feature: Some("trace_log".to_owned()),
+        }
+    }
+}
+
+impl Parse for LoggingConf {
+    fn parse(input: ParseStream) -> Result<Self> {
+        let lookahead = input.lookahead1();
+        if lookahead.peek(kw::log) {
+            input.parse::<kw::log>()?;
+            // TODO: syntax so the user can specify their own cfg_feature guard here.
+            Ok(LoggingConf::Log { cfg_feature: None })
+        } else if lookahead.peek(kw::tracing) {
+            input.parse::<kw::tracing>()?;
+            Ok(LoggingConf::Tracing)
+        } else {
+            Err(lookahead.error())
+        }
+    }
+}

From f89fc0ac5731d647b09329677428560fd7c6fc16 Mon Sep 17 00:00:00 2001
From: Pat Hickey <pat@moreproductive.org>
Date: Sat, 30 May 2020 19:06:37 -0700
Subject: [PATCH 02/10] wiggle: can swap in `tracing` for args

---
 Cargo.lock                            | 134 ++++++++++++++++++++++++++
 crates/wiggle/generate/src/config.rs  |   1 +
 crates/wiggle/generate/src/funcs.rs   |  71 ++++++++++----
 crates/wiggle/generate/src/lib.rs     |  11 ++-
 crates/wiggle/macro/src/lib.rs        |   2 +-
 crates/wiggle/test-helpers/Cargo.toml |   6 ++
 6 files changed, 203 insertions(+), 22 deletions(-)

diff --git a/Cargo.lock b/Cargo.lock
index a357573abb..782cffd7b8 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -252,6 +252,17 @@ version = "0.1.10"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "4785bdd1c96b2a846b2bd7cc02e86b6b3dbf14e7e53446c4f54c92a361040822"
 
+[[package]]
+name = "chrono"
+version = "0.4.11"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "80094f509cf8b5ae86a4966a39b3ff66cd7e2a3e594accec3743ff3fabeab5b2"
+dependencies = [
+ "num-integer",
+ "num-traits",
+ "time",
+]
+
 [[package]]
 name = "clap"
 version = "2.33.1"
@@ -1138,6 +1149,15 @@ dependencies = [
  "libc",
 ]
 
+[[package]]
+name = "matchers"
+version = "0.0.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f099785f7595cc4b4553a174ce30dd7589ef93391ff414dbb67f62392b9e0ce1"
+dependencies = [
+ "regex-automata",
+]
+
 [[package]]
 name = "maybe-uninit"
 version = "2.0.0"
@@ -1175,6 +1195,16 @@ version = "0.2.1"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "0debeb9fcf88823ea64d64e4a815ab1643f33127d995978e099942ce38f25238"
 
+[[package]]
+name = "num-integer"
+version = "0.1.42"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "3f6ea62e9d81a77cd3ee9a2a5b9b609447857f3d358704331e4ef39eb247fcba"
+dependencies = [
+ "autocfg 1.0.0",
+ "num-traits",
+]
+
 [[package]]
 name = "num-traits"
 version = "0.2.11"
@@ -1669,6 +1699,16 @@ dependencies = [
  "thread_local",
 ]
 
+[[package]]
+name = "regex-automata"
+version = "0.1.9"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ae1ded71d66a4a97f5e961fd0cb25a5f366a42a41570d16a763a69c092c26ae4"
+dependencies = [
+ "byteorder",
+ "regex-syntax",
+]
+
 [[package]]
 name = "regex-syntax"
 version = "0.6.18"
@@ -1847,6 +1887,15 @@ dependencies = [
  "opaque-debug",
 ]
 
+[[package]]
+name = "sharded-slab"
+version = "0.0.9"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "06d5a3f5166fb5b42a5439f2eee8b9de149e235961e3eb21c5808fc3ea17ff3e"
+dependencies = [
+ "lazy_static",
+]
+
 [[package]]
 name = "smallvec"
 version = "1.4.0"
@@ -2038,6 +2087,16 @@ dependencies = [
  "lazy_static",
 ]
 
+[[package]]
+name = "time"
+version = "0.1.43"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ca8a50ef2360fbd1eeb0ecd46795a87a19024eb4b53c5dc916ca1fd95fe62438"
+dependencies = [
+ "libc",
+ "winapi",
+]
+
 [[package]]
 name = "toml"
 version = "0.5.6"
@@ -2047,6 +2106,78 @@ dependencies = [
  "serde",
 ]
 
+[[package]]
+name = "tracing"
+version = "0.1.14"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "a7c6b59d116d218cb2d990eb06b77b64043e0268ef7323aae63d8b30ae462923"
+dependencies = [
+ "cfg-if",
+ "tracing-attributes",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-attributes"
+version = "0.1.8"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "99bbad0de3fd923c9c3232ead88510b783e5a4d16a6154adffa3d53308de984c"
+dependencies = [
+ "proc-macro2",
+ "quote",
+ "syn",
+]
+
+[[package]]
+name = "tracing-core"
+version = "0.1.10"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "0aa83a9a47081cd522c09c81b31aec2c9273424976f922ad61c053b58350b715"
+dependencies = [
+ "lazy_static",
+]
+
+[[package]]
+name = "tracing-log"
+version = "0.1.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "5e0f8c7178e13481ff6765bd169b33e8d554c5d2bbede5e32c356194be02b9b9"
+dependencies = [
+ "lazy_static",
+ "log",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-serde"
+version = "0.1.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "b6ccba2f8f16e0ed268fc765d9b7ff22e965e7185d32f8f1ec8294fe17d86e79"
+dependencies = [
+ "serde",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-subscriber"
+version = "0.2.5"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "1d53c40489aa69c9aed21ff483f26886ca8403df33bdc2d2f87c60c1617826d2"
+dependencies = [
+ "ansi_term",
+ "chrono",
+ "lazy_static",
+ "matchers",
+ "regex",
+ "serde",
+ "serde_json",
+ "sharded-slab",
+ "smallvec",
+ "tracing-core",
+ "tracing-log",
+ "tracing-serde",
+]
+
 [[package]]
 name = "traitobject"
 version = "0.1.0"
@@ -2525,6 +2656,9 @@ name = "wiggle-test"
 version = "0.17.0"
 dependencies = [
  "proptest",
+ "thiserror",
+ "tracing",
+ "tracing-subscriber",
  "wiggle",
 ]
 
diff --git a/crates/wiggle/generate/src/config.rs b/crates/wiggle/generate/src/config.rs
index 735cb92546..8769504780 100644
--- a/crates/wiggle/generate/src/config.rs
+++ b/crates/wiggle/generate/src/config.rs
@@ -321,6 +321,7 @@ impl Parse for ErrorConfField {
 }
 
 /// Configure logging statements in generated code
+#[derive(Debug, Clone)]
 pub enum LoggingConf {
     Log { cfg_feature: Option<String> },
     Tracing,
diff --git a/crates/wiggle/generate/src/funcs.rs b/crates/wiggle/generate/src/funcs.rs
index 2c8cf2b350..33827b75b6 100644
--- a/crates/wiggle/generate/src/funcs.rs
+++ b/crates/wiggle/generate/src/funcs.rs
@@ -1,6 +1,7 @@
 use proc_macro2::TokenStream;
 use quote::quote;
 
+use crate::config::LoggingConf;
 use crate::error_transform::ErrorTransform;
 use crate::lifetimes::anon_lifetime;
 use crate::module_trait::passed_by_reference;
@@ -11,6 +12,7 @@ pub fn define_func(
     func: &witx::InterfaceFunc,
     trait_name: TokenStream,
     errxform: &ErrorTransform,
+    logging: &LoggingConf,
 ) -> TokenStream {
     let funcname = func.name.as_str();
 
@@ -161,27 +163,12 @@ pub fn define_func(
         quote!()
     };
 
-    let (placeholders, args): (Vec<_>, Vec<_>) = func
-        .params
-        .iter()
-        .map(|param| {
-            let name = names.func_param(&param.name);
-            let fmt = if passed_by_reference(&*param.tref.type_()) {
-                "{:?}"
-            } else {
-                "{}"
-            };
-            (format!("{}={}", name.to_string(), fmt), quote!(#name))
-        })
-        .unzip();
-    let trace_fmt = format!("{}({})", ident.to_string(), placeholders.join(","));
+    let log_args = logging.args(&func, names);
+
     quote!(pub fn #ident(#abi_args) -> #abi_ret {
         #(#marshal_args)*
         #(#marshal_rets_pre)*
-        #[cfg(feature = "trace_log")]
-        {
-            log::trace!(#trace_fmt, #(#args),*);
-        }
+        #log_args
         let #trait_bindings  = match #trait_name::#ident(ctx, #(#trait_args),*) {
             Ok(#trait_bindings) => { #trait_rets },
             Err(e) => { #ret_err },
@@ -336,3 +323,51 @@ where
         _ => write_val_to_ptr,
     }
 }
+
+impl LoggingConf {
+    fn args(&self, func: &witx::InterfaceFunc, names: &Names) -> TokenStream {
+        match self {
+            Self::Log { cfg_feature } => {
+                let (placeholders, args): (Vec<_>, Vec<_>) = func
+                    .params
+                    .iter()
+                    .map(|param| {
+                        let name = names.func_param(&param.name);
+                        let fmt = if passed_by_reference(&*param.tref.type_()) {
+                            "{:?}"
+                        } else {
+                            "{}"
+                        };
+                        (format!("{}={}", name.to_string(), fmt), quote!(#name))
+                    })
+                    .unzip();
+                let trace_fmt = format!(
+                    "{}({})",
+                    names.func(&func.name).to_string(),
+                    placeholders.join(",")
+                );
+                let trace_stmt = quote!(log::trace!(#trace_fmt, #(#args),*););
+                if let Some(feature) = cfg_feature {
+                    quote! {
+                        #[cfg(feature = #feature)]
+                        {
+                            #trace_stmt
+                        }
+                    }
+                } else {
+                    trace_stmt
+                }
+            }
+            Self::Tracing => {
+                let args = func.params.iter().map(|param| {
+                    let name = names.func_param(&param.name);
+                    quote!( #name = #name )
+                });
+                let func_name = names.func(&func.name).to_string();
+                quote! {
+                    tracing::debug!(function = #func_name, #(#args),*, "marshalled arguments");
+                }
+            }
+        }
+    }
+}
diff --git a/crates/wiggle/generate/src/lib.rs b/crates/wiggle/generate/src/lib.rs
index bd6d5d9e40..459d22f472 100644
--- a/crates/wiggle/generate/src/lib.rs
+++ b/crates/wiggle/generate/src/lib.rs
@@ -11,14 +11,19 @@ use quote::quote;
 
 use lifetimes::anon_lifetime;
 
-pub use config::Config;
+pub use config::{Config, LoggingConf};
 pub use error_transform::{ErrorTransform, UserErrorType};
 pub use funcs::define_func;
 pub use module_trait::define_module_trait;
 pub use names::Names;
 pub use types::define_datatype;
 
-pub fn generate(doc: &witx::Document, names: &Names, errs: &ErrorTransform) -> TokenStream {
+pub fn generate(
+    doc: &witx::Document,
+    names: &Names,
+    errs: &ErrorTransform,
+    logging: &LoggingConf,
+) -> TokenStream {
     // TODO at some point config should grow more ability to configure name
     // overrides.
     let rt = names.runtime_mod();
@@ -52,7 +57,7 @@ pub fn generate(doc: &witx::Document, names: &Names, errs: &ErrorTransform) -> T
         let trait_name = names.trait_name(&module.name);
         let fs = module
             .funcs()
-            .map(|f| define_func(&names, &f, quote!(#trait_name), &errs));
+            .map(|f| define_func(&names, &f, quote!(#trait_name), &errs, logging));
         let modtrait = define_module_trait(&names, &module, &errs);
         let ctx_type = names.ctx_type();
         quote!(
diff --git a/crates/wiggle/macro/src/lib.rs b/crates/wiggle/macro/src/lib.rs
index ed4a3dc6f0..fced356f34 100644
--- a/crates/wiggle/macro/src/lib.rs
+++ b/crates/wiggle/macro/src/lib.rs
@@ -101,7 +101,7 @@ pub fn from_witx(args: TokenStream) -> TokenStream {
     let error_transform = wiggle_generate::ErrorTransform::new(&config.errors, &doc)
         .expect("validating error transform");
 
-    let code = wiggle_generate::generate(&doc, &names, &error_transform);
+    let code = wiggle_generate::generate(&doc, &names, &error_transform, &config.logging);
     let metadata = if cfg!(feature = "wiggle_metadata") {
         wiggle_generate::generate_metadata(&doc, &names)
     } else {
diff --git a/crates/wiggle/test-helpers/Cargo.toml b/crates/wiggle/test-helpers/Cargo.toml
index da548e3950..71015052c7 100644
--- a/crates/wiggle/test-helpers/Cargo.toml
+++ b/crates/wiggle/test-helpers/Cargo.toml
@@ -14,5 +14,11 @@ include = ["src/**/*", "LICENSE"]
 proptest = "0.9"
 wiggle = { path = ".." }
 
+[dev-dependencies]
+thiserror = "1.0"
+tracing = "0.1.14"
+tracing-subscriber = "0.2.4"
+
+
 [badges]
 maintenance = { status = "actively-developed" }

From 02c0c68ed27d5ebc1f6d5211726a6199c0601e1a Mon Sep 17 00:00:00 2001
From: Pat Hickey <pat@moreproductive.org>
Date: Tue, 2 Jun 2020 12:24:28 -0700
Subject: [PATCH 03/10] replace all uses of `log` with `tracing`

---
 Cargo.lock                                    |   1 +
 crates/wiggle/Cargo.toml                      |  12 +-
 crates/wiggle/generate/src/config.rs          |  49 ------
 crates/wiggle/generate/src/funcs.rs           | 142 +++++++-----------
 crates/wiggle/generate/src/lib.rs             |  12 +-
 crates/wiggle/generate/src/types/enum.rs      |   6 +
 crates/wiggle/generate/src/types/flags.rs     |   6 +
 crates/wiggle/generate/src/types/handle.rs    |   6 +
 crates/wiggle/generate/src/types/int.rs       |   6 +
 crates/wiggle/generate/src/types/mod.rs       |  53 +++++++
 crates/wiggle/generate/src/types/struct.rs    |   6 +
 crates/wiggle/generate/src/types/union.rs     |   6 +
 crates/wiggle/macro/src/lib.rs                |   2 +-
 crates/wiggle/src/lib.rs                      |   1 +
 crates/wiggle/src/tracing.rs                  |  11 ++
 .../wiggle/test-helpers/examples/tracing.rs   | 118 +++++++++++++++
 16 files changed, 285 insertions(+), 152 deletions(-)
 create mode 100644 crates/wiggle/src/tracing.rs
 create mode 100644 crates/wiggle/test-helpers/examples/tracing.rs

diff --git a/Cargo.lock b/Cargo.lock
index 782cffd7b8..3870242c33 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -2623,6 +2623,7 @@ version = "0.17.0"
 dependencies = [
  "proptest",
  "thiserror",
+ "tracing",
  "wiggle-macro",
  "wiggle-test",
  "witx",
diff --git a/crates/wiggle/Cargo.toml b/crates/wiggle/Cargo.toml
index c6f6adb427..07566bb338 100644
--- a/crates/wiggle/Cargo.toml
+++ b/crates/wiggle/Cargo.toml
@@ -14,6 +14,7 @@ include = ["src/**/*", "LICENSE"]
 thiserror = "1"
 witx = { path = "../wasi-common/WASI/tools/witx", version = "0.8.5", optional = true }
 wiggle-macro = { path = "macro", version = "0.17.0" }
+tracing_crate = { version = "0.1.14", optional = true, package = "tracing" }
 
 [badges]
 maintenance = { status = "actively-developed" }
@@ -23,13 +24,14 @@ wiggle-test = { path = "test-helpers" }
 proptest = "0.9"
 
 [features]
-# These features have no effect on the users of this crate. They are only
-# necessary for testing.
 # The wiggle proc-macro emits some code (inside `pub mod metadata`) guarded
 # by the `wiggle_metadata` feature flag. We use this feature flag so that
 # users of wiggle are not forced to take a direct dependency on the `witx`
 # crate unless they want it.
 wiggle_metadata = ['witx', "wiggle-macro/wiggle_metadata"]
-# In order to test that the contents of this metadata module meet
-# expectations, we must have this feature enabled for the crate by default.
-default = ["wiggle_metadata"]
+# The wiggle proc-macro emits code which may transitively depend on the
+# `tracing` crate, via `wiggle::tracing`. When this feature is not enabled,
+# a no-op equivelant to the tracing macros is provided instead.
+tracing = [ "tracing_crate" ]
+
+default = ["wiggle_metadata", "tracing"]
diff --git a/crates/wiggle/generate/src/config.rs b/crates/wiggle/generate/src/config.rs
index 8769504780..22ff88aa24 100644
--- a/crates/wiggle/generate/src/config.rs
+++ b/crates/wiggle/generate/src/config.rs
@@ -18,7 +18,6 @@ pub struct Config {
     pub witx: WitxConf,
     pub ctx: CtxConf,
     pub errors: ErrorConf,
-    pub logging: LoggingConf,
 }
 
 #[derive(Debug, Clone)]
@@ -26,17 +25,13 @@ pub enum ConfigField {
     Witx(WitxConf),
     Ctx(CtxConf),
     Error(ErrorConf),
-    Logging(LoggingConf),
 }
 
 mod kw {
     syn::custom_keyword!(witx);
     syn::custom_keyword!(witx_literal);
     syn::custom_keyword!(ctx);
-    syn::custom_keyword!(logging);
     syn::custom_keyword!(errors);
-    syn::custom_keyword!(log);
-    syn::custom_keyword!(tracing);
 }
 
 impl Parse for ConfigField {
@@ -54,10 +49,6 @@ impl Parse for ConfigField {
             input.parse::<kw::ctx>()?;
             input.parse::<Token![:]>()?;
             Ok(ConfigField::Ctx(input.parse()?))
-        } else if lookahead.peek(kw::logging) {
-            input.parse::<kw::logging>()?;
-            input.parse::<Token![:]>()?;
-            Ok(ConfigField::Logging(input.parse()?))
         } else if lookahead.peek(kw::errors) {
             input.parse::<kw::errors>()?;
             input.parse::<Token![:]>()?;
@@ -73,7 +64,6 @@ impl Config {
         let mut witx = None;
         let mut ctx = None;
         let mut errors = None;
-        let mut logging = None;
         for f in fields {
             match f {
                 ConfigField::Witx(c) => {
@@ -94,12 +84,6 @@ impl Config {
                     }
                     errors = Some(c);
                 }
-                ConfigField::Logging(c) => {
-                    if logging.is_some() {
-                        return Err(Error::new(err_loc, "duplicate `logging` field"));
-                    }
-                    logging = Some(c);
-                }
             }
         }
         Ok(Config {
@@ -110,7 +94,6 @@ impl Config {
                 .take()
                 .ok_or_else(|| Error::new(err_loc, "`ctx` field required"))?,
             errors: errors.take().unwrap_or_default(),
-            logging: logging.take().unwrap_or_default(),
         })
     }
 
@@ -319,35 +302,3 @@ impl Parse for ErrorConfField {
         })
     }
 }
-
-/// Configure logging statements in generated code
-#[derive(Debug, Clone)]
-pub enum LoggingConf {
-    Log { cfg_feature: Option<String> },
-    Tracing,
-}
-
-impl Default for LoggingConf {
-    fn default() -> Self {
-        // For compatibility with existing code. We should probably revise this later.
-        LoggingConf::Log {
-            cfg_feature: Some("trace_log".to_owned()),
-        }
-    }
-}
-
-impl Parse for LoggingConf {
-    fn parse(input: ParseStream) -> Result<Self> {
-        let lookahead = input.lookahead1();
-        if lookahead.peek(kw::log) {
-            input.parse::<kw::log>()?;
-            // TODO: syntax so the user can specify their own cfg_feature guard here.
-            Ok(LoggingConf::Log { cfg_feature: None })
-        } else if lookahead.peek(kw::tracing) {
-            input.parse::<kw::tracing>()?;
-            Ok(LoggingConf::Tracing)
-        } else {
-            Err(lookahead.error())
-        }
-    }
-}
diff --git a/crates/wiggle/generate/src/funcs.rs b/crates/wiggle/generate/src/funcs.rs
index 33827b75b6..0baa8cd390 100644
--- a/crates/wiggle/generate/src/funcs.rs
+++ b/crates/wiggle/generate/src/funcs.rs
@@ -1,18 +1,17 @@
 use proc_macro2::TokenStream;
 use quote::quote;
 
-use crate::config::LoggingConf;
 use crate::error_transform::ErrorTransform;
 use crate::lifetimes::anon_lifetime;
 use crate::module_trait::passed_by_reference;
 use crate::names::Names;
+use crate::types::WiggleType;
 
 pub fn define_func(
     names: &Names,
+    module: &witx::Module,
     func: &witx::InterfaceFunc,
-    trait_name: TokenStream,
     errxform: &ErrorTransform,
-    logging: &LoggingConf,
 ) -> TokenStream {
     let funcname = func.name.as_str();
 
@@ -51,19 +50,20 @@ pub fn define_func(
     let ret_err = coretype
         .ret
         .map(|ret| {
-            let name = ret.param.name.as_str();
+            let name = names.func_param(&ret.param.name);
             let conversion = if let Some(user_err) = errxform.for_abi_error(&ret.param.tref) {
                 let method = names.user_error_conversion_method(&user_err);
-                quote!(#abi_ret::from(UserErrorConversion::#method(ctx, e)))
+                quote!(UserErrorConversion::#method(ctx, e))
             } else {
-                quote!(#abi_ret::from(e))
+                quote!(e)
             };
             quote! {
-                #[cfg(feature = "trace_log")]
-                {
-                    log::trace!("     | {}={:?}", #name, e);
-                }
-                return #conversion;
+                let e = #conversion;
+                #rt::tracing::event!(
+                    #rt::tracing::Level::TRACE,
+                    #name = #rt::tracing::field::debug(&e),
+                );
+                return #abi_ret::from(e);
             }
         })
         .unwrap_or_else(|| quote!(()));
@@ -78,7 +78,7 @@ pub fn define_func(
             let err_method = names.guest_error_conversion_method(&tref);
             quote! {
                 let e = #rt::GuestError::InFunc { funcname: #funcname, location: #location, err: Box::new(e.into()) };
-                let err: #err_typename = GuestErrorConversion::#err_method(ctx, e); // XXX replace with conversion method on trait!
+                let err: #err_typename = GuestErrorConversion::#err_method(ctx, e);
                 return #abi_ret::from(err);
             }
         } else {
@@ -101,6 +101,23 @@ pub fn define_func(
         }
     });
 
+    let log_marshalled_args = if func.params.len() > 0 {
+        let rt = names.runtime_mod();
+        let args = func.params.iter().map(|param| {
+            let name = names.func_param(&param.name);
+            if param.impls_display() {
+                quote!( #name = #rt::tracing::field::display(&#name) )
+            } else {
+                quote!( #name = #rt::tracing::field::debug(&#name) )
+            }
+        });
+        quote! {
+            #rt::tracing::event!(#rt::tracing::Level::TRACE, #(#args),*);
+        }
+    } else {
+        quote!()
+    };
+
     let (trait_rets, trait_bindings) = if func.results.len() < 2 {
         (quote!({}), quote!(_))
     } else {
@@ -111,29 +128,16 @@ pub fn define_func(
             .map(|result| names.func_param(&result.name))
             .collect();
         let bindings = quote!((#(#trait_rets),*));
-        let names: Vec<_> = func
-            .results
-            .iter()
-            .skip(1)
-            .map(|result| {
-                let name = names.func_param(&result.name);
-                let fmt = match &*result.tref.type_() {
-                    witx::Type::Builtin(_)
-                    | witx::Type::Enum(_)
-                    | witx::Type::Flags(_)
-                    | witx::Type::Handle(_)
-                    | witx::Type::Int(_) => "{}",
-                    _ => "{:?}",
-                };
-                format!("{}={}", name.to_string(), fmt)
-            })
-            .collect();
-        let trace_fmt = format!("     | result=({})", names.join(","));
-        let rets = quote! {
-            #[cfg(feature = "trace_log")]
-            {
-                log::trace!(#trace_fmt, #(#trait_rets),*);
+        let trace_rets = func.results.iter().skip(1).map(|result| {
+            let name = names.func_param(&result.name);
+            if result.tref.impls_display() {
+                quote!(#name = #rt::tracing::field::display(&#name))
+            } else {
+                quote!(#name = #rt::tracing::field::debug(&#name))
             }
+        });
+        let rets = quote! {
+            #rt::tracing::event!(#rt::tracing::Level::TRACE, #(#trace_rets),*);
             (#(#trait_rets),*)
         };
         (rets, bindings)
@@ -153,22 +157,32 @@ pub fn define_func(
         let err_typename = names.type_ref(&err_type, anon_lifetime());
         quote! {
             let success:#err_typename = #rt::GuestErrorType::success();
-            #[cfg(feature = "trace_log")]
-            {
-                log::trace!("     | errno={}", success);
-            }
+            #rt::tracing::event!(
+                #rt::tracing::Level::TRACE,
+                success=#rt::tracing::field::display(&success)
+            );
             #abi_ret::from(success)
         }
     } else {
         quote!()
     };
 
-    let log_args = logging.args(&func, names);
+    let trait_name = names.trait_name(&module.name);
+    let mod_name = &module.name.as_str();
+    let func_name = &func.name.as_str();
 
     quote!(pub fn #ident(#abi_args) -> #abi_ret {
+        let _span = #rt::tracing::span!(
+            #rt::tracing::Level::TRACE,
+            "wiggle abi",
+            module = #mod_name,
+            function = #func_name
+        );
+        let _enter = _span.enter();
+
         #(#marshal_args)*
         #(#marshal_rets_pre)*
-        #log_args
+        #log_marshalled_args
         let #trait_bindings  = match #trait_name::#ident(ctx, #(#trait_args),*) {
             Ok(#trait_bindings) => { #trait_rets },
             Err(e) => { #ret_err },
@@ -323,51 +337,3 @@ where
         _ => write_val_to_ptr,
     }
 }
-
-impl LoggingConf {
-    fn args(&self, func: &witx::InterfaceFunc, names: &Names) -> TokenStream {
-        match self {
-            Self::Log { cfg_feature } => {
-                let (placeholders, args): (Vec<_>, Vec<_>) = func
-                    .params
-                    .iter()
-                    .map(|param| {
-                        let name = names.func_param(&param.name);
-                        let fmt = if passed_by_reference(&*param.tref.type_()) {
-                            "{:?}"
-                        } else {
-                            "{}"
-                        };
-                        (format!("{}={}", name.to_string(), fmt), quote!(#name))
-                    })
-                    .unzip();
-                let trace_fmt = format!(
-                    "{}({})",
-                    names.func(&func.name).to_string(),
-                    placeholders.join(",")
-                );
-                let trace_stmt = quote!(log::trace!(#trace_fmt, #(#args),*););
-                if let Some(feature) = cfg_feature {
-                    quote! {
-                        #[cfg(feature = #feature)]
-                        {
-                            #trace_stmt
-                        }
-                    }
-                } else {
-                    trace_stmt
-                }
-            }
-            Self::Tracing => {
-                let args = func.params.iter().map(|param| {
-                    let name = names.func_param(&param.name);
-                    quote!( #name = #name )
-                });
-                let func_name = names.func(&func.name).to_string();
-                quote! {
-                    tracing::debug!(function = #func_name, #(#args),*, "marshalled arguments");
-                }
-            }
-        }
-    }
-}
diff --git a/crates/wiggle/generate/src/lib.rs b/crates/wiggle/generate/src/lib.rs
index 459d22f472..f1913163c7 100644
--- a/crates/wiggle/generate/src/lib.rs
+++ b/crates/wiggle/generate/src/lib.rs
@@ -11,19 +11,14 @@ use quote::quote;
 
 use lifetimes::anon_lifetime;
 
-pub use config::{Config, LoggingConf};
+pub use config::Config;
 pub use error_transform::{ErrorTransform, UserErrorType};
 pub use funcs::define_func;
 pub use module_trait::define_module_trait;
 pub use names::Names;
 pub use types::define_datatype;
 
-pub fn generate(
-    doc: &witx::Document,
-    names: &Names,
-    errs: &ErrorTransform,
-    logging: &LoggingConf,
-) -> TokenStream {
+pub fn generate(doc: &witx::Document, names: &Names, errs: &ErrorTransform) -> TokenStream {
     // TODO at some point config should grow more ability to configure name
     // overrides.
     let rt = names.runtime_mod();
@@ -54,10 +49,9 @@ pub fn generate(
     };
     let modules = doc.modules().map(|module| {
         let modname = names.module(&module.name);
-        let trait_name = names.trait_name(&module.name);
         let fs = module
             .funcs()
-            .map(|f| define_func(&names, &f, quote!(#trait_name), &errs, logging));
+            .map(|f| define_func(&names, &module, &f, &errs));
         let modtrait = define_module_trait(&names, &module, &errs);
         let ctx_type = names.ctx_type();
         quote!(
diff --git a/crates/wiggle/generate/src/types/enum.rs b/crates/wiggle/generate/src/types/enum.rs
index a3a0096047..cef56065ef 100644
--- a/crates/wiggle/generate/src/types/enum.rs
+++ b/crates/wiggle/generate/src/types/enum.rs
@@ -112,3 +112,9 @@ pub(super) fn define_enum(names: &Names, name: &witx::Id, e: &witx::EnumDatatype
         }
     }
 }
+
+impl super::WiggleType for witx::EnumDatatype {
+    fn impls_display(&self) -> bool {
+        true
+    }
+}
diff --git a/crates/wiggle/generate/src/types/flags.rs b/crates/wiggle/generate/src/types/flags.rs
index 7759e7e6a2..f87261abca 100644
--- a/crates/wiggle/generate/src/types/flags.rs
+++ b/crates/wiggle/generate/src/types/flags.rs
@@ -180,3 +180,9 @@ pub(super) fn define_flags(names: &Names, name: &witx::Id, f: &witx::FlagsDataty
 
     }
 }
+
+impl super::WiggleType for witx::FlagsDatatype {
+    fn impls_display(&self) -> bool {
+        true
+    }
+}
diff --git a/crates/wiggle/generate/src/types/handle.rs b/crates/wiggle/generate/src/types/handle.rs
index c28b77d885..310c9e7d6e 100644
--- a/crates/wiggle/generate/src/types/handle.rs
+++ b/crates/wiggle/generate/src/types/handle.rs
@@ -82,3 +82,9 @@ pub(super) fn define_handle(
 
     }
 }
+
+impl super::WiggleType for witx::HandleDatatype {
+    fn impls_display(&self) -> bool {
+        true
+    }
+}
diff --git a/crates/wiggle/generate/src/types/int.rs b/crates/wiggle/generate/src/types/int.rs
index 43e6997683..d916b65b70 100644
--- a/crates/wiggle/generate/src/types/int.rs
+++ b/crates/wiggle/generate/src/types/int.rs
@@ -92,3 +92,9 @@ pub(super) fn define_int(names: &Names, name: &witx::Id, i: &witx::IntDatatype)
 
     }
 }
+
+impl super::WiggleType for witx::IntDatatype {
+    fn impls_display(&self) -> bool {
+        true
+    }
+}
diff --git a/crates/wiggle/generate/src/types/mod.rs b/crates/wiggle/generate/src/types/mod.rs
index 19b8aa9489..6ed29af94b 100644
--- a/crates/wiggle/generate/src/types/mod.rs
+++ b/crates/wiggle/generate/src/types/mod.rs
@@ -91,3 +91,56 @@ fn atom_token(atom: witx::AtomType) -> TokenStream {
         witx::AtomType::F64 => quote!(f64),
     }
 }
+
+pub trait WiggleType {
+    fn impls_display(&self) -> bool;
+}
+
+impl WiggleType for witx::TypeRef {
+    fn impls_display(&self) -> bool {
+        match self {
+            witx::TypeRef::Name(alias_to) => (&*alias_to).impls_display(),
+            witx::TypeRef::Value(v) => (&*v).impls_display(),
+        }
+    }
+}
+
+impl WiggleType for witx::NamedType {
+    fn impls_display(&self) -> bool {
+        self.tref.impls_display()
+    }
+}
+
+impl WiggleType for witx::Type {
+    fn impls_display(&self) -> bool {
+        match self {
+            witx::Type::Enum(x) => x.impls_display(),
+            witx::Type::Int(x) => x.impls_display(),
+            witx::Type::Flags(x) => x.impls_display(),
+            witx::Type::Struct(x) => x.impls_display(),
+            witx::Type::Union(x) => x.impls_display(),
+            witx::Type::Handle(x) => x.impls_display(),
+            witx::Type::Builtin(x) => x.impls_display(),
+            witx::Type::Pointer { .. }
+            | witx::Type::ConstPointer { .. }
+            | witx::Type::Array { .. } => false,
+        }
+    }
+}
+
+impl WiggleType for witx::BuiltinType {
+    fn impls_display(&self) -> bool {
+        true
+    }
+}
+
+impl WiggleType for witx::InterfaceFuncParam {
+    fn impls_display(&self) -> bool {
+        match &*self.tref.type_() {
+            witx::Type::Struct { .. }
+            | witx::Type::Union { .. }
+            | witx::Type::Builtin(witx::BuiltinType::String { .. }) => false,
+            _ => self.tref.impls_display(),
+        }
+    }
+}
diff --git a/crates/wiggle/generate/src/types/struct.rs b/crates/wiggle/generate/src/types/struct.rs
index 47cd32d1e5..5b3a025904 100644
--- a/crates/wiggle/generate/src/types/struct.rs
+++ b/crates/wiggle/generate/src/types/struct.rs
@@ -133,3 +133,9 @@ pub(super) fn define_struct(
         #transparent
     }
 }
+
+impl super::WiggleType for witx::StructDatatype {
+    fn impls_display(&self) -> bool {
+        false
+    }
+}
diff --git a/crates/wiggle/generate/src/types/union.rs b/crates/wiggle/generate/src/types/union.rs
index 0c357756eb..ecc3253f3c 100644
--- a/crates/wiggle/generate/src/types/union.rs
+++ b/crates/wiggle/generate/src/types/union.rs
@@ -108,3 +108,9 @@ pub(super) fn define_union(names: &Names, name: &witx::Id, u: &witx::UnionDataty
         }
     }
 }
+
+impl super::WiggleType for witx::UnionDatatype {
+    fn impls_display(&self) -> bool {
+        false
+    }
+}
diff --git a/crates/wiggle/macro/src/lib.rs b/crates/wiggle/macro/src/lib.rs
index fced356f34..ed4a3dc6f0 100644
--- a/crates/wiggle/macro/src/lib.rs
+++ b/crates/wiggle/macro/src/lib.rs
@@ -101,7 +101,7 @@ pub fn from_witx(args: TokenStream) -> TokenStream {
     let error_transform = wiggle_generate::ErrorTransform::new(&config.errors, &doc)
         .expect("validating error transform");
 
-    let code = wiggle_generate::generate(&doc, &names, &error_transform, &config.logging);
+    let code = wiggle_generate::generate(&doc, &names, &error_transform);
     let metadata = if cfg!(feature = "wiggle_metadata") {
         wiggle_generate::generate_metadata(&doc, &names)
     } else {
diff --git a/crates/wiggle/src/lib.rs b/crates/wiggle/src/lib.rs
index 000080ad86..9e6e9933fa 100644
--- a/crates/wiggle/src/lib.rs
+++ b/crates/wiggle/src/lib.rs
@@ -15,6 +15,7 @@ mod borrow;
 mod error;
 mod guest_type;
 mod region;
+pub mod tracing;
 
 pub use borrow::BorrowChecker;
 use borrow::BorrowHandle;
diff --git a/crates/wiggle/src/tracing.rs b/crates/wiggle/src/tracing.rs
new file mode 100644
index 0000000000..e9b5c6951d
--- /dev/null
+++ b/crates/wiggle/src/tracing.rs
@@ -0,0 +1,11 @@
+#[cfg(feature = "tracing")]
+pub use tracing_crate::*;
+
+#[cfg(not(feature = "tracing"))]
+mod noop_tracing {
+    // TODO fill in rest of the noop interface
+    // idk how to do this because macro_rules! / #[macro_export] doesn't follow the usual module
+    // visibility rules.
+}
+#[cfg(not(feature = "tracing"))]
+pub use noop_tracing::*;
diff --git a/crates/wiggle/test-helpers/examples/tracing.rs b/crates/wiggle/test-helpers/examples/tracing.rs
new file mode 100644
index 0000000000..d4f929689c
--- /dev/null
+++ b/crates/wiggle/test-helpers/examples/tracing.rs
@@ -0,0 +1,118 @@
+use wiggle_test::{impl_errno, HostMemory, WasiCtx};
+
+/// The `errors` argument to the wiggle gives us a hook to map a rich error
+/// type like this one (typical of wiggle use cases in wasi-common and beyond)
+/// down to the flat error enums that witx can specify.
+#[derive(Debug, thiserror::Error)]
+pub enum RichError {
+    #[error("Invalid argument: {0}")]
+    InvalidArg(String),
+    #[error("Won't cross picket line: {0}")]
+    PicketLine(String),
+}
+
+// Define an errno with variants corresponding to RichError. Use it in a
+// trivial function.
+wiggle::from_witx!({
+witx_literal: "
+(typename $errno (enum u8 $ok $invalid_arg $picket_line))
+(typename $s (struct (field $f1 (@witx usize)) (field $f2 (@witx pointer u8))))
+(typename $t (struct (field $f1 u32) (field $f2 f32)))
+(module $one_error_conversion
+  (@interface func (export \"foo\")
+     (param $strike u32)
+     (param $s $s)
+     (result $err $errno)
+     (result $t $t)))
+    ",
+    ctx: WasiCtx,
+    errors: { errno => RichError },
+});
+
+// The impl of GuestErrorConversion works just like in every other test where
+// we have a single error type with witx `$errno` with the success called `$ok`
+impl_errno!(types::Errno, types::GuestErrorConversion);
+
+/// When the `errors` mapping in witx is non-empty, we need to impl the
+/// types::UserErrorConversion trait that wiggle generates from that mapping.
+impl<'a> types::UserErrorConversion for WasiCtx<'a> {
+    fn errno_from_rich_error(&self, e: RichError) -> types::Errno {
+        wiggle::tracing::debug!(
+            rich_error = wiggle::tracing::field::debug(&e),
+            "error conversion"
+        );
+        // WasiCtx can collect a Vec<String> log so we can test this. We're
+        // logging the Display impl that `thiserror::Error` provides us.
+        self.log.borrow_mut().push(e.to_string());
+        // Then do the trivial mapping down to the flat enum.
+        match e {
+            RichError::InvalidArg { .. } => types::Errno::InvalidArg,
+            RichError::PicketLine { .. } => types::Errno::PicketLine,
+        }
+    }
+}
+
+impl<'a> one_error_conversion::OneErrorConversion for WasiCtx<'a> {
+    fn foo(&self, strike: u32, _s: &types::S) -> Result<types::T, RichError> {
+        // We use the argument to this function to exercise all of the
+        // possible error cases we could hit here
+        match strike {
+            0 => Ok(types::T {
+                f1: 123,
+                f2: 456.78,
+            }),
+            1 => Err(RichError::PicketLine(format!("I'm not a scab"))),
+            _ => Err(RichError::InvalidArg(format!("out-of-bounds: {}", strike))),
+        }
+    }
+}
+
+fn main() {
+    let subscriber = tracing_subscriber::fmt()
+        // all spans/events with a level higher than TRACE (e.g, debug, info, warn, etc.)
+        // will be written to stdout.
+        .with_max_level(tracing::Level::TRACE)
+        // builds the subscriber.
+        .finish();
+
+    tracing::subscriber::with_default(subscriber, || {
+        let ctx = WasiCtx::new();
+        let host_memory = HostMemory::new();
+
+        // Exercise each of the branches in `foo`.
+        // Start with the success case:
+        let r0 = one_error_conversion::foo(&ctx, &host_memory, 0, 0, 8);
+        assert_eq!(
+            r0,
+            i32::from(types::Errno::Ok),
+            "Expected return value for strike=0"
+        );
+        assert!(ctx.log.borrow().is_empty(), "No error log for strike=0");
+
+        // First error case:
+        let r1 = one_error_conversion::foo(&ctx, &host_memory, 1, 0, 8);
+        assert_eq!(
+            r1,
+            i32::from(types::Errno::PicketLine),
+            "Expected return value for strike=1"
+        );
+        assert_eq!(
+            ctx.log.borrow_mut().pop().expect("one log entry"),
+            "Won't cross picket line: I'm not a scab",
+            "Expected log entry for strike=1",
+        );
+
+        // Second error case:
+        let r2 = one_error_conversion::foo(&ctx, &host_memory, 2, 0, 8);
+        assert_eq!(
+            r2,
+            i32::from(types::Errno::InvalidArg),
+            "Expected return value for strike=2"
+        );
+        assert_eq!(
+            ctx.log.borrow_mut().pop().expect("one log entry"),
+            "Invalid argument: out-of-bounds: 2",
+            "Expected log entry for strike=2",
+        );
+    });
+}

From 820b283cf899ea0c890d423d8994d9676f6af6ed Mon Sep 17 00:00:00 2001
From: Pat Hickey <pat@moreproductive.org>
Date: Tue, 2 Jun 2020 15:56:13 -0700
Subject: [PATCH 04/10] can't put tracing behind a feature without an extra
 crate :(

---
 crates/wiggle/Cargo.toml     |  8 ++------
 crates/wiggle/src/lib.rs     |  4 +++-
 crates/wiggle/src/tracing.rs | 11 -----------
 3 files changed, 5 insertions(+), 18 deletions(-)
 delete mode 100644 crates/wiggle/src/tracing.rs

diff --git a/crates/wiggle/Cargo.toml b/crates/wiggle/Cargo.toml
index 07566bb338..b376d8d4b9 100644
--- a/crates/wiggle/Cargo.toml
+++ b/crates/wiggle/Cargo.toml
@@ -14,7 +14,7 @@ include = ["src/**/*", "LICENSE"]
 thiserror = "1"
 witx = { path = "../wasi-common/WASI/tools/witx", version = "0.8.5", optional = true }
 wiggle-macro = { path = "macro", version = "0.17.0" }
-tracing_crate = { version = "0.1.14", optional = true, package = "tracing" }
+tracing = { version = "0.1.14" }
 
 [badges]
 maintenance = { status = "actively-developed" }
@@ -29,9 +29,5 @@ proptest = "0.9"
 # users of wiggle are not forced to take a direct dependency on the `witx`
 # crate unless they want it.
 wiggle_metadata = ['witx', "wiggle-macro/wiggle_metadata"]
-# The wiggle proc-macro emits code which may transitively depend on the
-# `tracing` crate, via `wiggle::tracing`. When this feature is not enabled,
-# a no-op equivelant to the tracing macros is provided instead.
-tracing = [ "tracing_crate" ]
 
-default = ["wiggle_metadata", "tracing"]
+default = ["wiggle_metadata" ]
diff --git a/crates/wiggle/src/lib.rs b/crates/wiggle/src/lib.rs
index 9e6e9933fa..98f31ee171 100644
--- a/crates/wiggle/src/lib.rs
+++ b/crates/wiggle/src/lib.rs
@@ -15,7 +15,9 @@ mod borrow;
 mod error;
 mod guest_type;
 mod region;
-pub mod tracing;
+pub mod tracing {
+    pub use tracing::*;
+}
 
 pub use borrow::BorrowChecker;
 use borrow::BorrowHandle;
diff --git a/crates/wiggle/src/tracing.rs b/crates/wiggle/src/tracing.rs
deleted file mode 100644
index e9b5c6951d..0000000000
--- a/crates/wiggle/src/tracing.rs
+++ /dev/null
@@ -1,11 +0,0 @@
-#[cfg(feature = "tracing")]
-pub use tracing_crate::*;
-
-#[cfg(not(feature = "tracing"))]
-mod noop_tracing {
-    // TODO fill in rest of the noop interface
-    // idk how to do this because macro_rules! / #[macro_export] doesn't follow the usual module
-    // visibility rules.
-}
-#[cfg(not(feature = "tracing"))]
-pub use noop_tracing::*;

From 33a94ca7d5dbff28cb59ffc7542aca7a613ef0b4 Mon Sep 17 00:00:00 2001
From: Pat Hickey <pat@moreproductive.org>
Date: Tue, 2 Jun 2020 16:00:26 -0700
Subject: [PATCH 05/10] just one cargo feature for tracing/log

---
 crates/wiggle/Cargo.toml | 6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/crates/wiggle/Cargo.toml b/crates/wiggle/Cargo.toml
index b376d8d4b9..838e2a42f5 100644
--- a/crates/wiggle/Cargo.toml
+++ b/crates/wiggle/Cargo.toml
@@ -30,4 +30,10 @@ proptest = "0.9"
 # crate unless they want it.
 wiggle_metadata = ['witx', "wiggle-macro/wiggle_metadata"]
 
+# The `tracing` crate can use the `log` ecosystem of backends with this
+# non-default feature. We don't need to provide this by default, but its
+# useful for users that don't want to use `tracing-subscriber` to get
+# the logs out of wiggle-generated libraries.
+tracing_log = [ "tracing/log" ]
+
 default = ["wiggle_metadata" ]

From 1b95b24686b676acb0f1c2cbb6a5d05216a33052 Mon Sep 17 00:00:00 2001
From: Pat Hickey <pat@moreproductive.org>
Date: Tue, 2 Jun 2020 17:46:31 -0700
Subject: [PATCH 06/10] show env_logger working in wiggle tracing example

---
 Cargo.lock                                    |  2 +
 crates/wiggle/test-helpers/Cargo.toml         |  3 +-
 .../wiggle/test-helpers/examples/tracing.rs   | 91 ++++++++++---------
 3 files changed, 52 insertions(+), 44 deletions(-)

diff --git a/Cargo.lock b/Cargo.lock
index 3870242c33..9c284f78f3 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -2113,6 +2113,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "a7c6b59d116d218cb2d990eb06b77b64043e0268ef7323aae63d8b30ae462923"
 dependencies = [
  "cfg-if",
+ "log",
  "tracing-attributes",
  "tracing-core",
 ]
@@ -2656,6 +2657,7 @@ dependencies = [
 name = "wiggle-test"
 version = "0.17.0"
 dependencies = [
+ "env_logger 0.7.1",
  "proptest",
  "thiserror",
  "tracing",
diff --git a/crates/wiggle/test-helpers/Cargo.toml b/crates/wiggle/test-helpers/Cargo.toml
index 71015052c7..181e20aa27 100644
--- a/crates/wiggle/test-helpers/Cargo.toml
+++ b/crates/wiggle/test-helpers/Cargo.toml
@@ -12,12 +12,13 @@ include = ["src/**/*", "LICENSE"]
 
 [dependencies]
 proptest = "0.9"
-wiggle = { path = ".." }
+wiggle = { path = "..", features = ["tracing_log"] }
 
 [dev-dependencies]
 thiserror = "1.0"
 tracing = "0.1.14"
 tracing-subscriber = "0.2.4"
+env_logger="0.7"
 
 
 [badges]
diff --git a/crates/wiggle/test-helpers/examples/tracing.rs b/crates/wiggle/test-helpers/examples/tracing.rs
index d4f929689c..ac58e0d518 100644
--- a/crates/wiggle/test-helpers/examples/tracing.rs
+++ b/crates/wiggle/test-helpers/examples/tracing.rs
@@ -68,51 +68,56 @@ impl<'a> one_error_conversion::OneErrorConversion for WasiCtx<'a> {
 }
 
 fn main() {
-    let subscriber = tracing_subscriber::fmt()
-        // all spans/events with a level higher than TRACE (e.g, debug, info, warn, etc.)
-        // will be written to stdout.
-        .with_max_level(tracing::Level::TRACE)
-        // builds the subscriber.
-        .finish();
+    if std::env::var("RUST_LOG").is_err() {
+        // with no RUST_LOG env variable: use the tracing subscriber.
+        let subscriber = tracing_subscriber::fmt()
+            // all spans/events with a level higher than TRACE (e.g, debug, info, warn, etc.)
+            // will be written to stdout.
+            .with_max_level(tracing::Level::TRACE)
+            // builds the subscriber.
+            .finish();
+        tracing::subscriber::set_global_default(subscriber).expect("set global tracing subscriber");
+    } else {
+        // with RUST_LOG set: use the env_logger backend to tracing.
+        env_logger::init();
+    }
 
-    tracing::subscriber::with_default(subscriber, || {
-        let ctx = WasiCtx::new();
-        let host_memory = HostMemory::new();
+    let ctx = WasiCtx::new();
+    let host_memory = HostMemory::new();
 
-        // Exercise each of the branches in `foo`.
-        // Start with the success case:
-        let r0 = one_error_conversion::foo(&ctx, &host_memory, 0, 0, 8);
-        assert_eq!(
-            r0,
-            i32::from(types::Errno::Ok),
-            "Expected return value for strike=0"
-        );
-        assert!(ctx.log.borrow().is_empty(), "No error log for strike=0");
+    // Exercise each of the branches in `foo`.
+    // Start with the success case:
+    let r0 = one_error_conversion::foo(&ctx, &host_memory, 0, 0, 8);
+    assert_eq!(
+        r0,
+        i32::from(types::Errno::Ok),
+        "Expected return value for strike=0"
+    );
+    assert!(ctx.log.borrow().is_empty(), "No error log for strike=0");
 
-        // First error case:
-        let r1 = one_error_conversion::foo(&ctx, &host_memory, 1, 0, 8);
-        assert_eq!(
-            r1,
-            i32::from(types::Errno::PicketLine),
-            "Expected return value for strike=1"
-        );
-        assert_eq!(
-            ctx.log.borrow_mut().pop().expect("one log entry"),
-            "Won't cross picket line: I'm not a scab",
-            "Expected log entry for strike=1",
-        );
+    // First error case:
+    let r1 = one_error_conversion::foo(&ctx, &host_memory, 1, 0, 8);
+    assert_eq!(
+        r1,
+        i32::from(types::Errno::PicketLine),
+        "Expected return value for strike=1"
+    );
+    assert_eq!(
+        ctx.log.borrow_mut().pop().expect("one log entry"),
+        "Won't cross picket line: I'm not a scab",
+        "Expected log entry for strike=1",
+    );
 
-        // Second error case:
-        let r2 = one_error_conversion::foo(&ctx, &host_memory, 2, 0, 8);
-        assert_eq!(
-            r2,
-            i32::from(types::Errno::InvalidArg),
-            "Expected return value for strike=2"
-        );
-        assert_eq!(
-            ctx.log.borrow_mut().pop().expect("one log entry"),
-            "Invalid argument: out-of-bounds: 2",
-            "Expected log entry for strike=2",
-        );
-    });
+    // Second error case:
+    let r2 = one_error_conversion::foo(&ctx, &host_memory, 2, 0, 8);
+    assert_eq!(
+        r2,
+        i32::from(types::Errno::InvalidArg),
+        "Expected return value for strike=2"
+    );
+    assert_eq!(
+        ctx.log.borrow_mut().pop().expect("one log entry"),
+        "Invalid argument: out-of-bounds: 2",
+        "Expected log entry for strike=2",
+    );
 }

From dcb774a35e38eb9f042d4952b77a1da79e06b418 Mon Sep 17 00:00:00 2001
From: Pat Hickey <pat@moreproductive.org>
Date: Tue, 2 Jun 2020 18:25:40 -0700
Subject: [PATCH 07/10] temporarily use tracing from git

---
 Cargo.lock                    | 44 ++++++++++++++++++++++++++++-------
 crates/wasi-common/Cargo.toml |  8 +++----
 crates/wiggle/Cargo.toml      |  2 +-
 3 files changed, 41 insertions(+), 13 deletions(-)

diff --git a/Cargo.lock b/Cargo.lock
index 9c284f78f3..d462922d80 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -2106,6 +2106,17 @@ dependencies = [
  "serde",
 ]
 
+[[package]]
+name = "tracing"
+version = "0.1.14"
+source = "git+https://github.com/tokio-rs/tracing#180e494c7a13c0a18c09f3c7b465e8734c51f5e2"
+dependencies = [
+ "cfg-if",
+ "log",
+ "tracing-attributes 0.1.8 (git+https://github.com/tokio-rs/tracing)",
+ "tracing-core 0.1.10 (git+https://github.com/tokio-rs/tracing)",
+]
+
 [[package]]
 name = "tracing"
 version = "0.1.14"
@@ -2113,9 +2124,18 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "a7c6b59d116d218cb2d990eb06b77b64043e0268ef7323aae63d8b30ae462923"
 dependencies = [
  "cfg-if",
- "log",
- "tracing-attributes",
- "tracing-core",
+ "tracing-attributes 0.1.8 (registry+https://github.com/rust-lang/crates.io-index)",
+ "tracing-core 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)",
+]
+
+[[package]]
+name = "tracing-attributes"
+version = "0.1.8"
+source = "git+https://github.com/tokio-rs/tracing#180e494c7a13c0a18c09f3c7b465e8734c51f5e2"
+dependencies = [
+ "proc-macro2",
+ "quote",
+ "syn",
 ]
 
 [[package]]
@@ -2129,6 +2149,14 @@ dependencies = [
  "syn",
 ]
 
+[[package]]
+name = "tracing-core"
+version = "0.1.10"
+source = "git+https://github.com/tokio-rs/tracing#180e494c7a13c0a18c09f3c7b465e8734c51f5e2"
+dependencies = [
+ "lazy_static",
+]
+
 [[package]]
 name = "tracing-core"
 version = "0.1.10"
@@ -2146,7 +2174,7 @@ checksum = "5e0f8c7178e13481ff6765bd169b33e8d554c5d2bbede5e32c356194be02b9b9"
 dependencies = [
  "lazy_static",
  "log",
- "tracing-core",
+ "tracing-core 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)",
 ]
 
 [[package]]
@@ -2156,7 +2184,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "b6ccba2f8f16e0ed268fc765d9b7ff22e965e7185d32f8f1ec8294fe17d86e79"
 dependencies = [
  "serde",
- "tracing-core",
+ "tracing-core 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)",
 ]
 
 [[package]]
@@ -2174,7 +2202,7 @@ dependencies = [
  "serde_json",
  "sharded-slab",
  "smallvec",
- "tracing-core",
+ "tracing-core 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)",
  "tracing-log",
  "tracing-serde",
 ]
@@ -2624,7 +2652,7 @@ version = "0.17.0"
 dependencies = [
  "proptest",
  "thiserror",
- "tracing",
+ "tracing 0.1.14 (git+https://github.com/tokio-rs/tracing)",
  "wiggle-macro",
  "wiggle-test",
  "witx",
@@ -2660,7 +2688,7 @@ dependencies = [
  "env_logger 0.7.1",
  "proptest",
  "thiserror",
- "tracing",
+ "tracing 0.1.14 (registry+https://github.com/rust-lang/crates.io-index)",
  "tracing-subscriber",
  "wiggle",
 ]
diff --git a/crates/wasi-common/Cargo.toml b/crates/wasi-common/Cargo.toml
index c24127a33d..9a8f46db3e 100644
--- a/crates/wasi-common/Cargo.toml
+++ b/crates/wasi-common/Cargo.toml
@@ -41,10 +41,10 @@ maintenance = { status = "actively-developed" }
 
 [features]
 default = ["trace_log"]
-# This feature enables `log::trace` calls in syscalls shims, in effect
-# emulating something like `strace`. This feature is an opt-out and hence
-# enabled by default.
-trace_log = []
+# This feature enables the `tracing` logs in the calls to target the `log`
+# ecosystem of backends (e.g. `env_logger`. Disable this if you want to use
+# `tracing-subscriber`.
+trace_log = [ "wiggle/tracing_log" ]
 # Need to make the wiggle_metadata feature available to consumers of this
 # crate if they want the snapshots to have metadata available.
 wiggle_metadata = ["wiggle/wiggle_metadata"]
diff --git a/crates/wiggle/Cargo.toml b/crates/wiggle/Cargo.toml
index 838e2a42f5..7168c568f2 100644
--- a/crates/wiggle/Cargo.toml
+++ b/crates/wiggle/Cargo.toml
@@ -14,7 +14,7 @@ include = ["src/**/*", "LICENSE"]
 thiserror = "1"
 witx = { path = "../wasi-common/WASI/tools/witx", version = "0.8.5", optional = true }
 wiggle-macro = { path = "macro", version = "0.17.0" }
-tracing = { version = "0.1.14" }
+tracing = {  git = "https://github.com/tokio-rs/tracing" }
 
 [badges]
 maintenance = { status = "actively-developed" }

From 220733b974cffae988afef559b6e860aa9477c83 Mon Sep 17 00:00:00 2001
From: Pat Hickey <pat@moreproductive.org>
Date: Tue, 2 Jun 2020 18:41:53 -0700
Subject: [PATCH 08/10] wiggle-generate: add an `empty` constructor to
 ErrorTransform

some library users (me, in lucet-wasi) may not care about ErrorTransform YET
---
 crates/wiggle/generate/src/error_transform.rs | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/crates/wiggle/generate/src/error_transform.rs b/crates/wiggle/generate/src/error_transform.rs
index 80cb56f925..3598e221de 100644
--- a/crates/wiggle/generate/src/error_transform.rs
+++ b/crates/wiggle/generate/src/error_transform.rs
@@ -11,6 +11,9 @@ pub struct ErrorTransform {
 }
 
 impl ErrorTransform {
+    pub fn empty() -> Self {
+        Self { m: Vec::new() }
+    }
     pub fn new(conf: &ErrorConf, doc: &Document) -> Result<Self, Error> {
         let mut richtype_identifiers = HashMap::new();
         let m = conf.iter().map(|(ident, field)|

From 6910c1e03d5cdfee8c5b23de3de6b71a55466df6 Mon Sep 17 00:00:00 2001
From: Pat Hickey <pat@moreproductive.org>
Date: Wed, 3 Jun 2020 10:52:05 -0700
Subject: [PATCH 09/10] use tracing 0.1.15 release

---
 Cargo.lock               | 48 +++++++++-------------------------------
 crates/wiggle/Cargo.toml |  2 +-
 2 files changed, 11 insertions(+), 39 deletions(-)

diff --git a/Cargo.lock b/Cargo.lock
index d462922d80..902b7be644 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -2108,34 +2108,14 @@ dependencies = [
 
 [[package]]
 name = "tracing"
-version = "0.1.14"
-source = "git+https://github.com/tokio-rs/tracing#180e494c7a13c0a18c09f3c7b465e8734c51f5e2"
+version = "0.1.15"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "a41f40ed0e162c911ac6fcb53ecdc8134c46905fdbbae8c50add462a538b495f"
 dependencies = [
  "cfg-if",
  "log",
- "tracing-attributes 0.1.8 (git+https://github.com/tokio-rs/tracing)",
- "tracing-core 0.1.10 (git+https://github.com/tokio-rs/tracing)",
-]
-
-[[package]]
-name = "tracing"
-version = "0.1.14"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "a7c6b59d116d218cb2d990eb06b77b64043e0268ef7323aae63d8b30ae462923"
-dependencies = [
- "cfg-if",
- "tracing-attributes 0.1.8 (registry+https://github.com/rust-lang/crates.io-index)",
- "tracing-core 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)",
-]
-
-[[package]]
-name = "tracing-attributes"
-version = "0.1.8"
-source = "git+https://github.com/tokio-rs/tracing#180e494c7a13c0a18c09f3c7b465e8734c51f5e2"
-dependencies = [
- "proc-macro2",
- "quote",
- "syn",
+ "tracing-attributes",
+ "tracing-core",
 ]
 
 [[package]]
@@ -2149,14 +2129,6 @@ dependencies = [
  "syn",
 ]
 
-[[package]]
-name = "tracing-core"
-version = "0.1.10"
-source = "git+https://github.com/tokio-rs/tracing#180e494c7a13c0a18c09f3c7b465e8734c51f5e2"
-dependencies = [
- "lazy_static",
-]
-
 [[package]]
 name = "tracing-core"
 version = "0.1.10"
@@ -2174,7 +2146,7 @@ checksum = "5e0f8c7178e13481ff6765bd169b33e8d554c5d2bbede5e32c356194be02b9b9"
 dependencies = [
  "lazy_static",
  "log",
- "tracing-core 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)",
+ "tracing-core",
 ]
 
 [[package]]
@@ -2184,7 +2156,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "b6ccba2f8f16e0ed268fc765d9b7ff22e965e7185d32f8f1ec8294fe17d86e79"
 dependencies = [
  "serde",
- "tracing-core 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)",
+ "tracing-core",
 ]
 
 [[package]]
@@ -2202,7 +2174,7 @@ dependencies = [
  "serde_json",
  "sharded-slab",
  "smallvec",
- "tracing-core 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)",
+ "tracing-core",
  "tracing-log",
  "tracing-serde",
 ]
@@ -2652,7 +2624,7 @@ version = "0.17.0"
 dependencies = [
  "proptest",
  "thiserror",
- "tracing 0.1.14 (git+https://github.com/tokio-rs/tracing)",
+ "tracing",
  "wiggle-macro",
  "wiggle-test",
  "witx",
@@ -2688,7 +2660,7 @@ dependencies = [
  "env_logger 0.7.1",
  "proptest",
  "thiserror",
- "tracing 0.1.14 (registry+https://github.com/rust-lang/crates.io-index)",
+ "tracing",
  "tracing-subscriber",
  "wiggle",
 ]
diff --git a/crates/wiggle/Cargo.toml b/crates/wiggle/Cargo.toml
index 7168c568f2..55a4ceabb9 100644
--- a/crates/wiggle/Cargo.toml
+++ b/crates/wiggle/Cargo.toml
@@ -14,7 +14,7 @@ include = ["src/**/*", "LICENSE"]
 thiserror = "1"
 witx = { path = "../wasi-common/WASI/tools/witx", version = "0.8.5", optional = true }
 wiggle-macro = { path = "macro", version = "0.17.0" }
-tracing = {  git = "https://github.com/tokio-rs/tracing" }
+tracing = "0.1.15"
 
 [badges]
 maintenance = { status = "actively-developed" }

From 0fb374947a91c0462fb4a6d301124b7c58337535 Mon Sep 17 00:00:00 2001
From: Pat Hickey <pat@moreproductive.org>
Date: Wed, 3 Jun 2020 15:35:53 -0700
Subject: [PATCH 10/10] code review comments

---
 Cargo.lock                                     | 2 +-
 crates/wiggle/src/lib.rs                       | 5 ++---
 crates/wiggle/test-helpers/Cargo.toml          | 2 +-
 crates/wiggle/test-helpers/examples/tracing.rs | 2 +-
 4 files changed, 5 insertions(+), 6 deletions(-)

diff --git a/Cargo.lock b/Cargo.lock
index 902b7be644..ec84f1d5af 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -2657,7 +2657,7 @@ dependencies = [
 name = "wiggle-test"
 version = "0.17.0"
 dependencies = [
- "env_logger 0.7.1",
+ "env_logger",
  "proptest",
  "thiserror",
  "tracing",
diff --git a/crates/wiggle/src/lib.rs b/crates/wiggle/src/lib.rs
index 98f31ee171..cbc92f2662 100644
--- a/crates/wiggle/src/lib.rs
+++ b/crates/wiggle/src/lib.rs
@@ -15,9 +15,8 @@ mod borrow;
 mod error;
 mod guest_type;
 mod region;
-pub mod tracing {
-    pub use tracing::*;
-}
+
+pub extern crate tracing;
 
 pub use borrow::BorrowChecker;
 use borrow::BorrowHandle;
diff --git a/crates/wiggle/test-helpers/Cargo.toml b/crates/wiggle/test-helpers/Cargo.toml
index 181e20aa27..0df67f8624 100644
--- a/crates/wiggle/test-helpers/Cargo.toml
+++ b/crates/wiggle/test-helpers/Cargo.toml
@@ -18,7 +18,7 @@ wiggle = { path = "..", features = ["tracing_log"] }
 thiserror = "1.0"
 tracing = "0.1.14"
 tracing-subscriber = "0.2.4"
-env_logger="0.7"
+env_logger = "0.7"
 
 
 [badges]
diff --git a/crates/wiggle/test-helpers/examples/tracing.rs b/crates/wiggle/test-helpers/examples/tracing.rs
index ac58e0d518..5b7eeb8183 100644
--- a/crates/wiggle/test-helpers/examples/tracing.rs
+++ b/crates/wiggle/test-helpers/examples/tracing.rs
@@ -71,7 +71,7 @@ fn main() {
     if std::env::var("RUST_LOG").is_err() {
         // with no RUST_LOG env variable: use the tracing subscriber.
         let subscriber = tracing_subscriber::fmt()
-            // all spans/events with a level higher than TRACE (e.g, debug, info, warn, etc.)
+            // all spans/events with a level equal to or higher than TRACE (e.g, trace, debug, info, warn, etc.)
             // will be written to stdout.
             .with_max_level(tracing::Level::TRACE)
             // builds the subscriber.