Add more tracing instrumentation

cargo-registry-index/lib.rs

@@ -299,6 +299,7 @@ impl Repository {
     /// - If cloning the crate index fails.
     /// - If reading the global git config fails.
     ///
+    #[instrument(skip_all)]
     pub fn open(repository_config: &RepositoryConfig) -> anyhow::Result<Self> {
         let checkout_path = tempfile::Builder::new()
             .prefix("git")
@@ -401,6 +402,7 @@ impl Repository {
     ///
     /// Note that `modified_file` expects a file path **relative** to the
     /// repository working folder!
+    #[instrument(skip_all, fields(message = %msg))]
     fn perform_commit_and_push(&self, msg: &str, modified_file: &Path) -> anyhow::Result<()> {
         // git add $file
         let mut index = self.repository.index()?;
@@ -421,6 +423,7 @@ impl Repository {
 
     /// Gets a list of files that have been modified since a given `starting_commit`
     /// (use `starting_commit = None` for a list of all files).
+    #[instrument(skip_all)]
     pub fn get_files_modified_since(
         &self,
         starting_commit: Option<&str>,
@@ -464,6 +467,7 @@ impl Repository {
     }
 
     /// Push the current branch to the provided refname
+    #[instrument(skip_all)]
     fn push(&self, refspec: &str) -> anyhow::Result<()> {
         let mut ref_status = Ok(());
         let mut callback_called = false;
@@ -513,6 +517,7 @@ impl Repository {
 
     /// Fetches any changes from the `origin` remote and performs a hard reset
     /// to the tip of the `origin/master` branch.
+    #[instrument(skip_all)]
     pub fn reset_head(&self) -> anyhow::Result<()> {
         let mut origin = self.repository.find_remote("origin")?;
         let original_head = self.head_oid()?;
@@ -549,6 +554,7 @@ impl Repository {
     }
 
     /// Reset `HEAD` to a single commit with all the index contents, but no parent
+    #[instrument(skip_all)]
     pub fn squash_to_single_commit(&self, msg: &str) -> anyhow::Result<()> {
         let tree = self.repository.find_commit(self.head_oid()?)?.tree()?;
         let sig = self.repository.signature()?;
@@ -583,6 +589,7 @@ impl Repository {
 ///
 /// This function also temporarily sets the `GIT_SSH_COMMAND` environment
 /// variable to ensure that `git push` commands are able to succeed.
+#[instrument(skip_all)]
 pub fn run_via_cli(command: &mut Command, credentials: &Credentials) -> anyhow::Result<()> {
     let temp_key_path = credentials
         .ssh_key()

src/app.rs

@@ -213,13 +213,15 @@ impl App {
     }
 
     /// Obtain a read/write database connection from the primary pool
+    #[instrument(skip_all)]
     pub fn db_write(&self) -> Result<DieselPooledConn<'_>, PoolError> {
         self.primary_database.get()
     }
 
     /// Obtain a readonly database connection from the replica pool
     ///
     /// If the replica pool is disabled or unavailable, the primary pool is used instead.
+    #[instrument(skip_all)]
     pub fn db_read(&self) -> Result<DieselPooledConn<'_>, PoolError> {
         let read_only_pool = self.read_only_replica_database.as_ref();
         match read_only_pool.map(|pool| pool.get()) {
@@ -248,6 +250,7 @@ impl App {
     /// Obtain a readonly database connection from the primary pool
     ///
     /// If the primary pool is unavailable, the replica pool is used instead, if not disabled.
+    #[instrument(skip_all)]
     pub fn db_read_prefer_primary(&self) -> Result<DieselPooledConn<'_>, PoolError> {
         match (
             self.primary_database.get(),

src/auth.rs

@@ -55,6 +55,7 @@ impl AuthCheck {
         }
     }
 
+    #[instrument(name = "auth.check", skip_all)]
     pub fn check<T: RequestPartsExt>(
         &self,
         request: &T,
@@ -156,6 +157,7 @@ impl Authentication {
     }
 }
 
+#[instrument(skip_all)]
 fn authenticate_via_cookie<T: RequestPartsExt>(
     req: &T,
     conn: &mut PgConnection,
@@ -177,6 +179,7 @@ fn authenticate_via_cookie<T: RequestPartsExt>(
     Ok(Some(CookieAuthentication { user }))
 }
 
+#[instrument(skip_all)]
 fn authenticate_via_token<T: RequestPartsExt>(
     req: &T,
     conn: &mut PgConnection,
@@ -207,6 +210,7 @@ fn authenticate_via_token<T: RequestPartsExt>(
     Ok(Some(TokenAuthentication { user, token }))
 }
 
+#[instrument(skip_all)]
 fn authenticate<T: RequestPartsExt>(req: &T, conn: &mut PgConnection) -> AppResult<Authentication> {
     controllers::util::verify_origin(req)?;
 

src/background_jobs.rs

@@ -339,6 +339,7 @@ impl Environment {
         }
     }
 
+    #[instrument(skip_all)]
     pub fn lock_index(&self) -> Result<MutexGuard<'_, Repository>, PerformError> {
         let repo = self.index.lock().unwrap_or_else(PoisonError::into_inner);
         repo.reset_head()?;

src/controllers/krate/publish.rs

@@ -350,6 +350,7 @@ pub fn missing_metadata_error_message(missing: &[&str]) -> String {
     )
 }
 
+#[instrument(skip_all)]
 pub fn add_dependencies(
     conn: &mut PgConnection,
     deps: &[EncodableCrateDependency],
@@ -425,6 +426,7 @@ pub fn add_dependencies(
     Ok(git_deps)
 }
 
+#[instrument(skip_all, fields(%pkg_name))]
 fn verify_tarball(
     pkg_name: &str,
     tarball: &[u8],

src/controllers/krate/search.rs

@@ -280,9 +280,12 @@ pub async fn search(app: AppState, req: Parts) -> AppResult<Json<Value>> {
             //
             // If this becomes a problem in the future the crates count could be denormalized, at least
             // for the filterless happy path.
-            let total: i64 = crates::table.count().get_result(conn)?;
+            let total: i64 = info_span!("db.query", message = "SELECT COUNT(*) FROM crates")
+                .in_scope(|| crates::table.count().get_result(conn))?;
 
-            let results: Vec<(Crate, bool, Option<i64>)> = query.load(conn)?;
+            let results: Vec<(Crate, bool, Option<i64>)> =
+                info_span!("db.query", message = "SELECT ... FROM crates")
+                    .in_scope(|| query.load(conn))?;
 
             let next_page = if let Some(last) = results.last() {
                 let mut params = IndexMap::new();
@@ -298,7 +301,9 @@ pub async fn search(app: AppState, req: Parts) -> AppResult<Json<Value>> {
             (total, next_page, None, results, conn)
         } else {
             let query = query.pages_pagination(pagination);
-            let data: Paginated<(Crate, bool, Option<i64>)> = query.load(conn)?;
+            let data: Paginated<(Crate, bool, Option<i64>)> =
+                info_span!("db.query", message = "SELECT ..., COUNT(*) FROM crates")
+                    .in_scope(|| query.load(conn))?;
             (
                 data.total(),
                 data.next_page_params().map(|p| req.query_with_params(p)),
@@ -315,7 +320,8 @@ pub async fn search(app: AppState, req: Parts) -> AppResult<Json<Value>> {
             .collect::<Vec<_>>();
         let crates = data.into_iter().map(|(c, _, _)| c).collect::<Vec<_>>();
 
-        let versions: Vec<Version> = crates.versions().load(conn)?;
+        let versions: Vec<Version> = info_span!("db.query", message = "SELECT ... FROM versions")
+            .in_scope(|| crates.versions().load(conn))?;
         let versions = versions
             .grouped_by(&crates)
             .into_iter()

src/db.rs

@@ -77,6 +77,7 @@ impl DieselPool {
         DieselPool::Test(Arc::new(Mutex::new(conn)))
     }
 
+    #[instrument(name = "db.connect", skip_all)]
     pub fn get(&self) -> Result<DieselPooledConn<'_>, PoolError> {
         match self {
             DieselPool::Pool {
@@ -112,6 +113,7 @@ impl DieselPool {
         }
     }
 
+    #[instrument(skip_all)]
     pub fn wait_until_healthy(&self, timeout: Duration) -> Result<(), PoolError> {
         match self {
             DieselPool::Pool { pool, .. } | DieselPool::BackgroundJobPool { pool } => {

src/models/krate.rs

@@ -416,6 +416,7 @@ impl Crate {
     }
 
     /// Returns (dependency, dependent crate name, dependent crate downloads)
+    #[instrument(skip_all, fields(krate.name = %self.name))]
     pub(crate) fn reverse_dependencies(
         &self,
         conn: &mut PgConnection,

src/uploaders.rs

@@ -109,6 +109,7 @@ impl Uploader {
     ///
     /// This function can panic on an `Self::Local` during development.
     /// Production and tests use `Self::S3` which should not panic.
+    #[instrument(skip_all, fields(%path))]
     pub fn upload<R: Into<Body>>(
         &self,
         client: &Client,
@@ -149,6 +150,7 @@ impl Uploader {
     }
 
     /// Deletes a file using the configured uploader (either `S3`, `Local`).
+    #[instrument(skip_all, fields(%path))]
     pub fn delete(&self, client: &Client, path: &str, upload_bucket: UploadBucket) -> Result<()> {
         match *self {
             Uploader::S3 {
@@ -176,6 +178,7 @@ impl Uploader {
     }
 
     /// Uploads a crate and returns the checksum of the uploaded crate file.
+    #[instrument(skip_all)]
     pub fn upload_crate<R: Into<Body>>(
         &self,
         http_client: &Client,
@@ -201,6 +204,7 @@ impl Uploader {
         Ok(())
     }
 
+    #[instrument(skip_all)]
     pub(crate) fn upload_readme(
         &self,
         http_client: &Client,
@@ -225,6 +229,7 @@ impl Uploader {
         Ok(())
     }
 
+    #[instrument(skip_all)]
     pub(crate) fn upload_index(
         &self,
         http_client: &Client,
@@ -248,6 +253,7 @@ impl Uploader {
         Ok(())
     }
 
+    #[instrument(skip_all)]
     pub(crate) fn delete_index(&self, http_client: &Client, crate_name: &str) -> Result<()> {
         let path = Uploader::index_path(crate_name);
         self.delete(http_client, &path, UploadBucket::Index)?;

src/worker/readmes.rs

@@ -7,6 +7,7 @@ use diesel::PgConnection;
 use crate::background_jobs::Environment;
 use crate::models::Version;
 
+#[instrument(skip_all, fields(krate.name))]
 pub fn perform_render_and_upload_readme(
     conn: &mut PgConnection,
     env: &Environment,
@@ -19,6 +20,8 @@ pub fn perform_render_and_upload_readme(
     use crate::schema::*;
     use diesel::prelude::*;
 
+    info!(?version_id, "Rendering README");
+
     let rendered = text_to_html(text, readme_path, base_url, pkg_path_in_vcs);
 
     conn.transaction(|conn| {
@@ -28,6 +31,9 @@ pub fn perform_render_and_upload_readme(
             .inner_join(crates::table)
             .select((crates::name, versions::num))
             .first(conn)?;
+
+        tracing::Span::current().record("krate.name", tracing::field::display(&crate_name));
+
         env.uploader
             .upload_readme(env.http_client(), &crate_name, &vers, rendered)?;
         Ok(())