Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[EXPERIMENTAL] Crash when using a projection while it's materializing #26020

Closed
Algunenano opened this issue Jul 6, 2021 · 3 comments · Fixed by #26038
Closed

[EXPERIMENTAL] Crash when using a projection while it's materializing #26020

Algunenano opened this issue Jul 6, 2021 · 3 comments · Fixed by #26038
Assignees
@amosbird
Labels
experimental feature Bug in the feature that should not be used in production

Comments

@Algunenano
Copy link
Member

You have to provide the following information whenever possible.

Describe the bug

If you run a query that uses a projection while it's being materialized it might crash the server.

Does it reproduce on recent release?

Only tested on master/HEAD

How to reproduce

Here is what I did to reproduce it (twice):

Table (113M rows)

SHOW CREATE TABLE github_events


│ CREATE TABLE default.github_events
(
    `id` UInt32,
    `type` LowCardinality(String),
    `date` DateTime,
    `username` String,
    `repository` String,
)
ENGINE = MergeTree
PARTITION BY toYYYYMMDD(date)
ORDER BY repository
SETTINGS index_granularity = 8192

Add a new projection:

SET allow_experimental_projection_optimization = 1

SET force_optimize_projection = 1

ALTER TABLE github_events
    ADD PROJECTION projection_username_sort2
    (
        SELECT *
        ORDER BY username
    )

Materialize it:

ALTER TABLE github_events
    MATERIALIZE PROJECTION projection_username_sort2

Inmediately after, launch queries that should use that projection:

First I got a correct error as the projection wasn't ready and force_optimize_projection is on:

SELECT DISTINCT repository　FROM github_events　WHERE username = 'Algunenano'

SELECT DISTINCT repository
FROM github_events
WHERE username = 'Algunenano'

Query id: 0c3090f1-4309-4a11-a737-ba61031f4b6e


0 rows in set. Elapsed: 0.539 sec. 

Received exception from server (version 21.8.1):
Code: 584. DB::Exception: Received from localhost:9000. DB::Exception: No projection is used when allow_experimental_projection_optimization = 1 and force_optimize_projection = 1.

Then I got a crash with the same query:

SELECT DISTINCT repository　FROM github_events　WHERE username = 'Algunenano'

SELECT DISTINCT repository
FROM github_events
WHERE username = 'Algunenano'

Query id: 79a0f76b-fae3-4f30-b724-df43b662bcd7

[Mordor] 2021.07.06 11:31:40.374460 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Fatal> : Logical error: 'Block structure mismatch in Pipe::unitePipes stream: different number of columns:
id UInt32 UInt32(size = 0), type LowCardinality(String) ColumnLowCardinality(size = 0, UInt8(size = 0), ColumnUnique(size = 1, String(size = 1))), date DateTime UInt32(size = 0), username String String(size = 0), repository String String(size = 0)
repository String String(size = 0)'.
[Mordor] 2021.07.06 11:31:40.375446 [ 78251 ] <Fatal> BaseDaemon: ########################################
[Mordor] 2021.07.06 11:31:40.375807 [ 78251 ] <Fatal> BaseDaemon: (version 21.8.1.1, build id: 2C2002338A175F96F5F573C4AEE29BD8475792FC) (from thread 77794) (query_id: 79a0f76b-fae3-4f30-b724-df43b662bcd7) Received signal Aborted (6)
[Mordor] 2021.07.06 11:31:40.376099 [ 78251 ] <Fatal> BaseDaemon: 
[Mordor] 2021.07.06 11:31:40.376456 [ 78251 ] <Fatal> BaseDaemon: Stack trace: 0x7f691656bd22 0x7f6916555862 0x123ba079 0x123ba1b2 0x1d114095 0x1d1108b2 0x1d11178a 0x1ef13b62 0x1ef13755 0x1eb3ae92 0x1e673091 0x1dc85ccb 0x1dc7f744 0x1dc7ea55 0x1e008f1f 0x1e0099f3 0x1e29343a 0x1e29151e 0x1eeaddf3 0x1eebbb52 0x23815879 0x23816114 0x2397b161 0x2397779a 0x2397641a 0x7f6916716259 0x7f691662d5e3

Expected behavior

The projection shouldn't be considered if it isn't ready.

Error message and/or stacktrace

The logs at that time show that MergerMutator is generating the projection while the query arrives:

