vea_unittest: Calculate per-frame encode latency

content/common/gpu/media/video_encode_accelerator_unittest.cc

 // Copyright 2013 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
+#include <algorithm>
+
 #include "base/at_exit.h"
 #include "base/bind.h"
 #include "base/command_line.h"
 #include "base/files/file_util.h"
 #include "base/files/memory_mapped_file.h"
 #include "base/memory/scoped_vector.h"
 #include "base/numerics/safe_conversions.h"
 #include "base/process/process_handle.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/strings/string_split.h"
@@ skipping 546 matching lines @@
             unsigned int keyframe_period,
             bool force_bitrate,
             bool test_perf,
             bool mid_stream_bitrate_switch,
             bool mid_stream_framerate_switch,
             bool run_at_fps);
   ~VEAClient() override;
   void CreateEncoder();
   void DestroyEncoder();
 
-  // Return the number of encoded frames per second.
+  // Returns the number of encoded frames per second.

[Owen Lin, 2015/05/04 09:37:12]

why Return"s"? Most comments in this file use "Return". I think we should just
follow it.

[Justin Chuang, 2015/05/04 10:25:09]

OK. The correct way should be "returns" for first person comments in docstring,
but "return" in other comment for code block. (it's defined somewhere in coding
convention, and I was corrected by others before) 
But consistency is more important than rules. Will follow it.

[Justin Chuang, 2015/05/06 10:35:32]

Done.

   double frames_per_second();
 
+  // Returns a list of encode latency of the frames at the percentages in

[Owen Lin, 2015/05/04 09:37:12]

Why make it public? it is only used in VEAClient.

In fact, I would suggest just have a helper function to calculate the
percentile.

static float percentile(
    const vector<float>& sorted_values, float percentage);

[Justin Chuang, 2015/05/04 10:25:09]

I put this close to frames_per_second(). Or maybe I should move both methods to
private?
Sounds good. Will do.

[Owen Lin, 2015/05/05 06:03:13]

I see. It sounds we should move frames_per_second() to private as well.

[Justin Chuang, 2015/05/06 10:35:32]

Done.

+  // |ratios|. The values in |ratios| must be between 0 and 1.0.
+  std::vector<base::TimeDelta> encode_latency(const std::vector<float>& ratios);
+
   // VideoDecodeAccelerator::Client implementation.
   void RequireBitstreamBuffers(unsigned int input_count,
                                const gfx::Size& input_coded_size,
                                size_t output_buffer_size) override;
   void BitstreamBufferReady(int32 bitstream_buffer_id,
                             size_t payload_size,
                             bool key_frame) override;
   void NotifyError(VideoEncodeAccelerator::Error error) override;
 
  private:
@@ skipping 31 matching lines @@
   // Test codec performance, failing the test if we are currently running
   // the performance test.
   void VerifyPerf();
 
   // Write IVF file header to test_stream_->out_filename.
   void WriteIvfFileHeader();
 
   // Write an IVF frame header to test_stream_->out_filename.
   void WriteIvfFrameHeader(int frame_index, size_t frame_size);
 
-  // Prepare and return a frame wrapping the data at |position| bytes in
-  // the input stream, ready to be sent to encoder.
-  scoped_refptr<media::VideoFrame> PrepareInputFrame(off_t position);
+  // Prepare and return a frame wrapping the data at |position| bytes in the
+  // input stream, ready to be sent to encoder. Returns a pair of video frame
+  // and the input frame id.
+  std::pair<scoped_refptr<media::VideoFrame>, int32> PrepareInputFrame(

[Owen Lin, 2015/05/04 09:37:12]

We already has the next_input_id_ using around the code. How about just using it
instead of changing the interface?

[Justin Chuang, 2015/05/04 10:25:09]

But the value is incremented by 1 than the value I need after the function call.
I can pick the next_input_id_ value *before* calling PrepareInputFrame, or
decrement the value by one *after* calling it, etc.
IMO either way lacks encapsulation (why should the caller know this function
controls next_input_id_?). We can argue variable is in the context of this
class, but this class is big. 
Returning the input id of the frame to be encoded doesn't seem too terrible
compared to alternative methods.

[Owen Lin, 2015/05/05 06:03:13]

I got your point. See my reply below.

+      off_t position);
 
   // Update the parameters according to |mid_stream_bitrate_switch| and
   // |mid_stream_framerate_switch|.
   void UpdateTestStreamData(bool mid_stream_bitrate_switch,
                             bool mid_stream_framerate_switch);
 
   // Callback function of the |input_timer_|.
   void OnInputTimer();
 
   ClientState state_;
   scoped_ptr<VideoEncodeAccelerator> encoder_;
 
   TestStream* test_stream_;
 
   // Used to notify another thread about the state. VEAClient does not own this.
   ClientStateNotification<ClientState>* note_;
 
