Closed Bug 1312492 Opened 8 years ago Closed 8 years ago

Intermittent browser_ext_tabs_events.js | message queue is empty - Got ["on-updated-dims"], expected []

Categories

(WebExtensions :: Untriaged, defect)

Product:
WebExtensions
Component:
Untriaged
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(firefox50 unaffected, firefox51 unaffected, firefox52 fixed, firefox53 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla53
Tracking Flags:
Tracking Status
firefox50 --- unaffected
firefox51 --- unaffected
firefox52 --- fixed
firefox53 --- fixed

People

(Reporter: aryx, Assigned: robwu)

References

Details

(Keywords: intermittent-failure) 

https://treeherder.mozilla.org/logviewer.html#?job_id=38130189&repo=mozilla-inbound

09:49:35     INFO -  273 INFO TEST-PASS | browser/components/extensions/test/browser/browser_ext_tabs_events.js | tab from update reports expected width -
09:49:35     INFO -  274 INFO TEST-PASS | browser/components/extensions/test/browser/browser_ext_tabs_events.js | tab from update reports expected height -
09:49:35     INFO -  275 INFO TEST-PASS | browser/components/extensions/test/browser/browser_ext_tabs_events.js | tab from onUpdated reports expected width -
09:49:35     INFO -  276 INFO TEST-PASS | browser/components/extensions/test/browser/browser_ext_tabs_events.js | tab from onUpdated reports expected height -
09:49:35     INFO -  277 INFO Console message: [JavaScript Error: "NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIChannel.contentType]" {file: "resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/jsonview/converter-sniffer.js" line: 65}]
09:49:35     INFO -  278 INFO Leaving test bound testTabEventsSize
09:49:35     INFO -  279 INFO Entering test bound testTabRemovalEvent
09:49:35     INFO -  280 INFO Extension loaded
09:49:35     INFO -  281 INFO Console message: Warning: attempting to write 7034 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
09:49:35     INFO -  282 INFO Console message: [JavaScript Error: "NS_ERROR_NOT_INITIALIZED: Component returned failure code: 0xc1f30001 (NS_ERROR_NOT_INITIALIZED) [nsIMessageSender.sendAsyncMessage]" {file: "resource://gre/modules/Extension.jsm" line: 519}]
09:49:35     INFO -  283 INFO Make sure the removed tab is not available in the tabs.query callback.
09:49:35     INFO -  284 INFO TEST-PASS | browser/components/extensions/test/browser/browser_ext_tabs_events.js | Tab query should not include removed tabId -
09:49:35     INFO -  285 INFO TEST-PASS | browser/components/extensions/test/browser/browser_ext_tabs_events.js | tabs-events -
09:49:35     INFO -  286 INFO TEST-PASS | browser/components/extensions/test/browser/browser_ext_tabs_events.js | test result correct -
09:49:35     INFO -  287 INFO Leaving test bound testTabRemovalEvent
09:49:35     INFO -  288 INFO TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_tabs_events.js | message queue is empty - Got ["on-updated-dims"], expected []
09:49:35     INFO -  Stack trace:
09:49:35     INFO -      chrome://mochikit/content/browser-test.js:test_is:909
09:49:35     INFO -      chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:25
09:49:35     INFO -      chrome://mochikit/content/browser-test.js:Tester.prototype.nextTest<:435
09:49:35     INFO -      testScope/test_finish/<@chrome://mochikit/content/browser-test.js:1004:11
09:49:35     INFO -      testScope/test_executeSoon/<.run@chrome://mochikit/content/browser-test.js:935:9
Blocks: 1287007
FYI: When I ran all tests 26x times, the intermittent occurred only twice, and in OSX opt only (with e10s enabled) (not Linux nor OS X debug).

- 1/20 https://treeherder.mozilla.org/#/jobs?repo=try&revision=ea6bf867930b&selectedJob=29638643
  https://treeherder.mozilla.org/logviewer.html#?job_id=29638643&repo=try#L2351
- 1/3 https://treeherder.mozilla.org/#/jobs?repo=try&revision=012e56eb189f&selectedJob=29727094
  https://treeherder.mozilla.org/logviewer.html#?job_id=29727094&repo=try#L11814
- 0/3 https://treeherder.mozilla.org/#/jobs?repo=try&revision=05131d506fdf

In bug 1301862, I predicted that this may happen: the intermittent happens when onUpdated is triggered before the callback of tabs.create is called. I'll leave this open for a (short) while, if the intermittent becomes too frequent, the onUpdated listener could be moved before the tabs.create call to "fix" the tests.

An alternative approach is to somehow make sure that onUpdated listeners in the tabs.create callback get notified of all onUpdated notifications that were generated between the call to tabs.create and the onUpdated listener. Or only perform the actual window creation after the callback is invoked... This is better for extension compatibility, but also more complex to implement.
Assignee: nobody → rob
See Also: → 1301862
https://hg.mozilla.org/mozilla-central/rev/cd8a02710115
Status: NEW → RESOLVED
Closed: 8 years ago
status-firefox53: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla53
Product: Toolkit → WebExtensions
You need to log in before you can comment on or make changes to this bug.