Wednesday, September 4, 2013

Regression Testing of Script Load Order


I have a bug in the ICE Code Editor. That is nothing new, all projects have bugs in them. But this particular bug has been tough to isolate and I suspect that it is because of varying latencies when used on a production system.

The problem manifests itself when a new user of the ICE Code Editor follows a shared link. Shared links in ICE are Gzip encoded strings of the content in a code project. The Gzip string is encoded with base64 and jammed into a URL hash like so: http://gamingjs.com/ice/#B/88gvT6nUUXDKT1IEAA==. ICE tries to decode this, but—sometimes—will get the following error:
Uncaught Error: NoSuchMethodError : method not found: 'RawDeflate'
The missing RawDeflate is coming from a JavaScript file by way of Dart's js-interop and is used to parse that Gzip'd URL hash.

In this case, it seems that the Dart code is unable to call the JavaScript RawDeflate. My guess is that latency between me and the gamingjs.com site is to blame. Only I cannot reproduce the problem locally.

Well, of course I cannot reproduce locally—there is no latency on a local system, right? Actually, I can use the Linux traffic control utility tc to add any latency to the loopback device:
$ sudo tc qdisc add dev lo root netem delay 200ms
With that, the round-trip time for packets to and from localhost is 400ms:
➜  ~  ping localhost
PING localhost (127.0.0.1) 56(84) bytes of data.
64 bytes from localhost (127.0.0.1): icmp_req=1 ttl=64 time=400 ms
64 bytes from localhost (127.0.0.1): icmp_req=2 ttl=64 time=400 ms
That ought to be more than enough to reproduce latency issues. But it is not.

I am eventually able to get this to work fairly reliably—but still not regularly—going against the gamingjs.com site. I add latency to my wireless network device:
sudo tc qdisc add dev eth1 root netem delay 200ms
And can see the problem more often than not in Firefox. And when I do reproduce, I find that my hypothesis was correct. The RawDeflate.js library is not loading in time:



Not loaded in time in ICE is all relative to the ACE JavaScript file. Once that loads, all manner of Futures complete—even one that tries to parse URL hashes with Gzip data. But there are still 300ms before the Rawdeflate JavaScript library is ready to be used.

Last night I added a future that completes when Rawdeflate loads, meaning that I can delay URL hash parsing until Rawdeflate is available. But how do I test this to make sure that I have really solved my problem?

I could add latency to my Dart unittests, but even that may not be enough. I cannot reproduce the error in Chrome. It seems that Chrome's pipes are a bit warmer than Firefox's:



I think the main problem is that Chrome's warmest pipe (yes, I'm serious about warm pipes—read SPDY Book!) is used for the source map file. The remaining colder pipes are used for ACE and the deflate libraries. Since ACE is loaded over a cold pipe and because it is large, it does not finish loading until after the smaller Rawdeflate. In Firefox on the other hand, the hot pipe is used for ace, which means that the ace library loads, triggering all those futures, before rawdeflate can load over that cold pipe.

What will kill me when trying to write a test for this is that all of my tests run Dart code. When compiled to JavaScript and served from a place like gamingjs.com, only a few files are needed to transfer. But the original Dart is comprised of nearly a hundred small class files. Each one of those files needs to be transferred before any of the JavaScript, which warms all of Chrome's pipes—not just the first one:



So I am out of luck, right? Nope!

I can borrow a trick from gamingjs.com in order to fake the kind of latency behavior that I want. That trick is application cache. I add a latency.appcache manifest file to my local ICE page:
<!DOCTYPE html>
<html manifest="editor.appcache">
  <!-- Dart scripts as before -->
</html>
And in that manifest, I add a single file—the ace.js that I need to load before Rawdeflate:
CACHE MANIFEST
# 2013-09-04

CACHE:
/packages/ice_code_editor/js/ace/ace.js

NETWORK:
*
And that actually works:



The error is generated locally thanks to a combination of application cache and tc-induced latency (and yes, the artificial latency is needed).

This will not quite work in my test suite. I use content_shell to run browser-based Dart unittests. I verify that content_shell does honor application cache and can reproduce my error:
➜  ice-code-editor git:(master) ✗ content_shell \
    --dump-render-tree \
    'http://localhost:8080/full.html#B/88gvT6nUUXDKT1IEAA=='
CONSOLE MESSAGE: Uncaught Error: NoSuchMethodError : method not found: 'RawDeflate'
Receiver: top-level
Arguments: []
CONSOLE MESSAGE: Stack Trace:
#0      Proxy._forward (package:js/js.dart:1038:20)
#1      Proxy.noSuchMethod (package:js/js.dart:1027:20)
#2      Gzip.decode (package:ice_code_editor/gzip.dart:12:23)
#3      Full._openProject (package:ice_code_editor/full.dart:239:28)
#4      Full.Full.<anonymous closure> (package:ice_code_editor/full.dart:25:32)
...
The problem is that I usually run content_shell against file:// URLs. Application cache directives are ignored unless the web page is served from a web server. So I will need to come up with a robust solution for regression testing of asynchronous script load issues tomorrow.

But as far as I can tell from my work tonight, it ought to be possible.


Day #864

No comments:

Post a Comment