Swarming tasks: print start and end time

This will help determine how long each component of the task takes.

NOTRY=true
BUG=skia:4763
GOLD_TRYBOT_URL= https://gold.skia.org/search2?unt=true&query=source_type%3Dgm&master=false&issue=1769583002

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

4 files changed, 37 insertions, 8 deletions

diff --git a/infra/bots/compile_skia.py b/infra/bots/compile_skia.py
index ca2c7db600..2887461351 100644
--- a/infra/bots/compile_skia.py
+++ b/infra/bots/compile_skia.py
@@ -10,6 +10,7 @@ import argparse
 import common
 import os
 import sys
+import utils
 
 
 def main():
@@ -17,8 +18,9 @@ def main():
   parser.add_argument('--builder_name', required=True)
   parser.add_argument('--swarm_out_dir', required=True)
   args = parser.parse_args()
-  bot = common.BotInfo(args.builder_name, os.path.abspath(args.swarm_out_dir))
-  bot.compile_steps()
+  with utils.print_timings():
+    bot = common.BotInfo(args.builder_name, os.path.abspath(args.swarm_out_dir))
+    bot.compile_steps()
 
 
 if __name__ == '__main__':
diff --git a/infra/bots/perf_skia.py b/infra/bots/perf_skia.py
index 0e32feecca..f2568103ad 100644
--- a/infra/bots/perf_skia.py
+++ b/infra/bots/perf_skia.py
@@ -10,6 +10,7 @@ import argparse
 import common
 import os
 import sys
+import utils
 
 
 def main():
@@ -21,9 +22,10 @@ def main():
   parser.add_argument('--revision', required=True)
   parser.add_argument('--swarm_out_dir', required=True)
   args = parser.parse_args()
-  bot = common.BotInfo(args.builder_name, os.path.abspath(args.swarm_out_dir))
-  bot.perf_steps(args.revision, args.master_name, args.slave_name,
-                 args.build_number)
+  with utils.print_timings():
+    bot = common.BotInfo(args.builder_name, os.path.abspath(args.swarm_out_dir))
+    bot.perf_steps(args.revision, args.master_name, args.slave_name,
+                   args.build_number)
 
 
 if __name__ == '__main__':
diff --git a/infra/bots/test_skia.py b/infra/bots/test_skia.py
index 59992edd0e..d57fb7e37a 100644
--- a/infra/bots/test_skia.py
+++ b/infra/bots/test_skia.py
@@ -10,6 +10,7 @@ import argparse
 import common
 import os
 import sys
+import utils
 
 
 def main():
@@ -21,9 +22,10 @@ def main():
   parser.add_argument('--revision', required=True)
   parser.add_argument('--swarm_out_dir', required=True)
   args = parser.parse_args()
-  bot = common.BotInfo(args.builder_name, os.path.abspath(args.swarm_out_dir))
-  bot.test_steps(args.revision, args.master_name, args.slave_name,
-                 args.build_number)
+  with utils.print_timings():
+    bot = common.BotInfo(args.builder_name, os.path.abspath(args.swarm_out_dir))
+    bot.test_steps(args.revision, args.master_name, args.slave_name,
+                   args.build_number)
 
 
 if __name__ == '__main__':
diff --git a/infra/bots/utils.py b/infra/bots/utils.py
new file mode 100644
index 0000000000..ee648a26a4
--- /dev/null
+++ b/infra/bots/utils.py
@@ -0,0 +1,23 @@
+#!/usr/bin/env python
+#
+# Copyright 2016 Google Inc.
+#
+# Use of this source code is governed by a BSD-style license that can be
+# found in the LICENSE file.
+
+
+import datetime
+
+
+class print_timings(object):
+  def __init__(self):
+    self._start = None
+
+  def __enter__(self):
+    self._start = datetime.datetime.utcnow()
+    print 'Task started at %s GMT' % str(self._start)
+
+  def __exit__(self, t, v, tb):
+    finish = datetime.datetime.utcnow()
+    duration = (finish-self._start).total_seconds()
+    print 'Task finished at %s GMT (%f seconds)' % (str(finish), duration)