Merge lp:~thumper/pqm/record-elapsed-time into lp:pqm

[Tim Penhey]

[Tim Penhey (thumper)]

I was only going to do merge and precommit hook, but it seemed better to do all of them.

I'm not entirely sure how to test this.

=== modified file 'pqm/__init__.py'
--- pqm/__init__.py 2007-11-29 21:40:54 +0000
+++ pqm/__init__.py 2008-06-16 02:49:46 +0000
@@ -21,6 +21,7 @@
 import cgi
 import config_manager
 from copy import copy
+from datetime import datetime
 import errno
 import logging
 import os
@@ -501,6 +502,12 @@
                                 ["Sender not authorised to commit to branch %s"
                                     % branch])

+ def _success_output(self, command_name, start_time):
+ """The success output strings with current and elapsed time."""
+ elapsed_time = datetime.now() - start_time
+ return ['\n', '%s succeeded at %s (%s)' % (
+ command_name, time.strftime('%c'), elapsed_time), '\n']
+
     def cleanup_wd(self):
         """Cleans up all possible working dirs."""
         self.log_with_status(logger, "cleaning working directory")
@@ -516,6 +523,8 @@
                 self.rm_rf(os.path.join(possible_dir, top))

     def do_merge(self, from_repo_revision, to_repo_revision, merge_name, merge_method, line):
+ # Record the start time for elapsed time calculation.
+ start_time = datetime.now()
         sender = self.script.getSender()
         # Star-merge
         self.check_target(to_repo_revision, line)
@@ -543,7 +552,7 @@
         os.chdir(origdir)
         self.log_with_status(logger, "success: %s", line)
         self.successful.append(line)
- self.output += ['\n', '%s succeeded at %s' % (merge_name, time.strftime('%c')), '\n']
+ self.output += self._success_output(merge_name, start_time)
         self.get_vcs().commit(sender, dir, self.commitmsg, to_repo_revision, config)

     def get_arch_impl(self):
@@ -862,6 +871,7 @@
         if not hook:
             hook = precommit_hook
         if hook:
+ start_time = datetime.now()
             logger.info("running precommit hook: %s" % (hook,))
             self.output.extend(['\n', 'Executing pre-commit hook %s at %s' % (hook, time.strftime('%c')), '\n'])
             child = self.run_in_dir(self.dir, popen2.Popen4, hook)
@@ -874,7 +884,7 @@
             if not ((ecode is None) or (ecode == 0)):
                 self.output.append('\npre-commit hook failed with error code %d at %s\n' % (ecode - 255, time.strftime('%c')))
                 raise PQMCmdFailure(self.sender, self.successful, self.line, self.output)
- self.output += ['\n', 'pre-commit hook succeeded at %s' % (time.strftime('%c')), '\n']
+ self.output += self._success_output('pre-commit hook', start_time)
         return self.successful, self.unrecognized, self.output

@@ -924,6 +934,7 @@
         for line in self.lines:
             self.run_command(line)
         if self.patch_content != []:
+ start_time = datetime.now()
             self.patch_target, config = self.getBranchConfig(self.patch_target)
             self.set_current_vcs(self.patch_target)
             self.validate_revision(self.patch_target)
@@ -951,7 +962,7 @@
             logger.info("executing patch")
             se...