Improvement: better concurrency support of interleaved futures

Cargo.toml

@@ -10,11 +10,18 @@ readme = "README.md"
 
 [dependencies]
 tracing-core = "0.1"
-tracing-subscriber = { version = "0.3", default-features = false, features = ["registry", "fmt", "std"] }
+tracing-subscriber = { version = "0.3", default-features = false, features = [
+    "registry",
+    "fmt",
+    "std",
+] }
 nu-ansi-term = "0.46.0"
 is-terminal = "0.4.7"
 tracing-log = { version = "0.1", optional = true }
-time = { version = "0.3.20", optional = true, features = ["formatting", "local-offset"] }
+time = { version = "0.3.20", optional = true, features = [
+    "formatting",
+    "local-offset",
+] }
 
 [features]
 default = ["tracing-log"]
@@ -23,6 +30,7 @@ default = ["tracing-log"]
 tracing = "0.1"
 glob = "0.3"
 ui_test = "0.7"
+futures = "0.3"
 log = "0.4"
 
 [[test]]

examples/basic_non_verbose.rs

@@ -0,0 +1,81 @@
+use tracing::{debug, error, info, instrument, span, warn, Level};
+use tracing_subscriber::{layer::SubscriberExt, registry::Registry};
+use tracing_tree::HierarchicalLayer;
+
+fn main() {
+    let layer = HierarchicalLayer::default()
+        .with_writer(std::io::stdout)
+        .with_indent_lines(true)
+        .with_indent_amount(2)
+        .with_thread_names(true)
+        .with_thread_ids(true)
+        .with_targets(true);
+
+    let subscriber = Registry::default().with(layer);
+    tracing::subscriber::set_global_default(subscriber).unwrap();
+    #[cfg(feature = "tracing-log")]
+    tracing_log::LogTracer::init().unwrap();
+
+    let app_span = span!(Level::TRACE, "hierarchical-example", version = %0.1);
+    let _e = app_span.enter();
+
+    let server_span = span!(Level::TRACE, "server", host = "localhost", port = 8080);
+    let _e2 = server_span.enter();
+    info!("starting");
+    std::thread::sleep(std::time::Duration::from_millis(3000));
+    info!("listening");
+    let peer1 = span!(Level::TRACE, "conn", peer_addr = "82.9.9.9", port = 42381);
+    peer1.in_scope(|| {
+        debug!("connected");
+        std::thread::sleep(std::time::Duration::from_millis(300));
+        debug!(length = 2, "message received");
+    });
+    drop(peer1);
+    let peer2 = span!(Level::TRACE, "conn", peer_addr = "8.8.8.8", port = 18230);
+    peer2.in_scope(|| {
+        std::thread::sleep(std::time::Duration::from_millis(300));
+        debug!("connected");
+    });
+    drop(peer2);
+    let peer3 = span!(
+        Level::TRACE,
+        "foomp",
+        normal_var = 43,
+        "{} <- format string",
+        42
+    );
+    peer3.in_scope(|| {
+        error!("hello");
+    });
+    drop(peer3);
+    let peer1 = span!(Level::TRACE, "conn", peer_addr = "82.9.9.9", port = 42381);
+    peer1.in_scope(|| {
+        warn!(algo = "xor", "weak encryption requested");
+        std::thread::sleep(std::time::Duration::from_millis(300));
+        debug!(length = 8, "response sent");
+        debug!("disconnected");
+    });
+    drop(peer1);
+    let peer2 = span!(Level::TRACE, "conn", peer_addr = "8.8.8.8", port = 18230);
+    peer2.in_scope(|| {
+        debug!(length = 5, "message received");
+        std::thread::sleep(std::time::Duration::from_millis(300));
+        debug!(length = 8, "response sent");
+        debug!("disconnected");
+    });
+    drop(peer2);
+    warn!("internal error");
+    log::error!("this is a log message");
+    info!("exit");
+}
+
+#[instrument]
+fn call_a(name: &str) {
+    info!(name, "got a name");
+    call_b(name)
+}
+
+#[instrument]
+fn call_b(name: &str) {
+    info!(name, "got a name");
+}

examples/basic_non_verbose.stdout

