Add log_queries_min_type to filter which entries will be written to query_log

Can be used to write into query_log only failed queries (i.e. on memory
exceeded error), by using:

  set log_queries_min_type='EXCEPTION_WHILE_PROCESSING'
This commit is contained in:
Azat Khuzhin 2020-04-05 00:07:00 +03:00
parent b888c867b3
commit 365b5207b7
8 changed files with 68 additions and 18 deletions

View File

@ -507,6 +507,24 @@ Example:
log_queries=1 log_queries=1
``` ```
## log\_queries\_min\_type {#settings-log-queries-min-type}
`query_log` minimal type to log.
Possible values:
- `QUERY_START` (`=1`)
- `QUERY_FINISH` (`=2`)
- `EXCEPTION_BEFORE_START` (`=3`)
- `EXCEPTION_WHILE_PROCESSING` (`=4`)
Default value: `QUERY_START`.
Can be used to limit which entiries will goes to `query_log`, say you are interesting only in errors, then you can use `EXCEPTION_WHILE_PROCESSING`:
``` text
log_queries_min_type='EXCEPTION_WHILE_PROCESSING'
```
## log\_query\_threads {#settings-log-query-threads} ## log\_query\_threads {#settings-log-query-threads}
Setting up query threads logging. Setting up query threads logging.

View File

@ -149,7 +149,7 @@ struct Settings : public SettingsCollection<Settings>
M(SettingInt64, os_thread_priority, 0, "If non zero - set corresponding 'nice' value for query processing threads. Can be used to adjust query priority for OS scheduler.", 0) \ M(SettingInt64, os_thread_priority, 0, "If non zero - set corresponding 'nice' value for query processing threads. Can be used to adjust query priority for OS scheduler.", 0) \
\ \
M(SettingBool, log_queries, 0, "Log requests and write the log to the system table.", 0) \ M(SettingBool, log_queries, 0, "Log requests and write the log to the system table.", 0) \
\ M(SettingLogQueriesType, log_queries_min_type, QueryLogElementType::QUERY_START, "query_log minimal type to log, possible values (from low to high): QUERY_START, QUERY_FINISH, EXCEPTION_BEFORE_START, EXCEPTION_WHILE_PROCESSING.", 0) \
M(SettingUInt64, log_queries_cut_to_length, 100000, "If query length is greater than specified threshold (in bytes), then cut query when writing to query log. Also limit length of printed query in ordinary text log.", 0) \ M(SettingUInt64, log_queries_cut_to_length, 100000, "If query length is greater than specified threshold (in bytes), then cut query when writing to query log. Also limit length of printed query in ordinary text log.", 0) \
\ \
M(SettingDistributedProductMode, distributed_product_mode, DistributedProductMode::DENY, "How are distributed subqueries performed inside IN or JOIN sections?", IMPORTANT) \ M(SettingDistributedProductMode, distributed_product_mode, DistributedProductMode::DENY, "How are distributed subqueries performed inside IN or JOIN sections?", IMPORTANT) \

View File

