Wednesday, July 3, 2013

Missed Event

‹prev | My Chain | next›

One of the nice things about writing every day is that I can skip over something that I don't understand. Of course, that only works if I make a bargain with myself to follow up the next night and then follow-up. Tonight I honor such a bargain.

Last night, I focused on getting a bug fix in the latest version of the ICE Code Editor out to beta. The bug fix was fairly easy (displaying the preview after the iframe was ready instead of after a fixed time). But just before I was prepared to commit the fix, I realized that my tests were failing:
ERROR: Update Button updates the preview layer
  Callback called (2) after test case Update Button updates the preview layer has already been marked as pass.
Interestingly, updating the preview layer once the containing iframe was ready seems to result in two updates to the preview layer whereas a time delay only generated a single update.

The test itself could not be conceptually simpler. It checks only that a preview event is placed on the onPreviewChange stream:
    test("updates the preview layer", (){
      document.activeElement.
        dispatchEvent(new TextEvent('textInput', data: '<h1>Hello</h1>'));

      editor.onPreviewChange.listen(expectAsync1((_)=> true));

      helpers.click('button', text: " Update");
    });
When the event is generated in the code after a time delay:
class Editor {
  // ...
  updatePreview() {
    // ...
    var iframe = this.createPreviewIframe();
    var wait = new Duration(milliseconds: 100);
    new Timer(wait, (){
      // Actually update the preview here...
      _previewChangeController.add(true);
    });
  }
  // ...
}
The test was passing.

But, when I change this to wait for the containing iframe to load:
class Editor {
  // ...
  updatePreview() {
    // ...
    var iframe = this.createPreviewIframe();
    iframe.onLoad.listen((_) {
      // Actually update the preview here...
      _previewChangeController.add(true);
    });
  }
  // ...
}
The test fails because the _previewChangeController.add(true) at the end is called twice, placing two events on the onPreviewChange stream.

The quick and dirty solution that I arrived at was to make use of the iterable nature of streams in Dart. This allows me to listen once to the stream:
class Editor {
  // ...
  updatePreview() {
    // ...
    var iframe = this.createPreviewIframe();
    iframe.onLoad.first.then((_) {
      // Actually update the preview here...
      _previewChangeController.add(true);
    });
  }
  // ...
}
That magically fixes this test, a couple of exceptions, and seems the make the application much snappier as well.

Part of me is tempted to leave well enough alone. This is almost certainly the right fix since it solves so many problems and works in the actual browser (including Firefox, which is the only place the original bug was manifesting). But I hate committing fixes without understanding. It is eminently possible that the underlying cause is something simple and obvious. But there is always the the chance that the explanation is something sublime.

Sadly, the source of this behavior turns out to be quite humble. The first onLoad event is caused by the load of the preview_frame.html file that is the src of the iframe. The second is generated when the “Actually update the preview here...” code sends the content of the editor to preview_frame.html via a postMessage. When preview_frame.html receives this message, it overwrites its own content with a document.write().

It is somewhat unexpected that performing a document.write() results in an onLoad event in the containing document, but this is the cause. If I comment out the document.write() in preview_frame.html (actually, the corresponding document.close() is what really does it), then no problems occur.

Happily, the iframe.onLoad.first.then() is the exact way to resolve this. Once the first onLoad has fired, the preview_frame.html content is loaded and ready to receive postMessages. I now have an explanation to along with the correct code, which is a fine stopping point for tonight.


Day #801

No comments:

Post a Comment