From 75204c5ccdda561ccffbfa3a8fa94feac8e19e30 Mon Sep 17 00:00:00 2001 From: ilnik Date: Mon, 4 Sep 2017 03:35:40 -0700 Subject: [PATCH] Change reporting of timing frames conditions in GetStats on receive side Instead of the longest frame since the last GetStats call, the longest frame received during last 10 seconds should be returned in GetStats(). Previous way is not a good idea because there are maybe several consumers of GetStats calls. If not all of them parse timing frame reports, some of them may be lost. Also, streamline reporting of TimingFrames via GetStats (remove separate methods and use VideoReceiveStream::Stats struct instead). BUG=webrtc:7594 Review-Url: https://codereview.webrtc.org/3008983002 Cr-Commit-Position: refs/heads/master@{#19650} --- webrtc/api/video/video_timing.cc | 14 ++++++++--- webrtc/api/video/video_timing.h | 4 ++++ webrtc/call/video_receive_stream.h | 6 +++-- webrtc/media/engine/fakewebrtccall.cc | 5 ---- webrtc/media/engine/fakewebrtccall.h | 2 -- webrtc/media/engine/webrtcvideoengine.cc | 2 +- webrtc/video/end_to_end_tests.cc | 12 +++------- webrtc/video/receive_statistics_proxy.cc | 23 ++++--------------- webrtc/video/receive_statistics_proxy.h | 7 +++--- .../receive_statistics_proxy_unittest.cc | 16 ++++++++----- webrtc/video/video_receive_stream.cc | 5 ---- webrtc/video/video_receive_stream.h | 2 -- 12 files changed, 42 insertions(+), 56 deletions(-) diff --git a/webrtc/api/video/video_timing.cc b/webrtc/api/video/video_timing.cc index 0d22f904bf..2804c8ba45 100644 --- a/webrtc/api/video/video_timing.cc +++ b/webrtc/api/video/video_timing.cc @@ -39,6 +39,14 @@ bool TimingFrameInfo::IsLongerThan(const TimingFrameInfo& other) const { return other_delay == -1 || EndToEndDelay() > other_delay; } +bool TimingFrameInfo::operator<(const TimingFrameInfo& other) const { + return other.IsLongerThan(*this); +} + +bool TimingFrameInfo::operator<=(const TimingFrameInfo& other) const { + return !IsLongerThan(other); +} + bool TimingFrameInfo::IsOutlier() const { return !IsInvalid() && (flags & TimingFrameFlags::kTriggeredBySize); } @@ -54,15 +62,15 @@ bool TimingFrameInfo::IsInvalid() const { std::string TimingFrameInfo::ToString() const { std::stringstream out; if (IsInvalid()) { - out << "[Invalid]"; + out << ""; } else { out << rtp_timestamp << ',' << capture_time_ms << ',' << encode_start_ms << ',' << encode_finish_ms << ',' << packetization_finish_ms << ',' << pacer_exit_ms << ',' << network_timestamp_ms << ',' << network2_timestamp_ms << ',' << receive_start_ms << ',' << receive_finish_ms << ',' << decode_start_ms << ',' - << decode_finish_ms << ',' << render_time_ms << ", outlier_triggered " - << IsOutlier() << ", timer_triggered " << IsTimerTriggered(); + << decode_finish_ms << ',' << render_time_ms << ',' + << IsOutlier() << ',' << IsTimerTriggered(); } return out.str(); } diff --git a/webrtc/api/video/video_timing.h b/webrtc/api/video/video_timing.h index f5134636ba..e75c0c1070 100644 --- a/webrtc/api/video/video_timing.h +++ b/webrtc/api/video/video_timing.h @@ -89,6 +89,10 @@ struct TimingFrameInfo { std::string ToString() const; + bool operator<(const TimingFrameInfo& other) const; + + bool operator<=(const TimingFrameInfo& other) const; + uint32_t rtp_timestamp; // Identifier of a frame. // All timestamps below are in local monotonous clock of a receiver. // If sender clock is not yet estimated, sender timestamps diff --git a/webrtc/call/video_receive_stream.h b/webrtc/call/video_receive_stream.h index e78a36945f..542027e953 100644 --- a/webrtc/call/video_receive_stream.h +++ b/webrtc/call/video_receive_stream.h @@ -95,6 +95,10 @@ class VideoReceiveStream { StreamDataCounters rtp_stats; RtcpPacketTypeCounter rtcp_packet_type_counts; RtcpStatistics rtcp_stats; + + // Timing frame info: all important timestamps for a full lifetime of a + // single 'timing frame'. + rtc::Optional timing_frame_info; }; struct Config { @@ -227,8 +231,6 @@ class VideoReceiveStream { // TODO(pbos): Add info on currently-received codec to Stats. virtual Stats GetStats() const = 0; - virtual rtc::Optional GetAndResetTimingFrameInfo() = 0; - // Takes ownership of the file, is responsible for closing it later. // Calling this method will close and finalize any current log. // Giving rtc::kInvalidPlatformFileValue disables logging. diff --git a/webrtc/media/engine/fakewebrtccall.cc b/webrtc/media/engine/fakewebrtccall.cc index af86fddb17..8081819654 100644 --- a/webrtc/media/engine/fakewebrtccall.cc +++ b/webrtc/media/engine/fakewebrtccall.cc @@ -309,11 +309,6 @@ webrtc::VideoReceiveStream::Stats FakeVideoReceiveStream::GetStats() const { return stats_; } -rtc::Optional -FakeVideoReceiveStream::GetAndResetTimingFrameInfo() { - return rtc::Optional(); -} - void FakeVideoReceiveStream::Start() { receiving_ = true; } diff --git a/webrtc/media/engine/fakewebrtccall.h b/webrtc/media/engine/fakewebrtccall.h index cd8d3709ef..0b4496b45f 100644 --- a/webrtc/media/engine/fakewebrtccall.h +++ b/webrtc/media/engine/fakewebrtccall.h @@ -209,8 +209,6 @@ class FakeVideoReceiveStream final : public webrtc::VideoReceiveStream { webrtc::VideoReceiveStream::Stats GetStats() const override; - rtc::Optional GetAndResetTimingFrameInfo() override; - webrtc::VideoReceiveStream::Config config_; bool receiving_; webrtc::VideoReceiveStream::Stats stats_; diff --git a/webrtc/media/engine/webrtcvideoengine.cc b/webrtc/media/engine/webrtcvideoengine.cc index 4fabe52314..cd34e6b478 100644 --- a/webrtc/media/engine/webrtcvideoengine.cc +++ b/webrtc/media/engine/webrtcvideoengine.cc @@ -2434,7 +2434,7 @@ WebRtcVideoChannel::WebRtcVideoReceiveStream::GetVideoReceiverInfo( info.plis_sent = stats.rtcp_packet_type_counts.pli_packets; info.nacks_sent = stats.rtcp_packet_type_counts.nack_packets; - info.timing_frame_info = stream_->GetAndResetTimingFrameInfo(); + info.timing_frame_info = stats.timing_frame_info; if (log_stats) LOG(LS_INFO) << stats.ToString(rtc::TimeMillis()); diff --git a/webrtc/video/end_to_end_tests.cc b/webrtc/video/end_to_end_tests.cc index 8ace93e786..107aed8346 100644 --- a/webrtc/video/end_to_end_tests.cc +++ b/webrtc/video/end_to_end_tests.cc @@ -3631,7 +3631,7 @@ TEST_F(EndToEndTest, GetStats) { RunBaseTest(&test); } -TEST_F(EndToEndTest, GetTimingFrameInfoReportsTimingFrames) { +TEST_F(EndToEndTest, TimingFramesAreReported) { static const int kExtensionId = 5; class StatsObserver : public test::EndToEndTest { @@ -3639,12 +3639,6 @@ TEST_F(EndToEndTest, GetTimingFrameInfoReportsTimingFrames) { StatsObserver() : EndToEndTest(kLongTimeoutMs) {} private: - std::string CompoundKey(const char* name, uint32_t ssrc) { - std::ostringstream oss; - oss << name << "_" << ssrc; - return oss.str(); - } - void ModifyVideoConfigs( VideoSendStream::Config* send_config, std::vector* receive_configs, @@ -3668,13 +3662,13 @@ TEST_F(EndToEndTest, GetTimingFrameInfoReportsTimingFrames) { void PerformTest() override { // No frames reported initially. for (size_t i = 0; i < receive_streams_.size(); ++i) { - EXPECT_FALSE(receive_streams_[i]->GetAndResetTimingFrameInfo()); + EXPECT_FALSE(receive_streams_[i]->GetStats().timing_frame_info); } // Wait for at least one timing frame to be sent with 100ms grace period. SleepMs(kDefaultTimingFramesDelayMs + 100); // Check that timing frames are reported for each stream. for (size_t i = 0; i < receive_streams_.size(); ++i) { - EXPECT_TRUE(receive_streams_[i]->GetAndResetTimingFrameInfo()); + EXPECT_TRUE(receive_streams_[i]->GetStats().timing_frame_info); } } diff --git a/webrtc/video/receive_statistics_proxy.cc b/webrtc/video/receive_statistics_proxy.cc index 6e58e1e86b..2448bad746 100644 --- a/webrtc/video/receive_statistics_proxy.cc +++ b/webrtc/video/receive_statistics_proxy.cc @@ -104,7 +104,8 @@ ReceiveStatisticsProxy::ReceiveStatisticsProxy( freq_offset_counter_(clock, nullptr, kFreqOffsetProcessIntervalMs), first_report_block_time_ms_(-1), avg_rtt_ms_(0), - last_content_type_(VideoContentType::UNSPECIFIED) { + last_content_type_(VideoContentType::UNSPECIFIED), + timing_frame_info_counter_(kMovingMaxWindowMs) { stats_.ssrc = config_.rtp.remote_ssrc; // TODO(brandtr): Replace |rtx_stats_| with a single instance of // StreamDataCounters. @@ -499,20 +500,10 @@ VideoReceiveStream::Stats ReceiveStatisticsProxy::GetStats() const { static_cast(total_byte_tracker_.ComputeRate() * 8); stats_.interframe_delay_max_ms = interframe_delay_max_moving_.Max(now_ms).value_or(-1); + stats_.timing_frame_info = timing_frame_info_counter_.Max(now_ms); return stats_; } -rtc::Optional -ReceiveStatisticsProxy::GetAndResetTimingFrameInfo() { - rtc::CritScope lock(&crit_); - rtc::Optional info = timing_frame_info_; - // Reset reported value to empty, so it will be always - // overwritten in |OnTimingFrameInfoUpdated|, thus allowing to store new - // value instead of reported one. - timing_frame_info_.reset(); - return info; -} - void ReceiveStatisticsProxy::OnIncomingPayloadType(int payload_type) { rtc::CritScope lock(&crit_); stats_.current_payload_type = payload_type; @@ -557,13 +548,9 @@ void ReceiveStatisticsProxy::OnFrameBufferTimingsUpdated( void ReceiveStatisticsProxy::OnTimingFrameInfoUpdated( const TimingFrameInfo& info) { + int64_t now_ms = clock_->TimeInMilliseconds(); rtc::CritScope lock(&crit_); - // Only the frame which was processed the longest since the last - // GetStats() call is reported. Therefore, only single 'longest' frame is - // stored. - if (!timing_frame_info_ || info.IsLongerThan(*timing_frame_info_)) { - timing_frame_info_.emplace(info); - } + timing_frame_info_counter_.Add(info, now_ms); } void ReceiveStatisticsProxy::RtcpPacketTypesCounterUpdated( diff --git a/webrtc/video/receive_statistics_proxy.h b/webrtc/video/receive_statistics_proxy.h index 9a6807c4b2..140cdbd407 100644 --- a/webrtc/video/receive_statistics_proxy.h +++ b/webrtc/video/receive_statistics_proxy.h @@ -48,8 +48,6 @@ class ReceiveStatisticsProxy : public VCMReceiveStatisticsCallback, VideoReceiveStream::Stats GetStats() const; - rtc::Optional GetAndResetTimingFrameInfo(); - void OnDecodedFrame(rtc::Optional qp, VideoContentType content_type); void OnSyncOffsetUpdated(int64_t sync_offset_ms, double estimated_freq_khz); void OnRenderedFrame(const VideoFrame& frame); @@ -179,7 +177,10 @@ class ReceiveStatisticsProxy : public VCMReceiveStatisticsCallback, mutable std::map frame_window_ GUARDED_BY(&crit_); VideoContentType last_content_type_ GUARDED_BY(&crit_); rtc::Optional last_decoded_frame_time_ms_ GUARDED_BY(&crit_); - rtc::Optional timing_frame_info_ GUARDED_BY(&crit_); + // Mutable because calling Max() on MovingMaxCounter is not const. Yet it is + // called from const GetStats(). + mutable rtc::MovingMaxCounter timing_frame_info_counter_ + GUARDED_BY(&crit_); }; } // namespace webrtc diff --git a/webrtc/video/receive_statistics_proxy_unittest.cc b/webrtc/video/receive_statistics_proxy_unittest.cc index 528ef09c88..0b8b3a6be1 100644 --- a/webrtc/video/receive_statistics_proxy_unittest.cc +++ b/webrtc/video/receive_statistics_proxy_unittest.cc @@ -309,7 +309,7 @@ TEST_F(ReceiveStatisticsProxyTest, GetStatsReportsNoCNameForUnknownSsrc) { } TEST_F(ReceiveStatisticsProxyTest, - GetTimingFrameInfoReportsLongestTimingFrame) { + ReportsLongestTimingFrameInfo) { const int64_t kShortEndToEndDelay = 10; const int64_t kMedEndToEndDelay = 20; const int64_t kLongEndToEndDelay = 100; @@ -329,24 +329,28 @@ TEST_F(ReceiveStatisticsProxyTest, info.capture_time_ms = 0; info.decode_finish_ms = kMedEndToEndDelay; statistics_proxy_->OnTimingFrameInfoUpdated(info); - result = statistics_proxy_->GetAndResetTimingFrameInfo(); + result = statistics_proxy_->GetStats().timing_frame_info; EXPECT_TRUE(result); EXPECT_EQ(kExpectedRtpTimestamp, result->rtp_timestamp); } -TEST_F(ReceiveStatisticsProxyTest, GetTimingFrameInfoTimingFramesReportedOnce) { +TEST_F(ReceiveStatisticsProxyTest, RespectsReportingIntervalForTimingFrames) { + TimingFrameInfo info; const int64_t kShortEndToEndDelay = 10; const uint32_t kExpectedRtpTimestamp = 2; - TimingFrameInfo info; + const int64_t kShortDelayMs = 1000; + const int64_t kLongDelayMs = 10000; rtc::Optional result; info.rtp_timestamp = kExpectedRtpTimestamp; info.capture_time_ms = 0; info.decode_finish_ms = kShortEndToEndDelay; statistics_proxy_->OnTimingFrameInfoUpdated(info); - result = statistics_proxy_->GetAndResetTimingFrameInfo(); + fake_clock_.AdvanceTimeMilliseconds(kShortDelayMs); + result = statistics_proxy_->GetStats().timing_frame_info; EXPECT_TRUE(result); EXPECT_EQ(kExpectedRtpTimestamp, result->rtp_timestamp); - result = statistics_proxy_->GetAndResetTimingFrameInfo(); + fake_clock_.AdvanceTimeMilliseconds(kLongDelayMs); + result = statistics_proxy_->GetStats().timing_frame_info; EXPECT_FALSE(result); } diff --git a/webrtc/video/video_receive_stream.cc b/webrtc/video/video_receive_stream.cc index 5af855b8dd..9f5528bb2f 100644 --- a/webrtc/video/video_receive_stream.cc +++ b/webrtc/video/video_receive_stream.cc @@ -251,11 +251,6 @@ VideoReceiveStream::Stats VideoReceiveStream::GetStats() const { return stats_proxy_.GetStats(); } -rtc::Optional -VideoReceiveStream::GetAndResetTimingFrameInfo() { - return stats_proxy_.GetAndResetTimingFrameInfo(); -} - void VideoReceiveStream::EnableEncodedFrameRecording(rtc::PlatformFile file, size_t byte_limit) { { diff --git a/webrtc/video/video_receive_stream.h b/webrtc/video/video_receive_stream.h index 967efccd3a..2f29c90170 100644 --- a/webrtc/video/video_receive_stream.h +++ b/webrtc/video/video_receive_stream.h @@ -73,8 +73,6 @@ class VideoReceiveStream : public webrtc::VideoReceiveStream, webrtc::VideoReceiveStream::Stats GetStats() const override; - rtc::Optional GetAndResetTimingFrameInfo() override; - // Takes ownership of the file, is responsible for closing it later. // Calling this method will close and finalize any current log. // Giving rtc::kInvalidPlatformFileValue disables logging.