less flaky functional tests

tests/clickhouse-test

@@ -170,7 +170,7 @@ def run_single_test(args, ext, server_logs_level, client_options, case_file, std
 
     if need_drop_database:
         clickhouse_proc_create = Popen(shlex.split(args.client), stdin=PIPE, stdout=PIPE, stderr=PIPE, universal_newlines=True)
-        seconds_left = max(args.timeout - (datetime.now() - start_time).total_seconds(), 10)
+        seconds_left = max(args.timeout - (datetime.now() - start_time).total_seconds(), 20)
         try:
             clickhouse_proc_create.communicate(("DROP DATABASE " + database), timeout=seconds_left)
         except TimeoutExpired:
@@ -207,7 +207,7 @@ def need_retry(stderr):
 def get_processlist(args):
     try:
         clickhouse_proc = Popen(shlex.split(args.client), stdin=PIPE, stdout=PIPE, stderr=PIPE)
-        (stdout, _) = clickhouse_proc.communicate((b"SHOW PROCESSLIST FORMAT Vertical"), timeout=10)
+        (stdout, _) = clickhouse_proc.communicate((b"SHOW PROCESSLIST FORMAT Vertical"), timeout=20)
         return False, stdout.decode('utf-8')
     except Exception as ex:
         print("Exception", ex)
@@ -352,7 +352,7 @@ def run_tests_array(all_tests_with_params):
                         clickhouse_proc = Popen(shlex.split(args.client), stdin=PIPE, stdout=PIPE, stderr=PIPE, universal_newlines=True)
                         failed_to_check = False
                         try:
-                            clickhouse_proc.communicate(("SELECT 'Running test {suite}/{case} from pid={pid}';".format(pid = os.getpid(), case = case, suite = suite)), timeout=10)
+                            clickhouse_proc.communicate(("SELECT 'Running test {suite}/{case} from pid={pid}';".format(pid = os.getpid(), case = case, suite = suite)), timeout=20)
                         except:
                             failed_to_check = True
 

tests/queries/0_stateless/00634_performance_introspection_and_logging.sh

@@ -48,7 +48,7 @@ SELECT
     threads_realtime >= threads_time_user_system_io,
     any(length(thread_ids)) >= 1
     FROM
-        (SELECT * FROM system.query_log PREWHERE query='$heavy_cpu_query' WHERE event_date >= today()-1 AND current_database = currentDatabase() AND type=2 ORDER BY event_time DESC LIMIT 1)
+        (SELECT * FROM system.query_log PREWHERE query='$heavy_cpu_query' WHERE event_date >= today()-2 AND current_database = currentDatabase() AND type=2 ORDER BY event_time DESC LIMIT 1)
     ARRAY JOIN ProfileEvents.Names AS PN, ProfileEvents.Values AS PV"
 
 # Clean

tests/queries/0_stateless/00956_sensitive_data_masking.sh

@@ -97,7 +97,7 @@ echo 7
 # and finally querylog
 $CLICKHOUSE_CLIENT \
   --server_logs_file=/dev/null \
-  --query="select * from system.query_log where current_database = currentDatabase() AND event_time > now() - 10 and query like '%TOPSECRET%';"
+  --query="select * from system.query_log where current_database = currentDatabase() AND event_date >= yesterday() and query like '%TOPSECRET%';"
 
 
 rm -f "$tmp_file" >/dev/null 2>&1

tests/queries/0_stateless/01231_log_queries_min_type.sql

@@ -2,18 +2,18 @@ set log_queries=1;
 
 select '01231_log_queries_min_type/QUERY_START';
 system flush logs;
-select count() from system.query_log where current_database = currentDatabase() and query like '%01231_log_queries_min_type/QUERY_START%' and query not like '%system.query_log%' and event_date = today() and event_time >= now() - interval 1 minute;
+select count() from system.query_log where current_database = currentDatabase() and query like '%01231_log_queries_min_type/QUERY_START%' and query not like '%system.query_log%' and event_date >= yesterday();
 
 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 current_database = currentDatabase() and query like '%01231_log_queries_min_type/EXCEPTION_BEFORE_START%' and query not like '%system.query_log%' and event_date = today() and event_time >= now() - interval 1 minute;
+select count() from system.query_log where current_database = currentDatabase() and query like '%01231_log_queries_min_type/EXCEPTION_BEFORE_START%' and query not like '%system.query_log%' and event_date >= yesterday();
 
 set max_rows_to_read='100K';
 set log_queries_min_type='EXCEPTION_WHILE_PROCESSING';
 select '01231_log_queries_min_type/EXCEPTION_WHILE_PROCESSING', max(number) from system.numbers limit 1e6; -- { serverError 158; }
 system flush logs;
-select count() from system.query_log where current_database = currentDatabase() and query like '%01231_log_queries_min_type/EXCEPTION_WHILE_PROCESSING%' and query not like '%system.query_log%' and event_date = today() and event_time >= now() - interval 1 minute and type = 'ExceptionWhileProcessing';
+select count() from system.query_log where current_database = currentDatabase() and query like '%01231_log_queries_min_type/EXCEPTION_WHILE_PROCESSING%' and query not like '%system.query_log%' and event_date >= yesterday() and type = 'ExceptionWhileProcessing';
 
 select '01231_log_queries_min_type w/ Settings/EXCEPTION_WHILE_PROCESSING', max(number) from system.numbers limit 1e6; -- { serverError 158; }
 system flush logs;
@@ -21,7 +21,6 @@ select count() from system.query_log where
     current_database = currentDatabase() and
     query like '%01231_log_queries_min_type w/ Settings/EXCEPTION_WHILE_PROCESSING%' and
     query not like '%system.query_log%' and
-    event_date = today() and
+    event_date >= yesterday() and
-    event_time >= now() - interval 1 minute and
     type = 'ExceptionWhileProcessing' and
     has(Settings.Names, 'max_rows_to_read');

tests/queries/0_stateless/01304_direct_io.sh

@@ -9,12 +9,12 @@ $CLICKHOUSE_CLIENT --multiquery --query "
     CREATE TABLE bug (UserID UInt64, Date Date) ENGINE = MergeTree ORDER BY Date;
     INSERT INTO bug SELECT rand64(), '2020-06-07' FROM numbers(50000000);
     OPTIMIZE TABLE bug FINAL;"
+LOG="$CLICKHOUSE_TMP/err-$CLICKHOUSE_DATABASE"
+$CLICKHOUSE_BENCHMARK --iterations 10 --max_threads 100 --min_bytes_to_use_direct_io 1 <<< "SELECT sum(UserID) FROM bug PREWHERE NOT ignore(Date)" 1>/dev/null 2>"$LOG"
+cat "$LOG" | grep Exception
+cat "$LOG" | grep Loaded
 
-$CLICKHOUSE_BENCHMARK --iterations 10 --max_threads 100 --min_bytes_to_use_direct_io 1 <<< "SELECT sum(UserID) FROM bug PREWHERE NOT ignore(Date)" 1>/dev/null 2>"$CLICKHOUSE_TMP"/err
+rm "$LOG"
-cat "$CLICKHOUSE_TMP"/err | grep Exception
-cat "$CLICKHOUSE_TMP"/err | grep Loaded
-
-rm "$CLICKHOUSE_TMP"/err
 
 $CLICKHOUSE_CLIENT --multiquery --query "
     DROP TABLE bug;"

tests/queries/0_stateless/01344_min_bytes_to_use_mmap_io_index.sql

@@ -6,6 +6,6 @@ SET min_bytes_to_use_mmap_io = 1;
 SELECT * FROM test_01344 WHERE x = 'Hello, world';
 
 SYSTEM FLUSH LOGS;
-SELECT PE.Values FROM system.query_log ARRAY JOIN ProfileEvents AS PE WHERE current_database = currentDatabase() AND event_date >= yesterday() AND event_time >= now() - 300 AND query LIKE 'SELECT * FROM test_01344 WHERE x = ''Hello, world''%' AND PE.Names = 'CreatedReadBufferMMap' AND type = 2 ORDER BY event_time DESC LIMIT 1;
+SELECT PE.Values FROM system.query_log ARRAY JOIN ProfileEvents AS PE WHERE current_database = currentDatabase() AND event_date >= yesterday() AND query LIKE 'SELECT * FROM test_01344 WHERE x = ''Hello, world''%' AND PE.Names = 'CreatedReadBufferMMap' AND type = 2 ORDER BY event_time DESC LIMIT 1;
 
 DROP TABLE test_01344;

tests/queries/0_stateless/01360_materialized_view_with_join_on_query_log.sql

@@ -17,7 +17,7 @@ CREATE MATERIALIZED VIEW slow_log Engine=Memory AS
                 extract(query,'/\\*\\s*QUERY_GROUP_ID:(.*?)\\s*\\*/') as QUERY_GROUP_ID,
                 *
             FROM system.query_log
-            WHERE type<>1 and event_date >= yesterday() and event_time > now() - 120
+            WHERE type<>1 and event_date >= yesterday()
         ) as ql
         INNER JOIN expected_times USING (QUERY_GROUP_ID)
         WHERE query_duration_ms > max_query_duration_ms
