You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@buildstream.apache.org by ro...@apache.org on 2020/12/29 13:29:16 UTC

[buildstream] branch early-logging created (now 44a4907)

This is an automated email from the ASF dual-hosted git repository.

root pushed a change to branch early-logging
in repository https://gitbox.apache.org/repos/asf/buildstream.git.


      at 44a4907  Adapting test cases to expect logs in stderr

This branch includes the following new commits:

     new fe65e79  _context.py: Added _timed_activity() method
     new 398ad63  plugin.py: Implement Plugin.timed_activity() using Context._timed_activity()
     new 69b793e  _pipeline.py: Removed tickers, use timed activities instead
     new 915bd43  _frontend: Enable logging right away
     new 1bd1948  _frontend: Send all logging materials to stderr
     new f522248  tests/testutils/runcli.py: Enhanced to capture stdout/stderr separately
     new 1feef7c  tests/testutils/site.py: Removed HAVE_ROOT
     new 44a4907  Adapting test cases to expect logs in stderr

The 8 revisions listed above as "new" are entirely new to this
repository and will be described in separate emails.  The revisions
listed as "add" were already present in the repository and have only
been added to this reference.



[buildstream] 06/08: tests/testutils/runcli.py: Enhanced to capture stdout/stderr separately

Posted by ro...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

root pushed a commit to branch early-logging
in repository https://gitbox.apache.org/repos/asf/buildstream.git

commit f522248cc8aa5539d037a035186617f2884343f1
Author: Tristan Van Berkom <tr...@codethink.co.uk>
AuthorDate: Wed Dec 13 11:21:41 2017 -0500

    tests/testutils/runcli.py: Enhanced to capture stdout/stderr separately
    
    We need this now in order to properly test the frontend and
    parse logs from stderr or output from stdout.
---
 tests/testutils/runcli.py | 75 ++++++++++++++++++++++++++++++++++++++++-------
 1 file changed, 64 insertions(+), 11 deletions(-)

diff --git a/tests/testutils/runcli.py b/tests/testutils/runcli.py
index ddcb4c0..fbc0380 100644
--- a/tests/testutils/runcli.py
+++ b/tests/testutils/runcli.py
@@ -5,10 +5,18 @@ import shutil
 import itertools
 import traceback
 from contextlib import contextmanager, ExitStack
-from click.testing import CliRunner
 from ruamel import yaml
 import pytest
 
+# XXX Using pytest private internals here
+#
+# We use pytest internals to capture the stdout/stderr during
+# a run of the buildstream CLI. We do this because click's
+# CliRunner convenience API (click.testing module) does not support
+# separation of stdout/stderr.
+#
+from _pytest.capture import MultiCapture, SysCapture
+
 from tests.testutils.site import IS_LINUX
 
 # Import the main cli entrypoint
@@ -22,18 +30,24 @@ from buildstream._exceptions import _get_last_exception
 # Wrapper for the click.testing result
 class Result():
 
-    def __init__(self, result):
-        self.exit_code = result.exit_code
-        self.output = result.output
+    def __init__(self,
+                 exit_code=None,
+                 exception=None,
+                 exc_info=None,
+                 output=None,
+                 stderr=None):
+        self.exit_code = exit_code
+        self.exc = exception
+        self.exc_info = exc_info
         self.exception = _get_last_exception()
-        self.result = result
+        self.output = output
+        self.stderr = stderr
 
     ##################################################################
     #                         Result parsers                         #
     ##################################################################
     def get_tracked_elements(self):
-        tracked = re.findall(r'\[track:(\S+)\s*]',
-                             self.result.output)
+        tracked = re.findall(r'\[track:(\S+)\s*]', self.stderr)
         if tracked is None:
             return []
 
@@ -45,7 +59,6 @@ class Cli():
     def __init__(self, directory, verbose=True):
         self.directory = directory
         self.config = None
-        self.cli_runner = CliRunner()
         self.verbose = verbose
 
     # configure():
@@ -118,19 +131,59 @@ class Cli():
             except ValueError:
                 sys.__stdout__ = open('/dev/stdout', 'w')
 
-            result = self.cli_runner.invoke(bst_cli, bst_args)
+            result = self.invoke(bst_cli, bst_args)
 
         # Some informative stdout we can observe when anything fails
         if self.verbose:
             command = "bst " + " ".join(bst_args)
             print("BuildStream exited with code {} for invocation:\n\t{}"
                   .format(result.exit_code, command))
-            print("Program output was:\n{}".format(result.output))
+            if result.output:
+                print("Program output was:\n{}".format(result.output))
+            if result.stderr:
+                print("Program stderr was:\n{}".format(result.stderr))
 
             if result.exc_info and result.exc_info[0] != SystemExit:
                 traceback.print_exception(*result.exc_info)
 
-        return Result(result)
+        return result
+
+    def invoke(self, cli, args=None, color=False, **extra):
+        exc_info = None
+        exception = None
+        exit_code = 0
+
+        capture = MultiCapture(Capture=SysCapture)
+        capture.start_capturing()
+
+        try:
+            cli.main(args=args or (), prog_name=cli.name, **extra)
+        except SystemExit as e:
+            if e.code != 0:
+                exception = e
+
+            exc_info = sys.exc_info()
+
+            exit_code = e.code
+            if not isinstance(exit_code, int):
+                sys.stdout.write(str(exit_code))
+                sys.stdout.write('\n')
+                exit_code = 1
+        except Exception as e:
+            exception = e
+            exit_code = -1
+            exc_info = sys.exc_info()
+        finally:
+            sys.stdout.flush()
+
+        out, err = capture.readouterr()
+        capture.stop_capturing()
+
+        return Result(exit_code=exit_code,
+                      exception=exception,
+                      exc_info=exc_info,
+                      output=out,
+                      stderr=err)
 
     # Fetch an element state by name by
     # invoking bst show on the project with the CLI


[buildstream] 04/08: _frontend: Enable logging right away

Posted by ro...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

root pushed a commit to branch early-logging
in repository https://gitbox.apache.org/repos/asf/buildstream.git

commit 915bd43b415103a8715f804064aa330423aa7428
Author: Tristan Van Berkom <tr...@codethink.co.uk>
AuthorDate: Tue Dec 12 18:53:24 2017 -0500

    _frontend: Enable logging right away
    
    Now we just assume that logging is turned on all the time, any
    messages must now always go through the central context messaging
    APIs.
