From 162b37fe8d0451040c96eab426ad3be3f18d0370 Mon Sep 17 00:00:00 2001 From: Deirdre Connolly Date: Mon, 9 Sep 2019 16:05:42 -0400 Subject: [PATCH] Tracing endpoint (#3) * Add a TracingConfig and some components Co-authored-by: Deirdre Connolly * Restructure, use dependency injection, initialize tracing * Start a placeholder loop in start command * Add hyper alpha.1, bump tokio to alpha.4 * Hello world endpoint using async/await from hyper 0.13 alpha Also cleaned up some linter messages. Co-authored-by: Henry de Valence * Update to tracing_subscriber 0.1 * fmt * add rust-toolchain * Remove hyper::Version import * wip: start filter_handler impl * Add .rustfmt.toml * rustfmt * Tidy up .rustfmt.toml * Add filter reloading handling. * bump toolchain * Remove generated hello world acceptance tests. These test the behaviour of the autogenerated binary and work as examples of how to test the behaviour of abscissa binaries. Since we don't print "Hello World" any more, they fail, but we don't yet have replacement behaviour to add tests for, so they're removed for now. * Clean up config file handling with Option::and_then. --- .rustfmt.toml | 66 ++++++++++++++ rust-toolchain | 1 + zebrad/Cargo.toml | 8 ++ zebrad/src/application.rs | 23 ++++- zebrad/src/commands.rs | 21 ++--- zebrad/src/commands/start.rs | 33 +++++-- zebrad/src/commands/version.rs | 6 +- zebrad/src/components.rs | 2 + zebrad/src/components/tokio.rs | 19 ++++ zebrad/src/components/tracing.rs | 144 +++++++++++++++++++++++++++++++ zebrad/src/config.rs | 20 ++--- zebrad/src/lib.rs | 8 +- zebrad/src/prelude.rs | 5 +- zebrad/tests/acceptance.rs | 53 ------------ 14 files changed, 313 insertions(+), 96 deletions(-) create mode 100644 .rustfmt.toml create mode 100644 rust-toolchain create mode 100644 zebrad/src/components.rs create mode 100644 zebrad/src/components/tokio.rs create mode 100644 zebrad/src/components/tracing.rs diff --git a/.rustfmt.toml b/.rustfmt.toml new file mode 100644 index 000000000..ab694ba49 --- /dev/null +++ b/.rustfmt.toml @@ -0,0 +1,66 @@ +max_width = 100 +hard_tabs = false +tab_spaces = 4 +newline_style = "Auto" +use_small_heuristics = "Default" +indent_style = "Block" +wrap_comments = false +format_code_in_doc_comments = false +comment_width = 80 +normalize_comments = false +normalize_doc_attributes = false +#license_template_path = "" +format_strings = false +format_macro_matchers = false +format_macro_bodies = true +empty_item_single_line = true +struct_lit_single_line = true +fn_single_line = false +where_single_line = false +imports_indent = "Block" +imports_layout = "Mixed" +merge_imports = false +reorder_imports = true +reorder_modules = true +reorder_impl_items = false +type_punctuation_density = "Wide" +space_before_colon = false +space_after_colon = true +spaces_around_ranges = false +binop_separator = "Front" +remove_nested_parens = true +combine_control_expr = true +overflow_delimited_expr = false +struct_field_align_threshold = 0 +enum_discrim_align_threshold = 0 +match_arm_blocks = true +force_multiline_blocks = false +fn_args_layout = "Tall" +brace_style = "SameLineWhere" +control_brace_style = "AlwaysSameLine" +trailing_semicolon = true +trailing_comma = "Vertical" +match_block_trailing_comma = false +blank_lines_upper_bound = 1 +blank_lines_lower_bound = 0 +edition = "2018" +version = "One" +inline_attribute_width = 0 +merge_derives = true +use_try_shorthand = false +use_field_init_shorthand = false +force_explicit_abi = true +condense_wildcard_suffixes = false +color = "Auto" +#required_version = "1.3.0" +unstable_features = false +disable_all_formatting = false +skip_children = false +hide_parse_errors = false +error_on_line_overflow = false +error_on_unformatted = false +report_todo = "Never" +report_fixme = "Never" +ignore = [] +emit_mode = "Files" +make_backup = false diff --git a/rust-toolchain b/rust-toolchain new file mode 100644 index 000000000..6002098eb --- /dev/null +++ b/rust-toolchain @@ -0,0 +1 @@ +nightly-2019-09-05 diff --git a/zebrad/Cargo.toml b/zebrad/Cargo.toml index 266b50e61..85875077d 100644 --- a/zebrad/Cargo.toml +++ b/zebrad/Cargo.toml @@ -10,6 +10,14 @@ failure = "0.1" gumdrop = "0.6" lazy_static = "1" serde = { version = "1", features = ["serde_derive"] } +toml = "0.5" +tokio = "=0.2.0-alpha.4" +tracing = "0.1" +tracing-subscriber = "0.1" +tracing-log = "=0.0.1-alpha.2" +hyper = "=0.13.0-alpha.1" +futures-core-preview = { version = "=0.3.0-alpha.18" } +futures-util-preview = { version = "=0.3.0-alpha.18" } [dev-dependencies.abscissa_core] version = "0.3.0" diff --git a/zebrad/src/application.rs b/zebrad/src/application.rs index 0d864bde6..ed1ce6512 100644 --- a/zebrad/src/application.rs +++ b/zebrad/src/application.rs @@ -2,7 +2,7 @@ use crate::{commands::ZebradCmd, config::ZebradConfig}; use abscissa_core::{ - application, config, logging, Application, EntryPoint, FrameworkError, StandardPaths, + application, config, logging, Application, Component, EntryPoint, FrameworkError, StandardPaths, }; use lazy_static::lazy_static; @@ -78,13 +78,32 @@ impl Application for ZebradApp { &mut self.state } + /// Override the provided impl to skip the default logging component. + /// + /// We want to use tracing as the log subscriber in our tracing component, + /// so only initialize the abscissa Terminal component. + fn framework_components( + &mut self, + _command: &Self::Cmd, + ) -> Result>>, FrameworkError> { + use abscissa_core::terminal::{component::Terminal, ColorChoice}; + // XXX abscissa uses self.term_colors(command), check if we should match + let terminal = Terminal::new(ColorChoice::Auto); + Ok(vec![Box::new(terminal)]) + } + /// Register all components used by this application. /// /// If you would like to add additional components to your application /// beyond the default ones provided by the framework, this is the place /// to do so. fn register_components(&mut self, command: &Self::Cmd) -> Result<(), FrameworkError> { - let components = self.framework_components(command)?; + use crate::components::{tokio::TokioComponent, tracing::TracingEndpoint}; + + let mut components = self.framework_components(command)?; + components.push(Box::new(TokioComponent::new()?)); + components.push(Box::new(TracingEndpoint::new()?)); + self.state.components.register(components) } diff --git a/zebrad/src/commands.rs b/zebrad/src/commands.rs index 11c18d75b..d3413ea98 100644 --- a/zebrad/src/commands.rs +++ b/zebrad/src/commands.rs @@ -43,16 +43,14 @@ pub enum ZebradCmd { impl Configurable for ZebradCmd { /// Location of the configuration file fn config_path(&self) -> Option { - // Check if the config file exists, and if it does not, ignore it. - // If you'd like for a missing configuration file to be a hard error - // instead, always return `Some(CONFIG_FILE)` here. - let filename = PathBuf::from(CONFIG_FILE); + let filename = std::env::current_dir().ok().map(|mut dir_path| { + dir_path.push(CONFIG_FILE); + dir_path + }); - if filename.exists() { - Some(filename) - } else { - None - } + let if_exists = |f: PathBuf| if f.exists() { Some(f) } else { None }; + + filename.and_then(|f| if_exists(f)) } /// Apply changes to the config after it's been loaded, e.g. overriding @@ -60,10 +58,7 @@ impl Configurable for ZebradCmd { /// /// This can be safely deleted if you don't want to override config /// settings from command-line options. - fn process_config( - &self, - config: ZebradConfig, - ) -> Result { + fn process_config(&self, config: ZebradConfig) -> Result { match self { ZebradCmd::Start(cmd) => cmd.override_config(config), _ => Ok(config), diff --git a/zebrad/src/commands/start.rs b/zebrad/src/commands/start.rs index 137da8202..bf5e47183 100644 --- a/zebrad/src/commands/start.rs +++ b/zebrad/src/commands/start.rs @@ -16,16 +16,34 @@ use abscissa_core::{config, Command, FrameworkError, Options, Runnable}; /// #[derive(Command, Debug, Options)] pub struct StartCmd { - /// To whom are we saying hello? + /// Filter strings #[options(free)] - recipient: Vec, + filters: Vec, } impl Runnable for StartCmd { /// Start the application. fn run(&self) { + warn!("starting application"); let config = app_config(); - println!("Hello, {}!", &config.hello.recipient); + println!("filter: {}!", &config.tracing.filter); + + let default_config = ZebradConfig::default(); + println!("Default config: {:?}", default_config); + + println!("Toml:\n{}", toml::to_string(&default_config).unwrap()); + + info!("Starting placeholder loop"); + + use crate::components::tokio::TokioComponent; + + app_reader() + .state() + .components + .get_downcast_ref::() + .expect("TokioComponent should be available") + .rt + .block_on(tokio::future::pending::<()>()); } } @@ -33,12 +51,9 @@ impl config::Override for StartCmd { // Process the given command line options, overriding settings from // a configuration file using explicit flags taken from command-line // arguments. - fn override_config( - &self, - mut config: ZebradConfig, - ) -> Result { - if !self.recipient.is_empty() { - config.hello.recipient = self.recipient.join(" "); + fn override_config(&self, mut config: ZebradConfig) -> Result { + if !self.filters.is_empty() { + config.tracing.filter = self.filters.join(","); } Ok(config) diff --git a/zebrad/src/commands/version.rs b/zebrad/src/commands/version.rs index dac099573..c248ae9df 100644 --- a/zebrad/src/commands/version.rs +++ b/zebrad/src/commands/version.rs @@ -12,10 +12,6 @@ pub struct VersionCmd {} impl Runnable for VersionCmd { /// Print version message fn run(&self) { - println!( - "{} {}", - ZebradCmd::name(), - ZebradCmd::version() - ); + println!("{} {}", ZebradCmd::name(), ZebradCmd::version()); } } diff --git a/zebrad/src/components.rs b/zebrad/src/components.rs new file mode 100644 index 000000000..a5c36e7d2 --- /dev/null +++ b/zebrad/src/components.rs @@ -0,0 +1,2 @@ +pub mod tokio; +pub mod tracing; diff --git a/zebrad/src/components/tokio.rs b/zebrad/src/components/tokio.rs new file mode 100644 index 000000000..0487585e6 --- /dev/null +++ b/zebrad/src/components/tokio.rs @@ -0,0 +1,19 @@ +//! A component owning the Tokio runtime. + +use abscissa_core::{Component, FrameworkError}; + +use tokio::runtime::Runtime; + +/// An Abscissa component which owns a Tokio runtime. +#[derive(Component, Debug)] +pub struct TokioComponent { + pub rt: Runtime, +} + +impl TokioComponent { + pub fn new() -> Result { + Ok(Self { + rt: Runtime::new().unwrap(), + }) + } +} diff --git a/zebrad/src/components/tracing.rs b/zebrad/src/components/tracing.rs new file mode 100644 index 000000000..1455deb4d --- /dev/null +++ b/zebrad/src/components/tracing.rs @@ -0,0 +1,144 @@ +//! An HTTP endpoint for dynamically setting tracing filters. + +use crate::components::tokio::TokioComponent; + +use abscissa_core::{err, Component, FrameworkError, FrameworkErrorKind}; + +use hyper::service::{make_service_fn, service_fn}; +use hyper::{Body, Request, Response, Server}; + +use tracing::Subscriber; +use tracing_log::LogTracer; +use tracing_subscriber::{filter::Filter, reload::Handle, FmtSubscriber}; + +/// Abscissa component which runs a tracing filter endpoint. +#[derive(Component)] +#[component(inject = "init_tokio(zebrad::components::tokio::TokioComponent)")] +// XXX ideally this would be TracingEndpoint +// but this doesn't seem to play well with derive(Component) +pub struct TracingEndpoint { + filter_handle: Handle, +} + +impl ::std::fmt::Debug for TracingEndpoint { + fn fmt(&self, f: &mut ::std::fmt::Formatter) -> Result<(), ::std::fmt::Error> { + // Debug is required by Component, can't be derived as a Handle is not Debug + write!(f, "TracingEndpoint") + } +} + +impl TracingEndpoint { + /// Create the component. + pub fn new() -> Result { + // Set the global logger for the log crate to emit tracing events. + // XXX this is only required if we have a dependency that uses log; + // currently this is maybe only abscissa itself? + LogTracer::init().map_err(|e| { + err!( + FrameworkErrorKind::ComponentError, + "could not set log subscriber: {}", + e + ) + })?; + + let builder = FmtSubscriber::builder() + .with_ansi(true) + // Set the initial filter from the RUST_LOG env variable + // XXX pull from config file? + .with_filter(Filter::from_default_env()) + .with_filter_reloading(); + let filter_handle = builder.reload_handle(); + let subscriber = builder.finish(); + + // Set that subscriber to be the global tracing subscriber + tracing::subscriber::set_global_default(subscriber).map_err(|e| { + err!( + FrameworkErrorKind::ComponentError, + "could not set tracing subscriber: {}", + e + ) + })?; + + Ok(Self { filter_handle }) + } + + /// Do setup after receiving a tokio runtime. + pub fn init_tokio(&mut self, tokio_component: &TokioComponent) -> Result<(), FrameworkError> { + info!("Initializing tracing endpoint"); + + // Clone the filter handle so it can be moved into make_service_fn closure + let handle = self.filter_handle.clone(); + let service = make_service_fn(move |_| { + // Clone again to move into the service_fn closure + let handle = handle.clone(); + async move { + Ok::<_, hyper::Error>(service_fn(move |req| filter_handler(handle.clone(), req))) + } + }); + + // XXX load tracing addr from config + let addr = "127.0.0.1:3000".parse().unwrap(); + + let server = Server::bind(&addr).serve(service); + + tokio_component.rt.spawn(async { + if let Err(e) = server.await { + error!("Server error: {}", e); + } + }); + + Ok(()) + } +} + +fn reload_filter_from_chunk( + handle: Handle, + chunk: hyper::Chunk, +) -> Result<(), String> { + let bytes = chunk.into_bytes(); + let body = std::str::from_utf8(bytes.as_ref()).map_err(|e| format!("{}", e))?; + trace!(request.body = ?body); + let filter = body.parse::().map_err(|e| format!("{}", e))?; + handle.reload(filter).map_err(|e| format!("{}", e)) +} + +async fn filter_handler( + handle: Handle, + req: Request, +) -> Result, hyper::Error> { + use futures_util::TryStreamExt; + use hyper::{Method, StatusCode}; + + // We can't use #[instrument] because Handle<_,_> is not Debug, + // so we create a span manually. + let handler_span = + info_span!("filter_handler", method = ?req.method(), path = ?req.uri().path()); + let _enter = handler_span.enter(); // dropping _enter closes the span + + 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 set the filter, POST it to /filter: + +curl -X POST localhost:3000/filter -d "zebrad=trace" +"#, + )), + (&Method::POST, "/filter") => { + // Combine all HTTP request chunks into one + let whole_chunk = req.into_body().try_concat().await?; + match reload_filter_from_chunk(handle, whole_chunk) { + Err(e) => Response::builder() + .status(StatusCode::BAD_REQUEST) + .body(Body::from(e)) + .expect("response with known status code cannot fail"), + Ok(()) => Response::new(Body::from("")), + } + } + _ => Response::builder() + .status(StatusCode::NOT_FOUND) + .body(Body::from("")) + .expect("response with known status cannot fail"), + }; + Ok(rsp) +} diff --git a/zebrad/src/config.rs b/zebrad/src/config.rs index 66ab61d68..ee632b06b 100644 --- a/zebrad/src/config.rs +++ b/zebrad/src/config.rs @@ -11,8 +11,8 @@ use serde::{Deserialize, Serialize}; #[derive(Clone, Config, Debug, Deserialize, Serialize)] #[serde(deny_unknown_fields)] pub struct ZebradConfig { - /// An example configuration section - pub hello: ExampleSection, + /// Tracing configuration + pub tracing: TracingSection, } /// Default configuration settings. @@ -22,25 +22,23 @@ pub struct ZebradConfig { impl Default for ZebradConfig { fn default() -> Self { Self { - hello: ExampleSection::default(), + tracing: TracingSection::default(), } } } -/// Example configuration section. -/// -/// Delete this and replace it with your actual configuration structs. +/// Tracing configuration section. #[derive(Clone, Debug, Deserialize, Serialize)] #[serde(deny_unknown_fields)] -pub struct ExampleSection { - /// Example configuration value - pub recipient: String, +pub struct TracingSection { + /// The filter used for tracing events. + pub filter: String, } -impl Default for ExampleSection { +impl Default for TracingSection { fn default() -> Self { Self { - recipient: "world".to_owned(), + filter: "info".to_owned(), } } } diff --git a/zebrad/src/lib.rs b/zebrad/src/lib.rs index 00ddc5bf3..fe8da8a2f 100644 --- a/zebrad/src/lib.rs +++ b/zebrad/src/lib.rs @@ -4,8 +4,14 @@ //! //! [Abscissa]: https://github.com/iqlusioninc/abscissa -#![deny(warnings, missing_docs, trivial_casts, unused_qualifications)] +//#![deny(warnings, missing_docs, trivial_casts, unused_qualifications)] #![forbid(unsafe_code)] +#![feature(async_await)] + +#[macro_use] +extern crate tracing; + +mod components; pub mod application; pub mod commands; diff --git a/zebrad/src/prelude.rs b/zebrad/src/prelude.rs index 220548fa1..3d5938403 100644 --- a/zebrad/src/prelude.rs +++ b/zebrad/src/prelude.rs @@ -7,5 +7,6 @@ pub use crate::application::{app_config, app_reader, app_writer}; /// Commonly used Abscissa traits pub use abscissa_core::{Application, Command, Runnable}; -/// Logging macros -pub use abscissa_core::log::{debug, error, info, log, log_enabled, trace, warn}; +// These are disabled because we use tracing. +// Logging macros +//pub use abscissa_core::log::{debug, error, info, log, log_enabled, trace, warn}; diff --git a/zebrad/tests/acceptance.rs b/zebrad/tests/acceptance.rs index d0c00fdee..786868f1b 100644 --- a/zebrad/tests/acceptance.rs +++ b/zebrad/tests/acceptance.rs @@ -11,7 +11,6 @@ #![forbid(unsafe_code)] use abscissa_core::testing::prelude::*; -use zebrad::config::ZebradConfig; use lazy_static::lazy_static; lazy_static! { @@ -24,58 +23,6 @@ lazy_static! { pub static ref RUNNER: CmdRunner = CmdRunner::default(); } -/// Use `ZebradConfig::default()` value if no config or args -#[test] -fn start_no_args() { - let mut runner = RUNNER.clone(); - let mut cmd = runner.arg("start").capture_stdout().run(); - cmd.stdout().expect_line("Hello, world!"); - cmd.wait().unwrap().expect_success(); -} - -/// Use command-line argument value -#[test] -fn start_with_args() { - let mut runner = RUNNER.clone(); - let mut cmd = runner - .args(&["start", "acceptance", "test"]) - .capture_stdout() - .run(); - - cmd.stdout().expect_line("Hello, acceptance test!"); - cmd.wait().unwrap().expect_success(); -} - -/// Use configured value -#[test] -fn start_with_config_no_args() { - let mut config = ZebradConfig::default(); - config.hello.recipient = "configured recipient".to_owned(); - let expected_line = format!("Hello, {}!", &config.hello.recipient); - - let mut runner = RUNNER.clone(); - let mut cmd = runner.config(&config).arg("start").capture_stdout().run(); - cmd.stdout().expect_line(&expected_line); - cmd.wait().unwrap().expect_success(); -} - -/// Override configured value with command-line argument -#[test] -fn start_with_config_and_args() { - let mut config = ZebradConfig::default(); - config.hello.recipient = "configured recipient".to_owned(); - - let mut runner = RUNNER.clone(); - let mut cmd = runner - .config(&config) - .args(&["start", "acceptance", "test"]) - .capture_stdout() - .run(); - - cmd.stdout().expect_line("Hello, acceptance test!"); - cmd.wait().unwrap().expect_success(); -} - /// Example of a test which matches a regular expression #[test] fn version_no_args() {