@@ -38,7 +38,7 @@ SELECT
     extract(query,'/\\*\\s*QUERY_GROUP_ID:(.*?)\\s*\\*/') as QUERY_GROUP_ID,
     count()
 FROM system.query_log
-WHERE current_database = currentDatabase() AND type<>1 and event_date >= yesterday() and event_time > now() - 20 and QUERY_GROUP_ID<>''
+WHERE current_database = currentDatabase() AND type<>1 and event_date >= yesterday() and QUERY_GROUP_ID<>''
 GROUP BY QUERY_GROUP_ID
 ORDER BY QUERY_GROUP_ID;
 

tests/queries/0_stateless/01475_read_subcolumns.sql

@@ -10,7 +10,7 @@ SYSTEM FLUSH LOGS;
 SELECT ProfileEvents.Values[indexOf(ProfileEvents.Names, 'FileOpen')]
 FROM system.query_log
 WHERE (type = 'QueryFinish') AND (lower(query) LIKE lower('SELECT a.size0 FROM %t_arr%'))
-    AND event_time > now() - INTERVAL 10 SECOND AND current_database = currentDatabase();
+    AND current_database = currentDatabase();
 
 SELECT '====tuple====';
 DROP TABLE IF EXISTS t_tup;
@@ -27,7 +27,7 @@ SYSTEM FLUSH LOGS;
 SELECT ProfileEvents.Values[indexOf(ProfileEvents.Names, 'FileOpen')]
 FROM system.query_log
 WHERE (type = 'QueryFinish') AND (lower(query) LIKE lower('SELECT t._ FROM %t_tup%'))
