Merge pull request #45751 from ClickHouse/qc-better-logging

Improve logging in Query Cache
This commit is contained in:
Robert Schulze 2023-02-02 20:11:18 +01:00 committed by GitHub
commit 0e5a10b856
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23

View File

@ -186,7 +186,10 @@ QueryCache::Writer::Writer(std::mutex & mutex_, Cache & cache_, const Key & key_
, min_query_runtime(min_query_runtime_)
{
if (auto it = cache.find(key); it != cache.end() && !is_stale(it->first))
{
skip_insert = true; /// Key already contained in cache and did not expire yet --> don't replace it
LOG_TRACE(&Poco::Logger::get("QueryResultCache"), "Skipped insert (non-stale entry found), query: {}", key.queryStringFromAst());
}
}
void QueryCache::Writer::buffer(Chunk && partial_query_result)
@ -205,6 +208,7 @@ void QueryCache::Writer::buffer(Chunk && partial_query_result)
{
chunks->clear(); /// eagerly free some space
skip_insert = true;
LOG_TRACE(&Poco::Logger::get("QueryResultCache"), "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.queryStringFromAst());
}
}
@ -214,12 +218,19 @@ void QueryCache::Writer::finalizeWrite()
return;
if (std::chrono::duration_cast<std::chrono::milliseconds>(std::chrono::system_clock::now() - query_start_time) < min_query_runtime)
{
LOG_TRACE(&Poco::Logger::get("QueryResultCache"), "Skipped insert (query not expensive enough), query: {}", key.queryStringFromAst());
return;
}
std::lock_guard lock(mutex);
if (auto it = cache.find(key); it != cache.end() && !is_stale(it->first))
return; /// 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("QueryResultCache"), "Skipped insert (non-stale entry found), query: {}", key.queryStringFromAst());
return;
}
auto sufficient_space_in_cache = [this]() TSA_REQUIRES(mutex)
{
@ -242,9 +253,11 @@ void QueryCache::Writer::finalizeWrite()
LOG_TRACE(&Poco::Logger::get("QueryCache"), "Removed {} stale entries", removed_items);
}
/// Insert or replace if enough space
if (sufficient_space_in_cache())
if (!sufficient_space_in_cache())
LOG_TRACE(&Poco::Logger::get("QueryResultCache"), "Skipped insert (cache has insufficient space), query: {}", key.queryStringFromAst());
else
{
//// Insert or replace key
cache_size_in_bytes += query_result.sizeInBytes();
if (auto it = cache.find(key); it != cache.end())
cache_size_in_bytes -= it->second.sizeInBytes(); // key replacement