video/video_analyzer.cc

/*
 *  Copyright 2018 The WebRTC project authors. All Rights Reserved.
 *
 *  Use of this source code is governed by a BSD-style license
 *  that can be found in the LICENSE file in the root of the source
 *  tree. An additional intellectual property rights grant can be found
 *  in the file PATENTS.  All contributing project authors may
 *  be found in the AUTHORS file in the root of the source tree.
 */
#include "video/video_analyzer.h"

#include <inttypes.h>

#include <algorithm>
#include <utility>

#include "absl/algorithm/container.h"
#include "absl/flags/flag.h"
#include "absl/flags/parse.h"
#include "absl/strings/string_view.h"
#include "api/test/metrics/global_metrics_logger_and_exporter.h"
#include "api/test/metrics/metric.h"
#include "common_video/libyuv/include/webrtc_libyuv.h"
#include "modules/rtp_rtcp/source/create_video_rtp_depacketizer.h"
#include "modules/rtp_rtcp/source/rtp_packet.h"
#include "modules/rtp_rtcp/source/rtp_util.h"
#include "rtc_base/cpu_time.h"
#include "rtc_base/memory_usage.h"
#include "rtc_base/task_queue_for_test.h"
#include "rtc_base/task_utils/repeating_task.h"
#include "rtc_base/time_utils.h"
#include "system_wrappers/include/cpu_info.h"
#include "test/call_test.h"
#include "test/testsupport/file_utils.h"
#include "test/testsupport/frame_writer.h"
#include "test/testsupport/test_artifacts.h"
#include "test/video_test_constants.h"

ABSL_FLAG(bool,
          save_worst_frame,
          false,
          "Enable saving a frame with the lowest PSNR to a jpeg file in the "
          "test_artifacts_dir");

namespace webrtc {
namespace {

using ::webrtc::test::GetGlobalMetricsLogger;
using ::webrtc::test::ImprovementDirection;
using ::webrtc::test::Metric;
using ::webrtc::test::Unit;

constexpr TimeDelta kSendStatsPollingInterval = TimeDelta::Seconds(1);
constexpr size_t kMaxComparisons = 10;
// How often is keep alive message printed.
constexpr TimeDelta kKeepAliveInterval = TimeDelta::Seconds(30);
// Interval between checking that the test is over.
constexpr TimeDelta kProbingInterval = TimeDelta::Millis(500);
constexpr int kKeepAliveIntervalIterations =
    kKeepAliveInterval.ms() / kProbingInterval.ms();

bool IsFlexfec(int payload_type) {
  return payload_type == test::VideoTestConstants::kFlexfecPayloadType;
}

}  // namespace

VideoAnalyzer::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)
    : transport_(transport),
      receiver_(nullptr),
      call_(nullptr),
      send_stream_(nullptr),
      receive_stream_(nullptr),
      audio_receive_stream_(nullptr),
      captured_frame_forwarder_(this, clock, duration_frames, test_duration),
      test_label_(test_label),
      graph_data_output_file_(graph_data_output_file),
      graph_title_(graph_title),
      ssrc_to_analyze_(ssrc_to_analyze),
      rtx_ssrc_to_analyze_(rtx_ssrc_to_analyze),
      selected_stream_(selected_stream),
      selected_sl_(selected_sl),
      selected_tl_(selected_tl),
      mean_decode_time_ms_(0.0),
      freeze_count_(0),
      total_freezes_duration_ms_(0),
      total_inter_frame_delay_(0),
      total_squared_inter_frame_delay_(0),
      decode_frame_rate_(0),
      render_frame_rate_(0),
      last_fec_bytes_(0),
      frames_to_process_(duration_frames),
      test_end_(clock->CurrentTime() + test_duration),
      frames_recorded_(0),
      frames_processed_(0),
      captured_frames_(0),
      dropped_frames_(0),
      dropped_frames_before_first_encode_(0),
      dropped_frames_before_rendering_(0),
      last_render_time_(0),
      last_render_delta_ms_(0),
      last_unfreeze_time_ms_(0),
      rtp_timestamp_delta_(0),
      cpu_time_(0),
      wallclock_time_(0),
      avg_psnr_threshold_(avg_psnr_threshold),
      avg_ssim_threshold_(avg_ssim_threshold),
      is_quick_test_enabled_(is_quick_test_enabled),
      quit_(false),
      done_(true, false),
      vp8_depacketizer_(CreateVideoRtpDepacketizer(kVideoCodecVP8)),
      vp9_depacketizer_(CreateVideoRtpDepacketizer(kVideoCodecVP9)),
      clock_(clock),
      start_ms_(clock->TimeInMilliseconds()),
      task_queue_(task_queue) {
  // Create thread pool for CPU-expensive PSNR/SSIM calculations.

  // Try to use about as many threads as cores, but leave kMinCoresLeft alone,
  // so that we don't accidentally starve "real" worker threads (codec etc).
  // Also, don't allocate more than kMaxComparisonThreads, even if there are
  // spare cores.

  uint32_t num_cores = CpuInfo::DetectNumberOfCores();
  RTC_DCHECK_GE(num_cores, 1);
  static const uint32_t kMinCoresLeft = 4;
  static const uint32_t kMaxComparisonThreads = 8;

  if (num_cores <= kMinCoresLeft) {
    num_cores = 1;
  } else {
    num_cores -= kMinCoresLeft;
    num_cores = std::min(num_cores, kMaxComparisonThreads);
  }

  for (uint32_t i = 0; i < num_cores; ++i) {
    comparison_thread_pool_.push_back(rtc::PlatformThread::SpawnJoinable(
        [this] {
          while (CompareFrames()) {
          }
        },
        "Analyzer"));
  }

  if (!rtp_dump_name.empty()) {
    fprintf(stdout, "Writing rtp dump to %s\n", rtp_dump_name.c_str());
    rtp_file_writer_.reset(test::RtpFileWriter::Create(
        test::RtpFileWriter::kRtpDump, rtp_dump_name));
  }
}