-    AND event_time > now() - INTERVAL 10 SECOND AND current_database = currentDatabase();
+    AND current_database = currentDatabase();
 
 SELECT '====nullable====';
 DROP TABLE IF EXISTS t_nul;
@@ -41,7 +41,7 @@ SYSTEM FLUSH LOGS;
 SELECT ProfileEvents.Values[indexOf(ProfileEvents.Names, 'FileOpen')]
 FROM system.query_log
 WHERE (type = 'QueryFinish') AND (lower(query) LIKE lower('SELECT n.null FROM %t_nul%'))
-    AND event_time > now() - INTERVAL 10 SECOND AND current_database = currentDatabase();
+    AND current_database = currentDatabase();
 
 SELECT '====map====';
 SET allow_experimental_map_type = 1;
@@ -60,7 +60,7 @@ SYSTEM FLUSH LOGS;
 SELECT ProfileEvents.Values[indexOf(ProfileEvents.Names, 'FileOpen')]
 FROM system.query_log
 WHERE (type = 'QueryFinish') AND (lower(query) LIKE lower('SELECT m.% FROM %t_map%'))
-    AND event_time > now() - INTERVAL 10 SECOND AND current_database = currentDatabase();
+    AND current_database = currentDatabase();
 
 DROP TABLE t_arr;
 DROP TABLE t_nul;

tests/queries/0_stateless/01531_query_log_query_comment.sql

@@ -5,7 +5,7 @@ set enable_global_with_statement=1;
 select /* test=01531, enable_global_with_statement=0 */ 2;
 system flush logs;
 select count() from system.query_log
-where event_time >= now() - interval 5 minute
+where event_date >= yesterday()
     and query like '%select /* test=01531, enable_global_with_statement=0 */ 2%'
     and current_database = currentDatabase()
     ;
@@ -14,7 +14,7 @@ set enable_global_with_statement=1;
 select /* test=01531 enable_global_with_statement=1 */ 2;
 system flush logs;
 select count() from system.query_log
-where event_time >= now() - interval 5 minute
+where event_date >= yesterday()
     and query like '%select /* test=01531 enable_global_with_statement=1 */ 2%'
     and current_database = currentDatabase()
     ;

tests/queries/0_stateless/01533_multiple_nested.sql

