Errors get swallowed up after WebSocket callbacks. #44
Description
This issue has been solved. But the solution took about 8-10 hours to find, and warrants an explanation.
https://twitter.com/DanaRSilver/status/718964241743683584
Before I started making server requests, throwing an Error worked fine:
throw new Error();
// Uncaught Error()However, in the callbacks from Backbone.sync, errors were silently swallowed:
var View = Backbone.View.extend({
initialize: function() {
// An Error here would throw
this.listenTo(middguard.Nodes, 'reset', this.render);
middguard.Nodes.fetch({reset: true});
},
render: function() {
// this Error will fail silently
throw new Error();
return this;
}
});
new View();The error in render would be thrown and caught somewhere (but where!?) and any following code would fail.
Tracking down the error
First, I enabled Pause on Exceptions in the Chrome DevTools Sources panel with the optional Pause On Caught Exceptions (these exceptions are being handled) and found where my Error should have been thrown.
The damning line:
I could stop there and just develop always with Pause On Caught Exceptions on, but that's a pretty terrible solution.
Chrome DevTools gives you a nice stack trace from any line you break on.
Using the stack trace, I was able to trace the calls through my code, into Backbone.js, through backbone.iobind, and finally to socket.io.
I ruled out something in my code since I knew I didn't have any global exception handlers, or try catches that squashed the error silently. I ruled out Backbone after quickly searching for try catch statements, onerror handlers, and any sign that it might handle unhandled errors. (The Backbone annotated source code is wonderful.)
Things get complicated with Backbone.iobind. It's a tiny library to bind socket.io's API to Backbone's models and collections with a secondary library (really just a single function) to swap out Backbone's Backbone.sync (which uses jQuery.ajax), for a socket.io based solution.
Backbone.iobind uses a jQuery Deferred Object to handle the callbacks from socket.io. Promises, if implemented or used incorrectly can swallow errors that would otherwise bubble up. Just Google "Promises swallowing errors". jQuery's idea of a Promise is particularly suspicious.
Chrome supports Promises natively, so I rewrote the Promise without jQuery. Same result. I even removed the Promise/$.Deferred entirely, just letting the socket.io callback be called and returning nothing from the replacement Backbone.sync. No difference. I still wasn't seeing errors thrown.
Lots of Googling to this point had unearthed little beyond the issues with Promises swallowing errors, so I ran a few more experiments:
I upgraded backbone.io bind to the latest version. No substantial changes. (Though there is a bug introduced and a PR with a fix waiting to be merged!)
I implemented the endpoint I was reaching over HTTP (rather than WS) and used backbone.iobind's ajaxSync option on the collection to indicate I wanted to use the original Backbone.sync. An error! Finally! But this just confirmed that it was a problem in backbone.iobind or socket.io, not Backbone or my code. This did mean more focused material to Google, though, which eventually confirmed my answer.
I switched back to WS and wrapped the code in the socket.io callback in a try catch, logging the caught error to prevent it from bubbling any higher on the stack. I figured I would trap it and isolate the issue: if it logged it mean't the error wasn't getting caught any higher. To be fair, higher was the Backbone code and my own code. But I was looking for a win after 6 hours on this problem!
It did log something! Once again ruling out an issue higher on the stack.
With this same try catch set up, I commented out the $.Deferred code, though I was pretty sure that wasn't the problem either. The error still was logged. I removed the try catch wrapping the callback code (inside the callback function) and the error was not thrown. At this point I strongly suspected something in socket.io. It was the only piece of the puzzle I hadn't thoroughly audited.
I opened the socket.io-client library and started looking for try catches, onerrors, etc. Lots of material this time. One of socket.io's strength's is it's ability to reconnect and emulate a websocket against all odds. Odds like... throwing an error.
I was disappointed after a cursory look. No really strong evidence it was swallowing up my errors. I turned on debug mode in the Console:
localStorage.debug = '*';Tons of output. Everything socket.io was doing. Nothing that said "Caught Uncaught Error". Disappointing still.
I should mention at this point, I had come across this issue on the socket.io main repo a few hours earlier with a Google search for "socket.io callback swallowing error" and mainly discredited it. It was reported on the wrong repo. No one had every responded. The developer closed it himself. I hadn't come across any other similar questions or issues.
I still had the tab open and came back to it at this point. I returned to the Google results page and started hunting for similar issues.
Lo and behold.
I was starting to feel good that socket.io was my issue. How to test it though... Socket.io is particularly useful (moreso than other clients) because of all it's niceties like namespaces, rooms, heartbeats, etc. All things that work well when both the client and server are using the same library. It's its own protocol over WebSockets. Ideally I'd just drop in another WebSocket library and see if it worked, but that would require too much server work to be practical right now.
Looking at that last issue though, I saw another one from the same user linked. This was the jackpot. Like the other two, it roughly described the problem I was facing, but unlike the others it pointed to the specific version I was using as well!
I was very excited now. I might finally have real fix. After 8 hours of debugging this ridiculous problem.
I updated the package.json and bower.json to the latest versions of socket.io and socket.io-client respectively (they're released together) and reloaded the page.
YES! An error! A beautiful error right where I expected. No debugger open.
There's nothing like that satisfaction of wrestling with a problem for hours on end and finally finding the solution.
Closing thoughts
I don't know why socket.io ever decided to swallow up errors inside event callbacks. socket.io is the kind of API I enjoy using because I can forget about it, not because I love working with it. Lots of magic and big abstractions.
On my part, I should have updated my dependencies once in the past year and a half. That's bitten me more than once on this project.
This reporting is told more linearly than it actually occurred. In between experiments and investigation, there was plenty of second guessing, pacing and reverting to code previous failed fixes.
For now, all is well and I can go back to developing without console.logs everywhere. 🎉