-  // Ids assigned to VideoFrames (start at 1 for easy comparison with
-  // num_encoded_frames_).
+  // Ids assigned to VideoFrames.
   std::set<int32> inputs_at_client_;
   int32 next_input_id_;
 
+  typedef std::map<int32, base::TimeTicks> IdToTicks;
+  // A map from input frame id to the encode start time of the frame.
+  IdToTicks encode_start_time_per_frame_;
+  // The encode latencies of all encoded frames.
+  std::vector<base::TimeDelta> encode_latencies_;
+
   // Ids for output BitstreamBuffers.
   typedef std::map<int32, base::SharedMemory*> IdToSHM;
   ScopedVector<base::SharedMemory> output_shms_;
   IdToSHM output_buffers_at_client_;
   int32 next_output_buffer_id_;
 
   // Current offset into input stream.
   off_t pos_in_input_stream_;
   gfx::Size input_coded_size_;
   // Requested by encoder.
@@ skipping 248 matching lines @@
   }
   if (requested_subsequent_framerate_ == 0)
     requested_subsequent_framerate_ = 1;
 }
 
 double VEAClient::frames_per_second() {
   base::TimeDelta duration = last_frame_ready_time_ - encode_start_time_;
   return num_encoded_frames_ / duration.InSecondsF();
 }
 
+std::vector<base::TimeDelta> VEAClient::encode_latency(
+    const std::vector<float>& ratios) {
+  std::sort(encode_latencies_.begin(), encode_latencies_.end());
+  size_t size = encode_latencies_.size();
+  std::vector<base::TimeDelta> latencies;
+  for (auto ratio : ratios) {
+    if (size == 0) {
+      latencies.push_back(base::TimeDelta());
+    } else {
+      CHECK_GE(ratio, 0.0f);
+      CHECK_LE(ratio, 1.0f);
+      size_t index = base::checked_cast<size_t>(ratio * (size - 1));

[Owen Lin, 2015/05/04 09:37:12]

Can we either implement the Nearest Rank method or the Linear Interpolation
Between Closest Ranks method ?

http://en.wikipedia.org/wiki/Percentile

[Justin Chuang, 2015/05/04 10:25:09]

Yeah... I thought about this. But I think the real value of outlier is more
useful than the interpolated value on the dashboard. 

How do you think? I'll change to interpolation if you feel it's a better
measurement.

[Owen Lin, 2015/05/05 06:03:13]

First, it won't do extrapolation for outliers (for p near 0 or 1). The
percentile value is always between two real values.

But I am also fine with the nearest rank method. It seems the used formula
doesn't match. I thought it should be 

index = std::max(base::checked_cast<size_t>(ratio * size), size - 1)

[Justin Chuang, 2015/05/06 10:35:32]

Changed to your formula (but s/max/min/). Thanks!

+      latencies.push_back(encode_latencies_[index]);
+    }
+  }
+  return latencies;
+}
+
 void VEAClient::RequireBitstreamBuffers(unsigned int input_count,
                                         const gfx::Size& input_coded_size,
                                         size_t output_size) {
   DCHECK(thread_checker_.CalledOnValidThread());
   ASSERT_EQ(state_, CS_INITIALIZED);
   SetState(CS_ENCODING);
 
   CreateAlignedInputStreamFile(input_coded_size, test_stream_);
 
   num_frames_to_encode_ = test_stream_->num_frames;
@@ skipping 103 matching lines @@
 }
 
 void VEAClient::InputNoLongerNeededCallback(int32 input_id) {
   std::set<int32>::iterator it = inputs_at_client_.find(input_id);
   ASSERT_NE(it, inputs_at_client_.end());
   inputs_at_client_.erase(it);
   if (!run_at_fps_)
     FeedEncoderWithOneInput();
 }
 
