From b682dbbc2e7db1df1bf29bf48aa83569f7951d31 Mon Sep 17 00:00:00 2001
From: Nga Tran <nga-tran@live.com>
Date: Tue, 14 Jun 2022 16:39:17 -0400
Subject: [PATCH] chore: Add debug info of sort_key for ingester (#4859)

Co-authored-by: kodiakhq[bot] <49736102+kodiakhq[bot]@users.noreply.github.com>
---
 Cargo.lock                  |  1 +
 ingester/src/data.rs        | 14 +++++++++++++-
 iox_catalog/src/postgres.rs |  4 +++-
 schema/Cargo.toml           |  1 +
 schema/src/sort.rs          |  8 +++++++-
 5 files changed, 25 insertions(+), 3 deletions(-)

diff --git a/Cargo.lock b/Cargo.lock
index 3a572d26ab..312d3aeed8 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -4597,6 +4597,7 @@ dependencies = [
  "hashbrown 0.12.1",
  "indexmap",
  "itertools",
+ "observability_deps",
  "snafu",
  "workspace-hack",
 ]
diff --git a/ingester/src/data.rs b/ingester/src/data.rs
index 18b6e4f6a6..16d61845d3 100644
--- a/ingester/src/data.rs
+++ b/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(),
diff --git a/iox_catalog/src/postgres.rs b/iox_catalog/src/postgres.rs
index 743a36f970..66cef6a526 100644
--- a/iox_catalog/src/postgres.rs
+++ b/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)
     }
 }
diff --git a/schema/Cargo.toml b/schema/Cargo.toml
index 200fbf85eb..80632b9e73 100644
--- a/schema/Cargo.toml
+++ b/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"}
diff --git a/schema/src/sort.rs b/schema/src/sort.rs
index 32c3e55a45..bac472f2a2 100644
--- a/schema/src/sort.rs
+++ b/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)
 }