Breakdown profile time by command type in the overview pane

https://codereview.appspot.com/6851073/



git-svn-id: http://skia.googlecode.com/svn/trunk@6492 2bbb7eff-a529-9590-31e7-b0007b416f81
diff --git a/debugger/QT/SkDebuggerGUI.cpp b/debugger/QT/SkDebuggerGUI.cpp
index e7be72d..3b9b8aa 100644
--- a/debugger/QT/SkDebuggerGUI.cpp
+++ b/debugger/QT/SkDebuggerGUI.cpp
@@ -9,9 +9,7 @@
 #include "SkGraphics.h"
 #include "SkImageDecoder.h"
 #include <QListWidgetItem>
-#include "PictureBenchmark.h"
 #include "PictureRenderer.h"
-#include "SkBenchLogger.h"
 #include "SkPictureRecord.h"
 #include "SkPicturePlayback.h"
 #include "BenchTimer.h"
@@ -138,21 +136,36 @@
         , fCurCommand(0)
         , fOffsets(offsets) {
         fTimes.setCount(fOffsets.count());
+        fTypeTimes.setCount(LAST_DRAWTYPE_ENUM+1);
+        this->resetTimes();
+    }
+
+    void resetTimes() {
         for (int i = 0; i < fOffsets.count(); ++i) {
-            fTimes[i] = 0;
+            fTimes[i] = 0.0;
         }
+        for (int i = 0; i < fTypeTimes.count(); ++i) {
+            fTypeTimes[i] = 0.0f;
+        }
+        fTot = 0.0;
     }
 
     int count() const { return fTimes.count(); }
 
     double time(int index) const { return fTimes[index] / fTot; }
 
+    const SkTDArray<double>* typeTimes() const { return &fTypeTimes; }
+
+    double totTime() const { return fTot; }
+
 protected:
     BenchTimer fTimer;
     SkTDArray<size_t> fOffsets; // offset in the SkPicture for each command
     SkTDArray<double> fTimes;   // sum of time consumed for each command
+    SkTDArray<double> fTypeTimes; // sum of time consumed for each type of command (e.g., drawPath)
     double fTot;                // total of all times in 'fTimes'
     size_t fCurOffset;
+    int fCurType;
     int fCurCommand;            // the current command being executed/timed
 
     virtual void preDraw(size_t offset, int type) {
@@ -166,6 +179,15 @@
         }
 
         fCurOffset = offset;
+        fCurType = type;
+        // The SkDebugCanvas doesn't recognize these types. This class needs to
+        // convert or else we'll wind up with a mismatch between the type counts
+        // the debugger displays and the profile times.
+        if (DRAW_POS_TEXT_TOP_BOTTOM == type) {
+            fCurType = DRAW_POS_TEXT;
+        } else if (DRAW_POS_TEXT_H_TOP_BOTTOM == type) {
+            fCurType = DRAW_POS_TEXT_H;
+        }
 
         fTimer.start();
     }
@@ -174,13 +196,16 @@
         fTimer.end();
 
         SkASSERT(offset == fCurOffset);
+        SkASSERT(fCurType <= LAST_DRAWTYPE_ENUM);
 
 #if defined(SK_BUILD_FOR_WIN32)
         // CPU timer doesn't work well on Windows
         fTimes[fCurCommand] += fTimer.fWall;
+        fTypeTimes[fCurType] += fTimer.fWall;
         fTot += fTimer.fWall;
 #else
         fTimes[fCurCommand] += fTimer.fCpu;
+        fTypeTimes[fCurType] += fTimer.fCpu;
         fTot += fTimer.fCpu;
 #endif
     }
@@ -231,15 +256,59 @@
         }
     }
 
+    void resetTimes() { ((SkTimedPicturePlayback*) fPlayback)->resetTimes(); }
+
     int count() const { return ((SkTimedPicturePlayback*) fPlayback)->count(); }
 
     // return the fraction of the total time this command consumed
     double time(int index) const { return ((SkTimedPicturePlayback*) fPlayback)->time(index); }
 
