_frontend: Early logging initialization

  o This makes logging independent from the Pipeline()

  o Removed size_request Widget() method, add context to Widget() initializer

  o Make the Status() widget derive anything it needs through the Context()

3 files changed, 120 insertions, 147 deletions

diff --git a/buildstream/_frontend/app.py b/buildstream/_frontend/app.py
index 2e53b54de..ea6aed0d9 100644
--- a/buildstream/_frontend/app.py
+++ b/buildstream/_frontend/app.py
@@ -145,6 +145,9 @@ class App():
         directory = self._main_options['directory']
         config = self._main_options['config']
 
+        #
+        # Load the Context
+        #
         try:
             self.context = Context(fetch_subprojects=fetch_subprojects)
             self.context.load(config)
@@ -171,30 +174,9 @@ class App():
             if option_value is not None:
                 setattr(self.context, context_attr, option_value)
 
-        # Create the logger right before setting the message handler
-        self.logger = LogLine(
-            self._content_profile,
-            self._format_profile,
-            self._success_profile,
-            self._error_profile,
-            self._detail_profile,
-            # Indentation for detailed messages
-            indent=INDENT,
-            # Number of last lines in an element's log to print (when encountering errors)
-            log_lines=self.context.log_error_lines,
-            # Maximum number of lines to print in a detailed message
-            message_lines=self.context.log_message_lines,
-            # Whether to print additional debugging information
-            debug=self.context.log_debug,
-            message_format=self.context.log_message_format)
-
-        # Propagate pipeline feedback to the user
-        self.context.set_message_handler(self._message_handler)
-
-        # Now that we have a logger and message handler,
-        # we can override the global exception hook.
-        sys.excepthook = self._global_exception_handler
-
+        #
+        # Load the Project
+        #
         try:
             self.project = Project(directory, self.context, cli_options=self._main_options['option'])
         except LoadError as e:
@@ -211,9 +193,39 @@ class App():
         except BstError as e:
             self._error_exit(e, "Error loading project")
 
-        # Create the stream now.
+        # Create the stream right away, we'll need to pass it around
         self.stream = Stream(self.context)
 
+        # Create the application's scheduler
+        self.scheduler = Scheduler(self.context, self._session_start,
+                                   interrupt_callback=self._interrupt_handler,
+                                   ticker_callback=self._tick,
+                                   job_start_callback=self._job_started,
+                                   job_complete_callback=self._job_completed)
+
+        # Create the logger right before setting the message handler
+        self.logger = LogLine(self.context,
+                              self._content_profile,
+                              self._format_profile,
+                              self._success_profile,
+                              self._error_profile,
+                              self._detail_profile,
+                              indent=INDENT)
+
+        # Create our status printer, only available in interactive
+        self._status = Status(self.context,
+                              self._content_profile, self._format_profile,
+                              self._success_profile, self._error_profile,
+                              self.stream, self.scheduler,
+                              colors=self.colors)
+
+        # Propagate pipeline feedback to the user
+        self.context.set_message_handler(self._message_handler)
+
+        # Now that we have a logger and message handler,
+        # we can override the global exception hook.
+        sys.excepthook = self._global_exception_handler
+
         # Run the body of the session here, once everything is loaded
         try:
             yield
@@ -269,25 +281,12 @@ class App():
             if session_name:
                 self._message(MessageType.START, session_name)
 
-            # Create the application's scheduler
-            self.scheduler = Scheduler(self.context, self._session_start,
-                                       interrupt_callback=self._interrupt_handler,
-                                       ticker_callback=self._tick,
-                                       job_start_callback=self._job_started,
-                                       job_complete_callback=self._job_completed)
-
             try:
                 self.pipeline = Pipeline(self.context, self.project, elements, except_,
                                          rewritable=rewritable)
             except BstError as e:
                 self._error_exit(e, "Error loading pipeline")
 
