From d0394719c6da6c3a7d647332b7ae977f703636b6 Mon Sep 17 00:00:00 2001 From: kssenii Date: Fri, 1 Nov 2024 12:11:07 +0100 Subject: [PATCH 1/9] More assertions --- .../IO/CachedOnDiskReadBufferFromFile.cpp | 1 + src/Interpreters/Cache/FileCache.cpp | 2 + src/Interpreters/Cache/FileSegment.cpp | 91 ++++++++++++++----- src/Interpreters/Cache/FileSegment.h | 2 +- src/Interpreters/Cache/Metadata.cpp | 21 +++-- 5 files changed, 89 insertions(+), 28 deletions(-) diff --git a/src/Disks/IO/CachedOnDiskReadBufferFromFile.cpp b/src/Disks/IO/CachedOnDiskReadBufferFromFile.cpp index 51c6045cb68..0f0cc4c4139 100644 --- a/src/Disks/IO/CachedOnDiskReadBufferFromFile.cpp +++ b/src/Disks/IO/CachedOnDiskReadBufferFromFile.cpp @@ -784,6 +784,7 @@ bool CachedOnDiskReadBufferFromFile::writeCache(char * data, size_t size, size_t LOG_INFO(log, "Insert into cache is skipped due to insufficient disk space. ({})", e.displayText()); return false; } + chassert(file_segment.state() == FileSegment::State::PARTIALLY_DOWNLOADED_NO_CONTINUATION); throw; } diff --git a/src/Interpreters/Cache/FileCache.cpp b/src/Interpreters/Cache/FileCache.cpp index f7b7ffc5aea..ae3c9c58fc5 100644 --- a/src/Interpreters/Cache/FileCache.cpp +++ b/src/Interpreters/Cache/FileCache.cpp @@ -1438,6 +1438,8 @@ void FileCache::loadMetadataForKeys(const fs::path & keys_dir) "cached file `{}` does not fit in cache anymore (size: {})", size_limit, offset_it->path().string(), size); + chassert(false); /// TODO: remove before merge. + fs::remove(offset_it->path()); } } diff --git a/src/Interpreters/Cache/FileSegment.cpp b/src/Interpreters/Cache/FileSegment.cpp index c356800fa57..f5a7011833a 100644 --- a/src/Interpreters/Cache/FileSegment.cpp +++ b/src/Interpreters/Cache/FileSegment.cpp @@ -139,7 +139,7 @@ FileSegmentGuard::Lock FileSegment::lock() const void FileSegment::setDownloadState(State state, const FileSegmentGuard::Lock & lock) { - if (isCompleted(false) && state != State::DETACHED) + if (isCompleted(false)) { throw Exception( ErrorCodes::LOGICAL_ERROR, @@ -700,6 +700,8 @@ void FileSegment::complete() case State::PARTIALLY_DOWNLOADED: { chassert(current_downloaded_size > 0); + chassert(fs::exists(getPath())); + chassert(fs::file_size(getPath()) > 0); if (is_last_holder) { @@ -841,29 +843,60 @@ bool FileSegment::assertCorrectnessUnlocked(const FileSegmentGuard::Lock & lock) } } - if (download_state == State::DOWNLOADED) + switch (download_state.load()) { - chassert(downloader_id.empty()); - chassert(downloaded_size == reserved_size); - chassert(downloaded_size == range().size()); - chassert(downloaded_size > 0); - chassert(std::filesystem::file_size(getPath()) > 0); - check_iterator(queue_iterator); - } - else - { - if (download_state == State::DOWNLOADING) - { - chassert(!downloader_id.empty()); - } - else if (download_state == State::PARTIALLY_DOWNLOADED - || download_state == State::EMPTY) + case State::EMPTY: { chassert(downloader_id.empty()); + chassert(!fs::exists(getPath())); + chassert(!queue_iterator); + break; } + case State::DOWNLOADED: + { + chassert(downloader_id.empty()); - chassert(reserved_size >= downloaded_size); - check_iterator(queue_iterator); + chassert(downloaded_size == reserved_size); + chassert(downloaded_size == range().size()); + chassert(downloaded_size > 0); + chassert(fs::file_size(getPath()) > 0); + + chassert(queue_iterator); + check_iterator(queue_iterator); + break; + } + case State::DOWNLOADING: + { + chassert(!downloader_id.empty()); + if (downloaded_size) + { + chassert(queue_iterator); + chassert(fs::file_size(getPath()) > 0); + } + break; + } + case State::PARTIALLY_DOWNLOADED: + { + chassert(downloader_id.empty()); + + chassert(reserved_size >= downloaded_size); + chassert(downloaded_size > 0); + chassert(fs::file_size(getPath()) > 0); + + chassert(queue_iterator); + check_iterator(queue_iterator); + break; + } + case State::PARTIALLY_DOWNLOADED_NO_CONTINUATION: + { + chassert(reserved_size >= downloaded_size); + check_iterator(queue_iterator); + break; + } + case State::DETACHED: + { + break; + } } return true; @@ -991,7 +1024,12 @@ FileSegmentsHolder::FileSegmentsHolder(FileSegments && file_segments_) FileSegmentPtr FileSegmentsHolder::getSingleFileSegment() const { if (file_segments.size() != 1) - throw Exception(ErrorCodes::LOGICAL_ERROR, "Expected single file segment, got: {} in holder {}", file_segments.size(), toString()); + { + throw Exception( + ErrorCodes::LOGICAL_ERROR, + "Expected single file segment, got: {} in holder {}", + file_segments.size(), toString()); + } return file_segments.front(); } @@ -1001,7 +1039,18 @@ void FileSegmentsHolder::reset() ProfileEvents::increment(ProfileEvents::FilesystemCacheUnusedHoldFileSegments, file_segments.size()); for (auto file_segment_it = file_segments.begin(); file_segment_it != file_segments.end();) - file_segment_it = completeAndPopFrontImpl(); + { + try + { + file_segment_it = completeAndPopFrontImpl(); + } + catch (...) + { + chassert(false); + tryLogCurrentException(__PRETTY_FUNCTION__); + continue; + } + } file_segments.clear(); } diff --git a/src/Interpreters/Cache/FileSegment.h b/src/Interpreters/Cache/FileSegment.h index ee9aee1e354..79adc342329 100644 --- a/src/Interpreters/Cache/FileSegment.h +++ b/src/Interpreters/Cache/FileSegment.h @@ -254,7 +254,7 @@ private: const FileSegmentKind segment_kind; /// Size of the segment is not known until it is downloaded and /// can be bigger than max_file_segment_size. - const bool is_unbound = false; + const bool is_unbound; const bool background_download_enabled; std::atomic download_state; diff --git a/src/Interpreters/Cache/Metadata.cpp b/src/Interpreters/Cache/Metadata.cpp index 99ea01aa4f1..49dbbc71fa2 100644 --- a/src/Interpreters/Cache/Metadata.cpp +++ b/src/Interpreters/Cache/Metadata.cpp @@ -940,7 +940,16 @@ KeyMetadata::iterator LockedKey::removeFileSegmentImpl( if (file_segment->queue_iterator && invalidate_queue_entry) file_segment->queue_iterator->invalidate(); - file_segment->detach(segment_lock, *this); + try + { + file_segment->detach(segment_lock, *this); + } + catch (...) + { + tryLogCurrentException(__PRETTY_FUNCTION__); + chassert(false); + /// Do not rethrow, we much delete the file below. + } try { @@ -990,8 +999,8 @@ void LockedKey::shrinkFileSegmentToDownloadedSize( * because of no space left in cache, we need to be able to cut file segment's size to downloaded_size. */ - auto metadata = getByOffset(offset); - const auto & file_segment = metadata->file_segment; + auto file_segment_metadata = getByOffset(offset); + const auto & file_segment = file_segment_metadata->file_segment; chassert(file_segment->assertCorrectnessUnlocked(segment_lock)); const size_t downloaded_size = file_segment->getDownloadedSize(); @@ -1006,15 +1015,15 @@ void LockedKey::shrinkFileSegmentToDownloadedSize( chassert(file_segment->reserved_size >= downloaded_size); int64_t diff = file_segment->reserved_size - downloaded_size; - metadata->file_segment = std::make_shared( + file_segment_metadata->file_segment = std::make_shared( getKey(), offset, downloaded_size, FileSegment::State::DOWNLOADED, CreateFileSegmentSettings(file_segment->getKind()), false, file_segment->cache, key_metadata, file_segment->queue_iterator); if (diff) - metadata->getQueueIterator()->decrementSize(diff); + file_segment_metadata->getQueueIterator()->decrementSize(diff); - chassert(file_segment->assertCorrectnessUnlocked(segment_lock)); + chassert(file_segment_metadata->file_segment->assertCorrectnessUnlocked(segment_lock)); } bool LockedKey::addToDownloadQueue(size_t offset, const FileSegmentGuard::Lock &) From e83cff7360e1a7ec0459a09bf95c954263b4c27c Mon Sep 17 00:00:00 2001 From: kssenii Date: Fri, 1 Nov 2024 12:47:03 +0100 Subject: [PATCH 2/9] Fix typo --- src/Interpreters/Cache/FileSegment.cpp | 2 +- src/Interpreters/Cache/Metadata.cpp | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/src/Interpreters/Cache/FileSegment.cpp b/src/Interpreters/Cache/FileSegment.cpp index f5a7011833a..080b54feb06 100644 --- a/src/Interpreters/Cache/FileSegment.cpp +++ b/src/Interpreters/Cache/FileSegment.cpp @@ -1046,8 +1046,8 @@ void FileSegmentsHolder::reset() } catch (...) { - chassert(false); tryLogCurrentException(__PRETTY_FUNCTION__); + chassert(false); continue; } } diff --git a/src/Interpreters/Cache/Metadata.cpp b/src/Interpreters/Cache/Metadata.cpp index 49dbbc71fa2..231545212cd 100644 --- a/src/Interpreters/Cache/Metadata.cpp +++ b/src/Interpreters/Cache/Metadata.cpp @@ -948,7 +948,7 @@ KeyMetadata::iterator LockedKey::removeFileSegmentImpl( { tryLogCurrentException(__PRETTY_FUNCTION__); chassert(false); - /// Do not rethrow, we much delete the file below. + /// Do not rethrow, we must delete the file below. } try From 1d888bc1ebc762faf1136d6910fef8641216fb6e Mon Sep 17 00:00:00 2001 From: Kseniia Sumarokova <54203879+kssenii@users.noreply.github.com> Date: Mon, 4 Nov 2024 16:40:26 +0100 Subject: [PATCH 3/9] Fix wrong change --- src/Interpreters/Cache/FileSegment.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Interpreters/Cache/FileSegment.cpp b/src/Interpreters/Cache/FileSegment.cpp index 080b54feb06..9c8f041fabf 100644 --- a/src/Interpreters/Cache/FileSegment.cpp +++ b/src/Interpreters/Cache/FileSegment.cpp @@ -139,7 +139,7 @@ FileSegmentGuard::Lock FileSegment::lock() const void FileSegment::setDownloadState(State state, const FileSegmentGuard::Lock & lock) { - if (isCompleted(false)) + if (isCompleted(false) && state != State::DETACHED) { throw Exception( ErrorCodes::LOGICAL_ERROR, From d7977f0b916ccdcc240de8d413015532d492f668 Mon Sep 17 00:00:00 2001 From: kssenii Date: Tue, 5 Nov 2024 13:36:27 +0100 Subject: [PATCH 4/9] More correct assertion --- src/Interpreters/Cache/EvictionCandidates.cpp | 3 ++- src/Interpreters/Cache/FileSegment.cpp | 7 ++++--- src/Interpreters/Cache/FileSegment.h | 7 +++++-- 3 files changed, 11 insertions(+), 6 deletions(-) diff --git a/src/Interpreters/Cache/EvictionCandidates.cpp b/src/Interpreters/Cache/EvictionCandidates.cpp index 08776ad5aee..f5d5fdec6ba 100644 --- a/src/Interpreters/Cache/EvictionCandidates.cpp +++ b/src/Interpreters/Cache/EvictionCandidates.cpp @@ -83,7 +83,8 @@ void EvictionCandidates::removeQueueEntries(const CachePriorityGuard::Lock & loc queue_iterator->invalidate(); chassert(candidate->releasable()); - candidate->file_segment->resetQueueIterator(); + candidate->file_segment->markDelayedRemovalAndResetQueueIterator(); + /// We need to set removed flag in file segment metadata, /// because in dynamic cache resize we first remove queue entries, /// then evict which also removes file segment metadata, diff --git a/src/Interpreters/Cache/FileSegment.cpp b/src/Interpreters/Cache/FileSegment.cpp index 080b54feb06..307d9c8afe1 100644 --- a/src/Interpreters/Cache/FileSegment.cpp +++ b/src/Interpreters/Cache/FileSegment.cpp @@ -171,10 +171,11 @@ void FileSegment::setQueueIterator(Priority::IteratorPtr iterator) queue_iterator = iterator; } -void FileSegment::resetQueueIterator() +void FileSegment::markDelayedRemovalAndResetQueueIterator() { auto lk = lock(); - queue_iterator.reset(); + on_delayed_removal = true; + queue_iterator = {}; } size_t FileSegment::getCurrentWriteOffset() const @@ -861,7 +862,7 @@ bool FileSegment::assertCorrectnessUnlocked(const FileSegmentGuard::Lock & lock) chassert(downloaded_size > 0); chassert(fs::file_size(getPath()) > 0); - chassert(queue_iterator); + chassert(queue_iterator || on_delayed_removal); check_iterator(queue_iterator); break; } diff --git a/src/Interpreters/Cache/FileSegment.h b/src/Interpreters/Cache/FileSegment.h index 79adc342329..6946d70b764 100644 --- a/src/Interpreters/Cache/FileSegment.h +++ b/src/Interpreters/Cache/FileSegment.h @@ -177,7 +177,7 @@ public: void setQueueIterator(Priority::IteratorPtr iterator); - void resetQueueIterator(); + void markDelayedRemovalAndResetQueueIterator(); KeyMetadataPtr tryGetKeyMetadata() const; @@ -249,11 +249,12 @@ private: String tryGetPath() const; - Key file_key; + const Key file_key; Range segment_range; const FileSegmentKind segment_kind; /// Size of the segment is not known until it is downloaded and /// can be bigger than max_file_segment_size. + /// is_unbound == true for temporary data in cache. const bool is_unbound; const bool background_download_enabled; @@ -279,6 +280,8 @@ private: std::atomic hits_count = 0; /// cache hits. std::atomic ref_count = 0; /// Used for getting snapshot state + bool on_delayed_removal = false; + CurrentMetrics::Increment metric_increment{CurrentMetrics::CacheFileSegments}; }; From b38dc1d8ca791c6fc686ae9d8efedeb77e354de2 Mon Sep 17 00:00:00 2001 From: Kseniia Sumarokova <54203879+kssenii@users.noreply.github.com> Date: Wed, 6 Nov 2024 11:05:43 +0100 Subject: [PATCH 5/9] Update FileCache.cpp --- src/Interpreters/Cache/FileCache.cpp | 2 -- 1 file changed, 2 deletions(-) diff --git a/src/Interpreters/Cache/FileCache.cpp b/src/Interpreters/Cache/FileCache.cpp index ae3c9c58fc5..f7b7ffc5aea 100644 --- a/src/Interpreters/Cache/FileCache.cpp +++ b/src/Interpreters/Cache/FileCache.cpp @@ -1438,8 +1438,6 @@ void FileCache::loadMetadataForKeys(const fs::path & keys_dir) "cached file `{}` does not fit in cache anymore (size: {})", size_limit, offset_it->path().string(), size); - chassert(false); /// TODO: remove before merge. - fs::remove(offset_it->path()); } } From 9ee22533a067fc235aea65ff7b89c801b112b918 Mon Sep 17 00:00:00 2001 From: Pablo Marcos Date: Wed, 6 Nov 2024 13:46:30 +0100 Subject: [PATCH 6/9] Move bitShift function changelog entries to backward incompatible Move bitShift function changelog entries to backward incompatible --- CHANGELOG.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 90285582b4e..dacee73440f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -488,6 +488,7 @@ * Remove `is_deterministic` field from the `system.functions` table. [#66630](https://github.com/ClickHouse/ClickHouse/pull/66630) ([Alexey Milovidov](https://github.com/alexey-milovidov)). * Function `tuple` will now try to construct named tuples in query (controlled by `enable_named_columns_in_function_tuple`). Introduce function `tupleNames` to extract names from tuples. [#54881](https://github.com/ClickHouse/ClickHouse/pull/54881) ([Amos Bird](https://github.com/amosbird)). * Change how deduplication for Materialized Views works. Fixed a lot of cases like: - on destination table: data is split for 2 or more blocks and that blocks is considered as duplicate when that block is inserted in parallel. - on MV destination table: the equal blocks are deduplicated, that happens when MV often produces equal data as a result for different input data due to performing aggregation. - on MV destination table: the equal blocks which comes from different MV are deduplicated. [#61601](https://github.com/ClickHouse/ClickHouse/pull/61601) ([Sema Checherinda](https://github.com/CheSema)). +* Functions `bitShiftLeft` and `bitShitfRight` return an error for out of bounds shift positions [#65838](https://github.com/ClickHouse/ClickHouse/pull/65838) ([Pablo Marcos](https://github.com/pamarcos)). #### New Feature * Add `ASOF JOIN` support for `full_sorting_join` algorithm. [#55051](https://github.com/ClickHouse/ClickHouse/pull/55051) ([vdimir](https://github.com/vdimir)). @@ -599,7 +600,6 @@ * Functions `bitTest`, `bitTestAll`, and `bitTestAny` now return an error if the specified bit index is out-of-bounds [#65818](https://github.com/ClickHouse/ClickHouse/pull/65818) ([Pablo Marcos](https://github.com/pamarcos)). * Setting `join_any_take_last_row` is supported in any query with hash join. [#65820](https://github.com/ClickHouse/ClickHouse/pull/65820) ([vdimir](https://github.com/vdimir)). * Better handling of join conditions involving `IS NULL` checks (for example `ON (a = b AND (a IS NOT NULL) AND (b IS NOT NULL) ) OR ( (a IS NULL) AND (b IS NULL) )` is rewritten to `ON a <=> b`), fix incorrect optimization when condition other then `IS NULL` are present. [#65835](https://github.com/ClickHouse/ClickHouse/pull/65835) ([vdimir](https://github.com/vdimir)). -* Functions `bitShiftLeft` and `bitShitfRight` return an error for out of bounds shift positions [#65838](https://github.com/ClickHouse/ClickHouse/pull/65838) ([Pablo Marcos](https://github.com/pamarcos)). * Fix growing memory usage in S3Queue. [#65839](https://github.com/ClickHouse/ClickHouse/pull/65839) ([Kseniia Sumarokova](https://github.com/kssenii)). * Fix tie handling in `arrayAUC` to match sklearn. [#65840](https://github.com/ClickHouse/ClickHouse/pull/65840) ([gabrielmcg44](https://github.com/gabrielmcg44)). * Fix possible issues with MySQL server protocol TLS connections. [#65917](https://github.com/ClickHouse/ClickHouse/pull/65917) ([Azat Khuzhin](https://github.com/azat)). From 4e3bde24605e1401749703bfe2eb28d7298f6630 Mon Sep 17 00:00:00 2001 From: alesapin Date: Wed, 6 Nov 2024 14:52:59 +0100 Subject: [PATCH 7/9] Add ProfileEvents for merge selector timings --- src/Common/ProfileEvents.cpp | 6 ++++ .../MergeTree/MergeTreeDataMergerMutator.cpp | 30 +++++++++++++++++-- 2 files changed, 34 insertions(+), 2 deletions(-) diff --git a/src/Common/ProfileEvents.cpp b/src/Common/ProfileEvents.cpp index 0774d36462d..7b9f670d340 100644 --- a/src/Common/ProfileEvents.cpp +++ b/src/Common/ProfileEvents.cpp @@ -746,6 +746,12 @@ The server successfully detected this situation and will download merged part fr M(ReadTaskRequestsSentElapsedMicroseconds, "Time spent in callbacks requested from the remote server back to the initiator server to choose the read task (for s3Cluster table function and similar). Measured on the remote server side.", ValueType::Microseconds) \ M(MergeTreeReadTaskRequestsSentElapsedMicroseconds, "Time spent in callbacks requested from the remote server back to the initiator server to choose the read task (for MergeTree tables). Measured on the remote server side.", ValueType::Microseconds) \ M(MergeTreeAllRangesAnnouncementsSentElapsedMicroseconds, "Time spent in sending the announcement from the remote server to the initiator server about the set of data parts (for MergeTree tables). Measured on the remote server side.", ValueType::Microseconds) \ + M(MergerMutatorsGetPartsForMergeElapsedMicroseconds, "Time spent to take data parts snapshot to build ranges from them.", ValueType::Microseconds) \ + M(MergerMutatorPrepareRangesForMergeElapsedMicroseconds, "Time spent to prepare parts ranges which can be merged according to merge predicate.", ValueType::Microseconds) \ + M(MergerMutatorSelectPartsForMergeElapsedMicroseconds, "Time spent to select parts from ranges which can be merged.", ValueType::Microseconds) \ + M(MergerMutatorRangesForMergeCount, "Amount of candidate ranges for merge", ValueType::Number) \ + M(MergerMutatorPartsInRangesForMergeCount, "Amount of candidate parts for merge", ValueType::Number) \ + M(MergerMutatorSelectRangePartsCount, "Amount of parts in selected range for merge", ValueType::Number) \ \ M(ConnectionPoolIsFullMicroseconds, "Total time spent waiting for a slot in connection pool.", ValueType::Microseconds) \ M(AsyncLoaderWaitMicroseconds, "Total time a query was waiting for async loader jobs.", ValueType::Microseconds) \ diff --git a/src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp b/src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp index 6b9638b11d2..3d935f8b70d 100644 --- a/src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp +++ b/src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp @@ -48,6 +48,17 @@ namespace CurrentMetrics { extern const Metric BackgroundMergesAndMutationsPoolTask; } +namespace ProfileEvents +{ + + extern const Event MergeTreeAllRangesAnnouncementsSentElapsedMicroseconds; + extern const Event MergerMutatorsGetPartsForMergeElapsedMicroseconds; + extern const Event MergerMutatorPrepareRangesForMergeElapsedMicroseconds; + extern const Event MergerMutatorSelectPartsForMergeElapsedMicroseconds; + extern const Event MergerMutatorRangesForMergeCount; + extern const Event MergerMutatorPartsInRangesForMergeCount; + extern const Event MergerMutatorSelectRangePartsCount; +} namespace DB { @@ -215,6 +226,7 @@ MergeTreeDataMergerMutator::PartitionIdsHint MergeTreeDataMergerMutator::getPart { PartitionIdsHint res; MergeTreeData::DataPartsVector data_parts = getDataPartsToSelectMergeFrom(txn); + if (data_parts.empty()) return res; @@ -272,6 +284,8 @@ MergeTreeDataMergerMutator::PartitionIdsHint MergeTreeDataMergerMutator::getPart MergeTreeData::DataPartsVector MergeTreeDataMergerMutator::getDataPartsToSelectMergeFrom( const MergeTreeTransactionPtr & txn, const PartitionIdsHint * partitions_hint) const { + + Stopwatch get_data_parts_for_merge_timer; auto res = getDataPartsToSelectMergeFrom(txn); if (!partitions_hint) return res; @@ -280,6 +294,8 @@ MergeTreeData::DataPartsVector MergeTreeDataMergerMutator::getDataPartsToSelectM { return !partitions_hint->contains(part->info.partition_id); }); + + ProfileEvents::increment(ProfileEvents::MergerMutatorsGetPartsForMergeElapsedMicroseconds, get_data_parts_for_merge_timer.elapsedMicroseconds()); return res; } @@ -357,6 +373,7 @@ MergeTreeDataMergerMutator::MergeSelectingInfo MergeTreeDataMergerMutator::getPo const MergeTreeTransactionPtr & txn, PreformattedMessage & out_disable_reason) const { + Stopwatch ranges_for_merge_timer; MergeSelectingInfo res; res.current_time = std::time(nullptr); @@ -457,6 +474,10 @@ MergeTreeDataMergerMutator::MergeSelectingInfo MergeTreeDataMergerMutator::getPo prev_part = ∂ } + ProfileEvents::increment(ProfileEvents::MergerMutatorPartsInRangesForMergeCount, res.parts_selected_precondition); + ProfileEvents::increment(ProfileEvents::MergerMutatorRangesForMergeCount, res.parts_ranges.size()); + ProfileEvents::increment(ProfileEvents::MergerMutatorPrepareRangesForMergeElapsedMicroseconds, ranges_for_merge_timer.elapsedMicroseconds()); + return res; } @@ -471,6 +492,7 @@ SelectPartsDecision MergeTreeDataMergerMutator::selectPartsToMergeFromRanges( PreformattedMessage & out_disable_reason, bool dry_run) { + Stopwatch select_parts_from_ranges_timer; const auto data_settings = data.getSettings(); IMergeSelector::PartsRange parts_to_merge; @@ -570,7 +592,8 @@ SelectPartsDecision MergeTreeDataMergerMutator::selectPartsToMergeFromRanges( if (parts_to_merge.empty()) { - out_disable_reason = PreformattedMessage::create("Did not find any parts to merge (with usual merge selectors)"); + ProfileEvents::increment(ProfileEvents::MergerMutatorSelectPartsForMergeElapsedMicroseconds, select_parts_from_ranges_timer.elapsedMicroseconds()); + out_disable_reason = PreformattedMessage::create("Did not find any parts to merge (with usual merge selectors) in {}", select_parts_from_ranges_timer.elapsedMicroseconds() / 1000); return SelectPartsDecision::CANNOT_SELECT; } } @@ -583,8 +606,11 @@ SelectPartsDecision MergeTreeDataMergerMutator::selectPartsToMergeFromRanges( parts.push_back(part); } - LOG_DEBUG(log, "Selected {} parts from {} to {}", parts.size(), parts.front()->name, parts.back()->name); + LOG_DEBUG(log, "Selected {} parts from {} to {} in {}ms", parts.size(), parts.front()->name, parts.back()->name, select_parts_from_ranges_timer.elapsedMicroseconds() / 1000); + ProfileEvents::increment(ProfileEvents::MergerMutatorSelectRangePartsCount, parts.size()); + future_part->assign(std::move(parts)); + ProfileEvents::increment(ProfileEvents::MergerMutatorSelectPartsForMergeElapsedMicroseconds, select_parts_from_ranges_timer.elapsedMicroseconds()); return SelectPartsDecision::SELECTED; } From afb92f04e62b446fb5c8b0417c658f206ce2a55d Mon Sep 17 00:00:00 2001 From: Alexander Gololobov Date: Wed, 6 Nov 2024 14:56:30 +0100 Subject: [PATCH 8/9] Added ms --- src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp b/src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp index 3d935f8b70d..4d0fb7f9eeb 100644 --- a/src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp +++ b/src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp @@ -593,7 +593,7 @@ SelectPartsDecision MergeTreeDataMergerMutator::selectPartsToMergeFromRanges( if (parts_to_merge.empty()) { ProfileEvents::increment(ProfileEvents::MergerMutatorSelectPartsForMergeElapsedMicroseconds, select_parts_from_ranges_timer.elapsedMicroseconds()); - out_disable_reason = PreformattedMessage::create("Did not find any parts to merge (with usual merge selectors) in {}", select_parts_from_ranges_timer.elapsedMicroseconds() / 1000); + out_disable_reason = PreformattedMessage::create("Did not find any parts to merge (with usual merge selectors) in {}ms", select_parts_from_ranges_timer.elapsedMicroseconds() / 1000); return SelectPartsDecision::CANNOT_SELECT; } } From 33bd082149ca207b55915cd78c8c19cdc6aacdc9 Mon Sep 17 00:00:00 2001 From: alesapin Date: Wed, 6 Nov 2024 16:00:25 +0100 Subject: [PATCH 9/9] Followup --- src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp | 1 - 1 file changed, 1 deletion(-) diff --git a/src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp b/src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp index 3d935f8b70d..40c4db3a69d 100644 --- a/src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp +++ b/src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp @@ -51,7 +51,6 @@ namespace CurrentMetrics namespace ProfileEvents { - extern const Event MergeTreeAllRangesAnnouncementsSentElapsedMicroseconds; extern const Event MergerMutatorsGetPartsForMergeElapsedMicroseconds; extern const Event MergerMutatorPrepareRangesForMergeElapsedMicroseconds; extern const Event MergerMutatorSelectPartsForMergeElapsedMicroseconds;