2021.07.06 11:31:40.279848 [ 77944 ] {} <Debug> MergeTreeSelectProcessor: Reading 1 ranges from part 20200116_48_52_3_202, approx. 2067783 rows starting from 0
2021.07.06 11:31:40.280122 [ 77944 ] {} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.07.06 11:31:40.290056 [ 77804 ] {} <Debug> default.github_events (MergerMutator): Merged 2 parts in level 1 to projection_username_sort2_25
2021.07.06 11:31:40.290136 [ 77804 ] {} <Debug> default.github_events (MergerMutator): Merging 2 parts: from projection_username_sort2_23 to projection_username_sort2_21 into Wide
2021.07.06 11:31:40.290350 [ 77804 ] {} <Debug> default.github_events (MergerMutator): Selected MergeAlgorithm: Horizontal
2021.07.06 11:31:40.290688 [ 77804 ] {} <Debug> MergeTreeSequentialSource: Reading 73 marks from part projection_username_sort2_23, total 589824 rows starting from the beginning of the part
2021.07.06 11:31:40.292197 [ 77804 ] {} <Debug> MergeTreeSequentialSource: Reading 83 marks from part projection_username_sort2_21, total 671737 rows starting from the beginning of the part
2021.07.06 11:31:40.293491 [ 77802 ] {} <Debug> default.github_events (MergerMutator): Merged 2 parts in level 1 to projection_username_sort2_26
2021.07.06 11:31:40.293571 [ 77802 ] {} <Debug> default.github_events (MergerMutator): Merging 2 parts: from projection_username_sort2_24 to projection_username_sort2_22 into Wide
2021.07.06 11:31:40.293789 [ 77802 ] {} <Debug> default.github_events (MergerMutator): Selected MergeAlgorithm: Horizontal
2021.07.06 11:31:40.294123 [ 77802 ] {} <Debug> MergeTreeSequentialSource: Reading 85 marks from part projection_username_sort2_24, total 688128 rows starting from the beginning of the part
2021.07.06 11:31:40.295342 [ 77944 ] {} <Trace> InterpreterSelectQuery: FetchColumns -> FetchColumns
2021.07.06 11:31:40.295679 [ 77802 ] {} <Debug> MergeTreeSequentialSource: Reading 78 marks from part projection_username_sort2_22, total 628056 rows starting from the beginning of the part
2021.07.06 11:31:40.300809 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Debug> executeQuery: (from [::1]:42312) SELECT DISTINCT repository FROM github_events WHERE username = 'Algunenano'
2021.07.06 11:31:40.302975 [ 77944 ] {} <Trace> InterpreterSelectQuery: FetchColumns -> FetchColumns
2021.07.06 11:31:40.303171 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Debug> InterpreterSelectQuery: MergeTreeWhereOptimizer: condition "username = 'Algunenano'" moved to PREWHERE
2021.07.06 11:31:40.307114 [ 77801 ] {} <Debug> default.github_events (MergerMutator): Merged 2 parts in level 1 to projection_username_sort2_26
2021.07.06 11:31:40.307217 [ 77801 ] {} <Debug> default.github_events (MergerMutator): Merging 2 parts: from projection_username_sort2_24 to projection_username_sort2_22 into Wide
2021.07.06 11:31:40.307496 [ 77801 ] {} <Debug> default.github_events (MergerMutator): Selected MergeAlgorithm: Horizontal
2021.07.06 11:31:40.307928 [ 77801 ] {} <Debug> MergeTreeSequentialSource: Reading 82 marks from part projection_username_sort2_24, total 663552 rows starting from the beginning of the part
2021.07.06 11:31:40.309038 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Trace> ContextAccess (default): Access granted: SELECT(username, repository) ON default.github_events
2021.07.06 11:31:40.310004 [ 77801 ] {} <Debug> MergeTreeSequentialSource: Reading 82 marks from part projection_username_sort2_22, total 655621 rows starting from the beginning of the part
2021.07.06 11:31:40.311530 [ 77944 ] {} <Trace> InterpreterSelectQuery: FetchColumns -> FetchColumns
2021.07.06 11:31:40.314197 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Debug> default.github_events (SelectExecutor): MinMax index condition: unknown
2021.07.06 11:31:40.314505 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Trace> default.github_events (SelectExecutor): Running binary search on index range for part projection_username_sort2 (121 marks)
2021.07.06 11:31:40.314697 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Trace> default.github_events (SelectExecutor): Found (LEFT) boundary mark: 2
2021.07.06 11:31:40.314865 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Trace> default.github_events (SelectExecutor): Found (RIGHT) boundary mark: 3
2021.07.06 11:31:40.314984 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Trace> default.github_events (SelectExecutor): Found continuous range in 13 steps
2021.07.06 11:31:40.317756 [ 77944 ] {} <Trace> InterpreterSelectQuery: FetchColumns -> FetchColumns
2021.07.06 11:31:40.318714 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Trace> ContextAccess (default): Access granted: SELECT(username, repository) ON default.github_events
2021.07.06 11:31:40.319016 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Debug> default.github_events (SelectExecutor): Choose normal projection projection_username_sort2
2021.07.06 11:31:40.319216 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Debug> default.github_events (SelectExecutor): projection required columns: username, repository
2021.07.06 11:31:40.320345 [ 77951 ] {} <Debug> default.github_events (MergerMutator): Merge sorted 2259406 rows, containing 5 columns (5 merged, 0 gathered) in 8.281952147 sec., 272810.801112686 rows/sec., 15.94 MiB/sec.
2021.07.06 11:31:40.321450 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Debug> default.github_events (SelectExecutor): Key condition: (column 0 in ['Algunenano', 'Algunenano'])
2021.07.06 11:31:40.322896 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Debug> default.github_events (SelectExecutor): MinMax index condition: unknown
2021.07.06 11:31:40.323198 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Trace> default.github_events (SelectExecutor): Running binary search on index range for part projection_username_sort2 (121 marks)
2021.07.06 11:31:40.323376 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Trace> default.github_events (SelectExecutor): Found (LEFT) boundary mark: 2
2021.07.06 11:31:40.323407 [ 77944 ] {} <Trace> InterpreterSelectQuery: FetchColumns -> FetchColumns
2021.07.06 11:31:40.323541 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Trace> default.github_events (SelectExecutor): Found (RIGHT) boundary mark: 3
2021.07.06 11:31:40.323671 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Trace> default.github_events (SelectExecutor): Found continuous range in 13 steps
2021.07.06 11:31:40.323867 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Debug> default.github_events (SelectExecutor): Selected 1/1 parts by partition key, 1 parts by primary key, 1/120 marks by primary key, 1 marks to read from 1 ranges
2021.07.06 11:31:40.324604 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Debug> MergeTreeSelectProcessor: Reading 1 ranges from part projection_username_sort2, approx. 8192 rows starting from 16384
2021.07.06 11:31:40.324650 [ 77944 ] {} <Debug> DiskLocal: Reserving 3.86 MiB on disk `default`, having unreserved 514.04 GiB.
2021.07.06 11:31:40.332574 [ 77808 ] {} <Trace> InterpreterSelectQuery: FetchColumns -> FetchColumns
2021.07.06 11:31:40.333170 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Debug> default.github_events (SelectExecutor): Key condition: unknown
2021.07.06 11:31:40.336136 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Debug> default.github_events (SelectExecutor): MinMax index condition: unknown
2021.07.06 11:31:40.338405 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Debug> default.github_events (SelectExecutor): Selected 59/59 parts by partition key, 59 parts by primary key, 13713/13713 marks by primary key, 13713 marks to read from 59 ranges

