Forge Code

Scripting iTunes With Ruby, and Snow Leopard's Apple Events Bug

About 2 weeks ago, I made a post to the rb-appscript-discuss mailing list about an error I was receiving while working with rb-appscript. rb-appscript is an event bridge that allows you to use Ruby instead of AppleScript to communicate with scriptable applications on Mac OS X.

As a programmer, I find AppleScript tedious at best. For better or worse, my brain has adapted to understanding programming languages that have non-ambiguous, concise grammars. I find it a lot easier to use a “real” programming language, and luckily enough, in 2009, we can use a number of languages as an AppleScript substitute, including Ruby.

Since I don’t actually know much about AppleScript or how it works, I didn’t appreciate the fact that you can use AppleScript to request data, with a logical set of constraints, and that the constraints will be filtered within the client app. This means that you can do the following with iTunes (this is pseudo-code, not AppleScript):

get all tracks where the track length is greater than 300 seconds,
    and the track length is less than 310 seconds
    and the artist is "Radiohead"

This can be achieved in rb-appscript using the following:

app('iTunes').playlists[1].tracks[its.duration.gt(300).and(
                                its.duration.lt(310)).and(
                                its.artist.eq("Radiohead"))].get

That line of code takes about 0.2 seconds to execute on my 2GHz Core Duo MacBook, and I have an iTunes library of around 5000 songs. When I started working with rb-appscript, I didn’t realise this was possible, and I was using Ruby enumerables to do my data filtering like so (this example finds all songs by Radiohead):

app('iTunes').playlists[1].tracks.get.select { |track|
  track.artist.get == 'Radiohead'
}

This line of code takes around 2 seconds to execute. There’s a number of reasons that it’s so slow, but a major reason is that for every track in the iTunes library, a separate Apple Event is being sent to iTunes to request its ‘artist’. The script I was working on (which I’ll describe in detail in a later post) was doing quite a bit of data filtering, which when done in this fashion using Ruby enumerables, was sending a crap load of Apple Events. Occasionally, on my Mac Pro (which has 10.6.1 installed), my script would freeze, and I’d get the following message:

OSERROR: -1712
MESSAGE: Apple event timed out.

I did a bit of testing, and discovered that the same script would not freeze on any machine running 10.5. I made a post to the rb-appscript-discuss list, and after following Matt Neuburg’s suggestion that it might be caused by a Scripting Addition, I removed /Library/ScriptingAdditions/Adobe Unit Types.osax, and restarted, which seemed to fix the problem. Although everything seemed to be working again, I had a nagging feeling that perhaps the restart was what “fixed” things.

I was able to work for a few days without any crashes, until eventually my script froze while attempting a particularly long sequence of data requests. I posted to the rb-appscript-mailing list again, and after describing in more specific detail what was happening, was able to get Matt Neuburg to reproduce the bug also. Given that the freeze would only happen after a large number of Apple Events, Matt had the insight to write a script that would count the number of Apple Events before the freeze occurred. He mentioned that the “crash count” for him was a number close to 65535 (216 - 1, which is the largest number you can represent in an unsigned 16-bit integer). I ran his script, and initially got a number around 47000. After quite a bit of experimenting and collecting of data, I discovered the following things:

  • Restarting the computer would reset the crash count to something near 65535
  • Every time a crash occurred, the next crash count would be slightly smaller
  • The crash count was independent of the process you send Apple Events to, it was system-wide

After reporting this information to Matt on rb-appscript-discuss, he was able to get in touch with the right people, and was able to diagnose the exact nature of the problem. It looks like Apple may even be rolling a bug-fix into 10.6.2.

If I had actually known what I was doing with AppleScript or rb-appscript when I started working on this particular project, I never would’ve encountered this bug, and it may have stayed lurking in the Snow Leopard source code until someone else inadvertently “stress tested” the Apple Events sub-system.

Matt has a full write-up on the bug in his comprehensive article over at TidBITS, which explains part of the Apple Events mechanism and the actual bug itself.

Comments