@@ -0,0 +1,29 @@
+1:main┐basic_non_verbose::hierarchical-example version=0.1
+1:main├─┐basic_non_verbose::server host="localhost", port=8080
+1:main│ ├─  Xms INFO basic_non_verbose starting
+1:main│ ├─  Xs  INFO basic_non_verbose listening
+1:main│ ├─┐basic_non_verbose::conn peer_addr="82.9.9.9", port=42381
+1:main│ │ ├─  Xms DEBUG basic_non_verbose connected
+1:main│ │ ├─  Xms DEBUG basic_non_verbose message received, length=2
+1:main│ ├─┘
+1:main│ ├─┐basic_non_verbose::conn peer_addr="8.8.8.8", port=18230
+1:main│ │ ├─  Xms DEBUG basic_non_verbose connected
+1:main│ ├─┘
+1:main│ ├─┐basic_non_verbose::foomp 42 <- format string, normal_var=43
+1:main│ │ ├─  Xms ERROR basic_non_verbose hello
+1:main│ ├─┘
+1:main│ ├─┐basic_non_verbose::conn peer_addr="82.9.9.9", port=42381
+1:main│ │ ├─  Xms WARN basic_non_verbose weak encryption requested, algo="xor"
+1:main│ │ ├─  Xms DEBUG basic_non_verbose response sent, length=8
+1:main│ │ ├─  Xms DEBUG basic_non_verbose disconnected
+1:main│ ├─┘
+1:main│ ├─┐basic_non_verbose::conn peer_addr="8.8.8.8", port=18230
+1:main│ │ ├─  Xms DEBUG basic_non_verbose message received, length=5
+1:main│ │ ├─  Xms DEBUG basic_non_verbose response sent, length=8
+1:main│ │ ├─  Xms DEBUG basic_non_verbose disconnected
+1:main│ ├─┘
+1:main│ ├─  Xs  WARN basic_non_verbose internal error
+1:main│ ├─  Xs  ERROR basic_non_verbose this is a log message
+1:main│ ├─  Xs  INFO basic_non_verbose exit
+1:main├─┘
+1:main┘

examples/basic_verbose_entry.rs

@@ -0,0 +1,83 @@
+use tracing::{debug, error, info, instrument, span, warn, Level};
+use tracing_subscriber::{layer::SubscriberExt, registry::Registry};
+use tracing_tree::HierarchicalLayer;
+
+fn main() {
+    let layer = HierarchicalLayer::default()
+        .with_writer(std::io::stdout)
+        .with_indent_lines(true)
+        .with_indent_amount(2)
+        .with_thread_names(true)
+        .with_thread_ids(true)
+        .with_verbose_exit(false)
+        .with_verbose_entry(true)
+        .with_targets(true);
+
+    let subscriber = Registry::default().with(layer);
+    tracing::subscriber::set_global_default(subscriber).unwrap();
+    #[cfg(feature = "tracing-log")]
+    tracing_log::LogTracer::init().unwrap();
+
+    let app_span = span!(Level::TRACE, "hierarchical-example", version = %0.1);
+    let _e = app_span.enter();
+
+    let server_span = span!(Level::TRACE, "server", host = "localhost", port = 8080);
+    let _e2 = server_span.enter();
+    info!("starting");
+    std::thread::sleep(std::time::Duration::from_millis(3000));
+    info!("listening");
+    let peer1 = span!(Level::TRACE, "conn", peer_addr = "82.9.9.9", port = 42381);
+    peer1.in_scope(|| {
+        debug!("connected");
+        std::thread::sleep(std::time::Duration::from_millis(300));
+        debug!(length = 2, "message received");
+    });
+    drop(peer1);
+    let peer2 = span!(Level::TRACE, "conn", peer_addr = "8.8.8.8", port = 18230);
+    peer2.in_scope(|| {
+        std::thread::sleep(std::time::Duration::from_millis(300));
+        debug!("connected");
+    });
+    drop(peer2);
+    let peer3 = span!(
+        Level::TRACE,
+        "foomp",
+        normal_var = 43,
+        "{} <- format string",
+        42
+    );
+    peer3.in_scope(|| {
+        error!("hello");
+    });
+    drop(peer3);
+    let peer1 = span!(Level::TRACE, "conn", peer_addr = "82.9.9.9", port = 42381);
+    peer1.in_scope(|| {
+        warn!(algo = "xor", "weak encryption requested");
+        std::thread::sleep(std::time::Duration::from_millis(300));
+        debug!(length = 8, "response sent");
+        debug!("disconnected");
+    });
+    drop(peer1);
+    let peer2 = span!(Level::TRACE, "conn", peer_addr = "8.8.8.8", port = 18230);
+    peer2.in_scope(|| {
+        debug!(length = 5, "message received");
+        std::thread::sleep(std::time::Duration::from_millis(300));
+        debug!(length = 8, "response sent");
+        debug!("disconnected");
+    });
+    drop(peer2);
+    warn!("internal error");
+    log::error!("this is a log message");
+    info!("exit");
+}
+
+#[instrument]
+fn call_a(name: &str) {
+    info!(name, "got a name");
+    call_b(name)
+}
+
+#[instrument]
+fn call_b(name: &str) {
+    info!(name, "got a name");
+}