Backtraces:

As reported by the client / logs:

[Mordor] 2021.07.06 11:31:40.374460 [ 77794 ] {79a0f76b-fae3-4f30-b724-df43b662bcd7} <Fatal> : Logical error: 'Block structure mismatch in Pipe::unitePipes stream: different number of columns:
id UInt32 UInt32(size = 0), type LowCardinality(String) ColumnLowCardinality(size = 0, UInt8(size = 0), ColumnUnique(size = 1, String(size = 1))), date DateTime UInt32(size = 0), username String String(size = 0), repository String String(size = 0)
repository String String(size = 0)'.
[Mordor] 2021.07.06 11:31:40.375446 [ 78251 ] <Fatal> BaseDaemon: ########################################
[Mordor] 2021.07.06 11:31:40.375807 [ 78251 ] <Fatal> BaseDaemon: (version 21.8.1.1, build id: 2C2002338A175F96F5F573C4AEE29BD8475792FC) (from thread 77794) (query_id: 79a0f76b-fae3-4f30-b724-df43b662bcd7) Received signal Aborted (6)
[Mordor] 2021.07.06 11:31:40.376099 [ 78251 ] <Fatal> BaseDaemon: 
[Mordor] 2021.07.06 11:31:40.376456 [ 78251 ] <Fatal> BaseDaemon: Stack trace: 0x7f691656bd22 0x7f6916555862 0x123ba079 0x123ba1b2 0x1d114095 0x1d1108b2 0x1d11178a 0x1ef13b62 0x1ef13755 0x1eb3ae92 0x1e673091 0x1dc85ccb 0x1dc7f744 0x1dc7ea55 0x1e008f1f 0x1e0099f3 0x1e29343a 0x1e29151e 0x1eeaddf3 0x1eebbb52 0x23815879 0x23816114 0x2397b161 0x2397779a 0x2397641a 0x7f6916716259 0x7f691662d5e3
[Mordor] 2021.07.06 11:31:40.376936 [ 78251 ] <Fatal> BaseDaemon: 4. raise @ 0x3cd22 in /usr/lib/libc-2.33.so
[Mordor] 2021.07.06 11:31:40.377097 [ 78251 ] <Fatal> BaseDaemon: 5. __GI_abort @ 0x26862 in /usr/lib/libc-2.33.so
[Mordor] 2021.07.06 11:31:40.572593 [ 78251 ] <Fatal> BaseDaemon: 6. /mnt/ch/ClickHouse/build_head_asserts/../src/Common/Exception.cpp:53: DB::handle_error_code(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int, bool, std::__1::vector<void*, std::__1::allocator<void*> > const&) @ 0x123ba079 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:40.754393 [ 78251 ] <Fatal> BaseDaemon: 7. /mnt/ch/ClickHouse/build_head_asserts/../src/Common/Exception.cpp:60: DB::Exception::Exception(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int, bool) @ 0x123ba1b2 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:40.882859 [ 78251 ] <Fatal> BaseDaemon: 8. /mnt/ch/ClickHouse/build_head_asserts/../src/Core/Block.cpp:504: void DB::checkBlockStructure<void>(DB::Block const&, DB::Block const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, bool)::'lambda'(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int)::operator()(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int) const @ 0x1d114095 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:41.012847 [ 78251 ] <Fatal> BaseDaemon: 9. /mnt/ch/ClickHouse/build_head_asserts/../src/Core/Block.cpp:511: void DB::checkBlockStructure<void>(DB::Block const&, DB::Block const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, bool) @ 0x1d1108b2 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:41.142456 [ 78251 ] <Fatal> BaseDaemon: 10. /mnt/ch/ClickHouse/build_head_asserts/../src/Core/Block.cpp:580: DB::assertCompatibleHeader(DB::Block const&, DB::Block const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&) @ 0x1d11178a in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:41.345206 [ 78251 ] <Fatal> BaseDaemon: 11. /mnt/ch/ClickHouse/build_head_asserts/../src/Processors/Pipe.cpp:326: DB::Pipe::unitePipes(std::__1::vector<DB::Pipe, std::__1::allocator<DB::Pipe> >, std::__1::vector<std::__1::shared_ptr<DB::IProcessor>, std::__1::allocator<std::__1::shared_ptr<DB::IProcessor> > >*, bool) @ 0x1ef13b62 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:41.548397 [ 78251 ] <Fatal> BaseDaemon: 12. /mnt/ch/ClickHouse/build_head_asserts/../src/Processors/Pipe.cpp:297: DB::Pipe::unitePipes(std::__1::vector<DB::Pipe, std::__1::allocator<DB::Pipe> >) @ 0x1ef13755 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:42.198539 [ 78251 ] <Fatal> BaseDaemon: 13. /mnt/ch/ClickHouse/build_head_asserts/../src/Storages/MergeTree/MergeTreeDataSelectExecutor.cpp:366: DB::MergeTreeDataSelectExecutor::read(std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > > const&, std::__1::shared_ptr<DB::StorageInMemoryMetadata const> const&, DB::SelectQueryInfo const&, std::__1::shared_ptr<DB::Context const>, unsigned long, unsigned int, DB::QueryProcessingStage::Enum, std::__1::shared_ptr<std::__1::unordered_map<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, long, std::__1::hash<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > >, std::__1::equal_to<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > >, std::__1::allocator<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const, long> > > >) const @ 0x1eb3ae92 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:42.921584 [ 78251 ] <Fatal> BaseDaemon: 14. /mnt/ch/ClickHouse/build_head_asserts/../src/Storages/StorageMergeTree.cpp:190: DB::StorageMergeTree::read(DB::QueryPlan&, std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > > const&, std::__1::shared_ptr<DB::StorageInMemoryMetadata const> const&, DB::SelectQueryInfo&, std::__1::shared_ptr<DB::Context const>, DB::QueryProcessingStage::Enum, unsigned long, unsigned int) @ 0x1e673091 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:43.766840 [ 78251 ] <Fatal> BaseDaemon: 15. /mnt/ch/ClickHouse/build_head_asserts/../src/Interpreters/InterpreterSelectQuery.cpp:1951: DB::InterpreterSelectQuery::executeFetchColumns(DB::QueryProcessingStage::Enum, DB::QueryPlan&) @ 0x1dc85ccb in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:44.559043 [ 78251 ] <Fatal> BaseDaemon: 16. /mnt/ch/ClickHouse/build_head_asserts/../src/Interpreters/InterpreterSelectQuery.cpp:1012: DB::InterpreterSelectQuery::executeImpl(DB::QueryPlan&, std::__1::shared_ptr<DB::IBlockInputStream> const&, std::__1::optional<DB::Pipe>) @ 0x1dc7f744 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:45.355610 [ 78251 ] <Fatal> BaseDaemon: 17. /mnt/ch/ClickHouse/build_head_asserts/../src/Interpreters/InterpreterSelectQuery.cpp:576: DB::InterpreterSelectQuery::buildQueryPlan(DB::QueryPlan&) @ 0x1dc7ea55 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:45.694841 [ 78251 ] <Fatal> BaseDaemon: 18. /mnt/ch/ClickHouse/build_head_asserts/../src/Interpreters/InterpreterSelectWithUnionQuery.cpp:245: DB::InterpreterSelectWithUnionQuery::buildQueryPlan(DB::QueryPlan&) @ 0x1e008f1f in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:46.032892 [ 78251 ] <Fatal> BaseDaemon: 19. /mnt/ch/ClickHouse/build_head_asserts/../src/Interpreters/InterpreterSelectWithUnionQuery.cpp:311: DB::InterpreterSelectWithUnionQuery::execute() @ 0x1e0099f3 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:46.483663 [ 78251 ] <Fatal> BaseDaemon: 20. /mnt/ch/ClickHouse/build_head_asserts/../src/Interpreters/executeQuery.cpp:554: DB::executeQueryImpl(char const*, char const*, std::__1::shared_ptr<DB::Context>, bool, DB::QueryProcessingStage::Enum, bool, DB::ReadBuffer*) @ 0x1e29343a in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:46.961846 [ 78251 ] <Fatal> BaseDaemon: 21. /mnt/ch/ClickHouse/build_head_asserts/../src/Interpreters/executeQuery.cpp:913: DB::executeQuery(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, std::__1::shared_ptr<DB::Context>, bool, DB::QueryProcessingStage::Enum, bool) @ 0x1e29151e in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:47.445451 [ 78251 ] <Fatal> BaseDaemon: 22. /mnt/ch/ClickHouse/build_head_asserts/../src/Server/TCPHandler.cpp:312: DB::TCPHandler::runImpl() @ 0x1eeaddf3 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:47.959754 [ 78251 ] <Fatal> BaseDaemon: 23. /mnt/ch/ClickHouse/build_head_asserts/../src/Server/TCPHandler.cpp:1622: DB::TCPHandler::run() @ 0x1eebbb52 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:48.006909 [ 78251 ] <Fatal> BaseDaemon: 24. /mnt/ch/ClickHouse/build_asserts/../contrib/poco/Net/src/TCPServerConnection.cpp:43: Poco::Net::TCPServerConnection::start() @ 0x23815879 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:48.079337 [ 78251 ] <Fatal> BaseDaemon: 25. /mnt/ch/ClickHouse/build_asserts/../contrib/poco/Net/src/TCPServerDispatcher.cpp:115: Poco::Net::TCPServerDispatcher::run() @ 0x23816114 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:48.173957 [ 78251 ] <Fatal> BaseDaemon: 26. /mnt/ch/ClickHouse/build_asserts/../contrib/poco/Foundation/src/ThreadPool.cpp:199: Poco::PooledThread::run() @ 0x2397b161 in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:48.244566 [ 78251 ] <Fatal> BaseDaemon: 27. /mnt/ch/ClickHouse/build_asserts/../contrib/poco/Foundation/src/Thread.cpp:56: Poco::(anonymous namespace)::RunnableHolder::run() @ 0x2397779a in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:48.306345 [ 78251 ] <Fatal> BaseDaemon: 28. /mnt/ch/ClickHouse/build_asserts/../contrib/poco/Foundation/src/Thread_POSIX.cpp:345: Poco::ThreadImpl::runnableEntry(void*) @ 0x2397641a in /mnt/ch/ClickHouse/build_head_asserts/programs/clickhouse
[Mordor] 2021.07.06 11:31:48.306680 [ 78251 ] <Fatal> BaseDaemon: 29. start_thread @ 0x9259 in /usr/lib/libpthread-2.33.so
[Mordor] 2021.07.06 11:31:48.306909 [ 78251 ] <Fatal> BaseDaemon: 30. __clone @ 0xfe5e3 in /usr/lib/libc-2.33.so
[Mordor] 2021.07.06 11:31:49.268776 [ 78251 ] <Fatal> BaseDaemon: Calculated checksum of the binary: DCEB0ABB9B2CADF571878537D837F943. There is no information about the reference checksum.

From the coredump:

(gdb) bt
#0  0x00007f691656bd22 in raise () from /usr/lib/libc.so.6
#1  0x00007f6916555862 in abort () from /usr/lib/libc.so.6
#2  0x00000000123ba079 in DB::handle_error_code (msg=..., code=49, remote=false, trace=...) at ../src/Common/Exception.cpp:49
#3  0x00000000123ba1b2 in DB::Exception::Exception (this=0x7f68031df900, msg=..., code=49, remote_=false) at ../src/Common/Exception.cpp:60
#4  0x000000001d114095 in DB::checkBlockStructure<void>(DB::Block const&, DB::Block const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, bool)::{lambda(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int)#1}::operator()(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int) const (this=0x7f68645ec870, message=..., code=49) at ../src/Core/Block.cpp:504
#5  0x000000001d1108b2 in DB::checkBlockStructure<void> (lhs=..., rhs=..., context_description=..., allow_remove_constants=true) at ../src/Core/Block.cpp:511
#6  0x000000001d11178a in DB::assertCompatibleHeader (actual=..., desired=..., context_description=...) at ../src/Core/Block.cpp:579
#7  0x000000001ef13b62 in DB::Pipe::unitePipes (pipes=..., collected_processors=0x0, allow_empty_header=false) at ../src/Processors/Pipe.cpp:326
#8  0x000000001ef13755 in DB::Pipe::unitePipes (pipes=...) at ../src/Processors/Pipe.cpp:297
#9  0x000000001eb3ae92 in DB::MergeTreeDataSelectExecutor::read (this=0x7f68646a43c0, column_names_to_return=..., metadata_snapshot=..., query_info=..., context=..., max_block_size=65505, num_streams=16, 
    processed_stage=DB::QueryProcessingStage::FetchColumns, max_block_numbers_to_read=...) at ../src/Storages/MergeTree/MergeTreeDataSelectExecutor.cpp:366
