How to get non-blocking/real-time behavior from Python logging module? (output to PyQt QTextBrowser)

Question

Description: I have written a custom log handler for capturing log events and writing them to a QTextBrowser object (working sample code shown below).

Issue: Pressing the button invokes someProcess(). This writes two strings to the logger object. However, the strings only appear after someProcess() returns.

Question: How do I get the logged strings to appear in the QTextBrowser object immediately/in real-time? (i.e. as soon as a logger output method is invoked)

from PyQt4 import QtCore, QtGui
import sys
import time
import logging
logger = logging.getLogger(__name__)

class ConsoleWindowLogHandler(logging.Handler):
    def __init__(self, textBox):
        super(ConsoleWindowLogHandler, self).__init__()
        self.textBox = textBox

    def emit(self, logRecord):
        self.textBox.append(str(logRecord.getMessage()))

def someProcess():
    logger.error("line1")
    time.sleep(5)
    logger.error("line2")

if __name__ == "__main__":
    app = QtGui.QApplication(sys.argv)
    window = QtGui.QWidget()
    textBox = QtGui.QTextBrowser()
    button = QtGui.QPushButton()
    button.clicked.connect(someProcess)
    vertLayout = QtGui.QVBoxLayout()
    vertLayout.addWidget(textBox)
    vertLayout.addWidget(button)
    window.setLayout(vertLayout)
    window.show()
    consoleHandler = ConsoleWindowLogHandler(textBox)
    logger.addHandler(consoleHandler)
    sys.exit(app.exec_())

EDIT: thanks to the answer by @abarnert, I managed to write this piece of working code using QThread. I subclassed QThread in order to run some function someProcess in a background thread. For the signalling, I had to resort to old-style Signal and Slots (I'm not sure how to do it in the new-style). I created a dummy QObject in order to be able to emit signals from the logging handler.

from PyQt4 import QtCore, QtGui
import sys
import time
import logging
logger = logging.getLogger(__name__)

#------------------------------------------------------------------------------
class ConsoleWindowLogHandler(logging.Handler):
    def __init__(self, sigEmitter):
        super(ConsoleWindowLogHandler, self).__init__()
        self.sigEmitter = sigEmitter

    def emit(self, logRecord):
        message = str(logRecord.getMessage())
        self.sigEmitter.emit(QtCore.SIGNAL("logMsg(QString)"), message)

#------------------------------------------------------------------------------
class Window(QtGui.QWidget):
    def __init__(self):
        super(Window, self).__init__()

        # Layout
        textBox = QtGui.QTextBrowser()
        self.button = QtGui.QPushButton()
        vertLayout = QtGui.QVBoxLayout()
        vertLayout.addWidget(textBox)
        vertLayout.addWidget(self.button)
        self.setLayout(vertLayout)

        # Connect button
        self.button.clicked.connect(self.buttonPressed)

        # Thread
        self.bee = Worker(self.someProcess, ())
        self.bee.finished.connect(self.restoreUi)
        self.bee.terminated.connect(self.restoreUi)

        # Console handler
        dummyEmitter = QtCore.QObject()
        self.connect(dummyEmitter, QtCore.SIGNAL("logMsg(QString)"),
                     textBox.append)
        consoleHandler = ConsoleWindowLogHandler(dummyEmitter)
        logger.addHandler(consoleHandler)

    def buttonPressed(self):
        self.button.setEnabled(False)
        self.bee.start()

    def someProcess(self):
        logger.error("starting")
        for i in xrange(10):
            logger.error("line%d" % i)
            time.sleep(2)

    def restoreUi(self):
        self.button.setEnabled(True)

#------------------------------------------------------------------------------
class Worker(QtCore.QThread):
    def __init__(self, func, args):
        super(Worker, self).__init__()
        self.func = func
        self.args = args

    def run(self):
        self.func(*self.args)

#------------------------------------------------------------------------------
if __name__ == "__main__":
    app = QtGui.QApplication(sys.argv)
    window = Window()
    window.show()
    sys.exit(app.exec_())

Answer 1

The real problem here is that you're blocking the entire GUI for 5 seconds by sleeping in the main thread. You can't do that, or no updates will show up, the user won't be able to interact with your app, etc. The logging issue is just a minor sub-consequence of that major problem.

And if your real program is calling some code from a third-party module that takes 5 seconds or does something blocking, it will have the exact same problem.

In general, there are two ways to do slow, blocking things without blocking a GUI (or other event-loop-based) app:

1. Do the work in a background thread. Depending on your GUI framework, from a background thread, you usually can't call functions directly on the GUI or modify its objects; you instead have to use some mechanism to post messages to the event loop. In Qt, you normally do this through the signal-slot mechanism. See this question for details.

2. Break the job up into non-blocking or guaranteed-only-very-short-term-blocking jobs that return quickly, each scheduling the next right before returning. (With some GUI frameworks, you can do the equivalent in-line by calling something like safeYield or calling the event loop recursively, but you don't do that with Qt.)

Given that someProcess is some external code that you can't modify, which either takes seconds to finish or does something blocking, you can't use option 2. So, option 1 it is: run it in a background thread.

Fortunately, this is easy. Qt has ways to do this, but Python's ways are even easier:

t = threading.Thread(target=someProcess)
t.start()

Now, you need to change ConsoleWindowLogHandler.emit so that, instead of directly modifying textBox, it sends a signal to get that done in the main thread. See Threads and QObjects for all the details, and some good examples.

More concretely: The Mandelbrot example uses a RenderThread that doesn't actually draw anything, but instead sends a renderedImage signal; the MandelbrotWidget then has an updatePixmap slot that it connects to the renderedImage signal. In the same way, your log handler wouldn't actually update the text box, but instead send a gotLogMessage signal; then you'd have a LogTextWidget with a updateLog slot that it connects to that signal. Of course for your simple case, you can keep them together in a single class, just as long as you connect the two sides up with a signal-slot connection rather than a direct method call.

You probably want to either keep t around somewhere and join it during shutdown, or set t.daemon = True.

Either way, if you want to know when someProcess is done, you need to use other means of communicating back to your main thread when it's done—again, with Qt, the usual answer is to send a signal. And this also lets you get a result back from someProcess. And you don't need to modify someProcess to do this; just define a wrapper function that calls someProcess and signals its result, and call that wrapper function from the background thread.