Add ability to execute mutations synchronously #8237

alesapin · 2019-12-16T15:55:26Z

I hereby agree to the terms of the CLA available at: https://yandex.ru/legal/cla/?lang=en

Changelog category (leave one):

Improvement

Changelog entry (up to few sentences, required except for Non-significant/Documentation categories):
Add setting mutations_sync which allows you to wait ALTER UPDATE/DELETE queries synchronously.

alesapin · 2019-12-16T17:31:33Z

Own tests failed :(

alesapin · 2019-12-16T19:58:19Z

According to logs 10 seconds is not enough for mutation of two parts.

2019.12.16 20:20:58.616343 [ 36 ] {862e949e-b28f-4864-abfb-58f07ecd0141} <Debug> executeQuery: (from [::1]:54892) ALTER TABLE table_for_synchronous_mutations_no_replication UPDATE v1 = v1 + 1 WHERE 1  SETTINGS mutation_synchronous_wait_timeout = 10
2019.12.16 20:20:58.686906 [ 36 ] {862e949e-b28f-4864-abfb-58f07ecd0141} <Information> test_s3z7p9.table_for_synchronous_mutations_no_replication: Added mutation: mutation_5.txt
2019.12.16 20:20:58.686932 [ 36 ] {862e949e-b28f-4864-abfb-58f07ecd0141} <Information> test_s3z7p9.table_for_synchronous_mutations_no_replication: Waiting mutation: mutation_5.txt for 10 seconds
2019.12.16 20:20:58.687802 [ 45 ] {} <Debug> DiskLocal: Reserving 1.00 MiB on disk `default`, having unreserved 396.38 GiB.
2019.12.16 20:20:58.867656 [ 2 ] {} <Trace> SystemLog (system.query_log): Flushing system log
2019.12.16 20:20:58.868468 [ 2 ] {} <Debug> DiskLocal: Reserving 1.00 MiB on disk `default`, having unreserved 396.38 GiB.
2019.12.16 20:20:58.871714 [ 2 ] {} <Trace> system.query_log: Renaming temporary part tmp_insert_201912_2_2_0 to 201912_2_2_0_2.
2019.12.16 20:20:58.888662 [ 3 ] {} <Trace> SystemLog (system.query_thread_log): Flushing system log
2019.12.16 20:20:58.889236 [ 3 ] {} <Debug> DiskLocal: Reserving 1.00 MiB on disk `default`, having unreserved 396.38 GiB.
2019.12.16 20:20:58.891434 [ 6 ] {} <Trace> SystemLog (system.text_log): Flushing system log
2019.12.16 20:20:58.891972 [ 3 ] {} <Trace> system.query_thread_log: Renaming temporary part tmp_insert_201912_2_2_0 to 201912_2_2_0_2.
2019.12.16 20:20:58.892320 [ 6 ] {} <Debug> DiskLocal: Reserving 1.00 MiB on disk `default`, having unreserved 396.37 GiB.
2019.12.16 20:20:58.893661 [ 6 ] {} <Trace> system.text_log: Renaming temporary part tmp_insert_201912_2_2_0 to 201912_2_2_0_2.
2019.12.16 20:20:58.918133 [ 4 ] {} <Trace> SystemLog (system.part_log): Flushing system log
2019.12.16 20:20:58.918396 [ 4 ] {} <Debug> DiskLocal: Reserving 1.00 MiB on disk `default`, having unreserved 396.37 GiB.
2019.12.16 20:20:58.919751 [ 4 ] {} <Trace> system.part_log: Renaming temporary part tmp_insert_201912_2_2_0 to 201912_2_2_0_2.
2019.12.16 20:20:58.932256 [ 7 ] {} <Trace> SystemLog (system.metric_log): Flushing system log
2019.12.16 20:20:58.934049 [ 7 ] {} <Debug> DiskLocal: Reserving 1.00 MiB on disk `default`, having unreserved 396.37 GiB.
2019.12.16 20:20:58.955291 [ 7 ] {} <Trace> system.metric_log: Renaming temporary part tmp_insert_201912_2_2_0 to 201912_2_2_0_2.
2019.12.16 20:21:02.610187 [ 37 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): Key condition: unknown
2019.12.16 20:21:02.610227 [ 37 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): MinMax index condition: unknown
2019.12.16 20:21:02.610244 [ 37 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): Selected 1 parts by date, 1 parts by key, 7 marks to read from 1 ranges
2019.12.16 20:21:02.610286 [ 37 ] {} <Trace> MergeTreeSelectProcessor: Reading 1 ranges from part 0_1_1_0_3, approx. 57344 rows starting from 0
2019.12.16 20:21:02.610319 [ 37 ] {} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2019.12.16 20:21:02.610385 [ 37 ] {} <Trace> Aggregator: Aggregating
2019.12.16 20:21:02.610406 [ 37 ] {} <Trace> Aggregator: Aggregation method: without_key
2019.12.16 20:21:02.610434 [ 37 ] {} <Trace> Aggregator: Aggregated. 0 to 1 rows (from 0.000 MiB) in 0.000 sec. (0.000 rows/sec., 0.000 MiB/sec.)
2019.12.16 20:21:02.610448 [ 37 ] {} <Trace> Aggregator: Merging aggregated data
2019.12.16 20:21:02.610473 [ 37 ] {} <Trace> virtual DB::MergingAndConvertingBlockInputStream::~MergingAndConvertingBlockInputStream(): Waiting for threads to finish
2019.12.16 20:21:02.610520 [ 37 ] {} <Trace> test_s3z7p9.table_for_synchronous_mutations_no_replication (MergerMutator): Part 0_1_1_0_3 doesn't change up to mutation version 4
2019.12.16 20:21:02.610567 [ 37 ] {} <Debug> DiskLocal: Reserving 1.00 MiB on disk `default`, having unreserved 396.37 GiB.
2019.12.16 20:21:02.610610 [ 37 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication: Cloning part /var/lib/clickhouse/data/test_s3z7p9/table_for_synchronous_mutations_no_replication/0_1_1_0_3/ to /var/lib/clickhouse/data/test_s3z7p9/table_for_synchronous_mutations_no_replication/tmp_clone_0_1_1_0_4
2019.12.16 20:21:02.611233 [ 37 ] {} <Trace> test_s3z7p9.table_for_synchronous_mutations_no_replication: Renaming temporary part tmp_clone_0_1_1_0_4 to 0_1_1_0_4.
2019.12.16 20:21:02.611652 [ 37 ] {} <Debug> DiskLocal: Reserving 1.00 MiB on disk `default`, having unreserved 396.37 GiB.
2019.12.16 20:21:02.611882 [ 37 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): Key condition: unknown
2019.12.16 20:21:02.611900 [ 37 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): MinMax index condition: unknown
2019.12.16 20:21:02.611915 [ 37 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): Selected 1 parts by date, 1 parts by key, 7 marks to read from 1 ranges
2019.12.16 20:21:02.611934 [ 37 ] {} <Trace> MergeTreeSelectProcessor: Reading 1 ranges from part 0_1_1_0_4, approx. 57344 rows starting from 0
2019.12.16 20:21:02.611954 [ 37 ] {} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2019.12.16 20:21:02.612002 [ 37 ] {} <Trace> Aggregator: Aggregating
2019.12.16 20:21:02.612379 [ 37 ] {} <Trace> Aggregator: Aggregation method: without_key
2019.12.16 20:21:02.612415 [ 37 ] {} <Trace> Aggregator: Aggregated. 50000 to 1 rows (from 0.191 MiB) in 0.000 sec. (127828198.901 rows/sec., 487.626 MiB/sec.)
2019.12.16 20:21:02.612432 [ 37 ] {} <Trace> Aggregator: Merging aggregated data
2019.12.16 20:21:02.612452 [ 37 ] {} <Trace> virtual DB::MergingAndConvertingBlockInputStream::~MergingAndConvertingBlockInputStream(): Waiting for threads to finish
2019.12.16 20:21:02.612480 [ 37 ] {} <Trace> test_s3z7p9.table_for_synchronous_mutations_no_replication (MergerMutator): Mutating part 0_1_1_0_4 to mutation version 5
2019.12.16 20:21:02.612751 [ 37 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): Key condition: unknown
2019.12.16 20:21:02.612769 [ 37 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): MinMax index condition: unknown
2019.12.16 20:21:02.612781 [ 37 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): Selected 1 parts by date, 1 parts by key, 7 marks to read from 1 ranges
2019.12.16 20:21:02.612804 [ 37 ] {} <Trace> MergeTreeSelectProcessor: Reading 1 ranges from part 0_1_1_0_4, approx. 57344 rows starting from 0
2019.12.16 20:21:02.612825 [ 37 ] {} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2019.12.16 20:21:02.615319 [ 37 ] {} <Trace> test_s3z7p9.table_for_synchronous_mutations_no_replication: Renaming temporary part tmp_mut_0_1_1_0_5 to 0_1_1_0_5.
2019.12.16 20:21:04.688657 [ 45 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): Key condition: unknown, true, or
2019.12.16 20:21:04.688707 [ 45 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): MinMax index condition: unknown, true, or
2019.12.16 20:21:04.688724 [ 45 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): Selected 1 parts by date, 1 parts by key, 7 marks to read from 1 ranges
2019.12.16 20:21:04.688756 [ 45 ] {} <Trace> MergeTreeSelectProcessor: Reading 1 ranges from part 1_2_2_0_3, approx. 57344 rows starting from 0
2019.12.16 20:21:04.688786 [ 45 ] {} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2019.12.16 20:21:04.688855 [ 45 ] {} <Trace> Aggregator: Aggregating
2019.12.16 20:21:06.394006 [ 6 ] {} <Trace> SystemLog (system.text_log): Flushing system log
2019.12.16 20:21:06.394433 [ 6 ] {} <Debug> DiskLocal: Reserving 1.00 MiB on disk `default`, having unreserved 396.37 GiB.
2019.12.16 20:21:06.395768 [ 6 ] {} <Trace> system.text_log: Renaming temporary part tmp_insert_201912_3_3_0 to 201912_3_3_0_3.
2019.12.16 20:21:06.420516 [ 4 ] {} <Trace> SystemLog (system.part_log): Flushing system log
2019.12.16 20:21:06.420783 [ 4 ] {} <Debug> DiskLocal: Reserving 1.00 MiB on disk `default`, having unreserved 396.37 GiB.
2019.12.16 20:21:06.422172 [ 4 ] {} <Trace> system.part_log: Renaming temporary part tmp_insert_201912_3_3_0 to 201912_3_3_0_3.
2019.12.16 20:21:06.456227 [ 7 ] {} <Trace> SystemLog (system.metric_log): Flushing system log
2019.12.16 20:21:06.458459 [ 7 ] {} <Debug> DiskLocal: Reserving 1.00 MiB on disk `default`, having unreserved 396.37 GiB.
2019.12.16 20:21:06.480613 [ 7 ] {} <Trace> system.metric_log: Renaming temporary part tmp_insert_201912_3_3_0 to 201912_3_3_0_3.
2019.12.16 20:21:07.689489 [ 45 ] {} <Trace> Aggregator: Aggregation method: without_key
2019.12.16 20:21:07.689568 [ 45 ] {} <Trace> Aggregator: Aggregated. 50000 to 1 rows (from 0.000 MiB) in 3.001 sec. (16662.882 rows/sec., 0.000 MiB/sec.)
2019.12.16 20:21:07.689584 [ 45 ] {} <Trace> Aggregator: Merging aggregated data
2019.12.16 20:21:07.689616 [ 45 ] {} <Trace> virtual DB::MergingAndConvertingBlockInputStream::~MergingAndConvertingBlockInputStream(): Waiting for threads to finish
2019.12.16 20:21:07.689673 [ 45 ] {} <Trace> test_s3z7p9.table_for_synchronous_mutations_no_replication (MergerMutator): Mutating part 1_2_2_0_3 to mutation version 5
2019.12.16 20:21:07.690260 [ 45 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): Key condition: unknown
2019.12.16 20:21:07.690283 [ 45 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): MinMax index condition: unknown
2019.12.16 20:21:07.690298 [ 45 ] {} <Debug> test_s3z7p9.table_for_synchronous_mutations_no_replication (SelectExecutor): Selected 1 parts by date, 1 parts by key, 7 marks to read from 1 ranges
2019.12.16 20:21:07.690323 [ 45 ] {} <Trace> MergeTreeSelectProcessor: Reading 1 ranges from part 1_2_2_0_3, approx. 57344 rows starting from 0
2019.12.16 20:21:07.690349 [ 45 ] {} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2019.12.16 20:21:08.687206 [ 36 ] {862e949e-b28f-4864-abfb-58f07ecd0141} <Debug> MemoryTracker: Peak memory usage (total): 0.00 B.
2019.12.16 20:21:08.687319 [ 36 ] {862e949e-b28f-4864-abfb-58f07ecd0141} <Error> executeQuery: Code: 341, e.displayText() = DB::Exception: Mutation mutation_5.txt is not finished. Will be done asynchronously (version 19.19.1.1902) (from [::1]:54892) (in query: ALTER TABLE table_for_synchronous_mutations_no_replication UPDATE v1 = v1 + 1 WHERE 1  SETTINGS mutation_synchronous_wait_timeout = 10), Stack trace (when copying this message, always include the lines below):

dbms/tests/queries/0_stateless/01045_zookeeper_system_mutations_with_parts_names.sh

alesapin · 2019-12-17T14:31:14Z

00600_replace_running_query -- known failure?

dbms/src/Core/Settings.h

alesapin · 2019-12-18T15:25:46Z

test_mysql_protocol/test.py::test_mysql_federated -- flap

dbms/src/Storages/StorageReplicatedMergeTree.cpp

Add ability to execute mutations asynchronously

2695aa1

alesapin added the pr-improvement Pull request with some product improvements label Dec 16, 2019

Simplify test and sligtly increase timeouts

9e7033c

alesapin commented Dec 16, 2019

View reviewed changes

dbms/tests/queries/0_stateless/01045_zookeeper_system_mutations_with_parts_names.sh Outdated Show resolved Hide resolved

alesapin force-pushed the synchronous_mutations branch from 0bb2d39 to 9e7033c Compare December 17, 2019 12:26

Merge branch 'master' into synchronous_mutations

9a005d2

alexey-milovidov reviewed Dec 17, 2019

View reviewed changes

dbms/src/Core/Settings.h Outdated Show resolved Hide resolved

alesapin added 3 commits December 18, 2019 12:00

Merge branch 'master' into synchronous_mutations

f110b70

Fix setting description

8116351

Fix flapping test

9b3bc2f

alesapin added 3 commits December 19, 2019 15:44

Merge branch 'master' into synchronous_mutations

88033a4

Make wait endless

9fea941

Remove unintended diff

0cc7ccf

alesapin requested a review from alexey-milovidov December 19, 2019 16:55

Event better test

ee85111

alesapin requested a review from CurtizJ December 23, 2019 08:55

CurtizJ approved these changes Dec 23, 2019

View reviewed changes

dbms/src/Storages/StorageReplicatedMergeTree.cpp Outdated Show resolved Hide resolved

alesapin added 2 commits December 23, 2019 16:24

Merge branch 'master' into synchronous_mutations

f168977

Remove redundant code

73c9f0e

alesapin merged commit 88c05c4 into master Dec 23, 2019

alesapin mentioned this pull request Jan 29, 2020

Create Function for Rename Column #6861

Closed

olgarev mentioned this pull request Jul 21, 2020

DOCSUP-790: docs for mutations_sync setting #12639

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add ability to execute mutations synchronously #8237

Add ability to execute mutations synchronously #8237

alesapin commented Dec 16, 2019 •

edited

alesapin commented Dec 16, 2019

alesapin commented Dec 16, 2019

alesapin commented Dec 17, 2019 •

edited

alesapin commented Dec 18, 2019

Add ability to execute mutations synchronously #8237

Add ability to execute mutations synchronously #8237

Conversation

alesapin commented Dec 16, 2019 • edited

alesapin commented Dec 16, 2019

alesapin commented Dec 16, 2019

alesapin commented Dec 17, 2019 • edited

alesapin commented Dec 18, 2019

alesapin commented Dec 16, 2019 •

edited

alesapin commented Dec 17, 2019 •

edited