blob: 9b5189d307b449125bea18ae158a04bd9116eb03 [file] [log] [blame]
Sebastian Janssond4c5d632018-07-10 12:57:37 +02001/*
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 <algorithm>
13#include <utility>
14
Steve Antonbd631a02019-03-28 10:51:27 -070015#include "absl/algorithm/container.h"
Niels Möller1c931c42018-12-18 16:08:11 +010016#include "common_video/libyuv/include/webrtc_libyuv.h"
Sebastian Janssond4c5d632018-07-10 12:57:37 +020017#include "modules/rtp_rtcp/source/rtp_format.h"
18#include "modules/rtp_rtcp/source/rtp_utility.h"
19#include "rtc_base/cpu_time.h"
20#include "rtc_base/flags.h"
21#include "rtc_base/format_macros.h"
22#include "rtc_base/memory_usage.h"
Sebastian Janssond4c5d632018-07-10 12:57:37 +020023#include "system_wrappers/include/cpu_info.h"
24#include "test/call_test.h"
Steve Anton10542f22019-01-11 09:11:00 -080025#include "test/testsupport/file_utils.h"
Sebastian Janssond4c5d632018-07-10 12:57:37 +020026#include "test/testsupport/frame_writer.h"
27#include "test/testsupport/perf_test.h"
28#include "test/testsupport/test_artifacts.h"
29
Mirko Bonadei2dfa9982018-10-18 11:35:32 +020030WEBRTC_DEFINE_bool(
31 save_worst_frame,
32 false,
33 "Enable saving a frame with the lowest PSNR to a jpeg file in the "
34 "test_artifacts_dir");
Sebastian Janssond4c5d632018-07-10 12:57:37 +020035
36namespace webrtc {
37namespace {
38constexpr int kSendStatsPollingIntervalMs = 1000;
39constexpr size_t kMaxComparisons = 10;
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +010040// How often is keep alive message printed.
41constexpr int kKeepAliveIntervalSeconds = 30;
42// Interval between checking that the test is over.
43constexpr int kProbingIntervalMs = 500;
44constexpr int kKeepAliveIntervalIterations =
45 kKeepAliveIntervalSeconds * 1000 / kProbingIntervalMs;
Sebastian Janssond4c5d632018-07-10 12:57:37 +020046
47bool IsFlexfec(int payload_type) {
48 return payload_type == test::CallTest::kFlexfecPayloadType;
49}
50} // namespace
51
Artem Titovff7730d2019-04-02 13:46:53 +020052VideoAnalyzer::VideoAnalyzer(
53 test::LayerFilteringTransport* transport,
54 const std::string& test_label,
55 double avg_psnr_threshold,
56 double avg_ssim_threshold,
57 int duration_frames,
58 FILE* graph_data_output_file,
59 const std::string& graph_title,
60 uint32_t ssrc_to_analyze,
61 uint32_t rtx_ssrc_to_analyze,
62 size_t selected_stream,
63 int selected_sl,
64 int selected_tl,
65 bool is_quick_test_enabled,
66 Clock* clock,
67 std::string rtp_dump_name,
68 test::SingleThreadedTaskQueueForTesting* task_queue)
Sebastian Janssond4c5d632018-07-10 12:57:37 +020069 : transport_(transport),
70 receiver_(nullptr),
71 call_(nullptr),
72 send_stream_(nullptr),
73 receive_stream_(nullptr),
Christoffer Rodbroc2a02882018-08-07 14:10:56 +020074 audio_receive_stream_(nullptr),
Ilya Nikolaevskiy85fc3252019-02-11 10:41:50 +010075 captured_frame_forwarder_(this, clock, duration_frames),
Sebastian Janssond4c5d632018-07-10 12:57:37 +020076 test_label_(test_label),
77 graph_data_output_file_(graph_data_output_file),
78 graph_title_(graph_title),
79 ssrc_to_analyze_(ssrc_to_analyze),
80 rtx_ssrc_to_analyze_(rtx_ssrc_to_analyze),
81 selected_stream_(selected_stream),
82 selected_sl_(selected_sl),
83 selected_tl_(selected_tl),
Elad Alon8c513c72019-05-07 21:22:24 +020084 freeze_count_(0),
85 total_freezes_duration_ms_(0),
86 total_frames_duration_ms_(0),
87 sum_squared_frame_durations_(0),
Sebastian Janssond4c5d632018-07-10 12:57:37 +020088 last_fec_bytes_(0),
89 frames_to_process_(duration_frames),
90 frames_recorded_(0),
91 frames_processed_(0),
92 dropped_frames_(0),
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +010093 captured_frames_(0),
Sebastian Janssond4c5d632018-07-10 12:57:37 +020094 dropped_frames_before_first_encode_(0),
95 dropped_frames_before_rendering_(0),
96 last_render_time_(0),
97 last_render_delta_ms_(0),
98 last_unfreeze_time_ms_(0),
99 rtp_timestamp_delta_(0),
100 total_media_bytes_(0),
101 first_sending_time_(0),
102 last_sending_time_(0),
103 cpu_time_(0),
104 wallclock_time_(0),
105 avg_psnr_threshold_(avg_psnr_threshold),
106 avg_ssim_threshold_(avg_ssim_threshold),
107 is_quick_test_enabled_(is_quick_test_enabled),
Niels Möller4731f002019-05-03 09:34:24 +0200108 quit_(false),
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200109 done_(true, false),
110 clock_(clock),
Artem Titovff7730d2019-04-02 13:46:53 +0200111 start_ms_(clock->TimeInMilliseconds()),
112 task_queue_(task_queue) {
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200113 // Create thread pool for CPU-expensive PSNR/SSIM calculations.
114
115 // Try to use about as many threads as cores, but leave kMinCoresLeft alone,
116 // so that we don't accidentally starve "real" worker threads (codec etc).
117 // Also, don't allocate more than kMaxComparisonThreads, even if there are
118 // spare cores.
119
120 uint32_t num_cores = CpuInfo::DetectNumberOfCores();
121 RTC_DCHECK_GE(num_cores, 1);
122 static const uint32_t kMinCoresLeft = 4;
123 static const uint32_t kMaxComparisonThreads = 8;
124
125 if (num_cores <= kMinCoresLeft) {
126 num_cores = 1;
127 } else {
128 num_cores -= kMinCoresLeft;
129 num_cores = std::min(num_cores, kMaxComparisonThreads);
130 }
131
132 for (uint32_t i = 0; i < num_cores; ++i) {
133 rtc::PlatformThread* thread =
134 new rtc::PlatformThread(&FrameComparisonThread, this, "Analyzer");
135 thread->Start();
136 comparison_thread_pool_.push_back(thread);
137 }
138
139 if (!rtp_dump_name.empty()) {
140 fprintf(stdout, "Writing rtp dump to %s\n", rtp_dump_name.c_str());
141 rtp_file_writer_.reset(test::RtpFileWriter::Create(
142 test::RtpFileWriter::kRtpDump, rtp_dump_name));
143 }
144}
145
146VideoAnalyzer::~VideoAnalyzer() {
Niels Möller4731f002019-05-03 09:34:24 +0200147 {
148 rtc::CritScope crit(&comparison_lock_);
149 quit_ = true;
150 }
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200151 for (rtc::PlatformThread* thread : comparison_thread_pool_) {
152 thread->Stop();
153 delete thread;
154 }
155}
156
157void VideoAnalyzer::SetReceiver(PacketReceiver* receiver) {
158 receiver_ = receiver;
159}
160
Niels Möller1c931c42018-12-18 16:08:11 +0100161void VideoAnalyzer::SetSource(
162 rtc::VideoSourceInterface<VideoFrame>* video_source,
163 bool respect_sink_wants) {
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200164 if (respect_sink_wants)
Niels Möller1c931c42018-12-18 16:08:11 +0100165 captured_frame_forwarder_.SetSource(video_source);
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200166 rtc::VideoSinkWants wants;
Niels Möller1c931c42018-12-18 16:08:11 +0100167 video_source->AddOrUpdateSink(InputInterface(), wants);
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200168}
169
170void VideoAnalyzer::SetCall(Call* call) {
171 rtc::CritScope lock(&crit_);
172 RTC_DCHECK(!call_);
173 call_ = call;
174}
175
176void VideoAnalyzer::SetSendStream(VideoSendStream* stream) {
177 rtc::CritScope lock(&crit_);
178 RTC_DCHECK(!send_stream_);
179 send_stream_ = stream;
180}
181
182void VideoAnalyzer::SetReceiveStream(VideoReceiveStream* stream) {
183 rtc::CritScope lock(&crit_);
184 RTC_DCHECK(!receive_stream_);
185 receive_stream_ = stream;
186}
187
Christoffer Rodbroc2a02882018-08-07 14:10:56 +0200188void VideoAnalyzer::SetAudioReceiveStream(AudioReceiveStream* recv_stream) {
189 rtc::CritScope lock(&crit_);
190 RTC_CHECK(!audio_receive_stream_);
191 audio_receive_stream_ = recv_stream;
192}
193
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200194rtc::VideoSinkInterface<VideoFrame>* VideoAnalyzer::InputInterface() {
195 return &captured_frame_forwarder_;
196}
197
198rtc::VideoSourceInterface<VideoFrame>* VideoAnalyzer::OutputInterface() {
199 return &captured_frame_forwarder_;
200}
201
202PacketReceiver::DeliveryStatus VideoAnalyzer::DeliverPacket(
203 MediaType media_type,
204 rtc::CopyOnWriteBuffer packet,
Niels Möller70082872018-08-07 11:03:12 +0200205 int64_t packet_time_us) {
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200206 // Ignore timestamps of RTCP packets. They're not synchronized with
207 // RTP packet timestamps and so they would confuse wrap_handler_.
208 if (RtpHeaderParser::IsRtcp(packet.cdata(), packet.size())) {
Niels Möller70082872018-08-07 11:03:12 +0200209 return receiver_->DeliverPacket(media_type, std::move(packet),
210 packet_time_us);
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200211 }
212
213 if (rtp_file_writer_) {
214 test::RtpPacket p;
215 memcpy(p.data, packet.cdata(), packet.size());
216 p.length = packet.size();
217 p.original_length = packet.size();
218 p.time_ms = clock_->TimeInMilliseconds() - start_ms_;
219 rtp_file_writer_->WritePacket(&p);
220 }
221
222 RtpUtility::RtpHeaderParser parser(packet.cdata(), packet.size());
223 RTPHeader header;
224 parser.Parse(&header);
225 if (!IsFlexfec(header.payloadType) && (header.ssrc == ssrc_to_analyze_ ||
226 header.ssrc == rtx_ssrc_to_analyze_)) {
227 // Ignore FlexFEC timestamps, to avoid collisions with media timestamps.
228 // (FlexFEC and media are sent on different SSRCs, which have different
229 // timestamps spaces.)
230 // Also ignore packets from wrong SSRC, but include retransmits.
231 rtc::CritScope lock(&crit_);
232 int64_t timestamp =
233 wrap_handler_.Unwrap(header.timestamp - rtp_timestamp_delta_);
Sebastian Jansson11c012a2019-03-29 14:17:26 +0100234 recv_times_[timestamp] = clock_->CurrentNtpInMilliseconds();
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200235 }
236
Niels Möller70082872018-08-07 11:03:12 +0200237 return receiver_->DeliverPacket(media_type, std::move(packet),
238 packet_time_us);
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200239}
240
241void VideoAnalyzer::PreEncodeOnFrame(const VideoFrame& video_frame) {
242 rtc::CritScope lock(&crit_);
243 if (!first_encoded_timestamp_) {
244 while (frames_.front().timestamp() != video_frame.timestamp()) {
245 ++dropped_frames_before_first_encode_;
246 frames_.pop_front();
247 RTC_CHECK(!frames_.empty());
248 }
249 first_encoded_timestamp_ = video_frame.timestamp();
250 }
251}
252
Niels Möller88be9722018-10-10 10:58:52 +0200253void VideoAnalyzer::PostEncodeOnFrame(size_t stream_id, uint32_t timestamp) {
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200254 rtc::CritScope lock(&crit_);
Niels Möller88be9722018-10-10 10:58:52 +0200255 if (!first_sent_timestamp_ && stream_id == selected_stream_) {
256 first_sent_timestamp_ = timestamp;
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200257 }
258}
259
260bool VideoAnalyzer::SendRtp(const uint8_t* packet,
261 size_t length,
262 const PacketOptions& options) {
263 RtpUtility::RtpHeaderParser parser(packet, length);
264 RTPHeader header;
265 parser.Parse(&header);
266
Sebastian Jansson11c012a2019-03-29 14:17:26 +0100267 int64_t current_time = clock_->CurrentNtpInMilliseconds();
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200268
269 bool result = transport_->SendRtp(packet, length, options);
270 {
271 rtc::CritScope lock(&crit_);
272 if (rtp_timestamp_delta_ == 0 && header.ssrc == ssrc_to_analyze_) {
273 RTC_CHECK(static_cast<bool>(first_sent_timestamp_));
274 rtp_timestamp_delta_ = header.timestamp - *first_sent_timestamp_;
275 }
276
277 if (!IsFlexfec(header.payloadType) && header.ssrc == ssrc_to_analyze_) {
278 // Ignore FlexFEC timestamps, to avoid collisions with media timestamps.
279 // (FlexFEC and media are sent on different SSRCs, which have different
280 // timestamps spaces.)
281 // Also ignore packets from wrong SSRC and retransmits.
282 int64_t timestamp =
283 wrap_handler_.Unwrap(header.timestamp - rtp_timestamp_delta_);
284 send_times_[timestamp] = current_time;
285
286 if (IsInSelectedSpatialAndTemporalLayer(packet, length, header)) {
287 encoded_frame_sizes_[timestamp] +=
288 length - (header.headerLength + header.paddingLength);
289 total_media_bytes_ +=
290 length - (header.headerLength + header.paddingLength);
291 }
292 if (first_sending_time_ == 0)
293 first_sending_time_ = current_time;
294 last_sending_time_ = current_time;
295 }
296 }
297 return result;
298}
299
300bool VideoAnalyzer::SendRtcp(const uint8_t* packet, size_t length) {
301 return transport_->SendRtcp(packet, length);
302}
303
304void VideoAnalyzer::OnFrame(const VideoFrame& video_frame) {
Sebastian Jansson11c012a2019-03-29 14:17:26 +0100305 int64_t render_time_ms = clock_->CurrentNtpInMilliseconds();
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200306
307 rtc::CritScope lock(&crit_);
308
309 StartExcludingCpuThreadTime();
310
311 int64_t send_timestamp =
312 wrap_handler_.Unwrap(video_frame.timestamp() - rtp_timestamp_delta_);
313
314 while (wrap_handler_.Unwrap(frames_.front().timestamp()) < send_timestamp) {
315 if (!last_rendered_frame_) {
316 // No previous frame rendered, this one was dropped after sending but
317 // before rendering.
318 ++dropped_frames_before_rendering_;
319 } else {
320 AddFrameComparison(frames_.front(), *last_rendered_frame_, true,
321 render_time_ms);
322 }
323 frames_.pop_front();
324 RTC_DCHECK(!frames_.empty());
325 }
326
327 VideoFrame reference_frame = frames_.front();
328 frames_.pop_front();
329 int64_t reference_timestamp =
330 wrap_handler_.Unwrap(reference_frame.timestamp());
331 if (send_timestamp == reference_timestamp - 1) {
332 // TODO(ivica): Make this work for > 2 streams.
333 // Look at RTPSender::BuildRTPHeader.
334 ++send_timestamp;
335 }
336 ASSERT_EQ(reference_timestamp, send_timestamp);
337
338 AddFrameComparison(reference_frame, video_frame, false, render_time_ms);
339
340 last_rendered_frame_ = video_frame;
341
342 StopExcludingCpuThreadTime();
343}
344
345void VideoAnalyzer::Wait() {
346 // Frame comparisons can be very expensive. Wait for test to be done, but
347 // at time-out check if frames_processed is going up. If so, give it more
348 // time, otherwise fail. Hopefully this will reduce test flakiness.
349
Artem Titovff7730d2019-04-02 13:46:53 +0200350 {
351 rtc::CritScope lock(&comparison_lock_);
352 stop_stats_poller_ = false;
353 stats_polling_task_id_ = task_queue_->PostDelayedTask(
354 [this]() { PollStats(); }, kSendStatsPollingIntervalMs);
355 }
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200356
357 int last_frames_processed = -1;
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100358 int last_frames_captured = -1;
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200359 int iteration = 0;
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100360
361 while (!done_.Wait(kProbingIntervalMs)) {
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200362 int frames_processed;
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100363 int frames_captured;
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200364 {
365 rtc::CritScope crit(&comparison_lock_);
366 frames_processed = frames_processed_;
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100367 frames_captured = captured_frames_;
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200368 }
369
370 // Print some output so test infrastructure won't think we've crashed.
371 const char* kKeepAliveMessages[3] = {
372 "Uh, I'm-I'm not quite dead, sir.",
373 "Uh, I-I think uh, I could pull through, sir.",
374 "Actually, I think I'm all right to come with you--"};
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100375 if (++iteration % kKeepAliveIntervalIterations == 0) {
376 printf("- %s\n", kKeepAliveMessages[iteration % 3]);
377 }
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200378
379 if (last_frames_processed == -1) {
380 last_frames_processed = frames_processed;
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100381 last_frames_captured = frames_captured;
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200382 continue;
383 }
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100384 if (frames_processed == last_frames_processed &&
385 last_frames_captured == frames_captured) {
386 if (frames_captured < frames_to_process_) {
387 EXPECT_GT(frames_processed, last_frames_processed)
388 << "Analyzer stalled while waiting for test to finish.";
389 }
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200390 done_.Set();
391 break;
392 }
393 last_frames_processed = frames_processed;
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100394 last_frames_captured = frames_captured;
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200395 }
396
397 if (iteration > 0)
398 printf("- Farewell, sweet Concorde!\n");
399
Artem Titovff7730d2019-04-02 13:46:53 +0200400 {
401 rtc::CritScope lock(&comparison_lock_);
402 stop_stats_poller_ = true;
403 task_queue_->CancelTask(stats_polling_task_id_);
404 }
405
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100406 PrintResults();
407 if (graph_data_output_file_)
408 PrintSamplesToFile();
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200409}
410
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200411void VideoAnalyzer::StartMeasuringCpuProcessTime() {
412 rtc::CritScope lock(&cpu_measurement_lock_);
413 cpu_time_ -= rtc::GetProcessCpuTimeNanos();
414 wallclock_time_ -= rtc::SystemTimeNanos();
415}
416
417void VideoAnalyzer::StopMeasuringCpuProcessTime() {
418 rtc::CritScope lock(&cpu_measurement_lock_);
419 cpu_time_ += rtc::GetProcessCpuTimeNanos();
420 wallclock_time_ += rtc::SystemTimeNanos();
421}
422
423void VideoAnalyzer::StartExcludingCpuThreadTime() {
424 rtc::CritScope lock(&cpu_measurement_lock_);
425 cpu_time_ += rtc::GetThreadCpuTimeNanos();
426}
427
428void VideoAnalyzer::StopExcludingCpuThreadTime() {
429 rtc::CritScope lock(&cpu_measurement_lock_);
430 cpu_time_ -= rtc::GetThreadCpuTimeNanos();
431}
432
433double VideoAnalyzer::GetCpuUsagePercent() {
434 rtc::CritScope lock(&cpu_measurement_lock_);
435 return static_cast<double>(cpu_time_) / wallclock_time_ * 100.0;
436}
437
438bool VideoAnalyzer::IsInSelectedSpatialAndTemporalLayer(
439 const uint8_t* packet,
440 size_t length,
441 const RTPHeader& header) {
442 if (header.payloadType != test::CallTest::kPayloadTypeVP9 &&
443 header.payloadType != test::CallTest::kPayloadTypeVP8) {
444 return true;
445 } else {
446 // Get VP8 and VP9 specific header to check layers indexes.
447 const uint8_t* payload = packet + header.headerLength;
448 const size_t payload_length = length - header.headerLength;
449 const size_t payload_data_length = payload_length - header.paddingLength;
450 const bool is_vp8 = header.payloadType == test::CallTest::kPayloadTypeVP8;
451 std::unique_ptr<RtpDepacketizer> depacketizer(
452 RtpDepacketizer::Create(is_vp8 ? kVideoCodecVP8 : kVideoCodecVP9));
453 RtpDepacketizer::ParsedPayload parsed_payload;
454 bool result =
455 depacketizer->Parse(&parsed_payload, payload, payload_data_length);
456 RTC_DCHECK(result);
philipel29d88462018-08-08 14:26:00 +0200457
458 int temporal_idx;
459 int spatial_idx;
460 if (is_vp8) {
Philip Eliassond52a1a62018-09-07 13:03:55 +0000461 temporal_idx = absl::get<RTPVideoHeaderVP8>(
462 parsed_payload.video_header().video_type_header)
463 .temporalIdx;
philipel29d88462018-08-08 14:26:00 +0200464 spatial_idx = kNoTemporalIdx;
465 } else {
466 const auto& vp9_header = absl::get<RTPVideoHeaderVP9>(
467 parsed_payload.video_header().video_type_header);
468 temporal_idx = vp9_header.temporal_idx;
469 spatial_idx = vp9_header.spatial_idx;
470 }
471
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200472 return (selected_tl_ < 0 || temporal_idx == kNoTemporalIdx ||
473 temporal_idx <= selected_tl_) &&
474 (selected_sl_ < 0 || spatial_idx == kNoSpatialIdx ||
475 spatial_idx <= selected_sl_);
476 }
477}
478
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200479void VideoAnalyzer::PollStats() {
Artem Titovff7730d2019-04-02 13:46:53 +0200480 rtc::CritScope crit(&comparison_lock_);
481 if (stop_stats_poller_) {
482 return;
Artem Titovf537da62019-04-02 13:46:53 +0200483 }
Artem Titovff7730d2019-04-02 13:46:53 +0200484
485 Call::Stats call_stats = call_->GetStats();
486 send_bandwidth_bps_.AddSample(call_stats.send_bandwidth_bps);
487
488 VideoSendStream::Stats send_stats = send_stream_->GetStats();
489 // It's not certain that we yet have estimates for any of these stats.
490 // Check that they are positive before mixing them in.
491 if (send_stats.encode_frame_rate > 0)
492 encode_frame_rate_.AddSample(send_stats.encode_frame_rate);
493 if (send_stats.avg_encode_time_ms > 0)
494 encode_time_ms_.AddSample(send_stats.avg_encode_time_ms);
495 if (send_stats.encode_usage_percent > 0)
496 encode_usage_percent_.AddSample(send_stats.encode_usage_percent);
497 if (send_stats.media_bitrate_bps > 0)
498 media_bitrate_bps_.AddSample(send_stats.media_bitrate_bps);
499 size_t fec_bytes = 0;
500 for (const auto& kv : send_stats.substreams) {
501 fec_bytes += kv.second.rtp_stats.fec.payload_bytes +
502 kv.second.rtp_stats.fec.padding_bytes;
503 }
504 fec_bitrate_bps_.AddSample((fec_bytes - last_fec_bytes_) * 8);
505 last_fec_bytes_ = fec_bytes;
506
507 if (receive_stream_ != nullptr) {
508 VideoReceiveStream::Stats receive_stats = receive_stream_->GetStats();
509 if (receive_stats.decode_ms > 0)
510 decode_time_ms_.AddSample(receive_stats.decode_ms);
511 if (receive_stats.max_decode_ms > 0)
512 decode_time_max_ms_.AddSample(receive_stats.max_decode_ms);
513 if (receive_stats.width > 0 && receive_stats.height > 0) {
514 pixels_.AddSample(receive_stats.width * receive_stats.height);
515 }
Elad Alon8c513c72019-05-07 21:22:24 +0200516 freeze_count_ = receive_stats.freeze_count;
517 total_freezes_duration_ms_ = receive_stats.total_freezes_duration_ms;
518 total_frames_duration_ms_ = receive_stats.total_frames_duration_ms;
519 sum_squared_frame_durations_ = receive_stats.sum_squared_frame_durations;
Artem Titovff7730d2019-04-02 13:46:53 +0200520 }
521
522 if (audio_receive_stream_ != nullptr) {
523 AudioReceiveStream::Stats receive_stats = audio_receive_stream_->GetStats();
524 audio_expand_rate_.AddSample(receive_stats.expand_rate);
525 audio_accelerate_rate_.AddSample(receive_stats.accelerate_rate);
526 audio_jitter_buffer_ms_.AddSample(receive_stats.jitter_buffer_ms);
527 }
528
529 memory_usage_.AddSample(rtc::GetProcessResidentSizeBytes());
530
531 stats_polling_task_id_ = task_queue_->PostDelayedTask(
532 [this]() { PollStats(); }, kSendStatsPollingIntervalMs);
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200533}
534
Niels Möller4731f002019-05-03 09:34:24 +0200535void VideoAnalyzer::FrameComparisonThread(void* obj) {
536 VideoAnalyzer* analyzer = static_cast<VideoAnalyzer*>(obj);
537 while (analyzer->CompareFrames()) {
538 }
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200539}
540
541bool VideoAnalyzer::CompareFrames() {
542 if (AllFramesRecorded())
543 return false;
544
545 FrameComparison comparison;
546
547 if (!PopComparison(&comparison)) {
548 // Wait until new comparison task is available, or test is done.
549 // If done, wake up remaining threads waiting.
550 comparison_available_event_.Wait(1000);
551 if (AllFramesRecorded()) {
552 comparison_available_event_.Set();
553 return false;
554 }
555 return true; // Try again.
556 }
557
558 StartExcludingCpuThreadTime();
559
560 PerformFrameComparison(comparison);
561
562 StopExcludingCpuThreadTime();
563
564 if (FrameProcessed()) {
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200565 done_.Set();
566 comparison_available_event_.Set();
567 return false;
568 }
569
570 return true;
571}
572
573bool VideoAnalyzer::PopComparison(VideoAnalyzer::FrameComparison* comparison) {
574 rtc::CritScope crit(&comparison_lock_);
575 // If AllFramesRecorded() is true, it means we have already popped
576 // frames_to_process_ frames from comparisons_, so there is no more work
577 // for this thread to be done. frames_processed_ might still be lower if
578 // all comparisons are not done, but those frames are currently being
579 // worked on by other threads.
580 if (comparisons_.empty() || AllFramesRecorded())
581 return false;
582
583 *comparison = comparisons_.front();
584 comparisons_.pop_front();
585
586 FrameRecorded();
587 return true;
588}
589
590void VideoAnalyzer::FrameRecorded() {
591 rtc::CritScope crit(&comparison_lock_);
592 ++frames_recorded_;
593}
594
595bool VideoAnalyzer::AllFramesRecorded() {
596 rtc::CritScope crit(&comparison_lock_);
Niels Möller4731f002019-05-03 09:34:24 +0200597 RTC_DCHECK(frames_recorded_ <= frames_to_process_);
598 return frames_recorded_ == frames_to_process_ || quit_;
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200599}
600
601bool VideoAnalyzer::FrameProcessed() {
602 rtc::CritScope crit(&comparison_lock_);
603 ++frames_processed_;
604 assert(frames_processed_ <= frames_to_process_);
605 return frames_processed_ == frames_to_process_;
606}
607
608void VideoAnalyzer::PrintResults() {
609 StopMeasuringCpuProcessTime();
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100610 int frames_left;
611 {
612 rtc::CritScope crit(&crit_);
613 frames_left = frames_.size();
614 }
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200615 rtc::CritScope crit(&comparison_lock_);
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200616 PrintResult("psnr", psnr_, " dB");
617 PrintResult("ssim", ssim_, " score");
618 PrintResult("sender_time", sender_time_, " ms");
619 PrintResult("receiver_time", receiver_time_, " ms");
620 PrintResult("network_time", network_time_, " ms");
621 PrintResult("total_delay_incl_network", end_to_end_, " ms");
622 PrintResult("time_between_rendered_frames", rendered_delta_, " ms");
623 PrintResult("encode_frame_rate", encode_frame_rate_, " fps");
624 PrintResult("encode_time", encode_time_ms_, " ms");
625 PrintResult("media_bitrate", media_bitrate_bps_, " bps");
626 PrintResult("fec_bitrate", fec_bitrate_bps_, " bps");
627 PrintResult("send_bandwidth", send_bandwidth_bps_, " bps");
Ilya Nikolaevskiyd47d3eb2019-01-21 16:27:17 +0100628 PrintResult("pixels_per_frame", pixels_, " px");
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200629
Elad Alon8c513c72019-05-07 21:22:24 +0200630 // Record the time from the last freeze until the last rendered frame to
631 // ensure we cover the full timespan of the session. Otherwise the metric
632 // would penalize an early freeze followed by no freezes until the end.
633 time_between_freezes_.AddSample(last_render_time_ - last_unfreeze_time_ms_);
634
635 // Freeze metrics.
636 PrintResult("time_between_freezes", time_between_freezes_, " ms");
637
638 const double freeze_count_double = static_cast<double>(freeze_count_);
639 const double total_freezes_duration_ms_double =
640 static_cast<double>(total_freezes_duration_ms_);
641 const double total_frames_duration_ms_double =
642 static_cast<double>(total_frames_duration_ms_);
643
644 if (total_frames_duration_ms_double > 0) {
645 test::PrintResult(
646 "freeze_duration_ratio", "", test_label_.c_str(),
647 total_freezes_duration_ms_double / total_frames_duration_ms_double, "",
648 false);
649 RTC_DCHECK_LE(total_freezes_duration_ms_double,
650 total_frames_duration_ms_double);
651
652 constexpr double ms_per_minute = 60 * 1000;
653 const double total_frames_duration_min =
654 total_frames_duration_ms_double / ms_per_minute;
655 if (total_frames_duration_min > 0) {
656 test::PrintResult("freeze_count_per_minute", "", test_label_.c_str(),
657 freeze_count_double / total_frames_duration_min,
658 "freezes", false);
659 }
660 }
661
Elad Alon133f7e72019-05-08 09:51:56 +0200662 test::PrintResult("freeze_duration_average", "", test_label_.c_str(),
Elad Alon8c513c72019-05-07 21:22:24 +0200663 freeze_count_double > 0
664 ? total_freezes_duration_ms_double / freeze_count_double
665 : 0,
666 "ms", false);
667
668 if (1000 * sum_squared_frame_durations_ > 0) {
669 test::PrintResult(
670 "harmonic_frame_rate", "", test_label_.c_str(),
671 total_frames_duration_ms_double / (1000 * sum_squared_frame_durations_),
672 "", false);
673 }
674
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200675 if (worst_frame_) {
676 test::PrintResult("min_psnr", "", test_label_.c_str(), worst_frame_->psnr,
677 "dB", false);
678 }
679
680 if (receive_stream_ != nullptr) {
681 PrintResult("decode_time", decode_time_ms_, " ms");
682 }
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100683 dropped_frames_ += dropped_frames_before_first_encode_ +
684 dropped_frames_before_rendering_ + frames_left;
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200685 test::PrintResult("dropped_frames", "", test_label_.c_str(), dropped_frames_,
686 "frames", false);
687 test::PrintResult("cpu_usage", "", test_label_.c_str(), GetCpuUsagePercent(),
688 "%", false);
689
690#if defined(WEBRTC_WIN)
691 // On Linux and Mac in Resident Set some unused pages may be counted.
692 // Therefore this metric will depend on order in which tests are run and
693 // will be flaky.
694 PrintResult("memory_usage", memory_usage_, " bytes");
695#endif
696
697 // Saving only the worst frame for manual analysis. Intention here is to
698 // only detect video corruptions and not to track picture quality. Thus,
699 // jpeg is used here.
700 if (FLAG_save_worst_frame && worst_frame_) {
701 std::string output_dir;
702 test::GetTestArtifactsDir(&output_dir);
703 std::string output_path =
Niels Möller7b3c76b2018-11-07 09:54:28 +0100704 test::JoinFilename(output_dir, test_label_ + ".jpg");
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200705 RTC_LOG(LS_INFO) << "Saving worst frame to " << output_path;
706 test::JpegFrameWriter frame_writer(output_path);
707 RTC_CHECK(
708 frame_writer.WriteFrame(worst_frame_->frame, 100 /*best quality*/));
709 }
710
Christoffer Rodbroc2a02882018-08-07 14:10:56 +0200711 if (audio_receive_stream_ != nullptr) {
712 PrintResult("audio_expand_rate", audio_expand_rate_, "");
713 PrintResult("audio_accelerate_rate", audio_accelerate_rate_, "");
714 PrintResult("audio_jitter_buffer", audio_jitter_buffer_ms_, " ms");
715 }
716
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200717 // Disable quality check for quick test, as quality checks may fail
718 // because too few samples were collected.
719 if (!is_quick_test_enabled_) {
Yves Gerey79e9f4b2019-04-13 18:59:53 +0200720 EXPECT_GT(*psnr_.GetMean(), avg_psnr_threshold_);
721 EXPECT_GT(*ssim_.GetMean(), avg_ssim_threshold_);
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200722 }
723}
724
725void VideoAnalyzer::PerformFrameComparison(
726 const VideoAnalyzer::FrameComparison& comparison) {
727 // Perform expensive psnr and ssim calculations while not holding lock.
728 double psnr = -1.0;
729 double ssim = -1.0;
730 if (comparison.reference && !comparison.dropped) {
731 psnr = I420PSNR(&*comparison.reference, &*comparison.render);
732 ssim = I420SSIM(&*comparison.reference, &*comparison.render);
733 }
734
735 rtc::CritScope crit(&comparison_lock_);
736
737 if (psnr >= 0.0 && (!worst_frame_ || worst_frame_->psnr > psnr)) {
738 worst_frame_.emplace(FrameWithPsnr{psnr, *comparison.render});
739 }
740
741 if (graph_data_output_file_) {
742 samples_.push_back(Sample(comparison.dropped, comparison.input_time_ms,
743 comparison.send_time_ms, comparison.recv_time_ms,
744 comparison.render_time_ms,
745 comparison.encoded_frame_size, psnr, ssim));
746 }
747 if (psnr >= 0.0)
748 psnr_.AddSample(psnr);
749 if (ssim >= 0.0)
750 ssim_.AddSample(ssim);
751
752 if (comparison.dropped) {
753 ++dropped_frames_;
754 return;
755 }
756 if (last_unfreeze_time_ms_ == 0)
757 last_unfreeze_time_ms_ = comparison.render_time_ms;
758 if (last_render_time_ != 0) {
759 const int64_t render_delta_ms =
760 comparison.render_time_ms - last_render_time_;
761 rendered_delta_.AddSample(render_delta_ms);
762 if (last_render_delta_ms_ != 0 &&
763 render_delta_ms - last_render_delta_ms_ > 150) {
764 time_between_freezes_.AddSample(last_render_time_ -
765 last_unfreeze_time_ms_);
766 last_unfreeze_time_ms_ = comparison.render_time_ms;
767 }
768 last_render_delta_ms_ = render_delta_ms;
769 }
770 last_render_time_ = comparison.render_time_ms;
771
772 sender_time_.AddSample(comparison.send_time_ms - comparison.input_time_ms);
773 if (comparison.recv_time_ms > 0) {
774 // If recv_time_ms == 0, this frame consisted of a packets which were all
775 // lost in the transport. Since we were able to render the frame, however,
776 // the dropped packets were recovered by FlexFEC. The FlexFEC recovery
777 // happens internally in Call, and we can therefore here not know which
778 // FEC packets that protected the lost media packets. Consequently, we
779 // were not able to record a meaningful recv_time_ms. We therefore skip
780 // this sample.
781 //
782 // The reasoning above does not hold for ULPFEC and RTX, as for those
783 // strategies the timestamp of the received packets is set to the
784 // timestamp of the protected/retransmitted media packet. I.e., then
785 // recv_time_ms != 0, even though the media packets were lost.
786 receiver_time_.AddSample(comparison.render_time_ms -
787 comparison.recv_time_ms);
788 network_time_.AddSample(comparison.recv_time_ms - comparison.send_time_ms);
789 }
790 end_to_end_.AddSample(comparison.render_time_ms - comparison.input_time_ms);
791 encoded_frame_size_.AddSample(comparison.encoded_frame_size);
792}
793
794void VideoAnalyzer::PrintResult(const char* result_type,
Yves Gerey79e9f4b2019-04-13 18:59:53 +0200795 Statistics stats,
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200796 const char* unit) {
Yves Gerey79e9f4b2019-04-13 18:59:53 +0200797 test::PrintResultMeanAndError(
798 result_type, "", test_label_.c_str(), stats.GetMean().value_or(0),
799 stats.GetStandardDeviation().value_or(0), unit, false);
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200800}
801
802void VideoAnalyzer::PrintSamplesToFile() {
803 FILE* out = graph_data_output_file_;
804 rtc::CritScope crit(&comparison_lock_);
Steve Antonbd631a02019-03-28 10:51:27 -0700805 absl::c_sort(samples_, [](const Sample& A, const Sample& B) -> bool {
806 return A.input_time_ms < B.input_time_ms;
807 });
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200808
809 fprintf(out, "%s\n", graph_title_.c_str());
810 fprintf(out, "%" PRIuS "\n", samples_.size());
811 fprintf(out,
812 "dropped "
813 "input_time_ms "
814 "send_time_ms "
815 "recv_time_ms "
816 "render_time_ms "
817 "encoded_frame_size "
818 "psnr "
819 "ssim "
820 "encode_time_ms\n");
821 for (const Sample& sample : samples_) {
822 fprintf(out,
823 "%d %" PRId64 " %" PRId64 " %" PRId64 " %" PRId64 " %" PRIuS
824 " %lf %lf\n",
825 sample.dropped, sample.input_time_ms, sample.send_time_ms,
826 sample.recv_time_ms, sample.render_time_ms,
827 sample.encoded_frame_size, sample.psnr, sample.ssim);
828 }
829}
830
831double VideoAnalyzer::GetAverageMediaBitrateBps() {
832 if (last_sending_time_ == first_sending_time_) {
833 return 0;
834 } else {
835 return static_cast<double>(total_media_bytes_) * 8 /
836 (last_sending_time_ - first_sending_time_) *
837 rtc::kNumMillisecsPerSec;
838 }
839}
840
841void VideoAnalyzer::AddCapturedFrameForComparison(
842 const VideoFrame& video_frame) {
843 rtc::CritScope lock(&crit_);
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100844 if (captured_frames_ < frames_to_process_) {
845 ++captured_frames_;
846 frames_.push_back(video_frame);
847 }
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200848}
849
850void VideoAnalyzer::AddFrameComparison(const VideoFrame& reference,
851 const VideoFrame& render,
852 bool dropped,
853 int64_t render_time_ms) {
854 int64_t reference_timestamp = wrap_handler_.Unwrap(reference.timestamp());
855 int64_t send_time_ms = send_times_[reference_timestamp];
856 send_times_.erase(reference_timestamp);
857 int64_t recv_time_ms = recv_times_[reference_timestamp];
858 recv_times_.erase(reference_timestamp);
859
860 // TODO(ivica): Make this work for > 2 streams.
861 auto it = encoded_frame_sizes_.find(reference_timestamp);
862 if (it == encoded_frame_sizes_.end())
863 it = encoded_frame_sizes_.find(reference_timestamp - 1);
864 size_t encoded_size = it == encoded_frame_sizes_.end() ? 0 : it->second;
865 if (it != encoded_frame_sizes_.end())
866 encoded_frame_sizes_.erase(it);
867
868 rtc::CritScope crit(&comparison_lock_);
869 if (comparisons_.size() < kMaxComparisons) {
870 comparisons_.push_back(FrameComparison(
871 reference, render, dropped, reference.ntp_time_ms(), send_time_ms,
872 recv_time_ms, render_time_ms, encoded_size));
873 } else {
874 comparisons_.push_back(FrameComparison(dropped, reference.ntp_time_ms(),
875 send_time_ms, recv_time_ms,
876 render_time_ms, encoded_size));
877 }
878 comparison_available_event_.Set();
879}
880
881VideoAnalyzer::FrameComparison::FrameComparison()
882 : dropped(false),
883 input_time_ms(0),
884 send_time_ms(0),
885 recv_time_ms(0),
886 render_time_ms(0),
887 encoded_frame_size(0) {}
888
889VideoAnalyzer::FrameComparison::FrameComparison(const VideoFrame& reference,
890 const VideoFrame& render,
891 bool dropped,
892 int64_t input_time_ms,
893 int64_t send_time_ms,
894 int64_t recv_time_ms,
895 int64_t render_time_ms,
896 size_t encoded_frame_size)
897 : reference(reference),
898 render(render),
899 dropped(dropped),
900 input_time_ms(input_time_ms),
901 send_time_ms(send_time_ms),
902 recv_time_ms(recv_time_ms),
903 render_time_ms(render_time_ms),
904 encoded_frame_size(encoded_frame_size) {}
905
906VideoAnalyzer::FrameComparison::FrameComparison(bool dropped,
907 int64_t input_time_ms,
908 int64_t send_time_ms,
909 int64_t recv_time_ms,
910 int64_t render_time_ms,
911 size_t encoded_frame_size)
912 : dropped(dropped),
913 input_time_ms(input_time_ms),
914 send_time_ms(send_time_ms),
915 recv_time_ms(recv_time_ms),
916 render_time_ms(render_time_ms),
917 encoded_frame_size(encoded_frame_size) {}
918
919VideoAnalyzer::Sample::Sample(int dropped,
920 int64_t input_time_ms,
921 int64_t send_time_ms,
922 int64_t recv_time_ms,
923 int64_t render_time_ms,
924 size_t encoded_frame_size,
925 double psnr,
926 double ssim)
927 : dropped(dropped),
928 input_time_ms(input_time_ms),
929 send_time_ms(send_time_ms),
930 recv_time_ms(recv_time_ms),
931 render_time_ms(render_time_ms),
932 encoded_frame_size(encoded_frame_size),
933 psnr(psnr),
934 ssim(ssim) {}
935
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200936VideoAnalyzer::CapturedFrameForwarder::CapturedFrameForwarder(
937 VideoAnalyzer* analyzer,
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100938 Clock* clock,
Ilya Nikolaevskiy85fc3252019-02-11 10:41:50 +0100939 int frames_to_process)
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200940 : analyzer_(analyzer),
941 send_stream_input_(nullptr),
Niels Möller1c931c42018-12-18 16:08:11 +0100942 video_source_(nullptr),
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100943 clock_(clock),
944 captured_frames_(0),
Ilya Nikolaevskiy85fc3252019-02-11 10:41:50 +0100945 frames_to_process_(frames_to_process) {}
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200946
947void VideoAnalyzer::CapturedFrameForwarder::SetSource(
Niels Möller1c931c42018-12-18 16:08:11 +0100948 VideoSourceInterface<VideoFrame>* video_source) {
949 video_source_ = video_source;
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200950}
951
952void VideoAnalyzer::CapturedFrameForwarder::OnFrame(
953 const VideoFrame& video_frame) {
954 VideoFrame copy = video_frame;
955 // Frames from the capturer does not have a rtp timestamp.
956 // Create one so it can be used for comparison.
957 RTC_DCHECK_EQ(0, video_frame.timestamp());
958 if (video_frame.ntp_time_ms() == 0)
959 copy.set_ntp_time_ms(clock_->CurrentNtpInMilliseconds());
960 copy.set_timestamp(copy.ntp_time_ms() * 90);
961 analyzer_->AddCapturedFrameForComparison(copy);
962 rtc::CritScope lock(&crit_);
Ilya Nikolaevskiy6957abe2019-01-29 16:33:04 +0100963 ++captured_frames_;
Ilya Nikolaevskiy85fc3252019-02-11 10:41:50 +0100964 if (send_stream_input_ && captured_frames_ <= frames_to_process_)
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200965 send_stream_input_->OnFrame(copy);
966}
967
968void VideoAnalyzer::CapturedFrameForwarder::AddOrUpdateSink(
969 rtc::VideoSinkInterface<VideoFrame>* sink,
970 const rtc::VideoSinkWants& wants) {
971 {
972 rtc::CritScope lock(&crit_);
973 RTC_DCHECK(!send_stream_input_ || send_stream_input_ == sink);
974 send_stream_input_ = sink;
975 }
Niels Möller1c931c42018-12-18 16:08:11 +0100976 if (video_source_) {
977 video_source_->AddOrUpdateSink(this, wants);
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200978 }
979}
980
981void VideoAnalyzer::CapturedFrameForwarder::RemoveSink(
982 rtc::VideoSinkInterface<VideoFrame>* sink) {
983 rtc::CritScope lock(&crit_);
984 RTC_DCHECK(sink == send_stream_input_);
985 send_stream_input_ = nullptr;
Sebastian Janssond4c5d632018-07-10 12:57:37 +0200986}
987
988} // namespace webrtc