Add await_holding_span_guard lint

Cargo.toml

@@ -17,3 +17,8 @@ members = [
     "tracing-journald",
     "examples"
 ]
+
+[workspace.metadata.dylint]
+libraries = [
+    { path = "lints/await_holding_span_guard" },
+]

lints/await_holding_span_guard/.cargo/config.toml

@@ -0,0 +1,8 @@
+[target.x86_64-apple-darwin]
+linker = "dylint-link"
+
+[target.x86_64-unknown-linux-gnu]
+linker = "dylint-link"
+
+[target.x86_64-pc-windows-msvc]
+linker = "dylint-link"

lints/await_holding_span_guard/.gitignore

@@ -0,0 +1,2 @@
+/target
+/Cargo.lock

lints/await_holding_span_guard/Cargo.toml

@@ -0,0 +1,28 @@
+[package]
+name = "await_holding_span_guard"
+version = "0.1.0"
+authors = ["authors go here"]
+description = "decription goes here"
+edition = "2021"
+publish = false
+
+[lib]
+crate-type = ["cdylib"]
+
+[[example]]
+name = "ui"
+path = "ui/main.rs"
+
+[dependencies]
+clippy_utils = { git = "https://github.com/rust-lang/rust-clippy", rev = "5707491b185f9c9fc913f25efbd09d2649136683" }
+dylint_linting = "1.0.13"
+if_chain = "1.0.2"
+
+[dev-dependencies]
+dylint_testing = "1.0.13"
+tracing = { path = "../../tracing" }
+
+[package.metadata.rust-analyzer]
+rustc_private = true
+
+[workspace]

lints/await_holding_span_guard/rust-toolchain

@@ -0,0 +1,3 @@
+[toolchain]
+channel = "nightly-2022-02-10"
+components = ["llvm-tools-preview", "rustc-dev"]

lints/await_holding_span_guard/src/await_holding_span_guard.rs