-            # Create our status printer, only available in interactive
-            self._status = Status(self._content_profile, self._format_profile,
-                                  self._success_profile, self._error_profile,
-                                  self.stream, self.pipeline, self.scheduler,
-                                  colors=self.colors)
-
             # Initialize pipeline
             try:
                 self.pipeline.initialize(use_configured_remote_caches=use_configured_remote_caches,
@@ -304,9 +303,6 @@ class App():
             self.stream._pipeline = self.pipeline
             self.stream.total_elements = len(list(self.pipeline.dependencies(Scope.ALL)))
 
-            # Pipeline is loaded, now we can tell the logger about it
-            self.logger.size_request(self.pipeline)
-
             profile_end(Topics.LOAD_PIPELINE, "_".join(t.replace(os.sep, '-') for t in elements))
 
             # Print the heading
@@ -318,16 +314,14 @@ class App():
                 yield
             except BstError as e:
 
-                # Catch the error and summarize what happened
-                elapsed = self.scheduler.elapsed_time()
-
                 if session_name:
+                    elapsed = self.scheduler.elapsed_time()
+
                     if isinstance(e, StreamError) and e.terminated:  # pylint: disable=no-member
                         self._message(MessageType.WARN, session_name + ' Terminated', elapsed=elapsed)
                     else:
                         self._message(MessageType.FAIL, session_name, elapsed=elapsed)
 
-                if session_name:
                     self._print_summary()
 
                 # Let the outer context manager print the error and exit
diff --git a/buildstream/_frontend/status.py b/buildstream/_frontend/status.py
index 4f3eed0f5..13e00f58f 100644
--- a/buildstream/_frontend/status.py
+++ b/buildstream/_frontend/status.py
@@ -33,21 +33,23 @@ from .widget import TimeCode
 # to a terminal, or if the terminal does not support ANSI escape codes.
 #
 # Args:
+#    context (Context): The Context
 #    content_profile (Profile): Formatting profile for content text
 #    format_profile (Profile): Formatting profile for formatting text
 #    success_profile (Profile): Formatting profile for success text
 #    error_profile (Profile): Formatting profile for error text
 #    stream (Stream): The Stream
-#    pipeline (Pipeline): The Pipeline
 #    scheduler (Scheduler): The Scheduler
 #    colors (bool): Whether to print the ANSI color codes in the output
 #
 class Status():
 
-    def __init__(self, content_profile, format_profile,
+    def __init__(self, context,
+                 content_profile, format_profile,
                  success_profile, error_profile,
-                 stream, pipeline, scheduler, colors=False):
+                 stream, scheduler, colors=False):
 
+        self._context = context
         self._content_profile = content_profile
         self._format_profile = format_profile
         self._success_profile = success_profile
@@ -58,9 +60,10 @@ class Status():
         self._term = Terminal()
         self._spacing = 1
         self._colors = colors
-        self._header = _StatusHeader(content_profile, format_profile,
+        self._header = _StatusHeader(context,
+                                     content_profile, format_profile,
                                      success_profile, error_profile,
-                                     stream, pipeline, scheduler)
+                                     stream, scheduler)
 
         self._term_width, _ = click.get_terminal_size()
         self._alloc_lines = 0
@@ -78,7 +81,7 @@ class Status():
     #
     def add_job(self, element, action_name):
         elapsed = self._scheduler.elapsed_time()
-        job = _StatusJob(element, action_name, self._content_profile, self._format_profile, elapsed)
+        job = _StatusJob(self._context, element, action_name, self._content_profile, self._format_profile, elapsed)
         self._jobs.append(job)
         self._need_alloc = True
 
@@ -242,19 +245,20 @@ class Status():
 # A delegate object for rendering the header part of the Status() widget
 #
 # Args:
+#    context (Context): The Context
 #    content_profile (Profile): Formatting profile for content text
 #    format_profile (Profile): Formatting profile for formatting text
 #    success_profile (Profile): Formatting profile for success text
 #    error_profile (Profile): Formatting profile for error text
 #    stream (Stream): The Stream
-#    pipeline (Pipeline): The Pipeline
 #    scheduler (Scheduler): The Scheduler
 #
 class _StatusHeader():
 
-    def __init__(self, content_profile, format_profile,
+    def __init__(self, context,
+                 content_profile, format_profile,
                  success_profile, error_profile,
-                 stream, pipeline, scheduler):
+                 stream, scheduler):
 
         #
         # Public members
@@ -269,11 +273,12 @@ class _StatusHeader():
         self._success_profile = success_profile
         self._error_profile = error_profile
         self._stream = stream
-        self._pipeline = pipeline
         self._scheduler = scheduler
-        self._time_code = TimeCode(content_profile, format_profile)
+        self._time_code = TimeCode(context, content_profile, format_profile)
+        self._context = context
 
     def render(self, line_length, elapsed):
+        project = self._context.get_toplevel_project()
         line_length = max(line_length, 80)
         size = 0
         text = ''
@@ -281,12 +286,12 @@ class _StatusHeader():
         session = str(self._stream.session_elements)
         total = str(self._stream.total_elements)
 
-        # Format and calculate size for pipeline target and overall time code
+        # Format and calculate size for target and overall time code
         size += len(total) + len(session) + 4  # Size for (N/N) with a leading space
         size += 8  # Size of time code
-        size += len(self._pipeline.project.name) + 1
+        size += len(project.name) + 1
         text += self._time_code.render_time(elapsed)
-        text += ' ' + self._content_profile.fmt(self._pipeline.project.name)
+        text += ' ' + self._content_profile.fmt(project.name)
         text += ' ' + self._format_profile.fmt('(') + \
                 self._content_profile.fmt(session) + \
                 self._format_profile.fmt('/') + \
@@ -356,6 +361,7 @@ class _StatusHeader():
 # A delegate object for rendering a job in the status area
 #
 # Args:
+#    context (Context): The Context
 #    element (Element): The element being processed
 #    action_name (str): The name of the action
 #    content_profile (Profile): Formatting profile for content text
@@ -364,7 +370,7 @@ class _StatusHeader():
 #
 class _StatusJob():
 
-    def __init__(self, element, action_name, content_profile, format_profile, elapsed):
+    def __init__(self, context, element, action_name, content_profile, format_profile, elapsed):
 
         #
         # Public members
@@ -379,7 +385,7 @@ class _StatusJob():
         self._offset = elapsed
         self._content_profile = content_profile
         self._format_profile = format_profile
-        self._time_code = TimeCode(content_profile, format_profile)
+        self._time_code = TimeCode(context, content_profile, format_profile)
 
         # Calculate the size needed to display
         self.size = 10  # Size of time code with brackets
diff --git a/buildstream/_frontend/widget.py b/buildstream/_frontend/widget.py
index a72293b04..814f87ff5 100644
--- a/buildstream/_frontend/widget.py
+++ b/buildstream/_frontend/widget.py
@@ -50,7 +50,10 @@ ERROR_MESSAGES = [MessageType.FAIL, MessageType.ERROR, MessageType.BUG]
 #
 class Widget():
 
-    def __init__(self, content_profile, format_profile):
+    def __init__(self, context, content_profile, format_profile):
+
+        # The context
+        self.context = context
 
         # The content profile
         self.content_profile = content_profile
@@ -58,17 +61,6 @@ class Widget():
         # The formatting profile
         self.format_profile = format_profile
 
-    # size_request()
-    #
-    # Gives the widget a chance to preflight the pipeline
-    # and figure out what size it might need for alignment purposes
-    #
-    # Args:
-    #    pipeline (Pipeline): The pipeline to process
-    #
-    def size_request(self, pipeline):
-        pass
-
     # render()
     #
     # Renders a string to be printed in the UI
@@ -93,8 +85,8 @@ class Space(Widget):
 # Used to add fixed text between columns
 class FixedText(Widget):
 
-    def __init__(self, text, content_profile, format_profile):
-        super(FixedText, self).__init__(content_profile, format_profile)
+    def __init__(self, context, text, content_profile, format_profile):
+        super(FixedText, self).__init__(context, content_profile, format_profile)
         self.text = text
 
     def render(self, message):
@@ -127,9 +119,9 @@ class Debug(Widget):
 
 # A widget for rendering the time codes
 class TimeCode(Widget):
-    def __init__(self, content_profile, format_profile, microseconds=False):
+    def __init__(self, context, content_profile, format_profile, microseconds=False):
         self._microseconds = microseconds
-        super(TimeCode, self).__init__(content_profile, format_profile)
+        super(TimeCode, self).__init__(context, content_profile, format_profile)
 
     def render(self, message):
         return self.render_time(message.elapsed)
@@ -183,23 +175,13 @@ class TypeName(Widget):
 # A widget for displaying the Element name
 class ElementName(Widget):
 
-    def __init__(self, content_profile, format_profile):
-        super(ElementName, self).__init__(content_profile, format_profile)
+    def __init__(self, context, content_profile, format_profile):
+        super(ElementName, self).__init__(context, content_profile, format_profile)
 
         # Pre initialization format string, before we know the length of
         # element names in the pipeline
         self._fmt_string = '{: <30}'
 
-    def size_request(self, pipeline):
-        longest_name = 0
-        for plugin in pipeline.dependencies(Scope.ALL, include_sources=True):
-            longest_name = max(len(plugin.name), longest_name)
-
-        # Put a cap at a specific width, usually some elements cause the line
-        # to be too long, just live with the unaligned columns in that case
-        longest_name = min(longest_name, 30)
-        self._fmt_string = '{: <' + str(longest_name) + '}'
-
     def render(self, message):
         element_id = message.task_id or message.unique_id
         if element_id is None:
@@ -222,21 +204,17 @@ class ElementName(Widget):
 class MessageText(Widget):
 
     def render(self, message):
-
         return message.message
 
 
 # A widget for formatting the element cache key
 class CacheKey(Widget):
 
-    def __init__(self, content_profile, format_profile, err_profile):
-        super(CacheKey, self).__init__(content_profile, format_profile)
+    def __init__(self, context, content_profile, format_profile, err_profile):
+        super(CacheKey, self).__init__(context, content_profile, format_profile)
 
         self._err_profile = err_profile
-        self._key_length = 0
-
-    def size_request(self, pipeline):
-        self._key_length = pipeline.context.log_key_length
+        self._key_length = context.log_key_length
 
     def render(self, message):
 
@@ -261,16 +239,11 @@ class CacheKey(Widget):
 # A widget for formatting the log file
 class LogFile(Widget):
 
-    def __init__(self, content_profile, format_profile, err_profile):
-        super(LogFile, self).__init__(content_profile, format_profile)
+    def __init__(self, context, content_profile, format_profile, err_profile):
+        super(LogFile, self).__init__(context, content_profile, format_profile)
 
         self._err_profile = err_profile
-        self._logdir = ''
-
-    def size_request(self, pipeline):
-
-        # Hold on to the logging directory so we can abbreviate
-        self._logdir = pipeline.context.logdir
+        self._logdir = context.logdir
 
     def render(self, message, abbrev=True):
 
@@ -296,14 +269,10 @@ class LogFile(Widget):
 # these messages, and the message text for other types.
 #
 class MessageOrLogFile(Widget):
-    def __init__(self, content_profile, format_profile, err_profile):
-        super(MessageOrLogFile, self).__init__(content_profile, format_profile)
-        self._message_widget = MessageText(content_profile, format_profile)
-        self._logfile_widget = LogFile(content_profile, format_profile, err_profile)
-
-    def size_request(self, pipeline):
-        self._message_widget.size_request(pipeline)
-        self._logfile_widget.size_request(pipeline)
+    def __init__(self, context, content_profile, format_profile, err_profile):
+        super(MessageOrLogFile, self).__init__(context, content_profile, format_profile)
+        self._message_widget = MessageText(context, content_profile, format_profile)
+        self._logfile_widget = LogFile(context, content_profile, format_profile, err_profile)
 
     def render(self, message):
         # Show the log file only in the main start/success messages
@@ -315,46 +284,58 @@ class MessageOrLogFile(Widget):
         return text
 
 
+# LogLine
+#
 # A widget for formatting a log line
+#
+# Args:
+#    context (Context): The Context
+#    content_profile (Profile): Formatting profile for content text
+#    format_profile (Profile): Formatting profile for formatting text
+#    success_profile (Profile): Formatting profile for success text
+#    error_profile (Profile): Formatting profile for error text
+#    detail_profile (Profile): Formatting profile for detail text
+#    indent (int): Number of spaces to use for general indentation
+#
 class LogLine(Widget):
 
-    def __init__(self, content_profile, format_profile, success_profile, err_profile, detail_profile,
-                 indent=4,
-                 log_lines=10,
-                 message_lines=10,
-                 debug=False,
-                 message_format: str = None):
-        super(LogLine, self).__init__(content_profile, format_profile)
+    def __init__(self, context,
+                 content_profile,
+                 format_profile,
+                 success_profile,
+                 err_profile,
+                 detail_profile,
+                 indent=4):
+        super(LogLine, self).__init__(context, content_profile, format_profile)
 
         self._columns = []
         self._failure_messages = defaultdict(list)
-        self._context = None
         self._success_profile = success_profile
         self._err_profile = err_profile
         self._detail_profile = detail_profile
         self._indent = ' ' * indent
-        self._log_lines = log_lines
-        self._message_lines = message_lines
+        self._log_lines = context.log_error_lines
+        self._message_lines = context.log_message_lines
         self._resolved_keys = None
 
-        self._space_widget = Space(content_profile, format_profile)
-        self._logfile_widget = LogFile(content_profile, format_profile, err_profile)
+        self._space_widget = Space(context, content_profile, format_profile)
+        self._logfile_widget = LogFile(context, content_profile, format_profile, err_profile)
 
-        if debug:
+        if context.log_debug:
             self._columns.extend([
-                Debug(content_profile, format_profile)
+                Debug(context, content_profile, format_profile)
             ])
 
         self.logfile_variable_names = {
-            "elapsed": TimeCode(content_profile, format_profile, microseconds=False),
-            "elapsed-us": TimeCode(content_profile, format_profile, microseconds=True),
-            "wallclock": WallclockTime(content_profile, format_profile),
-            "key": CacheKey(content_profile, format_profile, err_profile),
-            "element": ElementName(content_profile, format_profile),
-            "action": TypeName(content_profile, format_profile),
-            "message": MessageOrLogFile(content_profile, format_profile, err_profile)
+            "elapsed": TimeCode(context, content_profile, format_profile, microseconds=False),
+            "elapsed-us": TimeCode(context, content_profile, format_profile, microseconds=True),
+            "wallclock": WallclockTime(context, content_profile, format_profile),
+            "key": CacheKey(context, content_profile, format_profile, err_profile),
+            "element": ElementName(context, content_profile, format_profile),
+            "action": TypeName(context, content_profile, format_profile),
+            "message": MessageOrLogFile(context, content_profile, format_profile, err_profile)
         }
-        logfile_tokens = self._parse_logfile_format(message_format, content_profile, format_profile)
+        logfile_tokens = self._parse_logfile_format(context.log_message_format, content_profile, format_profile)
         self._columns.extend(logfile_tokens)
 
     # show_pipeline()
@@ -460,7 +441,7 @@ class LogLine(Widget):
     #    styling (bool): Whether to enable ansi escape codes in the output
     #
     def print_heading(self, pipeline, log_file, deps=None, styling=False):
-        context = pipeline.context
+        context = self.context
         project = pipeline.project
         starttime = datetime.datetime.now()
         text = ''
@@ -549,7 +530,7 @@ class LogLine(Widget):
         elements = sorted(e for (e, k) in self._resolved_keys.items() if k != e._get_cache_key())
         if elements:
             text += self.content_profile.fmt("Resolved key Summary\n", bold=True)
-            text += self.show_pipeline(elements, self._context.log_element_format)
+            text += self.show_pipeline(elements, self.context.log_element_format)
             text += "\n\n"
 
         if self._failure_messages:
@@ -604,14 +585,6 @@ class LogLine(Widget):
     ###################################################
     #             Widget Abstract Methods             #
     ###################################################
-    def size_request(self, pipeline):
-        for widget in self._columns:
-            widget.size_request(pipeline)
-
-        self._space_widget.size_request(pipeline)
-        self._logfile_widget.size_request(pipeline)
-
-        self._context = pipeline.context
 
     def render(self, message):
 
@@ -630,7 +603,7 @@ class LogLine(Widget):
         logfile_tokens = []
         while format_string:
             if format_string.startswith("%%"):
-                logfile_tokens.append(FixedText("%", content_profile, format_profile))
+                logfile_tokens.append(FixedText(self.context, "%", content_profile, format_profile))
                 format_string = format_string[2:]
                 continue
             m = re.search(r"^%\{([^\}]+)\}", format_string)
@@ -643,7 +616,7 @@ class LogLine(Widget):
             else:
                 m = re.search("^[^%]+", format_string)
                 if m is not None:
-                    text = FixedText(m.group(0), content_profile, format_profile)
+                    text = FixedText(self.context, m.group(0), content_profile, format_profile)
                     format_string = format_string[m.end(0):]
                     logfile_tokens.append(text)
                 else:
@@ -710,7 +683,7 @@ class LogLine(Widget):
         if message.scheduler and message.message_type == MessageType.FAIL:
             text += '\n'
 
-            if self._context is not None and not self._context.log_verbose:
+            if self.context is not None and not self.context.log_verbose:
                 text += self._indent + self._err_profile.fmt("Log file: ")
                 text += self._indent + self._logfile_widget.render(message) + '\n'
             else: