Refactor tracing components (#834)

* Split tracing component code into modules.

* Repatriate Tracing and simplify config handling.

We upstreamed our Tracing component, expecting not to have to exert fine
control over the tracing settings.  But this turned out not to be the case, and
now that we want to do other things (flamegraphs, journalctl, opentelemetry,
etc), we end up with really awkward code (as in the current flamegraph
handling).

This also makes use of the changes to `init()` to load the config early to pass
configuration data into the components, which avoids the need for the
refactoring in #775.

Finally, we restore support for the `-v` flag when the filter is unset.  Closes #831.

* Disable tracing and metrics endpoints by default.

Closes #660.

* Switch back to upstream Abscissa.

* Integrate flamegraph support into the new Tracing component.

* Pass -v in acceptance tests to get info-level output.

* Clean up acceptance test code.
This commit is contained in:
Henry de Valence 2020-08-06 10:29:31 -07:00 committed by GitHub
parent c0caba401c
commit a77328ad7c
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
12 changed files with 439 additions and 459 deletions

126
Cargo.lock generated
View File

@ -3,7 +3,8 @@
[[package]]
name = "abscissa_core"
version = "0.5.2"
source = "git+https://github.com/yaahc/abscissa.git?rev=41d342a9344e38442b2211b07f28a89505892a21#41d342a9344e38442b2211b07f28a89505892a21"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "6a07677093120a02583717b6dd1ef81d8de1e8d01bd226c83f0f9bdf3e56bb3a"
dependencies = [
"abscissa_derive",
"backtrace",
@ -23,20 +24,21 @@ dependencies = [
"toml",
"tracing",
"tracing-log",
"tracing-subscriber",
"tracing-subscriber 0.1.6",
"wait-timeout",
]
[[package]]
name = "abscissa_derive"
version = "0.5.0"
source = "git+https://github.com/yaahc/abscissa.git?rev=41d342a9344e38442b2211b07f28a89505892a21#41d342a9344e38442b2211b07f28a89505892a21"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "74f5722bc48763cb9d81d8427ca05b6aa2842f6632cf8e4c0a29eef9baececcc"
dependencies = [
"darling",
"ident_case",
"proc-macro2 1.0.19",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
"synstructure",
]
@ -343,9 +345,9 @@ dependencies = [
[[package]]
name = "clap"
version = "2.33.1"
version = "2.33.2"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "bdfa80d47f954d53a35a64987ca1422f495b8d6483c0fe9f7117b36c2a792129"
checksum = "10040cdf04294b565d9e0319955430099ec3813a64c952b86a41200ad714ae48"
dependencies = [
"ansi_term 0.11.0",
"atty",
@ -376,9 +378,9 @@ dependencies = [
[[package]]
name = "color-backtrace"
version = "0.4.2"
version = "0.3.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "5356ae4e07c994a2763226a8a991e5829ded78ac23f8ac88b3f3e69970db5163"
checksum = "65d13f1078cc63c791d0deba0dd43db37c9ec02b311f10bed10b577016f3a957"
dependencies = [
"atty",
"backtrace",
@ -531,7 +533,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "39858aa5bac06462d4dd4b9164848eb81ffc4aa5c479746393598fd193afa227"
dependencies = [
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
]
[[package]]
@ -569,7 +571,7 @@ dependencies = [
"proc-macro2 1.0.19",
"quote 1.0.7",
"strsim 0.9.3",
"syn 1.0.37",
"syn 1.0.38",
]
[[package]]
@ -580,7 +582,7 @@ checksum = "d9b5a2f4ac4969822c62224815d069952656cadc7084fdca9751e6d959189b72"
dependencies = [
"darling_core",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
]
[[package]]
@ -629,7 +631,7 @@ checksum = "adc2ab4d5a16117f9029e9a6b5e4e79f4c67f6519bc134210d4d4a04ba31f41b"
dependencies = [
"proc-macro2 1.0.19",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
]
[[package]]
@ -805,7 +807,7 @@ dependencies = [
"proc-macro-hack",
"proc-macro2 1.0.19",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
]
[[package]]
@ -914,7 +916,7 @@ checksum = "90454ce4de40b7ca6a8968b5ef367bdab48413962588d0d2b1638d60090c35d7"
dependencies = [
"proc-macro2 1.0.19",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
]
[[package]]
@ -1458,6 +1460,15 @@ version = "0.2.3"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "2839e79665f131bdb5782e51f2c6c9599c133c6098982a54c794358bf432529c"
[[package]]
name = "owning_ref"
version = "0.4.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "6ff55baddef9e4ad00f88b6c743a2a8062d4c6ade126c2a528644b8e444d52ce"
dependencies = [
"stable_deref_trait",
]
[[package]]
name = "parity-scale-codec"
version = "1.3.4"
@ -1501,7 +1512,7 @@ dependencies = [
"cloudabi 0.0.3",
"libc",
"redox_syscall",
"smallvec",
"smallvec 1.4.1",
"winapi 0.3.9",
]
@ -1516,7 +1527,7 @@ dependencies = [
"instant",
"libc",
"redox_syscall",
"smallvec",
"smallvec 1.4.1",
"winapi 0.3.9",
]
@ -1537,7 +1548,7 @@ checksum = "2c0e815c3ee9a031fdf5af21c10aa17c573c9c6a566328d99e3936c34e36461f"
dependencies = [
"proc-macro2 1.0.19",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
]
[[package]]
@ -1578,7 +1589,7 @@ dependencies = [
"proc-macro-error-attr",
"proc-macro2 1.0.19",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
"version_check",
]
@ -1969,9 +1980,9 @@ dependencies = [
[[package]]
name = "semver"
version = "0.10.0"
version = "0.9.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "394cec28fa623e00903caf7ba4fa6fb9a0e260280bb8cdbbba029611108a0190"
checksum = "1d7eb9ef2c18661902cc47e535f9bc51b78acd254da71d375c2f6720d9a40403"
dependencies = [
"semver-parser",
"serde",
@ -2010,7 +2021,7 @@ checksum = "2a0be94b04690fbaed37cddffc5c134bf537c8e3329d53e982fe04c374978f8e"
dependencies = [
"proc-macro2 1.0.19",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
]
[[package]]
@ -2069,9 +2080,9 @@ dependencies = [
[[package]]
name = "signal-hook-registry"
version = "1.2.0"
version = "1.2.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "94f478ede9f64724c5d173d7bb56099ec3e2d9fc2774aac65d34b8b890405f41"
checksum = "a3e12110bc539e657a646068aaf5eb5b63af9d0c1f7b29c97113fad80e15f035"
dependencies = [
"arc-swap",
"libc",
@ -2109,6 +2120,15 @@ dependencies = [
"parking_lot 0.11.0",
]
[[package]]
name = "smallvec"
version = "0.6.13"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "f7b0758c52e15a8b5e3691eae6cc559f08eee9406e548a4477ba4e67770a82b6"
dependencies = [
"maybe-uninit",
]
[[package]]
name = "smallvec"
version = "1.4.1"
@ -2146,9 +2166,15 @@ checksum = "5254766110c377a921c002ca0775d4e384ba69af951fc4329d9dd77af2c25763"
dependencies = [
"proc-macro2 1.0.19",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
]
[[package]]
name = "stable_deref_trait"
version = "1.2.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "a8f112729512f8e442d81f95a8a7ddf2b7c6b8a1a6f509a95864142b30cab2d3"
[[package]]
name = "static_assertions"
version = "1.1.0"
@ -2194,7 +2220,7 @@ dependencies = [
"proc-macro-error",
"proc-macro2 1.0.19",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
]
[[package]]
@ -2216,9 +2242,9 @@ dependencies = [
[[package]]
name = "syn"
version = "1.0.37"
version = "1.0.38"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "239f255b9e3429350f188c27b807fc9920a15eb9145230ff1a7d054c08fec319"
checksum = "e69abc24912995b3038597a7a593be5053eb0fb44f3cc5beec0deb421790c1f4"
dependencies = [
"proc-macro2 1.0.19",
"quote 1.0.7",
@ -2233,7 +2259,7 @@ checksum = "b834f2d66f734cb897113e34aaff2f1ab4719ca946f9a7358dba8f8064148701"
dependencies = [
"proc-macro2 1.0.19",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
"unicode-xid 0.2.1",
]
@ -2296,7 +2322,7 @@ checksum = "bd80fc12f73063ac132ac92aceea36734f04a1d93c1240c6944e23a3b8841793"
dependencies = [
"proc-macro2 1.0.19",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
]
[[package]]
@ -2351,7 +2377,7 @@ checksum = "f0c3acc6aa564495a0f2e1d59fab677cd7f81a19994cfc7f3ad0e64301560389"
dependencies = [
"proc-macro2 1.0.19",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
]
[[package]]
@ -2573,14 +2599,14 @@ checksum = "f0693bf8d6f2bf22c690fc61a9d21ac69efdbb894a17ed596b9af0f01e64b84b"
dependencies = [
"proc-macro2 1.0.19",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
]
[[package]]
name = "tracing-core"
version = "0.1.12"
version = "0.1.13"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "b2734b5a028fa697686f16c6d18c2c6a3c7e41513f9a213abb6754c4acb3c8d7"
checksum = "d593f98af59ebc017c0648f0117525db358745a8894a8d684e185ba3f45954f9"
dependencies = [
"lazy_static",
]
@ -2592,7 +2618,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "b4d7c0b83d4a500748fa5879461652b361edf5c9d51ede2a2ac03875ca185e24"
dependencies = [
"tracing",
"tracing-subscriber",
"tracing-subscriber 0.2.10",
]
[[package]]
@ -2603,7 +2629,7 @@ checksum = "bd520fe41c667b437952383f3a1ec14f1fa45d653f719a77eedd6e6a02d8fa54"
dependencies = [
"lazy_static",
"tracing",
"tracing-subscriber",
"tracing-subscriber 0.2.10",
]
[[package]]
@ -2637,6 +2663,23 @@ dependencies = [
"tracing-core",
]
[[package]]
name = "tracing-subscriber"
version = "0.1.6"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "192ca16595cdd0661ce319e8eede9c975f227cdaabc4faaefdc256f43d852e45"
dependencies = [
"ansi_term 0.11.0",
"chrono",
"lazy_static",
"matchers",
"owning_ref",
"regex",
"smallvec 0.6.13",
"tracing-core",
"tracing-log",
]
[[package]]
name = "tracing-subscriber"
version = "0.2.10"
@ -2651,7 +2694,7 @@ dependencies = [
"serde",
"serde_json",
"sharded-slab",
"smallvec",
"smallvec 1.4.1",
"tracing-core",
"tracing-log",
"tracing-serde",
@ -2877,7 +2920,7 @@ dependencies = [
"tracing",
"tracing-error",
"tracing-futures",
"tracing-subscriber",
"tracing-subscriber 0.2.10",
"zebra-chain",
"zebra-state",
"zebra-test",
@ -2961,7 +3004,7 @@ dependencies = [
"tower",
"tracing",
"tracing-error",
"tracing-subscriber",
"tracing-subscriber 0.2.10",
]
[[package]]
@ -2974,7 +3017,7 @@ dependencies = [
"serde_json",
"structopt",
"tracing-error",
"tracing-subscriber",
"tracing-subscriber 0.2.10",
"zebra-chain",
"zebra-consensus",
]
@ -3004,8 +3047,7 @@ dependencies = [
"tracing-error",
"tracing-flame",
"tracing-futures",
"tracing-log",
"tracing-subscriber",
"tracing-subscriber 0.2.10",
"zebra-chain",
"zebra-consensus",
"zebra-network",
@ -3030,6 +3072,6 @@ checksum = "de251eec69fc7c1bc3923403d18ececb929380e016afe103da75f396704f8ca2"
dependencies = [
"proc-macro2 1.0.19",
"quote 1.0.7",
"syn 1.0.37",
"syn 1.0.38",
"synstructure",
]

View File

@ -19,6 +19,3 @@ panic = "abort"
[profile.release]
panic = "abort"
[patch.crates-io]
abscissa_core = { git = "https://github.com/yaahc/abscissa.git", rev = "41d342a9344e38442b2211b07f28a89505892a21" }

View File

@ -28,7 +28,6 @@ color-eyre = "0.5"
thiserror = "1"
tracing = "0.1"
tracing-futures = "0.2"
tracing-log = "0.1"
tracing-subscriber = { version = "0.2.10", features = ["tracing-log"] }
tracing-error = "0.1.2"

View File

@ -1,16 +1,15 @@
//! Zebrad Abscissa Application
use crate::{commands::ZebradCmd, components::tracing::FlameGrapher, config::ZebradConfig};
use crate::{commands::ZebradCmd, components::tracing::Tracing, config::ZebradConfig};
use abscissa_core::{
application::{self, AppCell},
config,
config::Configurable,
terminal::component::Terminal,
trace::Tracing,
Application, Component, EntryPoint, FrameworkError, Shutdown, StandardPaths,
};
use application::fatal_error;
use std::{fmt, process};
use std::process;
/// Application state
pub static APPLICATION: AppCell<ZebradApp> = AppCell::new();
@ -35,14 +34,11 @@ pub fn app_config() -> config::Reader<ZebradApp> {
}
/// Zebrad Application
#[derive(Debug)]
pub struct ZebradApp {
/// Application configuration.
config: Option<ZebradConfig>,
/// drop handle for tracing-flame layer to ensure it flushes its buffer when
/// the application exits
flame_guard: Option<FlameGrapher>,
/// Application state.
state: application::State<Self>,
}
@ -55,21 +51,11 @@ impl Default for ZebradApp {
fn default() -> Self {
Self {
config: None,
flame_guard: None,
state: application::State::default(),
}
}
}
impl fmt::Debug for ZebradApp {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
f.debug_struct("ZebraApp")
.field("config", &self.config)
.field("state", &self.state)
.finish()
}
}
impl Application for ZebradApp {
/// Entrypoint command for this application.
type Cmd = EntryPoint<ZebradCmd>;
@ -101,18 +87,11 @@ impl Application for ZebradApp {
command: &Self::Cmd,
) -> Result<Vec<Box<dyn Component<Self>>>, FrameworkError> {
let terminal = Terminal::new(self.term_colors(command));
// This MUST happen after `Terminal::new` to ensure our preferred panic
// handler is the last one installed
color_eyre::install().unwrap();
if ZebradApp::command_is_server(&command) {
let tracing = self.tracing_component();
Ok(vec![Box::new(terminal), Box::new(tracing)])
} else {
crate::components::tracing::init_backup(&self.config().tracing);
Ok(vec![Box::new(terminal)])
}
Ok(vec![Box::new(terminal)])
}
/// Register all components used by this application.
@ -126,11 +105,29 @@ impl Application for ZebradApp {
};
let mut components = self.framework_components(command)?;
let cfg_ref = self
.config
.as_ref()
.expect("config is loaded before register_components");
let default_filter = if command.verbose { "info" } else { "warn" };
let is_server = command
.command
.as_ref()
.map(ZebradCmd::is_server)
.unwrap_or(false);
// Launch network endpoints for long-running commands
if ZebradApp::command_is_server(&command) {
if is_server {
let filter = cfg_ref.tracing.filter.as_deref().unwrap_or(default_filter);
let flame_root = cfg_ref.tracing.flamegraph.as_deref();
components.push(Box::new(Tracing::new(filter, flame_root)?));
components.push(Box::new(TokioComponent::new()?));
components.push(Box::new(TracingEndpoint::new()?));
components.push(Box::new(MetricsEndpoint::new()?));
components.push(Box::new(TracingEndpoint::new(cfg_ref)?));
components.push(Box::new(MetricsEndpoint::new(cfg_ref)?));
} else {
components.push(Box::new(Tracing::new(default_filter, None)?));
}
self.state.components.register(components)
@ -157,7 +154,7 @@ impl Application for ZebradApp {
// Fire callback regardless of whether any config was loaded to
// in order to signal state in the application lifecycle
self.after_config(config, command)?;
self.after_config(config)?;
Ok(())
}
@ -167,53 +164,11 @@ impl Application for ZebradApp {
/// Called regardless of whether config is loaded to indicate this is the
/// time in app lifecycle when configuration would be loaded if
/// possible.
fn after_config(
&mut self,
config: Self::Cfg,
command: &Self::Cmd,
) -> Result<(), FrameworkError> {
use crate::components::{
metrics::MetricsEndpoint, tokio::TokioComponent, tracing::TracingEndpoint,
};
fn after_config(&mut self, config: Self::Cfg) -> Result<(), FrameworkError> {
// Configure components
self.state.components.after_config(&config)?;
self.config = Some(config);
if ZebradApp::command_is_server(&command) {
if let Some(filter) = self.config.as_ref().unwrap().tracing.filter.as_ref() {
self.state
.components
.get_downcast_mut::<Tracing>()
.expect("Tracing component should be available")
.reload_filter(filter);
}
// Work around some issues with dependency injection and configs
let config = self
.config
.clone()
.expect("config was set to Some earlier in this function");
let tokio_component = self
.state
.components
.get_downcast_ref::<TokioComponent>()
.expect("Tokio component should be available");
self.state
.components
.get_downcast_ref::<TracingEndpoint>()
.expect("Tracing endpoint should be available")
.open_endpoint(&config.tracing, tokio_component);
self.state
.components
.get_downcast_ref::<MetricsEndpoint>()
.expect("Metrics endpoint should be available")
.open_endpoint(&config.metrics, tokio_component);
}
Ok(())
}
@ -232,24 +187,3 @@ impl Application for ZebradApp {
}
}
}
impl ZebradApp {
fn tracing_component(&mut self) -> Tracing {
let config = &self.config().tracing;
let (component, guard) = crate::components::tracing::init(config);
self.flame_guard = guard;
component
}
/// Returns true if command is a server command.
///
/// Server commands use long-running components such as tracing, metrics,
/// and the tokio runtime.
fn command_is_server(command: &EntryPoint<ZebradCmd>) -> bool {
// `None` outputs zebrad usage information and exits
match &command.command {
None => false,
Some(c) => c.is_server(),
}
}
}

View File

@ -14,12 +14,7 @@ pub struct GenerateCmd {
impl Runnable for GenerateCmd {
/// Start the application.
fn run(&self) {
let default_config = ZebradConfig {
metrics: Default::default(),
network: Default::default(),
state: Default::default(),
tracing: crate::config::TracingSection::populated(),
};
let default_config = ZebradConfig::default();
let mut output = r"# Default configuration for zebrad.
#
# This file can be used as a skeleton for custom configs.

View File

@ -1,39 +1,37 @@
//! An HTTP endpoint for metrics collection.
use crate::{components::tokio::TokioComponent, config::MetricsSection};
use std::net::SocketAddr;
use abscissa_core::{Component, FrameworkError};
use metrics_runtime::{exporters::HttpExporter, observers::PrometheusBuilder, Receiver};
use crate::{components::tokio::TokioComponent, config::ZebradConfig};
/// Abscissa component which runs a metrics endpoint.
#[derive(Debug, Component)]
#[component(inject = "init_tokio(zebrad::components::tokio::TokioComponent)")]
pub struct MetricsEndpoint {}
pub struct MetricsEndpoint {
addr: Option<SocketAddr>,
}
impl MetricsEndpoint {
/// Create the component.
pub fn new() -> Result<Self, FrameworkError> {
Ok(Self {})
pub fn new(config: &ZebradConfig) -> Result<Self, FrameworkError> {
Ok(Self {
addr: config.metrics.endpoint_addr,
})
}
/// Tokio endpoint dependency stub.
///
/// We can't open the endpoint here, because the config has not been loaded.
pub fn init_tokio(&mut self, _tokio_component: &TokioComponent) -> Result<(), FrameworkError> {
Ok(())
}
pub fn init_tokio(&mut self, tokio_component: &TokioComponent) -> Result<(), FrameworkError> {
let addr = if let Some(addr) = self.addr {
addr
} else {
return Ok(());
};
/// Open the metrics endpoint.
///
/// We can't implement `after_config`, because we use `derive(Component)`.
/// And the ownership rules might make it hard to access the TokioComponent
/// from `after_config`.
pub fn open_endpoint(&self, metrics_config: &MetricsSection, tokio_component: &TokioComponent) {
info!("Initializing metrics endpoint");
let addr = metrics_config.endpoint_addr;
// XXX do we need to hold on to the receiver?
let receiver = Receiver::builder()
.build()
@ -50,5 +48,7 @@ impl MetricsEndpoint {
.spawn(endpoint.async_run());
metrics::set_boxed_recorder(Box::new(receiver)).expect("XXX FIXME ERROR CONVERSION");
Ok(())
}
}

View File

@ -1,205 +1,7 @@
//! An HTTP endpoint for dynamically setting tracing filters.
mod component;
mod endpoint;
mod flame;
use crate::{components::tokio::TokioComponent, config::TracingSection, prelude::*};
use abscissa_core::{trace::Tracing, Component, FrameworkError};
use color_eyre::eyre::Report;
use hyper::service::{make_service_fn, service_fn};
use hyper::{Body, Request, Response, Server};
use std::{
fs::File,
io::{BufReader, BufWriter},
path::PathBuf,
sync::Arc,
};
use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};
/// Abscissa component which runs a tracing filter endpoint.
#[derive(Debug, Component)]
#[component(inject = "init_tokio(zebrad::components::tokio::TokioComponent)")]
pub struct TracingEndpoint {}
async fn read_filter(req: Request<Body>) -> Result<String, String> {
std::str::from_utf8(
&hyper::body::to_bytes(req.into_body())
.await
.map_err(|_| "Error reading body".to_owned())?,
)
.map(|s| s.to_owned())
.map_err(|_| "Filter must be UTF-8".to_owned())
}
impl TracingEndpoint {
/// Create the component.
pub fn new() -> Result<Self, FrameworkError> {
Ok(Self {})
}
/// Tokio endpoint dependency stub.
///
/// We can't open the endpoint here, because the config has not been loaded.
pub fn init_tokio(&mut self, _tokio_component: &TokioComponent) -> Result<(), FrameworkError> {
Ok(())
}
/// Open the tracing endpoint.
///
/// We can't implement `after_config`, because we use `derive(Component)`.
/// And the ownership rules might make it hard to access the TokioComponent
/// from `after_config`.
pub fn open_endpoint(&self, tracing_config: &TracingSection, tokio_component: &TokioComponent) {
info!("Initializing tracing endpoint");
let service =
make_service_fn(|_| async { Ok::<_, hyper::Error>(service_fn(request_handler)) });
let addr = tracing_config.endpoint_addr;
tokio_component
.rt
.as_ref()
.expect("runtime should not be taken")
.spawn(async move {
// try_bind uses the tokio runtime, so we
// need to construct it inside the task.
let server = match Server::try_bind(&addr) {
Ok(s) => s,
Err(e) => {
error!("Could not open tracing endpoint listener");
error!("Error: {}", e);
return;
}
}
.serve(service);
if let Err(e) = server.await {
error!("Server error: {}", e);
}
});
}
}
#[instrument]
async fn request_handler(req: Request<Body>) -> Result<Response<Body>, hyper::Error> {
use hyper::{Method, StatusCode};
let rsp = match (req.method(), req.uri().path()) {
(&Method::GET, "/") => Response::new(Body::from(
r#"
This HTTP endpoint allows dynamic control of the filter applied to
tracing events.
To get the current filter, GET /filter:
curl -X GET localhost:3000/filter
To set the filter, POST the new filter string to /filter:
curl -X POST localhost:3000/filter -d "zebrad=trace"
"#,
)),
(&Method::GET, "/filter") => Response::builder()
.status(StatusCode::OK)
.body(Body::from(
app_reader()
.state()
.components
.get_downcast_ref::<abscissa_core::trace::Tracing>()
.expect("Tracing component should be available")
.filter(),
))
.expect("response with known status code cannot fail"),
(&Method::POST, "/filter") => match read_filter(req).await {
Ok(filter) => {
app_writer()
.state_mut()
.components
.get_downcast_mut::<abscissa_core::trace::Tracing>()
.expect("Tracing component should be available")
.reload_filter(filter);
Response::new(Body::from(""))
}
Err(e) => Response::builder()
.status(StatusCode::BAD_REQUEST)
.body(Body::from(e))
.expect("response with known status code cannot fail"),
},
_ => Response::builder()
.status(StatusCode::NOT_FOUND)
.body(Body::from(""))
.expect("response with known status cannot fail"),
};
Ok(rsp)
}
#[derive(Clone)]
pub(crate) struct FlameGrapher {
guard: Arc<tracing_flame::FlushGuard<BufWriter<File>>>,
path: PathBuf,
}
impl FlameGrapher {
fn make_flamegraph(&self) -> Result<(), Report> {
self.guard.flush()?;
let out_path = self.path.with_extension("svg");
let inf = File::open(&self.path)?;
let reader = BufReader::new(inf);
let out = File::create(out_path)?;
let writer = BufWriter::new(out);
let mut opts = inferno::flamegraph::Options::default();
info!("writing flamegraph to disk...");
inferno::flamegraph::from_reader(&mut opts, reader, writer)?;
Ok(())
}
}
impl Drop for FlameGrapher {
fn drop(&mut self) {
match self.make_flamegraph() {
Ok(()) => {}
Err(report) => {
warn!(
"Error while constructing flamegraph during shutdown: {:?}",
report
);
}
}
}
}
pub(crate) fn init(config: &TracingSection) -> (Tracing, Option<FlameGrapher>) {
// Construct a tracing subscriber with the supplied filter and enable reloading.
let builder = tracing_subscriber::FmtSubscriber::builder()
.with_env_filter(config.env_filter())
.with_filter_reloading();
let filter_handle = builder.reload_handle();
let subscriber = builder.finish().with(tracing_error::ErrorLayer::default());
let guard = if let Some(flamegraph_path) = config.flamegraph.as_deref() {
let flamegraph_path = flamegraph_path.with_extension("folded");
let (flame_layer, guard) = tracing_flame::FlameLayer::with_file(&flamegraph_path).unwrap();
let flame_layer = flame_layer
.with_empty_samples(false)
.with_threads_collapsed(true);
subscriber.with(flame_layer).init();
Some(FlameGrapher {
guard: Arc::new(guard),
path: flamegraph_path,
})
} else {
subscriber.init();
None
};
(filter_handle.into(), guard)
}
pub(crate) fn init_backup(config: &TracingSection) {
tracing_subscriber::Registry::default()
.with(config.env_filter())
.with(tracing_error::ErrorLayer::default())
.init();
}
pub use component::Tracing;
pub use endpoint::TracingEndpoint;
pub use flame::{layer, Grapher};

View File

@ -0,0 +1,87 @@
use std::path::Path;
use tracing_error::ErrorLayer;
use tracing_subscriber::{
fmt::Formatter, layer::SubscriberExt, reload::Handle, util::SubscriberInitExt, EnvFilter,
FmtSubscriber,
};
use abscissa_core::{Component, FrameworkError, FrameworkErrorKind, Shutdown};
use super::flame;
/// Abscissa component for initializing the `tracing` subsystem
pub struct Tracing {
filter_handle: Handle<EnvFilter, Formatter>,
flamegrapher: Option<flame::Grapher>,
}
impl Tracing {
/// Try to create a new [`Tracing`] component with the given `filter`.
pub fn new(filter: &str, flame_root: Option<&Path>) -> Result<Self, FrameworkError> {
// Construct a tracing subscriber with the supplied filter and enable reloading.
let builder = FmtSubscriber::builder()
.with_ansi(true)
.with_env_filter(filter)
.with_filter_reloading();
let filter_handle = builder.reload_handle();
let subscriber = builder.finish().with(ErrorLayer::default());
let flamegrapher = if let Some(path) = flame_root {
let (flamelayer, flamegrapher) = flame::layer(path);
subscriber.with(flamelayer).init();
Some(flamegrapher)
} else {
subscriber.init();
None
};
Ok(Self {
filter_handle,
flamegrapher,
})
}
/// Return the currently-active tracing filter.
pub fn filter(&self) -> String {
self.filter_handle
.with_current(|filter| filter.to_string())
.expect("the subscriber is not dropped before the component is")
}
/// Reload the currently-active filter with the supplied value.
///
/// This can be used to provide a dynamic tracing filter endpoint.
pub fn reload_filter(&mut self, filter: impl Into<EnvFilter>) {
self.filter_handle
.reload(filter)
.expect("the subscriber is not dropped before the component is");
}
}
impl std::fmt::Debug for Tracing {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
f.debug_struct("Tracing").finish()
}
}
impl<A: abscissa_core::Application> Component<A> for Tracing {
fn id(&self) -> abscissa_core::component::Id {
abscissa_core::component::Id::new("zebrad::components::tracing::component::Tracing")
}
fn version(&self) -> abscissa_core::Version {
abscissa_core::Version::parse("3.0.0-alpha.0").unwrap()
}
fn before_shutdown(&self, _kind: Shutdown) -> Result<(), FrameworkError> {
if let Some(ref grapher) = self.flamegrapher {
tracing::info!("writing flamegraph");
grapher
.write_flamegraph()
.map_err(|e| FrameworkErrorKind::ComponentError.context(e))?
}
Ok(())
}
}

View File

@ -0,0 +1,127 @@
//! An HTTP endpoint for dynamically setting tracing filters.
use std::net::SocketAddr;
use abscissa_core::{Component, FrameworkError};
use hyper::service::{make_service_fn, service_fn};
use hyper::{Body, Request, Response, Server};
use crate::{components::tokio::TokioComponent, config::ZebradConfig, prelude::*};
use super::Tracing;
/// Abscissa component which runs a tracing filter endpoint.
#[derive(Debug, Component)]
#[component(inject = "init_tokio(zebrad::components::tokio::TokioComponent)")]
pub struct TracingEndpoint {
addr: Option<SocketAddr>,
}
async fn read_filter(req: Request<Body>) -> Result<String, String> {
std::str::from_utf8(
&hyper::body::to_bytes(req.into_body())
.await
.map_err(|_| "Error reading body".to_owned())?,
)
.map(|s| s.to_owned())
.map_err(|_| "Filter must be UTF-8".to_owned())
}
impl TracingEndpoint {
/// Create the component.
pub fn new(config: &ZebradConfig) -> Result<Self, FrameworkError> {
Ok(Self {
addr: config.tracing.endpoint_addr,
})
}
pub fn init_tokio(&mut self, tokio_component: &TokioComponent) -> Result<(), FrameworkError> {
let addr = if let Some(addr) = self.addr {
addr
} else {
return Ok(());
};
info!("Initializing tracing endpoint");
let service =
make_service_fn(|_| async { Ok::<_, hyper::Error>(service_fn(request_handler)) });
tokio_component
.rt
.as_ref()
.expect("runtime should not be taken")
.spawn(async move {
// try_bind uses the tokio runtime, so we
// need to construct it inside the task.
let server = match Server::try_bind(&addr) {
Ok(s) => s,
Err(e) => {
error!("Could not open tracing endpoint listener");
error!("Error: {}", e);
return;
}
}
.serve(service);
if let Err(e) = server.await {
error!("Server error: {}", e);
}
});
Ok(())
}
}
#[instrument]
async fn request_handler(req: Request<Body>) -> Result<Response<Body>, hyper::Error> {
use hyper::{Method, StatusCode};
let rsp = match (req.method(), req.uri().path()) {
(&Method::GET, "/") => Response::new(Body::from(
r#"
This HTTP endpoint allows dynamic control of the filter applied to
tracing events.
To get the current filter, GET /filter:
curl -X GET localhost:3000/filter
To set the filter, POST the new filter string to /filter:
curl -X POST localhost:3000/filter -d "zebrad=trace"
"#,
)),
(&Method::GET, "/filter") => Response::builder()
.status(StatusCode::OK)
.body(Body::from(
app_reader()
.state()
.components
.get_downcast_ref::<Tracing>()
.expect("Tracing component should be available")
.filter(),
))
.expect("response with known status code cannot fail"),
(&Method::POST, "/filter") => match read_filter(req).await {
Ok(filter) => {
app_writer()
.state_mut()
.components
.get_downcast_mut::<Tracing>()
.expect("Tracing component should be available")
.reload_filter(filter);
Response::new(Body::from(""))
}
Err(e) => Response::builder()
.status(StatusCode::BAD_REQUEST)
.body(Body::from(e))
.expect("response with known status code cannot fail"),
},
_ => Response::builder()
.status(StatusCode::NOT_FOUND)
.body(Body::from(""))
.expect("response with known status cannot fail"),
};
Ok(rsp)
}

View File

@ -0,0 +1,45 @@
//! An HTTP endpoint for dynamically setting tracing filters.
use color_eyre::eyre::Report;
use std::{
fs::File,
io::{BufReader, BufWriter},
path::Path,
path::PathBuf,
};
use tracing::Subscriber;
use tracing_subscriber::{registry::LookupSpan, Layer};
pub struct Grapher {
guard: tracing_flame::FlushGuard<BufWriter<File>>,
path: PathBuf,
}
pub fn layer<S>(path_root: &Path) -> (impl Layer<S>, Grapher)
where
S: Subscriber + for<'span> LookupSpan<'span>,
{
let path = path_root.with_extension("folded");
let (layer, guard) = tracing_flame::FlameLayer::with_file(&path).unwrap();
let layer = layer.with_empty_samples(false).with_threads_collapsed(true);
let flamegrapher = Grapher { guard, path };
(layer, flamegrapher)
}
impl Grapher {
pub fn write_flamegraph(&self) -> Result<(), Report> {
self.guard.flush()?;
let out_path = self.path.with_extension("svg");
let inf = File::open(&self.path)?;
let reader = BufReader::new(inf);
let out = File::create(out_path)?;
let writer = BufWriter::new(out);
let mut opts = inferno::flamegraph::Options::default();
info!("writing flamegraph to disk...");
inferno::flamegraph::from_reader(&mut opts, reader, writer)?;
Ok(())
}
}

View File

@ -8,7 +8,6 @@ use std::{net::SocketAddr, path::PathBuf};
use serde::{Deserialize, Serialize};
use tracing_subscriber::EnvFilter;
use zebra_network::Config as NetworkSection;
use zebra_state::Config as StateSection;
@ -44,6 +43,9 @@ pub struct TracingSection {
/// and more details on the syntax can be found there or in the examples
/// below.
///
/// If no filter is specified (`None`), the filter is set to `info` if the
/// `-v` flag is given and `warn` if it is not given.
///
/// # Examples
///
/// `warn,zebrad=info,zebra_network=debug` sets a global `warn` level, an
@ -58,10 +60,15 @@ pub struct TracingSection {
/// verification of every 1000th block.
pub filter: Option<String>,
/// The endpoint address used for tracing.
pub endpoint_addr: SocketAddr,
/// The address used for an ad-hoc RPC endpoint allowing dynamic control of the tracing filter.
///
/// If this is set to None, the endpoint is disabled.
pub endpoint_addr: Option<SocketAddr>,
/// The path to write a flamegraph of tracing spans too.
/// Controls whether to write a flamegraph of tracing spans.
///
/// If this is set to None, flamegraphs are disabled. Otherwise, it specifies
/// an output file path, as described below.
///
/// This path is not used verbatim when writing out the flamegraph. This is
/// because the flamegraph is written out as two parts. First the flamegraph
@ -76,37 +83,21 @@ pub struct TracingSection {
///
/// # Example
///
/// Given `flamegraph = "flamegraph"` we will generate a `flamegraph.svg`
/// and a `flamegraph.folded` file in the current directory.
/// Given `flamegraph = "flamegraph"` we will generate a `flamegraph.svg` and
/// a `flamegraph.folded` file in the current directory.
///
/// If you provide a path with an extension the extension will be ignored and
/// replaced with `.folded` and `.svg` for the respective files.
pub flamegraph: Option<PathBuf>,
}
impl TracingSection {
pub fn populated() -> Self {
Self {
filter: Some("info".to_owned()),
endpoint_addr: "0.0.0.0:3000".parse().unwrap(),
flamegraph: None,
}
}
/// Constructs an EnvFilter for use in our tracing subscriber.
///
/// The env filter controls filtering of spans and events, but not how
/// they're emitted. Creating an env filter alone doesn't enable logging, it
/// needs to be used in conjunction with other layers like a fmt subscriber,
/// for logs, or an error layer, for SpanTraces.
pub fn env_filter(&self) -> EnvFilter {
self.filter.as_deref().unwrap_or("info").into()
}
}
impl Default for TracingSection {
fn default() -> Self {
Self::populated()
Self {
filter: None,
endpoint_addr: None,
flamegraph: None,
}
}
}
@ -114,29 +105,16 @@ impl Default for TracingSection {
#[derive(Clone, Debug, Deserialize, Serialize)]
#[serde(deny_unknown_fields, default)]
pub struct MetricsSection {
/// The endpoint address used for metrics.
pub endpoint_addr: SocketAddr,
/// The address used for the Prometheus metrics endpoint.
///
/// The endpoint is disabled if this is set to `None`.
pub endpoint_addr: Option<SocketAddr>,
}
impl Default for MetricsSection {
fn default() -> Self {
Self {
endpoint_addr: "0.0.0.0:9999".parse().unwrap(),
endpoint_addr: None,
}
}
}
#[cfg(test)]
mod test {
use color_eyre::eyre::Result;
#[test]
fn test_toml_ser() -> Result<()> {
let default_config = super::ZebradConfig::default();
println!("Default config: {:?}", default_config);
println!("Toml:\n{}", toml::Value::try_from(&default_config)?);
Ok(())
}
}

View File

@ -8,21 +8,7 @@ use color_eyre::eyre::Result;
use std::time::Duration;
use zebra_test::prelude::*;
// Todo: The following 3 helper functions can probably be abstracted into one
pub fn get_child_single_arg(arg: &str) -> Result<(zebra_test::command::TestChild, impl Drop)> {
let (mut cmd, guard) = test_cmd(env!("CARGO_BIN_EXE_zebrad"))?;
Ok((
cmd.arg(arg)
.stdout(Stdio::piped())
.stderr(Stdio::piped())
.spawn2()
.unwrap(),
guard,
))
}
pub fn get_child_multi_args(args: &[&str]) -> Result<(zebra_test::command::TestChild, impl Drop)> {
pub fn get_child(args: &[&str]) -> Result<(zebra_test::command::TestChild, impl Drop)> {
let (mut cmd, guard) = test_cmd(env!("CARGO_BIN_EXE_zebrad"))?;
Ok((
@ -35,23 +21,11 @@ pub fn get_child_multi_args(args: &[&str]) -> Result<(zebra_test::command::TestC
))
}
pub fn get_child_no_args() -> Result<(zebra_test::command::TestChild, impl Drop)> {
let (mut cmd, guard) = test_cmd(env!("CARGO_BIN_EXE_zebrad"))?;
Ok((
cmd.stdout(Stdio::piped())
.stderr(Stdio::piped())
.spawn2()
.unwrap(),
guard,
))
}
#[test]
fn generate_no_args() -> Result<()> {
zebra_test::init();
let (child, _guard) = get_child_single_arg("generate")?;
let (child, _guard) = get_child(&["generate"])?;
let output = child.wait_with_output()?;
let output = output.assert_success()?;
@ -65,22 +39,22 @@ fn generate_args() -> Result<()> {
zebra_test::init();
// unexpected free argument `argument`
let (child, _guard) = get_child_multi_args(&["generate", "argument"])?;
let (child, _guard) = get_child(&["generate", "argument"])?;
let output = child.wait_with_output()?;
output.assert_failure()?;
// unrecognized option `-f`
let (child, _guard) = get_child_multi_args(&["generate", "-f"])?;
let (child, _guard) = get_child(&["generate", "-f"])?;
let output = child.wait_with_output()?;
output.assert_failure()?;
// missing argument to option `-o`
let (child, _guard) = get_child_multi_args(&["generate", "-o"])?;
let (child, _guard) = get_child(&["generate", "-o"])?;
let output = child.wait_with_output()?;
output.assert_failure()?;
// Valid
let (child, _guard) = get_child_multi_args(&["generate", "-o", "file.yaml"])?;
let (child, _guard) = get_child(&["generate", "-o", "file.yaml"])?;
let output = child.wait_with_output()?;
output.assert_success()?;
@ -93,7 +67,7 @@ fn generate_args() -> Result<()> {
fn help_no_args() -> Result<()> {
zebra_test::init();
let (child, _guard) = get_child_single_arg("help")?;
let (child, _guard) = get_child(&["help"])?;
let output = child.wait_with_output()?;
let output = output.assert_success()?;
@ -107,12 +81,12 @@ fn help_args() -> Result<()> {
zebra_test::init();
// The subcommand "argument" wasn't recognized.
let (child, _guard) = get_child_multi_args(&["help", "argument"])?;
let (child, _guard) = get_child(&["help", "argument"])?;
let output = child.wait_with_output()?;
output.assert_failure()?;
// option `-f` does not accept an argument
let (child, _guard) = get_child_multi_args(&["help", "-f"])?;
let (child, _guard) = get_child(&["help", "-f"])?;
let output = child.wait_with_output()?;
output.assert_failure()?;
@ -124,7 +98,7 @@ fn revhex_args() -> Result<()> {
zebra_test::init();
// Valid
let (child, _guard) = get_child_multi_args(&["revhex", "33eeff55"])?;
let (child, _guard) = get_child(&["revhex", "33eeff55"])?;
let output = child.wait_with_output()?;
let output = output.assert_success()?;
@ -136,7 +110,7 @@ fn revhex_args() -> Result<()> {
fn seed_no_args() -> Result<()> {
zebra_test::init();
let (mut child, _guard) = get_child_single_arg("seed")?;
let (mut child, _guard) = get_child(&["-v", "seed"])?;
// Run the program and kill it at 1 second
std::thread::sleep(Duration::from_secs(1));
@ -158,17 +132,17 @@ fn seed_args() -> Result<()> {
zebra_test::init();
// unexpected free argument `argument`
let (child, _guard) = get_child_multi_args(&["seed", "argument"])?;
let (child, _guard) = get_child(&["seed", "argument"])?;
let output = child.wait_with_output()?;
output.assert_failure()?;
// unrecognized option `-f`
let (child, _guard) = get_child_multi_args(&["seed", "-f"])?;
let (child, _guard) = get_child(&["seed", "-f"])?;
let output = child.wait_with_output()?;
output.assert_failure()?;
// unexpected free argument `start`
let (child, _guard) = get_child_multi_args(&["seed", "start"])?;
let (child, _guard) = get_child(&["seed", "start"])?;
let output = child.wait_with_output()?;
output.assert_failure()?;
@ -178,7 +152,7 @@ fn seed_args() -> Result<()> {
fn start_no_args() -> Result<()> {
zebra_test::init();
let (mut child, _guard) = get_child_single_arg("start")?;
let (mut child, _guard) = get_child(&["-v", "start"])?;
// Run the program and kill it at 1 second
std::thread::sleep(Duration::from_secs(1));
@ -199,7 +173,7 @@ fn start_args() -> Result<()> {
zebra_test::init();
// Any free argument is valid
let (mut child, _guard) = get_child_multi_args(&["start", "argument"])?;
let (mut child, _guard) = get_child(&["start", "argument"])?;
// Run the program and kill it at 1 second
std::thread::sleep(Duration::from_secs(1));
child.kill()?;
@ -211,7 +185,7 @@ fn start_args() -> Result<()> {
output.assert_failure()?;
// unrecognized option `-f`
let (child, _guard) = get_child_multi_args(&["start", "-f"])?;
let (child, _guard) = get_child(&["start", "-f"])?;
let output = child.wait_with_output()?;
output.assert_failure()?;
@ -222,7 +196,7 @@ fn start_args() -> Result<()> {
fn app_no_args() -> Result<()> {
zebra_test::init();
let (child, _guard) = get_child_no_args()?;
let (child, _guard) = get_child(&[])?;
let output = child.wait_with_output()?;
let output = output.assert_success()?;
@ -235,7 +209,7 @@ fn app_no_args() -> Result<()> {
fn version_no_args() -> Result<()> {
zebra_test::init();
let (child, _guard) = get_child_single_arg("version")?;
let (child, _guard) = get_child(&["version"])?;
let output = child.wait_with_output()?;
let output = output.assert_success()?;
@ -249,12 +223,12 @@ fn version_args() -> Result<()> {
zebra_test::init();
// unexpected free argument `argument`
let (child, _guard) = get_child_multi_args(&["version", "argument"])?;
let (child, _guard) = get_child(&["version", "argument"])?;
let output = child.wait_with_output()?;
output.assert_failure()?;
// unrecognized option `-f`
let (child, _guard) = get_child_multi_args(&["version", "-f"])?;
let (child, _guard) = get_child(&["version", "-f"])?;
let output = child.wait_with_output()?;
output.assert_failure()?;