Add tracing_durations_export feature to puffin-cli (#830)

The optional `tracing-durations-export` feature allows creating
parallelism plots from all puffin-cli commands without affecting
production builds.

Usage:

```
virtualenv --clear -p 3.10 .venv310 && TRACING_DURATIONS_FILE=target/traces/jupyter-no-cache.ndjson RUST_LOG=puffin=info VIRTUAL_ENV=.venv310 cargo run --bin puffin --profile profiling --features tracing-durations-export -- pip-install -v --no-cache jupyter
virtualenv --clear -p 3.10 .venv310 && TRACING_DURATIONS_FILE=target/traces/jupyter.ndjson RUST_LOG=puffin=info VIRTUAL_ENV=.venv310 cargo run --bin puffin --profile profiling --features tracing-durations-export -- pip-install -v jupyter
 ```

Output, plotted in collapsed mode for readability:

Cached jupyter:

![jupyter](f7e03c68-0438-4cf4-bceb-9a4a146cc506)

Uncached jupyter:

![image](cfdd3383-7a9d-43d6-b8d0-201f64611596)

crates/puffin-cli/Cargo.toml

@@ -66,6 +66,7 @@ tracing-tree = { workspace = true }
 url = { workspace = true }
 waitmap = { workspace = true }
 which = { workspace = true }
+tracing-durations-export = { version = "0.1.0", features = ["plot"], optional = true }
 
 [target.'cfg(target_os = "windows")'.dependencies]
 mimalloc = "0.1.39"

crates/puffin-cli/src/logging.rs

@@ -1,4 +1,10 @@
+use std::env;
+use std::path::PathBuf;
+use std::time::Duration;
+
 use tracing::level_filters::LevelFilter;
+use tracing_durations_export::plot::PlotConfig;
+use tracing_durations_export::{DurationsLayerBuilder, DurationsLayerDropGuard};
 use tracing_subscriber::layer::SubscriberExt;
 use tracing_subscriber::util::SubscriberInitExt;
 use tracing_subscriber::EnvFilter;
@@ -20,7 +26,39 @@ pub(crate) enum Level {
 /// The [`Level`] is used to dictate the default filters (which can be overridden by the `RUST_LOG`
 /// environment variable) along with the formatting of the output. For example, [`Level::Verbose`]
 /// includes targets and timestamps, along with all `puffin=debug` messages by default.
-pub(crate) fn setup_logging(level: Level) {
+pub(crate) fn setup_logging(level: Level) -> Option<DurationsLayerDropGuard> {
+    let (duration_layer, guard) = {
+        #[cfg(feature = "tracing-durations-export")]
+        if let Ok(location) = env::var("TRACING_DURATIONS_FILE") {
+            let location = PathBuf::from(location);
+            if let Some(parent) = location.parent() {
+                fs_err::create_dir_all(parent)
+                    .expect("Failed to create parent of TRACING_DURATIONS_FILE");
+            }
+            let plot_config = PlotConfig {
+                multi_lane: true,
+                min_length: Some(Duration::from_secs_f32(0.002)),
+                remove: Some(
+                    ["get_cached_with_callback".to_string()]
+                        .into_iter()
+                        .collect(),
+                ),
+                ..PlotConfig::default()
+            };
+            let (layer, guard) = DurationsLayerBuilder::default()
+                .durations_file(&location)
+                .plot_file(location.with_extension("svg"))
+                .plot_config(plot_config)
+                .build()
+                .expect("Couldn't create TRACING_DURATIONS_FILE files");
+            (Some(layer), Some(guard))
+        } else {
+            (None, None)
+        }
+        #[cfg(not(feature = "tracing-durations-export"))]
+        (None, None)
+    };
+
     match level {
         Level::Default => {
             // Show nothing, but allow `RUST_LOG` to override.
@@ -30,6 +68,7 @@ pub(crate) fn setup_logging(level: Level) {
 
             // Regardless of the tracing level, show messages without any adornment.
             tracing_subscriber::registry()
+                .with(duration_layer)
                 .with(filter)
                 .with(
                     tracing_subscriber::fmt::layer()
@@ -47,6 +86,7 @@ pub(crate) fn setup_logging(level: Level) {
 
             // Regardless of the tracing level, include the uptime and target for each message.
             tracing_subscriber::registry()
+                .with(duration_layer)
                 .with(filter)
                 .with(
                     HierarchicalLayer::default()
@@ -57,4 +97,6 @@ pub(crate) fn setup_logging(level: Level) {
                 .init();
         }
     }
+
+    guard
 }

crates/puffin-cli/src/main.rs

@@ -415,7 +415,7 @@ async fn inner() -> Result<ExitStatus> {
     let cli = Cli::parse();
 
     // Configure the `tracing` crate, which controls internal logging.
-    logging::setup_logging(if cli.verbose {
+    let _guard = logging::setup_logging(if cli.verbose {
         logging::Level::Verbose
     } else {
         logging::Level::Default