VideoAnalyzer::~VideoAnalyzer() {
  {
    MutexLock lock(&comparison_lock_);
    quit_ = true;
  }
  // Joins all threads.
  comparison_thread_pool_.clear();
}

void VideoAnalyzer::SetReceiver(PacketReceiver* receiver) {
  receiver_ = receiver;
}

void VideoAnalyzer::SetSource(
    rtc::VideoSourceInterface<VideoFrame>* video_source,
    bool respect_sink_wants) {
  if (respect_sink_wants)
    captured_frame_forwarder_.SetSource(video_source);
  rtc::VideoSinkWants wants;
  video_source->AddOrUpdateSink(InputInterface(), wants);
}

void VideoAnalyzer::SetCall(Call* call) {
  MutexLock lock(&lock_);
  RTC_DCHECK(!call_);
  call_ = call;
}

void VideoAnalyzer::SetSendStream(VideoSendStream* stream) {
  MutexLock lock(&lock_);
  RTC_DCHECK(!send_stream_);
  send_stream_ = stream;
}

void VideoAnalyzer::SetReceiveStream(VideoReceiveStreamInterface* stream) {
  MutexLock lock(&lock_);
  RTC_DCHECK(!receive_stream_);
  receive_stream_ = stream;
}

void VideoAnalyzer::SetAudioReceiveStream(
    AudioReceiveStreamInterface* recv_stream) {
  MutexLock lock(&lock_);
  RTC_CHECK(!audio_receive_stream_);
  audio_receive_stream_ = recv_stream;
}

rtc::VideoSinkInterface<VideoFrame>* VideoAnalyzer::InputInterface() {
  return &captured_frame_forwarder_;
}

rtc::VideoSourceInterface<VideoFrame>* VideoAnalyzer::OutputInterface() {
  return &captured_frame_forwarder_;
}

void VideoAnalyzer::DeliverRtcpPacket(rtc::CopyOnWriteBuffer packet) {
  return receiver_->DeliverRtcpPacket(std::move(packet));
}

void VideoAnalyzer::DeliverRtpPacket(
    MediaType media_type,
    RtpPacketReceived packet,
    PacketReceiver::OnUndemuxablePacketHandler undemuxable_packet_handler) {
  if (rtp_file_writer_) {
    test::RtpPacket p;
    memcpy(p.data, packet.Buffer().data(), packet.size());
    p.length = packet.size();
    p.original_length = packet.size();
    p.time_ms = clock_->TimeInMilliseconds() - start_ms_;
    rtp_file_writer_->WritePacket(&p);
  }

  if (!IsFlexfec(packet.PayloadType()) &&
      (packet.Ssrc() == ssrc_to_analyze_ ||
       packet.Ssrc() == rtx_ssrc_to_analyze_)) {
    // Ignore FlexFEC timestamps, to avoid collisions with media timestamps.
    // (FlexFEC and media are sent on different SSRCs, which have different
    // timestamps spaces.)
    // Also ignore packets from wrong SSRC, but include retransmits.
    MutexLock lock(&lock_);
    int64_t timestamp =
        wrap_handler_.Unwrap(packet.Timestamp() - rtp_timestamp_delta_);
    recv_times_[timestamp] = clock_->CurrentNtpInMilliseconds();
  }

  return receiver_->DeliverRtpPacket(media_type, std::move(packet),
                                     std::move(undemuxable_packet_handler));
}

void VideoAnalyzer::PreEncodeOnFrame(const VideoFrame& video_frame) {
  MutexLock lock(&lock_);
  if (!first_encoded_timestamp_) {
    while (frames_.front().timestamp() != video_frame.timestamp()) {
      ++dropped_frames_before_first_encode_;
      frames_.pop_front();
      RTC_CHECK(!frames_.empty());
    }
    first_encoded_timestamp_ = video_frame.timestamp();
  }
}

void VideoAnalyzer::PostEncodeOnFrame(size_t stream_id, uint32_t timestamp) {
  MutexLock lock(&lock_);
  if (!first_sent_timestamp_ && stream_id == selected_stream_) {
    first_sent_timestamp_ = timestamp;
  }
}

