Merge pull request #27194 from azat/query_log_used-on-error

Save information about used functions/tables/... into query_log on error
This commit is contained in:
Kseniia Sumarokova 2021-08-05 09:15:09 +03:00 committed by GitHub
commit 3d347065a8
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
4 changed files with 31 additions and 18 deletions

View File

@ -671,7 +671,7 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
}
/// Common code for finish and exception callbacks
auto status_info_to_query_log = [](QueryLogElement &element, const QueryStatusInfo &info, const ASTPtr query_ast) mutable
auto status_info_to_query_log = [](QueryLogElement & element, const QueryStatusInfo & info, const ASTPtr query_ast, const ContextPtr context_ptr) mutable
{
DB::UInt64 query_time = info.elapsed_seconds * 1000000;
ProfileEvents::increment(ProfileEvents::QueryTimeMicroseconds, query_time);
@ -696,6 +696,17 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
element.thread_ids = std::move(info.thread_ids);
element.profile_counters = std::move(info.profile_counters);
const auto & factories_info = context_ptr->getQueryFactoriesInfo();
element.used_aggregate_functions = factories_info.aggregate_functions;
element.used_aggregate_function_combinators = factories_info.aggregate_function_combinators;
element.used_database_engines = factories_info.database_engines;
element.used_data_type_families = factories_info.data_type_families;
element.used_dictionaries = factories_info.dictionaries;
element.used_formats = factories_info.formats;
element.used_functions = factories_info.functions;
element.used_storages = factories_info.storages;
element.used_table_functions = factories_info.table_functions;
};
/// Also make possible for caller to log successful query finish and exception during execution.
@ -726,7 +737,7 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
const auto finish_time = std::chrono::system_clock::now();
elem.event_time = time_in_seconds(finish_time);
elem.event_time_microseconds = time_in_microseconds(finish_time);
status_info_to_query_log(elem, info, ast);
status_info_to_query_log(elem, info, ast, context);
auto progress_callback = context->getProgressCallback();
@ -767,20 +778,6 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
ReadableSize(elem.read_bytes / elapsed_seconds));
}
elem.thread_ids = std::move(info.thread_ids);
elem.profile_counters = std::move(info.profile_counters);
const auto & factories_info = context->getQueryFactoriesInfo();
elem.used_aggregate_functions = factories_info.aggregate_functions;
elem.used_aggregate_function_combinators = factories_info.aggregate_function_combinators;
elem.used_database_engines = factories_info.database_engines;
elem.used_data_type_families = factories_info.data_type_families;
elem.used_dictionaries = factories_info.dictionaries;
elem.used_formats = factories_info.formats;
elem.used_functions = factories_info.functions;
elem.used_storages = factories_info.storages;
elem.used_table_functions = factories_info.table_functions;
if (log_queries && elem.type >= log_queries_min_type && Int64(elem.query_duration_ms) >= log_queries_min_query_duration_ms)
{
if (auto query_log = context->getQueryLog())
@ -849,7 +846,7 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
if (process_list_elem)
{
QueryStatusInfo info = process_list_elem->getInfo(true, current_settings.log_profile_events, false);
status_info_to_query_log(elem, info, ast);
status_info_to_query_log(elem, info, ast, context);
}
if (current_settings.calculate_text_stack_trace)

View File

@ -222,7 +222,7 @@ StoragePtr StorageFactory::get(
storage_def->engine->arguments->children = empty_engine_args;
}
if (local_context->hasQueryContext() && context->getSettingsRef().log_queries)
if (local_context->hasQueryContext() && local_context->getSettingsRef().log_queries)
local_context->getQueryContext()->addQueryFactoriesInfo(Context::QueryLogFactories::Storage, name);
return res;

View File

@ -13,6 +13,9 @@ arraySort(used_table_functions)
arraySort(used_functions)
['CAST','CRC32','addDays','array','arrayFlatten','modulo','plus','pow','round','substring','tanh','toDate','toDayOfYear','toTypeName','toWeek']
used_functions
['repeat']
arraySort(used_data_type_families)
['Array','Int32','Nullable','String']

View File

@ -1,4 +1,5 @@
SET database_atomic_wait_for_drop_and_detach_synchronously=1;
SET log_queries=1;
SELECT uniqArray([1, 1, 2]),
SUBSTRING('Hello, world', 7, 5),
@ -13,9 +14,16 @@ SELECT uniqArray([1, 1, 2]),
countIf(toDate('2000-12-05') + number as d,
toDayOfYear(d) % 2)
FROM numbers(100);
SELECT repeat('a', number)
FROM numbers(10e3)
SETTINGS max_memory_usage=4e6, max_block_size=100
FORMAT Null; -- { serverError 241 }
SELECT '';
SYSTEM FLUSH LOGS;
SELECT arraySort(used_aggregate_functions)
FROM system.query_log WHERE current_database = currentDatabase() AND type = 'QueryFinish' AND (query LIKE '%toDate(\'2000-12-05\')%')
ORDER BY query_start_time DESC LIMIT 1 FORMAT TabSeparatedWithNames;
@ -36,6 +44,11 @@ FROM system.query_log WHERE current_database = currentDatabase() AND type = 'Que
ORDER BY query_start_time DESC LIMIT 1 FORMAT TabSeparatedWithNames;
SELECT '';
SELECT used_functions
FROM system.query_log WHERE current_database = currentDatabase() AND type != 'QueryStart' AND (query LIKE '%repeat%')
ORDER BY query_start_time DESC LIMIT 1 FORMAT TabSeparatedWithNames;
SELECT '';
SELECT arraySort(used_data_type_families)
FROM system.query_log WHERE current_database = currentDatabase() AND type = 'QueryFinish' AND (query LIKE '%toDate(\'2000-12-05\')%')
ORDER BY query_start_time DESC LIMIT 1 FORMAT TabSeparatedWithNames;