[ 
https://issues.apache.org/jira/browse/KUDU-2727?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17125466#comment-17125466
 ] 

Alexey Serbin edited comment on KUDU-2727 at 6/4/20, 3:14 AM:
--------------------------------------------------------------

Another set of stacks, just for more context (captured with code close to kudu 
1.10.1):

{noformat}
  tids=[1866940]
      0x7fc8d67f95e0 <unknown>
           0x1ec35f4 base::internal::SpinLockDelay()
           0x1ec347c base::SpinLock::SlowLock()
            0xb68518 kudu::consensus::RaftConsensus::NotifyCommitIndex()
            0xb4c9e7 kudu::consensus::PeerMessageQueue::NotifyObserversTask()
            0xb47850 
_ZN4kudu8internal7InvokerILi2ENS0_9BindStateINS0_15RunnableAdapterIMNS_9consensus16PeerMessageQueueEFvRKSt8functionIFvPNS4_24PeerMessageQueueObserverEEEEEEFvPS5_SC_EFvNS0_17UnretainedWrapperIS5_EEZNS5_34NotifyObserversOfCommitIndexChangeElEUlS8_E_EEESH_E3RunEPNS0_13BindStateBaseE
           0x1eaedbf kudu::ThreadPool::DispatchThread()
           0x1ea4a84 kudu::Thread::SuperviseThread()
      0x7fc8d67f1e25 start_thread
      0x7fc8d4acf34d __clone
  
tids=[1370336,1370326,1370327,1370328,1370329,1370330,1370331,1370332,1370333,1370334,1370335,1370323,1370337,1370338,1370339,1370340,1370341,1370342,1370343,1370344,1370345,1370346,1370353,1370361,1370360,1370359,1370358,1370357,1370356,1370355,1370354,1370325,1370352,1370351,1370350,1370349,1370348,1370347,1370322,1370324]
      0x7fc8d67f95e0 <unknown>
           0x1ec35f4 base::internal::SpinLockDelay()
           0x1ec347c base::SpinLock::SlowLock()
            0xb7deb8 
kudu::consensus::RaftConsensus::CheckLeadershipAndBindTerm()
            0xaab010 kudu::tablet::TransactionDriver::ExecuteAsync()
            0xaa344c kudu::tablet::TabletReplica::SubmitWrite()
            0x928fb0 kudu::tserver::TabletServiceImpl::Write()
           0x1d2e8d9 kudu::rpc::GeneratedServiceIf::Handle()
           0x1d2efd9 kudu::rpc::ServicePool::RunThread()
           0x1ea4a84 kudu::Thread::SuperviseThread()
      0x7fc8d67f1e25 start_thread
      0x7fc8d4acf34d __clone
  tids=[1866932,1866929]
      0x7fc8d67f95e0 <unknown>
      0x7fc8d67f5943 __pthread_cond_wait
            0xb99b38 kudu::log::Log::AsyncAppend()
            0xb9c24c kudu::log::Log::AsyncAppendCommit()
            0xaad489 kudu::tablet::TransactionDriver::ApplyTask()
           0x1eaedbf kudu::ThreadPool::DispatchThread()
           0x1ea4a84 kudu::Thread::SuperviseThread()
      0x7fc8d67f1e25 start_thread
      0x7fc8d4acf34d __clone
  tids=[1866928]
      0x7fc8d67f95e0 <unknown>
      0x7fc8d67f5943 __pthread_cond_wait
            0xb99b38 kudu::log::Log::AsyncAppend()
            0xb9c493 kudu::log::Log::AsyncAppendReplicates()
            0xb597e9 kudu::consensus::LogCache::AppendOperations()
            0xb4fa24 kudu::consensus::PeerMessageQueue::AppendOperations()
            0xb4fd45 kudu::consensus::PeerMessageQueue::AppendOperation()
            0xb6f28c 
kudu::consensus::RaftConsensus::AppendNewRoundToQueueUnlocked()
            0xb7dff8 kudu::consensus::RaftConsensus::Replicate()
            0xaab8e7 kudu::tablet::TransactionDriver::Prepare()
            0xaac009 kudu::tablet::TransactionDriver::PrepareTask()
           0x1eaedbf kudu::ThreadPool::DispatchThread()
           0x1ea4a84 kudu::Thread::SuperviseThread()
{noformat}

In the stacks above, thread {{1866928}} is holding a lock taken in 
{{RaftConsensus::Replicate()}} while waiting on a condition variable in 
{{Log::AsyncAppend()}}, calling 
{{entry_batch_queue_.BlockingPut(entry_batch.get())}}.


was (Author: aserbin):
Another set of stacks, just for more context (captured with code close to kudu 
1.10.1):

