Python + PySide + logging = headache

Wait what?

I’ve been working with Python and PySide for quite a while, but only just a couple of months ago as my full-time job. As it has happened to me before, I start to think “well, I really know this thing from head to toes”, and then I realize I don’t.

As a part of the LEAP Client a friend of mine started developing a log viewer for the app. Since we were already using logging, what made most sense was to have a logging.Handler subclass that harvested all the logs and then later on display those in a nice dialog. While the dialog is open, it needs to receive new logs, and for that of course we used the mighty signals.

Here’s where it got tricky. Being good devs, we are using PySide’s new style signal handling, but when the time came to actually emit it, here’s the error message we got:

  File "blah.py", line 18, in emit
    self.new_log.emit(log_item)
TypeError: emit() takes exactly 2 arguments (3 given)

new_log is a QtCore.QSignal(dict) class member. self.new_log on the other hand gets you a SignalInstance, huh.

Looking at it quickly it’s kind of funny, using one arg in the code, it says that emit() takes 2 args and we gave it 3, WTF?.

Calling conventions

Whenever you do self.method(somearg) in Python it gets converted into something like ClassName.method(self, somearg), so there’s always one more arg than what you use, but two more args? That’s a new one.

PySide and Signals

So, PySide is great, it does some nice tricks to get you to write nicer code, but when that fails you are drowning in error messages that you cannot really figure out from the python side, there’s no pdb, inspect or traceback that can give you any more info about those 3 args given, and where they came from.

The deal with signals is this: their concept was born with C++. There, you have macros that can convert whatever you write into a string literal, so when you write:

connect(somebtn, SIGNAL(clicked()), this, SLOT(myslot()));

The SIGNAL and SLOT macros, among other tricks, convert clicked() to “clicked()” and myslot() to “myslot()”, and then Qt with its MOC take it from there. That’s why the Qt documentation intructs you to write signals’ and slots’ parameters with just their type, not a parameter name. You never see this, and you don’t need to.

When you have to do that in Python, there are no macros, so you’ve got to go through the pain of typing quotes and praying that you don’t have any typos otherwise stuff might not work and who knows why. So PySide gives you a way out of this, you can use the strings and be as close to the C++ counter part of your Python code, or you can follow a
minimal series of rules and do it the PySide-way.

These rules are:

  • Always declare signals as a part of a QObject derived class
  • Always declare signals as a class member with type QtCore.Signal

And that’s about it. The trick is that PySide knows the difference between when you say MyClass.my_signal, and self.my_signal, and those mean different things even though you haven’t defined self.my_signal anywhere.

The idea once you’ve got that, is that you use signals like this:

self.my_signal.emit(my_whatever_data)

and do things like:

self.my_signal.connect(self._my_slot)

So this is really neat when you are working with Qt’s widgets, you can do:

my_pushbutton.clicked.connect(self._btn_clicked)

The bug

Back to the bug:

  File "blah.py", line 18, in emit
    self.new_log.emit(log_item)
TypeError: emit() takes exactly 2 arguments (3 given)

But lets see some context now, here’s a small app that reproduces this error:


import sys
import logging
from functools import partial
from PySide import QtCore, QtGui
class Obj(QtCore.QObject, logging.Handler):
sig = QtCore.Signal(dict)
def __init__(self):
QtCore.QObject.__init__(self)
logging.Handler.__init__(self)
def emit(self, logRecord):
# This is intended to be logging.Handler
# implementation of emit, not the QObject one
self.sig.emit({"a":123, "b":321})
if __name__ == "__main__":
app = QtGui.QApplication(sys.argv)
handler = Obj()
logger = logging.getLogger(name='test')
logger.setLevel(logging.DEBUG)
logger.addHandler(handler)
w = QtGui.QWidget()
b = QtGui.QPushButton(w)
b.clicked.connect(partial(logger.debug, "ASD"))
w.show()
app.exec_()

view raw

error.py

hosted with ❤ by GitHub

The idea is that we want to implement a logging.Handler that emits Qt signals, but logging.Handler makes you reimplement emit(self, logRecord), while QObject has its own emit(self, signal, data).

The first thing I thought is that we are emitting a signal before we create the QApplication and run its exec_() (we log things before that), but that wasn’t it (and looking at this from the other side it also sounds like a really stupid idea). Since we cannot gather any new info about the error, lets dive into PySide’s code.

As a part of the code generator, the function that generates the constructor for the Python module that will wrap a Qt class adds the following call:

PySide::Signal::updateSourceObject(self)

What this does is initialize all the signals that were declared as a class member for the given object being constructed (rule number 1). This initialization involves creating an object member called exactly the same as the signal but as a SignalInstance object instead of a Signal.

The SignalInstance is what implements the methods emit, connect and disconnect (but not quite so).

So when you run self.my_signal.emit(my_data), the SignalInstance code kicks in:


PyObject* signalInstanceEmit(PyObject* self, PyObject* args)
{
PySideSignalInstance* source = reinterpret_cast(self);
Shiboken::AutoDecRef pyArgs(PyList_New(0));
Shiboken::AutoDecRef sourceSignature(PySide::Signal::buildQtCompatible(source->d->signature));
PyList_Append(pyArgs, sourceSignature);
for (Py_ssize_t i = 0, max = PyTuple_Size(args); i d->source, "emit"));
Shiboken::AutoDecRef tupleArgs(PyList_AsTuple(pyArgs));
return PyObject_CallObject(pyMethod, tupleArgs);
}

and converts that Python line to the following:

self.emit("my_signal(PyObject)", my_data)

self is expected to be a QObject, so it’ll implement that emit and we are all happy, BUT we have our own emit that we have to define because of the logging.Handler implementation.

So the next step for Python is to do:

Obj.emit(self, "my_signal(PyObject)", my_data)

Well, well, 3 parameters, but our implementation only takes 2 (self and logRecord), and that’s the error we’ve got.

To work around it we need to change our line from:

self.sig.emit(my_dict)

to:

QtCore.QObject.emit(self, "sig(PyObject)", my_dict)

The PyObject is needed because we used a signal that uses a dict, which is represented in Python’s source as a PyObject, if we were using data types from Qt, that would be different.

The bug itself is that PySide doesn’t use the QObject to look for the emit implementation but the current self. It’s an edge case, I guess, but with just a couple of years of using this I’ve bumped into it, so may be not that edgy.

The bug has been reported here, we’ll see if upstream agrees with me.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s