feat(query-engine): add window composition debug logs

asap-planner-rs/src/planner/promql.rs

@@ -6,6 +6,7 @@ use promql_utilities::query_logics::enums::{
     AggregationType, PromQLFunction, QueryTreatmentType, Statistic,
 };
 use promql_utilities::query_logics::parsing::get_metric_and_spatial_filter;
+use tracing::debug;
 
 use crate::config::input::{SketchParameterOverrides, WindowingConfig};
 use crate::error::ControllerError;
@@ -266,6 +267,17 @@ impl SingleQueryProcessor {
             self.windowing.as_ref(),
         )?;
 
+        debug!(
+            query = %self.query,
+            metric = %metric,
+            data_range_ms = requirements.data_range_ms,
+            step_ms = self.step_ms,
+            window_type = ?window_cfg.window_type,
+            window_size_ms = window_cfg.window_size_ms,
+            slide_interval_ms = window_cfg.slide_interval_ms,
+            "Selected streaming window configuration"
+        );
+
         let subpopulation_labels = requirements.grouping_labels;
         let rollup = all_labels.difference(&subpopulation_labels);
 

asap-query-engine/src/engines/simple_engine/mod.rs

@@ -15,7 +15,7 @@ use crate::stores::{Store, TimestampedBucketsMap};
 use std::collections::{BTreeSet, HashMap};
 use std::sync::{Arc, RwLock};
 use std::time::Instant;
-use tracing::{debug, warn};
+use tracing::{debug, trace, warn};
 
 use crate::precompute_operators::AccumulatorError;
 use crate::AggregateCore;
@@ -445,6 +445,20 @@ impl SimpleEngine {
         let range_ms = timestamps.end_timestamp - timestamps.start_timestamp;
         let do_merge = range_ms > aggregation_config_for_value.window_size_ms;
 
+        debug!(
+            metric,
+            value_aggregation_id = agg_info.aggregation_id_for_value,
+            key_aggregation_id = agg_info.aggregation_id_for_key,
+            query_start_timestamp = timestamps.start_timestamp,
+            query_end_timestamp = timestamps.end_timestamp,
+            range_ms,
+            window_type = ?window_type,
+            window_size_ms = aggregation_config_for_value.window_size_ms,
+            slide_interval_ms = Self::bucket_step_ms(aggregation_config_for_value),
+            do_merge,
+            "Built store query plan"
+        );
+
         let values_query = StoreQueryParams {
             metric: metric.to_string(),
             aggregation_id: agg_info.aggregation_id_for_value,
@@ -799,6 +813,12 @@ impl SimpleEngine {
             window_count = windows.len(),
             "Querying exact non-overlapping Sliding-window cover"
         );
+        trace!(
+            aggregation_id = params.aggregation_id,
+            output_timestamps = ?output_timestamps,
+            windows = ?windows,
+            "Planned exact Sliding-window cover ranges"
+        );
         let outputs = self
             .store
             .query_precomputed_output_exact_batch(&params.metric, params.aggregation_id, &windows)
@@ -2265,6 +2285,17 @@ impl SimpleEngine {
                     context.window_size_ms,
                 );
 
+                trace!(
+                    current_time,
+                    window_type = ?window_type,
+                    window_start,
+                    window_end,
+                    grid_step_ms = tumbling_window_ms,
+                    stored_window_size_ms = context.window_size_ms,
+                    selected_bucket_count = window_buckets.len(),
+                    "Composed query output window from stored buckets"
+                );
+
                 if window_type == WindowType::Sliding {
                     let expected = (lookback_ms / context.window_size_ms) as usize;
                     if window_buckets.len() < expected {