DM: tweak output.

Show task name in verbose mode only, and add task runtime.

BUG=skia:
R=reed@google.com, bsalomon@google.com, mtklein@google.com

Author: mtklein@chromium.org

Review URL: https://codereview.chromium.org/185233004

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

4 files changed, 17 insertions, 4 deletions

diff --git a/dm/DMReporter.cpp b/dm/DMReporter.cpp
index fb925abf7b..4bb25d349d 100644
--- a/dm/DMReporter.cpp
+++ b/dm/DMReporter.cpp
@@ -8,7 +8,7 @@ DEFINE_bool2(verbose, v, false, "If true, print status updates one-per-line.");
 
 namespace DM {
 
-void Reporter::finish(SkString name) {
+void Reporter::finish(SkString name, SkMSec timeMs) {
     sk_atomic_inc(&fFinished);
 
     if (FLAGS_quiet) {
@@ -23,7 +23,9 @@ void Reporter::finish(SkString name) {
     if (failed > 0) {
         status.appendf(", %d failed", failed);
     }
-    status.appendf("\t[%s done]", name.c_str());
+    if (FLAGS_verbose) {
+        status.appendf("\t%5dms %s", timeMs, name.c_str());
+    }
     SkDebugf("%s", status.c_str());
 }
 
diff --git a/dm/DMReporter.h b/dm/DMReporter.h
index 2bb4702178..3f8e953a71 100644
--- a/dm/DMReporter.h
+++ b/dm/DMReporter.h
@@ -4,6 +4,7 @@
 #include "SkString.h"
 #include "SkTArray.h"
 #include "SkThread.h"
+#include "SkTime.h"
 #include "SkTypes.h"
 
 // Used to report status changes including failures.  All public methods are threadsafe.
@@ -14,7 +15,7 @@ public:
     Reporter() : fStarted(0), fFinished(0) {}
 
     void start()  { sk_atomic_inc(&fStarted); }
-    void finish(SkString name);
+    void finish(SkString name, SkMSec timeMs);
     void fail(SkString msg);
 
     int32_t started()  const { return fStarted; }
diff --git a/dm/DMTask.cpp b/dm/DMTask.cpp
index 1c4cc25693..419463a5b4 100644
--- a/dm/DMTask.cpp
+++ b/dm/DMTask.cpp
@@ -25,8 +25,12 @@ void Task::fail(const char* msg) {
     fReporter->fail(failure);
 }
 
+void Task::start() {
+    fStart = SkTime::GetMSecs();
+}
+
 void Task::finish() {
-    fReporter->finish(this->name());
+    fReporter->finish(this->name(), SkTime::GetMSecs() - fStart);
 }
 
 void Task::spawnChild(CpuTask* task) {
@@ -37,6 +41,7 @@ CpuTask::CpuTask(Reporter* reporter, TaskRunner* taskRunner) : Task(reporter, ta
 CpuTask::CpuTask(const Task& parent) : Task(parent) {}
 
 void CpuTask::run() {
+    this->start();
     if (!this->shouldSkip()) {
         this->draw();
     }
@@ -47,6 +52,7 @@ void CpuTask::run() {
 GpuTask::GpuTask(Reporter* reporter, TaskRunner* taskRunner) : Task(reporter, taskRunner) {}
 
 void GpuTask::run(GrContextFactory& factory) {
+    this->start();
     if (!this->shouldSkip()) {
         this->draw(&factory);
     }
diff --git a/dm/DMTask.h b/dm/DMTask.h
index cad8234c05..4baac44982 100644
--- a/dm/DMTask.h
+++ b/dm/DMTask.h
@@ -4,6 +4,7 @@
 #include "DMReporter.h"
 #include "GrContextFactory.h"
 #include "SkRunnable.h"
+#include "SkTime.h"
 
 // DM will run() these tasks on one of two threadpools.
 // Subclasses can call fail() to mark this task as failed, or make any number of spawnChild() calls
@@ -31,14 +32,17 @@ protected:
     Task(const Task& parent);
     virtual ~Task() {}
 
+    void start();
     void fail(const char* msg = NULL);
     void finish();
+
     void spawnChild(CpuTask* task);  // For now we don't allow GPU child tasks.
 
 private:
     Reporter* fReporter;      // Unowned.
     TaskRunner* fTaskRunner;  // Unowned.
     int fDepth;
+    SkMSec fStart;
 };
 
 class CpuTask : public Task, public SkRunnable {