thevar1able/ClickHouse
1
0
Fork 0
mirror of https://github.com/ClickHouse/ClickHouse.git synced 2024-11-21 15:12:02 +00:00
Code Issues Packages Projects Releases Wiki Activity

Fix query_thread_log.query_duration_ms unit

Browse Source 
There is a similar problem as in [1], the problem is that
getCurrentTimeNanoseconds() returns time using CLOCK_MONOTONIC.

  [1]: c0e15ba348 ("Fix RealTimeMicroseconds ProfileEvents")
This commit is contained in:
Azat Khuzhin 2020-10-31 11:15:27 +03:00
parent 15a342e5e1
commit 3b188921dd
3 changed files with 31 additions and 1 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
src/Interpreters/ThreadStatusExt.cpp
View File

@ -336,7 +336,7 @@ void ThreadStatus::logToQueryThreadLog(QueryThreadLog & thread_log, const String
elem.event_time_microseconds = current_time_microseconds; elem.event_time_microseconds = current_time_microseconds;
elem.query_start_time = query_start_time; elem.query_start_time = query_start_time;
elem.query_start_time_microseconds = query_start_time_microseconds; elem.query_start_time_microseconds = query_start_time_microseconds;
elem.query_duration_ms = (getCurrentTimeNanoseconds() - query_start_time_nanoseconds) / 1000000U; elem.query_duration_ms = (time_in_nanoseconds(now) - query_start_time_nanoseconds) / 1000000U;
elem.read_rows = progress_in.read_rows.load(std::memory_order_relaxed); elem.read_rows = progress_in.read_rows.load(std::memory_order_relaxed);
elem.read_bytes = progress_in.read_bytes.load(std::memory_order_relaxed); elem.read_bytes = progress_in.read_bytes.load(std::memory_order_relaxed);

2
tests/queries/0_stateless/01548_query_log_query_execution_ms.reference Normal file
View File

@ -0,0 +1,2 @@
1
1

28
tests/queries/0_stateless/01548_query_log_query_execution_ms.sql Normal file
View File

@ -0,0 +1,28 @@
set log_query_threads=1;
set log_queries_min_type='QUERY_FINISH';
set log_queries=1;
select '01548_query_log_query_execution_ms', sleep(0.4) format Null;
set log_queries=0;
set log_query_threads=0;
system flush logs;
select count()
from system.query_log
where
query like '%01548_query_log_query_execution_ms%'
and current_database = currentDatabase()
and query_duration_ms between 100 and 800
and event_date = today()
and event_time >= now() - interval 1 minute;
-- at least two threads for processing
-- (but one just waits for another, sigh)
select count() == 2
from system.query_thread_log
where
query like '%01548_query_log_query_execution_ms%'
and current_database = currentDatabase()
and query_duration_ms between 100 and 800
and event_date = today()
and event_time >= now() - interval 1 minute;