Skip to content

Commit

Permalink
Bug 1748458 - Add TRACE_EVENTs for dropped frames and packets for rec…
Browse files Browse the repository at this point in the history 
…eived 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
  • Loading branch information
@Pehrsons
Pehrsons committed Jan 6, 2022
1 parent 275727d commit 2c879f9
Show file tree
Hide file tree
Showing 3 changed files with 54 additions and 0 deletions.
39 changes: 39 additions & 0 deletions third_party/libwebrtc/modules/video_coding/frame_buffer2.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -262,9 +262,19 @@ EncodedFrame* FrameBuffer::GetNextFrame() {
return frame.second.frame != nullptr;
});
if (discarded_packets > 0) {
const auto& pis = frame->PacketInfos();
TRACE_EVENT2("webrtc",
"FrameBuffer::GetNextFrame Discarding Old Packets",
"remote_ssrc", pis.empty() ? 0 : pis[0].ssrc(), "picture_id",
frame_it->first.picture_id);
stats_callback_->OnDiscardedPackets(discarded_packets);
}
if (dropped_frames > 0) {
const auto& pis = frame->PacketInfos();
TRACE_EVENT2("webrtc",
"FrameBuffer::GetNextFrame Dropping Old Frames",
"remote_ssrc", pis.empty() ? 0 : pis[0].ssrc(), "picture_id",
frame_it->first.picture_id);
stats_callback_->OnDroppedFrames(dropped_frames);
}
}
Expand Down Expand Up @@ -441,11 +451,16 @@ int64_t FrameBuffer::InsertFrame(std::unique_ptr<EncodedFrame> frame) {

MutexLock lock(&mutex_);

const auto& pis = frame->PacketInfos();
const VideoLayerFrameId& id = frame->id;
int64_t last_continuous_picture_id =
!last_continuous_frame_ ? -1 : last_continuous_frame_->picture_id;

if (!ValidReferences(*frame)) {
TRACE_EVENT2("webrtc",
"FrameBuffer::InsertFrame Frame dropped (Invalid references)",
"remote_ssrc", pis.empty() ? 0 : pis[0].ssrc(), "picture_id",
id.picture_id);
RTC_LOG(LS_WARNING) << "Frame with (picture_id:spatial_id) ("
<< id.picture_id << ":"
<< static_cast<int>(id.spatial_layer)
Expand All @@ -455,13 +470,21 @@ int64_t FrameBuffer::InsertFrame(std::unique_ptr<EncodedFrame> frame) {

if (frames_.size() >= kMaxFramesBuffered) {
if (frame->is_keyframe()) {
TRACE_EVENT2("webrtc",
"FrameBuffer::InsertFrame Frames dropped (KF + Full buffer)",
"remote_ssrc", pis.empty() ? 0 : pis[0].ssrc(), "picture_id",
id.picture_id);
RTC_LOG(LS_WARNING) << "Inserting keyframe (picture_id:spatial_id) ("
<< id.picture_id << ":"
<< static_cast<int>(id.spatial_layer)
<< ") but buffer is full, clearing"
" buffer and inserting the frame.";
ClearFramesAndHistory();
} else {
TRACE_EVENT2("webrtc",
"FrameBuffer::InsertFrame Frame dropped (Full buffer)",
"remote_ssrc", pis.empty() ? 0 : pis[0].ssrc(), "picture_id",
id.picture_id);
RTC_LOG(LS_WARNING) << "Frame with (picture_id:spatial_id) ("
<< id.picture_id << ":"
<< static_cast<int>(id.spatial_layer)
Expand All @@ -482,11 +505,19 @@ int64_t FrameBuffer::InsertFrame(std::unique_ptr<EncodedFrame> frame) {
// reconfiguration or some other reason. Even though this is not according
// to spec we can still continue to decode from this frame if it is a
// keyframe.
TRACE_EVENT2("webrtc",
"FrameBuffer::InsertFrame Frames dropped (OOO + PicId jump)",
"remote_ssrc", pis.empty() ? 0 : pis[0].ssrc(), "picture_id",
id.picture_id);
RTC_LOG(LS_WARNING)
<< "A jump in picture id was detected, clearing buffer.";
ClearFramesAndHistory();
last_continuous_picture_id = -1;
} else {
TRACE_EVENT2("webrtc",
"FrameBuffer::InsertFrame Frame dropped (Out of order)",
"remote_ssrc", pis.empty() ? 0 : pis[0].ssrc(), "picture_id",
id.picture_id);
RTC_LOG(LS_WARNING) << "Frame with (picture_id:spatial_id) ("
<< id.picture_id << ":"
<< static_cast<int>(id.spatial_layer)
Expand All @@ -503,6 +534,10 @@ int64_t FrameBuffer::InsertFrame(std::unique_ptr<EncodedFrame> frame) {
// when the picture id make large jumps mid stream.
if (!frames_.empty() && id < frames_.begin()->first &&
frames_.rbegin()->first < id) {
TRACE_EVENT2("webrtc",
"FrameBuffer::InsertFrame Frames dropped (PicId big-jump)",
"remote_ssrc", pis.empty() ? 0 : pis[0].ssrc(), "picture_id",
id.picture_id);
RTC_LOG(LS_WARNING)
<< "A jump in picture id was detected, clearing buffer.";
ClearFramesAndHistory();
Expand All @@ -522,6 +557,10 @@ int64_t FrameBuffer::InsertFrame(std::unique_ptr<EncodedFrame> frame) {
timing_->IncomingTimestamp(frame->Timestamp(), frame->ReceivedTime());

if (stats_callback_ && IsCompleteSuperFrame(*frame)) {
TRACE_EVENT2("webrtc",
"FrameBuffer::InsertFrame Frame Complete",
"remote_ssrc", pis.empty() ? 0 : pis[0].ssrc(), "picture_id",
id.picture_id);
stats_callback_->OnCompleteFrame(frame->is_keyframe(), frame->size(),
frame->contentType());
}
Expand Down
11 changes: 11 additions & 0 deletions third_party/libwebrtc/video/receive_statistics_proxy2.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@
#include "rtc_base/task_utils/to_queued_task.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/field_trial.h"
#include "system_wrappers/include/metrics.h"
Expand Down Expand Up @@ -973,6 +974,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);

if (is_keyframe) {
++stats_.frame_counts.key_frames;
} else {
Expand Down Expand Up @@ -1004,6 +1008,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(ToQueuedTask(task_safety_, [frames_dropped, this]() {
RTC_DCHECK_RUN_ON(&main_thread_);
stats_.frames_dropped += frames_dropped;
Expand All @@ -1013,6 +1019,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(
ToQueuedTask(task_safety_, [packets_discarded, this]() {
RTC_DCHECK_RUN_ON(&main_thread_);
Expand Down Expand Up @@ -1045,6 +1054,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;
}

Expand Down
4 changes: 4 additions & 0 deletions third_party/libwebrtc/video/rtp_video_stream_receiver2.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -46,6 +46,7 @@
#include "rtc_base/location.h"
#include "rtc_base/logging.h"
#include "rtc_base/strings/string_builder.h"
#include "rtc_base/trace_event.h"
#include "system_wrappers/include/field_trial.h"
#include "system_wrappers/include/metrics.h"
#include "system_wrappers/include/ntp_time.h"
Expand Down Expand Up @@ -1103,6 +1104,9 @@ void RtpVideoStreamReceiver2::FrameDecoded(int64_t picture_id) {
if (seq_num != -1) {
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);
Expand Down

0 comments on commit 2c879f9

Please sign in to comment.