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.

(Bitbake rev: c23c015cf8af1868faf293b19b80a5faf7e736a5)

Signed-off-by: Chris Larson <chris_larson@mentor.com>
Signed-off-by: Richard Purdie <rpurdie@linux.intel.com>

4 files changed, 57 insertions, 48 deletions

diff --git a/bitbake/bin/bitbake b/bitbake/bin/bitbake
index 9b2cfdf5c5..a80c01ca50 100755
--- a/bitbake/bin/bitbake
+++ b/bitbake/bin/bitbake
@@ -164,7 +164,8 @@ Default BBFILES are the .bb files in the current directory.""")
     configuration.pkgs_to_build.extend(args[1:])
     configuration.initial_path = os.environ['PATH']
 
-    logger.addHandler(event.LogHandler())
+    loghandler = event.LogHandler()
+    logger.addHandler(loghandler)
 
     #server = bb.server.xmlrpc
     server = bb.server.none
@@ -190,6 +191,8 @@ Default BBFILES are the .bb files in the current directory.""")
     server.BitBakeServerFork(cooker, cooker.server, serverinfo, cooker_logfile)
     del cooker
 
+    logger.removeHandler(loghandler)
+
     # Setup a connection to the server (cooker)
     serverConnection = server.BitBakeServerConnection(serverinfo)
 
diff --git a/bitbake/lib/bb/event.py b/bitbake/lib/bb/event.py
index c04ffd5ac1..3fb9ff5bfc 100644
--- a/bitbake/lib/bb/event.py
+++ b/bitbake/lib/bb/event.py
@@ -328,20 +328,8 @@ 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)
-                if bb.event.useStdout:
-                    print(record.levelname + ": " + record.getMessage())
-                break
+        fire(record, None)
+        if bb.event.useStdout:
+            print(self.format(record))
 
diff --git a/bitbake/lib/bb/runqueue.py b/bitbake/lib/bb/runqueue.py
index be873ff7dc..94b456a988 100644
--- a/bitbake/lib/bb/runqueue.py
+++ b/bitbake/lib/bb/runqueue.py
@@ -24,11 +24,14 @@ Handles preparation and execution of a queue of tasks
 
 import bb, os, sys
 import subprocess
-from bb import msg, data, event
 import signal
 import stat
 import fcntl
 import copy
+import logging
+from bb import msg, data, event
+
+bblogger = logging.getLogger("BitBake")
 
 try:
     import cPickle as pickle
@@ -1127,6 +1130,11 @@ class RunQueueExecute:
             bb.event.worker_pipe = pipeout
             bb.event.useStdout = False
 
+            # Child processes should send their messages to the UI
+            # process via the server process, not print them
+            # themselves
+            bblogger.handlers = [bb.event.LogHandler()]
+
             self.rq.state = runQueueChildProcess
             # Make the child the process group leader
             os.setpgid(0, 0)
diff --git a/bitbake/lib/bb/ui/knotty.py b/bitbake/lib/bb/ui/knotty.py
index 9162c79f6a..177a12609c 100644
--- a/bitbake/lib/bb/ui/knotty.py
+++ b/bitbake/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, "FATAL")
+
+    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,13 @@ 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)
-                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)
+            if isinstance(event, logging.LogRecord):
+                if event.levelno is logging.CRITICAL or event.levelno is logging.ERROR:
+                    return_value = 1
+            if isinstance(event, logging.LogRecord):
+                logger.handle(event)
                 continue
+
             if isinstance(event, bb.build.TaskFailed):
                 return_value = 1
                 logfile = event.logfile
@@ -117,7 +127,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 +154,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 +171,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 +185,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: