Query cache: Log caching of entries

This commit is contained in:
Robert Schulze 2023-09-04 16:54:50 +00:00
parent de4971c71e
commit 917a9f47b9
No known key found for this signature in database
GPG Key ID: 26703B55FB13728A
2 changed files with 13 additions and 9 deletions

View File

@ -7,7 +7,6 @@
#include <Parsers/ASTSetQuery.h> #include <Parsers/ASTSetQuery.h>
#include <Parsers/IAST.h> #include <Parsers/IAST.h>
#include <Parsers/formatAST.h> #include <Parsers/formatAST.h>
#include <Common/logger_useful.h>
#include <Common/ProfileEvents.h> #include <Common/ProfileEvents.h>
#include <Common/SipHash.h> #include <Common/SipHash.h>
#include <Common/TTLCachePolicy.h> #include <Common/TTLCachePolicy.h>
@ -191,7 +190,7 @@ QueryCache::Writer::Writer(
if (auto entry = cache.getWithKey(key); entry.has_value() && !IsStale()(entry->key)) if (auto entry = cache.getWithKey(key); entry.has_value() && !IsStale()(entry->key))
{ {
skip_insert = true; /// Key already contained in cache and did not expire yet --> don't replace it skip_insert = true; /// Key already contained in cache and did not expire yet --> don't replace it
LOG_TRACE(&Poco::Logger::get("QueryCache"), "Skipped insert (non-stale entry found), query: {}", key.query_string); LOG_TRACE(logger, "Skipped insert (non-stale entry found), query: {}", key.query_string);
} }
} }
@ -263,14 +262,14 @@ void QueryCache::Writer::finalizeWrite()
if (std::chrono::duration_cast<std::chrono::milliseconds>(std::chrono::system_clock::now() - query_start_time) < min_query_runtime) if (std::chrono::duration_cast<std::chrono::milliseconds>(std::chrono::system_clock::now() - query_start_time) < min_query_runtime)
{ {
LOG_TRACE(&Poco::Logger::get("QueryCache"), "Skipped insert (query not expensive enough), query: {}", key.query_string); LOG_TRACE(logger, "Skipped insert (query not expensive enough), query: {}", key.query_string);
return; return;
} }
if (auto entry = cache.getWithKey(key); entry.has_value() && !IsStale()(entry->key)) if (auto entry = cache.getWithKey(key); entry.has_value() && !IsStale()(entry->key))
{ {
/// Same check as in ctor because a parallel Writer could have inserted the current key in the meantime /// Same check as in ctor because a parallel Writer could have inserted the current key in the meantime
LOG_TRACE(&Poco::Logger::get("QueryCache"), "Skipped insert (non-stale entry found), query: {}", key.query_string); LOG_TRACE(logger, "Skipped insert (non-stale entry found), query: {}", key.query_string);
return; return;
} }
@ -353,12 +352,14 @@ void QueryCache::Writer::finalizeWrite()
if ((new_entry_size_in_bytes > max_entry_size_in_bytes) || (new_entry_size_in_rows > max_entry_size_in_rows)) if ((new_entry_size_in_bytes > max_entry_size_in_bytes) || (new_entry_size_in_rows > max_entry_size_in_rows))
{ {
LOG_TRACE(&Poco::Logger::get("QueryCache"), "Skipped insert (query result too big), new_entry_size_in_bytes: {} ({}), new_entry_size_in_rows: {} ({}), query: {}", new_entry_size_in_bytes, max_entry_size_in_bytes, new_entry_size_in_rows, max_entry_size_in_rows, key.query_string); LOG_TRACE(logger, "Skipped insert (query result too big), new_entry_size_in_bytes: {} ({}), new_entry_size_in_rows: {} ({}), query: {}", new_entry_size_in_bytes, max_entry_size_in_bytes, new_entry_size_in_rows, max_entry_size_in_rows, key.query_string);
return; return;
} }
cache.set(key, query_result); cache.set(key, query_result);
LOG_TRACE(logger, "Stored result of query: {}", key.query_string);
was_finalized = true; was_finalized = true;
} }
@ -388,7 +389,7 @@ QueryCache::Reader::Reader(Cache & cache_, const Key & key, const std::lock_guar
if (!entry.has_value()) if (!entry.has_value())
{ {
LOG_TRACE(&Poco::Logger::get("QueryCache"), "No entry found for query {}", key.query_string); LOG_TRACE(logger, "No entry found for query {}", key.query_string);
return; return;
} }
@ -397,13 +398,13 @@ QueryCache::Reader::Reader(Cache & cache_, const Key & key, const std::lock_guar
if (!entry_key.is_shared && entry_key.user_name != key.user_name) if (!entry_key.is_shared && entry_key.user_name != key.user_name)
{ {
LOG_TRACE(&Poco::Logger::get("QueryCache"), "Inaccessible entry found for query {}", key.query_string); LOG_TRACE(logger, "Inaccessible entry found for query {}", key.query_string);
return; return;
} }
if (IsStale()(entry_key)) if (IsStale()(entry_key))
{ {
LOG_TRACE(&Poco::Logger::get("QueryCache"), "Stale entry found for query {}", key.query_string); LOG_TRACE(logger, "Stale entry found for query {}", key.query_string);
return; return;
} }
@ -441,7 +442,7 @@ QueryCache::Reader::Reader(Cache & cache_, const Key & key, const std::lock_guar
buildSourceFromChunks(entry_key.header, std::move(decompressed_chunks), entry_mapped->totals, entry_mapped->extremes); buildSourceFromChunks(entry_key.header, std::move(decompressed_chunks), entry_mapped->totals, entry_mapped->extremes);
} }
LOG_TRACE(&Poco::Logger::get("QueryCache"), "Entry found for query {}", key.query_string); LOG_TRACE(logger, "Entry found for query {}", key.query_string);
} }
bool QueryCache::Reader::hasCacheEntryForKey() const bool QueryCache::Reader::hasCacheEntryForKey() const

View File

@ -1,6 +1,7 @@
#pragma once #pragma once
#include <Common/CacheBase.h> #include <Common/CacheBase.h>
#include <Common/logger_useful.h>
#include <Core/Block.h> #include <Core/Block.h>
#include <Parsers/IAST_fwd.h> #include <Parsers/IAST_fwd.h>
#include <Processors/Sources/SourceFromChunks.h> #include <Processors/Sources/SourceFromChunks.h>
@ -144,6 +145,7 @@ public:
Cache::MappedPtr query_result TSA_GUARDED_BY(mutex) = std::make_shared<Entry>(); Cache::MappedPtr query_result TSA_GUARDED_BY(mutex) = std::make_shared<Entry>();
std::atomic<bool> skip_insert = false; std::atomic<bool> skip_insert = false;
bool was_finalized = false; bool was_finalized = false;
Poco::Logger * logger = &Poco::Logger::get("QueryCache");
Writer(Cache & cache_, const Key & key_, Writer(Cache & cache_, const Key & key_,
size_t max_entry_size_in_bytes_, size_t max_entry_size_in_rows_, size_t max_entry_size_in_bytes_, size_t max_entry_size_in_rows_,
@ -170,6 +172,7 @@ public:
std::unique_ptr<SourceFromChunks> source_from_chunks; std::unique_ptr<SourceFromChunks> source_from_chunks;
std::unique_ptr<SourceFromChunks> source_from_chunks_totals; std::unique_ptr<SourceFromChunks> source_from_chunks_totals;
std::unique_ptr<SourceFromChunks> source_from_chunks_extremes; std::unique_ptr<SourceFromChunks> source_from_chunks_extremes;
Poco::Logger * logger = &Poco::Logger::get("QueryCache");
friend class QueryCache; /// for createReader() friend class QueryCache; /// for createReader()
}; };