bool VideoAnalyzer::SendRtp(rtc::ArrayView<const uint8_t> packet,
                            const PacketOptions& options) {
  RtpPacket rtp_packet;
  rtp_packet.Parse(packet);

  int64_t current_time = clock_->CurrentNtpInMilliseconds();

  bool result = transport_->SendRtp(packet, options);
  {
    MutexLock lock(&lock_);
    if (rtp_timestamp_delta_ == 0 && rtp_packet.Ssrc() == ssrc_to_analyze_) {
      RTC_CHECK(static_cast<bool>(first_sent_timestamp_));
      rtp_timestamp_delta_ = rtp_packet.Timestamp() - *first_sent_timestamp_;
    }

    if (!IsFlexfec(rtp_packet.PayloadType()) &&
        rtp_packet.Ssrc() == ssrc_to_analyze_) {
      // Ignore FlexFEC timestamps, to avoid collisions with media timestamps.
      // (FlexFEC and media are sent on different SSRCs, which have different
      // timestamps spaces.)
      // Also ignore packets from wrong SSRC and retransmits.
      int64_t timestamp =
          wrap_handler_.Unwrap(rtp_packet.Timestamp() - rtp_timestamp_delta_);
      send_times_[timestamp] = current_time;

      if (IsInSelectedSpatialAndTemporalLayer(rtp_packet)) {
        encoded_frame_sizes_[timestamp] += rtp_packet.payload_size();
      }
    }
  }
  return result;
}

bool VideoAnalyzer::SendRtcp(rtc::ArrayView<const uint8_t> packet) {
  return transport_->SendRtcp(packet);
}

void VideoAnalyzer::OnFrame(const VideoFrame& video_frame) {
  int64_t render_time_ms = clock_->CurrentNtpInMilliseconds();

  MutexLock lock(&lock_);

  StartExcludingCpuThreadTime();

  int64_t send_timestamp =
      wrap_handler_.Unwrap(video_frame.timestamp() - rtp_timestamp_delta_);

  while (wrap_handler_.Unwrap(frames_.front().timestamp()) < send_timestamp) {
    if (!last_rendered_frame_) {
      // No previous frame rendered, this one was dropped after sending but
      // before rendering.
      ++dropped_frames_before_rendering_;
    } else {
      AddFrameComparison(frames_.front(), *last_rendered_frame_, true,
                         render_time_ms);
    }
    frames_.pop_front();
    RTC_DCHECK(!frames_.empty());
  }

  VideoFrame reference_frame = frames_.front();
  frames_.pop_front();
  int64_t reference_timestamp =
      wrap_handler_.Unwrap(reference_frame.timestamp());
  if (send_timestamp == reference_timestamp - 1) {
    // TODO(ivica): Make this work for > 2 streams.
    // Look at RTPSender::BuildRTPHeader.
    ++send_timestamp;
  }
  ASSERT_EQ(reference_timestamp, send_timestamp);

  AddFrameComparison(reference_frame, video_frame, false, render_time_ms);

  last_rendered_frame_ = video_frame;

  StopExcludingCpuThreadTime();
}

void VideoAnalyzer::Wait() {
  // Frame comparisons can be very expensive. Wait for test to be done, but
  // at time-out check if frames_processed is going up. If so, give it more
  // time, otherwise fail. Hopefully this will reduce test flakiness.

  RepeatingTaskHandle stats_polling_task = RepeatingTaskHandle::DelayedStart(
      task_queue_, kSendStatsPollingInterval, [this] {
        PollStats();
        return kSendStatsPollingInterval;
      });

  int last_frames_processed = -1;
  int last_frames_captured = -1;
  int iteration = 0;

  while (!done_.Wait(kProbingInterval)) {
    int frames_processed;
    int frames_captured;
    {
      MutexLock lock(&comparison_lock_);
      frames_processed = frames_processed_;
      frames_captured = captured_frames_;
    }

    // Print some output so test infrastructure won't think we've crashed.
    const char* kKeepAliveMessages[3] = {
        "Uh, I'm-I'm not quite dead, sir.",
        "Uh, I-I think uh, I could pull through, sir.",
        "Actually, I think I'm all right to come with you--"};
    if (++iteration % kKeepAliveIntervalIterations == 0) {
      printf("- %s\n", kKeepAliveMessages[iteration % 3]);
    }

    if (last_frames_processed == -1) {
      last_frames_processed = frames_processed;
      last_frames_captured = frames_captured;
      continue;
    }
    if (frames_processed == last_frames_processed &&
        last_frames_captured == frames_captured &&
        clock_->CurrentTime() > test_end_) {
      done_.Set();
      break;
    }
    last_frames_processed = frames_processed;
    last_frames_captured = frames_captured;
  }

  if (iteration > 0)
    printf("- Farewell, sweet Concorde!\n");

  SendTask(task_queue_, [&] { stats_polling_task.Stop(); });

  PrintResults();
  if (graph_data_output_file_)
    PrintSamplesToFile();
}

void VideoAnalyzer::StartMeasuringCpuProcessTime() {
  MutexLock lock(&cpu_measurement_lock_);
  cpu_time_ -= rtc::GetProcessCpuTimeNanos();
  wallclock_time_ -= rtc::SystemTimeNanos();
}

void VideoAnalyzer::StopMeasuringCpuProcessTime() {
  MutexLock lock(&cpu_measurement_lock_);
  cpu_time_ += rtc::GetProcessCpuTimeNanos();
  wallclock_time_ += rtc::SystemTimeNanos();
}

void VideoAnalyzer::StartExcludingCpuThreadTime() {
  MutexLock lock(&cpu_measurement_lock_);
  cpu_time_ += rtc::GetThreadCpuTimeNanos();
}