@@ -36,7 +36,7 @@ SYSTEM FLUSH LOGS;
 SELECT ProfileEvents.Values[indexOf(ProfileEvents.Names, 'FileOpen')]
 FROM system.query_log
 WHERE (type = 'QueryFinish') AND (lower(query) LIKE lower('SELECT col1.a FROM %nested%'))
-    AND event_time > now() - INTERVAL 10 SECOND AND current_database = currentDatabase();
+    AND event_date >= yesterday() AND current_database = currentDatabase();
 
 SYSTEM DROP MARK CACHE;
 SELECT col3.n2.s FROM nested FORMAT Null;
@@ -46,7 +46,7 @@ SYSTEM FLUSH LOGS;
 SELECT ProfileEvents.Values[indexOf(ProfileEvents.Names, 'FileOpen')]
 FROM system.query_log
 WHERE (type = 'QueryFinish') AND (lower(query) LIKE lower('SELECT col3.n2.s FROM %nested%'))
-    AND event_time > now() - INTERVAL 10 SECOND AND current_database = currentDatabase();
+    AND event_date >= yesterday() AND current_database = currentDatabase();
 
 DROP TABLE nested;
 

tests/queries/0_stateless/01546_log_queries_min_query_duration_ms.sql

@@ -15,16 +15,14 @@ where
     query like '%01546_log_queries_min_query_duration_ms-fast%'
     and query not like '%system.query_log%'
     and current_database = currentDatabase()
-    and event_date = today()
+    and event_date >= yesterday();
-    and event_time >= now() - interval 1 minute;
 select count()
 from system.query_thread_log
 where
     query like '%01546_log_queries_min_query_duration_ms-fast%'
     and query not like '%system.query_thread_log%'
     and current_database = currentDatabase()
-    and event_date = today()
+    and event_date >= yesterday();
-    and event_time >= now() - interval 1 minute;
 
 --
 -- slow -- query logged
@@ -40,8 +38,7 @@ where
     query like '%01546_log_queries_min_query_duration_ms-slow%'
     and query not like '%system.query_log%'
     and current_database = currentDatabase()
-    and event_date = today()
+    and event_date >= yesterday();
-    and event_time >= now() - interval 1 minute;
 -- There at least two threads involved in a simple query
 -- (one thread just waits another, sigh)
 select count() == 2
@@ -50,5 +47,4 @@ where
     query like '%01546_log_queries_min_query_duration_ms-slow%'
     and query not like '%system.query_thread_log%'
     and current_database = currentDatabase()
-    and event_date = today()
+    and event_date >= yesterday();
-    and event_time >= now() - interval 1 minute;

tests/queries/0_stateless/01547_query_log_current_database.sql

@@ -23,8 +23,7 @@ from system.query_log
 where
     query like '%01547_query_log_current_database%'
     and current_database = currentDatabase()
-    and event_date = today()
+    and event_date >= yesterday();
-    and event_time >= now() - interval 1 minute;
 
 -- at least two threads for processing
 -- (but one just waits for another, sigh)

tests/queries/0_stateless/01548_query_log_query_execution_ms.sql

@@ -13,8 +13,7 @@ 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_date >= yesterday();
-    and event_time >= now() - interval 1 minute;
 
 -- at least two threads for processing
 -- (but one just waits for another, sigh)

tests/queries/0_stateless/01600_benchmark_query.sh

@@ -4,9 +4,10 @@ CURDIR=$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)
 # shellcheck source=../shell_config.sh
 . "$CURDIR"/../shell_config.sh
 
-$CLICKHOUSE_BENCHMARK --iterations 10 --query "SELECT 1" 1>/dev/null 2>"$CLICKHOUSE_TMP"/err
+LOG="$CLICKHOUSE_TMP/err-$CLICKHOUSE_DATABASE"
+$CLICKHOUSE_BENCHMARK --iterations 10 --query "SELECT 1" 1>/dev/null 2>"$LOG"
 
-cat "$CLICKHOUSE_TMP"/err | grep Exception
+cat "$LOG" | grep Exception
-cat "$CLICKHOUSE_TMP"/err | grep Loaded
+cat "$LOG" | grep Loaded
 
-rm "$CLICKHOUSE_TMP"/err
+rm "$LOG"

tests/queries/0_stateless/01686_event_time_microseconds_part_log.sql

