Smarter debug logging with q

I stumbled across an interesting looking library completely by chance the other day. It has the impossible-to-Google name of q, so I guess other people might have overlooked it as well.

The idea is to deal with those cases that aren’t supposed to happen, but happen anyway: you’re working on a bug and want to see the value of some intermediate calculation. Ideally there would already be logging for this and you could just crank up the log level, but there never seems to be just the right values being logged. So you end up modifying the code.

There are two very basic things q can help with here:

  • It’s less to import, and less to type
  • It outputs directly to a special file (/tmp/q) that isn’t used for anything else, so logging will work even when STDOUT / STDERR are redirected.

Neither of these is decisive, on it’s own. It’s convenient that you can log the value of a variable by typing:

import q

but you could probably rig up your own library to do that in a few minutes.

Much more interesting is the ability to thread debug logging code into your existing code, without having to refactor it to expose loggable variables. This is important, because refactoring to put logging in can often be the cause of further problems.

Suppose you have some code that is using an intermediate calculation that isn’t assigned to a temporary variable:

if thing.flags & (1 << which_flag):

If we want to see the value of 1 << which_flag then we have to create a temporary:

flag_value = 1 << which_flag
logger.debug("flag_value = %s", flag_value)
if thing.flags & flag_value:

Whereas with q we can do:

if thing.flags & q(1 << which_flag):

This works unchanged. It can do this because q() is a function that not only prints its argument but returns its argument unchanged, so wrapping q() around it doesn't change the logic.

This worked well because our sub-expression was already wrapped in parentheses. If you want to tag a single variable to be logged and you don't want to bother putting it in parentheses, you don't have to:

if q/thing.flags & (1 << which_flag):

This dumps the value of thing.flags. It's able to do this because the q object has an operator overload defined on it, which customises the __div__ operator when applied to the q object. In fact, Python is seeing this as a division expression, but one that executes custom code that logs the second argument. Of course, it also returns that same value so it doesn't affect the value of the expression.

But what if you want to log the value of the whole if expression? Time for parentheses?

No again. If you want this, you can use a different operators:

if q | thing.flags & (1 << which_flag):

This now writes the whole value thing.flags & (1 << which_flag) to the log.


This is interesting stuff. It's both a powerful tool and incredibly compact to type. There are some interesting aspects to the implementation, and I'll probably do a bit of a teardown on it.

I don't think I'll actually start using the library myself, though. The magic operators look like they might actually confuse the issue when I'm debugging. Still, it's great to see that someone came up with this and I think it deserves wider attention.

Leave a Reply

Your email address will not be published. Required fields are marked *