[PATCH 0/8] knotty: Interactive logging changes

[PATCH 0/8] knotty: Interactive logging changes

[Jason Wessel]

This a series that was posted some time ago in conjunction with the
knotty2 -> knotty merge.  Since that time the knotty2 has been merged
into knotty.  This series of patches adds in the ability to
interactively control the logging behavior while building, or set
the defaults by using the variable BB_RT_LOGLEVEL.

Certainly I am open to the re-naming any of these variables and such
or even changing the key bindings.  I do find it quite useful to be
able track down problems without having to go snooping through logs.
Most of the problems I find or debug all use these logging changes, so
I would like to make another attempt to get them upstream.

Thanks,
Jason.

--

Jason Wessel (8):
      bitbake: Unbuffer stdout for log files
      knotty.py: Extend knotty to support "real time" log tail for tasks
      knotty.py: Add the ability to dynamically select loglevel from stdin
      msg.py, knotty.py: Allow dynamic toggle of the debug log level
      knotty.py: update footer on dynamic log level change
      knotty.py: Add interactive commands to knotty
      knotty.py: Add ability to dynamically toggle log location
      knotty.py: Handle rare interrupted select call

 bin/bitbake                      |    8 ++
 lib/bb/build.py                  |    4 +
 lib/bb/msg.py                    |    9 ++-
 lib/bb/ui/crumbs/multilogtail.py |  135 +++++++++++++++++++++++++++++
 lib/bb/ui/knotty.py              |  178 +++++++++++++++++++++++++++++++++++++-
 5 files changed, 330 insertions(+), 4 deletions(-)
 create mode 100644 lib/bb/ui/crumbs/multilogtail.py

[PATCH 1/8] bitbake: Unbuffer stdout for log files

[Jason Wessel]

It is possible to lose critical log data when python exits in an
unorderly fashion via segmentation fault or certain types of crashes.
This is because the buffer characteristics are inherited from the top
level stdout, which should be set to unbuffered, for the purpose of
all the forked children.

This pushes the buffering to the OS, instead of having python managing
the buffers in its stream handler class.

This change is also to provide the ability to tail logs written from
processes in "real time" because they would be written in an orderly
fashion depending upon the OS characteristics for the file I/O.

(LOCAL REV ONLY: NOT UPSTREAM)

Signed-off-by: Jason Wessel <jason.wessel@windriver.com>
---
 bin/bitbake |    8 ++++++++
 1 files changed, 8 insertions(+), 0 deletions(-)

diff --git a/bin/bitbake b/bin/bitbake
index ed2ff06..c000d98 100755
--- a/bin/bitbake
+++ b/bin/bitbake
@@ -43,6 +43,14 @@ from bb import server
 __version__ = "1.15.3"
 logger = logging.getLogger("BitBake")
 
