don't run Eventlogging by default -- the tests instantiate it, though.

python/src/deltachat/__init__.py

@@ -1,4 +1,4 @@
-from . import capi, const
+from . import capi, const, hookspec
 from .capi import ffi
 from .account import Account  # noqa
 
@@ -74,3 +74,8 @@ def get_dc_event_name(integer, _DC_EVENTNAME_MAP={}):
             if name.startswith("DC_EVENT_"):
                 _DC_EVENTNAME_MAP[val] = name
     return _DC_EVENTNAME_MAP[integer]
+
+
+def register_global_plugin(plugin):
+    gm = hookspect.Global._get_plugin_manager()
+    gm.register(plugin)

python/src/deltachat/account.py

@@ -14,29 +14,20 @@ from .cutil import as_dc_charpointer, from_dc_charpointer, iter_array, DCLot
 from .chat import Chat
 from .message import Message
 from .contact import Contact
-from . import eventlogger
 from .tracker import ImexTracker
 from . import hookspec
 
 
-hookspec.Global._get_plugin_manager().register(eventlogger)
-
-
 class Account(object):
     """ Each account is tied to a sqlite database file which is fully managed
     by the underlying deltachat core library.  All public Account methods are
     meant to be memory-safe and return memory-safe objects.
     """
-    # to prevent garbled logging
+    def __init__(self, db_path, os_name=None):
-    _loglock = threading.RLock()
-
-    def __init__(self, db_path, logid=None, os_name=None):
         """ initialize account object.
 
         :param db_path: a path to the account database. The database
                         will be created if it doesn't exist.
-        :param logid: an optional logging prefix that should be used with
-                      the default internal logging.
         :param os_name: this will be put to the X-Mailer header in outgoing messages
         """
         # initialize per-account plugin system
@@ -49,9 +40,9 @@ class Account(object):
         )
 
         hook = hookspec.Global._get_plugin_manager().hook
-        hook.at_account_init(account=self, db_path=db_path, logid=logid)
+        hook.at_account_init(account=self, db_path=db_path)
 
-        self._threads = IOThreads(self._dc_context)
+        self._threads = IOThreads(self)
 
         # send all FFI events for this account to a plugin hook
         def _ll_event(ctx, evt_name, data1, data2):
@@ -86,13 +77,7 @@ class Account(object):
     #    self.shutdown()
 
     def log_line(self, msg):
-        t = threading.currentThread()
+        self._pm.hook.log_line(message=msg)
-        tname = getattr(t, "name", t)
-        if tname == "MainThread":
-            tname = "MAIN"
-        with self._loglock:
-            print("{:2.2f} [{}-{}] {}".format(time.time() - self._evlogger.init_time,
-                  tname, self._evlogger.logid, msg))
 
     def _check_config_key(self, name):
         if name not in self._configkeys:
@@ -537,7 +522,6 @@ class Account(object):
             deltachat.clear_context_callback(self._dc_context)
             del self._dc_context
             atexit.unregister(self.shutdown)