+    const SkTDArray<double>* typeTimes() const { return ((SkTimedPicturePlayback*) fPlayback)->typeTimes(); }
+
+    double totTime() const { return ((SkTimedPicturePlayback*) fPlayback)->totTime(); }
+
 private:
+    // disallow default ctor b.c. we don't have a good way to setup the fPlayback ptr
+    SkTimedPicture();
+    // disallow the copy ctor - enabling would require copying code from SkPicture
+    SkTimedPicture(const SkTimedPicture& src);
+
     typedef SkPicture INHERITED;
 };
 
+// This is a simplification of PictureBenchmark's run with the addition of
+// clearing of the times after the first pass (in resetTimes)
+void SkDebuggerGUI::run(SkTimedPicture* pict, 
+                        sk_tools::PictureRenderer* renderer, 
+                        int repeats) {
+    SkASSERT(pict);
+    if (NULL == pict) {
+        return;
+    }
+
+    SkASSERT(renderer != NULL);
+    if (NULL == renderer) {
+        return;
+    }
+
+    renderer->init(pict);
+
+    renderer->setup();
+    renderer->render(NULL);
+    renderer->resetState();
+
+    // We throw this away the first batch of times to remove first time effects (such as paging in this program)
+    pict->resetTimes();
+
+    for (int i = 0; i < repeats; ++i) {
+        renderer->setup();
+        renderer->render(NULL);
+        renderer->resetState();
+    }
+
+    renderer->end();
+}
+
 void SkDebuggerGUI::actionProfile() {
     // In order to profile we pass the command offsets (that were read-in
     // in loadPicture by the SkOffsetPicture) to an SkTimedPlaybackPicture.
@@ -263,24 +332,21 @@
         return;
     }
 
-    sk_tools::PictureBenchmark benchmark;
-
+    // For now this #if allows switching between tiled and simple rendering
+    // modes. Eventually this will be accomplished via the GUI
+#if 1
     sk_tools::TiledPictureRenderer* renderer = NULL;
 
     renderer = SkNEW(sk_tools::TiledPictureRenderer);
     renderer->setTileWidth(256);
     renderer->setTileHeight(256);
+#else
+    sk_tools::SimplePictureRenderer* renderer = NULL;
 
+    renderer = SkNEW(sk_tools::SimplePictureRenderer);
+#endif
 
-    benchmark.setRepeats(2);
-    benchmark.setRenderer(renderer);
-    benchmark.setTimersToShow(true, false, true, false, false);
-
-    SkBenchLogger logger;
-
-    benchmark.setLogger(&logger);
-
-    benchmark.run(&picture);
+    run(&picture, renderer, 2);
 
     SkASSERT(picture.count() == fListWidget.count());
 
@@ -292,6 +358,8 @@
 
         item->setData(Qt::UserRole + 4, 100.0*temp);
     }
+
+    setupOverviewText(picture.typeTimes(), picture.totTime());
 }
 
 void SkDebuggerGUI::actionCancel() {
@@ -825,6 +893,11 @@
     }
 
 private:
+    // disallow default ctor b.c. we don't have a good way to setup the fPlayback ptr
+    SkOffsetPicture();
+    // disallow the copy ctor - enabling would require copying code from SkPicture
+    SkOffsetPicture(const SkOffsetPicture& src);
+
     typedef SkPicture INHERITED;
 };
 
@@ -845,7 +918,7 @@
     SkSafeUnref(picture);
 
     // Will this automatically clear out due to nature of refcnt?
-    SkTDArray<SkString*>* commands = fDebugger.getDrawCommands();
+    SkTArray<SkString>* commands = fDebugger.getDrawCommandsAsStrings();
 
     // If SkPicturePlayback is compiled w/o SK_PICTURE_PROFILING_STUBS
     // the offset count will always be zero
@@ -863,6 +936,7 @@
 
     setupListWidget(commands);
     setupComboBox(commands);
+    setupOverviewText(NULL, 0.0);
     fInspectorWidget.setDisabled(false);
     fSettingsWidget.setDisabled(false);
     fMenuEdit.setDisabled(false);
