runtime attributes

yoshuawuyts · yoshuawuyts · commit ba1b99e1710d · 2019-06-28T18:10:18.000+02:00
Signed-off-by: Yoshua Wuyts &lt;yoshuawuyts@gmail.com&gt;
diff --git a/Cargo.toml b/Cargo.toml
@@ -14,6 +14,13 @@ edition = "2018"
 [dependencies]
 log = "0.4.6"
 backtrace = "0.3.30"
+async-log-attributes = { path = "async-log-attributes" }
 
 [dev-dependencies]
 env_logger = "0.6.1"
+
+[workspace]
+members = [
+  ".",
+  "async-log-attributes",
+]
diff --git a/README.md b/README.md
@@ -2,7 +2,9 @@
 [![crates.io version][1]][2] [![build status][3]][4]
 [![downloads][5]][6] [![docs.rs docs][7]][8]
 
-Async tracing capabilities for the log crate.
+Async tracing capabilities for the standard [`log`] crate.
+
+[`log`]: https://docs.rs/log
 
 - [Documentation][8]
 - [Crates.io][2]
@@ -11,7 +13,32 @@ Async tracing capabilities for the log crate.
 ## Examples
 __Basic usage__
 ```rust
-// tbi
+use async_log::span;
+use log::info;
+
+fn setup_logger() {
+    let logger = env_logger::Builder::new()
+        .filter(None, log::LevelFilter::Trace)
+        .build();
+
+    async_log::Logger::wrap(logger, || 12)
+        .start(log::LevelFilter::Trace)
+        .unwrap();
+}
+
+fn main() {
+    setup_logger();
+
+    span!("level I", {
+        let x = "beep";
+        info!("look at this value, x={}", x);
+
+        span!("level II", {
+            let y = "boop";
+            info!("another nice value, y={}", y);
+        })
+    })
+}
 ```
 
 ## Installation
diff --git a/async-log-attributes/Cargo.toml b/async-log-attributes/Cargo.toml
@@ -0,0 +1,21 @@
+[package]
+name = "async-log-attributes"
+description = "Proc Macro attributes for the async-log crate."
+version = "0.3.0-alpha.4"
+license = "MIT OR Apache-2.0"
+readme = "README.md"
+repository = "https://github.com/rustasync/runtime"
+homepage = "https://github.com/rustasync/runtime"
+documentation = "https://docs.rs/runtime-attributes"
+authors = ["The Rust Async Ecosystem Working Group"]
+keywords = ["async", "log", "trace", "span", "macro"]
+categories = ["asynchronous", "command-line-utilities", "development-tools", "text-processing", "web-programming"]
+edition = "2018"
+
+[lib]
+proc-macro = true
+
+[dependencies]
+syn = { version = "0.15.33", features = ["full"] }
+proc-macro2 = { version = "0.4.29", features = ["nightly"] }
+quote = "0.6.12"
diff --git a/async-log-attributes/README.md b/async-log-attributes/README.md
@@ -0,0 +1,47 @@
+# runtime-attributes
+Proc Macro attributes for the [Runtime](https://github.com/rustasync/runtime) crate. See the
+[Runtime](https://docs.rs/runtime) documentation for more details.
+
+__This macro was designed to be used from the Runtime crate. Using this in any other way is unlikely
+to work.__
+
+## Installation
+With [cargo-edit](https://crates.io/crates/cargo-edit) do:
+```sh
+$ cargo add runtime-attributes
+```
+
+## Safety
+This crate uses ``#![deny(unsafe_code)]`` to ensure everything is implemented in 100% Safe Rust.
+
+## Contributing
+Want to join us? Check out our [The "Contributing" section of the
+guide][contributing] and take a look at some of these issues:
+
+- [Issues labeled "good first issue"][good-first-issue]
+- [Issues labeled "help wanted"][help-wanted]
+
+#### Conduct
+
+The Runtime project adheres to the [Contributor Covenant Code of
+Conduct](https://github.com/rustasync/runtime/blob/master/.github/CODE_OF_CONDUCT.md).  This
+describes the minimum behavior expected from all contributors.
+
+## License
+Licensed under either of
+
+ * Apache License, Version 2.0 ([LICENSE-APACHE](../LICENSE-APACHE) or http://www.apache.org/licenses/LICENSE-2.0)
+ * MIT license ([LICENSE-MIT](../LICENSE-MIT) or http://opensource.org/licenses/MIT)
+
+at your option.
+
+#### Contribution
+
+Unless you explicitly state otherwise, any contribution intentionally submitted
+for inclusion in the work by you, as defined in the Apache-2.0 license, shall be
+dual licensed as above, without any additional terms or conditions.
+
+[releases]: https://github.com/rustasync/runtime/releases
+[contributing]: https://github.com/rustasync/runtime/blob/master/.github/CONTRIBUTING.md
+[good-first-issue]: https://github.com/rustasync/runtime/labels/good%20first%20issue
+[help-wanted]: https://github.com/rustasync/runtime/labels/help%20wanted
diff --git a/async-log-attributes/src/lib.rs b/async-log-attributes/src/lib.rs
@@ -0,0 +1,79 @@
+//! Proc Macro attributes for the [Runtime](https://github.com/rustasync/runtime) crate. See the
+//! [Runtime](https://docs.rs/runtime) documentation for more details.
+
+#![forbid(unsafe_code, future_incompatible, rust_2018_idioms)]
+#![deny(missing_debug_implementations, nonstandard_style)]
+#![feature(async_await)]
+#![recursion_limit = "512"]
+
+extern crate proc_macro;
+
+use proc_macro::TokenStream;
+use quote::quote;
+
+/// Defines the async main function.
+///
+/// # Examples
+///
+/// ```ignore
+/// #[span]
+/// async fn main() -> std::io::Result<()> {
+///     Ok(())
+/// }
+/// ```
+#[cfg(not(test))] // NOTE: exporting main breaks tests, we should file an issue.
+#[proc_macro_attribute]
+pub fn span_wrap(_attr: TokenStream, item: TokenStream) -> TokenStream {
+    let input = syn::parse_macro_input!(item as syn::ItemFn);
+
+    let attrs = &input.attrs;
+    let vis = &input.vis;
+    let constness = &input.constness;
+    let unsafety = &input.unsafety;
+    let asyncness = &input.asyncness;
+    let abi = &input.abi;
+
+    let generics = &input.decl.generics;
+    let name = &input.ident;
+    let inputs = &input.decl.inputs;
+    let output = &input.decl.output;
+    let body = &input.block.stmts;
+
+    let args: Vec<syn::Pat> = inputs
+        .pairs()
+        .filter_map(|pair| match pair.into_value() {
+            syn::FnArg::Captured(arg) => Some(arg.pat.clone()),
+            _ => return None,
+        })
+        .collect();
+
+    let names: String = args
+        .iter()
+        .enumerate()
+        .map(|(i, _arg)| match i {
+            0 => {
+                let mut string = format!("arg_{}", 0);
+                string.push_str("={}");
+                string
+            }
+            n => {
+                let mut string = format!(", arg_{}", n);
+                string.push_str("={}");
+                string
+            }
+        })
+        .collect();
+
+    let result = quote! {
+        #(#attrs)*
+        #vis #constness #unsafety #asyncness #abi fn #generics #name(#(#inputs)*) #output {
+            let __name = format!("{}#{}", file!(), stringify!(#name));
+            let __args = format!("{} {}", __name, format_args!(#names, #(#args)*));
+            async_log::span!(__args, {
+                #(#body)*
+            })
+        }
+    };
+
+    result.into()
+}
diff --git a/examples/trace.rs b/examples/trace.rs
@@ -6,20 +6,25 @@ fn setup_logger() {
         .filter(None, log::LevelFilter::Trace)
         .build();
 
-    async_log::Logger::wrap(logger, || 12)
+    async_log::Logger::wrap(logger, || /* get the task id here */ 0)
         .start(log::LevelFilter::Trace)
         .unwrap();
 }
 
 fn main() {
     setup_logger();
 
-    span!("main", {
-        let x = "foo";
-        info!("this {}", x);
+    span!("new level, depth={}", 1, {
+        let x = "beep";
+        info!("look at this value, x={}", x);
 
-        span!("inner, x={}", x, {
-            info!("we must go deeper {}", x);
+        span!("new level, depth={}", 2, {
+            inner("boop");
         })
     })
 }
+
+#[async_log::span_wrap]
+fn inner(y: &str) {
+    info!("another nice value, y={}", y);
+}
diff --git a/src/lib.rs b/src/lib.rs
@@ -1,4 +1,4 @@
-//! Async tracing capabilities for [`log`].
+//! Async tracing capabilities for the standard [`log`] crate.
 //!
 //! [`log`]: https://docs.rs/log
 //!
@@ -51,10 +51,15 @@
 //!
 //! __example__
 //! ```txt
-//! runtime::fs::read_to_string, span_mark=start, path=/tmp/foob, task_id=7, parent_id=5, thread_id=8
-//! runtime::fs::read_to_string, span_mark=end, path=/tmp/foob, task_id=7, parent_id=5, thread_id=8
+//! runtime::fs::read_to_string, span_mark=start, path=/tmp/foob, task_id=7, thread_id=8
+//! runtime::fs::read_to_string, span_mark=end, path=/tmp/foob, task_id=7, thread_id=8
 //! ```
 //!
+//! ## Why build on the log crate?
+//! [`log`](https://docs.rs/log/) is Rust's standard log crate. It's incredibly flexible, and was
+//! built with extensibility in mind. Because it's so widely used, being able to extend it allows
+//! us to add tracing data to crates without needing to make any changes to their `log!` calls.
+//!
 //! ## Formatting
 //! Structured logging (key-value logging) is [currently in the
 //! process](https://github.com/rust-lang-nursery/log/issues/328) of being added to `log`.
@@ -81,21 +86,22 @@
 //!         .filter(None, log::LevelFilter::Trace)
 //!         .build();
 //!
-//!     async_log::Logger::wrap(logger, || (12, Some(13)))
+//!     async_log::Logger::wrap(logger, || 12)
 //!         .start(log::LevelFilter::Trace)
 //!         .unwrap();
 //! }
 //!
 //! fn main() {
 //!     setup_logger();
 //!
-//!     span!("main", {
-//!         let x = "foo";
-//!         info!("this {}", x);
+//!     span!("new level, depth={}", 1, {
+//!         let x = "beep";
+//!         info!("look at this value, x={}", x);
 //!
-//!         span!("inner, x={}", x, {
-//!             info!("we must go deeper {}", x);
-//!         });
+//!         span!("new level, depth={}", 2, {
+//!             let y = "boop";
+//!             info!("another nice value, y={}", y);
+//!         })
 //!     })
 //! }
 //! ```
@@ -105,6 +111,8 @@
 #![warn(missing_docs, missing_doc_code_examples, unreachable_pub)]
 #![cfg_attr(test, deny(warnings))]
 
+pub use async_log_attributes::span_wrap;
+
 mod backtrace;
 mod logger;
 mod macros;
diff --git a/src/logger.rs b/src/logger.rs
@@ -1,5 +1,5 @@
 use crate::backtrace::async_log_capture_caller;
-use log::{LevelFilter, Log, Metadata, Record};
+use log::{LevelFilter, Log, Metadata, Record, set_boxed_logger};
 
 use std::thread;
 
@@ -32,7 +32,7 @@ where
 
     /// Start logging.
     pub fn start(self, filter: LevelFilter) -> Result<(), log::SetLoggerError> {
-        let res = log::set_boxed_logger(Box::new(self));
+        let res = set_boxed_logger(Box::new(self));
         if res.is_ok() {
             log::set_max_level(filter);
         }
@@ -77,7 +77,7 @@ where
             let thread_id = format!(", thread_id={}", thread_id());
             let task_id = format!(", task_id={}", curr_id);
 
-            let (line, filename) = if self.backtrace {
+            let (line, filename, fn_name) = if self.backtrace {
                 match symbol {
                     Some(symbol) => {
                         let line = symbol
@@ -90,24 +90,29 @@ where
                             .map(|f| format!(", filename={}", f.to_string_lossy()))
                             .unwrap_or_else(|| String::from(""));
 
-                        (line, filename)
+                        let fn_name = symbol
+                            .name
+                            .map(|l| format!(", fn_name={}", l))
+                            .unwrap_or_else(|| String::from(""));
+
+                        (line, filename, fn_name)
                     }
-                    None => (String::from(""), String::from("")),
+                    None => (String::from(""), String::from(""), String::from("")),
                 }
             } else {
-                (String::from(""), String::from(""))
+                (String::from(""), String::from(""), String::from(""))
             };
 
             // This is done this way b/c `Record` + `format_args` needs to be built inline. See:
             // https://stackoverflow.com/q/56304313/1541707
             self.logger.log(
                 &log::Record::builder()
-                    .args(record.args().clone())
                     .args(format_args!(
-                        "{}{}{}{}{}",
+                        "{}{}{}{}{}{}",
                         record.args(),
                         filename,
                         line,
+                        fn_name,
                         task_id,
                         thread_id
                     ))
