From 68a50137cd250272ef1f8b84daa8ddd21170c4fc Mon Sep 17 00:00:00 2001 From: Seongmin Lee Date: Fri, 9 Oct 2026 17:55:21 +0900 Subject: [PATCH] knot2,gitmirror maintenance logs Signed-off-by: Seongmin Lee --- .../crates/gitmirror-maintenance/src/lib.rs | 10 +- knot2/crates/knot-maintenance/src/lib.rs | 118 ++++++++++++------ 2 files changed, 88 insertions(+), 40 deletions(-) diff --git a/gitmirror/crates/gitmirror-maintenance/src/lib.rs b/gitmirror/crates/gitmirror-maintenance/src/lib.rs index 53348154e..679fa56c5 100644 --- a/gitmirror/crates/gitmirror-maintenance/src/lib.rs +++ b/gitmirror/crates/gitmirror-maintenance/src/lib.rs @@ -1,7 +1,7 @@ //! periodic repository maintenance (repack, prune, commit-graph, midx) use std::sync::Arc; -use std::time::Duration; +use std::time::{Duration, Instant}; use bobbin_runtime::Clock; use gitmirror_db::Db; @@ -48,12 +48,20 @@ impl MaintenanceWorker { continue; } }; + let started = Instant::now(); + let count = repos.len(); + info!(repos = count, "maintenance pass started"); for did in repos { if self.rt.cancel.is_cancelled() { break; } self.maintain_one(did).await; } + info!( + repos = count, + duration_ms = started.elapsed().as_millis() as u64, + "maintenance pass finished" + ); } info!("maintenance worker stopped"); } diff --git a/knot2/crates/knot-maintenance/src/lib.rs b/knot2/crates/knot-maintenance/src/lib.rs index 8dad43f62..7a909f93b 100644 --- a/knot2/crates/knot-maintenance/src/lib.rs +++ b/knot2/crates/knot-maintenance/src/lib.rs @@ -1,6 +1,6 @@ use std::collections::HashSet; use std::path::PathBuf; -use std::time::Duration; +use std::time::{Duration, Instant}; use knot_git::{PackRefsReport, RefClass, ReflogReport, Repo}; use knot_types::{Oid, UnixSeconds}; @@ -242,15 +242,24 @@ pub fn run_repo( now_seconds: UnixSeconds, opts: &Options, ) -> Result { + let started = Instant::now(); let objects_dir = repo.objects_dir(); let kind = repo.object_format().kind(); let snapshot = Snapshot::take(repo, opts, now_seconds); let loose = &snapshot.loose; + tracing::info!( + repo = %repo.path().display(), + loose = loose.len(), + loose_refs = snapshot.loose_refs, + "maintenance started" + ); // open previous bitmap before repack. rollup and cruft clear the midx and delete packs but old // midx is needed to map the old bitmap's positions to OIDs. // TODO(boltless): follow git's flow instead let previous_bitmap = if opts.bitmap { - knot_git::open_bitmap_index(repo).ok().flatten() + timed(repo, "open_bitmap", || knot_git::open_bitmap_index(repo)) + .ok() + .flatten() } else { None }; @@ -260,14 +269,16 @@ pub fn run_repo( } let packed_refs = if snapshot.due(Task::PackRefs) { - repo.pack_refs()? + timed(repo, "pack_refs", || repo.pack_refs())? } else { PackRefsReport { packed: 0 } }; let floor_secs = (opts.reflog_floor.get().as_secs() as i64).max(MIN_REFLOG_RETENTION_SECS); let retention_floor = now_seconds.saturating_sub_secs(floor_secs); let reflog = if snapshot.due(Task::ExpireReflog) { - repo.expire_reflogs(retention_floor)? + timed(repo, "expire_reflogs", || { + repo.expire_reflogs(retention_floor) + })? } else { ReflogReport { files: 0, @@ -282,19 +293,23 @@ pub fn run_repo( let (repack, reachable, roots, new_stem, kept_large) = if full_repack { let roots = collect_roots(repo, retention_floor)?; - let (report, reachable, new_stem, kept_large) = repack::run( - repo, - &objects_dir, - kind, - roots.iter().copied().collect(), - opts.repack_max_objects, - opts.geometric_factor, - loose, - )?; + let (report, reachable, new_stem, kept_large) = timed(repo, "full_repack", || { + repack::run( + repo, + &objects_dir, + kind, + roots.iter().copied().collect(), + opts.repack_max_objects, + opts.geometric_factor, + loose, + ) + })?; (report, reachable, roots, new_stem, kept_large) } else if snapshot.due(Task::Repack) { ( - repack::roll_up(&objects_dir, kind, opts.geometric_factor, loose)?, + timed(repo, "roll_up", || { + repack::roll_up(&objects_dir, kind, opts.geometric_factor, loose) + })?, None, HashSet::new(), None, @@ -311,25 +326,27 @@ pub fn run_repo( }; let prune = match &reachable { - Some(set) => repo.with_ref_lock(|| { - let current = collect_roots(repo, retention_floor)?; - if current != roots { - return Ok(PruneReport::skipped()); - } - if repack.status == RepackStatus::Repacked { - midx::clear(&objects_dir)?; - cruft::run( - &objects_dir, - kind, - set, - new_stem.as_ref(), - &kept_large, - loose, - opts.prune_grace.get(), - ) - } else { - prune::run(&objects_dir, set, loose, opts.prune_grace.get()) - } + Some(set) => timed(repo, "prune", || { + repo.with_ref_lock(|| { + let current = collect_roots(repo, retention_floor)?; + if current != roots { + return Ok(PruneReport::skipped()); + } + if repack.status == RepackStatus::Repacked { + midx::clear(&objects_dir)?; + cruft::run( + &objects_dir, + kind, + set, + new_stem.as_ref(), + &kept_large, + loose, + opts.prune_grace.get(), + ) + } else { + prune::run(&objects_dir, set, loose, opts.prune_grace.get()) + } + }) })?, None => PruneReport::skipped(), }; @@ -337,9 +354,11 @@ pub fn run_repo( let commit_graph = if !opts.commit_graph { false } else if full_repack { - commitgraph::write(repo)? + timed(repo, "commit_graph", || commitgraph::write(repo))? } else if snapshot.due(Task::CommitGraph) { - commitgraph::write_layer(repo)? + timed(repo, "commit_graph_layer", || { + commitgraph::write_layer(repo) + })? } else { false }; @@ -347,18 +366,20 @@ pub fn run_repo( let multi_pack_index = if !opts.multi_pack_index { MidxStatus::Absent } else if snapshot.due(Task::MultiPackIndex) { - midx::write(repo)? + timed(repo, "multi_pack_index", || midx::write(repo))? } else { MidxStatus::Unchanged }; let bitmap = if opts.bitmap && snapshot.due(Task::Bitmap) { - bitmap::refresh(repo, &objects_dir, previous_bitmap.as_ref())? + timed(repo, "bitmap", || { + bitmap::refresh(repo, &objects_dir, previous_bitmap.as_ref()) + })? } else { false }; - Ok(Report { + let report = Report { packed_refs, reflog, commit_graph, @@ -366,7 +387,26 @@ pub fn run_repo( prune, multi_pack_index, bitmap, - }) + }; + tracing::info!( + repo = %repo.path().display(), + duration_ms = started.elapsed().as_millis() as u64, + ?report, + "maintenance finished" + ); + Ok(report) +} + +fn timed(repo: &Repo, task: &'static str, run: impl FnOnce() -> T) -> T { + let started = Instant::now(); + let out = run(); + tracing::info!( + repo = %repo.path().display(), + task, + duration_ms = started.elapsed().as_millis() as u64, + "maintenance task finished" + ); + out } fn collect_roots(repo: &Repo, retention_floor: UnixSeconds) -> Result, MaintError> { -- 2.54.0