{noformat}
  tids=[1866940]
      0x7fc8d67f95e0 <unknown>
           0x1ec35f4 base::internal::SpinLockDelay()
           0x1ec347c base::SpinLock::SlowLock()
            0xb68518 kudu::consensus::RaftConsensus::NotifyCommitIndex()
            0xb4c9e7 kudu::consensus::PeerMessageQueue::NotifyObserversTask()
            0xb47850 
_ZN4kudu8internal7InvokerILi2ENS0_9BindStateINS0_15RunnableAdapterIMNS_9consensus16PeerMessageQueueEFvRKSt8functionIFvPNS4_24PeerMessageQueueObserverEEEEEEFvPS5_SC_EFvNS0_17UnretainedWrapperIS5_EEZNS5_34NotifyObserversOfCommitIndexChangeElEUlS8_E_EEESH_E3RunEPNS0_13BindStateBaseE
           0x1eaedbf kudu::ThreadPool::DispatchThread()
           0x1ea4a84 kudu::Thread::SuperviseThread()
      0x7fc8d67f1e25 start_thread
      0x7fc8d4acf34d __clone
  
tids=[1370336,1370326,1370327,1370328,1370329,1370330,1370331,1370332,1370333,1370334,1370335,1370323,1370337,1370338,1370339,1370340,1370341,1370342,1370343,1370344,1370345,1370346,1370353,1370361,1370360,1370359,1370358,1370357,1370356,1370355,1370354,1370325,1370352,1370351,1370350,1370349,1370348,1370347,1370322,1370324]
      0x7fc8d67f95e0 <unknown>
           0x1ec35f4 base::internal::SpinLockDelay()
           0x1ec347c base::SpinLock::SlowLock()
            0xb7deb8 
kudu::consensus::RaftConsensus::CheckLeadershipAndBindTerm()
            0xaab010 kudu::tablet::TransactionDriver::ExecuteAsync()
            0xaa344c kudu::tablet::TabletReplica::SubmitWrite()
            0x928fb0 kudu::tserver::TabletServiceImpl::Write()
           0x1d2e8d9 kudu::rpc::GeneratedServiceIf::Handle()
           0x1d2efd9 kudu::rpc::ServicePool::RunThread()
           0x1ea4a84 kudu::Thread::SuperviseThread()
      0x7fc8d67f1e25 start_thread
      0x7fc8d4acf34d __clone
  tids=[1866932,1866929]
      0x7fc8d67f95e0 <unknown>
      0x7fc8d67f5943 __pthread_cond_wait
            0xb99b38 kudu::log::Log::AsyncAppend()
            0xb9c24c kudu::log::Log::AsyncAppendCommit()
            0xaad489 kudu::tablet::TransactionDriver::ApplyTask()
           0x1eaedbf kudu::ThreadPool::DispatchThread()
           0x1ea4a84 kudu::Thread::SuperviseThread()
      0x7fc8d67f1e25 start_thread
      0x7fc8d4acf34d __clone
  tids=[1866928]
      0x7fc8d67f95e0 <unknown>
      0x7fc8d67f5943 __pthread_cond_wait
            0xb99b38 kudu::log::Log::AsyncAppend()
            0xb9c493 kudu::log::Log::AsyncAppendReplicates()
            0xb597e9 kudu::consensus::LogCache::AppendOperations()
            0xb4fa24 kudu::consensus::PeerMessageQueue::AppendOperations()
            0xb4fd45 kudu::consensus::PeerMessageQueue::AppendOperation()
            0xb6f28c 
kudu::consensus::RaftConsensus::AppendNewRoundToQueueUnlocked()
            0xb7dff8 kudu::consensus::RaftConsensus::Replicate()
            0xaab8e7 kudu::tablet::TransactionDriver::Prepare()
            0xaac009 kudu::tablet::TransactionDriver::PrepareTask()
           0x1eaedbf kudu::ThreadPool::DispatchThread()
           0x1ea4a84 kudu::Thread::SuperviseThread()
{noformat}

