From 02b20edeb311e019c97f803801c57d70141770f1 Mon Sep 17 00:00:00 2001
From: Nick Mathewson <nickm@torproject.org>
Date: Wed, 13 Oct 2021 13:37:18 -0400
Subject: [PATCH] Add a few tracing directives to tor-dirmgr.

---
 crates/tor-dirmgr/src/bootstrap.rs      | 8 +++++++-
 crates/tor-dirmgr/src/lib.rs            | 4 +++-
 crates/tor-dirmgr/src/storage/sqlite.rs | 5 ++++-
 3 files changed, 14 insertions(+), 3 deletions(-)

diff --git a/crates/tor-dirmgr/src/bootstrap.rs b/crates/tor-dirmgr/src/bootstrap.rs
index 81af0f44d..7af4af4f5 100644
--- a/crates/tor-dirmgr/src/bootstrap.rs
+++ b/crates/tor-dirmgr/src/bootstrap.rs
@@ -17,7 +17,7 @@ use futures::FutureExt;
 use futures::StreamExt;
 use tor_dirclient::DirResponse;
 use tor_rtcompat::{Runtime, SleepProviderExt};
-use tracing::{info, warn};
+use tracing::{info, trace, warn};
 
 /// Try to read a set of documents from `dirmgr` by ID.
 async fn load_all<R: Runtime>(
@@ -91,8 +91,13 @@ async fn load_once<R: Runtime>(
 ) -> Result<bool> {
     let missing = state.missing_docs();
     let outcome = if missing.is_empty() {
+        trace!("Found no missing documents; can't advance current state");
         Ok(false)
     } else {
+        trace!(
+            "Found {} missing documents; trying to load them",
+            missing.len()
+        );
         let documents = load_all(dirmgr, missing).await?;
         state.add_from_cache(documents)
     };
@@ -110,6 +115,7 @@ pub(crate) async fn load<R: Runtime>(
 ) -> Result<Box<dyn DirState>> {
     let mut safety_counter = 0_usize;
     loop {
+        trace!(state=%state.describe(), "Loading from cache");
         let changed = load_once(&dirmgr, &mut state).await?;
 
         if state.can_advance() {
diff --git a/crates/tor-dirmgr/src/lib.rs b/crates/tor-dirmgr/src/lib.rs
index e2d2b8135..8b7ecd60a 100644
--- a/crates/tor-dirmgr/src/lib.rs
+++ b/crates/tor-dirmgr/src/lib.rs
@@ -74,7 +74,7 @@ use anyhow::{Context, Result};
 use async_trait::async_trait;
 use futures::{channel::oneshot, lock::Mutex, task::SpawnExt};
 use tor_rtcompat::{Runtime, SleepProviderExt};
-use tracing::{info, warn};
+use tracing::{info, trace, warn};
 
 use std::sync::atomic::{AtomicBool, Ordering};
 use std::sync::Arc;
@@ -518,9 +518,11 @@ impl<R: Runtime> DirMgr<R> {
             } => {
                 if *cache_usage == CacheUsage::MustDownload {
                     // Do nothing: we don't want a cached consensus.
+                    trace!("MustDownload is set; not checking for cached consensus.");
                 } else if let Some(c) =
                     store.latest_consensus(*flavor, cache_usage.pending_requirement())?
                 {
+                    trace!("Found a reasonable consensus in the cache");
                     let id = DocId::LatestConsensus {
                         flavor: *flavor,
                         cache_usage: *cache_usage,
diff --git a/crates/tor-dirmgr/src/storage/sqlite.rs b/crates/tor-dirmgr/src/storage/sqlite.rs
index 9ba8d0c4e..33757f7dc 100644
--- a/crates/tor-dirmgr/src/storage/sqlite.rs
+++ b/crates/tor-dirmgr/src/storage/sqlite.rs
@@ -21,6 +21,7 @@ use anyhow::Context;
 use chrono::prelude::*;
 use chrono::Duration as CDuration;
 use rusqlite::{params, OpenFlags, OptionalExtension, Transaction};
+use tracing::trace;
 
 #[cfg(target_family = "unix")]
 use std::os::unix::fs::DirBuilderExt;
@@ -384,6 +385,7 @@ impl SqliteStore {
         flavor: ConsensusFlavor,
         pending: Option<bool>,
     ) -> Result<Option<InputString>> {
+        trace!(?flavor, ?pending, "Loading latest consensus from cache");
         let rv: Option<(DateTime<Utc>, DateTime<Utc>, String)>;
         rv = match pending {
             None => self
@@ -446,7 +448,8 @@ impl SqliteStore {
         let digest = format!("sha3-256-{}", d);
 
         let tx = self.conn.transaction()?;
-        tx.execute(MARK_CONSENSUS_NON_PENDING, params![digest])?;
+        let n = tx.execute(MARK_CONSENSUS_NON_PENDING, params![digest])?;
+        trace!("Marked {} consensuses usable", n);
         tx.commit()?;
 
         Ok(())