1 /*
2 * Copyright 2018 The WebRTC project authors. All Rights Reserved.
3 *
4 * Use of this source code is governed by a BSD-style license
5 * that can be found in the LICENSE file in the root of the source
6 * tree. An additional intellectual property rights grant can be found
7 * in the file PATENTS. All contributing project authors may
8 * be found in the AUTHORS file in the root of the source tree.
9 */
10 #include "video/video_analyzer.h"
11
12 #include <inttypes.h>
13
14 #include <algorithm>
15 #include <utility>
16
17 #include "absl/algorithm/container.h"
18 #include "absl/flags/flag.h"
19 #include "absl/flags/parse.h"
20 #include "absl/strings/string_view.h"
21 #include "api/test/metrics/global_metrics_logger_and_exporter.h"
22 #include "api/test/metrics/metric.h"
23 #include "common_video/libyuv/include/webrtc_libyuv.h"
24 #include "modules/rtp_rtcp/source/create_video_rtp_depacketizer.h"
25 #include "modules/rtp_rtcp/source/rtp_packet.h"
26 #include "modules/rtp_rtcp/source/rtp_util.h"
27 #include "rtc_base/cpu_time.h"
28 #include "rtc_base/memory_usage.h"
29 #include "rtc_base/task_queue_for_test.h"
30 #include "rtc_base/task_utils/repeating_task.h"
31 #include "rtc_base/time_utils.h"
32 #include "system_wrappers/include/cpu_info.h"
33 #include "test/call_test.h"
34 #include "test/testsupport/file_utils.h"
35 #include "test/testsupport/frame_writer.h"
36 #include "test/testsupport/test_artifacts.h"
37
38 ABSL_FLAG(bool,
39 save_worst_frame,
40 false,
41 "Enable saving a frame with the lowest PSNR to a jpeg file in the "
42 "test_artifacts_dir");
43
44 namespace webrtc {
45 namespace {
46
47 using ::webrtc::test::GetGlobalMetricsLogger;
48 using ::webrtc::test::ImprovementDirection;
49 using ::webrtc::test::Metric;
50 using ::webrtc::test::Unit;
51
52 constexpr TimeDelta kSendStatsPollingInterval = TimeDelta::Seconds(1);
53 constexpr size_t kMaxComparisons = 10;
54 // How often is keep alive message printed.
55 constexpr TimeDelta kKeepAliveInterval = TimeDelta::Seconds(30);
56 // Interval between checking that the test is over.
57 constexpr TimeDelta kProbingInterval = TimeDelta::Millis(500);
58 constexpr int kKeepAliveIntervalIterations =
59 kKeepAliveInterval.ms() / kProbingInterval.ms();
60
IsFlexfec(int payload_type)61 bool IsFlexfec(int payload_type) {
62 return payload_type == test::CallTest::kFlexfecPayloadType;
63 }
64
65 } // namespace
66
VideoAnalyzer(test::LayerFilteringTransport * transport,const std::string & test_label,double avg_psnr_threshold,double avg_ssim_threshold,int duration_frames,TimeDelta test_duration,FILE * graph_data_output_file,const std::string & graph_title,uint32_t ssrc_to_analyze,uint32_t rtx_ssrc_to_analyze,size_t selected_stream,int selected_sl,int selected_tl,bool is_quick_test_enabled,Clock * clock,std::string rtp_dump_name,TaskQueueBase * task_queue)67 VideoAnalyzer::VideoAnalyzer(test::LayerFilteringTransport* transport,
68 const std::string& test_label,
69 double avg_psnr_threshold,
70 double avg_ssim_threshold,
71 int duration_frames,
72 TimeDelta test_duration,
73 FILE* graph_data_output_file,
74 const std::string& graph_title,
75 uint32_t ssrc_to_analyze,
76 uint32_t rtx_ssrc_to_analyze,
77 size_t selected_stream,
78 int selected_sl,
79 int selected_tl,
80 bool is_quick_test_enabled,
81 Clock* clock,
82 std::string rtp_dump_name,
83 TaskQueueBase* task_queue)
84 : transport_(transport),
85 receiver_(nullptr),
86 call_(nullptr),
87 send_stream_(nullptr),
88 receive_stream_(nullptr),
89 audio_receive_stream_(nullptr),
90 captured_frame_forwarder_(this, clock, duration_frames, test_duration),
91 test_label_(test_label),
92 graph_data_output_file_(graph_data_output_file),
93 graph_title_(graph_title),
94 ssrc_to_analyze_(ssrc_to_analyze),
95 rtx_ssrc_to_analyze_(rtx_ssrc_to_analyze),
96 selected_stream_(selected_stream),
97 selected_sl_(selected_sl),
98 selected_tl_(selected_tl),
99 mean_decode_time_ms_(0.0),
100 freeze_count_(0),
101 total_freezes_duration_ms_(0),
102 total_frames_duration_ms_(0),
103 sum_squared_frame_durations_(0),
104 decode_frame_rate_(0),
105 render_frame_rate_(0),
106 last_fec_bytes_(0),
107 frames_to_process_(duration_frames),
108 test_end_(clock->CurrentTime() + test_duration),
109 frames_recorded_(0),
110 frames_processed_(0),
111 captured_frames_(0),
112 dropped_frames_(0),
113 dropped_frames_before_first_encode_(0),
114 dropped_frames_before_rendering_(0),
115 last_render_time_(0),
116 last_render_delta_ms_(0),
117 last_unfreeze_time_ms_(0),
118 rtp_timestamp_delta_(0),
119 cpu_time_(0),
120 wallclock_time_(0),
121 avg_psnr_threshold_(avg_psnr_threshold),
122 avg_ssim_threshold_(avg_ssim_threshold),
123 is_quick_test_enabled_(is_quick_test_enabled),
124 quit_(false),
125 done_(true, false),
126 vp8_depacketizer_(CreateVideoRtpDepacketizer(kVideoCodecVP8)),
127 vp9_depacketizer_(CreateVideoRtpDepacketizer(kVideoCodecVP9)),
128 clock_(clock),
129 start_ms_(clock->TimeInMilliseconds()),
130 task_queue_(task_queue) {
131 // Create thread pool for CPU-expensive PSNR/SSIM calculations.
132
133 // Try to use about as many threads as cores, but leave kMinCoresLeft alone,
134 // so that we don't accidentally starve "real" worker threads (codec etc).
135 // Also, don't allocate more than kMaxComparisonThreads, even if there are
136 // spare cores.
137
138 uint32_t num_cores = CpuInfo::DetectNumberOfCores();
139 RTC_DCHECK_GE(num_cores, 1);
140 static const uint32_t kMinCoresLeft = 4;
141 static const uint32_t kMaxComparisonThreads = 8;
142
143 if (num_cores <= kMinCoresLeft) {
144 num_cores = 1;
145 } else {
146 num_cores -= kMinCoresLeft;
147 num_cores = std::min(num_cores, kMaxComparisonThreads);
148 }
149
150 for (uint32_t i = 0; i < num_cores; ++i) {
151 comparison_thread_pool_.push_back(rtc::PlatformThread::SpawnJoinable(
152 [this] {
153 while (CompareFrames()) {
154 }
155 },
156 "Analyzer"));
157 }
158
159 if (!rtp_dump_name.empty()) {
160 fprintf(stdout, "Writing rtp dump to %s\n", rtp_dump_name.c_str());
161 rtp_file_writer_.reset(test::RtpFileWriter::Create(
162 test::RtpFileWriter::kRtpDump, rtp_dump_name));
163 }
164 }
165
~VideoAnalyzer()166 VideoAnalyzer::~VideoAnalyzer() {
167 {
168 MutexLock lock(&comparison_lock_);
169 quit_ = true;
170 }
171 // Joins all threads.
172 comparison_thread_pool_.clear();
173 }
174
SetReceiver(PacketReceiver * receiver)175 void VideoAnalyzer::SetReceiver(PacketReceiver* receiver) {
176 receiver_ = receiver;
177 }
178
SetSource(rtc::VideoSourceInterface<VideoFrame> * video_source,bool respect_sink_wants)179 void VideoAnalyzer::SetSource(
180 rtc::VideoSourceInterface<VideoFrame>* video_source,
181 bool respect_sink_wants) {
182 if (respect_sink_wants)
183 captured_frame_forwarder_.SetSource(video_source);
184 rtc::VideoSinkWants wants;
185 video_source->AddOrUpdateSink(InputInterface(), wants);
186 }
187
SetCall(Call * call)188 void VideoAnalyzer::SetCall(Call* call) {
189 MutexLock lock(&lock_);
190 RTC_DCHECK(!call_);
191 call_ = call;
192 }
193
SetSendStream(VideoSendStream * stream)194 void VideoAnalyzer::SetSendStream(VideoSendStream* stream) {
195 MutexLock lock(&lock_);
196 RTC_DCHECK(!send_stream_);
197 send_stream_ = stream;
198 }
199
SetReceiveStream(VideoReceiveStreamInterface * stream)200 void VideoAnalyzer::SetReceiveStream(VideoReceiveStreamInterface* stream) {
201 MutexLock lock(&lock_);
202 RTC_DCHECK(!receive_stream_);
203 receive_stream_ = stream;
204 }
205
SetAudioReceiveStream(AudioReceiveStreamInterface * recv_stream)206 void VideoAnalyzer::SetAudioReceiveStream(
207 AudioReceiveStreamInterface* recv_stream) {
208 MutexLock lock(&lock_);
209 RTC_CHECK(!audio_receive_stream_);
210 audio_receive_stream_ = recv_stream;
211 }
212
InputInterface()213 rtc::VideoSinkInterface<VideoFrame>* VideoAnalyzer::InputInterface() {
214 return &captured_frame_forwarder_;
215 }
216
OutputInterface()217 rtc::VideoSourceInterface<VideoFrame>* VideoAnalyzer::OutputInterface() {
218 return &captured_frame_forwarder_;
219 }
220
DeliverPacket(MediaType media_type,rtc::CopyOnWriteBuffer packet,int64_t packet_time_us)221 PacketReceiver::DeliveryStatus VideoAnalyzer::DeliverPacket(
222 MediaType media_type,
223 rtc::CopyOnWriteBuffer packet,
224 int64_t packet_time_us) {
225 // Ignore timestamps of RTCP packets. They're not synchronized with
226 // RTP packet timestamps and so they would confuse wrap_handler_.
227 if (IsRtcpPacket(packet)) {
228 return receiver_->DeliverPacket(media_type, std::move(packet),
229 packet_time_us);
230 }
231
232 if (rtp_file_writer_) {
233 test::RtpPacket p;
234 memcpy(p.data, packet.cdata(), packet.size());
235 p.length = packet.size();
236 p.original_length = packet.size();
237 p.time_ms = clock_->TimeInMilliseconds() - start_ms_;
238 rtp_file_writer_->WritePacket(&p);
239 }
240
241 RtpPacket rtp_packet;
242 rtp_packet.Parse(packet);
243 if (!IsFlexfec(rtp_packet.PayloadType()) &&
244 (rtp_packet.Ssrc() == ssrc_to_analyze_ ||
245 rtp_packet.Ssrc() == rtx_ssrc_to_analyze_)) {
246 // Ignore FlexFEC timestamps, to avoid collisions with media timestamps.
247 // (FlexFEC and media are sent on different SSRCs, which have different
248 // timestamps spaces.)
249 // Also ignore packets from wrong SSRC, but include retransmits.
250 MutexLock lock(&lock_);
251 int64_t timestamp =
252 wrap_handler_.Unwrap(rtp_packet.Timestamp() - rtp_timestamp_delta_);
253 recv_times_[timestamp] = clock_->CurrentNtpInMilliseconds();
254 }
255
256 return receiver_->DeliverPacket(media_type, std::move(packet),
257 packet_time_us);
258 }
259
PreEncodeOnFrame(const VideoFrame & video_frame)260 void VideoAnalyzer::PreEncodeOnFrame(const VideoFrame& video_frame) {
261 MutexLock lock(&lock_);
262 if (!first_encoded_timestamp_) {
263 while (frames_.front().timestamp() != video_frame.timestamp()) {
264 ++dropped_frames_before_first_encode_;
265 frames_.pop_front();
266 RTC_CHECK(!frames_.empty());
267 }
268 first_encoded_timestamp_ = video_frame.timestamp();
269 }
270 }
271
PostEncodeOnFrame(size_t stream_id,uint32_t timestamp)272 void VideoAnalyzer::PostEncodeOnFrame(size_t stream_id, uint32_t timestamp) {
273 MutexLock lock(&lock_);
274 if (!first_sent_timestamp_ && stream_id == selected_stream_) {
275 first_sent_timestamp_ = timestamp;
276 }
277 }
278
SendRtp(const uint8_t * packet,size_t length,const PacketOptions & options)279 bool VideoAnalyzer::SendRtp(const uint8_t* packet,
280 size_t length,
281 const PacketOptions& options) {
282 RtpPacket rtp_packet;
283 rtp_packet.Parse(packet, length);
284
285 int64_t current_time = clock_->CurrentNtpInMilliseconds();
286
287 bool result = transport_->SendRtp(packet, length, options);
288 {
289 MutexLock lock(&lock_);
290 if (rtp_timestamp_delta_ == 0 && rtp_packet.Ssrc() == ssrc_to_analyze_) {
291 RTC_CHECK(static_cast<bool>(first_sent_timestamp_));
292 rtp_timestamp_delta_ = rtp_packet.Timestamp() - *first_sent_timestamp_;
293 }
294
295 if (!IsFlexfec(rtp_packet.PayloadType()) &&
296 rtp_packet.Ssrc() == ssrc_to_analyze_) {
297 // Ignore FlexFEC timestamps, to avoid collisions with media timestamps.
298 // (FlexFEC and media are sent on different SSRCs, which have different
299 // timestamps spaces.)
300 // Also ignore packets from wrong SSRC and retransmits.
301 int64_t timestamp =
302 wrap_handler_.Unwrap(rtp_packet.Timestamp() - rtp_timestamp_delta_);
303 send_times_[timestamp] = current_time;
304
305 if (IsInSelectedSpatialAndTemporalLayer(rtp_packet)) {
306 encoded_frame_sizes_[timestamp] += rtp_packet.payload_size();
307 }
308 }
309 }
310 return result;
311 }
312
SendRtcp(const uint8_t * packet,size_t length)313 bool VideoAnalyzer::SendRtcp(const uint8_t* packet, size_t length) {
314 return transport_->SendRtcp(packet, length);
315 }
316
OnFrame(const VideoFrame & video_frame)317 void VideoAnalyzer::OnFrame(const VideoFrame& video_frame) {
318 int64_t render_time_ms = clock_->CurrentNtpInMilliseconds();
319
320 MutexLock lock(&lock_);
321
322 StartExcludingCpuThreadTime();
323
324 int64_t send_timestamp =
325 wrap_handler_.Unwrap(video_frame.timestamp() - rtp_timestamp_delta_);
326
327 while (wrap_handler_.Unwrap(frames_.front().timestamp()) < send_timestamp) {
328 if (!last_rendered_frame_) {
329 // No previous frame rendered, this one was dropped after sending but
330 // before rendering.
331 ++dropped_frames_before_rendering_;
332 } else {
333 AddFrameComparison(frames_.front(), *last_rendered_frame_, true,
334 render_time_ms);
335 }
336 frames_.pop_front();
337 RTC_DCHECK(!frames_.empty());
338 }
339
340 VideoFrame reference_frame = frames_.front();
341 frames_.pop_front();
342 int64_t reference_timestamp =
343 wrap_handler_.Unwrap(reference_frame.timestamp());
344 if (send_timestamp == reference_timestamp - 1) {
345 // TODO(ivica): Make this work for > 2 streams.
346 // Look at RTPSender::BuildRTPHeader.
347 ++send_timestamp;
348 }
349 ASSERT_EQ(reference_timestamp, send_timestamp);
350
351 AddFrameComparison(reference_frame, video_frame, false, render_time_ms);
352
353 last_rendered_frame_ = video_frame;
354
355 StopExcludingCpuThreadTime();
356 }
357
Wait()358 void VideoAnalyzer::Wait() {
359 // Frame comparisons can be very expensive. Wait for test to be done, but
360 // at time-out check if frames_processed is going up. If so, give it more
361 // time, otherwise fail. Hopefully this will reduce test flakiness.
362
363 RepeatingTaskHandle stats_polling_task = RepeatingTaskHandle::DelayedStart(
364 task_queue_, kSendStatsPollingInterval, [this] {
365 PollStats();
366 return kSendStatsPollingInterval;
367 });
368
369 int last_frames_processed = -1;
370 int last_frames_captured = -1;
371 int iteration = 0;
372
373 while (!done_.Wait(kProbingInterval)) {
374 int frames_processed;
375 int frames_captured;
376 {
377 MutexLock lock(&comparison_lock_);
378 frames_processed = frames_processed_;
379 frames_captured = captured_frames_;
380 }
381
382 // Print some output so test infrastructure won't think we've crashed.
383 const char* kKeepAliveMessages[3] = {
384 "Uh, I'm-I'm not quite dead, sir.",
385 "Uh, I-I think uh, I could pull through, sir.",
386 "Actually, I think I'm all right to come with you--"};
387 if (++iteration % kKeepAliveIntervalIterations == 0) {
388 printf("- %s\n", kKeepAliveMessages[iteration % 3]);
389 }
390
391 if (last_frames_processed == -1) {
392 last_frames_processed = frames_processed;
393 last_frames_captured = frames_captured;
394 continue;
395 }
396 if (frames_processed == last_frames_processed &&
397 last_frames_captured == frames_captured &&
398 clock_->CurrentTime() > test_end_) {
399 done_.Set();
400 break;
401 }
402 last_frames_processed = frames_processed;
403 last_frames_captured = frames_captured;
404 }
405
406 if (iteration > 0)
407 printf("- Farewell, sweet Concorde!\n");
408
409 SendTask(task_queue_, [&] { stats_polling_task.Stop(); });
410
411 PrintResults();
412 if (graph_data_output_file_)
413 PrintSamplesToFile();
414 }
415
StartMeasuringCpuProcessTime()416 void VideoAnalyzer::StartMeasuringCpuProcessTime() {
417 MutexLock lock(&cpu_measurement_lock_);
418 cpu_time_ -= rtc::GetProcessCpuTimeNanos();
419 wallclock_time_ -= rtc::SystemTimeNanos();
420 }
421
StopMeasuringCpuProcessTime()422 void VideoAnalyzer::StopMeasuringCpuProcessTime() {
423 MutexLock lock(&cpu_measurement_lock_);
424 cpu_time_ += rtc::GetProcessCpuTimeNanos();
425 wallclock_time_ += rtc::SystemTimeNanos();
426 }
427
StartExcludingCpuThreadTime()428 void VideoAnalyzer::StartExcludingCpuThreadTime() {
429 MutexLock lock(&cpu_measurement_lock_);
430 cpu_time_ += rtc::GetThreadCpuTimeNanos();
431 }
432
StopExcludingCpuThreadTime()433 void VideoAnalyzer::StopExcludingCpuThreadTime() {
434 MutexLock lock(&cpu_measurement_lock_);
435 cpu_time_ -= rtc::GetThreadCpuTimeNanos();
436 }
437
GetCpuUsagePercent()438 double VideoAnalyzer::GetCpuUsagePercent() {
439 MutexLock lock(&cpu_measurement_lock_);
440 return static_cast<double>(cpu_time_) / wallclock_time_ * 100.0;
441 }
442
IsInSelectedSpatialAndTemporalLayer(const RtpPacket & rtp_packet)443 bool VideoAnalyzer::IsInSelectedSpatialAndTemporalLayer(
444 const RtpPacket& rtp_packet) {
445 if (rtp_packet.PayloadType() == test::CallTest::kPayloadTypeVP8) {
446 auto parsed_payload = vp8_depacketizer_->Parse(rtp_packet.PayloadBuffer());
447 RTC_DCHECK(parsed_payload);
448 const auto& vp8_header = absl::get<RTPVideoHeaderVP8>(
449 parsed_payload->video_header.video_type_header);
450 int temporal_idx = vp8_header.temporalIdx;
451 return selected_tl_ < 0 || temporal_idx == kNoTemporalIdx ||
452 temporal_idx <= selected_tl_;
453 }
454
455 if (rtp_packet.PayloadType() == test::CallTest::kPayloadTypeVP9) {
456 auto parsed_payload = vp9_depacketizer_->Parse(rtp_packet.PayloadBuffer());
457 RTC_DCHECK(parsed_payload);
458 const auto& vp9_header = absl::get<RTPVideoHeaderVP9>(
459 parsed_payload->video_header.video_type_header);
460 int temporal_idx = vp9_header.temporal_idx;
461 int spatial_idx = vp9_header.spatial_idx;
462 return (selected_tl_ < 0 || temporal_idx == kNoTemporalIdx ||
463 temporal_idx <= selected_tl_) &&
464 (selected_sl_ < 0 || spatial_idx == kNoSpatialIdx ||
465 spatial_idx <= selected_sl_);
466 }
467
468 return true;
469 }
470
PollStats()471 void VideoAnalyzer::PollStats() {
472 // Do not grab `comparison_lock_`, before `GetStats()` completes.
473 // Otherwise a deadlock may occur:
474 // 1) `comparison_lock_` is acquired after `lock_`
475 // 2) `lock_` is acquired after internal pacer lock in SendRtp()
476 // 3) internal pacer lock is acquired by GetStats().
477 Call::Stats call_stats = call_->GetStats();
478
479 MutexLock lock(&comparison_lock_);
480
481 send_bandwidth_bps_.AddSample(call_stats.send_bandwidth_bps);
482
483 VideoSendStream::Stats send_stats = send_stream_->GetStats();
484 // It's not certain that we yet have estimates for any of these stats.
485 // Check that they are positive before mixing them in.
486 if (send_stats.encode_frame_rate > 0)
487 encode_frame_rate_.AddSample(send_stats.encode_frame_rate);
488 if (send_stats.avg_encode_time_ms > 0)
489 encode_time_ms_.AddSample(send_stats.avg_encode_time_ms);
490 if (send_stats.encode_usage_percent > 0)
491 encode_usage_percent_.AddSample(send_stats.encode_usage_percent);
492 if (send_stats.media_bitrate_bps > 0)
493 media_bitrate_bps_.AddSample(send_stats.media_bitrate_bps);
494 size_t fec_bytes = 0;
495 for (const auto& kv : send_stats.substreams) {
496 fec_bytes += kv.second.rtp_stats.fec.payload_bytes +
497 kv.second.rtp_stats.fec.padding_bytes;
498 }
499 fec_bitrate_bps_.AddSample((fec_bytes - last_fec_bytes_) * 8);
500 last_fec_bytes_ = fec_bytes;
501
502 if (receive_stream_ != nullptr) {
503 VideoReceiveStreamInterface::Stats receive_stats =
504 receive_stream_->GetStats();
505 // `total_decode_time_ms` gives a good estimate of the mean decode time,
506 // `decode_ms` is used to keep track of the standard deviation.
507 if (receive_stats.frames_decoded > 0)
508 mean_decode_time_ms_ = receive_stats.total_decode_time.ms<double>() /
509 receive_stats.frames_decoded;
510 if (receive_stats.decode_ms > 0)
511 decode_time_ms_.AddSample(receive_stats.decode_ms);
512 if (receive_stats.max_decode_ms > 0)
513 decode_time_max_ms_.AddSample(receive_stats.max_decode_ms);
514 if (receive_stats.width > 0 && receive_stats.height > 0) {
515 pixels_.AddSample(receive_stats.width * receive_stats.height);
516 }
517
518 // `frames_decoded` and `frames_rendered` are used because they are more
519 // accurate than `decode_frame_rate` and `render_frame_rate`.
520 // The latter two are calculated on a momentary basis.
521 const double total_frames_duration_sec_double =
522 static_cast<double>(receive_stats.total_frames_duration_ms) / 1000.0;
523 if (total_frames_duration_sec_double > 0) {
524 decode_frame_rate_ = static_cast<double>(receive_stats.frames_decoded) /
525 total_frames_duration_sec_double;
526 render_frame_rate_ = static_cast<double>(receive_stats.frames_rendered) /
527 total_frames_duration_sec_double;
528 }
529
530 // Freeze metrics.
531 freeze_count_ = receive_stats.freeze_count;
532 total_freezes_duration_ms_ = receive_stats.total_freezes_duration_ms;
533 total_frames_duration_ms_ = receive_stats.total_frames_duration_ms;
534 sum_squared_frame_durations_ = receive_stats.sum_squared_frame_durations;
535 }
536
537 if (audio_receive_stream_ != nullptr) {
538 AudioReceiveStreamInterface::Stats receive_stats =
539 audio_receive_stream_->GetStats(/*get_and_clear_legacy_stats=*/true);
540 audio_expand_rate_.AddSample(receive_stats.expand_rate);
541 audio_accelerate_rate_.AddSample(receive_stats.accelerate_rate);
542 audio_jitter_buffer_ms_.AddSample(receive_stats.jitter_buffer_ms);
543 }
544
545 memory_usage_.AddSample(rtc::GetProcessResidentSizeBytes());
546 }
547
CompareFrames()548 bool VideoAnalyzer::CompareFrames() {
549 if (AllFramesRecorded())
550 return false;
551
552 FrameComparison comparison;
553
554 if (!PopComparison(&comparison)) {
555 // Wait until new comparison task is available, or test is done.
556 // If done, wake up remaining threads waiting.
557 comparison_available_event_.Wait(TimeDelta::Seconds(1));
558 if (AllFramesRecorded()) {
559 comparison_available_event_.Set();
560 return false;
561 }
562 return true; // Try again.
563 }
564
565 StartExcludingCpuThreadTime();
566
567 PerformFrameComparison(comparison);
568
569 StopExcludingCpuThreadTime();
570
571 if (FrameProcessed()) {
572 done_.Set();
573 comparison_available_event_.Set();
574 return false;
575 }
576
577 return true;
578 }
579
PopComparison(VideoAnalyzer::FrameComparison * comparison)580 bool VideoAnalyzer::PopComparison(VideoAnalyzer::FrameComparison* comparison) {
581 MutexLock lock(&comparison_lock_);
582 // If AllFramesRecorded() is true, it means we have already popped
583 // frames_to_process_ frames from comparisons_, so there is no more work
584 // for this thread to be done. frames_processed_ might still be lower if
585 // all comparisons are not done, but those frames are currently being
586 // worked on by other threads.
587 if (comparisons_.empty() || AllFramesRecordedLocked())
588 return false;
589
590 *comparison = comparisons_.front();
591 comparisons_.pop_front();
592
593 FrameRecorded();
594 return true;
595 }
596
FrameRecorded()597 void VideoAnalyzer::FrameRecorded() {
598 ++frames_recorded_;
599 }
600
AllFramesRecorded()601 bool VideoAnalyzer::AllFramesRecorded() {
602 MutexLock lock(&comparison_lock_);
603 return AllFramesRecordedLocked();
604 }
605
AllFramesRecordedLocked()606 bool VideoAnalyzer::AllFramesRecordedLocked() {
607 RTC_DCHECK(frames_recorded_ <= frames_to_process_);
608 return frames_recorded_ == frames_to_process_ ||
609 (clock_->CurrentTime() > test_end_ && comparisons_.empty()) || quit_;
610 }
611
FrameProcessed()612 bool VideoAnalyzer::FrameProcessed() {
613 MutexLock lock(&comparison_lock_);
614 ++frames_processed_;
615 RTC_DCHECK_LE(frames_processed_, frames_to_process_);
616 return frames_processed_ == frames_to_process_ ||
617 (clock_->CurrentTime() > test_end_ && comparisons_.empty());
618 }
619
PrintResults()620 void VideoAnalyzer::PrintResults() {
621 StopMeasuringCpuProcessTime();
622 int dropped_frames_diff;
623 {
624 MutexLock lock(&lock_);
625 dropped_frames_diff = dropped_frames_before_first_encode_ +
626 dropped_frames_before_rendering_ + frames_.size();
627 }
628 MutexLock lock(&comparison_lock_);
629 PrintResult("psnr_dB", psnr_, Unit::kUnitless,
630 ImprovementDirection::kBiggerIsBetter);
631 PrintResult("ssim", ssim_, Unit::kUnitless,
632 ImprovementDirection::kBiggerIsBetter);
633 PrintResult("sender_time", sender_time_, Unit::kMilliseconds,
634 ImprovementDirection::kSmallerIsBetter);
635 PrintResult("receiver_time", receiver_time_, Unit::kMilliseconds,
636 ImprovementDirection::kSmallerIsBetter);
637 PrintResult("network_time", network_time_, Unit::kMilliseconds,
638 ImprovementDirection::kSmallerIsBetter);
639 PrintResult("total_delay_incl_network", end_to_end_, Unit::kMilliseconds,
640 ImprovementDirection::kSmallerIsBetter);
641 PrintResult("time_between_rendered_frames", rendered_delta_,
642 Unit::kMilliseconds, ImprovementDirection::kSmallerIsBetter);
643 PrintResult("encode_frame_rate_fps", encode_frame_rate_, Unit::kHertz,
644 ImprovementDirection::kBiggerIsBetter);
645 PrintResult("encode_time", encode_time_ms_, Unit::kMilliseconds,
646 ImprovementDirection::kSmallerIsBetter);
647 PrintResult("media_bitrate", media_bitrate_bps_ / 1000.0,
648 Unit::kKilobitsPerSecond, ImprovementDirection::kNeitherIsBetter);
649 PrintResult("fec_bitrate", fec_bitrate_bps_ / 1000.0,
650 Unit::kKilobitsPerSecond, ImprovementDirection::kNeitherIsBetter);
651 PrintResult("send_bandwidth", send_bandwidth_bps_ / 1000.0,
652 Unit::kKilobitsPerSecond, ImprovementDirection::kNeitherIsBetter);
653 PrintResult("pixels_per_frame", pixels_, Unit::kCount,
654 ImprovementDirection::kBiggerIsBetter);
655
656 GetGlobalMetricsLogger()->LogSingleValueMetric(
657 "decode_frame_rate_fps", test_label_, decode_frame_rate_, Unit::kHertz,
658 ImprovementDirection::kBiggerIsBetter);
659 GetGlobalMetricsLogger()->LogSingleValueMetric(
660 "render_frame_rate_fps", test_label_, render_frame_rate_, Unit::kHertz,
661 ImprovementDirection::kBiggerIsBetter);
662
663 // Record the time from the last freeze until the last rendered frame to
664 // ensure we cover the full timespan of the session. Otherwise the metric
665 // would penalize an early freeze followed by no freezes until the end.
666 time_between_freezes_.AddSample(last_render_time_ - last_unfreeze_time_ms_);
667
668 // Freeze metrics.
669 PrintResult("time_between_freezes", time_between_freezes_,
670 Unit::kMilliseconds, ImprovementDirection::kBiggerIsBetter);
671
672 const double freeze_count_double = static_cast<double>(freeze_count_);
673 const double total_freezes_duration_ms_double =
674 static_cast<double>(total_freezes_duration_ms_);
675 const double total_frames_duration_ms_double =
676 static_cast<double>(total_frames_duration_ms_);
677
678 if (total_frames_duration_ms_double > 0) {
679 GetGlobalMetricsLogger()->LogSingleValueMetric(
680 "freeze_duration_ratio", test_label_,
681 total_freezes_duration_ms_double / total_frames_duration_ms_double,
682 Unit::kUnitless, ImprovementDirection::kSmallerIsBetter);
683 RTC_DCHECK_LE(total_freezes_duration_ms_double,
684 total_frames_duration_ms_double);
685
686 constexpr double ms_per_minute = 60 * 1000;
687 const double total_frames_duration_min =
688 total_frames_duration_ms_double / ms_per_minute;
689 if (total_frames_duration_min > 0) {
690 GetGlobalMetricsLogger()->LogSingleValueMetric(
691 "freeze_count_per_minute", test_label_,
692 freeze_count_double / total_frames_duration_min, Unit::kUnitless,
693 ImprovementDirection::kSmallerIsBetter);
694 }
695 }
696
697 GetGlobalMetricsLogger()->LogSingleValueMetric(
698 "freeze_duration_average", test_label_,
699 freeze_count_double > 0
700 ? total_freezes_duration_ms_double / freeze_count_double
701 : 0,
702 Unit::kMilliseconds, ImprovementDirection::kSmallerIsBetter);
703
704 if (1000 * sum_squared_frame_durations_ > 0) {
705 GetGlobalMetricsLogger()->LogSingleValueMetric(
706 "harmonic_frame_rate_fps", test_label_,
707 total_frames_duration_ms_double / (1000 * sum_squared_frame_durations_),
708 Unit::kHertz, ImprovementDirection::kBiggerIsBetter);
709 }
710
711 if (worst_frame_) {
712 GetGlobalMetricsLogger()->LogSingleValueMetric(
713 "min_psnr_dB", test_label_, worst_frame_->psnr, Unit::kUnitless,
714 ImprovementDirection::kBiggerIsBetter);
715 }
716
717 if (receive_stream_ != nullptr) {
718 PrintResultWithExternalMean("decode_time", mean_decode_time_ms_,
719 decode_time_ms_, Unit::kMilliseconds,
720 ImprovementDirection::kSmallerIsBetter);
721 }
722 dropped_frames_ += dropped_frames_diff;
723 GetGlobalMetricsLogger()->LogSingleValueMetric(
724 "dropped_frames", test_label_, dropped_frames_, Unit::kCount,
725 ImprovementDirection::kSmallerIsBetter);
726 GetGlobalMetricsLogger()->LogSingleValueMetric(
727 "cpu_usage_%", test_label_, GetCpuUsagePercent(), Unit::kUnitless,
728 ImprovementDirection::kSmallerIsBetter);
729
730 #if defined(WEBRTC_WIN)
731 // On Linux and Mac in Resident Set some unused pages may be counted.
732 // Therefore this metric will depend on order in which tests are run and
733 // will be flaky.
734 PrintResult("memory_usage", memory_usage_, Unit::kBytes,
735 ImprovementDirection::kSmallerIsBetter);
736 #endif
737
738 // Saving only the worst frame for manual analysis. Intention here is to
739 // only detect video corruptions and not to track picture quality. Thus,
740 // jpeg is used here.
741 if (absl::GetFlag(FLAGS_save_worst_frame) && worst_frame_) {
742 std::string output_dir;
743 test::GetTestArtifactsDir(&output_dir);
744 std::string output_path =
745 test::JoinFilename(output_dir, test_label_ + ".jpg");
746 RTC_LOG(LS_INFO) << "Saving worst frame to " << output_path;
747 test::JpegFrameWriter frame_writer(output_path);
748 RTC_CHECK(
749 frame_writer.WriteFrame(worst_frame_->frame, 100 /*best quality*/));
750 }
751
752 if (audio_receive_stream_ != nullptr) {
753 PrintResult("audio_expand_rate", audio_expand_rate_, Unit::kUnitless,
754 ImprovementDirection::kSmallerIsBetter);
755 PrintResult("audio_accelerate_rate", audio_accelerate_rate_,
756 Unit::kUnitless, ImprovementDirection::kSmallerIsBetter);
757 PrintResult("audio_jitter_buffer", audio_jitter_buffer_ms_,
758 Unit::kMilliseconds, ImprovementDirection::kNeitherIsBetter);
759 }
760
761 // Disable quality check for quick test, as quality checks may fail
762 // because too few samples were collected.
763 if (!is_quick_test_enabled_) {
764 EXPECT_GT(psnr_.GetAverage(), avg_psnr_threshold_);
765 EXPECT_GT(ssim_.GetAverage(), avg_ssim_threshold_);
766 }
767 }
768
PerformFrameComparison(const VideoAnalyzer::FrameComparison & comparison)769 void VideoAnalyzer::PerformFrameComparison(
770 const VideoAnalyzer::FrameComparison& comparison) {
771 // Perform expensive psnr and ssim calculations while not holding lock.
772 double psnr = -1.0;
773 double ssim = -1.0;
774 if (comparison.reference && !comparison.dropped) {
775 psnr = I420PSNR(&*comparison.reference, &*comparison.render);
776 ssim = I420SSIM(&*comparison.reference, &*comparison.render);
777 }
778
779 MutexLock lock(&comparison_lock_);
780
781 if (psnr >= 0.0 && (!worst_frame_ || worst_frame_->psnr > psnr)) {
782 worst_frame_.emplace(FrameWithPsnr{psnr, *comparison.render});
783 }
784
785 if (graph_data_output_file_) {
786 samples_.push_back(Sample(comparison.dropped, comparison.input_time_ms,
787 comparison.send_time_ms, comparison.recv_time_ms,
788 comparison.render_time_ms,
789 comparison.encoded_frame_size, psnr, ssim));
790 }
791 if (psnr >= 0.0)
792 psnr_.AddSample(psnr);
793 if (ssim >= 0.0)
794 ssim_.AddSample(ssim);
795
796 if (comparison.dropped) {
797 ++dropped_frames_;
798 return;
799 }
800 if (last_unfreeze_time_ms_ == 0)
801 last_unfreeze_time_ms_ = comparison.render_time_ms;
802 if (last_render_time_ != 0) {
803 const int64_t render_delta_ms =
804 comparison.render_time_ms - last_render_time_;
805 rendered_delta_.AddSample(render_delta_ms);
806 if (last_render_delta_ms_ != 0 &&
807 render_delta_ms - last_render_delta_ms_ > 150) {
808 time_between_freezes_.AddSample(last_render_time_ -
809 last_unfreeze_time_ms_);
810 last_unfreeze_time_ms_ = comparison.render_time_ms;
811 }
812 last_render_delta_ms_ = render_delta_ms;
813 }
814 last_render_time_ = comparison.render_time_ms;
815
816 sender_time_.AddSample(comparison.send_time_ms - comparison.input_time_ms);
817 if (comparison.recv_time_ms > 0) {
818 // If recv_time_ms == 0, this frame consisted of a packets which were all
819 // lost in the transport. Since we were able to render the frame, however,
820 // the dropped packets were recovered by FlexFEC. The FlexFEC recovery
821 // happens internally in Call, and we can therefore here not know which
822 // FEC packets that protected the lost media packets. Consequently, we
823 // were not able to record a meaningful recv_time_ms. We therefore skip
824 // this sample.
825 //
826 // The reasoning above does not hold for ULPFEC and RTX, as for those
827 // strategies the timestamp of the received packets is set to the
828 // timestamp of the protected/retransmitted media packet. I.e., then
829 // recv_time_ms != 0, even though the media packets were lost.
830 receiver_time_.AddSample(comparison.render_time_ms -
831 comparison.recv_time_ms);
832 network_time_.AddSample(comparison.recv_time_ms - comparison.send_time_ms);
833 }
834 end_to_end_.AddSample(comparison.render_time_ms - comparison.input_time_ms);
835 encoded_frame_size_.AddSample(comparison.encoded_frame_size);
836 }
837
PrintResult(absl::string_view result_type,const SamplesStatsCounter & stats,Unit unit,ImprovementDirection improvement_direction)838 void VideoAnalyzer::PrintResult(absl::string_view result_type,
839 const SamplesStatsCounter& stats,
840 Unit unit,
841 ImprovementDirection improvement_direction) {
842 GetGlobalMetricsLogger()->LogMetric(result_type, test_label_, stats, unit,
843 improvement_direction);
844 }
845
PrintResultWithExternalMean(absl::string_view result_type,double mean,const SamplesStatsCounter & stats,Unit unit,ImprovementDirection improvement_direction)846 void VideoAnalyzer::PrintResultWithExternalMean(
847 absl::string_view result_type,
848 double mean,
849 const SamplesStatsCounter& stats,
850 Unit unit,
851 ImprovementDirection improvement_direction) {
852 // If the true mean is different than the sample mean, the sample variance is
853 // too low. The sample variance given a known mean is obtained by adding the
854 // squared error between the true mean and the sample mean.
855 double compensated_variance =
856 stats.IsEmpty()
857 ? 0.0
858 : stats.GetVariance() + pow(mean - stats.GetAverage(), 2.0);
859 GetGlobalMetricsLogger()->LogMetric(
860 result_type, test_label_,
861 Metric::Stats{.mean = mean, .stddev = std::sqrt(compensated_variance)},
862 unit, improvement_direction);
863 }
864
PrintSamplesToFile()865 void VideoAnalyzer::PrintSamplesToFile() {
866 FILE* out = graph_data_output_file_;
867 MutexLock lock(&comparison_lock_);
868 absl::c_sort(samples_, [](const Sample& A, const Sample& B) -> bool {
869 return A.input_time_ms < B.input_time_ms;
870 });
871
872 fprintf(out, "%s\n", graph_title_.c_str());
873 fprintf(out, "%zu\n", samples_.size());
874 fprintf(out,
875 "dropped "
876 "input_time_ms "
877 "send_time_ms "
878 "recv_time_ms "
879 "render_time_ms "
880 "encoded_frame_size "
881 "psnr "
882 "ssim "
883 "encode_time_ms\n");
884 for (const Sample& sample : samples_) {
885 fprintf(out,
886 "%d %" PRId64 " %" PRId64 " %" PRId64 " %" PRId64 " %zu %lf %lf\n",
887 sample.dropped, sample.input_time_ms, sample.send_time_ms,
888 sample.recv_time_ms, sample.render_time_ms,
889 sample.encoded_frame_size, sample.psnr, sample.ssim);
890 }
891 }
892
AddCapturedFrameForComparison(const VideoFrame & video_frame)893 void VideoAnalyzer::AddCapturedFrameForComparison(
894 const VideoFrame& video_frame) {
895 bool must_capture = false;
896 {
897 MutexLock lock(&comparison_lock_);
898 must_capture = captured_frames_ < frames_to_process_;
899 if (must_capture) {
900 ++captured_frames_;
901 }
902 }
903 if (must_capture) {
904 MutexLock lock(&lock_);
905 frames_.push_back(video_frame);
906 }
907 }
908
AddFrameComparison(const VideoFrame & reference,const VideoFrame & render,bool dropped,int64_t render_time_ms)909 void VideoAnalyzer::AddFrameComparison(const VideoFrame& reference,
910 const VideoFrame& render,
911 bool dropped,
912 int64_t render_time_ms) {
913 int64_t reference_timestamp = wrap_handler_.Unwrap(reference.timestamp());
914 int64_t send_time_ms = send_times_[reference_timestamp];
915 send_times_.erase(reference_timestamp);
916 int64_t recv_time_ms = recv_times_[reference_timestamp];
917 recv_times_.erase(reference_timestamp);
918
919 // TODO(ivica): Make this work for > 2 streams.
920 auto it = encoded_frame_sizes_.find(reference_timestamp);
921 if (it == encoded_frame_sizes_.end())
922 it = encoded_frame_sizes_.find(reference_timestamp - 1);
923 size_t encoded_size = it == encoded_frame_sizes_.end() ? 0 : it->second;
924 if (it != encoded_frame_sizes_.end())
925 encoded_frame_sizes_.erase(it);
926
927 MutexLock lock(&comparison_lock_);
928 if (comparisons_.size() < kMaxComparisons) {
929 comparisons_.push_back(FrameComparison(
930 reference, render, dropped, reference.ntp_time_ms(), send_time_ms,
931 recv_time_ms, render_time_ms, encoded_size));
932 } else {
933 comparisons_.push_back(FrameComparison(dropped, reference.ntp_time_ms(),
934 send_time_ms, recv_time_ms,
935 render_time_ms, encoded_size));
936 }
937 comparison_available_event_.Set();
938 }
939
FrameComparison()940 VideoAnalyzer::FrameComparison::FrameComparison()
941 : dropped(false),
942 input_time_ms(0),
943 send_time_ms(0),
944 recv_time_ms(0),
945 render_time_ms(0),
946 encoded_frame_size(0) {}
947
FrameComparison(const VideoFrame & reference,const VideoFrame & render,bool dropped,int64_t input_time_ms,int64_t send_time_ms,int64_t recv_time_ms,int64_t render_time_ms,size_t encoded_frame_size)948 VideoAnalyzer::FrameComparison::FrameComparison(const VideoFrame& reference,
949 const VideoFrame& render,
950 bool dropped,
951 int64_t input_time_ms,
952 int64_t send_time_ms,
953 int64_t recv_time_ms,
954 int64_t render_time_ms,
955 size_t encoded_frame_size)
956 : reference(reference),
957 render(render),
958 dropped(dropped),
959 input_time_ms(input_time_ms),
960 send_time_ms(send_time_ms),
961 recv_time_ms(recv_time_ms),
962 render_time_ms(render_time_ms),
963 encoded_frame_size(encoded_frame_size) {}
964
FrameComparison(bool dropped,int64_t input_time_ms,int64_t send_time_ms,int64_t recv_time_ms,int64_t render_time_ms,size_t encoded_frame_size)965 VideoAnalyzer::FrameComparison::FrameComparison(bool dropped,
966 int64_t input_time_ms,
967 int64_t send_time_ms,
968 int64_t recv_time_ms,
969 int64_t render_time_ms,
970 size_t encoded_frame_size)
971 : dropped(dropped),
972 input_time_ms(input_time_ms),
973 send_time_ms(send_time_ms),
974 recv_time_ms(recv_time_ms),
975 render_time_ms(render_time_ms),
976 encoded_frame_size(encoded_frame_size) {}
977
Sample(int dropped,int64_t input_time_ms,int64_t send_time_ms,int64_t recv_time_ms,int64_t render_time_ms,size_t encoded_frame_size,double psnr,double ssim)978 VideoAnalyzer::Sample::Sample(int dropped,
979 int64_t input_time_ms,
980 int64_t send_time_ms,
981 int64_t recv_time_ms,
982 int64_t render_time_ms,
983 size_t encoded_frame_size,
984 double psnr,
985 double ssim)
986 : dropped(dropped),
987 input_time_ms(input_time_ms),
988 send_time_ms(send_time_ms),
989 recv_time_ms(recv_time_ms),
990 render_time_ms(render_time_ms),
991 encoded_frame_size(encoded_frame_size),
992 psnr(psnr),
993 ssim(ssim) {}
994
CapturedFrameForwarder(VideoAnalyzer * analyzer,Clock * clock,int frames_to_capture,TimeDelta test_duration)995 VideoAnalyzer::CapturedFrameForwarder::CapturedFrameForwarder(
996 VideoAnalyzer* analyzer,
997 Clock* clock,
998 int frames_to_capture,
999 TimeDelta test_duration)
1000 : analyzer_(analyzer),
1001 send_stream_input_(nullptr),
1002 video_source_(nullptr),
1003 clock_(clock),
1004 captured_frames_(0),
1005 frames_to_capture_(frames_to_capture),
1006 test_end_(clock->CurrentTime() + test_duration) {}
1007
SetSource(VideoSourceInterface<VideoFrame> * video_source)1008 void VideoAnalyzer::CapturedFrameForwarder::SetSource(
1009 VideoSourceInterface<VideoFrame>* video_source) {
1010 video_source_ = video_source;
1011 }
1012
OnFrame(const VideoFrame & video_frame)1013 void VideoAnalyzer::CapturedFrameForwarder::OnFrame(
1014 const VideoFrame& video_frame) {
1015 VideoFrame copy = video_frame;
1016 // Frames from the capturer does not have a rtp timestamp.
1017 // Create one so it can be used for comparison.
1018 RTC_DCHECK_EQ(0, video_frame.timestamp());
1019 if (video_frame.ntp_time_ms() == 0)
1020 copy.set_ntp_time_ms(clock_->CurrentNtpInMilliseconds());
1021 copy.set_timestamp(copy.ntp_time_ms() * 90);
1022 analyzer_->AddCapturedFrameForComparison(copy);
1023 MutexLock lock(&lock_);
1024 ++captured_frames_;
1025 if (send_stream_input_ && clock_->CurrentTime() <= test_end_ &&
1026 captured_frames_ <= frames_to_capture_) {
1027 send_stream_input_->OnFrame(copy);
1028 }
1029 }
1030
AddOrUpdateSink(rtc::VideoSinkInterface<VideoFrame> * sink,const rtc::VideoSinkWants & wants)1031 void VideoAnalyzer::CapturedFrameForwarder::AddOrUpdateSink(
1032 rtc::VideoSinkInterface<VideoFrame>* sink,
1033 const rtc::VideoSinkWants& wants) {
1034 {
1035 MutexLock lock(&lock_);
1036 RTC_DCHECK(!send_stream_input_ || send_stream_input_ == sink);
1037 send_stream_input_ = sink;
1038 }
1039 if (video_source_) {
1040 video_source_->AddOrUpdateSink(this, wants);
1041 }
1042 }
1043
RemoveSink(rtc::VideoSinkInterface<VideoFrame> * sink)1044 void VideoAnalyzer::CapturedFrameForwarder::RemoveSink(
1045 rtc::VideoSinkInterface<VideoFrame>* sink) {
1046 MutexLock lock(&lock_);
1047 RTC_DCHECK(sink == send_stream_input_);
1048 send_stream_input_ = nullptr;
1049 }
1050
1051 } // namespace webrtc
1052