chore: Add debug info of sort_key for ingester (#4859)

Co-authored-by: kodiakhq[bot] <49736102+kodiakhq[bot]@users.noreply.github.com>

Cargo.lock

@@ -4597,6 +4597,7 @@ dependencies = [
  "hashbrown 0.12.1",
  "indexmap",
  "itertools",
+ "observability_deps",
  "snafu",
  "workspace-hack",
 ]

ingester/src/data.rs

@@ -274,7 +274,7 @@ impl Persister for IngesterData {
                     partition_info.namespace_name, partition_info.partition.sequencer_id
                 )
             });
-        debug!(?partition_info, "Persisting");
+        debug!(?partition_id, ?partition_info, "Persisting");
 
         let persisting_batch = namespace.snapshot_to_persisting(&partition_info).await;
 
@@ -300,6 +300,11 @@ impl Persister for IngesterData {
                     return;
                 }
             };
+            debug!(
+                ?partition_id,
+                ?sort_key_update,
+                "Adjusted sort key during compacting the persting batch"
+            );
 
             // Save the compacted data to a parquet file in object storage.
             //
@@ -328,6 +333,12 @@ impl Persister for IngesterData {
             // Update the sort key in the catalog if there are additional columns
             if let Some(new_sort_key) = sort_key_update {
                 let sort_key = new_sort_key.to_columns().collect::<Vec<_>>();
+                debug!(
+                    ?partition_id,
+                    ?sort_key,
+                    ?partition_id,
+                    "Adjusted sort key to be updated to the catalog"
+                );
                 Backoff::new(&self.backoff_config)
                     .retry_all_errors("update_sort_key", || async {
                         let mut repos = self.catalog.repositories().await;
@@ -342,6 +353,7 @@ impl Persister for IngesterData {
 
             // and remove the persisted data from memory
             debug!(
+                ?partition_id,
                 table_name=%partition_info.table_name,
                 partition_key=%partition_info.partition.partition_key,
                 max_sequence_number=%iox_meta.max_sequence_number.get(),

iox_catalog/src/postgres.rs

@@ -17,7 +17,7 @@ use data_types::{
     Sequencer, SequencerId, Table, TableId, TablePartition, Timestamp, Tombstone, TombstoneId,
 };
 use iox_time::{SystemProvider, TimeProvider};
-use observability_deps::tracing::{info, warn};
+use observability_deps::tracing::{debug, info, warn};
 use sqlx::{
     migrate::Migrator, postgres::PgPoolOptions, types::Uuid, Acquire, Executor, Postgres, Row,
 };
@@ -1243,6 +1243,8 @@ RETURNING *;
             _ => Error::SqlxError { source: e },
         })?;
 
+        debug!(?partition_id, input_sort_key=?sort_key, partition_after_catalog_update=?partition, "Paritition after updating sort key");
+
         Ok(partition)
     }
 }

schema/Cargo.toml

@@ -10,5 +10,6 @@ arrow = { version = "16.0.0", features = ["prettyprint"] }
 hashbrown = "0.12"
 indexmap = { version = "1.8", features = ["std"] }
 itertools = "0.10.1"
+observability_deps = { path = "../observability_deps" }
 snafu = "0.7"
 workspace-hack = { path = "../workspace-hack"}

schema/src/sort.rs

@@ -7,6 +7,7 @@ use arrow::{
 };
 use indexmap::{map::Iter, IndexMap};
 use itertools::Itertools;
+use observability_deps::tracing::debug;
 use snafu::Snafu;
 use std::{
     collections::{HashMap, HashSet},
@@ -383,7 +384,10 @@ pub fn compute_sort_key<'a>(
         builder = builder.with_col(col)
     }
     builder = builder.with_col(TIME_COLUMN_NAME);
-    builder.build()
+    let sort_key = builder.build();
+
+    debug!(?primary_key, ?sort_key, "Computed sort key");
+    sort_key
 }
 
 /// Takes batches of data and the columns that make up the primary key. Computes the number of
@@ -511,6 +515,8 @@ pub fn adjust_sort_key_columns(
         ))
     };
 
+    debug!(?primary_key, input_catalog_sort_key=?catalog_sort_key, output_chunk_sort_key=?metadata_sort_key, output_catalog_sort_key=?catalog_update, "Adjusted sort key");
+
     (metadata_sort_key, catalog_update)
 }