-scoped_refptr<media::VideoFrame> VEAClient::PrepareInputFrame(off_t position) {
+std::pair<scoped_refptr<media::VideoFrame>, int32> VEAClient::PrepareInputFrame(
+    off_t position) {
   CHECK_LE(position + test_stream_->aligned_buffer_size,
            test_stream_->mapped_aligned_in_file.length());
 
   uint8* frame_data_y = const_cast<uint8*>(
       test_stream_->mapped_aligned_in_file.data() + position);
   uint8* frame_data_u = frame_data_y + test_stream_->aligned_plane_size[0];
   uint8* frame_data_v = frame_data_u + test_stream_->aligned_plane_size[1];
 
   CHECK_GT(current_framerate_, 0U);
   scoped_refptr<media::VideoFrame> frame =
@@ skipping 10 matching lines @@
           frame_data_v,
           base::TimeDelta().FromMilliseconds(
               next_input_id_ * base::Time::kMillisecondsPerSecond /
               current_framerate_),
           media::BindToCurrentLoop(
               base::Bind(&VEAClient::InputNoLongerNeededCallback,
                          base::Unretained(this),
                          next_input_id_)));
 
   CHECK(inputs_at_client_.insert(next_input_id_).second);
-  ++next_input_id_;
 
-  return frame;
+  return std::make_pair(frame, next_input_id_++);
 }
 
 void VEAClient::OnInputTimer() {
   if (!has_encoder() || state_ != CS_ENCODING)
     input_timer_.reset();
   else if (inputs_at_client_.size() <
            num_required_input_buffers_ + kNumExtraInputFrames)
     FeedEncoderWithOneInput();
   else
     DVLOG(1) << "Dropping input frame";
 }
 
 void VEAClient::FeedEncoderWithOneInput() {
   if (!has_encoder() || state_ != CS_ENCODING)
     return;
 
   size_t bytes_left =
       test_stream_->mapped_aligned_in_file.length() - pos_in_input_stream_;
   if (bytes_left < test_stream_->aligned_buffer_size) {
     DCHECK_EQ(bytes_left, 0UL);
     // Rewind if at the end of stream and we are still encoding.
     // This is to flush the encoder with additional frames from the beginning
     // of the stream, or if the stream is shorter that the number of frames
     // we require for bitrate tests.
     pos_in_input_stream_ = 0;
   }
 
   bool force_keyframe = false;
   if (keyframe_period_ && next_input_id_ % keyframe_period_ == 0) {

[Owen Lin, 2015/05/05 06:03:13]

We already used "next_input_id_" in the same function. I think it would be good
to make them consist.

Besides, I would prefer got the returned value from the argument instead of
returned a pair. At least we can have a name for the argument.

So, what about

int32 input_id;
scoped_refptr<media::VideoFrame> video_frame =
    PrepareInputFrame(pos_in_input_stream_, &input_id);

and set force_keyframe by using input_id and then call Encode()?

     force_keyframe = true;
     ++num_keyframes_requested_;
   }
 
-  scoped_refptr<media::VideoFrame> video_frame =
-      PrepareInputFrame(pos_in_input_stream_);
+  auto ret = PrepareInputFrame(pos_in_input_stream_);

[Owen Lin, 2015/05/04 09:37:12]

we can get the input id by:

int32 input_id = next_input_id_;

[Justin Chuang, 2015/05/04 10:25:09]

I don't like this. See above.

[Justin Chuang, 2015/05/06 10:35:32]

Changed the prototype and remove reference to next_input_id_ in caller. Thx

   pos_in_input_stream_ += test_stream_->aligned_buffer_size;
 
-  encoder_->Encode(video_frame, force_keyframe);
+  CHECK(encode_start_time_per_frame_.insert(
+      std::make_pair(ret.second, base::TimeTicks::Now())).second);
+  encoder_->Encode(ret.first, force_keyframe);
 }
 
 void VEAClient::FeedEncoderWithOutput(base::SharedMemory* shm) {
   if (!has_encoder())
     return;
 
   if (state_ != CS_ENCODING)
     return;
 
   base::SharedMemoryHandle dup_handle;
   CHECK(shm->ShareToProcess(base::GetCurrentProcessHandle(), &dup_handle));
 
   media::BitstreamBuffer bitstream_buffer(
       next_output_buffer_id_++, dup_handle, output_buffer_size_);
   CHECK(output_buffers_at_client_.insert(std::make_pair(bitstream_buffer.id(),
                                                         shm)).second);
   encoder_->UseOutputBitstreamBuffer(bitstream_buffer);
 }
 
 bool VEAClient::HandleEncodedFrame(bool keyframe) {
   // This would be a bug in the test, which should not ignore false
   // return value from this method.
   CHECK_LE(num_encoded_frames_, num_frames_to_encode_);
 
+  last_frame_ready_time_ = base::TimeTicks::Now();
+
+  // Record encode latency of this frame.
+  IdToTicks::iterator it =
+      encode_start_time_per_frame_.find(num_encoded_frames_);
+  CHECK_NE(it, encode_start_time_per_frame_.end());
+  encode_latencies_.push_back(last_frame_ready_time_ - it->second);
+  encode_start_time_per_frame_.erase(it);
+
   ++num_encoded_frames_;
   ++num_frames_since_last_check_;
 
-  last_frame_ready_time_ = base::TimeTicks::Now();
-
   // Because the keyframe behavior requirements are loose, we give
   // the encoder more freedom here. It could either deliver a keyframe
   // immediately after we requested it, which could be for a frame number
   // before the one we requested it for (if the keyframe request
   // is asynchronous, i.e. not bound to any concrete frame, and because
   // the pipeline can be deeper than one frame), at that frame, or after.
   // So the only constraints we put here is that we get a keyframe not
   // earlier than we requested one (in time), and not later than
   // kMaxKeyframeDelay frames after the frame, for which we requested
   // it, comes back encoded.
@@ skipping 30 matching lines @@
   return true;
 }
 
 void VEAClient::VerifyPerf() {
   double measured_fps = frames_per_second();
   LOG(INFO) << "Measured encoder FPS: " << measured_fps;
   g_env->LogToFile("Measured encoder FPS",
                    base::StringPrintf("%.3f", measured_fps));
   if (test_perf_)
     EXPECT_GE(measured_fps, kMinPerfFPS);
+
+  std::vector<float> ratios;

[Owen Lin, 2015/05/04 09:37:12]

Define them as constant, e.g. 

static float kLoggedLatencyPercentages[] = {0.50, 0.75, 0.95};

[Justin Chuang, 2015/05/04 10:25:09]

Will do. 

[Justin Chuang, 2015/05/06 10:35:32]

Done.

+  ratios.push_back(0.50f);
+  ratios.push_back(0.75f);
+  ratios.push_back(0.95f);
+  auto latencies = encode_latency(ratios);
+  for (size_t i = 0; i < ratios.size(); i++) {
+    std::string ratio_str =
+        base::StringPrintf("%d%%", static_cast<int>(ratios[i] * 100));
+    LOG(INFO) << "Encode latency at " << ratio_str << ": "

[Owen Lin, 2015/05/04 09:37:12]

Why using StringPrintf? The following code won't work?

LOG(INFO) << "Encode latency at "
          << static_cast<int>(ratios[i] * 100) << "%: "
          .....
          

[Justin Chuang, 2015/05/04 10:25:09]

This string used in two places.

[Owen Lin, 2015/05/05 06:03:13]

OK, it's fine. But I think you just need the percentage.

int percentage = static_cast<int>(ratios[i] * 100 + .5);
Then you can use it at both places.

[Justin Chuang, 2015/05/06 10:35:32]

Done. Thanks. Nice tip. +0.5 is good, I added it, although normally the FP
library won't have such issue. 

+              << latencies[i].InMicroseconds() << " us";
+    g_env->LogToFile(
+        base::StringPrintf("Encode latency at %s", ratio_str.c_str()),
+        base::StringPrintf("%" PRId64 " us", latencies[i].InMicroseconds()));
+  }
 }
 
 void VEAClient::VerifyStreamProperties() {
   CHECK_GT(num_frames_since_last_check_, 0UL);
   CHECK_GT(encoded_stream_size_since_last_check_, 0UL);
   unsigned int bitrate = encoded_stream_size_since_last_check_ * 8 *
                          current_framerate_ / num_frames_since_last_check_;
   DVLOG(1) << "Current chunk's bitrate: " << bitrate
            << " (expected: " << current_requested_bitrate_
            << " @ " << current_framerate_ << " FPS,"
@@ skipping 239 matching lines @@
   }
 
   content::g_env =
       reinterpret_cast<content::VideoEncodeAcceleratorTestEnvironment*>(
           testing::AddGlobalTestEnvironment(
               new content::VideoEncodeAcceleratorTestEnvironment(
                   test_stream_data.Pass(), log_path, run_at_fps)));
 
   return RUN_ALL_TESTS();
 }