@@ -0,0 +1,125 @@
+use clippy_utils::diagnostics::span_lint_and_note;
+use clippy_utils::match_def_path;
+use rustc_hir::def_id::DefId;
+use rustc_hir::{AsyncGeneratorKind, Body, BodyId, GeneratorKind};
+use rustc_lint::{LateContext, LateLintPass};
+use rustc_middle::ty::GeneratorInteriorTypeCause;
+use rustc_session::{declare_lint, declare_lint_pass};
+use rustc_span::Span;
+
+declare_lint! {
+    /// ### What it does
+    /// Checks for calls to await while holding a
+    /// `tracing` span's `Entered` or `EnteredSpan` guards.
+    ///
+    /// ### Why is this bad?
+    /// The guards created by `tracing::Span::enter()` or `tracing::Span::entered()`
+    /// across `.await` points will result in incorrect traces. This occurs when
+    /// an async function or async block yields at an .await point, the current
+    /// scope is exited, but values in that scope are not dropped (because
+    /// the async block will eventually resume execution from that await point).
+    /// This means that another task will begin executing while remaining in the entered span.
+    ///
+    /// ### Known problems
+    /// Will report false positive for explicitly dropped refs ([#6353](https://github.com/rust-lang/rust-clippy/issues/6353)).
+    ///
+    /// ### Example
+    /// ```rust,ignore
+    /// use tracing::{span, Level};
+    ///
+    /// async fn foo() {
+    ///     let span = span!(Level::INFO, "foo");
+    ///
+    ///     THIS WILL RESULT IN INCORRECT TRACES
+    ///     let _enter = span.enter();
+    ///     bar().await;
+    /// }
+    /// ```
+    ///
+    /// Use instead:
+    /// ```rust,ignore
+    /// use tracing::{span, Level}
+    ///
+    /// async fn foo() {
+    ///     let span = span!(Level::INFO, "foo");
+    ///
+    ///     let some_value = span.in_scope(|| {
+    ///         // run some synchronous code inside the span...
+    ///     });
+    ///
+    ///     // This is okay! The span has already been exited before we reach
+    ///     // the await point.
+    ///     bar(some_value).await;
+    /// }
+    /// ```
+    ///
+    /// Or use:
+    ///
+    /// ```rust,ignore
+    /// use tracing::{span, Level, Instrument};
+    ///
+    /// async fn foo() {
+    ///     let span = span!(Level::INFO, "foo");
+    ///     async move {
+    ///         // This is correct! If we yield here, the span will be exited,
+    ///         // and re-entered when we resume.
+    ///         bar().await;
+    ///     }.instrument(span) // instrument the async block with the span...
+    ///     .await // ...and await it.
+    /// }
+    /// ```
+    pub AWAIT_HOLDING_SPAN_GUARD,
+    Warn,
+    "Inside an async function, holding a Span guard while calling await"
+}
+
+declare_lint_pass!(AwaitHoldingSpanGuard => [AWAIT_HOLDING_SPAN_GUARD]);
+
+pub const TRACING_SPAN_ENTER_GUARD: [&str; 3] = ["tracing", "span", "Entered"];
+pub const TRACING_SPAN_ENTERED_GUARD: [&str; 3] = ["tracing", "span", "EnteredSpan"];
+
+impl LateLintPass<'_> for AwaitHoldingSpanGuard {
+    fn check_body(&mut self, cx: &LateContext<'_>, body: &'_ Body<'_>) {
+        use AsyncGeneratorKind::{Block, Closure, Fn};
+        if let Some(GeneratorKind::Async(Block | Closure | Fn)) = body.generator_kind {
+            let body_id = BodyId {
+                hir_id: body.value.hir_id,
+            };
+            let typeck_results = cx.tcx.typeck_body(body_id);
+            check_interior_types(
+                cx,
+                typeck_results
+                    .generator_interior_types
+                    .as_ref()
+                    .skip_binder(),
+                body.value.span,
+            );
+        }
+    }
+}
+
+fn check_interior_types(
+    cx: &LateContext<'_>,
+    ty_causes: &[GeneratorInteriorTypeCause<'_>],
+    span: Span,
+) {
+    for ty_cause in ty_causes {
+        if let rustc_middle::ty::Adt(adt, _) = ty_cause.ty.kind() {
+            if is_tracing_span_guard(cx, adt.did) {
+                span_lint_and_note(
+                    cx,
+                    AWAIT_HOLDING_SPAN_GUARD,
+                    ty_cause.span,
+                    "this Span guard is held across an 'await' point. Consider using the `.instrument()` combinator or the `.in_scope()` method instead",
+                    ty_cause.scope_span.or(Some(span)),
+                    "these are all the await points this ref is held through",
+                );
+            }
+        }
+    }
+}
+
+fn is_tracing_span_guard(cx: &LateContext<'_>, def_id: DefId) -> bool {
+    match_def_path(cx, def_id, &TRACING_SPAN_ENTER_GUARD)
+        || match_def_path(cx, def_id, &TRACING_SPAN_ENTERED_GUARD)
+}

lints/await_holding_span_guard/src/lib.rs

@@ -0,0 +1,24 @@
+#![feature(rustc_private)]
+#![warn(unused_extern_crates)]
+
+dylint_linting::dylint_library!();
+
+extern crate rustc_hir;
+extern crate rustc_lint;
+extern crate rustc_middle;
+extern crate rustc_session;
+extern crate rustc_span;
+
+mod await_holding_span_guard;
+
+#[doc(hidden)]
+#[no_mangle]
+pub fn register_lints(_sess: &rustc_session::Session, lint_store: &mut rustc_lint::LintStore) {
+    lint_store.register_lints(&[await_holding_span_guard::AWAIT_HOLDING_SPAN_GUARD]);
+    lint_store.register_late_pass(|| Box::new(await_holding_span_guard::AwaitHoldingSpanGuard));
+}
+
+#[test]
+fn ui() {
+    dylint_testing::ui_test_example(env!("CARGO_PKG_NAME"), "ui");
+}

lints/await_holding_span_guard/ui/main.rs

@@ -0,0 +1,54 @@
+#![warn(await_holding_span_guard)]
+
+use tracing::{span, Instrument, Level, Span};
+
+async fn good_in_scope() {
+    let span = span!(Level::INFO, "good");
+
+    let some_value = span.in_scope(|| 32);
+
+    baz(some_value).await;
+}
+
+async fn good_instrument() {
+    let span = span!(Level::INFO, "good");
+
+    baz(32).instrument(span).await;
+}
+
+async fn bad_borrowed() {
+    let span = span!(Level::INFO, "bad_borrowed");
+
+    let _guard = span.enter();
+    bar().await;
+}
+
+async fn bad_owned() {
+    let span = span!(Level::INFO, "bad_owned");
+
+    let _guard = span.entered();
+    bar().await;
+}
+
+#[allow(clippy::manual_async_fn)]
+fn bad_async_block_borrowed() -> impl std::future::Future<Output = ()> + 'static {
+    async move {
+        let span = span!(Level::INFO, "async_block_borrowed");
+        let _guard = span.enter();
+        bar().await
+    }
+}
+
+async fn bar() {}
+
+async fn baz(value: usize) {
+    let _ = value;
+}
+
+fn main() {
+    good_in_scope();
+    good_instrument();
+    bad_borrowed();
+    bad_owned();
+    bad_async_block_borrowed();
+}

lints/await_holding_span_guard/ui/main.stderr

@@ -0,0 +1,45 @@
+error: this Span guard is held across an 'await' point. Consider using the `.instrument()` combinator or the `.in_scope()` method instead
+  --> $DIR/main.rs:22:9
+   |
+LL |     let _guard = span.enter();
+   |         ^^^^^^
+   |
+   = note: `-D await-holding-span-guard` implied by `-D warnings`
+note: these are all the await points this ref is held through
+  --> $DIR/main.rs:22:5
+   |
+LL | /     let _guard = span.enter();
+LL | |     bar().await;
+LL | | }
+   | |_^
+
+error: this Span guard is held across an 'await' point. Consider using the `.instrument()` combinator or the `.in_scope()` method instead
+  --> $DIR/main.rs:29:9
+   |
+LL |     let _guard = span.entered();
+   |         ^^^^^^
+   |
+note: these are all the await points this ref is held through
+  --> $DIR/main.rs:29:5
+   |
+LL | /     let _guard = span.entered();
+LL | |     bar().await;
+LL | | }
+   | |_^
+
+error: this Span guard is held across an 'await' point. Consider using the `.instrument()` combinator or the `.in_scope()` method instead
+  --> $DIR/main.rs:37:13
+   |
+LL |         let _guard = span.enter();
+   |             ^^^^^^
+   |
+note: these are all the await points this ref is held through
+  --> $DIR/main.rs:37:9
+   |
+LL | /         let _guard = span.enter();
+LL | |         bar().await
+LL | |     }
+   | |_____^
+
+error: aborting due to 3 previous errors
+