Add JSON output option to bench.

bench/benchmain.cpp

 /*
  * Copyright 2011 Google Inc.
  *
  * Use of this source code is governed by a BSD-style license that can be
  * found in the LICENSE file.
  */
 
 #include "BenchTimer.h"
 #include "SkBenchLogger.h"
 #include "SkBenchmark.h"
 #include "SkBitmapDevice.h"
 #include "SkCanvas.h"
 #include "SkColorPriv.h"
 #include "SkCommandLineFlags.h"
 #include "SkDeferredCanvas.h"
 #include "SkGraphics.h"
 #include "SkImageEncoder.h"
 #include "SkOSFile.h"
 #include "SkPicture.h"
+#include "SkStream.h"
 #include "SkString.h"
 
 #if SK_SUPPORT_GPU
 #include "GrContext.h"
 #include "GrContextFactory.h"
 #include "GrRenderTarget.h"
 #include "SkGpuDevice.h"
 #include "gl/GrGLDefines.h"
 #else
 class GrContext;
 #endif // SK_SUPPORT_GPU
 
+#ifdef SK_BUILD_FOR_WIN

[bsalomon, 2013/11/22 20:36:30]

We have this same #ifdef stuff in several places, maybe we should have a header
somewhere that is just this block?

[jcgregorio, 2013/11/25 14:39:16]

Sure, how about include/utils/SkJSONCPP.h?

[bsalomon, 2013/11/25 15:28:33]

SGTM

[jcgregorio, 2013/11/25 16:06:47]

Done.

+    // json includes xlocale which generates warning 4530 because we're
+    // compiling without exceptions;
+    // see https://code.google.com/p/skia/issues/detail?id=1067
+    #pragma warning(push)
+    #pragma warning(disable : 4530)
+#endif
+#include "json/value.h"
+#ifdef SK_BUILD_FOR_WIN
+    #pragma warning(pop)
+#endif
+
 #include <limits>
 
 enum BenchMode {
     kNormal_BenchMode,
     kDeferred_BenchMode,
     kDeferredSilent_BenchMode,
     kRecord_BenchMode,
     kPictureRecord_BenchMode
 };
 const char* BenchMode_Name[] = {
     "normal", "deferred", "deferredSilent", "record", "picturerecord"
 };
 
 static const char kDefaultsConfigStr[] = "defaults";
 
 ///////////////////////////////////////////////////////////////////////////////
 
 static void erase(SkBitmap& bm) {
     if (bm.config() == SkBitmap::kA8_Config) {
         bm.eraseColor(SK_ColorTRANSPARENT);
     } else {
         bm.eraseColor(SK_ColorWHITE);
     }
 }
 
