[PATCH] rtemstoolkit: Rework the log locking adding an output thread.

[chrisj at rtems.org]

From: Chris Johns <chrisj at rtems.org>

---
 rtemstoolkit/log.py | 76 +++++++++++++++++++++++++++++----------------
 1 file changed, 49 insertions(+), 27 deletions(-)

diff --git a/rtemstoolkit/log.py b/rtemstoolkit/log.py
index 00fdb05..2e73e72 100755
--- a/rtemstoolkit/log.py
+++ b/rtemstoolkit/log.py
@@ -34,8 +34,11 @@
 
 from __future__ import print_function
 
+import atexit
 import os
+import queue
 import sys
+import time
 import threading
 
 from rtemstoolkit import error
@@ -57,9 +60,47 @@ tracing = False
 quiet = False
 
 #
-# Global output lock to keep output together when working with threads
+# Run the output from a separate thread to avoid blocking with a
+# lock. We want the outout to be blocks.
 #
-lock = threading.Lock()
+_output_queue = queue.SimpleQueue()
+
+def _output_worker(timeout=None):
+    try:
+        is_write, is_flush, handle, out = _output_queue.get(timeout=timeout)
+    except queue.Empty:
+        return timeout is None
+    except KeyboardInterrupt:
+        return False
+    except:
+        return False
+    if is_write:
+        handle.write(out)
+    else:
+        for l in out.replace(chr(13), '').splitlines():
+            print(l, file=handle)
+    if is_flush:
+        handle.flush()
+    return True
+
+def _output_put(is_write, is_flush, handle, out):
+    _output_queue.put((is_write, is_flush, handle, out))
+    while not _output_queue.empty():
+        time.sleep(0.001)
+
+def _output_exiting():
+    while _output_worker(timeout=0.100):
+        pass
+
+def _output_thread():
+    while _output_worker():
+        pass
+
+_outputter = threading.Thread(target=_output_thread,
+                              daemon=True,
+                              name='log_outputter')
+_outputter.start()
+atexit.register(_output_exiting)
 
 def info(args):
     s = [' Command Line: %s' % (' '.join(args))]
@@ -92,20 +133,12 @@ def _output(text = os.linesep, log = None):
     elif default is not None:
         default.output(text)
     else:
-        lock.acquire()
-        for l in text.replace(chr(13), '').splitlines():
-            print(l)
-        lock.release()
+        _output_put(False, False, sys.stdout, text)
     if capture is not None:
-        lock.acquire()
         capture(text)
-        lock.release()
 
 def stderr(text = os.linesep, log = None):
-    lock.acquire()
-    for l in text.replace(chr(13), '').splitlines():
-        print(l, file = sys.stderr)
-    lock.release()
+    _output_put(False, False, sys.stderr, text)
 
 def output(text = os.linesep, log = None):
     if not quiet:
@@ -114,10 +147,7 @@ def output(text = os.linesep, log = None):
 def notice(text = os.linesep, log = None, stdout_only = False):
     if not quiet and \
             (default is not None and not default.has_stdout() or stdout_only):
-        lock.acquire()
-        for l in text.replace(chr(13), '').splitlines():
-            print(l)
-        lock.release()
+        _output_put(False, False, sys.stdout, text)
     if not stdout_only:
         _output(text, log)
 
@@ -138,7 +168,6 @@ def flush(log = None):
 class log:
     """Log output to stdout or a file."""
     def __init__(self, streams = None, tail_size = 100):
-        self.lock = threading.Lock()
         self.tail = []
         self.tail_size = tail_size
         self.fhs = [None, None]
@@ -186,16 +215,9 @@ class log:
         out = os.linesep.join(text) + os.linesep
         if isinstance(out, bytes):
             out = out.decode('utf-8', 'ignore')
-        self.lock.acquire()
-        try:
-            for f in range(0, len(self.fhs)):
-                if self.fhs[f] is not None:
-                    self.fhs[f].write(out)
-            self.flush()
-        except:
-            raise
-        finally:
-            self.lock.release()
+        for f in range(0, len(self.fhs)):
+            if self.fhs[f] is not None:
+                _output_put(True, True, self.fhs[f], out)
 
     def flush(self):
         """Flush the output."""
-- 
2.24.1