stats: implement inbound-rtp totalProcessingDelay for video

https://w3c.github.io/webrtc-stats/#dom-rtcinboundrtpstreamstats-totalprocessingdelay

BUG=webrtc:13984

Change-Id: Ifd821bd8553add46218f09a11366096d62f5d09f
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/259768
Reviewed-by: Harald Alvestrand <hta@webrtc.org>
Commit-Queue: Henrik Boström <hbos@webrtc.org>
Reviewed-by: Henrik Boström <hbos@webrtc.org>
Cr-Commit-Position: refs/heads/main@{#36732}
This commit is contained in:
Philipp Hancke
2022-04-25 12:21:30 +02:00
committed by WebRTC LUCI CQ
parent a63b6b7d40
commit a16a6a6341
11 changed files with 95 additions and 17 deletions

View File

@ -487,7 +487,6 @@ class RTC_EXPORT RTCInboundRTPStreamStats final
RTCStatsMember<double> audio_level;
RTCStatsMember<double> total_audio_energy;
RTCStatsMember<double> total_samples_duration;
RTCStatsMember<int32_t> frames_received;
// TODO(hbos): Collect and populate this value. https://bugs.webrtc.org/7065
RTCStatsMember<double> round_trip_time;
// TODO(hbos): Collect and populate this value. https://bugs.webrtc.org/7065
@ -508,6 +507,8 @@ class RTC_EXPORT RTCInboundRTPStreamStats final
RTCStatsMember<double> gap_loss_rate;
// TODO(hbos): Collect and populate this value. https://bugs.webrtc.org/7065
RTCStatsMember<double> gap_discard_rate;
// Stats below are only implemented or defined for video.
RTCStatsMember<int32_t> frames_received;
RTCStatsMember<uint32_t> frame_width;
RTCStatsMember<uint32_t> frame_height;
RTCStatsMember<uint32_t> frame_bit_depth;
@ -516,6 +517,7 @@ class RTC_EXPORT RTCInboundRTPStreamStats final
RTCStatsMember<uint32_t> key_frames_decoded;
RTCStatsMember<uint32_t> frames_dropped;
RTCStatsMember<double> total_decode_time;
RTCStatsMember<double> total_processing_delay;
RTCStatsMember<double> total_inter_frame_delay;
RTCStatsMember<double> total_squared_inter_frame_delay;
// https://henbos.github.io/webrtc-provisional-stats/#dom-rtcinboundrtpstreamstats-contenttype

View File

@ -106,6 +106,8 @@ class VideoReceiveStream : public MediaReceiveStream {
uint32_t frames_decoded = 0;
// https://w3c.github.io/webrtc-stats/#dom-rtcinboundrtpstreamstats-totaldecodetime
uint64_t total_decode_time_ms = 0;
// https://w3c.github.io/webrtc-stats/#dom-rtcinboundrtpstreamstats-totalprocessingdelay
webrtc::TimeDelta total_processing_delay = webrtc::TimeDelta::Millis(0);
// Total inter frame delay in seconds.
// https://w3c.github.io/webrtc-stats/#dom-rtcinboundrtpstreamstats-totalinterframedelay
double total_inter_frame_delay = 0;

View File

@ -613,6 +613,8 @@ struct VideoReceiverInfo : public MediaReceiverInfo {
absl::optional<uint64_t> qp_sum;
// https://w3c.github.io/webrtc-stats/#dom-rtcinboundrtpstreamstats-totaldecodetime
uint64_t total_decode_time_ms = 0;
// https://w3c.github.io/webrtc-stats/#dom-rtcinboundrtpstreamstats-totalprocessingdelay
webrtc::TimeDelta total_processing_delay = webrtc::TimeDelta::Millis(0);
double total_inter_frame_delay = 0;
double total_squared_inter_frame_delay = 0;
int64_t interframe_delay_max_ms = -1;

View File

@ -3166,6 +3166,7 @@ WebRtcVideoChannel::WebRtcVideoReceiveStream::GetVideoReceiverInfo(
info.frames_rendered = stats.frames_rendered;
info.qp_sum = stats.qp_sum;
info.total_decode_time_ms = stats.total_decode_time_ms;
info.total_processing_delay = stats.total_processing_delay;
info.last_packet_received_timestamp_ms =
stats.rtp_stats.last_packet_received_timestamp_ms;
info.estimated_playout_ntp_timestamp_ms =

View File

@ -521,6 +521,9 @@ void SetInboundRTPStreamStatsFromVideoReceiverInfo(
inbound_video->total_decode_time =
static_cast<double>(video_receiver_info.total_decode_time_ms) /
rtc::kNumMillisecsPerSec;
inbound_video->total_processing_delay =
static_cast<double>(video_receiver_info.total_processing_delay.ms()) /
rtc::kNumMillisecsPerSec;
inbound_video->total_inter_frame_delay =
video_receiver_info.total_inter_frame_delay;
inbound_video->total_squared_inter_frame_delay =

View File

@ -2139,6 +2139,8 @@ TEST_F(RTCStatsCollectorTest, CollectRTCInboundRTPStreamStats_Video) {
video_media_info.receivers[0].frames_dropped = 13;
video_media_info.receivers[0].qp_sum = absl::nullopt;
video_media_info.receivers[0].total_decode_time_ms = 9000;
video_media_info.receivers[0].total_processing_delay =
webrtc::TimeDelta::Millis(600);
video_media_info.receivers[0].total_inter_frame_delay = 0.123;
video_media_info.receivers[0].total_squared_inter_frame_delay = 0.00456;
video_media_info.receivers[0].jitter_ms = 1199;
@ -2188,6 +2190,7 @@ TEST_F(RTCStatsCollectorTest, CollectRTCInboundRTPStreamStats_Video) {
expected_video.frames_dropped = 13;
// `expected_video.qp_sum` should be undefined.
expected_video.total_decode_time = 9.0;
expected_video.total_processing_delay = 0.6;
expected_video.total_inter_frame_delay = 0.123;
expected_video.total_squared_inter_frame_delay = 0.00456;
expected_video.jitter = 1.199;

View File

@ -914,6 +914,8 @@ class RTCStatsReportVerifier {
verifier.TestMemberIsNonNegative<uint32_t>(inbound_stream.frames_dropped);
verifier.TestMemberIsNonNegative<double>(
inbound_stream.total_decode_time);
verifier.TestMemberIsNonNegative<double>(
inbound_stream.total_processing_delay);
verifier.TestMemberIsNonNegative<double>(
inbound_stream.total_inter_frame_delay);
verifier.TestMemberIsNonNegative<double>(
@ -926,6 +928,7 @@ class RTCStatsReportVerifier {
verifier.TestMemberIsUndefined(inbound_stream.key_frames_decoded);
verifier.TestMemberIsUndefined(inbound_stream.frames_dropped);
verifier.TestMemberIsUndefined(inbound_stream.total_decode_time);
verifier.TestMemberIsUndefined(inbound_stream.total_processing_delay);
verifier.TestMemberIsUndefined(inbound_stream.total_inter_frame_delay);
verifier.TestMemberIsUndefined(
inbound_stream.total_squared_inter_frame_delay);

View File

@ -674,7 +674,6 @@ WEBRTC_RTCSTATS_IMPL(
&audio_level,
&total_audio_energy,
&total_samples_duration,
&frames_received,
&round_trip_time,
&packets_repaired,
&burst_packets_lost,
@ -685,6 +684,7 @@ WEBRTC_RTCSTATS_IMPL(
&burst_discard_rate,
&gap_loss_rate,
&gap_discard_rate,
&frames_received,
&frame_width,
&frame_height,
&frame_bit_depth,
@ -693,6 +693,7 @@ WEBRTC_RTCSTATS_IMPL(
&key_frames_decoded,
&frames_dropped,
&total_decode_time,
&total_processing_delay,
&total_inter_frame_delay,
&total_squared_inter_frame_delay,
&content_type,
@ -729,7 +730,6 @@ RTCInboundRTPStreamStats::RTCInboundRTPStreamStats(std::string&& id,
audio_level("audioLevel"),
total_audio_energy("totalAudioEnergy"),
total_samples_duration("totalSamplesDuration"),
frames_received("framesReceived"),
round_trip_time("roundTripTime"),
packets_repaired("packetsRepaired"),
burst_packets_lost("burstPacketsLost"),
@ -740,6 +740,7 @@ RTCInboundRTPStreamStats::RTCInboundRTPStreamStats(std::string&& id,
burst_discard_rate("burstDiscardRate"),
gap_loss_rate("gapLossRate"),
gap_discard_rate("gapDiscardRate"),
frames_received("framesReceived"),
frame_width("frameWidth"),
frame_height("frameHeight"),
frame_bit_depth("frameBitDepth"),
@ -748,6 +749,7 @@ RTCInboundRTPStreamStats::RTCInboundRTPStreamStats(std::string&& id,
key_frames_decoded("keyFramesDecoded"),
frames_dropped("framesDropped"),
total_decode_time("totalDecodeTime"),
total_processing_delay("totalProcessingDelay"),
total_inter_frame_delay("totalInterFrameDelay"),
total_squared_inter_frame_delay("totalSquaredInterFrameDelay"),
content_type("contentType"),
@ -780,7 +782,6 @@ RTCInboundRTPStreamStats::RTCInboundRTPStreamStats(
audio_level(other.audio_level),
total_audio_energy(other.total_audio_energy),
total_samples_duration(other.total_samples_duration),
frames_received(other.frames_received),
round_trip_time(other.round_trip_time),
packets_repaired(other.packets_repaired),
burst_packets_lost(other.burst_packets_lost),
@ -791,6 +792,7 @@ RTCInboundRTPStreamStats::RTCInboundRTPStreamStats(
burst_discard_rate(other.burst_discard_rate),
gap_loss_rate(other.gap_loss_rate),
gap_discard_rate(other.gap_discard_rate),
frames_received(other.frames_received),
frame_width(other.frame_width),
frame_height(other.frame_height),
frame_bit_depth(other.frame_bit_depth),
@ -799,6 +801,7 @@ RTCInboundRTPStreamStats::RTCInboundRTPStreamStats(
key_frames_decoded(other.key_frames_decoded),
frames_dropped(other.frames_dropped),
total_decode_time(other.total_decode_time),
total_processing_delay(other.total_processing_delay),
total_inter_frame_delay(other.total_inter_frame_delay),
total_squared_inter_frame_delay(other.total_squared_inter_frame_delay),
content_type(other.content_type),

View File

@ -830,20 +830,33 @@ void ReceiveStatisticsProxy::OnDecodedFrame(const VideoFrame& frame,
absl::optional<uint8_t> qp,
int32_t decode_time_ms,
VideoContentType content_type) {
webrtc::TimeDelta processing_delay = webrtc::TimeDelta::Millis(0);
webrtc::Timestamp current_time = clock_->CurrentTime();
// TODO(bugs.webrtc.org/13984): some tests do not fill packet_infos().
if (frame.packet_infos().size() > 0) {
auto first_packet = std::min_element(
frame.packet_infos().cbegin(), frame.packet_infos().cend(),
[](const webrtc::RtpPacketInfo& a, const webrtc::RtpPacketInfo& b) {
return a.receive_time() < b.receive_time();
});
processing_delay = current_time - first_packet->receive_time();
}
// See VCMDecodedFrameCallback::Decoded for more info on what thread/queue we
// 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(
task_safety_, [meta, qp, decode_time_ms, content_type, this]() {
OnDecodedFrame(meta, qp, decode_time_ms, content_type);
}));
VideoFrameMetaData meta(frame, current_time);
worker_thread_->PostTask(ToQueuedTask(task_safety_, [meta, qp, decode_time_ms,
processing_delay,
content_type, this]() {
OnDecodedFrame(meta, qp, decode_time_ms, processing_delay, content_type);
}));
}
void ReceiveStatisticsProxy::OnDecodedFrame(
const VideoFrameMetaData& frame_meta,
absl::optional<uint8_t> qp,
int32_t decode_time_ms,
webrtc::TimeDelta processing_delay,
VideoContentType content_type) {
RTC_DCHECK_RUN_ON(&main_thread_);
@ -884,6 +897,7 @@ void ReceiveStatisticsProxy::OnDecodedFrame(
decode_time_counter_.Add(decode_time_ms);
stats_.decode_ms = decode_time_ms;
stats_.total_decode_time_ms += decode_time_ms;
stats_.total_processing_delay += processing_delay;
if (enable_decode_time_histograms_) {
UpdateDecodeTimeHistograms(frame_meta.width, frame_meta.height,
decode_time_ms);

View File

@ -68,6 +68,7 @@ class ReceiveStatisticsProxy : public VCMReceiveStatisticsCallback,
void OnDecodedFrame(const VideoFrameMetaData& frame_meta,
absl::optional<uint8_t> qp,
int32_t decode_time_ms,
webrtc::TimeDelta processing_delay_ms,
VideoContentType content_type);
void OnSyncOffsetUpdated(int64_t video_playout_ntp_ms,

View File

@ -177,6 +177,42 @@ TEST_F(ReceiveStatisticsProxy2Test,
statistics_proxy_->GetStats().total_decode_time_ms);
}
TEST_F(ReceiveStatisticsProxy2Test, OnDecodedFrameIncreasesProcessingDelay) {
const TimeDelta kProcessingDelay = TimeDelta::Millis(10);
EXPECT_EQ(0u, statistics_proxy_->GetStats().frames_decoded);
webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight);
TimeDelta expected_total_processing_delay = TimeDelta::Millis(0);
unsigned int expected_frames_decoded = 0;
// We set receive time fixed and increase the clock by 10ms
// in the loop which will increase the processing delay by
// 10/20/30ms respectively.
RtpPacketInfos::vector_type packet_infos = {
RtpPacketInfo({}, {}, {}, {}, {}, Now())};
frame.set_packet_infos(RtpPacketInfos(packet_infos));
for (int i = 1; i <= 3; ++i) {
fake_clock_.AdvanceTime(kProcessingDelay);
statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 1,
VideoContentType::UNSPECIFIED);
expected_total_processing_delay += i * kProcessingDelay;
++expected_frames_decoded;
loop_.Flush();
EXPECT_EQ(expected_frames_decoded,
statistics_proxy_->GetStats().frames_decoded);
EXPECT_EQ(expected_total_processing_delay,
statistics_proxy_->GetStats().total_processing_delay);
}
fake_clock_.AdvanceTime(kProcessingDelay);
statistics_proxy_->OnDecodedFrame(frame, 1u, 3,
VideoContentType::UNSPECIFIED);
++expected_frames_decoded;
expected_total_processing_delay += 4 * kProcessingDelay;
loop_.Flush();
EXPECT_EQ(expected_frames_decoded,
statistics_proxy_->GetStats().frames_decoded);
EXPECT_EQ(expected_total_processing_delay,
statistics_proxy_->GetStats().total_processing_delay);
}
TEST_F(ReceiveStatisticsProxy2Test, OnDecodedFrameIncreasesQpSum) {
EXPECT_EQ(absl::nullopt, statistics_proxy_->GetStats().qp_sum);
webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight);
@ -1351,14 +1387,16 @@ TEST_P(ReceiveStatisticsProxy2TestWithContent, FreezesAreReported) {
for (int i = 0; i < kMinRequiredSamples; ++i) {
VideoFrameMetaData meta = MetaData(frame);
statistics_proxy_->OnDecodedFrame(meta, absl::nullopt, 0, content_type_);
statistics_proxy_->OnDecodedFrame(
meta, absl::nullopt, 0, webrtc::TimeDelta::Millis(0), content_type_);
statistics_proxy_->OnRenderedFrame(meta);
fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs);
}
// Add extra freeze.
fake_clock_.AdvanceTimeMilliseconds(kFreezeDelayMs);
VideoFrameMetaData meta = MetaData(frame);
statistics_proxy_->OnDecodedFrame(meta, absl::nullopt, 0, content_type_);
statistics_proxy_->OnDecodedFrame(
meta, absl::nullopt, 0, webrtc::TimeDelta::Millis(0), content_type_);
statistics_proxy_->OnRenderedFrame(meta);
FlushAndUpdateHistograms(absl::nullopt, StreamDataCounters(), nullptr);
@ -1441,7 +1479,8 @@ TEST_P(ReceiveStatisticsProxy2TestWithContent, PausesAreIgnored) {
for (int i = 0; i <= kMinRequiredSamples; ++i) {
VideoFrameMetaData meta = MetaData(frame);
statistics_proxy_->OnDecodedFrame(meta, absl::nullopt, 0, content_type_);
statistics_proxy_->OnDecodedFrame(
meta, absl::nullopt, 0, webrtc::TimeDelta::Millis(0), content_type_);
statistics_proxy_->OnRenderedFrame(meta);
fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs);
}
@ -1451,7 +1490,8 @@ TEST_P(ReceiveStatisticsProxy2TestWithContent, PausesAreIgnored) {
// Second playback interval with triple the length.
for (int i = 0; i <= kMinRequiredSamples * 3; ++i) {
VideoFrameMetaData meta = MetaData(frame);
statistics_proxy_->OnDecodedFrame(meta, absl::nullopt, 0, content_type_);
statistics_proxy_->OnDecodedFrame(
meta, absl::nullopt, 0, webrtc::TimeDelta::Millis(0), content_type_);
statistics_proxy_->OnRenderedFrame(meta);
fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs);
}
@ -1512,14 +1552,16 @@ TEST_P(ReceiveStatisticsProxy2TestWithContent, TimeInHdReported) {
// HD frames.
for (int i = 0; i < kMinRequiredSamples; ++i) {
VideoFrameMetaData meta = MetaData(frame_hd);
statistics_proxy_->OnDecodedFrame(meta, absl::nullopt, 0, content_type_);
statistics_proxy_->OnDecodedFrame(
meta, absl::nullopt, 0, webrtc::TimeDelta::Millis(0), content_type_);
statistics_proxy_->OnRenderedFrame(meta);
fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs);
}
// SD frames.
for (int i = 0; i < 2 * kMinRequiredSamples; ++i) {
VideoFrameMetaData meta = MetaData(frame_sd);
statistics_proxy_->OnDecodedFrame(meta, absl::nullopt, 0, content_type_);
statistics_proxy_->OnDecodedFrame(
meta, absl::nullopt, 0, webrtc::TimeDelta::Millis(0), content_type_);
statistics_proxy_->OnRenderedFrame(meta);
fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs);
}
@ -1548,14 +1590,16 @@ TEST_P(ReceiveStatisticsProxy2TestWithContent, TimeInBlockyVideoReported) {
// High quality frames.
for (int i = 0; i < kMinRequiredSamples; ++i) {
VideoFrameMetaData meta = MetaData(frame);
statistics_proxy_->OnDecodedFrame(meta, kLowQp, 0, content_type_);
statistics_proxy_->OnDecodedFrame(
meta, kLowQp, 0, webrtc::TimeDelta::Millis(0), content_type_);
statistics_proxy_->OnRenderedFrame(meta);
fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs);
}
// Blocky frames.
for (int i = 0; i < 2 * kMinRequiredSamples; ++i) {
VideoFrameMetaData meta = MetaData(frame);
statistics_proxy_->OnDecodedFrame(meta, kHighQp, 0, content_type_);
statistics_proxy_->OnDecodedFrame(
meta, kHighQp, 0, webrtc::TimeDelta::Millis(0), content_type_);
statistics_proxy_->OnRenderedFrame(meta);
fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs);
}