Uploaded image for project: 'IMPALA'
  1. IMPALA
  2. IMPALA-3100

Runtime filter kenrel spinlock contention driven by memory allocation

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Critical
    • Resolution: Fixed
    • Impala 2.5.0
    • Impala 2.5.0
    • Backend
    • None

    Description

      It appears that runtime filters are causing high spinning in the kernel which is driven by memory allocation and deallocation of runtime filters.

      CPU Time
      1 of 14: 31.4% (1.150s of 3.668s)
      
      impalad ! base::internal::SpinLockDelay - [unknown source file]
      impalad ! SpinLock::SlowLock + 0xa6 - [unknown source file]
      impalad ! tcmalloc::CentralFreeList::InsertRange + 0x3f - [unknown source file]
      impalad ! tcmalloc::ThreadCache::ReleaseToCentralCache + 0x8d - [unknown source file]
      impalad ! tcmalloc::ThreadCache::Scavenge + 0x3e - [unknown source file]
      impalad ! operator delete + 0x2a3 - [unknown source file]
      impalad ! std::vector<std::string, std::allocator<std::string>>::~vector + 0x50 - [unknown source file]
      impalad ! impala::ImpalaInternalServiceProcessor::process_UpdateFilter + 0x319 - [unknown source file]
      impalad ! impala::ImpalaInternalServiceProcessor::dispatchCall + 0xe8 - [unknown source file]
      impalad ! apache::thrift::TDispatchProcessor::process + 0xab - [unknown source file]
      impalad ! apache::thrift::server::TThreadedServer::Task::run + 0x22e - [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 + 0x226 - [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@0xd30ef0 + 0xd9 - [unknown source file]
      libpthread.so.0 ! start_thread + 0xd0 - [unknown source file]
      libc.so.6 ! clone + 0x6c - [unknown source file]
      
      CPU Time
      2 of 14: 25.7% (0.943s of 3.668s)
      
      impalad ! base::internal::SpinLockDelay - [unknown source file]
      impalad ! SpinLock::SlowLock + 0xa6 - [unknown source file]
      impalad ! tcmalloc::CentralFreeList::RemoveRange + 0x43 - [unknown source file]
      impalad ! tcmalloc::ThreadCache::FetchFromCentralCache + 0x62 - [unknown source file]
      impalad ! tc_new + 0x407 - [unknown source file]
      libstdc++.so.6 ! std::string::_Rep::_S_create + 0x58 - [unknown source file]
      libstdc++.so.6 ! std::string::_M_mutate + 0x53 - [unknown source file]
      libstdc++.so.6 ! std::string::_M_replace_safe + 0x1d - [unknown source file]
      impalad ! apache::thrift::protocol::TBinaryProtocolT<apache::thrift::transport::TTransport>::readStringBody<std::string> + 0x5d - [unknown source file]
      impalad ! apache::thrift::protocol::TVirtualProtocol<apache::thrift::protocol::TBinaryProtocolT<apache::thrift::transport::TTransport>, apache::thrift::protocol::TProtocolDefaults>::readBinary_virt + 0x2d - [unknown source file]
      impalad ! impala::TBloomFilter::read + 0x1f5 - [unknown source file]
      impalad ! impala::TUpdateFilterParams::read + 0x14c - [unknown source file]
      impalad ! impala::ImpalaInternalService_UpdateFilter_args::read + 0xbc - [unknown source file]
      impalad ! impala::ImpalaInternalServiceProcessor::process_UpdateFilter + 0x119 - [unknown source file]
      impalad ! impala::ImpalaInternalServiceProcessor::dispatchCall + 0xe8 - [unknown source file]
      impalad ! apache::thrift::TDispatchProcessor::process + 0xab - [unknown source file]
      impalad ! apache::thrift::server::TThreadedServer::Task::run + 0x22e - [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 + 0x226 - [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@0xd30ef0 + 0xd9 - [unknown source file]
      libpthread.so.0 ! start_thread + 0xd0 - [unknown source file]
      libc.so.6 ! clone + 0x6c - [unknown source file]
      
      CPU Time
      5 of 14: 8.7% (0.321s of 3.668s)
      
      impalad ! base::internal::SpinLockDelay - [unknown source file]
      impalad ! SpinLock::SlowLock + 0xa6 - [unknown source file]
      impalad ! tcmalloc::CentralFreeList::ReleaseListToSpans + 0x1a - [unknown source file]
      impalad ! tcmalloc::CentralFreeList::InsertRange + 0x5c - [unknown source file]
      impalad ! tcmalloc::ThreadCache::ReleaseToCentralCache + 0x8d - [unknown source file]
      impalad ! tcmalloc::ThreadCache::Scavenge + 0x3e - [unknown source file]
      impalad ! operator delete + 0x2a3 - [unknown source file]
      impalad ! std::vector<std::string, std::allocator<std::string>>::~vector + 0x50 - [unknown source file]
      impalad ! impala::ImpalaInternalServiceProcessor::process_UpdateFilter + 0x319 - [unknown source file]
      impalad ! impala::ImpalaInternalServiceProcessor::dispatchCall + 0xe8 - [unknown source file]
      impalad ! apache::thrift::TDispatchProcessor::process + 0xab - [unknown source file]
      impalad ! apache::thrift::server::TThreadedServer::Task::run + 0x22e - [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 + 0x226 - [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@0xd30ef0 + 0xd9 - [unknown source file]
      libpthread.so.0 ! start_thread + 0xd0 - [unknown source file]
      libc.so.6 ! clone + 0x6c - [unknown source file]
      
      CPU Time
      1 of 13: 34.5% (0.620s of 1.795s)
      
      impalad ! base::internal::SpinLockWake - [unknown source file]
      impalad ! SpinLock::SlowUnlock + 0x13 - [unknown source file]
      impalad ! tcmalloc::ThreadCache::ReleaseToCentralCache + 0x8d - [unknown source file]
      impalad ! tcmalloc::ThreadCache::Scavenge + 0x3e - [unknown source file]
      impalad ! operator delete + 0x2a3 - [unknown source file]
      impalad ! std::vector<std::string, std::allocator<std::string>>::~vector + 0x50 - [unknown source file]
      impalad ! impala::ImpalaInternalServiceProcessor::process_UpdateFilter + 0x319 - [unknown source file]
      impalad ! impala::ImpalaInternalServiceProcessor::dispatchCall + 0xe8 - [unknown source file]
      impalad ! apache::thrift::TDispatchProcessor::process + 0xab - [unknown source file]
      impalad ! apache::thrift::server::TThreadedServer::Task::run + 0x22e - [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 + 0x226 - [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@0xd30ef0 + 0xd9 - [unknown source file]
      libpthread.so.0 ! start_thread + 0xd0 - [unknown source file]
      libc.so.6 ! clone + 0x6c - [unknown source file]
      
      CPU Time
      2 of 13: 23.3% (0.419s of 1.795s)
      
      impalad ! base::internal::SpinLockWake - [unknown source file]
      impalad ! SpinLock::SlowUnlock + 0x13 - [unknown source file]
      impalad ! tcmalloc::CentralFreeList::RemoveRange + 0xc6 - [unknown source file]
      impalad ! tcmalloc::ThreadCache::FetchFromCentralCache + 0x62 - [unknown source file]
      impalad ! tc_new + 0x407 - [unknown source file]
      libstdc++.so.6 ! std::string::_Rep::_S_create + 0x58 - [unknown source file]
      libstdc++.so.6 ! std::string::_M_mutate + 0x53 - [unknown source file]
      libstdc++.so.6 ! std::string::_M_replace_safe + 0x1d - [unknown source file]
      impalad ! apache::thrift::protocol::TBinaryProtocolT<apache::thrift::transport::TTransport>::readStringBody<std::string> + 0x5d - [unknown source file]
      impalad ! apache::thrift::protocol::TVirtualProtocol<apache::thrift::protocol::TBinaryProtocolT<apache::thrift::transport::TTransport>, apache::thrift::protocol::TProtocolDefaults>::readBinary_virt + 0x2d - [unknown source file]
      impalad ! impala::TBloomFilter::read + 0x1f5 - [unknown source file]
      impalad ! impala::TUpdateFilterParams::read + 0x14c - [unknown source file]
      impalad ! impala::ImpalaInternalService_UpdateFilter_args::read + 0xbc - [unknown source file]
      impalad ! impala::ImpalaInternalServiceProcessor::process_UpdateFilter + 0x119 - [unknown source file]
      impalad ! impala::ImpalaInternalServiceProcessor::dispatchCall + 0xe8 - [unknown source file]
      impalad ! apache::thrift::TDispatchProcessor::process + 0xab - [unknown source file]
      impalad ! apache::thrift::server::TThreadedServer::Task::run + 0x22e - [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 + 0x226 - [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@0xd30ef0 + 0xd9 - [unknown source file]
      libpthread.so.0 ! start_thread + 0xd0 - [unknown source file]
      libc.so.6 ! clone + 0x6c - [unknown source file]
      

      From perf

      -  29.05%        impalad  [kernel.kallsyms]        [k] _spin_lock                                                            
         - _spin_lock                                                                                                               
            - 53.23% futex_wake                                                                                                     
                 do_futex                                                                                                           
                 sys_futex                                                                                                          
               - system_call_fastpath                                                                                               
                  - 94.88% __lll_unlock_wake                                                                                        
                       34.13% 0x29                                                                                                  
                       32.69% 0                                                                                                     
                       17.37% 0x128e8180                                                                                            
                       15.81% 0x128de000                                                                                            
                  - 5.12% base::internal::SpinLockWake(int volatile*, bool)                                                         
                     - 100.00% SpinLock::SlowUnlock(unsigned long)                                                                  
                        + 55.82% tcmalloc::ThreadCache::ReleaseToCentralCache(tcmalloc::ThreadCache::FreeList*, unsigned long, int) 
                        + 43.08% tcmalloc::CentralFreeList::RemoveRange(void**, void**, int)                                        
                        + 0.57% tcmalloc::CentralFreeList::Populate()                                                               
                        + 0.52% tcmalloc::CentralFreeList::ReleaseToSpans(void*)                                                    
            - 43.80% futex_wait_setup                                                                                               
                 futex_wait                                                                                                         
                 do_futex                                                                                                           
                 sys_futex                                                                                                          
               - system_call_fastpath                                                                                               
                  + 89.47% __lll_lock_wait                                                                                          
                  - 10.53% base::internal::SpinLockDelay(int volatile*, int, int)                                                   
                     - 100.00% SpinLock::SlowLock()                                                                                 
                        + 53.81% tcmalloc::CentralFreeList::InsertRange(void*, void*, int)                                          
                        + 41.05% tcmalloc::CentralFreeList::RemoveRange(void**, void**, int)                                        
                        + 4.49% tcmalloc::CentralFreeList::ReleaseListToSpans(void*)                                                
                        + 0.66% tcmalloc::CentralFreeList::Populate()
      

      Attachments

        Issue Links

          Activity

            People

              henryr Henry Robinson
              mmokhtar Mostafa Mokhtar
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: