Add: timings for the major steps

1 files changed, 24 insertions, 0 deletions

diff --git a/contractor b/contractor
index 6168874..3653466 100755
--- a/contractor
+++ b/contractor
@@ -57,19 +57,24 @@ class ContractorApplication(cliapp.Application):
         self.output.write('{}\n'.format(json.dumps(bs.as_dict(), indent=4)))
 
     def cmd_build(self, args):
+        timer = Timer(self.verbose)
+
         self.verbose('building using spec at {}'.format(args[0]))
         bs = self.load_build_spec(args[0])
         m = self.manager()
+        timer.report('load-build-spec')
 
         # This might fail. We ignore the failure.
         self.verbose('stopping worker')
         m.kill_worker()
+        timer.report('kill-worker')
 
         self.verbose(
             'uploading image to worker: {}'.format(bs.worker_image()))
         if m.upload_worker_image(bs.worker_image()).failed():
             self.error('could not upload image to worker')
             sys.exit(1)
+        timer.report('upload-image')
 
         self.verbose('setting up workspace on worker')
         ws = bs.workspace()
@@ -77,12 +82,14 @@ class ContractorApplication(cliapp.Application):
         if m.setup_workspace(ws, source).failed():
             self.error('could not set up workspace')
             sys.exit(1)
+        timer.report('setup-workspace')
 
         self.verbose('starting worker')
         w = m.start_worker()
         if not w:
             self.error('could not start worker')
             sys.exit(1)
+        timer.report('start-worker')
 
         install = bs.install()
         if install:
@@ -93,19 +100,23 @@ class ContractorApplication(cliapp.Application):
                 sys.exit(1)
         else:
             self.verbose('no packages to install')
+        timer.report('install-packages')
 
         self.verbose('building')
         if w.build(bs.build()).failed():
             self.error('build failed')
             sys.exit(1)
+        timer.report('build')
 
         # This might fail. We ignore the failure.
         self.verbose('stopping worker')
         m.stop_worker()
+        timer.report('stop-worker')
 
         if ws:
             self.verbose('saving workspace to {}'.format(ws))
             m.save_workspace(ws)
+            timer.report('save-workspace')
 
         self.verbose('build finished OK')
 
@@ -431,4 +442,17 @@ class Worker:
         return self.ssh(['sh', '-euxc', shell_text])
 
 
+class Timer:
+
+    def __init__(self, report):
+        self._report = report
+        self._prev = time.time()
+
+    def report(self, msg):
+        now = time.time()
+        duration = now - self._prev
+        self._prev = now
+        self._report('time: {:.1f} s {}'.format(duration, msg))
+
+
 ContractorApplication().run()