Cannot quickly remove directory .../delete_tmp_all_1_2_1 by removing files; fallback to recursive removal. Reason: ... File not found: .../checksums.txt

[qoega]

Describe the bug

2020.03.30 14:09:29.106962 [ 886680 ] {} <Error> tmp1.mass_table_628: Cannot quickly remove directory /home/qoega/clickhouse-server/data/data/tmp1/mass_table_628/delete_tmp_all_1_2_1 by removing files; fallback to recursive removal. Reason: Poco::Exception. Code: 1000, e.code() = 2, e.displayText() = File not found: /home/qoega/clickhouse-server/data/data/tmp1/mass_table_628/delete_tmp_all_1_2_1/checksums.txt (version 20.4.1.1)
2020.03.30 14:09:29.108484 [ 886680 ] {} <Error> void DB::BackgroundProcessingPool::threadFunction(): Code: 117, e.displayText() = DB::Exception: Incorrect data: Sign = -37 (must be 1 or -1)., Stack trace (when copying this message, always include the lines below):

0. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/exception:129: std::exception::capture() @ 0xd1eb8c8 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
1. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/exception:109: std::exception::exception() @ 0xd1eb850 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
2. /home/qoega/clickhouse/build-asan/../contrib/poco/Foundation/src/Exception.cpp:27: Poco::Exception::Exception(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int) @ 0x29db5cc6 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
3. /home/qoega/clickhouse/build-asan/../dbms/src/Common/Exception.cpp:29: DB::Exception::Exception(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int) @ 0x200ffbe7 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
4. /home/qoega/clickhouse/build-asan/../dbms/src/DataStreams/CollapsingSortedBlockInputStream.cpp:181: DB::CollapsingSortedBlockInputStream::merge(std::__1::vector<COW<DB::IColumn>::mutable_ptr<DB::IColumn>, std::__1::allocator<COW<DB::IColumn>::mutable_ptr<DB::IColumn> > >&, DB::SortingHeap<DB::SortCursor>&) @ 0x1eaf66e2 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
5. /home/qoega/clickhouse/build-asan/../dbms/src/DataStreams/CollapsingSortedBlockInputStream.cpp:103: DB::CollapsingSortedBlockInputStream::readImpl() @ 0x1eaf5576 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
6. /home/qoega/clickhouse/build-asan/../dbms/src/DataStreams/IBlockInputStream.cpp:60: DB::IBlockInputStream::read() @ 0x1beb0856 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
7. /home/qoega/clickhouse/build-asan/../dbms/src/Storages/MergeTree/MergeTreeDataMergerMutator.cpp:788: DB::MergeTreeDataMergerMutator::mergePartsToTemporaryPart(DB::FutureMergedMutatedPart const&, DB::MergeListEntry&, DB::TableStructureReadLockHolder&, long, std::__1::unique_ptr<DB::IReservation, std::__1::default_delete<DB::IReservation> > const&, bool, bool) @ 0x1ddc2ffc in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
8. /home/qoega/clickhouse/build-asan/../dbms/src/Storages/StorageMergeTree.cpp:608: DB::StorageMergeTree::merge(bool, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, bool, bool, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >*) @ 0x1d95cf29 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
9. /home/qoega/clickhouse/build-asan/../dbms/src/Storages/StorageMergeTree.cpp:786: DB::StorageMergeTree::mergeMutateTask() @ 0x1d9615fd in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
10. /home/qoega/clickhouse/build-asan/../dbms/src/Storages/StorageMergeTree.cpp:96: DB::StorageMergeTree::startup()::$_0::operator()() const @ 0x1d9720fd in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
11. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/type_traits:3519: decltype(std::__1::forward<DB::StorageMergeTree::startup()::$_0&>(fp)()) std::__1::__invoke<DB::StorageMergeTree::startup()::$_0&>(DB::StorageMergeTree::startup()::$_0&) @ 0x1d97209d in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
12. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/__functional_base:317: DB::BackgroundProcessingPoolTaskResult std::__1::__invoke_void_return_wrapper<DB::BackgroundProcessingPoolTaskResult>::__call<DB::StorageMergeTree::startup()::$_0&>(DB::StorageMergeTree::startup()::$_0&) @ 0x1d97204d in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
13. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/functional:1540: std::__1::__function::__alloc_func<DB::StorageMergeTree::startup()::$_0, std::__1::allocator<DB::StorageMergeTree::startup()::$_0>, DB::BackgroundProcessingPoolTaskResult ()>::operator()() @ 0x1d97201d in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
14. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/functional:1714: std::__1::__function::__func<DB::StorageMergeTree::startup()::$_0, std::__1::allocator<DB::StorageMergeTree::startup()::$_0>, DB::BackgroundProcessingPoolTaskResult ()>::operator()() @ 0x1d96f88e in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
15. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/functional:1867: std::__1::__function::__value_func<DB::BackgroundProcessingPoolTaskResult ()>::operator()() const @ 0x1dc1490a in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
16. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/functional:2473: std::__1::function<DB::BackgroundProcessingPoolTaskResult ()>::operator()() const @ 0x1dc0bb45 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
17. /home/qoega/clickhouse/build-asan/../dbms/src/Storages/MergeTree/BackgroundProcessingPool.cpp:200: DB::BackgroundProcessingPool::threadFunction() @ 0x1dc04af9 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
18. /home/qoega/clickhouse/build-asan/../dbms/src/Storages/MergeTree/BackgroundProcessingPool.cpp:59: DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0::operator()() const @ 0x1dc097dd in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
19. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/type_traits:3525: decltype(std::__1::forward<DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0 const&>(fp)()) std::__1::__invoke_constexpr<DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0 const&>(DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0 const&) @ 0x1dc0978d in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
20. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/tuple:1415: decltype(auto) std::__1::__apply_tuple_impl<DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0 const&, std::__1::tuple<> const&>(DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0 const&, std::__1::tuple<> const&, std::__1::__tuple_indices<>) @ 0x1dc09751 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
21. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/tuple:1424: decltype(auto) std::__1::apply<DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0 const&, std::__1::tuple<> const&>(DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0 const&, std::__1::tuple<> const&) @ 0x1dc09722 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
22. /home/qoega/clickhouse/build-asan/../dbms/src/Common/ThreadPool.h:160: ThreadFromGlobalPool::ThreadFromGlobalPool<DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0>(DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0&&)::'lambda'()::operator()() const @ 0x1dc0951e in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
23. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/type_traits:3519: decltype(std::__1::forward<DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0>(fp)()) std::__1::__invoke<ThreadFromGlobalPool::ThreadFromGlobalPool<DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0>(DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0&&)::'lambda'()&>(DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0&&) @ 0x1dc0935d in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
24. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/__functional_base:349: void std::__1::__invoke_void_return_wrapper<void>::__call<ThreadFromGlobalPool::ThreadFromGlobalPool<DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0>(DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0&&)::'lambda'()&>(DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0&&...) @ 0x1dc0930d in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
25. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/functional:1540: std::__1::__function::__alloc_func<ThreadFromGlobalPool::ThreadFromGlobalPool<DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0>(DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0&&)::'lambda'(), std::__1::allocator<ThreadFromGlobalPool::ThreadFromGlobalPool<DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0>(DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0&&)::'lambda'()>, void ()>::operator()() @ 0x1dc092dd in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
26. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/functional:1714: std::__1::__function::__func<ThreadFromGlobalPool::ThreadFromGlobalPool<DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0>(DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0&&)::'lambda'(), std::__1::allocator<ThreadFromGlobalPool::ThreadFromGlobalPool<DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0>(DB::BackgroundProcessingPool::BackgroundProcessingPool(int, DB::BackgroundProcessingPool::PoolSettings const&, char const*, char const*)::$_0&&)::'lambda'()>, void ()>::operator()() @ 0x1dc06b1e in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
27. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/functional:1867: std::__1::__function::__value_func<void ()>::operator()() const @ 0xd1eb69a in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
28. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/functional:2473: std::__1::function<void ()>::operator()() const @ 0xd1eb555 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
29. /home/qoega/clickhouse/build-asan/../dbms/src/Common/ThreadPool.cpp:224: ThreadPoolImpl<std::__1::thread>::worker(std::__1::__list_iterator<std::__1::thread, void*>) @ 0x20192aa9 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
30. /home/qoega/clickhouse/build-asan/../dbms/src/Common/ThreadPool.cpp:105: void ThreadPoolImpl<std::__1::thread>::scheduleImpl<void>(std::__1::function<void ()>, int, std::__1::optional<unsigned long>)::'lambda1'()::operator()() const @ 0x201a37c0 in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
31. /home/qoega/clickhouse/build-asan/../contrib/libcxx/include/type_traits:3519: decltype(std::__1::forward<void>(fp)(std::__1::forward<void ThreadPoolImpl<std::__1::thread>::scheduleImpl<void>(std::__1::function<void ()>, int, std::__1::optional<unsigned long>)::'lambda1'()>(fp0)...)) std::__1::__invoke<void ThreadPoolImpl<std::__1::thread>::scheduleImpl<void>(std::__1::function<void ()>, int, std::__1::optional<unsigned long>)::'lambda1'()>(void&&, void ThreadPoolImpl<std::__1::thread>::scheduleImpl<void>(std::__1::function<void ()>, int, std::__1::optional<unsigned long>)::'lambda1'()&&...) @ 0x201a361d in /home/qoega/clickhouse/build-asan/dbms/programs/clickhouse
 (version 20.4.1.1)

