Adding cpu measurments to video_quality_tests

webrtc/video/video_quality_test.cc

Index: webrtc/video/video_quality_test.cc
diff --git a/webrtc/video/video_quality_test.cc b/webrtc/video/video_quality_test.cc
index b754d295485342a208420502be117e28ab1ee87e..31213e9e812463cd60ca19d7cc7b6a9e83eaf510 100644
--- a/webrtc/video/video_quality_test.cc
+++ b/webrtc/video/video_quality_test.cc
@@ -18,6 +18,7 @@
 #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"
@@ -162,6 +163,8 @@ class VideoAnalyzer : public PacketReceiver,
         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),
@@ -193,6 +196,10 @@ class VideoAnalyzer : public PacketReceiver,
       thread->Start();
       comparison_thread_pool_.push_back(thread);
     }
+
+    // Start time measurements

[sprang_webrtc, 2017/02/21 15:43:20]

nit: End comments with period.

[ilnik, 2017/02/22 08:43:28]

Done.

+    cpu_time_ -= rtc::GetProcessCpuTimeNanos();

[sprang_webrtc, 2017/02/21 15:43:20]

I was a bit confused of the usage here at first. Can you maybe rename them
cpu_time_start_offset_ or something and don't start the negative offset. Then
just take the delta in a local variable at the end?

[sprang_webrtc, 2017/02/21 15:43:20]

I'm not sure we should start measuring time from the construction time of the
analyzer. Then we'll include some setup time, may include open files for the
capturer etc. 

Maybe you can set the start time in Wait()? Possibly add an explicit Start()
method, might be other things that should go there as well.

[ilnik, 2017/02/22 08:43:28]

Done.

[ilnik, 2017/02/22 08:43:28]

I created special functions for manipulating cpu_time_. I hope now it's clear
that's happening there.

+    wallclock_time_ -= rtc::SystemTimeNanos();
   }
 
   ~VideoAnalyzer() {
@@ -330,6 +337,9 @@ class VideoAnalyzer : public PacketReceiver,
         Clock::GetRealTimeClock()->CurrentNtpInMilliseconds();
 
     rtc::CritScope lock(&crit_);
+
+    cpu_time_ += rtc::GetThreadCpuTimeNanos();

[sprang_webrtc, 2017/02/21 15:43:20]

Is this scope significant?
I think it would be more readable if you create a temp variable here. Maybe
int64_t comparison_cpu_time_start_offset_ = rtc::GetThreadCpuTimeNanos();

[ilnik, 2017/02/22 08:43:28]

Done it the other way.

+
     int64_t send_timestamp =
         wrap_handler_.Unwrap(video_frame.timestamp() - rtp_timestamp_delta_);
 
@@ -360,6 +370,8 @@ class VideoAnalyzer : public PacketReceiver,
     AddFrameComparison(reference_frame, video_frame, false, render_time_ms);
 
     last_rendered_frame_ = rtc::Optional<VideoFrame>(video_frame);
+
+    cpu_time_ -= rtc::GetThreadCpuTimeNanos();

[sprang_webrtc, 2017/02/21 15:43:20]

...and here did something like
cpu_time_start_offset_ += rtc::GetThreadCpuTimeNanos() -
comparison_cpu_time_start_offset_;

[ilnik, 2017/02/22 08:43:28]

Acknowledged.

   }
 
   void Wait() {
@@ -609,8 +621,18 @@ class VideoAnalyzer : public PacketReceiver,
       return true;  // Try again.
     }
 
+    {
+      rtc::CritScope crit(&comparison_lock_);
+      cpu_time_ += rtc::GetThreadCpuTimeNanos();

[sprang_webrtc, 2017/02/21 15:43:20]

Could do same thing with a local temp timestamp here as above.

[ilnik, 2017/02/22 08:43:28]

Acknowledged.

+    }
+
     PerformFrameComparison(comparison);
 
+    {
+      rtc::CritScope crit(&comparison_lock_);
+      cpu_time_ -= rtc::GetThreadCpuTimeNanos();
+    }
+
     if (FrameProcessed()) {
       PrintResults();
       if (graph_data_output_file_)
@@ -664,6 +686,9 @@ class VideoAnalyzer : public PacketReceiver,
 
   void PrintResults() {
     rtc::CritScope crit(&comparison_lock_);
+    cpu_time_ += rtc::GetProcessCpuTimeNanos();
+    wallclock_time_ += rtc::SystemTimeNanos();
+
     PrintResult("psnr", psnr_, " dB");
     PrintResult("ssim", ssim_, " score");
     PrintResult("sender_time", sender_time_, " ms");
@@ -687,6 +712,8 @@ class VideoAnalyzer : public PacketReceiver,
            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(),
+           static_cast<double>(cpu_time_) / wallclock_time_ * 100.0);
     //  Disable quality check for quick test, as quality checks may fail
     //  because too few samples were collected.
     if (!is_quick_test_enabled_) {
@@ -885,6 +912,8 @@ class VideoAnalyzer : public PacketReceiver,
   int dropped_frames_before_rendering_;
   int64_t last_render_time_;
   uint32_t rtp_timestamp_delta_;
+  int64_t cpu_time_;
+  int64_t wallclock_time_;
 
   rtc::CriticalSection crit_;
   std::deque<VideoFrame> frames_ GUARDED_BY(crit_);