+// Base class for writing out the bench results.
+//
+// TODO(jcgregorio) Add info if tests fail to converge?
+class ResultsWriter : SkNoncopyable {
+public:
+    virtual ~ResultsWriter() {};
+    virtual void option(const char name[], const char value[]) = 0;
+    virtual void bench(const char name[], int32_t x, int32_t y) = 0;

[bsalomon, 2013/11/22 20:36:30]

maybe some short comments about how the caller uses these functions? It's not
totally clear what a valid call sequence is.

Would it make sense for the base class to have some asserts that calls are
correctly matched? (e.g. bench()/endBench())

[jcgregorio, 2013/11/25 14:39:16]

Done. Also, when writing the comments I realized I could drop the endBench()
call and make the interface a little simpler.

+    virtual void endBench() = 0;
+    virtual void config(const char name[]) = 0;
+    virtual void timer(const char name[], double ms) = 0;
+    virtual void end() = 0;
+};
+
+// This ResultsWriter handles writing out the human readable format of the
+// bench results.
+class LoggerResultsWriter : public ResultsWriter {

[bsalomon, 2013/11/22 20:36:30]

I don't know much about the logger but I'm wondering if it's functionality
should be subsumed by this class.

[jcgregorio, 2013/11/25 14:39:16]

The current logger also takes care of logging errors, which this interface
doesn't currently handle. Should I add handling for errors and completely
subsume the old interface?

On 2013/11/22 20:36:30, bsalomon wrote:

[bsalomon, 2013/11/25 15:28:33]

I don't know. I'm not really familiar with this. If no one else chimes in, then
I'd say ignore my comment. :)

[jcgregorio, 2013/11/25 16:06:47]

OK, ignoring for now.

+public:
+    explicit LoggerResultsWriter(SkBenchLogger& logger, const char* timeFormat)
+        : fLogger(logger)
+        , fTimeFormat(timeFormat)
+        , fFinishedOptions(false) {
+        fLogger.logProgress("skia bench:");
+    }
+    virtual void option(const char name[], const char value[]) {
+        fLogger.logProgress(SkStringPrintf(" %s=%s", name, value));
+    }
+    virtual void bench(const char name[], int32_t x, int32_t y) {
+        if (!fFinishedOptions) {
+          fLogger.logProgress("\n");
+          fFinishedOptions = true;
+        }
+        fLogger.logProgress(SkStringPrintf(
+            "running bench [%3d %3d] %040s", x, y, name));
+    }
+    virtual void endBench() {
+        fLogger.logProgress("\n");
+    }
+    virtual void config(const char name[]) {
+        fLogger.logProgress(SkStringPrintf("   %s:", name));
+    }
+    virtual void timer(const char name[], double ms) {
+        fLogger.logProgress(SkStringPrintf("  %s = ", name));
+        fLogger.logProgress(SkStringPrintf(fTimeFormat, ms));
+    }
+    virtual void end() {
+        fLogger.logProgress("\n");
+    }
+private:
+    SkBenchLogger& fLogger;
+    const char* fTimeFormat;
+    bool fFinishedOptions;
+};
+
+// This ResultsWriter handles writing out the results in JSON.
+//
+// The output looks like:
+//
+//  {
+//   "options" : {
+//      "alpha" : "0xFF",
+//      "scale" : "0",
+//      ...
+//      "system" : "UNIX"
+//   },
+//   "results" : {
+//      "Xfermode_Luminosity_640_480" : {
+//         "565" : {
+//            "cmsecs" : 143.188128906250,
+//            "msecs" : 143.835957031250
+//         },
+//         ...
+//
+class JSONResultsWriter : public ResultsWriter {
+public:
+    explicit JSONResultsWriter(const char filename[])
+        : fFilename(filename)
+        , fRoot()
+        , fResults(fRoot["results"])
+        , fBench(NULL)
+        , fConfig(NULL) {
+    }
+    virtual void option(const char name[], const char value[]) {
+        fRoot["options"][name] = value;
+    }
+    virtual void bench(const char name[], int32_t x, int32_t y) {
+        fBench = &fResults[SkStringPrintf( "%s_%d_%d", name, x, y).c_str()];
+    }
+    virtual void endBench() {
+    }
+    virtual void config(const char name[]) {
+        SkASSERT(NULL != fBench);
+        fConfig = &(*fBench)[name];
+    }
+    virtual void timer(const char name[], double ms) {
+        SkASSERT(NULL != fConfig);
+        (*fConfig)[name] = ms;
+    }
+    virtual void end() {
+        SkFILEWStream stream(fFilename.c_str());
+        stream.writeText(fRoot.toStyledString().c_str());
+        stream.flush();
+    }
+private:
+    SkString fFilename;
+    Json::Value fRoot;
+    Json::Value& fResults;
+    Json::Value* fBench;
+    Json::Value* fConfig;
+};
+
+// This ResultsWriter writes out to multiple ResultsWriters.
+class MultiResultsWriter : public ResultsWriter {
+public:
+    MultiResultsWriter() {
+    };
+    void add(ResultsWriter* writer) {
+      writers.push_back(writer);
+    }
+    virtual void option(const char name[], const char value[]) {
+        for (int i = 0; i < writers.count(); ++i) {
+            writers[i]->option(name, value);
+        }
+    }
+    virtual void bench(const char name[], int32_t x, int32_t y) {
+        for (int i = 0; i < writers.count(); ++i) {
+            writers[i]->bench(name, x, y);
+        }
+    }
+    virtual void endBench() {
+        for (int i = 0; i < writers.count(); ++i) {
+            writers[i]->endBench();
+        }
+    }
+    virtual void config(const char name[]) {
+        for (int i = 0; i < writers.count(); ++i) {
+            writers[i]->config(name);
+        }
+    }
+    virtual void timer(const char name[], double ms) {
+        for (int i = 0; i < writers.count(); ++i) {
+            writers[i]->timer(name, ms);
+        }
+    }
+    virtual void end() {
+        for (int i = 0; i < writers.count(); ++i) {
+            writers[i]->end();
+        }
+    }
+private:
+    SkTArray<ResultsWriter *> writers;
+};
+
 class Iter {
 public:
     Iter() : fBench(BenchRegistry::Head()) {}
 
     SkBenchmark* next() {
         if (fBench) {
             BenchRegistry::Factory f = fBench->factory();
             fBench = fBench->next();
             return f();
         }
@@ skipping 201 matching lines @@
 DEFINE_string(config, kDefaultsConfigStr,
               "Run configs given.  By default, runs the configs marked \"runByDefault\" in gConfigs.");
 DEFINE_string(logFile, "", "Also write stdout here.");
 DEFINE_int32(minMs, 20,  "Shortest time we'll allow a benchmark to run.");
 DEFINE_int32(maxMs, 4000, "Longest time we'll allow a benchmark to run.");
 DEFINE_double(error, 0.01,
               "Ratio of subsequent bench measurements must drop within 1±error to converge.");
 DEFINE_string(timeFormat, "%9.2f", "Format to print results, in milliseconds per 1000 loops.");
 DEFINE_bool2(verbose, v, false, "Print more.");
 DEFINE_string2(resourcePath, i, NULL, "directory for test resources.");
+DEFINE_string(outResultsFile, "", "If given, the results will be written to the file in JSON format.");
 
 // Has this bench converged?  First arguments are milliseconds / loop iteration,
 // last is overall runtime in milliseconds.
 static bool HasConverged(double prevPerLoop, double currPerLoop, double currRaw) {
     if (currRaw < FLAGS_minMs) {
         return false;
     }
     const double low = 1 - FLAGS_error, high = 1 + FLAGS_error;
     const double ratio = currPerLoop / prevPerLoop;
     return low < ratio && ratio < high;
 }
 
 int tool_main(int argc, char** argv);
 int tool_main(int argc, char** argv) {
 #if SK_ENABLE_INST_COUNT
     gPrintInstCount = true;
 #endif
     SkAutoGraphics ag;
     SkCommandLineFlags::Parse(argc, argv);
 
     // First, parse some flags.
-
     SkBenchLogger logger;
     if (FLAGS_logFile.count()) {
         logger.SetLogFile(FLAGS_logFile[0]);
     }
 
+    LoggerResultsWriter logWriter(logger, FLAGS_timeFormat[0]);
+    MultiResultsWriter writer;
+    writer.add(&logWriter);
+    JSONResultsWriter* jsonWriter = NULL;
+    if (FLAGS_outResultsFile.count()) {
+        jsonWriter = SkNEW(JSONResultsWriter(FLAGS_outResultsFile[0]));
+        writer.add(jsonWriter);
+    }
+
     const uint8_t alpha = FLAGS_forceBlend ? 0x80 : 0xFF;
     SkTriState::State dither = SkTriState::kDefault;
     for (size_t i = 0; i < 3; i++) {
         if (strcmp(SkTriState::Name[i], FLAGS_forceDither[0]) == 0) {
             dither = static_cast<SkTriState::State>(i);
         }
     }
 
     BenchMode benchMode = kNormal_BenchMode;
     for (size_t i = 0; i < SK_ARRAY_COUNT(BenchMode_Name); i++) {
@@ skipping 62 matching lines @@
             }
         }
     }
 #endif
 
     // All flags should be parsed now.  Report our settings.
     if (kIsDebug) {
         logger.logError("bench was built in Debug mode, so we're going to hide the times."
                         "  It's for your own good!\n");
     }
-    SkString str("skia bench:");
-    str.appendf(" mode=%s", FLAGS_mode[0]);
-    str.appendf(" alpha=0x%02X antialias=%d filter=%d dither=%s",
-                alpha, FLAGS_forceAA, FLAGS_forceFilter, SkTriState::Name[dither]);
-    str.appendf(" rotate=%d scale=%d clip=%d", FLAGS_rotate, FLAGS_scale, FLAGS_clip);
+    writer.option("mode", FLAGS_mode[0]);
+    writer.option("alpha", SkStringPrintf("0x%02X", alpha).c_str());
+    writer.option("antialias", SkStringPrintf("%d", FLAGS_forceAA).c_str());
+    writer.option("filter", SkStringPrintf("%d", FLAGS_forceFilter).c_str());
+    writer.option("dither",  SkTriState::Name[dither]);
+
+    writer.option("rotate", SkStringPrintf("%d", FLAGS_rotate).c_str());
+    writer.option("scale", SkStringPrintf("%d", FLAGS_scale).c_str());
+    writer.option("clip", SkStringPrintf("%d", FLAGS_clip).c_str());
 
 #if defined(SK_SCALAR_IS_FIXED)
-    str.append(" scalar=fixed");
+    writer.option("scalar", "fixed");
 #else
-    str.append(" scalar=float");
+    writer.option("scalar", "float");
 #endif
 
 #if defined(SK_BUILD_FOR_WIN32)
-    str.append(" system=WIN32");
+    writer.option("system", "WIN32");
 #elif defined(SK_BUILD_FOR_MAC)
-    str.append(" system=MAC");
+    writer.option("system", "MAC");
 #elif defined(SK_BUILD_FOR_ANDROID)
-    str.append(" system=ANDROID");
+    writer.option("system", "ANDROID");
 #elif defined(SK_BUILD_FOR_UNIX)
-    str.append(" system=UNIX");
+    writer.option("system", "UNIX");
 #else
-    str.append(" system=other");
+    writer.option("system", "other");
 #endif
 
 #if defined(SK_DEBUG)
-    str.append(" DEBUG");
+    writer.option("build", "DEBUG");
+#else
+    writer.option("build", "RELEASE");
 #endif
-    str.append("\n");
-    logger.logProgress(str);
-
 
     // Set texture cache limits if non-default.
     for (size_t i = 0; i < SK_ARRAY_COUNT(gConfigs); ++i) {
 #if SK_SUPPORT_GPU
         const Config& config = gConfigs[i];
         if (SkBenchmark::kGPU_Backend != config.backend) {
             continue;
         }
         GrContext* context = gContextFactory.get(config.contextType);
         if (NULL == context) {
             continue;
         }
 
         size_t bytes;
         int count;
         context->getTextureCacheLimits(&count, &bytes);
         if (-1 != FLAGS_gpuCacheBytes) {
             bytes = static_cast<size_t>(FLAGS_gpuCacheBytes);
         }
         if (-1 != FLAGS_gpuCacheCount) {
             count = FLAGS_gpuCacheCount;
         }
         context->setTextureCacheLimits(count, bytes);
 #endif
     }
 
-    // Find the longest name of the benches we're going to run to make the output pretty.
-    Iter names;
-    SkBenchmark* bench;
-    size_t longestName = 0;
-    while ((bench = names.next()) != NULL) {
-        SkAutoTUnref<SkBenchmark> benchUnref(bench);
-        if (SkCommandLineFlags::ShouldSkip(FLAGS_match, bench->getName())) {
-            continue;
-        }
-        const size_t length = strlen(bench->getName());
-        longestName = length > longestName ? length : longestName;
-    }
-
     // Run each bench in each configuration it supports and we asked for.
     Iter iter;
+    SkBenchmark* bench;
     while ((bench = iter.next()) != NULL) {
         SkAutoTUnref<SkBenchmark> benchUnref(bench);
         if (SkCommandLineFlags::ShouldSkip(FLAGS_match, bench->getName())) {
             continue;
         }
 
         bench->setForceAlpha(alpha);
         bench->setForceAA(FLAGS_forceAA);
         bench->setForceFilter(FLAGS_forceFilter);
         bench->setDither(dither);
@@ skipping 62 matching lines @@
 
             if (NULL != canvas) {
                 canvas->clear(SK_ColorWHITE);
                 if (FLAGS_clip)   {   performClip(canvas, dim.fX, dim.fY); }
                 if (FLAGS_scale)  {  performScale(canvas, dim.fX, dim.fY); }
                 if (FLAGS_rotate) { performRotate(canvas, dim.fX, dim.fY); }
             }
 
             if (!loggedBenchName) {
                 loggedBenchName = true;
-                SkString str;
-                str.printf("running bench [%3d %3d] %*s ",
-                           dim.fX, dim.fY, (int)longestName, bench->getName());
-                logger.logProgress(str);
+                writer.bench(bench->getName(), dim.fX, dim.fY);
             }
 
 #if SK_SUPPORT_GPU
             SkGLContextHelper* contextHelper = NULL;
             if (SkBenchmark::kGPU_Backend == config.backend) {
                 contextHelper = gContextFactory.getGLContext(config.contextType);
             }
             BenchTimer timer(contextHelper);
 #else
             BenchTimer timer;
@@ skipping 118 matching lines @@
             // Normalize to ms per 1000 iterations.
             const double normalize = 1000.0 / loopsPerIter;
             const struct { char shortName; const char* longName; double ms; } times[] = {
                 {'w', "msecs",  normalize * timer.fWall},
                 {'W', "Wmsecs", normalize * timer.fTruncatedWall},
                 {'c', "cmsecs", normalize * timer.fCpu},
                 {'C', "Cmsecs", normalize * timer.fTruncatedCpu},
                 {'g', "gmsecs", normalize * timer.fGpu},
             };
 
-            SkString result;
-            result.appendf("   %s:", config.name);
+            writer.config(config.name);
             for (size_t i = 0; i < SK_ARRAY_COUNT(times); i++) {
                 if (strchr(FLAGS_timers[0], times[i].shortName) && times[i].ms > 0) {
-                    result.appendf(" %s = ", times[i].longName);
-                    result.appendf(FLAGS_timeFormat[0], times[i].ms);
+                    writer.timer(times[i].longName, times[i].ms);
                 }
             }
-            logger.logProgress(result);
         }
         if (loggedBenchName) {
-            logger.logProgress("\n");
+            writer.endBench();
         }
     }
+    writer.end();
+    if (NULL != jsonWriter) {
+      SkDELETE(jsonWriter);

[bsalomon, 2013/11/22 20:36:30]

I don't think you need the NULL check.

[jcgregorio, 2013/11/25 14:39:16]

Done.

+    }
 #if SK_SUPPORT_GPU
     gContextFactory.destroyContexts();
 #endif
     return 0;
 }
 
 #if !defined(SK_BUILD_FOR_IOS) && !defined(SK_BUILD_FOR_NACL)
 int main(int argc, char * const argv[]) {
     return tool_main(argc, (char**) argv);
 }
 #endif