#10 0x000000001e673091 in DB::StorageMergeTree::read (this=0x7f68646a3e00, query_plan=..., column_names=..., metadata_snapshot=..., query_info=..., local_context=..., processed_stage=DB::QueryProcessingStage::FetchColumns, max_block_size=65505, 
    num_streams=16) at ../src/Storages/StorageMergeTree.cpp:190
#11 0x000000001dc85ccb in DB::InterpreterSelectQuery::executeFetchColumns (this=0x7f6857e69100, processing_stage=DB::QueryProcessingStage::FetchColumns, query_plan=...) at ../src/Interpreters/InterpreterSelectQuery.cpp:1951
#12 0x000000001dc7f744 in DB::InterpreterSelectQuery::executeImpl (this=0x7f6857e69100, query_plan=..., prepared_input=..., prepared_pipe=...) at ../src/Interpreters/InterpreterSelectQuery.cpp:1010
#13 0x000000001dc7ea55 in DB::InterpreterSelectQuery::buildQueryPlan (this=0x7f6857e69100, query_plan=...) at ../src/Interpreters/InterpreterSelectQuery.cpp:576
#14 0x000000001e008f1f in DB::InterpreterSelectWithUnionQuery::buildQueryPlan (this=0x7f685b975a80, query_plan=...) at ../src/Interpreters/InterpreterSelectWithUnionQuery.cpp:244
#15 0x000000001e0099f3 in DB::InterpreterSelectWithUnionQuery::execute (this=0x7f685b975a80) at ../src/Interpreters/InterpreterSelectWithUnionQuery.cpp:311
#16 0x000000001e29343a in DB::executeQueryImpl (begin=0x7f685b97af50 "SELECT DISTINCT repository\nFROM github_events\nWHERE username = 'Algunenano'", end=0x7f685b97af9b "", context=..., internal=false, stage=DB::QueryProcessingStage::Complete, 
    has_query_tail=false, istr=0x0) at ../src/Interpreters/executeQuery.cpp:554
