From 1e750c659b387733309352eaff58b4909301a227 Mon Sep 17 00:00:00 2001
From: sergei Trofimov <sergei.trofimov@arm.com>
Date: Mon, 30 Apr 2018 11:30:45 +0100
Subject: [PATCH] utils/log: add early record buffering

Buffer early log records until a log file becomes available, flush
records to said file afterwards. This ensures that early log output,
which, among other things, contains plugin discovery logging, is not
lost. Buffer capacity is configurable via an environment variable.
---
 doc/source/user_reference/configuration.rst | 10 +++++
 wa/utils/log.py                             | 47 ++++++++++++++++++++-
 2 files changed, 55 insertions(+), 2 deletions(-)

diff --git a/doc/source/user_reference/configuration.rst b/doc/source/user_reference/configuration.rst
index e5cd0d08..0e8a9a01 100644
--- a/doc/source/user_reference/configuration.rst
+++ b/doc/source/user_reference/configuration.rst
@@ -50,5 +50,15 @@ various assets when it starts.
    .. note:: This location **must** be writable by the user who runs WA.
 
 
+.. confval:: WA_LOG_BUFFER_CAPACITY
+
+    Specifies the capacity (in log records) for the early log handler which is
+    used to buffer log records until a log file becomes available. If the is not
+    set, the default value of ``1000`` will be used. This should sufficient for
+    most scenarios, however this may need to be increased, e.g. if plugin loader
+    scans a very large number of locations; this may also be set to a lower
+    value to reduce WA's memory footprint on memory-constrained hosts.
+
+
 .. include:: user_reference/runtime_parameters.rst
 
diff --git a/wa/utils/log.py b/wa/utils/log.py
index 3ac4baf8..e554a109 100644
--- a/wa/utils/log.py
+++ b/wa/utils/log.py
@@ -16,9 +16,11 @@
 
 # pylint: disable=E1101
 import logging
+import logging.handlers
+import os
 import string
-import threading
 import subprocess
+import threading
 
 import colorama
 
@@ -39,16 +41,19 @@ COLOR_MAP = {
 
 RESET_COLOR = colorama.Style.RESET_ALL
 
+DEFAULT_INIT_BUFFER_CAPACITY = 1000
+
 _indent_level = 0
 _indent_width = 4
 _console_handler = None
+_init_handler = None
 
 
 def init(verbosity=logging.INFO, color=True, indent_with=4,
          regular_fmt='%(levelname)-8s %(message)s',
          verbose_fmt='%(asctime)s %(levelname)-8s %(name)10.10s: %(message)s',
          debug=False):
-    global _indent_width, _console_handler
+    global _indent_width, _console_handler, _init_handler
     _indent_width = indent_with
     signal.log_error_func = lambda m: log_error(m, signal.logger)
 
@@ -70,6 +75,13 @@ def init(verbosity=logging.INFO, color=True, indent_with=4,
         _console_handler.setLevel(logging.INFO)
         _console_handler.setFormatter(formatter(regular_fmt))
     root_logger.addHandler(_console_handler)
+
+    buffer_capacity = os.getenv('WA_LOG_BUFFER_CAPACITY',
+                                DEFAULT_INIT_BUFFER_CAPACITY)
+    _init_handler = InitHandler(buffer_capacity)
+    _init_handler.setLevel(logging.DEBUG)
+    root_logger.addHandler(_init_handler)
+
     logging.basicConfig(level=logging.DEBUG)
     if not debug:
         logging.raiseExceptions = False
@@ -84,10 +96,17 @@ def set_level(level):
 
 def add_file(filepath, level=logging.DEBUG,
              fmt='%(asctime)s %(levelname)-8s %(name)10.10s: %(message)s'):
+    global _init_handler
     root_logger = logging.getLogger()
     file_handler = logging.FileHandler(filepath)
     file_handler.setLevel(level)
     file_handler.setFormatter(LineFormatter(fmt))
+
+    if _init_handler:
+        _init_handler.flush_to_target(file_handler)
+        root_logger.removeHandler(_init_handler)
+        _init_handler = None
+
     root_logger.addHandler(file_handler)
 
 
@@ -196,6 +215,30 @@ class ErrorSignalHandler(logging.Handler):
             signal.send(signal.WARNING_LOGGED, self, record)
 
 
+class InitHandler(logging.handlers.BufferingHandler):
+    """
+    Used to buffer early logging records before a log file is created.
+
+    """
+
+    def __init__(self, capacity):
+        super(InitHandler, self).__init__(capacity)
+        self.targets = []
+
+    def add_target(self, target):
+        if target not in self.targets:
+            self.targets.append(target)
+
+    def flush(self):
+        for target in self.targets:
+            self.flush_to_target(target)
+        self.buffer = []
+
+    def flush_to_target(self, target):
+        for record in self.buffer:
+            target.emit(record)
+
+
 class LineFormatter(logging.Formatter):
     """
     Logs each line of the message separately.