[DVQA] Add support for processing decoder errors correctly

Bug: b/243855428
Change-Id: I3f1a6fab0aecf0586b97076054a7e46f624397a1
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/272966
Reviewed-by: Florent Castelli <orphis@webrtc.org>
Commit-Queue: Artem Titov <titovartem@webrtc.org>
Reviewed-by: Mirko Bonadei <mbonadei@webrtc.org>
Cr-Commit-Position: refs/heads/main@{#37930}
This commit is contained in:
Artem Titov
2022-08-29 13:56:06 +02:00
committed by WebRTC LUCI CQ
parent 1a43f2c6c5
commit 7d18a5a4c0
11 changed files with 1138 additions and 28 deletions

View File

@ -131,9 +131,14 @@ class VideoQualityAnalyzerInterface
// All available codes are listed in // All available codes are listed in
// modules/video_coding/include/video_error_codes.h // modules/video_coding/include/video_error_codes.h
// `peer_name` is name of the peer on which side error acquired. // `peer_name` is name of the peer on which side error acquired.
// TODO(titovartem): remove this method when downstreams are migrated.
virtual void OnDecoderError(absl::string_view peer_name, virtual void OnDecoderError(absl::string_view peer_name,
uint16_t frame_id, uint16_t frame_id,
int32_t error_code) {} int32_t error_code) {}
virtual void OnDecoderError(absl::string_view peer_name,
uint16_t frame_id,
int32_t error_code,
const DecoderStats& stats) {}
// Will be called every time new stats reports are available for the // Will be called every time new stats reports are available for the
// Peer Connection identified by `pc_label`. // Peer Connection identified by `pc_label`.
void OnStatsReports( void OnStatsReports(

View File

@ -43,13 +43,22 @@ constexpr absl::string_view kSkipRenderedFrameReasonDropped =
"considered dropped"; "considered dropped";
void LogFrameCounters(const std::string& name, const FrameCounters& counters) { void LogFrameCounters(const std::string& name, const FrameCounters& counters) {
RTC_LOG(LS_INFO) << "[" << name << "] Captured : " << counters.captured; RTC_LOG(LS_INFO) << "[" << name
RTC_LOG(LS_INFO) << "[" << name << "] Pre encoded : " << counters.pre_encoded; << "] Captured : " << counters.captured;
RTC_LOG(LS_INFO) << "[" << name << "] Encoded : " << counters.encoded; RTC_LOG(LS_INFO) << "[" << name
RTC_LOG(LS_INFO) << "[" << name << "] Received : " << counters.received; << "] Pre encoded : " << counters.pre_encoded;
RTC_LOG(LS_INFO) << "[" << name << "] Decoded : " << counters.decoded; RTC_LOG(LS_INFO) << "[" << name
RTC_LOG(LS_INFO) << "[" << name << "] Rendered : " << counters.rendered; << "] Encoded : " << counters.encoded;
RTC_LOG(LS_INFO) << "[" << name << "] Dropped : " << counters.dropped; RTC_LOG(LS_INFO) << "[" << name
<< "] Received : " << counters.received;
RTC_LOG(LS_INFO) << "[" << name
<< "] Decoded : " << counters.decoded;
RTC_LOG(LS_INFO) << "[" << name
<< "] Rendered : " << counters.rendered;
RTC_LOG(LS_INFO) << "[" << name
<< "] Dropped : " << counters.dropped;
RTC_LOG(LS_INFO) << "[" << name
<< "] Failed to decode : " << counters.failed_to_decode;
} }
void LogStreamInternalStats(const std::string& name, void LogStreamInternalStats(const std::string& name,
@ -392,7 +401,7 @@ void DefaultVideoQualityAnalyzer::OnFrameDecoded(
it->second.HasDecodeEndTime(peer_index)) { it->second.HasDecodeEndTime(peer_index)) {
// It means this frame was decoded before, so we can skip it. It may happen // It means this frame was decoded before, so we can skip it. It may happen
// when we have multiple simulcast streams in one track and received // when we have multiple simulcast streams in one track and received
// the same picture from two different streams because SFU can't reliably // the same frame from two different streams because SFU can't reliably
// correlate two simulcast streams and started relaying the second stream // correlate two simulcast streams and started relaying the second stream
// from the same frame it has relayed right before for the first stream. // from the same frame it has relayed right before for the first stream.
return; return;
@ -529,9 +538,45 @@ void DefaultVideoQualityAnalyzer::OnEncoderError(
void DefaultVideoQualityAnalyzer::OnDecoderError(absl::string_view peer_name, void DefaultVideoQualityAnalyzer::OnDecoderError(absl::string_view peer_name,
uint16_t frame_id, uint16_t frame_id,
int32_t error_code) { int32_t error_code,
const DecoderStats& stats) {
RTC_LOG(LS_ERROR) << "Decoder error for frame_id=" << frame_id RTC_LOG(LS_ERROR) << "Decoder error for frame_id=" << frame_id
<< ", code=" << error_code; << ", code=" << error_code;
MutexLock lock(&mutex_);
RTC_CHECK_EQ(state_, State::kActive)
<< "DefaultVideoQualityAnalyzer has to be started before use";
size_t peer_index = peers_->index(peer_name);
if (frame_id == VideoFrame::kNotSetId) {
frame_counters_.failed_to_decode++;
unknown_sender_frame_counters_[std::string(peer_name)].failed_to_decode++;
return;
}
auto it = captured_frames_in_flight_.find(frame_id);
if (it == captured_frames_in_flight_.end() ||
it->second.HasDecodeEndTime(peer_index)) {
// It means this frame was decoded before, so we can skip it. It may happen
// when we have multiple simulcast streams in one track and received
// the same frame from two different streams because SFU can't reliably
// correlate two simulcast streams and started relaying the second stream
// from the same frame it has relayed right before for the first stream.
return;
}
frame_counters_.failed_to_decode++;
InternalStatsKey key(it->second.stream(),
stream_to_sender_.at(it->second.stream()), peer_index);
stream_frame_counters_.at(key).failed_to_decode++;
Timestamp now = Now();
StreamCodecInfo used_decoder;
used_decoder.codec_name = stats.decoder_name;
used_decoder.first_frame_id = frame_id;
used_decoder.last_frame_id = frame_id;
used_decoder.switched_on_at = now;
used_decoder.switched_from_at = now;
it->second.OnDecoderError(peer_index, used_decoder);
} }
void DefaultVideoQualityAnalyzer::RegisterParticipantInCall( void DefaultVideoQualityAnalyzer::RegisterParticipantInCall(

View File

@ -78,7 +78,8 @@ class DefaultVideoQualityAnalyzer : public VideoQualityAnalyzerInterface {
int32_t error_code) override; int32_t error_code) override;
void OnDecoderError(absl::string_view peer_name, void OnDecoderError(absl::string_view peer_name,
uint16_t frame_id, uint16_t frame_id,
int32_t error_code) override; int32_t error_code,
const DecoderStats& stats) override;
void RegisterParticipantInCall(absl::string_view peer_name) override; void RegisterParticipantInCall(absl::string_view peer_name) override;
void UnregisterParticipantInCall(absl::string_view peer_name) override; void UnregisterParticipantInCall(absl::string_view peer_name) override;

View File

@ -127,11 +127,17 @@ bool FrameInFlight::HasReceivedTime(size_t peer) const {
void FrameInFlight::OnFrameDecoded(size_t peer, void FrameInFlight::OnFrameDecoded(size_t peer,
webrtc::Timestamp time, webrtc::Timestamp time,
StreamCodecInfo used_decoder) { const StreamCodecInfo& used_decoder) {
receiver_stats_[peer].decode_end_time = time; receiver_stats_[peer].decode_end_time = time;
receiver_stats_[peer].used_decoder = used_decoder; receiver_stats_[peer].used_decoder = used_decoder;
} }
void FrameInFlight::OnDecoderError(size_t peer,
const StreamCodecInfo& used_decoder) {
receiver_stats_[peer].decoder_failed = true;
receiver_stats_[peer].used_decoder = used_decoder;
}
bool FrameInFlight::HasDecodeEndTime(size_t peer) const { bool FrameInFlight::HasDecodeEndTime(size_t peer) const {
auto it = receiver_stats_.find(peer); auto it = receiver_stats_.find(peer);
if (it == receiver_stats_.end()) { if (it == receiver_stats_.end()) {
@ -187,6 +193,7 @@ FrameStats FrameInFlight::GetStatsForPeer(size_t peer) const {
stats.used_decoder = receiver_stats->used_decoder; stats.used_decoder = receiver_stats->used_decoder;
stats.pre_decoded_frame_type = receiver_stats->frame_type; stats.pre_decoded_frame_type = receiver_stats->frame_type;
stats.pre_decoded_image_size = receiver_stats->encoded_image_size; stats.pre_decoded_image_size = receiver_stats->encoded_image_size;
stats.decoder_failed = receiver_stats->decoder_failed;
} }
return stats; return stats;
} }

View File

@ -44,6 +44,7 @@ struct ReceiverFrameStats {
absl::optional<StreamCodecInfo> used_decoder = absl::nullopt; absl::optional<StreamCodecInfo> used_decoder = absl::nullopt;
bool dropped = false; bool dropped = false;
bool decoder_failed = false;
}; };
// Represents a frame which was sent by sender and is currently on the way to // Represents a frame which was sent by sender and is currently on the way to
@ -100,7 +101,8 @@ class FrameInFlight {
void OnFrameDecoded(size_t peer, void OnFrameDecoded(size_t peer,
webrtc::Timestamp time, webrtc::Timestamp time,
StreamCodecInfo used_decoder); const StreamCodecInfo& used_decoder);
void OnDecoderError(size_t peer, const StreamCodecInfo& used_decoder);
bool HasDecodeEndTime(size_t peer) const; bool HasDecodeEndTime(size_t peer) const;

View File

@ -77,6 +77,8 @@ FrameComparison ValidateFrameComparison(FrameComparison comparison) {
<< "Regular comparison has to have used_encoder"; << "Regular comparison has to have used_encoder";
RTC_DCHECK(comparison.frame_stats.used_decoder.has_value()) RTC_DCHECK(comparison.frame_stats.used_decoder.has_value())
<< "Regular comparison has to have used_decoder"; << "Regular comparison has to have used_decoder";
RTC_DCHECK(!comparison.frame_stats.decoder_failed)
<< "Regular comparison can't have decoder failure";
break; break;
case FrameComparisonType::kDroppedFrame: case FrameComparisonType::kDroppedFrame:
// Frame can be dropped before encoder, by encoder, inside network or // Frame can be dropped before encoder, by encoder, inside network or
@ -95,26 +97,27 @@ FrameComparison ValidateFrameComparison(FrameComparison comparison) {
<< "when encoded_time is finite."; << "when encoded_time is finite.";
} }
if (comparison.frame_stats.decode_end_time.IsFinite()) { if (comparison.frame_stats.decode_end_time.IsFinite() ||
comparison.frame_stats.decoder_failed) {
RTC_DCHECK(comparison.frame_stats.received_time.IsFinite()) RTC_DCHECK(comparison.frame_stats.received_time.IsFinite())
<< "Dropped frame comparison has to have received_time when " << "Dropped frame comparison has to have received_time when "
<< "decode_end_time is set"; << "decode_end_time is set or decoder_failed is true";
RTC_DCHECK(comparison.frame_stats.decode_start_time.IsFinite()) RTC_DCHECK(comparison.frame_stats.decode_start_time.IsFinite())
<< "Dropped frame comparison has to have decode_start_time when " << "Dropped frame comparison has to have decode_start_time when "
<< "decode_end_time is set"; << "decode_end_time is set or decoder_failed is true";
RTC_DCHECK(comparison.frame_stats.used_decoder.has_value()) RTC_DCHECK(comparison.frame_stats.used_decoder.has_value())
<< "Dropped frame comparison has to have used_decoder when " << "Dropped frame comparison has to have used_decoder when "
<< "decode_end_time is set"; << "decode_end_time is set or decoder_failed is true";
} else { } else {
RTC_DCHECK(!comparison.frame_stats.received_time.IsFinite()) RTC_DCHECK(!comparison.frame_stats.received_time.IsFinite())
<< "Dropped frame comparison can't have received_time when " << "Dropped frame comparison can't have received_time when "
<< "decode_end_time is not set"; << "decode_end_time is not set and there were no decoder failures";
RTC_DCHECK(!comparison.frame_stats.decode_start_time.IsFinite()) RTC_DCHECK(!comparison.frame_stats.decode_start_time.IsFinite())
<< "Dropped frame comparison can't have decode_start_time when " << "Dropped frame comparison can't have decode_start_time when "
<< "decode_end_time is not set"; << "decode_end_time is not set and there were no decoder failures";
RTC_DCHECK(!comparison.frame_stats.used_decoder.has_value()) RTC_DCHECK(!comparison.frame_stats.used_decoder.has_value())
<< "Dropped frame comparison can't have used_decoder when " << "Dropped frame comparison can't have used_decoder when "
<< "decode_end_time is not set"; << "decode_end_time is not set and there were no decoder failures";
} }
RTC_DCHECK(!comparison.frame_stats.rendered_time.IsFinite()) RTC_DCHECK(!comparison.frame_stats.rendered_time.IsFinite())
<< "Dropped frame comparison can't have rendered_time"; << "Dropped frame comparison can't have rendered_time";
@ -138,13 +141,15 @@ FrameComparison ValidateFrameComparison(FrameComparison comparison) {
RTC_DCHECK(!comparison.frame_stats.rendered_frame_height.has_value()) RTC_DCHECK(!comparison.frame_stats.rendered_frame_height.has_value())
<< "Frame in flight comparison can't have rendered_frame_height"; << "Frame in flight comparison can't have rendered_frame_height";
if (comparison.frame_stats.decode_end_time.IsFinite()) { if (comparison.frame_stats.decode_end_time.IsFinite() ||
comparison.frame_stats.decoder_failed) {
RTC_DCHECK(comparison.frame_stats.used_decoder.has_value()) RTC_DCHECK(comparison.frame_stats.used_decoder.has_value())
<< "Frame in flight comparison has to have used_decoder when " << "Frame in flight comparison has to have used_decoder when "
<< "decode_end_time is set"; << "decode_end_time is set or decoder_failed is true.";
RTC_DCHECK(comparison.frame_stats.decode_start_time.IsFinite()) RTC_DCHECK(comparison.frame_stats.decode_start_time.IsFinite())
<< "Frame in flight comparison has to have finite " << "Frame in flight comparison has to have finite "
<< "decode_start_time when decode_end_time is finite."; << "decode_start_time when decode_end_time is finite or "
<< "decoder_failed is true.";
} }
if (comparison.frame_stats.decode_start_time.IsFinite()) { if (comparison.frame_stats.decode_start_time.IsFinite()) {
RTC_DCHECK(comparison.frame_stats.received_time.IsFinite()) RTC_DCHECK(comparison.frame_stats.received_time.IsFinite())
@ -415,6 +420,9 @@ void DefaultVideoQualityAnalyzerFramesComparator::ProcessComparison(
FrameDropPhase dropped_phase; FrameDropPhase dropped_phase;
if (frame_stats.decode_end_time.IsFinite()) { if (frame_stats.decode_end_time.IsFinite()) {
dropped_phase = FrameDropPhase::kAfterDecoder; dropped_phase = FrameDropPhase::kAfterDecoder;
} else if (frame_stats.decode_start_time.IsFinite() &&
frame_stats.decoder_failed) {
dropped_phase = FrameDropPhase::kByDecoder;
} else if (frame_stats.encoded_time.IsFinite()) { } else if (frame_stats.encoded_time.IsFinite()) {
dropped_phase = FrameDropPhase::kTransport; dropped_phase = FrameDropPhase::kTransport;
} else if (frame_stats.pre_encode_time.IsFinite()) { } else if (frame_stats.pre_encode_time.IsFinite()) {
@ -441,7 +449,8 @@ void DefaultVideoQualityAnalyzerFramesComparator::ProcessComparison(
} }
} }
// Next stats can be calculated only if frame was received on remote side. // Next stats can be calculated only if frame was received on remote side.
if (comparison.type != FrameComparisonType::kDroppedFrame) { if (comparison.type != FrameComparisonType::kDroppedFrame ||
comparison.frame_stats.decoder_failed) {
if (frame_stats.rendered_time.IsFinite()) { if (frame_stats.rendered_time.IsFinite()) {
stats->resolution_of_rendered_frame.AddSample( stats->resolution_of_rendered_frame.AddSample(
StatsSample(*comparison.frame_stats.rendered_frame_width * StatsSample(*comparison.frame_stats.rendered_frame_width *

View File

@ -68,6 +68,8 @@ struct FrameStats {
absl::optional<StreamCodecInfo> used_encoder = absl::nullopt; absl::optional<StreamCodecInfo> used_encoder = absl::nullopt;
// Can be not set if frame was dropped in the network. // Can be not set if frame was dropped in the network.
absl::optional<StreamCodecInfo> used_decoder = absl::nullopt; absl::optional<StreamCodecInfo> used_decoder = absl::nullopt;
bool decoder_failed = false;
}; };
// Describes why comparison was done in overloaded mode (without calculating // Describes why comparison was done in overloaded mode (without calculating

View File

@ -43,6 +43,13 @@ rtc::StringBuilder& operator<<(rtc::StringBuilder& sb,
return sb << state.ToString(); return sb << state.ToString();
} }
bool operator==(const StreamCodecInfo& a, const StreamCodecInfo& b) {
return a.codec_name == b.codec_name && a.first_frame_id == b.first_frame_id &&
a.last_frame_id == b.last_frame_id &&
a.switched_on_at == b.switched_on_at &&
a.switched_from_at == b.switched_from_at;
}
std::string ToString(FrameDropPhase phase) { std::string ToString(FrameDropPhase phase) {
switch (phase) { switch (phase) {
case FrameDropPhase::kBeforeEncoder: case FrameDropPhase::kBeforeEncoder:
@ -51,6 +58,8 @@ std::string ToString(FrameDropPhase phase) {
return "kByEncoder"; return "kByEncoder";
case FrameDropPhase::kTransport: case FrameDropPhase::kTransport:
return "kTransport"; return "kTransport";
case FrameDropPhase::kByDecoder:
return "kByDecoder";
case FrameDropPhase::kAfterDecoder: case FrameDropPhase::kAfterDecoder:
return "kAfterDecoder"; return "kAfterDecoder";
case FrameDropPhase::kLastValue: case FrameDropPhase::kLastValue:

View File

@ -64,6 +64,9 @@ struct FrameCounters {
// Count of frames that were dropped in any point between capturing and // Count of frames that were dropped in any point between capturing and
// rendering. // rendering.
int64_t dropped = 0; int64_t dropped = 0;
// Count of frames for which decoder returned error when they were sent for
// decoding.
int64_t failed_to_decode = 0;
}; };
// Contains information about the codec that was used for encoding or decoding // Contains information about the codec that was used for encoding or decoding
@ -86,6 +89,7 @@ struct StreamCodecInfo {
std::ostream& operator<<(std::ostream& os, const StreamCodecInfo& state); std::ostream& operator<<(std::ostream& os, const StreamCodecInfo& state);
rtc::StringBuilder& operator<<(rtc::StringBuilder& sb, rtc::StringBuilder& operator<<(rtc::StringBuilder& sb,
const StreamCodecInfo& state); const StreamCodecInfo& state);
bool operator==(const StreamCodecInfo& a, const StreamCodecInfo& b);
// Represents phases where video frame can be dropped and such drop will be // Represents phases where video frame can be dropped and such drop will be
// detected by analyzer. // detected by analyzer.
@ -93,6 +97,7 @@ enum class FrameDropPhase : int {
kBeforeEncoder, kBeforeEncoder,
kByEncoder, kByEncoder,
kTransport, kTransport,
kByDecoder,
kAfterDecoder, kAfterDecoder,
// kLastValue must be the last value in this enumeration. // kLastValue must be the last value in this enumeration.
kLastValue kLastValue

View File

@ -100,13 +100,15 @@ int32_t QualityAnalyzingVideoDecoder::Decode(const EncodedImage& input_image,
delegate_->Decode(*origin_image, missing_frames, render_time_ms); delegate_->Decode(*origin_image, missing_frames, render_time_ms);
if (result != WEBRTC_VIDEO_CODEC_OK) { if (result != WEBRTC_VIDEO_CODEC_OK) {
// If delegate decoder failed, then cleanup data for this image. // If delegate decoder failed, then cleanup data for this image.
VideoQualityAnalyzerInterface::DecoderStats stats;
{ {
MutexLock lock(&mutex_); MutexLock lock(&mutex_);
timestamp_to_frame_id_.erase(input_image.Timestamp()); timestamp_to_frame_id_.erase(input_image.Timestamp());
decoding_images_.erase(input_image.Timestamp()); decoding_images_.erase(input_image.Timestamp());
stats.decoder_name = codec_name_;
} }
analyzer_->OnDecoderError(peer_name_, analyzer_->OnDecoderError(
out.id.value_or(VideoFrame::kNotSetId), result); peer_name_, out.id.value_or(VideoFrame::kNotSetId), result, stats);
} }
return result; return result;
} }