From b0c4ec05942ccb66ef487a6bac14e963d2b8c35d Mon Sep 17 00:00:00 2001
From: Kirill Bulatov <kirill@neon.tech>
Date: Thu, 2 Jun 2022 12:31:04 +0300
Subject: [PATCH] Log storage sync and etcd events a bit better

---
 libs/etcd_broker/src/lib.rs    |  4 ++--
 pageserver/src/storage_sync.rs |  4 ++--
 pageserver/src/walreceiver.rs  | 14 ++++++++++----
 3 files changed, 14 insertions(+), 8 deletions(-)

diff --git a/libs/etcd_broker/src/lib.rs b/libs/etcd_broker/src/lib.rs
index 0bfce66a5d..9184412eb1 100644
--- a/libs/etcd_broker/src/lib.rs
+++ b/libs/etcd_broker/src/lib.rs
@@ -258,7 +258,7 @@ pub async fn subscribe_to_safekeeper_timeline_updates(
                                     }
                                 }
                             }
-                            Ok(None) => {}
+                            Ok(None) => warn!("Ignoring etcd KV with unexpected key {:?} that does not match required regex {}", new_etcd_kv.key_str(), regex),
                             Err(e) => error!("Failed to parse timeline update: {e}"),
                         };
                     }
@@ -272,7 +272,7 @@ pub async fn subscribe_to_safekeeper_timeline_updates(
         }
 
         Ok(())
-    });
+    }.instrument(info_span!("etcd_broker")));
 
     Ok(SkTimelineSubscription {
         kind: subscription,
diff --git a/pageserver/src/storage_sync.rs b/pageserver/src/storage_sync.rs
index 1c33d8315c..a140149c23 100644
--- a/pageserver/src/storage_sync.rs
+++ b/pageserver/src/storage_sync.rs
@@ -892,7 +892,7 @@ fn storage_sync_loop<P, S>(
 
         REMAINING_SYNC_ITEMS.set(remaining_queue_length as i64);
         if remaining_queue_length > 0 || !batched_tasks.is_empty() {
-            info!("Processing tasks for {} timelines in batch, more tasks left to process: {remaining_queue_length}", batched_tasks.len());
+            debug!("Processing tasks for {} timelines in batch, more tasks left to process: {remaining_queue_length}", batched_tasks.len());
         } else {
             debug!("No tasks to process");
             continue;
@@ -1186,7 +1186,7 @@ async fn update_local_metadata(
     let remote_metadata = match remote_timeline {
         Some(timeline) => &timeline.metadata,
         None => {
-            info!("No remote timeline to update local metadata from, skipping the update");
+            debug!("No remote timeline to update local metadata from, skipping the update");
             return Ok(());
         }
     };
diff --git a/pageserver/src/walreceiver.rs b/pageserver/src/walreceiver.rs
index e54406a450..527fb137cd 100644
--- a/pageserver/src/walreceiver.rs
+++ b/pageserver/src/walreceiver.rs
@@ -468,11 +468,17 @@ async fn timeline_wal_broker_loop_step(
             // finally, if no other tasks are completed, get another broker update and possibly reconnect
             updates = broker_subscription.fetch_data() => match updates {
                 Some(mut all_timeline_updates) => {
-                    if let Some(subscribed_timeline_updates) = all_timeline_updates.remove(&id) {
-                        if let Some(candidate) = wal_connection_manager.select_connection_candidate(subscribed_timeline_updates) {
-                            info!("Switching to different safekeeper {} for timeline {id}, reason: {:?}", candidate.safekeeper_id, candidate.reason);
-                            wal_connection_manager.change_connection(candidate.safekeeper_id, candidate.wal_producer_connstr).await;
+                    match all_timeline_updates.remove(&id) {
+                        Some(subscribed_timeline_updates) => {
+                            match wal_connection_manager.select_connection_candidate(subscribed_timeline_updates) {
+                                Some(candidate) => {
+                                    info!("Switching to different safekeeper {} for timeline {id}, reason: {:?}", candidate.safekeeper_id, candidate.reason);
+                                    wal_connection_manager.change_connection(candidate.safekeeper_id, candidate.wal_producer_connstr).await;
+                                },
+                                None => debug!("No connection candidate was selected for timeline"),
+                            }
                         }
+                        None => warn!("Timeline has an active broker subscription, but got no updates. Other data length: {}", all_timeline_updates.len()),
                     }
                 },
                 None => {