util: Create a stopwatch to monitor how long some expensive functions take

Signed-off-by: Michael Tremer <michael.tremer@ipfire.org>

diff --git a/src/dnsbl/exporters.py b/src/dnsbl/exporters.py
index 504a72b19aeb0854913e529e73fe2d47844e4c97..60a4ece73990478b21681a75da1a980fd2f9925a 100644 (file)
--- a/src/dnsbl/exporters.py
+++ b/src/dnsbl/exporters.py
@@ -26,6 +26,9 @@ import dns.zone
 import io
 import tarfile
 
+from . import util
+from .i18n import _
+
 class Exporter(abc.ABC):
        """
                Abstract class to define an exporter
@@ -39,7 +42,9 @@ class Exporter(abc.ABC):
                        The main entry point to export something with this exporter...
                """
                # Export!
-               self.export(f, **kwargs)
+               with util.Stopwatch(_("Exporting %(name)s using %(exporter)s") % \
+                               { "name" : self.list.name, "exporter" : self.__class__.__name__ }):
+                       self.export(f, **kwargs)
 
        @abc.abstractmethod
        def export(self, f, **kwargs):

diff --git a/src/dnsbl/util.py b/src/dnsbl/util.py
index a418959a3b86ba98f5ce886f4428fc0694a015d6..0e828d1f1308406f03bc367ac09b3278ddb51db4 100644 (file)
--- a/src/dnsbl/util.py
+++ b/src/dnsbl/util.py
@@ -19,9 +19,43 @@
 ###############################################################################
 
 import idna
+import logging
 import re
+import time
 import unicodedata
 
+from .i18n import _
+
+# Setup logging
+log = logging.getLogger(__name__)
+
+class Stopwatch(object):
+       def __init__(self, task):
+               self.task = task
+
+               self.started_at = None
+               self.ended_at = None
+
+       def __enter__(self):
+               # Store the start time
+               self.started_at = time.perf_counter()
+
+               return self
+
+       def __exit__(self, type, value, traceback):
+               # Store the end time
+               self.ended_at = time.perf_counter()
+
+               # Compute how much time has elapsed
+               elapsed = self.ended_at - self.started_at
+
+               # Log the time
+               log.debug(_("%(task)s took %(time)s") % {
+                       "task" : self.task,
+                       "time" : ("%.0fs" % elapsed) if elapsed > 10 else ("%.2fms" % (elapsed * 1000)),
+               })
+
+
 def slugify(text, iteration=None):
        # Append the iteration
        if iteration: