Improve logging with axum

Cargo.lock

@@ -702,6 +702,7 @@ dependencies = [
  "recipe-store",
  "recipes",
  "rust-embed",
+ "tower-http",
  "tracing",
  "tracing-subscriber",
 ]
@@ -1394,6 +1395,7 @@ dependencies = [
  "tower",
  "tower-layer",
  "tower-service",
+ "tracing",
 ]
 
 [[package]]

kitchen/Cargo.toml

@@ -16,6 +16,7 @@ axum = "0.5.13"
 rust-embed="6.4.0"
 mime_guess = "2.0.4"
 async-trait = "0.1.57"
+tower-http = { version = "0.3.0", features = ["trace"] }
 
 [dependencies.clap]
 version = "3.2.16"

kitchen/src/main.rs

@@ -30,7 +30,7 @@ fn create_app<'a>() -> clap::App<'a> {
         (version: crate_version!())
         (author: crate_authors!())
         (about: "Kitchen Management CLI")
-        (@arg verbose: --verbose -v "Verbosity level for logging (error, warn, info, debug, trace")
+        (@arg verbose: --verbose -v +takes_value "Verbosity level for logging (error, warn, info, debug, trace")
         (@subcommand recipe =>
             (about: "parse a recipe file and output info about it")
             (@arg ingredients: -i --ingredients "Output the ingredients list.")

kitchen/src/web.rs

@@ -20,13 +20,14 @@ use async_std::stream::StreamExt;
 use axum::{
     body::{boxed, Full},
     extract::{Extension, Path},
-    http::{header, StatusCode, Uri},
+    http::{header, StatusCode},
     response::{IntoResponse, Redirect, Response},
     routing::{get, Router},
 };
 use mime_guess;
 use recipe_store::{self, RecipeStore};
 use rust_embed::RustEmbed;
+use tower_http::trace::TraceLayer;
 use tracing::{debug, info, instrument, warn};
 
 use crate::api::ParseError;
@@ -91,15 +92,15 @@ where
 
 #[instrument]
 async fn ui_static_assets(Path(path): Path<String>) -> impl IntoResponse {
-    info!(path = path, "Serving ui path");
+    info!("Serving ui path");
 
     let mut path = path.trim_start_matches("/");
     path = if path == "" { "index.html" } else { path };
-    debug!(path = path, "Serving ui path");
+    debug!(path = path, "Serving transformed path");
     StaticFile(path.to_owned())
 }
 
-#[instrument(skip(store))]
+#[instrument]
 async fn api_recipes(Extension(store): Extension<Arc<recipe_store::AsyncFileStore>>) -> Response {
     let result: Result<axum::Json<Vec<String>>, String> = match store
         .get_recipes()
@@ -113,7 +114,7 @@ async fn api_recipes(Extension(store): Extension<Arc<recipe_store::AsyncFileStor
     result.into_response()
 }
 
-#[instrument(skip(store))]
+#[instrument]
 async fn api_categories(
     Extension(store): Extension<Arc<recipe_store::AsyncFileStore>>,
 ) -> Response {
@@ -134,13 +135,16 @@ pub async fn ui_main(recipe_dir_path: PathBuf, listen_socket: SocketAddr) {
     let store = Arc::new(recipe_store::AsyncFileStore::new(recipe_dir_path.clone()));
     //let dir_path = (&dir_path).clone();
     let router = Router::new()
-        .layer(Extension(store))
         .route("/", get(|| async { Redirect::temporary("/ui/") }))
         .route("/ui/*path", get(ui_static_assets))
         // recipes api path route
         .route("/api/v1/recipes", get(api_recipes))
         // categories api path route
-        .route("/api/v1/categories", get(api_categories));
+        .route("/api/v1/categories", get(api_categories))
+        // NOTE(jwall): Note that the layers are applied to the preceding routes not
+        // the following routes.
+        .layer(TraceLayer::new_for_http())
+        .layer(Extension(store));
     info!(
         http = format!("http://{}", listen_socket),
         "Starting server"

recipe-store/src/lib.rs

@@ -21,11 +21,9 @@ use async_std::{
 use async_trait::async_trait;
 #[cfg(target_arch = "wasm32")]
 use reqwasm;
-#[cfg(target_arch = "wasm32")]
-use tracing::debug;
-use tracing::instrument;
 #[cfg(not(target_arch = "wasm32"))]
-use tracing::{info, warn};
+use tracing::warn;
+use tracing::{debug, instrument};
 
 #[derive(Debug)]
 pub struct Error(String);
@@ -85,7 +83,7 @@ pub trait RecipeStore: Clone + Sized {
 }
 
 #[cfg(not(target_arch = "wasm32"))]
-#[derive(Clone)]
+#[derive(Clone, Debug)]
 pub struct AsyncFileStore {
     path: PathBuf,
 }
@@ -107,6 +105,7 @@ impl RecipeStore for AsyncFileStore {
         category_path.push(&self.path);
         category_path.push("categories.txt");
         let category_file = File::open(&category_path).await?;
+        debug!(category_file = ?category_path, "Opened category file");
         let mut buf_reader = io::BufReader::new(category_file);
         let mut contents = Vec::new();
         buf_reader.read_to_end(&mut contents).await?;
@@ -130,7 +129,7 @@ impl RecipeStore for AsyncFileStore {
                     .any(|&s| s == entry.file_name().to_string_lossy().to_string())
             {
                 // add it to the entry
-                info!("adding recipe file {}", entry.file_name().to_string_lossy());
+                debug!("adding recipe file {}", entry.file_name().to_string_lossy());
                 let recipe_contents = read_to_string(entry.path()).await?;
                 entry_vec.push(recipe_contents);
             } else {

run.sh

@@ -15,6 +15,6 @@ EXAMPLES=${EXAMPLES:-../examples}
 make clean wasm kitchen
 pushd kitchen
 echo Starting api server serving ${EXAMPLES}
-cargo run -- serve --dir ${EXAMPLES}
+cargo run -- --verbose debug serve --dir ${EXAMPLES}
 popd
 # This is ghetto but I'm doing it anyway