Measure frame decodes more accurately from ImageDecodeBench

third_party/WebKit/Source/platform/testing/ImageDecodeBench.cpp

Index: third_party/WebKit/Source/platform/testing/ImageDecodeBench.cpp
diff --git a/third_party/WebKit/Source/platform/testing/ImageDecodeBench.cpp b/third_party/WebKit/Source/platform/testing/ImageDecodeBench.cpp
index 9fc57c794207db0f0656bb22664ae52753ff4d17..7d48d80475f1fcb371b6e5cbb3f36477ed008bb8 100644
--- a/third_party/WebKit/Source/platform/testing/ImageDecodeBench.cpp
+++ b/third_party/WebKit/Source/platform/testing/ImageDecodeBench.cpp
@@ -18,12 +18,15 @@
 // to http://crbug.com/398235#c103 and http://crbug.com/258324#c5
 
 #include <memory>
+#include <vector>
 #include "base/command_line.h"
 #include "platform/SharedBuffer.h"
 #include "platform/image-decoders/ImageDecoder.h"
 #include "platform/wtf/PassRefPtr.h"
 #include "platform/wtf/PtrUtil.h"
 #include "public/platform/Platform.h"
+#include "third_party/skia/include/core/SkCanvas.h"
+#include "third_party/skia/include/core/SkSurface.h"
 #include "ui/gfx/test/icc_profiles.h"
 
 #if defined(_WIN32)
@@ -204,26 +207,69 @@ PassRefPtr<SharedBuffer> ReadFile(const char* file_name) {
   return SharedBuffer::Create(buffer.get(), file_size);
 }
 
