From 31ddfc6f5f8b2cca0f003102ee296738b4ad9789 Mon Sep 17 00:00:00 2001 From: Alexander Gololobov Date: Fri, 13 Sep 2024 19:19:21 +0200 Subject: [PATCH 1/3] Check time limit while analyzing indexes --- .../MergeTree/MergeTreeDataSelectExecutor.cpp | 17 +++++++++++++++-- .../MergeTree/MergeTreeDataSelectExecutor.h | 3 ++- 2 files changed, 17 insertions(+), 3 deletions(-) diff --git a/src/Storages/MergeTree/MergeTreeDataSelectExecutor.cpp b/src/Storages/MergeTree/MergeTreeDataSelectExecutor.cpp index 03db96dd016..5d246293396 100644 --- a/src/Storages/MergeTree/MergeTreeDataSelectExecutor.cpp +++ b/src/Storages/MergeTree/MergeTreeDataSelectExecutor.cpp @@ -23,6 +23,7 @@ #include #include #include +#include #include #include #include @@ -528,6 +529,8 @@ void MergeTreeDataSelectExecutor::filterPartsByPartition( } auto query_context = context->hasQueryContext() ? context->getQueryContext() : context; + QueryStatusPtr query_status = context->getProcessListElement(); + PartFilterCounters part_filter_counters; if (query_context->getSettingsRef().allow_experimental_query_deduplication) selectPartsToReadWithUUIDFilter( @@ -549,7 +552,8 @@ void MergeTreeDataSelectExecutor::filterPartsByPartition( minmax_columns_types, partition_pruner, max_block_numbers_to_read, - part_filter_counters); + part_filter_counters, + query_status); index_stats.emplace_back(ReadFromMergeTree::IndexStat{ .type = ReadFromMergeTree::IndexType::None, @@ -649,8 +653,13 @@ RangesInDataParts MergeTreeDataSelectExecutor::filterPartsByPrimaryKeyAndSkipInd auto mark_cache = context->getIndexMarkCache(); auto uncompressed_cache = context->getIndexUncompressedCache(); + auto query_status = context->getProcessListElement(); + auto process_part = [&](size_t part_index) { + if (query_status) + query_status->checkTimeLimit(); + auto & part = parts[part_index]; RangesInDataPart ranges(part, part_index); @@ -1545,13 +1554,17 @@ void MergeTreeDataSelectExecutor::selectPartsToRead( const DataTypes & minmax_columns_types, const std::optional & partition_pruner, const PartitionIdToMaxBlock * max_block_numbers_to_read, - PartFilterCounters & counters) + PartFilterCounters & counters, + QueryStatusPtr query_status) { MergeTreeData::DataPartsVector prev_parts; std::swap(prev_parts, parts); for (const auto & part_or_projection : prev_parts) { + if (query_status) + query_status->checkTimeLimit(); + const auto * part = part_or_projection->isProjectionPart() ? part_or_projection->getParentPart() : part_or_projection.get(); if (part_values && part_values->find(part->name) == part_values->end()) continue; diff --git a/src/Storages/MergeTree/MergeTreeDataSelectExecutor.h b/src/Storages/MergeTree/MergeTreeDataSelectExecutor.h index 3668eb0ad90..70536b7aa54 100644 --- a/src/Storages/MergeTree/MergeTreeDataSelectExecutor.h +++ b/src/Storages/MergeTree/MergeTreeDataSelectExecutor.h @@ -126,7 +126,8 @@ private: const DataTypes & minmax_columns_types, const std::optional & partition_pruner, const PartitionIdToMaxBlock * max_block_numbers_to_read, - PartFilterCounters & counters); + PartFilterCounters & counters, + QueryStatusPtr query_status); /// Same as previous but also skip parts uuids if any to the query context, or skip parts which uuids marked as excluded. static void selectPartsToReadWithUUIDFilter( From 4af369fbc4bada857e267f34440df72f1aaba425 Mon Sep 17 00:00:00 2001 From: Alexander Gololobov Date: Mon, 16 Sep 2024 13:34:01 +0200 Subject: [PATCH 2/3] Failpoint for testing slow index analysis --- src/Common/FailPoint.cpp | 1 + .../MergeTree/MergeTreeDataSelectExecutor.cpp | 12 ++++++++++++ 2 files changed, 13 insertions(+) diff --git a/src/Common/FailPoint.cpp b/src/Common/FailPoint.cpp index b2fcbc77c56..1b65447efc3 100644 --- a/src/Common/FailPoint.cpp +++ b/src/Common/FailPoint.cpp @@ -63,6 +63,7 @@ static struct InitFiu REGULAR(keepermap_fail_drop_data) \ REGULAR(lazy_pipe_fds_fail_close) \ PAUSEABLE(infinite_sleep) \ + REGULAR(slowdown_index_analysis) \ namespace FailPoints diff --git a/src/Storages/MergeTree/MergeTreeDataSelectExecutor.cpp b/src/Storages/MergeTree/MergeTreeDataSelectExecutor.cpp index 5d246293396..6e0ae8f7cca 100644 --- a/src/Storages/MergeTree/MergeTreeDataSelectExecutor.cpp +++ b/src/Storages/MergeTree/MergeTreeDataSelectExecutor.cpp @@ -41,6 +41,8 @@ #include #include #include +#include +#include #include #include #include @@ -75,6 +77,11 @@ namespace ErrorCodes extern const int DUPLICATED_PART_UUIDS; } +namespace FailPoints +{ + extern const char slowdown_index_analysis[]; +} + MergeTreeDataSelectExecutor::MergeTreeDataSelectExecutor(const MergeTreeData & data_) : data(data_), log(getLogger(data.getLogName() + " (SelectExecutor)")) @@ -1565,6 +1572,11 @@ void MergeTreeDataSelectExecutor::selectPartsToRead( if (query_status) query_status->checkTimeLimit(); + fiu_do_on(FailPoints::slowdown_index_analysis, + { + sleepForMilliseconds(1000); + }); + const auto * part = part_or_projection->isProjectionPart() ? part_or_projection->getParentPart() : part_or_projection.get(); if (part_values && part_values->find(part->name) == part_values->end()) continue; From f5b9d5ad34e6e3c7143ac26f4cc871db3b69604d Mon Sep 17 00:00:00 2001 From: Alexander Gololobov Date: Mon, 16 Sep 2024 13:34:40 +0200 Subject: [PATCH 3/3] Test for checking time limit in index analysis --- ..._check_timeout_in_index_analysis.reference | 4 +++ .../03176_check_timeout_in_index_analysis.sql | 32 +++++++++++++++++++ 2 files changed, 36 insertions(+) create mode 100644 tests/queries/0_stateless/03176_check_timeout_in_index_analysis.reference create mode 100644 tests/queries/0_stateless/03176_check_timeout_in_index_analysis.sql diff --git a/tests/queries/0_stateless/03176_check_timeout_in_index_analysis.reference b/tests/queries/0_stateless/03176_check_timeout_in_index_analysis.reference new file mode 100644 index 00000000000..05a83c81dae --- /dev/null +++ b/tests/queries/0_stateless/03176_check_timeout_in_index_analysis.reference @@ -0,0 +1,4 @@ +5 +03176_q1 1 0 0 +03176_q2 1 2 0 +03176_q3 0 1 1 diff --git a/tests/queries/0_stateless/03176_check_timeout_in_index_analysis.sql b/tests/queries/0_stateless/03176_check_timeout_in_index_analysis.sql new file mode 100644 index 00000000000..4163ad58c4e --- /dev/null +++ b/tests/queries/0_stateless/03176_check_timeout_in_index_analysis.sql @@ -0,0 +1,32 @@ +-- Tags: no-parallel, no-tsan, no-asan, no-ubsan, no-msan, no-debug, no-fasttest +-- no-parallel because the test uses failpoint + +CREATE TABLE t_03176(k UInt64, v UInt64) ENGINE=MergeTree() ORDER BY k PARTITION BY k; + +INSERT INTO t_03176 SELECT number, number FROM numbers(5); + +-- Table is partitioned by k to so it will have 5 partitions +SELECT count() FROM system.parts WHERE database = currentDatabase() AND table = 't_03176' AND active; + +-- This query is fast without failpoint: should take < 1 sec +EXPLAIN indexes = 1 SELECT * FROM t_03176 ORDER BY k LIMIT 5 SETTINGS log_comment = '03176_q1' FORMAT Null; + +SYSTEM ENABLE FAILPOINT slowdown_index_analysis; + +-- Check that failpont actually works: the query should take >= 5 sec +EXPLAIN indexes = 1 SELECT * FROM t_03176 ORDER BY k LIMIT 5 SETTINGS log_comment = '03176_q2' FORMAT Null; + +-- Now the query should be cancelled after about 1 sec +EXPLAIN indexes = 1 SELECT * FROM t_03176 ORDER BY k LIMIT 5 SETTINGS log_comment = '03176_q3', max_execution_time = 1.1 FORMAT Null; -- { serverError TIMEOUT_EXCEEDED } + +SYSTEM DISABLE FAILPOINT slowdown_index_analysis; + +SYSTEM FLUSH LOGS; + +-- Check that q1 was fast, q2 was slow and q3 had timeout +SELECT log_comment, type = 'QueryFinish', intDiv(query_duration_ms, 2000), length(exception) > 0 +FROM system.query_log +WHERE current_database = currentDatabase() AND log_comment LIKE '03176_q_' AND type IN ('QueryFinish', 'ExceptionBeforeStart') +ORDER BY log_comment; + +DROP TABLE t_03176;