#17 0x000000001e29151e in DB::executeQuery (query=..., context=..., internal=false, stage=DB::QueryProcessingStage::Complete, may_have_embedded_data=true) at ../src/Interpreters/executeQuery.cpp:913
#18 0x000000001eeaddf3 in DB::TCPHandler::runImpl (this=0x7f685d3aa500) at ../src/Server/TCPHandler.cpp:312
#19 0x000000001eebbb52 in DB::TCPHandler::run (this=0x7f685d3aa500) at ../src/Server/TCPHandler.cpp:1622
#20 0x0000000023815879 in Poco::Net::TCPServerConnection::start (this=0x7f685d3aa500) at ../contrib/poco/Net/src/TCPServerConnection.cpp:43
#21 0x0000000023816114 in Poco::Net::TCPServerDispatcher::run (this=0x7f6853e37200) at ../contrib/poco/Net/src/TCPServerDispatcher.cpp:115
#22 0x000000002397b161 in Poco::PooledThread::run (this=0x7f69156d8880) at ../contrib/poco/Foundation/src/ThreadPool.cpp:199
#23 0x000000002397779a in Poco::(anonymous namespace)::RunnableHolder::run (this=0x7f691560e5c0) at ../contrib/poco/Foundation/src/Thread.cpp:55
#24 0x000000002397641a in Poco::ThreadImpl::runnableEntry (pThread=0x7f69156d88b8) at ../contrib/poco/Foundation/src/Thread_POSIX.cpp:345
#25 0x00007f6916716259 in start_thread () from /usr/lib/libpthread.so.0
#26 0x00007f691662d5e3 in clone () from /usr/lib/libc.so.6

