Use logging in the knotty ui, and pass the log record across directly

This kills firing of Msg* events in favor of just passing along LogRecord
objects.  These objects hold more than just level and message, but can also
have exception information, so the UI can decide what to do with that.

As an aside, when using the 'none' server, this results in the log messages in
the server being displayed directly via the logging module and the UI's
handler, rather than going through the server's event queue.  As a result of
doing it this way, we have to override the event handlers of the base logger
when spawning a worker process, to ensure they log via events rather than
directly.

Signed-off-by: Chris Larson <chris_larson@mentor.com>

4 files changed, 52 insertions, 46 deletions

diff --git a/bin/bitbake b/bin/bitbake
index 06198c45a..67cc9d594 100755
--- a/bin/bitbake
+++ b/bin/bitbake
@@ -160,7 +160,8 @@ Default BBFILES are the .bb files in the current directory.""")
     configuration = BBConfiguration(options)
     configuration.pkgs_to_build.extend(args[1:])
 
-    logger.addHandler(event.LogHandler())
+    loghandler = event.LogHandler()
+    logger.addHandler(loghandler)
 
     #server = bb.server.xmlrpc
     server = bb.server.none
@@ -186,6 +187,8 @@ Default BBFILES are the .bb files in the current directory.""")
     server.BitBakeServerFork(serverinfo, cooker.serve, cooker_logfile)
     del cooker
 
+    logger.removeHandler(loghandler)
+
     # Setup a connection to the server (cooker)
     serverConnection = server.BitBakeServerConnection(serverinfo)
 
diff --git a/lib/bb/event.py b/lib/bb/event.py
index dbcd11e1b..bf1812e69 100644
--- a/lib/bb/event.py
+++ b/lib/bb/event.py
@@ -328,17 +328,5 @@ class MsgPlain(MsgBase):
 class LogHandler(logging.Handler):
     """Dispatch logging messages as bitbake events"""
 
-    messages = (
-        (logging.DEBUG, MsgDebug),
-        (logging.INFO, MsgNote),
-        (logging.WARNING, MsgWarn),
-        (logging.ERROR, MsgError),
-        (logging.CRITICAL, MsgFatal),
-    )
-
     def emit(self, record):
-        for level, msgclass in self.messages:
-            if record.levelno <= level:
-                msg = self.format(record)
-                fire(msgclass(msg), None)
-                break
+        fire(record, None)
diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
index 0645d0699..4010dadf7 100644
--- a/lib/bb/runqueue.py
+++ b/lib/bb/runqueue.py
@@ -23,10 +23,13 @@ Handles preparation and execution of a queue of tasks
 # 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
 
 import bb, os, sys
-from bb import msg, data, event
 import signal
 import stat
 import fcntl
+import logging
+from bb import msg, data, event
+
+bblogger = logging.getLogger("BitBake")
 
 class TaskFailure(Exception):
     """Exception raised when a task in a runqueue fails"""
@@ -1075,6 +1078,11 @@ class RunQueue:
             bb.event.worker_pid = os.getpid()
             bb.event.worker_pipe = pipeout
 
+            # Child processes should send their messages to the UI
+            # process via the server process, not print them
+            # themselves
+            bblogger.handlers = [bb.event.LogHandler()]
+
             self.state = runQueueChildProcess
             # Make the child the process group leader
             os.setpgid(0, 0)
diff --git a/lib/bb/ui/knotty.py b/lib/bb/ui/knotty.py
index b43a35a13..516c78de6 100644
--- a/lib/bb/ui/knotty.py
+++ b/lib/bb/ui/knotty.py
@@ -24,12 +24,22 @@ import os
 import sys
 import itertools
 import xmlrpclib
+import logging
 from bb import ui
 from bb.ui import uihelper
 
-
+logger = logging.getLogger("BitBake")
 parsespin = itertools.cycle( r'|/-\\' )
 
+class BBLogFormatter(logging.Formatter):
+    """Formatter which ensures that our 'plain' messages (logging.INFO + 1) are used as is"""
+
+    def format(self, record):
+        if record.levelno == logging.INFO + 1:
+            return record.getMessage()
+        else:
+            return logging.Formatter.format(self, record)
+
 def init(server, eventHandler):
 
     # Get values of variables which control our output
@@ -38,9 +48,23 @@ def init(server, eventHandler):
 
     helper = uihelper.BBUIHelper()
 