void VideoAnalyzer::StopExcludingCpuThreadTime() {
  MutexLock lock(&cpu_measurement_lock_);
  cpu_time_ -= rtc::GetThreadCpuTimeNanos();
}

double VideoAnalyzer::GetCpuUsagePercent() {
  MutexLock lock(&cpu_measurement_lock_);
  return static_cast<double>(cpu_time_) / wallclock_time_ * 100.0;
}

bool VideoAnalyzer::IsInSelectedSpatialAndTemporalLayer(
    const RtpPacket& rtp_packet) {
  if (rtp_packet.PayloadType() == test::VideoTestConstants::kPayloadTypeVP8) {
    auto parsed_payload = vp8_depacketizer_->Parse(rtp_packet.PayloadBuffer());
    RTC_DCHECK(parsed_payload);
    const auto& vp8_header = absl::get<RTPVideoHeaderVP8>(
        parsed_payload->video_header.video_type_header);
    int temporal_idx = vp8_header.temporalIdx;
    return selected_tl_ < 0 || temporal_idx == kNoTemporalIdx ||
           temporal_idx <= selected_tl_;
  }

  if (rtp_packet.PayloadType() == test::VideoTestConstants::kPayloadTypeVP9) {
    auto parsed_payload = vp9_depacketizer_->Parse(rtp_packet.PayloadBuffer());
    RTC_DCHECK(parsed_payload);
    const auto& vp9_header = absl::get<RTPVideoHeaderVP9>(
        parsed_payload->video_header.video_type_header);
    int temporal_idx = vp9_header.temporal_idx;
    int spatial_idx = vp9_header.spatial_idx;
    return (selected_tl_ < 0 || temporal_idx == kNoTemporalIdx ||
            temporal_idx <= selected_tl_) &&
           (selected_sl_ < 0 || spatial_idx == kNoSpatialIdx ||
            spatial_idx <= selected_sl_);
  }

  return true;
}

void VideoAnalyzer::PollStats() {
  // Do not grab `comparison_lock_`, before `GetStats()` completes.
  // Otherwise a deadlock may occur:
  // 1) `comparison_lock_` is acquired after `lock_`
  // 2) `lock_` is acquired after internal pacer lock in SendRtp()
  // 3) internal pacer lock is acquired by GetStats().
  Call::Stats call_stats = call_->GetStats();

  MutexLock lock(&comparison_lock_);

  send_bandwidth_bps_.AddSample(call_stats.send_bandwidth_bps);

  VideoSendStream::Stats send_stats = send_stream_->GetStats();
  // It's not certain that we yet have estimates for any of these stats.
  // Check that they are positive before mixing them in.
  if (send_stats.encode_frame_rate > 0)
    encode_frame_rate_.AddSample(send_stats.encode_frame_rate);
  if (send_stats.avg_encode_time_ms > 0)
    encode_time_ms_.AddSample(send_stats.avg_encode_time_ms);
  if (send_stats.encode_usage_percent > 0)
    encode_usage_percent_.AddSample(send_stats.encode_usage_percent);
  if (send_stats.media_bitrate_bps > 0)
    media_bitrate_bps_.AddSample(send_stats.media_bitrate_bps);
  size_t fec_bytes = 0;
  for (const auto& kv : send_stats.substreams) {
    fec_bytes += kv.second.rtp_stats.fec.payload_bytes +
                 kv.second.rtp_stats.fec.padding_bytes;
  }
  fec_bitrate_bps_.AddSample((fec_bytes - last_fec_bytes_) * 8);
  last_fec_bytes_ = fec_bytes;

  if (receive_stream_ != nullptr) {
    VideoReceiveStreamInterface::Stats receive_stats =
        receive_stream_->GetStats();

    // Freeze metrics.
    freeze_count_ = receive_stats.freeze_count;
    total_freezes_duration_ms_ = receive_stats.total_freezes_duration_ms;
    total_inter_frame_delay_ = receive_stats.total_inter_frame_delay;
    total_squared_inter_frame_delay_ =
        receive_stats.total_squared_inter_frame_delay;

    // `total_decode_time_ms` gives a good estimate of the mean decode time,
    // `decode_ms` is used to keep track of the standard deviation.
    if (receive_stats.frames_decoded > 0)
      mean_decode_time_ms_ = receive_stats.total_decode_time.ms<double>() /
                             receive_stats.frames_decoded;
    if (receive_stats.decode_ms > 0)
      decode_time_ms_.AddSample(receive_stats.decode_ms);
    if (receive_stats.max_decode_ms > 0)
      decode_time_max_ms_.AddSample(receive_stats.max_decode_ms);
    if (receive_stats.width > 0 && receive_stats.height > 0) {
      pixels_.AddSample(receive_stats.width * receive_stats.height);
    }

    // `frames_decoded` and `frames_rendered` are used because they are more
    // accurate than `decode_frame_rate` and `render_frame_rate`.
    // The latter two are calculated on a momentary basis.
    if (total_inter_frame_delay_ > 0) {
      decode_frame_rate_ =
          receive_stats.frames_decoded / total_inter_frame_delay_;
      render_frame_rate_ =
          receive_stats.frames_rendered / total_inter_frame_delay_;
    }
  }

  if (audio_receive_stream_ != nullptr) {
    AudioReceiveStreamInterface::Stats receive_stats =
        audio_receive_stream_->GetStats(/*get_and_clear_legacy_stats=*/true);
    audio_expand_rate_.AddSample(receive_stats.expand_rate);
    audio_accelerate_rate_.AddSample(receive_stats.accelerate_rate);
    audio_jitter_buffer_ms_.AddSample(receive_stats.jitter_buffer_ms);
  }

  memory_usage_.AddSample(rtc::GetProcessResidentSizeBytes());
}