@@ -15,6 +15,8 @@ SYSTEM FLUSH LOGS;
 WITH (
          SELECT (event_time, event_time_microseconds)
          FROM system.part_log
+         WHERE "table" = 'table_with_single_pk'
+             AND "database" = currentDatabase()
          ORDER BY event_time DESC
          LIMIT 1
     ) AS time

tests/queries/0_stateless/01702_system_query_log.sql

@@ -136,7 +136,7 @@ SELECT 'ACTUAL LOG CONTENT:';
 -- Try to filter out all possible previous junk events by excluding old log entries,
 SELECT query_kind, query FROM system.query_log
 WHERE
-    log_comment LIKE '%system.query_log%' AND type == 'QueryStart' AND event_time >= now() - 10
+    log_comment LIKE '%system.query_log%' AND type == 'QueryStart' AND event_date >= yesterday()
     AND current_database == currentDatabase()
 ORDER BY event_time_microseconds;
 

tests/queries/skip_list.json

@@ -525,8 +525,8 @@
         "00571_non_exist_database_when_create_materializ_view",
         "00575_illegal_column_exception_when_drop_depen_column",
         "00599_create_view_with_subquery",
-        "00604_show_create_database",
         "00600_replace_running_query",
+        "00604_show_create_database",
         "00612_http_max_query_size",
         "00619_union_highlite",
         "00620_optimize_on_nonleader_replica_zookeeper",
@@ -577,6 +577,7 @@
         "00933_test_fix_extra_seek_on_compressed_cache",
         "00933_ttl_replicated_zookeeper",
         "00933_ttl_with_default",
+        "00950_dict_get",
         "00955_test_final_mark",
         "00976_ttl_with_old_parts",
         "00980_merge_alter_settings",
@@ -740,8 +741,8 @@
         "01530_drop_database_atomic_sync",
         "01541_max_memory_usage_for_user_long",
         "01542_dictionary_load_exception_race",
-        "01560_optimize_on_insert_zookeeper",
         "01545_system_errors", // looks at the difference of values in system.errors
+        "01560_optimize_on_insert_zookeeper",
         "01575_disable_detach_table_of_dictionary",
         "01593_concurrent_alter_mutations_kill",
         "01593_concurrent_alter_mutations_kill_many_replicas",
@@ -754,11 +755,23 @@
         "01603_rename_overwrite_bug",
         "01646_system_restart_replicas_smoke", // system restart replicas is a global query
         "01656_test_query_log_factories_info",
+        "01658_read_file_to_stringcolumn",
         "01669_columns_declaration_serde",
         "01676_dictget_in_default_expression",
+        "01681_cache_dictionary_simple_key",
+        "01682_cache_dictionary_complex_key",
+        "01683_flat_dictionary",
+        "01684_ssd_cache_dictionary_simple_key",
+        "01685_ssd_cache_dictionary_complex_key",
         "01700_system_zookeeper_path_in",
+        "01702_system_query_log", // It's ok to execute in parallel with oter tests but not several instances of the same test.
+        "01702_system_query_log", // Runs many global system queries
         "01715_background_checker_blather_zookeeper",
+        "01721_engine_file_truncate_on_insert", // It's ok to execute in parallel but not several instances of the same test.
         "01747_alter_partition_key_enum_zookeeper",
+        "01748_dictionary_table_dot", // creates database
+        "01760_polygon_dictionaries",
+        "01760_system_dictionaries",
         "01761_alter_decimal_zookeeper",
         "attach",
         "ddl_dictionaries",
@@ -767,18 +780,6 @@
         "live_view",
         "memory_leak",
         "memory_limit",
-        "polygon_dicts", // they use an explicitly specified database
+        "polygon_dicts" // they use an explicitly specified database
-        "01658_read_file_to_stringcolumn",
-        "01721_engine_file_truncate_on_insert", // It's ok to execute in parallel but not several instances of the same test.
-        "01702_system_query_log", // It's ok to execute in parallel with oter tests but not several instances of the same test.
-        "01748_dictionary_table_dot", // creates database
-        "00950_dict_get",
-        "01683_flat_dictionary",
-        "01681_cache_dictionary_simple_key",
-        "01682_cache_dictionary_complex_key",
-        "01684_ssd_cache_dictionary_simple_key",
-        "01685_ssd_cache_dictionary_complex_key",
-        "01760_system_dictionaries",
-        "01760_polygon_dictionaries"
     ]
 }