diff --git a/src/post/blag.rs b/src/post/blag.rs index 79cfbcb..68e0d00 100644 --- a/src/post/blag.rs +++ b/src/post/blag.rs @@ -206,7 +206,7 @@ impl PostManager for Blag { Ok(posts) } - #[instrument(level = "info", skip(self))] + #[instrument(skip(self))] async fn get_post( &self, name: Arc, diff --git a/src/post/cache.rs b/src/post/cache.rs index 9f66a3a..4c17c46 100644 --- a/src/post/cache.rs +++ b/src/post/cache.rs @@ -1,3 +1,4 @@ +use std::fmt::Debug; use std::io::{Read, Write}; use std::ops::Deref; use std::sync::Arc; @@ -8,7 +9,7 @@ use color_eyre::eyre::{self, Context}; use scc::HashMap; use serde::{Deserialize, Serialize}; use tokio::io::AsyncReadExt; -use tracing::{debug, info, instrument}; +use tracing::{debug, info, instrument, trace, Span}; /// do not persist cache if this version number changed pub const CACHE_VERSION: u16 = 5; @@ -37,14 +38,20 @@ pub struct CacheKey { } impl Cache { + #[instrument(level = "debug", skip(self), fields(entry_mtime))] pub async fn lookup(&self, name: Arc, mtime: u64, extra: u64) -> Option { + trace!("looking up in cache"); match self.0.get_async(&CacheKey { name, extra }).await { Some(entry) => { let cached = entry.get(); + Span::current().record("entry_mtime", cached.mtime); + trace!("found in cache"); if mtime <= cached.mtime { + trace!("entry up-to-date"); Some(cached.clone()) } else { let _ = entry.remove(); + debug!("removed stale entry"); None } } @@ -52,19 +59,24 @@ impl Cache { } } + #[instrument(level = "debug", skip(self), fields(entry_mtime))] pub async fn lookup_metadata( &self, name: Arc, mtime: u64, extra: u64, ) -> Option { + trace!("looking up metadata in cache"); match self.0.get_async(&CacheKey { name, extra }).await { Some(entry) => { let cached = entry.get(); + Span::current().record("entry_mtime", cached.mtime); if mtime <= cached.mtime { + trace!("entry up-to-date"); Some(cached.meta.clone()) } else { let _ = entry.remove(); + debug!("removed stale entry"); None } } @@ -72,6 +84,7 @@ impl Cache { } } + #[instrument(level = "debug", skip(self))] pub async fn insert( &self, name: Arc, @@ -80,7 +93,10 @@ impl Cache { rendered: Arc, extra: u64, ) -> Option { - self.0 + trace!("inserting into cache"); + + let r = self + .0 .upsert_async( CacheKey { name, extra }, CacheValue { @@ -89,15 +105,38 @@ impl Cache { mtime, }, ) - .await + .await; + + debug!( + "{} cache", + match r { + Some(_) => "updated in", + None => "inserted into", + } + ); + + r } + #[instrument(level = "debug", skip(self))] #[allow(unused)] pub async fn remove(&self, name: Arc, extra: u64) -> Option<(CacheKey, CacheValue)> { - self.0.remove_async(&CacheKey { name, extra }).await + trace!("removing from cache"); + + let r = self.0.remove_async(&CacheKey { name, extra }).await; + + debug!( + "item {} cache", + match r { + Some(_) => "removed from", + None => "did not exist in", + } + ); + + r } - #[instrument(name = "cleanup", skip_all)] + #[instrument(level = "debug", name = "cleanup", skip_all)] pub async fn retain(&self, predicate: impl Fn(&CacheKey, &CacheValue) -> bool) { let old_size = self.0.len(); let mut i = 0; diff --git a/src/templates/watcher.rs b/src/templates/watcher.rs index 8b3eb45..feecaa1 100644 --- a/src/templates/watcher.rs +++ b/src/templates/watcher.rs @@ -105,19 +105,21 @@ pub async fn watch_templates<'a>( let mut templates = Vec::new(); for event in events { - trace!("file event: {event:?}"); if let Err(err) = process_event(event, &mut templates).await { error!("error while processing event: {err}"); } } - let mut reg = reg.write().await; - for template in templates.into_iter() { - debug!("registered template {}", template.0); - reg.register_template(&template.0, template.1); + if !templates.is_empty() { + let mut reg = reg.write().await; + for template in templates.into_iter() { + debug!("registered template {}", template.0); + reg.register_template(&template.0, template.1); + } + drop(reg); + + info!("updated custom templates"); } - drop(reg); - info!("updated custom templates"); } Ok(())