[enh] Use Handler to write log

src/yunohost/app.py

@@ -422,6 +422,7 @@ def app_map(app=None, raw=False, user=None):
     return result
 
 
+@is_unit_operation()
 def app_change_url(auth, app, domain, path):
     """
     Modify the URL at which an application is installed.
@@ -433,7 +434,6 @@ def app_change_url(auth, app, domain, path):
 
     """
     from yunohost.hook import hook_exec, hook_callback
-    from yunohost.log import Journal
 
     installed = _is_installed(app)
     if not installed:
@@ -497,8 +497,7 @@ def app_change_url(auth, app, domain, path):
     os.system('chmod +x %s' % os.path.join(os.path.join(APP_TMP_FOLDER, "scripts")))
     os.system('chmod +x %s' % os.path.join(os.path.join(APP_TMP_FOLDER, "scripts", "change_url")))
 
-    journal = Journal(["change_url", app], "app", args=args_list, env=env_dict)
+    if hook_exec(os.path.join(APP_TMP_FOLDER, 'scripts/change_url'), args=args_list, env=env_dict, user="root") != 0:
-    if hook_exec(os.path.join(APP_TMP_FOLDER, 'scripts/change_url'), args=args_list, env=env_dict, user="root", journal=journal) != 0:
         logger.error("Failed to change '%s' url." % app)
 
         # restore values modified by app_checkurl
@@ -531,6 +530,7 @@ def app_change_url(auth, app, domain, path):
     hook_callback('post_app_change_url', args=args_list, env=env_dict)
 
 
+@is_unit_operation()
 def app_upgrade(auth, app=[], url=None, file=None):
     """
     Upgrade app
@@ -616,8 +616,7 @@ def app_upgrade(auth, app=[], url=None, file=None):
 
         # Execute App upgrade script
         os.system('chown -hR admin: %s' % INSTALL_TMP)
-        journal = Journal(["upgrade", app_instance_name], "app", args=args_list, env=env_dict)
+        if hook_exec(extracted_app_folder + '/scripts/upgrade', args=args_list, env=env_dict, user="root") != 0:
-        if hook_exec(extracted_app_folder + '/scripts/upgrade', args=args_list, env=env_dict, user="root", journal=journal) != 0:
             logger.error(m18n.n('app_upgrade_failed', app=app_instance_name))
         else:
             now = int(time.time())
@@ -660,8 +659,7 @@ def app_upgrade(auth, app=[], url=None, file=None):
     if is_api:
         return {"log": service_log('yunohost-api', number="100").values()[0]}
 
-
+def app_install(auth, app, label=None, args=None, no_remove_on_failure=False, **kwargs):
-def app_install(auth, app, label=None, args=None, no_remove_on_failure=False):
     """
     Install apps
 
@@ -673,7 +671,9 @@ def app_install(auth, app, label=None, args=None, no_remove_on_failure=False):
 
     """
     from yunohost.hook import hook_add, hook_remove, hook_exec, hook_callback
-    from yunohost.log import Journal
+    from yunohost.log import UnitOperationHandler
+
+    uo_install = UnitOperationHandler('app_install', 'app', args=kwargs)
 
     # Fetch or extract sources
     try:
@@ -762,11 +762,7 @@ def app_install(auth, app, label=None, args=None, no_remove_on_failure=False):
     try:
         install_retcode = hook_exec(
             os.path.join(extracted_app_folder, 'scripts/install'),
-            args=args_list, env=env_dict, user="root",
+            args=args_list, env=env_dict, user="root"
-            journal = Journal(
-                ["install", app_instance_name],
-                "app", args=args_list, env=env_dict
-            ),
         )
     except (KeyboardInterrupt, EOFError):
         install_retcode = -1
@@ -774,6 +770,7 @@ def app_install(auth, app, label=None, args=None, no_remove_on_failure=False):
         logger.exception(m18n.n('unexpected_error'))
     finally:
         if install_retcode != 0:
+            uo_install.close()
             if not no_remove_on_failure:
                 # Setup environment for remove script
                 env_dict_remove = {}
@@ -782,18 +779,19 @@ def app_install(auth, app, label=None, args=None, no_remove_on_failure=False):
                 env_dict_remove["YNH_APP_INSTANCE_NUMBER"] = str(instance_number)
 
                 # Execute remove script
+                uo_remove = UnitOperationHandler('remove_on_failed_install',
+                                                 'app', args=env_dict_remove)
+
                 remove_retcode = hook_exec(
                     os.path.join(extracted_app_folder, 'scripts/remove'),
-                    args=[app_instance_name], env=env_dict_remove, user="root",
+                    args=[app_instance_name], env=env_dict_remove, user="root"
-                    journal = Journal(
-                        ["remove", app_instance_name, "failed_install"],
-                        "app", args=[app_instance_name], env=env_dict_remove,
-                    ),
                 )
                 if remove_retcode != 0:
                     logger.warning(m18n.n('app_not_properly_removed',
                                           app=app_instance_name))
 
+                uo_remove.close()
+
             # Clean tmp folders
             shutil.rmtree(app_setting_path)
             shutil.rmtree(extracted_app_folder)
@@ -827,7 +825,10 @@ def app_install(auth, app, label=None, args=None, no_remove_on_failure=False):
 
     hook_callback('post_app_install', args=args_list, env=env_dict)
 
+    uo_install.close()
 
+
+@is_unit_operation()
 def app_remove(auth, app):
     """
     Remove app