bool VideoAnalyzer::CompareFrames() {
  if (AllFramesRecorded())
    return false;

  FrameComparison comparison;

  if (!PopComparison(&comparison)) {
    // Wait until new comparison task is available, or test is done.
    // If done, wake up remaining threads waiting.
    comparison_available_event_.Wait(TimeDelta::Seconds(1));
    if (AllFramesRecorded()) {
      comparison_available_event_.Set();
      return false;
    }
    return true;  // Try again.
  }

  StartExcludingCpuThreadTime();

  PerformFrameComparison(comparison);

  StopExcludingCpuThreadTime();

  if (FrameProcessed()) {
    done_.Set();
    comparison_available_event_.Set();
    return false;
  }

  return true;
}

bool VideoAnalyzer::PopComparison(VideoAnalyzer::FrameComparison* comparison) {
  MutexLock lock(&comparison_lock_);
  // If AllFramesRecorded() is true, it means we have already popped
  // frames_to_process_ frames from comparisons_, so there is no more work
  // for this thread to be done. frames_processed_ might still be lower if
  // all comparisons are not done, but those frames are currently being
  // worked on by other threads.
  if (comparisons_.empty() || AllFramesRecordedLocked())
    return false;

  *comparison = comparisons_.front();
  comparisons_.pop_front();

  FrameRecorded();
  return true;
}

void VideoAnalyzer::FrameRecorded() {
  ++frames_recorded_;
}

bool VideoAnalyzer::AllFramesRecorded() {
  MutexLock lock(&comparison_lock_);
  return AllFramesRecordedLocked();
}

bool VideoAnalyzer::AllFramesRecordedLocked() {
  RTC_DCHECK(frames_recorded_ <= frames_to_process_);
  return frames_recorded_ == frames_to_process_ ||
         (clock_->CurrentTime() > test_end_ && comparisons_.empty()) || quit_;
}

bool VideoAnalyzer::FrameProcessed() {
  MutexLock lock(&comparison_lock_);
  ++frames_processed_;
  RTC_DCHECK_LE(frames_processed_, frames_to_process_);
  return frames_processed_ == frames_to_process_ ||
         (clock_->CurrentTime() > test_end_ && comparisons_.empty());
}

