Merge pull request ClickHouse#80679 from ClickHouse/add-observability-for-index-search-algorithm

Add ProfileEvents for index search algorithm

Author: pamarcos

src/Common/ProfileEvents.cpp

@@ -1027,6 +1027,8 @@ The server successfully detected this situation and will download merged part fr
     M(FilterTransformPassedRows, "Number of rows that passed the filter in the query", ValueType::Number) \
     M(FilterTransformPassedBytes, "Number of bytes that passed the filter in the query", ValueType::Bytes) \
     M(QueryPreempted, "How many times tasks are paused and waiting due to 'priority' setting", ValueType::Number) \
+    M(IndexBinarySearchAlgorithm, "Number of times the binary search algorithm is used over the index marks", ValueType::Number) \
+    M(IndexGenericExclusionSearchAlgorithm, "Number of times the generic exclusion search algorithm is used over the index marks", ValueType::Number) \
 
 
 #ifdef APPLY_FOR_EXTERNAL_EVENTS

src/Storages/MergeTree/MergeTreeDataSelectExecutor.cpp

@@ -55,6 +55,7 @@
 #include <Common/CurrentMetrics.h>
 #include <Common/ElapsedTimeProfileEventIncrement.h>
 #include <Common/FailPoint.h>
+#include <Common/ProfileEvents.h>
 #include <Common/quoteString.h>
 
 #include <IO/WriteBufferFromOStream.h>
@@ -72,6 +73,8 @@ namespace ProfileEvents
 {
 extern const Event FilteringMarksWithPrimaryKeyMicroseconds;
 extern const Event FilteringMarksWithSecondaryKeysMicroseconds;
+extern const Event IndexBinarySearchAlgorithm;
+extern const Event IndexGenericExclusionSearchAlgorithm;
 }
 
 namespace DB
@@ -1474,6 +1477,7 @@ MarkRanges MergeTreeDataSelectExecutor::markRangesFromPKRange(
             }
         }
 
+        ProfileEvents::increment(ProfileEvents::IndexGenericExclusionSearchAlgorithm);
         LOG_TRACE(
             log,
             "Used generic exclusion search {}over index for part {} with {} steps",
@@ -1487,6 +1491,7 @@ MarkRanges MergeTreeDataSelectExecutor::markRangesFromPKRange(
         /// we can use binary search algorithm to find the left and right endpoint key marks of such interval.
         /// The returned value is the minimum range of marks, containing all keys for which KeyCondition holds
 
+        ProfileEvents::increment(ProfileEvents::IndexBinarySearchAlgorithm);
         LOG_TRACE(log, "Running binary search on index range for part {} ({} marks)", part_name, marks_count);
 
         size_t steps = 0;

tests/queries/0_stateless/03518_key_condition_binary_search.reference

@@ -1,2 +1,2 @@
-3
-1
+3	0
+0	1

tests/queries/0_stateless/03518_key_condition_binary_search.sh

@@ -4,6 +4,8 @@ CUR_DIR=$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)
 # shellcheck source=../shell_config.sh
 . "$CUR_DIR"/../shell_config.sh
 
+readonly query_prefix=$CLICKHOUSE_DATABASE
+
 $CLICKHOUSE_CLIENT -n -q "
 DROP TABLE IF EXISTS t;
 CREATE TABLE t
@@ -12,11 +14,11 @@ CREATE TABLE t
 )
 ENGINE = MergeTree
 ORDER BY c;
-INSERT INTO t values('One');
-SELECT * FROM t WHERE c = 1 settings send_logs_level='trace';
-SELECT * FROM t WHERE c = 'One' settings send_logs_level='trace';
-SELECT * FROM t WHERE c = 1 and 1 = 1 settings send_logs_level='trace';
-" 2>&1 | grep -c "binary search"
+INSERT INTO t values('One');"
+
+$CLICKHOUSE_CLIENT -n -q "SELECT * FROM t WHERE c = 1 FORMAT Null;" --query_id="${query_prefix}_binary1"
+$CLICKHOUSE_CLIENT -n -q "SELECT * FROM t WHERE c = 'One' FORMAT Null;" --query_id="${query_prefix}_binary2"
+$CLICKHOUSE_CLIENT -n -q "SELECT * FROM t WHERE c = 1 and 1 = 1  FORMAT Null;" --query_id="${query_prefix}_binary3"
 
 $CLICKHOUSE_CLIENT -n -q "
 DROP TABLE IF EXISTS t1;
@@ -26,6 +28,12 @@ CREATE TABLE t1
 )
 ENGINE = MergeTree
 ORDER BY timestamp;
-INSERT INTO t1 VALUES ('2025-05-21 00:00:00');
-SELECT * FROM t1 WHERE toDayOfMonth(timestamp) = 1 settings send_logs_level='trace';
-" 2>&1 | grep -c "generic exclusion search"
+INSERT INTO t1 VALUES ('2025-05-21 00:00:00');"
+
+$CLICKHOUSE_CLIENT -n -q "SELECT * FROM t1 WHERE toDayOfMonth(timestamp) = 1 FORMAT Null;" --query-id="${query_prefix}_generic"
+$CLICKHOUSE_CLIENT -n -q "SYSTEM FLUSH LOGS query_log;"
+
+$CLICKHOUSE_CLIENT -n -q "SELECT sum(ProfileEvents['IndexBinarySearchAlgorithm']), sum(ProfileEvents['IndexGenericExclusionSearchAlgorithm']) FROM system.query_log
+    WHERE type > 1 AND event_date >= yesterday() AND query_id ILIKE '${query_prefix}_binary%' AND current_database = currentDatabase()"
+$CLICKHOUSE_CLIENT -n -q "SELECT sum(ProfileEvents['IndexBinarySearchAlgorithm']), sum(ProfileEvents['IndexGenericExclusionSearchAlgorithm']) FROM system.query_log
+    WHERE type > 1 AND event_date >= yesterday() AND query_id ILIKE '${query_prefix}_generic%' AND current_database = currentDatabase()"