-bool DecodeImageData(SharedBuffer* data,
-                     bool color_correction,
-                     size_t packet_size) {
-  std::unique_ptr<ImageDecoder> decoder = ImageDecoder::Create(
-      data, true, ImageDecoder::kAlphaPremultiplied,
-      color_correction ? ColorBehavior::TransformToTargetForTesting()
-                       : ColorBehavior::Ignore());
-  if (!packet_size) {
-    bool all_data_received = true;
-    decoder->SetData(data, all_data_received);
-
-    int frame_count = decoder->FrameCount();
-    for (int i = 0; i < frame_count; ++i) {
-      if (!decoder->FrameBufferAtIndex(i))
-        return false;
+void Print1DResults(const std::vector<double>& timings) {

[scroggo_chromium, 2017/05/15 15:59:04]

I suppose you put this here to keep it near Print2DResults? My preference would
be to put it closer to where it's used.

That said, it's used only once, and it seems pretty straightforward to just
print the iteration time where you currently add it to the vector.

[cblume, 2017/05/19 16:47:58]

Done.

+  for (double iteration_time : timings) {
+    printf("%f,", iteration_time);
+  }
+  printf("\n");
+}
+
+// The outer vector represents multiple iterations through the image.

[scroggo_chromium, 2017/05/15 15:59:04]

This comment appears several times. It makes me think the code itself should be
clearer. Maybe come up with a variable name that makes it more clear? I'm not
sure what that would be though. Another option: create a type that makes it more
clear, with a single comment. Some ideas:

// The outer vector represents multiple iterations through the image.
// The inner vector represents individual frames in an animation.
using FrameTime2DVector = std::vector<std::vector<double>>;

or 

// FrameTimeVector[i] is a single timing of decoding frame i.
using FrameTimeVector = std::vector<double>;

// Stores FrameTimeVectors over multiple iterations.
using IterationFrameTimeVector = std::vector<FrameTimeVector>;

I sometimes see "using" statements in sample code and think "But then I'll have
to go look up what it is when I need to use it!" But here it might be helpful,
because if I do not remember what it means I look back to the "using" statement
and see all I need to know.

On the other hand, maybe this can just be done in line? It seems pretty
straightforward - each time you add a time to the vector, you can just print it,
and then print \n when you finish your iteration. Then you don't need to worry
about all this explaining.

[cblume, 2017/05/19 16:47:58]

Yeah. I had tried to come up with a typedef / using but my solutions were
uglier. Your suggestion seems pretty good. I would definitely prefer to look it
up and have only one comment.

+// The inner vector represents individual frames in an animation.
+void Print2DResults(const std::vector<std::vector<double>>& timings) {
+  for (const std::vector<double>& iteration : timings) {
+    for (double frame_time : iteration) {
+      printf("%f,", frame_time);
     }
+    printf("\n");
+  }
+  printf("\n");
+}
 
-    return !decoder->Failed();
+void TimeDecode(ImageDecoder* decoder, SharedBuffer* data, size_t iterations) {
+  bool all_data_received = true;
+  decoder->SetData(data, all_data_received);
+
+  size_t frame_count = decoder->FrameCount();
+
+  // The outer vector represents multiple iterations through the image.
+  // The inner vector represents individual frames in an animation.
+  std::vector<std::vector<double>> timings(
+      iterations, std::vector<double>(frame_count, 0.0));
+
+  for (size_t iteration = 0; iteration < iterations; ++iteration) {
+    for (size_t frame_index = 0; frame_index < frame_count; ++frame_index) {
+      double start_time = GetCurrentTime();
+      ImageFrame* frame = decoder->FrameBufferAtIndex(frame_index);
+      double elapsed_time = GetCurrentTime() - start_time;
+      if (!frame) {

[scroggo_chromium, 2017/05/15 15:59:04]

As I've stated elsewhere, I don't think this can ever happen. Do you want to
check GetStatus instead?

[cblume, 2017/05/19 16:47:58]

Done.

+        return;
+      }
+      timings[iteration][frame_index] = elapsed_time;
+    }
   }
 
+  Print2DResults(timings);
+}
+
+// This function mimics what actually happens in Chromium.

[scroggo_chromium, 2017/05/15 15:59:04]

There are different paths that result in a decode, but I think this should be
more specific about when it actually happens this way.

Something like:

// This function mimics deferred decoding in Chromium when not all data has been
received yet.

[cblume, 2017/05/19 16:47:58]

Done.

+void TimePacketedDecode(ImageDecoder* decoder,
+                        SharedBuffer* data,
+                        size_t packet_size,
+                        size_t iterations) {
+  // Find total frame count.
+  // Doing this requires a decoder with full data (no packet size).
+  bool all_data_received = true;

[scroggo_chromium, 2017/05/15 15:59:04]

This variable ends up being shadowed by a variable in the outer loop, below.

I don't find it necessary, though. I suppose you include it to aid readability?

[cblume, 2017/05/19 16:47:58]

Right, I only have this bool for readability. It could be constexpr.
It mirrors what was already in the code [1].
The shadowing was not intentional.

I'll rename to avoid the shadowing. If you prefer to not have a named bool I'm
okay with that.

[1]
https://cs.chromium.org/chromium/src/third_party/WebKit/Source/platform/testi...

[scroggo_chromium, 2017/05/19 21:04:15]

Ah, I prefer not having a named bool, but it makes sense to follow existing
style. (The real fix may be to use an enum. Then the call site will say

  setData(..., AllDataReceived::Yes)

or something like that.)

[cblume, 2017/05/19 21:47:38]

I agree that I prefer the enum.
I'll leave it for now to match existing style. We can change it to an enum in a
separate CL.

+  decoder->SetData(data, all_data_received);
+  size_t total_frame_count = decoder->FrameCount();
+
+  // The outer vector represents multiple iterations through the image.
+  // The inner vector represents individual frames in an animation.
+  std::vector<std::vector<double>> timings(
+      iterations, std::vector<double>(total_frame_count, 0.0));
+
+  // Fill the buffer with only some data (|packet_size|), decode all the frames
+  // we can with that data, and then repeat -- filling with another packet.
   RefPtr<SharedBuffer> packet_data = SharedBuffer::Create();
   size_t position = 0;
   size_t next_frame_to_decode = 0;
@@ -236,41 +282,78 @@ bool DecodeImageData(SharedBuffer* data,
     position += length;
 
     bool all_data_received = position == data->size();
+
     size_t frame_count = decoder->FrameCount();

[scroggo_chromium, 2017/05/15 15:59:04]

Since you're using the same decoder as above, I don't think this value will ever
be different from total_frame_count, declared above.

[cblume, 2017/05/19 16:47:58]

Oh, you're right.
I want to create a new decoder here.

-    for (; next_frame_to_decode < frame_count; ++next_frame_to_decode) {
-      decoder->SetData(packet_data.Get(), all_data_received);
-      ImageFrame* frame = decoder->FrameBufferAtIndex(next_frame_to_decode);
-      if (frame->GetStatus() != ImageFrame::kFrameComplete)
-        break;
-      decoder->SetData(PassRefPtr<SegmentReader>(nullptr), false);
-      decoder->ClearCacheExceptFrame(next_frame_to_decode);
+    for (size_t iteration = 0; iteration < iterations; ++iteration) {
+      for (; next_frame_to_decode < frame_count; ++next_frame_to_decode) {
+        decoder->SetData(packet_data.Get(), all_data_received);
+        double start_time = GetCurrentTime();
+        ImageFrame* frame = decoder->FrameBufferAtIndex(next_frame_to_decode);
+        double elapsed_time = GetCurrentTime() - start_time;
+        if (frame->GetStatus() != ImageFrame::kFrameComplete)
+          break;
+        timings[iteration][next_frame_to_decode] = elapsed_time;
+        decoder->SetData(PassRefPtr<SegmentReader>(nullptr), false);
+        decoder->ClearCacheExceptFrame(next_frame_to_decode);
+      }
     }
 
     if (all_data_received || decoder->Failed())
-      break;
+      return;
+  }
+
+  Print2DResults(timings);
+}
+
+void TimeRaster(ImageDecoder* decoder, SharedBuffer* data, size_t iterations) {
+  // Decode first frame

[scroggo_chromium, 2017/05/15 15:59:04]

I'm guilty of this, too, but try to keep your comments focused on why you're
doing what you're doing. Reading the code, I can see that you're decoding the
first frame. That said, it's not necessarily clear to me why you only decode the
first frame.

[cblume, 2017/05/19 16:47:58]

Done.

+  const bool all_data_received = true;
+  decoder->SetData(data, all_data_received);
+  ImageFrame* frame = decoder->FrameBufferAtIndex(0);
+
+  // Create raster target
+  const auto size = decoder->Size();
+  auto surface = SkSurface::MakeRasterN32Premul(size.Width(), size.Height());
+  auto canvas = surface->getCanvas();
+
+  // Time raster iterations
+  std::vector<double> timings(iterations);
+  for (size_t iteration = 0; iteration < iterations; ++iteration) {
+    double start_time = GetCurrentTime();
+    canvas->drawBitmap(frame->Bitmap(), 0, 0, nullptr);
+    double elapsed_time = GetCurrentTime() - start_time;
+    timings[iteration] = elapsed_time;
   }
 
-  return !decoder->Failed();
+  Print1DResults(timings);
 }
 
 }  // namespace
 
 int Main(int argc, char* argv[]) {
   base::CommandLine::Init(argc, argv);
-
   // If the platform supports color correction, allow it to be controlled.
 
   bool apply_color_correction = false;
-
   if (argc >= 2 && strcmp(argv[1], "--color-correct") == 0) {
-    apply_color_correction = (--argc, ++argv, true);
+    --argc;
+    ++argv;
+    apply_color_correction = true;
     gfx::ICCProfile profile = gfx::ICCProfileForTestingColorSpin();
     ColorBehavior::SetGlobalTargetColorProfile(profile);
   }
 
+  bool time_raster = false;
+  if (argc >= 2 && strcmp(argv[1], "--raster") == 0) {
+    --argc;
+    ++argv;
+    time_raster = true;
+  }
+
   if (argc < 2) {
     fprintf(stderr,
-            "Usage: %s [--color-correct] file [iterations] [packetSize]\n",
+            "Usage: %s [--color-correct] [--raster] file [iterations] "
+            "[packetSize]\n",
             argv[0]);
     exit(1);
   }
@@ -322,33 +405,23 @@ int Main(int argc, char* argv[]) {
 
   data->Data();
 
-  // Warm-up: throw out the first iteration for more consistent results.

[scroggo_chromium, 2017/05/15 15:59:04]

Is this no longer necessary?

[cblume, 2017/05/19 16:47:58]

If you only do 1 iteration then it'll pretty much only show you cache miss time
which would have previously been discarded.

But presumably the main benefit is running several iterations.

If you run multiple iterations, it is perfectly okay for the first run to have a
wonky time because of cache misses. It'll get tossed out if you filter noise.
And you may actually want to just be aware of what to expect in the case of
cache misses. Most single-frame decodes are likely to hit that.

-
-  if (!DecodeImageData(data.Get(), apply_color_correction, packet_size)) {
-    fprintf(stderr, "Image decode failed [%s]\n", argv[1]);
-    exit(3);
-  }
-
   // Image decode bench for iterations.
 
-  double total_time = 0.0;
-
-  for (size_t i = 0; i < iterations; ++i) {
-    double start_time = GetCurrentTime();
-    bool decoded =
-        DecodeImageData(data.Get(), apply_color_correction, packet_size);
-    double elapsed_time = GetCurrentTime() - start_time;
-    total_time += elapsed_time;
-    if (!decoded) {
-      fprintf(stderr, "Image decode failed [%s]\n", argv[1]);
-      exit(3);
+  std::unique_ptr<ImageDecoder> decoder = ImageDecoder::Create(
+      data, true, ImageDecoder::kAlphaPremultiplied,
+      apply_color_correction ? ColorBehavior::TransformToTargetForTesting()
+                             : ColorBehavior::Ignore());
+  if (time_raster) {
+    blink::TimeRaster(decoder.get(), data.Get(), iterations);
+  } else {
+    if (packet_size) {
+      blink::TimePacketedDecode(decoder.get(), data.Get(), packet_size,
+                                iterations);
+    } else {
+      blink::TimeDecode(decoder.get(), data.Get(), iterations);
     }
   }
 
-  // Results to stdout.
-
-  double average_time = total_time / static_cast<double>(iterations);
-  printf("%f %f\n", total_time, average_time);

[scroggo_chromium, 2017/05/15 15:59:04]

Now that we do not print the average, is the expectation that the user will do
their own analysis? e.g. compute average, min, median, max?

Should that be printed as part of this program?

[cblume, 2017/05/19 16:47:58]

I want to be able to visualize the data. It also lets you see how noisy your
results are and trim as necessary.

An animated image may have one frame that decodes a large area and another frame
which decodes a small area. So you need to treat these frames separately. So we
definitely want to start dealing with more data anyway.

But visualizing the data has some serious benefits so we need access to all the
data points. With min we know the fastest it can go. Adding median, we can see
roughly how noisy our measurements are by how much higher the median is from the
average. If we weren't to visualize, those would be the values we want. But even
with them you don't get the full picture. Say there is some noise -- is it a
lot? Is that an expected amount of noise? What caused it? You're only option is
to run it again and maybe you'll get different noise. Visualizing could help you
say "whoa, right in the middle here times were very different. Now I can
investigate what might be causing that."

[scroggo_chromium, 2017/05/19 21:04:15]

I guess what I'm getting at is, what do you do to visualize the data? Do you
just look at it? Or do you plug it into some other program? Should that program
be a part of this one? Or checked in? Or referenced somewhere in this file?

[cblume, 2017/05/19 21:47:38]

I'm printing out the data in a way that makes it csv-friendly.
So then I import the csv into Google Sheets, where I can visualize it as a graph
and copy&trim out noise.

This is the downside of adding accuracy. It necessitates more data, which in
turn necessitates something to process that data.

In an ideal world, we would also provide the code to visualize & manipulate the
data. But that's a lot of extra work which I don't think is worth the effort
just yet.

A happy medium would be to allow passing in multiple image inputs and save it
all to a single import into Sheets. Right now, you have to import each csv
separately. I looked at a few options but none of the simple ones supported
this.

I'll add a comment about the output being csv-formatted.

   return 0;
 }