AJAX Logging with Exponential Backoff
I’ve been on something of a JavaScript kick lately. Despite its flaws, it’s a really expressive language that lacks you pack a lot of functionality into just a little bit of (still readable!) code. To that end, I spent some time this morning fiddling around with client-side logging. Specifically, I wanted to be able to make AJAX calls to log user actions from the browser back to the server. This wasn’t really driven by any actual project need, but I think it could be potentially useful in a few scenarios. Maybe you have a public-facing app, and you want to test usability; something like this could make it easy to figure out how people are navigating around your site. This could be especially useful if the site is AJAX-heavy already, or if it’s some kind of mash-up with a lot of calls to third parties.
How do we get started? Let’s build a simple page with a button:
<input id="btn" type="button" value="Click Me!" />
And this is how we want to make our calls:
CLARITY.log('clicked the button at ' + new Date());
Note the use of a global object to act as our namespace. This is a good idea because it lets you minimize your footprint on the global namespace. (I learned this from JavaScript master
Douglas Crockford, who wrote
the best book on the subject I’ve come across.) We’ll hook these up using a little
jQuery. Don’t fret if you’re not too familiar with it; just believe me when i tell you this code will bind a callback to the button’s click event:
$(function () {
$('#btn').click(function () {
CLARITY.log('clicked the button at ' + new Date());
});
});
Let’s go take a look at how CLARITY.log is defined.
var CLARITY = {
log: function (message) {
//do some logging, probably
}
};
As in previous examples, we’re taking advantage of JavaScript’s support for object and function literals to create an object with a property (“log”) on it. The log property is mapped to a function that takes a message parameter and (we hope!) does something interesting with it. First, let’s define a web method for our logging function to call:
[WebMethod]
public static void Log(string msg)
{
// logging happens here
}
I’ve just defined this as a page method. If you were really building something like this out, you might make it a web service call, instead. The difference is pretty transparent from the client-side, so I’m not going to go into it here. I’m also not going to flesh this method out. Server-side logging is a pretty well-explored problem. This is the place to do it.
Let’s take a first cut at our JavaScript logging method:
var CLARITY = {
log: function (message) {
$.ajax({
type: 'POST',
url: 'Default.aspx/Log',
data: JSON.stringify({ msg: message }),
contentType: 'application/json; charset=utf-8',
dataType: 'json'
});
}
};
We’re using jQuery again to make an AJAX call. I like jQuery’s AJAX interface; I think it strikes a good balance between simplicity and giving you complete control over your request. Many of the parameters we specify here are sort of boilerplate for making AJAX calls to ASP.NET (normally, I wrap AJAX calls in a helper method to mitigate this). For more information on this, Dave Ward’s blog is a great resource (this post in particular). The call to JSON.stringify comes from Douglas Crockford’s JSON utility. It’s kind of overkill in this scenario, but I thought I’d point it out, since it’s pretty useful for formatting data for AJAX calls.
To be honest, this is really all we need for logging. However, I thought it might be cool to add some fault tolerance. Maybe (for whatever reason) you’d prefer not to lose any of these logging messages when your server hiccups. We might try to solve that problem with an error handling function that tries again:
var CLARITY = {
log: function (message) {
var tryWrite = function () {
$.ajax({
type: 'POST',
url: 'Default.aspx/Log',
data: JSON.stringify({ msg: message }),
contentType: 'application/json; charset=utf-8',
dataType: 'json',
error: tryWrite
});
}
}
};
Note that what we’ve done here is wrap our AJAX call in a function that quasi-recursively specifies itself as the error handler for the call. This means that every returned error message will immediately fire off another attempt. Note also that message is not used as a parameter for tryWrite; this is unnecessary because tryWrite creates a closure with message in scope.
This isn’t bad for a first attempt, but it has obvious problems. What if the server is down for more than a few seconds? This is going be firing off logging attempts continuously, and it will only get worse as the user continues to click around the page. This will tie up their bandwidth and bombard your server (once it recovers). It will also increase the CPU strain from their browser (though my testing shows this may be negligible). All bad things.
What can we do differently? We might try adding a timer to at least give a buffer between attempts. Something like this:
var CLARITY = {
log: function (message) {
var tryWrite = function () {
$.ajax({
type: 'POST',
url: 'Default.aspx/Log',
data: JSON.stringify({ msg: message }),
contentType: 'application/json; charset=utf-8',
dataType: 'json',
error: function () {
setTimeout(tryWrite, 5000);
}
});
}
tryWrite();
}
};
Here tryWrite is wrapped in a call to setTimeout specifying tryWrite as the callback to be invoked in 5000ms. This will help to some extent. At least we won’t be firing off requests continuously until we succeed. But this still isn’t ideal. As the life of the page wears on, more and more of these will build up, and things will still eventually bog down. We can alleviate these problems with exponential backoff. You’ve probably seen something like this before. The idea is that, as we keep failing, we introduce longer and longer delays between attempts. This helps us to avoid spamming the server. Here’s a simple implementation:
var CLARITY = {
log: function (message) {
var delay = 1000, tryWrite;
tryWrite = function () {
$.ajax({
type: 'POST',
url: 'Default.aspx/Log',
data: JSON.stringify({ msg: message }),
contentType: 'application/json; charset=utf-8',
dataType: 'json',
error: function () {
setTimeout(tryWrite, delay);
delay *= 2;
}
});
}
tryWrite();
}
};
Note that, like tryWrite and message, delay is caught up in our closure, making it something like an implicit parameter. Here we use our delay to set our timer and then double the delay for the next (potential) failure. This guarantees that older failures will remain dormant most of the time, keeping the user from making too many extraneous calls.
This is still a fairly naive implementation, but I thought I’d throw it out there as an example. Hopefully someone can get some ideas from it. A more clever version might be more conservative after a failure (or maybe some small number of failures). It could go into a kind of hibernation state where it pings the server periodically and queues incoming messages to be sent once the server is back online. But that’s probably a topic for another post.
Hope this helps.