Adding cpu measurments to video_quality_tests

webrtc/video/video_quality_test.cc

 /*
  *  Copyright (c) 2015 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 "webrtc/video/video_quality_test.h"
 
 #include <stdio.h>
 #include <algorithm>
 #include <deque>
 #include <map>
 #include <sstream>
 #include <string>
 #include <vector>
 
 #include "webrtc/base/checks.h"
+#include "webrtc/base/cpu_time.h"
 #include "webrtc/base/event.h"
 #include "webrtc/base/format_macros.h"
 #include "webrtc/base/optional.h"
 #include "webrtc/base/platform_file.h"
 #include "webrtc/base/timeutils.h"
 #include "webrtc/call/call.h"
 #include "webrtc/common_video/libyuv/include/webrtc_libyuv.h"
 #include "webrtc/logging/rtc_event_log/rtc_event_log.h"
 #include "webrtc/modules/audio_mixer/audio_mixer_impl.h"
 #include "webrtc/modules/rtp_rtcp/include/rtp_header_parser.h"
@@ skipping 124 matching lines @@
         pre_encode_proxy_(this),
         encode_timing_proxy_(this),
         frames_to_process_(duration_frames),
         frames_recorded_(0),
         frames_processed_(0),
         dropped_frames_(0),
         dropped_frames_before_first_encode_(0),
         dropped_frames_before_rendering_(0),
         last_render_time_(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),
         stats_polling_thread_(&PollStatsThread, this, "StatsPoller"),
         comparison_available_event_(false, false),
         done_(true, false) {
     // 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).
@@ skipping 148 matching lines @@
     rtc::CritScope lock(&comparison_lock_);
     if (frames_recorded_ < frames_to_process_)
       encoded_frame_size_.AddSample(frame.length_);
   }
 
   void OnFrame(const VideoFrame& video_frame) override {
     int64_t render_time_ms =
         Clock::GetRealTimeClock()->CurrentNtpInMilliseconds();
 
     rtc::CritScope lock(&crit_);
+
+    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,
@@ skipping 10 matching lines @@
     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_ = rtc::Optional<VideoFrame>(video_frame);
+
+    StopExcludingCpuThreadTime();
   }
 
   void 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.
 
     stats_polling_thread_.Start();
 
     int last_frames_processed = -1;
@@ skipping 29 matching lines @@
       printf("- Farewell, sweet Concorde!\n");
 
     stats_polling_thread_.Stop();
   }
 
   rtc::VideoSinkInterface<VideoFrame>* pre_encode_proxy() {
     return &pre_encode_proxy_;
   }
   EncodedFrameObserver* encode_timing_proxy() { return &encode_timing_proxy_; }
 
+  void StartMeasuringCpuProcessTime() {
+    rtc::CritScope lock(&cpu_measurement_lock_);
+    cpu_time_ -= rtc::GetProcessCpuTimeNanos();
+    wallclock_time_ -= rtc::SystemTimeNanos();
+  }
+
+  void StopMeasuringCpuProcessTime() {
+    rtc::CritScope lock(&cpu_measurement_lock_);
+    cpu_time_ += rtc::GetProcessCpuTimeNanos();
+    wallclock_time_ += rtc::SystemTimeNanos();
+  }
+
+  void StartExcludingCpuThreadTime() {
+    rtc::CritScope lock(&cpu_measurement_lock_);
+    cpu_time_ += rtc::GetThreadCpuTimeNanos();
+  }
+
+  void StopExcludingCpuThreadTime() {
+    rtc::CritScope lock(&cpu_measurement_lock_);
+    cpu_time_ -= rtc::GetThreadCpuTimeNanos();
+  }
+
+  double GetCpuUsage() {

[sprang_webrtc, 2017/02/22 16:44:03]

nit: GetCpuUsagePercent()

[ilnik, 2017/02/23 09:00:59]

Done.

+    rtc::CritScope lock(&cpu_measurement_lock_);
+    return static_cast<double>(cpu_time_) / wallclock_time_ * 100.0;
+  }
+
   test::LayerFilteringTransport* const transport_;
   PacketReceiver* receiver_;
 
  private:
   struct FrameComparison {
     FrameComparison()
         : dropped(false),
           input_time_ms(0),
           send_time_ms(0),
           recv_time_ms(0),
@@ skipping 180 matching lines @@
       // Wait until new comparison task is available, or test is done.
       // If done, wake up remaining threads waiting.
       comparison_available_event_.Wait(1000);
       if (AllFramesRecorded()) {
         comparison_available_event_.Set();
         return false;
       }
       return true;  // Try again.
     }
 
+    StartExcludingCpuThreadTime();
+
     PerformFrameComparison(comparison);
 
+    StopExcludingCpuThreadTime();
+
     if (FrameProcessed()) {
       PrintResults();
       if (graph_data_output_file_)
         PrintSamplesToFile();
       done_.Set();
       comparison_available_event_.Set();
       return false;
     }
 
     return true;
@@ skipping 32 matching lines @@
   // Increase count of number of frames processed. Returns true if this was the
   // last frame to be processed.
   bool FrameProcessed() {
     rtc::CritScope crit(&comparison_lock_);
     ++frames_processed_;
     assert(frames_processed_ <= frames_to_process_);
     return frames_processed_ == frames_to_process_;
   }
 
   void PrintResults() {
+    StopMeasuringCpuProcessTime();
     rtc::CritScope crit(&comparison_lock_);
     PrintResult("psnr", psnr_, " dB");
     PrintResult("ssim", ssim_, " score");
     PrintResult("sender_time", sender_time_, " ms");
     PrintResult("receiver_time", receiver_time_, " ms");
     PrintResult("total_delay_incl_network", end_to_end_, " ms");
     PrintResult("time_between_rendered_frames", rendered_delta_, " ms");
     PrintResult("encoded_frame_size", encoded_frame_size_, " bytes");
     PrintResult("encode_frame_rate", encode_frame_rate_, " fps");
     PrintResult("encode_time", encode_time_ms_, " ms");
     PrintResult("encode_usage_percent", encode_usage_percent_, " percent");
     PrintResult("media_bitrate", media_bitrate_bps_, " bps");
 
     if (receive_stream_ != nullptr) {
       PrintResult("decode_time", decode_time_ms_, " ms");
       PrintResult("decode_time_max", decode_time_max_ms_, " ms");
     }
 
     printf("RESULT dropped_frames: %s = %d frames\n", test_label_.c_str(),
            dropped_frames_);
     printf("RESULT dropped_frames_before_first_encode: %s = %d frames\n",
            test_label_.c_str(), dropped_frames_before_first_encode_);
     printf("RESULT dropped_frames_before_rendering: %s = %d frames\n",
            test_label_.c_str(), dropped_frames_before_rendering_);
+    printf("RESULT cpu_usage: %s = %lf %%\n", test_label_.c_str(),
+           GetCpuUsage());
     //  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_.Mean(), avg_psnr_threshold_);
       EXPECT_GT(ssim_.Mean(), avg_ssim_threshold_);
     }
   }
 
   void PerformFrameComparison(const FrameComparison& comparison) {
     // Perform expensive psnr and ssim calculations while not holding lock.
@@ skipping 179 matching lines @@
 
   const int frames_to_process_;
   int frames_recorded_;
   int frames_processed_;
   int dropped_frames_;
   int dropped_frames_before_first_encode_;
   int dropped_frames_before_rendering_;
   int64_t last_render_time_;
   uint32_t rtp_timestamp_delta_;
 
+  int64_t cpu_time_ GUARDED_BY(cpu_measurement_lock_);
+  int64_t wallclock_time_ GUARDED_BY(cpu_measurement_lock_);
+  rtc::CriticalSection cpu_measurement_lock_;
+
   rtc::CriticalSection crit_;
   std::deque<VideoFrame> frames_ GUARDED_BY(crit_);
   rtc::Optional<VideoFrame> last_rendered_frame_ GUARDED_BY(crit_);
   rtc::TimestampWrapAroundHandler wrap_handler_ GUARDED_BY(crit_);
   std::map<int64_t, int64_t> send_times_ GUARDED_BY(crit_);
   std::map<int64_t, int64_t> recv_times_ GUARDED_BY(crit_);
   std::map<int64_t, size_t> encoded_frame_sizes_ GUARDED_BY(crit_);
   rtc::Optional<uint32_t> first_encoded_timestamp_ GUARDED_BY(crit_);
   rtc::Optional<uint32_t> first_sent_timestamp_ GUARDED_BY(crit_);
   const double avg_psnr_threshold_;
@@ skipping 479 matching lines @@
   if (video_receive_streams_.size() == 1)
     analyzer.SetReceiveStream(video_receive_streams_[0]);
 
   video_send_stream_->SetSource(analyzer.OutputInterface(),
                                 degradation_preference_);
 
   CreateCapturer();
   rtc::VideoSinkWants wants;
   video_capturer_->AddOrUpdateSink(analyzer.InputInterface(), wants);
 
+  analyzer.StartMeasuringCpuProcessTime();

[sprang_webrtc, 2017/02/22 16:44:03]

I think you can move this down even further. Definitely past
StartEncodedFrameLogs, but maybe it makes sense to even have it just before
video_capturer_->Start(), as no payload data will actually go through the
pipeline until we start producing frames..

[ilnik, 2017/02/23 09:00:59]

Done.

+
   StartEncodedFrameLogs(video_send_stream_);
   StartEncodedFrameLogs(video_receive_streams_[0]);
   video_send_stream_->Start();
   for (VideoReceiveStream* receive_stream : video_receive_streams_)
     receive_stream->Start();
   for (FlexfecReceiveStream* receive_stream : flexfec_receive_streams_)
     receive_stream->Start();
   video_capturer_->Start();
 
   analyzer.Wait();
@@ skipping 206 matching lines @@
     std::ostringstream str;
     str << receive_logs_++;
     std::string path =
         params_.video.encoded_frame_base_path + "." + str.str() + ".recv.ivf";
     stream->EnableEncodedFrameRecording(rtc::CreatePlatformFile(path),
                                         10000000);
   }
 }
 
 }  // namespace webrtc