Built from master/HEAD in debug mode
@Algunenano Algunenano added the bug Confirmed user-visible misbehaviour in official release label Jul 6, 2021
@kitaisreal
Copy link
Collaborator

@amosbird can you take a look at it ?

Algunenano added a commit to Algunenano/ClickHouse that referenced this issue Jul 6, 2021
@Algunenano
Attempt to fix ClickHouse#26020
004841d
@Algunenano Algunenano mentioned this issue Jul 6, 2021
Closed
@Algunenano
Copy link
Member Author

Fixed with #26026. The problem wasn't that the materialization of the projection is in progress, but that it couldn't merge the result of the 2 pipes (the ordinary_pipe that reads the parts that aren't materialized yet, and the projection_pipe that reads projected parts) because the ordinary was using the projection query, which has more columns than necessary.

To fix it I changed the ordinary pipe to use the main plan / query when the projection doesn't use aggregation and that seems to be working fine.

@alexey-milovidov alexey-milovidov added experimental feature Bug in the feature that should not be used in production and removed bug Confirmed user-visible misbehaviour in official release labels Jul 6, 2021
@amosbird
Copy link
Collaborator

amosbird commented Jul 6, 2021

To fix it I changed the ordinary pipe to use the main plan / query when the projection doesn't use aggregation and that seems to be working fine.

We cannot use the original plan since filtering is done in projection and we have to apply it to the ordinary pipe too.

@amosbird amosbird mentioned this issue Jul 6, 2021
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@amosbird amosbird

Labels
experimental feature Bug in the feature that should not be used in production
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix normal projection with prewhere amosbird/ClickHouse
Fix #26020 Algunenano/ClickHouse
4 participants
@Algunenano @amosbird @alexey-milovidov @kitaisreal