221 lines
9.9 KiB
Diff
221 lines
9.9 KiB
Diff
From: Andreas Pehrson <apehrson@mozilla.com>
|
|
Date: Thu, 6 Jan 2022 00:16:00 +0000
|
|
Subject: Bug 1748458 - Add TRACE_EVENTs for dropped frames and packets for
|
|
received video. r=bwc
|
|
|
|
This lets us see in the profiler how many received frames and packets we decide
|
|
to drop and the reasons why.
|
|
|
|
Differential Revision: https://phabricator.services.mozilla.com/D135062
|
|
Mercurial Revision: https://hg.mozilla.org/mozilla-central/rev/08e252da94c4752eccfd845eef13d8517953cc6a
|
|
|
|
Also includes:
|
|
|
|
Bug 1804288 - (fix-de7ae5755b) reimplement Bug 1748458 - Add TRACE_EVENTs for dropped frames and packets for received video. r=pehrsons
|
|
|
|
Differential Revision: https://phabricator.services.mozilla.com/D163960
|
|
Mercurial Revision: https://hg.mozilla.org/mozilla-central/rev/8e9a326a99cd5eaa6e447ff57c01ad9d79a09744
|
|
---
|
|
api/video/frame_buffer.cc | 33 +++++++++++++++++++++++++
|
|
video/receive_statistics_proxy.cc | 11 +++++++++
|
|
video/rtp_video_stream_receiver2.cc | 4 +++
|
|
video/video_stream_buffer_controller.cc | 7 ++++++
|
|
4 files changed, 55 insertions(+)
|
|
|
|
diff --git a/api/video/frame_buffer.cc b/api/video/frame_buffer.cc
|
|
index 4981acf0ca..f0c48f3702 100644
|
|
--- a/api/video/frame_buffer.cc
|
|
+++ b/api/video/frame_buffer.cc
|
|
@@ -25,6 +25,7 @@
|
|
#include "api/video/encoded_frame.h"
|
|
#include "rtc_base/logging.h"
|
|
#include "rtc_base/numerics/sequence_number_util.h"
|
|
+#include "rtc_base/trace_event.h"
|
|
|
|
namespace webrtc {
|
|
namespace {
|
|
@@ -77,7 +78,12 @@ FrameBuffer::FrameBuffer(int max_size,
|
|
decoded_frame_history_(max_decode_history) {}
|
|
|
|
bool FrameBuffer::InsertFrame(std::unique_ptr<EncodedFrame> frame) {
|
|
+ const uint32_t ssrc =
|
|
+ frame->PacketInfos().empty() ? 0 : frame->PacketInfos()[0].ssrc();
|
|
if (!ValidReferences(*frame)) {
|
|
+ TRACE_EVENT2("webrtc",
|
|
+ "FrameBuffer::InsertFrame Frame dropped (Invalid references)",
|
|
+ "remote_ssrc", ssrc, "frame_id", frame->Id());
|
|
RTC_DLOG(LS_WARNING) << "Frame " << frame->Id()
|
|
<< " has invalid references, dropping frame.";
|
|
return false;
|
|
@@ -87,23 +93,35 @@ bool FrameBuffer::InsertFrame(std::unique_ptr<EncodedFrame> frame) {
|
|
if (legacy_frame_id_jump_behavior_ && frame->is_keyframe() &&
|
|
AheadOf(frame->RtpTimestamp(),
|
|
*decoded_frame_history_.GetLastDecodedFrameTimestamp())) {
|
|
+ TRACE_EVENT2("webrtc",
|
|
+ "FrameBuffer::InsertFrame Frames dropped (OOO + PicId jump)",
|
|
+ "remote_ssrc", ssrc, "frame_id", frame->Id());
|
|
RTC_DLOG(LS_WARNING)
|
|
<< "Keyframe " << frame->Id()
|
|
<< " has newer timestamp but older picture id, clearing buffer.";
|
|
Clear();
|
|
} else {
|
|
// Already decoded past this frame.
|
|
+ TRACE_EVENT2("webrtc",
|
|
+ "FrameBuffer::InsertFrame Frame dropped (Out of order)",
|
|
+ "remote_ssrc", ssrc, "frame_id", frame->Id());
|
|
return false;
|
|
}
|
|
}
|
|
|
|
if (frames_.size() == max_size_) {
|
|
if (frame->is_keyframe()) {
|
|
+ TRACE_EVENT2("webrtc",
|
|
+ "FrameBuffer::InsertFrame Frames dropped (KF + Full buffer)",
|
|
+ "remote_ssrc", ssrc, "frame_id", frame->Id());
|
|
RTC_DLOG(LS_WARNING) << "Keyframe " << frame->Id()
|
|
<< " inserted into full buffer, clearing buffer.";
|
|
Clear();
|
|
} else {
|
|
// No space for this frame.
|
|
+ TRACE_EVENT2("webrtc",
|
|
+ "FrameBuffer::InsertFrame Frame dropped (Full buffer)",
|
|
+ "remote_ssrc", ssrc, "frame_id", frame->Id());
|
|
return false;
|
|
}
|
|
}
|
|
@@ -158,16 +176,31 @@ void FrameBuffer::DropNextDecodableTemporalUnit() {
|
|
|
|
void FrameBuffer::UpdateDroppedFramesAndDiscardedPackets(FrameIterator begin_it,
|
|
FrameIterator end_it) {
|
|
+ uint32_t dropped_ssrc = 0;
|
|
+ int64_t dropped_frame_id = 0;
|
|
unsigned int num_discarded_packets = 0;
|
|
unsigned int num_dropped_frames =
|
|
std::count_if(begin_it, end_it, [&](const auto& f) {
|
|
if (f.second.encoded_frame) {
|
|
const auto& packetInfos = f.second.encoded_frame->PacketInfos();
|
|
+ dropped_frame_id = f.first;
|
|
+ if (!packetInfos.empty()) {
|
|
+ dropped_ssrc = packetInfos[0].ssrc();
|
|
+ }
|
|
num_discarded_packets += packetInfos.size();
|
|
}
|
|
return f.second.encoded_frame != nullptr;
|
|
});
|
|
|
|
+ if (num_dropped_frames > 0) {
|
|
+ TRACE_EVENT2("webrtc", "FrameBuffer Dropping Old Frames", "remote_ssrc",
|
|
+ dropped_ssrc, "frame_id", dropped_frame_id);
|
|
+ }
|
|
+ if (num_discarded_packets > 0) {
|
|
+ TRACE_EVENT2("webrtc", "FrameBuffer Discarding Old Packets", "remote_ssrc",
|
|
+ dropped_ssrc, "frame_id", dropped_frame_id);
|
|
+ }
|
|
+
|
|
num_dropped_frames_ += num_dropped_frames;
|
|
num_discarded_packets_ += num_discarded_packets;
|
|
}
|
|
diff --git a/video/receive_statistics_proxy.cc b/video/receive_statistics_proxy.cc
|
|
index 8fbaf0ac0e..7924ef2594 100644
|
|
--- a/video/receive_statistics_proxy.cc
|
|
+++ b/video/receive_statistics_proxy.cc
|
|
@@ -20,6 +20,7 @@
|
|
#include "rtc_base/strings/string_builder.h"
|
|
#include "rtc_base/thread.h"
|
|
#include "rtc_base/time_utils.h"
|
|
+#include "rtc_base/trace_event.h"
|
|
#include "system_wrappers/include/clock.h"
|
|
#include "system_wrappers/include/metrics.h"
|
|
#include "video/video_receive_stream2.h"
|
|
@@ -766,6 +767,9 @@ void ReceiveStatisticsProxy::OnCompleteFrame(bool is_keyframe,
|
|
VideoContentType content_type) {
|
|
RTC_DCHECK_RUN_ON(&main_thread_);
|
|
|
|
+ TRACE_EVENT2("webrtc", "ReceiveStatisticsProxy::OnCompleteFrame",
|
|
+ "remote_ssrc", remote_ssrc_, "is_keyframe", is_keyframe);
|
|
+
|
|
// Content type extension is set only for keyframes and should be propagated
|
|
// for all the following delta frames. Here we may receive frames out of order
|
|
// and miscategorise some delta frames near the layer switch.
|
|
@@ -791,6 +795,8 @@ void ReceiveStatisticsProxy::OnCompleteFrame(bool is_keyframe,
|
|
void ReceiveStatisticsProxy::OnDroppedFrames(uint32_t frames_dropped) {
|
|
// Can be called on either the decode queue or the worker thread
|
|
// See FrameBuffer2 for more details.
|
|
+ TRACE_EVENT2("webrtc", "ReceiveStatisticsProxy::OnDroppedFrames",
|
|
+ "remote_ssrc", remote_ssrc_, "frames_dropped", frames_dropped);
|
|
worker_thread_->PostTask(
|
|
SafeTask(task_safety_.flag(), [frames_dropped, this]() {
|
|
RTC_DCHECK_RUN_ON(&main_thread_);
|
|
@@ -801,6 +807,9 @@ void ReceiveStatisticsProxy::OnDroppedFrames(uint32_t frames_dropped) {
|
|
void ReceiveStatisticsProxy::OnDiscardedPackets(uint32_t packets_discarded) {
|
|
// Can be called on either the decode queue or the worker thread
|
|
// See FrameBuffer2 for more details.
|
|
+ TRACE_EVENT2("webrtc", "ReceiveStatisticsProxy::OnDiscardedPackets",
|
|
+ "remote_ssrc", remote_ssrc_, "packets_discarded",
|
|
+ packets_discarded);
|
|
worker_thread_->PostTask(
|
|
SafeTask(task_safety_.flag(), [packets_discarded, this]() {
|
|
RTC_DCHECK_RUN_ON(&main_thread_);
|
|
@@ -829,6 +838,8 @@ void ReceiveStatisticsProxy::OnStreamInactive() {
|
|
|
|
void ReceiveStatisticsProxy::OnRttUpdate(int64_t avg_rtt_ms) {
|
|
RTC_DCHECK_RUN_ON(&main_thread_);
|
|
+ TRACE_EVENT2("webrtc", "ReceiveStatisticsProxy::OnRttUpdate",
|
|
+ "remote_ssrc", remote_ssrc_, "avg_rtt_ms", avg_rtt_ms);
|
|
avg_rtt_ms_ = avg_rtt_ms;
|
|
}
|
|
|
|
diff --git a/video/rtp_video_stream_receiver2.cc b/video/rtp_video_stream_receiver2.cc
|
|
index 73a8da11aa..5bf7f51c8e 100644
|
|
--- a/video/rtp_video_stream_receiver2.cc
|
|
+++ b/video/rtp_video_stream_receiver2.cc
|
|
@@ -49,6 +49,7 @@
|
|
#include "rtc_base/checks.h"
|
|
#include "rtc_base/logging.h"
|
|
#include "rtc_base/strings/string_builder.h"
|
|
+#include "rtc_base/trace_event.h"
|
|
#include "system_wrappers/include/metrics.h"
|
|
#include "system_wrappers/include/ntp_time.h"
|
|
|
|
@@ -1325,6 +1326,9 @@ void RtpVideoStreamReceiver2::FrameDecoded(int64_t picture_id) {
|
|
packet_infos_.upper_bound(unwrapped_rtp_seq_num));
|
|
uint32_t num_packets_cleared = packet_buffer_.ClearTo(seq_num);
|
|
if (num_packets_cleared > 0) {
|
|
+ TRACE_EVENT2("webrtc",
|
|
+ "RtpVideoStreamReceiver2::FrameDecoded Cleared Old Packets",
|
|
+ "remote_ssrc", config_.rtp.remote_ssrc, "seq_num", seq_num);
|
|
vcm_receive_statistics_->OnDiscardedPackets(num_packets_cleared);
|
|
}
|
|
reference_finder_->ClearTo(seq_num);
|
|
diff --git a/video/video_stream_buffer_controller.cc b/video/video_stream_buffer_controller.cc
|
|
index 01063b12f7..e12ce75ba0 100644
|
|
--- a/video/video_stream_buffer_controller.cc
|
|
+++ b/video/video_stream_buffer_controller.cc
|
|
@@ -31,6 +31,7 @@
|
|
#include "rtc_base/checks.h"
|
|
#include "rtc_base/logging.h"
|
|
#include "rtc_base/thread_annotations.h"
|
|
+#include "rtc_base/trace_event.h"
|
|
#include "video/frame_decode_scheduler.h"
|
|
#include "video/frame_decode_timing.h"
|
|
#include "video/task_queue_frame_decode_scheduler.h"
|
|
@@ -152,6 +153,9 @@ std::optional<int64_t> VideoStreamBufferController::InsertFrame(
|
|
std::unique_ptr<EncodedFrame> frame) {
|
|
RTC_DCHECK_RUN_ON(&worker_sequence_checker_);
|
|
FrameMetadata metadata(*frame);
|
|
+ const uint32_t ssrc =
|
|
+ frame->PacketInfos().empty() ? 0 : frame->PacketInfos()[0].ssrc();
|
|
+ const int64_t frameId = frame->Id();
|
|
int complete_units = buffer_->GetTotalNumberOfContinuousTemporalUnits();
|
|
if (buffer_->InsertFrame(std::move(frame))) {
|
|
RTC_DCHECK(metadata.receive_time) << "Frame receive time must be set!";
|
|
@@ -162,6 +166,9 @@ std::optional<int64_t> VideoStreamBufferController::InsertFrame(
|
|
*metadata.receive_time);
|
|
}
|
|
if (complete_units < buffer_->GetTotalNumberOfContinuousTemporalUnits()) {
|
|
+ TRACE_EVENT2("webrtc",
|
|
+ "VideoStreamBufferController::InsertFrame Frame Complete",
|
|
+ "remote_ssrc", ssrc, "frame_id", frameId);
|
|
stats_proxy_->OnCompleteFrame(metadata.is_keyframe, metadata.size,
|
|
metadata.contentType);
|
|
MaybeScheduleFrameForRelease();
|