From 59e5affe34ae3ed23988980887eed460b5919ed1 Mon Sep 17 00:00:00 2001 From: Alejandro Date: Mon, 2 Sep 2024 17:55:28 +0100 Subject: [PATCH] Add Virtual CPU time to the HTTP Header of X-Clickhouse-Summary --- docs/en/interfaces/http.md | 10 +++++----- docs/ru/interfaces/http.md | 10 +++++----- docs/zh/interfaces/http.md | 12 ++++++------ src/IO/Progress.cpp | 13 +++++++++++++ src/IO/Progress.h | 5 +++++ src/Interpreters/executeQuery.cpp | 2 ++ .../03228_url_engine_response_headers.reference | 2 +- .../03228_url_engine_response_headers.sql | 3 ++- 8 files changed, 39 insertions(+), 18 deletions(-) diff --git a/docs/en/interfaces/http.md b/docs/en/interfaces/http.md index ffd65fce00f..420dbee3ec2 100644 --- a/docs/en/interfaces/http.md +++ b/docs/en/interfaces/http.md @@ -58,7 +58,7 @@ Connection: Close Content-Type: text/tab-separated-values; charset=UTF-8 X-ClickHouse-Server-Display-Name: clickhouse.ru-central1.internal X-ClickHouse-Query-Id: 5abe861c-239c-467f-b955-8a201abb8b7f -X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds": "0"} +X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds": "0", "virtual_cpu_time_microseconds": "0"} 1 ``` @@ -472,7 +472,7 @@ $ curl -v 'http://localhost:8123/predefined_query' < X-ClickHouse-Format: Template < X-ClickHouse-Timezone: Asia/Shanghai < Keep-Alive: timeout=10 -< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0"} +< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} < # HELP "Query" "Number of executing queries" # TYPE "Query" counter @@ -708,7 +708,7 @@ $ curl -v -H 'XXX:xxx' 'http://localhost:8123/get_config_static_handler' < Content-Type: text/plain; charset=UTF-8 < Transfer-Encoding: chunked < Keep-Alive: timeout=10 -< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0"} +< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} < * Connection #0 to host localhost left intact
% @@ -766,7 +766,7 @@ $ curl -vv -H 'XXX:xxx' 'http://localhost:8123/get_absolute_path_static_handler' < Content-Type: text/html; charset=UTF-8 < Transfer-Encoding: chunked < Keep-Alive: timeout=10 -< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0"} +< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} < Absolute Path File * Connection #0 to host localhost left intact @@ -785,7 +785,7 @@ $ curl -vv -H 'XXX:xxx' 'http://localhost:8123/get_relative_path_static_handler' < Content-Type: text/html; charset=UTF-8 < Transfer-Encoding: chunked < Keep-Alive: timeout=10 -< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0"} +< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} < Relative Path File * Connection #0 to host localhost left intact diff --git a/docs/ru/interfaces/http.md b/docs/ru/interfaces/http.md index 01d788e62cf..00e720478a9 100644 --- a/docs/ru/interfaces/http.md +++ b/docs/ru/interfaces/http.md @@ -50,7 +50,7 @@ Connection: Close Content-Type: text/tab-separated-values; charset=UTF-8 X-ClickHouse-Server-Display-Name: clickhouse.ru-central1.internal X-ClickHouse-Query-Id: 5abe861c-239c-467f-b955-8a201abb8b7f -X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0"} +X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} 1 ``` @@ -367,7 +367,7 @@ $ curl -v 'http://localhost:8123/predefined_query' < X-ClickHouse-Format: Template < X-ClickHouse-Timezone: Asia/Shanghai < Keep-Alive: timeout=10 -< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0", "elapsed_ns":"662334", "real_time_microseconds":"0"} +< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0", "elapsed_ns":"662334", "real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} < # HELP "Query" "Number of executing queries" # TYPE "Query" counter @@ -601,7 +601,7 @@ $ curl -v -H 'XXX:xxx' 'http://localhost:8123/get_config_static_handler' < Content-Type: text/plain; charset=UTF-8 < Transfer-Encoding: chunked < Keep-Alive: timeout=10 -< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0"} +< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} < * Connection #0 to host localhost left intact
% @@ -659,7 +659,7 @@ $ curl -vv -H 'XXX:xxx' 'http://localhost:8123/get_absolute_path_static_handler' < Content-Type: text/html; charset=UTF-8 < Transfer-Encoding: chunked < Keep-Alive: timeout=10 -< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0"} +< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} < Absolute Path File * Connection #0 to host localhost left intact @@ -678,7 +678,7 @@ $ curl -vv -H 'XXX:xxx' 'http://localhost:8123/get_relative_path_static_handler' < Content-Type: text/html; charset=UTF-8 < Transfer-Encoding: chunked < Keep-Alive: timeout=10 -< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0"} +< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} < Relative Path File * Connection #0 to host localhost left intact diff --git a/docs/zh/interfaces/http.md b/docs/zh/interfaces/http.md index 4767a540d61..9ad98da673e 100644 --- a/docs/zh/interfaces/http.md +++ b/docs/zh/interfaces/http.md @@ -53,7 +53,7 @@ Connection: Close Content-Type: text/tab-separated-values; charset=UTF-8 X-ClickHouse-Server-Display-Name: clickhouse.ru-central1.internal X-ClickHouse-Query-Id: 5abe861c-239c-467f-b955-8a201abb8b7f -X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334","real_time_microseconds":"0"} +X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334","real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} 1 ``` @@ -363,7 +363,7 @@ $ curl -v 'http://localhost:8123/predefined_query' < X-ClickHouse-Format: Template < X-ClickHouse-Timezone: Asia/Shanghai < Keep-Alive: timeout=10 -< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0"} +< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} < # HELP "Query" "Number of executing queries" # TYPE "Query" counter @@ -524,7 +524,7 @@ $ curl -vv -H 'XXX:xxx' 'http://localhost:8123/hi' < Content-Type: text/html; charset=UTF-8 < Transfer-Encoding: chunked < Keep-Alive: timeout=10 -< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0"} +< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334", "real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} < * Connection #0 to host localhost left intact Say Hi!% @@ -564,7 +564,7 @@ $ curl -v -H 'XXX:xxx' 'http://localhost:8123/get_config_static_handler' < Content-Type: text/plain; charset=UTF-8 < Transfer-Encoding: chunked < Keep-Alive: timeout=10 -< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334","real_time_microseconds":"0"} +< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334","real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} < * Connection #0 to host localhost left intact
% @@ -616,7 +616,7 @@ $ curl -vv -H 'XXX:xxx' 'http://localhost:8123/get_absolute_path_static_handler' < Content-Type: text/html; charset=UTF-8 < Transfer-Encoding: chunked < Keep-Alive: timeout=10 -< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334","real_time_microseconds":"0"} +< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334","real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} < Absolute Path File * Connection #0 to host localhost left intact @@ -635,7 +635,7 @@ $ curl -vv -H 'XXX:xxx' 'http://localhost:8123/get_relative_path_static_handler' < Content-Type: text/html; charset=UTF-8 < Transfer-Encoding: chunked < Keep-Alive: timeout=10 -< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334","real_time_microseconds":"0"} +< X-ClickHouse-Summary: {"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0","total_rows_to_read":"0","elapsed_ns":"662334","real_time_microseconds":"0", "virtual_cpu_time_microseconds":"0"} < Relative Path File * Connection #0 to host localhost left intact diff --git a/src/IO/Progress.cpp b/src/IO/Progress.cpp index 179c7f7f807..f546b8497b8 100644 --- a/src/IO/Progress.cpp +++ b/src/IO/Progress.cpp @@ -93,6 +93,8 @@ void ProgressValues::writeJSON(WriteBuffer & out) const writeText(elapsed_ns, out); writeCString("\",\"real_time_microseconds\":\"", out); writeText(real_time_microseconds, out); + writeCString("\",\"virtual_cpu_time_microseconds\":\"", out); + writeText(virtual_cpu_time_microseconds, out); writeCString("\"", out); writeCString("}", out); } @@ -113,6 +115,7 @@ bool Progress::incrementPiecewiseAtomically(const Progress & rhs) elapsed_ns += rhs.elapsed_ns; real_time_microseconds += rhs.real_time_microseconds; + virtual_cpu_time_microseconds += rhs.virtual_cpu_time_microseconds; return rhs.read_rows || rhs.written_rows; } @@ -133,6 +136,7 @@ void Progress::reset() elapsed_ns = 0; real_time_microseconds = 0; + virtual_cpu_time_microseconds = 0; } ProgressValues Progress::getValues() const @@ -153,6 +157,7 @@ ProgressValues Progress::getValues() const res.elapsed_ns = elapsed_ns.load(std::memory_order_relaxed); res.real_time_microseconds = real_time_microseconds.load(std::memory_order_relaxed); + res.virtual_cpu_time_microseconds = virtual_cpu_time_microseconds.load(std::memory_order_relaxed); return res; } @@ -175,6 +180,7 @@ ProgressValues Progress::fetchValuesAndResetPiecewiseAtomically() res.elapsed_ns = elapsed_ns.fetch_and(0); res.real_time_microseconds = real_time_microseconds.fetch_and(0); + res.virtual_cpu_time_microseconds = virtual_cpu_time_microseconds.fetch_and(0); return res; } @@ -197,6 +203,7 @@ Progress Progress::fetchAndResetPiecewiseAtomically() res.elapsed_ns = elapsed_ns.fetch_and(0); res.real_time_microseconds = real_time_microseconds.fetch_and(0); + res.virtual_cpu_time_microseconds = virtual_cpu_time_microseconds.fetch_and(0); return res; } @@ -217,6 +224,7 @@ Progress & Progress::operator=(Progress && other) noexcept elapsed_ns = other.elapsed_ns.load(std::memory_order_relaxed); real_time_microseconds = other.real_time_microseconds.load(std::memory_order_relaxed); + virtual_cpu_time_microseconds = other.virtual_cpu_time_microseconds.load(std::memory_order_relaxed); return *this; } @@ -257,4 +265,9 @@ void Progress::incrementRealTimeMicroseconds(UInt64 microseconds) real_time_microseconds.fetch_add(microseconds, std::memory_order_relaxed); } +void Progress::incrementVirtualCPUTimeMicroseconds(UInt64 microseconds) +{ + virtual_cpu_time_microseconds.fetch_add(microseconds, std::memory_order_relaxed); +} + } diff --git a/src/IO/Progress.h b/src/IO/Progress.h index 223496166ec..be2e2ae60ae 100644 --- a/src/IO/Progress.h +++ b/src/IO/Progress.h @@ -29,6 +29,7 @@ struct ProgressValues UInt64 elapsed_ns = 0; UInt64 real_time_microseconds = 0; + UInt64 virtual_cpu_time_microseconds = 0; void read(ReadBuffer & in, UInt64 server_revision); void write(WriteBuffer & out, UInt64 client_revision) const; @@ -42,6 +43,7 @@ struct ReadProgress UInt64 total_rows_to_read = 0; UInt64 total_bytes_to_read = 0; UInt64 real_time_microseconds = 0; + UInt64 virtual_cpu_time_microseconds = 0; ReadProgress(UInt64 read_rows_, UInt64 read_bytes_, UInt64 total_rows_to_read_ = 0, UInt64 total_bytes_to_read_ = 0) : read_rows(read_rows_), read_bytes(read_bytes_), total_rows_to_read(total_rows_to_read_), total_bytes_to_read(total_bytes_to_read_) {} @@ -99,6 +101,7 @@ struct Progress std::atomic elapsed_ns {0}; std::atomic real_time_microseconds {0}; + std::atomic virtual_cpu_time_microseconds {0}; Progress() = default; @@ -131,6 +134,8 @@ struct Progress void incrementRealTimeMicroseconds(UInt64 microseconds); + void incrementVirtualCPUTimeMicroseconds(UInt64 microseconds); + void reset(); ProgressValues getValues() const; diff --git a/src/Interpreters/executeQuery.cpp b/src/Interpreters/executeQuery.cpp index 4da2ea55066..aca43e577e7 100644 --- a/src/Interpreters/executeQuery.cpp +++ b/src/Interpreters/executeQuery.cpp @@ -91,6 +91,7 @@ namespace ProfileEvents extern const Event InsertQueryTimeMicroseconds; extern const Event OtherQueryTimeMicroseconds; extern const Event RealTimeMicroseconds; + extern const Event OSCPUVirtualTimeMicroseconds; } namespace DB @@ -426,6 +427,7 @@ void logQueryFinish( Progress p; p.incrementPiecewiseAtomically(Progress{ResultProgress{elem.result_rows, elem.result_bytes}}); p.incrementRealTimeMicroseconds((*profile_counters)[ProfileEvents::RealTimeMicroseconds]); + p.incrementVirtualCPUTimeMicroseconds((*profile_counters)[ProfileEvents::OSCPUVirtualTimeMicroseconds]); progress_callback(p); } diff --git a/tests/queries/0_stateless/03228_url_engine_response_headers.reference b/tests/queries/0_stateless/03228_url_engine_response_headers.reference index 84b499f5a8c..9dc9ca11f45 100644 --- a/tests/queries/0_stateless/03228_url_engine_response_headers.reference +++ b/tests/queries/0_stateless/03228_url_engine_response_headers.reference @@ -1,3 +1,3 @@ Map(LowCardinality(String), LowCardinality(String)) 1 1 -3 100 1 +3 100 1 1 diff --git a/tests/queries/0_stateless/03228_url_engine_response_headers.sql b/tests/queries/0_stateless/03228_url_engine_response_headers.sql index 41a1a2406da..f51b0eccac5 100644 --- a/tests/queries/0_stateless/03228_url_engine_response_headers.sql +++ b/tests/queries/0_stateless/03228_url_engine_response_headers.sql @@ -11,5 +11,6 @@ FROM url('http://127.0.0.1:8123/?query=select+1&user=default', LineAsString, 's SELECT *, mapFromString(_headers['X-ClickHouse-Summary'])['read_rows'], - toUInt64OrZero(mapFromString(_headers['X-ClickHouse-Summary'])['real_time_microseconds']) >= 0 ? 1 : 0 + toUInt64OrZero(mapFromString(_headers['X-ClickHouse-Summary'])['real_time_microseconds']) >= 0 ? 1 : 0, + toUInt64OrZero(mapFromString(_headers['X-ClickHouse-Summary'])['virtual_cpu_time_microseconds']) > 0 ? 1 : 0 FROM url('http://127.0.0.1:8123/?query=SELECT%20uniq%28number%253%29%20FROM%20numbers%28100%29&user=default&wait_end_of_query=1', LineAsString, 's String');