Add timing to dump_record.

Prints microsecond timing for each command in the left-hand column:

optimized flat/http___mobile_news_sandbox_google_com_news_pt0_scroll_layer_7.skp
   4.0   1 Save
2075.0   2      DrawRect
 104.0   3      BoundedDrawPosTextH
 135.4   4      DrawRect
   9.4   5      DrawRect
   5.6   6      DrawRect
   8.2   7      DrawRect
   6.8   8      DrawRect
...

(I'm sure Rietveld will just mangle the crap out of that.  It's helpfully right-aligned.)

To do this, I made Draw from SkRecordDraw Skia-public as SkRecords::Draw,
and time it command-by-command.

BUG=skia:2378
R=fmalita@chromium.org, mtklein@google.com

Author: mtklein@chromium.org

Review URL: https://codereview.chromium.org/272723007

git-svn-id: http://skia.googlecode.com/svn/trunk@14672 2bbb7eff-a529-9590-31e7-b0007b416f81

1 files changed, 56 insertions, 23 deletions

diff --git a/tools/dump_record.cpp b/tools/dump_record.cpp
index b427a81d61..2d851e7c9f 100644
--- a/tools/dump_record.cpp
+++ b/tools/dump_record.cpp
@@ -7,12 +7,14 @@
 
 #include <stdio.h>
 
+#include "BenchTimer.h"
 #include "LazyDecodeBitmap.h"
 #include "SkCommandLineFlags.h"
 #include "SkGraphics.h"
 #include "SkOSFile.h"
 #include "SkPicture.h"
 #include "SkRecord.h"
+#include "SkRecordDraw.h"
 #include "SkRecordOpts.h"
 #include "SkRecorder.h"
 #include "SkStream.h"
@@ -20,37 +22,68 @@
 DEFINE_string2(skps, r, "", ".SKPs to dump.");
 DEFINE_string(match, "", "The usual filters on file names to dump.");
 DEFINE_bool2(optimize, O, false, "Run SkRecordOptimize before dumping.");
+DEFINE_int32(tile, 1000000000, "Simulated tile size.");
+DEFINE_bool(timeWithCommand, false, "If true, print time next to command, else in first column.");
 
 class Dumper {
 public:
-    Dumper() : fIndent(0) {}
+    explicit Dumper(SkCanvas* canvas, int count) : fDigits(0), fIndent(0), fDraw(canvas) {
+        while (count > 0) {
+            count /= 10;
+            fDigits++;
+        }
+    }
+
+    unsigned index() const { return fDraw.index(); }
+    void next() { fDraw.next(); }
 
     template <typename T>
     void operator()(const T& command) {
-        this->printIndentedName(command);
+        BenchTimer timer;
+        timer.start();
+            fDraw(command);
+        timer.end();
+
+        this->print(command, timer.fCpu);
     }
 
-    void operator()(const SkRecords::Restore& command) {
+    void operator()(const SkRecords::NoOp&) {
+        // Move on without printing anything.
+    }
+
+    template <typename T>
+    void print(const T& command, double time) {
+        this->printNameAndTime(command, time);
+    }
+
+    void print(const SkRecords::Restore& command, double time) {
         --fIndent;
-        this->printIndentedName(command);
+        this->printNameAndTime(command, time);
     }
 
-    void operator()(const SkRecords::Save& command) {
-        this->printIndentedName(command);
+    void print(const SkRecords::Save& command, double time) {
+        this->printNameAndTime(command, time);
         ++fIndent;
     }
 
-    void operator()(const SkRecords::SaveLayer& command) {
-        this->printIndentedName(command);
+    void print(const SkRecords::SaveLayer& command, double time) {
+        this->printNameAndTime(command, time);
         ++fIndent;
     }
 
 private:
     template <typename T>
-    void printIndentedName(const T& command) {
+    void printNameAndTime(const T& command, double time) {
+        if (!FLAGS_timeWithCommand) {
+            printf("%6.1f ", time * 1000);
+        }
+        printf("%*d ", fDigits, fDraw.index());
         for (int i = 0; i < fIndent; i++) {
             putchar('\t');
         }
+        if (FLAGS_timeWithCommand) {
+            printf("%6.1f ", time * 1000);
+        }
         puts(NameOf(command));
     }
 
@@ -67,24 +100,22 @@ private:
         return "\x1b[31;1mSaveLayer\x1b[0m";  // Bold red.
     }
 
+    int fDigits;
     int fIndent;
+    SkRecords::Draw fDraw;
 };
 
 
-static void dump(const char* name, const SkRecord& record) {
-    Dumper dumper;
-
-    unsigned count = record.count();
-    int digits = 0;
-    while (count > 0) {
-        count /= 10;
-        digits++;
-    }
+static void dump(const char* name, int w, int h, const SkRecord& record) {
+    SkBitmap bitmap;
+    bitmap.allocN32Pixels(w, h);
+    SkCanvas canvas(bitmap);
+    canvas.clipRect(SkRect::MakeWH(SkIntToScalar(FLAGS_tile), SkIntToScalar(FLAGS_tile)));
 
     printf("%s %s\n", FLAGS_optimize ? "optimized" : "not-optimized", name);
-    for (unsigned i = 0; i < record.count(); i++) {
-        printf("%*d ", digits, i);
-        record.visit<void>(i, dumper);
+
+    for (Dumper dumper(&canvas, record.count()); dumper.index() < record.count(); dumper.next()) {
+        record.visit<void>(dumper.index(), dumper);
     }
 }
 
@@ -109,16 +140,18 @@ int tool_main(int argc, char** argv) {
             SkDebugf("Could not read %s as an SkPicture.\n", FLAGS_skps[i]);
             exit(1);
         }
+        const int w = src->width(), h = src->height();
 
         SkRecord record;
-        SkRecorder canvas(SkRecorder::kWriteOnly_Mode, &record, src->width(), src->height());
+        SkRecorder canvas(SkRecorder::kWriteOnly_Mode, &record, w, h);
         src->draw(&canvas);
 
+
         if (FLAGS_optimize) {
             SkRecordOptimize(&record);
         }
 
-        dump(FLAGS_skps[i], record);
+        dump(FLAGS_skps[i], w, h, record);
     }
 
     return 0;