diff --git a/asynchronix/Cargo.toml b/asynchronix/Cargo.toml index 903474f..7b543d8 100644 --- a/asynchronix/Cargo.toml +++ b/asynchronix/Cargo.toml @@ -3,6 +3,7 @@ name = "asynchronix" # When incrementing version and releasing to crates.io: # - Update crate version in this Cargo.toml # - Update crate version in README.md +# - Update crate version in the lib.rs documentation of feature flags # - Update CHANGELOG.md # - Update if necessary copyright notice in LICENSE-MIT # - Create a "vX.Y.Z" git tag @@ -23,6 +24,7 @@ autotests = false [features] # gRPC service. grpc = ["dep:bytes", "dep:ciborium", "dep:prost", "dep:prost-types", "dep:serde", "dep:tonic", "dep:tokio", "dep:tonic"] +tracing = ["dep:tracing"] # DEVELOPMENT ONLY: API-unstable public exports meant for external test/benchmarking. dev-hooks = [] @@ -44,20 +46,23 @@ spin_sleep = "1" st3 = "0.4" tai-time = "0.3.3" -# gRPC service dependencies. +# Optional dependencies. bytes = { version = "1", default-features = false, optional = true } +ciborium = { version = "0.2.2", optional = true } prost = { version = "0.13", optional = true } prost-types = { version = "0.13", optional = true } -ciborium = { version = "0.2.2", optional = true } serde = { version = "1", optional = true } tokio = { version = "1.0", features=["net", "rt-multi-thread"], optional = true } tonic = { version = "0.12", default-features = false, features=["codegen", "prost", "server"], optional = true } +tracing = { version= "0.1.40", default-features = false, features=["std"], optional = true } [dev-dependencies] atomic-wait = "1.1" futures-util = "0.3" futures-executor = "0.3" mio = { version = "1.0", features = ["os-poll", "net"] } +tracing = "0.1" +tracing-subscriber = { version = "0.3", features = ["env-filter"] } [target.'cfg(asynchronix_loom)'.dev-dependencies] loom = "0.5" diff --git a/asynchronix/src/lib.rs b/asynchronix/src/lib.rs index f8aba7f..207b240 100644 --- a/asynchronix/src/lib.rs +++ b/asynchronix/src/lib.rs @@ -379,6 +379,61 @@ //! [pony]: https://www.ponylang.io/ //! //! +//! # Feature flags +//! +//! ## Tracing support +//! +//! The `tracing` feature flag provides support for the +//! [`tracing`](https://docs.rs/tracing/latest/tracing/) crate and can be +//! activated in `Cargo.toml` with: +//! +//! ```toml +//! [dependencies] +//! asynchronix = { version = "0.3", features = ["tracing"] } +//! ``` +//! +//! Each tracing event or span emitted by a model is then wrapped in a span +//! named `model` with a target `asynchronix` and an attribute `name`. The value +//! of the attribute is the name provided to +//! [`SimInit::add_model`](simulation::SimInit::add_model). +//! +//! Note that model spans are always emitted at +//! [`Level::INFO`](tracing::Level::INFO) . +//! +//! ### Tracing examples +//! +//! The examples below assume that the `tracing` feature flag is activated, the +//! `tracing_subscriber` crate is used with the `env-filter` feature flag +//! activated and the default subscriber is set up, e.g. with: +//! +//! ```ignore +//! tracing_subscriber::fmt::init(); +//! ``` +//! +//! In order to let only warnings and errors pass through but still see model +//! span information (which is emitted as info), you may run the bench with: +//! +//! ```{.bash} +//! $ RUST_LOG="warn,[model]=info" cargo run --release my_bench +//! 2024-09-09T21:05:47.891984Z WARN model{name="kettle"}: my_bench: water is boiling +//! 2024-09-09T21:08:13.284753Z WARN model{name="timer"}: my_bench: ring ring +//! 2024-09-09T21:08:13.284753Z WARN model{name="kettle"}: my_bench: water is hot +//! ``` +//! +//! In order to see warnings or errors for the `kettle` model only, you may +//! instead run the bench with: +//! +//! ```{.bash} +//! $ RUST_LOG="[model{name=kettle}]=warn" cargo run --release my_bench +//! 2024-09-09T21:05:47.891984Z WARN model{name="kettle"}: my_bench: water is boiling +//! 2024-09-09T21:08:13.284753Z WARN model{name="kettle"}: my_bench: water is hot +//! ``` +//! +//! If the `model` span name collides with that of spans defined outside +//! `asynchronix`, the above filters can be made more specific using +//! `asynchronix[model]` instead of just `[model]`. +//! +//! //! # Other resources //! //! ## Other examples diff --git a/asynchronix/src/simulation.rs b/asynchronix/src/simulation.rs index 0fc81ec..b4f13c1 100644 --- a/asynchronix/src/simulation.rs +++ b/asynchronix/src/simulation.rs @@ -257,7 +257,7 @@ impl Simulation { Ok(()) } - /// Returns scheduler. + /// Returns a scheduler handle. pub fn scheduler(&self) -> Scheduler { Scheduler::new(self.scheduler_queue.clone(), self.time.reader()) } @@ -488,14 +488,22 @@ pub(crate) fn add_model( scheduler: Scheduler, executor: &Executor, ) { + #[cfg(feature = "tracing")] + let span = tracing::span!(target: env!("CARGO_PKG_NAME"), tracing::Level::INFO, "model", name); + let context = Context::new(name, LocalScheduler::new(scheduler, mailbox.address())); let setup_context = SetupContext::new(&mailbox, &context, executor); model.setup(&setup_context); let mut receiver = mailbox.0; - executor.spawn_and_forget(async move { + let fut = async move { let mut model = model.init(&context).await.0; while receiver.recv(&mut model, &context).await.is_ok() {} - }); + }; + + #[cfg(feature = "tracing")] + let fut = tracing::Instrument::instrument(fut, span); + + executor.spawn_and_forget(fut); } diff --git a/asynchronix/src/simulation/sim_init.rs b/asynchronix/src/simulation/sim_init.rs index 273fa52..ba9fe4c 100644 --- a/asynchronix/src/simulation/sim_init.rs +++ b/asynchronix/src/simulation/sim_init.rs @@ -16,6 +16,8 @@ pub struct SimInit { scheduler_queue: Arc>, time: SyncCell, clock: Box, + #[cfg(feature = "tracing")] + log_level: tracing::Level, } impl SimInit { @@ -44,6 +46,8 @@ impl SimInit { scheduler_queue: Arc::new(Mutex::new(PriorityQueue::new())), time: SyncCell::new(TearableAtomicTime::new(MonotonicTime::EPOCH)), clock: Box::new(NoClock::new()), + #[cfg(feature = "tracing")] + log_level: tracing::Level::INFO, } } @@ -74,6 +78,16 @@ impl SimInit { self } + /// Set the level of verbosity for model spans. + /// + /// By default, model spans use [`Level::INFO`](tracing::Level::INFO). + #[cfg(feature = "tracing")] + pub fn with_log_level(mut self, level: tracing::Level) -> Self { + self.log_level = level; + + self + } + /// Builds a simulation initialized at the specified simulation time, /// executing the [`Model::init()`](crate::model::Model::init) method on all /// model initializers.