WriteBufferFromS3 is not finalized in destructor #43303
Description
A new test that uses S3 was added in this PR. AST fuzzer found terminate() call while running that new test (backtrace)
Problem is raised by this code snippet:
WriteBufferFromS3::~WriteBufferFromS3()
{
#ifndef NDEBUG
if (!finalized)
{
LOG_ERROR(log, "WriteBufferFromS3 is not finalized in destructor. It's a bug");
std::terminate();
}
#elseDuring AST fuzzer test we cannot access minio for 10 times with exponential backoff retry interval from 50 ms up to 12800 ms. This sums up to 28 seconds, which exceed query execution timeout 10 seconds, so an exception is thrown and QueryPipeline is destructed, after which we got not finalised WriteBufferFromS3 buffer during stack unwinding.
Note that minio is not available during AST fuzzing, so I've already fix it by removing all S3 tests from fuzzer, but anyway stack unwinding due to cancel could happen in real environment and should not lead to crash.
server.log
2022.11.11 18:21:27.425446 [ 150 ] {18ef878a-fbaa-4a8e-97e3-d7d83a7c7830} WriteBufferFromS3: WriteBufferFromS3 is not finalized in destructor. It's a bug
2022.11.11 18:21:27.425865 [ 148 ] {} BaseDaemon: Received signal -1
2022.11.11 18:21:27.426027 [ 148 ] {} BaseDaemon: (version 22.11.1.1, build id: A12D6F82C997B6D1D65AF039FB4F12D1CC77E95D) (from thread 150) Terminate called for uncaught exception:
2022.11.11 18:21:27.426102 [ 148 ] {} BaseDaemon: Code: 159. DB::Exception: Timeout exceeded: elapsed 28.076487826 seconds, maximum: 10. (TIMEOUT_EXCEEDED), Stack trace (when copying this message, always include the lines below):
2022.11.11 18:21:27.426165 [ 148 ] {} BaseDaemon:
2022.11.11 18:21:27.426234 [ 148 ] {} BaseDaemon: 0. /build/build_docker/../contrib/libcxx/include/exception:134: std::exception::capture() @ 0x17d66c02 in /workspace/clickhouse
2022.11.11 18:21:27.426291 [ 148 ] {} BaseDaemon: 1. /build/build_docker/../contrib/libcxx/include/exception:112: std::exception::exception[abi:v15003]() @ 0x17d66bcd in /workspace/clickhouse
2022.11.11 18:21:27.426363 [ 148 ] {} BaseDaemon: 2. /build/build_docker/../contrib/poco/Foundation/src/Exception.cpp:27: Poco::Exception::Exception(std::__1::basic_string, std::__1::allocator> const&, int) @ 0x2e50f420 in /workspace/clickhouse
2022.11.11 18:21:27.426450 [ 148 ] {} BaseDaemon: 3. /build/build_docker/../src/Common/Exception.cpp:67: DB::Exception::Exception(std::__1::basic_string, std::__1::allocator> const&, int, bool) @ 0x2046014e in /workspace/clickhouse
2022.11.11 18:21:27.426509 [ 148 ] {} BaseDaemon: 4. /build/build_docker/../src/Common/Exception.h:37: DB::Exception::Exception(int, fmt::v8::basic_format_string::type, fmt::v8::type_identity::type>, double&&, double&&) @ 0x26ddc092 in /workspace/clickhouse
2022.11.11 18:21:27.426568 [ 148 ] {} BaseDaemon: 5. /build/build_docker/../src/QueryPipeline/ExecutionSpeedLimits.cpp:110: bool DB::handleOverflowMode(DB::OverflowMode, int, fmt::v8::basic_format_string::type, fmt::v8::type_identity::type>, double&&, double&&) @ 0x26ddb516 in /workspace/clickhouse
2022.11.11 18:21:27.426626 [ 148 ] {} BaseDaemon: 6. /build/build_docker/../src/QueryPipeline/ExecutionSpeedLimits.cpp:126: DB::ExecutionSpeedLimits::checkTimeLimit(Stopwatch const&, DB::OverflowMode) const @ 0x26ddb449 in /workspace/clickhouse
2022.11.11 18:21:27.426680 [ 148 ] {} BaseDaemon: 7. /build/build_docker/../src/Interpreters/ProcessList.cpp:413: DB::QueryStatus::checkTimeLimit() @ 0x282a4c3c in /workspace/clickhouse
2022.11.11 18:21:27.426734 [ 148 ] {} BaseDaemon: 8. /build/build_docker/../src/Processors/Executors/PipelineExecutor.cpp:163: DB::PipelineExecutor::checkTimeLimit() @ 0x2986ec60 in /workspace/clickhouse
2022.11.11 18:21:27.426788 [ 148 ] {} BaseDaemon: 9. /build/build_docker/../src/Processors/Executors/PipelineExecutor.cpp:173: DB::PipelineExecutor::finalizeExecution() @ 0x2986f35c in /workspace/clickhouse
2022.11.11 18:21:27.426842 [ 148 ] {} BaseDaemon: 10. /build/build_docker/../src/Processors/Executors/PipelineExecutor.cpp:109: DB::PipelineExecutor::execute(unsigned long) @ 0x2986ec00 in /workspace/clickhouse
2022.11.11 18:21:27.426897 [ 148 ] {} BaseDaemon: 11. /build/build_docker/../src/Processors/Executors/CompletedPipelineExecutor.cpp:43: DB::threadFunction(DB::CompletedPipelineExecutor::Data&, std::__1::shared_ptr, unsigned long) @ 0x2986d212 in /workspace/clickhouse
2022.11.11 18:21:27.426955 [ 148 ] {} BaseDaemon: 12. /build/build_docker/../src/Processors/Executors/CompletedPipelineExecutor.cpp:80: DB::CompletedPipelineExecutor::execute()::$_0::operator()() const @ 0x2986d0e1 in /workspace/clickhouse
2022.11.11 18:21:27.427009 [ 148 ] {} BaseDaemon: 13. /build/build_docker/../contrib/libcxx/include/__functional/invoke.h:394: decltype(std::declval()()) std::__1::__invoke[abi:v15003](DB::CompletedPipelineExecutor::execute()::$_0&) @ 0x2986d095 in /workspace/clickhouse
2022.11.11 18:21:27.427068 [ 148 ] {} BaseDaemon: 14. /build/build_docker/../contrib/libcxx/include/tuple:1789: decltype(auto) std::__1::__apply_tuple_impl[abi:v15003]&>(DB::CompletedPipelineExecutor::execute()::$_0&, std::__1::tuple<>&, std::__1::__tuple_indices<>) @ 0x2986d079 in /workspace/clickhouse
2022.11.11 18:21:27.427128 [ 148 ] {} BaseDaemon: 15. /build/build_docker/../contrib/libcxx/include/tuple:1798: decltype(auto) std::__1::apply[abi:v15003]&>(DB::CompletedPipelineExecutor::execute()::$_0&, std::__1::tuple<>&) @ 0x2986cfdd in /workspace/clickhouse
2022.11.11 18:21:27.427186 [ 148 ] {} BaseDaemon: 16. /build/build_docker/../src/Common/ThreadPool.h:196: ThreadFromGlobalPoolImpl::ThreadFromGlobalPoolImpl(DB::CompletedPipelineExecutor::execute()::$_0&&)::'lambda'()::operator()() @ 0x2986cee2 in /workspace/clickhouse
2022.11.11 18:21:27.427244 [ 148 ] {} BaseDaemon: 17. /build/build_docker/../contrib/libcxx/include/__functional/invoke.h:394: decltype(std::declval BaseDaemon: Received signal 6
2022.11.11 18:21:27.427643 [ 401 ] {} BaseDaemon: ########################################
2022.11.11 18:21:27.428044 [ 401 ] {} BaseDaemon: (version 22.11.1.1, build id: A12D6F82C997B6D1D65AF039FB4F12D1CC77E95D) (from thread 150) (query_id: 18ef878a-fbaa-4a8e-97e3-d7d83a7c7830) (query: INSERT INTO FUNCTION s3('http://localhost:11111/test/request-throttler.csv', 'test', 'testtest', 'CSV', 'number UInt64') SETTINGS s3_max_single_part_upload_size = 10000, s3_truncate_on_insert = 1 SELECT number FROM numbers(1000000) SETTINGS s3_max_single_part_upload_size = 10000, s3_truncate_on_insert = 1) Received signal Aborted (6)
2022.11.11 18:21:27.428248 [ 401 ] {} BaseDaemon:
2022.11.11 18:21:27.428438 [ 401 ] {} BaseDaemon: Stack trace: 0x7f5369bac00b 0x7f5369b8b859 0x20787d8a 0x31fe88b2 0x31fe87e6 0x26a92298 0x26a92439 0x23889dd4 0x23889d3c 0x23887a99 0x28ea0b9e 0x28ea104e 0x28ea0ff5 0x28ea0fd9 0x28ea020e 0x17d59274 0x17d59219 0x26d9490c 0x26d98e2d 0x26d98dd5 0x26d98d39 0x26da53f8 0x26da5398 0x26d9683e 0x26da5e4d 0x26da5df5 0x26da5dd9 0x26da5b0e 0x17d59274 0x17d59219 0x2069030c 0x26db56d0 0x26db99a2 0x2868c06a 0x297e9024 0x297f88c5 0x2e34bc99 0x2e34c4dc 0x2e59ba14 0x2e5987ba 0x2e59759e
2022.11.11 18:21:27.428615 [ 401 ] {} BaseDaemon: 4. gsignal @ 0x7f5369bac00b in ?
2022.11.11 18:21:27.428789 [ 401 ] {} BaseDaemon: 5. abort @ 0x7f5369b8b859 in ?
2022.11.11 18:21:27.528112 [ 401 ] {} BaseDaemon: 6. /build/build_docker/../src/Daemon/BaseDaemon.cpp:0: terminate_handler() @ 0x20787d8a in /workspace/clickhouse
2022.11.11 18:21:27.590403 [ 401 ] {} BaseDaemon: 7. /build/build_docker/../contrib/libcxxabi/src/cxa_handlers.cpp:59: std::__terminate(void (*)()) @ 0x31fe88b2 in /workspace/clickhouse
2022.11.11 18:21:27.652753 [ 401 ] {} BaseDaemon: 8. /build/build_docker/../contrib/libcxxabi/src/cxa_handlers.cpp:89: std::terminate() @ 0x31fe87e6 in /workspace/clickhouse
2022.11.11 18:21:27.762301 [ 401 ] {} BaseDaemon: 9. /build/build_docker/../src/IO/WriteBufferFromS3.cpp:0: DB::WriteBufferFromS3::~WriteBufferFromS3() @ 0x26a92298 in /workspace/clickhouse
2022.11.11 18:21:27.871619 [ 401 ] {} BaseDaemon: 10. /build/build_docker/../src/IO/WriteBufferFromS3.cpp:137: DB::WriteBufferFromS3::~WriteBufferFromS3() @ 0x26a92439 in /workspace/clickhouse
2022.11.11 18:21:27.920920 [ 401 ] {} BaseDaemon: 11. /build/build_docker/../contrib/libcxx/include/__memory/unique_ptr.h:49: std::__1::default_delete::operator()[abi:v15003](DB::WriteBuffer*) const @ 0x23889dd4 in /workspace/clickhouse
2022.11.11 18:21:27.970438 [ 401 ] {} BaseDaemon: 12. /build/build_docker/../contrib/libcxx/include/__memory/unique_ptr.h:306: std::__1::unique_ptr>::reset[abi:v15003](DB::WriteBuffer*) @ 0x23889d3c in /workspace/clickhouse
2022.11.11 18:21:28.016487 [ 401 ] {} BaseDaemon: 13. /build/build_docker/../contrib/libcxx/include/__memory/unique_ptr.h:259: std::__1::unique_ptr>::~unique_ptr[abi:v15003]() @ 0x23887a99 in /workspace/clickhouse
2022.11.11 18:21:28.593828 [ 401 ] {} BaseDaemon: 14. /build/build_docker/../src/Storages/StorageS3.cpp:571: DB::StorageS3Sink::~StorageS3Sink() @ 0x28ea0b9e in /workspace/clickhouse
2022.11.11 18:21:29.178120 [ 401 ] {} BaseDaemon: 15. /build/build_docker/../contrib/libcxx/include/__memory/construct_at.h:64: void std::__1::__destroy_at[abi:v15003](DB::StorageS3Sink*) @ 0x28ea104e in /workspace/clickhouse
2022.11.11 18:21:29.762612 [ 401 ] {} BaseDaemon: 16. /build/build_docker/../contrib/libcxx/include/__memory/construct_at.h:89: void std::__1::destroy_at[abi:v15003](DB::StorageS3Sink*) @ 0x28ea0ff5 in /workspace/clickhouse
2022.11.11 18:21:30.340316 [ 401 ] {} BaseDaemon: 17. /build/build_docker/../contrib/libcxx/include/__memory/allocator_traits.h:321: void std::__1::allocator_traits>::destroy[abi:v15003](std::__1::allocator&, DB::StorageS3Sink*) @ 0x28ea0fd9 in /workspace/clickhouse
2022.11.11 18:21:30.916246 [ 401 ] {} BaseDaemon: 18. /build/build_docker/../contrib/libcxx/include/__memory/shared_ptr.h:309: std::__1::__shared_ptr_emplace>::__on_zero_shared() @ 0x28ea020e in /workspace/clickhouse
2022.11.11 18:21:31.015805 [ 401 ] {} BaseDaemon: 19. /build/build_docker/../contrib/libcxx/include/__memory/shared_ptr.h:175: std::__1::__shared_count::__release_shared[abi:v15003]() @ 0x17d59274 in /workspace/clickhouse
2022.11.11 18:21:31.115253 [ 401 ] {} BaseDaemon: 20. /build/build_docker/../contrib/libcxx/include/__memory/shared_ptr.h:215: std::__1::__shared_weak_count::__release_shared[abi:v15003]() @ 0x17d59219 in /workspace/clickhouse
2022.11.11 18:21:31.279521 [ 401 ] {} BaseDaemon: 21. /build/build_docker/../contrib/libcxx/include/__memory/shared_ptr.h:703: std::__1::shared_ptr::~shared_ptr[abi:v15003]() @ 0x26d9490c in /workspace/clickhouse
2022.11.11 18:21:31.464659 [ 401 ] {} BaseDaemon: 22. /build/build_docker/../contrib/libcxx/include/__memory/construct_at.h:64: void std::__1::__destroy_at[abi:v15003], 0>(std::__1::shared_ptr*) @ 0x26d98e2d in /workspace/clickhouse
2022.11.11 18:21:31.650185 [ 401 ] {} BaseDaemon: 23. /build/build_docker/../contrib/libcxx/include/__memory/construct_at.h:89: void std::__1::destroy_at[abi:v15003], 0>(std::__1::shared_ptr*) @ 0x26d98dd5 in /workspace/clickhouse
2022.11.11 18:21:31.823536 [ 401 ] {} BaseDaemon: 24. /build/build_docker/../contrib/libcxx/include/__memory/allocator_traits.h:321: void std::__1::allocator_traits>>::destroy[abi:v15003], void, void>(std::__1::allocator>&, std::__1::shared_ptr*) @ 0x26d98d39 in /workspace/clickhouse
2022.11.11 18:21:32.011961 [ 401 ] {} BaseDaemon: 25. /build/build_docker/../contrib/libcxx/include/vector:833: std::__1::vector, std::__1::allocator>>::__base_destruct_at_end[abi:v15003](std::__1::shared_ptr*) @ 0x26da53f8 in /workspace/clickhouse
2022.11.11 18:21:32.199382 [ 401 ] {} BaseDaemon: 26. /build/build_docker/../contrib/libcxx/include/vector:827: std::__1::vector, std::__1::allocator>>::__clear[abi:v15003]() @ 0x26da5398 in /workspace/clickhouse
2022.11.11 18:21:32.365993 [ 401 ] {} BaseDaemon: 27. /build/build_docker/../contrib/libcxx/include/vector:436: std::__1::vector, std::__1::allocator>>::~vector[abi:v15003]() @ 0x26d9683e in /workspace/clickhouse
2022.11.11 18:21:32.557645 [ 401 ] {} BaseDaemon: 28. /build/build_docker/../contrib/libcxx/include/__memory/construct_at.h:64: void std::__1::__destroy_at[abi:v15003], std::__1::allocator>>, 0>(std::__1::vector, std::__1::allocator>>*) @ 0x26da5e4d in /workspace/clickhouse
2022.11.11 18:21:32.750053 [ 401 ] {} BaseDaemon: 29. /build/build_docker/../contrib/libcxx/include/__memory/construct_at.h:89: void std::__1::destroy_at[abi:v15003], std::__1::allocator>>, 0>(std::__1::vector, std::__1::allocator>>*) @ 0x26da5df5 in /workspace/clickhouse
2022.11.11 18:21:32.938097 [ 401 ] {} BaseDaemon: 30. /build/build_docker/../contrib/libcxx/include/__memory/allocator_traits.h:321: void std::__1::allocator_traits, std::__1::allocator>>>>::destroy[abi:v15003], std::__1::allocator>>, void, void>(std::__1::allocator, std::__1::allocator>>>&, std::__1::vector, std::__1::allocator>>*) @ 0x26da5dd9 in /workspace/clickhouse
2022.11.11 18:21:33.126305 [ 401 ] {} BaseDaemon: 31. /build/build_docker/../contrib/libcxx/include/__memory/shared_ptr.h:309: std::__1::__shared_ptr_emplace, std::__1::allocator>>, std::__1::allocator, std::__1::allocator>>>>::__on_zero_shared() @ 0x26da5b0e in /workspace/clickhouse
2022.11.11 18:21:33.225387 [ 401 ] {} BaseDaemon: 32. /build/build_docker/../contrib/libcxx/include/__memory/shared_ptr.h:175: std::__1::__shared_count::__release_shared[abi:v15003]() @ 0x17d59274 in /workspace/clickhouse
2022.11.11 18:21:33.324508 [ 401 ] {} BaseDaemon: 33. /build/build_docker/../contrib/libcxx/include/__memory/shared_ptr.h:215: std::__1::__shared_weak_count::__release_shared[abi:v15003]() @ 0x17d59219 in /workspace/clickhouse
2022.11.11 18:21:33.713720 [ 401 ] {} BaseDaemon: 34. /build/build_docker/../contrib/libcxx/include/__memory/shared_ptr.h:703: std::__1::shared_ptr, std::__1::allocator>>>::~shared_ptr[abi:v15003]() @ 0x2069030c in /workspace/clickhouse
2022.11.11 18:21:33.868667 [ 401 ] {} BaseDaemon: 35. /build/build_docker/../src/QueryPipeline/QueryPipeline.cpp:40: DB::QueryPipeline::~QueryPipeline() @ 0x26db56d0 in /workspace/clickhouse
2022.11.11 18:21:34.025119 [ 401 ] {} BaseDaemon: 36. /build/build_docker/../src/QueryPipeline/QueryPipeline.cpp:546: DB::QueryPipeline::reset() @ 0x26db99a2 in /workspace/clickhouse
2022.11.11 18:21:34.278141 [ 401 ] {} BaseDaemon: 37. /build/build_docker/../src/QueryPipeline/BlockIO.h:48: DB::BlockIO::onException() @ 0x2868c06a in /workspace/clickhouse
2022.11.11 18:21:34.573290 [ 401 ] {} BaseDaemon: 38. /build/build_docker/../src/Server/TCPHandler.cpp:453: DB::TCPHandler::runImpl() @ 0x297e9024 in /workspace/clickhouse
2022.11.11 18:21:34.895077 [ 401 ] {} BaseDaemon: 39. /build/build_docker/../src/Server/TCPHandler.cpp:1902: DB::TCPHandler::run() @ 0x297f88c5 in /workspace/clickhouse
2022.11.11 18:21:34.959147 [ 401 ] {} BaseDaemon: 40. /build/build_docker/../contrib/poco/Net/src/TCPServerConnection.cpp:43: Poco::Net::TCPServerConnection::start() @ 0x2e34bc99 in /workspace/clickhouse
2022.11.11 18:21:35.030379 [ 401 ] {} BaseDaemon: 41. /build/build_docker/../contrib/poco/Net/src/TCPServerDispatcher.cpp:115: Poco::Net::TCPServerDispatcher::run() @ 0x2e34c4dc in /workspace/clickhouse
2022.11.11 18:21:35.107098 [ 401 ] {} BaseDaemon: 42. /build/build_docker/../contrib/poco/Foundation/src/ThreadPool.cpp:199: Poco::PooledThread::run() @ 0x2e59ba14 in /workspace/clickhouse
2022.11.11 18:21:35.180714 [ 401 ] {} BaseDaemon: 43. /build/build_docker/../contrib/poco/Foundation/src/Thread.cpp:56: Poco::(anonymous namespace)::RunnableHolder::run() @ 0x2e5987ba in /workspace/clickhouse
2022.11.11 18:21:35.253635 [ 401 ] {} BaseDaemon: 44. /build/build_docker/../contrib/poco/Foundation/src/Thread_POSIX.cpp:345: Poco::ThreadImpl::runnableEntry(void*) @ 0x2e59759e in /workspace/clickhouse
2022.11.11 18:21:36.480306 [ 401 ] {} BaseDaemon: Integrity check of the executable skipped because the reference checksum could not be read. (calculated checksum: EC7EF06506E70D829CED084DB53BBF7F)