---
 buildstream/_frontend/main.py   | 93 +----------------------------------------
 buildstream/_frontend/widget.py | 10 ++---
 2 files changed, 4 insertions(+), 99 deletions(-)

diff --git a/buildstream/_frontend/main.py b/buildstream/_frontend/main.py
index faef7e5..47bba1a 100644
--- a/buildstream/_frontend/main.py
+++ b/buildstream/_frontend/main.py
@@ -736,8 +736,6 @@ class App():
 
     def __init__(self, main_options):
         self.main_options = main_options
-        self.messaging_enabled = False
-        self.startup_messages = []
         self.logger = None
         self.status = None
         self.target = None
@@ -748,11 +746,6 @@ class App():
         self.scheduler = None
         self.pipeline = None
 
-        # For the initialization time tickers
-        self.file_count = 0
-        self.resolve_count = 0
-        self.cache_count = 0
-
         # Failure messages, hashed by unique plugin id
         self.fail_messages = {}
 
@@ -776,11 +769,6 @@ class App():
         # defaults to whether we are interactive or not.
         self.interactive_failures = self.interactive
 
-        # Early enable messaging in debug mode
-        if self.main_options['debug']:
-            click.echo("DEBUG: Early enablement of messages")
-            self.messaging_enabled = True
-
         # Resolve whether to use colors in output
         if self.main_options['colors'] is None:
             self.colors = self.is_a_tty
@@ -867,11 +855,7 @@ class App():
 
         try:
             self.pipeline = Pipeline(self.context, self.project, elements, except_,
-                                     rewritable=rewritable,
-                                     load_ticker=self.load_ticker,
-                                     resolve_ticker=self.resolve_ticker,
-                                     remote_ticker=self.remote_ticker,
-                                     cache_ticker=self.cache_ticker)
+                                     rewritable=rewritable)
         except BstError as e:
             click.echo("Error loading pipeline: {}".format(e))
             sys.exit(-1)
@@ -884,7 +868,6 @@ class App():
 
         # Pipeline is loaded, lets start displaying pipeline messages from tasks
         self.logger.size_request(self.pipeline)
-        self.messaging_enabled = True
 
         profile_end(Topics.LOAD_PIPELINE, "_".join(t.replace(os.sep, '-') for t in elements))
 
@@ -1052,11 +1035,6 @@ class App():
                                   styling=self.colors,
                                   deps=deps)
 
-        # Print any held messages from startup after printing the heading
-        for message in self.startup_messages:
-            self.message_handler(message, self.context)
-        self.startup_messages = []
-
     #
     # Print a summary of the queues
     #
@@ -1070,13 +1048,6 @@ class App():
     #
     def message_handler(self, message, context):
 
-        # Drop messages by default in the beginning while
-        # loading the pipeline, unless debug is specified.
-        if not self.messaging_enabled:
-            if message.message_type in unconditional_messages:
-                self.startup_messages.append(message)
-            return
-
         # Drop status messages from the UI if not verbose, we'll still see
         # info messages and status messages will still go to the log files.
         if not context.log_verbose and message.message_type == MessageType.STATUS:
@@ -1104,68 +1075,6 @@ class App():
         if self.main_options['log_file']:
             click.echo(text, file=self.main_options['log_file'], color=False, nl=False)
 
-    #
-    # Tickers at initialization time
-    #
-    def load_ticker(self, name):
-        if not self.context.log_verbose:
-            return
-
-        if name:
-            self.file_count += 1
-
-            if self.is_a_tty:
-                click.echo("Loading:   {:0>3}\r"
-                           .format(self.file_count), nl=False, err=True)
-            elif self.file_count == 1:
-                click.echo("Loading.", nl=False, err=True)
-            else:
-                click.echo(".", nl=False, err=True)
-        else:
-            click.echo('', err=True)
-
-    def resolve_ticker(self, name):
-        if not self.context.log_verbose:
-            return
-
-        if name:
-            self.resolve_count += 1
-
-            if self.is_a_tty:
-                click.echo("Resolving: {:0>3}/{:0>3}\r"
-                           .format(self.file_count, self.resolve_count), nl=False, err=True)
-            elif self.resolve_count == 1:
-                click.echo("Resolving {} elements."
-                           .format(self.file_count), nl=False, err=True)
-            else:
-                click.echo(".", nl=False, err=True)
-        else:
-            click.echo('', err=True)
-
-    def remote_ticker(self, name):
-        if not self.context.log_verbose:
-            return
-
-        click.echo("Fetching artifact list from {}".format(name), err=True)
-
-    def cache_ticker(self, name):
-        if not self.context.log_verbose:
-            return
-
-        if name:
-            self.cache_count += 1
-
-            if self.is_a_tty:
-                click.echo("Checking:  {:0>3}/{:0>3}\r"
-                           .format(self.file_count, self.cache_count), nl=False, err=True)
-            elif self.cache_count == 1:
-                click.echo("Checking {} elements."
-                           .format(self.file_count), nl=False, err=True)
-            else:
-                click.echo(".", nl=False, err=True)
-        else:
-            click.echo('', err=True)
-
     @contextmanager
     def interrupted(self):
         self.scheduler.disconnect_signals()
diff --git a/buildstream/_frontend/widget.py b/buildstream/_frontend/widget.py
index ccda68b..602105c 100644
--- a/buildstream/_frontend/widget.py
+++ b/buildstream/_frontend/widget.py
@@ -219,16 +219,12 @@ class CacheKey(Widget):
 
     def render(self, message):
 
-        # This can only happen when logging before initialization in debug mode
-        if not self.key_length:
-            return self.format_profile.fmt('[') + (' ' * 8) + self.format_profile.fmt(']')
-
-        missing = False
-        key = ' ' * self.key_length
         element_id = message.task_id or message.unique_id
-        if element_id is None:
+        if element_id is None or not self.key_length:
             return ""
 
+        missing = False
+        key = ' ' * self.key_length
         plugin = _plugin_lookup(element_id)
         if isinstance(plugin, Element):
             _, key, missing = plugin._get_full_display_key()


[buildstream] 05/08: _frontend: Send all logging materials to stderr

Posted by ro...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

root pushed a commit to branch early-logging
in repository https://gitbox.apache.org/repos/asf/buildstream.git

commit 1bd1948bdcc97cccca2d0e133be2426c4d1af084
Author: Tristan Van Berkom <tr...@codethink.co.uk>
AuthorDate: Wed Dec 13 11:17:50 2017 -0500

    _frontend: Send all logging materials to stderr
---
 buildstream/_frontend/main.py   | 86 ++++++++++++++++++++---------------------
 buildstream/_frontend/status.py | 10 ++---
 buildstream/_frontend/widget.py |  4 +-
 3 files changed, 50 insertions(+), 50 deletions(-)

diff --git a/buildstream/_frontend/main.py b/buildstream/_frontend/main.py
index 47bba1a..117d148 100644
--- a/buildstream/_frontend/main.py
+++ b/buildstream/_frontend/main.py
@@ -220,10 +220,10 @@ def build(app, elements, all, track, track_save, track_all, track_except):
     app.print_heading()
     try:
         app.pipeline.build(app.scheduler, all, track, track_save)
-        click.echo("")
+        click.echo("", err=True)
         app.print_summary()
     except PipelineError:
-        click.echo("")
+        click.echo("", err=True)
         app.print_summary()
         sys.exit(-1)
 
@@ -265,10 +265,10 @@ def fetch(app, elements, deps, track, except_):
         dependencies = app.pipeline.deps_elements(deps)
         app.print_heading(deps=dependencies)
         app.pipeline.fetch(app.scheduler, dependencies, track)
-        click.echo("")
+        click.echo("", err=True)
         app.print_summary()
     except PipelineError as e:
-        click.echo("{}".format(e))
+        click.echo("{}".format(e), err=True)
         app.print_summary()
         sys.exit(-1)
 
@@ -305,10 +305,10 @@ def track(app, elements, deps, except_):
         dependencies = app.pipeline.deps_elements(deps)
         app.print_heading(deps=dependencies)
         app.pipeline.track(app.scheduler, dependencies)
-        click.echo("")
+        click.echo("", err=True)
         app.print_summary()
     except PipelineError as e:
-        click.echo("{}".format(e))
+        click.echo("{}".format(e), err=True)
         app.print_summary()
         sys.exit(-1)
 
@@ -337,10 +337,10 @@ def pull(app, elements, deps):
     try:
         to_pull = app.pipeline.deps_elements(deps)
         app.pipeline.pull(app.scheduler, to_pull)
-        click.echo("")
+        click.echo("", err=True)
     except BstError as e:
-        click.echo("")
-        click.echo("ERROR: {}".format(e))
+        click.echo("", err=True)
+        click.echo("ERROR: {}".format(e), err=True)
         sys.exit(-1)
 
 
@@ -368,10 +368,10 @@ def push(app, elements, deps):
     try:
         to_push = app.pipeline.deps_elements(deps)
         app.pipeline.push(app.scheduler, to_push)
-        click.echo("")
+        click.echo("", err=True)
     except BstError as e:
-        click.echo("")
-        click.echo("ERROR: {}".format(e))
+        click.echo("", err=True)
+        click.echo("ERROR: {}".format(e), err=True)
         sys.exit(-1)
 
 
@@ -448,7 +448,7 @@ def show(app, elements, deps, except_, order, format, downloadable):
     try:
         dependencies = app.pipeline.deps_elements(deps)
     except PipelineError as e:
-        click.echo("{}".format(e))
+        click.echo("{}".format(e), err=True)
         sys.exit(-1)
 
     if order == "alpha":
@@ -507,20 +507,20 @@ def shell(app, element, sysroot, build, command):
                 missing_deps.append(dep)
 
     if missing_deps:
-        click.echo("")
-        click.echo("Missing elements for staging an environment for a shell:")
+        click.echo("", err=True)
+        click.echo("Missing elements for staging an environment for a shell:", err=True)
         for dep in missing_deps:
-            click.echo("   {}".format(dep.name))
-        click.echo("")
-        click.echo("Try building them first")
+            click.echo("   {}".format(dep.name), err=True)
+        click.echo("", err=True)
+        click.echo("Try building them first", err=True)
         sys.exit(-1)
 
     try:
         exitcode = app.pipeline.targets[0]._shell(scope, sysroot, command=command)
         sys.exit(exitcode)
     except BstError as e:
-        click.echo("")
-        click.echo("Errors shelling into this pipeline: {}".format(e))
+        click.echo("", err=True)
+        click.echo("Errors shelling into this pipeline: {}".format(e), err=True)
         sys.exit(-1)
 
 
@@ -545,10 +545,10 @@ def checkout(app, element, directory, force, integrate, hardlinks):
     app.pipeline.initialize()
     try:
         app.pipeline.checkout(directory, force, integrate, hardlinks)
-        click.echo("")
+        click.echo("", err=True)
     except BstError as e:
         click.echo("")
-        click.echo("ERROR: {}".format(e))
+        click.echo("ERROR: {}".format(e), err=True)
         sys.exit(-1)
 
 
