From eccd0ea8260e88f0641a7a0eb78f32e7c1c95fd6 Mon Sep 17 00:00:00 2001
From: Hirochika Matsumoto <git@hkmatsumoto.com>
Date: Sun, 14 Nov 2021 19:59:35 +0900
Subject: [PATCH 01/14] attributes: implement `#[instrument(ret)]`

## Motivation

Currently, users have to explicitly call logging functions at the end of
functions if they wanted to record values being returned. For example,
```rust
fn increment(a: i32) -> i32 {
    let succ = a + 1;
    tracing::debug!(?succ);
    succ
}
```
The code above will be significantly simpler if we provide the
functionality to record returned values.

## Solution

This PR adds the exact feature we're talking here, which enables users
to write the code below instead.
```rust
#[instrument(ret)]
fn increment(a: i32) -> i32 {
    a + 1
}
```
---
 tracing-attributes/src/attr.rs   |  26 +++---
 tracing-attributes/src/expand.rs |  86 ++++++++++++++-----
 tracing-attributes/tests/ret.rs  | 140 +++++++++++++++++++++++++++++++
 3 files changed, 220 insertions(+), 32 deletions(-)
 create mode 100644 tracing-attributes/tests/ret.rs

diff --git a/tracing-attributes/src/attr.rs b/tracing-attributes/src/attr.rs
index 0f429156cc..d8025ddf2b 100644
--- a/tracing-attributes/src/attr.rs
+++ b/tracing-attributes/src/attr.rs
@@ -13,7 +13,8 @@ pub(crate) struct InstrumentArgs {
     target: Option<LitStr>,
     pub(crate) skips: HashSet<Ident>,
     pub(crate) fields: Option<Fields>,
-    pub(crate) err_mode: Option<ErrorMode>,
+    pub(crate) err_mode: Option<FormatMode>,
+    pub(crate) ret_mode: Option<FormatMode>,
     /// Errors describing any unrecognized parse inputs that we skipped.
     parse_warnings: Vec<syn::Error>,
 }