void VideoAnalyzer::PrintResults() {
  StopMeasuringCpuProcessTime();
  int dropped_frames_diff;
  {
    MutexLock lock(&lock_);
    dropped_frames_diff = dropped_frames_before_first_encode_ +
                          dropped_frames_before_rendering_ + frames_.size();
  }
  MutexLock lock(&comparison_lock_);
  PrintResult("psnr_dB", psnr_, Unit::kUnitless,
              ImprovementDirection::kBiggerIsBetter);
  PrintResult("ssim", ssim_, Unit::kUnitless,
              ImprovementDirection::kBiggerIsBetter);
  PrintResult("sender_time", sender_time_, Unit::kMilliseconds,
              ImprovementDirection::kSmallerIsBetter);
  PrintResult("receiver_time", receiver_time_, Unit::kMilliseconds,
              ImprovementDirection::kSmallerIsBetter);
  PrintResult("network_time", network_time_, Unit::kMilliseconds,
              ImprovementDirection::kSmallerIsBetter);
  PrintResult("total_delay_incl_network", end_to_end_, Unit::kMilliseconds,
              ImprovementDirection::kSmallerIsBetter);
  PrintResult("time_between_rendered_frames", rendered_delta_,
              Unit::kMilliseconds, ImprovementDirection::kSmallerIsBetter);
  PrintResult("encode_frame_rate_fps", encode_frame_rate_, Unit::kHertz,
              ImprovementDirection::kBiggerIsBetter);
  PrintResult("encode_time", encode_time_ms_, Unit::kMilliseconds,
              ImprovementDirection::kSmallerIsBetter);
  PrintResult("media_bitrate", media_bitrate_bps_ / 1000.0,
              Unit::kKilobitsPerSecond, ImprovementDirection::kNeitherIsBetter);
  PrintResult("fec_bitrate", fec_bitrate_bps_ / 1000.0,
              Unit::kKilobitsPerSecond, ImprovementDirection::kNeitherIsBetter);
  PrintResult("send_bandwidth", send_bandwidth_bps_ / 1000.0,
              Unit::kKilobitsPerSecond, ImprovementDirection::kNeitherIsBetter);
  PrintResult("pixels_per_frame", pixels_, Unit::kCount,
              ImprovementDirection::kBiggerIsBetter);

  GetGlobalMetricsLogger()->LogSingleValueMetric(
      "decode_frame_rate_fps", test_label_, decode_frame_rate_, Unit::kHertz,
      ImprovementDirection::kBiggerIsBetter);
  GetGlobalMetricsLogger()->LogSingleValueMetric(
      "render_frame_rate_fps", test_label_, render_frame_rate_, Unit::kHertz,
      ImprovementDirection::kBiggerIsBetter);

  // Record the time from the last freeze until the last rendered frame to
  // ensure we cover the full timespan of the session. Otherwise the metric
  // would penalize an early freeze followed by no freezes until the end.
  time_between_freezes_.AddSample(last_render_time_ - last_unfreeze_time_ms_);

  // Freeze metrics.
  PrintResult("time_between_freezes", time_between_freezes_,
              Unit::kMilliseconds, ImprovementDirection::kBiggerIsBetter);

  const double freeze_count_double = static_cast<double>(freeze_count_);
  const double total_freezes_duration_ms_double =
      static_cast<double>(total_freezes_duration_ms_);
  const double total_frames_duration_ms_double =
      total_inter_frame_delay_ * rtc::kNumMillisecsPerSec;

  if (total_frames_duration_ms_double > 0) {
    GetGlobalMetricsLogger()->LogSingleValueMetric(
        "freeze_duration_ratio", test_label_,
        total_freezes_duration_ms_double / total_frames_duration_ms_double,
        Unit::kUnitless, ImprovementDirection::kSmallerIsBetter);
    RTC_DCHECK_LE(total_freezes_duration_ms_double,
                  total_frames_duration_ms_double);

    constexpr double ms_per_minute = 60 * 1000;
    const double total_frames_duration_min =
        total_frames_duration_ms_double / ms_per_minute;
    if (total_frames_duration_min > 0) {
      GetGlobalMetricsLogger()->LogSingleValueMetric(
          "freeze_count_per_minute", test_label_,
          freeze_count_double / total_frames_duration_min, Unit::kUnitless,
          ImprovementDirection::kSmallerIsBetter);
    }
  }

  GetGlobalMetricsLogger()->LogSingleValueMetric(
      "freeze_duration_average", test_label_,
      freeze_count_double > 0
          ? total_freezes_duration_ms_double / freeze_count_double
          : 0,
      Unit::kMilliseconds, ImprovementDirection::kSmallerIsBetter);

  if (total_squared_inter_frame_delay_ > 0) {
    GetGlobalMetricsLogger()->LogSingleValueMetric(
        "harmonic_frame_rate_fps", test_label_,
        total_frames_duration_ms_double /
            (1000 * total_squared_inter_frame_delay_),
        Unit::kHertz, ImprovementDirection::kBiggerIsBetter);
  }

  if (worst_frame_) {
    GetGlobalMetricsLogger()->LogSingleValueMetric(
        "min_psnr_dB", test_label_, worst_frame_->psnr, Unit::kUnitless,
        ImprovementDirection::kBiggerIsBetter);
  }

  if (receive_stream_ != nullptr) {
    PrintResultWithExternalMean("decode_time", mean_decode_time_ms_,
                                decode_time_ms_, Unit::kMilliseconds,
                                ImprovementDirection::kSmallerIsBetter);
  }
  dropped_frames_ += dropped_frames_diff;
  GetGlobalMetricsLogger()->LogSingleValueMetric(
      "dropped_frames", test_label_, dropped_frames_, Unit::kCount,
      ImprovementDirection::kSmallerIsBetter);
  GetGlobalMetricsLogger()->LogSingleValueMetric(
      "cpu_usage_%", test_label_, GetCpuUsagePercent(), Unit::kUnitless,
      ImprovementDirection::kSmallerIsBetter);

#if defined(WEBRTC_WIN)
  // On Linux and Mac in Resident Set some unused pages may be counted.
  // Therefore this metric will depend on order in which tests are run and
  // will be flaky.
  PrintResult("memory_usage", memory_usage_, Unit::kBytes,
              ImprovementDirection::kSmallerIsBetter);
#endif

  // Saving only the worst frame for manual analysis. Intention here is to
  // only detect video corruptions and not to track picture quality. Thus,
  // jpeg is used here.
  if (absl::GetFlag(FLAGS_save_worst_frame) && worst_frame_) {
    std::string output_dir;
    test::GetTestArtifactsDir(&output_dir);
    std::string output_path =
        test::JoinFilename(output_dir, test_label_ + ".jpg");
    RTC_LOG(LS_INFO) << "Saving worst frame to " << output_path;
    test::JpegFrameWriter frame_writer(output_path);
    RTC_CHECK(
        frame_writer.WriteFrame(worst_frame_->frame, 100 /*best quality*/));
  }

  if (audio_receive_stream_ != nullptr) {
    PrintResult("audio_expand_rate", audio_expand_rate_, Unit::kUnitless,
                ImprovementDirection::kSmallerIsBetter);
    PrintResult("audio_accelerate_rate", audio_accelerate_rate_,
                Unit::kUnitless, ImprovementDirection::kSmallerIsBetter);
    PrintResult("audio_jitter_buffer", audio_jitter_buffer_ms_,
                Unit::kMilliseconds, ImprovementDirection::kNeitherIsBetter);
  }

  //  Disable quality check for quick test, as quality checks may fail
  //  because too few samples were collected.
  if (!is_quick_test_enabled_) {
    EXPECT_GT(psnr_.GetAverage(), avg_psnr_threshold_);
    EXPECT_GT(ssim_.GetAverage(), avg_ssim_threshold_);
  }
}

