Change the method for timing individual tiles in bench_pictures.

When timing individual tiles in bench_pictures, keep a timer running
across all repeats, and then take the average. The former method of
timing each iteration separately runs into precision errors on some
platforms.

Running on my Mac Pro with OSX 10.8, the cmsecs for the new method
and the old method are roughly the same when checking the CPU time.
When checking the wall time, the old method often gives me 0ms,
while the new method gives me a larger value. I don't think this
can be entirely attributed to rounding though, since on occasion I
see the old method showing a short time period (.05 - .15ms) while
the new method shows .15ms higher (which is in range for the
difference I'm seeing for other tiles where the old method reports
0ms).

Some other changes:
PictureRenderer::resetState now takes a boolean parameter. If called
with false, it will only do a flush, while if called with true, it
will also call finish.

resetState is now called with true everywhere except in between
iterations of drawing the same tile (when timing individual tiles).

render_pictures_main no longer calls resetState directly, since it
already calls end, which calls resetState.

BUG=http://code.google.com/p/skia/issues/detail?id=1066

Review URL: https://codereview.appspot.com/7101060

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

4 files changed, 54 insertions, 22 deletions

diff --git a/tools/PictureBenchmark.cpp b/tools/PictureBenchmark.cpp
index bdf1306101..f1be2aafeb 100644
--- a/tools/PictureBenchmark.cpp
+++ b/tools/PictureBenchmark.cpp
@@ -70,9 +70,8 @@ void PictureBenchmark::run(SkPicture* pict) {
     // We throw this away to remove first time effects (such as paging in this program)
     fRenderer->setup();
     fRenderer->render(NULL);
-    fRenderer->resetState();
+    fRenderer->resetState(true);
 
-    BenchTimer* timer = this->setupTimer();
     bool usingGpu = false;
 #if SK_SUPPORT_GPU
     usingGpu = fRenderer->isUsingGpuDevice();
@@ -95,26 +94,55 @@ void PictureBenchmark::run(SkPicture* pict) {
 
         int x, y;
         while (tiledRenderer->nextTile(x, y)) {
-            TimerData timerData(tiledRenderer->getPerIterTimeFormat(),
-                                tiledRenderer->getNormalTimeFormat());
+            // There are two timers, which will behave slightly differently:
+            // 1) longRunningTimer, along with perTileTimerData, will time how long it takes to draw
+            // one tile fRepeats times, and take the average. As such, it will not respect the
+            // logPerIter or printMin options, since it does not know the time per iteration. It
+            // will also be unable to call flush() for each tile.
+            // The goal of this timer is to make up for a system timer that is not precise enough to
+            // measure the small amount of time it takes to draw one tile once.
+            //
+            // 2) perTileTimer, along with perTileTimerData, will record each run separately, and
+            // then take the average. As such, it supports logPerIter and printMin options.
+            SkAutoTDelete<BenchTimer> longRunningTimer(this->setupTimer());
+            TimerData longRunningTimerData(tiledRenderer->getPerIterTimeFormat(),
+                                           tiledRenderer->getNormalTimeFormat());
+            SkAutoTDelete<BenchTimer> perTileTimer(this->setupTimer());
+            TimerData perTileTimerData(tiledRenderer->getPerIterTimeFormat(),
+                                       tiledRenderer->getNormalTimeFormat());
+            longRunningTimer->start();
             for (int i = 0; i < fRepeats; ++i) {
-                timer->start();
+                perTileTimer->start();
                 tiledRenderer->drawCurrentTile();
-                timer->truncatedEnd();
-                tiledRenderer->resetState();
-                timer->end();
-                timerData.appendTimes(timer, fRepeats - 1 == i);
+                perTileTimer->truncatedEnd();
+                tiledRenderer->resetState(false);
+                perTileTimer->end();
+                perTileTimerData.appendTimes(perTileTimer.get(), fRepeats - 1 == i);
             }
+            longRunningTimer->truncatedEnd();
+            tiledRenderer->resetState(true);
+            longRunningTimer->end();
+            longRunningTimerData.appendTimes(longRunningTimer.get(), true);
+
             SkString configName = tiledRenderer->getConfigName();
             configName.appendf(": tile [%i,%i] out of [%i,%i]", x, y, xTiles, yTiles);
-            SkString result = timerData.getResult(fLogPerIter, fPrintMin, fRepeats,
-                                                  configName.c_str(), fShowWallTime,
-                                                  fShowTruncatedWallTime, fShowCpuTime,
-                                                  fShowTruncatedCpuTime, usingGpu && fShowGpuTime);
+            SkString result = perTileTimerData.getResult(fLogPerIter, fPrintMin, fRepeats,
+                                                         configName.c_str(), fShowWallTime,
+                                                         fShowTruncatedWallTime, fShowCpuTime,
+                                                         fShowTruncatedCpuTime,
+                                                         usingGpu && fShowGpuTime);
             result.append("\n");
             this->logProgress(result.c_str());
+
+            configName.append(" <averaged>");
+            SkString longRunningResult = longRunningTimerData.getResult(false, false, fRepeats,
+                    configName.c_str(), fShowWallTime, fShowTruncatedWallTime,
+                    fShowCpuTime, fShowTruncatedCpuTime, usingGpu && fShowGpuTime);
+            longRunningResult.append("\n");
+            this->logProgress(longRunningResult.c_str());
         }
     } else {
+        SkAutoTDelete<BenchTimer> timer(this->setupTimer());
         TimerData timerData(fRenderer->getPerIterTimeFormat(), fRenderer->getNormalTimeFormat());
         for (int i = 0; i < fRepeats; ++i) {
             fRenderer->setup();
@@ -124,10 +152,10 @@ void PictureBenchmark::run(SkPicture* pict) {
             timer->truncatedEnd();
 
             // Finishes gl context
-            fRenderer->resetState();
+            fRenderer->resetState(true);
             timer->end();
 
-            timerData.appendTimes(timer, fRepeats - 1 == i);
+            timerData.appendTimes(timer.get(), fRepeats - 1 == i);
         }
 
         SkString configName = fRenderer->getConfigName();
@@ -140,7 +168,6 @@ void PictureBenchmark::run(SkPicture* pict) {
     }
 
     fRenderer->end();
-    SkDELETE(timer);
 }
 
 }
diff --git a/tools/PictureRenderer.cpp b/tools/PictureRenderer.cpp
index 762051cd08..cb2c3a44f8 100644
--- a/tools/PictureRenderer.cpp
+++ b/tools/PictureRenderer.cpp
@@ -131,7 +131,7 @@ void PictureRenderer::scaleToScaleFactor(SkCanvas* canvas) {
 }
 
 void PictureRenderer::end() {
-    this->resetState();
+    this->resetState(true);
     SkSafeUnref(fPicture);
     fPicture = NULL;
     fCanvas.reset(NULL);
@@ -172,7 +172,7 @@ void PictureRenderer::buildBBoxHierarchy() {
     }
 }
 
-void PictureRenderer::resetState() {
+void PictureRenderer::resetState(bool callFinish) {
 #if SK_SUPPORT_GPU
     if (this->isUsingGpuDevice()) {
         SkGLContext* glContext = fGrContextFactory.getGLContext(
@@ -184,7 +184,9 @@ void PictureRenderer::resetState() {
         }
 
         fGrContext->flush();
-        SK_GL(*glContext, Finish());
+        if (callFinish) {
+            SK_GL(*glContext, Finish());
+        }
     }
 #endif
 }
diff --git a/tools/PictureRenderer.h b/tools/PictureRenderer.h
index c310b9f413..df38faa3de 100644
--- a/tools/PictureRenderer.h
+++ b/tools/PictureRenderer.h
@@ -110,7 +110,12 @@ public:
      */
     virtual TiledPictureRenderer* getTiledRenderer() { return NULL; }
 
-    void resetState();
+    /**
+     * Resets the GPU's state. Does nothing if the backing is raster. For a GPU renderer, calls
+     * flush, and calls finish if callFinish is true.
+     * @param callFinish Whether to call finish.
+     */
+    void resetState(bool callFinish);
 
     void setDeviceType(SkDeviceTypes deviceType) {
         fDeviceType = deviceType;
diff --git a/tools/render_pictures_main.cpp b/tools/render_pictures_main.cpp
index 7b9efc5f0f..a459bf20a9 100644
--- a/tools/render_pictures_main.cpp
+++ b/tools/render_pictures_main.cpp
@@ -168,8 +168,6 @@ static bool render_picture(const SkString& inputPath, const SkString* outputDir,
         SkDELETE(outputPath);
     }
 
-    renderer.resetState();
-
     renderer.end();
 
     SkDELETE(picture);