diff --git a/pc/connection_context.cc b/pc/connection_context.cc index 5f9dcb96aa..858f25ddb7 100644 --- a/pc/connection_context.cc +++ b/pc/connection_context.cc @@ -125,6 +125,14 @@ ConnectionContext::ConnectionContext( worker_thread(), network_thread()); channel_manager_->SetVideoRtxEnabled(true); + // Set warning levels on the threads, to give warnings when response + // may be slower than is expected of the thread. + // Since some of the threads may be the same, start with the least + // restrictive limits and end with the least permissive ones. + // This will give warnings for all cases. + signaling_thread_->SetDispatchWarningMs(100); + worker_thread_->SetDispatchWarningMs(30); + network_thread_->SetDispatchWarningMs(10); } ConnectionContext::~ConnectionContext() { diff --git a/rtc_base/thread.cc b/rtc_base/thread.cc index 1045398b4c..5a5c142c01 100644 --- a/rtc_base/thread.cc +++ b/rtc_base/thread.cc @@ -71,8 +71,6 @@ class ScopedAutoReleasePool { namespace rtc { namespace { -const int kSlowDispatchLoggingThreshold = 50; // 50 ms - class MessageHandlerWithTask final : public MessageHandler { public: MessageHandlerWithTask() {} @@ -681,14 +679,18 @@ void Thread::Dispatch(Message* pmsg) { TRACE_EVENT2("webrtc", "Thread::Dispatch", "src_file", pmsg->posted_from.file_name(), "src_func", pmsg->posted_from.function_name()); + RTC_DCHECK_RUN_ON(this); int64_t start_time = TimeMillis(); pmsg->phandler->OnMessage(pmsg); int64_t end_time = TimeMillis(); int64_t diff = TimeDiff(end_time, start_time); - if (diff >= kSlowDispatchLoggingThreshold) { - RTC_LOG(LS_INFO) << "Message took " << diff + if (diff >= dispatch_warning_ms_) { + RTC_LOG(LS_INFO) << "Message to " << name() << " took " << diff << "ms to dispatch. Posted from: " << pmsg->posted_from.ToString(); + // To avoid log spew, move the warning limit to only give warning + // for delays that are larger than the one observed. + dispatch_warning_ms_ = diff + 1; } } @@ -740,6 +742,16 @@ bool Thread::SetName(const std::string& name, const void* obj) { return true; } +void Thread::SetDispatchWarningMs(int deadline) { + if (!IsCurrent()) { + PostTask(webrtc::ToQueuedTask( + [this, deadline]() { SetDispatchWarningMs(deadline); })); + return; + } + RTC_DCHECK_RUN_ON(this); + dispatch_warning_ms_ = deadline; +} + bool Thread::Start() { RTC_DCHECK(!IsRunning()); diff --git a/rtc_base/thread.h b/rtc_base/thread.h index ed19e98927..e16d5d1dc2 100644 --- a/rtc_base/thread.h +++ b/rtc_base/thread.h @@ -290,6 +290,11 @@ class RTC_LOCKABLE RTC_EXPORT Thread : public webrtc::TaskQueueBase { const std::string& name() const { return name_; } bool SetName(const std::string& name, const void* obj); + // Sets the expected processing time in ms. The thread will write + // log messages when Invoke() takes more time than this. + // Default is 50 ms. + void SetDispatchWarningMs(int deadline); + // Starts the execution of the thread. bool Start(); @@ -525,6 +530,8 @@ class RTC_LOCKABLE RTC_EXPORT Thread : public webrtc::TaskQueueBase { RecursiveCriticalSection* CritForTest() { return &crit_; } private: + static const int kSlowDispatchLoggingThreshold = 50; // 50 ms + class QueuedTaskHandler final : public MessageHandler { public: QueuedTaskHandler() {} @@ -614,6 +621,8 @@ class RTC_LOCKABLE RTC_EXPORT Thread : public webrtc::TaskQueueBase { friend class ThreadManager; + int dispatch_warning_ms_ RTC_GUARDED_BY(this) = kSlowDispatchLoggingThreshold; + RTC_DISALLOW_COPY_AND_ASSIGN(Thread); };