@@ -581,10 +581,10 @@ def source_bundle(app, target, force, directory,
         app.print_heading(dependencies)
         app.pipeline.source_bundle(app.scheduler, dependencies, force, track,
                                    compression, directory)
-        click.echo("")
+        click.echo("", err=True)
     except BstError as e:
-        click.echo("")
-        click.echo("ERROR: {}".format(e))
+        click.echo("", err=True)
+        click.echo("ERROR: {}".format(e), err=True)
         sys.exit(-1)
 
 
@@ -620,10 +620,10 @@ def workspace_open(app, no_checkout, force, source, track, element, directory):
     app.pipeline.initialize(inconsistent=[element])
     try:
         app.pipeline.open_workspace(app.scheduler, directory, source, no_checkout, track, force)
-        click.echo("")
+        click.echo("", err=True)
     except BstError as e:
-        click.echo("")
-        click.echo("ERROR: {}".format(e))
+        click.echo("", err=True)
+        click.echo("ERROR: {}".format(e), err=True)
         sys.exit(-1)
 
 
@@ -645,15 +645,15 @@ def workspace_close(app, source, remove_dir, element):
     app.pipeline.initialize()
     if app.interactive and remove_dir:
         if not click.confirm('This will remove all your changes, are you sure?'):
-            click.echo('Aborting')
+            click.echo('Aborting', err=True)
             sys.exit(-1)
 
     try:
         app.pipeline.close_workspace(source, remove_dir)
-        click.echo("")
+        click.echo("", err=True)
     except BstError as e:
-        click.echo("")
-        click.echo("ERROR: {}".format(e))
+        click.echo("", err=True)
+        click.echo("ERROR: {}".format(e), err=True)
         sys.exit(-1)
 
 
@@ -676,15 +676,15 @@ def workspace_reset(app, source, track, no_checkout, element):
     app.pipeline.initialize()
     if app.interactive:
         if not click.confirm('This will remove all your changes, are you sure?'):
-            click.echo('Aborting')
+            click.echo('Aborting', err=True)
             sys.exit(-1)
 
     try:
         app.pipeline.reset_workspace(app.scheduler, source, track, no_checkout)
-        click.echo("")
+        click.echo("", err=True)
     except BstError as e:
-        click.echo("")
-        click.echo("ERROR: {}".format(e))
+        click.echo("", err=True)
+        click.echo("ERROR: {}".format(e), err=True)
         sys.exit(-1)
 
 
@@ -703,13 +703,13 @@ def workspace_list(app):
         context = Context(app.main_options['option'])
         context.load(config)
     except BstError as e:
-        click.echo("Error loading user configuration: {}".format(e))
+        click.echo("Error loading user configuration: {}".format(e), err=True)
         sys.exit(-1)
 
     try:
         project = Project(directory, context)
     except BstError as e:
-        click.echo("Error loading project: {}".format(e))
+        click.echo("Error loading project: {}".format(e), err=True)
         sys.exit(-1)
 
     workspaces = []
@@ -792,7 +792,7 @@ class App():
             self.context = Context(self.main_options['option'])
             self.context.load(config)
         except BstError as e:
-            click.echo("Error loading user configuration: {}".format(e))
+            click.echo("Error loading user configuration: {}".format(e), err=True)
             sys.exit(-1)
 
         # Override things in the context from our command line options,
@@ -850,14 +850,14 @@ class App():
         try:
             self.project = Project(directory, self.context)
         except BstError as e:
-            click.echo("Error loading project: {}".format(e))
+            click.echo("Error loading project: {}".format(e), err=True)
             sys.exit(-1)
 
         try:
             self.pipeline = Pipeline(self.context, self.project, elements, except_,
                                      rewritable=rewritable)
         except BstError as e:
-            click.echo("Error loading pipeline: {}".format(e))
+            click.echo("Error loading pipeline: {}".format(e), err=True)
             sys.exit(-1)
 
         # Create our status printer, only available in interactive
@@ -947,7 +947,7 @@ class App():
                 self.status.clear()
                 click.echo("\n\n\nBUG: Message handling out of sync, " +
                            "unable to retrieve failure message for element {}\n\n\n\n\n"
-                           .format(element))
+                           .format(element), err=True)
             else:
                 self.handle_failure(element, queue, failure)
 
@@ -1066,7 +1066,7 @@ class App():
             self.status.clear()
 
         text = self.logger.render(message)
-        click.echo(text, color=self.colors, nl=False)
+        click.echo(text, color=self.colors, nl=False, err=True)
 
         # Maybe render the status area
         self.maybe_render_status()
diff --git a/buildstream/_frontend/status.py b/buildstream/_frontend/status.py
index caaa8a3..b899274 100644
--- a/buildstream/_frontend/status.py
+++ b/buildstream/_frontend/status.py
@@ -145,13 +145,13 @@ class Status():
         # feeds for the amount of lines we intend to print first, and
         # move cursor position back to the first line
         for _ in range(self.alloc_lines + self.header.lines):
-            click.echo('')
+            click.echo('', err=True)
         for _ in range(self.alloc_lines + self.header.lines):
             self.move_up()
 
         # Render the one line header
         text = self.header.render(self.term_width, elapsed)
-        click.echo(text, color=self.colors)
+        click.echo(text, color=self.colors, err=True)
 
         # Now we have the number of columns, and an allocation for
         # alignment of each column
@@ -167,7 +167,7 @@ class Status():
                     text += ' ' * self.spacing
 
             # Print the line
-            click.echo(text, color=self.colors)
+            click.echo(text, color=self.colors, err=True)
 
         # Track what we printed last, for the next clear
         self.last_lines = self.alloc_lines + self.header.lines
@@ -184,10 +184,10 @@ class Status():
     def move_up(self):
         # Explicitly move to beginning of line, fixes things up
         # when there was a ^C or ^Z printed to the terminal.
-        click.echo(self.term.move_x(0) + self.term.move_up, nl=False)
+        click.echo(self.term.move_x(0) + self.term.move_up, nl=False, err=True)
 
     def clear_line(self):
-        click.echo(self.term.clear_eol, nl=False)
+        click.echo(self.term.clear_eol, nl=False, err=True)
 
     def allocate(self):
         if not self.need_alloc:
diff --git a/buildstream/_frontend/widget.py b/buildstream/_frontend/widget.py
index 602105c..83befd3 100644
--- a/buildstream/_frontend/widget.py
+++ b/buildstream/_frontend/widget.py
@@ -475,7 +475,7 @@ class LogLine(Widget):
         # Separator line before following output
         text += self.format_profile.fmt("~" * 79 + '\n')
 
-        click.echo(text, color=styling, nl=False)
+        click.echo(text, color=styling, nl=False, err=True)
         if log_file:
             click.echo(text, file=log_file, color=False, nl=False)
 
@@ -525,7 +525,7 @@ class LogLine(Widget):
 
         text += self.format_values(values, style_value=False)
 
-        click.echo(text, color=styling, nl=False)
+        click.echo(text, color=styling, nl=False, err=True)
         if log_file:
             click.echo(text, file=log_file, color=False, nl=False)
 


[buildstream] 08/08: Adapting test cases to expect logs in stderr

Posted by ro...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

root pushed a commit to branch early-logging
in repository https://gitbox.apache.org/repos/asf/buildstream.git

commit 44a49070c07433c99e6d9745f61479a21bbc31fd
Author: Tristan Van Berkom <tr...@codethink.co.uk>
AuthorDate: Wed Dec 13 11:49:39 2017 -0500

    Adapting test cases to expect logs in stderr
    
    And also adapted them to remove any occurrences of HAVE_ROOT.
---
 tests/context/context.py     |  4 ----
 tests/frontend/buildtrack.py |  6 +++---
 tests/frontend/overlaps.py   |  6 +++---
 tests/frontend/show.py       | 10 ++++------
 tests/plugins/pipeline.py    | 14 +++++---------
 tests/project/plugins.py     | 10 +++++-----
 tests/sources/tar.py         |  2 +-
 tests/sources/zip.py         |  2 +-
 tests/variables/variables.py | 11 +++++------
 9 files changed, 27 insertions(+), 38 deletions(-)

