Adjust spans around gc and compaction

So compaction and gc loops have their own span to always show tenant id
in log messages.
This commit is contained in:
Dmitry Rodionov
2022-09-19 18:41:18 +03:00
committed by Dmitry Rodionov
parent 4b5e7f2f82
commit fcb4a61a12
5 changed files with 28 additions and 19 deletions

View File

@@ -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

View File

@@ -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<GcResult> {
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();

View File

@@ -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.

View File

@@ -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) => {},

View File

@@ -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(())
}