void VideoAnalyzer::PerformFrameComparison(
    const VideoAnalyzer::FrameComparison& comparison) {
  // Perform expensive psnr and ssim calculations while not holding lock.
  double psnr = -1.0;
  double ssim = -1.0;
  if (comparison.reference && !comparison.dropped) {
    psnr = I420PSNR(&*comparison.reference, &*comparison.render);
    ssim = I420SSIM(&*comparison.reference, &*comparison.render);
  }

  MutexLock lock(&comparison_lock_);

  if (psnr >= 0.0 && (!worst_frame_ || worst_frame_->psnr > psnr)) {
    worst_frame_.emplace(FrameWithPsnr{psnr, *comparison.render});
  }

  if (graph_data_output_file_) {
    samples_.push_back(Sample(comparison.dropped, comparison.input_time_ms,
                              comparison.send_time_ms, comparison.recv_time_ms,
                              comparison.render_time_ms,
                              comparison.encoded_frame_size, psnr, ssim));
  }
  if (psnr >= 0.0)
    psnr_.AddSample(psnr);
  if (ssim >= 0.0)
    ssim_.AddSample(ssim);

  if (comparison.dropped) {
    ++dropped_frames_;
    return;
  }
  if (last_unfreeze_time_ms_ == 0)
    last_unfreeze_time_ms_ = comparison.render_time_ms;
  if (last_render_time_ != 0) {
    const int64_t render_delta_ms =
        comparison.render_time_ms - last_render_time_;
    rendered_delta_.AddSample(render_delta_ms);
    if (last_render_delta_ms_ != 0 &&
        render_delta_ms - last_render_delta_ms_ > 150) {
      time_between_freezes_.AddSample(last_render_time_ -
                                      last_unfreeze_time_ms_);
      last_unfreeze_time_ms_ = comparison.render_time_ms;
    }
    last_render_delta_ms_ = render_delta_ms;
  }
  last_render_time_ = comparison.render_time_ms;

  sender_time_.AddSample(comparison.send_time_ms - comparison.input_time_ms);
  if (comparison.recv_time_ms > 0) {
    // If recv_time_ms == 0, this frame consisted of a packets which were all
    // lost in the transport. Since we were able to render the frame, however,
    // the dropped packets were recovered by FlexFEC. The FlexFEC recovery
    // happens internally in Call, and we can therefore here not know which
    // FEC packets that protected the lost media packets. Consequently, we
    // were not able to record a meaningful recv_time_ms. We therefore skip
    // this sample.
    //
    // The reasoning above does not hold for ULPFEC and RTX, as for those
    // strategies the timestamp of the received packets is set to the
    // timestamp of the protected/retransmitted media packet. I.e., then
    // recv_time_ms != 0, even though the media packets were lost.
    receiver_time_.AddSample(comparison.render_time_ms -
                             comparison.recv_time_ms);
    network_time_.AddSample(comparison.recv_time_ms - comparison.send_time_ms);
  }
  end_to_end_.AddSample(comparison.render_time_ms - comparison.input_time_ms);
  encoded_frame_size_.AddSample(comparison.encoded_frame_size);
}

void VideoAnalyzer::PrintResult(absl::string_view result_type,
                                const SamplesStatsCounter& stats,
                                Unit unit,
                                ImprovementDirection improvement_direction) {
  GetGlobalMetricsLogger()->LogMetric(result_type, test_label_, stats, unit,
                                      improvement_direction);
}

void VideoAnalyzer::PrintResultWithExternalMean(
    absl::string_view result_type,
    double mean,
    const SamplesStatsCounter& stats,
    Unit unit,
    ImprovementDirection improvement_direction) {
  // If the true mean is different than the sample mean, the sample variance is
  // too low. The sample variance given a known mean is obtained by adding the
  // squared error between the true mean and the sample mean.
  double compensated_variance =
      stats.IsEmpty()
          ? 0.0
          : stats.GetVariance() + pow(mean - stats.GetAverage(), 2.0);
  GetGlobalMetricsLogger()->LogMetric(
      result_type, test_label_,
      Metric::Stats{.mean = mean, .stddev = std::sqrt(compensated_variance)},
      unit, improvement_direction);
}

void VideoAnalyzer::PrintSamplesToFile() {
  FILE* out = graph_data_output_file_;
  MutexLock lock(&comparison_lock_);
  absl::c_sort(samples_, [](const Sample& A, const Sample& B) -> bool {
    return A.input_time_ms < B.input_time_ms;
  });

  fprintf(out, "%s\n", graph_title_.c_str());
  fprintf(out, "%zu\n", samples_.size());
  fprintf(out,
          "dropped "
          "input_time_ms "
          "send_time_ms "
          "recv_time_ms "
          "render_time_ms "
          "encoded_frame_size "
          "psnr "
          "ssim "
          "encode_time_ms\n");
  for (const Sample& sample : samples_) {
    fprintf(out,
            "%d %" PRId64 " %" PRId64 " %" PRId64 " %" PRId64 " %zu %lf %lf\n",
            sample.dropped, sample.input_time_ms, sample.send_time_ms,
            sample.recv_time_ms, sample.render_time_ms,
            sample.encoded_frame_size, sample.psnr, sample.ssim);
  }
}