diff --git a/tests/context/context.py b/tests/context/context.py
index 0db589a..442069b 100644
--- a/tests/context/context.py
+++ b/tests/context/context.py
@@ -4,8 +4,6 @@ import pytest
 from buildstream._context import Context
 from buildstream._exceptions import LoadError, LoadErrorReason
 
-from tests.testutils.site import HAVE_ROOT
-
 DATA_DIR = os.path.join(
     os.path.dirname(os.path.realpath(__file__)),
     'data',
@@ -37,7 +35,6 @@ def test_context_create(context_fixture):
 #######################################
 #     Test configuration loading      #
 #######################################
-@pytest.mark.skipif(not HAVE_ROOT, reason="requires root permissions")
 def test_context_load(context_fixture):
     context = context_fixture['context']
     cache_home = context_fixture['xdg-cache']
@@ -52,7 +49,6 @@ def test_context_load(context_fixture):
 
 # Test that values in a user specified config file
 # override the defaults
-@pytest.mark.skipif(not HAVE_ROOT, reason="requires root permissions")
 @pytest.mark.datafiles(os.path.join(DATA_DIR))
 def test_context_load_user_config(context_fixture, datafiles):
     context = context_fixture['context']
diff --git a/tests/frontend/buildtrack.py b/tests/frontend/buildtrack.py
index e91274a..45dd30d 100644
--- a/tests/frontend/buildtrack.py
+++ b/tests/frontend/buildtrack.py
@@ -300,12 +300,12 @@ def test_build_track_track_first(cli, datafiles, tmpdir, strict):
     assert result.exit_code == 0
 
     # Assert that 1.bst successfully tracks before 0.bst builds
-    track_messages = re.finditer(r'\[track:1.bst\s*]', result.output)
-    build_0 = re.search(r'\[build:0.bst\s*] START', result.output).start()
+    track_messages = re.finditer(r'\[track:1.bst\s*]', result.stderr)
+    build_0 = re.search(r'\[build:0.bst\s*] START', result.stderr).start()
     assert all(track_message.start() < build_0 for track_message in track_messages)
 
     # Assert that 2.bst is *only* rebuilt if we are in strict mode
-    build_2 = re.search(r'\[build:2.bst\s*] START', result.output)
+    build_2 = re.search(r'\[build:2.bst\s*] START', result.stderr)
     if strict == '--strict':
         assert build_2 is not None
     else:
diff --git a/tests/frontend/overlaps.py b/tests/frontend/overlaps.py
index cc7c08f..4ef5657 100644
--- a/tests/frontend/overlaps.py
+++ b/tests/frontend/overlaps.py
@@ -17,6 +17,6 @@ def test_overlaps(cli, datafiles):
 
     assert result.exit_code == 0
     print(result.output)
-    assert "/file1: three.bst above one.bst" in result.output
-    assert "/file2: two.bst above three.bst above one.bst" in result.output
-    assert "/file3: two.bst above three.bst" in result.output
+    assert "/file1: three.bst above one.bst" in result.stderr
+    assert "/file2: two.bst above three.bst above one.bst" in result.stderr
+    assert "/file3: two.bst above three.bst" in result.stderr
diff --git a/tests/frontend/show.py b/tests/frontend/show.py
index fde6201..2c2f03d 100644
--- a/tests/frontend/show.py
+++ b/tests/frontend/show.py
@@ -70,9 +70,8 @@ def test_parallel_order(cli, tmpdir, datafiles):
 
     assert result.exit_code == 0
 
-    # Get the planned order, excepting the 'Loading' messages before
-    # the pipeline is printed
-    names = result.output.splitlines()[3:]
+    # Get the planned order
+    names = result.output.splitlines()
     names = [name[len('multiple_targets/order/'):] for name in names]
 
     # Create all possible 'correct' topological orderings
@@ -100,9 +99,8 @@ def test_target_is_dependency(cli, tmpdir, datafiles):
 
     assert result.exit_code == 0
 
-    # Get the planned order, excepting the 'Loading' messages before
-    # the pipeline is printed
-    names = result.output.splitlines()[3:]
+    # Get the planned order
+    names = result.output.splitlines()
     names = [name[len('multiple_targets/dependency/'):] for name in names]
 
     assert names == ['pony.bst', 'horsey.bst', 'zebry.bst']
diff --git a/tests/plugins/pipeline.py b/tests/plugins/pipeline.py
index c659aa3..a77dcd1 100644
--- a/tests/plugins/pipeline.py
+++ b/tests/plugins/pipeline.py
@@ -5,9 +5,6 @@ from buildstream._context import Context
 from buildstream._project import Project
 from buildstream._exceptions import PluginError
 from buildstream._pipeline import Pipeline
-from buildstream._platform import Platform
-
-from tests.testutils.site import HAVE_ROOT
 
 DATA_DIR = os.path.join(
     os.path.dirname(os.path.realpath(__file__)),
@@ -18,15 +15,17 @@ DATA_DIR = os.path.join(
 def create_pipeline(tmpdir, basedir, target):
     context = Context([])
     project = Project(basedir, context)
-
     context.deploydir = os.path.join(str(tmpdir), 'deploy')
     context.artifactdir = os.path.join(str(tmpdir), 'artifact')
-    context._platform = Platform.get_platform()
+
+    def dummy_handler(message, context):
+        pass
+
+    context._set_message_handler(dummy_handler)
 
     return Pipeline(context, project, [target], [])
 
 
-@pytest.mark.skipif(not HAVE_ROOT, reason="requires root permissions")
 @pytest.mark.datafiles(os.path.join(DATA_DIR, 'customsource'))
 def test_customsource(datafiles, tmpdir):
 
@@ -35,7 +34,6 @@ def test_customsource(datafiles, tmpdir):
     assert(pipeline.targets[0].get_kind() == "autotools")
 
 
-@pytest.mark.skipif(not HAVE_ROOT, reason="requires root permissions")
 @pytest.mark.datafiles(os.path.join(DATA_DIR, 'customelement'))
 def test_customelement(datafiles, tmpdir):
 
@@ -44,7 +42,6 @@ def test_customelement(datafiles, tmpdir):
     assert(pipeline.targets[0].get_kind() == "foo")
 
 
-@pytest.mark.skipif(not HAVE_ROOT, reason="requires root permissions")
 @pytest.mark.datafiles(os.path.join(DATA_DIR, 'badversionsource'))
 def test_badversionsource(datafiles, tmpdir):
     basedir = os.path.join(datafiles.dirname, datafiles.basename)
@@ -53,7 +50,6 @@ def test_badversionsource(datafiles, tmpdir):
         pipeline = create_pipeline(tmpdir, basedir, 'simple.bst')
 
 
-@pytest.mark.skipif(not HAVE_ROOT, reason="requires root permissions")
 @pytest.mark.datafiles(os.path.join(DATA_DIR, 'badversionelement'))
 def test_badversionelement(datafiles, tmpdir):
     basedir = os.path.join(datafiles.dirname, datafiles.basename)
diff --git a/tests/project/plugins.py b/tests/project/plugins.py
index 7932fcd..4040137 100644
--- a/tests/project/plugins.py
+++ b/tests/project/plugins.py
@@ -4,9 +4,6 @@ import pytest
 from buildstream._context import Context
 from buildstream._project import Project
 from buildstream._pipeline import Pipeline
-from buildstream._platform import Platform
-
-from tests.testutils.site import HAVE_ROOT
 
 DATA_DIR = os.path.join(
     os.path.dirname(os.path.realpath(__file__)),
@@ -18,7 +15,11 @@ def create_pipeline(tmpdir, basedir, target):
     context = Context([])
     project = Project(basedir, context)
     context.artifactdir = os.path.join(str(tmpdir), 'artifact')
-    context._platform = Platform.get_platform()
+
+    def dummy_handler(message, context):
+        pass
+
+    context._set_message_handler(dummy_handler)
 
     return Pipeline(context, project, [target], [])
 
@@ -29,7 +30,6 @@ def create_pipeline(tmpdir, basedir, target):
 # also test that the project's configuration of plugin
 # paths is actually working.
 #
-@pytest.mark.skipif(not HAVE_ROOT, reason="requires root permissions")
 @pytest.mark.datafiles(os.path.join(DATA_DIR, 'plugins'))
 def test_custom_element(datafiles, tmpdir):
 
diff --git a/tests/sources/tar.py b/tests/sources/tar.py
index b1859a8..ca1bef7 100644
--- a/tests/sources/tar.py
+++ b/tests/sources/tar.py
@@ -104,7 +104,7 @@ def test_track_warning(cli, tmpdir, datafiles):
         'track', 'target.bst'
     ])
     assert result.exit_code == 0
-    assert "Potential man-in-the-middle attack!" in result.output
+    assert "Potential man-in-the-middle attack!" in result.stderr
 
 
 def _list_dir_contents(srcdir):
diff --git a/tests/sources/zip.py b/tests/sources/zip.py
index 2fd0c04..70ad491 100644
--- a/tests/sources/zip.py
+++ b/tests/sources/zip.py
@@ -91,7 +91,7 @@ def test_track_warning(cli, tmpdir, datafiles):
         'track', 'target.bst'
     ])
     assert result.exit_code == 0
