nanobench: --veryVerbose for more Win7 debugging

bench/nanobench.cpp

 /*
  * Copyright 2014 Google Inc.
  *
  * Use of this source code is governed by a BSD-style license that can be
  * found in the LICENSE file.
  */
 
 #include <ctype.h>
 
 #include "Benchmark.h"
@@ skipping 36 matching lines @@
 
 DEFINE_bool(cpu, true, "Master switch for CPU-bound work.");
 DEFINE_bool(gpu, true, "Master switch for GPU-bound work.");
 
 DEFINE_string(outResultsFile, "", "If given, write results here as JSON.");
 DEFINE_bool(resetGpuContext, true, "Reset the GrContext before running each bench.");
 DEFINE_int32(maxCalibrationAttempts, 3,
              "Try up to this many times to guess loops for a bench, or skip the bench.");
 DEFINE_int32(maxLoops, 1000000, "Never run a bench more times than this.");
 
+DEFINE_bool2(veryVerbose, V, false, "Print lots for debugging bots.");
 
 static SkString humanize(double ms) {
     if (ms > 1e+3) return SkStringPrintf("%.3gs",  ms/1e3);
     if (ms < 1e-3) return SkStringPrintf("%.3gns", ms*1e6);
 #ifdef SK_BUILD_FOR_WIN
     if (ms < 1)    return SkStringPrintf("%.3gus", ms*1e3);
 #else
     if (ms < 1)    return SkStringPrintf("%.3gµs", ms*1e3);
 #endif
     return SkStringPrintf("%.3gms", ms);
 }
 #define HUMANIZE(ms) humanize(ms).c_str()
 
 static double time(int loops, Benchmark* bench, SkCanvas* canvas, SkGLContextHelper* gl) {
     WallTimer timer;
     timer.start();
     if (bench) {
+        if (FLAGS_veryVerbose) { SkDebugf("Timing %s for %d loops.\n", bench->getName(), loops); }
         bench->draw(loops, canvas);
     }
     if (canvas) {
         canvas->flush();
     }
 #if SK_SUPPORT_GPU
     if (gl) {
         SK_GL(*gl, Flush());
         gl->swapBuffers();
     }
@@ skipping 50 matching lines @@
     //  ------------------------------------------  < N
     //       bench_plus_overhead - overhead)
     //
     // Luckily, this also works well in practice. :)
     const double numer = overhead / FLAGS_overheadGoal - overhead;
     const double denom = bench_plus_overhead - overhead;
     const int loops = clamp_loops(FLAGS_runOnce ? 1 : (int)ceil(numer / denom));
 
     for (int i = 0; i < FLAGS_samples; i++) {
         samples[i] = time(loops, bench, canvas, NULL) / loops;
+        if (FLAGS_veryVerbose) { SkDebugf("  %s\n", HUMANIZE(samples[i])); }
     }
     return loops;
 }
 
 #if SK_SUPPORT_GPU
 static int gpu_bench(SkGLContextHelper* gl,
                      Benchmark* bench,
                      SkCanvas* canvas,
                      double* samples) {
     // Make sure we're done with whatever came before.
     SK_GL(*gl, Finish());
 
     // First, figure out how many loops it'll take to get a frame up to FLAGS_gpuMs.
     int loops = 1;
     if (!FLAGS_runOnce) {
         double elapsed = 0;
         do {
             loops *= 2;
             // If the GPU lets frames lag at all, we need to make sure we're timing
             // _this_ round, not still timing last round.  We force this by looping
             // more times than any reasonable GPU will allow frames to lag.
             for (int i = 0; i < FLAGS_gpuFrameLag; i++) {
                 elapsed = time(loops, bench, canvas, gl);
             }
         } while (elapsed < FLAGS_gpuMs);
 
         // We've overshot at least a little.  Scale back linearly.
         loops = (int)ceil(loops * FLAGS_gpuMs / elapsed);
 
+        if (FLAGS_veryVerbose) { SkDebugf("elapsed %s, loops %d\n", HUMANIZE(elapsed), loops); }
+
         // Might as well make sure we're not still timing our calibration.
         SK_GL(*gl, Finish());
     }
     loops = clamp_loops(loops);
 
     // Pretty much the same deal as the calibration: do some warmup to make
     // sure we're timing steady-state pipelined frames.
     for (int i = 0; i < FLAGS_gpuFrameLag; i++) {
         time(loops, bench, canvas, gl);
     }
 
     // Now, actually do the timing!
     for (int i = 0; i < FLAGS_samples; i++) {
         samples[i] = time(loops, bench, canvas, gl) / loops;
+        if (FLAGS_veryVerbose) { SkDebugf("  %s\n", HUMANIZE(samples[i])); }
     }
     return loops;
 }
 #endif
 
 static SkString to_lower(const char* str) {
     SkString lower(str);
     for (size_t i = 0; i < lower.size(); i++) {
         lower[i] = tolower(lower[i]);
     }
@@ skipping 138 matching lines @@
 
             const int loops =
 #if SK_SUPPORT_GPU
                 Benchmark::kGPU_Backend == targets[j]->backend
                 ? gpu_bench(targets[j]->gl, bench.get(), canvas, samples.get())
                 :
 #endif
                  cpu_bench(       overhead, bench.get(), canvas, samples.get());
 
             if (loops == 0) {
-                SkDebugf("Unable to time %s\t%s (overhead %s)\n",
-                         bench->getName(), config, HUMANIZE(overhead));
                 continue;
             }
 
             Stats stats(samples.get(), FLAGS_samples);
             log.config(config);
             log.timer("min_ms",    stats.min);
             log.timer("median_ms", stats.median);
             log.timer("mean_ms",   stats.mean);
             log.timer("max_ms",    stats.max);
             log.timer("stddev_ms", sqrt(stats.var));
@@ skipping 38 matching lines @@
     }
 
     return 0;
 }
 
 #if !defined SK_BUILD_FOR_IOS
 int main(int argc, char * const argv[]) {
     return tool_main(argc, (char**) argv);
 }
 #endif