Clickhouse: clickhouse-client failed with large volume data

[rogerlzp]

Describe the bug
A clear and concise description of what works not as it is supposed to.
clickhouse-client failed when importing large volume data, add several parameters to fix it, but it didn't work.
is there any workaround to this issue?

How to reproduce
clickhouse-client --input_format_parallel_parsing=0 --max_compress_block_size=500000000 --max_insert_block_size=10000000000000 --format_csv_delimiter="^A" -h 172.30.123.12 --query="insert into dw.even_trade_conf_d_all2 select ta_type,ta_conf_no,conf_date,apply_date,busi_type,hdatasrc,par_day from file('even_trade_conf_d_int/001785_0','CSV','
ta_type Nullable(String) , ta_conf_no String , conf_date String , apply_date Nullable(String) , busi_type Nullable(String) , hdatasrc String, par_day String
')" --password xxxx --input_format_allow_errors_num=1000

• Which ClickHouse server version to use
  20.5.2.7
• Which interface to use, if matters
• Non-default settings, if any
• CREATE TABLE statements for all tables involved
• Sample data for all these tables, use clickhouse-obfuscator if necessary
• Queries to run that lead to unexpected result

Expected behavior
A clear and concise description of what you expected to happen.

Error message and/or stacktrace

Code: 173. DB::Exception: Received from 172.30.123.12:9000. DB::Exception: Allocator: Cannot realloc from 1.00 MiB to 2.00 MiB., errno: 12, strerror: Cannot allocate memory: While executing SinkToOutputStream.
Received exception from server (version 20.5.2):
Code: 173. DB::Exception: Received from 172.30.123.12:9000. DB::Exception: Allocator: Cannot malloc 1.00 MiB., errno: 12, strerror: Cannot allocate memory: While executing File.
Code: 32. DB::Exception: Attempt to read after eof: while receiving packet from 172.30.123.12:9000

_from clickhouse-server.err.log:_
2020.08.31 16:39:59.772360 [ 15862 ] {} void DB::SystemLog::flushImpl(const std::__1::vector<_RealType>&, uint64_t) [with LogElement = DB::QueryThreadLogElement; uint64_t = long unsigned int]: Code: 173, e.displayText() = DB::ErrnoException: Allocator: Cannot realloc from 16.00 KiB to 32.00 KiB., errno: 12, strerror: Cannot allocate memory, Stack trace (when copying this message, always include the lines below):

1. /build/obj-x86_64-linux-gnu/../contrib/poco/Foundation/src/Exception.cpp:27: Poco::Exception::Exception(std::__1::basic_string, std::__1::allocator > const&, int) @ 0x10ed0da0 in /usr/lib/debug/usr/bin/clickhouse
2. /build/obj-x86_64-linux-gnu/../contrib/libcxx/include/optional:231: DB::ErrnoException::ErrnoException(std::__1::basic_string, std::__1::allocator > const&, int, int, std::__1::optional, std::__1::allocator > > const&) @ 0x95cd3cb in /usr/lib/debug/usr/bin/clickhouse
3. /build/obj-x86_64-linux-gnu/../contrib/libcxx/include/string:2134: DB::throwFromErrno(std::__1::basic_string, std::__1::allocator > const&, int, int) @ 0x95cb04f in /usr/lib/debug/usr/bin/clickhouse
4. /build/obj-x86_64-linux-gnu/../src/Common/Allocator.h:165: Allocator::realloc(void*, unsigned long, unsigned long, unsigned long) @ 0x9611a61 in /usr/lib/debug/usr/bin/clickhouse
5. DB::ColumnString::insertData(char const*, unsigned long) @ 0xa7b401c in /usr/lib/debug/usr/bin/clickhouse
6. /build/obj-x86_64-linux-gnu/../src/Interpreters/QueryThreadLog.cpp:93: DB::QueryThreadLogElement::appendToBlock(std::__1::vector::mutable_ptr, std::__1::allocator::mutable_ptr > >&) const @ 0xdfb30f2 in /usr/lib/debug/usr/bin/clickhouse
7. /build/obj-x86_64-linux-gnu/../src/Interpreters/SystemLog.h:417: DB::SystemLog::flushImpl(std::__1::vector > const&, unsigned long) @ 0x965af5d in /usr/lib/debug/usr/bin/clickhouse
8. /build/obj-x86_64-linux-gnu/../src/Interpreters/SystemLog.h:342: DB::SystemLog::savingThreadFunction() @ 0x9660f12 in /usr/lib/debug/usr/bin/clickhouse
9. /build/obj-x86_64-linux-gnu/../src/Common/ThreadPool.h:159: ThreadFromGlobalPool::ThreadFromGlobalPool::startup()::'lambda'()>(DB::QueryThreadLogElement&&, DB::SystemLog::startup()::'lambda'()&&...)::'lambda'()::operator()() const @ 0x96617c6 in /usr/lib/debug/usr/bin/clickhouse
10. /build/obj-x86_64-linux-gnu/../contrib/libcxx/include/atomic:856: ThreadPoolImpl::worker(std::__1::__list_iterator) @ 0x95f6e97 in /usr/lib/debug/usr/bin/clickhouse
11. /build/obj-x86_64-linux-gnu/../contrib/libcxx/include/memory:2615: void* std::__1::__thread_proxy >, void ThreadPoolImpl::scheduleImpl(std::__1::function)::'lambda1'()> >(void*) @ 0x95f5383 in /usr/lib/debug/usr/bin/clickhouse
12. start_thread @ 0x7dd5 in /usr/lib64/libpthread-2.17.so
13. clone @ 0xfeb3d in /usr/lib64/libc-2.17.so
    (version 20.5.2.7 (official build))

