From fcb4a61a120ab29de19f8a0bbe64aa29bed5f194 Mon Sep 17 00:00:00 2001 From: Dmitry Rodionov Date: Mon, 19 Sep 2022 18:41:18 +0300 Subject: [PATCH] Adjust spans around gc and compaction So compaction and gc loops have their own span to always show tenant id in log messages. --- pageserver/src/page_service.rs | 3 +++ pageserver/src/tenant.rs | 6 +----- pageserver/src/tenant/timeline.rs | 9 +++++---- pageserver/src/tenant_tasks.rs | 20 +++++++++++-------- .../src/walreceiver/connection_manager.rs | 9 +++++++-- 5 files changed, 28 insertions(+), 19 deletions(-) diff --git a/pageserver/src/page_service.rs b/pageserver/src/page_service.rs index b06814c557..1461a6d117 100644 --- a/pageserver/src/page_service.rs +++ b/pageserver/src/page_service.rs @@ -1090,6 +1090,9 @@ impl postgres_backend_async::Handler for PageServerHandler { let tenant_id = TenantId::from_str(caps.get(1).unwrap().as_str())?; let timeline_id = TimelineId::from_str(caps.get(2).unwrap().as_str())?; + let _span_guard = + info_span!("manual_gc", tenant = %tenant_id, timeline = %timeline_id).entered(); + let tenant = tenant_mgr::get_tenant(tenant_id, true)?; let gc_horizon: u64 = caps diff --git a/pageserver/src/tenant.rs b/pageserver/src/tenant.rs index 41fd98ec07..f56f10d7ea 100644 --- a/pageserver/src/tenant.rs +++ b/pageserver/src/tenant.rs @@ -342,8 +342,7 @@ impl Tenant { drop(timelines); for (timeline_id, timeline) in &timelines_to_compact { - let _entered = - info_span!("compact", timeline = %timeline_id, tenant = %self.tenant_id).entered(); + let _entered = info_span!("compact_timeline", timeline = %timeline_id).entered(); timeline.compact()?; } @@ -835,9 +834,6 @@ impl Tenant { pitr: Duration, checkpoint_before_gc: bool, ) -> Result { - let _span_guard = - info_span!("gc iteration", tenant = %self.tenant_id, timeline = ?target_timeline_id) - .entered(); let mut totals: GcResult = Default::default(); let now = Instant::now(); diff --git a/pageserver/src/tenant/timeline.rs b/pageserver/src/tenant/timeline.rs index 95bdf715b5..8670e979ee 100644 --- a/pageserver/src/tenant/timeline.rs +++ b/pageserver/src/tenant/timeline.rs @@ -1916,18 +1916,19 @@ impl Timeline { let new_gc_cutoff = Lsn::min(horizon_cutoff, pitr_cutoff); + let _enter = + info_span!("gc_timeline", timeline = %self.timeline_id, cutoff = %new_gc_cutoff) + .entered(); + // Nothing to GC. Return early. let latest_gc_cutoff = *self.get_latest_gc_cutoff_lsn(); if latest_gc_cutoff >= new_gc_cutoff { info!( - "Nothing to GC for timeline {}: new_gc_cutoff_lsn {new_gc_cutoff}, latest_gc_cutoff_lsn {latest_gc_cutoff}", - self.timeline_id + "Nothing to GC: new_gc_cutoff_lsn {new_gc_cutoff}, latest_gc_cutoff_lsn {latest_gc_cutoff}", ); return Ok(result); } - let _enter = info_span!("garbage collection", timeline = %self.timeline_id, tenant = %self.tenant_id, cutoff = %new_gc_cutoff).entered(); - // We need to ensure that no one tries to read page versions or create // branches at a point before latest_gc_cutoff_lsn. See branch_timeline() // for details. This will block until the old value is no longer in use. diff --git a/pageserver/src/tenant_tasks.rs b/pageserver/src/tenant_tasks.rs index c543a0ecb1..8329b15c08 100644 --- a/pageserver/src/tenant_tasks.rs +++ b/pageserver/src/tenant_tasks.rs @@ -21,7 +21,9 @@ pub fn start_background_loops(tenant_id: TenantId) { &format!("compactor for tenant {tenant_id}"), false, async move { - compaction_loop(tenant_id).await; + compaction_loop(tenant_id) + .instrument(info_span!("compaction_loop", tenant_id = %tenant_id)) + .await; Ok(()) }, ); @@ -33,7 +35,9 @@ pub fn start_background_loops(tenant_id: TenantId) { &format!("garbage collector for tenant {tenant_id}"), false, async move { - gc_loop(tenant_id).await; + gc_loop(tenant_id) + .instrument(info_span!("gc_loop", tenant_id = %tenant_id)) + .await; Ok(()) }, ); @@ -44,7 +48,7 @@ pub fn start_background_loops(tenant_id: TenantId) { /// async fn compaction_loop(tenant_id: TenantId) { let wait_duration = Duration::from_secs(2); - info!("starting compaction loop for {tenant_id}"); + info!("starting"); TENANT_TASK_EVENTS.with_label_values(&["start"]).inc(); async { loop { @@ -52,7 +56,7 @@ async fn compaction_loop(tenant_id: TenantId) { let tenant = tokio::select! { _ = task_mgr::shutdown_watcher() => { - info!("received compaction cancellation request"); + info!("received cancellation request"); return; }, tenant_wait_result = wait_for_active_tenant(tenant_id, wait_duration) => match tenant_wait_result { @@ -73,7 +77,7 @@ async fn compaction_loop(tenant_id: TenantId) { // Sleep tokio::select! { _ = task_mgr::shutdown_watcher() => { - info!("received compaction cancellation request during idling"); + info!("received cancellation request during idling"); break ; }, _ = tokio::time::sleep(sleep_duration) => {}, @@ -91,7 +95,7 @@ async fn compaction_loop(tenant_id: TenantId) { /// async fn gc_loop(tenant_id: TenantId) { let wait_duration = Duration::from_secs(2); - info!("starting gc loop for {tenant_id}"); + info!("starting"); TENANT_TASK_EVENTS.with_label_values(&["start"]).inc(); async { loop { @@ -99,7 +103,7 @@ async fn gc_loop(tenant_id: TenantId) { let tenant = tokio::select! { _ = task_mgr::shutdown_watcher() => { - info!("received GC cancellation request"); + info!("received cancellation request"); return; }, tenant_wait_result = wait_for_active_tenant(tenant_id, wait_duration) => match tenant_wait_result { @@ -123,7 +127,7 @@ async fn gc_loop(tenant_id: TenantId) { // Sleep tokio::select! { _ = task_mgr::shutdown_watcher() => { - info!("received GC cancellation request during idling"); + info!("received cancellation request during idling"); break; }, _ = tokio::time::sleep(sleep_duration) => {}, diff --git a/pageserver/src/walreceiver/connection_manager.rs b/pageserver/src/walreceiver/connection_manager.rs index 1e4b4e7d52..799062e935 100644 --- a/pageserver/src/walreceiver/connection_manager.rs +++ b/pageserver/src/walreceiver/connection_manager.rs @@ -58,7 +58,10 @@ pub fn spawn_connection_manager_task( TaskKind::WalReceiverManager, Some(tenant_id), Some(timeline_id), - &format!("walreceiver for tenant {} timeline {}", timeline.tenant_id, timeline.timeline_id), + &format!( + "walreceiver for tenant {} timeline {}", + timeline.tenant_id, timeline.timeline_id + ), false, async move { info!("WAL receiver broker started, connecting to etcd"); @@ -88,7 +91,9 @@ pub fn spawn_connection_manager_task( } } } - .instrument(info_span!("wal_connection_manager", tenant_id = %tenant_id, timeline_id = %timeline_id)) + .instrument( + info_span!("wal_connection_manager", tenant = %tenant_id, timeline = %timeline_id), + ), ); Ok(()) }