[IMPALA-4603] Serializing large query profiles as part of ImpalaServer::UnregisterQuery can potentially cause slow downs

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Duplicate
• Affects Version/s: Impala 2.8.0
• Component/s: Distributed Exec
• Labels: multithreading scalability
• Assignee: Unassigned
• Reporter: Mostafa Mokhtar
• Created: 06/Dec/16 22:43
• Updated: 19/May/20 19:37
• Resolved: 19/May/20 19:36

Description

"Unregister query" can take a large percentage of overall query execution time mostly due to serializing the query profile, this occurs when executing queries with a large number of fragments and can likely get worse with Multi threading.

A stop gap solution would be to add a query option similar to FLAGS_log_query_to_file.

https://github.com/apache/incubator-impala/blob/e3483c44a3180a5c1f15a09f7c4f4f7b45ffcb44/be/src/service/impala-server.cc#L675

This is the call stack

impalad ! impala::RuntimeProfile::ToThrift + 0x691 - [unknown source file]
impalad ! impala::RuntimeProfile::SerializeToArchiveString + 0x5c - [unknown source file]
impalad ! impala::RuntimeProfile::SerializeToArchiveString + 0x1de - [unknown source file]
impalad ! impala::ImpalaServer::ArchiveQuery + 0x33 - [unknown source file]
impalad ! impala::ImpalaServer::UnregisterQuery + 0x3bd - [unknown source file]
impalad ! impala::ImpalaServer::close + 0x16f - [unknown source file]
impalad ! beeswax::BeeswaxServiceProcessor::process_close + 0x244 - [unknown source file]
impalad ! beeswax::BeeswaxServiceProcessor::dispatchCall + 0x113 - [unknown source file]
impalad ! apache::thrift::TDispatchProcessor::process + 0xab - [unknown source file]
impalad ! apache::thrift::server::TThreadPoolServer::Task::run + 0x22a - [unknown source file]
impalad ! apache::thrift::concurrency::ThreadManager::Worker::run + 0x2c8 - [unknown source file]
impalad ! impala::ThriftThread::RunRunnable + 0x68 - [unknown source file]
impalad ! boost::detail::function::void_function_obj_invoker0<boost::_bi::bind_t<void, boost::_mfi::mf2<void, impala::ThriftThread, boost::shared_ptr<apache::thrift::concurrency::Runnable>, impala::Promise<unsigned long>*>, boost::_bi::list3<boost::_bi::value<impala::ThriftThread*>, boost::_bi::value<boost::shared_ptr<apache::thrift::concurrency::Runnable>>, boost::_bi::value<impala::Promise<unsigned long>*>>>, void>::invoke + 0x61 - [unknown source file]
impalad ! impala::Thread::SuperviseThread + 0x228 - [unknown source file]
impalad ! boost::detail::thread_data<boost::_bi::bind_t<void, void (*)(std::string const&, std::string const&, boost::function<void (void)>, impala::Promise<long>*), boost::_bi::list4<boost::_bi::value<std::string>, boost::_bi::value<std::string>, boost::_bi::value<boost::function<void (void)>>, boost::_bi::value<impala::Promise<long>*>>>>::run + 0x73 - [unknown source file]
impalad ! func@0xe17ac0 + 0xd9 - [unknown source file]
libpthread-2.12.so ! start_thread + 0xd0 - [unknown source file]
libc-2.12.so ! clone + 0x6c - [unknown source file]

Some Unregister timings from TPC-DS queries on 200 node cluster
(9s418ms) query34.sql.1.out: - Unregister query: 44s035ms (9s418ms)
(9s054ms) query34.sql.3.out: - Unregister query: 43s112ms (9s054ms)
(8s480ms) query71.sql.1.out: - Unregister query: 20s803ms (8s480ms)

Issue Links

• duplicates: IMPALA-9378 CPU usage for runtime profiles with multithreading