thevar1able/ClickHouse
1
0
Fork 0
mirror of https://github.com/ClickHouse/ClickHouse.git synced 2024-09-20 00:30:49 +00:00
Code Issues Packages Projects Releases Wiki Activity

The most precise way of tracking flushing time in 01246_buffer_flush

Browse Source 
Right now there are couple of issues with the test:

- it does not takes into account INSERT time
- it does not takes into account SELECT time, which can be significant
  from time to time, for instance here [1] it takes 3.3 seconds (and due
  to tsan build it is not possible to find out why)

      2024.07.23 20:52:18.238844 [ 13045 ] {d903650b-ab87-44f3-b7c3-4145e02f1301} <Debug> executeQuery: (from [::1]:39430) (comment: 01246_buffer_flush.sh) select count() from data_01256; (stage: Complete)
      2024.07.23 20:52:21.588183 [ 13045 ] {d903650b-ab87-44f3-b7c3-4145e02f1301} <Debug> TCPHandler: Processed in 3.354887498 sec.

  [1]: https://s3.amazonaws.com/clickhouse-test-reports/66934/919005c4f70b044ecd9cc1bbce5dc5e276e11929/stateless_tests__tsan__s3_storage__[4_4].html

Anyway all of this can be fixed by using QueryStart-insert into data
table time.

Signed-off-by: Azat Khuzhin <a.khuzhin@semrush.com>
This commit is contained in:
Azat Khuzhin 2024-07-25 11:06:00 +02:00
parent 2aa613fd14
commit 60f529f667
1 changed files with 31 additions and 18 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

49
tests/queries/0_stateless/01246_buffer_flush.sh
View File

@ -5,59 +5,72 @@ CUR_DIR=$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)
# shellcheck source=../shell_config.sh # shellcheck source=../shell_config.sh
. "$CUR_DIR"/../shell_config.sh . "$CUR_DIR"/../shell_config.sh
function elapsed_sec() set -e
function wait_until()
{ {
local expr=$1 && shift local expr=$1 && shift
local start end
start=$(date +%s.%N)
while ! eval "$expr"; do while ! eval "$expr"; do
sleep 0.5 sleep 0.5
done done
end=$(date +%s.%N) }
$CLICKHOUSE_LOCAL -q "select floor($end-$start)" function get_buffer_delay()
{
local buffer_insert_id=$1 && shift
$CLICKHOUSE_CLIENT -nm -q "
SYSTEM FLUSH LOGS;
WITH
(SELECT event_time_microseconds FROM system.query_log WHERE current_database = currentDatabase() AND type = 'QueryStart' AND query_id = '$buffer_insert_id') AS begin_,
(SELECT max(event_time) FROM data_01256) AS end_
SELECT dateDiff('seconds', begin_, end_)::UInt64;
"
} }
$CLICKHOUSE_CLIENT -nm -q " $CLICKHOUSE_CLIENT -nm -q "
drop table if exists data_01256; drop table if exists data_01256;
drop table if exists buffer_01256; drop table if exists buffer_01256;
create table data_01256 as system.numbers Engine=Memory(); create table data_01256 (key UInt64, event_time DateTime(6) MATERIALIZED now64(6)) Engine=Memory();
" "
echo "min" echo "min"
$CLICKHOUSE_CLIENT -nm -q " $CLICKHOUSE_CLIENT -q "
create table buffer_01256 as system.numbers Engine=Buffer(currentDatabase(), data_01256, 1, create table buffer_01256 (key UInt64) Engine=Buffer(currentDatabase(), data_01256, 1,
2, 100, /* time */ 2, 100, /* time */
4, 100, /* rows */ 4, 100, /* rows */
1, 1e6 /* bytes */ 1, 1e6 /* bytes */
); )
insert into buffer_01256 select * from system.numbers limit 5;
select count() from data_01256;
" "
sec=$(elapsed_sec '[[ $($CLICKHOUSE_CLIENT -q "select count() from data_01256") -eq 5 ]]') min_query_id=$(random_str 10)
$CLICKHOUSE_CLIENT --query_id="$min_query_id" -q "insert into buffer_01256 select * from system.numbers limit 5"
$CLICKHOUSE_CLIENT -q "select count() from data_01256"
wait_until '[[ $($CLICKHOUSE_CLIENT -q "select count() from data_01256") -eq 5 ]]'
sec=$(get_buffer_delay "$min_query_id")
[[ $sec -ge 2 ]] || echo "Buffer flushed too early, min_time=2, flushed after $sec sec" [[ $sec -ge 2 ]] || echo "Buffer flushed too early, min_time=2, flushed after $sec sec"
[[ $sec -lt 100 ]] || echo "Buffer flushed too late, max_time=100, flushed after $sec sec" [[ $sec -lt 100 ]] || echo "Buffer flushed too late, max_time=100, flushed after $sec sec"
$CLICKHOUSE_CLIENT -q "select count() from data_01256" $CLICKHOUSE_CLIENT -q "select count() from data_01256"
$CLICKHOUSE_CLIENT -q "drop table buffer_01256" $CLICKHOUSE_CLIENT -q "drop table buffer_01256"
echo "max" echo "max"
$CLICKHOUSE_CLIENT -nm -q " $CLICKHOUSE_CLIENT -q "
create table buffer_01256 as system.numbers Engine=Buffer(currentDatabase(), data_01256, 1, create table buffer_01256 (key UInt64) Engine=Buffer(currentDatabase(), data_01256, 1,
100, 2, /* time */ 100, 2, /* time */
0, 100, /* rows */ 0, 100, /* rows */
0, 1e6 /* bytes */ 0, 1e6 /* bytes */
); );
insert into buffer_01256 select * from system.numbers limit 5;
select count() from data_01256;
" "
sec=$(elapsed_sec '[[ $($CLICKHOUSE_CLIENT -q "select count() from data_01256") -eq 10 ]]') max_query_id=$(random_str 10)
$CLICKHOUSE_CLIENT --query_id="$max_query_id" -q "insert into buffer_01256 select * from system.numbers limit 5"
$CLICKHOUSE_CLIENT -q "select count() from data_01256"
wait_until '[[ $($CLICKHOUSE_CLIENT -q "select count() from data_01256") -eq 10 ]]'
sec=$(get_buffer_delay "$max_query_id")
[[ $sec -ge 2 ]] || echo "Buffer flushed too early, max_time=2, flushed after $sec sec" [[ $sec -ge 2 ]] || echo "Buffer flushed too early, max_time=2, flushed after $sec sec"
$CLICKHOUSE_CLIENT -q "select count() from data_01256" $CLICKHOUSE_CLIENT -q "select count() from data_01256"
$CLICKHOUSE_CLIENT -q "drop table buffer_01256" $CLICKHOUSE_CLIENT -q "drop table buffer_01256"
echo "direct" echo "direct"
$CLICKHOUSE_CLIENT -nm -q " $CLICKHOUSE_CLIENT -nm -q "
create table buffer_01256 as system.numbers Engine=Buffer(currentDatabase(), data_01256, 1, create table buffer_01256 (key UInt64) Engine=Buffer(currentDatabase(), data_01256, 1,
100, 100, /* time */ 100, 100, /* time */
0, 9, /* rows */ 0, 9, /* rows */
0, 1e6 /* bytes */ 0, 1e6 /* bytes */