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
2014-05-09 14:59:29 +00:00 · 2014-05-09 14:59:29 +00:00 · 27f6b0d013
commit 27f6b0d013
parent 36b3d34ef2
4 changed files with 113 additions and 71 deletions
--- a/gyp/tools.gyp
+++ b/gyp/tools.gyp
@ -357,6 +357,7 @@
        '../src/record',
      ],
      'dependencies': [
+        'bench.gyp:bench_timer',
        'flags.gyp:flags',
        'record.gyp:*',
        'skia_lib.gyp:skia_lib',
--- a/src/record/SkRecordDraw.cpp
+++ b/src/record/SkRecordDraw.cpp
@ -7,52 +7,30 @@

 #include "SkRecordDraw.h"

-namespace {
-
-// This is an SkRecord visitor that will draw that SkRecord to an SkCanvas.
-class Draw : SkNoncopyable {
-public:
-    explicit Draw(SkCanvas* canvas) : fCanvas(canvas), fIndex(0) {}
-
-    unsigned index() const { return fIndex; }
-    void next() { ++fIndex; }
-
-    template <typename T> void operator()(const T& r) {
-        if (!this->skip(r)) {
-            this->draw(r);
-        }
+void SkRecordDraw(const SkRecord& record, SkCanvas* canvas) {
+    for (SkRecords::Draw draw(canvas); draw.index() < record.count(); draw.next()) {
+        record.visit<void>(draw.index(), draw);
    }
+}

-private:
-    // No base case, so we'll be compile-time checked that we implemented all possibilities below.
-    template <typename T> void draw(const T&);
+namespace SkRecords {

-    // skip() should return true if we can skip this command, false if not.
-    // It may update fIndex directly to skip more than just this one command.
-
-    // Mostly we just blindly call fCanvas and let it handle quick rejects itself.
-    template <typename T> bool skip(const T&) { return false; }
-
-    // We add our own quick rejects for commands added by optimizations.
-    bool skip(const SkRecords::PairedPushCull& r) {
-        if (fCanvas->quickReject(r.base->rect)) {
-            fIndex += r.skip;
-            return true;
-        }
-        return false;
-    }
-    bool skip(const SkRecords::BoundedDrawPosTextH& r) {
-        return fCanvas->quickRejectY(r.minY, r.maxY);
+bool Draw::skip(const PairedPushCull& r) {
+    if (fCanvas->quickReject(r.base->rect)) {
+        fIndex += r.skip;
+        return true;
    }
+    return false;
+}

-    SkCanvas* fCanvas;
-    unsigned fIndex;
-};
+bool Draw::skip(const BoundedDrawPosTextH& r) {
+    return fCanvas->quickRejectY(r.minY, r.maxY);
+}

 // NoOps draw nothing.
-template <> void Draw::draw(const SkRecords::NoOp&) {}
+template <> void Draw::draw(const NoOp&) {}

-#define DRAW(T, call) template <> void Draw::draw(const SkRecords::T& r) { fCanvas->call; }
+#define DRAW(T, call) template <> void Draw::draw(const T& r) { fCanvas->call; }
 DRAW(Restore, restore());
 DRAW(Save, save(r.flags));
 DRAW(SaveLayer, saveLayer(r.bounds, r.paint, r.flags));
@ -87,13 +65,7 @@ DRAW(DrawVertices, drawVertices(r.vmode, r.vertexCount, r.vertices, r.texs, r.co
                                r.xmode.get(), r.indices, r.indexCount, r.paint));
 #undef DRAW

-template <> void Draw::draw(const SkRecords::PairedPushCull& r) { this->draw(*r.base); }
-template <> void Draw::draw(const SkRecords::BoundedDrawPosTextH& r) { this->draw(*r.base); }
+template <> void Draw::draw(const PairedPushCull& r) { this->draw(*r.base); }
+template <> void Draw::draw(const BoundedDrawPosTextH& r) { this->draw(*r.base); }

-}  // namespace
-
-void SkRecordDraw(const SkRecord& record, SkCanvas* canvas) {
-    for (Draw draw(canvas); draw.index() < record.count(); draw.next()) {
-        record.visit<void>(draw.index(), draw);
-    }
-}
+}  // namespace SkRecords
--- a/src/record/SkRecordDraw.h
+++ b/src/record/SkRecordDraw.h
@ -11,7 +11,43 @@
 #include "SkRecord.h"
 #include "SkCanvas.h"

-// Draw an SkRecord into an SkCanvas.
+// Draw an SkRecord into an SkCanvas.  A convenience wrapper around SkRecords::Draw.
 void SkRecordDraw(const SkRecord&, SkCanvas*);

+namespace SkRecords {
+
+// This is an SkRecord visitor that will draw that SkRecord to an SkCanvas.
+class Draw : SkNoncopyable {
+public:
+    explicit Draw(SkCanvas* canvas) : fCanvas(canvas), fIndex(0) {}
+
+    unsigned index() const { return fIndex; }
+    void next() { ++fIndex; }
+
+    template <typename T> void operator()(const T& r) {
+        if (!this->skip(r)) {
+            this->draw(r);
+        }
+    }
+
+private:
+    // No base case, so we'll be compile-time checked that we implement all possibilities.
+    template <typename T> void draw(const T&);
+
+    // skip() should return true if we can skip this command, false if not.
+    // It may update fIndex directly to skip more than just this one command.
+
+    // Mostly we just blindly call fCanvas and let it handle quick rejects itself.
+    template <typename T> bool skip(const T&) { return false; }
+
+    // We add our own quick rejects for commands added by optimizations.
+    bool skip(const PairedPushCull&);
+    bool skip(const BoundedDrawPosTextH&);
+
+    SkCanvas* fCanvas;
+    unsigned fIndex;
+};
+
+}  // namespace SkRecords
+
 #endif//SkRecordDraw_DEFINED
--- 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;