+    # Set up logging to stdout in our usual format
+    logging.addLevelName(logging.INFO, "NOTE")
+    logging.addLevelName(logging.CRITICAL, "ERROR")
+
+    for level in xrange(logging.INFO - 1, logging.DEBUG + 1, -1):
+        logging.addLevelName(level, logging.getLevelName(logging.INFO))
+
+    for level in xrange(logging.DEBUG - 1, 0, -1):
+        logging.addLevelName(level, logging.getLevelName(logging.DEBUG))
+
+    console = logging.StreamHandler(sys.stdout)
+    format = BBLogFormatter("%(levelname)s: %(message)s")
+    console.setFormatter(format)
+    logger.addHandler(console)
+
     try:
         cmdline = server.runCommand(["getCmdLineAction"])
-        #print cmdline
         if not cmdline:
             return 1
         ret = server.runCommand(cmdline)
@@ -58,7 +82,6 @@ def init(server, eventHandler):
             event = eventHandler.waitEvent(0.25)
             if event is None:
                 continue
-            #print event
             helper.eventHandler(event)
             if isinstance(event, bb.runqueue.runQueueExitWait):
                 if not shutdown:
@@ -72,26 +95,10 @@ def init(server, eventHandler):
                         print("%s: %s (pid %s)" % (tasknum, activetasks[task]["title"], task))
                         tasknum = tasknum + 1
 
-            if isinstance(event, bb.event.MsgPlain):
-                print(event._message)
-                continue
-            if isinstance(event, bb.event.MsgDebug):
-                print('DEBUG: ' + event._message)
+            if isinstance(event, logging.LogRecord):
+                logger.handle(event)
                 continue
-            if isinstance(event, bb.event.MsgNote):
-                print('NOTE: ' + event._message)
-                continue
-            if isinstance(event, bb.event.MsgWarn):
-                print('WARNING: ' + event._message)
-                continue
-            if isinstance(event, bb.event.MsgError):
-                return_value = 1
-                print('ERROR: ' + event._message)
-                continue
-            if isinstance(event, bb.event.MsgFatal):
-                return_value = 1
-                print('FATAL: ' + event._message)
-                break
+
             if isinstance(event, bb.build.TaskFailed):
                 return_value = 1
                 logfile = event.logfile
@@ -117,7 +124,7 @@ def init(server, eventHandler):
                             for line in lines:
                                 print(line)
             if isinstance(event, bb.build.TaskBase):
-                print("NOTE: %s" % event._message)
+                logger.info(event._message)
                 continue
             if isinstance(event, bb.event.ParseProgress):
                 x = event.sofar
@@ -144,15 +151,15 @@ def init(server, eventHandler):
                 continue
             if isinstance(event, bb.command.CookerCommandFailed):
                 return_value = 1
-                print("Command execution failed: %s" % event.error)
+                logger.error("Command execution failed: %s" % event.error)
                 break
             if isinstance(event, bb.cooker.CookerExit):
                 break
             if isinstance(event, bb.event.MultipleProviders):
-                print("NOTE: multiple providers are available for %s%s (%s)" % (event._is_runtime and "runtime " or "",
-                                                                                event._item,
-                                                                                ", ".join(event._candidates)))
-                print("NOTE: consider defining a PREFERRED_PROVIDER entry to match %s" % event._item)
+                logger.info("multiple providers are available for %s%s (%s)", event._is_runtime and "runtime " or "",
+                            event._item,
+                            ", ".join(event._candidates))
+                logger.info("consider defining a PREFERRED_PROVIDER entry to match %s", event._item)
                 continue
             if isinstance(event, bb.event.NoProvider):
                 if event._runtime:
@@ -161,9 +168,9 @@ def init(server, eventHandler):
                     r = ""
 
                 if event._dependees:
-                    print("ERROR: Nothing %sPROVIDES '%s' (but %s %sDEPENDS on or otherwise requires it)" % (r, event._item, ", ".join(event._dependees), r))
+                    logger.error("Nothing %sPROVIDES '%s' (but %s %sDEPENDS on or otherwise requires it)", r, event._item, ", ".join(event._dependees), r)
                 else:
-                    print("ERROR: Nothing %sPROVIDES '%s'" % (r, event._item))
+                    logger.error("Nothing %sPROVIDES '%s'", r, event._item)
                 continue
 
             # ignore
@@ -175,7 +182,7 @@ def init(server, eventHandler):
                                   bb.runqueue.runQueueExitWait)):
                 continue
 
-            print("Unknown Event: %s" % event)
+            logger.error("Unknown event: %s", event)
 
         except KeyboardInterrupt:
             if shutdown == 2: