Sebastian Jansson | d4c5d63 | 2018-07-10 12:57:37 +0200 | [diff] [blame] | 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 <algorithm> |
| 13 | #include <utility> |
| 14 | |
| 15 | #include "modules/rtp_rtcp/source/rtp_format.h" |
| 16 | #include "modules/rtp_rtcp/source/rtp_utility.h" |
| 17 | #include "rtc_base/cpu_time.h" |
| 18 | #include "rtc_base/flags.h" |
| 19 | #include "rtc_base/format_macros.h" |
| 20 | #include "rtc_base/memory_usage.h" |
| 21 | #include "rtc_base/pathutils.h" |
| 22 | #include "system_wrappers/include/cpu_info.h" |
| 23 | #include "test/call_test.h" |
| 24 | #include "test/testsupport/frame_writer.h" |
| 25 | #include "test/testsupport/perf_test.h" |
| 26 | #include "test/testsupport/test_artifacts.h" |
| 27 | |
| 28 | DEFINE_bool(save_worst_frame, |
| 29 | false, |
| 30 | "Enable saving a frame with the lowest PSNR to a jpeg file in the " |
| 31 | "test_artifacts_dir"); |
| 32 | |
| 33 | namespace webrtc { |
| 34 | namespace { |
| 35 | constexpr int kSendStatsPollingIntervalMs = 1000; |
| 36 | constexpr size_t kMaxComparisons = 10; |
| 37 | |
| 38 | bool IsFlexfec(int payload_type) { |
| 39 | return payload_type == test::CallTest::kFlexfecPayloadType; |
| 40 | } |
| 41 | } // namespace |
| 42 | |
| 43 | VideoAnalyzer::VideoAnalyzer(test::LayerFilteringTransport* transport, |
| 44 | const std::string& test_label, |
| 45 | double avg_psnr_threshold, |
| 46 | double avg_ssim_threshold, |
| 47 | int duration_frames, |
| 48 | FILE* graph_data_output_file, |
| 49 | const std::string& graph_title, |
| 50 | uint32_t ssrc_to_analyze, |
| 51 | uint32_t rtx_ssrc_to_analyze, |
| 52 | size_t selected_stream, |
| 53 | int selected_sl, |
| 54 | int selected_tl, |
| 55 | bool is_quick_test_enabled, |
| 56 | Clock* clock, |
| 57 | std::string rtp_dump_name) |
| 58 | : transport_(transport), |
| 59 | receiver_(nullptr), |
| 60 | call_(nullptr), |
| 61 | send_stream_(nullptr), |
| 62 | receive_stream_(nullptr), |
| 63 | captured_frame_forwarder_(this, clock), |
| 64 | test_label_(test_label), |
| 65 | graph_data_output_file_(graph_data_output_file), |
| 66 | graph_title_(graph_title), |
| 67 | ssrc_to_analyze_(ssrc_to_analyze), |
| 68 | rtx_ssrc_to_analyze_(rtx_ssrc_to_analyze), |
| 69 | selected_stream_(selected_stream), |
| 70 | selected_sl_(selected_sl), |
| 71 | selected_tl_(selected_tl), |
| 72 | pre_encode_proxy_(this), |
| 73 | last_fec_bytes_(0), |
| 74 | frames_to_process_(duration_frames), |
| 75 | frames_recorded_(0), |
| 76 | frames_processed_(0), |
| 77 | dropped_frames_(0), |
| 78 | dropped_frames_before_first_encode_(0), |
| 79 | dropped_frames_before_rendering_(0), |
| 80 | last_render_time_(0), |
| 81 | last_render_delta_ms_(0), |
| 82 | last_unfreeze_time_ms_(0), |
| 83 | rtp_timestamp_delta_(0), |
| 84 | total_media_bytes_(0), |
| 85 | first_sending_time_(0), |
| 86 | last_sending_time_(0), |
| 87 | cpu_time_(0), |
| 88 | wallclock_time_(0), |
| 89 | avg_psnr_threshold_(avg_psnr_threshold), |
| 90 | avg_ssim_threshold_(avg_ssim_threshold), |
| 91 | is_quick_test_enabled_(is_quick_test_enabled), |
| 92 | stats_polling_thread_(&PollStatsThread, this, "StatsPoller"), |
| 93 | comparison_available_event_(false, false), |
| 94 | done_(true, false), |
| 95 | clock_(clock), |
| 96 | start_ms_(clock->TimeInMilliseconds()) { |
| 97 | // Create thread pool for CPU-expensive PSNR/SSIM calculations. |
| 98 | |
| 99 | // Try to use about as many threads as cores, but leave kMinCoresLeft alone, |
| 100 | // so that we don't accidentally starve "real" worker threads (codec etc). |
| 101 | // Also, don't allocate more than kMaxComparisonThreads, even if there are |
| 102 | // spare cores. |
| 103 | |
| 104 | uint32_t num_cores = CpuInfo::DetectNumberOfCores(); |
| 105 | RTC_DCHECK_GE(num_cores, 1); |
| 106 | static const uint32_t kMinCoresLeft = 4; |
| 107 | static const uint32_t kMaxComparisonThreads = 8; |
| 108 | |
| 109 | if (num_cores <= kMinCoresLeft) { |
| 110 | num_cores = 1; |
| 111 | } else { |
| 112 | num_cores -= kMinCoresLeft; |
| 113 | num_cores = std::min(num_cores, kMaxComparisonThreads); |
| 114 | } |
| 115 | |
| 116 | for (uint32_t i = 0; i < num_cores; ++i) { |
| 117 | rtc::PlatformThread* thread = |
| 118 | new rtc::PlatformThread(&FrameComparisonThread, this, "Analyzer"); |
| 119 | thread->Start(); |
| 120 | comparison_thread_pool_.push_back(thread); |
| 121 | } |
| 122 | |
| 123 | if (!rtp_dump_name.empty()) { |
| 124 | fprintf(stdout, "Writing rtp dump to %s\n", rtp_dump_name.c_str()); |
| 125 | rtp_file_writer_.reset(test::RtpFileWriter::Create( |
| 126 | test::RtpFileWriter::kRtpDump, rtp_dump_name)); |
| 127 | } |
| 128 | } |
| 129 | |
| 130 | VideoAnalyzer::~VideoAnalyzer() { |
| 131 | for (rtc::PlatformThread* thread : comparison_thread_pool_) { |
| 132 | thread->Stop(); |
| 133 | delete thread; |
| 134 | } |
| 135 | } |
| 136 | |
| 137 | void VideoAnalyzer::SetReceiver(PacketReceiver* receiver) { |
| 138 | receiver_ = receiver; |
| 139 | } |
| 140 | |
| 141 | void VideoAnalyzer::SetSource(test::VideoCapturer* video_capturer, |
| 142 | bool respect_sink_wants) { |
| 143 | if (respect_sink_wants) |
| 144 | captured_frame_forwarder_.SetSource(video_capturer); |
| 145 | rtc::VideoSinkWants wants; |
| 146 | video_capturer->AddOrUpdateSink(InputInterface(), wants); |
| 147 | } |
| 148 | |
| 149 | void VideoAnalyzer::SetCall(Call* call) { |
| 150 | rtc::CritScope lock(&crit_); |
| 151 | RTC_DCHECK(!call_); |
| 152 | call_ = call; |
| 153 | } |
| 154 | |
| 155 | void VideoAnalyzer::SetSendStream(VideoSendStream* stream) { |
| 156 | rtc::CritScope lock(&crit_); |
| 157 | RTC_DCHECK(!send_stream_); |
| 158 | send_stream_ = stream; |
| 159 | } |
| 160 | |
| 161 | void VideoAnalyzer::SetReceiveStream(VideoReceiveStream* stream) { |
| 162 | rtc::CritScope lock(&crit_); |
| 163 | RTC_DCHECK(!receive_stream_); |
| 164 | receive_stream_ = stream; |
| 165 | } |
| 166 | |
| 167 | rtc::VideoSinkInterface<VideoFrame>* VideoAnalyzer::InputInterface() { |
| 168 | return &captured_frame_forwarder_; |
| 169 | } |
| 170 | |
| 171 | rtc::VideoSourceInterface<VideoFrame>* VideoAnalyzer::OutputInterface() { |
| 172 | return &captured_frame_forwarder_; |
| 173 | } |
| 174 | |
| 175 | PacketReceiver::DeliveryStatus VideoAnalyzer::DeliverPacket( |
| 176 | MediaType media_type, |
| 177 | rtc::CopyOnWriteBuffer packet, |
Niels Möller | 7008287 | 2018-08-07 11:03:12 +0200 | [diff] [blame] | 178 | int64_t packet_time_us) { |
Sebastian Jansson | d4c5d63 | 2018-07-10 12:57:37 +0200 | [diff] [blame] | 179 | // Ignore timestamps of RTCP packets. They're not synchronized with |
| 180 | // RTP packet timestamps and so they would confuse wrap_handler_. |
| 181 | if (RtpHeaderParser::IsRtcp(packet.cdata(), packet.size())) { |
Niels Möller | 7008287 | 2018-08-07 11:03:12 +0200 | [diff] [blame] | 182 | return receiver_->DeliverPacket(media_type, std::move(packet), |
| 183 | packet_time_us); |
Sebastian Jansson | d4c5d63 | 2018-07-10 12:57:37 +0200 | [diff] [blame] | 184 | } |
| 185 | |
| 186 | if (rtp_file_writer_) { |
| 187 | test::RtpPacket p; |
| 188 | memcpy(p.data, packet.cdata(), packet.size()); |
| 189 | p.length = packet.size(); |
| 190 | p.original_length = packet.size(); |
| 191 | p.time_ms = clock_->TimeInMilliseconds() - start_ms_; |
| 192 | rtp_file_writer_->WritePacket(&p); |
| 193 | } |
| 194 | |
| 195 | RtpUtility::RtpHeaderParser parser(packet.cdata(), packet.size()); |
| 196 | RTPHeader header; |
| 197 | parser.Parse(&header); |
| 198 | if (!IsFlexfec(header.payloadType) && (header.ssrc == ssrc_to_analyze_ || |
| 199 | header.ssrc == rtx_ssrc_to_analyze_)) { |
| 200 | // Ignore FlexFEC timestamps, to avoid collisions with media timestamps. |
| 201 | // (FlexFEC and media are sent on different SSRCs, which have different |
| 202 | // timestamps spaces.) |
| 203 | // Also ignore packets from wrong SSRC, but include retransmits. |
| 204 | rtc::CritScope lock(&crit_); |
| 205 | int64_t timestamp = |
| 206 | wrap_handler_.Unwrap(header.timestamp - rtp_timestamp_delta_); |
| 207 | recv_times_[timestamp] = |
| 208 | Clock::GetRealTimeClock()->CurrentNtpInMilliseconds(); |
| 209 | } |
| 210 | |
Niels Möller | 7008287 | 2018-08-07 11:03:12 +0200 | [diff] [blame] | 211 | return receiver_->DeliverPacket(media_type, std::move(packet), |
| 212 | packet_time_us); |
Sebastian Jansson | d4c5d63 | 2018-07-10 12:57:37 +0200 | [diff] [blame] | 213 | } |
| 214 | |
| 215 | void VideoAnalyzer::PreEncodeOnFrame(const VideoFrame& video_frame) { |
| 216 | rtc::CritScope lock(&crit_); |
| 217 | if (!first_encoded_timestamp_) { |
| 218 | while (frames_.front().timestamp() != video_frame.timestamp()) { |
| 219 | ++dropped_frames_before_first_encode_; |
| 220 | frames_.pop_front(); |
| 221 | RTC_CHECK(!frames_.empty()); |
| 222 | } |
| 223 | first_encoded_timestamp_ = video_frame.timestamp(); |
| 224 | } |
| 225 | } |
| 226 | |
| 227 | void VideoAnalyzer::EncodedFrameCallback(const EncodedFrame& encoded_frame) { |
| 228 | rtc::CritScope lock(&crit_); |
| 229 | if (!first_sent_timestamp_ && encoded_frame.stream_id_ == selected_stream_) { |
| 230 | first_sent_timestamp_ = encoded_frame.timestamp_; |
| 231 | } |
| 232 | } |
| 233 | |
| 234 | bool VideoAnalyzer::SendRtp(const uint8_t* packet, |
| 235 | size_t length, |
| 236 | const PacketOptions& options) { |
| 237 | RtpUtility::RtpHeaderParser parser(packet, length); |
| 238 | RTPHeader header; |
| 239 | parser.Parse(&header); |
| 240 | |
| 241 | int64_t current_time = Clock::GetRealTimeClock()->CurrentNtpInMilliseconds(); |
| 242 | |
| 243 | bool result = transport_->SendRtp(packet, length, options); |
| 244 | { |
| 245 | rtc::CritScope lock(&crit_); |
| 246 | if (rtp_timestamp_delta_ == 0 && header.ssrc == ssrc_to_analyze_) { |
| 247 | RTC_CHECK(static_cast<bool>(first_sent_timestamp_)); |
| 248 | rtp_timestamp_delta_ = header.timestamp - *first_sent_timestamp_; |
| 249 | } |
| 250 | |
| 251 | if (!IsFlexfec(header.payloadType) && header.ssrc == ssrc_to_analyze_) { |
| 252 | // Ignore FlexFEC timestamps, to avoid collisions with media timestamps. |
| 253 | // (FlexFEC and media are sent on different SSRCs, which have different |
| 254 | // timestamps spaces.) |
| 255 | // Also ignore packets from wrong SSRC and retransmits. |
| 256 | int64_t timestamp = |
| 257 | wrap_handler_.Unwrap(header.timestamp - rtp_timestamp_delta_); |
| 258 | send_times_[timestamp] = current_time; |
| 259 | |
| 260 | if (IsInSelectedSpatialAndTemporalLayer(packet, length, header)) { |
| 261 | encoded_frame_sizes_[timestamp] += |
| 262 | length - (header.headerLength + header.paddingLength); |
| 263 | total_media_bytes_ += |
| 264 | length - (header.headerLength + header.paddingLength); |
| 265 | } |
| 266 | if (first_sending_time_ == 0) |
| 267 | first_sending_time_ = current_time; |
| 268 | last_sending_time_ = current_time; |
| 269 | } |
| 270 | } |
| 271 | return result; |
| 272 | } |
| 273 | |
| 274 | bool VideoAnalyzer::SendRtcp(const uint8_t* packet, size_t length) { |
| 275 | return transport_->SendRtcp(packet, length); |
| 276 | } |
| 277 | |
| 278 | void VideoAnalyzer::OnFrame(const VideoFrame& video_frame) { |
| 279 | int64_t render_time_ms = |
| 280 | Clock::GetRealTimeClock()->CurrentNtpInMilliseconds(); |
| 281 | |
| 282 | rtc::CritScope lock(&crit_); |
| 283 | |
| 284 | StartExcludingCpuThreadTime(); |
| 285 | |
| 286 | int64_t send_timestamp = |
| 287 | wrap_handler_.Unwrap(video_frame.timestamp() - rtp_timestamp_delta_); |
| 288 | |
| 289 | while (wrap_handler_.Unwrap(frames_.front().timestamp()) < send_timestamp) { |
| 290 | if (!last_rendered_frame_) { |
| 291 | // No previous frame rendered, this one was dropped after sending but |
| 292 | // before rendering. |
| 293 | ++dropped_frames_before_rendering_; |
| 294 | } else { |
| 295 | AddFrameComparison(frames_.front(), *last_rendered_frame_, true, |
| 296 | render_time_ms); |
| 297 | } |
| 298 | frames_.pop_front(); |
| 299 | RTC_DCHECK(!frames_.empty()); |
| 300 | } |
| 301 | |
| 302 | VideoFrame reference_frame = frames_.front(); |
| 303 | frames_.pop_front(); |
| 304 | int64_t reference_timestamp = |
| 305 | wrap_handler_.Unwrap(reference_frame.timestamp()); |
| 306 | if (send_timestamp == reference_timestamp - 1) { |
| 307 | // TODO(ivica): Make this work for > 2 streams. |
| 308 | // Look at RTPSender::BuildRTPHeader. |
| 309 | ++send_timestamp; |
| 310 | } |
| 311 | ASSERT_EQ(reference_timestamp, send_timestamp); |
| 312 | |
| 313 | AddFrameComparison(reference_frame, video_frame, false, render_time_ms); |
| 314 | |
| 315 | last_rendered_frame_ = video_frame; |
| 316 | |
| 317 | StopExcludingCpuThreadTime(); |
| 318 | } |
| 319 | |
| 320 | void VideoAnalyzer::Wait() { |
| 321 | // Frame comparisons can be very expensive. Wait for test to be done, but |
| 322 | // at time-out check if frames_processed is going up. If so, give it more |
| 323 | // time, otherwise fail. Hopefully this will reduce test flakiness. |
| 324 | |
| 325 | stats_polling_thread_.Start(); |
| 326 | |
| 327 | int last_frames_processed = -1; |
| 328 | int iteration = 0; |
| 329 | while (!done_.Wait(test::CallTest::kDefaultTimeoutMs)) { |
| 330 | int frames_processed; |
| 331 | { |
| 332 | rtc::CritScope crit(&comparison_lock_); |
| 333 | frames_processed = frames_processed_; |
| 334 | } |
| 335 | |
| 336 | // Print some output so test infrastructure won't think we've crashed. |
| 337 | const char* kKeepAliveMessages[3] = { |
| 338 | "Uh, I'm-I'm not quite dead, sir.", |
| 339 | "Uh, I-I think uh, I could pull through, sir.", |
| 340 | "Actually, I think I'm all right to come with you--"}; |
| 341 | printf("- %s\n", kKeepAliveMessages[iteration++ % 3]); |
| 342 | |
| 343 | if (last_frames_processed == -1) { |
| 344 | last_frames_processed = frames_processed; |
| 345 | continue; |
| 346 | } |
| 347 | if (frames_processed == last_frames_processed) { |
| 348 | EXPECT_GT(frames_processed, last_frames_processed) |
| 349 | << "Analyzer stalled while waiting for test to finish."; |
| 350 | done_.Set(); |
| 351 | break; |
| 352 | } |
| 353 | last_frames_processed = frames_processed; |
| 354 | } |
| 355 | |
| 356 | if (iteration > 0) |
| 357 | printf("- Farewell, sweet Concorde!\n"); |
| 358 | |
| 359 | stats_polling_thread_.Stop(); |
| 360 | } |
| 361 | |
| 362 | rtc::VideoSinkInterface<VideoFrame>* VideoAnalyzer::pre_encode_proxy() { |
| 363 | return &pre_encode_proxy_; |
| 364 | } |
| 365 | |
| 366 | void VideoAnalyzer::StartMeasuringCpuProcessTime() { |
| 367 | rtc::CritScope lock(&cpu_measurement_lock_); |
| 368 | cpu_time_ -= rtc::GetProcessCpuTimeNanos(); |
| 369 | wallclock_time_ -= rtc::SystemTimeNanos(); |
| 370 | } |
| 371 | |
| 372 | void VideoAnalyzer::StopMeasuringCpuProcessTime() { |
| 373 | rtc::CritScope lock(&cpu_measurement_lock_); |
| 374 | cpu_time_ += rtc::GetProcessCpuTimeNanos(); |
| 375 | wallclock_time_ += rtc::SystemTimeNanos(); |
| 376 | } |
| 377 | |
| 378 | void VideoAnalyzer::StartExcludingCpuThreadTime() { |
| 379 | rtc::CritScope lock(&cpu_measurement_lock_); |
| 380 | cpu_time_ += rtc::GetThreadCpuTimeNanos(); |
| 381 | } |
| 382 | |
| 383 | void VideoAnalyzer::StopExcludingCpuThreadTime() { |
| 384 | rtc::CritScope lock(&cpu_measurement_lock_); |
| 385 | cpu_time_ -= rtc::GetThreadCpuTimeNanos(); |
| 386 | } |
| 387 | |
| 388 | double VideoAnalyzer::GetCpuUsagePercent() { |
| 389 | rtc::CritScope lock(&cpu_measurement_lock_); |
| 390 | return static_cast<double>(cpu_time_) / wallclock_time_ * 100.0; |
| 391 | } |
| 392 | |
| 393 | bool VideoAnalyzer::IsInSelectedSpatialAndTemporalLayer( |
| 394 | const uint8_t* packet, |
| 395 | size_t length, |
| 396 | const RTPHeader& header) { |
| 397 | if (header.payloadType != test::CallTest::kPayloadTypeVP9 && |
| 398 | header.payloadType != test::CallTest::kPayloadTypeVP8) { |
| 399 | return true; |
| 400 | } else { |
| 401 | // Get VP8 and VP9 specific header to check layers indexes. |
| 402 | const uint8_t* payload = packet + header.headerLength; |
| 403 | const size_t payload_length = length - header.headerLength; |
| 404 | const size_t payload_data_length = payload_length - header.paddingLength; |
| 405 | const bool is_vp8 = header.payloadType == test::CallTest::kPayloadTypeVP8; |
| 406 | std::unique_ptr<RtpDepacketizer> depacketizer( |
| 407 | RtpDepacketizer::Create(is_vp8 ? kVideoCodecVP8 : kVideoCodecVP9)); |
| 408 | RtpDepacketizer::ParsedPayload parsed_payload; |
| 409 | bool result = |
| 410 | depacketizer->Parse(&parsed_payload, payload, payload_data_length); |
| 411 | RTC_DCHECK(result); |
| 412 | const int temporal_idx = static_cast<int>( |
| 413 | is_vp8 ? parsed_payload.video_header().vp8().temporalIdx |
| 414 | : parsed_payload.video_header().vp9().temporal_idx); |
| 415 | const int spatial_idx = static_cast<int>( |
| 416 | is_vp8 ? kNoSpatialIdx |
| 417 | : parsed_payload.video_header().vp9().spatial_idx); |
| 418 | return (selected_tl_ < 0 || temporal_idx == kNoTemporalIdx || |
| 419 | temporal_idx <= selected_tl_) && |
| 420 | (selected_sl_ < 0 || spatial_idx == kNoSpatialIdx || |
| 421 | spatial_idx <= selected_sl_); |
| 422 | } |
| 423 | } |
| 424 | |
| 425 | void VideoAnalyzer::PollStatsThread(void* obj) { |
| 426 | static_cast<VideoAnalyzer*>(obj)->PollStats(); |
| 427 | } |
| 428 | |
| 429 | void VideoAnalyzer::PollStats() { |
| 430 | while (!done_.Wait(kSendStatsPollingIntervalMs)) { |
| 431 | rtc::CritScope crit(&comparison_lock_); |
| 432 | |
| 433 | Call::Stats call_stats = call_->GetStats(); |
| 434 | send_bandwidth_bps_.AddSample(call_stats.send_bandwidth_bps); |
| 435 | |
| 436 | VideoSendStream::Stats send_stats = send_stream_->GetStats(); |
| 437 | // It's not certain that we yet have estimates for any of these stats. |
| 438 | // Check that they are positive before mixing them in. |
| 439 | if (send_stats.encode_frame_rate > 0) |
| 440 | encode_frame_rate_.AddSample(send_stats.encode_frame_rate); |
| 441 | if (send_stats.avg_encode_time_ms > 0) |
| 442 | encode_time_ms_.AddSample(send_stats.avg_encode_time_ms); |
| 443 | if (send_stats.encode_usage_percent > 0) |
| 444 | encode_usage_percent_.AddSample(send_stats.encode_usage_percent); |
| 445 | if (send_stats.media_bitrate_bps > 0) |
| 446 | media_bitrate_bps_.AddSample(send_stats.media_bitrate_bps); |
| 447 | size_t fec_bytes = 0; |
| 448 | for (auto kv : send_stats.substreams) { |
| 449 | fec_bytes += kv.second.rtp_stats.fec.payload_bytes + |
| 450 | kv.second.rtp_stats.fec.padding_bytes; |
| 451 | } |
| 452 | fec_bitrate_bps_.AddSample((fec_bytes - last_fec_bytes_) * 8); |
| 453 | last_fec_bytes_ = fec_bytes; |
| 454 | |
| 455 | if (receive_stream_ != nullptr) { |
| 456 | VideoReceiveStream::Stats receive_stats = receive_stream_->GetStats(); |
| 457 | if (receive_stats.decode_ms > 0) |
| 458 | decode_time_ms_.AddSample(receive_stats.decode_ms); |
| 459 | if (receive_stats.max_decode_ms > 0) |
| 460 | decode_time_max_ms_.AddSample(receive_stats.max_decode_ms); |
| 461 | } |
| 462 | |
| 463 | memory_usage_.AddSample(rtc::GetProcessResidentSizeBytes()); |
| 464 | } |
| 465 | } |
| 466 | |
| 467 | bool VideoAnalyzer::FrameComparisonThread(void* obj) { |
| 468 | return static_cast<VideoAnalyzer*>(obj)->CompareFrames(); |
| 469 | } |
| 470 | |
| 471 | bool VideoAnalyzer::CompareFrames() { |
| 472 | if (AllFramesRecorded()) |
| 473 | return false; |
| 474 | |
| 475 | FrameComparison comparison; |
| 476 | |
| 477 | if (!PopComparison(&comparison)) { |
| 478 | // Wait until new comparison task is available, or test is done. |
| 479 | // If done, wake up remaining threads waiting. |
| 480 | comparison_available_event_.Wait(1000); |
| 481 | if (AllFramesRecorded()) { |
| 482 | comparison_available_event_.Set(); |
| 483 | return false; |
| 484 | } |
| 485 | return true; // Try again. |
| 486 | } |
| 487 | |
| 488 | StartExcludingCpuThreadTime(); |
| 489 | |
| 490 | PerformFrameComparison(comparison); |
| 491 | |
| 492 | StopExcludingCpuThreadTime(); |
| 493 | |
| 494 | if (FrameProcessed()) { |
| 495 | PrintResults(); |
| 496 | if (graph_data_output_file_) |
| 497 | PrintSamplesToFile(); |
| 498 | done_.Set(); |
| 499 | comparison_available_event_.Set(); |
| 500 | return false; |
| 501 | } |
| 502 | |
| 503 | return true; |
| 504 | } |
| 505 | |
| 506 | bool VideoAnalyzer::PopComparison(VideoAnalyzer::FrameComparison* comparison) { |
| 507 | rtc::CritScope crit(&comparison_lock_); |
| 508 | // If AllFramesRecorded() is true, it means we have already popped |
| 509 | // frames_to_process_ frames from comparisons_, so there is no more work |
| 510 | // for this thread to be done. frames_processed_ might still be lower if |
| 511 | // all comparisons are not done, but those frames are currently being |
| 512 | // worked on by other threads. |
| 513 | if (comparisons_.empty() || AllFramesRecorded()) |
| 514 | return false; |
| 515 | |
| 516 | *comparison = comparisons_.front(); |
| 517 | comparisons_.pop_front(); |
| 518 | |
| 519 | FrameRecorded(); |
| 520 | return true; |
| 521 | } |
| 522 | |
| 523 | void VideoAnalyzer::FrameRecorded() { |
| 524 | rtc::CritScope crit(&comparison_lock_); |
| 525 | ++frames_recorded_; |
| 526 | } |
| 527 | |
| 528 | bool VideoAnalyzer::AllFramesRecorded() { |
| 529 | rtc::CritScope crit(&comparison_lock_); |
| 530 | assert(frames_recorded_ <= frames_to_process_); |
| 531 | return frames_recorded_ == frames_to_process_; |
| 532 | } |
| 533 | |
| 534 | bool VideoAnalyzer::FrameProcessed() { |
| 535 | rtc::CritScope crit(&comparison_lock_); |
| 536 | ++frames_processed_; |
| 537 | assert(frames_processed_ <= frames_to_process_); |
| 538 | return frames_processed_ == frames_to_process_; |
| 539 | } |
| 540 | |
| 541 | void VideoAnalyzer::PrintResults() { |
| 542 | StopMeasuringCpuProcessTime(); |
| 543 | rtc::CritScope crit(&comparison_lock_); |
| 544 | // Record the time from the last freeze until the last rendered frame to |
| 545 | // ensure we cover the full timespan of the session. Otherwise the metric |
| 546 | // would penalize an early freeze followed by no freezes until the end. |
| 547 | time_between_freezes_.AddSample(last_render_time_ - last_unfreeze_time_ms_); |
| 548 | PrintResult("psnr", psnr_, " dB"); |
| 549 | PrintResult("ssim", ssim_, " score"); |
| 550 | PrintResult("sender_time", sender_time_, " ms"); |
| 551 | PrintResult("receiver_time", receiver_time_, " ms"); |
| 552 | PrintResult("network_time", network_time_, " ms"); |
| 553 | PrintResult("total_delay_incl_network", end_to_end_, " ms"); |
| 554 | PrintResult("time_between_rendered_frames", rendered_delta_, " ms"); |
| 555 | PrintResult("encode_frame_rate", encode_frame_rate_, " fps"); |
| 556 | PrintResult("encode_time", encode_time_ms_, " ms"); |
| 557 | PrintResult("media_bitrate", media_bitrate_bps_, " bps"); |
| 558 | PrintResult("fec_bitrate", fec_bitrate_bps_, " bps"); |
| 559 | PrintResult("send_bandwidth", send_bandwidth_bps_, " bps"); |
| 560 | PrintResult("time_between_freezes", time_between_freezes_, " ms"); |
| 561 | |
| 562 | if (worst_frame_) { |
| 563 | test::PrintResult("min_psnr", "", test_label_.c_str(), worst_frame_->psnr, |
| 564 | "dB", false); |
| 565 | } |
| 566 | |
| 567 | if (receive_stream_ != nullptr) { |
| 568 | PrintResult("decode_time", decode_time_ms_, " ms"); |
| 569 | } |
| 570 | |
| 571 | test::PrintResult("dropped_frames", "", test_label_.c_str(), dropped_frames_, |
| 572 | "frames", false); |
| 573 | test::PrintResult("cpu_usage", "", test_label_.c_str(), GetCpuUsagePercent(), |
| 574 | "%", false); |
| 575 | |
| 576 | #if defined(WEBRTC_WIN) |
| 577 | // On Linux and Mac in Resident Set some unused pages may be counted. |
| 578 | // Therefore this metric will depend on order in which tests are run and |
| 579 | // will be flaky. |
| 580 | PrintResult("memory_usage", memory_usage_, " bytes"); |
| 581 | #endif |
| 582 | |
| 583 | // Saving only the worst frame for manual analysis. Intention here is to |
| 584 | // only detect video corruptions and not to track picture quality. Thus, |
| 585 | // jpeg is used here. |
| 586 | if (FLAG_save_worst_frame && worst_frame_) { |
| 587 | std::string output_dir; |
| 588 | test::GetTestArtifactsDir(&output_dir); |
| 589 | std::string output_path = |
| 590 | rtc::Pathname(output_dir, test_label_ + ".jpg").pathname(); |
| 591 | RTC_LOG(LS_INFO) << "Saving worst frame to " << output_path; |
| 592 | test::JpegFrameWriter frame_writer(output_path); |
| 593 | RTC_CHECK( |
| 594 | frame_writer.WriteFrame(worst_frame_->frame, 100 /*best quality*/)); |
| 595 | } |
| 596 | |
| 597 | // Disable quality check for quick test, as quality checks may fail |
| 598 | // because too few samples were collected. |
| 599 | if (!is_quick_test_enabled_) { |
| 600 | EXPECT_GT(psnr_.Mean(), avg_psnr_threshold_); |
| 601 | EXPECT_GT(ssim_.Mean(), avg_ssim_threshold_); |
| 602 | } |
| 603 | } |
| 604 | |
| 605 | void VideoAnalyzer::PerformFrameComparison( |
| 606 | const VideoAnalyzer::FrameComparison& comparison) { |
| 607 | // Perform expensive psnr and ssim calculations while not holding lock. |
| 608 | double psnr = -1.0; |
| 609 | double ssim = -1.0; |
| 610 | if (comparison.reference && !comparison.dropped) { |
| 611 | psnr = I420PSNR(&*comparison.reference, &*comparison.render); |
| 612 | ssim = I420SSIM(&*comparison.reference, &*comparison.render); |
| 613 | } |
| 614 | |
| 615 | rtc::CritScope crit(&comparison_lock_); |
| 616 | |
| 617 | if (psnr >= 0.0 && (!worst_frame_ || worst_frame_->psnr > psnr)) { |
| 618 | worst_frame_.emplace(FrameWithPsnr{psnr, *comparison.render}); |
| 619 | } |
| 620 | |
| 621 | if (graph_data_output_file_) { |
| 622 | samples_.push_back(Sample(comparison.dropped, comparison.input_time_ms, |
| 623 | comparison.send_time_ms, comparison.recv_time_ms, |
| 624 | comparison.render_time_ms, |
| 625 | comparison.encoded_frame_size, psnr, ssim)); |
| 626 | } |
| 627 | if (psnr >= 0.0) |
| 628 | psnr_.AddSample(psnr); |
| 629 | if (ssim >= 0.0) |
| 630 | ssim_.AddSample(ssim); |
| 631 | |
| 632 | if (comparison.dropped) { |
| 633 | ++dropped_frames_; |
| 634 | return; |
| 635 | } |
| 636 | if (last_unfreeze_time_ms_ == 0) |
| 637 | last_unfreeze_time_ms_ = comparison.render_time_ms; |
| 638 | if (last_render_time_ != 0) { |
| 639 | const int64_t render_delta_ms = |
| 640 | comparison.render_time_ms - last_render_time_; |
| 641 | rendered_delta_.AddSample(render_delta_ms); |
| 642 | if (last_render_delta_ms_ != 0 && |
| 643 | render_delta_ms - last_render_delta_ms_ > 150) { |
| 644 | time_between_freezes_.AddSample(last_render_time_ - |
| 645 | last_unfreeze_time_ms_); |
| 646 | last_unfreeze_time_ms_ = comparison.render_time_ms; |
| 647 | } |
| 648 | last_render_delta_ms_ = render_delta_ms; |
| 649 | } |
| 650 | last_render_time_ = comparison.render_time_ms; |
| 651 | |
| 652 | sender_time_.AddSample(comparison.send_time_ms - comparison.input_time_ms); |
| 653 | if (comparison.recv_time_ms > 0) { |
| 654 | // If recv_time_ms == 0, this frame consisted of a packets which were all |
| 655 | // lost in the transport. Since we were able to render the frame, however, |
| 656 | // the dropped packets were recovered by FlexFEC. The FlexFEC recovery |
| 657 | // happens internally in Call, and we can therefore here not know which |
| 658 | // FEC packets that protected the lost media packets. Consequently, we |
| 659 | // were not able to record a meaningful recv_time_ms. We therefore skip |
| 660 | // this sample. |
| 661 | // |
| 662 | // The reasoning above does not hold for ULPFEC and RTX, as for those |
| 663 | // strategies the timestamp of the received packets is set to the |
| 664 | // timestamp of the protected/retransmitted media packet. I.e., then |
| 665 | // recv_time_ms != 0, even though the media packets were lost. |
| 666 | receiver_time_.AddSample(comparison.render_time_ms - |
| 667 | comparison.recv_time_ms); |
| 668 | network_time_.AddSample(comparison.recv_time_ms - comparison.send_time_ms); |
| 669 | } |
| 670 | end_to_end_.AddSample(comparison.render_time_ms - comparison.input_time_ms); |
| 671 | encoded_frame_size_.AddSample(comparison.encoded_frame_size); |
| 672 | } |
| 673 | |
| 674 | void VideoAnalyzer::PrintResult(const char* result_type, |
| 675 | test::Statistics stats, |
| 676 | const char* unit) { |
| 677 | test::PrintResultMeanAndError(result_type, "", test_label_.c_str(), |
| 678 | stats.Mean(), stats.StandardDeviation(), unit, |
| 679 | false); |
| 680 | } |
| 681 | |
| 682 | void VideoAnalyzer::PrintSamplesToFile() { |
| 683 | FILE* out = graph_data_output_file_; |
| 684 | rtc::CritScope crit(&comparison_lock_); |
| 685 | std::sort(samples_.begin(), samples_.end(), |
| 686 | [](const Sample& A, const Sample& B) -> bool { |
| 687 | return A.input_time_ms < B.input_time_ms; |
| 688 | }); |
| 689 | |
| 690 | fprintf(out, "%s\n", graph_title_.c_str()); |
| 691 | fprintf(out, "%" PRIuS "\n", samples_.size()); |
| 692 | fprintf(out, |
| 693 | "dropped " |
| 694 | "input_time_ms " |
| 695 | "send_time_ms " |
| 696 | "recv_time_ms " |
| 697 | "render_time_ms " |
| 698 | "encoded_frame_size " |
| 699 | "psnr " |
| 700 | "ssim " |
| 701 | "encode_time_ms\n"); |
| 702 | for (const Sample& sample : samples_) { |
| 703 | fprintf(out, |
| 704 | "%d %" PRId64 " %" PRId64 " %" PRId64 " %" PRId64 " %" PRIuS |
| 705 | " %lf %lf\n", |
| 706 | sample.dropped, sample.input_time_ms, sample.send_time_ms, |
| 707 | sample.recv_time_ms, sample.render_time_ms, |
| 708 | sample.encoded_frame_size, sample.psnr, sample.ssim); |
| 709 | } |
| 710 | } |
| 711 | |
| 712 | double VideoAnalyzer::GetAverageMediaBitrateBps() { |
| 713 | if (last_sending_time_ == first_sending_time_) { |
| 714 | return 0; |
| 715 | } else { |
| 716 | return static_cast<double>(total_media_bytes_) * 8 / |
| 717 | (last_sending_time_ - first_sending_time_) * |
| 718 | rtc::kNumMillisecsPerSec; |
| 719 | } |
| 720 | } |
| 721 | |
| 722 | void VideoAnalyzer::AddCapturedFrameForComparison( |
| 723 | const VideoFrame& video_frame) { |
| 724 | rtc::CritScope lock(&crit_); |
| 725 | frames_.push_back(video_frame); |
| 726 | } |
| 727 | |
| 728 | void VideoAnalyzer::AddFrameComparison(const VideoFrame& reference, |
| 729 | const VideoFrame& render, |
| 730 | bool dropped, |
| 731 | int64_t render_time_ms) { |
| 732 | int64_t reference_timestamp = wrap_handler_.Unwrap(reference.timestamp()); |
| 733 | int64_t send_time_ms = send_times_[reference_timestamp]; |
| 734 | send_times_.erase(reference_timestamp); |
| 735 | int64_t recv_time_ms = recv_times_[reference_timestamp]; |
| 736 | recv_times_.erase(reference_timestamp); |
| 737 | |
| 738 | // TODO(ivica): Make this work for > 2 streams. |
| 739 | auto it = encoded_frame_sizes_.find(reference_timestamp); |
| 740 | if (it == encoded_frame_sizes_.end()) |
| 741 | it = encoded_frame_sizes_.find(reference_timestamp - 1); |
| 742 | size_t encoded_size = it == encoded_frame_sizes_.end() ? 0 : it->second; |
| 743 | if (it != encoded_frame_sizes_.end()) |
| 744 | encoded_frame_sizes_.erase(it); |
| 745 | |
| 746 | rtc::CritScope crit(&comparison_lock_); |
| 747 | if (comparisons_.size() < kMaxComparisons) { |
| 748 | comparisons_.push_back(FrameComparison( |
| 749 | reference, render, dropped, reference.ntp_time_ms(), send_time_ms, |
| 750 | recv_time_ms, render_time_ms, encoded_size)); |
| 751 | } else { |
| 752 | comparisons_.push_back(FrameComparison(dropped, reference.ntp_time_ms(), |
| 753 | send_time_ms, recv_time_ms, |
| 754 | render_time_ms, encoded_size)); |
| 755 | } |
| 756 | comparison_available_event_.Set(); |
| 757 | } |
| 758 | |
| 759 | VideoAnalyzer::FrameComparison::FrameComparison() |
| 760 | : dropped(false), |
| 761 | input_time_ms(0), |
| 762 | send_time_ms(0), |
| 763 | recv_time_ms(0), |
| 764 | render_time_ms(0), |
| 765 | encoded_frame_size(0) {} |
| 766 | |
| 767 | VideoAnalyzer::FrameComparison::FrameComparison(const VideoFrame& reference, |
| 768 | const VideoFrame& render, |
| 769 | bool dropped, |
| 770 | int64_t input_time_ms, |
| 771 | int64_t send_time_ms, |
| 772 | int64_t recv_time_ms, |
| 773 | int64_t render_time_ms, |
| 774 | size_t encoded_frame_size) |
| 775 | : reference(reference), |
| 776 | render(render), |
| 777 | dropped(dropped), |
| 778 | input_time_ms(input_time_ms), |
| 779 | send_time_ms(send_time_ms), |
| 780 | recv_time_ms(recv_time_ms), |
| 781 | render_time_ms(render_time_ms), |
| 782 | encoded_frame_size(encoded_frame_size) {} |
| 783 | |
| 784 | VideoAnalyzer::FrameComparison::FrameComparison(bool dropped, |
| 785 | int64_t input_time_ms, |
| 786 | int64_t send_time_ms, |
| 787 | int64_t recv_time_ms, |
| 788 | int64_t render_time_ms, |
| 789 | size_t encoded_frame_size) |
| 790 | : dropped(dropped), |
| 791 | input_time_ms(input_time_ms), |
| 792 | send_time_ms(send_time_ms), |
| 793 | recv_time_ms(recv_time_ms), |
| 794 | render_time_ms(render_time_ms), |
| 795 | encoded_frame_size(encoded_frame_size) {} |
| 796 | |
| 797 | VideoAnalyzer::Sample::Sample(int dropped, |
| 798 | int64_t input_time_ms, |
| 799 | int64_t send_time_ms, |
| 800 | int64_t recv_time_ms, |
| 801 | int64_t render_time_ms, |
| 802 | size_t encoded_frame_size, |
| 803 | double psnr, |
| 804 | double ssim) |
| 805 | : dropped(dropped), |
| 806 | input_time_ms(input_time_ms), |
| 807 | send_time_ms(send_time_ms), |
| 808 | recv_time_ms(recv_time_ms), |
| 809 | render_time_ms(render_time_ms), |
| 810 | encoded_frame_size(encoded_frame_size), |
| 811 | psnr(psnr), |
| 812 | ssim(ssim) {} |
| 813 | |
| 814 | VideoAnalyzer::PreEncodeProxy::PreEncodeProxy(VideoAnalyzer* parent) |
| 815 | : parent_(parent) {} |
| 816 | |
| 817 | void VideoAnalyzer::PreEncodeProxy::OnFrame(const VideoFrame& video_frame) { |
| 818 | parent_->PreEncodeOnFrame(video_frame); |
| 819 | } |
| 820 | |
| 821 | VideoAnalyzer::CapturedFrameForwarder::CapturedFrameForwarder( |
| 822 | VideoAnalyzer* analyzer, |
| 823 | Clock* clock) |
| 824 | : analyzer_(analyzer), |
| 825 | send_stream_input_(nullptr), |
| 826 | video_capturer_(nullptr), |
| 827 | clock_(clock) {} |
| 828 | |
| 829 | void VideoAnalyzer::CapturedFrameForwarder::SetSource( |
| 830 | test::VideoCapturer* video_capturer) { |
| 831 | video_capturer_ = video_capturer; |
| 832 | } |
| 833 | |
| 834 | void VideoAnalyzer::CapturedFrameForwarder::OnFrame( |
| 835 | const VideoFrame& video_frame) { |
| 836 | VideoFrame copy = video_frame; |
| 837 | // Frames from the capturer does not have a rtp timestamp. |
| 838 | // Create one so it can be used for comparison. |
| 839 | RTC_DCHECK_EQ(0, video_frame.timestamp()); |
| 840 | if (video_frame.ntp_time_ms() == 0) |
| 841 | copy.set_ntp_time_ms(clock_->CurrentNtpInMilliseconds()); |
| 842 | copy.set_timestamp(copy.ntp_time_ms() * 90); |
| 843 | analyzer_->AddCapturedFrameForComparison(copy); |
| 844 | rtc::CritScope lock(&crit_); |
| 845 | if (send_stream_input_) |
| 846 | send_stream_input_->OnFrame(copy); |
| 847 | } |
| 848 | |
| 849 | void VideoAnalyzer::CapturedFrameForwarder::AddOrUpdateSink( |
| 850 | rtc::VideoSinkInterface<VideoFrame>* sink, |
| 851 | const rtc::VideoSinkWants& wants) { |
| 852 | { |
| 853 | rtc::CritScope lock(&crit_); |
| 854 | RTC_DCHECK(!send_stream_input_ || send_stream_input_ == sink); |
| 855 | send_stream_input_ = sink; |
| 856 | } |
| 857 | if (video_capturer_) { |
| 858 | video_capturer_->AddOrUpdateSink(this, wants); |
| 859 | } |
| 860 | } |
| 861 | |
| 862 | void VideoAnalyzer::CapturedFrameForwarder::RemoveSink( |
| 863 | rtc::VideoSinkInterface<VideoFrame>* sink) { |
| 864 | rtc::CritScope lock(&crit_); |
| 865 | RTC_DCHECK(sink == send_stream_input_); |
| 866 | send_stream_input_ = nullptr; |
| 867 | } |
| 868 | |
| 869 | } // namespace webrtc |