From df7bd80d06587d173179df6e0e7c0bbe8bfcb726 Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Tue, 21 Jun 2022 13:06:12 +0200 Subject: [PATCH 01/17] Start on the runtime console subscriber --- Cargo.toml | 2 +- runtime/console/Cargo.toml | 10 +++++ runtime/console/src/callsites.rs | 75 ++++++++++++++++++++++++++++++++ runtime/console/src/lib.rs | 10 +++++ 4 files changed, 96 insertions(+), 1 deletion(-) create mode 100644 runtime/console/Cargo.toml create mode 100644 runtime/console/src/callsites.rs create mode 100644 runtime/console/src/lib.rs diff --git a/Cargo.toml b/Cargo.toml index a50d54c..21b74fd 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -123,4 +123,4 @@ tempfile = "3.2" shadow-rs = "0.11" [workspace] -members = ["modules/*", "api"] +members = ["runtime/*", "modules/*", "api"] diff --git a/runtime/console/Cargo.toml b/runtime/console/Cargo.toml new file mode 100644 index 0000000..45d09e9 --- /dev/null +++ b/runtime/console/Cargo.toml @@ -0,0 +1,10 @@ +[package] +name = "console" +version = "0.1.0" +edition = "2021" + +# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html + +[dependencies] +console-api = "0.3" +tracing = "0.1" \ No newline at end of file diff --git a/runtime/console/src/callsites.rs b/runtime/console/src/callsites.rs new file mode 100644 index 0000000..d10c395 --- /dev/null +++ b/runtime/console/src/callsites.rs @@ -0,0 +1,75 @@ +use std::fmt; +use std::fmt::Formatter; +use std::ptr; +use std::sync::atomic::{AtomicPtr, AtomicUsize, Ordering}; +use tracing::Metadata; + +pub(crate) struct Callsites { + array: [AtomicPtr>; MAX_CALLSITES], + len: AtomicUsize, +} + +impl Callsites { + pub(crate) fn insert(&self, callsite: &'static Metadata<'static>) { + if self.contains(callsite) { + return; + } + + let idx = self.len.fetch_add(1, Ordering::AcqRel); + if idx <= MAX_CALLSITES { + self.array[idx] + .compare_exchange( + ptr::null_mut(), + callsite as *const _ as *mut _, + Ordering::AcqRel, + Ordering::Acquire, + ) + .expect("would have clobbered callsite array"); + } else { + todo!("Need to spill callsite over into backup storage"); + } + } + + pub(crate) fn contains(&self, callsite: &'static Metadata<'static>) -> bool { + let mut idx = 0; + let mut end = self.len.load(Ordering::Acquire); + while { + for cs in &self.array[idx..end] { + let ptr = cs.load(Ordering::Acquire); + let meta = unsafe { ptr as *const _ as &'static Metadata<'static> }; + if meta.callsite() == callsite.callsite() { + return true; + } + } + + idx = end; + + // Check if new callsites were added since we iterated + end = self.len.load(Ordering::Acquire); + end > idx + } {} + + false + } +} + +impl Default for Callsites { + fn default() -> Self { + const NULLPTR: AtomicPtr<_> = AtomicPtr::new(ptr::null_mut()); + Self { + array: [NULLPTR; MAX_CALLSITES], + len: AtomicUsize::new(0), + } + } +} + +impl fmt::Debug for Callsites { + fn fmt(&self, f: &mut Formatter<'_>) -> fmt::Result { + let len = self.len.load(Ordering::Acquire); + f.debug_struct("Callsites") + .field("MAX_CALLSITES", &MAX_CALLSITES) + .field("array", &&self.array[..len]) + .field("len", &len) + .finish() + } +} diff --git a/runtime/console/src/lib.rs b/runtime/console/src/lib.rs new file mode 100644 index 0000000..b02b962 --- /dev/null +++ b/runtime/console/src/lib.rs @@ -0,0 +1,10 @@ +mod callsites; + +#[cfg(test)] +mod tests { + #[test] + fn it_works() { + let result = 2 + 2; + assert_eq!(result, 4); + } +} From 8a35818b4f819fb47463608494782d15d28a207f Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Tue, 21 Jun 2022 16:20:44 +0200 Subject: [PATCH 02/17] More console implementation stuff --- Cargo.lock | 371 ++++++++++++++++++++++++++++++- runtime/console/Cargo.toml | 8 +- runtime/console/src/aggregate.rs | 12 + runtime/console/src/callsites.rs | 6 +- runtime/console/src/event.rs | 5 + runtime/console/src/lib.rs | 160 +++++++++++++ runtime/console/src/server.rs | 95 ++++++++ runtime/console/src/stack.rs | 64 ++++++ 8 files changed, 715 insertions(+), 6 deletions(-) create mode 100644 runtime/console/src/aggregate.rs create mode 100644 runtime/console/src/event.rs create mode 100644 runtime/console/src/server.rs create mode 100644 runtime/console/src/stack.rs diff --git a/Cargo.lock b/Cargo.lock index 1a9d6f4..d815106 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -88,6 +88,12 @@ dependencies = [ "winapi", ] +[[package]] +name = "anyhow" +version = "1.0.58" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bb07d2053ccdbe10e2af2995a2f116c1330396493dc1269f6a91d0ae82e19704" + [[package]] name = "api" version = "0.3.2" @@ -270,6 +276,27 @@ dependencies = [ "wasm-bindgen-futures", ] +[[package]] +name = "async-stream" +version = "0.3.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "dad5c83079eae9969be7fadefe640a1c566901f05ff91ab221de4b6f68d9507e" +dependencies = [ + "async-stream-impl", + "futures-core", +] + +[[package]] +name = "async-stream-impl" +version = "0.3.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "10f203db73a71dfa2fb6dd22763990fa26f3d2625a6da2da900d23b87d26be27" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + [[package]] name = "async-task" version = "4.2.0" @@ -310,6 +337,49 @@ version = "1.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "d468802bab17cbc0cc575e9b053f41e72aa36bfa6b7f55e3529ffa43161b97fa" +[[package]] +name = "axum" +version = "0.5.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f4af7447fc1214c1f3a1ace861d0216a6c8bb13965b64bbad9650f375b67689a" +dependencies = [ + "async-trait", + "axum-core", + "bitflags", + "bytes", + "futures-util", + "http", + "http-body", + "hyper", + "itoa 1.0.1", + "matchit", + "memchr", + "mime", + "percent-encoding", + "pin-project-lite", + "serde", + "sync_wrapper", + "tokio", + "tower", + "tower-http", + "tower-layer", + "tower-service", +] + +[[package]] +name = "axum-core" +version = "0.2.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3bdc19781b16e32f8a7200368a336fa4509d4b72ef15dd4e41df5290855ee1e6" +dependencies = [ + "async-trait", + "bytes", + "futures-util", + "http", + "http-body", + "mime", +] + [[package]] name = "backtrace" version = "0.3.65" @@ -596,6 +666,32 @@ dependencies = [ "cache-padded", ] +[[package]] +name = "console" +version = "0.1.0" +dependencies = [ + "console-api", + "crossbeam-channel", + "hyper", + "thread_local", + "tonic", + "tracing", + "tracing-core", + "tracing-subscriber 0.3.9", +] + +[[package]] +name = "console-api" +version = "0.3.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "06c5fd425783d81668ed68ec98408a80498fb4ae2fd607797539e1a9dfa3618f" +dependencies = [ + "prost", + "prost-types", + "tonic", + "tracing-core", +] + [[package]] name = "const_format" version = "0.2.23" @@ -1286,6 +1382,25 @@ dependencies = [ "wasm-bindgen", ] +[[package]] +name = "h2" +version = "0.3.13" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "37a82c6d637fc9515a4694bbf1cb2457b79d81ce52b3108bdeea58b07dd34a57" +dependencies = [ + "bytes", + "fnv", + "futures-core", + "futures-sink", + "futures-util", + "http", + "indexmap", + "slab", + "tokio", + "tokio-util", + "tracing", +] + [[package]] name = "half" version = "1.8.2" @@ -1336,6 +1451,71 @@ dependencies = [ "itoa 1.0.1", ] +[[package]] +name = "http-body" +version = "0.4.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d5f38f16d184e36f2408a55281cd658ecbd3ca05cce6d6510a176eca393e26d1" +dependencies = [ + "bytes", + "http", + "pin-project-lite", +] + +[[package]] +name = "http-range-header" +version = "0.3.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0bfe8eed0a9285ef776bb792479ea3834e8b94e13d615c2f66d03dd50a435a29" + +[[package]] +name = "httparse" +version = "1.7.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "496ce29bb5a52785b44e0f7ca2847ae0bb839c9bd28f69acac9b99d461c0c04c" + +[[package]] +name = "httpdate" +version = "1.0.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c4a1e36c821dbe04574f602848a19f742f4fb3c98d40449f11bcad18d6b17421" + +[[package]] +name = "hyper" +version = "0.14.19" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "42dc3c131584288d375f2d07f822b0cb012d8c6fb899a5b9fdb3cb7eb9b6004f" +dependencies = [ + "bytes", + "futures-channel", + "futures-core", + "futures-util", + "h2", + "http", + "http-body", + "httparse", + "httpdate", + "itoa 1.0.1", + "pin-project-lite", + "socket2", + "tokio", + "tower-service", + "tracing", + "want", +] + +[[package]] +name = "hyper-timeout" +version = "0.4.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bbb958482e8c7be4bc3cf272a766a2b0bf1a6755e7a6ae777f017a31d11b13b1" +dependencies = [ + "hyper", + "pin-project-lite", + "tokio", + "tokio-io-timeout", +] + [[package]] name = "idna" version = "0.2.3" @@ -1594,6 +1774,12 @@ version = "0.1.9" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "a3e378b66a060d48947b590737b30a1be76706c8dd7b8ba0f2fe3989c68a853f" +[[package]] +name = "matchit" +version = "0.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "73cbba799671b762df5a175adf59ce145165747bb891505c43d09aefbbf38beb" + [[package]] name = "memchr" version = "2.4.1" @@ -1640,6 +1826,12 @@ dependencies = [ "syn", ] +[[package]] +name = "mime" +version = "0.3.16" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2a60c7ce501c71e03a9c9c0d35b861413ae925bd979cc7a4e30d060069aaac8d" + [[package]] name = "miniz_oxide" version = "0.5.3" @@ -1985,6 +2177,39 @@ dependencies = [ "unicode-xid", ] +[[package]] +name = "prost" +version = "0.10.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "71adf41db68aa0daaefc69bb30bcd68ded9b9abaad5d1fbb6304c4fb390e083e" +dependencies = [ + "bytes", + "prost-derive", +] + +[[package]] +name = "prost-derive" +version = "0.10.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7b670f45da57fb8542ebdbb6105a925fe571b67f9e7ed9f47a06a84e72b4e7cc" +dependencies = [ + "anyhow", + "itertools 0.10.3", + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "prost-types" +version = "0.10.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2d0a014229361011dc8e69c8a1ec6c2e8d0f2af7c91e3ea3f5b2170298461e68" +dependencies = [ + "bytes", + "prost", +] + [[package]] name = "ptr_meta" version = "0.1.4" @@ -2647,6 +2872,12 @@ dependencies = [ "unicode-xid", ] +[[package]] +name = "sync_wrapper" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "20518fe4a4c9acf048008599e464deb21beeae3d3578418951a189c235a7a9a8" + [[package]] name = "tempfile" version = "3.3.0" @@ -2766,20 +2997,31 @@ checksum = "cda74da7e1a664f795bb1f8a87ec406fb89a02522cf6e50620d016add6dbbf5c" [[package]] name = "tokio" -version = "1.17.0" +version = "1.19.2" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "2af73ac49756f3f7c01172e34a23e5d0216f6c32333757c2c61feb2bbff5a5ee" +checksum = "c51a52ed6686dd62c320f9b89299e9dfb46f730c7a48e635c19f21d116cb1439" dependencies = [ "bytes", "libc", "memchr", "mio", + "once_cell", "pin-project-lite", "socket2", "tokio-macros", "winapi", ] +[[package]] +name = "tokio-io-timeout" +version = "1.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "30b74022ada614a1b4834de765f9bb43877f910cc8ce4be40e89042c9223a8bf" +dependencies = [ + "pin-project-lite", + "tokio", +] + [[package]] name = "tokio-macros" version = "1.7.0" @@ -2802,6 +3044,31 @@ dependencies = [ "webpki", ] +[[package]] +name = "tokio-stream" +version = "0.1.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "df54d54117d6fdc4e4fea40fe1e4e566b3505700e148a6827e59b34b0d2600d9" +dependencies = [ + "futures-core", + "pin-project-lite", + "tokio", +] + +[[package]] +name = "tokio-util" +version = "0.7.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "cc463cd8deddc3770d20f9852143d50bf6094e640b485cb2e189a2099085ff45" +dependencies = [ + "bytes", + "futures-core", + "futures-sink", + "pin-project-lite", + "tokio", + "tracing", +] + [[package]] name = "toml" version = "0.5.8" @@ -2811,6 +3078,89 @@ dependencies = [ "serde", ] +[[package]] +name = "tonic" +version = "0.7.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5be9d60db39854b30b835107500cf0aca0b0d14d6e1c3de124217c23a29c2ddb" +dependencies = [ + "async-stream", + "async-trait", + "axum", + "base64", + "bytes", + "futures-core", + "futures-util", + "h2", + "http", + "http-body", + "hyper", + "hyper-timeout", + "percent-encoding", + "pin-project", + "prost", + "prost-derive", + "tokio", + "tokio-stream", + "tokio-util", + "tower", + "tower-layer", + "tower-service", + "tracing", + "tracing-futures", +] + +[[package]] +name = "tower" +version = "0.4.13" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b8fa9be0de6cf49e536ce1851f987bd21a43b771b09473c3549a6c853db37c1c" +dependencies = [ + "futures-core", + "futures-util", + "indexmap", + "pin-project", + "pin-project-lite", + "rand", + "slab", + "tokio", + "tokio-util", + "tower-layer", + "tower-service", + "tracing", +] + +[[package]] +name = "tower-http" +version = "0.3.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3c530c8675c1dbf98facee631536fa116b5fb6382d7dd6dc1b118d970eafe3ba" +dependencies = [ + "bitflags", + "bytes", + "futures-core", + "futures-util", + "http", + "http-body", + "http-range-header", + "pin-project-lite", + "tower", + "tower-layer", + "tower-service", +] + +[[package]] +name = "tower-layer" +version = "0.3.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "343bc9466d3fe6b0f960ef45960509f84480bf4fd96f92901afe7ff3df9d3a62" + +[[package]] +name = "tower-service" +version = "0.3.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b6bc1c9ce2b5135ac7f93c72918fc37feb872bdc6a5533a8b85eb4b86bfdae52" + [[package]] name = "tracing" version = "0.1.32" @@ -2818,6 +3168,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "4a1bdf54a7c28a2bbf701e1d2233f6c77f473486b94bee4f9678da5a148dca7f" dependencies = [ "cfg-if", + "log", "pin-project-lite", "tracing-attributes", "tracing-core", @@ -2913,6 +3264,12 @@ dependencies = [ "tracing-log", ] +[[package]] +name = "try-lock" +version = "0.2.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "59547bce71d9c38b83d9c0e92b6066c4253371f15005def0c30d9657f50c7642" + [[package]] name = "trybuild" version = "1.0.56" @@ -3054,6 +3411,16 @@ dependencies = [ "winapi-util", ] +[[package]] +name = "want" +version = "0.3.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1ce8a968cb1cd110d136ff8b819a556d6fb6d919363c61534f6860c7eb172ba0" +dependencies = [ + "log", + "try-lock", +] + [[package]] name = "wasi" version = "0.10.2+wasi-snapshot-preview1" diff --git a/runtime/console/Cargo.toml b/runtime/console/Cargo.toml index 45d09e9..592b083 100644 --- a/runtime/console/Cargo.toml +++ b/runtime/console/Cargo.toml @@ -7,4 +7,10 @@ edition = "2021" [dependencies] console-api = "0.3" -tracing = "0.1" \ No newline at end of file +tonic = { version = "0.7.2", default_features = false, features = [] } +hyper = { version = "0.14", default_features = false, features = ["http2", "server", "stream"] } +thread_local = "1.1" +tracing = "0.1" +tracing-core = "0.1" +tracing-subscriber = { version = "0.3", default_features = false, features = ["registry"] } +crossbeam-channel = "0.5" \ No newline at end of file diff --git a/runtime/console/src/aggregate.rs b/runtime/console/src/aggregate.rs new file mode 100644 index 0000000..1c0a5a1 --- /dev/null +++ b/runtime/console/src/aggregate.rs @@ -0,0 +1,12 @@ +use crate::Event; +use crossbeam_channel::Receiver; + +pub(crate) struct Aggregator { + events: Receiver, +} + +impl Aggregator { + pub fn new(events: Receiver) -> Self { + Self { events } + } +} diff --git a/runtime/console/src/callsites.rs b/runtime/console/src/callsites.rs index d10c395..35a0da4 100644 --- a/runtime/console/src/callsites.rs +++ b/runtime/console/src/callsites.rs @@ -30,13 +30,13 @@ impl Callsites { } } - pub(crate) fn contains(&self, callsite: &'static Metadata<'static>) -> bool { + pub(crate) fn contains(&self, callsite: &Metadata<'static>) -> bool { let mut idx = 0; let mut end = self.len.load(Ordering::Acquire); while { for cs in &self.array[idx..end] { let ptr = cs.load(Ordering::Acquire); - let meta = unsafe { ptr as *const _ as &'static Metadata<'static> }; + let meta = unsafe { ptr as *const _ as &Metadata<'static> }; if meta.callsite() == callsite.callsite() { return true; } @@ -55,7 +55,7 @@ impl Callsites { impl Default for Callsites { fn default() -> Self { - const NULLPTR: AtomicPtr<_> = AtomicPtr::new(ptr::null_mut()); + const NULLPTR: AtomicPtr> = AtomicPtr::new(ptr::null_mut()); Self { array: [NULLPTR; MAX_CALLSITES], len: AtomicUsize::new(0), diff --git a/runtime/console/src/event.rs b/runtime/console/src/event.rs new file mode 100644 index 0000000..65b316f --- /dev/null +++ b/runtime/console/src/event.rs @@ -0,0 +1,5 @@ +use tracing_core::Metadata; + +pub(crate) enum Event { + Metadata(&'static Metadata<'static>), +} diff --git a/runtime/console/src/lib.rs b/runtime/console/src/lib.rs index b02b962..b0b8688 100644 --- a/runtime/console/src/lib.rs +++ b/runtime/console/src/lib.rs @@ -1,4 +1,164 @@ +use crossbeam_channel::{Sender, TrySendError}; +use std::any::TypeId; +use std::cell::RefCell; +use std::net::IpAddr; +use std::sync::atomic::{AtomicUsize, Ordering}; +use std::sync::Arc; +use thread_local::ThreadLocal; +use tracing_core::span::{Attributes, Id, Record}; +use tracing_core::{Interest, LevelFilter, Metadata, Subscriber}; +use tracing_subscriber::filter::Filtered; +use tracing_subscriber::layer::{Context, Filter, Layered}; +use tracing_subscriber::registry::LookupSpan; +use tracing_subscriber::Layer; + +mod aggregate; mod callsites; +mod event; +mod server; +mod stack; + +use crate::aggregate::Aggregator; +use crate::callsites::Callsites; +use event::Event; +pub use server::Server; +use stack::SpanStack; + +pub struct ConsoleLayer { + current_spans: ThreadLocal>, + + tx: Sender, + shared: Arc, + + spawn_callsites: Callsites<8>, + waker_callsites: Callsites<8>, +} + +#[derive(Debug)] +pub struct Builder { + /// Network Address the console server will listen on + server_addr: IpAddr, + /// Network Port the console server will listen on + server_port: u16, + + /// Number of events that can be buffered before events are dropped. + /// + /// A smaller number will reduce the memory footprint but may lead to more events being dropped + /// during activity bursts. + event_buffer_capacity: usize, +} +impl Builder { + pub fn build(self) -> (ConsoleLayer, Server) { + ConsoleLayer::build(self) + } +} +impl Default for Builder { + fn default() -> Self { + Self { + // Listen on `::1` (aka localhost) by default + server_addr: Server::DEFAULT_ADDR, + server_port: Server::DEFAULT_PORT, + event_buffer_capacity: ConsoleLayer::DEFAULT_EVENT_BUFFER_CAPACITY, + } + } +} + +#[derive(Debug, Default)] +struct Shared { + dropped_tasks: AtomicUsize, + dropped_resources: AtomicUsize, +} + +impl ConsoleLayer { + pub fn new() -> (Self, Server) { + Self::builder().build() + } + pub fn builder() -> Builder { + Builder::default() + } + fn build(config: Builder) -> (Self, Server) { + tracing::debug!( + ?config.server_addr, + config.event_buffer_capacity, + "configured console subscriber" + ); + + let (tx, events) = crossbeam_channel::bounded(config.event_buffer_capacity); + let shared = Arc::new(Shared::default()); + let aggregator = Aggregator::new(events); + let server = Server::new(aggregator); + let layer = Self { + current_spans: ThreadLocal::new(), + tx, + shared, + spawn_callsites: Callsites::default(), + waker_callsites: Callsites::default(), + }; + + (layer, server) + } +} + +impl ConsoleLayer { + const DEFAULT_EVENT_BUFFER_CAPACITY: usize = 1024; + const DEFAULT_CLIENT_BUFFER_CAPACITY: usize = 1024; + + fn is_spawn(&self, metadata: &Metadata<'static>) -> bool { + self.spawn_callsites.contains(metadata) + } + + fn is_waker(&self, metadata: &Metadata<'static>) -> bool { + self.waker_callsites.contains(metadata) + } + + fn send_stats( + &self, + dropped: &AtomicUsize, + mkEvent: impl FnOnce() -> (Event, S), + ) -> Option { + if self.tx.is_full() { + dropped.fetch_add(1, Ordering::Release); + return None; + } + + let (event, stats) = mkEvent(); + match self.tx.try_send(event) { + Ok(()) => Some(stats), + Err(TrySendError::Full(_)) => { + dropped.fetch_add(1, Ordering::Release); + None + } + Err(TrySendError::Disconnected(_)) => None, + } + } + + fn send_metadata(&self, dropped: &AtomicUsize, event: Event) -> bool { + self.send_stats(dropped, || (event, ())).is_some() + } +} + +impl Layer for ConsoleLayer +where + S: Subscriber + for<'a> LookupSpan<'a>, +{ + fn register_callsite(&self, metadata: &'static Metadata<'static>) -> Interest { + let dropped = match (metadata.name(), metadata.target()) { + (_, "executor::spawn") => { + self.spawn_callsites.insert(metadata); + &self.shared.dropped_tasks + } + (_, "executor::waker") => { + self.waker_callsites.insert(metadata); + &self.shared.dropped_tasks + } + (_, _) => &self.shared.dropped_tasks, + }; + + self.send_metadata(dropped, Event::Metadata(metadata)); + + Interest::always() + } +} #[cfg(test)] mod tests { diff --git a/runtime/console/src/server.rs b/runtime/console/src/server.rs new file mode 100644 index 0000000..2bf0ba1 --- /dev/null +++ b/runtime/console/src/server.rs @@ -0,0 +1,95 @@ +use crate::Aggregator; +use console_api::instrument::instrument_server::{Instrument, InstrumentServer}; +use console_api::instrument::{ + InstrumentRequest, PauseRequest, PauseResponse, ResumeRequest, ResumeResponse, + TaskDetailsRequest, +}; +use std::error::Error; +use std::net::{IpAddr, Ipv6Addr}; + +pub struct Server { + aggregator: Aggregator, + client_buffer_size: usize, +} + +impl Server { + pub(crate) const DEFAULT_ADDR: IpAddr = IpAddr::V6(Ipv6Addr::new(0, 0, 0, 0, 0, 0, 0, 1)); + pub(crate) const DEFAULT_PORT: u16 = 49289; + + pub(crate) fn new(aggregator: Aggregator, client_buffer_size: usize) -> Self { + Self { + aggregator, + client_buffer_size, + } + } + + pub(crate) async fn serve( + mut self, /*, incoming: I */ + ) -> Result<(), Box> { + // TODO: Spawn two tasks; the aggregator that's collecting stats, aggregating and + // collating them and the server task doing the tonic gRPC stuff + + let svc = InstrumentServer::new(self); + + // The gRPC server task; requires a `Stream` of `tokio::AsyncRead + tokio::AsyncWrite`. + // TODO: Pass an async listening socket that implements the tokio versions of Read/Write + let incoming = todo!(); + tonic::transport::Server::builder() + .add_service(svc) + .serve_with_incoming(incoming) + .await?; + + // TODO: Kill the aggregator task if the serve task has ended. + + Ok(()) + } +} + +#[tonic::async_trait] +impl Instrument for Server { + type WatchUpdatesStream = (); + + async fn watch_updates( + &self, + request: tonic::Request, + ) -> Result, tonic::Status> { + /* + match request.remote_addr() { + Some(addr) => tracing::debug!(client.addr = %addr, "starting a new watch"), + None => tracing::debug!(client.addr = %"", "starting a new watch"), + } + let permit = self.subscribe.reserve().await.map_err(|_| { + tonic::Status::internal("cannot start new watch, aggregation task is not running") + })?; + let (tx, rx) = mpsc::channel(self.client_buffer); + permit.send(Command::Instrument(Watch(tx))); + tracing::debug!("watch started"); + let stream = tokio_stream::wrappers::ReceiverStream::new(rx); + Ok(tonic::Response::new(stream)) + */ + todo!() + } + + type WatchTaskDetailsStream = (); + + async fn watch_task_details( + &self, + request: tonic::Request, + ) -> Result, tonic::Status> { + todo!() + } + + async fn pause( + &self, + request: tonic::Request, + ) -> Result, tonic::Status> { + todo!() + } + + async fn resume( + &self, + request: tonic::Request, + ) -> Result, tonic::Status> { + todo!() + } +} diff --git a/runtime/console/src/stack.rs b/runtime/console/src/stack.rs new file mode 100644 index 0000000..2bed34d --- /dev/null +++ b/runtime/console/src/stack.rs @@ -0,0 +1,64 @@ +use tracing_core::span::Id; + +// This has been copied from tracing-subscriber. Once the library adds +// the ability to iterate over entered spans, this code will +// no longer be needed here +// +// https://github.com/tokio-rs/tracing/blob/master/tracing-subscriber/src/registry/stack.rs +#[derive(Debug, Clone)] +pub(crate) struct ContextId { + id: Id, + duplicate: bool, +} + +impl ContextId { + pub fn id(&self) -> &Id { + &self.id + } +} + +/// `SpanStack` tracks what spans are currently executing on a thread-local basis. +/// +/// A "separate current span" for each thread is a semantic choice, as each span +/// can be executing in a different thread. +#[derive(Debug, Default)] +pub(crate) struct SpanStack { + stack: Vec, +} + +impl SpanStack { + #[inline] + pub(crate) fn push(&mut self, id: Id) -> bool { + let duplicate = self.stack.iter().any(|i| i.id == id); + self.stack.push(ContextId { id, duplicate }); + !duplicate + } + + /// Pop a currently entered span. + /// + /// Returns `true` if the span was actually exited. + #[inline] + pub(crate) fn pop(&mut self, expected_id: &Id) -> bool { + if let Some((idx, _)) = self + .stack + .iter() + .enumerate() + .rev() + .find(|(_, ctx_id)| ctx_id.id == *expected_id) + { + let ContextId { id: _, duplicate } = self.stack.remove(idx); + return !duplicate; + } + false + } + + pub(crate) fn iter(&self) -> impl Iterator { + self.stack + .iter() + .filter_map(|ContextId { id, duplicate }| if *duplicate { None } else { Some(id) }) + } + + pub(crate) fn stack(&self) -> &Vec { + &self.stack + } +} From ee0593dc6fb76cf9ecb56719a0c69eb17750aa0a Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Tue, 21 Jun 2022 16:21:13 +0200 Subject: [PATCH 03/17] Use `ManuallyDrop` instead of `mem::forget` where appropiate --- runtime/executor/src/pool.rs | 27 +++++++++++++++++++++++++++ runtime/lightproc/src/lightproc.rs | 10 +++++----- 2 files changed, 32 insertions(+), 5 deletions(-) diff --git a/runtime/executor/src/pool.rs b/runtime/executor/src/pool.rs index a900d24..ff422d1 100644 --- a/runtime/executor/src/pool.rs +++ b/runtime/executor/src/pool.rs @@ -20,6 +20,9 @@ use std::marker::PhantomData; use std::mem::MaybeUninit; use std::sync::Arc; use std::time::Duration; +use tracing::field::FieldSet; +use tracing::metadata::Kind; +use tracing::{Level, Span}; #[derive(Debug)] struct Spooler<'a> { @@ -45,12 +48,21 @@ impl Spooler<'_> { /// Global executor pub struct Executor<'a> { spooler: Arc>, + span: Span, } impl<'a, 'executor: 'a> Executor<'executor> { pub fn new() -> Self { Executor { spooler: Arc::new(Spooler::new()), + span: tracing::span!(Level::INFO, "executor"), + } + } + + pub fn new_with_parent_span(parent: &Span) -> Self { + Executor { + spooler: Arc::new(Spooler::new()), + span: tracing::span!(parent: parent, Level::INFO, "executor"), } } @@ -99,7 +111,15 @@ impl<'a, 'executor: 'a> Executor<'executor> { F: Future + Send + 'a, R: Send + 'a, { + let span = tracing::info_span!( + parent: &self.span, + //target: "executor::spawn", + "runtime.spawn" + ); + let _guard = span.enter(); + let (task, handle) = LightProc::recoverable(future, self.schedule()); + tracing::trace!("spawning sendable task"); task.schedule(); handle } @@ -109,7 +129,14 @@ impl<'a, 'executor: 'a> Executor<'executor> { F: Future + 'a, R: Send + 'a, { + let span = tracing::info_span!( + parent: &self.span, + //target: "executor::spawn", + "runtime.spawn_local" + ); + let _guard = span.enter(); let (task, handle) = LightProc::recoverable(future, schedule_local()); + tracing::trace!("spawning sendable task"); task.schedule(); handle } diff --git a/runtime/lightproc/src/lightproc.rs b/runtime/lightproc/src/lightproc.rs index 3d59379..c94b5fa 100644 --- a/runtime/lightproc/src/lightproc.rs +++ b/runtime/lightproc/src/lightproc.rs @@ -33,7 +33,7 @@ use crate::raw_proc::RawProc; use crate::recoverable_handle::RecoverableHandle; use std::fmt::{self, Debug, Formatter}; use std::future::Future; -use std::mem; +use std::mem::ManuallyDrop; use std::panic::AssertUnwindSafe; use std::ptr::NonNull; @@ -130,9 +130,9 @@ impl LightProc { /// /// Schedule the lightweight process with passed `schedule` function at the build time. pub fn schedule(self) { - let ptr = self.raw_proc.as_ptr(); + let this = ManuallyDrop::new(self); + let ptr = this.raw_proc.as_ptr(); let pdata = ptr as *const ProcData; - mem::forget(self); unsafe { ((*pdata).vtable.schedule)(ptr); @@ -144,9 +144,9 @@ impl LightProc { /// "Running" a lightproc means ticking it once and if it doesn't complete /// immediately re-scheduling it as soon as it's Waker wakes it back up. pub fn run(self) { - let ptr = self.raw_proc.as_ptr(); + let this = ManuallyDrop::new(self); + let ptr = this.raw_proc.as_ptr(); let pdata = ptr as *const ProcData; - mem::forget(self); unsafe { ((*pdata).vtable.tick)(ptr); From 35c9f45f6d35711c7902ae4c97fbf9908482e819 Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Tue, 21 Jun 2022 19:11:57 +0200 Subject: [PATCH 04/17] More console features --- Cargo.lock | 62 +++++- runtime/console/Cargo.toml | 13 +- runtime/console/src/aggregate.rs | 369 ++++++++++++++++++++++++++++++- runtime/console/src/attribute.rs | 30 +++ runtime/console/src/callsites.rs | 2 +- runtime/console/src/event.rs | 38 ++++ runtime/console/src/lib.rs | 10 +- runtime/console/src/server.rs | 191 +++++++++++++--- runtime/console/src/stats.rs | 161 ++++++++++++++ 9 files changed, 838 insertions(+), 38 deletions(-) create mode 100644 runtime/console/src/attribute.rs create mode 100644 runtime/console/src/stats.rs diff --git a/Cargo.lock b/Cargo.lock index d815106..d9e4bbb 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -8,7 +8,7 @@ version = "0.6.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "47feb9fbcef700639ef28e04ca2a87eab8161a01a075ee227b15c90143805462" dependencies = [ - "nom", + "nom 5.1.2", ] [[package]] @@ -670,10 +670,21 @@ dependencies = [ name = "console" version = "0.1.0" dependencies = [ + "async-channel", + "async-compat", + "async-io", + "async-net", + "async-oneshot", "console-api", "crossbeam-channel", + "crossbeam-utils", + "futures-util", + "hdrhistogram", "hyper", + "prost-types", "thread_local", + "tokio", + "tokio-util", "tonic", "tracing", "tracing-core", @@ -743,6 +754,15 @@ dependencies = [ "libc", ] +[[package]] +name = "crc32fast" +version = "1.3.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b540bd8bc810d3885c6ea91e2018302f68baba2129ab3e88f32389ee9370880d" +dependencies = [ + "cfg-if", +] + [[package]] name = "criterion" version = "0.3.5" @@ -1126,6 +1146,16 @@ dependencies = [ "instant", ] +[[package]] +name = "flate2" +version = "1.0.24" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f82b0f4c27ad9f8bfd1f3208d882da2b09c301bc1c828fd3a00d0216d2fbbff6" +dependencies = [ + "crc32fast", + "miniz_oxide", +] + [[package]] name = "fnv" version = "1.0.7" @@ -1422,6 +1452,20 @@ dependencies = [ "ahash", ] +[[package]] +name = "hdrhistogram" +version = "7.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "31672b7011be2c4f7456c4ddbcb40e7e9a4a9fad8efe49a6ebaf5f307d0109c0" +dependencies = [ + "base64", + "byteorder", + "crossbeam-channel", + "flate2", + "nom 7.1.1", + "num-traits", +] + [[package]] name = "hermit-abi" version = "0.1.19" @@ -1832,6 +1876,12 @@ version = "0.3.16" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "2a60c7ce501c71e03a9c9c0d35b861413ae925bd979cc7a4e30d060069aaac8d" +[[package]] +name = "minimal-lexical" +version = "0.2.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "68354c5c6bd36d73ff3feceb05efa59b6acb7626617f4962be322a825e61f79a" + [[package]] name = "miniz_oxide" version = "0.5.3" @@ -1888,6 +1938,16 @@ dependencies = [ "version_check", ] +[[package]] +name = "nom" +version = "7.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a8903e5a29a317527874d0402f867152a3d21c908bb0b933e416c65e301d4c36" +dependencies = [ + "memchr", + "minimal-lexical", +] + [[package]] name = "ntapi" version = "0.3.7" diff --git a/runtime/console/Cargo.toml b/runtime/console/Cargo.toml index 592b083..fd823e8 100644 --- a/runtime/console/Cargo.toml +++ b/runtime/console/Cargo.toml @@ -7,10 +7,21 @@ edition = "2021" [dependencies] console-api = "0.3" +prost-types = "0.10" tonic = { version = "0.7.2", default_features = false, features = [] } hyper = { version = "0.14", default_features = false, features = ["http2", "server", "stream"] } thread_local = "1.1" tracing = "0.1" tracing-core = "0.1" tracing-subscriber = { version = "0.3", default_features = false, features = ["registry"] } -crossbeam-channel = "0.5" \ No newline at end of file +crossbeam-utils = "0.8" +crossbeam-channel = "0.5" +async-net = "1.6" +async-compat = "0.2" +async-channel = "1.6" +async-oneshot = "0.5" +async-io = "1.7" +tokio-util = "0.7" +futures-util = "0.3" +tokio = { version = "1.19", default_features = false, features = []} +hdrhistogram = "7.5" \ No newline at end of file diff --git a/runtime/console/src/aggregate.rs b/runtime/console/src/aggregate.rs index 1c0a5a1..25fb192 100644 --- a/runtime/console/src/aggregate.rs +++ b/runtime/console/src/aggregate.rs @@ -1,12 +1,375 @@ +use crate::server::{Watch, WatchRequest}; +use crate::stats::TimeAnchor; use crate::Event; -use crossbeam_channel::Receiver; +use crate::{server, stats}; +use console_api::{async_ops, instrument, resources, tasks}; +use crossbeam_channel::{Receiver, TryRecvError}; +use futures_util::{FutureExt, StreamExt}; +use std::num::NonZeroU64; +use std::sync::atomic::AtomicBool; +use std::sync::Arc; +use std::time::{Duration, Instant}; +use tracing_core::Metadata; + +#[derive(Copy, Clone, Debug, PartialEq, Eq, Hash)] +pub(crate) struct Id(NonZeroU64); + +impl Id { + pub fn from_non_zero_u64(u: NonZeroU64) -> Self { + Self(u) + } +} + +impl Into for Id { + fn into(self) -> console_api::Id { + console_api::Id { id: self.0.into() } + } +} + +struct Resource { + id: Id, + is_dirty: AtomicBool, + parent_id: Option, + metadata: &'static Metadata<'static>, + concrete_type: String, + kind: resources::resource::Kind, + location: Option, + is_internal: bool, +} + +/// Represents static data for tasks +struct Task { + id: Id, + is_dirty: AtomicBool, + metadata: &'static Metadata<'static>, + fields: Vec, + location: Option, +} + +struct AsyncOp { + id: Id, + is_dirty: AtomicBool, + parent_id: Option, + resource_id: Id, + metadata: &'static Metadata<'static>, + source: String, +} + +#[derive(Copy, Clone, Eq, PartialEq)] +pub(crate) enum Include { + All, + UpdatedOnly, +} + +type IdMap = std::collections::HashMap; pub(crate) struct Aggregator { events: Receiver, + rpcs: async_channel::Receiver, + watchers: Vec>, + details_watchers: IdMap>>, + all_metadata: Vec, + new_metadata: Vec, + running: bool, + publish_interval: Duration, + base_time: TimeAnchor, + tasks: IdMap, + task_stats: IdMap>, + resources: IdMap, + resource_stats: IdMap>, + async_ops: IdMap, + async_op_stats: IdMap>, + poll_ops: Vec, } impl Aggregator { - pub fn new(events: Receiver) -> Self { - Self { events } + pub fn new(events: Receiver, rpcs: async_channel::Receiver) -> Self { + Self { + events, + rpcs, + watchers: Vec::new(), + details_watchers: IdMap::new(), + running: true, + publish_interval: Duration::from_secs(1), + all_metadata: Vec::new(), + new_metadata: Vec::new(), + base_time: TimeAnchor::new(), + tasks: IdMap::new(), + task_stats: IdMap::new(), + resources: IdMap::new(), + resource_stats: IdMap::new(), + async_ops: IdMap::new(), + async_op_stats: IdMap::new(), + poll_ops: Vec::new(), + } + } + + fn add_instrument_subscription(&mut self, subscription: Watch) { + tracing::debug!("new instrument subscription"); + + let task_update = Some(self.task_update(Include::All)); + let resource_update = Some(self.resource_update(Include::All)); + let async_op_update = Some(self.async_op_update(Include::All)); + let now = Instant::now(); + + let update = &instrument::Update { + task_update, + resource_update, + async_op_update, + now: Some(self.base_time.to_timestamp(now)), + new_metadata: Some(console_api::RegisterMetadata { + metadata: (self.all_metadata).clone(), + }), + }; + + // Send the initial state --- if this fails, the subscription is already dead + if subscription.update(update) { + self.watchers.push(subscription) + } + } + + /// Add the task details subscription to the watchers after sending the first update, + /// if the task is found. + fn add_task_detail_subscription( + &mut self, + watch_request: WatchRequest, + ) { + let WatchRequest { + id, + mut stream_sender, + buffer, + } = watch_request; + tracing::debug!(id = ?id, "new task details subscription"); + if let Some(stats) = self.task_stats.get(&id) { + let (tx, rx) = async_channel::bounded(buffer); + let subscription = Watch(tx); + let now = Some(self.base_time.to_timestamp(Instant::now())); + // Send back the stream receiver. + // Then send the initial state --- if this fails, the subscription is already dead. + if stream_sender.send(rx).is_ok() + && subscription.update(&console_api::tasks::TaskDetails { + task_id: Some(id.clone().into()), + now, + poll_times_histogram: Some(stats.poll_duration_histogram()), + }) + { + self.details_watchers + .entry(id.clone()) + .or_insert_with(Vec::new) + .push(subscription); + } + } + // If the task is not found, drop `stream_sender` which will result in a not found error + } + + fn task_update(&mut self, include: Include) -> tasks::TaskUpdate { + todo!() + } + + fn resource_update(&mut self, include: Include) -> resources::ResourceUpdate { + todo!() + } + + fn async_op_update(&mut self, include: Include) -> async_ops::AsyncOpUpdate { + todo!() + } + + pub async fn run(mut self) { + let mut timer = StreamExt::fuse(async_io::Timer::interval(self.publish_interval)); + loop { + let mut recv = self.rpcs.recv().fuse(); + let should_send: bool = futures_util::select! { + _ = timer.next() => self.running, + cmd = recv => { + match cmd { + Ok(server::Command::Instrument(subscription)) => { + self.add_instrument_subscription(subscription); + } + Ok(server::Command::WatchTaskDetail(request)) => { + } + Ok(server::Command::Pause) => { + self.running = false; + } + Ok(server::Command::Resume) => { + self.running = true; + } + Err(_) => { + tracing::debug!("rpc channel closed, exiting"); + return + } + } + false + }, + }; + + // drain and aggregate buffered events. + // + // Note: we *don't* want to actually await the call to `recv` --- we + // don't want the aggregator task to be woken on every event, + // because it will then be woken when its own `poll` calls are + // exited. that would result in a busy-loop. instead, we only want + // to be woken when the flush interval has elapsed, or when the + // channel is almost full. + let mut drained = false; + while let Ok(event) = self.events.try_recv() { + self.update_state(event); + } + if let Err(TryRecvError::Disconnected) = self.events.try_recv() { + tracing::debug!("event channel closed; terminating"); + return; + } + + // flush data to clients, if there are any currently subscribed + // watchers and we should send a new update. + if !self.watchers.is_empty() && should_send { + self.publish(); + } + } + } + + fn publish(&mut self) { + let new_metadata = if !self.new_metadata.is_empty() { + Some(console_api::RegisterMetadata { + metadata: std::mem::take(&mut self.new_metadata), + }) + } else { + None + }; + let task_update = Some(self.task_update(Include::UpdatedOnly)); + let resource_update = Some(self.resource_update(Include::UpdatedOnly)); + let async_op_update = Some(self.async_op_update(Include::UpdatedOnly)); + + let update = instrument::Update { + now: Some(self.base_time.to_timestamp(Instant::now())), + new_metadata, + task_update, + resource_update, + async_op_update, + }; + + //self.watchers.retain_and_shrink(|watch: &Watch| watch.update + // (&update)); + + let stats = &self.task_stats; + // Assuming there are much fewer task details subscribers than there are + // stats updates, iterate over `details_watchers` and compact the map. + /*self.details_watchers.retain_and_shrink(|id, watchers| { + if let Some(task_stats) = stats.get(id) { + let details = tasks::TaskDetails { + task_id: Some(id.clone().into()), + now: Some(self.base_time.to_timestamp(Instant::now())), + poll_times_histogram: Some(task_stats.poll_duration_histogram()), + }; + watchers.retain(|watch| watch.update(&details)); + !watchers.is_empty() + } else { + false + } + }); + + */ + } + + /// Update the current state with data from a single event. + fn update_state(&mut self, event: Event) { + // do state update + match event { + Event::Metadata(meta) => { + self.all_metadata.push(meta.into()); + self.new_metadata.push(meta.into()); + } + + Event::Spawn { + id, + metadata, + stats, + fields, + location, + } => { + self.tasks.insert( + id.clone(), + Task { + id: id.clone(), + is_dirty: AtomicBool::new(true), + metadata, + fields, + location, + // TODO: parents + }, + ); + + self.task_stats.insert(id, stats); + } + + Event::Resource { + id, + parent_id, + metadata, + kind, + concrete_type, + location, + is_internal, + stats, + } => { + self.resources.insert( + id.clone(), + Resource { + id: id.clone(), + is_dirty: AtomicBool::new(true), + parent_id, + kind, + metadata, + concrete_type, + location, + is_internal, + }, + ); + + self.resource_stats.insert(id, stats); + } + + Event::PollOp { + metadata, + resource_id, + op_name, + async_op_id, + task_id, + is_ready, + } => { + let poll_op = resources::PollOp { + metadata: Some(metadata.into()), + resource_id: Some(resource_id.into()), + name: op_name, + task_id: Some(task_id.into()), + async_op_id: Some(async_op_id.into()), + is_ready, + }; + + self.poll_ops.push(poll_op); + } + + Event::AsyncResourceOp { + id, + source, + resource_id, + metadata, + parent_id, + stats, + } => { + self.async_ops.insert( + id.clone(), + AsyncOp { + id: id.clone(), + is_dirty: AtomicBool::new(true), + resource_id, + metadata, + source, + parent_id, + }, + ); + + self.async_op_stats.insert(id, stats); + } + } } } diff --git a/runtime/console/src/attribute.rs b/runtime/console/src/attribute.rs new file mode 100644 index 0000000..55c2eb8 --- /dev/null +++ b/runtime/console/src/attribute.rs @@ -0,0 +1,30 @@ +use crate::aggregate::Id; +use std::collections::HashMap; + +#[derive(Debug, Default)] +pub(crate) struct Attributes { + attributes: HashMap, +} + +#[derive(Debug, Clone)] +pub(crate) struct Update { + pub(crate) field: console_api::Field, + pub(crate) op: Option, + pub(crate) unit: Option, +} + +#[derive(Debug, Clone)] +pub(crate) enum UpdateOp { + Add, + Override, + Sub, +} + +/// Represents a key for a `proto::field::Name`. Because the +/// proto::field::Name might not be unique we also include the +/// resource id in this key +#[derive(Debug, Hash, PartialEq, Eq)] +struct FieldKey { + update_id: Id, + field_name: console_api::field::Name, +} diff --git a/runtime/console/src/callsites.rs b/runtime/console/src/callsites.rs index 35a0da4..803a86a 100644 --- a/runtime/console/src/callsites.rs +++ b/runtime/console/src/callsites.rs @@ -36,7 +36,7 @@ impl Callsites { while { for cs in &self.array[idx..end] { let ptr = cs.load(Ordering::Acquire); - let meta = unsafe { ptr as *const _ as &Metadata<'static> }; + let meta = unsafe { &*ptr }; if meta.callsite() == callsite.callsite() { return true; } diff --git a/runtime/console/src/event.rs b/runtime/console/src/event.rs index 65b316f..d681715 100644 --- a/runtime/console/src/event.rs +++ b/runtime/console/src/event.rs @@ -1,5 +1,43 @@ +use crate::aggregate::Id; +use crate::stats; +use console_api::resources; +use std::sync::Arc; use tracing_core::Metadata; pub(crate) enum Event { Metadata(&'static Metadata<'static>), + Spawn { + id: Id, + metadata: &'static Metadata<'static>, + stats: Arc, + fields: Vec, + location: Option, + }, + Resource { + id: Id, + parent_id: Option, + metadata: &'static Metadata<'static>, + concrete_type: String, + kind: resources::resource::Kind, + location: Option, + is_internal: bool, + stats: Arc, + }, + PollOp { + metadata: &'static Metadata<'static>, + resource_id: Id, + op_name: String, + async_op_id: Id, + task_id: Id, + is_ready: bool, + }, + AsyncResourceOp { + id: Id, + parent_id: Option, + resource_id: Id, + metadata: &'static Metadata<'static>, + source: String, + + stats: Arc, + }, } diff --git a/runtime/console/src/lib.rs b/runtime/console/src/lib.rs index b0b8688..de46432 100644 --- a/runtime/console/src/lib.rs +++ b/runtime/console/src/lib.rs @@ -13,10 +13,12 @@ use tracing_subscriber::registry::LookupSpan; use tracing_subscriber::Layer; mod aggregate; +mod attribute; mod callsites; mod event; mod server; mod stack; +mod stats; use crate::aggregate::Aggregator; use crate::callsites::Callsites; @@ -46,6 +48,8 @@ pub struct Builder { /// A smaller number will reduce the memory footprint but may lead to more events being dropped /// during activity bursts. event_buffer_capacity: usize, + + client_buffer_capacity: usize, } impl Builder { pub fn build(self) -> (ConsoleLayer, Server) { @@ -59,6 +63,7 @@ impl Default for Builder { server_addr: Server::DEFAULT_ADDR, server_port: Server::DEFAULT_PORT, event_buffer_capacity: ConsoleLayer::DEFAULT_EVENT_BUFFER_CAPACITY, + client_buffer_capacity: 1024, } } } @@ -85,8 +90,9 @@ impl ConsoleLayer { let (tx, events) = crossbeam_channel::bounded(config.event_buffer_capacity); let shared = Arc::new(Shared::default()); - let aggregator = Aggregator::new(events); - let server = Server::new(aggregator); + let (subscribe, rpcs) = async_channel::bounded(config.client_buffer_capacity); + let aggregator = Aggregator::new(events, rpcs); + let server = Server::new(aggregator, config.client_buffer_capacity, subscribe); let layer = Self { current_spans: ThreadLocal::new(), tx, diff --git a/runtime/console/src/server.rs b/runtime/console/src/server.rs index 2bf0ba1..5591206 100644 --- a/runtime/console/src/server.rs +++ b/runtime/console/src/server.rs @@ -1,25 +1,93 @@ +use crate::aggregate::Id; use crate::Aggregator; +use async_channel::{Receiver, Sender}; +use console_api::instrument; use console_api::instrument::instrument_server::{Instrument, InstrumentServer}; -use console_api::instrument::{ - InstrumentRequest, PauseRequest, PauseResponse, ResumeRequest, ResumeResponse, - TaskDetailsRequest, -}; +use console_api::tasks; +use futures_util::TryStreamExt; use std::error::Error; -use std::net::{IpAddr, Ipv6Addr}; +use std::io::IoSlice; +use std::net::{IpAddr, Ipv6Addr, SocketAddr}; +use std::pin::Pin; +use std::task::{Context, Poll}; +use tokio::io::AsyncRead as TokioAsyncRead; +use tokio::io::{AsyncWrite as TokioAsyncWrite, ReadBuf}; +use tonic::transport::server::Connected; +use tonic::Status; + +struct StreamWrapper(T); +impl Connected for StreamWrapper { + type ConnectInfo = (); + + fn connect_info(&self) -> Self::ConnectInfo { + () + } +} +impl TokioAsyncWrite for StreamWrapper { + fn poll_write( + mut self: Pin<&mut Self>, + cx: &mut Context<'_>, + buf: &[u8], + ) -> Poll> { + TokioAsyncWrite::poll_write(Pin::new(&mut self.0), cx, buf) + } + + fn poll_flush( + mut self: Pin<&mut Self>, + cx: &mut Context<'_>, + ) -> Poll> { + TokioAsyncWrite::poll_flush(Pin::new(&mut self.0), cx) + } + + fn poll_shutdown( + mut self: Pin<&mut Self>, + cx: &mut Context<'_>, + ) -> Poll> { + TokioAsyncWrite::poll_shutdown(Pin::new(&mut self.0), cx) + } + + fn poll_write_vectored( + mut self: Pin<&mut Self>, + cx: &mut Context<'_>, + bufs: &[IoSlice<'_>], + ) -> Poll> { + TokioAsyncWrite::poll_write_vectored(Pin::new(&mut self.0), cx, bufs) + } + + fn is_write_vectored(&self) -> bool { + TokioAsyncWrite::is_write_vectored(&self.0) + } +} +impl TokioAsyncRead for StreamWrapper { + fn poll_read( + mut self: Pin<&mut Self>, + cx: &mut Context<'_>, + buf: &mut ReadBuf<'_>, + ) -> Poll> { + TokioAsyncRead::poll_read(Pin::new(&mut self.0), cx, buf) + } +} pub struct Server { aggregator: Aggregator, client_buffer_size: usize, + subscribe: Sender, } impl Server { pub(crate) const DEFAULT_ADDR: IpAddr = IpAddr::V6(Ipv6Addr::new(0, 0, 0, 0, 0, 0, 0, 1)); pub(crate) const DEFAULT_PORT: u16 = 49289; - pub(crate) fn new(aggregator: Aggregator, client_buffer_size: usize) -> Self { + pub(crate) fn new( + aggregator: Aggregator, + client_buffer_size: usize, + subscribe: Sender, + ) -> Self { + let subscribe = todo!(); Self { aggregator, client_buffer_size, + subscribe, } } @@ -32,8 +100,12 @@ impl Server { let svc = InstrumentServer::new(self); // The gRPC server task; requires a `Stream` of `tokio::AsyncRead + tokio::AsyncWrite`. - // TODO: Pass an async listening socket that implements the tokio versions of Read/Write - let incoming = todo!(); + let listener = + async_net::TcpListener::bind(SocketAddr::new(Self::DEFAULT_ADDR, Self::DEFAULT_PORT)) + .await?; + let incoming = listener + .incoming() + .map_ok(|stream| StreamWrapper(async_compat::Compat::new(stream))); tonic::transport::Server::builder() .add_service(svc) .serve_with_incoming(incoming) @@ -45,51 +117,110 @@ impl Server { } } +pub(crate) struct Watch(pub(crate) Sender>); +impl Watch { + pub fn update(&self, update: &T) -> bool { + self.0.try_send(Ok(update.clone())).is_ok() + } +} + +pub(crate) struct WatchRequest { + pub id: Id, + pub stream_sender: async_oneshot::Sender>>, + pub buffer: usize, +} + +pub(crate) enum Command { + Instrument(Watch), + WatchTaskDetail(WatchRequest), + Pause, + Resume, +} + #[tonic::async_trait] impl Instrument for Server { - type WatchUpdatesStream = (); + type WatchUpdatesStream = async_channel::Receiver>; async fn watch_updates( &self, - request: tonic::Request, + request: tonic::Request, ) -> Result, tonic::Status> { - /* match request.remote_addr() { Some(addr) => tracing::debug!(client.addr = %addr, "starting a new watch"), None => tracing::debug!(client.addr = %"", "starting a new watch"), } - let permit = self.subscribe.reserve().await.map_err(|_| { - tonic::Status::internal("cannot start new watch, aggregation task is not running") - })?; - let (tx, rx) = mpsc::channel(self.client_buffer); - permit.send(Command::Instrument(Watch(tx))); - tracing::debug!("watch started"); - let stream = tokio_stream::wrappers::ReceiverStream::new(rx); - Ok(tonic::Response::new(stream)) - */ - todo!() + + if !self.subscribe.is_full() { + let (tx, rx) = async_channel::bounded(self.client_buffer_size); + self.subscribe.send(Command::Instrument(Watch(tx))).await; + tracing::debug!("watch started"); + Ok(tonic::Response::new(rx)) + } else { + Err(tonic::Status::internal( + "cannot start new watch, aggregation task is not running", + )) + } } - type WatchTaskDetailsStream = (); + type WatchTaskDetailsStream = async_channel::Receiver>; async fn watch_task_details( &self, - request: tonic::Request, + request: tonic::Request, ) -> Result, tonic::Status> { - todo!() + let task_id = request + .into_inner() + .id + .ok_or_else(|| tonic::Status::invalid_argument("missing task_id"))? + .id; + + // `tracing` reserves span ID 0 for niche optimization for `Option`. + let id = std::num::NonZeroU64::new(task_id) + .map(Id::from_non_zero_u64) + .ok_or_else(|| tonic::Status::invalid_argument("task_id cannot be 0"))?; + + if !self.subscribe.is_full() { + // Check with the aggregator task to request a stream if the task exists. + let (stream_sender, stream_recv) = async_oneshot::oneshot(); + self.subscribe + .send(Command::WatchTaskDetail(WatchRequest { + id, + stream_sender, + buffer: self.client_buffer_size, + })) + .await; + // If the aggregator drops the sender, the task doesn't exist. + let rx = stream_recv.await.map_err(|_| { + tracing::warn!(id = ?task_id, "requested task not found"); + tonic::Status::not_found("task not found") + })?; + + tracing::debug!(id = ?task_id, "task details watch started"); + Ok(tonic::Response::new(rx)) + } else { + Err(tonic::Status::internal( + "cannot start new watch, aggregation task is not running", + )) + } } async fn pause( &self, - request: tonic::Request, - ) -> Result, tonic::Status> { - todo!() + _request: tonic::Request, + ) -> Result, tonic::Status> { + self.subscribe.send(Command::Pause).await.map_err(|_| { + tonic::Status::internal("cannot pause, aggregation task is not running") + })?; + Ok(tonic::Response::new(instrument::PauseResponse {})) } async fn resume( &self, - request: tonic::Request, - ) -> Result, tonic::Status> { - todo!() + _request: tonic::Request, + ) -> Result, tonic::Status> { + self.subscribe.send(Command::Resume).await.map_err(|_| { + tonic::Status::internal("cannot resume, aggregation task is not running") + })?; + Ok(tonic::Response::new(instrument::ResumeResponse {})) } } diff --git a/runtime/console/src/stats.rs b/runtime/console/src/stats.rs new file mode 100644 index 0000000..d2bf2af --- /dev/null +++ b/runtime/console/src/stats.rs @@ -0,0 +1,161 @@ +use crate::aggregate::Id; +use crate::attribute; +use crossbeam_utils::atomic::AtomicCell; +use hdrhistogram::serialization::{Serializer, V2Serializer}; +use std::sync::atomic::{AtomicBool, AtomicUsize}; +use std::sync::Mutex; +use std::time::{Duration, Instant, SystemTime}; + +/// Anchors an `Instant` with a `SystemTime` timestamp to allow converting +/// monotonic `Instant`s into timestamps that can be sent over the wire. +#[derive(Debug, Clone)] +pub(crate) struct TimeAnchor { + mono: Instant, + sys: SystemTime, +} + +impl TimeAnchor { + pub(crate) fn new() -> Self { + Self { + mono: Instant::now(), + sys: SystemTime::now(), + } + } + + pub(crate) fn to_system_time(&self, t: Instant) -> SystemTime { + let dur = t + .checked_duration_since(self.mono) + .unwrap_or_else(|| Duration::from_secs(0)); + self.sys + dur + } + + pub(crate) fn to_timestamp(&self, t: Instant) -> prost_types::Timestamp { + self.to_system_time(t).into() + } +} + +#[derive(Debug, Default)] +struct PollStats { + /// The number of polls in progress + current_polls: AtomicUsize, + /// The total number of polls + polls: AtomicUsize, + timestamps: Mutex>, +} + +/// Stats associated with a task. +#[derive(Debug)] +pub(crate) struct TaskStats { + is_dirty: AtomicBool, + is_dropped: AtomicBool, + // task stats + pub(crate) created_at: Instant, + timestamps: Mutex, + + // waker stats + wakes: AtomicUsize, + waker_clones: AtomicUsize, + waker_drops: AtomicUsize, + self_wakes: AtomicUsize, + + /// Poll durations and other stats. + poll_stats: PollStats, +} + +impl TaskStats { + pub(crate) fn poll_duration_histogram( + &self, + ) -> console_api::tasks::task_details::PollTimesHistogram { + let hist = self + .poll_stats + .timestamps + .lock() + .unwrap() + .histogram + .to_proto(); + console_api::tasks::task_details::PollTimesHistogram::Histogram(hist) + } +} + +/// Stats associated with an async operation. +/// +/// This shares all of the same fields as [`ResourceStats]`, with the addition +/// of [`PollStats`] tracking when the async operation is polled, and the task +/// ID of the last task to poll the async op. +#[derive(Debug)] +pub(crate) struct AsyncOpStats { + /// The task ID of the last task to poll this async op. + /// + /// This is set every time the async op is polled, in case a future is + /// passed between tasks. + task_id: AtomicCell, + + /// Fields shared with `ResourceStats`. + pub(crate) stats: ResourceStats, + + /// Poll durations and other stats. + poll_stats: PollStats<()>, +} + +/// Stats associated with a resource. +#[derive(Debug)] +pub(crate) struct ResourceStats { + is_dirty: AtomicBool, + is_dropped: AtomicBool, + created_at: Instant, + dropped_at: Mutex>, + attributes: Mutex, + pub(crate) inherit_child_attributes: bool, + pub(crate) parent_id: Option, +} + +#[derive(Debug, Default)] +struct TaskTimestamps { + dropped_at: Option, + last_wake: Option, +} + +#[derive(Debug, Default)] +struct PollTimestamps { + first_poll: Option, + last_poll_started: Option, + last_poll_ended: Option, + busy_time: Duration, + histogram: H, +} + +#[derive(Debug)] +struct Histogram { + histogram: hdrhistogram::Histogram, + max: u64, + outliers: u64, + max_outlier: Option, +} + +impl Histogram { + fn new(max: u64) -> Self { + // significant figures should be in the [0-5] range and memory usage + // grows exponentially with higher a sigfig + let histogram = hdrhistogram::Histogram::new_with_max(max, 2).unwrap(); + Self { + histogram, + max, + max_outlier: None, + outliers: 0, + } + } + + fn to_proto(&self) -> console_api::tasks::DurationHistogram { + let mut serializer = V2Serializer::new(); + let mut raw_histogram = Vec::new(); + serializer + .serialize(&self.histogram, &mut raw_histogram) + .expect("histogram failed to serialize"); + console_api::tasks::DurationHistogram { + raw_histogram, + max_value: self.max, + high_outliers: self.outliers, + highest_outlier: self.max_outlier, + } + } +} From 287ca9806de62af293a19f7f97eb72c763a10ae0 Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Tue, 21 Jun 2022 22:23:55 +0200 Subject: [PATCH 05/17] Console is attached and compiles --- Cargo.lock | 538 +++++++++++++++---------------- Cargo.toml | 7 +- bffhd/lib.rs | 7 +- bffhd/logging.rs | 25 +- runtime/console/Cargo.toml | 5 +- runtime/console/src/aggregate.rs | 168 +++++++--- runtime/console/src/attribute.rs | 85 ++++- runtime/console/src/event.rs | 43 ++- runtime/console/src/id_map.rs | 126 ++++++++ runtime/console/src/lib.rs | 357 +++++++++++++++++++- runtime/console/src/server.rs | 30 +- runtime/console/src/stats.rs | 460 +++++++++++++++++++++++++- runtime/console/src/visitors.rs | 529 ++++++++++++++++++++++++++++++ 13 files changed, 2008 insertions(+), 372 deletions(-) create mode 100644 runtime/console/src/id_map.rs create mode 100644 runtime/console/src/visitors.rs diff --git a/Cargo.lock b/Cargo.lock index d9e4bbb..164f0c9 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -161,14 +161,14 @@ dependencies = [ [[package]] name = "async-global-executor" -version = "2.0.3" +version = "2.2.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c026b7e44f1316b567ee750fea85103f87fcb80792b860e979f221259796ca0a" +checksum = "5262ed948da60dd8956c6c5aca4d4163593dddb7b32d73267c93dab7b2e98940" dependencies = [ "async-channel", "async-executor", "async-io", - "async-mutex", + "async-lock", "blocking", "futures-lite", "num_cpus", @@ -203,15 +203,6 @@ dependencies = [ "event-listener", ] -[[package]] -name = "async-mutex" -version = "1.4.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "479db852db25d9dbf6204e6cb6253698f175c15726470f78af0d918e99d6156e" -dependencies = [ - "event-listener", -] - [[package]] name = "async-net" version = "1.6.1" @@ -251,9 +242,9 @@ dependencies = [ [[package]] name = "async-std" -version = "1.10.0" +version = "1.12.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "f8056f1455169ab86dd47b47391e4ab0cbd25410a70e9fe675544f49bafaf952" +checksum = "62565bb4402e926b29953c785397c6dc0391b7b446e45008b0049eb43cec6f5d" dependencies = [ "async-channel", "async-global-executor", @@ -268,7 +259,6 @@ dependencies = [ "kv-log-macro", "log", "memchr", - "num_cpus", "once_cell", "pin-project-lite", "pin-utils", @@ -305,9 +295,9 @@ checksum = "30696a84d817107fc028e049980e09d5e140e8da8f1caeb17e8e950658a3cea9" [[package]] name = "async-trait" -version = "0.1.52" +version = "0.1.56" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "061a7acccaa286c011ddc30970520b98fa40e00c9d644633fb26b5fc63a265e3" +checksum = "96cf8829f67d2eab0b2dfa42c5d0ef737e0724e4a82b01b3e292456202b19716" dependencies = [ "proc-macro2", "quote", @@ -339,9 +329,9 @@ checksum = "d468802bab17cbc0cc575e9b053f41e72aa36bfa6b7f55e3529ffa43161b97fa" [[package]] name = "axum" -version = "0.5.4" +version = "0.5.9" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "f4af7447fc1214c1f3a1ace861d0216a6c8bb13965b64bbad9650f375b67689a" +checksum = "33d590cacd53140ff87cc2e192eb22fc3dc23c5b3f93b0d4f020677f98e8c629" dependencies = [ "async-trait", "axum-core", @@ -351,7 +341,7 @@ dependencies = [ "http", "http-body", "hyper", - "itoa 1.0.1", + "itoa 1.0.2", "matchit", "memchr", "mime", @@ -368,9 +358,9 @@ dependencies = [ [[package]] name = "axum-core" -version = "0.2.3" +version = "0.2.6" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "3bdc19781b16e32f8a7200368a336fa4509d4b72ef15dd4e41df5290855ee1e6" +checksum = "cf4d047478b986f14a13edad31a009e2e05cb241f9805d0d75e4cba4e129ad4d" dependencies = [ "async-trait", "bytes", @@ -498,9 +488,9 @@ dependencies = [ [[package]] name = "bumpalo" -version = "3.9.1" +version = "3.10.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "a4a45a46ab1f2412e53d3a0ade76ffad2025804294569aae387231a0cd6e0899" +checksum = "37ccbd214614c6783386c1af30caf03192f17891059cecc394b4fb119e363de3" [[package]] name = "byte-tools" @@ -510,9 +500,9 @@ checksum = "e3b5ca7a04898ad4bcd41c90c5285445ff5b791899bb1b0abdd2a2aa791211d7" [[package]] name = "bytecheck" -version = "0.6.7" +version = "0.6.8" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "314889ea31cda264cb7c3d6e6e5c9415a987ecb0e72c17c00d36fbb881d34abe" +checksum = "3a31f923c2db9513e4298b72df143e6e655a759b3d6a0966df18f81223fff54f" dependencies = [ "bytecheck_derive", "ptr_meta", @@ -520,9 +510,9 @@ dependencies = [ [[package]] name = "bytecheck_derive" -version = "0.6.7" +version = "0.6.8" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "4a2b3b92c135dae665a6f760205b89187638e83bed17ef3e44e83c712cf30600" +checksum = "edb17c862a905d912174daa27ae002326fff56dc8b8ada50a0a5f0976cb174f0" dependencies = [ "proc-macro2", "quote", @@ -549,9 +539,9 @@ checksum = "c1db59621ec70f09c5e9b597b220c7a2b43611f4710dc03ceb8748637775692c" [[package]] name = "capnp" -version = "0.14.5" +version = "0.14.6" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "16c262726f68118392269a3f7a5546baf51dcfe5cb3c3f0957b502106bf1a065" +checksum = "21d5d7da973146f1720672faa44f1523cc8f923636190ca1a931c7bc8834de68" [[package]] name = "capnp-futures" @@ -643,20 +633,29 @@ dependencies = [ [[package]] name = "clap" -version = "3.1.6" +version = "3.2.6" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d8c93436c21e4698bacadf42917db28b23017027a4deccb35dbe47a7e7840123" +checksum = "9f1fe12880bae935d142c8702d500c63a4e8634b6c3c57ad72bf978fc7b6249a" dependencies = [ "atty", "bitflags", + "clap_lex", "indexmap", - "lazy_static", - "os_str_bytes", + "once_cell", "strsim", "termcolor", "textwrap 0.15.0", ] +[[package]] +name = "clap_lex" +version = "0.2.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "87eba3c8c7f42ef17f6c659fc7416d0f4758cd3e58861ee63c5fa4a4dde649e4" +dependencies = [ + "os_str_bytes", +] + [[package]] name = "concurrent-queue" version = "1.2.2" @@ -688,7 +687,7 @@ dependencies = [ "tonic", "tracing", "tracing-core", - "tracing-subscriber 0.3.9", + "tracing-subscriber", ] [[package]] @@ -705,9 +704,9 @@ dependencies = [ [[package]] name = "const_format" -version = "0.2.23" +version = "0.2.25" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "0936ffe6d0c8d6a51b3b0a73b2acbe925d786f346cf45bfddc8341d79fb7dc8a" +checksum = "2906f2480cdc015e998deac388331a0f1c1cd88744948c749513020c83c370bc" dependencies = [ "const_format_proc_macros", ] @@ -747,9 +746,9 @@ checksum = "5827cebf4670468b8772dd191856768aedcb1b0278a04f989f7766351917b9dc" [[package]] name = "cpufeatures" -version = "0.2.1" +version = "0.2.2" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "95059428f66df56b63431fdb4e1947ed2190586af5c5a8a8b71122bdf5a7f469" +checksum = "59a6001667ab124aebae2a495118e11d30984c3a653e99d86d58971708cf5e4b" dependencies = [ "libc", ] @@ -815,9 +814,9 @@ dependencies = [ [[package]] name = "crossbeam-channel" -version = "0.5.3" +version = "0.5.5" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "fdbfe11fe19ff083c48923cf179540e8cd0535903dc35e178a1fdeeb59aef51f" +checksum = "4c02a4d71819009c192cf4872265391563fd6a84c81ff2c0f2a7026ca4c1d85c" dependencies = [ "cfg-if", "crossbeam-utils", @@ -836,15 +835,15 @@ dependencies = [ [[package]] name = "crossbeam-epoch" -version = "0.9.8" +version = "0.9.9" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "1145cf131a2c6ba0615079ab6a638f7e1973ac9c2634fcbeaaad6114246efe8c" +checksum = "07db9d94cbd326813772c968ccd25999e5f8ae22f4f8d1b11effa37ef6ce281d" dependencies = [ "autocfg", "cfg-if", "crossbeam-utils", - "lazy_static", "memoffset", + "once_cell", "scopeguard", ] @@ -860,12 +859,12 @@ dependencies = [ [[package]] name = "crossbeam-utils" -version = "0.8.8" +version = "0.8.9" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "0bf124c720b7686e3c2663cf54062ab0f68a88af2fb6a030e87e30bf721fcb38" +checksum = "8ff1f980957787286a554052d03c7aee98d99cc32e09f6d45f0a814133c87978" dependencies = [ "cfg-if", - "lazy_static", + "once_cell", ] [[package]] @@ -892,9 +891,9 @@ dependencies = [ [[package]] name = "ctor" -version = "0.1.21" +version = "0.1.22" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "ccc0a48a9b826acdf4028595adc9db92caea352f7af011a3034acd172a52a0aa" +checksum = "f877be4f7c9f246b183111634f75baa039715e3f46ce860677d3b19a69fb229c" dependencies = [ "quote", "syn", @@ -913,9 +912,9 @@ dependencies = [ [[package]] name = "desfire" -version = "0.2.0-alpha1" +version = "0.2.0-alpha2" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "83dddd3136b4dfc80f46dc6441cd3f16f99317e645bedc61eabc1452d24bfb3f" +checksum = "337f0fcd6ef888be0962aeff547f1b219f4190ea785b5c33328f071e91405411" dependencies = [ "aes", "block-modes", @@ -978,7 +977,8 @@ dependencies = [ "capnp", "capnp-rpc", "chrono", - "clap 3.1.6", + "clap 3.2.6", + "console", "desfire", "dirs", "erased-serde", @@ -1020,7 +1020,7 @@ dependencies = [ "toml", "tracing", "tracing-futures", - "tracing-subscriber 0.2.25", + "tracing-subscriber", "url", "uuid", ] @@ -1054,9 +1054,9 @@ dependencies = [ [[package]] name = "dirs-sys" -version = "0.3.6" +version = "0.3.7" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "03d86534ed367a67548dc68113a0f5db55432fdfbb6e6f9d77704397d95d5780" +checksum = "1b1d1d91c932ef41c0f2663aa8b0ca0342d444d842c06914aa0a7e352d0bada6" dependencies = [ "libc", "redox_users", @@ -1092,9 +1092,9 @@ dependencies = [ [[package]] name = "erased-serde" -version = "0.3.18" +version = "0.3.21" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "56047058e1ab118075ca22f9ecd737bcc961aa3566a3019cb71388afa280bd8a" +checksum = "81d013529d5574a60caeda29e179e695125448e5de52e3874f7b4c1d7360e18e" dependencies = [ "serde", ] @@ -1128,7 +1128,7 @@ dependencies = [ "rand", "slab", "tracing", - "tracing-subscriber 0.3.9", + "tracing-subscriber", ] [[package]] @@ -1257,9 +1257,9 @@ dependencies = [ [[package]] name = "futures-rustls" -version = "0.22.0" +version = "0.22.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d383f0425d991a05e564c2f3ec150bd6dde863179c131dd60d8aa73a05434461" +checksum = "e01fe9932a224b72b45336d96040aa86386d674a31d0af27d800ea7bc8ca97fe" dependencies = [ "futures-io", "rustls", @@ -1268,9 +1268,9 @@ dependencies = [ [[package]] name = "futures-signals" -version = "0.3.24" +version = "0.3.28" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "439b5920b9dc57ddd4a959b4b1c0eb9a68ded001f1e331d422b0a68ef2928c5f" +checksum = "633f5e17d6fb8d3cfa0710087d0cbe708d07cc416ca6c4682ce876aa7839c09d" dependencies = [ "discard", "futures-channel", @@ -1355,20 +1355,20 @@ dependencies = [ [[package]] name = "getrandom" -version = "0.2.5" +version = "0.2.7" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d39cd93900197114fa1fcb7ae84ca742095eed9442088988ae74fa744e930e77" +checksum = "4eb1a864a501629691edf6c15a593b7a51eebaa1e8468e9ddc623de7c9b58ec6" dependencies = [ "cfg-if", "libc", - "wasi 0.10.2+wasi-snapshot-preview1", + "wasi 0.11.0+wasi-snapshot-preview1", ] [[package]] name = "ghost" -version = "0.1.2" +version = "0.1.4" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "1a5bcf1bbeab73aa4cf2fde60a846858dc036163c7c33bec309f8d17de785479" +checksum = "76c813ffb63e8fd3df6f1ac3cc1ea392c7612ac2de4d0b44dcbfe03e5c4bf94a" dependencies = [ "proc-macro2", "quote", @@ -1402,9 +1402,9 @@ checksum = "9b919933a397b79c37e33b77bb2aa3dc8eb6e165ad809e58ff75bc7db2e34574" [[package]] name = "gloo-timers" -version = "0.2.3" +version = "0.2.4" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "4d12a7f4e95cfe710f1d624fb1210b7d961a5fb05c4fd942f4feab06e61f590e" +checksum = "5fb7d06c1c8cc2a29bee7ec961009a0b2caa0793ee4900c2ffb348734ba1c8f9" dependencies = [ "futures-channel", "futures-core", @@ -1439,15 +1439,9 @@ checksum = "eabb4a44450da02c90444cf74558da904edde8fb4e9035a9a6a4e15445af0bd7" [[package]] name = "hashbrown" -version = "0.11.2" +version = "0.12.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "ab5ef0d4909ef3724cc8cce6ccc8572c5c817592e9285f5464f8e86f8bd3726e" - -[[package]] -name = "hashbrown" -version = "0.12.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "8c21d40587b92fa6a6c6e3c1bdbf87d75511db5672f9c93175574b3a00df1758" +checksum = "db0d4cf898abf0081f964436dc980e96670a0f36863e4b83aaacdb65c9d7ccc3" dependencies = [ "ahash", ] @@ -1486,13 +1480,13 @@ dependencies = [ [[package]] name = "http" -version = "0.2.6" +version = "0.2.8" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "31f4c6746584866f0feabcc69893c5b51beef3831656a968ed7ae254cdc4fd03" +checksum = "75f43d41e26995c17e71ee126451dd3941010b0514a81a9d11f3b341debc2399" dependencies = [ "bytes", "fnv", - "itoa 1.0.1", + "itoa 1.0.2", ] [[package]] @@ -1539,7 +1533,7 @@ dependencies = [ "http-body", "httparse", "httpdate", - "itoa 1.0.1", + "itoa 1.0.2", "pin-project-lite", "socket2", "tokio", @@ -1573,12 +1567,12 @@ dependencies = [ [[package]] name = "indexmap" -version = "1.8.0" +version = "1.9.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "282a6247722caba404c065016bbfa522806e51714c34f5dfc3e4a3a46fcb4223" +checksum = "10a35a97730320ffe8e2d410b5d3b69279b98d2c14bdb8b70ea89ecf7888d41e" dependencies = [ "autocfg", - "hashbrown 0.11.2", + "hashbrown", ] [[package]] @@ -1650,9 +1644,9 @@ checksum = "b71991ff56294aa922b450139ee08b3bfc70982c6b2c7562771375cf73542dd4" [[package]] name = "itoa" -version = "1.0.1" +version = "1.0.2" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "1aab8fc367588b89dcee83ab0fd66b72b50b72fa1904d7095045ace2b0c81c35" +checksum = "112c678d4050afce233f4f2852bb2eb519230b3cf12f33585275537d7e41578d" [[package]] name = "jobserver" @@ -1665,9 +1659,9 @@ dependencies = [ [[package]] name = "js-sys" -version = "0.3.56" +version = "0.3.58" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "a38fc24e30fd564ce974c02bf1d337caddff65be6cc4735a1f7eab22a7440f04" +checksum = "c3fac17f7123a73ca62df411b1bf727ccc805daa070338fda671c86dac1bdc27" dependencies = [ "wasm-bindgen", ] @@ -1702,9 +1696,9 @@ dependencies = [ [[package]] name = "libc" -version = "0.2.120" +version = "0.2.126" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "ad5c14e80759d0939d013e6ca49930e59fc53dd8e5009132f76240c179380c09" +checksum = "349d5a591cd28b49e1d1037471617a32ddcda5731b99419008085f72d5a53836" [[package]] name = "libgit2-sys" @@ -1720,9 +1714,9 @@ dependencies = [ [[package]] name = "libz-sys" -version = "1.1.6" +version = "1.1.8" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "92e7e15d7610cce1d9752e137625f14e61a28cd45929b6e12e47b50fe154ee2e" +checksum = "9702761c3935f8cc2f101793272e202c72b99da8f4224a19ddcf1279a6450bbf" dependencies = [ "cc", "libc", @@ -1789,9 +1783,9 @@ dependencies = [ [[package]] name = "log" -version = "0.4.14" +version = "0.4.17" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "51b9bbe6c47d51fc3e1a9b945965946b4c44142ab8792c50835a980d362c2710" +checksum = "abb12e687cfb44aa40f41fc3978ef76448f9b6038cad6aef4259d3c095a2382e" dependencies = [ "cfg-if", "value-bag", @@ -1805,9 +1799,9 @@ checksum = "3e2e65a1a2e43cfcb47a895c4c8b10d1f4a61097f9f254f183aee60cad9c651d" [[package]] name = "matchers" -version = "0.0.1" +version = "0.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "f099785f7595cc4b4553a174ce30dd7589ef93391ff414dbb67f62392b9e0ce1" +checksum = "8263075bb86c5a1b1427b5ae862e8889656f126e9f77c484496e8b47cf5c5558" dependencies = [ "regex-automata", ] @@ -1826,9 +1820,9 @@ checksum = "73cbba799671b762df5a175adf59ce145165747bb891505c43d09aefbbf38beb" [[package]] name = "memchr" -version = "2.4.1" +version = "2.5.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "308cc39be01b73d0d18f82a0e7b2a3df85245f84af96fdddc5d202d27e47b86a" +checksum = "2dffe52ecf27772e601905b7522cb4ef790d2cc203488bbd0e2fe85fcb74566d" [[package]] name = "memoffset" @@ -1893,25 +1887,14 @@ dependencies = [ [[package]] name = "mio" -version = "0.8.1" +version = "0.8.4" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "7ba42135c6a5917b9db9cd7b293e5409e1c6b041e6f9825e92e55a894c63b6f8" +checksum = "57ee1c23c7c63b0c9250c339ffdc69255f110b298b901b9f6c82547b7b87caaf" dependencies = [ "libc", "log", - "miow", - "ntapi", "wasi 0.11.0+wasi-snapshot-preview1", - "winapi", -] - -[[package]] -name = "miow" -version = "0.3.7" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b9f1c5b025cda876f66ef43a113f91ebc9f4ccef34843000e0adf6ebbab84e21" -dependencies = [ - "winapi", + "windows-sys", ] [[package]] @@ -1948,15 +1931,6 @@ dependencies = [ "minimal-lexical", ] -[[package]] -name = "ntapi" -version = "0.3.7" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c28774a7fd2fbb4f0babd8237ce554b73af68021b5f695a3cebd6c59bac0980f" -dependencies = [ - "winapi", -] - [[package]] name = "num-derive" version = "0.3.3" @@ -1970,9 +1944,9 @@ dependencies = [ [[package]] name = "num-integer" -version = "0.1.44" +version = "0.1.45" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d2cc698a63b549a70bc047073d2949cce27cd1c7b0a4a862d08a8031bc2801db" +checksum = "225d3389fb3509a24c93f5c29eb6bde2586b98d9f016636dff58d7c6f7569cd9" dependencies = [ "autocfg", "num-traits", @@ -1980,9 +1954,9 @@ dependencies = [ [[package]] name = "num-traits" -version = "0.2.14" +version = "0.2.15" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "9a64b1ec5cda2586e284722486d802acf1f7dbdc623e2bfc57e65ca1cd099290" +checksum = "578ede34cf02f8924ab9447f50c28075b4d3e5b269972345e7e0372b38c6cdcd" dependencies = [ "autocfg", ] @@ -2008,9 +1982,9 @@ dependencies = [ [[package]] name = "once_cell" -version = "1.10.0" +version = "1.12.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "87f3e037eac156d1775da914196f0f37741a274155e34a0b7e427c35d2a2ecb9" +checksum = "7709cef83f0c1f58f666e746a08b21e0085f7440fa6a29cc194d68aac97a4225" [[package]] name = "oorandom" @@ -2038,12 +2012,9 @@ checksum = "ff011a302c396a5197692431fc1948019154afc178baf7d8e37367442a4601cf" [[package]] name = "os_str_bytes" -version = "6.0.0" +version = "6.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "8e22443d1643a904602595ba1cd8f7d896afe56d26712531c5ff73a15b2fbf64" -dependencies = [ - "memchr", -] +checksum = "21326818e99cfe6ce1e524c2a805c189a99b5ae555a35d19f9a284b427d86afa" [[package]] name = "owo-colors" @@ -2150,9 +2121,9 @@ dependencies = [ [[package]] name = "pin-project-lite" -version = "0.2.8" +version = "0.2.9" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "e280fbe77cc62c91527259e9442153f4688736748d24660126286329742b4c6c" +checksum = "e0a7ae3ac2f1173085d398531c705756c94a4c56843785df85a60c1a0afac116" [[package]] name = "pin-utils" @@ -2162,9 +2133,9 @@ checksum = "8b870d8c151b6f2fb93e84a13146138f05d02ed11c7e7c54f8826aaaf7c9f184" [[package]] name = "pkg-config" -version = "0.3.24" +version = "0.3.25" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "58893f751c9b0412871a09abd62ecd2a00298c6c83befa223ef98c52aef40cbe" +checksum = "1df8c4ec4b0627e53bdf214615ad287367e482558cf84b109250b37464dc03ae" [[package]] name = "plotters" @@ -2230,11 +2201,11 @@ dependencies = [ [[package]] name = "proc-macro2" -version = "1.0.36" +version = "1.0.40" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c7342d5883fbccae1cc37a2353b09c87c9b0f3afd73f5fb9bba687a1f733b029" +checksum = "dd96a1e8ed2596c337f8eae5f24924ec83f5ad5ab21ea8e455d3566c69fbcaf7" dependencies = [ - "unicode-xid", + "unicode-ident", ] [[package]] @@ -2292,9 +2263,9 @@ dependencies = [ [[package]] name = "quote" -version = "1.0.15" +version = "1.0.20" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "864d3e96a899863136fc6e99f3d7cae289dafe43bf2c5ac19b70df7210c0a145" +checksum = "3bcdf212e9776fbcb2d23ab029360416bb1706b1aea2d1a5ba002727cbcab804" dependencies = [ "proc-macro2", ] @@ -2331,9 +2302,9 @@ dependencies = [ [[package]] name = "rayon" -version = "1.5.1" +version = "1.5.3" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c06aca804d41dbc8ba42dfd964f0d01334eceb64314b9ecf7c5fad5188a06d90" +checksum = "bd99e5772ead8baa5215278c9b15bf92087709e9c1b2d1f97cdb5a183c933a7d" dependencies = [ "autocfg", "crossbeam-deque", @@ -2343,41 +2314,41 @@ dependencies = [ [[package]] name = "rayon-core" -version = "1.9.1" +version = "1.9.3" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d78120e2c850279833f1dd3582f730c4ab53ed95aeaaaa862a2a5c71b1656d8e" +checksum = "258bcdb5ac6dad48491bb2992db6b7cf74878b0384908af124823d118c99683f" dependencies = [ "crossbeam-channel", "crossbeam-deque", "crossbeam-utils", - "lazy_static", "num_cpus", ] [[package]] name = "redox_syscall" -version = "0.2.11" +version = "0.2.13" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "8380fe0152551244f0747b1bf41737e0f8a74f97a14ccefd1148187271634f3c" +checksum = "62f25bc4c7e55e0b0b7a1d43fb893f4fa1361d0abe38b9ce4f323c2adfe6ef42" dependencies = [ "bitflags", ] [[package]] name = "redox_users" -version = "0.4.0" +version = "0.4.3" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "528532f3d801c87aec9def2add9ca802fe569e44a544afe633765267840abe64" +checksum = "b033d837a7cf162d7993aded9304e30a83213c648b6e389db233191f891e5c2b" dependencies = [ "getrandom", "redox_syscall", + "thiserror", ] [[package]] name = "regex" -version = "1.5.5" +version = "1.5.6" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "1a11647b6b25ff05a515cb92c365cec08801e83423a235b51e231e1808747286" +checksum = "d83f127d94bdbcda4c8cc2e50f6f84f4b611f69c902699ca385a39c3a75f9ff1" dependencies = [ "aho-corasick", "memchr", @@ -2395,9 +2366,9 @@ dependencies = [ [[package]] name = "regex-syntax" -version = "0.6.25" +version = "0.6.26" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "f497285884f3fcff424ffc933e56d7cbca511def0c9831a7f9b5f6153e3cc89b" +checksum = "49b3de9ec5dc0a3417da371aab17d729997c15010e7fd24ff707773a33bddb64" [[package]] name = "remove_dir_all" @@ -2434,12 +2405,12 @@ dependencies = [ [[package]] name = "rkyv" -version = "0.7.36" +version = "0.7.38" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "5230ae2981a885590b0dc84e0b24c0ed23ad24f7adc0eb824b26cafa961f7c36" +checksum = "517a3034eb2b1499714e9d1e49b2367ad567e07639b69776d35e259d9c27cca6" dependencies = [ "bytecheck", - "hashbrown 0.12.0", + "hashbrown", "ptr_meta", "rend", "rkyv_derive", @@ -2448,9 +2419,9 @@ dependencies = [ [[package]] name = "rkyv_derive" -version = "0.7.36" +version = "0.7.38" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "0fc752d5925dbcb324522f3a4c93193d17f107b2e11810913aa3ad352fa01480" +checksum = "505c209ee04111a006431abf39696e640838364d67a107c559ababaf6fd8c9dd" dependencies = [ "proc-macro2", "quote", @@ -2459,9 +2430,9 @@ dependencies = [ [[package]] name = "rkyv_dyn" -version = "0.7.33" +version = "0.7.38" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "0ed5db4771a89bfd4ec32b790d09d1b03b7d6b888cb8d12877a6310def8f0118" +checksum = "b7c7adf3c35f3c1d8aa1f3a573e91d38c0da8110e99f4ff0006def9691025db2" dependencies = [ "inventory", "lazy_static", @@ -2473,9 +2444,9 @@ dependencies = [ [[package]] name = "rkyv_dyn_derive" -version = "0.7.33" +version = "0.7.38" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b8ec9b321e2966c8f1f086b7e6180c10af688ac590461c9e6395895ddedba753" +checksum = "d8079a7a86551483b68603bd3712c332e8adfd3a2747a8f51a65cd8b7412b98b" dependencies = [ "proc-macro2", "quote", @@ -2559,9 +2530,9 @@ dependencies = [ [[package]] name = "rustls" -version = "0.20.4" +version = "0.20.6" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "4fbfeb8d0ddb84706bc597a5574ab8912817c52a397f819e5b614e2265206921" +checksum = "5aab8ee6c7097ed6057f43c187a62418d0c05a4bd5f18b3571db50ee0f9ce033" dependencies = [ "log", "ring", @@ -2571,25 +2542,16 @@ dependencies = [ [[package]] name = "rustls-native-certs" -version = "0.6.1" +version = "0.6.2" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "5ca9ebdfa27d3fc180e42879037b5338ab1c040c06affd00d8338598e7800943" +checksum = "0167bac7a9f490495f3c33013e7722b53cb087ecbe082fb0c6387c96f634ea50" dependencies = [ "openssl-probe", - "rustls-pemfile 0.2.1", + "rustls-pemfile 1.0.0", "schannel", "security-framework", ] -[[package]] -name = "rustls-pemfile" -version = "0.2.1" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "5eebeaeb360c87bfb72e84abdb3447159c0eaececf1bef2aecd65a8be949d1c9" -dependencies = [ - "base64", -] - [[package]] name = "rustls-pemfile" version = "0.3.0" @@ -2600,10 +2562,19 @@ dependencies = [ ] [[package]] -name = "ryu" -version = "1.0.9" +name = "rustls-pemfile" +version = "1.0.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "73b4b750c782965c211b42f022f59af1fbceabdd026623714f104152f1ec149f" +checksum = "e7522c9de787ff061458fe9a829dc790a3f5b22dc571694fc5883f448b94d9a9" +dependencies = [ + "base64", +] + +[[package]] +name = "ryu" +version = "1.0.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f3f6f92acf49d1b98f7a81226834412ada05458b7364277387724a237f062695" [[package]] name = "same-file" @@ -2616,12 +2587,12 @@ dependencies = [ [[package]] name = "schannel" -version = "0.1.19" +version = "0.1.20" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "8f05ba609c234e60bee0d547fe94a4c7e9da733d1c962cf6e59efa4cd9c8bc75" +checksum = "88d6731146462ea25d9244b2ed5fd1d716d25c52e4d54aa4fb0f3c4e9854dbe2" dependencies = [ "lazy_static", - "winapi", + "windows-sys", ] [[package]] @@ -2690,15 +2661,15 @@ dependencies = [ [[package]] name = "semver" -version = "1.0.6" +version = "1.0.10" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "a4a3381e03edd24287172047536f20cabde766e2cd3e65e6b00fb3af51c4f38d" +checksum = "a41d061efea015927ac527063765e73601444cdc344ba855bc7bd44578b25e1c" [[package]] name = "serde" -version = "1.0.136" +version = "1.0.137" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "ce31e24b01e1e524df96f1c2fdd054405f8d7376249a5110886fb4b658484789" +checksum = "61ea8d54c77f8315140a05f4c7237403bf38b72704d031543aa1d16abbf517d1" dependencies = [ "serde_derive", ] @@ -2715,9 +2686,9 @@ dependencies = [ [[package]] name = "serde_derive" -version = "1.0.136" +version = "1.0.137" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "08597e7152fcd306f41838ed3e37be9eaeed2b61c42e2117266a554fab4662f9" +checksum = "1f26faba0c3959972377d3b2d306ee9f71faee9714294e41bb777f83f88578be" dependencies = [ "proc-macro2", "quote", @@ -2739,11 +2710,11 @@ dependencies = [ [[package]] name = "serde_json" -version = "1.0.79" +version = "1.0.81" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "8e8d9fa5c3b304765ce1fd9c4c8a3de2c8db365a5b91be52f186efc675681d95" +checksum = "9b7ce2b32a1aed03c558dc61a5cd328f15aff2dbc17daad8fb8af04d2100e15c" dependencies = [ - "itoa 1.0.1", + "itoa 1.0.2", "ryu", "serde", ] @@ -2796,9 +2767,9 @@ dependencies = [ [[package]] name = "signal-hook" -version = "0.3.13" +version = "0.3.14" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "647c97df271007dcea485bb74ffdb57f2e683f1306c854f468a0c244badabf2d" +checksum = "a253b5e89e2698464fc26b545c9edceb338e18a89effeeecfea192c3025be29d" dependencies = [ "libc", "signal-hook-registry", @@ -2833,9 +2804,9 @@ checksum = "cc47a29ce97772ca5c927f75bac34866b16d64e07f330c3248e2d7226623901b" [[package]] name = "slab" -version = "0.4.5" +version = "0.4.6" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "9def91fd1e018fe007022791f865d0ccc9b3a0d5001e01aabb8b40e46000afb5" +checksum = "eb703cfe953bccee95685111adeedb76fabe4e97549a58d16f03ea7b9367bb32" [[package]] name = "smallvec" @@ -2923,13 +2894,13 @@ dependencies = [ [[package]] name = "syn" -version = "1.0.88" +version = "1.0.98" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "ebd69e719f31e88618baa1eaa6ee2de5c9a1c004f1e9ecdb58e8352a13f20a01" +checksum = "c50aef8a904de4c23c788f104b7dddc7d6f79c647c7c8ce4cc8f73eb0ca773dd" dependencies = [ "proc-macro2", "quote", - "unicode-xid", + "unicode-ident", ] [[package]] @@ -3022,11 +2993,12 @@ dependencies = [ [[package]] name = "time" -version = "0.1.43" +version = "0.1.44" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "ca8a50ef2360fbd1eeb0ecd46795a87a19024eb4b53c5dc916ca1fd95fe62438" +checksum = "6db9e6914ab8b1ae1c260a4ae7a49b6c5611b40328a735b21862567685e73255" dependencies = [ "libc", + "wasi 0.10.0+wasi-snapshot-preview1", "winapi", ] @@ -3042,9 +3014,9 @@ dependencies = [ [[package]] name = "tinyvec" -version = "1.5.1" +version = "1.6.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "2c1c1d5a42b6245520c249549ec267180beaffcc0615401ac8e31853d4b6d8d2" +checksum = "87cc5ceb3875bb20c2890005a4e226a4651264a5c75edb2421b52861a0a0cb50" dependencies = [ "tinyvec_macros", ] @@ -3084,9 +3056,9 @@ dependencies = [ [[package]] name = "tokio-macros" -version = "1.7.0" +version = "1.8.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b557f72f448c511a979e2564e55d74e6c4432fc96ff4f6241bc6bded342643b7" +checksum = "9724f9a975fb987ef7a3cd9be0350edcbe130698af5b8f7a631e23d42d052484" dependencies = [ "proc-macro2", "quote", @@ -3095,9 +3067,9 @@ dependencies = [ [[package]] name = "tokio-rustls" -version = "0.23.2" +version = "0.23.4" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "a27d5f2b839802bd8267fa19b0530f5a08b9c08cd417976be2a65d130fe1c11b" +checksum = "c43ee83903113e03984cb9e5cebe6c04a5116269e900e3ddba8f068a62adda59" dependencies = [ "rustls", "tokio", @@ -3131,9 +3103,9 @@ dependencies = [ [[package]] name = "toml" -version = "0.5.8" +version = "0.5.9" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "a31142970826733df8241ef35dc040ef98c679ab14d7c3e54d827099b3acecaa" +checksum = "8d82e1a7758622a465f8cee077614c73484dac5b836c02ff6a40d5d1010324d7" dependencies = [ "serde", ] @@ -3223,9 +3195,9 @@ checksum = "b6bc1c9ce2b5135ac7f93c72918fc37feb872bdc6a5533a8b85eb4b86bfdae52" [[package]] name = "tracing" -version = "0.1.32" +version = "0.1.35" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "4a1bdf54a7c28a2bbf701e1d2233f6c77f473486b94bee4f9678da5a148dca7f" +checksum = "a400e31aa60b9d44a52a8ee0343b5b18566b03a8321e0d321f695cf56e940160" dependencies = [ "cfg-if", "log", @@ -3236,9 +3208,9 @@ dependencies = [ [[package]] name = "tracing-attributes" -version = "0.1.20" +version = "0.1.21" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "2e65ce065b4b5c53e73bb28912318cb8c9e9ad3921f1d669eb0e68b4c8143a2b" +checksum = "cc6b8ad3567499f98a1db7a752b07a7c8c7c7c34c332ec00effb2b0027974b7c" dependencies = [ "proc-macro2", "quote", @@ -3247,11 +3219,11 @@ dependencies = [ [[package]] name = "tracing-core" -version = "0.1.23" +version = "0.1.27" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "aa31669fa42c09c34d94d8165dd2012e8ff3c66aca50f3bb226b68f216f2706c" +checksum = "7709595b8878a4965ce5e87ebf880a7d39c9afc6837721b21a5a816a8117d921" dependencies = [ - "lazy_static", + "once_cell", "valuable", ] @@ -3269,59 +3241,31 @@ dependencies = [ [[package]] name = "tracing-log" -version = "0.1.2" +version = "0.1.3" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "a6923477a48e41c1951f1999ef8bb5a3023eb723ceadafe78ffb65dc366761e3" +checksum = "78ddad33d2d10b1ed7eb9d1f518a5674713876e97e5bb9b7345a7984fbb4f922" dependencies = [ "lazy_static", "log", "tracing-core", ] -[[package]] -name = "tracing-serde" -version = "0.1.3" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "bc6b213177105856957181934e4920de57730fc69bf42c37ee5bb664d406d9e1" -dependencies = [ - "serde", - "tracing-core", -] - [[package]] name = "tracing-subscriber" -version = "0.2.25" +version = "0.3.11" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "0e0d2eaa99c3c2e41547cfa109e910a68ea03823cccad4a0525dcbc9b01e8c71" +checksum = "4bc28f93baff38037f64e6f43d34cfa1605f27a49c34e8a04c5e78b0babf2596" dependencies = [ "ansi_term", - "chrono", "lazy_static", "matchers", "regex", - "serde", - "serde_json", "sharded-slab", "smallvec", "thread_local", "tracing", "tracing-core", "tracing-log", - "tracing-serde", -] - -[[package]] -name = "tracing-subscriber" -version = "0.3.9" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "9e0ab7bdc962035a87fba73f3acca9b8a8d0034c2e6f60b84aeaaddddc155dce" -dependencies = [ - "ansi_term", - "sharded-slab", - "smallvec", - "thread_local", - "tracing-core", - "tracing-log", ] [[package]] @@ -3332,13 +3276,14 @@ checksum = "59547bce71d9c38b83d9c0e92b6066c4253371f15005def0c30d9657f50c7642" [[package]] name = "trybuild" -version = "1.0.56" +version = "1.0.63" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "2d60539445867cdd9680b2bfe2d0428f1814b7d5c9652f09d8d3eae9d19308db" +checksum = "764b9e244b482a9b81bde596aa37aa6f1347bf8007adab25e59f901b32b4e0a0" dependencies = [ "glob", "once_cell", "serde", + "serde_derive", "serde_json", "termcolor", "toml", @@ -3364,9 +3309,15 @@ checksum = "56dee185309b50d1f11bfedef0fe6d036842e3fb77413abef29f8f8d1c5d4c1c" [[package]] name = "unicode-bidi" -version = "0.3.7" +version = "0.3.8" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "1a01404663e3db436ed2746d9fefef640d868edae3cceb81c3b8d5732fda678f" +checksum = "099b7128301d285f79ddd55b9a83d5e6b9e97c92e0ea0daebee7263e932de992" + +[[package]] +name = "unicode-ident" +version = "1.0.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5bd2fe26506023ed7b5e1e315add59d6f584c621d037f9368fea9cfb988f368c" [[package]] name = "unicode-linebreak" @@ -3394,9 +3345,9 @@ checksum = "3ed742d4ea2bd1176e236172c8429aaf54486e7ac098db29ffe6529e0ce50973" [[package]] name = "unicode-xid" -version = "0.2.2" +version = "0.2.3" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "8ccb82d61f80a663efe1f787a51b16b5a51e3314d6ac365b08639f52387b33f3" +checksum = "957e51f3646910546462e67d5f7599b9e4fb8acdd304b087a6494730f9eebf04" [[package]] name = "untrusted" @@ -3434,9 +3385,9 @@ checksum = "830b7e5d4d90034032940e4ace0d9a9a057e7a45cd94e6c007832e39edb82f6d" [[package]] name = "value-bag" -version = "1.0.0-alpha.8" +version = "1.0.0-alpha.9" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "79923f7731dc61ebfba3633098bf3ac533bbd35ccd8c57e7088d9a5eebe0263f" +checksum = "2209b78d1249f7e6f3293657c9779fe31ced465df091bbd433a1cf88e916ec55" dependencies = [ "ctor", "version_check", @@ -3483,9 +3434,9 @@ dependencies = [ [[package]] name = "wasi" -version = "0.10.2+wasi-snapshot-preview1" +version = "0.10.0+wasi-snapshot-preview1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "fd6fbd9a79829dd1ad0cc20627bf1ed606756a7f77edff7b66b7064f9cb327c6" +checksum = "1a143597ca7c7793eff794def352d41792a93c481eb1042423ff7ff72ba2c31f" [[package]] name = "wasi" @@ -3495,9 +3446,9 @@ checksum = "9c8d87e72b64a3b4db28d11ce29237c246188f4f51057d65a7eab63b7987e423" [[package]] name = "wasm-bindgen" -version = "0.2.79" +version = "0.2.81" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "25f1af7423d8588a3d840681122e72e6a24ddbcb3f0ec385cac0d12d24256c06" +checksum = "7c53b543413a17a202f4be280a7e5c62a1c69345f5de525ee64f8cfdbc954994" dependencies = [ "cfg-if", "wasm-bindgen-macro", @@ -3505,9 +3456,9 @@ dependencies = [ [[package]] name = "wasm-bindgen-backend" -version = "0.2.79" +version = "0.2.81" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "8b21c0df030f5a177f3cba22e9bc4322695ec43e7257d865302900290bcdedca" +checksum = "5491a68ab4500fa6b4d726bd67408630c3dbe9c4fe7bda16d5c82a1fd8c7340a" dependencies = [ "bumpalo", "lazy_static", @@ -3520,9 +3471,9 @@ dependencies = [ [[package]] name = "wasm-bindgen-futures" -version = "0.4.29" +version = "0.4.31" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "2eb6ec270a31b1d3c7e266b999739109abce8b6c87e4b31fcfcd788b65267395" +checksum = "de9a9cec1733468a8c657e57fa2413d2ae2c0129b95e87c5b72b8ace4d13f31f" dependencies = [ "cfg-if", "js-sys", @@ -3532,9 +3483,9 @@ dependencies = [ [[package]] name = "wasm-bindgen-macro" -version = "0.2.79" +version = "0.2.81" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "2f4203d69e40a52ee523b2529a773d5ffc1dc0071801c87b3d270b471b80ed01" +checksum = "c441e177922bc58f1e12c022624b6216378e5febc2f0533e41ba443d505b80aa" dependencies = [ "quote", "wasm-bindgen-macro-support", @@ -3542,9 +3493,9 @@ dependencies = [ [[package]] name = "wasm-bindgen-macro-support" -version = "0.2.79" +version = "0.2.81" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "bfa8a30d46208db204854cadbb5d4baf5fcf8071ba5bf48190c3e59937962ebc" +checksum = "7d94ac45fcf608c1f45ef53e748d35660f168490c10b23704c7779ab8f5c3048" dependencies = [ "proc-macro2", "quote", @@ -3555,15 +3506,15 @@ dependencies = [ [[package]] name = "wasm-bindgen-shared" -version = "0.2.79" +version = "0.2.81" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "3d958d035c4438e28c70e4321a2911302f10135ce78a9c7834c0cab4123d06a2" +checksum = "6a89911bd99e5f3659ec4acf9c4d93b0a90fe4a2a11f15328472058edc5261be" [[package]] name = "web-sys" -version = "0.3.56" +version = "0.3.58" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c060b319f29dd25724f09a2ba1418f142f539b2be99fbf4d2d5a8f7330afb8eb" +checksum = "2fed94beee57daf8dd7d51f2b15dc2bcde92d7a72304cdf662a4371008b71b90" dependencies = [ "js-sys", "wasm-bindgen", @@ -3618,3 +3569,46 @@ name = "winapi-x86_64-pc-windows-gnu" version = "0.4.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f" + +[[package]] +name = "windows-sys" +version = "0.36.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ea04155a16a59f9eab786fe12a4a450e75cdb175f9e0d80da1e17db09f55b8d2" +dependencies = [ + "windows_aarch64_msvc", + "windows_i686_gnu", + "windows_i686_msvc", + "windows_x86_64_gnu", + "windows_x86_64_msvc", +] + +[[package]] +name = "windows_aarch64_msvc" +version = "0.36.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9bb8c3fd39ade2d67e9874ac4f3db21f0d710bee00fe7cab16949ec184eeaa47" + +[[package]] +name = "windows_i686_gnu" +version = "0.36.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "180e6ccf01daf4c426b846dfc66db1fc518f074baa793aa7d9b9aaeffad6a3b6" + +[[package]] +name = "windows_i686_msvc" +version = "0.36.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e2e7917148b2812d1eeafaeb22a97e4813dfa60a3f8f78ebe204bcc88f12f024" + +[[package]] +name = "windows_x86_64_gnu" +version = "0.36.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4dcd171b8776c41b97521e5da127a2d86ad280114807d0b2ab1e462bc764d9e1" + +[[package]] +name = "windows_x86_64_msvc" +version = "0.36.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c811ca4a8c853ef420abd8592ba53ddbbac90410fab6903b3e79972a631f7680" diff --git a/Cargo.toml b/Cargo.toml index 21b74fd..fdae5ba 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -49,6 +49,7 @@ dirs = "4.0.0" # Runtime executor = { path = "runtime/executor" } +console = { path = "runtime/console" } # Catch&Handle POSIX process signals signal-hook = "0.3.13" @@ -72,9 +73,9 @@ rust-argon2 = "0.8.3" rand = "0.8.4" # Async aware logging and tracing -tracing = "0.1.28" -tracing-subscriber = { version = "0.2.25", features = ["env-filter"] } -tracing-futures = { version = "0.2.5", features = ["futures-03"] } +tracing = "0.1" +tracing-subscriber = { version = "0.3", features = ["env-filter", "registry", "std"] } +tracing-futures = { version = "0.2", features = ["futures-03"] } # API api = { path = "api" } diff --git a/bffhd/lib.rs b/bffhd/lib.rs index 21ff90c..e0c9d86 100644 --- a/bffhd/lib.rs +++ b/bffhd/lib.rs @@ -76,7 +76,7 @@ pub static RESOURCES: OnceCell = OnceCell::new(); impl Diflouroborane { pub fn new(config: Config) -> miette::Result { - logging::init(&config.logging); + let mut server = logging::init(&config.logging); tracing::info!(version = env::VERSION, "Starting BFFH"); let span = tracing::info_span!("setup"); @@ -84,6 +84,11 @@ impl Diflouroborane { let executor = Executor::new(); + if let Some(aggregator) = server.aggregator.take() { + executor.spawn(aggregator.run()); + } + executor.spawn(server.serve()); + let env = StateDB::open_env(&config.db_path)?; let statedb = StateDB::create_with_env(env.clone())?; diff --git a/bffhd/logging.rs b/bffhd/logging.rs index 026e83d..51d9832 100644 --- a/bffhd/logging.rs +++ b/bffhd/logging.rs @@ -1,6 +1,7 @@ use tracing_subscriber::EnvFilter; use serde::{Deserialize, Serialize}; +use tracing_subscriber::prelude::*; #[derive(Debug, Clone, Serialize, Deserialize)] pub struct LogConfig { @@ -24,21 +25,25 @@ impl Default for LogConfig { } } -pub fn init(config: &LogConfig) { +pub fn init(config: &LogConfig) -> console::Server { + let (console, server) = console::ConsoleLayer::new(); + let filter = if let Some(ref filter) = config.filter { EnvFilter::new(filter.as_str()) } else { EnvFilter::from_env("BFFH_LOG") }; - let builder = tracing_subscriber::fmt().with_env_filter(filter); + let format = &config.format; + // TODO: Restore output format settings being settable + let fmt_layer = tracing_subscriber::fmt::layer().with_filter(filter); - let format = config.format.to_lowercase(); - match format.as_str() { - "compact" => builder.compact().init(), - "pretty" => builder.pretty().init(), - "full" => builder.init(), - _ => builder.init(), - } - tracing::info!(format = format.as_str(), "Logging initialized") + tracing_subscriber::registry() + .with(fmt_layer) + .with(console) + .init(); + + tracing::info!(format = format.as_str(), "Logging initialized"); + + server } diff --git a/runtime/console/Cargo.toml b/runtime/console/Cargo.toml index fd823e8..82c629a 100644 --- a/runtime/console/Cargo.toml +++ b/runtime/console/Cargo.toml @@ -24,4 +24,7 @@ async-io = "1.7" tokio-util = "0.7" futures-util = "0.3" tokio = { version = "1.19", default_features = false, features = []} -hdrhistogram = "7.5" \ No newline at end of file +hdrhistogram = "7.5" + +[dev-dependencies] +tracing-subscriber = "0.3" diff --git a/runtime/console/src/aggregate.rs b/runtime/console/src/aggregate.rs index 25fb192..1acf6d2 100644 --- a/runtime/console/src/aggregate.rs +++ b/runtime/console/src/aggregate.rs @@ -1,35 +1,24 @@ +use crate::id_map::{IdMap, ToProto}; use crate::server::{Watch, WatchRequest}; -use crate::stats::TimeAnchor; -use crate::Event; +use crate::stats::{TimeAnchor, Unsent}; use crate::{server, stats}; +use crate::{Event, Shared}; use console_api::{async_ops, instrument, resources, tasks}; use crossbeam_channel::{Receiver, TryRecvError}; use futures_util::{FutureExt, StreamExt}; +use std::collections::HashMap; use std::num::NonZeroU64; -use std::sync::atomic::AtomicBool; +use std::sync::atomic::{AtomicBool, Ordering}; use std::sync::Arc; use std::time::{Duration, Instant}; +use tracing::span; use tracing_core::Metadata; -#[derive(Copy, Clone, Debug, PartialEq, Eq, Hash)] -pub(crate) struct Id(NonZeroU64); - -impl Id { - pub fn from_non_zero_u64(u: NonZeroU64) -> Self { - Self(u) - } -} - -impl Into for Id { - fn into(self) -> console_api::Id { - console_api::Id { id: self.0.into() } - } -} - +#[derive(Debug)] struct Resource { - id: Id, + id: span::Id, is_dirty: AtomicBool, - parent_id: Option, + parent_id: Option, metadata: &'static Metadata<'static>, concrete_type: String, kind: resources::resource::Kind, @@ -38,36 +27,114 @@ struct Resource { } /// Represents static data for tasks +#[derive(Debug)] struct Task { - id: Id, + id: span::Id, is_dirty: AtomicBool, metadata: &'static Metadata<'static>, fields: Vec, location: Option, } +#[derive(Debug)] struct AsyncOp { - id: Id, + id: span::Id, is_dirty: AtomicBool, - parent_id: Option, - resource_id: Id, + parent_id: Option, + resource_id: span::Id, metadata: &'static Metadata<'static>, source: String, } +impl ToProto for Task { + type Output = tasks::Task; + + fn to_proto(&self, _: &stats::TimeAnchor) -> Self::Output { + tasks::Task { + id: Some(self.id.clone().into()), + // TODO: more kinds of tasks... + kind: tasks::task::Kind::Spawn as i32, + metadata: Some(self.metadata.into()), + parents: Vec::new(), // TODO: implement parents nicely + fields: self.fields.clone(), + location: self.location.clone(), + } + } +} + +impl Unsent for Task { + fn take_unsent(&self) -> bool { + self.is_dirty.swap(false, Ordering::AcqRel) + } + + fn is_unsent(&self) -> bool { + self.is_dirty.load(Ordering::Acquire) + } +} + +impl ToProto for Resource { + type Output = resources::Resource; + + fn to_proto(&self, _: &stats::TimeAnchor) -> Self::Output { + resources::Resource { + id: Some(self.id.clone().into()), + parent_resource_id: self.parent_id.clone().map(Into::into), + kind: Some(self.kind.clone()), + metadata: Some(self.metadata.into()), + concrete_type: self.concrete_type.clone(), + location: self.location.clone(), + is_internal: self.is_internal, + } + } +} + +impl Unsent for Resource { + fn take_unsent(&self) -> bool { + self.is_dirty.swap(false, Ordering::AcqRel) + } + + fn is_unsent(&self) -> bool { + self.is_dirty.load(Ordering::Acquire) + } +} + +impl ToProto for AsyncOp { + type Output = async_ops::AsyncOp; + + fn to_proto(&self, _: &stats::TimeAnchor) -> Self::Output { + async_ops::AsyncOp { + id: Some(self.id.clone().into()), + metadata: Some(self.metadata.into()), + resource_id: Some(self.resource_id.clone().into()), + source: self.source.clone(), + parent_async_op_id: self.parent_id.clone().map(Into::into), + } + } +} + +impl Unsent for AsyncOp { + fn take_unsent(&self) -> bool { + self.is_dirty.swap(false, Ordering::AcqRel) + } + + fn is_unsent(&self) -> bool { + self.is_dirty.load(Ordering::Acquire) + } +} + #[derive(Copy, Clone, Eq, PartialEq)] pub(crate) enum Include { All, UpdatedOnly, } -type IdMap = std::collections::HashMap; - -pub(crate) struct Aggregator { +#[derive(Debug)] +pub struct Aggregator { + shared: Arc, events: Receiver, rpcs: async_channel::Receiver, watchers: Vec>, - details_watchers: IdMap>>, + details_watchers: HashMap>>, all_metadata: Vec, new_metadata: Vec, running: bool, @@ -83,23 +150,28 @@ pub(crate) struct Aggregator { } impl Aggregator { - pub fn new(events: Receiver, rpcs: async_channel::Receiver) -> Self { + pub(crate) fn new( + shared: Arc, + events: Receiver, + rpcs: async_channel::Receiver, + ) -> Self { Self { + shared, events, rpcs, watchers: Vec::new(), - details_watchers: IdMap::new(), + details_watchers: HashMap::default(), running: true, publish_interval: Duration::from_secs(1), all_metadata: Vec::new(), new_metadata: Vec::new(), base_time: TimeAnchor::new(), - tasks: IdMap::new(), - task_stats: IdMap::new(), - resources: IdMap::new(), - resource_stats: IdMap::new(), - async_ops: IdMap::new(), - async_op_stats: IdMap::new(), + tasks: IdMap::default(), + task_stats: IdMap::default(), + resources: IdMap::default(), + resource_stats: IdMap::default(), + async_ops: IdMap::default(), + async_op_stats: IdMap::default(), poll_ops: Vec::new(), } } @@ -163,15 +235,32 @@ impl Aggregator { } fn task_update(&mut self, include: Include) -> tasks::TaskUpdate { - todo!() + tasks::TaskUpdate { + new_tasks: self.tasks.as_proto_list(include, &self.base_time), + stats_update: self.task_stats.as_proto(include, &self.base_time), + dropped_events: self.shared.dropped_tasks.swap(0, Ordering::AcqRel) as u64, + } } fn resource_update(&mut self, include: Include) -> resources::ResourceUpdate { - todo!() + let new_poll_ops = match include { + Include::All => self.poll_ops.clone(), + Include::UpdatedOnly => std::mem::take(&mut self.poll_ops), + }; + resources::ResourceUpdate { + new_resources: self.resources.as_proto_list(include, &self.base_time), + stats_update: self.resource_stats.as_proto(include, &self.base_time), + new_poll_ops, + dropped_events: self.shared.dropped_resources.swap(0, Ordering::AcqRel) as u64, + } } fn async_op_update(&mut self, include: Include) -> async_ops::AsyncOpUpdate { - todo!() + async_ops::AsyncOpUpdate { + new_async_ops: self.async_ops.as_proto_list(include, &self.base_time), + stats_update: self.async_op_stats.as_proto(include, &self.base_time), + dropped_events: self.shared.dropped_async_ops.swap(0, Ordering::AcqRel) as u64, + } } pub async fn run(mut self) { @@ -210,7 +299,6 @@ impl Aggregator { // exited. that would result in a busy-loop. instead, we only want // to be woken when the flush interval has elapsed, or when the // channel is almost full. - let mut drained = false; while let Ok(event) = self.events.try_recv() { self.update_state(event); } diff --git a/runtime/console/src/attribute.rs b/runtime/console/src/attribute.rs index 55c2eb8..b012129 100644 --- a/runtime/console/src/attribute.rs +++ b/runtime/console/src/attribute.rs @@ -1,11 +1,94 @@ -use crate::aggregate::Id; use std::collections::HashMap; +use tracing_core::span::Id; #[derive(Debug, Default)] pub(crate) struct Attributes { attributes: HashMap, } +impl Attributes { + pub(crate) fn values(&self) -> impl Iterator { + self.attributes.values() + } + + pub(crate) fn update(&mut self, id: &Id, update: &Update) { + let field_name = match update.field.name.as_ref() { + Some(name) => name.clone(), + None => { + tracing::warn!(?update.field, "field missing name, skipping..."); + return; + } + }; + let update_id = id.clone(); + let key = FieldKey { + update_id, + field_name, + }; + + self.attributes + .entry(key) + .and_modify(|attr| update_attribute(attr, update)) + .or_insert_with(|| update.clone().into()); + } +} + +fn update_attribute(attribute: &mut console_api::Attribute, update: &Update) { + use console_api::field::Value::*; + let attribute_val = attribute.field.as_mut().and_then(|a| a.value.as_mut()); + let update_val = update.field.value.clone(); + let update_name = update.field.name.clone(); + match (attribute_val, update_val) { + (Some(BoolVal(v)), Some(BoolVal(upd))) => *v = upd, + + (Some(StrVal(v)), Some(StrVal(upd))) => *v = upd, + + (Some(DebugVal(v)), Some(DebugVal(upd))) => *v = upd, + + (Some(U64Val(v)), Some(U64Val(upd))) => match update.op { + Some(UpdateOp::Add) => *v = v.saturating_add(upd), + + Some(UpdateOp::Sub) => *v = v.saturating_sub(upd), + + Some(UpdateOp::Override) => *v = upd, + + None => tracing::warn!( + "numeric attribute update {:?} needs to have an op field", + update_name + ), + }, + + (Some(I64Val(v)), Some(I64Val(upd))) => match update.op { + Some(UpdateOp::Add) => *v = v.saturating_add(upd), + + Some(UpdateOp::Sub) => *v = v.saturating_sub(upd), + + Some(UpdateOp::Override) => *v = upd, + + None => tracing::warn!( + "numeric attribute update {:?} needs to have an op field", + update_name + ), + }, + + (val, update) => { + tracing::warn!( + "attribute {:?} cannot be updated by update {:?}", + val, + update + ); + } + } +} + +impl From for console_api::Attribute { + fn from(upd: Update) -> Self { + console_api::Attribute { + field: Some(upd.field), + unit: upd.unit, + } + } +} + #[derive(Debug, Clone)] pub(crate) struct Update { pub(crate) field: console_api::Field, diff --git a/runtime/console/src/event.rs b/runtime/console/src/event.rs index d681715..5cbe6ec 100644 --- a/runtime/console/src/event.rs +++ b/runtime/console/src/event.rs @@ -1,21 +1,21 @@ -use crate::aggregate::Id; use crate::stats; use console_api::resources; use std::sync::Arc; +use tracing::span; use tracing_core::Metadata; pub(crate) enum Event { Metadata(&'static Metadata<'static>), Spawn { - id: Id, + id: span::Id, metadata: &'static Metadata<'static>, stats: Arc, fields: Vec, location: Option, }, Resource { - id: Id, - parent_id: Option, + id: span::Id, + parent_id: Option, metadata: &'static Metadata<'static>, concrete_type: String, kind: resources::resource::Kind, @@ -25,19 +25,42 @@ pub(crate) enum Event { }, PollOp { metadata: &'static Metadata<'static>, - resource_id: Id, + resource_id: span::Id, op_name: String, - async_op_id: Id, - task_id: Id, + async_op_id: span::Id, + task_id: span::Id, is_ready: bool, }, AsyncResourceOp { - id: Id, - parent_id: Option, - resource_id: Id, + id: span::Id, + parent_id: Option, + resource_id: span::Id, metadata: &'static Metadata<'static>, source: String, stats: Arc, }, } + +#[derive(Clone, Debug, Copy)] +pub(crate) enum WakeOp { + Wake { self_wake: bool }, + WakeByRef { self_wake: bool }, + Clone, + Drop, +} + +impl WakeOp { + /// Returns `true` if `self` is a `Wake` or `WakeByRef` event. + pub(crate) fn is_wake(self) -> bool { + matches!(self, Self::Wake { .. } | Self::WakeByRef { .. }) + } + + pub(crate) fn self_wake(self, self_wake: bool) -> Self { + match self { + Self::Wake { .. } => Self::Wake { self_wake }, + Self::WakeByRef { .. } => Self::WakeByRef { self_wake }, + x => x, + } + } +} diff --git a/runtime/console/src/id_map.rs b/runtime/console/src/id_map.rs new file mode 100644 index 0000000..3af1602 --- /dev/null +++ b/runtime/console/src/id_map.rs @@ -0,0 +1,126 @@ +use crate::aggregate::Include; +use crate::stats::{DroppedAt, TimeAnchor, Unsent}; +use std::collections::HashMap; +use std::time::{Duration, Instant}; +use tracing_core::span::Id; + +pub(crate) trait ToProto { + type Output; + fn to_proto(&self, base_time: &TimeAnchor) -> Self::Output; +} + +#[derive(Debug)] +pub(crate) struct IdMap { + data: HashMap, +} + +impl Default for IdMap { + fn default() -> Self { + IdMap { + data: HashMap::::new(), + } + } +} + +impl IdMap { + pub(crate) fn insert(&mut self, id: Id, data: T) { + self.data.insert(id, data); + } + + pub(crate) fn since_last_update(&mut self) -> impl Iterator { + self.data.iter_mut().filter_map(|(id, data)| { + if data.take_unsent() { + Some((id, data)) + } else { + None + } + }) + } + + pub(crate) fn all(&self) -> impl Iterator { + self.data.iter() + } + + pub(crate) fn get(&self, id: &Id) -> Option<&T> { + self.data.get(id) + } + + pub(crate) fn as_proto_list( + &mut self, + include: Include, + base_time: &TimeAnchor, + ) -> Vec + where + T: ToProto, + { + match include { + Include::UpdatedOnly => self + .since_last_update() + .map(|(_, d)| d.to_proto(base_time)) + .collect(), + Include::All => self.all().map(|(_, d)| d.to_proto(base_time)).collect(), + } + } + + pub(crate) fn as_proto( + &mut self, + include: Include, + base_time: &TimeAnchor, + ) -> HashMap + where + T: ToProto, + { + match include { + Include::UpdatedOnly => self + .since_last_update() + .map(|(id, d)| (id.into_u64(), d.to_proto(base_time))) + .collect(), + Include::All => self + .all() + .map(|(id, d)| (id.into_u64(), d.to_proto(base_time))) + .collect(), + } + } + + pub(crate) fn drop_closed( + &mut self, + stats: &mut IdMap, + now: Instant, + retention: Duration, + has_watchers: bool, + ) { + let _span = tracing::debug_span!( + "drop_closed", + entity = %std::any::type_name::(), + stats = %std::any::type_name::(), + ) + .entered(); + + // drop closed entities + tracing::trace!(?retention, has_watchers, "dropping closed"); + + stats.data.retain(|id, stats| { + if let Some(dropped_at) = stats.dropped_at() { + let dropped_for = now.checked_duration_since(dropped_at).unwrap_or_default(); + let dirty = stats.is_unsent(); + let should_drop = + // if there are any clients watching, retain all dirty tasks regardless of age + (dirty && has_watchers) + || dropped_for > retention; + tracing::trace!( + stats.id = ?id, + stats.dropped_at = ?dropped_at, + stats.dropped_for = ?dropped_for, + stats.dirty = dirty, + should_drop, + ); + return !should_drop; + } + + true + }); + + // drop closed entities which no longer have stats. + self.data.retain(|id, _| stats.data.contains_key(id)); + } +} diff --git a/runtime/console/src/lib.rs b/runtime/console/src/lib.rs index de46432..d0c9305 100644 --- a/runtime/console/src/lib.rs +++ b/runtime/console/src/lib.rs @@ -1,31 +1,39 @@ use crossbeam_channel::{Sender, TrySendError}; -use std::any::TypeId; +use std::borrow::Borrow; use std::cell::RefCell; use std::net::IpAddr; use std::sync::atomic::{AtomicUsize, Ordering}; use std::sync::Arc; +use std::time::{Duration, Instant}; use thread_local::ThreadLocal; -use tracing_core::span::{Attributes, Id, Record}; -use tracing_core::{Interest, LevelFilter, Metadata, Subscriber}; -use tracing_subscriber::filter::Filtered; -use tracing_subscriber::layer::{Context, Filter, Layered}; -use tracing_subscriber::registry::LookupSpan; +use tracing::span; +use tracing_core::span::Attributes; +use tracing_core::{Interest, Metadata, Subscriber}; +use tracing_subscriber::layer::{Context, Filter}; +use tracing_subscriber::registry::{LookupSpan, SpanRef}; use tracing_subscriber::Layer; mod aggregate; mod attribute; mod callsites; mod event; +mod id_map; mod server; mod stack; mod stats; +mod visitors; use crate::aggregate::Aggregator; use crate::callsites::Callsites; +use crate::visitors::{ + AsyncOpVisitor, PollOpVisitor, ResourceVisitor, ResourceVisitorResult, StateUpdateVisitor, + TaskVisitor, WakerVisitor, +}; use event::Event; pub use server::Server; use stack::SpanStack; +#[derive(Debug)] pub struct ConsoleLayer { current_spans: ThreadLocal>, @@ -34,6 +42,34 @@ pub struct ConsoleLayer { spawn_callsites: Callsites<8>, waker_callsites: Callsites<8>, + resource_callsites: Callsites<8>, + + /// Set of callsites for spans representing async operations on resources + /// + /// TODO: Take some time to determine more reasonable numbers + async_op_callsites: Callsites<32>, + + /// Set of callsites for spans representing async op poll operations + /// + /// TODO: Take some time to determine more reasonable numbers + async_op_poll_callsites: Callsites<32>, + + /// Set of callsites for events representing poll operation invocations on resources + /// + /// TODO: Take some time to determine more reasonable numbers + poll_op_callsites: Callsites<32>, + + /// Set of callsites for events representing state attribute state updates on resources + /// + /// TODO: Take some time to determine more reasonable numbers + resource_state_update_callsites: Callsites<32>, + + /// Set of callsites for events representing state attribute state updates on async resource ops + /// + /// TODO: Take some time to determine more reasonable numbers + async_op_state_update_callsites: Callsites<32>, + + max_poll_duration_nanos: u64, } #[derive(Debug)] @@ -50,6 +86,8 @@ pub struct Builder { event_buffer_capacity: usize, client_buffer_capacity: usize, + + poll_duration_max: Duration, } impl Builder { pub fn build(self) -> (ConsoleLayer, Server) { @@ -64,6 +102,7 @@ impl Default for Builder { server_port: Server::DEFAULT_PORT, event_buffer_capacity: ConsoleLayer::DEFAULT_EVENT_BUFFER_CAPACITY, client_buffer_capacity: 1024, + poll_duration_max: ConsoleLayer::DEFAULT_POLL_DURATION_MAX, } } } @@ -72,6 +111,7 @@ impl Default for Builder { struct Shared { dropped_tasks: AtomicUsize, dropped_resources: AtomicUsize, + dropped_async_ops: AtomicUsize, } impl ConsoleLayer { @@ -91,7 +131,7 @@ impl ConsoleLayer { let (tx, events) = crossbeam_channel::bounded(config.event_buffer_capacity); let shared = Arc::new(Shared::default()); let (subscribe, rpcs) = async_channel::bounded(config.client_buffer_capacity); - let aggregator = Aggregator::new(events, rpcs); + let aggregator = Aggregator::new(shared.clone(), events, rpcs); let server = Server::new(aggregator, config.client_buffer_capacity, subscribe); let layer = Self { current_spans: ThreadLocal::new(), @@ -99,6 +139,13 @@ impl ConsoleLayer { shared, spawn_callsites: Callsites::default(), waker_callsites: Callsites::default(), + resource_callsites: Callsites::default(), + async_op_callsites: Callsites::default(), + async_op_poll_callsites: Callsites::default(), + poll_op_callsites: Callsites::default(), + resource_state_update_callsites: Callsites::default(), + async_op_state_update_callsites: Callsites::default(), + max_poll_duration_nanos: config.poll_duration_max.as_nanos() as u64, }; (layer, server) @@ -109,6 +156,14 @@ impl ConsoleLayer { const DEFAULT_EVENT_BUFFER_CAPACITY: usize = 1024; const DEFAULT_CLIENT_BUFFER_CAPACITY: usize = 1024; + /// The default maximum value for task poll duration histograms. + /// + /// Any poll duration exceeding this will be clamped to this value. By + /// default, the maximum poll duration is one second. + /// + /// See also [`Builder::poll_duration_histogram_max`]. + pub const DEFAULT_POLL_DURATION_MAX: Duration = Duration::from_secs(1); + fn is_spawn(&self, metadata: &Metadata<'static>) -> bool { self.spawn_callsites.contains(metadata) } @@ -117,6 +172,54 @@ impl ConsoleLayer { self.waker_callsites.contains(metadata) } + fn is_resource(&self, meta: &'static Metadata<'static>) -> bool { + self.resource_callsites.contains(meta) + } + + fn is_async_op(&self, meta: &'static Metadata<'static>) -> bool { + self.async_op_callsites.contains(meta) + } + + fn is_id_spawned(&self, id: &span::Id, cx: &Context<'_, S>) -> bool + where + S: Subscriber + for<'a> LookupSpan<'a>, + { + cx.span(id) + .map(|span| self.is_spawn(span.metadata())) + .unwrap_or(false) + } + + fn is_id_resource(&self, id: &span::Id, cx: &Context<'_, S>) -> bool + where + S: Subscriber + for<'a> LookupSpan<'a>, + { + cx.span(id) + .map(|span| self.is_resource(span.metadata())) + .unwrap_or(false) + } + + fn is_id_async_op(&self, id: &span::Id, cx: &Context<'_, S>) -> bool + where + S: Subscriber + for<'a> LookupSpan<'a>, + { + cx.span(id) + .map(|span| self.is_async_op(span.metadata())) + .unwrap_or(false) + } + + fn first_entered

