[bitbake-devel] [PATCH] server/process: Various server startup logging fixes

[Richard Purdie]

There were various problems in the server startup loggin:

a) stdout/stderr were not being flushed before forking which could potentially
   duplicate output

b) there were separate buffers for stdout/stderr leading to confusing logs
   where the entries could be reordered. This was particularly confusing
   due to the separator the logs use to idendify new messages

c) an fd wasn't being closed during server startup meaning if the
   server failed to start, the closed fd wasn't detected as it was held
   open by the other reference

d) If the pipe was detected as being closed, the code incorrectly retried
   server startup

e) The event code would remap stdout/stderr without flushing them, leading
   to lose log messages

Signed-off-by: Richard Purdie <richard.purdie at linuxfoundation.org>
---
 lib/bb/daemonize.py      | 12 +++++++++---
 lib/bb/event.py          |  3 +++
 lib/bb/server/process.py | 20 ++++++++++----------
 3 files changed, 22 insertions(+), 13 deletions(-)

diff --git a/lib/bb/daemonize.py b/lib/bb/daemonize.py
index bf16793468..613fb35536 100644
--- a/lib/bb/daemonize.py
+++ b/lib/bb/daemonize.py
@@ -16,6 +16,10 @@ def createDaemon(function, logfile):
     background as a daemon, returning control to the caller.
     """
 
+    # Ensure stdout/stderror are flushed before forking to avoid duplicate output
+    sys.stdout.flush()
+    sys.stderr.flush()
+
     try:
         # Fork a child process so the parent can exit.  This returns control to
         # the command-line or shell.  It also guarantees that the child will not
@@ -66,12 +70,14 @@ def createDaemon(function, logfile):
 
     try:
         so = open(logfile, 'a+')
-        se = so
         os.dup2(so.fileno(), sys.stdout.fileno())
-        os.dup2(se.fileno(), sys.stderr.fileno())
+        os.dup2(so.fileno(), sys.stderr.fileno())
     except io.UnsupportedOperation:
         sys.stdout = open(logfile, 'a+')
-        sys.stderr = sys.stdout
+
+    # Have stdout and stderr be the same so log output matches chronologically
+    # and there aren't two seperate buffers
+    sys.stderr = sys.stdout
 
     try:
         function()
diff --git a/lib/bb/event.py b/lib/bb/event.py
index c0ec605209..5b1b094a80 100644
--- a/lib/bb/event.py
+++ b/lib/bb/event.py
@@ -141,6 +141,9 @@ def print_ui_queue():
     logger = logging.getLogger("BitBake")
     if not _uiready:
         from bb.msg import BBLogFormatter
+        # Flush any existing buffered content
+        sys.stdout.flush()
+        sys.stderr.flush()
         stdout = logging.StreamHandler(sys.stdout)
         stderr = logging.StreamHandler(sys.stderr)
         formatter = BBLogFormatter("%(levelname)s: %(message)s")
diff --git a/lib/bb/server/process.py b/lib/bb/server/process.py
index 9e5e709f04..38b923fe2d 100644
--- a/lib/bb/server/process.py
+++ b/lib/bb/server/process.py
@@ -395,11 +395,16 @@ class BitBakeServer(object):
         bb.daemonize.createDaemon(self._startServer, logfile)
         self.sock.close()
         self.bitbake_lock.close()
+        os.close(self.readypipein)
 
         ready = ConnectionReader(self.readypipe)
         r = ready.poll(30)
         if r:
-            r = ready.get()
+            try:
+                r = ready.get()
+            except EOFError:
+                # Trap the child exitting/closing the pipe and error out
+                r = None
         if not r or r != "ready":
             ready.close()
             bb.error("Unable to start bitbake server")
@@ -425,21 +430,16 @@ class BitBakeServer(object):
                         bb.error("Server log for this session (%s):\n%s" % (logfile, "".join(lines)))
             raise SystemExit(1)
         ready.close()
-        os.close(self.readypipein)
 
     def _startServer(self):
         print(self.start_log_format % (os.getpid(), datetime.datetime.now().strftime(self.start_log_datetime_format)))
         server = ProcessServer(self.bitbake_lock, self.sock, self.sockname)
         self.configuration.setServerRegIdleCallback(server.register_idle_function)
+        os.close(self.readypipe)
         writer = ConnectionWriter(self.readypipein)
-        try:
-            self.cooker = bb.cooker.BBCooker(self.configuration, self.featureset)
-            writer.send("ready")
-        except:
-            writer.send("fail")
-            raise
-        finally:
-            os.close(self.readypipein)
+        self.cooker = bb.cooker.BBCooker(self.configuration, self.featureset)
+        writer.send("ready")
+        writer.close()
         server.cooker = self.cooker
         server.server_timeout = self.configuration.server_timeout
         server.xmlrpcinterface = self.configuration.xmlrpcinterface
-- 
2.17.1