@@ -874,23 +948,23 @@
     actionPlay();
 }
 
-void SkDebuggerGUI::setupListWidget(SkTDArray<SkString*>* command) {
+void SkDebuggerGUI::setupListWidget(SkTArray<SkString>* command) {
     fListWidget.clear();
     int counter = 0;
     int indent = 0;
     for (int i = 0; i < command->count(); i++) {
         QListWidgetItem *item = new QListWidgetItem();
-        item->setData(Qt::DisplayRole, (*command)[i]->c_str());
+        item->setData(Qt::DisplayRole, (*command)[i].c_str());
         item->setData(Qt::UserRole + 1, counter++);
 
-        if (0 == strcmp("Restore", (*command)[i]->c_str())) {
+        if (0 == strcmp("Restore", (*command)[i].c_str())) {
             indent -= 10;
         }
 
         item->setData(Qt::UserRole + 3, indent);
 
-        if (0 == strcmp("Save", (*command)[i]->c_str()) ||
-            0 == strcmp("Save Layer", (*command)[i]->c_str())) {
+        if (0 == strcmp("Save", (*command)[i].c_str()) ||
+            0 == strcmp("Save Layer", (*command)[i].c_str())) {
             indent += 10;
         }
 
@@ -900,31 +974,75 @@
     }
 }
 
-void SkDebuggerGUI::setupComboBox(SkTDArray<SkString*>* command) {
-    fFilter.clear();
-    fFilter.addItem("--Filter By Available Commands--");
+void SkDebuggerGUI::setupOverviewText(const SkTDArray<double>* typeTimes, double totTime) {
 
-    std::map<std::string, int> map;
-    for (int i = 0; i < command->count(); i++) {
-        map[(*command)[i]->c_str()]++;
+    const SkTDArray<SkDrawCommand*>& commands = fDebugger.getDrawCommands();
+
+    SkTDArray<int> counts;
+    counts.setCount(LAST_DRAWTYPE_ENUM+1);
+    for (int i = 0; i < LAST_DRAWTYPE_ENUM+1; ++i) {
+        counts[i] = 0;
+    }
+
+    for (int i = 0; i < commands.count(); i++) {
+        counts[commands[i]->getType()]++;
     }
 
     QString overview;
-    int counter = 0;
-    for (std::map<std::string, int>::iterator it = map.begin(); it != map.end();
-            ++it) {
-        overview.append((it->first).c_str());
+    int total = 0;
+#ifdef SK_DEBUG
+    double totPercent = 0, tempSum = 0;
+#endif
+    for (int i = 0; i < LAST_DRAWTYPE_ENUM+1; ++i) {
+        if (0 == counts[i]) {
+            // if there were no commands of this type then they should've consumed no time
+            SkASSERT(NULL == typeTimes || 0.0 == (*typeTimes)[i]);
+            continue;
+        }
+
+        overview.append(SkDrawCommand::GetCommandString((DrawType) i));
         overview.append(": ");
-        overview.append(QString::number(it->second));
+        overview.append(QString::number(counts[i]));
+        if (NULL != typeTimes) {
+            overview.append(" - ");
+            overview.append(QString::number((*typeTimes)[i], 'f', 1));
+            overview.append("ms");
+            overview.append(" - ");
+            double percent = 100.0*(*typeTimes)[i]/totTime;
+            overview.append(QString::number(percent, 'f', 1));
+            overview.append("%");
+#ifdef SK_DEBUG
+            totPercent += percent;
+            tempSum += (*typeTimes)[i];
+#endif
+        }
         overview.append("<br/>");
-        counter += it->second;
-        fFilter.addItem((it->first).c_str());
+        total += counts[i];
     }
-    QString total;
-    total.append("Total Draw Commands: ");
-    total.append(QString::number(counter));
-    total.append("<br/>");
-    overview.insert(0, total);
+#ifdef SK_DEBUG
+    if (NULL != typeTimes) {
+        SkASSERT(SkScalarNearlyEqual(totPercent, 100.0));
+        SkASSERT(SkScalarNearlyEqual(tempSum, totTime));
+    }
+#endif
+
+    if (totTime > 0.0) {
+        overview.append("Total Time: ");
+        overview.append(QString::number(totTime, 'f', 2));
+        overview.append("ms");
+#ifdef SK_DEBUG
+        overview.append(" ");
+        overview.append(QString::number(totPercent));
+        overview.append("% ");
+#endif
+        overview.append("<br/>");
+    }
+
+    QString totalStr;
+    totalStr.append("Total Draw Commands: ");
+    totalStr.append(QString::number(total));
+    totalStr.append("<br/>");
+    overview.insert(0, totalStr);
 
     overview.append("<br/>");
     overview.append("SkPicture Width: ");
@@ -935,6 +1053,21 @@
     overview.append(QString::number(fDebugger.pictureHeight()));
     overview.append("px");
     fInspectorWidget.setText(overview, SkInspectorWidget::kOverview_TabType);
+}
+
+void SkDebuggerGUI::setupComboBox(SkTArray<SkString>* command) {
+    fFilter.clear();
+    fFilter.addItem("--Filter By Available Commands--");
+
+    std::map<std::string, int> map;
+    for (int i = 0; i < command->count(); i++) {
+        map[(*command)[i].c_str()]++;
+    }
+
+    for (std::map<std::string, int>::iterator it = map.begin(); it != map.end(); 
+         ++it) {
+        fFilter.addItem((it->first).c_str());
+    }
 
     // NOTE(chudy): Makes first item unselectable.
     QStandardItemModel* model = qobject_cast<QStandardItemModel*>(
diff --git a/debugger/QT/SkDebuggerGUI.h b/debugger/QT/SkDebuggerGUI.h
index 570ebdb..09e7f70 100644
--- a/debugger/QT/SkDebuggerGUI.h
+++ b/debugger/QT/SkDebuggerGUI.h
@@ -35,6 +35,11 @@
 #include <QtGui/QMenuBar>
 #include <vector>
 
+class SkTimedPicture;
+namespace sk_tools {
+    class PictureRenderer;
+}
+
 /** \class SkDebuggerGUI
 
     Container for the UI and it's functions.
@@ -286,18 +291,31 @@
     /**
         Populates the list widget with the vector of strings passed in.
      */
-    void setupListWidget(SkTDArray<SkString*>* command);
+    void setupListWidget(SkTArray<SkString>* command);
 
     /**
         Populates the combo box widget with the vector of strings passed in.
      */
-    void setupComboBox(SkTDArray<SkString*>* command);
+    void setupComboBox(SkTArray<SkString>* command);
+
+    /**
+        Fills in the overview pane with text
+     */
+    void setupOverviewText(const SkTDArray<double>* typeTimes, double totTime);
 
     /**
         Updates the directory widget with the latest directory path stored in
         the global class variable fPath.
      */
     void setupDirectoryWidget();
+
+    /**
+        Render the supplied picture several times tracking the time consumed
+        by each command.
+     */
+    void run(SkTimedPicture* pict, 
+             sk_tools::PictureRenderer* renderer, 
+             int repeats);
 };
 
 #endif // SKDEBUGGERUI_H
diff --git a/debugger/SkDebugCanvas.cpp b/debugger/SkDebugCanvas.cpp
index b970bb9..f6c8082 100644
--- a/debugger/SkDebugCanvas.cpp
+++ b/debugger/SkDebugCanvas.cpp
@@ -142,16 +142,16 @@
     return commandVector[index]->isVisible();
 }
 
-SkTDArray <SkDrawCommand*> SkDebugCanvas::getDrawCommands() {
+const SkTDArray <SkDrawCommand*>& SkDebugCanvas::getDrawCommands() const {
     return commandVector;
 }
 
 // TODO(chudy): Free command string memory.
-SkTDArray<SkString*>* SkDebugCanvas::getDrawCommandsAsStrings() {
-    SkTDArray<SkString*>* commandString = new SkTDArray<SkString*>();
+SkTArray<SkString>* SkDebugCanvas::getDrawCommandsAsStrings() const {
+    SkTArray<SkString>* commandString = new SkTArray<SkString>(commandVector.count());
     if (!commandVector.isEmpty()) {
         for (int i = 0; i < commandVector.count(); i ++) {
-            commandString->push(new SkString(commandVector[i]->toString()));
+            commandString->push_back() = commandVector[i]->toString();
         }
     }
     return commandString;
diff --git a/debugger/SkDebugCanvas.h b/debugger/SkDebugCanvas.h
index 5172bc2..1eeada2 100644
--- a/debugger/SkDebugCanvas.h
+++ b/debugger/SkDebugCanvas.h
@@ -13,7 +13,7 @@
 #include "SkCanvas.h"
 #include "SkDrawCommand.h"
 #include "SkPicture.h"
-#include "SkTDArray.h"
+#include "SkTArray.h"
 #include "SkString.h"
 
 class SkDebugCanvas : public SkCanvas {
@@ -85,12 +85,12 @@
     /**
         Returns the vector of draw commands
      */
-    SkTDArray<SkDrawCommand*> getDrawCommands();
+    const SkTDArray<SkDrawCommand*>& getDrawCommands() const;
 
     /**
      * Returns the string vector of draw commands
      */
-    SkTDArray<SkString*>* getDrawCommandsAsStrings();
+    SkTArray<SkString>* getDrawCommandsAsStrings() const;
 
     /**
         Returns length of draw command vector.
diff --git a/debugger/SkDebugger.h b/debugger/SkDebugger.h
index 67fa6a0..a0a1682 100644
--- a/debugger/SkDebugger.h
+++ b/debugger/SkDebugger.h
@@ -12,6 +12,7 @@
 
 #include "SkDebugCanvas.h"
 #include "SkPicture.h"
+#include "SkTArray.h"
 
 class SkDebugger {
 public:
@@ -41,10 +42,14 @@
         fDebugCanvas->toggleCommand(index, isVisible);
     }
 
-    SkTDArray<SkString*>* getDrawCommands() {
+    SkTArray<SkString>* getDrawCommandsAsStrings() {
         return fDebugCanvas->getDrawCommandsAsStrings();
     }
 
+    const SkTDArray<SkDrawCommand*>& getDrawCommands() const {
+        return fDebugCanvas->getDrawCommands();
+    }
+
     void highlightCurrentCommand(bool on) {
         fDebugCanvas->toggleFilter(on);
     }
diff --git a/debugger/SkDrawCommand.h b/debugger/SkDrawCommand.h
index 3334209..54fbf9e 100644
--- a/debugger/SkDrawCommand.h
+++ b/debugger/SkDrawCommand.h
@@ -37,13 +37,14 @@
     virtual void execute(SkCanvas* canvas)=0;
     DrawType getType() { return fDrawType; };
 
+    static const char* GetCommandString(DrawType type);
+
 protected:
     DrawType fDrawType;
     SkTDArray<SkString*> fInfo;
 
 private:
     bool fVisible;
-    static const char* GetCommandString(DrawType type);
 };
 
 class Restore : public SkDrawCommand {
diff --git a/gyp/debugger.gyp b/gyp/debugger.gyp
index d39a7b2..3d44cbc 100644
--- a/gyp/debugger.gyp
+++ b/gyp/debugger.gyp
@@ -109,14 +109,6 @@
         '../debugger/QT/SkRasterWidget.h',
         '../debugger/QT/SkRasterWidget.cpp',
 
-        '../tools/PictureBenchmark.h',
-        '../tools/PictureBenchmark.cpp',
-
-        '../bench/SkBenchLogger.h',
-        '../bench/SkBenchLogger.cpp',
-        '../bench/TimerData.h',
-        '../bench/TimerData.cpp',
-
         # To update this file edit SkIcons.qrc and rerun rcc to generate cpp
         '../debugger/QT/qrc_SkIcons.cpp',