incorporate tracing instead of log (#222)

* incorporate tracing instead of log

* fix a test

* fix a test

Cargo.lock

@@ -66,6 +66,15 @@ dependencies = [
  "winapi 0.3.9",
 ]
 
+[[package]]
+name = "ansi_term"
+version = "0.12.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "d52a9bb7ec0cf484c551830a7ce27bd20d67eac647e1befb56b0be4ee39a55d2"
+dependencies = [
+ "winapi 0.3.9",
+]
+
 [[package]]
 name = "arrayvec"
 version = "0.5.1"
@@ -232,7 +241,7 @@ version = "2.33.1"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "bdfa80d47f954d53a35a64987ca1422f495b8d6483c0fe9f7117b36c2a792129"
 dependencies = [
- "ansi_term",
+ "ansi_term 0.11.0",
  "atty",
  "bitflags",
  "strsim",
@@ -280,7 +289,7 @@ version = "0.1.4"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "6a99aa4aa18448eef4c7d3f86d2720d2d8cad5c860fe9ff9b279293efdc8f5be"
 dependencies = [
- "ansi_term",
+ "ansi_term 0.11.0",
  "tracing-core",
  "tracing-error",
 ]
@@ -965,6 +974,15 @@ version = "1.0.2"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "3e2e65a1a2e43cfcb47a895c4c8b10d1f4a61097f9f254f183aee60cad9c651d"
 
+[[package]]
+name = "matchers"
+version = "0.0.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f099785f7595cc4b4553a174ce30dd7589ef93391ff414dbb67f62392b9e0ce1"
+dependencies = [
+ "regex-automata",
+]
+
 [[package]]
 name = "matches"
 version = "0.1.8"
@@ -1221,13 +1239,14 @@ version = "0.1.0"
 dependencies = [
  "chrono",
  "envy",
- "log",
  "pretty_env_logger",
  "reqwest",
  "serde",
  "serde_json",
  "thiserror",
  "tokio",
+ "tracing",
+ "tracing-futures",
 ]
 
 [[package]]
@@ -1612,6 +1631,16 @@ dependencies = [
  "thread_local",
 ]
 
+[[package]]
+name = "regex-automata"
+version = "0.1.9"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ae1ded71d66a4a97f5e961fd0cb25a5f366a42a41570d16a763a69c092c26ae4"
+dependencies = [
+ "byteorder",
+ "regex-syntax",
+]
+
 [[package]]
 name = "regex-syntax"
 version = "0.6.18"
@@ -2148,14 +2177,45 @@ dependencies = [
  "tracing",
 ]
 
+[[package]]
+name = "tracing-log"
+version = "0.1.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "5e0f8c7178e13481ff6765bd169b33e8d554c5d2bbede5e32c356194be02b9b9"
+dependencies = [
+ "lazy_static",
+ "log",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-serde"
+version = "0.1.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "fb65ea441fbb84f9f6748fd496cf7f63ec9af5bca94dd86456978d055e8eb28b"
+dependencies = [
+ "serde",
+ "tracing-core",
+]
+
 [[package]]
 name = "tracing-subscriber"
 version = "0.2.9"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "e4f5dd7095c2481b7b3cbed71c8de53085fb3542bc3c2b4c73cba43e8f11c7ba"
 dependencies = [
+ "ansi_term 0.12.1",
+ "chrono",
+ "lazy_static",
+ "matchers",
+ "regex",
+ "serde",
+ "serde_json",
  "sharded-slab",
+ "smallvec",
  "tracing-core",
+ "tracing-log",
+ "tracing-serde",
 ]
 
 [[package]]
@@ -2544,6 +2604,9 @@ dependencies = [
  "sitemap",
  "thiserror",
  "tokio",
+ "tracing",
+ "tracing-futures",
+ "tracing-subscriber",
  "url",
  "warp",
  "xml-rs",

Cargo.toml

@@ -19,7 +19,6 @@ kankyo = "0.3"
 lazy_static = "1.4"
 log = "0.4"
 mime = "0.3.0"
-pretty_env_logger = "0"
 prometheus = { version = "0.10", default-features = false, features = ["process"] }
 rand = "0"
 serde_dhall = "0.7.0"
@@ -28,6 +27,9 @@ serde_yaml = "0.8"
 sitemap = "0.4"
 thiserror = "1"
 tokio = { version = "0.2", features = ["macros"] }
+tracing = "0.1"
+tracing-futures = "0.2"
+tracing-subscriber = { version = "0.2", features = ["fmt"] }
 warp = "0.2"
 xml-rs = "0.8"
 url = "2"
@@ -45,6 +47,7 @@ pfacts = "0"
 serde_json = "1"
 eyre = "0.6"
 reqwest = { version = "0.10", features = ["json"] }
+pretty_env_logger = "0"
 
 [workspace]
 members = [

lib/patreon/Cargo.toml

@@ -12,7 +12,8 @@ reqwest = { version = "0.10", features = ["json"] }
 serde_json = "1.0"
 serde = { version = "1", features = ["derive"] }
 thiserror = "1"
-log = "0"
+tracing = "0.1"
+tracing-futures = "0.2"
 
 [dev-dependencies]
 tokio = { version = "0.2", features = ["macros"] }

lib/patreon/src/lib.rs

@@ -1,6 +1,7 @@
+use chrono::prelude::*;
 use serde::{Deserialize, Serialize};
 use thiserror::Error;
-use chrono::prelude::*;
+use tracing::{debug, error, instrument};
 
 pub type Campaigns = Vec<Object<Campaign>>;
 pub type Pledges = Vec<Object<Pledge>>;
@@ -70,7 +71,7 @@ pub enum Error {
     Request(#[from] reqwest::Error),
 }
 
-#[derive(Debug, Serialize, Deserialize, Clone)]
+#[derive(Debug, Serialize, Deserialize, Clone, Default)]
 pub struct Credentials {
     pub client_id: String,
     pub client_secret: String,
@@ -112,6 +113,7 @@ impl Client {
         }
     }
 
+    #[instrument(skip(self))]
     pub async fn campaign(&self) -> Result<Data<Vec<Object<Campaign>>, ()>> {
         let data = self
             .cli
@@ -126,11 +128,14 @@ impl Client {
             )
             .send()
             .await?
-            .error_for_status()?.text().await?;
+            .error_for_status()?
-        log::debug!("campaign response: {}", data);
+            .text()
+            .await?;
+        debug!("campaign response: {}", data);
         Ok(serde_json::from_str(&data)?)
     }
 
+    #[instrument(skip(self))]
     pub async fn pledges(&self, camp_id: String) -> Result<Vec<Object<User>>> {
         let data = self
             .cli
@@ -148,7 +153,7 @@ impl Client {
             .error_for_status()?
             .text()
             .await?;
-        log::debug!("pledges for {}: {}", camp_id, data);
+        debug!("pledges for {}: {}", camp_id, data);
         let data: Data<Vec<Object<Pledge>>, Object<User>> = serde_json::from_str(&data)?;
         Ok(data.included.unwrap())
     }

src/app/mod.rs

@@ -2,6 +2,7 @@ use crate::{post::Post, signalboost::Person};
 use color_eyre::eyre::Result;
 use serde::Deserialize;
 use std::{fs, path::PathBuf};
+use tracing::{instrument, error};
 
 pub mod markdown;
 
@@ -15,9 +16,10 @@ pub struct Config {
     resume_fname: PathBuf,
 }
 
+#[instrument]
 async fn patrons() -> Result<Option<patreon::Users>> {
     use patreon::*;
-    let creds: Credentials = envy::prefixed("PATREON_").from_env().unwrap();
+    let creds: Credentials = envy::prefixed("PATREON_").from_env().unwrap_or(Credentials::default());
     let cli = Client::new(creds);
 
     match cli.campaign().await {
@@ -27,13 +29,13 @@ async fn patrons() -> Result<Option<patreon::Users>> {
             match cli.pledges(id).await {
                 Ok(users) => Ok(Some(users)),
                 Err(why) => {
-                    log::error!("error getting pledges: {:?}", why);
+                    error!("error getting pledges: {}", why);
                     Ok(None)
                 }
             }
         }
         Err(why) => {
-            log::error!("error getting patreon campaign: {:?}", why);
+            error!("error getting patreon campaign: {}", why);
             Ok(None)
         }
     }
@@ -134,7 +136,6 @@ mod tests {
     use color_eyre::eyre::Result;
     #[tokio::test]
     async fn init() -> Result<()> {
-        let _ = pretty_env_logger::try_init();
         super::init("./config.dhall".into()).await?;
         Ok(())
     }

src/handlers/blog.rs

@@ -5,21 +5,26 @@ use crate::{
     templates::{self, Html, RenderRucte},
 };
 use lazy_static::lazy_static;
-use prometheus::{IntCounterVec, register_int_counter_vec, opts};
+use prometheus::{opts, register_int_counter_vec, IntCounterVec};
 use std::sync::Arc;
+use tracing::{error, instrument};
 use warp::{http::Response, Rejection, Reply};
 
 lazy_static! {
-    static ref HIT_COUNTER: IntCounterVec =
+    static ref HIT_COUNTER: IntCounterVec = register_int_counter_vec!(
-        register_int_counter_vec!(opts!("blogpost_hits", "Number of hits to blogposts"), &["name"])
+        opts!("blogpost_hits", "Number of hits to blogposts"),
+        &["name"]
+    )
     .unwrap();
 }
 
+#[instrument(skip(state))]
 pub async fn index(state: Arc<State>) -> Result<impl Reply, Rejection> {
     let state = state.clone();
     Response::builder().html(|o| templates::blogindex_html(o, state.blog.clone()))
 }
 
+#[instrument(skip(state))]
 pub async fn series(state: Arc<State>) -> Result<impl Reply, Rejection> {
     let state = state.clone();
     let mut series: Vec<String> = vec![];
@@ -36,6 +41,7 @@ pub async fn series(state: Arc<State>) -> Result<impl Reply, Rejection> {
     Response::builder().html(|o| templates::series_html(o, series))
 }
 
+#[instrument(skip(state))]
 pub async fn series_view(series: String, state: Arc<State>) -> Result<impl Reply, Rejection> {
     let state = state.clone();
     let mut posts: Vec<Post> = vec![];
@@ -51,12 +57,14 @@ pub async fn series_view(series: String, state: Arc<State>) -> Result<impl Reply
     }
 
     if posts.len() == 0 {
+        error!("series not found");
         Err(SeriesNotFound(series).into())
     } else {
         Response::builder().html(|o| templates::series_posts_html(o, series, &posts))
     }
 }
 
+#[instrument(skip(state))]
 pub async fn post_view(name: String, state: Arc<State>) -> Result<impl Reply, Rejection> {
     let mut want: Option<Post> = None;
 
@@ -69,7 +77,9 @@ pub async fn post_view(name: String, state: Arc<State>) -> Result<impl Reply, Re
     match want {
         None => Err(PostNotFound("blog".into(), name).into()),
         Some(post) => {
-            HIT_COUNTER.with_label_values(&[name.clone().as_str()]).inc();
+            HIT_COUNTER
+                .with_label_values(&[name.clone().as_str()])
+                .inc();
             let body = Html(post.body_html.clone());
             Response::builder().html(|o| templates::blogpost_html(o, post, body))
         }

src/handlers/feeds.rs

@@ -1,7 +1,8 @@
 use crate::{app::State, templates};
 use lazy_static::lazy_static;
 use prometheus::{opts, register_int_counter_vec, IntCounterVec};
-use std::{sync::Arc, io};
+use std::{io, sync::Arc};
+use tracing::instrument;
 use warp::{http::Response, Rejection, Reply};
 
 lazy_static! {
@@ -12,6 +13,7 @@ lazy_static! {
     .unwrap();
 }
 
+#[instrument(skip(state))]
 pub async fn jsonfeed(state: Arc<State>) -> Result<impl Reply, Rejection> {
     HIT_COUNTER.with_label_values(&["json"]).inc();
     let state = state.clone();
@@ -26,6 +28,7 @@ pub enum RenderError {
 
 impl warp::reject::Reject for RenderError {}
 
+#[instrument(skip(state))]
 pub async fn atom(state: Arc<State>) -> Result<impl Reply, Rejection> {
     HIT_COUNTER.with_label_values(&["atom"]).inc();
     let state = state.clone();
@@ -41,6 +44,7 @@ pub async fn atom(state: Arc<State>) -> Result<impl Reply, Rejection> {
         .map_err(warp::reject::custom)
 }
 
+#[instrument(skip(state))]
 pub async fn rss(state: Arc<State>) -> Result<impl Reply, Rejection> {
     HIT_COUNTER.with_label_values(&["rss"]).inc();
     let state = state.clone();
@@ -56,6 +60,7 @@ pub async fn rss(state: Arc<State>) -> Result<impl Reply, Rejection> {
         .map_err(warp::reject::custom)
 }
 
+#[instrument(skip(state))]
 pub async fn sitemap(state: Arc<State>) -> Result<impl Reply, Rejection> {
     HIT_COUNTER.with_label_values(&["sitemap"]).inc();
     let state = state.clone();

src/handlers/gallery.rs

@@ -8,6 +8,7 @@ use lazy_static::lazy_static;
 use prometheus::{IntCounterVec, register_int_counter_vec, opts};
 use std::sync::Arc;
 use warp::{http::Response, Rejection, Reply};
+use tracing::instrument;
 
 lazy_static! {
     static ref HIT_COUNTER: IntCounterVec =
@@ -15,11 +16,13 @@ lazy_static! {
         .unwrap();
 }
 
+#[instrument(skip(state))]
 pub async fn index(state: Arc<State>) -> Result<impl Reply, Rejection> {
     let state = state.clone();
     Response::builder().html(|o| templates::galleryindex_html(o, state.gallery.clone()))
 }
 
+#[instrument(skip(state))]
 pub async fn post_view(name: String, state: Arc<State>) -> Result<impl Reply, Rejection> {
     let mut want: Option<Post> = None;
 

src/handlers/mod.rs

@@ -9,6 +9,7 @@ use warp::{
     http::{Response, StatusCode},
     Rejection, Reply,
 };
+use tracing::instrument;
 
 lazy_static! {
     static ref HIT_COUNTER: IntCounterVec =
@@ -16,27 +17,32 @@ lazy_static! {
             .unwrap();
 }
 
+#[instrument]
 pub async fn index() -> Result<impl Reply, Rejection> {
     HIT_COUNTER.with_label_values(&["index"]).inc();
     Response::builder().html(|o| templates::index_html(o))
 }
 
+#[instrument]
 pub async fn contact() -> Result<impl Reply, Rejection> {
     HIT_COUNTER.with_label_values(&["contact"]).inc();
     Response::builder().html(|o| templates::contact_html(o))
 }
 
+#[instrument]
 pub async fn feeds() -> Result<impl Reply, Rejection> {
     HIT_COUNTER.with_label_values(&["feeds"]).inc();
     Response::builder().html(|o| templates::feeds_html(o))
 }
 
+#[instrument(skip(state))]
 pub async fn resume(state: Arc<State>) -> Result<impl Reply, Rejection> {
     HIT_COUNTER.with_label_values(&["resume"]).inc();
     let state = state.clone();
     Response::builder().html(|o| templates::resume_html(o, Html(state.resume.clone())))
 }
 
+#[instrument(skip(state))]
 pub async fn patrons(state: Arc<State>) -> Result<impl Reply, Rejection> {
     HIT_COUNTER.with_label_values(&["patrons"]).inc();
     let state = state.clone();
@@ -51,12 +57,14 @@ pub async fn patrons(state: Arc<State>) -> Result<impl Reply, Rejection> {
     }
 }
 
+#[instrument(skip(state))]
 pub async fn signalboost(state: Arc<State>) -> Result<impl Reply, Rejection> {
     HIT_COUNTER.with_label_values(&["signalboost"]).inc();
     let state = state.clone();
     Response::builder().html(|o| templates::signalboost_html(o, state.signalboost.clone()))
 }
 
+#[instrument]
 pub async fn not_found() -> Result<impl Reply, Rejection> {
     HIT_COUNTER.with_label_values(&["not_found"]).inc();
     Response::builder().html(|o| templates::notfound_html(o, "some path".into()))
@@ -109,6 +117,7 @@ lazy_static! {
     .unwrap();
 }
 
+#[instrument]
 pub async fn rejection(err: Rejection) -> Result<impl Reply, Infallible> {
     let path: String;
     let code;

src/handlers/talks.rs

@@ -8,6 +8,7 @@ use lazy_static::lazy_static;
 use prometheus::{IntCounterVec, register_int_counter_vec, opts};
 use std::sync::Arc;
 use warp::{http::Response, Rejection, Reply};
+use tracing::instrument;
 
 lazy_static! {
     static ref HIT_COUNTER: IntCounterVec =
@@ -15,11 +16,13 @@ lazy_static! {
         .unwrap();
 }
 
+#[instrument(skip(state))]
 pub async fn index(state: Arc<State>) -> Result<impl Reply, Rejection> {
     let state = state.clone();
     Response::builder().html(|o| templates::talkindex_html(o, state.talks.clone()))
 }
 
+#[instrument(skip(state))]
 pub async fn post_view(name: String, state: Arc<State>) -> Result<impl Reply, Rejection> {
     let mut want: Option<Post> = None;
 

src/main.rs

@@ -23,7 +23,7 @@ fn with_state(
 async fn main() -> Result<()> {
     color_eyre::install()?;
     let _ = kankyo::init();
-    pretty_env_logger::init();
+    tracing_subscriber::fmt::init();
     log::info!("starting up commit {}", env!("GITHUB_SHA"));
 
     let state = Arc::new(app::init(