tracing integration

Cucumber::init_tracing() (enabled by tracing feature in Cargo.toml) initializes global tracing::Subscriber that intercepts all the tracing events and transforms them into event::Scenario::Logs. Each Writer can handle those event::Scenario::Logs in its own way. writer::Basic, for example, emits all the event::Scenario::Logs only whenever scenario itself is outputted.

extern crate cucumber;
extern crate tokio;
extern crate tracing;

use std::{
    sync::atomic::{AtomicUsize, Ordering},
    time::Duration,
};

use cucumber::{given, then, when, World as _};
use tokio::time;

#[derive(cucumber::World, Debug, Default)]
struct World;

#[given(regex = r"(\d+) secs?")]
#[when(regex = r"(\d+) secs?")]
#[then(regex = r"(\d+) secs?")]
async fn sleep(_: &mut World, secs: u64) {
    static ID: AtomicUsize = AtomicUsize::new(0);

    let id = ID.fetch_add(1, Ordering::Relaxed);

    tracing::info!("before {secs}s sleep: {id}");
    time::sleep(Duration::from_secs(secs)).await;
    tracing::info!("after {secs}s sleep: {id}");
}

#[tokio::main]
async fn main() {
    World::cucumber()
        .init_tracing()
        .run("tests/features/wait")
        .await;
}

Loosing tracing::Span

tracing::Span is used to wire emitted tracing events (logs) to concrete scenarios: each scenario is executed in its own tracing::Span. In case a tracing event is emitted outside the tracing::Span of a scenario, it will be propagated to every running scenario at the moment.

extern crate cucumber;
extern crate tokio;
extern crate tracing;

use std::{
    sync::atomic::{AtomicUsize, Ordering},
    time::Duration,
};

use cucumber::{given, then, when, World as _};
use tokio::time;

#[derive(cucumber::World, Debug, Default)]
struct World;

#[given(regex = r"(\d+) secs?")]
#[when(regex = r"(\d+) secs?")]
#[then(regex = r"(\d+) secs?")]
async fn sleep(_: &mut World, secs: u64) {
    static ID: AtomicUsize = AtomicUsize::new(0);

    let id = ID.fetch_add(1, Ordering::Relaxed);

    tracing::info!("before {secs}s sleep: {id}");
    time::sleep(Duration::from_secs(secs)).await;
    tracing::info!("after {secs}s sleep: {id}");
}

#[tokio::main]
async fn main() {
    // Background task outside of any scenario.
    tokio::spawn(async {
        let mut id = 0;
        loop {
            time::sleep(Duration::from_secs(3)).await;
            tracing::info!("Background: {id}");
            id += 1;
        }
    });

    World::cucumber()
        .init_tracing()
        .run("tests/features/wait")
        .await;
}

As we see, Background: 2/3/4 is shown in multiple scenarios, while being emitted only once each.

TIP: If you're spawning a Future inside your step matching function, consider to propagate its tracing::Span into the spawned Future for outputting its logs properly.