-    assert "Potential man-in-the-middle attack!" in result.output
+    assert "Potential man-in-the-middle attack!" in result.stderr
 
 
 def _list_dir_contents(srcdir):
diff --git a/tests/variables/variables.py b/tests/variables/variables.py
index 47b1ff9..24f323c 100644
--- a/tests/variables/variables.py
+++ b/tests/variables/variables.py
@@ -5,9 +5,6 @@ from buildstream import BuildElement
 from buildstream._context import Context
 from buildstream._project import Project
 from buildstream._pipeline import Pipeline
-from buildstream._platform import Platform
-
-from tests.testutils.site import HAVE_ROOT
 
 DATA_DIR = os.path.join(
     os.path.dirname(os.path.realpath(__file__)),
@@ -18,7 +15,11 @@ def create_pipeline(tmpdir, basedir, target):
     context = Context([])
     project = Project(basedir, context)
     context.artifactdir = os.path.join(str(tmpdir), 'artifact')
-    context._platform = Platform.get_platform()
+
+    def dummy_handler(message, context):
+        pass
+
+    context._set_message_handler(dummy_handler)
 
     return Pipeline(context, project, [target], [])
 
@@ -41,7 +42,6 @@ def assert_command(datafiles, tmpdir, target, command, expected):
 ###############################################################
 #  Test proper loading of some default commands from plugins  #
 ###############################################################
-@pytest.mark.skipif(not HAVE_ROOT, reason="requires root permissions")
 @pytest.mark.parametrize("target,command,expected", [
     ('autotools.bst', 'install-commands', "make -j1 DESTDIR=\"/buildstream/install\" install"),
     ('cmake.bst', 'configure-commands',
@@ -62,7 +62,6 @@ def test_defaults(datafiles, tmpdir, target, command, expected):
 ################################################################
 #  Test overriding of variables to produce different commands  #
 ################################################################
-@pytest.mark.skipif(not HAVE_ROOT, reason="requires root permissions")
 @pytest.mark.parametrize("target,command,expected", [
     ('autotools.bst', 'install-commands', "make -j1 DESTDIR=\"/custom/install/root\" install"),
     ('cmake.bst', 'configure-commands',


[buildstream] 03/08: _pipeline.py: Removed tickers, use timed activities instead

Posted by ro...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

root pushed a commit to branch early-logging
in repository https://gitbox.apache.org/repos/asf/buildstream.git

commit 69b793e9a77d8de91bbebb8b98e1e60385e3f421
Author: Tristan Van Berkom <tr...@codethink.co.uk>
AuthorDate: Tue Dec 12 18:51:56 2017 -0500

    _pipeline.py: Removed tickers, use timed activities instead
    
    Currently this does not update the task list, and is for timing
    groups of activities from the frontend, or for timing long standing
    tasks which run directly in the frontend and not in a child task
    (like downloading the refs from a remote at load time before a build
    commences).
---
 buildstream/_pipeline.py | 92 ++++++++++++++++++++----------------------------
 1 file changed, 38 insertions(+), 54 deletions(-)

diff --git a/buildstream/_pipeline.py b/buildstream/_pipeline.py
index 550ab60..036a1ca 100644
--- a/buildstream/_pipeline.py
+++ b/buildstream/_pipeline.py
@@ -25,9 +25,10 @@ import shlex
 import shutil
 import tarfile
 import itertools
+from contextlib import contextmanager
 from operator import itemgetter
-from tempfile import TemporaryDirectory
 from pluginbase import PluginBase
+from tempfile import TemporaryDirectory
 
 from ._exceptions import PipelineError, ArtifactError, ImplError
 from ._message import Message, MessageType
@@ -93,14 +94,6 @@ class Planner():
 #    rewritable (bool): Whether the loaded files should be rewritable
 #                       this is a bit more expensive due to deep copies
 #    use_remote_cache (bool): Whether to connect with remote artifact cache
-#    load_ticker (callable): A function which will be called for each loaded element
-#    resolve_ticker (callable): A function which will be called for each resolved element
-#    cache_ticker (callable): A function which will be called for each element
-#                             while interrogating caches
-#
-# The ticker methods will be called with an element name for each tick, a final
-# tick with None as the argument is passed to signal that processing of this
-# stage has terminated.
 #
 # Raises:
 #    LoadError
@@ -111,12 +104,7 @@ class Planner():
 #
 class Pipeline():
 
-    def __init__(self, context, project, targets, except_,
-                 rewritable=False,
-                 remote_ticker=None,
-                 cache_ticker=None,
-                 load_ticker=None,
-                 resolve_ticker=None):
+    def __init__(self, context, project, targets, except_, rewritable=False):
         self.context = context
         self.project = project
         self.session_elements = 0
@@ -128,14 +116,12 @@ class Pipeline():
         Platform._create_instance(context, project)
         self.platform = Platform.get_platform()
         self.artifacts = self.platform.artifactcache
-        self.remote_ticker = remote_ticker
-        self.cache_ticker = cache_ticker
 
         loader = Loader(self.project.element_path, targets + except_,
                         self.project._options)
-        meta_elements = loader.load(rewritable, load_ticker)
-        if load_ticker:
-            load_ticker(None)
+
+        with self.timed_activity("Loading pipeline", silent_nested=True):
+            meta_elements = loader.load(rewritable, None)
 
         # Create the factories after resolving the project
         pluginbase = PluginBase(package='buildstream.plugins')
@@ -143,15 +129,13 @@ class Pipeline():
         self.source_factory = SourceFactory(pluginbase, project._plugin_source_paths)
 
         # Resolve the real elements now that we've resolved the project
-        resolved_elements = [self.resolve(meta_element, ticker=resolve_ticker)
-                             for meta_element in meta_elements]
+        with self.timed_activity("Resolving pipeline"):
+            resolved_elements = [self.resolve(meta_element)
+                                 for meta_element in meta_elements]
 
         self.targets = resolved_elements[:len(targets)]
         self.exceptions = resolved_elements[len(targets):]
 
-        if resolve_ticker:
-            resolve_ticker(None)
-
     def initialize(self, use_remote_cache=False, inconsistent=None):
         # Preflight directly, before ever interrogating caches or
         # anything.
@@ -182,34 +166,28 @@ class Pipeline():
                 self.project._set_workspace(element, source, workspace)
 
     def fetch_remote_refs(self):
-        try:
-            if self.remote_ticker:
-                self.remote_ticker(self.artifacts.url)
-            self.artifacts.initialize_remote()
-            self.artifacts.fetch_remote_refs()
-        except ArtifactError:
-            self.message(MessageType.WARN, "Failed to fetch remote refs")
-            self.artifacts.set_offline()
+        with self.timed_activity("Fetching remote refs", silent_nested=True):
+            try:
+                self.artifacts.initialize_remote()
+                self.artifacts.fetch_remote_refs()
+            except ArtifactError:
+                self.message(MessageType.WARN, "Failed to fetch remote refs")
+                self.artifacts.set_offline()
 
     def resolve_cache_keys(self, inconsistent):
         if inconsistent:
             inconsistent = self.get_elements_to_track(inconsistent)
 
-        for element in self.dependencies(Scope.ALL):
-            if self.cache_ticker:
-                self.cache_ticker(element.name)
-
-            if inconsistent and element in inconsistent:
-                # Load the pipeline in an explicitly inconsistent state, use
-                # this for pipelines with tracking queues enabled.
-                element._force_inconsistent()
-            else:
-                # Resolve cache keys and interrogate the artifact cache
-                # for the first time.
-                element._cached()
-
-        if self.cache_ticker:
-            self.cache_ticker(None)
+        with self.timed_activity("Resolving cached state", silent_nested=True):
+            for element in self.dependencies(Scope.ALL):
+                if inconsistent and element in inconsistent:
+                    # Load the pipeline in an explicitly inconsistent state, use
+                    # this for pipelines with tracking queues enabled.
+                    element._force_inconsistent()
+                else:
+                    # Resolve cache keys and interrogate the artifact cache
+                    # for the first time.
+                    element._cached()
 
     # Generator function to iterate over elements and optionally
     # also iterate over sources.
@@ -266,16 +244,22 @@ class Pipeline():
         self.context._message(
             Message(None, message_type, message, **args))
 
+    # Local timed activities, announces the jobs as well
+    #
+    @contextmanager
+    def timed_activity(self, activity_name, *, detail=None, silent_nested=False):
+        with self.context._timed_activity(activity_name,
+                                          detail=detail,
+                                          silent_nested=silent_nested):
+            yield
+
     # Internal: Instantiates plugin-provided Element and Source instances
     # from MetaElement and MetaSource objects
     #
-    def resolve(self, meta_element, ticker=None):
+    def resolve(self, meta_element):
         if meta_element in self._resolved_elements:
             return self._resolved_elements[meta_element]
 
-        if ticker:
-            ticker(meta_element.name)
-
         element = self.element_factory.create(meta_element.kind,
                                               self.context,
                                               self.project,
@@ -286,9 +270,9 @@ class Pipeline():
 
         # resolve dependencies
         for dep in meta_element.dependencies:
-            element._add_dependency(self.resolve(dep, ticker=ticker), Scope.RUN)
+            element._add_dependency(self.resolve(dep), Scope.RUN)
         for dep in meta_element.build_dependencies:
-            element._add_dependency(self.resolve(dep, ticker=ticker), Scope.BUILD)
+            element._add_dependency(self.resolve(dep), Scope.BUILD)
 
         # resolve sources
         for meta_source in meta_element.sources:


[buildstream] 01/08: _context.py: Added _timed_activity() method

Posted by ro...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

root pushed a commit to branch early-logging
in repository https://gitbox.apache.org/repos/asf/buildstream.git

commit fe65e79c9b36d7ca5fe2d4d3d79cff5b51beeb38
Author: Tristan Van Berkom <tr...@codethink.co.uk>
AuthorDate: Tue Dec 12 18:47:43 2017 -0500

    _context.py: Added _timed_activity() method
    
    A version of the function which can be shared with the frontend too.
---
 buildstream/_context.py | 54 ++++++++++++++++++++++++++++++++++++++++++++++++-
 1 file changed, 53 insertions(+), 1 deletion(-)

diff --git a/buildstream/_context.py b/buildstream/_context.py
index f975d3d..08ce83a 100644
--- a/buildstream/_context.py
+++ b/buildstream/_context.py
@@ -19,11 +19,15 @@
 #        Tristan Van Berkom <tr...@codethink.co.uk>
 
 import os
+import datetime
 from collections import deque, Mapping
+from contextlib import contextmanager
+from . import _signals
 from . import _site
 from . import _yaml
 from . import utils
-from ._exceptions import LoadError, LoadErrorReason
+from ._exceptions import LoadError, LoadErrorReason, BstError
+from ._message import Message, MessageType
 from ._profile import Topics, profile_start, profile_end
 
 
@@ -303,6 +307,54 @@ class Context():
         self._message_handler(message, context=self)
         return
 
+    # _timed_activity()
+    #
+    # Context manager for performing timed activities and logging those
+    #
+    # Args:
+    #    context (Context): The invocation context object
+    #    activity_name (str): The name of the activity
+    #    detail (str): An optional detailed message, can be multiline output
+    #    silent_nested (bool): If specified, nested messages will be silenced
+    #
+    @contextmanager
+    def _timed_activity(self, activity_name, *, unique_id=None, detail=None, silent_nested=False):
+
+        starttime = datetime.datetime.now()
+        stopped_time = None
+
+        def stop_time():
+            nonlocal stopped_time
+            stopped_time = datetime.datetime.now()
+
+        def resume_time():
+            nonlocal stopped_time
+            nonlocal starttime
+            sleep_time = datetime.datetime.now() - stopped_time
+            starttime += sleep_time
+
+        with _signals.suspendable(stop_time, resume_time):
+            try:
+                # Push activity depth for status messages
+                message = Message(unique_id, MessageType.START, activity_name, detail=detail)
+                self._message(message)
+                self._push_message_depth(silent_nested)
+                yield
+
+            except BstError as e:
+                # Note the failure in status messages and reraise, the scheduler
+                # expects an error when there is an error.
+                elapsed = datetime.datetime.now() - starttime
+                message = Message(unique_id, MessageType.FAIL, activity_name, elapsed=elapsed)
+                self._pop_message_depth()
+                self._message(message)
+                raise
+
+            elapsed = datetime.datetime.now() - starttime
+            message = Message(unique_id, MessageType.SUCCESS, activity_name, elapsed=elapsed)
+            self._pop_message_depth()
+            self._message(message)
+
     # Force the resolved XDG variables into the environment,
     # this is so that they can be used directly to specify
     # preferred locations of things from user configuration


[buildstream] 07/08: tests/testutils/site.py: Removed HAVE_ROOT

Posted by ro...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

root pushed a commit to branch early-logging
in repository https://gitbox.apache.org/repos/asf/buildstream.git

commit 1feef7c08980a635d78942e202bc93ec1fadb20e
Author: Tristan Van Berkom <tr...@codethink.co.uk>
AuthorDate: Wed Dec 13 11:48:33 2017 -0500

    tests/testutils/site.py: Removed HAVE_ROOT
    
    There is no scenario worth testing where this condition is
    not true, removing this.
---
 tests/testutils/site.py | 2 --
 1 file changed, 2 deletions(-)

diff --git a/tests/testutils/site.py b/tests/testutils/site.py
index 456f6ec..fb57c40 100644
--- a/tests/testutils/site.py
+++ b/tests/testutils/site.py
@@ -44,5 +44,3 @@ except ProgramNotFoundError:
     HAVE_LZIP = False
 
 IS_LINUX = os.getenv('BST_FORCE_BACKEND', sys.platform).startswith('linux')
-
-HAVE_ROOT = HAVE_BWRAP or os.geteuid() == 0


[buildstream] 02/08: plugin.py: Implement Plugin.timed_activity() using Context._timed_activity()

Posted by ro...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

root pushed a commit to branch early-logging
in repository https://gitbox.apache.org/repos/asf/buildstream.git

commit 398ad6354661d6d94ca4231cf016cc2a3894ecd0
Author: Tristan Van Berkom <tr...@codethink.co.uk>
AuthorDate: Tue Dec 12 18:48:21 2017 -0500

    plugin.py: Implement Plugin.timed_activity() using Context._timed_activity()
---
 buildstream/plugin.py | 38 +++++---------------------------------
 1 file changed, 5 insertions(+), 33 deletions(-)

diff --git a/buildstream/plugin.py b/buildstream/plugin.py
index fa1cb03..a6baff8 100644
--- a/buildstream/plugin.py
+++ b/buildstream/plugin.py
@@ -67,7 +67,6 @@ Class Reference
 ---------------
 """
 
-import datetime
 import os
 import subprocess
 from contextlib import contextmanager
@@ -75,7 +74,7 @@ from weakref import WeakValueDictionary
 
 from . import _yaml, _signals
 from . import utils
-from ._exceptions import PluginError, ImplError, BstError
+from ._exceptions import PluginError, ImplError
 from ._message import Message, MessageType
 
 
@@ -449,37 +448,10 @@ class Plugin():
               # This will raise SourceError on its own
               self.call(... command which takes time ...)
         """
-        starttime = datetime.datetime.now()
-        stopped_time = None
-
-        def stop_time():
-            nonlocal stopped_time
-            stopped_time = datetime.datetime.now()
-
-        def resume_time():
-            nonlocal stopped_time
-            nonlocal starttime
-            sleep_time = datetime.datetime.now() - stopped_time
-            starttime += sleep_time
-
-        with _signals.suspendable(stop_time, resume_time):
-            try:
-                # Push activity depth for status messages
-                self.__message(MessageType.START, activity_name, detail=detail)
-                self.__context._push_message_depth(silent_nested)
-                yield
-
-            except BstError as e:
-                # Note the failure in status messages and reraise, the scheduler
-                # expects an error when there is an error.
-                elapsed = datetime.datetime.now() - starttime
-                self.__context._pop_message_depth()
-                self.__message(MessageType.FAIL, activity_name, elapsed=elapsed)
-                raise
-
-            elapsed = datetime.datetime.now() - starttime
-            self.__context._pop_message_depth()
-            self.__message(MessageType.SUCCESS, activity_name, elapsed=elapsed)
+        with self.__context._timed_activity(activity_name,
+                                            detail=detail,
+                                            silent_nested=silent_nested):
+            yield
 
     def call(self, *popenargs, fail=None, **kwargs):
         """A wrapper for subprocess.call()