How to reproduce

• Which ClickHouse server version to use
• 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
If applicable, add screenshots to help explain your problem.

Additional context
Add any other context about the problem here.

[qoega]

@excitoon

[excitoon]

I guess there are two issues here:

1. Corrupted part data upon deletion (missing checksum.txt);
2. Sign was somehow collapsed to -37, which is not good at all.

[excitoon]

@qoega Which are CREATE statements and are there any ways to reproduce that?

[alexey-milovidov]

@excitoon

Most likely Ilya manually inserted data with incorrect Sign via generateRandom function. This is expected.

[alexey-milovidov]

It is reproducing every time on server shutdown if metric_log is enabled:

2020.04.13 02:35:36.370276 [ 25812 ] {} <Error> system.metric_log: Cannot quickly remove directory ./data/system/metric_log/delete_tmp_202004_1_4970_1338 by removing files; fallback to recursive removal. Reason: Poco::Exception. Code: 1000, e.code() = 2, e.displayText() = File not found: ./data/system/metric_log/delete_tmp_202004_1_4970_1338/checksums.txt (version 20.4.1.1)

[qoega]

@qoega Which are CREATE statements and are there any ways to reproduce that?
Here is complete scenario, but I'm sure is can be minimized
https://gist.github.com/qoega/64c15b57a96e602bd779e4ee115cba17

@excitoon

[mo-avatar]

I have just find the same log on our production machine, but we don't use quantile related thing.

Cannot quickly remove directory /var/lib/clickhouse/data/default/%2Einner%2Ertt_50p_graph_day/delete_tmp_20200408_280071_401482_7307 by removing files; fallback to recursive removal. Reason: Code: 458, e.displayText() = DB::ErrnoException: Cannot unlink file /var/lib/clickhouse/data/default/%2Einner%2Ertt_50p_graph_day/delete_tmp_20200408_280071_401482_7307/checksums.txt, errno: 2, strerror: No such file or directory (version 20.3.4.10 (official build))

Any one knows , if the problem will cause clickhouse not respond to a query? or the cost of "fallback to recursive removal" is very limit, and it can barely influence the query.
It just occured irregularly, and it seems each time the echo test returns time out on our production machine, the error occurs.
but I can't make sure if some thing else cause the time out , or only the error can cause time out.
Thanks.
@alexey-milovidov
@den-crane