(&self, stack: &SpanStack, p: P) -> Option + where + P: Fn(&span::Id) -> bool, + { + stack + .stack() + .iter() + .rev() + .find(|id| p(id.id())) + .map(|id| id.id()) + .cloned() + } + fn send_stats( &self, dropped: &AtomicUsize, @@ -157,6 +260,30 @@ where self.waker_callsites.insert(metadata); &self.shared.dropped_tasks } + (ResourceVisitor::RES_SPAN_NAME, _) => { + self.resource_callsites.insert(metadata); + &self.shared.dropped_resources + } + (AsyncOpVisitor::ASYNC_OP_SPAN_NAME, _) => { + self.async_op_callsites.insert(metadata); + &self.shared.dropped_async_ops + } + ("runtime.resource.async_op.poll", _) => { + self.async_op_poll_callsites.insert(metadata); + &self.shared.dropped_async_ops + } + (_, PollOpVisitor::POLL_OP_EVENT_TARGET) => { + self.poll_op_callsites.insert(metadata); + &self.shared.dropped_async_ops + } + (_, StateUpdateVisitor::RE_STATE_UPDATE_EVENT_TARGET) => { + self.resource_state_update_callsites.insert(metadata); + &self.shared.dropped_resources + } + (_, StateUpdateVisitor::AO_STATE_UPDATE_EVENT_TARGET) => { + self.async_op_state_update_callsites.insert(metadata); + &self.shared.dropped_async_ops + } (_, _) => &self.shared.dropped_tasks, }; @@ -164,13 +291,215 @@ where Interest::always() } -} -#[cfg(test)] -mod tests { - #[test] - fn it_works() { - let result = 2 + 2; - assert_eq!(result, 4); + fn on_new_span(&self, attrs: &Attributes<'_>, id: &span::Id, ctx: Context<'_, S>) { + let metadata = attrs.metadata(); + if self.is_spawn(metadata) { + let at = Instant::now(); + let mut task_visitor = TaskVisitor::new(metadata.into()); + attrs.record(&mut task_visitor); + let (fields, location) = task_visitor.result(); + if let Some(stats) = self.send_stats(&self.shared.dropped_tasks, move || { + let stats = Arc::new(stats::TaskStats::new(self.max_poll_duration_nanos, at)); + let event = Event::Spawn { + id: id.clone(), + stats: stats.clone(), + metadata, + fields, + location, + }; + (event, stats) + }) { + ctx.span(id) + .expect("`on_new_span` called with nonexistent span. This is a tracing bug."); + } + } else if self.is_resource(metadata) { + let at = Instant::now(); + let mut resource_visitor = ResourceVisitor::default(); + attrs.record(&mut resource_visitor); + if let Some(result) = resource_visitor.result() { + let ResourceVisitorResult { + concrete_type, + kind, + location, + is_internal, + inherit_child_attrs, + } = result; + let parent_id = self.current_spans.get().and_then(|stack| { + self.first_entered(&stack.borrow(), |id| self.is_id_resource(id, &ctx)) + }); + if let Some(stats) = self.send_stats(&self.shared.dropped_resources, move || { + let stats = Arc::new(stats::ResourceStats::new( + at, + inherit_child_attrs, + parent_id.clone(), + )); + let event = Event::Resource { + id: id.clone(), + parent_id, + metadata, + concrete_type, + kind, + location, + is_internal, + stats: stats.clone(), + }; + (event, stats) + }) { + ctx.span(id).expect("if `on_new_span` was called, the span must exist; this is a `tracing` bug!").extensions_mut().insert(stats); + } + } + } else if self.is_async_op(metadata) { + let at = Instant::now(); + let mut async_op_visitor = AsyncOpVisitor::default(); + attrs.record(&mut async_op_visitor); + if let Some((source, inherit_child_attrs)) = async_op_visitor.result() { + let resource_id = self.current_spans.get().and_then(|stack| { + self.first_entered(&stack.borrow(), |id| self.is_id_resource(id, &ctx)) + }); + + let parent_id = self.current_spans.get().and_then(|stack| { + self.first_entered(&stack.borrow(), |id| self.is_id_async_op(id, &ctx)) + }); + + if let Some(resource_id) = resource_id { + if let Some(stats) = + self.send_stats(&self.shared.dropped_async_ops, move || { + let stats = Arc::new(stats::AsyncOpStats::new( + at, + inherit_child_attrs, + parent_id.clone(), + )); + let event = Event::AsyncResourceOp { + id: id.clone(), + parent_id, + resource_id, + metadata, + source, + stats: stats.clone(), + }; + (event, stats) + }) + { + ctx.span(id).expect("if `on_new_span` was called, the span must exist; this is a `tracing` bug!").extensions_mut().insert(stats); + } + } + } + } + } + + fn on_event(&self, event: &tracing::Event<'_>, ctx: Context<'_, S>) { + let metadata = event.metadata(); + if self.waker_callsites.contains(metadata) { + let at = Instant::now(); + let mut visitor = WakerVisitor::default(); + event.record(&mut visitor); + if let Some((id, mut op)) = visitor.result() { + if let Some(span) = ctx.span(&id) { + let exts = span.extensions(); + if let Some(stats) = exts.get::>() { + if op.is_wake() { + let self_wake = self + .current_spans + .get() + .map(|spans| spans.borrow().iter().any(|span| span == &id)) + .unwrap_or(false); + op = op.self_wake(self_wake); + } + + stats.record_wake_op(op, at); + } + } + } + } + } + + fn on_enter(&self, id: &span::Id, cx: Context<'_, S>) { + fn update LookupSpan<'a>>( + span: &SpanRef, + at: Option, + ) -> Option { + let exts = span.extensions(); + // if the span we are entering is a task or async op, record the + // poll stats. + if let Some(stats) = exts.get::>() { + let at = at.unwrap_or_else(Instant::now); + stats.start_poll(at); + Some(at) + } else if let Some(stats) = exts.get::>() { + let at = at.unwrap_or_else(Instant::now); + stats.start_poll(at); + Some(at) + // otherwise, is the span a resource? in that case, we also want + // to enter it, although we don't care about recording poll + // stats. + } else if exts.get::>().is_some() { + Some(at.unwrap_or_else(Instant::now)) + } else { + None + } + } + + if let Some(span) = cx.span(id) { + if let Some(now) = update(&span, None) { + if let Some(parent) = span.parent() { + update(&parent, Some(now)); + } + self.current_spans + .get_or_default() + .borrow_mut() + .push(id.clone()); + } + } + } + + fn on_exit(&self, id: &span::Id, cx: Context<'_, S>) { + fn update LookupSpan<'a>>( + span: &SpanRef, + at: Option, + ) -> Option { + let exts = span.extensions(); + // if the span we are entering is a task or async op, record the + // poll stats. + if let Some(stats) = exts.get::>() { + let at = at.unwrap_or_else(Instant::now); + stats.end_poll(at); + Some(at) + } else if let Some(stats) = exts.get::>() { + let at = at.unwrap_or_else(Instant::now); + stats.end_poll(at); + Some(at) + // otherwise, is the span a resource? in that case, we also want + // to enter it, although we don't care about recording poll + // stats. + } else if exts.get::>().is_some() { + Some(at.unwrap_or_else(Instant::now)) + } else { + None + } + } + + if let Some(span) = cx.span(id) { + if let Some(now) = update(&span, None) { + if let Some(parent) = span.parent() { + update(&parent, Some(now)); + } + self.current_spans.get_or_default().borrow_mut().pop(id); + } + } + } + + fn on_close(&self, id: span::Id, cx: Context<'_, S>) { + if let Some(span) = cx.span(&id) { + let now = Instant::now(); + let exts = span.extensions(); + if let Some(stats) = exts.get::>() { + stats.drop_task(now); + } else if let Some(stats) = exts.get::>() { + stats.drop_async_op(now); + } else if let Some(stats) = exts.get::>() { + stats.drop_resource(now); + } + } } } diff --git a/runtime/console/src/server.rs b/runtime/console/src/server.rs index 5591206..14ff385 100644 --- a/runtime/console/src/server.rs +++ b/runtime/console/src/server.rs @@ -1,19 +1,21 @@ -use crate::aggregate::Id; use crate::Aggregator; use async_channel::{Receiver, Sender}; +use async_compat::CompatExt; use console_api::instrument; use console_api::instrument::instrument_server::{Instrument, InstrumentServer}; use console_api::tasks; use futures_util::TryStreamExt; use std::error::Error; +use std::future::Future; use std::io::IoSlice; -use std::net::{IpAddr, Ipv6Addr, SocketAddr}; +use std::net::{IpAddr, Ipv4Addr, Ipv6Addr, SocketAddr}; use std::pin::Pin; use std::task::{Context, Poll}; use tokio::io::AsyncRead as TokioAsyncRead; use tokio::io::{AsyncWrite as TokioAsyncWrite, ReadBuf}; use tonic::transport::server::Connected; use tonic::Status; +use tracing_core::span::Id; struct StreamWrapper(T); impl Connected for StreamWrapper { @@ -68,14 +70,16 @@ impl TokioAsyncRead for StreamWrapper { } } +#[derive(Debug)] pub struct Server { - aggregator: Aggregator, + pub aggregator: Option, client_buffer_size: usize, subscribe: Sender, } impl Server { - pub(crate) const DEFAULT_ADDR: IpAddr = IpAddr::V6(Ipv6Addr::new(0, 0, 0, 0, 0, 0, 0, 1)); + //pub(crate) const DEFAULT_ADDR: IpAddr = IpAddr::V6(Ipv6Addr::new(0, 0, 0, 0, 0, 0, 0, 1)); + pub(crate) const DEFAULT_ADDR: IpAddr = IpAddr::V4(Ipv4Addr::new(127, 0, 0, 1)); pub(crate) const DEFAULT_PORT: u16 = 49289; pub(crate) fn new( @@ -83,15 +87,14 @@ impl Server { client_buffer_size: usize, subscribe: Sender, ) -> Self { - let subscribe = todo!(); Self { - aggregator, + aggregator: Some(aggregator), client_buffer_size, subscribe, } } - pub(crate) async fn serve( + pub async fn serve( mut self, /*, incoming: I */ ) -> Result<(), Box> { // TODO: Spawn two tasks; the aggregator that's collecting stats, aggregating and @@ -99,16 +102,10 @@ impl Server { let svc = InstrumentServer::new(self); - // The gRPC server task; requires a `Stream` of `tokio::AsyncRead + tokio::AsyncWrite`. - let listener = - async_net::TcpListener::bind(SocketAddr::new(Self::DEFAULT_ADDR, Self::DEFAULT_PORT)) - .await?; - let incoming = listener - .incoming() - .map_ok(|stream| StreamWrapper(async_compat::Compat::new(stream))); tonic::transport::Server::builder() .add_service(svc) - .serve_with_incoming(incoming) + .serve(SocketAddr::new(Self::DEFAULT_ADDR, Self::DEFAULT_PORT)) + .compat() .await?; // TODO: Kill the aggregator task if the serve task has ended. @@ -117,6 +114,7 @@ impl Server { } } +#[derive(Debug)] pub(crate) struct Watch(pub(crate) Sender>); impl Watch { pub fn update(&self, update: &T) -> bool { @@ -124,12 +122,14 @@ impl Watch { } } +#[derive(Debug)] pub(crate) struct WatchRequest { pub id: Id, pub stream_sender: async_oneshot::Sender>>, pub buffer: usize, } +#[derive(Debug)] pub(crate) enum Command { Instrument(Watch), WatchTaskDetail(WatchRequest), diff --git a/runtime/console/src/stats.rs b/runtime/console/src/stats.rs index d2bf2af..9018d8f 100644 --- a/runtime/console/src/stats.rs +++ b/runtime/console/src/stats.rs @@ -1,10 +1,62 @@ -use crate::aggregate::Id; -use crate::attribute; +use crate::id_map::ToProto; +use crate::{attribute, event}; use crossbeam_utils::atomic::AtomicCell; use hdrhistogram::serialization::{Serializer, V2Serializer}; -use std::sync::atomic::{AtomicBool, AtomicUsize}; -use std::sync::Mutex; +use std::cmp; +use std::sync::atomic::{AtomicBool, AtomicUsize, Ordering}; +use std::sync::{Arc, Mutex}; use std::time::{Duration, Instant, SystemTime}; +use tracing::span; + +/// A type which records whether it has unsent updates. +/// +/// If something implementing this trait has been changed since the last time +/// data was sent to a client, it will indicate that it is "dirty". If it has +/// not been changed, it does not have to be included in the current update. +pub(crate) trait Unsent { + /// Returns `true` if this type has unsent updates, and if it does, clears + /// the flag indicating there are unsent updates. + /// + /// This is called when filtering which stats need to be included in the + /// current update. If this returns `true`, it will be included, so it + /// becomes no longer dirty. + fn take_unsent(&self) -> bool; + + /// Returns `true` if this type has unsent updates, without changing the + /// flag. + fn is_unsent(&self) -> bool; +} + +// An entity (e.g Task, Resource) that at some point in +// time can be dropped. This generally refers to spans that +// have been closed indicating that a task, async op or a +// resource is not in use anymore +pub(crate) trait DroppedAt { + fn dropped_at(&self) -> Option; +} + +impl DroppedAt for Arc { + fn dropped_at(&self) -> Option { + T::dropped_at(self) + } +} + +impl Unsent for Arc { + fn take_unsent(&self) -> bool { + T::take_unsent(self) + } + + fn is_unsent(&self) -> bool { + T::is_unsent(self) + } +} + +impl ToProto for Arc { + type Output = T::Output; + fn to_proto(&self, base_time: &TimeAnchor) -> T::Output { + T::to_proto(self, base_time) + } +} /// Anchors an `Instant` with a `SystemTime` timestamp to allow converting /// monotonic `Instant`s into timestamps that can be sent over the wire. @@ -34,6 +86,10 @@ impl TimeAnchor { } } +trait RecordPoll { + fn record_poll_duration(&mut self, duration: Duration); +} + #[derive(Debug, Default)] struct PollStats { /// The number of polls in progress @@ -43,6 +99,78 @@ struct PollStats { timestamps: Mutex>, } +impl PollStats { + fn start_poll(&self, at: Instant) { + if self.current_polls.fetch_add(1, Ordering::AcqRel) == 0 { + // We are starting the first poll + let mut timestamps = self.timestamps.lock().unwrap(); + if timestamps.first_poll.is_none() { + timestamps.first_poll = Some(at); + } + + timestamps.last_poll_started = Some(at); + + self.polls.fetch_add(1, Ordering::Release); + } + } + + fn end_poll(&self, at: Instant) { + // Are we ending the last current poll? + if self.current_polls.fetch_sub(1, Ordering::AcqRel) > 1 { + return; + } + + let mut timestamps = self.timestamps.lock().unwrap(); + let started = match timestamps.last_poll_started { + Some(last_poll) => last_poll, + None => { + eprintln!( + "a poll ended, but start timestamp was recorded. \ + this is probably a `console-subscriber` bug" + ); + return; + } + }; + + timestamps.last_poll_ended = Some(at); + let elapsed = match at.checked_duration_since(started) { + Some(elapsed) => elapsed, + None => { + eprintln!( + "possible Instant clock skew detected: a poll's end timestamp \ + was before its start timestamp\nstart = {:?}\n end = {:?}", + started, at + ); + return; + } + }; + + // if we have a poll time histogram, add the timestamp + timestamps.histogram.record_poll_duration(elapsed); + + timestamps.busy_time += elapsed; + } +} + +impl ToProto for PollStats { + type Output = console_api::PollStats; + + fn to_proto(&self, base_time: &TimeAnchor) -> Self::Output { + let timestamps = self.timestamps.lock().unwrap(); + console_api::PollStats { + polls: self.polls.load(Ordering::Acquire) as u64, + first_poll: timestamps.first_poll.map(|at| base_time.to_timestamp(at)), + last_poll_started: timestamps + .last_poll_started + .map(|at| base_time.to_timestamp(at)), + last_poll_ended: timestamps + .last_poll_ended + .map(|at| base_time.to_timestamp(at)), + busy_time: Some(timestamps.busy_time.into()), + } + } +} + /// Stats associated with a task. #[derive(Debug)] pub(crate) struct TaskStats { @@ -63,6 +191,30 @@ pub(crate) struct TaskStats { } impl TaskStats { + pub(crate) fn new(poll_duration_max: u64, created_at: Instant) -> Self { + Self { + is_dirty: AtomicBool::new(true), + is_dropped: AtomicBool::new(false), + created_at, + timestamps: Mutex::new(TaskTimestamps::default()), + poll_stats: PollStats { + timestamps: Mutex::new(PollTimestamps { + histogram: Histogram::new(poll_duration_max), + first_poll: None, + last_poll_started: None, + last_poll_ended: None, + busy_time: Duration::new(0, 0), + }), + current_polls: AtomicUsize::new(0), + polls: AtomicUsize::new(0), + }, + wakes: AtomicUsize::new(0), + waker_clones: AtomicUsize::new(0), + waker_drops: AtomicUsize::new(0), + self_wakes: AtomicUsize::new(0), + } + } + pub(crate) fn poll_duration_histogram( &self, ) -> console_api::tasks::task_details::PollTimesHistogram { @@ -75,6 +227,104 @@ impl TaskStats { .to_proto(); console_api::tasks::task_details::PollTimesHistogram::Histogram(hist) } + + pub(crate) fn record_wake_op(&self, op: event::WakeOp, at: Instant) { + use event::WakeOp; + match op { + WakeOp::Wake { self_wake } => { + self.waker_drops.fetch_add(1, Ordering::Release); + self.wake(at, self_wake); + } + WakeOp::WakeByRef { self_wake } => { + self.wake(at, self_wake); + } + WakeOp::Clone => { + self.waker_clones.fetch_add(1, Ordering::Release); + } + WakeOp::Drop => { + self.waker_drops.fetch_add(1, Ordering::Release); + } + } + self.make_dirty(); + } + + fn wake(&self, at: Instant, self_wake: bool) { + let mut timestamps = self.timestamps.lock().unwrap(); + timestamps.last_wake = cmp::max(timestamps.last_wake, Some(at)); + if self_wake { + self.wakes.fetch_add(1, Ordering::Release); + } + self.wakes.fetch_add(1, Ordering::Release); + } + + pub(crate) fn start_poll(&self, at: Instant) { + self.poll_stats.start_poll(at); + self.make_dirty(); + } + + pub(crate) fn end_poll(&self, at: Instant) { + self.poll_stats.end_poll(at); + self.make_dirty(); + } + + pub(crate) fn drop_task(&self, dropped_at: Instant) { + if self.is_dropped.swap(true, Ordering::AcqRel) { + // The task was already dropped. + // TODO(eliza): this could maybe panic in debug mode... + return; + } + + let mut timestamps = self.timestamps.lock().unwrap(); + let _prev = timestamps.dropped_at.replace(dropped_at); + debug_assert_eq!(_prev, None, "tried to drop a task twice; this is a bug!"); + self.make_dirty(); + } + + fn make_dirty(&self) { + self.is_dirty.swap(true, Ordering::AcqRel); + } +} + +impl ToProto for TaskStats { + type Output = console_api::tasks::Stats; + + fn to_proto(&self, base_time: &TimeAnchor) -> Self::Output { + let poll_stats = Some(self.poll_stats.to_proto(base_time)); + let timestamps = self.timestamps.lock().unwrap(); + console_api::tasks::Stats { + poll_stats, + created_at: Some(base_time.to_timestamp(self.created_at)), + dropped_at: timestamps.dropped_at.map(|at| base_time.to_timestamp(at)), + wakes: self.wakes.load(Ordering::Acquire) as u64, + waker_clones: self.waker_clones.load(Ordering::Acquire) as u64, + self_wakes: self.self_wakes.load(Ordering::Acquire) as u64, + waker_drops: self.waker_drops.load(Ordering::Acquire) as u64, + last_wake: timestamps.last_wake.map(|at| base_time.to_timestamp(at)), + } + } +} + +impl Unsent for TaskStats { + #[inline] + fn take_unsent(&self) -> bool { + self.is_dirty.swap(false, Ordering::AcqRel) + } + + fn is_unsent(&self) -> bool { + self.is_dirty.load(Ordering::Acquire) + } +} + +impl DroppedAt for TaskStats { + fn dropped_at(&self) -> Option { + // avoid acquiring the lock if we know we haven't tried to drop this + // thing yet + if self.is_dropped.load(Ordering::Acquire) { + return self.timestamps.lock().unwrap().dropped_at; + } + + None + } } /// Stats associated with an async operation. @@ -97,6 +347,98 @@ pub(crate) struct AsyncOpStats { poll_stats: PollStats<()>, } +impl AsyncOpStats { + pub(crate) fn new( + created_at: Instant, + inherit_child_attributes: bool, + parent_id: Option, + ) -> Self { + Self { + task_id: AtomicCell::new(0), + stats: ResourceStats::new(created_at, inherit_child_attributes, parent_id), + poll_stats: PollStats::default(), + } + } + + pub(crate) fn task_id(&self) -> Option { + let id = self.task_id.load(); + if id > 0 { + Some(id as u64) + } else { + None + } + } + + pub(crate) fn set_task_id(&self, id: &tracing::span::Id) { + self.task_id.store(id.into_u64()); + self.make_dirty(); + } + + pub(crate) fn drop_async_op(&self, dropped_at: Instant) { + self.stats.drop_resource(dropped_at) + } + + pub(crate) fn start_poll(&self, at: Instant) { + self.poll_stats.start_poll(at); + self.make_dirty(); + } + + pub(crate) fn end_poll(&self, at: Instant) { + self.poll_stats.end_poll(at); + self.make_dirty(); + } + + #[inline] + fn make_dirty(&self) { + self.stats.make_dirty() + } +} + +impl Unsent for AsyncOpStats { + #[inline] + fn take_unsent(&self) -> bool { + self.stats.take_unsent() + } + + #[inline] + fn is_unsent(&self) -> bool { + self.stats.is_unsent() + } +} + +impl DroppedAt for AsyncOpStats { + fn dropped_at(&self) -> Option { + self.stats.dropped_at() + } +} + +impl ToProto for AsyncOpStats { + type Output = console_api::async_ops::Stats; + + fn to_proto(&self, base_time: &TimeAnchor) -> Self::Output { + let attributes = self + .stats + .attributes + .lock() + .unwrap() + .values() + .cloned() + .collect(); + console_api::async_ops::Stats { + poll_stats: Some(self.poll_stats.to_proto(base_time)), + created_at: Some(base_time.to_timestamp(self.stats.created_at)), + dropped_at: self + .stats + .dropped_at + .lock() + .unwrap() + .map(|at| base_time.to_timestamp(at)), + task_id: self.task_id().map(Into::into), + attributes, + } + } +} + /// Stats associated with a resource. #[derive(Debug)] pub(crate) struct ResourceStats { @@ -106,7 +448,92 @@ pub(crate) struct ResourceStats { dropped_at: Mutex>, attributes: Mutex, pub(crate) inherit_child_attributes: bool, - pub(crate) parent_id: Option, + pub(crate) parent_id: Option, +} + +impl ResourceStats { + pub(crate) fn new( + created_at: Instant, + inherit_child_attributes: bool, + parent_id: Option, + ) -> Self { + Self { + is_dirty: AtomicBool::new(true), + is_dropped: AtomicBool::new(false), + created_at, + dropped_at: Mutex::new(None), + attributes: Default::default(), + inherit_child_attributes, + parent_id, + } + } + + pub(crate) fn update_attribute(&self, id: &span::Id, update: &attribute::Update) { + self.attributes.lock().unwrap().update(id, update); + self.make_dirty(); + } + + #[inline] + pub(crate) fn drop_resource(&self, dropped_at: Instant) { + if self.is_dropped.swap(true, Ordering::AcqRel) { + // The task was already dropped. + // TODO(eliza): this could maybe panic in debug mode... + return; + } + + let mut timestamp = self.dropped_at.lock().unwrap(); + let _prev = timestamp.replace(dropped_at); + debug_assert_eq!( + _prev, None, + "tried to drop a resource/async op twice; this is a bug!" + ); + self.make_dirty(); + } + + #[inline] + fn make_dirty(&self) { + self.is_dirty.swap(true, Ordering::AcqRel); + } +} + +impl Unsent for ResourceStats { + #[inline] + fn take_unsent(&self) -> bool { + self.is_dirty.swap(false, Ordering::AcqRel) + } + + fn is_unsent(&self) -> bool { + self.is_dirty.load(Ordering::Acquire) + } +} + +impl DroppedAt for ResourceStats { + fn dropped_at(&self) -> Option { + // avoid acquiring the lock if we know we haven't tried to drop this + // thing yet + if self.is_dropped.load(Ordering::Acquire) { + return *self.dropped_at.lock().unwrap(); + } + + None + } +} + +impl ToProto for ResourceStats { + type Output = console_api::resources::Stats; + + fn to_proto(&self, base_time: &TimeAnchor) -> Self::Output { + let attributes = self.attributes.lock().unwrap().values().cloned().collect(); + console_api::resources::Stats { + created_at: Some(base_time.to_timestamp(self.created_at)), + dropped_at: self + .dropped_at + .lock() + .unwrap() + .map(|at| base_time.to_timestamp(at)), + attributes, + } + } } #[derive(Debug, Default)] @@ -159,3 +586,26 @@ impl Histogram { } } } + +impl RecordPoll for Histogram { + fn record_poll_duration(&mut self, duration: Duration) { + let mut duration_ns = duration.as_nanos() as u64; + + // clamp the duration to the histogram's max value + if duration_ns > self.max { + self.outliers += 1; + self.max_outlier = cmp::max(self.max_outlier, Some(duration_ns)); + duration_ns = self.max; + } + + self.histogram + .record(duration_ns) + .expect("duration has already been clamped to histogram max value") + } +} + +impl RecordPoll for () { + fn record_poll_duration(&mut self, _: Duration) { + // do nothing + } +} diff --git a/runtime/console/src/visitors.rs b/runtime/console/src/visitors.rs new file mode 100644 index 0000000..858703f --- /dev/null +++ b/runtime/console/src/visitors.rs @@ -0,0 +1,529 @@ +use crate::{attribute, event}; +use console_api::resources::resource; +use tracing::{field, span}; +use tracing_core::field::Visit; + +const LOCATION_FILE: &str = "loc.file"; +const LOCATION_LINE: &str = "loc.line"; +const LOCATION_COLUMN: &str = "loc.col"; +const INHERIT_FIELD_NAME: &str = "inherits_child_attrs"; + +/// Used to extract the fields needed to construct +/// an Event::Resource from the metadata of a tracing span +/// that has the following shape: +/// +/// tracing::trace_span!( +/// "runtime.resource", +/// concrete_type = "Sleep", +/// kind = "timer", +/// is_internal = true, +/// inherits_child_attrs = true, +/// ); +/// +/// Fields: +/// concrete_type - indicates the concrete rust type for this resource +/// kind - indicates the type of resource (i.e. timer, sync, io ) +/// is_internal - whether this is a resource type that is not exposed publicly (i.e. BatchSemaphore) +/// inherits_child_attrs - whether this resource should inherit the state attributes of its children +#[derive(Default)] +pub(crate) struct ResourceVisitor { + concrete_type: Option, + kind: Option, + is_internal: bool, + inherit_child_attrs: bool, + line: Option, + file: Option, + column: Option, +} + +pub(crate) struct ResourceVisitorResult { + pub(crate) concrete_type: String, + pub(crate) kind: resource::Kind, + pub(crate) location: Option, + pub(crate) is_internal: bool, + pub(crate) inherit_child_attrs: bool, +} + +/// Used to extract all fields from the metadata +/// of a tracing span +pub(crate) struct FieldVisitor { + fields: Vec, + meta_id: console_api::MetaId, +} + +/// Used to extract the fields needed to construct +/// an `Event::Spawn` from the metadata of a tracing span +/// that has the following shape: +/// +/// ``` +/// tracing::trace_span!( +/// target: "tokio::task", +/// "runtime.spawn", +/// kind = "local", +/// task.name = "some_name", +/// loc.file = "some_file.rs", +/// loc.line = 555, +/// loc.col = 5, +/// ); +/// ``` +/// +/// # Fields +/// +/// This visitor has special behavior for `loc.line`, `loc.file`, and `loc.col` +/// fields, which are interpreted as a Rust source code location where the task +/// was spawned, if they are present. Other fields are recorded as arbitrary +/// key-value pairs. +pub(crate) struct TaskVisitor { + field_visitor: FieldVisitor, + line: Option, + file: Option, + column: Option, +} + +/// Used to extract the fields needed to construct +/// an Event::AsyncOp from the metadata of a tracing span +/// that has the following shape: +/// +/// tracing::trace_span!( +/// "runtime.resource.async_op", +/// source = "Sleep::new_timeout", +/// ); +/// +/// Fields: +/// source - the method which has created an instance of this async operation +#[derive(Default)] +pub(crate) struct AsyncOpVisitor { + source: Option, + inherit_child_attrs: bool, +} + +/// Used to extract the fields needed to construct +/// an Event::Waker from the metadata of a tracing span +/// that has the following shape: +/// +/// tracing::trace!( +/// target: "tokio::task::waker", +/// op = "waker.clone", +/// task.id = id.into_u64(), +/// ); +/// +/// Fields: +/// task.id - the id of the task this waker will wake +/// op - the operation associated with this waker event +#[derive(Default)] +pub(crate) struct WakerVisitor { + id: Option, + op: Option, +} + +/// Used to extract the fields needed to construct +/// an Event::PollOp from the metadata of a tracing event +/// that has the following shape: +/// +/// tracing::trace!( +/// target: "runtime::resource::poll_op", +/// op_name = "poll_elapsed", +/// readiness = "pending" +/// ); +/// +/// Fields: +/// op_name - the name of this resource poll operation +/// readiness - the result of invoking this poll op, describing its readiness +#[derive(Default)] +pub(crate) struct PollOpVisitor { + op_name: Option, + is_ready: Option, +} + +/// Used to extract the fields needed to construct +/// an Event::StateUpdate from the metadata of a tracing event +/// that has the following shape: +/// +/// tracing::trace!( +/// target: "runtime::resource::state_update", +/// duration = duration, +/// duration.unit = "ms", +/// duration.op = "override", +/// ); +/// +/// Fields: +/// attribute_name - a field value for a field that has the name of the resource attribute being updated +/// value - the value for this update +/// unit - the unit for the value being updated (e.g. ms, s, bytes) +/// op - the operation that this update performs to the value of the resource attribute (one of: ovr, sub, add) +pub(crate) struct StateUpdateVisitor { + meta_id: console_api::MetaId, + field: Option, + unit: Option, + op: Option, +} + +impl ResourceVisitor { + pub(crate) const RES_SPAN_NAME: &'static str = "runtime.resource"; + const RES_CONCRETE_TYPE_FIELD_NAME: &'static str = "concrete_type"; + const RES_VIZ_FIELD_NAME: &'static str = "is_internal"; + const RES_KIND_FIELD_NAME: &'static str = "kind"; + const RES_KIND_TIMER: &'static str = "timer"; + + pub(crate) fn result(self) -> Option { + let concrete_type = self.concrete_type?; + let kind = self.kind?; + + let location = if self.file.is_some() && self.line.is_some() && self.column.is_some() { + Some(console_api::Location { + file: self.file, + line: self.line, + column: self.column, + ..Default::default() + }) + } else { + None + }; + + Some(ResourceVisitorResult { + concrete_type, + kind, + location, + is_internal: self.is_internal, + inherit_child_attrs: self.inherit_child_attrs, + }) + } +} + +impl Visit for ResourceVisitor { + fn record_debug(&mut self, _: &field::Field, _: &dyn std::fmt::Debug) {} + + fn record_str(&mut self, field: &tracing_core::Field, value: &str) { + match field.name() { + Self::RES_CONCRETE_TYPE_FIELD_NAME => self.concrete_type = Some(value.to_string()), + Self::RES_KIND_FIELD_NAME => { + let kind = Some(match value { + Self::RES_KIND_TIMER => { + resource::kind::Kind::Known(resource::kind::Known::Timer as i32) + } + other => resource::kind::Kind::Other(other.to_string()), + }); + self.kind = Some(resource::Kind { kind }); + } + LOCATION_FILE => self.file = Some(value.to_string()), + _ => {} + } + } + + fn record_bool(&mut self, field: &tracing_core::Field, value: bool) { + match field.name() { + Self::RES_VIZ_FIELD_NAME => self.is_internal = value, + INHERIT_FIELD_NAME => self.inherit_child_attrs = value, + _ => {} + } + } + + fn record_u64(&mut self, field: &tracing_core::Field, value: u64) { + match field.name() { + LOCATION_LINE => self.line = Some(value as u32), + LOCATION_COLUMN => self.column = Some(value as u32), + _ => {} + } + } +} + +impl FieldVisitor { + pub(crate) fn new(meta_id: console_api::MetaId) -> Self { + FieldVisitor { + fields: Vec::default(), + meta_id, + } + } + pub(crate) fn result(self) -> Vec { + self.fields + } +} + +impl TaskVisitor { + pub(crate) fn new(meta_id: console_api::MetaId) -> Self { + TaskVisitor { + field_visitor: FieldVisitor::new(meta_id), + line: None, + file: None, + column: None, + } + } + + pub(crate) fn result(self) -> (Vec, Option) { + let fields = self.field_visitor.result(); + let location = if self.file.is_some() && self.line.is_some() && self.column.is_some() { + Some(console_api::Location { + file: self.file, + line: self.line, + column: self.column, + ..Default::default() + }) + } else { + None + }; + + (fields, location) + } +} + +impl Visit for TaskVisitor { + fn record_debug(&mut self, field: &field::Field, value: &dyn std::fmt::Debug) { + self.field_visitor.record_debug(field, value); + } + + fn record_i64(&mut self, field: &tracing_core::Field, value: i64) { + self.field_visitor.record_i64(field, value); + } + + fn record_u64(&mut self, field: &tracing_core::Field, value: u64) { + match field.name() { + LOCATION_LINE => self.line = Some(value as u32), + LOCATION_COLUMN => self.column = Some(value as u32), + _ => self.field_visitor.record_u64(field, value), + } + } + + fn record_bool(&mut self, field: &tracing_core::Field, value: bool) { + self.field_visitor.record_bool(field, value); + } + + fn record_str(&mut self, field: &tracing_core::Field, value: &str) { + if field.name() == LOCATION_FILE { + self.file = Some(value.to_string()); + } else { + self.field_visitor.record_str(field, value); + } + } +} + +impl Visit for FieldVisitor { + fn record_debug(&mut self, field: &field::Field, value: &dyn std::fmt::Debug) { + self.fields.push(console_api::Field { + name: Some(field.name().into()), + value: Some(value.into()), + metadata_id: Some(self.meta_id.clone()), + }); + } + + fn record_i64(&mut self, field: &tracing_core::Field, value: i64) { + self.fields.push(console_api::Field { + name: Some(field.name().into()), + value: Some(value.into()), + metadata_id: Some(self.meta_id.clone()), + }); + } + + fn record_u64(&mut self, field: &tracing_core::Field, value: u64) { + self.fields.push(console_api::Field { + name: Some(field.name().into()), + value: Some(value.into()), + metadata_id: Some(self.meta_id.clone()), + }); + } + + fn record_bool(&mut self, field: &tracing_core::Field, value: bool) { + self.fields.push(console_api::Field { + name: Some(field.name().into()), + value: Some(value.into()), + metadata_id: Some(self.meta_id.clone()), + }); + } + + fn record_str(&mut self, field: &tracing_core::Field, value: &str) { + self.fields.push(console_api::Field { + name: Some(field.name().into()), + value: Some(value.into()), + metadata_id: Some(self.meta_id.clone()), + }); + } +} + +impl AsyncOpVisitor { + pub(crate) const ASYNC_OP_SPAN_NAME: &'static str = "runtime.resource.async_op"; + const ASYNC_OP_SRC_FIELD_NAME: &'static str = "source"; + + pub(crate) fn result(self) -> Option<(String, bool)> { + let inherit = self.inherit_child_attrs; + self.source.map(|s| (s, inherit)) + } +} + +impl Visit for AsyncOpVisitor { + fn record_debug(&mut self, _: &field::Field, _: &dyn std::fmt::Debug) {} + + fn record_str(&mut self, field: &tracing_core::Field, value: &str) { + if field.name() == Self::ASYNC_OP_SRC_FIELD_NAME { + self.source = Some(value.to_string()); + } + } + + fn record_bool(&mut self, field: &tracing_core::Field, value: bool) { + if field.name() == INHERIT_FIELD_NAME { + self.inherit_child_attrs = value; + } + } +} + +impl WakerVisitor { + const WAKE: &'static str = "waker.wake"; + const WAKE_BY_REF: &'static str = "waker.wake_by_ref"; + const CLONE: &'static str = "waker.clone"; + const DROP: &'static str = "waker.drop"; + const TASK_ID_FIELD_NAME: &'static str = "task.id"; + + pub(crate) fn result(self) -> Option<(span::Id, event::WakeOp)> { + self.id.zip(self.op) + } +} + +impl Visit for WakerVisitor { + fn record_debug(&mut self, _: &field::Field, _: &dyn std::fmt::Debug) { + // don't care (yet?) + } + + fn record_u64(&mut self, field: &tracing_core::Field, value: u64) { + if field.name() == Self::TASK_ID_FIELD_NAME { + self.id = Some(span::Id::from_u64(value)); + } + } + + fn record_str(&mut self, field: &tracing_core::Field, value: &str) { + use crate::event::WakeOp; + if field.name() == "op" { + self.op = Some(match value { + Self::WAKE => WakeOp::Wake { self_wake: false }, + Self::WAKE_BY_REF => WakeOp::WakeByRef { self_wake: false }, + Self::CLONE => WakeOp::Clone, + Self::DROP => WakeOp::Drop, + _ => return, + }); + } + } +} + +impl PollOpVisitor { + pub(crate) const POLL_OP_EVENT_TARGET: &'static str = "runtime::resource::poll_op"; + const OP_NAME_FIELD_NAME: &'static str = "op_name"; + const OP_READINESS_FIELD_NAME: &'static str = "is_ready"; + + pub(crate) fn result(self) -> Option<(String, bool)> { + let op_name = self.op_name?; + let is_ready = self.is_ready?; + Some((op_name, is_ready)) + } +} + +impl Visit for PollOpVisitor { + fn record_debug(&mut self, _: &field::Field, _: &dyn std::fmt::Debug) {} + + fn record_bool(&mut self, field: &tracing_core::Field, value: bool) { + if field.name() == Self::OP_READINESS_FIELD_NAME { + self.is_ready = Some(value) + } + } + + fn record_str(&mut self, field: &tracing_core::Field, value: &str) { + if field.name() == Self::OP_NAME_FIELD_NAME { + self.op_name = Some(value.to_string()); + } + } +} + +impl StateUpdateVisitor { + pub(crate) const RE_STATE_UPDATE_EVENT_TARGET: &'static str = "runtime::resource::state_update"; + pub(crate) const AO_STATE_UPDATE_EVENT_TARGET: &'static str = + "runtime::resource::async_op::state_update"; + + const STATE_OP_SUFFIX: &'static str = ".op"; + const STATE_UNIT_SUFFIX: &'static str = ".unit"; + + const OP_ADD: &'static str = "add"; + const OP_SUB: &'static str = "sub"; + const OP_OVERRIDE: &'static str = "override"; + + pub(crate) fn new(meta_id: console_api::MetaId) -> Self { + StateUpdateVisitor { + meta_id, + field: None, + unit: None, + op: None, + } + } + + pub(crate) fn result(self) -> Option { + Some(attribute::Update { + field: self.field?, + op: self.op, + unit: self.unit, + }) + } +} + +impl Visit for StateUpdateVisitor { + fn record_debug(&mut self, field: &field::Field, value: &dyn std::fmt::Debug) { + if !field.name().ends_with(Self::STATE_OP_SUFFIX) + && !field.name().ends_with(Self::STATE_UNIT_SUFFIX) + { + self.field = Some(console_api::Field { + name: Some(field.name().into()), + value: Some(value.into()), + metadata_id: Some(self.meta_id.clone()), + }); + } + } + + fn record_i64(&mut self, field: &field::Field, value: i64) { + if !field.name().ends_with(Self::STATE_OP_SUFFIX) + && !field.name().ends_with(Self::STATE_UNIT_SUFFIX) + { + self.field = Some(console_api::Field { + name: Some(field.name().into()), + value: Some(value.into()), + metadata_id: Some(self.meta_id.clone()), + }); + } + } + + fn record_u64(&mut self, field: &field::Field, value: u64) { + if !field.name().ends_with(Self::STATE_OP_SUFFIX) + && !field.name().ends_with(Self::STATE_UNIT_SUFFIX) + { + self.field = Some(console_api::Field { + name: Some(field.name().into()), + value: Some(value.into()), + metadata_id: Some(self.meta_id.clone()), + }); + } + } + + fn record_bool(&mut self, field: &field::Field, value: bool) { + if !field.name().ends_with(Self::STATE_OP_SUFFIX) + && !field.name().ends_with(Self::STATE_UNIT_SUFFIX) + { + self.field = Some(console_api::Field { + name: Some(field.name().into()), + value: Some(value.into()), + metadata_id: Some(self.meta_id.clone()), + }); + } + } + + fn record_str(&mut self, field: &field::Field, value: &str) { + if field.name().ends_with(Self::STATE_OP_SUFFIX) { + match value { + Self::OP_ADD => self.op = Some(attribute::UpdateOp::Add), + Self::OP_SUB => self.op = Some(attribute::UpdateOp::Sub), + Self::OP_OVERRIDE => self.op = Some(attribute::UpdateOp::Override), + _ => {} + }; + } else if field.name().ends_with(Self::STATE_UNIT_SUFFIX) { + self.unit = Some(value.to_string()); + } else { + self.field = Some(console_api::Field { + name: Some(field.name().into()), + value: Some(value.into()), + metadata_id: Some(self.meta_id.clone()), + }); + } + } +} From aef36fa3d4786d658fb7097e380c1debab08815b Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Tue, 21 Jun 2022 22:48:12 +0200 Subject: [PATCH 06/17] Some bits work \o/ --- runtime/console/src/lib.rs | 2 +- runtime/executor/src/pool.rs | 25 ++++++++++++------------- 2 files changed, 13 insertions(+), 14 deletions(-) diff --git a/runtime/console/src/lib.rs b/runtime/console/src/lib.rs index d0c9305..fb3ba3a 100644 --- a/runtime/console/src/lib.rs +++ b/runtime/console/src/lib.rs @@ -252,7 +252,7 @@ where { fn register_callsite(&self, metadata: &'static Metadata<'static>) -> Interest { let dropped = match (metadata.name(), metadata.target()) { - (_, "executor::spawn") => { + (_, "executor::task") | ("runtime.spawn", _) => { self.spawn_callsites.insert(metadata); &self.shared.dropped_tasks } diff --git a/runtime/executor/src/pool.rs b/runtime/executor/src/pool.rs index ff422d1..b74e035 100644 --- a/runtime/executor/src/pool.rs +++ b/runtime/executor/src/pool.rs @@ -22,7 +22,7 @@ use std::sync::Arc; use std::time::Duration; use tracing::field::FieldSet; use tracing::metadata::Kind; -use tracing::{Level, Span}; +use tracing::{Instrument, Level, Span}; #[derive(Debug)] struct Spooler<'a> { @@ -111,14 +111,13 @@ impl<'a, 'executor: 'a> Executor<'executor> { F: Future + Send + 'a, R: Send + 'a, { - let span = tracing::info_span!( - parent: &self.span, - //target: "executor::spawn", - "runtime.spawn" + let span = tracing::trace_span!( + target: "executor::task", + "runtime.spawn", ); - let _guard = span.enter(); + let fut = future.instrument(span); - let (task, handle) = LightProc::recoverable(future, self.schedule()); + let (task, handle) = LightProc::recoverable(fut, self.schedule()); tracing::trace!("spawning sendable task"); task.schedule(); handle @@ -129,13 +128,13 @@ impl<'a, 'executor: 'a> Executor<'executor> { F: Future + 'a, R: Send + 'a, { - let span = tracing::info_span!( - parent: &self.span, - //target: "executor::spawn", - "runtime.spawn_local" + let span = tracing::trace_span!( + target: "executor::task", + "runtime.spawn", ); - let _guard = span.enter(); - let (task, handle) = LightProc::recoverable(future, schedule_local()); + let fut = future.instrument(span); + + let (task, handle) = LightProc::recoverable(fut, schedule_local()); tracing::trace!("spawning sendable task"); task.schedule(); handle From 2d8d6f9938e0efa63c7b0b0bef36f2feeaccc0ff Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Wed, 22 Jun 2022 14:43:09 +0200 Subject: [PATCH 07/17] tracing more data --- Cargo.lock | 1 + bffhd/lib.rs | 13 ++++++-- runtime/console/src/lib.rs | 6 ++-- runtime/console/src/server.rs | 3 -- runtime/console/src/visitors.rs | 6 ++++ runtime/executor/src/pool.rs | 8 ++--- runtime/executor/src/worker.rs | 1 + runtime/lightproc/Cargo.toml | 1 + runtime/lightproc/src/lib.rs | 4 +-- runtime/lightproc/src/lightproc.rs | 15 ++++++--- runtime/lightproc/src/proc_data.rs | 7 ++++ runtime/lightproc/src/raw_proc.rs | 53 +++++++++++++++++++++++++++++- 12 files changed, 98 insertions(+), 20 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 164f0c9..4764797 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1736,6 +1736,7 @@ dependencies = [ "futures-executor", "lazy_static", "pin-utils", + "tracing", ] [[package]] diff --git a/bffhd/lib.rs b/bffhd/lib.rs index e0c9d86..4153e9b 100644 --- a/bffhd/lib.rs +++ b/bffhd/lib.rs @@ -62,6 +62,7 @@ use crate::users::db::UserDB; use crate::users::Users; use executor::pool::Executor; use signal_hook::consts::signal::*; +use tracing::Span; pub struct Diflouroborane { config: Config, @@ -70,6 +71,7 @@ pub struct Diflouroborane { pub users: Users, pub roles: Roles, pub resources: ResourcesHandle, + span: Span, } pub static RESOURCES: OnceCell = OnceCell::new(); @@ -77,11 +79,14 @@ pub static RESOURCES: OnceCell = OnceCell::new(); impl Diflouroborane { pub fn new(config: Config) -> miette::Result { let mut server = logging::init(&config.logging); + let span = tracing::info_span!( + target: "bffh", + "bffh" + ); + let span2 = span.clone(); + let _guard = span2.enter(); tracing::info!(version = env::VERSION, "Starting BFFH"); - let span = tracing::info_span!("setup"); - let _guard = span.enter(); - let executor = Executor::new(); if let Some(aggregator) = server.aggregator.take() { @@ -116,10 +121,12 @@ impl Diflouroborane { users, roles, resources, + span, }) } pub fn run(&mut self) -> miette::Result<()> { + let _guard = self.span.enter(); let mut signals = signal_hook_async_std::Signals::new(&[SIGINT, SIGQUIT, SIGTERM]) .into_diagnostic() .wrap_err("Failed to construct signal handler")?; diff --git a/runtime/console/src/lib.rs b/runtime/console/src/lib.rs index fb3ba3a..112c6d2 100644 --- a/runtime/console/src/lib.rs +++ b/runtime/console/src/lib.rs @@ -252,11 +252,11 @@ where { fn register_callsite(&self, metadata: &'static Metadata<'static>) -> Interest { let dropped = match (metadata.name(), metadata.target()) { - (_, "executor::task") | ("runtime.spawn", _) => { + (_, TaskVisitor::SPAWN_TARGET) | (TaskVisitor::SPAWN_NAME, _) => { self.spawn_callsites.insert(metadata); &self.shared.dropped_tasks } - (_, "executor::waker") => { + (WakerVisitor::WAKE_TARGET, _) => { self.waker_callsites.insert(metadata); &self.shared.dropped_tasks } @@ -268,7 +268,7 @@ where self.async_op_callsites.insert(metadata); &self.shared.dropped_async_ops } - ("runtime.resource.async_op.poll", _) => { + (AsyncOpVisitor::ASYNC_OP_POLL_NAME, _) => { self.async_op_poll_callsites.insert(metadata); &self.shared.dropped_async_ops } diff --git a/runtime/console/src/server.rs b/runtime/console/src/server.rs index 14ff385..b92e8c0 100644 --- a/runtime/console/src/server.rs +++ b/runtime/console/src/server.rs @@ -97,9 +97,6 @@ impl Server { pub async fn serve( mut self, /*, incoming: I */ ) -> Result<(), Box> { - // TODO: Spawn two tasks; the aggregator that's collecting stats, aggregating and - // collating them and the server task doing the tonic gRPC stuff - let svc = InstrumentServer::new(self); tonic::transport::Server::builder() diff --git a/runtime/console/src/visitors.rs b/runtime/console/src/visitors.rs index 858703f..77398d1 100644 --- a/runtime/console/src/visitors.rs +++ b/runtime/console/src/visitors.rs @@ -240,6 +240,9 @@ impl FieldVisitor { } impl TaskVisitor { + pub(crate) const SPAWN_TARGET: &'static str = "executor::task"; + pub(crate) const SPAWN_NAME: &'static str = "runtime.spawn"; + pub(crate) fn new(meta_id: console_api::MetaId) -> Self { TaskVisitor { field_visitor: FieldVisitor::new(meta_id), @@ -340,6 +343,7 @@ impl Visit for FieldVisitor { impl AsyncOpVisitor { pub(crate) const ASYNC_OP_SPAN_NAME: &'static str = "runtime.resource.async_op"; + pub(crate) const ASYNC_OP_POLL_NAME: &'static str = "runtime.resource.async_op.poll"; const ASYNC_OP_SRC_FIELD_NAME: &'static str = "source"; pub(crate) fn result(self) -> Option<(String, bool)> { @@ -365,6 +369,8 @@ impl Visit for AsyncOpVisitor { } impl WakerVisitor { + pub(crate) const WAKE_TARGET: &'static str = "executor::waker"; + const WAKE: &'static str = "waker.wake"; const WAKE_BY_REF: &'static str = "waker.wake_by_ref"; const CLONE: &'static str = "waker.clone"; diff --git a/runtime/executor/src/pool.rs b/runtime/executor/src/pool.rs index b74e035..d6f1338 100644 --- a/runtime/executor/src/pool.rs +++ b/runtime/executor/src/pool.rs @@ -113,11 +113,11 @@ impl<'a, 'executor: 'a> Executor<'executor> { { let span = tracing::trace_span!( target: "executor::task", + parent: &self.span, "runtime.spawn", ); - let fut = future.instrument(span); - let (task, handle) = LightProc::recoverable(fut, self.schedule()); + let (task, handle) = LightProc::recoverable(future, self.schedule(), span); tracing::trace!("spawning sendable task"); task.schedule(); handle @@ -130,11 +130,11 @@ impl<'a, 'executor: 'a> Executor<'executor> { { let span = tracing::trace_span!( target: "executor::task", + parent: &self.span, "runtime.spawn", ); - let fut = future.instrument(span); - let (task, handle) = LightProc::recoverable(fut, schedule_local()); + let (task, handle) = LightProc::recoverable(future, schedule_local(), span); tracing::trace!("spawning sendable task"); task.schedule(); handle diff --git a/runtime/executor/src/worker.rs b/runtime/executor/src/worker.rs index 345afa7..413476e 100644 --- a/runtime/executor/src/worker.rs +++ b/runtime/executor/src/worker.rs @@ -2,6 +2,7 @@ use crossbeam_deque::{Injector, Steal, Stealer, Worker}; use crossbeam_queue::SegQueue; use crossbeam_utils::sync::{Parker, Unparker}; use lightproc::prelude::LightProc; +use lightproc::raw_proc::ProcData; use std::marker::PhantomData; use std::sync::Arc; use std::time::Duration; diff --git a/runtime/lightproc/Cargo.toml b/runtime/lightproc/Cargo.toml index 52403ea..7d4be3e 100644 --- a/runtime/lightproc/Cargo.toml +++ b/runtime/lightproc/Cargo.toml @@ -15,6 +15,7 @@ crossbeam-utils = "0.8" pin-utils = "0.1.0" bitfield = "0.13.2" bitflags = "1.3.2" +tracing = "0.1" [dev-dependencies] crossbeam = "0.8" diff --git a/runtime/lightproc/src/lib.rs b/runtime/lightproc/src/lib.rs index fc325b0..2bcf9db 100644 --- a/runtime/lightproc/src/lib.rs +++ b/runtime/lightproc/src/lib.rs @@ -16,9 +16,9 @@ #![forbid(missing_docs)] #![forbid(missing_debug_implementations)] #![forbid(unused_import_braces)] -#![forbid(unused_imports)] +#![warn(unused_imports)] #![forbid(unused_must_use)] -#![forbid(unused_variables)] +//TODO: reenable #![forbid(unused_variables)] mod catch_unwind; mod layout_helpers; diff --git a/runtime/lightproc/src/lightproc.rs b/runtime/lightproc/src/lightproc.rs index c94b5fa..0900f56 100644 --- a/runtime/lightproc/src/lightproc.rs +++ b/runtime/lightproc/src/lightproc.rs @@ -36,6 +36,7 @@ use std::future::Future; use std::mem::ManuallyDrop; use std::panic::AssertUnwindSafe; use std::ptr::NonNull; +use tracing::Span; /// Shared functionality for both Send and !Send LightProc pub struct LightProc { @@ -76,14 +77,18 @@ impl LightProc { /// println!("future panicked!: {}", &reason); /// }); /// ``` - pub fn recoverable<'a, F, R, S>(future: F, schedule: S) -> (Self, RecoverableHandle) + pub fn recoverable<'a, F, R, S>( + future: F, + schedule: S, + span: Span, + ) -> (Self, RecoverableHandle) where F: Future + 'a, R: 'a, S: Fn(LightProc) + 'a, { let recovery_future = AssertUnwindSafe(future).catch_unwind(); - let (proc, handle) = Self::build(recovery_future, schedule); + let (proc, handle) = Self::build(recovery_future, schedule, span); (proc, RecoverableHandle::new(handle)) } @@ -92,6 +97,7 @@ impl LightProc { /// /// # Example /// ```rust + /// # use tracing::Span; /// # use lightproc::prelude::*; /// # /// # // ... future that does work @@ -113,15 +119,16 @@ impl LightProc { /// let standard = LightProc::build( /// future, /// schedule_function, + /// Span::current(), /// ); /// ``` - pub fn build<'a, F, R, S>(future: F, schedule: S) -> (Self, ProcHandle) + pub fn build<'a, F, R, S>(future: F, schedule: S, span: Span) -> (Self, ProcHandle) where F: Future + 'a, R: 'a, S: Fn(LightProc) + 'a, { - let raw_proc = RawProc::allocate(future, schedule); + let raw_proc = RawProc::allocate(future, schedule, span); let proc = LightProc { raw_proc }; let handle = ProcHandle::new(raw_proc); (proc, handle) diff --git a/runtime/lightproc/src/proc_data.rs b/runtime/lightproc/src/proc_data.rs index be9b956..8c215a5 100644 --- a/runtime/lightproc/src/proc_data.rs +++ b/runtime/lightproc/src/proc_data.rs @@ -5,6 +5,7 @@ use std::cell::Cell; use std::fmt::{self, Debug, Formatter}; use std::sync::atomic::Ordering; use std::task::Waker; +use tracing::Span; /// The pdata of a proc. /// @@ -25,6 +26,12 @@ pub(crate) struct ProcData { /// In addition to the actual waker virtual table, it also contains pointers to several other /// methods necessary for bookkeeping the heap-allocated proc. pub(crate) vtable: &'static ProcVTable, + + /// The span assigned to this process. + /// + /// A lightproc has a tracing span associated that allow recording occurances of vtable calls + /// for this process. + pub(crate) span: Span, } impl ProcData { diff --git a/runtime/lightproc/src/raw_proc.rs b/runtime/lightproc/src/raw_proc.rs index 4c28603..c06cf95 100644 --- a/runtime/lightproc/src/raw_proc.rs +++ b/runtime/lightproc/src/raw_proc.rs @@ -16,8 +16,10 @@ use std::ptr::NonNull; use std::sync::atomic::Ordering; use std::task::{Context, Poll, RawWaker, RawWakerVTable, Waker}; +use tracing::Span; /// Raw pointers to the fields of a proc. +// TODO: Make generic over the Allocator used! pub(crate) struct RawProc<'a, F, R, S> { pub(crate) pdata: *const ProcData, pub(crate) schedule: *const S, @@ -26,6 +28,10 @@ pub(crate) struct RawProc<'a, F, R, S> { // Make the lifetime 'a of the future invariant _marker: PhantomData<&'a ()>, + // TODO: We should link a proc to a process bucket for scheduling and tracing + // => nope, do that via scheduling func + // TODO: A proc should be able to be assigned a name for tracing and reporting + // This could also be implemented via storing a Span similar to `Instrumented` } impl<'a, F, R, S> RawProc<'a, F, R, S> @@ -37,7 +43,7 @@ where /// Allocates a proc with the given `future` and `schedule` function. /// /// It is assumed there are initially only the `LightProc` reference and the `ProcHandle`. - pub(crate) fn allocate(future: F, schedule: S) -> NonNull<()> { + pub(crate) fn allocate(future: F, schedule: S, span: Span) -> NonNull<()> { // Compute the layout of the proc for allocation. Abort if the computation fails. let proc_layout = Self::proc_layout(); @@ -70,6 +76,7 @@ where destroy: Self::destroy, tick: Self::tick, }, + span, }); // Write the schedule function as the third field of the proc. @@ -128,6 +135,16 @@ where /// Wakes a waker. unsafe fn wake(ptr: *const ()) { let raw = Self::from_ptr(ptr); + let _guard = (&(*raw.pdata).span).enter(); + let id = (&(*raw.pdata).span) + .id() + .map(|id| id.into_u64()) + .unwrap_or(0); + tracing::trace!( + target: "executor::waker", + op = "waker.wake", + task.id = id, + ); let mut state = (*raw.pdata).state.load(Ordering::Acquire); @@ -191,6 +208,16 @@ where /// Wakes a waker by reference. unsafe fn wake_by_ref(ptr: *const ()) { let raw = Self::from_ptr(ptr); + let _guard = (&(*raw.pdata).span).enter(); + let id = (&(*raw.pdata).span) + .id() + .map(|id| id.into_u64()) + .unwrap_or(0); + tracing::trace!( + target: "executor::waker", + op = "waker.wake_by_ref", + task.id = id, + ); let mut state = (*raw.pdata).state.load(Ordering::Acquire); @@ -250,6 +277,17 @@ where /// Clones a waker. unsafe fn clone_waker(ptr: *const ()) -> RawWaker { let raw = Self::from_ptr(ptr); + let _guard = (&(*raw.pdata).span).enter(); + let id = (&(*raw.pdata).span) + .id() + .map(|id| id.into_u64()) + .unwrap_or(0); + tracing::trace!( + target: "executor::waker", + op = "waker.clone", + task.id = id, + ); + let raw_waker = &(*raw.pdata).vtable.raw_waker; // Increment the reference count. With any kind of reference-counted data structure, @@ -271,6 +309,16 @@ where #[inline] unsafe fn decrement(ptr: *const ()) { let raw = Self::from_ptr(ptr); + let _guard = (&(*raw.pdata).span).enter(); + let id = (&(*raw.pdata).span) + .id() + .map(|id| id.into_u64()) + .unwrap_or(0); + tracing::trace!( + target: "executor::waker", + op = "waker.drop", + task.id = id, + ); // Decrement the reference count. let new = (*raw.pdata).state.fetch_sub(1, Ordering::AcqRel); @@ -323,6 +371,9 @@ where // Drop the schedule function. (raw.schedule as *mut S).drop_in_place(); + // Drop the proc data containing the associated Span + (raw.pdata as *mut ProcData).drop_in_place(); + // Finally, deallocate the memory reserved by the proc. alloc::dealloc(ptr as *mut u8, proc_layout.layout); } From 18d69063fd6fb7b856b91ff58188f213704ef324 Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Wed, 22 Jun 2022 19:01:51 +0200 Subject: [PATCH 08/17] Even more console shenanigans --- bffhd/lib.rs | 17 ++++++++++++++++- runtime/console/src/aggregate.rs | 8 +++----- runtime/console/src/lib.rs | 16 ++++++++++++---- runtime/console/src/stats.rs | 3 +-- runtime/executor/src/pool.rs | 16 ++++++++++++++-- runtime/executor/src/worker.rs | 1 - 6 files changed, 46 insertions(+), 15 deletions(-) diff --git a/bffhd/lib.rs b/bffhd/lib.rs index 4153e9b..777b81e 100644 --- a/bffhd/lib.rs +++ b/bffhd/lib.rs @@ -92,7 +92,22 @@ impl Diflouroborane { if let Some(aggregator) = server.aggregator.take() { executor.spawn(aggregator.run()); } - executor.spawn(server.serve()); + tracing::info!("Server is being spawned"); + let handle = executor.spawn(server.serve()); + std::thread::spawn(move || { + let result = async_io::block_on(handle); + match result { + Some(Ok(())) => { + tracing::info!("console server finished without error"); + } + Some(Err(error)) => { + tracing::info!(%error, "console server finished with error"); + } + None => { + tracing::info!("console server finished with panic"); + } + } + }); let env = StateDB::open_env(&config.db_path)?; diff --git a/runtime/console/src/aggregate.rs b/runtime/console/src/aggregate.rs index 1acf6d2..4029a1f 100644 --- a/runtime/console/src/aggregate.rs +++ b/runtime/console/src/aggregate.rs @@ -335,13 +335,13 @@ impl Aggregator { async_op_update, }; - //self.watchers.retain_and_shrink(|watch: &Watch| watch.update - // (&update)); + self.watchers + .retain(|watch: &Watch| watch.update(&update)); let stats = &self.task_stats; // Assuming there are much fewer task details subscribers than there are // stats updates, iterate over `details_watchers` and compact the map. - /*self.details_watchers.retain_and_shrink(|id, watchers| { + self.details_watchers.retain(|id, watchers| { if let Some(task_stats) = stats.get(id) { let details = tasks::TaskDetails { task_id: Some(id.clone().into()), @@ -354,8 +354,6 @@ impl Aggregator { false } }); - - */ } /// Update the current state with data from a single event. diff --git a/runtime/console/src/lib.rs b/runtime/console/src/lib.rs index 112c6d2..e5c7cc7 100644 --- a/runtime/console/src/lib.rs +++ b/runtime/console/src/lib.rs @@ -256,7 +256,7 @@ where self.spawn_callsites.insert(metadata); &self.shared.dropped_tasks } - (WakerVisitor::WAKE_TARGET, _) => { + (_, WakerVisitor::WAKE_TARGET) => { self.waker_callsites.insert(metadata); &self.shared.dropped_tasks } @@ -311,7 +311,9 @@ where (event, stats) }) { ctx.span(id) - .expect("`on_new_span` called with nonexistent span. This is a tracing bug."); + .expect("`on_new_span` called with nonexistent span. This is a tracing bug.") + .extensions_mut() + .insert(stats); } } else if self.is_resource(metadata) { let at = Instant::now(); @@ -346,7 +348,10 @@ where }; (event, stats) }) { - ctx.span(id).expect("if `on_new_span` was called, the span must exist; this is a `tracing` bug!").extensions_mut().insert(stats); + ctx.span(id) + .expect("if `on_new_span` was called, the span must exist; this is a `tracing` bug!") + .extensions_mut() + .insert(stats); } } } else if self.is_async_op(metadata) { @@ -381,7 +386,10 @@ where (event, stats) }) { - ctx.span(id).expect("if `on_new_span` was called, the span must exist; this is a `tracing` bug!").extensions_mut().insert(stats); + ctx.span(id) + .expect("if `on_new_span` was called, the span must exist; this is a `tracing` bug!") + .extensions_mut() + .insert(stats); } } } diff --git a/runtime/console/src/stats.rs b/runtime/console/src/stats.rs index 9018d8f..021c8da 100644 --- a/runtime/console/src/stats.rs +++ b/runtime/console/src/stats.rs @@ -209,7 +209,7 @@ impl TaskStats { polls: AtomicUsize::new(0), }, wakes: AtomicUsize::new(0), - waker_clones: AtomicUsize::new(0), + waker_clones: AtomicUsize::new(1), waker_drops: AtomicUsize::new(0), self_wakes: AtomicUsize::new(0), } @@ -232,7 +232,6 @@ impl TaskStats { use event::WakeOp; match op { WakeOp::Wake { self_wake } => { - self.waker_drops.fetch_add(1, Ordering::Release); self.wake(at, self_wake); } WakeOp::WakeByRef { self_wake } => { diff --git a/runtime/executor/src/pool.rs b/runtime/executor/src/pool.rs index d6f1338..4c91363 100644 --- a/runtime/executor/src/pool.rs +++ b/runtime/executor/src/pool.rs @@ -106,15 +106,21 @@ impl<'a, 'executor: 'a> Executor<'executor> { /// ); /// # } /// ``` + #[track_caller] pub fn spawn(&self, future: F) -> RecoverableHandle where F: Future + Send + 'a, R: Send + 'a, { + let location = std::panic::Location::caller(); let span = tracing::trace_span!( target: "executor::task", - parent: &self.span, + parent: Span::current(), "runtime.spawn", + kind = "global", + loc.file = location.file(), + loc.line = location.line(), + loc.col = location.column(), ); let (task, handle) = LightProc::recoverable(future, self.schedule(), span); @@ -123,15 +129,21 @@ impl<'a, 'executor: 'a> Executor<'executor> { handle } + #[track_caller] pub fn spawn_local(&self, future: F) -> RecoverableHandle where F: Future + 'a, R: Send + 'a, { + let location = std::panic::Location::caller(); let span = tracing::trace_span!( target: "executor::task", - parent: &self.span, + parent: Span::current(), "runtime.spawn", + kind = "local", + loc.file = location.file(), + loc.line = location.line(), + loc.col = location.column(), ); let (task, handle) = LightProc::recoverable(future, schedule_local(), span); diff --git a/runtime/executor/src/worker.rs b/runtime/executor/src/worker.rs index 413476e..345afa7 100644 --- a/runtime/executor/src/worker.rs +++ b/runtime/executor/src/worker.rs @@ -2,7 +2,6 @@ use crossbeam_deque::{Injector, Steal, Stealer, Worker}; use crossbeam_queue::SegQueue; use crossbeam_utils::sync::{Parker, Unparker}; use lightproc::prelude::LightProc; -use lightproc::raw_proc::ProcData; use std::marker::PhantomData; use std::sync::Arc; use std::time::Duration; From 9a86bae45a5900e3cd90d4bb5db9fe938f2cde00 Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Thu, 23 Jun 2022 13:02:40 +0200 Subject: [PATCH 09/17] Improve Drop guards --- runtime/lightproc/src/raw_proc.rs | 45 ++++++++++++++++++++++--------- 1 file changed, 33 insertions(+), 12 deletions(-) diff --git a/runtime/lightproc/src/raw_proc.rs b/runtime/lightproc/src/raw_proc.rs index c06cf95..81e0c21 100644 --- a/runtime/lightproc/src/raw_proc.rs +++ b/runtime/lightproc/src/raw_proc.rs @@ -24,6 +24,7 @@ pub(crate) struct RawProc<'a, F, R, S> { pub(crate) pdata: *const ProcData, pub(crate) schedule: *const S, pub(crate) future: *mut F, + // TODO: Replace with `MaybeUninit` pub(crate) output: *mut R, // Make the lifetime 'a of the future invariant @@ -135,7 +136,6 @@ where /// Wakes a waker. unsafe fn wake(ptr: *const ()) { let raw = Self::from_ptr(ptr); - let _guard = (&(*raw.pdata).span).enter(); let id = (&(*raw.pdata).span) .id() .map(|id| id.into_u64()) @@ -208,7 +208,6 @@ where /// Wakes a waker by reference. unsafe fn wake_by_ref(ptr: *const ()) { let raw = Self::from_ptr(ptr); - let _guard = (&(*raw.pdata).span).enter(); let id = (&(*raw.pdata).span) .id() .map(|id| id.into_u64()) @@ -277,7 +276,6 @@ where /// Clones a waker. unsafe fn clone_waker(ptr: *const ()) -> RawWaker { let raw = Self::from_ptr(ptr); - let _guard = (&(*raw.pdata).span).enter(); let id = (&(*raw.pdata).span) .id() .map(|id| id.into_u64()) @@ -309,7 +307,6 @@ where #[inline] unsafe fn decrement(ptr: *const ()) { let raw = Self::from_ptr(ptr); - let _guard = (&(*raw.pdata).span).enter(); let id = (&(*raw.pdata).span) .id() .map(|id| id.into_u64()) @@ -383,9 +380,11 @@ where /// Ticking will call `poll` once and re-schedule the task if it returns `Poll::Pending`. If /// polling its future panics, the proc will be closed and the panic propagated into the caller. unsafe fn tick(ptr: *const ()) { - let raw = Self::from_ptr(ptr); + let mut raw = Self::from_ptr(ptr); + // Enter the span associated with the process to track execution time if enabled. + let _guard = (&(*raw.pdata).span).enter(); - // Create a context from the raw proc pointer and the vtable inside the its pdata. + // Create a context from the raw proc pointer and the vtable inside its pdata. let waker = ManuallyDrop::new(Waker::from_raw(RawWaker::new( ptr, &(*raw.pdata).vtable.raw_waker, @@ -431,9 +430,9 @@ where // Poll the inner future, but surround it with a guard that closes the proc in case polling // panics. - let guard = Guard(raw); - let poll = ::poll(Pin::new_unchecked(&mut *raw.future), cx); - mem::forget(guard); + let drop_guard = Guard(&mut raw); + let poll = ::poll(drop_guard.pin_future(), cx); + drop_guard.disable(); match poll { Poll::Ready(out) => { @@ -548,21 +547,43 @@ impl<'a, F, R, S> Clone for RawProc<'a, F, R, S> { } impl<'a, F, R, S> Copy for RawProc<'a, F, R, S> {} +#[repr(transparent)] /// A guard that closes the proc if polling its future panics. -struct Guard<'a, F, R, S>(RawProc<'a, F, R, S>) +struct Guard<'guard, 'a, F, R, S>(&'guard mut RawProc<'a, F, R, S>) where F: Future + 'a, R: 'a, S: Fn(LightProc) + 'a; -impl<'a, F, R, S> Drop for Guard<'a, F, R, S> +impl<'guard, 'a, F, R, S> Guard<'guard, 'a, F, R, S> +where + F: Future + 'a, + R: 'a, + S: Fn(LightProc) + 'a, +{ + #[inline(always)] + /// Disable the guard again. + /// + /// This does essentially nothing but prevents the Drop implementation from being called + fn disable(self) { + // Put `self` in a ManuallyDrop telling the compiler to explicitly not call Drop::drop + let _ = ManuallyDrop::new(self); + } + + #[inline(always)] + unsafe fn pin_future(&self) -> Pin<&mut F> { + Pin::new_unchecked(&mut *self.0.future) + } +} + +impl<'a, F, R, S> Drop for Guard<'_, 'a, F, R, S> where F: Future + 'a, R: 'a, S: Fn(LightProc) + 'a, { fn drop(&mut self) { - let raw = self.0; + let raw = &self.0; let ptr = raw.pdata as *const (); unsafe { From 567df800f30d47baf1ac76fed06d74875f3e94ea Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Thu, 23 Jun 2022 13:33:29 +0200 Subject: [PATCH 10/17] A number of small updates batched into one commit --- runtime/console/src/lib.rs | 3 ++- runtime/console/src/visitors.rs | 2 +- runtime/executor/src/pool.rs | 4 ++-- runtime/lightproc/src/proc_handle.rs | 2 ++ runtime/lightproc/src/raw_proc.rs | 3 ++- 5 files changed, 9 insertions(+), 5 deletions(-) diff --git a/runtime/console/src/lib.rs b/runtime/console/src/lib.rs index e5c7cc7..c3d38af 100644 --- a/runtime/console/src/lib.rs +++ b/runtime/console/src/lib.rs @@ -256,7 +256,7 @@ where self.spawn_callsites.insert(metadata); &self.shared.dropped_tasks } - (_, WakerVisitor::WAKE_TARGET) => { + (_, WakerVisitor::WAKER_EVENT_TARGET) => { self.waker_callsites.insert(metadata); &self.shared.dropped_tasks } @@ -419,6 +419,7 @@ where } } } + } else if self.poll_op_callsites.contains(metadata) { } } diff --git a/runtime/console/src/visitors.rs b/runtime/console/src/visitors.rs index 77398d1..75706a6 100644 --- a/runtime/console/src/visitors.rs +++ b/runtime/console/src/visitors.rs @@ -369,7 +369,7 @@ impl Visit for AsyncOpVisitor { } impl WakerVisitor { - pub(crate) const WAKE_TARGET: &'static str = "executor::waker"; + pub(crate) const WAKER_EVENT_TARGET: &'static str = "executor::waker"; const WAKE: &'static str = "waker.wake"; const WAKE_BY_REF: &'static str = "waker.wake_by_ref"; diff --git a/runtime/executor/src/pool.rs b/runtime/executor/src/pool.rs index 4c91363..50adb8b 100644 --- a/runtime/executor/src/pool.rs +++ b/runtime/executor/src/pool.rs @@ -117,10 +117,10 @@ impl<'a, 'executor: 'a> Executor<'executor> { target: "executor::task", parent: Span::current(), "runtime.spawn", - kind = "global", loc.file = location.file(), loc.line = location.line(), loc.col = location.column(), + kind = "global", ); let (task, handle) = LightProc::recoverable(future, self.schedule(), span); @@ -140,10 +140,10 @@ impl<'a, 'executor: 'a> Executor<'executor> { target: "executor::task", parent: Span::current(), "runtime.spawn", - kind = "local", loc.file = location.file(), loc.line = location.line(), loc.col = location.column(), + kind = "local", ); let (task, handle) = LightProc::recoverable(future, schedule_local(), span); diff --git a/runtime/lightproc/src/proc_handle.rs b/runtime/lightproc/src/proc_handle.rs index f2144e6..2dd7666 100644 --- a/runtime/lightproc/src/proc_handle.rs +++ b/runtime/lightproc/src/proc_handle.rs @@ -22,6 +22,8 @@ pub struct ProcHandle { pub(crate) raw_proc: NonNull<()>, /// A marker capturing the generic type `R`. + // TODO: Instead of writing the future output to the RawProc on heap, put it in the handle + // (if still available). pub(crate) result: PhantomData, } diff --git a/runtime/lightproc/src/raw_proc.rs b/runtime/lightproc/src/raw_proc.rs index 81e0c21..b23d4f4 100644 --- a/runtime/lightproc/src/raw_proc.rs +++ b/runtime/lightproc/src/raw_proc.rs @@ -24,7 +24,8 @@ pub(crate) struct RawProc<'a, F, R, S> { pub(crate) pdata: *const ProcData, pub(crate) schedule: *const S, pub(crate) future: *mut F, - // TODO: Replace with `MaybeUninit` + // TODO: Replace with `*mut MaybeUninit`? And also, store the result in the handle if that's + // still available, instead of copying it to the heap. pub(crate) output: *mut R, // Make the lifetime 'a of the future invariant From 2f5f7cb0d79b900d808a5a578a132e5ca72a9640 Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Thu, 23 Jun 2022 14:37:17 +0200 Subject: [PATCH 11/17] More ideas about how to record data --- Cargo.lock | 35 ++++++++++++++++++++++++++++ runtime/executor/Cargo.toml | 6 ++++- runtime/executor/src/pool.rs | 11 --------- runtime/lightproc/src/proc_handle.rs | 8 +++++++ 4 files changed, 48 insertions(+), 12 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 4764797..6932cc5 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1119,11 +1119,13 @@ dependencies = [ "crossbeam-utils", "futures-timer", "futures-util", + "hdrhistogram", "lazy_static", "libc", "lightproc", "num_cpus", "once_cell", + "parking_lot", "pin-utils", "rand", "slab", @@ -1782,6 +1784,16 @@ dependencies = [ "pkg-config", ] +[[package]] +name = "lock_api" +version = "0.4.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "327fa5b6a6940e4699ec49a9beae1ea4845c6bab9314e4f84ac68742139d8c53" +dependencies = [ + "autocfg", + "scopeguard", +] + [[package]] name = "log" version = "0.4.17" @@ -2029,6 +2041,29 @@ version = "2.0.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "427c3892f9e783d91cc128285287e70a59e206ca452770ece88a76f7a3eddd72" +[[package]] +name = "parking_lot" +version = "0.12.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3742b2c103b9f06bc9fff0a37ff4912935851bee6d36f3c02bcc755bcfec228f" +dependencies = [ + "lock_api", + "parking_lot_core", +] + +[[package]] +name = "parking_lot_core" +version = "0.9.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "09a279cbf25cb0757810394fbc1e359949b59e348145c643a939a525692e6929" +dependencies = [ + "cfg-if", + "libc", + "redox_syscall", + "smallvec", + "windows-sys", +] + [[package]] name = "percent-encoding" version = "2.1.0" diff --git a/runtime/executor/Cargo.toml b/runtime/executor/Cargo.toml index ac3a2c3..85c6df6 100644 --- a/runtime/executor/Cargo.toml +++ b/runtime/executor/Cargo.toml @@ -40,13 +40,17 @@ libc = "0.2" num_cpus = "1.13" pin-utils = "0.1.0" slab = "0.4" +parking_lot = "0.12" # Allocator arrayvec = { version = "0.7.0" } futures-timer = "3.0.2" once_cell = "1.4.0" -tracing = "0.1.19" crossbeam-queue = "0.3.0" +hdrhistogram = "7.5" + +# Stats & Tracing +tracing = "0.1" [dev-dependencies] async-std = "1.10.0" diff --git a/runtime/executor/src/pool.rs b/runtime/executor/src/pool.rs index 50adb8b..4f288d6 100644 --- a/runtime/executor/src/pool.rs +++ b/runtime/executor/src/pool.rs @@ -48,21 +48,12 @@ impl Spooler<'_> { /// Global executor pub struct Executor<'a> { spooler: Arc>, - span: Span, } impl<'a, 'executor: 'a> Executor<'executor> { pub fn new() -> Self { Executor { spooler: Arc::new(Spooler::new()), - span: tracing::span!(Level::INFO, "executor"), - } - } - - pub fn new_with_parent_span(parent: &Span) -> Self { - Executor { - spooler: Arc::new(Spooler::new()), - span: tracing::span!(parent: parent, Level::INFO, "executor"), } } @@ -115,7 +106,6 @@ impl<'a, 'executor: 'a> Executor<'executor> { let location = std::panic::Location::caller(); let span = tracing::trace_span!( target: "executor::task", - parent: Span::current(), "runtime.spawn", loc.file = location.file(), loc.line = location.line(), @@ -138,7 +128,6 @@ impl<'a, 'executor: 'a> Executor<'executor> { let location = std::panic::Location::caller(); let span = tracing::trace_span!( target: "executor::task", - parent: Span::current(), "runtime.spawn", loc.file = location.file(), loc.line = location.line(), diff --git a/runtime/lightproc/src/proc_handle.rs b/runtime/lightproc/src/proc_handle.rs index 2dd7666..7a399d6 100644 --- a/runtime/lightproc/src/proc_handle.rs +++ b/runtime/lightproc/src/proc_handle.rs @@ -191,6 +191,14 @@ impl Drop for ProcHandle { let mut output = None; unsafe { + // Record dropping the handle for this task + let id = (&(*pdata).span).id().map(|id| id.into_u64()).unwrap_or(0); + tracing::trace!( + target: "executor::handle", + op = "handle.drop", + task.id = id, + ); + // Optimistically assume the `ProcHandle` is being dropped just after creating the // proc. This is a common case so if the handle is not used, the overhead of it is only // one compare-exchange operation. From ff727b6d972fcd567ab74313f3b0262adf7fac93 Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Thu, 23 Jun 2022 16:00:21 +0200 Subject: [PATCH 12/17] Noting down improvement ideas for procs --- runtime/lightproc/src/lightproc.rs | 4 ++-- runtime/lightproc/src/proc_handle.rs | 12 ++++++++++-- runtime/lightproc/src/raw_proc.rs | 12 ++++++++---- 3 files changed, 20 insertions(+), 8 deletions(-) diff --git a/runtime/lightproc/src/lightproc.rs b/runtime/lightproc/src/lightproc.rs index 0900f56..b527c54 100644 --- a/runtime/lightproc/src/lightproc.rs +++ b/runtime/lightproc/src/lightproc.rs @@ -46,8 +46,8 @@ pub struct LightProc { // LightProc is both Sync and Send because it explicitly handles synchronization internally: // The state of a `LightProc` is only modified atomically guaranteeing a consistent view from all -// threads. Existing handles are atomically reference counted so the proc itself will not be dropped -// until all pointers to it are themselves dropped. +// threads. Existing wakers (and the proc_handle) are atomically reference counted so the proc +// itself will not be dropped until all pointers to it are themselves dropped. // However, if the future or result inside the LightProc is !Send the executor must ensure that // the `schedule` function does not move the LightProc to a different thread. unsafe impl Send for LightProc {} diff --git a/runtime/lightproc/src/proc_handle.rs b/runtime/lightproc/src/proc_handle.rs index 7a399d6..124c5ca 100644 --- a/runtime/lightproc/src/proc_handle.rs +++ b/runtime/lightproc/src/proc_handle.rs @@ -6,6 +6,7 @@ use crate::state::*; use std::fmt::{self, Debug, Formatter}; use std::future::Future; use std::marker::{PhantomData, Unpin}; +use std::mem::MaybeUninit; use std::pin::Pin; use std::ptr::NonNull; use std::sync::atomic::Ordering; @@ -24,7 +25,7 @@ pub struct ProcHandle { /// A marker capturing the generic type `R`. // TODO: Instead of writing the future output to the RawProc on heap, put it in the handle // (if still available). - pub(crate) result: PhantomData, + pub(crate) result: MaybeUninit, } unsafe impl Send for ProcHandle {} @@ -36,7 +37,7 @@ impl ProcHandle { pub(crate) fn new(raw_proc: NonNull<()>) -> Self { Self { raw_proc, - result: PhantomData, + result: MaybeUninit::uninit(), } } @@ -50,6 +51,13 @@ impl ProcHandle { let pdata = ptr as *const ProcData; unsafe { + let id = (&(*pdata).span).id().map(|id| id.into_u64()).unwrap_or(0); + tracing::trace!( + target: "executor::handle", + op = "handle.cancel", + task.id = id, + ); + let mut state = (*pdata).state.load(Ordering::Acquire); loop { diff --git a/runtime/lightproc/src/raw_proc.rs b/runtime/lightproc/src/raw_proc.rs index b23d4f4..4cb7041 100644 --- a/runtime/lightproc/src/raw_proc.rs +++ b/runtime/lightproc/src/raw_proc.rs @@ -20,6 +20,7 @@ use tracing::Span; /// Raw pointers to the fields of a proc. // TODO: Make generic over the Allocator used! +// TODO: The actual layout stored could be expressed as a struct w/ union. Maybe do that? pub(crate) struct RawProc<'a, F, R, S> { pub(crate) pdata: *const ProcData, pub(crate) schedule: *const S, @@ -30,10 +31,13 @@ pub(crate) struct RawProc<'a, F, R, S> { // Make the lifetime 'a of the future invariant _marker: PhantomData<&'a ()>, - // TODO: We should link a proc to a process bucket for scheduling and tracing - // => nope, do that via scheduling func - // TODO: A proc should be able to be assigned a name for tracing and reporting - // This could also be implemented via storing a Span similar to `Instrumented` + // TODO: We should link a proc to a process group for scheduling and tracing + // - sub-tasks should start in the same group by default + // - that data needs to be available when calling `spawn` and to decide which task to run. + // So there must be a thread-local reference to it that's managed by the executor, and + // updated when a new task is being polled. + // Additionally `schedule` must have a reference to it to be able to push to the right + // queue? The `schedule` fn could just come from the group instead. } impl<'a, F, R, S> RawProc<'a, F, R, S> From 7e113bab474842d09e85b9b0043e60e4991acdc0 Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Thu, 23 Jun 2022 17:28:13 +0200 Subject: [PATCH 13/17] Attach a GroupID to all LightProcs --- runtime/executor/src/pool.rs | 7 +++++-- runtime/lightproc/src/lib.rs | 2 ++ runtime/lightproc/src/lightproc.rs | 13 ++++++++++--- runtime/lightproc/src/proc_data.rs | 11 +++++++++++ runtime/lightproc/src/raw_proc.rs | 16 ++++++++++++---- 5 files changed, 40 insertions(+), 9 deletions(-) diff --git a/runtime/executor/src/pool.rs b/runtime/executor/src/pool.rs index 4f288d6..e5038ba 100644 --- a/runtime/executor/src/pool.rs +++ b/runtime/executor/src/pool.rs @@ -13,6 +13,7 @@ use crate::worker::{Sleeper, WorkerThread}; use crossbeam_deque::{Injector, Stealer}; use lightproc::lightproc::LightProc; use lightproc::recoverable_handle::RecoverableHandle; +use lightproc::GroupId; use std::cell::Cell; use std::future::Future; use std::iter::Iterator; @@ -112,8 +113,9 @@ impl<'a, 'executor: 'a> Executor<'executor> { loc.col = location.column(), kind = "global", ); + let cgroup = None; - let (task, handle) = LightProc::recoverable(future, self.schedule(), span); + let (task, handle) = LightProc::recoverable(future, self.schedule(), span, cgroup); tracing::trace!("spawning sendable task"); task.schedule(); handle @@ -134,8 +136,9 @@ impl<'a, 'executor: 'a> Executor<'executor> { loc.col = location.column(), kind = "local", ); + let cgroup = None; - let (task, handle) = LightProc::recoverable(future, schedule_local(), span); + let (task, handle) = LightProc::recoverable(future, schedule_local(), span, cgroup); tracing::trace!("spawning sendable task"); task.schedule(); handle diff --git a/runtime/lightproc/src/lib.rs b/runtime/lightproc/src/lib.rs index 2bcf9db..075e0f4 100644 --- a/runtime/lightproc/src/lib.rs +++ b/runtime/lightproc/src/lib.rs @@ -33,6 +33,8 @@ pub mod lightproc; pub mod proc_handle; pub mod recoverable_handle; +pub use proc_data::GroupId; + /// The lightproc prelude. /// /// The prelude re-exports lightproc structs and handles from this crate. diff --git a/runtime/lightproc/src/lightproc.rs b/runtime/lightproc/src/lightproc.rs index b527c54..c8e2f6c 100644 --- a/runtime/lightproc/src/lightproc.rs +++ b/runtime/lightproc/src/lightproc.rs @@ -31,6 +31,7 @@ use crate::proc_ext::ProcFutureExt; use crate::proc_handle::ProcHandle; use crate::raw_proc::RawProc; use crate::recoverable_handle::RecoverableHandle; +use crate::GroupId; use std::fmt::{self, Debug, Formatter}; use std::future::Future; use std::mem::ManuallyDrop; @@ -81,6 +82,7 @@ impl LightProc { future: F, schedule: S, span: Span, + cgroup: Option, ) -> (Self, RecoverableHandle) where F: Future + 'a, @@ -88,7 +90,7 @@ impl LightProc { S: Fn(LightProc) + 'a, { let recovery_future = AssertUnwindSafe(future).catch_unwind(); - let (proc, handle) = Self::build(recovery_future, schedule, span); + let (proc, handle) = Self::build(recovery_future, schedule, span, cgroup); (proc, RecoverableHandle::new(handle)) } @@ -122,13 +124,18 @@ impl LightProc { /// Span::current(), /// ); /// ``` - pub fn build<'a, F, R, S>(future: F, schedule: S, span: Span) -> (Self, ProcHandle) + pub fn build<'a, F, R, S>( + future: F, + schedule: S, + span: Span, + cgroup: Option, + ) -> (Self, ProcHandle) where F: Future + 'a, R: 'a, S: Fn(LightProc) + 'a, { - let raw_proc = RawProc::allocate(future, schedule, span); + let raw_proc = RawProc::allocate(future, schedule, span, cgroup); let proc = LightProc { raw_proc }; let handle = ProcHandle::new(raw_proc); (proc, handle) diff --git a/runtime/lightproc/src/proc_data.rs b/runtime/lightproc/src/proc_data.rs index 8c215a5..9412459 100644 --- a/runtime/lightproc/src/proc_data.rs +++ b/runtime/lightproc/src/proc_data.rs @@ -3,10 +3,16 @@ use crate::state::*; use crossbeam_utils::Backoff; use std::cell::Cell; use std::fmt::{self, Debug, Formatter}; +use std::num::NonZeroU64; use std::sync::atomic::Ordering; use std::task::Waker; use tracing::Span; +#[derive(Clone, Debug, Eq, PartialEq, Hash)] +#[repr(transparent)] +/// Opaque id of the group this proc belongs to +pub struct GroupId(NonZeroU64); + /// The pdata of a proc. /// /// This pdata is stored right at the beginning of every heap-allocated proc. @@ -32,6 +38,11 @@ pub(crate) struct ProcData { /// A lightproc has a tracing span associated that allow recording occurances of vtable calls /// for this process. pub(crate) span: Span, + + /// Control group assigned to this process. + /// + /// The control group links this process to its supervision tree + pub(crate) cgroup: Option, } impl ProcData { diff --git a/runtime/lightproc/src/raw_proc.rs b/runtime/lightproc/src/raw_proc.rs index 4cb7041..1481fb0 100644 --- a/runtime/lightproc/src/raw_proc.rs +++ b/runtime/lightproc/src/raw_proc.rs @@ -15,6 +15,7 @@ use std::pin::Pin; use std::ptr::NonNull; use std::sync::atomic::Ordering; +use crate::GroupId; use std::task::{Context, Poll, RawWaker, RawWakerVTable, Waker}; use tracing::Span; @@ -49,7 +50,12 @@ where /// Allocates a proc with the given `future` and `schedule` function. /// /// It is assumed there are initially only the `LightProc` reference and the `ProcHandle`. - pub(crate) fn allocate(future: F, schedule: S, span: Span) -> NonNull<()> { + pub(crate) fn allocate( + future: F, + schedule: S, + span: Span, + cgroup: Option, + ) -> NonNull<()> { // Compute the layout of the proc for allocation. Abort if the computation fails. let proc_layout = Self::proc_layout(); @@ -83,6 +89,7 @@ where tick: Self::tick, }, span, + cgroup, }); // Write the schedule function as the third field of the proc. @@ -360,10 +367,11 @@ where raw.output as *const () } - /// Cleans up proc's resources and deallocates it. + /// Cleans up the procs resources and deallocates the associated memory. /// - /// If the proc has not been closed, then its future or the output will be dropped. The - /// schedule function gets dropped too. + /// The future or output stored will *not* be dropped, but its memory will be freed. Callers + /// must ensure that they are correctly dropped beforehand if either of those is still alive to + /// prevent use-after-free. #[inline] unsafe fn destroy(ptr: *const ()) { let raw = Self::from_ptr(ptr); From 3075e1c0274a065c363a2a66650a207fa9efd7bb Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Thu, 23 Jun 2022 17:28:41 +0200 Subject: [PATCH 14/17] Get started on supervision trees --- Cargo.lock | 1 - runtime/executor/Cargo.toml | 1 - runtime/executor/src/lib.rs | 1 + runtime/executor/src/supervision.rs | 3 +++ 4 files changed, 4 insertions(+), 2 deletions(-) create mode 100644 runtime/executor/src/supervision.rs diff --git a/Cargo.lock b/Cargo.lock index 6932cc5..6def150 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1128,7 +1128,6 @@ dependencies = [ "parking_lot", "pin-utils", "rand", - "slab", "tracing", "tracing-subscriber", ] diff --git a/runtime/executor/Cargo.toml b/runtime/executor/Cargo.toml index 85c6df6..be7e348 100644 --- a/runtime/executor/Cargo.toml +++ b/runtime/executor/Cargo.toml @@ -39,7 +39,6 @@ lazy_static = "1.4" libc = "0.2" num_cpus = "1.13" pin-utils = "0.1.0" -slab = "0.4" parking_lot = "0.12" # Allocator diff --git a/runtime/executor/src/lib.rs b/runtime/executor/src/lib.rs index c3d71fa..96024ea 100644 --- a/runtime/executor/src/lib.rs +++ b/runtime/executor/src/lib.rs @@ -32,6 +32,7 @@ pub mod manage; pub mod placement; pub mod pool; pub mod run; +mod supervision; mod thread_manager; mod worker; diff --git a/runtime/executor/src/supervision.rs b/runtime/executor/src/supervision.rs new file mode 100644 index 0000000..9694c84 --- /dev/null +++ b/runtime/executor/src/supervision.rs @@ -0,0 +1,3 @@ +pub(crate) struct SupervisionRegistry {} + +impl SupervisionRegistry {} From e7358838d547fd647938353222b89dfc1181c57b Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Thu, 23 Jun 2022 17:31:57 +0200 Subject: [PATCH 15/17] Oh whoops handle that --- bffhd/audit.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/bffhd/audit.rs b/bffhd/audit.rs index e30fe3d..35f0340 100644 --- a/bffhd/audit.rs +++ b/bffhd/audit.rs @@ -51,7 +51,7 @@ impl AuditLog { let mut ser = Serializer::new(&mut writer); line.serialize(&mut ser) .expect("failed to serialize audit log line"); - writer.write("\n".as_bytes())?; + writer.write_all("\n".as_bytes())?; Ok(()) } } From 77e093594536e9b84a9538fed024d794d4b84bda Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Thu, 23 Jun 2022 21:19:31 +0200 Subject: [PATCH 16/17] Allow tracking cgroups with futures --- Cargo.lock | 2 + bffhd/capnp/mod.rs | 5 +- runtime/executor/Cargo.toml | 4 + runtime/executor/src/lib.rs | 2 + runtime/executor/src/pool.rs | 39 +++++- runtime/executor/src/supervision.rs | 180 +++++++++++++++++++++++++++- runtime/lightproc/src/lightproc.rs | 1 + runtime/lightproc/src/proc_data.rs | 34 ++++++ 8 files changed, 261 insertions(+), 6 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 6def150..f01992f 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1128,6 +1128,8 @@ dependencies = [ "parking_lot", "pin-utils", "rand", + "sharded-slab", + "thread_local", "tracing", "tracing-subscriber", ] diff --git a/bffhd/capnp/mod.rs b/bffhd/capnp/mod.rs index d19ac28..42ba89f 100644 --- a/bffhd/capnp/mod.rs +++ b/bffhd/capnp/mod.rs @@ -3,7 +3,7 @@ use async_net::TcpListener; use capnp_rpc::rpc_twoparty_capnp::Side; use capnp_rpc::twoparty::VatNetwork; use capnp_rpc::RpcSystem; -use executor::prelude::Executor; +use executor::prelude::{Executor, GroupId, SupervisionRegistry}; use futures_rustls::server::TlsStream; use futures_rustls::TlsAcceptor; use futures_util::stream::FuturesUnordered; @@ -167,6 +167,7 @@ impl APIServer { tracing::error!("Error during RPC handling: {}", e); } }; - self.executor.spawn_local(f); + let cgroup = SupervisionRegistry::with(SupervisionRegistry::new_group); + self.executor.spawn_local_cgroup(f, cgroup); } } diff --git a/runtime/executor/Cargo.toml b/runtime/executor/Cargo.toml index be7e348..b11121f 100644 --- a/runtime/executor/Cargo.toml +++ b/runtime/executor/Cargo.toml @@ -51,6 +51,10 @@ hdrhistogram = "7.5" # Stats & Tracing tracing = "0.1" +# Supervision trees +sharded-slab = "0.1" +thread_local = "1.1" + [dev-dependencies] async-std = "1.10.0" tracing = { version = "0.1.19", features = ["max_level_trace"]} diff --git a/runtime/executor/src/lib.rs b/runtime/executor/src/lib.rs index 96024ea..60fa1f9 100644 --- a/runtime/executor/src/lib.rs +++ b/runtime/executor/src/lib.rs @@ -40,4 +40,6 @@ mod worker; /// Prelude of Bastion Executor pub mod prelude { pub use crate::pool::*; + pub use crate::supervision::SupervisionRegistry; + pub use lightproc::GroupId; } diff --git a/runtime/executor/src/pool.rs b/runtime/executor/src/pool.rs index e5038ba..9686706 100644 --- a/runtime/executor/src/pool.rs +++ b/runtime/executor/src/pool.rs @@ -8,6 +8,7 @@ //! [`Worker`]: crate::run_queue::Worker use crate::run::block; +use crate::supervision::SupervisionRegistry; use crate::thread_manager::{DynamicRunner, ThreadManager}; use crate::worker::{Sleeper, WorkerThread}; use crossbeam_deque::{Injector, Stealer}; @@ -49,12 +50,19 @@ impl Spooler<'_> { /// Global executor pub struct Executor<'a> { spooler: Arc>, + root_cgroup: GroupId, } impl<'a, 'executor: 'a> Executor<'executor> { pub fn new() -> Self { + let root_cgroup = SupervisionRegistry::with(|registry| { + let cgroup = registry.new_root_group(); + registry.set_current(&cgroup); + cgroup + }); Executor { spooler: Arc::new(Spooler::new()), + root_cgroup, } } @@ -105,6 +113,8 @@ impl<'a, 'executor: 'a> Executor<'executor> { R: Send + 'a, { let location = std::panic::Location::caller(); + let cgroup = SupervisionRegistry::current(); + let id = cgroup.as_ref().map(|id| id.into_u64()).unwrap_or(0); let span = tracing::trace_span!( target: "executor::task", "runtime.spawn", @@ -112,8 +122,8 @@ impl<'a, 'executor: 'a> Executor<'executor> { loc.line = location.line(), loc.col = location.column(), kind = "global", + cgroup = id, ); - let cgroup = None; let (task, handle) = LightProc::recoverable(future, self.schedule(), span, cgroup); tracing::trace!("spawning sendable task"); @@ -128,6 +138,8 @@ impl<'a, 'executor: 'a> Executor<'executor> { R: Send + 'a, { let location = std::panic::Location::caller(); + let cgroup = SupervisionRegistry::current(); + let id = cgroup.as_ref().map(|id| id.into_u64()).unwrap_or(0); let span = tracing::trace_span!( target: "executor::task", "runtime.spawn", @@ -135,8 +147,8 @@ impl<'a, 'executor: 'a> Executor<'executor> { loc.line = location.line(), loc.col = location.column(), kind = "local", + cgroup = id, ); - let cgroup = None; let (task, handle) = LightProc::recoverable(future, schedule_local(), span, cgroup); tracing::trace!("spawning sendable task"); @@ -144,6 +156,29 @@ impl<'a, 'executor: 'a> Executor<'executor> { handle } + #[track_caller] + pub fn spawn_local_cgroup(&self, future: F, cgroup: GroupId) -> RecoverableHandle + where + F: Future + 'a, + R: Send + 'a, + { + let location = std::panic::Location::caller(); + let span = tracing::trace_span!( + target: "executor::task", + "runtime.spawn", + loc.file = location.file(), + loc.line = location.line(), + loc.col = location.column(), + kind = "local", + cgroup = cgroup.into_u64(), + ); + + let (task, handle) = LightProc::recoverable(future, schedule_local(), span, Some(cgroup)); + tracing::trace!("spawning sendable task"); + task.schedule(); + handle + } + /// Block the calling thread until the given future completes. /// /// # Example diff --git a/runtime/executor/src/supervision.rs b/runtime/executor/src/supervision.rs index 9694c84..a11cfe0 100644 --- a/runtime/executor/src/supervision.rs +++ b/runtime/executor/src/supervision.rs @@ -1,3 +1,179 @@ -pub(crate) struct SupervisionRegistry {} +use lightproc::GroupId; +use once_cell::sync::OnceCell; +use sharded_slab::pool::Ref; +use sharded_slab::{Clear, Pool}; +use std::borrow::Borrow; +use std::cell; +use std::cell::RefCell; +use std::sync::atomic::{fence, AtomicUsize, Ordering}; +use thread_local::ThreadLocal; -impl SupervisionRegistry {} +static REGISTRY: OnceCell = OnceCell::new(); + +fn id_to_idx(id: &GroupId) -> usize { + (id.into_u64() as usize).wrapping_sub(1) +} + +fn idx_to_id(idx: usize) -> GroupId { + GroupId::from_u64(idx.wrapping_add(1) as u64) +} + +pub struct SupervisionRegistry { + groups: Pool, + // TODO: would this be better as the full stack? + current: ThreadLocal>, +} + +impl SupervisionRegistry { + fn new() -> Self { + Self { + groups: Pool::new(), + current: ThreadLocal::new(), + } + } + + pub fn with(f: impl FnOnce(&Self) -> T) -> T { + let this = REGISTRY.get_or_init(SupervisionRegistry::new); + f(&this) + } + + pub(crate) fn get(&self, id: &GroupId) -> Option> { + self.groups.get(id_to_idx(id)) + } + + #[inline] + pub fn current_ref(&self) -> Option> { + self.current.get().map(|c| c.borrow()) + } + + pub fn current() -> Option { + Self::with(|this| this.current_ref().map(|id| this.clone_group(&id))) + } + + pub(crate) fn set_current(&self, id: &GroupId) { + self.current.get_or(|| RefCell::new(id.clone())); + } + + pub fn new_root_group(&self) -> GroupId { + self.new_group_inner(None) + } + + pub fn new_group(&self) -> GroupId { + let parent = self.current_ref().map(|id| self.clone_group(&id)); + self.new_group_inner(parent) + } + + fn new_group_inner(&self, parent: Option) -> GroupId { + tracing::trace_span!( + target: "executor::supervision", + "new_group" + ); + let parent_id = parent.as_ref().map(|id| id.into_non_zero_u64()); + let idx = self + .groups + .create_with(|group| { + group.parent = parent; + + let ref_cnt = group.ref_count.get_mut(); + debug_assert_eq!(0, *ref_cnt); + *ref_cnt = 1; + }) + .expect("Failed to allocate a new group"); + + let id = idx_to_id(idx); + tracing::trace!( + target: "executor::supervision", + parent = parent_id, + id = id.into_non_zero_u64(), + "process group created" + ); + + id + } + + fn clone_group(&self, id: &GroupId) -> GroupId { + tracing::trace!( + target: "executor::supervision", + id = id.into_u64(), + "cloning process group" + ); + let group = self + .get(&id) + .unwrap_or_else(|| panic!("tried to clone group {:?}, but no such group exists!", id)); + + let ref_cnt = group.ref_count.fetch_add(1, Ordering::Relaxed); + assert_ne!( + 0, ref_cnt, + "tried cloning group {:?} that was already closed", + id + ); + id.clone() + } + + /// Try to close the group with the given ID + /// + /// If this method returns `true` the Group was closed. Otherwise there are still references + /// left open. + fn try_close(&self, id: GroupId) -> bool { + tracing::trace!( + target: "executor::supervision", + id = id.into_u64(), + "dropping process group" + ); + let group = match self.get(&id) { + None if std::thread::panicking() => return false, + None => panic!("tried to drop a ref to {:?}, but no such group exists!", id), + Some(group) => group, + }; + + // Reference count *decreases* on the other hand must observe strong ordering — when + let remaining = group.ref_count.fetch_sub(1, Ordering::Release); + if !std::thread::panicking() { + assert!(remaining < usize::MAX, "group reference count overflow"); + } + if remaining > 1 { + return false; + } + + // Generate a compiler fence making sure that all other calls to `try_close` are finished + // before the one that returns `true`. + fence(Ordering::Acquire); + true + } +} + +#[derive(Debug)] +pub(crate) struct GroupInner { + parent: Option, + ref_count: AtomicUsize, +} + +impl GroupInner { + #[inline] + /// Increment the reference count of this group and return the previous value + fn increment_refcnt(&self) -> usize { + // Reference count increases don't need strong ordering. The increments can be done in + // any order as long as they *do* happen. + self.ref_count.fetch_add(1, Ordering::Relaxed) + } +} + +impl Default for GroupInner { + fn default() -> Self { + Self { + parent: None, + ref_count: AtomicUsize::new(0), + } + } +} + +impl Clear for GroupInner { + fn clear(&mut self) { + // A group is always alive as long as at least one of its children is alive. So each + // Group holds a reference to its parent if it has one. If a group is being deleted this + // reference must be closed too, i.e. the parent reference count reduced by one. + if let Some(parent) = self.parent.take() { + SupervisionRegistry::with(|reg| reg.try_close(parent)); + } + } +} diff --git a/runtime/lightproc/src/lightproc.rs b/runtime/lightproc/src/lightproc.rs index c8e2f6c..63af3cd 100644 --- a/runtime/lightproc/src/lightproc.rs +++ b/runtime/lightproc/src/lightproc.rs @@ -122,6 +122,7 @@ impl LightProc { /// future, /// schedule_function, /// Span::current(), + /// None, /// ); /// ``` pub fn build<'a, F, R, S>( diff --git a/runtime/lightproc/src/proc_data.rs b/runtime/lightproc/src/proc_data.rs index 9412459..138fc2c 100644 --- a/runtime/lightproc/src/proc_data.rs +++ b/runtime/lightproc/src/proc_data.rs @@ -13,6 +13,40 @@ use tracing::Span; /// Opaque id of the group this proc belongs to pub struct GroupId(NonZeroU64); +impl GroupId { + /// Construct an ID from an u64 + /// + /// # Panics + /// - if the provided `u64` is `0`. + pub fn from_u64(i: u64) -> Self { + Self(NonZeroU64::new(i).expect("group id must be > 0")) + } + + #[inline] + /// Construct an ID from a NonZeroU64 + /// + /// This method can't fail + pub const fn from_non_zero_u64(i: NonZeroU64) -> Self { + Self(i) + } + + #[allow(clippy::wrong_self_convention)] + //noinspection RsSelfConvention + #[inline] + /// Convert a GroupId into a u64 + pub const fn into_u64(&self) -> u64 { + self.0.get() + } + + #[allow(clippy::wrong_self_convention)] + //noinspection RsSelfConvention + #[inline] + /// Convert a GroupId into a NonZeroU64 + pub const fn into_non_zero_u64(&self) -> NonZeroU64 { + self.0 + } +} + /// The pdata of a proc. /// /// This pdata is stored right at the beginning of every heap-allocated proc. From 57fb279092fe6b6eee89952be8398e594f8752a4 Mon Sep 17 00:00:00 2001 From: Nadja Reitzenstein Date: Fri, 24 Jun 2022 12:24:29 +0200 Subject: [PATCH 17/17] Runtime things furthermore --- runtime/lightproc/src/proc_data.rs | 2 +- runtime/lightproc/src/proc_handle.rs | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/runtime/lightproc/src/proc_data.rs b/runtime/lightproc/src/proc_data.rs index 138fc2c..d6d0e9c 100644 --- a/runtime/lightproc/src/proc_data.rs +++ b/runtime/lightproc/src/proc_data.rs @@ -113,7 +113,7 @@ impl ProcData { } } - /// Notifies the proc blocked on the proc. + /// Notifies the proc blocked on this proc, if any. /// /// If there is a registered waker, it will be removed from the pdata and woken. #[inline] diff --git a/runtime/lightproc/src/proc_handle.rs b/runtime/lightproc/src/proc_handle.rs index 124c5ca..f04fef0 100644 --- a/runtime/lightproc/src/proc_handle.rs +++ b/runtime/lightproc/src/proc_handle.rs @@ -25,7 +25,7 @@ pub struct ProcHandle { /// A marker capturing the generic type `R`. // TODO: Instead of writing the future output to the RawProc on heap, put it in the handle // (if still available). - pub(crate) result: MaybeUninit, + pub(crate) marker: PhantomData, } unsafe impl Send for ProcHandle {} @@ -37,7 +37,7 @@ impl ProcHandle { pub(crate) fn new(raw_proc: NonNull<()>) -> Self { Self { raw_proc, - result: MaybeUninit::uninit(), + marker: PhantomData, } }