> Contention on the Raft consensus lock can cause tablet service queue overflows
> ------------------------------------------------------------------------------
>
>                 Key: KUDU-2727
>                 URL: https://issues.apache.org/jira/browse/KUDU-2727
>             Project: Kudu
>          Issue Type: Improvement
>          Components: perf
>            Reporter: William Berkeley
>            Priority: Major
>
> Here's stacks illustrating the phenomenon:
> {noformat}
>   tids=[2201]
>         0x379ba0f710 <unknown>
>            0x1fb951a base::internal::SpinLockDelay()
>            0x1fb93b7 base::SpinLock::SlowLock()
>             0xb4e68e kudu::consensus::Peer::SignalRequest()
>             0xb9c0df kudu::consensus::PeerManager::SignalRequest()
>             0xb8c178 kudu::consensus::RaftConsensus::Replicate()
>             0xaab816 kudu::tablet::TransactionDriver::Prepare()
>             0xaac0ed kudu::tablet::TransactionDriver::PrepareTask()
>            0x1fa37ed kudu::ThreadPool::DispatchThread()
>            0x1f9c2a1 kudu::Thread::SuperviseThread()
>         0x379ba079d1 start_thread
>         0x379b6e88fd clone
>   tids=[4515]
>         0x379ba0f710 <unknown>
>            0x1fb951a base::internal::SpinLockDelay()
>            0x1fb93b7 base::SpinLock::SlowLock()
>             0xb74c60 kudu::consensus::RaftConsensus::NotifyCommitIndex()
>             0xb59307 kudu::consensus::PeerMessageQueue::NotifyObserversTask()
>             0xb54058 
> _ZN4kudu8internal7InvokerILi2ENS0_9BindStateINS0_15RunnableAdapterIMNS_9consensus16PeerMessageQueueEFvRKSt8functionIFvPNS4_24PeerMessageQueueObserverEEEEEEFvPS5_SC_EFvNS0_17UnretainedWrapperIS5_EEZNS5_34NotifyObserversOfCommitIndexChangeElEUlS8_E_EEESH_E3RunEPNS0_13BindStateBaseE
>            0x1fa37ed kudu::ThreadPool::DispatchThread()
>            0x1f9c2a1 kudu::Thread::SuperviseThread()
>         0x379ba079d1 start_thread
>         0x379b6e88fd clone
>   tids=[22185,22194,22193,22188,22187,22186]
>         0x379ba0f710 <unknown>
>            0x1fb951a base::internal::SpinLockDelay()
>            0x1fb93b7 base::SpinLock::SlowLock()
>             0xb8bff8 
> kudu::consensus::RaftConsensus::CheckLeadershipAndBindTerm()
>             0xaaaef9 kudu::tablet::TransactionDriver::ExecuteAsync()
>             0xaa3742 kudu::tablet::TabletReplica::SubmitWrite()
>             0x92812d kudu::tserver::TabletServiceImpl::Write()
>            0x1e28f3c kudu::rpc::GeneratedServiceIf::Handle()
>            0x1e2986a kudu::rpc::ServicePool::RunThread()
>            0x1f9c2a1 kudu::Thread::SuperviseThread()
>         0x379ba079d1 start_thread
>         0x379b6e88fd clone
>   tids=[22192,22191]
>         0x379ba0f710 <unknown>
>            0x1fb951a base::internal::SpinLockDelay()
>            0x1fb93b7 base::SpinLock::SlowLock()
>            0x1e13dec kudu::rpc::ResultTracker::TrackRpc()
>            0x1e28ef5 kudu::rpc::GeneratedServiceIf::Handle()
>            0x1e2986a kudu::rpc::ServicePool::RunThread()
>            0x1f9c2a1 kudu::Thread::SuperviseThread()
>         0x379ba079d1 start_thread
>         0x379b6e88fd clone
>   tids=[4426]
>         0x379ba0f710 <unknown>
>            0x206d3d0 <unknown>
>            0x212fd25 google::protobuf::Message::SpaceUsedLong()
>            0x211dee4 
> google::protobuf::internal::GeneratedMessageReflection::SpaceUsedLong()
>             0xb6658e kudu::consensus::LogCache::AppendOperations()
>             0xb5c539 kudu::consensus::PeerMessageQueue::AppendOperations()
>             0xb5c7c7 kudu::consensus::PeerMessageQueue::AppendOperation()
>             0xb7c675 
> kudu::consensus::RaftConsensus::AppendNewRoundToQueueUnlocked()
>             0xb8c147 kudu::consensus::RaftConsensus::Replicate()
>             0xaab816 kudu::tablet::TransactionDriver::Prepare()
>             0xaac0ed kudu::tablet::TransactionDriver::PrepareTask()
>            0x1fa37ed kudu::ThreadPool::DispatchThread()
>            0x1f9c2a1 kudu::Thread::SuperviseThread()
>         0x379ba079d1 start_thread
>         0x379b6e88fd clone
> {noformat}
> {{kudu::consensus::RaftConsensus::CheckLeadershipAndBindTerm()}} needs to 
> take the lock to check the term and the Raft role. When many RPCs come in for 
> the same tablet, the contention can hog service threads and cause queue 
> overflows on busy systems.
> Yugabyte switched their equivalent lock to be an atomic that allows them to 
> read the term and role wait-free.



--
This message was sent by Atlassian Jira
(v8.3.4#803005)

Reply via email to