void VideoAnalyzer::AddCapturedFrameForComparison(
    const VideoFrame& video_frame) {
  bool must_capture = false;
  {
    MutexLock lock(&comparison_lock_);
    must_capture = captured_frames_ < frames_to_process_;
    if (must_capture) {
      ++captured_frames_;
    }
  }
  if (must_capture) {
    MutexLock lock(&lock_);
    frames_.push_back(video_frame);
  }
}

void VideoAnalyzer::AddFrameComparison(const VideoFrame& reference,
                                       const VideoFrame& render,
                                       bool dropped,
                                       int64_t render_time_ms) {
  int64_t reference_timestamp = wrap_handler_.Unwrap(reference.timestamp());
  int64_t send_time_ms = send_times_[reference_timestamp];
  send_times_.erase(reference_timestamp);
  int64_t recv_time_ms = recv_times_[reference_timestamp];
  recv_times_.erase(reference_timestamp);

  // TODO(ivica): Make this work for > 2 streams.
  auto it = encoded_frame_sizes_.find(reference_timestamp);
  if (it == encoded_frame_sizes_.end())
    it = encoded_frame_sizes_.find(reference_timestamp - 1);
  size_t encoded_size = it == encoded_frame_sizes_.end() ? 0 : it->second;
  if (it != encoded_frame_sizes_.end())
    encoded_frame_sizes_.erase(it);

  MutexLock lock(&comparison_lock_);
  if (comparisons_.size() < kMaxComparisons) {
    comparisons_.push_back(FrameComparison(
        reference, render, dropped, reference.ntp_time_ms(), send_time_ms,
        recv_time_ms, render_time_ms, encoded_size));
  } else {
    comparisons_.push_back(FrameComparison(dropped, reference.ntp_time_ms(),
                                           send_time_ms, recv_time_ms,
                                           render_time_ms, encoded_size));
  }
  comparison_available_event_.Set();
}

VideoAnalyzer::FrameComparison::FrameComparison()
    : dropped(false),
      input_time_ms(0),
      send_time_ms(0),
      recv_time_ms(0),
      render_time_ms(0),
      encoded_frame_size(0) {}

VideoAnalyzer::FrameComparison::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)
    : reference(reference),
      render(render),
      dropped(dropped),
      input_time_ms(input_time_ms),
      send_time_ms(send_time_ms),
      recv_time_ms(recv_time_ms),
      render_time_ms(render_time_ms),
      encoded_frame_size(encoded_frame_size) {}

VideoAnalyzer::FrameComparison::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)
    : dropped(dropped),
      input_time_ms(input_time_ms),
      send_time_ms(send_time_ms),
      recv_time_ms(recv_time_ms),
      render_time_ms(render_time_ms),
      encoded_frame_size(encoded_frame_size) {}

VideoAnalyzer::Sample::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)
    : dropped(dropped),
      input_time_ms(input_time_ms),
      send_time_ms(send_time_ms),
      recv_time_ms(recv_time_ms),
      render_time_ms(render_time_ms),
      encoded_frame_size(encoded_frame_size),
      psnr(psnr),
      ssim(ssim) {}

VideoAnalyzer::CapturedFrameForwarder::CapturedFrameForwarder(
    VideoAnalyzer* analyzer,
    Clock* clock,
    int frames_to_capture,
    TimeDelta test_duration)
    : analyzer_(analyzer),
      send_stream_input_(nullptr),
      video_source_(nullptr),
      clock_(clock),
      captured_frames_(0),
      frames_to_capture_(frames_to_capture),
      test_end_(clock->CurrentTime() + test_duration) {}

void VideoAnalyzer::CapturedFrameForwarder::SetSource(
    VideoSourceInterface<VideoFrame>* video_source) {
  video_source_ = video_source;
}

void VideoAnalyzer::CapturedFrameForwarder::OnFrame(
    const VideoFrame& video_frame) {
  VideoFrame copy = video_frame;
  // Frames from the capturer does not have a rtp timestamp.
  // Create one so it can be used for comparison.
  RTC_DCHECK_EQ(0, video_frame.timestamp());
  if (video_frame.ntp_time_ms() == 0)
    copy.set_ntp_time_ms(clock_->CurrentNtpInMilliseconds());
  copy.set_timestamp(copy.ntp_time_ms() * 90);
  analyzer_->AddCapturedFrameForComparison(copy);
  MutexLock lock(&lock_);
  ++captured_frames_;
  if (send_stream_input_ && clock_->CurrentTime() <= test_end_ &&
      captured_frames_ <= frames_to_capture_) {
    send_stream_input_->OnFrame(copy);
  }
}

void VideoAnalyzer::CapturedFrameForwarder::AddOrUpdateSink(
    rtc::VideoSinkInterface<VideoFrame>* sink,
    const rtc::VideoSinkWants& wants) {
  {
    MutexLock lock(&lock_);
    RTC_DCHECK(!send_stream_input_ || send_stream_input_ == sink);
    send_stream_input_ = sink;
  }
  if (video_source_) {
    video_source_->AddOrUpdateSink(this, wants);
  }
}

void VideoAnalyzer::CapturedFrameForwarder::RemoveSink(
    rtc::VideoSinkInterface<VideoFrame>* sink) {
  MutexLock lock(&lock_);
  RTC_DCHECK(sink == send_stream_input_);
  send_stream_input_ = nullptr;
}

}  // namespace webrtc