@@ -863,8 +864,7 @@ def app_remove(auth, app):
     env_dict["YNH_APP_INSTANCE_NAME"] = app
     env_dict["YNH_APP_INSTANCE_NUMBER"] = str(app_instance_nb)
 
-    journal = Journal(["remove", app], "app", args=args_list, env=env_dict)
+    if hook_exec('/tmp/yunohost_remove/scripts/remove', args=args_list, env=env_dict, user="root") == 0:
-    if hook_exec('/tmp/yunohost_remove/scripts/remove', args=args_list, env=env_dict, user="root", journal=journal) == 0:
         logger.success(m18n.n('app_removed', app=app))
 
         hook_callback('post_app_remove', args=args_list, env=env_dict)

src/yunohost/hook.py

@@ -297,7 +297,7 @@ def hook_callback(action, hooks=[], args=None, no_trace=False, chdir=None,
 
 
 def hook_exec(path, args=None, raise_on_error=False, no_trace=False,
-              chdir=None, env=None, journal=None, user="admin"):
+              chdir=None, env=None, user="admin"):
     """
     Execute hook from a file with arguments
 
@@ -359,18 +359,6 @@ def hook_exec(path, args=None, raise_on_error=False, no_trace=False,
     else:
         logger.info(m18n.n('executing_script', script=path))
 
-    if journal is None:
-        # Define output callbacks and call command
-        callbacks = (
-            lambda l: logger.info(l.rstrip()),
-            lambda l: logger.warning(l.rstrip()),
-        )
-    else:
-        callbacks = journal.as_callbacks_tuple(
-            stdout=lambda l: logger.info(l.rstrip()),
-            stderr=lambda l: logger.warning(l.rstrip()),
-        )
-
     returncode = call_async_output(
         command, callbacks, shell=False, cwd=chdir
     )

src/yunohost/log.py

@@ -27,8 +27,11 @@
 import os
 import yaml
 import errno
+import logging
 
 from datetime import datetime
+from logging import StreamHandler, getLogger, Formatter
+from sys import exc_info
 
 from moulinette import m18n
 from moulinette.core import MoulinetteError
@@ -39,7 +42,6 @@ OPERATION_FILE_EXT = '.yml'
 
 logger = getActionLogger('yunohost.log')
 
-
 def log_list(limit=None):
     """
     List available logs
@@ -127,71 +129,105 @@ def log_display(file_name_list):
         result['operations'] = sorted(result['operations'], key=lambda operation: operation['started_at'])
         return result
 
-class Journal(object):
+def is_unit_operation(categorie=None, description_key=None):
-    def __init__(self, name, category, on_stdout=None, on_stderr=None, on_write=None, **kwargs):
+    def decorate(func):
+        def func_wrapper(*args, **kwargs):
+            cat = categorie
+            desc_key = description_key
+
+            if cat is None:
+                cat = func.__module__.split('.')[1]
+            if desc_key is None:
+                desc_key = func.__name__
+            uo = UnitOperationHandler(desc_key, cat, args=kwargs)
+            try:
+                result = func(*args, **kwargs)
+            finally:
+                uo.close(exc_info()[0])
+            return result
+        return func_wrapper
+    return decorate
+
+class UnitOperationHandler(StreamHandler):
+    def __init__(self, name, category, **kwargs):
         # TODO add a way to not save password on app installation
