From 674b0c81115c686f9bd9a140a92f00c77e0384f7 Mon Sep 17 00:00:00 2001 From: Tommi Date: Sun, 10 May 2020 21:52:17 +0200 Subject: [PATCH] Move ReceiveStatisticsProxy stats variables to the worker thread. This reduces locking on the decoder thread and moves all stats management to the worker thread, which also avoids contention between querying for these stats and the threads where the media processing happens.. Bug: webrtc:11489,webrtc:11490 Change-Id: I802577eab6b48edcbe124c02a1b793a640b74181 Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/174205 Commit-Queue: Tommi Reviewed-by: Rasmus Brandt Cr-Commit-Position: refs/heads/master@{#31202} --- video/call_stats.h | 2 + video/receive_statistics_proxy2.cc | 199 ++++++++++---------- video/receive_statistics_proxy2.h | 75 ++++---- video/receive_statistics_proxy2_unittest.cc | 34 ++-- video/video_receive_stream2.cc | 10 +- 5 files changed, 158 insertions(+), 162 deletions(-) diff --git a/video/call_stats.h b/video/call_stats.h index 5029453bf7..80030012b6 100644 --- a/video/call_stats.h +++ b/video/call_stats.h @@ -25,6 +25,8 @@ namespace webrtc { // CallStats keeps track of statistics for a call. +// TODO(webrtc:11489): Make call_stats_ not depend on ProcessThread and +// make callbacks on the worker thread (TQ). class CallStats : public Module, public RtcpRttStats { public: // Time interval for updating the observers. diff --git a/video/receive_statistics_proxy2.cc b/video/receive_statistics_proxy2.cc index cafea6c868..0fda7c8aee 100644 --- a/video/receive_statistics_proxy2.cc +++ b/video/receive_statistics_proxy2.cc @@ -115,7 +115,6 @@ ReceiveStatisticsProxy::ReceiveStatisticsProxy( video_quality_observer_(new VideoQualityObserver()), interframe_delay_max_moving_(kMovingMaxWindowMs), freq_offset_counter_(clock, nullptr, kFreqOffsetProcessIntervalMs), - avg_rtt_ms_(0), last_content_type_(VideoContentType::UNSPECIFIED), last_codec_type_(kVideoCodecVP8), num_delayed_frames_rendered_(0), @@ -139,17 +138,11 @@ void ReceiveStatisticsProxy::UpdateHistograms( const StreamDataCounters* rtx_stats) { RTC_DCHECK_RUN_ON(&main_thread_); - // TODO(bugs.webrtc.org/11489): Many of these variables don't need to be - // inside the scope of a lock. Also consider grabbing the lock only to copy - // the state that histograms need to be reported for, then report histograms - // while not holding the lock. char log_stream_buf[8 * 1024]; rtc::SimpleStringBuilder log_stream(log_stream_buf); int stream_duration_sec = (clock_->TimeInMilliseconds() - start_ms_) / 1000; - rtc::CritScope lock(&crit_); - if (stats_.frame_counts.key_frames > 0 || stats_.frame_counts.delta_frames > 0) { RTC_HISTOGRAM_COUNTS_100000("WebRTC.Video.ReceiveStreamLifetimeInSeconds", @@ -241,18 +234,12 @@ void ReceiveStatisticsProxy::UpdateHistograms( << key_frames_permille << '\n'; } - { - // We're not actually running on the decoder thread, but this function must - // be called after DecoderThreadStopped, which detaches the thread checker. - // It is therefore safe to access |qp_counters_|, which were updated on the - // decode thread earlier. - RTC_DCHECK_RUN_ON(&decode_queue_); - absl::optional qp = qp_counters_.vp8.Avg(kMinRequiredSamples); - if (qp) { - RTC_HISTOGRAM_COUNTS_200("WebRTC.Video.Decoded.Vp8.Qp", *qp); - log_stream << "WebRTC.Video.Decoded.Vp8.Qp " << *qp << '\n'; - } + absl::optional qp = qp_counters_.vp8.Avg(kMinRequiredSamples); + if (qp) { + RTC_HISTOGRAM_COUNTS_200("WebRTC.Video.Decoded.Vp8.Qp", *qp); + log_stream << "WebRTC.Video.Decoded.Vp8.Qp " << *qp << '\n'; } + absl::optional decode_ms = decode_time_counter_.Avg(kMinRequiredSamples); if (decode_ms) { RTC_HISTOGRAM_COUNTS_1000("WebRTC.Video.DecodeTimeInMs", *decode_ms); @@ -579,7 +566,6 @@ void ReceiveStatisticsProxy::UpdateFramerate(int64_t now_ms) const { size_t framerate = (frame_window_.size() * 1000 + 500) / kRateStatisticsWindowSizeMs; - rtc::CritScope lock(&crit_); stats_.network_frame_rate = static_cast(framerate); } @@ -664,7 +650,6 @@ VideoReceiveStream::Stats ReceiveStatisticsProxy::GetStats() const { int64_t now_ms = clock_->TimeInMilliseconds(); UpdateFramerate(now_ms); - rtc::CritScope lock(&crit_); stats_.render_frame_rate = renders_fps_estimator_.Rate(now_ms).value_or(0); stats_.decode_frame_rate = decode_fps_estimator_.Rate(now_ms).value_or(0); @@ -704,17 +689,21 @@ VideoReceiveStream::Stats ReceiveStatisticsProxy::GetStats() const { void ReceiveStatisticsProxy::OnIncomingPayloadType(int payload_type) { RTC_DCHECK_RUN_ON(&decode_queue_); - rtc::CritScope lock(&crit_); - stats_.current_payload_type = payload_type; + worker_thread_->PostTask( + ToQueuedTask(task_safety_flag_, [payload_type, this]() { + RTC_DCHECK_RUN_ON(&main_thread_); + stats_.current_payload_type = payload_type; + })); } void ReceiveStatisticsProxy::OnDecoderImplementationName( const char* implementation_name) { RTC_DCHECK_RUN_ON(&decode_queue_); - // TODO(bugs.webrtc.org/11489): is a lock needed for this variable? Currently - // seems to be only touched on the decoder queue. - rtc::CritScope lock(&crit_); - stats_.decoder_implementation_name = implementation_name; + worker_thread_->PostTask(ToQueuedTask( + task_safety_flag_, [name = std::string(implementation_name), this]() { + RTC_DCHECK_RUN_ON(&main_thread_); + stats_.decoder_implementation_name = name; + })); } void ReceiveStatisticsProxy::OnFrameBufferTimingsUpdated( @@ -725,46 +714,52 @@ void ReceiveStatisticsProxy::OnFrameBufferTimingsUpdated( int min_playout_delay_ms, int render_delay_ms) { RTC_DCHECK_RUN_ON(&decode_queue_); - rtc::CritScope lock(&crit_); - stats_.max_decode_ms = max_decode_ms; - stats_.current_delay_ms = current_delay_ms; - stats_.target_delay_ms = target_delay_ms; - stats_.jitter_buffer_ms = jitter_buffer_ms; - stats_.min_playout_delay_ms = min_playout_delay_ms; - stats_.render_delay_ms = render_delay_ms; - jitter_buffer_delay_counter_.Add(jitter_buffer_ms); - target_delay_counter_.Add(target_delay_ms); - current_delay_counter_.Add(current_delay_ms); - // Network delay (rtt/2) + target_delay_ms (jitter delay + decode time + - // render delay). - delay_counter_.Add(target_delay_ms + avg_rtt_ms_ / 2); + worker_thread_->PostTask(ToQueuedTask( + task_safety_flag_, + [max_decode_ms, current_delay_ms, target_delay_ms, jitter_buffer_ms, + min_playout_delay_ms, render_delay_ms, this]() { + RTC_DCHECK_RUN_ON(&main_thread_); + stats_.max_decode_ms = max_decode_ms; + stats_.current_delay_ms = current_delay_ms; + stats_.target_delay_ms = target_delay_ms; + stats_.jitter_buffer_ms = jitter_buffer_ms; + stats_.min_playout_delay_ms = min_playout_delay_ms; + stats_.render_delay_ms = render_delay_ms; + jitter_buffer_delay_counter_.Add(jitter_buffer_ms); + target_delay_counter_.Add(target_delay_ms); + current_delay_counter_.Add(current_delay_ms); + // Network delay (rtt/2) + target_delay_ms (jitter delay + decode time + + // render delay). + delay_counter_.Add(target_delay_ms + avg_rtt_ms_ / 2); + })); } void ReceiveStatisticsProxy::OnUniqueFramesCounted(int num_unique_frames) { RTC_DCHECK_RUN_ON(&main_thread_); - rtc::CritScope lock(&crit_); num_unique_frames_.emplace(num_unique_frames); } void ReceiveStatisticsProxy::OnTimingFrameInfoUpdated( const TimingFrameInfo& info) { RTC_DCHECK_RUN_ON(&decode_queue_); - rtc::CritScope lock(&crit_); - if (info.flags != VideoSendTiming::kInvalid) { - int64_t now_ms = clock_->TimeInMilliseconds(); - timing_frame_info_counter_.Add(info, now_ms); - } + worker_thread_->PostTask(ToQueuedTask(task_safety_flag_, [info, this]() { + RTC_DCHECK_RUN_ON(&main_thread_); + if (info.flags != VideoSendTiming::kInvalid) { + int64_t now_ms = clock_->TimeInMilliseconds(); + timing_frame_info_counter_.Add(info, now_ms); + } - // Measure initial decoding latency between the first frame arriving and the - // first frame being decoded. - if (!first_frame_received_time_ms_.has_value()) { - first_frame_received_time_ms_ = info.receive_finish_ms; - } - if (stats_.first_frame_received_to_decoded_ms == -1 && - first_decoded_frame_time_ms_) { - stats_.first_frame_received_to_decoded_ms = - *first_decoded_frame_time_ms_ - *first_frame_received_time_ms_; - } + // Measure initial decoding latency between the first frame arriving and + // the first frame being decoded. + if (!first_frame_received_time_ms_.has_value()) { + first_frame_received_time_ms_ = info.receive_finish_ms; + } + if (stats_.first_frame_received_to_decoded_ms == -1 && + first_decoded_frame_time_ms_) { + stats_.first_frame_received_to_decoded_ms = + *first_decoded_frame_time_ms_ - *first_frame_received_time_ms_; + } + })); } void ReceiveStatisticsProxy::RtcpPacketTypesCounterUpdated( @@ -793,7 +788,6 @@ void ReceiveStatisticsProxy::RtcpPacketTypesCounterUpdated( } RTC_DCHECK_RUN_ON(&main_thread_); - rtc::CritScope lock(&crit_); stats_.rtcp_packet_type_counts = packet_counter; } @@ -804,7 +798,6 @@ void ReceiveStatisticsProxy::OnCname(uint32_t ssrc, absl::string_view cname) { if (remote_ssrc_ != ssrc) return; - rtc::CritScope lock(&crit_); stats_.c_name = std::string(cname); } @@ -816,12 +809,10 @@ void ReceiveStatisticsProxy::OnDecodedFrame(const VideoFrame& frame, // may be on. E.g. on iOS this gets called on // "com.apple.coremedia.decompressionsession.clientcallback" VideoFrameMetaData meta(frame, clock_->CurrentTime()); - worker_thread_->PostTask(ToQueuedTask([safety = task_safety_flag_, meta, qp, - decode_time_ms, content_type, this]() { - if (!safety->alive()) - return; - OnDecodedFrame(meta, qp, decode_time_ms, content_type); - })); + worker_thread_->PostTask(ToQueuedTask( + task_safety_flag_, [meta, qp, decode_time_ms, content_type, this]() { + OnDecodedFrame(meta, qp, decode_time_ms, content_type); + })); } void ReceiveStatisticsProxy::OnDecodedFrame( @@ -843,12 +834,12 @@ void ReceiveStatisticsProxy::OnDecodedFrame( video_quality_observer_.reset(new VideoQualityObserver()); } - rtc::CritScope lock(&crit_); video_quality_observer_->OnDecodedFrame(frame_meta.rtp_timestamp, qp, last_codec_type_); ContentSpecificStats* content_specific_stats = &content_specific_stats_[content_type]; + ++stats_.frames_decoded; if (qp) { if (!stats_.qp_sum) { @@ -905,17 +896,16 @@ void ReceiveStatisticsProxy::OnRenderedFrame( RTC_DCHECK_GT(frame_meta.width, 0); RTC_DCHECK_GT(frame_meta.height, 0); - // TODO(bugs.webrtc.org/11489): Remove lock once sync isn't needed. - rtc::CritScope lock(&crit_); - video_quality_observer_->OnRenderedFrame(frame_meta); ContentSpecificStats* content_specific_stats = &content_specific_stats_[last_content_type_]; renders_fps_estimator_.Update(1, frame_meta.decode_timestamp.ms()); + ++stats_.frames_rendered; stats_.width = frame_meta.width; stats_.height = frame_meta.height; + render_fps_tracker_.AddSamples(1); render_pixel_tracker_.AddSamples(sqrt(frame_meta.width * frame_meta.height)); content_specific_stats->received_width.Add(frame_meta.width); @@ -936,6 +926,7 @@ void ReceiveStatisticsProxy::OnRenderedFrame( content_specific_stats->e2e_delay_counter.Add(delay_ms); } } + QualitySample(frame_meta.decode_timestamp); } @@ -943,28 +934,32 @@ void ReceiveStatisticsProxy::OnSyncOffsetUpdated(int64_t video_playout_ntp_ms, int64_t sync_offset_ms, double estimated_freq_khz) { RTC_DCHECK_RUN_ON(&incoming_render_queue_); - rtc::CritScope lock(&crit_); - // TODO(bugs.webrtc.org/11489): Lock possibly not needed for - // sync_offset_counter_ if it's only touched on the decoder thread. - sync_offset_counter_.Add(std::abs(sync_offset_ms)); - stats_.sync_offset_ms = sync_offset_ms; - last_estimated_playout_ntp_timestamp_ms_ = video_playout_ntp_ms; - last_estimated_playout_time_ms_ = clock_->TimeInMilliseconds(); + int64_t now_ms = clock_->TimeInMilliseconds(); + worker_thread_->PostTask( + ToQueuedTask(task_safety_flag_, [video_playout_ntp_ms, sync_offset_ms, + estimated_freq_khz, now_ms, this]() { + RTC_DCHECK_RUN_ON(&main_thread_); + sync_offset_counter_.Add(std::abs(sync_offset_ms)); + stats_.sync_offset_ms = sync_offset_ms; + last_estimated_playout_ntp_timestamp_ms_ = video_playout_ntp_ms; + last_estimated_playout_time_ms_ = now_ms; - const double kMaxFreqKhz = 10000.0; - int offset_khz = kMaxFreqKhz; - // Should not be zero or negative. If so, report max. - if (estimated_freq_khz < kMaxFreqKhz && estimated_freq_khz > 0.0) - offset_khz = static_cast(std::fabs(estimated_freq_khz - 90.0) + 0.5); + const double kMaxFreqKhz = 10000.0; + int offset_khz = kMaxFreqKhz; + // Should not be zero or negative. If so, report max. + if (estimated_freq_khz < kMaxFreqKhz && estimated_freq_khz > 0.0) + offset_khz = + static_cast(std::fabs(estimated_freq_khz - 90.0) + 0.5); - freq_offset_counter_.Add(offset_khz); + freq_offset_counter_.Add(offset_khz); + })); } void ReceiveStatisticsProxy::OnCompleteFrame(bool is_keyframe, size_t size_bytes, VideoContentType content_type) { RTC_DCHECK_RUN_ON(&main_thread_); - rtc::CritScope lock(&crit_); + if (is_keyframe) { ++stats_.frame_counts.key_frames; } else { @@ -994,18 +989,25 @@ void ReceiveStatisticsProxy::OnCompleteFrame(bool is_keyframe, } void ReceiveStatisticsProxy::OnDroppedFrames(uint32_t frames_dropped) { - rtc::CritScope lock(&crit_); - stats_.frames_dropped += frames_dropped; + RTC_DCHECK_RUN_ON(&decode_queue_); + worker_thread_->PostTask( + ToQueuedTask(task_safety_flag_, [frames_dropped, this]() { + RTC_DCHECK_RUN_ON(&main_thread_); + stats_.frames_dropped += frames_dropped; + })); } void ReceiveStatisticsProxy::OnPreDecode(VideoCodecType codec_type, int qp) { RTC_DCHECK_RUN_ON(&decode_queue_); - rtc::CritScope lock(&crit_); - last_codec_type_ = codec_type; - if (last_codec_type_ == kVideoCodecVP8 && qp != -1) { - qp_counters_.vp8.Add(qp); - qp_sample_.Add(qp); - } + worker_thread_->PostTask( + ToQueuedTask(task_safety_flag_, [codec_type, qp, this]() { + RTC_DCHECK_RUN_ON(&main_thread_); + last_codec_type_ = codec_type; + if (last_codec_type_ == kVideoCodecVP8 && qp != -1) { + qp_counters_.vp8.Add(qp); + qp_sample_.Add(qp); + } + })); } void ReceiveStatisticsProxy::OnStreamInactive() { @@ -1019,18 +1021,13 @@ void ReceiveStatisticsProxy::OnStreamInactive() { video_quality_observer_->OnStreamInactive(); } -void ReceiveStatisticsProxy::OnRttUpdate(int64_t avg_rtt_ms, - int64_t max_rtt_ms) { - // TODO(bugs.webrtc.org/11489): Is this a duplicate of - // VideoReceiveStream::OnRttUpdate? - // - looks like that runs on a/the module process thread. - // - - // BUGBUG - // Actually, it looks like this method is never called except from a unit - // test, GetStatsReportsDecodeTimingStats. - rtc::CritScope lock(&crit_); - avg_rtt_ms_ = avg_rtt_ms; +void ReceiveStatisticsProxy::OnRttUpdate(int64_t avg_rtt_ms) { + // TODO(bugs.webrtc.org/11489): This method is currently never called except + // from a unit test, GetStatsReportsDecodeTimingStats, and even then it has no + // effect. Once 11490 items in video_receive_stream2.cc have been addressed, + // we can uncomment the following: + // RTC_DCHECK_RUN_ON(&main_thread_); + // avg_rtt_ms_ = avg_rtt_ms; } void ReceiveStatisticsProxy::DecoderThreadStarting() { diff --git a/video/receive_statistics_proxy2.h b/video/receive_statistics_proxy2.h index 6e6826628c..d6f6f1cc21 100644 --- a/video/receive_statistics_proxy2.h +++ b/video/receive_statistics_proxy2.h @@ -22,7 +22,6 @@ #include "call/video_receive_stream.h" #include "modules/include/module_common_types.h" #include "modules/video_coding/include/video_coding_defines.h" -#include "rtc_base/critical_section.h" #include "rtc_base/numerics/histogram_percentile_counter.h" #include "rtc_base/numerics/moving_max_counter.h" #include "rtc_base/numerics/sample_counter.h" @@ -47,8 +46,7 @@ struct VideoFrameMetaData; class ReceiveStatisticsProxy : public VCMReceiveStatisticsCallback, public RtcpCnameCallback, - public RtcpPacketTypeCounterObserver, - public CallStatsObserver { + public RtcpPacketTypeCounterObserver { public: ReceiveStatisticsProxy(const VideoReceiveStream::Config* config, Clock* clock, @@ -106,8 +104,7 @@ class ReceiveStatisticsProxy : public VCMReceiveStatisticsCallback, uint32_t ssrc, const RtcpPacketTypeCounter& packet_counter) override; - // Implements CallStatsObserver. - void OnRttUpdate(int64_t avg_rtt_ms, int64_t max_rtt_ms) override; + void OnRttUpdate(int64_t avg_rtt_ms); // Notification methods that are used to check our internal state and validate // threading assumptions. These are called by VideoReceiveStream. @@ -142,73 +139,73 @@ class ReceiveStatisticsProxy : public VCMReceiveStatisticsCallback, rtc::HistogramPercentileCounter interframe_delay_percentiles; }; - void QualitySample(Timestamp now) RTC_EXCLUSIVE_LOCKS_REQUIRED(crit_); + void QualitySample(Timestamp now); // Removes info about old frames and then updates the framerate. void UpdateFramerate(int64_t now_ms) const; void UpdateDecodeTimeHistograms(int width, int height, - int decode_time_ms) const - RTC_EXCLUSIVE_LOCKS_REQUIRED(crit_); + int decode_time_ms) const; absl::optional GetCurrentEstimatedPlayoutNtpTimestampMs( - int64_t now_ms) const RTC_EXCLUSIVE_LOCKS_REQUIRED(crit_); + int64_t now_ms) const; Clock* const clock_; const int64_t start_ms_; const bool enable_decode_time_histograms_; - rtc::CriticalSection crit_; int64_t last_sample_time_ RTC_GUARDED_BY(main_thread_); QualityThreshold fps_threshold_ RTC_GUARDED_BY(main_thread_); - QualityThreshold qp_threshold_ RTC_GUARDED_BY(crit_); - QualityThreshold variance_threshold_ RTC_GUARDED_BY(crit_); - rtc::SampleCounter qp_sample_ RTC_GUARDED_BY(crit_); - int num_bad_states_ RTC_GUARDED_BY(crit_); - int num_certain_states_ RTC_GUARDED_BY(crit_); + QualityThreshold qp_threshold_ RTC_GUARDED_BY(main_thread_); + QualityThreshold variance_threshold_ RTC_GUARDED_BY(main_thread_); + rtc::SampleCounter qp_sample_ RTC_GUARDED_BY(main_thread_); + int num_bad_states_ RTC_GUARDED_BY(main_thread_); + int num_certain_states_ RTC_GUARDED_BY(main_thread_); // Note: The |stats_.rtp_stats| member is not used or populated by this class. - mutable VideoReceiveStream::Stats stats_ RTC_GUARDED_BY(crit_); + mutable VideoReceiveStream::Stats stats_ RTC_GUARDED_BY(main_thread_); // Same as stats_.ssrc, but const (no lock required). const uint32_t remote_ssrc_; - RateStatistics decode_fps_estimator_ RTC_GUARDED_BY(crit_); - RateStatistics renders_fps_estimator_ RTC_GUARDED_BY(crit_); - rtc::RateTracker render_fps_tracker_ RTC_GUARDED_BY(crit_); - rtc::RateTracker render_pixel_tracker_ RTC_GUARDED_BY(crit_); - rtc::SampleCounter sync_offset_counter_ RTC_GUARDED_BY(crit_); - rtc::SampleCounter decode_time_counter_ RTC_GUARDED_BY(crit_); - rtc::SampleCounter jitter_buffer_delay_counter_ RTC_GUARDED_BY(crit_); - rtc::SampleCounter target_delay_counter_ RTC_GUARDED_BY(crit_); - rtc::SampleCounter current_delay_counter_ RTC_GUARDED_BY(crit_); - rtc::SampleCounter delay_counter_ RTC_GUARDED_BY(crit_); + RateStatistics decode_fps_estimator_ RTC_GUARDED_BY(main_thread_); + RateStatistics renders_fps_estimator_ RTC_GUARDED_BY(main_thread_); + rtc::RateTracker render_fps_tracker_ RTC_GUARDED_BY(main_thread_); + rtc::RateTracker render_pixel_tracker_ RTC_GUARDED_BY(main_thread_); + rtc::SampleCounter sync_offset_counter_ RTC_GUARDED_BY(main_thread_); + rtc::SampleCounter decode_time_counter_ RTC_GUARDED_BY(main_thread_); + rtc::SampleCounter jitter_buffer_delay_counter_ RTC_GUARDED_BY(main_thread_); + rtc::SampleCounter target_delay_counter_ RTC_GUARDED_BY(main_thread_); + rtc::SampleCounter current_delay_counter_ RTC_GUARDED_BY(main_thread_); + rtc::SampleCounter delay_counter_ RTC_GUARDED_BY(main_thread_); std::unique_ptr video_quality_observer_ RTC_GUARDED_BY(main_thread_); mutable rtc::MovingMaxCounter interframe_delay_max_moving_ RTC_GUARDED_BY(main_thread_); std::map content_specific_stats_ - RTC_GUARDED_BY(crit_); - MaxCounter freq_offset_counter_ RTC_GUARDED_BY(crit_); - QpCounters qp_counters_ RTC_GUARDED_BY(decode_queue_); - int64_t avg_rtt_ms_ RTC_GUARDED_BY(crit_); + RTC_GUARDED_BY(main_thread_); + MaxCounter freq_offset_counter_ RTC_GUARDED_BY(main_thread_); + QpCounters qp_counters_ RTC_GUARDED_BY(main_thread_); + int64_t avg_rtt_ms_ RTC_GUARDED_BY(main_thread_) = 0; mutable std::map frame_window_ RTC_GUARDED_BY(main_thread_); VideoContentType last_content_type_ RTC_GUARDED_BY(&main_thread_); - VideoCodecType last_codec_type_ RTC_GUARDED_BY(&crit_); - absl::optional first_frame_received_time_ms_ RTC_GUARDED_BY(&crit_); - absl::optional first_decoded_frame_time_ms_ RTC_GUARDED_BY(&crit_); + VideoCodecType last_codec_type_ RTC_GUARDED_BY(main_thread_); + absl::optional first_frame_received_time_ms_ + RTC_GUARDED_BY(main_thread_); + absl::optional first_decoded_frame_time_ms_ + RTC_GUARDED_BY(main_thread_); absl::optional last_decoded_frame_time_ms_ RTC_GUARDED_BY(main_thread_); - size_t num_delayed_frames_rendered_ RTC_GUARDED_BY(&crit_); - int64_t sum_missed_render_deadline_ms_ RTC_GUARDED_BY(&crit_); + size_t num_delayed_frames_rendered_ RTC_GUARDED_BY(main_thread_); + int64_t sum_missed_render_deadline_ms_ RTC_GUARDED_BY(main_thread_); // Mutable because calling Max() on MovingMaxCounter is not const. Yet it is // called from const GetStats(). mutable rtc::MovingMaxCounter timing_frame_info_counter_ - RTC_GUARDED_BY(&crit_); - absl::optional num_unique_frames_ RTC_GUARDED_BY(crit_); + RTC_GUARDED_BY(main_thread_); + absl::optional num_unique_frames_ RTC_GUARDED_BY(main_thread_); absl::optional last_estimated_playout_ntp_timestamp_ms_ - RTC_GUARDED_BY(&crit_); + RTC_GUARDED_BY(main_thread_); absl::optional last_estimated_playout_time_ms_ - RTC_GUARDED_BY(&crit_); + RTC_GUARDED_BY(main_thread_); // The thread on which this instance is constructed and some of its main // methods are invoked on such as GetStats(). diff --git a/video/receive_statistics_proxy2_unittest.cc b/video/receive_statistics_proxy2_unittest.cc index 90c6a32435..867a3c337f 100644 --- a/video/receive_statistics_proxy2_unittest.cc +++ b/video/receive_statistics_proxy2_unittest.cc @@ -469,12 +469,14 @@ TEST_F(ReceiveStatisticsProxy2Test, GetStatsReportsSsrc) { TEST_F(ReceiveStatisticsProxy2Test, GetStatsReportsIncomingPayloadType) { const int kPayloadType = 111; statistics_proxy_->OnIncomingPayloadType(kPayloadType); + loop_.Flush(); EXPECT_EQ(kPayloadType, statistics_proxy_->GetStats().current_payload_type); } TEST_F(ReceiveStatisticsProxy2Test, GetStatsReportsDecoderImplementationName) { const char* kName = "decoderName"; statistics_proxy_->OnDecoderImplementationName(kName); + loop_.Flush(); EXPECT_STREQ( kName, statistics_proxy_->GetStats().decoder_implementation_name.c_str()); } @@ -495,7 +497,7 @@ TEST_F(ReceiveStatisticsProxy2Test, GetStatsReportsOnDroppedFrame) { statistics_proxy_->OnDroppedFrames(i); dropped_frames += i; } - VideoReceiveStream::Stats stats = statistics_proxy_->GetStats(); + VideoReceiveStream::Stats stats = FlushAndGetStats(); EXPECT_EQ(dropped_frames, stats.frames_dropped); } @@ -507,11 +509,11 @@ TEST_F(ReceiveStatisticsProxy2Test, GetStatsReportsDecodeTimingStats) { const int kMinPlayoutDelayMs = 6; const int kRenderDelayMs = 7; const int64_t kRttMs = 8; - statistics_proxy_->OnRttUpdate(kRttMs, 0); + statistics_proxy_->OnRttUpdate(kRttMs); statistics_proxy_->OnFrameBufferTimingsUpdated( kMaxDecodeMs, kCurrentDelayMs, kTargetDelayMs, kJitterBufferMs, kMinPlayoutDelayMs, kRenderDelayMs); - VideoReceiveStream::Stats stats = statistics_proxy_->GetStats(); + VideoReceiveStream::Stats stats = FlushAndGetStats(); EXPECT_EQ(kMaxDecodeMs, stats.max_decode_ms); EXPECT_EQ(kCurrentDelayMs, stats.current_delay_ms); EXPECT_EQ(kTargetDelayMs, stats.target_delay_ms); @@ -591,7 +593,7 @@ TEST_F(ReceiveStatisticsProxy2Test, ReportsLongestTimingFrameInfo) { info.capture_time_ms = 0; info.decode_finish_ms = kMedEndToEndDelay; statistics_proxy_->OnTimingFrameInfoUpdated(info); - result = statistics_proxy_->GetStats().timing_frame_info; + result = FlushAndGetStats().timing_frame_info; EXPECT_TRUE(result); EXPECT_EQ(kExpectedRtpTimestamp, result->rtp_timestamp); } @@ -608,7 +610,7 @@ TEST_F(ReceiveStatisticsProxy2Test, RespectsReportingIntervalForTimingFrames) { info.decode_finish_ms = kShortEndToEndDelay; statistics_proxy_->OnTimingFrameInfoUpdated(info); fake_clock_.AdvanceTimeMilliseconds(kShortDelayMs); - result = statistics_proxy_->GetStats().timing_frame_info; + result = FlushAndGetStats().timing_frame_info; EXPECT_TRUE(result); EXPECT_EQ(kExpectedRtpTimestamp, result->rtp_timestamp); fake_clock_.AdvanceTimeMilliseconds(kLongDelayMs); @@ -696,8 +698,7 @@ TEST_F(ReceiveStatisticsProxy2Test, GetStatsReportsPlayoutTimestamp) { EXPECT_EQ(absl::nullopt, statistics_proxy_->GetStats().estimated_playout_ntp_timestamp_ms); statistics_proxy_->OnSyncOffsetUpdated(kVideoNtpMs, kSyncOffsetMs, kFreqKhz); - EXPECT_EQ(kVideoNtpMs, - statistics_proxy_->GetStats().estimated_playout_ntp_timestamp_ms); + EXPECT_EQ(kVideoNtpMs, FlushAndGetStats().estimated_playout_ntp_timestamp_ms); fake_clock_.AdvanceTimeMilliseconds(13); EXPECT_EQ(kVideoNtpMs + 13, statistics_proxy_->GetStats().estimated_playout_ntp_timestamp_ms); @@ -713,18 +714,18 @@ TEST_F(ReceiveStatisticsProxy2Test, GetStatsReportsAvSyncOffset) { EXPECT_EQ(std::numeric_limits::max(), statistics_proxy_->GetStats().sync_offset_ms); statistics_proxy_->OnSyncOffsetUpdated(kVideoNtpMs, kSyncOffsetMs, kFreqKhz); - EXPECT_EQ(kSyncOffsetMs, statistics_proxy_->GetStats().sync_offset_ms); + EXPECT_EQ(kSyncOffsetMs, FlushAndGetStats().sync_offset_ms); } TEST_F(ReceiveStatisticsProxy2Test, AvSyncOffsetHistogramIsUpdated) { const int64_t kVideoNtpMs = 21; const int64_t kSyncOffsetMs = 22; const double kFreqKhz = 90.0; - for (int i = 0; i < kMinRequiredSamples; ++i) + for (int i = 0; i < kMinRequiredSamples; ++i) { statistics_proxy_->OnSyncOffsetUpdated(kVideoNtpMs, kSyncOffsetMs, kFreqKhz); - statistics_proxy_->UpdateHistograms(absl::nullopt, StreamDataCounters(), - nullptr); + } + FlushAndUpdateHistograms(absl::nullopt, StreamDataCounters(), nullptr); EXPECT_METRIC_EQ(1, metrics::NumSamples("WebRTC.Video.AVSyncOffsetInMs")); EXPECT_METRIC_EQ( 1, metrics::NumEvents("WebRTC.Video.AVSyncOffsetInMs", kSyncOffsetMs)); @@ -737,6 +738,7 @@ TEST_F(ReceiveStatisticsProxy2Test, RtpToNtpFrequencyOffsetHistogramIsUpdated) { statistics_proxy_->OnSyncOffsetUpdated(kVideoNtpMs, kSyncOffsetMs, kFreqKhz); statistics_proxy_->OnSyncOffsetUpdated(kVideoNtpMs, kSyncOffsetMs, kFreqKhz + 2.2); + loop_.Flush(); fake_clock_.AdvanceTimeMilliseconds(kFreqOffsetProcessIntervalInMs); // Process interval passed, max diff: 2. statistics_proxy_->OnSyncOffsetUpdated(kVideoNtpMs, kSyncOffsetMs, @@ -745,11 +747,11 @@ TEST_F(ReceiveStatisticsProxy2Test, RtpToNtpFrequencyOffsetHistogramIsUpdated) { kFreqKhz - 4.2); statistics_proxy_->OnSyncOffsetUpdated(kVideoNtpMs, kSyncOffsetMs, kFreqKhz - 0.9); + loop_.Flush(); fake_clock_.AdvanceTimeMilliseconds(kFreqOffsetProcessIntervalInMs); // Process interval passed, max diff: 4. statistics_proxy_->OnSyncOffsetUpdated(kVideoNtpMs, kSyncOffsetMs, kFreqKhz); - statistics_proxy_->UpdateHistograms(absl::nullopt, StreamDataCounters(), - nullptr); + FlushAndUpdateHistograms(absl::nullopt, StreamDataCounters(), nullptr); // Average reported: (2 + 4) / 2 = 3. EXPECT_METRIC_EQ(1, metrics::NumSamples("WebRTC.Video.RtpToNtpFreqOffsetInKhz")); @@ -763,8 +765,7 @@ TEST_F(ReceiveStatisticsProxy2Test, Vp8QpHistogramIsUpdated) { for (int i = 0; i < kMinRequiredSamples; ++i) statistics_proxy_->OnPreDecode(kVideoCodecVP8, kQp); - statistics_proxy_->UpdateHistograms(absl::nullopt, StreamDataCounters(), - nullptr); + FlushAndUpdateHistograms(absl::nullopt, StreamDataCounters(), nullptr); EXPECT_METRIC_EQ(1, metrics::NumSamples("WebRTC.Video.Decoded.Vp8.Qp")); EXPECT_METRIC_EQ(1, metrics::NumEvents("WebRTC.Video.Decoded.Vp8.Qp", kQp)); } @@ -893,8 +894,7 @@ TEST_F(ReceiveStatisticsProxy2Test, TimingHistogramsAreUpdated) { kMinPlayoutDelayMs, kRenderDelayMs); } - statistics_proxy_->UpdateHistograms(absl::nullopt, StreamDataCounters(), - nullptr); + FlushAndUpdateHistograms(absl::nullopt, StreamDataCounters(), nullptr); EXPECT_METRIC_EQ(1, metrics::NumSamples("WebRTC.Video.JitterBufferDelayInMs")); EXPECT_METRIC_EQ(1, metrics::NumSamples("WebRTC.Video.TargetDelayInMs")); diff --git a/video/video_receive_stream2.cc b/video/video_receive_stream2.cc index dbc345566a..a6c3f6533b 100644 --- a/video/video_receive_stream2.cc +++ b/video/video_receive_stream2.cc @@ -364,6 +364,8 @@ void VideoReceiveStream2::Start() { // Make sure we register as a stats observer *after* we've prepared the // |video_stream_decoder_|. + // TODO(webrtc:11489): Make call_stats_ not depend on ProcessThread and + // make callbacks on the worker thread (TQ). call_stats_->RegisterStatsObserver(this); // Start decoding on task queue. @@ -496,11 +498,6 @@ void VideoReceiveStream2::OnFrame(const VideoFrame& video_frame) { int64_t video_playout_ntp_ms; int64_t sync_offset_ms; double estimated_freq_khz; - // TODO(bugs.webrtc.org/11489): GetStreamSyncOffsetInMs grabs three - // locks. One inside the function itself, another in GetChannel() and a - // third in GetPlayoutTimestamp. Seems excessive. Anyhow, I'm assuming - // the function succeeds most of the time, which leads to grabbing a - // fourth lock. if (rtp_stream_sync_.GetStreamSyncOffsetInMs( frame_meta.rtp_timestamp, frame_meta.render_time_ms(), &video_playout_ntp_ms, &sync_offset_ms, &estimated_freq_khz)) { @@ -572,6 +569,9 @@ void VideoReceiveStream2::OnCompleteFrame( void VideoReceiveStream2::OnRttUpdate(int64_t avg_rtt_ms, int64_t max_rtt_ms) { RTC_DCHECK_RUN_ON(&module_process_sequence_checker_); + // TODO(webrtc:11489, webrtc:11490): Once call_stats_ does not depend on + // ProcessThread, this callback should happen on the worker thread. Then we + // can share the avg_rtt_ms with ReceiveStatisticsProxy. frame_buffer_->UpdateRtt(max_rtt_ms); rtp_video_stream_receiver_.UpdateRtt(max_rtt_ms); }