Skip to content

Logical error: 'Bad cast from type DB::ColumnVector to DB::ColumnNullable'. Assertion `false' #14974

Closed
Closed
Logical error: 'Bad cast from type DB::ColumnVector to DB::ColumnNullable'. Assertion `false'#14974
Labels
bugConfirmed user-visible misbehaviour in official releasecomp-joinsJOINs end-to-end (planning hooks + runtime join operators/algorithms). Single bucket to avoid pla...fuzzProblem found by one of the fuzzers
@alesapin

Description

@alesapin
alesapin
opened on Sep 18, 2020

The Issue can be reproduced using data from https://github.com/clickhouse/ClickHouse/blob/master/tests/queries/0_stateless/01412_row_from_totals.sql#L1 and query from log:

2020.09.18 08:46:27.682347 [ 269 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Debug> executeQuery: (from [::1]:51170) SELECT EventDate FROM (SELECT EventDate FROM tracking_events_tmp AS t1 WHERE (EventDate >= toDate('2020-07-10')) AND (EventDate <= toDate('2020-07-11')) AND (APIKey = 2) GROUP BY EventDate) FULL OUTER JOIN (SELECT EventDate FROM remote('127.0.0.{1,3}', currentDatabase(), open_events_tmp) AS t2 WHERE (EventDate <= toDate('2020-07-11')) AND (APIKey = 2) GROUP BY EventDate WITH TOTALS) USING (EventDate) ORDER BY EventDate ASC SETTINGS totals_mode = 'after_having_auto', group_by_overflow_mode = 'any', max_rows_to_group_by = 10000000, joined_subquery_requires_alias = 0
2020.09.18 08:46:27.690007 [ 269 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> ContextAccess (default): Access granted: SELECT(APIKey, EventDate) ON default.tracking_events_tmp
2020.09.18 08:46:27.691118 [ 269 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> ContextAccess (default): Access granted: CREATE TEMPORARY TABLE, REMOTE ON *.*
2020.09.18 08:46:27.692652 [ 269 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> ContextAccess (default): Access granted: CREATE TEMPORARY TABLE, REMOTE ON *.*
2020.09.18 08:46:27.705775 [ 269 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> ContextAccess (default): Access granted: SELECT(APIKey, EventDate) ON default.tracking_events_tmp
2020.09.18 08:46:27.716425 [ 269 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> InterpreterSelectQuery: WithMergeableState -> Complete
2020.09.18 08:46:27.718060 [ 269 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Debug> HashJoin: Right sample block: EventDate Date UInt16(size = 0)
2020.09.18 08:46:27.723176 [ 269 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Debug> default.tracking_events_tmp (SelectExecutor): Key condition: (column 1 in [18453, +inf)), (column 1 in (-inf, 18454]), and, (column 0 in [2, 2]), and
2020.09.18 08:46:27.723365 [ 269 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Debug> default.tracking_events_tmp (SelectExecutor): MinMax index condition: (column 0 in [18453, +inf)), (column 0 in (-inf, 18454]), and, unknown, and
2020.09.18 08:46:27.723460 [ 269 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Debug> default.tracking_events_tmp (SelectExecutor): Selected 0 parts by date, 0 parts by key, 0 marks by primary key, 0 marks to read from 0 ranges
2020.09.18 08:46:27.723768 [ 269 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2020.09.18 08:46:27.724591 [ 269 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2020.09.18 08:46:27.731271 [ 208 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> Connection (127.0.0.1:9000): Connecting. Database: (not specified). User: default
2020.09.18 08:46:27.731880 [ 270 ] {} <Trace> TCPHandlerFactory: TCP Request. Address: [::ffff:127.0.0.1]:39458
2020.09.18 08:46:27.732343 [ 270 ] {} <Debug> TCPHandler: Connected ClickHouse server version 20.10.0, revision: 54441, user: default.
2020.09.18 08:46:27.732788 [ 208 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> Connection (127.0.0.1:9000): Connected to ClickHouse server version 20.10.1.
2020.09.18 08:46:27.737505 [ 270 ] {fe78ab33-3cd6-4e58-b507-63a61634b223} <Debug> executeQuery: (from [::ffff:127.0.0.1]:39458, initial_query_id: 9dc86454-ceec-49de-9fa8-322e38fb091a) SELECT EventDate FROM default.open_events_tmp AS t2 WHERE (EventDate <= toDate('2020-07-11')) AND (APIKey = 2) GROUP BY EventDate WITH TOTALS
2020.09.18 08:46:27.742999 [ 270 ] {fe78ab33-3cd6-4e58-b507-63a61634b223} <Trace> ContextAccess (default): Access granted: SELECT(APIKey, EventDate) ON default.open_events_tmp
2020.09.18 08:46:27.745526 [ 270 ] {fe78ab33-3cd6-4e58-b507-63a61634b223} <Debug> default.open_events_tmp (SelectExecutor): Key condition: (column 1 in (-inf, 18454]), (column 0 in [2, 2]), and
2020.09.18 08:46:27.745678 [ 270 ] {fe78ab33-3cd6-4e58-b507-63a61634b223} <Debug> default.open_events_tmp (SelectExecutor): MinMax index condition: (column 0 in (-inf, 18454]), unknown, and
2020.09.18 08:46:27.745773 [ 270 ] {fe78ab33-3cd6-4e58-b507-63a61634b223} <Debug> default.open_events_tmp (SelectExecutor): Selected 0 parts by date, 0 parts by key, 0 marks by primary key, 0 marks to read from 0 ranges
2020.09.18 08:46:27.746118 [ 270 ] {fe78ab33-3cd6-4e58-b507-63a61634b223} <Trace> InterpreterSelectQuery: FetchColumns -> WithMergeableState
2020.09.18 08:46:27.749077 [ 212 ] {fe78ab33-3cd6-4e58-b507-63a61634b223} <Trace> AggregatingTransform: Aggregated. 0 to 0 rows (from 0.00 B) in 0.001340574 sec. (0.0 rows/sec., 0.00 B/sec.)
2020.09.18 08:46:27.749171 [ 212 ] {fe78ab33-3cd6-4e58-b507-63a61634b223} <Trace> Aggregator: Merging aggregated data
2020.09.18 08:46:27.749576 [ 212 ] {fe78ab33-3cd6-4e58-b507-63a61634b223} <Trace> PipelineExecutor: Thread finished. Total time: 0.000599354 sec. Execution time: 0.000293989 sec. Processing time: 0.000279782 sec. Wait time: 2.5583e-05 sec.
2020.09.18 08:46:27.750199 [ 270 ] {fe78ab33-3cd6-4e58-b507-63a61634b223} <Debug> MemoryTracker: Peak memory usage (for query): 0.00 B.
2020.09.18 08:46:27.750432 [ 208 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> Connection (127.0.0.3:9000): Connecting. Database: (not specified). User: default
2020.09.18 08:46:27.750934 [ 271 ] {} <Trace> TCPHandlerFactory: TCP Request. Address: [::ffff:127.0.0.1]:51706
2020.09.18 08:46:27.751002 [ 270 ] {} <Information> TCPHandler: Processed in 0.01744666 sec.
2020.09.18 08:46:27.751252 [ 271 ] {} <Debug> TCPHandler: Connected ClickHouse server version 20.10.0, revision: 54441, user: default.
2020.09.18 08:46:27.751589 [ 208 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> Connection (127.0.0.3:9000): Connected to ClickHouse server version 20.10.1.
2020.09.18 08:46:27.756289 [ 271 ] {20b90570-2fc7-46f4-8cce-9494b5982363} <Debug> executeQuery: (from [::ffff:127.0.0.1]:51706, initial_query_id: 9dc86454-ceec-49de-9fa8-322e38fb091a) SELECT EventDate FROM default.open_events_tmp AS t2 WHERE (EventDate <= toDate('2020-07-11')) AND (APIKey = 2) GROUP BY EventDate WITH TOTALS
2020.09.18 08:46:27.761653 [ 271 ] {20b90570-2fc7-46f4-8cce-9494b5982363} <Trace> ContextAccess (default): Access granted: SELECT(APIKey, EventDate) ON default.open_events_tmp
2020.09.18 08:46:27.764114 [ 271 ] {20b90570-2fc7-46f4-8cce-9494b5982363} <Debug> default.open_events_tmp (SelectExecutor): Key condition: (column 1 in (-inf, 18454]), (column 0 in [2, 2]), and
2020.09.18 08:46:27.764250 [ 271 ] {20b90570-2fc7-46f4-8cce-9494b5982363} <Debug> default.open_events_tmp (SelectExecutor): MinMax index condition: (column 0 in (-inf, 18454]), unknown, and
2020.09.18 08:46:27.764342 [ 271 ] {20b90570-2fc7-46f4-8cce-9494b5982363} <Debug> default.open_events_tmp (SelectExecutor): Selected 0 parts by date, 0 parts by key, 0 marks by primary key, 0 marks to read from 0 ranges
2020.09.18 08:46:27.764644 [ 271 ] {20b90570-2fc7-46f4-8cce-9494b5982363} <Trace> InterpreterSelectQuery: FetchColumns -> WithMergeableState
2020.09.18 08:46:27.767592 [ 214 ] {20b90570-2fc7-46f4-8cce-9494b5982363} <Trace> AggregatingTransform: Aggregated. 0 to 0 rows (from 0.00 B) in 0.001287615 sec. (0.0 rows/sec., 0.00 B/sec.)
2020.09.18 08:46:27.767687 [ 214 ] {20b90570-2fc7-46f4-8cce-9494b5982363} <Trace> Aggregator: Merging aggregated data
2020.09.18 08:46:27.768147 [ 214 ] {20b90570-2fc7-46f4-8cce-9494b5982363} <Trace> PipelineExecutor: Thread finished. Total time: 0.000637813 sec. Execution time: 0.000335426 sec. Processing time: 0.000279552 sec. Wait time: 2.2835e-05 sec.
2020.09.18 08:46:27.768787 [ 271 ] {20b90570-2fc7-46f4-8cce-9494b5982363} <Debug> MemoryTracker: Peak memory usage (for query): 0.00 B.
2020.09.18 08:46:27.768964 [ 208 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> MergingAggregatedTransform: Read 0 blocks of partially aggregated data, total 0 rows.
2020.09.18 08:46:27.769053 [ 208 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> Aggregator: Converting aggregated data to blocks
2020.09.18 08:46:27.769389 [ 208 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> CreatingSetsTransform: Creating join.
2020.09.18 08:46:27.769469 [ 208 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Debug> CreatingSetsTransform: Subquery has empty result.
2020.09.18 08:46:27.769584 [ 271 ] {} <Information> TCPHandler: Processed in 0.017211962 sec.
2020.09.18 08:46:27.769832 [ 208 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> AggregatingTransform: Aggregated. 0 to 0 rows (from 0.00 B) in 0.043143635 sec. (0.0 rows/sec., 0.00 B/sec.)
2020.09.18 08:46:27.769941 [ 208 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> Aggregator: Merging aggregated data
2020.09.18 08:46:27.770896 [ 208 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Trace> PipelineExecutor: Thread finished. Total time: 0.039679588 sec. Execution time: 0.038588883 sec. Processing time: 0.00104718 sec. Wait time: 4.3525e-05 sec.
2020.09.18 08:46:27.771295 [ 269 ] {9dc86454-ceec-49de-9fa8-322e38fb091a} <Error> : Logical error: 'Bad cast from type DB::ColumnVector<unsigned short> to DB::ColumnNullable'.
clickhouse-server: ../src/Common/Exception.cpp:45: DB::Exception::Exception(const std::string &, int): Assertion `false' failed.
2020.09.18 08:46:27.771573 [ 64 ] {} <Trace> BaseDaemon: Received signal 6
2020.09.18 08:46:27.771884 [ 272 ] {} <Fatal> BaseDaemon: ########################################
2020.09.18 08:46:27.772308 [ 272 ] {} <Fatal> BaseDaemon: (version 20.10.1.4674, build id: 0A8DBFD7309E392E) (from thread 269) (query_id: 9dc86454-ceec-49de-9fa8-322e38fb091a) Received signal Aborted (6)
2020.09.18 08:46:27.772493 [ 272 ] {} <Fatal> BaseDaemon: 
2020.09.18 08:46:27.772674 [ 272 ] {} <Fatal> BaseDaemon: Stack trace: 0x7fd9095a9f47 0x7fd9095ab8b1 0x7fd90959b42a 0x7fd90959b4a2 0x118999fc 0x11b17a24 0x1a4b9277 0x1addb654 0x1addba94 0x1b93ad43 0x1b939332 0x1b935637 0x1b93df28 0x1f5e335c 0x1f5e3b6c 0x1f725bd3 0x1f722b0d 0x1f721998 0x7fd909d6f6db 0x7fd90968ca3f
2020.09.18 08:46:27.773036 [ 272 ] {} <Fatal> BaseDaemon: 4. /build/glibc-2ORdQG/glibc-2.27/signal/../sysdeps/unix/sysv/linux/raise.c:51: __GI_raise @ 0x3ef47 in /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.27.so
2020.09.18 08:46:27.773277 [ 272 ] {} <Fatal> BaseDaemon: 5. /build/glibc-2ORdQG/glibc-2.27/stdlib/abort.c:81: __GI_abort @ 0x408b1 in /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.27.so
2020.09.18 08:46:27.773494 [ 272 ] {} <Fatal> BaseDaemon: 6. /build/glibc-2ORdQG/glibc-2.27/assert/assert.c:89: __assert_fail_base @ 0x3042a in /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.27.so
2020.09.18 08:46:27.773847 [ 272 ] {} <Fatal> BaseDaemon: 7. ? @ 0x304a2 in /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.27.so
2020.09.18 08:46:27.774195 [ 272 ] {} <Fatal> BaseDaemon: 8. /build/obj-x86_64-linux-gnu/../src/Common/Exception.cpp:48: DB::Exception::Exception(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int) @ 0x118999fc in /workspace/clickhouse
2020.09.18 08:46:27.777917 [ 272 ] {} <Fatal> BaseDaemon: 9. /build/obj-x86_64-linux-gnu/../src/Common/assert_cast.h:47: DB::ColumnNullable const& assert_cast<DB::ColumnNullable const&, DB::IColumn const&>(DB::IColumn const&) @ 0x11b17a24 in /workspace/clickhouse
2020.09.18 08:46:27.811771 [ 272 ] {} <Fatal> BaseDaemon: 10. /build/obj-x86_64-linux-gnu/../src/DataTypes/DataTypeNullable.cpp:91: DB::DataTypeNullable::serializeBinaryBulkWithMultipleStreams(DB::IColumn const&, unsigned long, unsigned long, DB::IDataType::SerializeBinaryBulkSettings&, std::__1::shared_ptr<DB::IDataType::SerializeBinaryBulkState>&) const @ 0x1a4b9277 in /workspace/clickhouse
2020.09.18 08:46:27.849208 [ 272 ] {} <Fatal> BaseDaemon: 11. /build/obj-x86_64-linux-gnu/../src/DataStreams/NativeBlockOutputStream.cpp:58: DB::NativeBlockOutputStream::writeData(DB::IDataType const&, COW<DB::IColumn>::immutable_ptr<DB::IColumn> const&, DB::WriteBuffer&, unsigned long, unsigned long) @ 0x1addb654 in /workspace/clickhouse
2020.09.18 08:46:27.884883 [ 272 ] {} <Fatal> BaseDaemon: 12. /build/obj-x86_64-linux-gnu/../src/DataStreams/NativeBlockOutputStream.cpp:124: DB::NativeBlockOutputStream::write(DB::Block const&) @ 0x1addba94 in /workspace/clickhouse
2020.09.18 08:46:27.928546 [ 272 ] {} <Fatal> BaseDaemon: 13. /build/obj-x86_64-linux-gnu/../src/Server/TCPHandler.cpp:702: DB::TCPHandler::sendTotals(DB::Block const&) @ 0x1b93ad43 in /workspace/clickhouse
2020.09.18 08:46:27.972383 [ 272 ] {} <Fatal> BaseDaemon: 14. /build/obj-x86_64-linux-gnu/../src/Server/TCPHandler.cpp:632: DB::TCPHandler::processOrdinaryQueryWithProcessors() @ 0x1b939332 in /workspace/clickhouse
2020.09.18 08:46:28.016255 [ 272 ] {} <Fatal> BaseDaemon: 15. /build/obj-x86_64-linux-gnu/../src/Server/TCPHandler.cpp:274: DB::TCPHandler::runImpl() @ 0x1b935637 in /workspace/clickhouse
2020.09.18 08:46:28.060069 [ 272 ] {} <Fatal> BaseDaemon: 16. /build/obj-x86_64-linux-gnu/../src/Server/TCPHandler.cpp:1312: DB::TCPHandler::run() @ 0x1b93df28 in /workspace/clickhouse
2020.09.18 08:46:28.110152 [ 272 ] {} <Fatal> BaseDaemon: 17. /build/obj-x86_64-linux-gnu/../contrib/poco/Net/src/TCPServerConnection.cpp:43: Poco::Net::TCPServerConnection::start() @ 0x1f5e335c in /workspace/clickhouse
2020.09.18 08:46:28.160124 [ 272 ] {} <Fatal> BaseDaemon: 18. /build/obj-x86_64-linux-gnu/../contrib/poco/Net/src/TCPServerDispatcher.cpp:114: Poco::Net::TCPServerDispatcher::run() @ 0x1f5e3b6c in /workspace/clickhouse
2020.09.18 08:46:28.210146 [ 272 ] {} <Fatal> BaseDaemon: 19. /build/obj-x86_64-linux-gnu/../contrib/poco/Foundation/src/ThreadPool.cpp:199: Poco::PooledThread::run() @ 0x1f725bd3 in /workspace/clickhouse
2020.09.18 08:46:28.260062 [ 272 ] {} <Fatal> BaseDaemon: 20. /build/obj-x86_64-linux-gnu/../contrib/poco/Foundation/src/Thread.cpp:56: Poco::(anonymous namespace)::RunnableHolder::run() @ 0x1f722b0d in /workspace/clickhouse
2020.09.18 08:46:28.310133 [ 272 ] {} <Fatal> BaseDaemon: 21. /build/obj-x86_64-linux-gnu/../contrib/poco/Foundation/src/Thread_POSIX.cpp:345: Poco::ThreadImpl::runnableEntry(void*) @ 0x1f721998 in /workspace/clickhouse
2020.09.18 08:46:28.310500 [ 272 ] {} <Fatal> BaseDaemon: 22. start_thread @ 0x76db in /lib/x86_64-linux-gnu/libpthread-2.27.so
2020.09.18 08:46:28.310862 [ 272 ] {} <Fatal> BaseDaemon: 23. /build/glibc-2ORdQG/glibc-2.27/misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:97: __GI___clone @ 0x121a3f in /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.27.so

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugConfirmed user-visible misbehaviour in official releasecomp-joinsJOINs end-to-end (planning hooks + runtime join operators/algorithms). Single bucket to avoid pla...fuzzProblem found by one of the fuzzers

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions