Output sync timing

Modify the UI:acct and acctdone functions to keep tab of the time
inbetween. Put self.ui.acct() and acctdone() at the right places in
accounts.py so that the timing happens at the right places.

While modifying that loop, flatten the nested try: try: except: finally:
constructs, we require python 2.5 now which copes with that.

At the end of each account sync you will now see something like:
*** Finished account 'test' in 0:05

Signed-off-by: Sebastian Spaeth <Sebastian@SSpaeth.de>

Changelog.draft.rst

@@ -18,6 +18,8 @@ Changes
 
 * Indicate progress when copying many messages (slightly change log format)
 
+* Output how long an account sync took (min:sec).
+
 Bug Fixes
 ---------
 

offlineimap/accounts.py

@@ -1,5 +1,4 @@
-# Copyright (C) 2003 John Goerzen
+# Copyright (C) 2003-2011 John Goerzen & contributors
-# <jgoerzen@complete.org>
 #
 #    This program is free software; you can redistribute it and/or modify
 #    it under the terms of the GNU General Public License as published by
@@ -196,7 +195,6 @@ class SyncableAccount(Account):
 
     def syncrunner(self):
         self.ui.registerthread(self.name)
-        self.ui.acct(self.name)
         accountmetadata = self.getaccountmeta()
         if not os.path.exists(accountmetadata):
             os.mkdir(accountmetadata, 0700)            
@@ -208,7 +206,7 @@ class SyncableAccount(Account):
         # Loop account sync if needed (bail out after 3 failures)
         looping = 3
         while looping:
-            try:
+            self.ui.acct(self)
             try:
                 self.lock()
                 self.sync()
@@ -223,17 +221,17 @@ class SyncableAccount(Account):
                         raise
                 self.ui.error(e, exc_info()[2])
             except Exception, e:
-                    self.ui.error(e, msg = "While attempting to sync "
+                self.ui.error(e, exc_info()[2], msg = "While attempting to sync"
-                        "account %s:\n  %s"% (self, traceback.format_exc()))
+                    " account '%s'" % self)
             else:
                 # after success sync, reset the looping counter to 3
                 if self.refreshperiod:
                     looping = 3
             finally:
+                self.ui.acctdone(self)
                 self.unlock()
                 if looping and self.sleeper() >= 2:
                     looping = 0                    
-                self.ui.acctdone(self.name)
 
     def getaccountmeta(self):
         return os.path.join(self.metadatadir, 'Account-' + self.name)

offlineimap/ui/UIBase.py

@@ -1,6 +1,5 @@
 # UI base class
-# Copyright (C) 2002 John Goerzen
+# Copyright (C) 2002-2011 John Goerzen & contributors
-# <jgoerzen@complete.org>
 #
 #    This program is free software; you can redistribute it and/or modify
 #    it under the terms of the GNU General Public License as published by
@@ -48,6 +47,8 @@ class UIBase:
         s.debugmsglen = 50
         s.threadaccounts = {}
         """dict linking active threads (k) to account names (v)"""
+        s.acct_startimes = {}
+        """linking active accounts with the time.time() when sync started"""
         s.logfile = None
         s.exc_queue = Queue()
         """saves all occuring exceptions, so we can output them at the end"""
@@ -238,13 +239,18 @@ class UIBase:
             displaystr = '.'
         s._msg("Establishing connection" + displaystr)
 
-    def acct(s, accountname):
+    def acct(self, account):
-        if s.verbose >= 0:
+        """Output that we start syncing an account (and start counting)"""
-            s._msg("***** Processing account %s" % accountname)
+        self.acct_startimes[account] = time.time()
+        if self.verbose >= 0:
+            self._msg("*** Processing account %s" % account)
 
-    def acctdone(s, accountname):
+    def acctdone(self, account):
-        if s.verbose >= 0:
+        """Output that we finished syncing an account (in which time)"""
-            s._msg("***** Finished processing account " + accountname)
+        sec = time.time() - self.acct_startimes[account]
+        del self.acct_startimes[account]
+        self._msg("*** Finished account '%s' in %d:%02d" %
+               (account, sec // 60, sec % 60))
 
     def syncfolders(s, srcrepos, destrepos):
         if s.verbose >= 0: