introduce a Context object for logging start/stop events

subiquity/controllers/tests/test_filesystem.py

@@ -15,6 +15,7 @@
 
 import unittest
 
+from subiquitycore.context import Context
 from subiquity.controllers.filesystem import (
     FilesystemController,
     )
@@ -35,15 +36,19 @@ class Thing:
 
 class MiniApplication:
     ui = signal = loop = None
+    project = "mini"
     answers = {}
     opts = Thing()
     opts.dry_run = True
     opts.bootloader = None
+    def report_start_event(*args): pass
+    def report_finish_event(*args): pass
 
 
 def make_controller(bootloader=None):
     app = MiniApplication()
     app.base_model = bm = Thing()
+    app.context = Context.new(app)
     bm.filesystem = make_model(bootloader)
     controller = FilesystemController(app)
     return controller

subiquitycore/context.py

@@ -0,0 +1,97 @@
+# Copyright 2019 Canonical, Ltd.
+#
+# This program is free software: you can redistribute it and/or modify
+# it under the terms of the GNU Affero General Public License as
+# published by the Free Software Foundation, either version 3 of the
+# License, or (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU Affero General Public License for more details.
+#
+# You should have received a copy of the GNU Affero General Public License
+# along with this program.  If not, see <http://www.gnu.org/licenses/>.
+
+import asyncio
+import enum
+
+
+class Status(enum.Enum):
+    SUCCESS = enum.auto()
+    FAIL = enum.auto()
+    WARN = enum.auto()
+
+
+class Context:
+    """Class to report when things start and finish.
+
+    The expected way to use this is something like:
+
+    with somecontext.child("operation"):
+        await long_running_operation()
+
+    but you can also call .enter() and .exit() if use as a context
+    manager isn't possible.
+
+    start and finish events are reported via the report_start_event and
+    report_finish_event methods on app.
+
+    You can override the message shown on exit by passing it to the .exit
+    method or by assigning to description:
+
+    with somecontext.child("operation") as context:
+        result = await long_running_operation()
+        context.description = "result was {}".format(result)
+    """
+
+    def __init__(self, app, name, description, parent, level):
+        self.app = app
+        self.name = name
+        self.description = description
+        self.parent = parent
+        self.level = level
+
+    @classmethod
+    def new(self, app):
+        return Context(app, app.project, "", None, "INFO")
+
+    def child(self, name, description="", level=None):
+        if level is None:
+            level = self.level
+        return Context(self.app, name, description, self, level)
+
+    def _name(self):
+        c = self
+        names = []
+        while c is not None:
+            names.append(c.name)
+            c = c.parent
+        return '/'.join(reversed(names))
+
+    def enter(self, description=None):
+        if description is None:
+            description = self.description
+        self.app.report_start_event(self._name(), description, self.level)
+
+    def exit(self, description=None, result=Status.SUCCESS):
+        if description is None:
+            description = self.description
+        self.app.report_finish_event(
+            self._name(), description, result, self.level)
+
+    def __enter__(self):
+        self.enter()
+        return self
+
+    def __exit__(self, exc, value, tb):
+        if exc is not None:
+            result = Status.FAIL
+            if isinstance(value, asyncio.CancelledError):
+                description = "cancelled"
+            else:
+                description = str(value)
+        else:
+            result = Status.SUCCESS
+            description = None
+        self.exit(description, result)

subiquitycore/controller.py

@@ -36,6 +36,7 @@ class BaseController(ABC):
         self.opts = app.opts
         self.loop = app.loop
         self.app = app
+        self.context = self.app.context.child(self.name)
         self.answers = app.answers.get(self.name, {})
         if self.model_name is not None:
             self.model = getattr(self.app.base_model, self.model_name)
@@ -143,6 +144,7 @@ class RepeatedController(BaseController):
         self.name = "{}-{}".format(orig.name, index)
         self.orig = orig
         self.index = index
+        self.context = orig.context
 
     def register_signals(self):
         pass

subiquitycore/core.py

@@ -25,6 +25,9 @@ import urwid
 import yaml
 
 from subiquitycore.async_helpers import schedule_task
+from subiquitycore.context import (
+    Context,
+    )
 from subiquitycore.controller import (
     RepeatedController,
     Skip,
@@ -385,6 +388,7 @@ class Application:
         self.prober = prober
         self.loop = None
         self.controllers = ControllerSet(self, self.controllers)
+        self.context = Context.new(self)
 
     def run_command_in_foreground(self, cmd, before_hook=None, after_hook=None,
                                   **kw):
@@ -476,6 +480,17 @@ class Application:
         self.controllers.index = controller_index - 1
         self.next_screen()
 
+    def report_start_event(self, name, description, level):
+        # See context.py for what calls these.
+        log = logging.getLogger(name)
+        level = getattr(logging, level)
+        log.log(level, "start: %s", description)
+
+    def report_finish_event(self, name, description, status, level):
+        log = logging.getLogger(name)
+        level = getattr(logging, level)
+        log.log(level, "finish: %s %s", description, status.name)
+
 # EventLoop -------------------------------------------------------------------
 
     def exit(self):