_from clickhouse-server.log:_
2020.08.31 16:39:59.819038 [ 15864 ] {} DiskLocal: Reserving 1.00 MiB on disk default, having unreserved 592.72 GiB.
2020.08.31 16:39:59.820484 [ 15864 ] {} system.metric_log: Renaming temporary part tmp_insert_202008_12_12_0 to 202008_529892_529892_0.
2020.08.31 16:39:59.820807 [ 15864 ] {} SystemLog (system.metric_log): Flushed system log
2020.08.31 16:39:59.820865 [ 15821 ] {} system.metric_log (MergerMutator): Selected 2 parts from 202008_527615_529886_1719 to 202008_529887_529887_0
2020.08.31 16:39:59.820900 [ 15821 ] {} DiskLocal: Reserving 2.17 MiB on disk default, having unreserved 592.72 GiB.
2020.08.31 16:39:59.820918 [ 15821 ] {} system.metric_log (MergerMutator): Merging 2 parts: from 202008_527615_529886_1719 to 202008_529887_529887_0 into Wide
2020.08.31 16:39:59.821125 [ 15821 ] {} system.metric_log (MergerMutator): Selected MergeAlgorithm: Horizontal
2020.08.31 16:39:59.855418 [ 15821 ] {} MergeTreeSequentialSource: Reading 5 marks from part 202008_527615_529886_1719, total 17057 rows starting from the beginning of the part
2020.08.31 16:39:59.861180 [ 15821 ] {} MergeTreeSequentialSource: Reading 2 marks from part 202008_529887_529887_0, total 7 rows starting from the beginning of the part
2020.08.31 16:39:59.878777 [ 15822 ] {} system.query_log (MergerMutator): Merge sorted 10974 rows, containing 42 columns (42 merged, 0 gathered) in 0.104793818 sec., 104719.91773407855 rows/sec., 408.76 MiB/sec.
2020.08.31 16:39:59.881614 [ 15822 ] {} system.query_log: Renaming temporary part tmp_merge_202008_2936_3467_329 to 202008_2936_3467_329.
2020.08.31 16:39:59.881701 [ 15822 ] {} system.query_log (MergerMutator): Merged 2 parts: from 202008_2936_3466_328 to 202008_3467_3467_0
2020.08.31 16:39:59.881716 [ 15822 ] {} MemoryTracker: Peak memory usage: 100.41 MiB.
2020.08.31 16:39:59.951778 [ 15821 ] {} system.metric_log (MergerMutator): Merge sorted 17064 rows, containing 235 columns (235 merged, 0 gathered) in 0.130852755 sec., 130406.11945847071 rows/sec., 232.56 MiB/sec.
2020.08.31 16:39:59.964520 [ 15821 ] {} system.metric_log: Renaming temporary part tmp_merge_202008_527615_529887_1720 to 202008_527615_529887_1720.
2020.08.31 16:39:59.964741 [ 15821 ] {} system.metric_log (MergerMutator): Merged 2 parts: from 202008_527615_529886_1719 to 202008_529887_529887_0
2020.08.31 16:39:59.964761 [ 15821 ] {} MemoryTracker: Peak memory usage: 333.87 MiB.
2020.08.31 16:40:00.848159 [ 15850 ] {} DNSResolver: Updating DNS cache
2020.08.31 16:40:00.857440 [ 15850 ] {} DNSResolver: Updated DNS cache
2020.08.31 16:40:07.249499 [ 15851 ] {} SystemLog (system.trace_log): Flushing system log, 7 entries to flush
2020.08.31 16:40:07.249948 [ 15851 ] {} DiskLocal: Reserving 1.00 MiB on disk default, having unreserved 592.79 GiB.
2020.08.31 16:40:07.250757 [ 15851 ] {} system.trace_log: Renaming temporary part tmp_insert_202008_11_11_0 to 202008_528187_528187_0.
2020.08.31 16:40:07.250836 [ 15851 ] {} SystemLog (system.trace_log): Flushed system log
2020.08.31 16:40:07.251020 [ 15833 ] {} system.trace_log (MergerMutator): Selected 2 parts from 202008_527168_528181_906 to 202008_528182_528182_0
2020.08.31 16:40:07.251061 [ 15833 ] {} DiskLocal: Reserving 1.49 MiB on disk default, having unreserved 592.79 GiB.
2020.08.31 16:40:07.251093 [ 15833 ] {} system.trace_log (MergerMutator): Merging 2 parts: from 202008_527168_528181_906 to 202008_528182_528182_0 into Wide
2020.08.31 16:40:07.251132 [ 15833 ] {} system.trace_log (MergerMutator): Selected MergeAlgorithm: Horizontal
2020.08.31 16:40:07.251211 [ 15833 ] {} MergeTreeSequentialSource: Reading 10 marks from part 202008_527168_528181_906, total 66707 rows starting from the beginning of the part
2020.08.31 16:40:07.251539 [ 15833 ] {} MergeTreeSequentialSource: Reading 2 marks from part 202008_528182_528182_0, total 21 rows starting from the beginning of the part
2020.08.31 16:40:07.279699 [ 15833 ] {} system.trace_log (MergerMutator): Merge sorted 66728 rows, containing 9 columns (9 merged, 0 gathered) in 0.028593464 sec., 2333680.172503758 rows/sec., 531.01 MiB/sec.
2020.08.31 16:40:07.280572 [ 15833 ] {} system.trace_log: Renaming temporary part tmp_merge_202008_527168_528182_907 to 202008_527168_528182_907.
2020.08.31 16:40:07.280641 [ 15833 ] {} system.trace_log (MergerMutator): Merged 2 parts: from 202008_527168_528181_906 to 202008_528182_528182_0
2020.08.31 16:40:07.280658 [ 15833 ] {} MemoryTracker: Peak memory usage: 23.09 MiB.
2020.08.31 16:40:07.320961 [ 15864 ] {} SystemLog (system.metric_log): Flushing system log, 7 entries to flush
2020.08.31 16:40:07.323510 [ 15864 ] {} DiskLocal: Reserving 1.00 MiB on disk default, having unreserved 592.79 GiB.
2020.08.31 16:40:07.324985 [ 15864 ] {} system.metric_log: Renaming temporary part tmp_insert_202008_13_13_0 to 202008_529893_529893_0.
2020.08.31 16:40:07.325242 [ 15825 ] {} system.metric_log (MergerMutator): Selected 2 parts from 202008_527615_529887_1720 to 202008_529888_529888_0
2020.08.31 16:40:07.325292 [ 15825 ] {} DiskLocal: Reserving 2.17 MiB on disk default, having unreserved 592.79 GiB.
2020.08.31 16:40:07.325307 [ 15825 ] {} system.metric_log (MergerMutator): Merging 2 parts: from 202008_527615_529887_1720 to 202008_529888_529888_0 into Wide
2020.08.31 16:40:07.325317 [ 15864 ] {} SystemLog (system.metric_log): Flushed system log
2020.08.31 16:40:07.325909 [ 15825 ] {} system.metric_log (MergerMutator): Selected MergeAlgorithm: Horizontal
2020.08.31 16:40:07.326351 [ 15825 ] {} MergeTreeSequentialSource: Reading 5 marks from part 202008_527615_529887_1720, total 17064 rows starting from the beginning of the part
2020.08.31 16:40:07.332144 [ 15825 ] {} MergeTreeSequentialSource: Reading 2 marks from part 202008_529888_529888_0, total 8 rows starting from the beginning of the part
2020.08.31 16:40:07.425607 [ 15825 ] {} system.metric_log (MergerMutator): Merge sorted 17072 rows, containing 235 columns (235 merged, 0 gathered) in 0.100289629 sec., 170226.97331944463 rows/sec., 303.58 MiB/sec.
2020.08.31 16:40:07.438381 [ 15825 ] {} system.metric_log: Renaming temporary part tmp_merge_202008_527615_529888_1721 to 202008_527615_529888_1721.
2020.08.31 16:40:07.438578 [ 15825 ] {} system.metric_log (MergerMutator): Merged 2 parts: from 202008_527615_529887_1720 to 202008_529888_529888_0
2020.08.31 16:40:07.438598 [ 15825 ] {} MemoryTracker: Peak memory usage: 333.87 MiB.

Additional context
it works well with a smaller file.

[den-crane]

--max_compress_block_size=500000000 --max_insert_block_size=10000000000000
DB::Exception: Allocator: Cannot realloc from 1.00 MiB to 2.00 MiB., errno: 12

It's kinda expected behavior, that huge blocks need a lot of memory. Did you try max_insert_block_size=1000000 (100000) ?
Did you change max_memory_usage (default value is 10GB)?

[filimonov]

--max_compress_block_size=500000000 --max_insert_block_size=10000000000000

Those settings have no sense at all. Do you have a server with > 10 Terabytes of RAM?

[alexey-milovidov]

Raising max_compress_block_size is especially harmful. It will slow down all SELECT queries.