@@ -139,8 +140,12 @@ impl Parse for InstrumentArgs {
                 args.fields = Some(input.parse()?);
             } else if lookahead.peek(kw::err) {
                 let _ = input.parse::<kw::err>();
-                let mode = ErrorMode::parse(input)?;
+                let mode = FormatMode::parse(input)?;
                 args.err_mode = Some(mode);
+            } else if lookahead.peek(kw::ret) {
+                let _ = input.parse::<kw::ret>()?;
+                let mode = FormatMode::parse(input)?;
+                args.ret_mode = Some(mode);
             } else if lookahead.peek(Token![,]) {
                 let _ = input.parse::<Token![,]>()?;
             } else {
@@ -199,29 +204,29 @@ impl Parse for Skips {
 }
 
 #[derive(Clone, Debug, Hash, PartialEq, Eq)]
-pub(crate) enum ErrorMode {
+pub(crate) enum FormatMode {
     Display,
     Debug,
 }
 
-impl Default for ErrorMode {
+impl Default for FormatMode {
     fn default() -> Self {
-        ErrorMode::Display
+        FormatMode::Display
     }
 }
 
-impl Parse for ErrorMode {
+impl Parse for FormatMode {
     fn parse(input: ParseStream<'_>) -> syn::Result<Self> {
         if !input.peek(syn::token::Paren) {
-            return Ok(ErrorMode::default());
+            return Ok(FormatMode::default());
         }
         let content;
         let _ = syn::parenthesized!(content in input);
         let maybe_mode: Option<Ident> = content.parse()?;
-        maybe_mode.map_or(Ok(ErrorMode::default()), |ident| {
+        maybe_mode.map_or(Ok(FormatMode::default()), |ident| {
             match ident.to_string().as_str() {
-                "Debug" => Ok(ErrorMode::Debug),
-                "Display" => Ok(ErrorMode::Display),
+                "Debug" => Ok(FormatMode::Debug),
+                "Display" => Ok(FormatMode::Display),
                 _ => Err(syn::Error::new(
                     ident.span(),
                     "unknown error mode, must be Debug or Display",
@@ -356,4 +361,5 @@ mod kw {
     syn::custom_keyword!(target);
     syn::custom_keyword!(name);
     syn::custom_keyword!(err);
+    syn::custom_keyword!(ret);
 }
diff --git a/tracing-attributes/src/expand.rs b/tracing-attributes/src/expand.rs
index d5f031de23..802e817ea0 100644
--- a/tracing-attributes/src/expand.rs
+++ b/tracing-attributes/src/expand.rs
@@ -9,7 +9,7 @@ use syn::{
 };
 
 use crate::{
-    attr::{ErrorMode, Field, Fields, InstrumentArgs},
+    attr::{Field, Fields, FormatMode, InstrumentArgs},
     MaybeItemFnRef,
 };
 
@@ -191,8 +191,14 @@ fn gen_block<B: ToTokens>(
     })();
 
     let err_event = match args.err_mode {
-        Some(ErrorMode::Display) => Some(quote!(tracing::error!(error = %e))),
-        Some(ErrorMode::Debug) => Some(quote!(tracing::error!(error = ?e))),
+        Some(FormatMode::Display) => Some(quote!(tracing::error!(error = %e))),
+        Some(FormatMode::Debug) => Some(quote!(tracing::error!(error = ?e))),
+        _ => None,
+    };
+
+    let ret_event = match args.ret_mode {
+        Some(FormatMode::Display) => Some(quote!(tracing::trace!(return = %#block))),
+        Some(FormatMode::Debug) => Some(quote!(tracing::trace!(return = ?#block))),
         _ => None,
     };
 
@@ -202,8 +208,21 @@ fn gen_block<B: ToTokens>(
     // enter the span and then perform the rest of the body.
     // If `err` is in args, instrument any resulting `Err`s.
     if async_context {
-        let mk_fut = match err_event {
-            Some(err_event) => quote_spanned!(block.span()=>
+        let mk_fut = match (err_event, ret_event) {
+            (Some(err_event), Some(ret_event)) => quote_spanned!(block.span()=>
+                async move {
+                    #ret_event;
+                    match async move { #block }.await {
+                        #[allow(clippy::unit_arg)]
+                        Ok(x) => Ok(x),
+                        Err(e) => {
+                            #err_event;
+                            Err(e)
+                        }
+                    }
+                }
+            ),
+            (Some(err_event), None) => quote_spanned!(block.span()=>
                 async move {
                     match async move { #block }.await {
                         #[allow(clippy::unit_arg)]
@@ -215,7 +234,13 @@ fn gen_block<B: ToTokens>(
                     }
                 }
             ),
-            None => quote_spanned!(block.span()=>
+            (None, Some(ret_event)) => quote_spanned!(block.span()=>
+                async move {
+                    #ret_event;
+                    #block
+                }
+            ),
+            (None, None) => quote_spanned!(block.span()=>
                 async move { #block }
             ),
         };
@@ -254,9 +279,10 @@ fn gen_block<B: ToTokens>(
         }
     );
 
-    if let Some(err_event) = err_event {
-        return quote_spanned!(block.span()=>
+    match (err_event, ret_event) {
+        (Some(err_event), Some(ret_event)) => quote_spanned! {block.span()=>
             #span
+            #ret_event;
             #[allow(clippy::redundant_closure_call)]
             match (move || #block)() {
                 #[allow(clippy::unit_arg)]
@@ -266,22 +292,38 @@ fn gen_block<B: ToTokens>(
                     Err(e)
                 }
             }
-        );
-    }
-
-    quote_spanned!(block.span() =>
-        // Because `quote` produces a stream of tokens _without_ whitespace, the
-        // `if` and the block will appear directly next to each other. This
-        // generates a clippy lint about suspicious `if/else` formatting.
-        // Therefore, suppress the lint inside the generated code...
-        #[allow(clippy::suspicious_else_formatting)]
-        {
+        },
+        (Some(err_event), None) => quote_spanned!(block.span()=>
             #span
-            // ...but turn the lint back on inside the function body.
-            #[warn(clippy::suspicious_else_formatting)]
+            #[allow(clippy::redundant_closure_call)]
+            match (move || #block)() {
+                #[allow(clippy::unit_arg)]
+                Ok(x) => Ok(x),
+                Err(e) => {
+                    #err_event;
+                    Err(e)
+                }
+            }
+        ),
+        (None, Some(ret_event)) => quote_spanned!(block.span()=>
+            #span
+            #ret_event;
             #block
-        }
-    )
+        ),
+        (None, None) => quote_spanned!(block.span() =>
+            // Because `quote` produces a stream of tokens _without_ whitespace, the
+            // `if` and the block will appear directly next to each other. This
+            // generates a clippy lint about suspicious `if/else` formatting.
+            // Therefore, suppress the lint inside the generated code...
+            #[allow(clippy::suspicious_else_formatting)]
+            {
+                #span
+                // ...but turn the lint back on inside the function body.
+                #[warn(clippy::suspicious_else_formatting)]
+                #block
+            }
+        ),
+    }
 }
 
 /// Indicates whether a field should be recorded as `Value` or `Debug`.
diff --git a/tracing-attributes/tests/ret.rs b/tracing-attributes/tests/ret.rs
new file mode 100644
index 0000000000..d590311d31
--- /dev/null
+++ b/tracing-attributes/tests/ret.rs
@@ -0,0 +1,140 @@
+#[path = "../../tracing-futures/tests/support.rs"]
+// we don't use some of the test support functions, but `tracing-futures` does.
+#[allow(dead_code)]
+mod support;
+use support::*;
+
+use std::convert::TryFrom;
+use std::num::TryFromIntError;
+
+use tracing::{collect::with_default, Level};
+use tracing_attributes::instrument;
+
+#[instrument(ret)]
+fn ret() -> i32 {
+    42
+}
+
+#[test]
+fn test() {
+    let span = span::mock().named("ret");
+    let (collector, handle) = collector::mock()
+        .new_span(span.clone())
+        .enter(span.clone())
+        .event(
+            event::mock()
+                .with_fields(field::mock("return").with_value(&tracing::field::debug(42)))
+                .at_level(Level::TRACE),
+        )
+        .exit(span.clone())
+        .drop_span(span)
+        .done()
+        .run_with_handle();
+
+    with_default(collector, ret);
+    handle.assert_finished();
+}
+
+#[instrument(ret)]
+async fn ret_async() -> i32 {
+    42
+}
+
+#[test]
+fn test_async() {
+    let span = span::mock().named("ret_async");
+    let (collector, handle) = collector::mock()
+        .new_span(span.clone())
+        .enter(span.clone())
+        .event(
+            event::mock()
+                .with_fields(field::mock("return").with_value(&tracing::field::debug(42)))
+                .at_level(Level::TRACE),
+        )
+        .exit(span.clone())
+        .drop_span(span)
+        .done()
+        .run_with_handle();
+
+    with_default(collector, || block_on_future(async { ret_async().await }));
+    handle.assert_finished();
+}
+
+#[instrument(ret)]
+fn ret_impl_type() -> impl Copy {
+    42
+}
+
+#[test]
+fn test_impl_type() {
+    let span = span::mock().named("ret_impl_type");
+    let (collector, handle) = collector::mock()
+        .new_span(span.clone())
+        .enter(span.clone())
+        .event(
+            event::mock()
+                .with_fields(field::mock("return").with_value(&tracing::field::debug(42)))
+                .at_level(Level::TRACE),
+        )
+        .exit(span.clone())
+        .drop_span(span)
+        .done()
+        .run_with_handle();
+
+    with_default(collector, ret_impl_type);
+    handle.assert_finished();
+}
+
+#[instrument(ret(Debug))]
+fn ret_dbg() -> i32 {
+    42
+}
+
+#[test]
+fn test_dbg() {
+    let span = span::mock().named("ret_dbg");
+    let (collector, handle) = collector::mock()
+        .new_span(span.clone())
+        .enter(span.clone())
+        .event(
+            event::mock()
+                .with_fields(field::mock("return").with_value(&tracing::field::debug(42)))
+                .at_level(Level::TRACE),
+        )
+        .exit(span.clone())
+        .drop_span(span)
+        .done()
+        .run_with_handle();
+
+    with_default(collector, ret_dbg);
+    handle.assert_finished();
+}
+
+#[instrument(err, ret(Debug))]
+fn ret_and_err() -> Result<u8, TryFromIntError> {
+    u8::try_from(1234)
+}
+
+#[test]
+fn test_ret_and_err() {
+    let span = span::mock().named("ret_and_err");
+    let (collector, handle) = collector::mock()
+        .new_span(span.clone())
+        .enter(span.clone())
+        .event(event::mock().with_fields(
+            field::mock("return").with_value(&tracing::field::debug(u8::try_from(1234))),
+        ))
+        .event(
+            event::mock().with_fields(
+                field::mock("error")
+                    .with_value(&tracing::field::display(u8::try_from(1234).unwrap_err())),
+            ),
+        )
+        .exit(span.clone())
+        .drop_span(span)
+        .done()
+        .run_with_handle();
+
+    with_default(collector, || ret_and_err().ok());
+    handle.assert_finished();
+}

From f7cd4c476d6aaaf3a5f510e6d6f4db77a8afb7cc Mon Sep 17 00:00:00 2001
From: Hirochika Matsumoto <git@hkmatsumoto.com>
Date: Wed, 17 Nov 2021 17:50:18 +0900
Subject: [PATCH 02/14] don't expand given `block` twice

---
 tracing-attributes/src/expand.rs | 23 +++++++---
 tracing-attributes/tests/ret.rs  | 75 +++++++++++++++++++++++++++++---
 2 files changed, 84 insertions(+), 14 deletions(-)

diff --git a/tracing-attributes/src/expand.rs b/tracing-attributes/src/expand.rs
index 802e817ea0..08b8afa41f 100644
--- a/tracing-attributes/src/expand.rs
+++ b/tracing-attributes/src/expand.rs
@@ -197,8 +197,8 @@ fn gen_block<B: ToTokens>(
     };
 
     let ret_event = match args.ret_mode {
-        Some(FormatMode::Display) => Some(quote!(tracing::trace!(return = %#block))),
-        Some(FormatMode::Debug) => Some(quote!(tracing::trace!(return = ?#block))),
+        Some(FormatMode::Display) => Some(quote!(tracing::trace!(return = %x))),
+        Some(FormatMode::Debug) => Some(quote!(tracing::trace!(return = ?x))),
         _ => None,
     };
 
@@ -207,6 +207,8 @@ fn gen_block<B: ToTokens>(
     // which is `instrument`ed using `tracing-futures`. Otherwise, this will
     // enter the span and then perform the rest of the body.
     // If `err` is in args, instrument any resulting `Err`s.
+    // If `ret` is in args, instrument any resulting `Ok`s when the function
+    // returns `Result`s, otherwise instrument any resulting values.
     if async_context {
         let mk_fut = match (err_event, ret_event) {
             (Some(err_event), Some(ret_event)) => quote_spanned!(block.span()=>
@@ -214,7 +216,10 @@ fn gen_block<B: ToTokens>(
                     #ret_event;
                     match async move { #block }.await {
                         #[allow(clippy::unit_arg)]
-                        Ok(x) => Ok(x),
+                        Ok(x) => {
+                            #ret_event;
+                            Ok(x)
+                        },
                         Err(e) => {
                             #err_event;
                             Err(e)
@@ -236,8 +241,9 @@ fn gen_block<B: ToTokens>(
             ),
             (None, Some(ret_event)) => quote_spanned!(block.span()=>
                 async move {
+                    let x = async move { #block }.await;
                     #ret_event;
-                    #block
+                    x
                 }
             ),
             (None, None) => quote_spanned!(block.span()=>
@@ -282,11 +288,13 @@ fn gen_block<B: ToTokens>(
     match (err_event, ret_event) {
         (Some(err_event), Some(ret_event)) => quote_spanned! {block.span()=>
             #span
-            #ret_event;
             #[allow(clippy::redundant_closure_call)]
             match (move || #block)() {
                 #[allow(clippy::unit_arg)]
-                Ok(x) => Ok(x),
+                Ok(x) => {
+                    #ret_event;
+                    Ok(x)
+                },
                 Err(e) => {
                     #err_event;
                     Err(e)
@@ -307,8 +315,9 @@ fn gen_block<B: ToTokens>(
         ),
         (None, Some(ret_event)) => quote_spanned!(block.span()=>
             #span
+            let x = (move || #block)();
             #ret_event;
-            #block
+            x
         ),
         (None, None) => quote_spanned!(block.span() =>
             // Because `quote` produces a stream of tokens _without_ whitespace, the
diff --git a/tracing-attributes/tests/ret.rs b/tracing-attributes/tests/ret.rs
index d590311d31..fc476d21c0 100644
--- a/tracing-attributes/tests/ret.rs
+++ b/tracing-attributes/tests/ret.rs
@@ -35,6 +35,38 @@ fn test() {
     handle.assert_finished();
 }
 
+#[instrument(ret)]
+fn ret_mut(a: &mut i32) -> i32 {
+    *a *= 2;
+    tracing::info!(?a);
+    *a
+}
+
+#[test]
+fn test_mut() {
+    let span = span::mock().named("ret_mut");
+    let (collector, handle) = collector::mock()
+        .new_span(span.clone())
+        .enter(span.clone())
+        .event(
+            event::mock()
+                .with_fields(field::mock("a").with_value(&tracing::field::display(2)))
+                .at_level(Level::INFO),
+        )
+        .event(
+            event::mock()
+                .with_fields(field::mock("return").with_value(&tracing::field::display(2)))
+                .at_level(Level::TRACE),
+        )
+        .exit(span.clone())
+        .drop_span(span)
+        .done()
+        .run_with_handle();
+
+    with_default(collector, || ret_mut(&mut 1));
+    handle.assert_finished();
+}
+
 #[instrument(ret)]
 async fn ret_async() -> i32 {
     42
@@ -121,14 +153,14 @@ fn test_ret_and_err() {
     let (collector, handle) = collector::mock()
         .new_span(span.clone())
         .enter(span.clone())
-        .event(event::mock().with_fields(
-            field::mock("return").with_value(&tracing::field::debug(u8::try_from(1234))),
-        ))
         .event(
-            event::mock().with_fields(
-                field::mock("error")
-                    .with_value(&tracing::field::display(u8::try_from(1234).unwrap_err())),
-            ),
+            event::mock()
+                .with_fields(
+                    field::mock("error")
+                        .with_value(&tracing::field::display(u8::try_from(1234).unwrap_err()))
+                        .only(),
+                )
+                .at_level(Level::ERROR),
         )
         .exit(span.clone())
         .drop_span(span)
@@ -138,3 +170,32 @@ fn test_ret_and_err() {
     with_default(collector, || ret_and_err().ok());
     handle.assert_finished();
 }
+
+#[instrument(err, ret(Debug))]
+fn ret_and_ok() -> Result<u8, TryFromIntError> {
+    u8::try_from(123)
+}
+
+#[test]
+fn test_ret_and_ok() {
+    let span = span::mock().named("ret_and_ok");
+    let (collector, handle) = collector::mock()
+        .new_span(span.clone())
+        .enter(span.clone())
+        .event(
+            event::mock()
+                .with_fields(
+                    field::mock("return")
+                        .with_value(&tracing::field::display(u8::try_from(123).unwrap()))
+                        .only(),
+                )
+                .at_level(Level::TRACE),
+        )
+        .exit(span.clone())
+        .drop_span(span)
+        .done()
+        .run_with_handle();
+
+    with_default(collector, || ret_and_ok().ok());
+    handle.assert_finished();
+}

From 16e8bf1dbda263a3d30f95fd5a042e4fc52e186d Mon Sep 17 00:00:00 2001
From: Hirochika Matsumoto <git@hkmatsumoto.com>
Date: Wed, 17 Nov 2021 18:32:39 +0900
Subject: [PATCH 03/14] record return values in the default log level

---
 tracing-attributes/src/expand.rs |  4 ++--
 tracing-attributes/tests/ret.rs  | 37 ++++++++++++++++++++++++++------
 2 files changed, 33 insertions(+), 8 deletions(-)

diff --git a/tracing-attributes/src/expand.rs b/tracing-attributes/src/expand.rs
index 08b8afa41f..00c3a9b8fc 100644
--- a/tracing-attributes/src/expand.rs
+++ b/tracing-attributes/src/expand.rs
@@ -197,8 +197,8 @@ fn gen_block<B: ToTokens>(
     };
 
     let ret_event = match args.ret_mode {
-        Some(FormatMode::Display) => Some(quote!(tracing::trace!(return = %x))),
-        Some(FormatMode::Debug) => Some(quote!(tracing::trace!(return = ?x))),
+        Some(FormatMode::Display) => Some(quote!(tracing::event!(#level, return = %x))),
+        Some(FormatMode::Debug) => Some(quote!(tracing::event!(#level, return = ?x))),
         _ => None,
     };
 
diff --git a/tracing-attributes/tests/ret.rs b/tracing-attributes/tests/ret.rs
index fc476d21c0..eb6381a9a4 100644
--- a/tracing-attributes/tests/ret.rs
+++ b/tracing-attributes/tests/ret.rs
@@ -24,7 +24,7 @@ fn test() {
         .event(
             event::mock()
                 .with_fields(field::mock("return").with_value(&tracing::field::debug(42)))
-                .at_level(Level::TRACE),
+                .at_level(Level::INFO),
         )
         .exit(span.clone())
         .drop_span(span)
@@ -35,6 +35,31 @@ fn test() {
     handle.assert_finished();
 }
 
+#[instrument(level = "warn", ret)]
+fn ret_warn() -> i32 {
+    42
+}
+
+#[test]
+fn test_warn() {
+    let span = span::mock().named("ret_warn");
+    let (collector, handle) = collector::mock()
+        .new_span(span.clone())
+        .enter(span.clone())
+        .event(
+            event::mock()
+                .with_fields(field::mock("return").with_value(&tracing::field::debug(42)))
+                .at_level(Level::WARN),
+        )
+        .exit(span.clone())
+        .drop_span(span)
+        .done()
+        .run_with_handle();
+
+    with_default(collector, ret_warn);
+    handle.assert_finished();
+}
+
 #[instrument(ret)]
 fn ret_mut(a: &mut i32) -> i32 {
     *a *= 2;
@@ -56,7 +81,7 @@ fn test_mut() {
         .event(
             event::mock()
                 .with_fields(field::mock("return").with_value(&tracing::field::display(2)))
-                .at_level(Level::TRACE),
+                .at_level(Level::INFO),
         )
         .exit(span.clone())
         .drop_span(span)
@@ -81,7 +106,7 @@ fn test_async() {
         .event(
             event::mock()
                 .with_fields(field::mock("return").with_value(&tracing::field::debug(42)))
-                .at_level(Level::TRACE),
+                .at_level(Level::INFO),
         )
         .exit(span.clone())
         .drop_span(span)
@@ -106,7 +131,7 @@ fn test_impl_type() {
         .event(
             event::mock()
                 .with_fields(field::mock("return").with_value(&tracing::field::debug(42)))
-                .at_level(Level::TRACE),
+                .at_level(Level::INFO),
         )
         .exit(span.clone())
         .drop_span(span)
@@ -131,7 +156,7 @@ fn test_dbg() {
         .event(
             event::mock()
                 .with_fields(field::mock("return").with_value(&tracing::field::debug(42)))
-                .at_level(Level::TRACE),
+                .at_level(Level::INFO),
         )
         .exit(span.clone())
         .drop_span(span)
@@ -189,7 +214,7 @@ fn test_ret_and_ok() {
                         .with_value(&tracing::field::display(u8::try_from(123).unwrap()))
                         .only(),
                 )
-                .at_level(Level::TRACE),
+                .at_level(Level::INFO),
         )
         .exit(span.clone())
         .drop_span(span)

From d3a0a21df323b2af4964c3e4a3cf6df51976738d Mon Sep 17 00:00:00 2001
From: Hirochika Matsumoto <git@hkmatsumoto.com>
Date: Wed, 17 Nov 2021 18:44:34 +0900
Subject: [PATCH 04/14] remove a leftover

---
 tracing-attributes/src/expand.rs | 1 -
 1 file changed, 1 deletion(-)

diff --git a/tracing-attributes/src/expand.rs b/tracing-attributes/src/expand.rs
index 00c3a9b8fc..b7d231af15 100644
--- a/tracing-attributes/src/expand.rs
+++ b/tracing-attributes/src/expand.rs
@@ -213,7 +213,6 @@ fn gen_block<B: ToTokens>(
         let mk_fut = match (err_event, ret_event) {
             (Some(err_event), Some(ret_event)) => quote_spanned!(block.span()=>
                 async move {
-                    #ret_event;
                     match async move { #block }.await {
                         #[allow(clippy::unit_arg)]
                         Ok(x) => {

From d049d808c5bf18b58f116c1bdf71224fd7e94d6d Mon Sep 17 00:00:00 2001
From: Hirochika Matsumoto <git@hkmatsumoto.com>
Date: Wed, 17 Nov 2021 19:05:39 +0900
Subject: [PATCH 05/14] add documentation on `ret` and its combination with
 `err`

---
 tracing-attributes/src/lib.rs | 36 +++++++++++++++++++++++++++++++++++
 1 file changed, 36 insertions(+)

diff --git a/tracing-attributes/src/lib.rs b/tracing-attributes/src/lib.rs
index 77f97a91f8..1136a34a92 100644
--- a/tracing-attributes/src/lib.rs
+++ b/tracing-attributes/src/lib.rs
@@ -176,6 +176,31 @@ mod expand;
 /// }
 /// ```
 ///
+/// To record a returned value from a function, you can use `ret`:
+///
+/// ```
+/// # use tracing_attributes::instrument;
+/// #[instrument(ret)]
+/// fn my_function() -> i32 {
+///     42
+/// }
+/// ```
+///
+/// Note that if the function returns a `Result<T, E>`, `ret` will record returned values iff the
+/// function returns [`Result::Ok`].
+///
+/// By default, returned values will be recorded using their [`std::fmt::Display`] implementations.
+/// If a returned value implements [`std::fmt::Debug`], it can be recorded using its `Debug`
+/// implementation instead, by writing `ret(Debug)`:
+///
+/// ```
+/// # use tracing_attributes::instrument;
+/// #[instrument(ret(Debug))]
+/// fn my_function() -> Option<()> {
+///     Some(())
+/// }
+/// ```
+///
 /// If the function returns a `Result<T, E>` and `E` implements `std::fmt::Display`, you can add
 /// `err` or `err(Display)` to emit error events when the function returns `Err`:
 ///
@@ -199,6 +224,17 @@ mod expand;
 /// }
 /// ```
 ///
+/// With the aforementioned `ret`, you can record a returned value in either case whether a function
+/// returns [`Result::Ok`] or [`Result::Err`]:
+///
+/// ```
+/// # use tracing_attributes::instrument;
+/// #[instrument(err, ret(Debug))]
+/// fn my_function(arg: usize) -> Result<(), std::io::Error> {
+///     Ok(())
+/// }
+/// ```
+///
 /// `async fn`s may also be instrumented:
 ///
 /// ```

From a12814dbbc20d9a264f2fa7a10993e65ff7cd0d8 Mon Sep 17 00:00:00 2001
From: Hirochika Matsumoto <git@hkmatsumoto.com>
Date: Wed, 17 Nov 2021 19:09:49 +0900
Subject: [PATCH 06/14] change `ret(Debug)` to `ret` where possible

Now that `ret` displays `Result::Ok` but not `Result`, there are some
case that `ret(Debug)` is not necessary any longer.
---
 tracing-attributes/tests/ret.rs | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/tracing-attributes/tests/ret.rs b/tracing-attributes/tests/ret.rs
index eb6381a9a4..817ec73c96 100644
--- a/tracing-attributes/tests/ret.rs
+++ b/tracing-attributes/tests/ret.rs
@@ -167,7 +167,7 @@ fn test_dbg() {
     handle.assert_finished();
 }
 
-#[instrument(err, ret(Debug))]
+#[instrument(err, ret)]
 fn ret_and_err() -> Result<u8, TryFromIntError> {
     u8::try_from(1234)
 }
@@ -196,7 +196,7 @@ fn test_ret_and_err() {
     handle.assert_finished();
 }
 
-#[instrument(err, ret(Debug))]
+#[instrument(err, ret)]
 fn ret_and_ok() -> Result<u8, TryFromIntError> {
     u8::try_from(123)
 }

From 9cc53b12e44b150ec214b906ae7e682b6c7afa99 Mon Sep 17 00:00:00 2001
From: Hirochika Matsumoto <git@hkmatsumoto.com>
Date: Sat, 20 Nov 2021 14:45:31 +0900
Subject: [PATCH 07/14] make clippy smile

---
 tracing-attributes/src/expand.rs | 1 +
 1 file changed, 1 insertion(+)

diff --git a/tracing-attributes/src/expand.rs b/tracing-attributes/src/expand.rs
index b7d231af15..56089547b4 100644
--- a/tracing-attributes/src/expand.rs
+++ b/tracing-attributes/src/expand.rs
@@ -314,6 +314,7 @@ fn gen_block<B: ToTokens>(
         ),
         (None, Some(ret_event)) => quote_spanned!(block.span()=>
             #span
+            #[allow(clippy::redundant_closure_call)]
             let x = (move || #block)();
             #ret_event;
             x

From 47fc691a95d67df27bc1db2a0562d785fa82d76b Mon Sep 17 00:00:00 2001
From: Hirochika Matsumoto <git@hkmatsumoto.com>
Date: Sun, 21 Nov 2021 20:35:57 +0900
Subject: [PATCH 08/14] record returned values by debug format

---
 tracing-attributes/src/attr.rs   |  3 ++-
 tracing-attributes/src/expand.rs |  8 ++++++--
 tracing-attributes/src/lib.rs    | 14 +++++++-------
 tracing-attributes/tests/ret.rs  | 14 +++++++-------
 4 files changed, 22 insertions(+), 17 deletions(-)

diff --git a/tracing-attributes/src/attr.rs b/tracing-attributes/src/attr.rs
index d8025ddf2b..bde089fb65 100644
--- a/tracing-attributes/src/attr.rs
+++ b/tracing-attributes/src/attr.rs
@@ -205,13 +205,14 @@ impl Parse for Skips {
 
 #[derive(Clone, Debug, Hash, PartialEq, Eq)]
 pub(crate) enum FormatMode {
+    Default,
     Display,
     Debug,
 }
 
 impl Default for FormatMode {
     fn default() -> Self {
-        FormatMode::Display
+        FormatMode::Default
     }
 }
 
diff --git a/tracing-attributes/src/expand.rs b/tracing-attributes/src/expand.rs
index 56089547b4..9d73416aa9 100644
--- a/tracing-attributes/src/expand.rs
+++ b/tracing-attributes/src/expand.rs
@@ -191,14 +191,18 @@ fn gen_block<B: ToTokens>(
     })();
 
     let err_event = match args.err_mode {
-        Some(FormatMode::Display) => Some(quote!(tracing::error!(error = %e))),
+        Some(FormatMode::Default | FormatMode::Display) => {
+            Some(quote!(tracing::error!(error = %e)))
+        }
         Some(FormatMode::Debug) => Some(quote!(tracing::error!(error = ?e))),
         _ => None,
     };
 
     let ret_event = match args.ret_mode {
         Some(FormatMode::Display) => Some(quote!(tracing::event!(#level, return = %x))),
-        Some(FormatMode::Debug) => Some(quote!(tracing::event!(#level, return = ?x))),
+        Some(FormatMode::Default | FormatMode::Debug) => {
+            Some(quote!(tracing::event!(#level, return = ?x)))
+        }
         _ => None,
     };
 
diff --git a/tracing-attributes/src/lib.rs b/tracing-attributes/src/lib.rs
index 1136a34a92..81865d60f1 100644
--- a/tracing-attributes/src/lib.rs
+++ b/tracing-attributes/src/lib.rs
@@ -189,15 +189,15 @@ mod expand;
 /// Note that if the function returns a `Result<T, E>`, `ret` will record returned values iff the
 /// function returns [`Result::Ok`].
 ///
-/// By default, returned values will be recorded using their [`std::fmt::Display`] implementations.
-/// If a returned value implements [`std::fmt::Debug`], it can be recorded using its `Debug`
-/// implementation instead, by writing `ret(Debug)`:
+/// By default, returned values will be recorded using their [`std::fmt::Debug`] implementations.
+/// If a returned value implements [`std::fmt::Display`], it can be recorded using its `Display`
+/// implementation instead, by writing `ret(Display)`:
 ///
 /// ```
 /// # use tracing_attributes::instrument;
-/// #[instrument(ret(Debug))]
-/// fn my_function() -> Option<()> {
-///     Some(())
+/// #[instrument(ret(Display))]
+/// fn my_function() -> i32 {
+///     42
 /// }
 /// ```
 ///
@@ -229,7 +229,7 @@ mod expand;
 ///
 /// ```
 /// # use tracing_attributes::instrument;
-/// #[instrument(err, ret(Debug))]
+/// #[instrument(err, ret)]
 /// fn my_function(arg: usize) -> Result<(), std::io::Error> {
 ///     Ok(())
 /// }
diff --git a/tracing-attributes/tests/ret.rs b/tracing-attributes/tests/ret.rs
index 817ec73c96..d59d611824 100644
--- a/tracing-attributes/tests/ret.rs
+++ b/tracing-attributes/tests/ret.rs
@@ -80,7 +80,7 @@ fn test_mut() {
         )
         .event(
             event::mock()
-                .with_fields(field::mock("return").with_value(&tracing::field::display(2)))
+                .with_fields(field::mock("return").with_value(&tracing::field::debug(2)))
                 .at_level(Level::INFO),
         )
         .exit(span.clone())
@@ -142,20 +142,20 @@ fn test_impl_type() {
     handle.assert_finished();
 }
 
-#[instrument(ret(Debug))]
-fn ret_dbg() -> i32 {
+#[instrument(ret(Display))]
+fn ret_display() -> i32 {
     42
 }
 
 #[test]
 fn test_dbg() {
-    let span = span::mock().named("ret_dbg");
+    let span = span::mock().named("ret_display");
     let (collector, handle) = collector::mock()
         .new_span(span.clone())
         .enter(span.clone())
         .event(
             event::mock()
-                .with_fields(field::mock("return").with_value(&tracing::field::debug(42)))
+                .with_fields(field::mock("return").with_value(&tracing::field::display(42)))
                 .at_level(Level::INFO),
         )
         .exit(span.clone())
@@ -163,7 +163,7 @@ fn test_dbg() {
         .done()
         .run_with_handle();
 
-    with_default(collector, ret_dbg);
+    with_default(collector, ret_display);
     handle.assert_finished();
 }
 
@@ -211,7 +211,7 @@ fn test_ret_and_ok() {
             event::mock()
                 .with_fields(
                     field::mock("return")
-                        .with_value(&tracing::field::display(u8::try_from(123).unwrap()))
+                        .with_value(&tracing::field::debug(u8::try_from(123).unwrap()))
                         .only(),
                 )
                 .at_level(Level::INFO),

From 0382e4a777370c3dc92ee87eeabfcf4de61c548e Mon Sep 17 00:00:00 2001
From: Hirochika Matsumoto <git@hkmatsumoto.com>
Date: Sun, 21 Nov 2021 20:38:21 +0900
Subject: [PATCH 09/14] Update tracing-attributes/src/lib.rs

minor fix on documentation

Co-authored-by: Eliza Weisman <eliza@buoyant.io>
---
 tracing-attributes/src/lib.rs | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/tracing-attributes/src/lib.rs b/tracing-attributes/src/lib.rs
index 81865d60f1..b02d59d954 100644
--- a/tracing-attributes/src/lib.rs
+++ b/tracing-attributes/src/lib.rs
@@ -186,7 +186,7 @@ mod expand;
 /// }
 /// ```
 ///
-/// Note that if the function returns a `Result<T, E>`, `ret` will record returned values iff the
+/// **Note**:  if the function returns a `Result<T, E>`, `ret` will record returned values iff the
 /// function returns [`Result::Ok`].
 ///
 /// By default, returned values will be recorded using their [`std::fmt::Debug`] implementations.

From 4798f64802b5b8d48bd1888c4f66574498d7353d Mon Sep 17 00:00:00 2001
From: Hirochika Matsumoto <git@hkmatsumoto.com>
Date: Tue, 23 Nov 2021 14:48:19 +0900
Subject: [PATCH 10/14] avoid "or pattern" which is experimental on some
 versions

---
 tracing-attributes/src/expand.rs | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/tracing-attributes/src/expand.rs b/tracing-attributes/src/expand.rs
index 9d73416aa9..64b2cef6c9 100644
--- a/tracing-attributes/src/expand.rs
+++ b/tracing-attributes/src/expand.rs
@@ -191,7 +191,7 @@ fn gen_block<B: ToTokens>(
     })();
 
     let err_event = match args.err_mode {
-        Some(FormatMode::Default | FormatMode::Display) => {
+        Some(FormatMode::Default) | Some(FormatMode::Display) => {
             Some(quote!(tracing::error!(error = %e)))
         }
         Some(FormatMode::Debug) => Some(quote!(tracing::error!(error = ?e))),
@@ -200,7 +200,7 @@ fn gen_block<B: ToTokens>(
 
     let ret_event = match args.ret_mode {
         Some(FormatMode::Display) => Some(quote!(tracing::event!(#level, return = %x))),
-        Some(FormatMode::Default | FormatMode::Debug) => {
+        Some(FormatMode::Default) | Some(FormatMode::Debug) => {
             Some(quote!(tracing::event!(#level, return = ?x)))
         }
         _ => None,

From 255170cd23c1bab5f3de81b6d5de31adfcc50ea7 Mon Sep 17 00:00:00 2001
From: Hirochika Matsumoto <git@hkmatsumoto.com>
Date: Tue, 23 Nov 2021 14:51:11 +0900
Subject: [PATCH 11/14] fix wording, part 1

Co-authored-by: Eliza Weisman <eliza@buoyant.io>
---
 tracing-attributes/src/lib.rs | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/tracing-attributes/src/lib.rs b/tracing-attributes/src/lib.rs
index b02d59d954..9439e80167 100644
--- a/tracing-attributes/src/lib.rs
+++ b/tracing-attributes/src/lib.rs
@@ -176,7 +176,8 @@ mod expand;
 /// }
 /// ```
 ///
-/// To record a returned value from a function, you can use `ret`:
+/// Adding the `ret` argument to `#[instrument]` will emit an event with the function's
+/// return value when the function returns:
 ///
 /// ```
 /// # use tracing_attributes::instrument;

From 887e764acb19b77b4b3c4e7f4a00ee1393d8a765 Mon Sep 17 00:00:00 2001
From: Hirochika Matsumoto <git@hkmatsumoto.com>
Date: Tue, 23 Nov 2021 14:51:20 +0900
Subject: [PATCH 12/14] fix wording, part 2

Co-authored-by: Eliza Weisman <eliza@buoyant.io>
---
 tracing-attributes/src/lib.rs | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/tracing-attributes/src/lib.rs b/tracing-attributes/src/lib.rs
index 9439e80167..6c2d19b08f 100644
--- a/tracing-attributes/src/lib.rs
+++ b/tracing-attributes/src/lib.rs
@@ -187,8 +187,8 @@ mod expand;
 /// }
 /// ```
 ///
-/// **Note**:  if the function returns a `Result<T, E>`, `ret` will record returned values iff the
-/// function returns [`Result::Ok`].
+/// **Note**:  if the function returns a `Result<T, E>`, `ret` will record returned values if and
+/// only if the function returns [`Result::Ok`].
 ///
 /// By default, returned values will be recorded using their [`std::fmt::Debug`] implementations.
 /// If a returned value implements [`std::fmt::Display`], it can be recorded using its `Display`

From 55209a4469efd779eee3d35cb0faeade5eb59219 Mon Sep 17 00:00:00 2001
From: Hirochika Matsumoto <git@hkmatsumoto.com>
Date: Tue, 23 Nov 2021 14:51:29 +0900
Subject: [PATCH 13/14] fix wording, part 3

Co-authored-by: Eliza Weisman <eliza@buoyant.io>
---
 tracing-attributes/src/lib.rs | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/tracing-attributes/src/lib.rs b/tracing-attributes/src/lib.rs
index 6c2d19b08f..c417f2e4bb 100644
--- a/tracing-attributes/src/lib.rs
+++ b/tracing-attributes/src/lib.rs
@@ -225,8 +225,8 @@ mod expand;
 /// }
 /// ```
 ///
-/// With the aforementioned `ret`, you can record a returned value in either case whether a function
-/// returns [`Result::Ok`] or [`Result::Err`]:
+/// The `ret` and `err` arguments can be combined in order to record an event if a
+/// function returns [`Result::Ok`] or [`Result::Err`]:
 ///
 /// ```
 /// # use tracing_attributes::instrument;

From e26c10f86022406821c6aebae0c3e5e3032faed7 Mon Sep 17 00:00:00 2001
From: Hirochika Matsumoto <git@hkmatsumoto.com>
Date: Tue, 23 Nov 2021 14:53:22 +0900
Subject: [PATCH 14/14] fix wording, part 4

Co-authored-by: Eliza Weisman <eliza@buoyant.io>
---
 tracing-attributes/src/lib.rs | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/tracing-attributes/src/lib.rs b/tracing-attributes/src/lib.rs
index c417f2e4bb..52df2dd4fb 100644
--- a/tracing-attributes/src/lib.rs
+++ b/tracing-attributes/src/lib.rs
@@ -186,6 +186,9 @@ mod expand;
 ///     42
 /// }
 /// ```
+/// The return value event will have the same level as the span generated by `#[instrument]`.
+/// By default, this will be `TRACE`, but if the level is overridden, the event will be at the same
+/// level.
 ///
 /// **Note**:  if the function returns a `Result<T, E>`, `ret` will record returned values if and
 /// only if the function returns [`Result::Ok`].