From 283d6691c67d077512a8683b203bdb629e9817e3 Mon Sep 17 00:00:00 2001 From: alamb Date: Mon, 29 Jun 2020 08:45:31 -0400 Subject: [PATCH 1/2] feat: enable rpc debug tracing, tweaked logging levels, respect RUST_FMT env var --- Cargo.lock | 2 ++ Cargo.toml | 3 +++ src/main.rs | 55 ++++++++++++++++++++++++++++++++++++++++----------- src/rpc.rs | 27 ++++++++++++++++++++++++- src/server.rs | 3 ++- 5 files changed, 76 insertions(+), 14 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index f1462ccce5..c2e8fa0664 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -662,6 +662,8 @@ dependencies = [ "tempfile", "tokio", "tonic 0.2.1", + "tracing", + "tracing-futures", ] [[package]] diff --git a/Cargo.toml b/Cargo.toml index 1d6e8fd649..dcdd325aed 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -57,6 +57,9 @@ num_cpus = "1.11.1" tonic = "0.2.0" prost = "0.6.1" prost-types = "0.6.1" +tracing = "0.1" +tracing-futures="0.2.4" + crc32fast = "1.2.0" num = "0.2.1" diff --git a/src/main.rs b/src/main.rs index 3ab267e9a9..29b7d0a2d8 100644 --- a/src/main.rs +++ b/src/main.rs @@ -35,6 +35,9 @@ Examples: # Run the Delorean server with extra verbose logging delorean -v + # Run delorean with full debug logging specified with RUST_LOG + RUST_LOG=debug delorean + # converts line protocol formatted data in temperature.lp to out.parquet delorean convert temperature.lp out.parquet @@ -87,20 +90,13 @@ Examples: ), ) .subcommand(SubCommand::with_name("server").about("Runs in server mode (default)")) - .arg( - Arg::with_name("verbose") - .short("v") - .long("verbose") - .help("Enables verbose output"), - ) + .arg(Arg::with_name("verbose").short("v").long("verbose").help( + "Enables verbose logging. You can also set log level via \ + the environment variable RUST_LOG=", + )) .get_matches(); - if matches.is_present("verbose") { - std::env::set_var("RUST_LOG", "delorean=debug,hyper=info"); - } else { - std::env::set_var("RUST_LOG", "delorean=info,hyper=info"); - } - env_logger::init(); + setup_logging(matches.is_present("verbose")); match matches.subcommand() { ("convert", Some(sub_matches)) => { @@ -146,3 +142,38 @@ Examples: } } } + +/// Defauly debug level is debug for everything except +/// some especially noisy low level libraries +const DEFAULT_DEBUG_LOG_LEVEL: &str = "debug,h2=info"; + +// Default log level is info level for all components +const DEFAULT_LOG_LEVEL: &str = "info"; + +/// Configures logging in the following precidence: +/// +/// 1. If RUST_LOG environment variable is set, use that value +/// 2. if `verbose_requested`, use DEFAULT_DEBUG_LOG_LEVEL +/// 3. otherwise, use DEFAULT_LOGL_LEVEL +fn setup_logging(verbose_requested: bool) { + let rust_log_env = std::env::var("RUST_LOG"); + + if verbose_requested { + match rust_log_env { + Ok(lvl) => { + eprintln!( + "WARNING: Using RUST_LOG='{}' environment, ignoring request for -v", + lvl + ); + } + Err(_) => std::env::set_var("RUST_LOG", DEFAULT_DEBUG_LOG_LEVEL), + } + } else { + match rust_log_env { + Ok(_) => {} + Err(_) => std::env::set_var("RUST_LOG", DEFAULT_LOG_LEVEL), + } + } + + env_logger::init(); +} diff --git a/src/rpc.rs b/src/rpc.rs index 89afa2103c..7337c48600 100644 --- a/src/rpc.rs +++ b/src/rpc.rs @@ -1,3 +1,9 @@ +//! This module contains gRPC service implementatations + +// Something about how `tracing::instrument` works triggers a clippy +// warning about complex types +#![allow(clippy::type_complexity)] + use delorean::generated_types::{ delorean_server::Delorean, measurement_fields_response::MessageField, @@ -26,12 +32,14 @@ use tonic::Status; use crate::server::App; +#[derive(Debug)] pub struct GrpcServer { pub app: Arc, } #[tonic::async_trait] impl Delorean for GrpcServer { + #[tracing::instrument(level = "debug")] async fn create_bucket( &self, req: tonic::Request, @@ -55,6 +63,9 @@ impl Delorean for GrpcServer { Ok(tonic::Response::new(CreateBucketResponse {})) } + // Something in instrument is causing lint warnings about unused braces + #[allow(unused_braces)] + #[tracing::instrument(level = "debug")] async fn delete_bucket( &self, _req: tonic::Request, @@ -62,6 +73,7 @@ impl Delorean for GrpcServer { Ok(tonic::Response::new(DeleteBucketResponse {})) } + #[tracing::instrument(level = "debug")] async fn get_buckets( &self, req: tonic::Request, @@ -174,6 +186,7 @@ impl GrpcInputs for MeasurementFieldsRequest { impl Storage for GrpcServer { type ReadFilterStream = mpsc::Receiver>; + #[tracing::instrument(level = "debug")] async fn read_filter( &self, req: tonic::Request, @@ -210,6 +223,7 @@ impl Storage for GrpcServer { type ReadGroupStream = mpsc::Receiver>; + #[tracing::instrument(level = "debug")] async fn read_group( &self, req: tonic::Request, @@ -256,6 +270,7 @@ impl Storage for GrpcServer { type TagKeysStream = mpsc::Receiver>; + #[tracing::instrument(level = "debug")] async fn tag_keys( &self, req: tonic::Request, @@ -306,6 +321,7 @@ impl Storage for GrpcServer { type TagValuesStream = mpsc::Receiver>; + #[tracing::instrument(level = "debug")] async fn tag_values( &self, req: tonic::Request, @@ -360,15 +376,19 @@ impl Storage for GrpcServer { Ok(tonic::Response::new(rx)) } + // Something in instrument is causing lint warnings about unused braces + #[allow(unused_braces)] + #[tracing::instrument(level = "debug")] async fn capabilities( &self, - _: tonic::Request<()>, + req: tonic::Request<()>, ) -> Result, Status> { Err(Status::unimplemented("Not yet implemented")) } type MeasurementNamesStream = mpsc::Receiver>; + #[tracing::instrument(level = "debug")] async fn measurement_names( &self, req: tonic::Request, @@ -422,6 +442,7 @@ impl Storage for GrpcServer { type MeasurementTagKeysStream = mpsc::Receiver>; + #[tracing::instrument(level = "debug")] async fn measurement_tag_keys( &self, req: tonic::Request, @@ -483,6 +504,7 @@ impl Storage for GrpcServer { type MeasurementTagValuesStream = mpsc::Receiver>; + #[tracing::instrument(level = "debug")] async fn measurement_tag_values( &self, req: tonic::Request, @@ -546,6 +568,7 @@ impl Storage for GrpcServer { type MeasurementFieldsStream = mpsc::Receiver>; + #[tracing::instrument(level = "debug")] async fn measurement_fields( &self, req: tonic::Request, @@ -617,6 +640,7 @@ impl Storage for GrpcServer { } } +#[tracing::instrument(level = "debug")] async fn send_series_filters( mut tx: mpsc::Sender>, app: Arc, @@ -681,6 +705,7 @@ async fn send_series_filters( Ok(()) } +#[tracing::instrument(level = "debug")] async fn send_groups( mut tx: mpsc::Sender>, app: Arc, diff --git a/src/server.rs b/src/server.rs index 1b44e6bacf..371b381d5e 100644 --- a/src/server.rs +++ b/src/server.rs @@ -1,6 +1,6 @@ #![deny(rust_2018_idioms)] -use log::{debug, info, warn}; +use tracing::{debug, info, warn}; use delorean::generated_types::{ delorean_server::DeloreanServer, storage_server::StorageServer, Bucket, TimestampRange, @@ -29,6 +29,7 @@ use serde::Deserialize; use crate::rpc::GrpcServer; +#[derive(Debug)] pub struct App { pub db: Database, } From 07e61cdf064efc5bb64c4c0b9ff5857bb048ca20 Mon Sep 17 00:00:00 2001 From: Andrew Lamb Date: Mon, 29 Jun 2020 16:35:07 -0400 Subject: [PATCH 2/2] fix: fix comments Co-authored-by: Carol (Nichols || Goulding) <193874+carols10cents@users.noreply.github.com> --- src/main.rs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/main.rs b/src/main.rs index 29b7d0a2d8..264c943be4 100644 --- a/src/main.rs +++ b/src/main.rs @@ -143,18 +143,18 @@ Examples: } } -/// Defauly debug level is debug for everything except +/// Default debug level is debug for everything except /// some especially noisy low level libraries const DEFAULT_DEBUG_LOG_LEVEL: &str = "debug,h2=info"; // Default log level is info level for all components const DEFAULT_LOG_LEVEL: &str = "info"; -/// Configures logging in the following precidence: +/// Configures logging in the following precedence: /// /// 1. If RUST_LOG environment variable is set, use that value /// 2. if `verbose_requested`, use DEFAULT_DEBUG_LOG_LEVEL -/// 3. otherwise, use DEFAULT_LOGL_LEVEL +/// 3. otherwise, use DEFAULT_LOG_LEVEL fn setup_logging(verbose_requested: bool) { let rust_log_env = std::env::var("RUST_LOG");