Adjust performance tests by azat · Pull Request #29760 · ClickHouse/ClickHouse

azat · 2021-10-05T06:58:46Z

Changelog category (leave one):

Not for changelog (changelog entry is not required)

Changelog entry (a user-readable short description of the changes that goes to CHANGELOG.md):

tests/performance: decrease number of rows to INSERT in parallel_mv (10e6 is too much, and usually it exceed allowed_single_run_time (=2s))

10e6 is too much, and usually it exceed allowed_single_run_time (=2s).

alexey-milovidov · 2021-10-05T07:24:28Z

Is the change needed only because parallel MV insertion stopped to work?
Maybe drop perf test and replace it with a functional tests with sleep(1) and a check that insertion into two MVs can finish in less than two seconds.

azat · 2021-10-05T07:40:38Z

Is the change needed only because parallel MV insertion stopped to work?

Hm, indeed, it seems that it is just broken, I guess after #28582

Details

2021.10.05 01:53:00.453530 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> default.`.inner.mv_4`: Renaming temporary part tmp_insert_all_1_1_0 to all_1_1_0.
2021.10.05 01:53:00.454753 [ 1246 ] {parallel_mv.query0.prewarm0} <Debug> DiskLocal: Reserving 8.00 MiB on disk `default`, having unreserved 131.83 GiB.
2021.10.05 01:53:00.475316 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> default.main_table: Renaming temporary part tmp_insert_all_3_3_0 to all_3_3_0.
2021.10.05 01:53:00.475800 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> ContextAccess (default): Access granted: SELECT(number) ON default.main_table
2021.10.05 01:53:00.475839 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.10.05 01:53:00.489028 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> ContextAccess (default): Access granted: SELECT(number) ON default.main_table
2021.10.05 01:53:00.489073 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.10.05 01:53:00.501578 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> ContextAccess (default): Access granted: SELECT(number) ON default.main_table
2021.10.05 01:53:00.501622 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.10.05 01:53:00.513832 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> ContextAccess (default): Access granted: SELECT(number) ON default.main_table
2021.10.05 01:53:00.513877 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.10.05 01:53:00.527718 [ 1246 ] {parallel_mv.query0.prewarm0} <Debug> DiskLocal: Reserving 8.00 MiB on disk `default`, having unreserved 131.83 GiB.
2021.10.05 01:53:00.547839 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> default.main_table: Renaming temporary part tmp_insert_all_4_4_0 to all_4_4_0.
2021.10.05 01:53:00.548296 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> ContextAccess (default): Access granted: SELECT(number) ON default.main_table
2021.10.05 01:53:00.548338 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.10.05 01:53:00.568763 [ 1246 ] {parallel_mv.query0.prewarm0} <Debug> DiskLocal: Reserving 44.31 MiB on disk `default`, having unreserved 131.82 GiB.
2021.10.05 01:53:00.656901 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> default.`.inner.mv_1`: Renaming temporary part tmp_insert_all_2_2_0 to all_2_2_0.
2021.10.05 01:53:00.657378 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> ContextAccess (default): Access granted: SELECT(number) ON default.main_table
2021.10.05 01:53:00.657417 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.10.05 01:53:00.676376 [ 1246 ] {parallel_mv.query0.prewarm0} <Debug> DiskLocal: Reserving 44.31 MiB on disk `default`, having unreserved 131.81 GiB.
2021.10.05 01:53:00.816125 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> default.`.inner.mv_2`: Renaming temporary part tmp_insert_all_2_2_0 to all_2_2_0.
2021.10.05 01:53:00.816645 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> ContextAccess (default): Access granted: SELECT(number) ON default.main_table
2021.10.05 01:53:00.816687 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.10.05 01:53:00.837678 [ 1246 ] {parallel_mv.query0.prewarm0} <Debug> DiskLocal: Reserving 44.31 MiB on disk `default`, having unreserved 131.79 GiB.
2021.10.05 01:53:00.925963 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> default.`.inner.mv_3`: Renaming temporary part tmp_insert_all_2_2_0 to all_2_2_0.
2021.10.05 01:53:00.926446 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> ContextAccess (default): Access granted: SELECT(number) ON default.main_table
2021.10.05 01:53:00.926487 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.10.05 01:53:00.946752 [ 1246 ] {parallel_mv.query0.prewarm0} <Debug> DiskLocal: Reserving 44.31 MiB on disk `default`, having unreserved 131.78 GiB.
2021.10.05 01:53:01.035259 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> default.`.inner.mv_4`: Renaming temporary part tmp_insert_all_2_2_0 to all_2_2_0.
2021.10.05 01:53:01.036661 [ 1246 ] {parallel_mv.query0.prewarm0} <Debug> DiskLocal: Reserving 8.00 MiB on disk `default`, having unreserved 131.76 GiB.
2021.10.05 01:53:01.055437 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> default.main_table: Renaming temporary part tmp_insert_all_5_5_0 to all_5_5_0.
2021.10.05 01:53:01.055870 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> ContextAccess (default): Access granted: SELECT(number) ON default.main_table
2021.10.05 01:53:01.055911 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.10.05 01:53:01.068921 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> ContextAccess (default): Access granted: SELECT(number) ON default.main_table
2021.10.05 01:53:01.068966 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.10.05 01:53:01.080304 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> ContextAccess (default): Access granted: SELECT(number) ON default.main_table
2021.10.05 01:53:01.080348 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.10.05 01:53:01.091936 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> ContextAccess (default): Access granted: SELECT(number) ON default.main_table
2021.10.05 01:53:01.091981 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.10.05 01:53:01.103936 [ 1246 ] {parallel_mv.query0.prewarm0} <Debug> DiskLocal: Reserving 8.00 MiB on disk `default`, having unreserved 131.76 GiB.
2021.10.05 01:53:01.123127 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> default.main_table: Renaming temporary part tmp_insert_all_6_6_0 to all_6_6_0.
2021.10.05 01:53:01.123592 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> ContextAccess (default): Access granted: SELECT(number) ON default.main_table
2021.10.05 01:53:01.123634 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.10.05 01:53:01.142704 [ 1246 ] {parallel_mv.query0.prewarm0} <Debug> DiskLocal: Reserving 44.31 MiB on disk `default`, having unreserved 131.76 GiB.
...
2021.10.05 01:53:02.697285 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> PushingToViews: Pushing (parallel 4) from default.main_table to default.mv_1 took 428 ms.
2021.10.05 01:53:02.697294 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> PushingToViews: Pushing (parallel 4) from default.main_table to default.mv_2 took 665 ms.
2021.10.05 01:53:02.697304 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> PushingToViews: Pushing (parallel 4) from default.main_table to default.mv_3 took 438 ms.
2021.10.05 01:53:02.697309 [ 1246 ] {parallel_mv.query0.prewarm0} <Trace> PushingToViews: Pushing (parallel 4) from default.main_table to default.mv_4 took 439 ms.
2021.10.05 01:53:02.697650 [ 405 ] {parallel_mv.query0.prewarm0} <Information> executeQuery: Read 10485450 rows, 80.00 MiB in 2.864713013 sec., 3660209 rows/sec., 27.93 MiB/sec.
2021.10.05 01:53:02.697672 [ 405 ] {parallel_mv.query0.prewarm0} <Debug> MemoryTracker: Peak memory usage (for query): 184.27 MiB.

