Present Perfect


Picture Gallery
Present Perfect

gst-python gotcha

Filed under: GStreamer,Hacking,Python — Thomas @ 9:39 am

9:39 am

Here’s an innocent little line of code that caused me to lose an hour of debugging and svn bisecting time yesterday:

gobject.timeout_add(0L, self._pipeline.set_state, gst.STATE_PLAYING)

That change was buried inbetween some other cosmetic changes, and caused the UI of my application to be frozen. It took me a while before I nailed it down to this line, and a little bit more to figure out exactly why.

The goal was to set the state of the pipeline to PLAYING ‘as soon as possible’, from the main thread.

Of course the line of code does something subtly different. timeout_add schedules a call, so that part’s fine. But, the call gets rescheduled automatically unless the call returns False. Since that returns a GST_STATE_CHANGE enum, as long as the state change doesn’t fail, it keeps getting rescheduled, over and over. So, no time for the UI to update.

I figure this is something I”m bound to run into again, so a little blog will increase my chances of figuring it out again next time.


Filed under: TV,Twisted — Thomas @ 11:06 pm

11:06 pm

Two weeks ago for some reason I didn’t even know that Joss Whedon had a new TV series out.

I just finished watching Dollhouse, Episode 6 just now. It was all kinds of awesome. I have purposefully not read too much about the series because it seems Joss is getting a lot of backlash. And now I’m looking for reviews of episode 6 and it seems this is the episode where Joss really puts things into motion.

Well, it certainly clicked with me. The first 5 episodes are slow buildups, introducing new elements all over the places, and having little of the trademark JW dialogue but enough of the trademark JW setups and subtle hints. And then bam – 6 delivers in spades.

Well … I’m …
sure I’m in need of some serious moral spankitude, but …
uhm… guess who’s not qualified to be a rabbi.

Man, I love the internet. Thanks for letting me know through Planet Twisted, Itamar!


Filed under: General — Thomas @ 11:19 pm

11:19 pm

After more than two years, I finally finished reading my second Spanish novel. This one was ‘Zorro’ by Isabel Allende. I assume it’s different from her usual work. I obviously bit off more than I could chew, with a 380 page novel in small letters and very little whitespace. But I will persevere. Next!

Bug hunting

Filed under: GStreamer,Hacking,Python — Thomas @ 12:31 pm

12:31 pm

Yesterday, I was working some more on my jukebox code. It is now in the state where I can actually have it play a playlist and do the mixing properly. So I’m finally into dog food mode if you will, or in the mode where I can actually enjoy the result of the code I’ve written.

But I still had random failures that I couldn’t make sense of that I thought were due to gnonlin. I was getting random backtraces on startup when setting up my gnl objects, like so:

Traceback (most recent call last):
File "examples/jukebox.py", line 123, in
File "examples/jukebox.py", line 115, in main
main = Main(loop, tracks, playlist)
File "examples/jukebox.py", line 67, in __init__
self._jukebox.add_track(path, self._tracks[path][0])
File "/home/thomas/svn/src/dad/trunk/dad/gstreamer/jukebox.py", line 81, in add_track
File "/home/thomas/svn/src/dad/trunk/dad/gstreamer/jukebox.py", line 137, in _process
operation.props.duration = mix.duration
TypeError: could not convert argument to correct param type

I had been noticing them before but always thought “I’ll get to that later.” But yesterday it was getting on my nerves.

The problem was, there was nothing wrong with the duration I was setting. ‘duration’ is an INT64 property on a gnloperation, and the duration I was setting was a normal long. I spent hours sprinkling debugging code and diving deeper into the stack to figure out where it was going wrong, but couldn’t turn up anything.

I did see that in pygobject’s gobject/pygtype.c code, it was checking PyErr_Occurred, and just resetting the error and the GValue. I added a PyErr_Print to see why the conversion was failing, and it told me:

TypeError: can't convert negative long to unsigned

This made even less sense – I wasn’t setting a negative long, and I wasn’t setting it to an unsigned property either. It’s too bad the pygtype code wasn’t bubbling up this clear error up, instead obfuscating it with the generic error, but it still didn’t explain my bug.

We had invited friends over for dinner, so in the afternoon I was forced to take my mind off the keyboard, but as you all know that doesn’t mean your mind is off the problem. I’m sure you all know that feeling where you have lots of different pieces of the puzzle lying in front of your mind’s eye, and none of your theories made sense and you still see a bunch of different pieces.

Dinner was prepared, friends came, a good time was had by all, and my mind was off the problem. My only distraction was listening to the mixing points at the end of each song. And then when they left around 1 AM, Kristien and I sat on the couch, were watching some TV, it suddenly hit me. A classic bug pitfall.

What if the error was actually triggered before the line of code I was looking at ?

I’m sure you also all know that feeling where suddenly, a different way of looking at the problem makes all the pieces of the puzzle fall into place. It’s probably the most gratifying moment when doing bug hunting – after hours of frustrating undirected prodding, suddenly you get that one theory that explains both the problem and the lack of result in the prodding.

That’s when, instead of flying to the computer and trying it out, I prefer to savor the moment a bit. Because there’s still the possibility that I might be wrong, and just uncover another layer of fur on the yak you’re shaving. But no, everything seemed to add up, and I knew in my mind exactly the one line of code I needed to add to either prove or disprove your theory. And I also knew that this one line of code was the last thing I needed to try that day. Nothing else. Before, every ‘just 2 more minutes’ I asked for where valiant efforts borne from bug hunting optimism. Now, I see the problem crystal clear.

If the one line proves the theory, I can go to bed safely, be happy that I found the problem, that my stack ws unwound, and I was holding my juggling balls of my mental state in my hands. (Of course, if it disproved the theory, I was in for a night of bad sleep, going over the problem again and again in my head).

So, while Kristien got ready for bed, I moved back to the keyboard, and before the call that I thought was failing in the bindings, added another PyErr_Occurred check, and ran it. And there it went – and it confirmed that the error was actually generated before the line I was looking at, and coming from somewhere else.

So, off to bed, knowing that in the morning I knew exactly where to look.

After some futzing around, I realized that the call before was setting a negative value on a UINT64 property, and it was not erroring out. I was able to reproduce it from a python shell:

>>> import gst
>>> e = gst.element_factory_make('gnlsource')
>>> e.props.start = -1L
>>> import gobject
Traceback (most recent call last):
File "", line 1, in
TypeError: can't convert negative long to unsigned

And after digging through the history of that code, I found the revision where a change was made that removed the error checking for this particular case.

I filed a bug, and that was it. Hours of frustration boiling down to a simple commit labeled ‘guint64 property fix’. The patch is trivial, so I’m sure they will do a better job at it than I would.

Of course, the actual bug is still in my code – I need to figure out why I’m setting a negative start value.

But again I am reminded of a fundamental bug fixing rule that I broke again this time: before trying to fix the bug where it appears to be, first make sure that the bug is where it appears to be. Sometimes the bug is created before where it is detected, and it’s a lot easier to verify that first before anything else.


Filed under: Conference — Thomas @ 11:39 am

11:39 am

Just noticed, while planning holidays with Kristien, that this year’s GUADEC/Desktop Summit actually has its core days on the weekend. In the past I always remember them being during the week, in the center, with the fringe stuff before and after.

Bummer – I have two weddings, one on the starting weekend and one on the ending weekend, so while I was looking forward to going, maybe it doesn’t make so much sense after all to go if I’ll have to miss half of the core stuff already…

« Previous PageNext Page »