@ -542,6 +542,13 @@ IMPLEMENT_SETTING_ENUM(FormatSettings::DateTimeInputFormat, DATE_TIME_INPUT_FORM
M(trace, "trace") M(trace, "trace")
IMPLEMENT_SETTING_ENUM(LogsLevel, LOGS_LEVEL_LIST_OF_NAMES, ErrorCodes::BAD_ARGUMENTS) IMPLEMENT_SETTING_ENUM(LogsLevel, LOGS_LEVEL_LIST_OF_NAMES, ErrorCodes::BAD_ARGUMENTS)
#define LOG_QUERIES_TYPE_LIST_OF_NAMES(M) \
M(QUERY_START, "QUERY_START") \
M(QUERY_FINISH, "QUERY_FINISH") \
M(EXCEPTION_BEFORE_START, "EXCEPTION_BEFORE_START") \
M(EXCEPTION_WHILE_PROCESSING, "EXCEPTION_WHILE_PROCESSING")
IMPLEMENT_SETTING_ENUM(QueryLogElementType, LOG_QUERIES_TYPE_LIST_OF_NAMES, ErrorCodes::BAD_ARGUMENTS)
namespace details namespace details
{ {

View File

@ -298,6 +298,16 @@ enum class LogsLevel
}; };
using SettingLogsLevel = SettingEnum<LogsLevel>; using SettingLogsLevel = SettingEnum<LogsLevel>;
// Make it signed for compatibility with DataTypeEnum8
enum QueryLogElementType : int8_t
{
QUERY_START = 1,
QUERY_FINISH = 2,
EXCEPTION_BEFORE_START = 3,
EXCEPTION_WHILE_PROCESSING = 4,
};
using SettingLogQueriesType = SettingEnum<QueryLogElementType>;
enum class SettingsBinaryFormat enum class SettingsBinaryFormat
{ {

View File

@ -1,6 +1,7 @@
#pragma once #pragma once
#include <Interpreters/SystemLog.h> #include <Interpreters/SystemLog.h>
#include <Core/SettingsCollection.h>
namespace ProfileEvents namespace ProfileEvents
@ -22,13 +23,7 @@ namespace DB
/// A struct which will be inserted as row into query_log table /// A struct which will be inserted as row into query_log table
struct QueryLogElement struct QueryLogElement
{ {
enum Type : int8_t // Make it signed for compatibility with DataTypeEnum8 using Type = QueryLogElementType;
{
QUERY_START = 1,
QUERY_FINISH = 2,
EXCEPTION_BEFORE_START = 3,
EXCEPTION_WHILE_PROCESSING = 4,
};
Type type = QUERY_START; Type type = QUERY_START;

View File

@ -157,7 +157,7 @@ static void onExceptionBeforeStart(const String & query_for_logging, Context & c
/// Log the start of query execution into the table if necessary. /// Log the start of query execution into the table if necessary.
QueryLogElement elem; QueryLogElement elem;
elem.type = QueryLogElement::EXCEPTION_BEFORE_START; elem.type = QueryLogElementType::EXCEPTION_BEFORE_START;
elem.event_time = current_time; elem.event_time = current_time;
elem.query_start_time = current_time; elem.query_start_time = current_time;
@ -175,7 +175,7 @@ static void onExceptionBeforeStart(const String & query_for_logging, Context & c
/// Update performance counters before logging to query_log /// Update performance counters before logging to query_log
CurrentThread::finalizePerformanceCounters(); CurrentThread::finalizePerformanceCounters();
if (settings.log_queries) if (settings.log_queries && elem.type >= settings.log_queries_min_type)
if (auto query_log = context.getQueryLog()) if (auto query_log = context.getQueryLog())
query_log->add(elem); query_log->add(elem);
} }
@ -400,7 +400,7 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
{ {
QueryLogElement elem; QueryLogElement elem;
elem.type = QueryLogElement::QUERY_START; elem.type = QueryLogElementType::QUERY_START;
elem.event_time = current_time; elem.event_time = current_time;
elem.query_start_time = current_time; elem.query_start_time = current_time;
@ -412,7 +412,7 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
bool log_queries = settings.log_queries && !internal; bool log_queries = settings.log_queries && !internal;
/// Log into system table start of query execution, if need. /// Log into system table start of query execution, if need.
if (log_queries) if (log_queries && elem.type >= settings.log_queries_min_type)
{ {
if (settings.log_query_settings) if (settings.log_query_settings)
elem.query_settings = std::make_shared<Settings>(context.getSettingsRef()); elem.query_settings = std::make_shared<Settings>(context.getSettingsRef());
@ -422,7 +422,7 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
} }
/// Also make possible for caller to log successful query finish and exception during execution. /// Also make possible for caller to log successful query finish and exception during execution.
auto finish_callback = [elem, &context, log_queries] (IBlockInputStream * stream_in, IBlockOutputStream * stream_out) mutable auto finish_callback = [elem, &context, log_queries, log_queries_min_type = settings.log_queries_min_type] (IBlockInputStream * stream_in, IBlockOutputStream * stream_out) mutable
{ {
QueryStatus * process_list_elem = context.getProcessListElement(); QueryStatus * process_list_elem = context.getProcessListElement();
@ -436,7 +436,7 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
double elapsed_seconds = info.elapsed_seconds; double elapsed_seconds = info.elapsed_seconds;
elem.type = QueryLogElement::QUERY_FINISH; elem.type = QueryLogElementType::QUERY_FINISH;
elem.event_time = time(nullptr); elem.event_time = time(nullptr);
elem.query_duration_ms = elapsed_seconds * 1000; elem.query_duration_ms = elapsed_seconds * 1000;
@ -484,19 +484,19 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
elem.thread_ids = std::move(info.thread_ids); elem.thread_ids = std::move(info.thread_ids);
elem.profile_counters = std::move(info.profile_counters); elem.profile_counters = std::move(info.profile_counters);
if (log_queries) if (log_queries && elem.type >= log_queries_min_type)
{ {
if (auto query_log = context.getQueryLog()) if (auto query_log = context.getQueryLog())
query_log->add(elem); query_log->add(elem);
} }
}; };
auto exception_callback = [elem, &context, log_queries, quota(quota)] () mutable auto exception_callback = [elem, &context, log_queries, log_queries_min_type = settings.log_queries_min_type, quota(quota)] () mutable
{ {
if (quota) if (quota)
quota->used(Quota::ERRORS, 1, /* check_exceeded = */ false); quota->used(Quota::ERRORS, 1, /* check_exceeded = */ false);
elem.type = QueryLogElement::EXCEPTION_WHILE_PROCESSING; elem.type = QueryLogElementType::EXCEPTION_WHILE_PROCESSING;
elem.event_time = time(nullptr); elem.event_time = time(nullptr);
elem.query_duration_ms = 1000 * (elem.event_time - elem.query_start_time); elem.query_duration_ms = 1000 * (elem.event_time - elem.query_start_time);
@ -529,7 +529,7 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
logException(context, elem); logException(context, elem);
/// In case of exception we log internal queries also /// In case of exception we log internal queries also
if (log_queries) if (log_queries && elem.type >= log_queries_min_type)
{ {
if (auto query_log = context.getQueryLog()) if (auto query_log = context.getQueryLog())
query_log->add(elem); query_log->add(elem);

View File

@ -0,0 +1,5 @@
01231_log_queries_min_type/QUERY_START
2
01231_log_queries_min_type/EXCEPTION_BEFORE_START
2
3

View File

@ -0,0 +1,15 @@
set log_queries=1;
select '01231_log_queries_min_type/QUERY_START';
system flush logs;
select count() from system.query_log where query like '%01231_log_queries_min_type/%' and query not like '%system.query_log%' and event_date = today() and event_time >= now() - interval 1 minute;
set log_queries_min_type='EXCEPTION_BEFORE_START';
select '01231_log_queries_min_type/EXCEPTION_BEFORE_START';
system flush logs;
select count() from system.query_log where query like '%01231_log_queries_min_type/%' and query not like '%system.query_log%' and event_date = today() and event_time >= now() - interval 1 minute;
set log_queries_min_type='EXCEPTION_WHILE_PROCESSING';
select '01231_log_queries_min_type/', max(number) from system.numbers limit 1e6 settings max_rows_to_read='100K'; -- { serverError 158; }
system flush logs;
select count() from system.query_log where query like '%01231_log_queries_min_type/%' and query not like '%system.query_log%' and event_date = today() and event_time >= now() - interval 1 minute;