First, a little background…
At LogNormal, we measure page load time (among other things) using JavaScript and beacon the results back to our servers. Our JavaScript is based on boomerang and we serve a different build of the JavaScript file for each of our clients. The JavaScript has a max age of 1 week from request and most clients honour this and make a conditional request a week later. Most, but not all. The JavaScript sends us a beacon when complete, and the beacon includes the version number of the JavaScript file.
This configuration has been active for a few months, and the first file served using this configuration was pushed out on February 1st.
Note that all times mentioned are UTC. What we see — Our log files for June 4th show the following:
| JavaScript timestamp | JavaScript version | Number of Requests |
|---|---|---|
| Feb 1 17:33:00 | 0.9.1328117580 | 168 |
| Mar 8 15:39:17 | 0.9.1331221157 | 53 |
| Mar 16 18:16:32 | 0.9.1331921792 | 9 |
| Mar 22 03:33:44 | 0.9.1332387224 | 25 |
| Mar 27 16:39:11 | 0.9.1332866351 | 4 |
| Mar 28 16:03:01 | 0.9.1332950581 | 28 |
| Mar 28 19:59:40 | 0.9.1332964780 | 3 |
| Mar 29 16:04:27 | 0.9.1333037067 | 6 |
| Mar 30 22:23:14 | 0.9.1333146194 | 2 |
| Mar 31 00:52:20 | 0.9.1333155140 | 161 |
| Apr 9 17:34:33 | 0.9.1333992873 | 387 |
| Apr 11 13:37:46 | 0.9.1334151466 | 17 |
| Apr 11 16:46:14 | 0.9.1334162774 | 69 |
| Apr 13 17:35:38 | 0.9.1334338538 | 388 |
| Apr 19 21:26:08 | 0.9.1334870768 | 1 |
| Apr 19 22:43:46 | 0.9.1334875426 | 241 |
| Apr 28 18:11:26 | 0.9.1335636686 | 118 |
| May 1 07:27:15 | 0.9.1335857235 | 169 |
| May 1 22:17:11 | 0.9.1335910631 | 2411 |
| May 23 08:10:48 | 0.9.1337760648 | 1529 |
| May 25 20:41:28 | 0.9.1337978488 | 3837537 |
That last row is the latest version of the file, but as you can see, we still receive beacons from the version we pushed out on Feb 1. I decided to look only at requests from the oldest version of our JavaScript. The first thing to do was see if there was a pattern to these requests. Looking at our logs showed that three IPs accounted for the majority of these requests, and this was common across several days of logs.
Further investigation showed that all three of these IPs were proxies, two of which belonged to the same company and used the bluecat proxy software. I was unable to identify the proxy software running on the third host.
Forcing a cache refresh
As luck would have it, Stoyan and Steve did some research on forcing clients to update a cached script and this was exactly what I needed as the next step.
Our first attempt at this resulted in some of our users complaining about the reload page opening in a new tab. This time I decided to limit the test only to these three IPs and see what happened. Additionally, I made some changes to the reload HTML to let me know if things went wrong, and to avoid infinite loops if the proxy refused to update the script.
This is what the JavaScript in our new reload file looked like:
if(!window.parent) {
BOOMR.version += '-1';
}
else if(window.parent === window) {
BOOMR.version += '-2';
}
if (location.hash === '') {
location.hash = "check";
location.reload(true);
}
else if(location.hostname == 'lognormal.net') {
location.href="about:blank";
}The first two conditions check for exceptional situations that tell us if the page loaded in a new tab, or something weird. The last case makes sure our beacon only fires once (by default it fires every 5 minutes) if the user leaves the page open for a long time.
I added this in the morning of June 5th (UTC). There had been no requests from the Feb 1 version of the JavaScript prior to adding in this change. Over the course of the day, we received the following requests (sanitized for privacy). The displayed fields are: Time, response code, request URL, referrer URL, User Agent.
Remember that these requests come from a Proxy, so we see many different “users” from the same IP.
Beacon request from page belonging to client1, using MSIE 8.0
04:27:12.488 200 reload.html http://client1_page MSIE 8.0Beacon loads reload.html in an iframe
Note that our JavaScript isn't loaded because it's cached
Beacon loaded from reload.html returns a 204 because it knows this is the reload page
04:27:12.673 200 reload.html http://client1_page MSIE 8.0Page reloaded
04:27:12.751 200 client1_js.js reload.html MSIE 8.0JavaScript loaded (returns a 200)
15:25:29.925 200 client2_js.js http://client2_page Chrome/18.0 15:25:30.225 200 beacon.js?d=client2&t=4463033&v=0.9.1337978488 http://client2_page Chrome/18.0 15:28:05.349 200 beacon.js?d=client2&t=4463034&v=0.9.1337978488 http://client2_page Chrome/18.0The 3 requests above are for pages belonging to client2, using Chrome 18, and all have the latest JavaScript, so no reload.
15:53:23.396 200 beacon.js?d=client1&t=4463039&v=0.9.1337978488 http://client1_page MSIE 8.0Another request for a page belonging to client1, but this time with the latest JavaScript
16:08:54.995 200 beacon.js?d=client1 http://client1_page MSIE 8.0 16:08:56.606 200 reload.html http://client1_page MSIE 8.0 16:08:56.844 204 beacon.js?d=lognormal.net reload.html MSIE 8.0 16:08:58.545 200 reload.html http://client1_page MSIE 8.0 16:08:58.609 200 client1_js.js reload.html MSIE 8.0The 5 requests above are probably from a different user behind the same proxy, starts off with the old JavaScript, and ends up with the new JavaScript
17:48:46.666 200 beacon.js?d=client1&t=4463062&v=0.9.1337978488 http://client1_page MSIE 8.0 18:45:34.777 200 beacon.js?d=client1&t=4463073&v=0.9.1337978488 http://client1_page MSIE 9.0 19:16:25.665 200 beacon.js?d=client1&t=4463079&v=0.9.1337978488 http://client1_page MSIE 8.0And finally, 3 requests from MSIE 8 & 9 using the new JavaScript
IP 2 13:07:25.914 200 beacon.js?d=client1 http://client1_page MSIE 8.0 13:07:26.474 200 reload.html http://client1_page MSIE 8.0 13:07:26.662 204 beacon.js?d=lognormal.net reload.html MSIE 8.0 13:07:26.837 200 reload.html http://client1_page MSIE 8.0 13:07:26.990 200 client1_js.js reload.html MSIE 8.0 13:07:36.524 200 beacon.js?d=client1&t=4463006&v=0.9.1337978488 http://client1_page MSIE 8.0From the second IP, we see the same pattern starting with the old JavaScript and ending with the new JavaScript
19:20:14.674 200 beacon.js?d=client1&t=4463080&v=0.9.1337978488 http://client1_page MSIE 8.0 IP 3 13:36:28.651 200 beacon.js?d=client1 http://client1_page MSIE 8.0 13:36:30.385 200 reload.html http://client1_page MSIE 8.0 13:36:32.306 200 reload.html http://client1_page MSIE 8.0 13:36:32.593 200 client1_js.js reload.html MSIE 8.0Same story here, but for some reason beacon.js is never requested a second time
13:48:46.252 200 beacon.js?d=client1 http://client1_page MSIE 8.0 13:50:28.566 200 reload.html http://client1_page MSIE 8.0 13:50:30.087 200 reload.html http://client1_page MSIE 8.0 13:50:30.262 200 client1_js.js reload.html MSIE 8.0Then we go through the whole flow again
13:50:56.891 304 client1_js.js - "Mozilla/4.0 (compatible;)"This is a strange request
13:51:00.284 200 beacon.js?d=client1&t=4463014&v=0.9.1337978488 http://client1_page MSIE 8.0 13:52:41.645 200 beacon.js?d=client1&t=4463015&v=0.9.1337978488 http://client1_page MSIE 8.0 14:05:07.855 200 beacon.js?d=client1&t=4463017&v=0.9.1337978488 http://client1_page MSIE 8.0And a bunch of requests with the latest JavaScript
Results
I looked at the logs again at the end of the day (UTC), and this is what we have for the Feb 1st version:
| JavaScript timestamp | JavaScript version | Number of Requests |
|---|---|---|
| Feb 1 17:33:00 2012 | 0.9.1328117580 | 35 |
The number of requests from the Feb 1 version of our JavaScript went down significantly, however, we should really look at the ratio.
On June 4, 153 out of 168 or 91% of requests from the Feb 1 version of our JavaScript came from the three IPs I looked at.
On June 5, the ratio is 6 out of 35 or 17%, giving us a 81% reduction in stale cache hits.
I’ll look at the numbers again tomorrow and update this post at that time and if things look good, will extend it to a few more IPs and versions.
Have thoughts on what else I should be looking at? Let me know in the comments. Interested in trying out LogNormal, visit our plans page.
Update: June 7
On June 6, 0 out of 84 requests using the Feb 1 version of our JavaScript came from the three IPs I looked at. We still receive many requests from old versions of our JavaScript, and over time we will try to get all of them to load up the latest version.