624903 - NS_ERROR_NOT_IMPLEMENTED exceptions calling nsIFrameLoaderOwner.swapFrameLoaders during panel tests

Status: RESOLVED FIXED

(Add-on SDK Graveyard :: General, defect)

Description

[Myk Melez [:myk] [@mykmelez]]

When running panel tests, I periodically see NS_ERROR_NOT_IMPLEMENTED exceptions when calling nsIFrameLoaderOwner.swapFrameLoaders.  Here's an example on Windows:

--------------------------------------------------------------------------------
(Z:\myk\Projects\addon-sdk) Z:\myk\Projects\addon-sdk\packages\addon-kit>cfx test -f test-panel.js --binary="C:\Program
Files (x86)\Minefield\firefox.exe"
Using binary at 'C:\Program Files (x86)\Minefield\firefox.exe'.
Using profile at 'c:\users\myk\appdata\local\temp\tmpwrivqz.mozrunner'.
Running tests on Firefox 4.0b9pre/Gecko 2.0b9pre ({ec8030f7-c20a-464f-9b0e-13a3a9e97384}) under WINNT/x86-msvc.
........error: An exception occurred.
Traceback (most recent call last):
  File "resource://addon-kit-addon-kit-lib/panel.js", line 228, in _onShow
    this._frameLoadersSwapped = true;
  File "resource://addon-kit-addon-kit-lib/panel.js", line 93, in null
    .swapFrameLoaders(this._viewFrame);
[Exception... "Component returned failure code: 0x80004001 (NS_ERROR_NOT_IMPLEMENTED) [nsIFrameLoaderOwner.swapFrameLoad
ers]"  nsresult: "0x80004001 (NS_ERROR_NOT_IMPLEMENTED)"  location: "JS frame :: resource://addon-kit-api-utils-lib/secu
rable-module.js -> resource://addon-kit-api-utils-lib/securable-module.js -> resource://addon-kit-addon-kit-lib/panel.js
 :: <TOP_LEVEL> :: line 93"  data: no]
console: Invalid use of the preferences on a background thread!
console: Invalid use of the preferences on a background thread!
console: Direct3D 9 DeviceManager Initialized Succesfully.
Driver: vm3dum.dll
Description: VMware SVGA 3D (Microsoft Corporation - WDDM)
Version: 7.14.1.42
error: TEST FAILED: test-panel.testResizePanel (timed out)
.error: fail: error was emitted:Component returned failure code: 0x80004001 (NS_ERROR_NOT_IMPLEMENTED) [nsIFrameLoaderOw
ner.swapFrameLoaders]
undefined
info: Traceback (most recent call last):
  File "resource://addon-kit-addon-kit-lib/panel.js", line 231, in _onShow
    this._emit('error', e);
  File "resource://addon-kit-api-utils-lib/events.js", line 129, in _emit
    return this._emitOnObject.apply(this, args);
  File "resource://addon-kit-api-utils-lib/events.js", line 159, in _emitOnObject
    listener.apply(targetObj, params);
  File "resource://addon-kit-addon-kit-tests/test-panel.js", line 135, in null
    test.fail('error was emitted:' + e.message + '\n' + e.stack);
  File "resource://addon-kit-api-utils-lib/unit-test.js", line 113, in fail
    console.trace();
..............error: fail: The panel was resized.
info: Traceback (most recent call last):
  File "resource://addon-kit-addon-kit-lib/panel.js", line 215, in _onHide
    this._emit('hide');
  File "resource://addon-kit-api-utils-lib/events.js", line 129, in _emit
    return this._emitOnObject.apply(this, args);
  File "resource://addon-kit-api-utils-lib/events.js", line 159, in _emitOnObject
    listener.apply(targetObj, params);
  File "resource://addon-kit-addon-kit-tests/test-panel.js", line 84, in null
    "The panel was resized.");
  File "resource://addon-kit-api-utils-lib/unit-test.js", line 164, in assert
    this.fail(message);
  File "resource://addon-kit-api-utils-lib/unit-test.js", line 113, in fail
    console.trace();

22 of 25 tests passed.
FAIL
Total time: 22.720000 seconds
Program terminated unsuccessfully.
--------------------------------------------------------------------------------

And here's one on Linux:

--------------------------------------------------------------------------------
(addon-sdk)myk@myk:~/Projects/addon-sdk/packages/addon-kit$ cfx test -f test-panel.js
Using binary at '/home/myk/bin/firefox'.
Using profile at '/tmp/tmptho8fr.mozrunner'.

(firefox-bin:9766): GLib-WARNING **: g_set_prgname() called multiple times
Running tests on Firefox 4.0b10pre/Gecko 2.0b10pre ({ec8030f7-c20a-464f-9b0e-13a3a9e97384}) under Linux/x86-gcc3.
..........error: TEST FAILED: test-panel.testSeveralShowHides (failure)
error: fail: error was emitted:Component returned failure code: 0x80004001 (NS_ERROR_NOT_IMPLEMENTED) [nsIFrameLoaderOwner.swapFrameLoaders]
undefined
info: Traceback (most recent call last):
  File "resource://addon-kit-api-utils-lib/observer-service.js", line 174, in null
    this.callback(subject, data);
  File "resource://addon-kit-api-utils-lib/content/symbiont.js", line 163, in _onStart
    this._onInit();
  File "resource://addon-kit-addon-kit-lib/panel.js", line 242, in _onInit
    this._emit('inited');
  File "resource://addon-kit-api-utils-lib/events.js", line 129, in _emit
    return this._emitOnObject.apply(this, args);
  File "resource://addon-kit-api-utils-lib/events.js", line 159, in _emitOnObject
    listener.apply(targetObj, params);
  File "resource://addon-kit-addon-kit-lib/panel.js", line 231, in _onShow
    this._emit('error', e);
  File "resource://addon-kit-api-utils-lib/events.js", line 129, in _emit
    return this._emitOnObject.apply(this, args);
  File "resource://addon-kit-api-utils-lib/events.js", line 159, in _emitOnObject
    listener.apply(targetObj, params);
  File "resource://addon-kit-addon-kit-tests/test-panel.js", line 135, in null
    test.fail('error was emitted:' + e.message + '\n' + e.stack);
  File "resource://addon-kit-api-utils-lib/unit-test.js", line 113, in fail
    console.trace();
..............
24 of 25 tests passed.
FAIL
Total time: 3.012058 seconds
Program terminated unsuccessfully.
--------------------------------------------------------------------------------


Over in bug 606007, comment 8, Alex mentioned that he noticed some race conditions while working on the fix for bug 619991.

Alex: can you describe the race conditions you discovered?

Comment 1

[Alexandre Poirot [:ochameau]]

Attachment: swapFrameLoaders behavior in unit test

As I was not able to produce an unit test on Panel that throw this exception at *all* executions, I wrote this unit test that highlight what kind of race condition we may have with panel code.
I really convinced that this is our intermittent failure, that is not only occur during unit test execution, but in real world usage too!
To resume, we create a XUL iframe in panel that will load receive content of an hidden iframe which load contentURL. We do this by calling swapFrameLoaders.
But swapFrameLoaders is going to work only when both DOMContentLoaded event is fired from both iframes.
I think we wait for this event for the hidden iframe, but clearly not for the panel iframe!!!

Comment 2

[Alexandre Poirot [:ochameau]]

Attachment: Update unit test with a fix

Here is the output of this unit test:
debug: ## 3 - Call swapFrames immediatly on iframe2
debug: NS_ERROR_NOT_IMPLEMENTED exception from swapFrameLoaders,
   iframe may not be ready!
debug: ## 4 - Call swapFrames after DOMContentLoaded on iframe2
debug: swapFrameLoaders succeeded!
debug: ## 6 - Call swapFrames immediatly on iframe3
debug: swapFrameLoaders succeeded!

So adding: frame3.setAttribute("src","data:,"); 
solve this problem as swapFrameLoaders doesn't throw anymore, even if we call it immediatly after iframe creation!

Comment 3

[Alexandre Poirot [:ochameau]]

Attachment: Patch to add this one line fix in panel.js

Add this iframe.setAttribute("src","data:,"); magic line to panel.js.
But as I do not have unit test that raise this exception ... I can't be sure that the problem is solved!

Comment 4

[Myk Melez [:myk] [@mykmelez]]

Comment on attachment 509100 [details] [diff] [review]
Patch to add this one line fix in panel.js

Hunh, I didn't realize one could immediately load an empty document in this way!  I wonder if the load is truly synchronous or is just so fast that it triggers the race condition much more rarely.  In any case, this is a handy fix!

Comment 5

[Myk Melez [:myk] [@mykmelez]]

https://github.com/mozilla/addon-sdk/commit/94135b548017a8d14fed015f4b6aee3832ebf38e