Algunenano · 2021-10-05T08:15:18Z

There is an issue related to this: #29621 Parallel MVs are currently broken.

tests/performance: decrease number of rows to INSERT in parallel_mv

378caa2

10e6 is too much, and usually it exceed allowed_single_run_time (=2s).

robot-clickhouse added the pr-not-for-changelog This PR should not be mentioned in the changelog label Oct 5, 2021

azat mentioned this pull request Oct 5, 2021

Forbid Nullable for JSONExtract* (JSONExtract() still supports Nullable), leads to SIGSEGV before #29746

Merged

alexey-milovidov requested a review from KochetovNicolai October 5, 2021 07:24

azat marked this pull request as draft October 5, 2021 07:40

KochetovNicolai approved these changes Oct 5, 2021

View reviewed changes

azat mentioned this pull request Oct 5, 2021

Fix parallel_view_processing #29786

Merged

azat closed this Oct 5, 2021

azat deleted the perf-fixes branch October 27, 2021 19:46

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Adjust performance tests#29760

Adjust performance tests#29760
azat wants to merge 1 commit intoClickHouse:masterfrom
azat:perf-fixes

azat commented Oct 5, 2021

Uh oh!

alexey-milovidov commented Oct 5, 2021

Uh oh!

azat commented Oct 5, 2021 •

edited

Loading

Uh oh!

Algunenano commented Oct 5, 2021

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

Conversation

azat commented Oct 5, 2021

Uh oh!

alexey-milovidov commented Oct 5, 2021

Uh oh!

azat commented Oct 5, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Algunenano commented Oct 5, 2021

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

azat commented Oct 5, 2021 •

edited

Loading