Log time to load mail lists from mailstore

1 files changed, 27 insertions, 1 deletions

diff --git a/service/pixelated/adapter/mailstore/leap_mailstore.py b/service/pixelated/adapter/mailstore/leap_mailstore.py
index e517ec4c..98758d1f 100644
--- a/service/pixelated/adapter/mailstore/leap_mailstore.py
+++ b/service/pixelated/adapter/mailstore/leap_mailstore.py
@@ -14,8 +14,10 @@
 # You should have received a copy of the GNU Affero General Public License
 # along with Pixelated. If not, see <http://www.gnu.org/licenses/>.
 import re
+import logging
+import time
 from email.header import decode_header
-from email.utils import parseaddr
+from functools import wraps
 from uuid import uuid4
 
 from leap.mail.adaptors.soledad import SoledadMailAdaptor
@@ -29,6 +31,9 @@ from pixelated.adapter.model.mail import Mail, InputMail
 from pixelated.support.functional import to_unicode
 
 
+log = logging.getLogger(__name__)
+
+
 class AttachmentInfo(object):
     def __init__(self, ident, name, encoding=None, ctype='application/octet-stream', size=0):
         self.ident = ident
@@ -188,6 +193,25 @@ def _extract_filename_from_name_header_part(header_value):
     return filename
 
 
+def log_time_deferred(f):
+
+    def log_time(result, start):
+        log.info('after callback: Needed %f ms to execute %s' % ((time.clock() - start), f))
+        return result
+
+    @wraps(f)
+    def wrapper(*args, **kwds):
+        start = time.clock()
+        result = f(*args, **kwds)
+        if isinstance(result, defer.Deferred):
+            result.addCallback(log_time, start=start)
+        else:
+            log.warn('No Deferred returned, perhaps need to re-order annotations?')
+        return result
+
+    return wrapper
+
+
 class LeapMailStore(MailStore):
     __slots__ = ('soledad')
 
@@ -204,6 +228,7 @@ class LeapMailStore(MailStore):
 
         defer.returnValue(leap_mail)
 
+    @log_time_deferred
     @defer.inlineCallbacks
     def get_mails(self, mail_ids, gracefully_ignore_errors=False, include_body=False):
         deferreds = []
@@ -224,6 +249,7 @@ class LeapMailStore(MailStore):
         message.get_wrapper().set_flags(tuple(mail.flags))
         yield self._update_mail(message)  # TODO assert this is yielded (otherwise asynchronous)
 
+    @log_time_deferred
     @defer.inlineCallbacks
     def all_mails(self, gracefully_ignore_errors=False):
         mdocs = yield self.soledad.get_from_index('by-type', 'meta')