diff --git a/api/Cargo.lock b/api/Cargo.lock index 3b8638bf..645e3337 100644 --- a/api/Cargo.lock +++ b/api/Cargo.lock @@ -18,17 +18,17 @@ dependencies = [ "crossbeam", "crossbeam-queue", "crossbeam-skiplist", - "env_logger", "fmt", "futures", - "log", "rand", "rocket", "serde", "tracing", "tracing-appender", + "tracing-log", "tracing-subscriber", "uuid", + "yansi 0.5.1", ] [[package]] @@ -253,19 +253,6 @@ dependencies = [ "cfg-if", ] -[[package]] -name = "env_logger" -version = "0.10.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "85cdab6a89accf66733ad5a1693a4dcced6aeff64602b634530dd73c1f3ee9f0" -dependencies = [ - "humantime", - "is-terminal", - "log", - "regex", - "termcolor", -] - [[package]] name = "errno" version = "0.2.8" @@ -526,12 +513,6 @@ version = "1.0.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "c4a1e36c821dbe04574f602848a19f742f4fb3c98d40449f11bcad18d6b17421" -[[package]] -name = "humantime" -version = "2.1.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "9a3a5bfb195931eeb336b2a7b4d761daec841b97f947d34394601737a7bba5e4" - [[package]] name = "hyper" version = "0.14.25" @@ -1241,15 +1222,6 @@ dependencies = [ "windows-sys 0.42.0", ] -[[package]] -name = "termcolor" -version = "1.3.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "6093bad37da69aab9d123a8091e4be0aa4a03e4d601ec641c327398315f62b64" -dependencies = [ - "winapi-util", -] - [[package]] name = "thread_local" version = "1.1.7" @@ -1412,22 +1384,35 @@ dependencies = [ "tracing-core", ] +[[package]] +name = "tracing-serde" +version = "0.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bc6b213177105856957181934e4920de57730fc69bf42c37ee5bb664d406d9e1" +dependencies = [ + "serde", + "tracing-core", +] + [[package]] name = "tracing-subscriber" -version = "0.3.16" +version = "0.3.17" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "a6176eae26dd70d0c919749377897b54a9276bd7061339665dd68777926b5a70" +checksum = "30a651bc37f915e81f087d86e62a18eec5f79550c7faff886f7090b4ea757c77" dependencies = [ "matchers", "nu-ansi-term", "once_cell", "regex", + "serde", + "serde_json", "sharded-slab", "smallvec", "thread_local", "tracing", "tracing-core", "tracing-log", + "tracing-serde", ] [[package]] @@ -1521,15 +1506,6 @@ version = "0.4.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6" -[[package]] -name = "winapi-util" -version = "0.1.6" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "f29e6f9198ba0d26b4c9f07dbe6f9ed633e1f3d5b8b414090084349e46a52596" -dependencies = [ - "winapi", -] - [[package]] name = "winapi-x86_64-pc-windows-gnu" version = "0.4.0" diff --git a/api/Cargo.toml b/api/Cargo.toml index 9a543fab..deddc35f 100644 --- a/api/Cargo.toml +++ b/api/Cargo.toml @@ -10,13 +10,13 @@ rocket = { version = "0.5.0-rc.2", features = ["json"] } rand = "0.8" serde = { version = "1.0.152", features = ["derive"] } tracing = "^0.1" -tracing-subscriber = "^0.3" +tracing-subscriber = { version = "^0.3.17", features=["env-filter", "json", "registry", "smallvec"]} tracing-appender = "0.2" -log = "0.4.20" -env_logger = "0.10.0" +tracing-log = "0.1.3" crossbeam = "0.8.2" uuid = { version = "1.4.1", features = ["serde", "v4"] } futures = "0.3.28" crossbeam-queue = "0.3.8" crossbeam-skiplist = "0.1.1" fmt = "0.1.0" +yansi = "0.5.1" diff --git a/api/src/handlers/cairo_version.rs b/api/src/handlers/cairo_version.rs index 8164e17e..3c7226de 100644 --- a/api/src/handlers/cairo_version.rs +++ b/api/src/handlers/cairo_version.rs @@ -4,12 +4,13 @@ use crate::utils::lib::CAIRO_DIR; use crate::worker::WorkerEngine; use rocket::State; use std::process::{Command, Stdio}; -use tracing::instrument; +use tracing::{error, info, instrument}; // Read the version from the cairo Cargo.toml file. #[instrument] #[get("/cairo_version")] pub async fn cairo_version() -> String { + info!("/cairo_version"); do_cairo_version().unwrap_or_else(|e| e) } @@ -17,12 +18,14 @@ pub async fn cairo_version() -> String { #[instrument] #[get("/cairo_version_async")] pub async fn cairo_version_async(engine: &State) -> String { + info!("/cairo_version_async"); do_process_command(ApiCommand::CairoVersion, engine) } #[instrument] #[get("/cairo_version_result/")] pub async fn get_cairo_version_result(process_id: String, engine: &State) -> String { + info!("/cairo_version_result/{:?}", process_id); fetch_process_result(process_id, engine, |result| match result { ApiCommandResult::CairoVersion(version) => version.to_string(), _ => String::from("Result not available"), @@ -51,6 +54,9 @@ pub fn do_cairo_version() -> Result { .stdout, ) { Ok(version) => Ok(version), - Err(e) => Err(e.to_string()), + Err(e) => { + error!("{:?}", e.to_string()); + Err(e.to_string()) + } } } diff --git a/api/src/handlers/compile_casm.rs b/api/src/handlers/compile_casm.rs index a0ccf8df..a3f39f92 100644 --- a/api/src/handlers/compile_casm.rs +++ b/api/src/handlers/compile_casm.rs @@ -7,24 +7,32 @@ use rocket::serde::json; use rocket::serde::json::Json; use rocket::tokio::fs; use rocket::State; +use tracing::info; +use tracing::instrument; use std::path::{Path, PathBuf}; use std::process::{Command, Stdio}; +#[instrument] #[get("/compile-to-casm/")] pub async fn compile_to_casm(remix_file_path: PathBuf) -> Json { + info!("/compile-to-casm/{:?}", remix_file_path); do_compile_to_casm(remix_file_path).await } +#[instrument] #[get("/compile-to-casm-async/")] pub async fn compile_to_casm_async( remix_file_path: PathBuf, engine: &State, ) -> String { + info!("/compile-to-casm-async/{:?}", remix_file_path); do_process_command(ApiCommand::CasmCompile(remix_file_path), engine) } +#[instrument] #[get("/compile-to-casm-result/")] pub async fn copmile_to_casm_result(process_id: String, engine: &State) -> String { + info!("/compile-to-casm-result/{:?}", process_id); fetch_process_result(process_id, engine, |result| match result { ApiCommandResult::CasmCompile(casm_result) => json::to_string(&casm_result).unwrap(), _ => String::from("Result not available"), @@ -48,10 +56,10 @@ pub async fn do_compile_to_casm(remix_file_path: PathBuf) -> Json { - println!("LOG: File extension is sierra"); + debug!("LOG: File extension is sierra"); } _ => { - println!("LOG: File extension not supported"); + debug!("LOG: File extension not supported"); return Json(CompileResponse { file_content: "".to_string(), message: "File extension not supported".to_string(), @@ -73,14 +81,14 @@ pub async fn do_compile_to_casm(remix_file_path: PathBuf) -> Json match fs::create_dir_all(parent).await { Ok(_) => { - println!("LOG: Created directory: {:?}", parent); + debug!("LOG: Created directory: {:?}", parent); } Err(e) => { - println!("LOG: Error creating directory: {:?}", e); + debug!("LOG: Error creating directory: {:?}", e); } }, None => { - println!("LOG: Error creating directory"); + debug!("LOG: Error creating directory"); } } @@ -96,7 +104,7 @@ pub async fn do_compile_to_casm(remix_file_path: PathBuf) -> Json")] pub async fn compile_to_sierra(remix_file_path: PathBuf) -> Json { + info!("/compile-to-sierra"); do_compile_to_sierra(remix_file_path) .await .unwrap_or(Json::from(CompileResponse { @@ -21,16 +24,20 @@ pub async fn compile_to_sierra(remix_file_path: PathBuf) -> Json")] pub async fn compile_to_siera_async( remix_file_path: PathBuf, engine: &State, ) -> String { + info!("/compile-to-sierra-async"); do_process_command(ApiCommand::SierraCompile(remix_file_path), engine) } +#[instrument] #[get("/compile-to-sierra-result/")] pub async fn get_siera_compile_result(process_id: String, engine: &State) -> String { + info!("/compile-to-sierra-result"); fetch_process_result(process_id, engine, |result| match result { ApiCommandResult::SierraCompile(sierra_result) => json::to_string(&sierra_result).unwrap(), _ => String::from("Result not available"), @@ -56,10 +63,10 @@ pub async fn do_compile_to_sierra( // check if the file has .cairo extension match get_file_ext(&remix_file_path) { ext if ext == "cairo" => { - println!("LOG: File extension is cairo"); + debug!("LOG: File extension is cairo"); } _ => { - println!("LOG: File extension not supported"); + debug!("LOG: File extension not supported"); return Ok(Json(CompileResponse { file_content: "".to_string(), message: "File extension not supported".to_string(), @@ -82,14 +89,14 @@ pub async fn do_compile_to_sierra( match sierra_path.parent() { Some(parent) => match fs::create_dir_all(parent).await { Ok(_) => { - println!("LOG: Created directory: {:?}", parent); + debug!("LOG: Created directory: {:?}", parent); } Err(e) => { - println!("LOG: Error creating directory: {:?}", e); + debug!("LOG: Error creating directory: {:?}", e); } }, None => { - println!("LOG: Error creating directory"); + debug!("LOG: Error creating directory"); } } @@ -107,7 +114,7 @@ pub async fn do_compile_to_sierra( .spawn() .expect("Failed to execute starknet-compile"); - println!("LOG: ran command:{:?}", compile); + debug!("LOG: ran command:{:?}", compile); let output = result.wait_with_output().expect("Failed to wait on child"); diff --git a/api/src/handlers/mod.rs b/api/src/handlers/mod.rs index 6f18fcf8..0b8f788a 100644 --- a/api/src/handlers/mod.rs +++ b/api/src/handlers/mod.rs @@ -12,18 +12,21 @@ use crate::handlers::compile_sierra::do_compile_to_sierra; use crate::handlers::scarb_compile::do_scarb_compile; use crate::handlers::types::{ApiCommand, ApiCommandResult, FileContentMap}; use rocket::serde::json::Json; +use tracing::info; use std::path::Path; use tracing::instrument; #[instrument] #[get("/health")] pub async fn health() -> &'static str { + info!("/health"); "OK" } #[instrument] #[get("/")] pub async fn who_is_this() -> &'static str { + info!("/who_is_this"); "Who are you?" } diff --git a/api/src/handlers/process.rs b/api/src/handlers/process.rs index 87344ae2..4deb2395 100644 --- a/api/src/handlers/process.rs +++ b/api/src/handlers/process.rs @@ -1,10 +1,13 @@ use crate::handlers::types::{ApiCommand, ApiCommandResult}; use crate::worker::{ProcessState, WorkerEngine}; use rocket::State; +use tracing::{info, instrument}; use uuid::Uuid; +#[instrument] #[get("/process_status/")] pub async fn get_process_status(process_id: String, engine: &State) -> String { + info!("/process_status/{:?}", process_id); // get status of process by ID match Uuid::parse_str(&process_id) { Ok(process_uuid) => { diff --git a/api/src/handlers/save_code.rs b/api/src/handlers/save_code.rs index 9a977d4b..9c3fee38 100644 --- a/api/src/handlers/save_code.rs +++ b/api/src/handlers/save_code.rs @@ -2,10 +2,12 @@ use crate::utils::lib::get_file_path; use rocket::data::ToByteUnit; use rocket::tokio::fs; use rocket::Data; +use tracing::info; use std::path::PathBuf; #[post("/save_code/", data = "")] pub async fn save_code(file: Data<'_>, remix_file_path: PathBuf) -> String { + info!("/save_code/{:?}", remix_file_path); do_save_code(file, remix_file_path).await } @@ -25,14 +27,14 @@ pub async fn do_save_code(file: Data<'_>, remix_file_path: PathBuf) -> String { match file_path.parent() { Some(parent) => match fs::create_dir_all(parent).await { Ok(_) => { - println!("LOG: Created directory: {:?}", parent); + debug!("LOG: Created directory: {:?}", parent); } Err(e) => { - println!("LOG: Error creating directory: {:?}", e); + debug!("LOG: Error creating directory: {:?}", e); } }, None => { - println!("LOG: Error creating directory"); + debug!("LOG: Error creating directory"); } } @@ -41,14 +43,14 @@ pub async fn do_save_code(file: Data<'_>, remix_file_path: PathBuf) -> String { match saved_file { Ok(_) => { - println!("LOG: File saved successfully"); + debug!("LOG: File saved successfully"); match file_path.to_str() { Some(path) => path.to_string(), None => "".to_string(), } } Err(e) => { - println!("LOG: Error saving file: {:?}", e); + debug!("LOG: Error saving file: {:?}", e); "".to_string() // set the response with not ok code. } diff --git a/api/src/handlers/scarb_compile.rs b/api/src/handlers/scarb_compile.rs index 6bede41f..7cab5c8c 100644 --- a/api/src/handlers/scarb_compile.rs +++ b/api/src/handlers/scarb_compile.rs @@ -8,23 +8,26 @@ use rocket::serde::json::Json; use rocket::State; use std::path::PathBuf; use std::process::{Command, Stdio}; -use tracing::instrument; +use tracing::{instrument, info}; #[instrument] #[get("/compile-scarb/")] pub async fn scarb_compile(remix_file_path: PathBuf) -> Json { + info!("/compile-scarb/{:?}", remix_file_path); do_scarb_compile(remix_file_path).await.unwrap() } #[instrument] #[get("/compile-scarb-async/")] pub async fn scarb_compile_async(remix_file_path: PathBuf, engine: &State) -> String { + info!("/compile-scarb-async/{:?}", remix_file_path); do_process_command(ApiCommand::ScarbCompile(remix_file_path), engine) } #[instrument] #[get("/compile-scarb-result/")] pub async fn get_scarb_compile_result(process_id: String, engine: &State) -> String { + info!("/compile-scarb-result/{:?}", process_id); fetch_process_result(process_id, engine, |result| match result { ApiCommandResult::ScarbCompile(scarb_result) => json::to_string(&scarb_result).unwrap(), _ => String::from("Result not available"), @@ -59,7 +62,7 @@ pub async fn do_scarb_compile( .spawn() .expect("Failed to execute scarb build"); - println!("LOG: ran command:{:?}", compile); + debug!("LOG: ran command:{:?}", compile); let output = result.wait_with_output().expect("Failed to wait on child"); diff --git a/api/src/main.rs b/api/src/main.rs index 706a9a96..92cae1af 100644 --- a/api/src/main.rs +++ b/api/src/main.rs @@ -18,7 +18,7 @@ use handlers::process::get_process_status; use handlers::save_code::save_code; use handlers::scarb_compile::{get_scarb_compile_result, scarb_compile, scarb_compile_async}; use handlers::{health, who_is_this}; -use log::info; +use tracing::info; use tracing_log::init_logger; #[launch] diff --git a/api/src/tracing_log.rs b/api/src/tracing_log.rs index 17145e66..4f592f9c 100644 --- a/api/src/tracing_log.rs +++ b/api/src/tracing_log.rs @@ -1,31 +1,150 @@ + use tracing_appender::rolling; -use tracing_subscriber::filter::LevelFilter; + use tracing_subscriber::fmt::writer::MakeWriterExt; -use tracing_subscriber::prelude::*; +use tracing_subscriber::registry::LookupSpan; +use tracing_subscriber::{prelude::*, EnvFilter}; + +use tracing_subscriber::field::MakeExt; + + + +use tracing_subscriber::Layer; +use yansi::Paint; + +pub enum LogType { + Formatted, + Json, +} + +impl From for LogType { + fn from(input: String) -> Self { + match input.as_str() { + "formatted" => Self::Formatted, + "json" => Self::Json, + _ => panic!("Unkown log type {}", input), + } + } +} + +pub fn default_logging_layer() -> impl Layer +where + S: tracing::Subscriber, + S: for<'span> LookupSpan<'span>, +{ + let field_format = tracing_subscriber::fmt::format::debug_fn(|writer, field, value| { + // We'll format the field name and value separated with a colon. + if field.name() == "message" { + write!(writer, "{:?}", Paint::new(value).bold()) + } else { + write!(writer, "{}: {:?}", field, Paint::default(value).bold()) + } + }) + .delimited(", ") + .display_messages(); + + tracing_subscriber::fmt::layer() + .fmt_fields(field_format) + // Configure the formatter to use `print!` rather than + // `stdout().write_str(...)`, so that logs are captured by libtest's test + // capturing. + .with_test_writer() +} + +pub fn json_logging_layer< + S: for<'a> tracing_subscriber::registry::LookupSpan<'a> + tracing::Subscriber, +>() -> impl tracing_subscriber::Layer { + Paint::disable(); + + tracing_subscriber::fmt::layer() + .json() + // Configure the formatter to use `print!` rather than + // `stdout().write_str(...)`, so that logs are captured by libtest's test + // capturing. + .with_test_writer() +} + +#[derive(PartialEq, Eq, Debug, Clone, Copy)] +pub enum LogLevel { + /// Only shows errors and warnings: `"critical"`. + Critical, + /// Shows errors, warnings, and some informational messages that are likely + /// to be relevant when troubleshooting such as configuration: `"support"`. + Support, + /// Shows everything except debug and trace information: `"normal"`. + Normal, + /// Shows everything: `"debug"`. + Debug, + /// Shows nothing: "`"off"`". + Off, +} + +impl From<&str> for LogLevel { + fn from(s: &str) -> Self { + return match &*s.to_ascii_lowercase() { + "critical" => LogLevel::Critical, + "support" => LogLevel::Support, + "normal" => LogLevel::Normal, + "debug" => LogLevel::Debug, + "off" => LogLevel::Off, + _ => panic!("a log level (off, debug, normal, support, critical)"), + }; + } +} + +pub fn filter_layer(level: LogLevel) -> EnvFilter { + let filter_str = match level { + LogLevel::Critical => "warn,hyper=off,rustls=off", + LogLevel::Support => "warn,rocket::support=info,hyper=off,rustls=off", + LogLevel::Normal => "info,hyper=off,rustls=off", + LogLevel::Debug => "trace", + LogLevel::Off => "off", + }; + + tracing_subscriber::filter::EnvFilter::try_new(filter_str).expect("filter string must parse") +} pub fn init_logger() -> Result<(), Box> { - // TO STDOUT - let stdout_log = tracing_subscriber::fmt::layer().pretty(); // Log all `tracing` events to files prefixed with `debug`. // Rolling these files every day - let debug_file = rolling::daily("./logs", "debug"); + let debug_file = rolling::daily("./logs", "debug").with_max_level(tracing::Level::TRACE); // Log warnings and errors to a separate file. Since we expect these events // to occur less frequently, roll that file on a daily basis let warn_file = rolling::daily("./logs", "warnings").with_max_level(tracing::Level::WARN); - let all_files = debug_file.and(warn_file); + let info_file = rolling::daily("./logs", "info").with_max_level(tracing::Level::INFO); + let all_files = debug_file.and(warn_file).and(info_file); let rolling_files = tracing_subscriber::fmt::layer() + .json() .with_writer(all_files) .with_ansi(false); - tracing_subscriber::registry() - .with( - stdout_log - // Add an `INFO` filter to the stdout logging layer - .with_filter(LevelFilter::INFO) - .and_then(rolling_files), - ) - .init(); + let log_type = LogType::from(std::env::var("LOG_TYPE").unwrap_or_else(|_| "json".to_string())); + let log_level = LogLevel::from( + std::env::var("LOG_LEVEL") + .unwrap_or_else(|_| "debug".to_string()) + .as_str(), + ); + + match log_type { + LogType::Formatted => { + tracing::subscriber::set_global_default( + tracing_subscriber::registry() + .with(default_logging_layer()) + .with(filter_layer(log_level)), + ) + .unwrap(); + } + LogType::Json => { + tracing::subscriber::set_global_default( + tracing_subscriber::registry() + .with(json_logging_layer()) + .with(filter_layer(log_level)) + .with(rolling_files), + ) + .unwrap(); + } + }; Ok(()) } diff --git a/api/src/utils/lib.rs b/api/src/utils/lib.rs index b9ea3e3b..63b763cf 100644 --- a/api/src/utils/lib.rs +++ b/api/src/utils/lib.rs @@ -12,7 +12,7 @@ pub fn get_file_ext(file_path: &str) -> String { match file_path.split('.').last() { Some(ext) => ext.to_string(), None => { - println!("LOG: File extension not found"); + debug!("LOG: File extension not found"); "".to_string() } } diff --git a/api/src/worker.rs b/api/src/worker.rs index 7a5c9d91..7f7c369a 100644 --- a/api/src/worker.rs +++ b/api/src/worker.rs @@ -2,15 +2,12 @@ use crate::handlers; use crate::handlers::types::{ApiCommand, ApiCommandResult}; use crossbeam_queue::ArrayQueue; use crossbeam_skiplist::SkipMap; -use futures::executor::block_on; -use futures::TryFutureExt; use rocket::tokio; use rocket::tokio::task::JoinHandle; use rocket::tokio::time; use rocket::tokio::time::sleep; use std::fmt::{Display, Formatter}; use std::sync::Arc; -use tracing::error_span; use uuid::Uuid; #[derive(Debug)]