From 673e2335420b46072968bd2f6e9e0b65bfaee71d Mon Sep 17 00:00:00 2001
From: Adam Harvey <adam@adamharvey.name>
Date: Wed, 5 Nov 2025 17:15:48 -0800
Subject: [PATCH] worker: add more fine-grained logging for Git index syncs

This should be reverted once we have the data we need, but in the short
term, this will be useful to decide our next step with #12281.
---
 crates/crates_io_index/repo.rs | 6 ++++++
 src/worker/environment.rs      | 2 ++
 src/worker/jobs/index/sync.rs  | 6 ++++++
 3 files changed, 14 insertions(+)

diff --git a/crates/crates_io_index/repo.rs b/crates/crates_io_index/repo.rs
index 87fe276adba..daa66c978c9 100644
--- a/crates/crates_io_index/repo.rs
+++ b/crates/crates_io_index/repo.rs
@@ -5,6 +5,7 @@ use crates_io_env_vars::{required_var, required_var_parsed, var};
 use secrecy::{ExposeSecret, SecretString};
 use std::path::{Path, PathBuf};
 use std::process::Command;
+use std::time::Instant;
 use tempfile::TempDir;
 use url::Url;
 
@@ -282,8 +283,13 @@ impl Repository {
     pub fn reset_head(&self) -> anyhow::Result<()> {
         let original_head = self.head_oid()?;
 
+        let fetch_start = Instant::now();
         self.run_command(Command::new("git").args(["fetch", "origin", "master"]))?;
+        info!(duration = fetch_start.elapsed().as_nanos(), "Index fetched");
+
+        let reset_start = Instant::now();
         self.run_command(Command::new("git").args(["reset", "--hard", "origin/master"]))?;
+        info!(duration = reset_start.elapsed().as_nanos(), "Index reset");
 
         let head = self.head_oid()?;
         if head != original_head {
diff --git a/src/worker/environment.rs b/src/worker/environment.rs
index 5f1579c8802..0de9d1500a5 100644
--- a/src/worker/environment.rs
+++ b/src/worker/environment.rs
@@ -47,7 +47,9 @@ pub struct Environment {
 impl Environment {
     #[instrument(skip_all)]
     pub fn lock_index(&self) -> anyhow::Result<RepositoryLock<'_>> {
+        let lock_start = Instant::now();
         let mut repo = self.repository.lock();
+        info!(duration = lock_start.elapsed().as_nanos(), "Index locked");
 
         if repo.is_none() {
             info!("Cloning index");
diff --git a/src/worker/jobs/index/sync.rs b/src/worker/jobs/index/sync.rs
index efdd14507bf..d4bc7329ae1 100644
--- a/src/worker/jobs/index/sync.rs
+++ b/src/worker/jobs/index/sync.rs
@@ -11,6 +11,7 @@ use std::fs;
 use std::fs::File;
 use std::io::{ErrorKind, Write};
 use std::sync::Arc;
+use std::time::Instant;
 use tracing::{debug, info, instrument};
 
 #[derive(Serialize, Deserialize)]
@@ -56,6 +57,7 @@ impl BackgroundJob for SyncToGitIndex {
                 Err(error) => return Err(error.into()),
             };
 
+            let commit_and_push_start = Instant::now();
             match (old, new) {
                 (None, Some(new)) => {
                     fs::create_dir_all(dst.parent().unwrap())?;
@@ -74,6 +76,10 @@ impl BackgroundJob for SyncToGitIndex {
                 }
                 _ => debug!("Skipping sync because index is up-to-date"),
             }
+            info!(
+                duration = commit_and_push_start.elapsed().as_nanos(),
+                "Committed and pushed"
+            );
 
             Ok(())
         })