pre-upload: warn whenever a hook is too slow

Bug: None
Test: added some slow hooks and reviewed the logged output
Change-Id: I19b024e995b564a12d929db2c5cf15a3e5a4a2b6
diff --git a/pre-upload.py b/pre-upload.py
index d9b1b1e..0e032f4 100755
--- a/pre-upload.py
+++ b/pre-upload.py
@@ -62,6 +62,9 @@
     FAILED = COLOR.color(COLOR.RED, 'FAILED')
     WARNING = COLOR.color(COLOR.YELLOW, 'WARNING')
 
+    # How long a hook is allowed to run before we warn that it is "too slow".
+    _SLOW_HOOK_DURATION = datetime.timedelta(seconds=30)
+
     def __init__(self, project_name):
         """Create a new Output object for a specified project.
 
@@ -73,6 +76,8 @@
         self.hook_index = 0
         self.success = True
         self.start_time = datetime.datetime.now()
+        self.hook_start_time = None
+        self._curr_hook_name = None
 
     def set_num_hooks(self, num_hooks):
         """Keep track of how many hooks we'll be running.
@@ -99,28 +104,38 @@
         Args:
           hook_name: name of the hook.
         """
+        self._curr_hook_name = hook_name
+        self.hook_start_time = datetime.datetime.now()
         status_line = '[%s %d/%d] %s' % (self.RUNNING, self.hook_index,
                                          self.num_hooks, hook_name)
         self.hook_index += 1
         rh.terminal.print_status_line(status_line)
 
-    def hook_error(self, hook_name, error):
+    def hook_finish(self):
+        """Finish processing any per-hook state."""
+        duration = datetime.datetime.now() - self.hook_start_time
+        if duration >= self._SLOW_HOOK_DURATION:
+            self.hook_warning(
+                'This hook took %s to finish which is fairly slow for '
+                'developers.\nPlease consider moving the check to the '
+                'server/CI system instead.' %
+                (rh.utils.timedelta_str(duration),))
+
+    def hook_error(self, error):
         """Print an error for a single hook.
 
         Args:
-          hook_name: name of the hook.
           error: error string.
         """
-        self.error(hook_name, error)
+        self.error(self._curr_hook_name, error)
 
-    def hook_warning(self, hook_name, warning):
+    def hook_warning(self, warning):
         """Print a warning for a single hook.
 
         Args:
-          hook_name: name of the hook.
           warning: warning string.
         """
-        status_line = '[%s] %s' % (self.WARNING, hook_name)
+        status_line = '[%s] %s' % (self.WARNING, self._curr_hook_name)
         rh.terminal.print_status_line(status_line, print_newline=True)
         print(warning, file=sys.stderr)
 
@@ -303,13 +318,14 @@
             if rel_proj_dir in exclusion_scope:
                 break
             hook_results = hook(project, commit, desc, diff)
+            output.hook_finish()
             (error, warning) = _process_hook_results(hook_results)
             if error is not None or warning is not None:
                 if warning is not None:
-                    output.hook_warning(name, warning)
+                    output.hook_warning(warning)
                 if error is not None:
                     ret = False
-                    output.hook_error(name, error)
+                    output.hook_error(error)
                 for result in hook_results:
                     if result.fixup_func:
                         fixup_func_list.append((name, commit,