examples/basic_verbose_entry.stdout

@@ -0,0 +1,35 @@
+1:main┐basic_verbose_entry::hierarchical-example version=0.1
+1:main├┐basic_verbose_entry::hierarchical-example version=0.1
+1:main│└┐basic_verbose_entry::server host="localhost", port=8080
+1:main│ ├─  Xms INFO basic_verbose_entry starting
+1:main│ ├─  Xs  INFO basic_verbose_entry listening
+1:main│ ├┐basic_verbose_entry::server host="localhost", port=8080
+1:main│ │└┐basic_verbose_entry::conn peer_addr="82.9.9.9", port=42381
+1:main│ │ ├─  Xms DEBUG basic_verbose_entry connected
+1:main│ │ ├─  Xms DEBUG basic_verbose_entry message received, length=2
+1:main│ ├─┘
+1:main│ ├┐basic_verbose_entry::server host="localhost", port=8080
+1:main│ │└┐basic_verbose_entry::conn peer_addr="8.8.8.8", port=18230
+1:main│ │ ├─  Xms DEBUG basic_verbose_entry connected
+1:main│ ├─┘
+1:main│ ├┐basic_verbose_entry::server host="localhost", port=8080
+1:main│ │└┐basic_verbose_entry::foomp 42 <- format string, normal_var=43
+1:main│ │ ├─  Xms ERROR basic_verbose_entry hello
+1:main│ ├─┘
+1:main│ ├┐basic_verbose_entry::server host="localhost", port=8080
+1:main│ │└┐basic_verbose_entry::conn peer_addr="82.9.9.9", port=42381
+1:main│ │ ├─  Xms WARN basic_verbose_entry weak encryption requested, algo="xor"
+1:main│ │ ├─  Xms DEBUG basic_verbose_entry response sent, length=8
+1:main│ │ ├─  Xms DEBUG basic_verbose_entry disconnected
+1:main│ ├─┘
+1:main│ ├┐basic_verbose_entry::server host="localhost", port=8080
+1:main│ │└┐basic_verbose_entry::conn peer_addr="8.8.8.8", port=18230
+1:main│ │ ├─  Xms DEBUG basic_verbose_entry message received, length=5
+1:main│ │ ├─  Xms DEBUG basic_verbose_entry response sent, length=8
+1:main│ │ ├─  Xms DEBUG basic_verbose_entry disconnected
+1:main│ ├─┘
+1:main│ ├─  Xs  WARN basic_verbose_entry internal error
+1:main│ ├─  Xs  ERROR basic_verbose_entry this is a log message
+1:main│ ├─  Xs  INFO basic_verbose_entry exit
+1:main├─┘
+1:main┘

examples/basic_verbose_exit.rs

@@ -0,0 +1,83 @@
+use tracing::{debug, error, info, instrument, span, warn, Level};
+use tracing_subscriber::{layer::SubscriberExt, registry::Registry};
+use tracing_tree::HierarchicalLayer;
+
+fn main() {
+    let layer = HierarchicalLayer::default()
+        .with_writer(std::io::stdout)
+        .with_indent_lines(true)
+        .with_indent_amount(2)
+        .with_thread_names(true)
+        .with_thread_ids(true)
+        .with_verbose_exit(true)
+        .with_verbose_entry(false)
+        .with_targets(true);
+
+    let subscriber = Registry::default().with(layer);
+    tracing::subscriber::set_global_default(subscriber).unwrap();
+    #[cfg(feature = "tracing-log")]
+    tracing_log::LogTracer::init().unwrap();
+
+    let app_span = span!(Level::TRACE, "hierarchical-example", version = %0.1);
+    let _e = app_span.enter();
+
+    let server_span = span!(Level::TRACE, "server", host = "localhost", port = 8080);
+    let _e2 = server_span.enter();
+    info!("starting");
+    std::thread::sleep(std::time::Duration::from_millis(3000));
+    info!("listening");
+    let peer1 = span!(Level::TRACE, "conn", peer_addr = "82.9.9.9", port = 42381);
+    peer1.in_scope(|| {
+        debug!("connected");
+        std::thread::sleep(std::time::Duration::from_millis(300));
+        debug!(length = 2, "message received");
+    });
+    drop(peer1);
+    let peer2 = span!(Level::TRACE, "conn", peer_addr = "8.8.8.8", port = 18230);
+    peer2.in_scope(|| {
+        std::thread::sleep(std::time::Duration::from_millis(300));
+        debug!("connected");
+    });
+    drop(peer2);
+    let peer3 = span!(
+        Level::TRACE,
+        "foomp",
+        normal_var = 43,
+        "{} <- format string",
+        42
+    );
+    peer3.in_scope(|| {
+        error!("hello");
+    });
+    drop(peer3);
+    let peer1 = span!(Level::TRACE, "conn", peer_addr = "82.9.9.9", port = 42381);
+    peer1.in_scope(|| {
+        warn!(algo = "xor", "weak encryption requested");
+        std::thread::sleep(std::time::Duration::from_millis(300));
+        debug!(length = 8, "response sent");
+        debug!("disconnected");
+    });
+    drop(peer1);
+    let peer2 = span!(Level::TRACE, "conn", peer_addr = "8.8.8.8", port = 18230);
+    peer2.in_scope(|| {
+        debug!(length = 5, "message received");
+        std::thread::sleep(std::time::Duration::from_millis(300));
+        debug!(length = 8, "response sent");
+        debug!("disconnected");
+    });
+    drop(peer2);
+    warn!("internal error");
+    log::error!("this is a log message");
+    info!("exit");
+}
+
+#[instrument]
+fn call_a(name: &str) {
+    info!(name, "got a name");
+    call_b(name)
+}
+
+#[instrument]
+fn call_b(name: &str) {
+    info!(name, "got a name");
+}