+# Unbuffer stdout to avoid log truncation in the event
+# of an unorderly exit as well as to provide timely
+# updates to log files for use with tail
+try:
+    if sys.stdout.name == '<stdout>':
+        sys.stdout = os.fdopen(sys.stdout.fileno(), 'w', 0)
+except:
+    pass
 
 class BBConfiguration(object):
     """
-- 
1.7.1

Re: [PATCH 1/8] bitbake: Unbuffer stdout for log files

[Chris Larson]

On Mon, Sep 17, 2012 at 3:43 PM, Jason Wessel
<jason.wessel@windriver.com> wrote:
> It is possible to lose critical log data when python exits in an
> unorderly fashion via segmentation fault or certain types of crashes.
> This is because the buffer characteristics are inherited from the top
> level stdout, which should be set to unbuffered, for the purpose of
> all the forked children.
>
> This pushes the buffering to the OS, instead of having python managing
> the buffers in its stream handler class.
>
> This change is also to provide the ability to tail logs written from
> processes in "real time" because they would be written in an orderly
> fashion depending upon the OS characteristics for the file I/O.
>
> (LOCAL REV ONLY: NOT UPSTREAM)
>
> Signed-off-by: Jason Wessel <jason.wessel@windriver.com>


I'm assuming you forgot to rebase -i and remove the LOCAL REV ONLY? :)
-- 
Christopher Larson

Re: [PATCH 1/8] bitbake: Unbuffer stdout for log files

[Jason Wessel]

On 09/17/2012 07:46 PM, Chris Larson wrote:
> On Mon, Sep 17, 2012 at 3:43 PM, Jason Wessel
> <jason.wessel@windriver.com> wrote:
>> It is possible to lose critical log data when python exits in an
>> unorderly fashion via segmentation fault or certain types of crashes.
>> This is because the buffer characteristics are inherited from the top
>> level stdout, which should be set to unbuffered, for the purpose of
>> all the forked children.
>>
>> This pushes the buffering to the OS, instead of having python managing
>> the buffers in its stream handler class.
>>
>> This change is also to provide the ability to tail logs written from
>> processes in "real time" because they would be written in an orderly
>> fashion depending upon the OS characteristics for the file I/O.
>>
>> (LOCAL REV ONLY: NOT UPSTREAM)
>>
>> Signed-off-by: Jason Wessel <jason.wessel@windriver.com>
>
> I'm assuming you forgot to rebase -i and remove the LOCAL REV ONLY? :)


Oops :-)

I can resend the patches, but I did re-base against the head but for some reason the filter was not working.

Jason.

[PATCH 2/8] knotty.py: Extend knotty to support "real time" log tail for tasks

[Jason Wessel]

This patch provides the capability to knotty to have a higher log
level where the individual tasks logs can be multiplexed to stdio.
This is highly desirable for several different use cases.

1) You can visually spot "hot spots" in building parallel tasks

2) The relative order an sequence of events can be determined in
   difficult to diagnose inter-related library problems.

3) It provides a nice way to see what all is actually going on and
   getting logged by various tasks such as a kernel compile where you
   might want to actually look at the output in a build over build
   scenario.

4) There are most certainly other aspects where this is useful.

The primary control is to set the BB_RT_LOGLEVEL = "2" in your
local.conf.  Additional capabilities will follow in successive
patches.  When parallel tasks are enabled, the logs will be
multiplexed and prefixed with the PID of the task.  In the
non-parallel case there is no PID prefix as everything is linear.

(LOCAL REV: NOT UPSTREAM)

Signed-off-by: Jason Wessel <jason.wessel@windriver.com>
---
 lib/bb/build.py                  |    4 +
 lib/bb/ui/crumbs/multilogtail.py |  135 ++++++++++++++++++++++++++++++++++++++
 lib/bb/ui/knotty.py              |   44 ++++++++++++
 3 files changed, 183 insertions(+), 0 deletions(-)
 create mode 100644 lib/bb/ui/crumbs/multilogtail.py

diff --git a/lib/bb/build.py b/lib/bb/build.py
index 82d22f7..beb53dd 100644
--- a/lib/bb/build.py
+++ b/lib/bb/build.py
@@ -88,6 +88,10 @@ class TaskBase(event.Event):
 class TaskStarted(TaskBase):
     """Task execution started"""
 
+    def __init__(self, t, d):
+        self.logfile = d.getVar("BB_LOGFILE", True) or "";
+        super(TaskStarted, self).__init__(t, d)
+
 class TaskSucceeded(TaskBase):
     """Task execution completed"""
 
diff --git a/lib/bb/ui/crumbs/multilogtail.py b/lib/bb/ui/crumbs/multilogtail.py
new file mode 100644
index 0000000..da8ae68
--- /dev/null
+++ b/lib/bb/ui/crumbs/multilogtail.py
@@ -0,0 +1,135 @@
+#
+# Multipile Log Tail for real time logging
+#
+# Copyright (C) 2012 Wind River Systems, Inc.
+#
+# Authored by Jason Wessel <jason.wessel@windriver.com>
+#
+# This program is free software; you can redistribute it and/or modify
+# it under the terms of the GNU General Public License version 2 as
+# published by the Free Software Foundation.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License along
+# with this program; if not, write to the Free Software Foundation, Inc.,
+# 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
+
+import re
+import time
+import sys
+
+class LogTail(object):
+    """Tail a single log file"""
+
+    def __init__(self):
+        self.file = None
+        self.offset = 0
+        self.filterLines = True
+        self.limit = 8192
+        self.cnt = 0
+        self.storedLine = ""
+
+    def openLog(self, filename, filterLines=True, limit=8192):
+        try:
+            self.file = open(filename, 'rb')
+            self.limit = limit
+            self.filterLines = filterLines
+        except:
+            return False
+        return True
+
+    def getLeftLine(self):
+        (left, right) = self.storedLine.split('\r',1)
+        self.storedLine = right
+        self.cnt = len(right)
+        return left
+
+    def getLine(self):
+        if self.cnt > 0 and '\r' in self.storedLine:
+            return self.getLeftLine()
+        while 1:
+            self.offset = self.file.tell()
+            line = self.file.readline()
+            if line:
+                if self.filterLines:
+                    line = line.replace('\r\n','\r');
+                    line = line.replace('\n','\r');
+                    self.storedLine += line
+                    self.cnt = len(self.storedLine)
+                    if (self.cnt > self.limit):
+                        if not '\r' in self.storedLine:
+                            self.storedLine += '\r'
+                        return self.getLeftLine()
+                    if '\r' in self.storedLine:
+                        return self.getLeftLine()
+                    continue
+                else:
+                    return line
+            self.file.seek(self.offset)
+            return None
+
+    def closeLog(self):
+        if self.file:
+            self.file.close()
+            self.file = None
+
+    def __del__(self):
+        self.closeLog()
+
+class MultiLogTail(object):
+    """Tail mulitple log files"""
+
+    def __init__(self, printPid=True):
+        self.filelist = []
+        self.trackPid = []
+        self.printPid = printPid
+
+    def openLog(self, filename, pid=0, limit=8192):
+        logtail = LogTail()
+        if logtail.openLog(filename, True, limit):
+            self.filelist.append((logtail, filename, pid))
+        else:
+            if pid > 0:
+                self.trackPid.append(pid)
+
+    def displayLogs(self):
+        for (logtail, filename, pid) in self.filelist:
+            while 1:
+                output = logtail.getLine()
+                if output == None:
+                    break
+                if self.printPid:
+                    print " " + str(pid) + ":" + output
+                else:
+                    print output
+
+    def closeLogs(self):
+        while 1:
+            try:
+                (logtail, filename, pid) = self.filelist.pop()
+                logtail.closeLog()
+            except:
+                break
+
+    def closeLog(self, rm_filename):
+        for (logtail, filename, pid) in self.filelist:
+            if filename == rm_filename:
+                self.filelist.remove((logtail, filename, pid))
+                logtail.closeLog()
+                return
+        raise Exception("File %s not in the list" % rm_filename)
+
+    def closeLogPid(self, rm_pid):
+        for (logtail, filename, pid) in self.filelist:
+            if pid == rm_pid:
+                self.filelist.remove((logtail, filename, pid))
+                logtail.closeLog()
+                return
+        if rm_pid in self.trackPid:
+            self.trackPid.remove(rm_pid)
+            return
+        print "ERROR: PID %s not in the list" % rm_pid
diff --git a/lib/bb/ui/knotty.py b/lib/bb/ui/knotty.py
index d81ad5d..d412192 100644
--- a/lib/bb/ui/knotty.py
+++ b/lib/bb/ui/knotty.py
@@ -22,6 +22,7 @@ from __future__ import division
 
 import os
 import sys
+import select
 import xmlrpclib
 import logging
 import progressbar
@@ -32,6 +33,7 @@ import fcntl
 import struct
 import copy
 from bb.ui import uihelper
+from bb.ui.crumbs.multilogtail import MultiLogTail
 
 logger = logging.getLogger("BitBake")
 interactive = sys.stdout.isatty()
@@ -211,6 +213,25 @@ class TerminalFilter(object):
             fd = sys.stdin.fileno()
             self.termios.tcsetattr(fd, self.termios.TCSADRAIN, self.stdinbackup)
 
+class RtLogLevel:
+    def __init__(self, mlt):
+        self.displaytail = False
+        self.mlt = mlt
+
+    def displayLogs(self):
+        if self.displaytail:
+            self.mlt.displayLogs()
+
+    def setLevel(self, input, verbose):
+        if input == "1":
+            if verbose:
+                print "NOTE: Turning off real time log tail"
+            self.displaytail = False
+        elif input == "2":
+            if verbose:
+                print "NOTE: Turning on real time log tail"
+            self.displaytail = True
+
 def main(server, eventHandler, tf = TerminalFilter):
 
     # Get values of variables which control our output
@@ -222,11 +243,22 @@ def main(server, eventHandler, tf = TerminalFilter):
     else:
         log_exec_tty = False
 
+    # MultiTail affected varialbles
+    numthreads = server.runCommand(["getVariable", "BB_NUMBER_THREADS"])
+    if numthreads is None or numthreads == "1":
+        mlt = MultiLogTail(False)
+    else:
+        mlt = MultiLogTail(True)
+
     helper = uihelper.BBUIHelper()
 
     console = logging.StreamHandler(sys.stdout)
     format = bb.msg.BBLogFormatter("%(levelname)s: %(message)s")
     bb.msg.addDefaultlogFilter(console)
+    rtloglevel = RtLogLevel(mlt)
+    bb_rt_loglevel = server.runCommand(["getVariable", "BB_RT_LOGLEVEL"])
+    if bb_rt_loglevel and bb_rt_loglevel != "":
+        rtloglevel.setLevel(bb_rt_loglevel, False)
     console.setFormatter(format)
     logger.addHandler(console)
     if consolelogfile:
@@ -267,11 +299,23 @@ def main(server, eventHandler, tf = TerminalFilter):
         try:
             termfilter.updateFooter()
             event = eventHandler.waitEvent(0.25)
+            # Always try printing any accumulated log files first
+            rtloglevel.displayLogs()
             if event is None:
                 if main.shutdown > 1:
                     break
                 continue
             helper.eventHandler(event)
+            if isinstance(event, bb.build.TaskStarted):
+                mlt.openLog(event.logfile, event.pid)
+                rtloglevel.displayLogs()
+
+            if isinstance(event, bb.build.TaskSucceeded):
+                mlt.closeLogPid(event.pid)
+
+            if isinstance(event, bb.build.TaskFailed):
+                mlt.closeLogPid(event.pid)
+
             if isinstance(event, bb.runqueue.runQueueExitWait):
                 if not main.shutdown:
                     main.shutdown = 1
-- 
1.7.1

Re: [PATCH 2/8] knotty.py: Extend knotty to support "real time" log tail for tasks

[Mark Hatle]

On 9/17/12 5:43 PM, Jason Wessel wrote:
> This patch provides the capability to knotty to have a higher log
> level where the individual tasks logs can be multiplexed to stdio.
> This is highly desirable for several different use cases.
>
> 1) You can visually spot "hot spots" in building parallel tasks
>
> 2) The relative order an sequence of events can be determined in
>     difficult to diagnose inter-related library problems.
>
> 3) It provides a nice way to see what all is actually going on and
>     getting logged by various tasks such as a kernel compile where you
>     might want to actually look at the output in a build over build
>     scenario.
>
> 4) There are most certainly other aspects where this is useful.
>
> The primary control is to set the BB_RT_LOGLEVEL = "2" in your
> local.conf.  Additional capabilities will follow in successive
> patches.  When parallel tasks are enabled, the logs will be
> multiplexed and prefixed with the PID of the task.  In the
> non-parallel case there is no PID prefix as everything is linear.
>
> (LOCAL REV: NOT UPSTREAM)

As any FYI, this adds the new BB_RT_LOGLEVEL.  If this patch is applied, then 
BB_RT_LOGLEVEL should be added to BB_HASHCONFIG_WHITELIST in bitbake.conf.

--Mark

[PATCH 3/8] knotty.py: Add the ability to dynamically select loglevel from stdin

[Jason Wessel]

If stdin is a controlling terminal, make it possible to dynamically
select a log level with the keys 1 and 2.

1 = normal bitbake knotty logs
2 = realtime multiple tail of task logs

(LOCAL REV: NOT UPSTREAM)

Signed-off-by: Jason Wessel <jason.wessel@windriver.com>
---
 lib/bb/ui/knotty.py |   35 +++++++++++++++++++++++++++++++++++
 1 files changed, 35 insertions(+), 0 deletions(-)

diff --git a/lib/bb/ui/knotty.py b/lib/bb/ui/knotty.py
index d412192..0ec1b30 100644
--- a/lib/bb/ui/knotty.py
+++ b/lib/bb/ui/knotty.py
@@ -213,6 +213,35 @@ class TerminalFilter(object):
             fd = sys.stdin.fileno()
             self.termios.tcsetattr(fd, self.termios.TCSADRAIN, self.stdinbackup)
 
+class StdinMgr:
+    def __init__(self):
+        import termios
+        self.termios = termios
+        self.stdinbackup = None
+        self.fd = None
+        if sys.stdin.isatty():
+            self.fd = sys.stdin.fileno()
+            self.stdinbackup = self.termios.tcgetattr(self.fd)
+            new = self.termios.tcgetattr(self.fd)
+            new[3] = new[3] & ~self.termios.ICANON & ~self.termios.ECHO
+            self.termios.tcsetattr(self.fd, self.termios.TCSANOW, new)
+
+    def poll(self):
+        if not self.stdinbackup:
+            return False
+        return select.select([sys.stdin], [], [], 0) == ([sys.stdin], [], [])
+
+    def restore(self):
+        if self.stdinbackup:
+            self.termios.tcsetattr(self.fd, self.termios.TCSADRAIN,
+                                   self.stdinbackup)
+            self.stdinbackup = None
+        # Force echo back on "just in case" something went haywire with an exception
+        if sys.stdin.isatty():
+            new = self.termios.tcgetattr(self.fd)
+            new[3] = new[3] | self.termios.ECHO
+            self.termios.tcsetattr(self.fd, self.termios.TCSANOW, new)
+
 class RtLogLevel:
     def __init__(self, mlt):
         self.displaytail = False
@@ -294,11 +323,15 @@ def main(server, eventHandler, tf = TerminalFilter):
     taskfailures = []
 
     termfilter = tf(main, helper, console, format)
+    stdin_mgr = StdinMgr()
 
     while True:
         try:
             termfilter.updateFooter()
             event = eventHandler.waitEvent(0.25)
+            if stdin_mgr.poll():
+                keyinput = sys.stdin.read(1)
+                rtloglevel.setLevel(keyinput, True)
             # Always try printing any accumulated log files first
             rtloglevel.displayLogs()
             if event is None:
@@ -488,6 +521,7 @@ def main(server, eventHandler, tf = TerminalFilter):
             if ioerror.args[0] == 4:
                 pass
         except KeyboardInterrupt:
+            stdin_mgr.restore()
             termfilter.clearFooter()
             if main.shutdown == 1:
                 print("\nSecond Keyboard Interrupt, stopping...\n")
@@ -499,6 +533,7 @@ def main(server, eventHandler, tf = TerminalFilter):
             main.shutdown = main.shutdown + 1
             pass
 
+    stdin_mgr.restore()
     summary = ""
     if taskfailures:
         summary += pluralise("\nSummary: %s task failed:",
-- 
1.7.1

[PATCH 4/8] msg.py, knotty.py: Allow dynamic toggle of the debug log level

[Jason Wessel]

If stdin is a controlling tty, make it possible to have
log levels 1-4 where you can press a key to dynamically
change the log level, while bitbake is running to see
what is going on.

1 = default log level
2 = multiple log tail of bitbake tasks
3 = bit bake debug messages
4 = bitbake debug messages + multiple lot tail of bitbake tasks

In order to make this possible a slight modification to
the msg logfilter was needed to make it possible to get
an object so as to change the filter log level.

(LOCAL REV: NOT UPSTREAM)

Signed-off-by: Jason Wessel <jason.wessel@windriver.com>
---
 lib/bb/msg.py       |    9 ++++++++-
 lib/bb/ui/knotty.py |   21 ++++++++++++++++++---
 2 files changed, 26 insertions(+), 4 deletions(-)

diff --git a/lib/bb/msg.py b/lib/bb/msg.py
index 9b39325..4b2f90e 100644
--- a/lib/bb/msg.py
+++ b/lib/bb/msg.py
@@ -86,6 +86,13 @@ class BBLogFilter(object):
         handler.setLevel(loglevel)
         handler.addFilter(self)
 
+    def setFiltLevel(self, handler, level):
+        self.stdlevel = level
+        handler.setLevel(level)
+
+    def getFiltLevel(self):
+        return self.stdlevel
+
     def filter(self, record):
         if record.levelno >= self.stdlevel:
             return True
@@ -131,7 +138,7 @@ def addDefaultlogFilter(handler):
         dlevel = len(tuple(iterator))
         debug_domains["BitBake.%s" % domainarg] = logging.DEBUG - dlevel + 1
 
-    BBLogFilter(handler, level, debug_domains)
+    return BBLogFilter(handler, level, debug_domains)
 
 #
 # Message handling functions
diff --git a/lib/bb/ui/knotty.py b/lib/bb/ui/knotty.py
index 0ec1b30..f7a770b 100644
--- a/lib/bb/ui/knotty.py
+++ b/lib/bb/ui/knotty.py
@@ -243,8 +243,11 @@ class StdinMgr:
             self.termios.tcsetattr(self.fd, self.termios.TCSANOW, new)
 
 class RtLogLevel:
-    def __init__(self, mlt):
+    def __init__(self, handler, logfilter, mlt):
         self.displaytail = False
+        self.handler = handler
+        self.logfilter = logfilter
+        self.defaultLevel = logfilter.getFiltLevel()
         self.mlt = mlt
 
     def displayLogs(self):
@@ -255,10 +258,22 @@ class RtLogLevel:
         if input == "1":
             if verbose:
                 print "NOTE: Turning off real time log tail"
+            self.logfilter.setFiltLevel(self.handler, self.defaultLevel)
             self.displaytail = False
         elif input == "2":
             if verbose:
                 print "NOTE: Turning on real time log tail"
+            self.logfilter.setFiltLevel(self.handler, self.defaultLevel)
+            self.displaytail = True
+        elif input == "3":
+            if verbose:
+                print "NOTE: Turning on DEBUG logging"
+            self.logfilter.setFiltLevel(self.handler, logging.DEBUG)
+            self.displaytail = False
+        elif input == "4":
+            if verbose:
+                print "NOTE: Turning on DEBUG logging + real time log tail"
+            self.logfilter.setFiltLevel(self.handler, logging.DEBUG)
             self.displaytail = True
 
 def main(server, eventHandler, tf = TerminalFilter):
@@ -283,8 +298,8 @@ def main(server, eventHandler, tf = TerminalFilter):
 
     console = logging.StreamHandler(sys.stdout)
     format = bb.msg.BBLogFormatter("%(levelname)s: %(message)s")
-    bb.msg.addDefaultlogFilter(console)
-    rtloglevel = RtLogLevel(mlt)
+    logfilter = bb.msg.addDefaultlogFilter(console)
+    rtloglevel = RtLogLevel(console, logfilter, mlt)
     bb_rt_loglevel = server.runCommand(["getVariable", "BB_RT_LOGLEVEL"])
     if bb_rt_loglevel and bb_rt_loglevel != "":
         rtloglevel.setLevel(bb_rt_loglevel, False)
-- 
1.7.1

[PATCH 5/8] knotty.py: update footer on dynamic log level change

[Jason Wessel]

This patch adds a call to update the task list after changing log
modes dynamically such that you can immediately see the remaining
tasks.

(LOCAL REV: NOT UPSTREAM)

Signed-off-by: Jason Wessel <jason.wessel@windriver.com>
---
 lib/bb/ui/knotty.py |    6 ++++++
 1 files changed, 6 insertions(+), 0 deletions(-)

diff --git a/lib/bb/ui/knotty.py b/lib/bb/ui/knotty.py
index f7a770b..5882c24 100644
--- a/lib/bb/ui/knotty.py
+++ b/lib/bb/ui/knotty.py
@@ -179,6 +179,10 @@ class TerminalFilter(object):
             sys.stdout.write(self.curses.tparm(self.ed))
         self.footer_present = False
 
+    def updateFooterForce(self):
+        self.footer_present = False
+        self.updateFooter()
+
     def updateFooter(self):
         if not self.cuu:
             return
@@ -347,6 +351,8 @@ def main(server, eventHandler, tf = TerminalFilter):
             if stdin_mgr.poll():
                 keyinput = sys.stdin.read(1)
                 rtloglevel.setLevel(keyinput, True)
+                termfilter.updateFooterForce()
+
             # Always try printing any accumulated log files first
             rtloglevel.displayLogs()
             if event is None:
-- 
1.7.1

[PATCH 6/8] knotty.py: Add interactive commands to knotty

[Jason Wessel]

0 - Linear logging
1 - turn off real time log tail
2 - turn on real time log tail
3 - turn on debug logging
4 - turn on debug logging and real time log tail
t - Display tasks in "top" mode
N - Display all runtime NOTE's that are normally filtered (0 or 1 toggles off)
h - display commands

The knotty 2 functionality can be activated in realtime
by pressing "t" for top mode or reverted with "0" for
normal mode.

(LOCAL REV: NOT UPSTREAM)

Signed-off-by: Jason Wessel <jason.wessel@windriver.com>
---
 lib/bb/ui/knotty.py |   75 ++++++++++++++++++++++++++++++++++++++++++++-------
 1 files changed, 65 insertions(+), 10 deletions(-)

diff --git a/lib/bb/ui/knotty.py b/lib/bb/ui/knotty.py
index 5882c24..df8de0f 100644
--- a/lib/bb/ui/knotty.py
+++ b/lib/bb/ui/knotty.py
@@ -97,7 +97,7 @@ class InteractConsoleLogFilter(logging.Filter):
         self.format = format
 
     def filter(self, record):
-        if record.levelno == self.format.NOTE and (record.msg.startswith("Running") or record.msg.startswith("recipe ")):
+        if self.tf.filterOn and record.levelno == self.format.NOTE and (record.msg.startswith("Running") or record.msg.startswith("recipe ")):
             return False
         self.tf.clearFooter()
         return True
@@ -136,6 +136,8 @@ class TerminalFilter(object):
         self.main = main
         self.helper = helper
         self.cuu = None
+        self.topMode = False
+        self.filterOn = False
         self.stdinbackup = None
         self.interactive = sys.stdout.isatty()
         self.footer_present = False
@@ -170,9 +172,31 @@ class TerminalFilter(object):
             self.columns = self.getTerminalColumns()
         except:
             self.cuu = None
+        self.topMode = True
+        self.filterOn = True
         console.addFilter(InteractConsoleLogFilter(self, format))
 
+    def setTopMode(self):
+        if self.topMode:
+            return
+        self.topMode = True
+        self.setFilterOn()
+
+    def setNormalMode(self):
+        if not self.topMode:
+            return
+        self.topMode = False
+        self.setFilterOff()
+
+    def setFilterOn(self):
+        self.filterOn = True
+
+    def setFilterOff(self):
+        self.filterOn = False
+
     def clearFooter(self):
+        if not self.topMode:
+            return
         if self.footer_present:
             lines = self.footer_present
             sys.stdout.write(self.curses.tparm(self.cuu, lines))
@@ -184,7 +208,7 @@ class TerminalFilter(object):
         self.updateFooter()
 
     def updateFooter(self):
-        if not self.cuu:
+        if not self.cuu or not self.topMode:
             return
         activetasks = self.helper.running_tasks
         failedtasks = self.helper.failed_tasks
@@ -247,23 +271,29 @@ class StdinMgr:
             self.termios.tcsetattr(self.fd, self.termios.TCSANOW, new)
 
 class RtLogLevel:
-    def __init__(self, handler, logfilter, mlt):
+    def __init__(self, handler, logfilter, mlt, tf):
         self.displaytail = False
         self.handler = handler
         self.logfilter = logfilter
         self.defaultLevel = logfilter.getFiltLevel()
         self.mlt = mlt
+        self.tf = tf
 
     def displayLogs(self):
         if self.displaytail:
             self.mlt.displayLogs()
 
     def setLevel(self, input, verbose):
-        if input == "1":
+        if input == "1" or input == "0":
             if verbose:
                 print "NOTE: Turning off real time log tail"
             self.logfilter.setFiltLevel(self.handler, self.defaultLevel)
             self.displaytail = False
+            if isinstance(self.tf, TerminalFilter):
+                if input == "0":
+                    self.tf.setNormalMode()
+                else:
+                    self.tf.setTopMode()
         elif input == "2":
             if verbose:
                 print "NOTE: Turning on real time log tail"
@@ -279,6 +309,29 @@ class RtLogLevel:
                 print "NOTE: Turning on DEBUG logging + real time log tail"
             self.logfilter.setFiltLevel(self.handler, logging.DEBUG)
             self.displaytail = True
+        elif input == "t":
+            if verbose:
+                print "NOTE: Activing task \"top\" mode"
+            if isinstance(self.tf, TerminalFilter):
+                self.tf.setTopMode()
+        elif input == "N":
+            if verbose:
+                print "NOTE: Turning on task notes"
+            if isinstance(self.tf, TerminalFilter):
+                self.tf.setFilterOff()
+        elif input == "h" or input == "?":
+            print "============================================="
+            print "Interaction help commands:"
+            print " 0 - Linear logging"
+            print " 1 - turn off real time log tail"
+            print " 2 - turn on real time log tail"
+            print " 3 - turn on debug logging"
+            print " 4 - turn on debug logging and real time log tail"
+            print " t - Display tasks in \"top\" mode"
+            print " N - Display all runtime NOTE's that are normally filtered (0 or 1 toggles off)"
+            print " h - display commands"
+            return False
+        return True
 
 def main(server, eventHandler, tf = TerminalFilter):
 
@@ -303,10 +356,6 @@ def main(server, eventHandler, tf = TerminalFilter):
     console = logging.StreamHandler(sys.stdout)
     format = bb.msg.BBLogFormatter("%(levelname)s: %(message)s")
     logfilter = bb.msg.addDefaultlogFilter(console)
-    rtloglevel = RtLogLevel(console, logfilter, mlt)
-    bb_rt_loglevel = server.runCommand(["getVariable", "BB_RT_LOGLEVEL"])
-    if bb_rt_loglevel and bb_rt_loglevel != "":
-        rtloglevel.setLevel(bb_rt_loglevel, False)
     console.setFormatter(format)
     logger.addHandler(console)
     if consolelogfile:
@@ -344,14 +393,20 @@ def main(server, eventHandler, tf = TerminalFilter):
     termfilter = tf(main, helper, console, format)
     stdin_mgr = StdinMgr()
 
+    rtloglevel = RtLogLevel(console, logfilter, mlt, termfilter)
+    bb_rt_loglevel = server.runCommand(["getVariable", "BB_RT_LOGLEVEL"])
+    if bb_rt_loglevel and bb_rt_loglevel != "":
+        for inputkey in bb_rt_loglevel:
+            rtloglevel.setLevel(inputkey, False)
     while True:
         try:
             termfilter.updateFooter()
             event = eventHandler.waitEvent(0.25)
             if stdin_mgr.poll():
                 keyinput = sys.stdin.read(1)
-                rtloglevel.setLevel(keyinput, True)
-                termfilter.updateFooterForce()
+                termfilter.clearFooter()
+                if (rtloglevel.setLevel(keyinput, True)):
+                    termfilter.updateFooterForce()
 
             # Always try printing any accumulated log files first
             rtloglevel.displayLogs()
-- 
1.7.1

[PATCH 7/8] knotty.py: Add ability to dynamically toggle log location

[Jason Wessel]

Add the ability to see where all the per task logs
were written to disk.

The resulting output looks like where [...] is the full path:

NOTE: LOG: [...]/python-2.7.2-r2.20/temp/log.do_package_setscene.8719
NOTE: LOG: [...]/perl-5.14.2-r7/temp/log.do_package_setscene.8760

(LOCAL REV: NOT UPSTREAM)

Signed-off-by: Jason Wessel <jason.wessel@windriver.com>
---
 lib/bb/ui/knotty.py |   13 +++++++++++++
 1 files changed, 13 insertions(+), 0 deletions(-)

diff --git a/lib/bb/ui/knotty.py b/lib/bb/ui/knotty.py
index df8de0f..2d58ebe 100644
--- a/lib/bb/ui/knotty.py
+++ b/lib/bb/ui/knotty.py
@@ -273,6 +273,7 @@ class StdinMgr:
 class RtLogLevel:
     def __init__(self, handler, logfilter, mlt, tf):
         self.displaytail = False
+        self.displayLogLocations = False
         self.handler = handler
         self.logfilter = logfilter
         self.defaultLevel = logfilter.getFiltLevel()
@@ -319,6 +320,14 @@ class RtLogLevel:
                 print "NOTE: Turning on task notes"
             if isinstance(self.tf, TerminalFilter):
                 self.tf.setFilterOff()
+        elif input == "l":
+            if verbose:
+                print "NOTE: Activating log locations display"
+            self.displayLogLocations = True
+        elif input == "L":
+            if verbose:
+                print "NOTE: Disable log locations display"
+            self.displayLogLocations = False
         elif input == "h" or input == "?":
             print "============================================="
             print "Interaction help commands:"
@@ -327,6 +336,7 @@ class RtLogLevel:
             print " 2 - turn on real time log tail"
             print " 3 - turn on debug logging"
             print " 4 - turn on debug logging and real time log tail"
+            print " l - emit log locations (L to turn off)"
             print " t - Display tasks in \"top\" mode"
             print " N - Display all runtime NOTE's that are normally filtered (0 or 1 toggles off)"
             print " h - display commands"
@@ -416,6 +426,9 @@ def main(server, eventHandler, tf = TerminalFilter):
                 continue
             helper.eventHandler(event)
             if isinstance(event, bb.build.TaskStarted):
+                if (rtloglevel.displayLogLocations):
+                    termfilter.clearFooter()
+                    print "NOTE: LOG: %s" % event.logfile
                 mlt.openLog(event.logfile, event.pid)
                 rtloglevel.displayLogs()
 
-- 
1.7.1

[PATCH 8/8] knotty.py: Handle rare interrupted select call

[Jason Wessel]

Under a high load and while resizing the terminal window, I received the following traceback:

Traceback (most recent call last):
  File "/bitbake/bin//bitbake", line 263, in <module>
    ret = main()
  File "/bitbake/bin//bitbake", line 252, in main
    return server.launchUI(ui_main, server_connection.connection, server_connection.events)
  File "/bitbake/lib/bb/server/process.py", line 269, in launchUI
    return bb.cooker.server_main(self.cooker, uifunc, *args)
  File "/bitbake/lib/bb/cooker.py", line 1407, in server_main
    ret = func(*args)
  File "/bitbake/lib/bb/ui/knotty.py", line 385, in main
    if stdin_mgr.poll():
error: (4, 'Interrupted system call')

Interrupted system calls from a sigwinch are certainly possible and the
right thing to do is just restart the system call, or in this case,
punt and wait until the next poll cycle.

(LOCAL REV: NOT UPSTREAM)

Signed-off-by: Jason Wessel <jason.wessel@windriver.com>
---
 lib/bb/ui/knotty.py |    6 +++++-
 1 files changed, 5 insertions(+), 1 deletions(-)

diff --git a/lib/bb/ui/knotty.py b/lib/bb/ui/knotty.py
index 2d58ebe..73327b5 100644
--- a/lib/bb/ui/knotty.py
+++ b/lib/bb/ui/knotty.py
@@ -257,7 +257,11 @@ class StdinMgr:
     def poll(self):
         if not self.stdinbackup:
             return False
-        return select.select([sys.stdin], [], [], 0) == ([sys.stdin], [], [])
+        try:
+            ret = select.select([sys.stdin], [], [], 0) == ([sys.stdin], [], [])
+        except:
+            return False
+        return ret
 
     def restore(self):
         if self.stdinbackup:
-- 
1.7.1