Links

Patrick Mueller elsewhere: muellerware.org, twitter.com/pmuellr

Friday, May 20, 2011

callback debugging - better mobile error diagnostics

One of the common issues that comes up regarding debugging mobile web apps, is that the error diagnostics for JavaScript are terrible. Sometimes non-existent. Current state of the art is to turn on the "Debug Console" switch in Mobile Safari, which is kinda horrifying, but does provide some information. Or use low-level debug tools like Android's logcat. These tools provide additional clues about JavaScript errors that have occurred.

But I've wanted to add something to weinre, and a while back opened issue 38 - "provide better error handling - by hook or by crook". My first attempt was to try overriding some addEventListener() functions, which would instrument the callback methods passed to them. The instrumentation was to wrap the invocation of the original callback in a try/catch, and if something was caught, report it. The reason this is a good avenue to go down is that after the top-level JavaScript code in your HTML and JavaScript files runs, everything else is run because of a callback somewhere. If you can control the callbacks, you control JavaScript.

Aside, there's a number of interesting links in that bug report:

I decided to spend some time on the error diagnostics issue this week, but first did a cursory Google search, and found an article by Tom Robinson on the subject. Basically describes the approach I was heading down, so things still sounded promising.

Since I didn't see any kind of existing library to do this kinda stuff, I wrote one - CBWrapper. Putting it in a separate GitHub repository for now, because it's kind of a general purpose callback diagnostic tool. Could be useful in Node, perhaps. If it turns out to be useful and safe for weinre, I'll add it, but for now you can use it as a separate set of script files.

Here's what it can do. Keep in mind that the normal amount of JavaScript error handling you get in weinre is - nothing. Add the CBWrapper scripts as indicated on it's page, and you'll instead see the following output in the weinre console. Note that the information displayed is different depending on your web browser's JavaScript engine. I only tested under Mobile Safari and Android's Browser.

under JSC - all Apple devices and older Android devices

exception: TypeError: Result of expression 'xScript' [null] is not an object.
location:  https://[[url-elided]]/CBWrapper/tests/script-runtime-error-function.js:8
callback:  window.setTimeout(aScript(), 2000)

under V8 - newer Android devices

exception: TypeError: Cannot call method 'doSomething' of null
callback:  window.setTimeout(aScript(), 2000)
           [http://[[url-elided]]/CBWrapper/tests/test-weinre-runtime-function-script.html:10]
stack:
TypeError: Cannot call method 'doSomething' of null
    at bScript (http://[[url-elided]]/CBWrapper/tests/script-runtime-error-function.js:8:11)
    at aScript (http://[[url-elided]]/CBWrapper/tests/script-runtime-error-function.js:3:5)
    at cbWrapper (http://[[url-elided]]/CBWrapper/CBWrapper.js:253:27)
    at http://[[url-elided]]/target/target-script-min.js#test:3674:14

Curiously, the exception messages are wildly different here. The line that threw the exception was:

    xScript.doSomething() // where xScript == null

Note that besides the other information provided, there's a line labelled "callback", which gives you some information about the function that registered the callback that just threw the error. In this case, it was a window.setTimeout() call, and the message provides some contextual information on the call itself. The registration function is no longer on the stack, but I keep a reference to it in case you want it. Like in this case.

CBWrapper can do a lot more than log errors. It provides before/after callbacks before every callback that it wraps, so you can do things like get the elapsed time of all the callbacks, log callback events on the Web Inspector timeline, etc. In theory.

Practice, however, is a different story. Playing with it a bit, under weinre, led me to some issues. See, weinre itself uses some of the same callbacks that CBWrapper wraps, so it's pretty easy to fall into a trap where you do something in a CBWrapper callback (write to the console), which causes weinre code to set a timer or do an XHR, and you've just created an endless chain of console logs / CBWrapper callbacks that will never end. The callback-based async version of infinite recursion.

Finally, Kent Beck posted the following message on Twitter today:

the problem with callbacks triggering callbacks triggering callbacks is that when something goes wrong, reading the code doesn't help much

Seems like maybe you could whip something up with CBWrapper that could show you callbacks registered from other callbacks, and then show a trail of those callbacks when an error is thrown. Would that help? Only one way to find out and I'll leave that as an exercise for the reader.