examples/basic_verbose_exit.stdout

@@ -0,0 +1,35 @@
+1:main┐basic_verbose_exit::hierarchical-example version=0.1
+1:main├─┐basic_verbose_exit::server host="localhost", port=8080
+1:main│ ├─  Xms INFO basic_verbose_exit starting
+1:main│ ├─  Xs  INFO basic_verbose_exit listening
+1:main│ ├─┐basic_verbose_exit::conn peer_addr="82.9.9.9", port=42381
+1:main│ │ ├─  Xms DEBUG basic_verbose_exit connected
+1:main│ │ ├─  Xms DEBUG basic_verbose_exit message received, length=2
+1:main│ │┌┘basic_verbose_exit::conn peer_addr="82.9.9.9", port=42381
+1:main│ ├┘basic_verbose_exit::server host="localhost", port=8080
+1:main│ ├─┐basic_verbose_exit::conn peer_addr="8.8.8.8", port=18230
+1:main│ │ ├─  Xms DEBUG basic_verbose_exit connected
+1:main│ │┌┘basic_verbose_exit::conn peer_addr="8.8.8.8", port=18230
+1:main│ ├┘basic_verbose_exit::server host="localhost", port=8080
+1:main│ ├─┐basic_verbose_exit::foomp 42 <- format string, normal_var=43
+1:main│ │ ├─  Xms ERROR basic_verbose_exit hello
+1:main│ │┌┘basic_verbose_exit::foomp 42 <- format string, normal_var=43
+1:main│ ├┘basic_verbose_exit::server host="localhost", port=8080
+1:main│ ├─┐basic_verbose_exit::conn peer_addr="82.9.9.9", port=42381
+1:main│ │ ├─  Xms WARN basic_verbose_exit weak encryption requested, algo="xor"
+1:main│ │ ├─  Xms DEBUG basic_verbose_exit response sent, length=8
+1:main│ │ ├─  Xms DEBUG basic_verbose_exit disconnected
+1:main│ │┌┘basic_verbose_exit::conn peer_addr="82.9.9.9", port=42381
+1:main│ ├┘basic_verbose_exit::server host="localhost", port=8080
+1:main│ ├─┐basic_verbose_exit::conn peer_addr="8.8.8.8", port=18230
+1:main│ │ ├─  Xms DEBUG basic_verbose_exit message received, length=5
+1:main│ │ ├─  Xms DEBUG basic_verbose_exit response sent, length=8
+1:main│ │ ├─  Xms DEBUG basic_verbose_exit disconnected
+1:main│ │┌┘basic_verbose_exit::conn peer_addr="8.8.8.8", port=18230
+1:main│ ├┘basic_verbose_exit::server host="localhost", port=8080
+1:main│ ├─  Xs  WARN basic_verbose_exit internal error
+1:main│ ├─  Xs  ERROR basic_verbose_exit this is a log message
+1:main│ ├─  Xs  INFO basic_verbose_exit exit
+1:main│┌┘basic_verbose_exit::server host="localhost", port=8080
+1:main├┘basic_verbose_exit::hierarchical-example version=0.1
+1:main┘basic_verbose_exit::hierarchical-example version=0.1