-        self.name = name
+        self._name = name
         self.category = category
         self.first_write = True
+        self.closed = False
 
         # this help uniformise file name and avoir threads concurrency errors
         self.started_at = datetime.now()
 
         self.path = os.path.join(OPERATIONS_PATH, category)
 
-        self.fd = None
+        if not os.path.exists(self.path):
+            os.makedirs(self.path)
 
-        self.on_stdout = [] if on_stdout is None else on_stdout
+        self.filename = "%s_%s" % (self.started_at.strftime("%F_%X").replace(":", "-"), self._name if isinstance(self._name, basestring) else "_".join(self._name))
-        self.on_stderr = [] if on_stderr is None else on_stderr
+        self.filename += OPERATION_FILE_EXT
-        self.on_write = [] if on_write is None else on_write
 
         self.additional_information = kwargs
 
-    def __del__(self):
+        logging.StreamHandler.__init__(self, self._open())
-        if self.fd:
-            self.fd.close()
 
-    def write(self, line):
+        self.formatter = Formatter('%(asctime)s: %(levelname)s - %(message)s')
+
+        if self.stream is None:
+            self.stream = self._open()
+
+        # Listen to the root logger
+        self.logger = getLogger('yunohost')
+        self.logger.addHandler(self)
+
+
+    def _open(self):
+        stream = open(os.path.join(self.path, self.filename), "w")
+        return stream
+
+    def close(self, error=None):
+        """
+        Closes the stream.
+        """
+        if self.closed:
+            return
+        self.acquire()
+        #self.ended_at = datetime.now()
+        #self.error = error
+        #self.stream.seek(0)
+        #context = {
+        #    'ended_at': datetime.now()
+        #}
+        #if error is not None:
+        #    context['error'] = error
+        #self.stream.write(yaml.safe_dump(context))
+        self.logger.removeHandler(self)
+        try:
+            if self.stream:
+                try:
+                    self.flush()
+                finally:
+                    stream = self.stream
+                    self.stream = None
+                    if hasattr(stream, "close"):
+                        stream.close()
+        finally:
+            self.release()
+            self.closed = True
+
+    def __del__(self):
+        self.close()
+
+    def emit(self, record):
         if self.first_write:
             self._do_first_write()
             self.first_write = False
 
-        self.fd.write("%s: " % datetime.now().strftime("%F %X"))
+        StreamHandler.emit(self, record)
-        self.fd.write(line.rstrip())
-        self.fd.write("\n")
-        self.fd.flush()
 
     def _do_first_write(self):
-        if not os.path.exists(self.path):
-            os.makedirs(self.path)
-
-        file_name = "%s_%s" % (self.started_at.strftime("%F_%X").replace(":", "-"), self.name if isinstance(self.name, basestring) else "_".join(self.name))
-        file_name += OPERATION_FILE_EXT
 
         serialized_additional_information = yaml.safe_dump(self.additional_information, default_flow_style=False)
 
-        self.fd = open(os.path.join(self.path, file_name), "w")
+        self.stream.write(serialized_additional_information)
-
+        self.stream.write("\n---\n")
-        self.fd.write(serialized_additional_information)
-        self.fd.write("\n---\n")
-
-    def stdout(self, line):
-        for i in self.on_stdout:
-            i(line)
-
-        self.write(line)
-
-    def stderr(self, line):
-        for i in self.on_stderr:
-            i(line)
-
-        self.write(line)
-
-    def as_callbacks_tuple(self, stdout=None, stderr=None):
-        if stdout:
-            self.on_stdout.append(stdout)
-
-        if stderr:
-            self.on_stderr.append(stderr)
-
-        return (self.stdout, self.stderr)

src/yunohost/service.py

@@ -38,6 +38,7 @@ from moulinette.core import MoulinetteError
 from moulinette.utils import log, filesystem
 
 from yunohost.hook import hook_callback
+from yunohost.log import is_unit_operation
 
 BASE_CONF_PATH = '/home/yunohost.conf'
 BACKUP_CONF_DIR = os.path.join(BASE_CONF_PATH, 'backup')
@@ -141,7 +142,7 @@ def service_stop(names):
                                       m18n.n('service_stop_failed', service=name))
             logger.info(m18n.n('service_already_stopped', service=name))
 
-
+@is_unit_operation()
 def service_enable(names):
     """
     Enable one or more services