Debugging Transient Test Failures with Bash One Liners

I confess that I am rather pleased with myself. I almost certainly messed something up, so it's not like I am going to get a big head or anything. But, for the moment, I am pleased with myself.

The new eee-polymer-tests generator for Karma / Jasmine testing of Polymer elements works pretty darn well. Even if I start a Polymer project with no tests:

$ rm -rf node_modules karma.conf.js test

Making the project dependent on eee-polymer-tests in an NPM package.json:

{
  "name": "parent-events",
  "devDependencies": {
    "eee-polymer-tests": "eee-c/eee-polymer-tests"
  }
}

Will install Karma, Jasmine and generate tests:

$ npm install
|
> eee-polymer-tests@0.0.1 postinstall /home/chris/repos/polymer-book/book/code-js/parent_events/node_modules/eee-polymer-tests
> ./generator.js

What is the name of the Polymer element being tested? click-sink

Generating test setup for: click-sink
Done!

Even better, the generated test, albeit quite simple, actually works without making any changes:

karma start --single-run
INFO [karma]: Karma v0.12.23 server started at http://localhost:9876/
INFO [launcher]: Starting browser Chrome
INFO [Chrome 37.0.2062 (Linux)]: Connected on socket ciIVgf_I_GJhvyvorEtq with id 85510144
Chrome 37.0.2062 (Linux): Executed 1 of 1 SUCCESS (0.049 secs / 0.043 secs)

Well… it works most of the time. Every now and then, I get a failure like:

karma start --single-run
INFO [karma]: Karma v0.12.23 server started at http://localhost:9876/
INFO [launcher]: Starting browser Chrome
INFO [Chrome 37.0.2062 (Linux)]: Connected on socket -cnZn5zrZF_OLuYjrF2l with id 31182079
Chrome 37.0.2062 (Linux) ERROR
  Uncaught TypeError: Cannot read property 'register' of undefined
  at /home/chris/repos/polymer-book/book/code-js/parent_events/bower_components/platform/platform.js:15

Oh, how I hate transient errors like this.

I get a failure like the one above roughly one out of every fives runs. To be sure that I have solved the problem, I am probably going to have to run the test file 10 times before I have any confidence. Fortunately, there are Bash one-liners for just this kind of thing:

$ for i in {1..10}; do karma start --single-run; done

Interestingly—and hopefully something of a clue—this passes for my hand-written specs (all two tests of them):

$ for i in {1..10}; do karma start --single-run; done
Chrome 37.0.2062 (Linux): Executed 2 of 2 SUCCESS (0.083 secs / 0.075 secs)
Chrome 37.0.2062 (Linux): Executed 2 of 2 SUCCESS (0.071 secs / 0.065 secs)
Chrome 37.0.2062 (Linux): Executed 2 of 2 SUCCESS (0.071 secs / 0.066 secs)
Chrome 37.0.2062 (Linux): Executed 2 of 2 SUCCESS (0.073 secs / 0.066 secs)
Chrome 37.0.2062 (Linux): Executed 2 of 2 SUCCESS (0.076 secs / 0.071 secs)
Chrome 37.0.2062 (Linux): Executed 2 of 2 SUCCESS (0.076 secs / 0.073 secs)
Chrome 37.0.2062 (Linux): Executed 2 of 2 SUCCESS (0.088 secs / 0.08 secs)
Chrome 37.0.2062 (Linux): Executed 2 of 2 SUCCESS (0.062 secs / 0.055 secs)
Chrome 37.0.2062 (Linux): Executed 2 of 2 SUCCESS (0.068 secs / 0.063 secs)
Chrome 37.0.2062 (Linux): Executed 2 of 2 SUCCESS (0.066 secs / 0.062 secs)

Perhaps this has something to do with the number of tests? To test that theory, I comment out one test and re-run the remaining test 10 times:

$ for i in {1..10}; do karma start --single-run; done
Chrome 37.0.2062 (Linux): Executed 1 of 1 SUCCESS (0.062 secs / 0.056 secs)
Chrome 37.0.2062 (Linux): Executed 1 of 1 SUCCESS (0.059 secs / 0.054 secs)
Chrome 37.0.2062 (Linux): Executed 1 of 1 SUCCESS (0.053 secs / 0.049 secs)
Chrome 37.0.2062 (Linux): Executed 1 of 1 SUCCESS (0.058 secs / 0.052 secs)
Chrome 37.0.2062 (Linux): Executed 1 of 1 SUCCESS (0.057 secs / 0.051 secs)
Chrome 37.0.2062 (Linux): Executed 1 of 1 SUCCESS (0.055 secs / 0.049 secs)
Chrome 37.0.2062 (Linux): Executed 1 of 1 SUCCESS (0.055 secs / 0.05 secs)
Chrome 37.0.2062 (Linux): Executed 1 of 1 SUCCESS (0.05 secs / 0.045 secs)
Chrome 37.0.2062 (Linux): Executed 1 of 1 SUCCESS (0.054 secs / 0.05 secs)
Chrome 37.0.2062 (Linux): Executed 1 of 1 SUCCESS (0.061 secs / 0.055 secs)

Nope. That's not it.

This suggests that either the problem is in the contents of my tests (the generated one is simpler than my actual hand-coded one that currently seems to work) or the problem has to do with the size of my test file (I only commented out the one test). It seems easier to delete the commented out test in my current spec as a next step. After doing so, I find:

$ for i in {1..10}; do karma start --single-run; done
Chrome 37.0.2062 (Linux) ERROR
  Uncaught TypeError: Cannot read property 'register' of undefined
  at /home/chris/repos/polymer-book/book/code-js/parent_events/bower_components/platform/platform.js:15

Chrome 37.0.2062 (Linux) ERROR
  Uncaught TypeError: Cannot read property 'resolveDom' of undefined
  at /home/chris/repos/polymer-book/book/code-js/parent_events/bower_components/polymer/polymer.js:14

Chrome 37.0.2062 (Linux): Executed 1 of 1 SUCCESS (0.056 secs / 0.051 secs)
Chrome 37.0.2062 (Linux): Executed 1 of 1 SUCCESS (0.055 secs / 0.05 secs)
...

Bingo.

The most obvious solution—and possibly the one with which I am stuck—is to jam a bunch of comments in there. Heck I could even call it documentation. But why is this happening?

Update: Through process of elimination, I track this down to PolymerSetup.js, which does its level best to simulate a normal Polymer setup on a web page:

// 1. Load Polymer before any code that touches the DOM.
var script = document.createElement("script");
script.src = "/base/bower_components/platform/platform.js";
document.getElementsByTagName("head")[0].appendChild(script);

// 2. Load component(s)
var link = document.createElement("link");
link.rel = "import";
link.href = "/base/elements/click-sink.html";
document.getElementsByTagName("head")[0].appendChild(link);

The Polymer documentation is adamant that platform.js be the first script on a page—and this is probably why. And, even though it is the first script here and even though PolymerSetup.js is the first script in the Karma files list and even though it is the first file loaded (verified with --log-level debug on Karma), this is still not always the first file evaluated. And I think that is the cause. If my spec file is sufficiently small, it will be loaded and evaluated before this setup file is able to add platform.js in its proper place.

As I see it, I have three options:

1. Move code that waits for polymer-ready out of PolymerSetup.js into the spec file (making the spec file large enough so that PolymerSetup.js loads and is evaluated first.
2. Remove the platform.js inclusion from PolymerSetup.js and add it first to the files list in karma.conf.js
3. Add junk data to be loaded before the spec files.

Crazy as it might seem, I may opt for #3. I have verified (via Bash for-loops) that all three options work. But the last one is probably the best Polymer solution.

The code that waits for polymer-ready feels like PolymerSetup.js so I would like to keep it there. The proper Karma solution would be #2, but I would end up with platform.js and the element being loaded from two different locations—and via two different mechanisms. The current PolymerSetup.js is not perfect, but it is as close to a normal Polymer solution as I can get (Karma makes it very hard to override the static page that holds the tests).

So adding a dummy file, with an explanation at the top, seems the best bet for my purposes.




Day #172

‹prev | My Chain | next›