From 8a1cdaece7e1d009befb84f21bb82370025bf4d6 Mon Sep 17 00:00:00 2001 From: "robertphillips@google.com" Date: Mon, 19 Nov 2012 20:44:29 +0000 Subject: [PATCH] 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 --- debugger/QT/SkDebuggerGUI.cpp | 209 +++++++++++++++++++++++++++------- debugger/QT/SkDebuggerGUI.h | 22 +++- debugger/SkDebugCanvas.cpp | 8 +- debugger/SkDebugCanvas.h | 6 +- debugger/SkDebugger.h | 7 +- debugger/SkDrawCommand.h | 3 +- gyp/debugger.gyp | 8 -- 7 files changed, 206 insertions(+), 57 deletions(-) diff --git a/debugger/QT/SkDebuggerGUI.cpp b/debugger/QT/SkDebuggerGUI.cpp index e7be72da88..3b9b8aaefb 100644 --- a/debugger/QT/SkDebuggerGUI.cpp +++ b/debugger/QT/SkDebuggerGUI.cpp @@ -9,9 +9,7 @@ #include "SkGraphics.h" #include "SkImageDecoder.h" #include -#include "PictureBenchmark.h" #include "PictureRenderer.h" -#include "SkBenchLogger.h" #include "SkPictureRecord.h" #include "SkPicturePlayback.h" #include "BenchTimer.h" @@ -138,21 +136,36 @@ public: , 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* typeTimes() const { return &fTypeTimes; } + + double totTime() const { return fTot; } + protected: BenchTimer fTimer; SkTDArray fOffsets; // offset in the SkPicture for each command SkTDArray fTimes; // sum of time consumed for each command + SkTDArray 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 @@ protected: } 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 @@ protected: 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 @@ public: } } + 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* 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 @@ void SkDebuggerGUI::actionProfile() { 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 @@ void SkDebuggerGUI::actionProfile() { item->setData(Qt::UserRole + 4, 100.0*temp); } + + setupOverviewText(picture.typeTimes(), picture.totTime()); } void SkDebuggerGUI::actionCancel() { @@ -825,6 +893,11 @@ public: } 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 @@ void SkDebuggerGUI::loadPicture(const SkString& fileName) { SkSafeUnref(picture); // Will this automatically clear out due to nature of refcnt? - SkTDArray* commands = fDebugger.getDrawCommands(); + SkTArray* commands = fDebugger.getDrawCommandsAsStrings(); // If SkPicturePlayback is compiled w/o SK_PICTURE_PROFILING_STUBS // the offset count will always be zero @@ -863,6 +936,7 @@ void SkDebuggerGUI::loadPicture(const SkString& fileName) { setupListWidget(commands); setupComboBox(commands); + setupOverviewText(NULL, 0.0); fInspectorWidget.setDisabled(false); fSettingsWidget.setDisabled(false); fMenuEdit.setDisabled(false); @@ -874,23 +948,23 @@ void SkDebuggerGUI::loadPicture(const SkString& fileName) { actionPlay(); } -void SkDebuggerGUI::setupListWidget(SkTDArray* command) { +void SkDebuggerGUI::setupListWidget(SkTArray* 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::setupListWidget(SkTDArray* command) { } } -void SkDebuggerGUI::setupComboBox(SkTDArray* command) { - fFilter.clear(); - fFilter.addItem("--Filter By Available Commands--"); +void SkDebuggerGUI::setupOverviewText(const SkTDArray* typeTimes, double totTime) { - std::map map; - for (int i = 0; i < command->count(); i++) { - map[(*command)[i]->c_str()]++; + const SkTDArray& commands = fDebugger.getDrawCommands(); + + SkTDArray 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::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("
"); - 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("
"); - 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("
"); + } + + QString totalStr; + totalStr.append("Total Draw Commands: "); + totalStr.append(QString::number(total)); + totalStr.append("
"); + overview.insert(0, totalStr); overview.append("
"); overview.append("SkPicture Width: "); @@ -935,6 +1053,21 @@ void SkDebuggerGUI::setupComboBox(SkTDArray* command) { overview.append(QString::number(fDebugger.pictureHeight())); overview.append("px"); fInspectorWidget.setText(overview, SkInspectorWidget::kOverview_TabType); +} + +void SkDebuggerGUI::setupComboBox(SkTArray* command) { + fFilter.clear(); + fFilter.addItem("--Filter By Available Commands--"); + + std::map map; + for (int i = 0; i < command->count(); i++) { + map[(*command)[i].c_str()]++; + } + + for (std::map::iterator it = map.begin(); it != map.end(); + ++it) { + fFilter.addItem((it->first).c_str()); + } // NOTE(chudy): Makes first item unselectable. QStandardItemModel* model = qobject_cast( diff --git a/debugger/QT/SkDebuggerGUI.h b/debugger/QT/SkDebuggerGUI.h index 570ebdbf12..09e7f70216 100644 --- a/debugger/QT/SkDebuggerGUI.h +++ b/debugger/QT/SkDebuggerGUI.h @@ -35,6 +35,11 @@ #include #include +class SkTimedPicture; +namespace sk_tools { + class PictureRenderer; +} + /** \class SkDebuggerGUI Container for the UI and it's functions. @@ -286,18 +291,31 @@ private: /** Populates the list widget with the vector of strings passed in. */ - void setupListWidget(SkTDArray* command); + void setupListWidget(SkTArray* command); /** Populates the combo box widget with the vector of strings passed in. */ - void setupComboBox(SkTDArray* command); + void setupComboBox(SkTArray* command); + + /** + Fills in the overview pane with text + */ + void setupOverviewText(const SkTDArray* 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 b970bb940b..f6c8082c2d 100644 --- a/debugger/SkDebugCanvas.cpp +++ b/debugger/SkDebugCanvas.cpp @@ -142,16 +142,16 @@ bool SkDebugCanvas::getDrawCommandVisibilityAt(int index) { return commandVector[index]->isVisible(); } -SkTDArray SkDebugCanvas::getDrawCommands() { +const SkTDArray & SkDebugCanvas::getDrawCommands() const { return commandVector; } // TODO(chudy): Free command string memory. -SkTDArray* SkDebugCanvas::getDrawCommandsAsStrings() { - SkTDArray* commandString = new SkTDArray(); +SkTArray* SkDebugCanvas::getDrawCommandsAsStrings() const { + SkTArray* commandString = new SkTArray(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 5172bc23f5..1eeada2697 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 @@ public: /** Returns the vector of draw commands */ - SkTDArray getDrawCommands(); + const SkTDArray& getDrawCommands() const; /** * Returns the string vector of draw commands */ - SkTDArray* getDrawCommandsAsStrings(); + SkTArray* getDrawCommandsAsStrings() const; /** Returns length of draw command vector. diff --git a/debugger/SkDebugger.h b/debugger/SkDebugger.h index 67fa6a0f5e..a0a1682ba7 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 @@ public: fDebugCanvas->toggleCommand(index, isVisible); } - SkTDArray* getDrawCommands() { + SkTArray* getDrawCommandsAsStrings() { return fDebugCanvas->getDrawCommandsAsStrings(); } + const SkTDArray& getDrawCommands() const { + return fDebugCanvas->getDrawCommands(); + } + void highlightCurrentCommand(bool on) { fDebugCanvas->toggleFilter(on); } diff --git a/debugger/SkDrawCommand.h b/debugger/SkDrawCommand.h index 3334209bd0..54fbf9ee15 100644 --- a/debugger/SkDrawCommand.h +++ b/debugger/SkDrawCommand.h @@ -37,13 +37,14 @@ public: virtual void execute(SkCanvas* canvas)=0; DrawType getType() { return fDrawType; }; + static const char* GetCommandString(DrawType type); + protected: DrawType fDrawType; SkTDArray 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 d39a7b2df3..3d44cbc3ff 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',