-            self._pm.unregister(self._evlogger)
 
     def set_location(self, latitude=0.0, longitude=0.0, accuracy=0.0):
         """set a new location. It effects all chats where we currently
@@ -562,11 +546,11 @@ class Account(object):
 
 
 class IOThreads:
-    def __init__(self, dc_context, log_event=lambda *args: None):
+    def __init__(self, account):
-        self._dc_context = dc_context
+        self.account = account
+        self._dc_context = account._dc_context
         self._thread_quitflag = False
         self._name2thread = {}
-        self._log_event = log_event
 
     def is_started(self):
         return len(self._name2thread) > 0
@@ -587,6 +571,12 @@ class IOThreads:
         t.setDaemon(1)
         t.start()
 
+    @contextmanager
+    def log_execution(self, message):
+        self.account.log_line(message + " START")
+        yield
+        self.account.log_line(message + " FINISHED")
+
     def stop(self, wait=False):
         self._thread_quitflag = True
 
@@ -603,42 +593,38 @@ class IOThreads:
                 thread.join()
 
     def imap_thread_run(self):
-        self._log_event("py-bindings-info", 0, "INBOX THREAD START")
+        with self.log_execution("INBOX THREAD START"):
-        while not self._thread_quitflag:
+            while not self._thread_quitflag:
-            lib.dc_perform_imap_jobs(self._dc_context)
+                lib.dc_perform_imap_jobs(self._dc_context)
-            if not self._thread_quitflag:
+                if not self._thread_quitflag:
-                lib.dc_perform_imap_fetch(self._dc_context)
+                    lib.dc_perform_imap_fetch(self._dc_context)
-            if not self._thread_quitflag:
+                if not self._thread_quitflag:
-                lib.dc_perform_imap_idle(self._dc_context)
+                    lib.dc_perform_imap_idle(self._dc_context)
-        self._log_event("py-bindings-info", 0, "INBOX THREAD FINISHED")
 
     def mvbox_thread_run(self):
-        self._log_event("py-bindings-info", 0, "MVBOX THREAD START")
+        with self.log_execution("MVBOX THREAD"):
-        while not self._thread_quitflag:
+            while not self._thread_quitflag:
-            lib.dc_perform_mvbox_jobs(self._dc_context)
+                lib.dc_perform_mvbox_jobs(self._dc_context)
-            if not self._thread_quitflag:
+                if not self._thread_quitflag:
-                lib.dc_perform_mvbox_fetch(self._dc_context)
+                    lib.dc_perform_mvbox_fetch(self._dc_context)
-            if not self._thread_quitflag:
+                if not self._thread_quitflag:
-                lib.dc_perform_mvbox_idle(self._dc_context)
+                    lib.dc_perform_mvbox_idle(self._dc_context)
-        self._log_event("py-bindings-info", 0, "MVBOX THREAD FINISHED")
 
     def sentbox_thread_run(self):
-        self._log_event("py-bindings-info", 0, "SENTBOX THREAD START")
+        with self.log_execution("SENTBOX THREAD"):
-        while not self._thread_quitflag:
+            while not self._thread_quitflag:
-            lib.dc_perform_sentbox_jobs(self._dc_context)
+                lib.dc_perform_sentbox_jobs(self._dc_context)
-            if not self._thread_quitflag:
+                if not self._thread_quitflag:
-                lib.dc_perform_sentbox_fetch(self._dc_context)
+                    lib.dc_perform_sentbox_fetch(self._dc_context)
-            if not self._thread_quitflag:
+                if not self._thread_quitflag:
-                lib.dc_perform_sentbox_idle(self._dc_context)
+                    lib.dc_perform_sentbox_idle(self._dc_context)
-        self._log_event("py-bindings-info", 0, "SENTBOX THREAD FINISHED")
 
     def smtp_thread_run(self):
-        self._log_event("py-bindings-info", 0, "SMTP THREAD START")
+        with self.log_execution("SMTP THREAD"):
-        while not self._thread_quitflag:
+            while not self._thread_quitflag:
-            lib.dc_perform_smtp_jobs(self._dc_context)
+                lib.dc_perform_smtp_jobs(self._dc_context)
-            if not self._thread_quitflag:
+                if not self._thread_quitflag:
-                lib.dc_perform_smtp_idle(self._dc_context)
+                    lib.dc_perform_smtp_idle(self._dc_context)
-        self._log_event("py-bindings-info", 0, "SMTP THREAD FINISHED")
 
 
 def _destroy_dc_context(dc_context, dc_context_unref=lib.dc_context_unref):

python/src/deltachat/eventlogger.py

@@ -1,17 +1,21 @@
+import threading
 import time
 from .hookspec import account_hookimpl, global_hookimpl
 
 
-@global_hookimpl
+class FFIEventLogger:
-def at_account_init(account, logid):
+    """ If you register an instance of this logger with an Account
-    account._evlogger = account.add_account_plugin(EventLogger(account, logid=logid))
+    you'll get all ffi-events printed.
+    """
+    # to prevent garbled logging
+    _loglock = threading.RLock()
 
-
+    def __init__(self, account, logid):
-class EventLogger:
+        """
-    def __init__(self, account, logid=None):
+        :param logid: an optional logging prefix that should be used with
+                      the default internal logging.
+        """
         self.account = account
-        if logid is None:
-            logid = str(self.account._dc_context).strip(">").split()[-1]
         self.logid = logid
         self.init_time = time.time()
 
@@ -25,3 +29,16 @@ class EventLogger:
             return
         evpart = "{}({!r},{!r})".format(evt_name, data1, data2)
         self.account.log_line(evpart)
+
+    @account_hookimpl
+    def log_line(self, message):
+        t = threading.currentThread()
+        tname = getattr(t, "name", t)
+        if tname == "MainThread":
+            tname = "MAIN"
+        with self._loglock:
+            print("{:2.2f} [{}-{}] {}".format(
+                time.time() - self.init_time,
+                tname,
+                self.logid,
+                message))

python/src/deltachat/hookspec.py

@@ -27,6 +27,10 @@ class PerAccount:
     def process_low_level_event(self, event_name, data1, data2):
         """ process a CFFI low level events for a given account. """
 
+    @account_hookspec
+    def log_line(self, message):
+        """ log a message related to the account. """
+
     @account_hookspec
     def configure_completed(self, success):
         """ Called when a configure process completed. """
@@ -47,5 +51,5 @@ class Global:
         return cls._plugin_manager
 
     @global_hookspec
-    def at_account_init(self, account, logid):
+    def at_account_init(self, account):
         """ called when `Account::__init__()` function starts executing. """

python/tests/conftest.py

@@ -9,6 +9,7 @@ from deltachat import Account
 from deltachat.tracker import ConfigureTracker
 from deltachat import const
 from deltachat.capi import lib
+from deltachat.eventlogger import FFIEventLogger
 from _pytest.monkeypatch import MonkeyPatch
 from ffi_event import FFIEventTracker
 import tempfile
@@ -164,9 +165,10 @@ def acfactory(pytestconfig, tmpdir, request, session_liveconfig, datadir):
                 fin()
 
         def make_account(self, path, logid):
-            ac = Account(path, logid=logid)
+            ac = Account(path)
             ac._evtracker = ac.add_account_plugin(FFIEventTracker(ac))
             ac._configtracker = ac.add_account_plugin(ConfigureTracker())
+            ac.add_account_plugin(FFIEventLogger(ac, logid=logid))
             self._finalizers.append(ac.shutdown)
             return ac