Closed
Bug 1453260
Opened 6 years ago
Closed 6 years ago
Intermittent browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | Error: Error: Attempt to postMessage on disconnected port :: @moz-extension://d02e4296-f26d-451b-9e1a-ddf81bc133
Categories
(WebExtensions :: General, defect, P5)
WebExtensions
General
Tracking
(firefox61 fixed)
RESOLVED
FIXED
mozilla61
| Tracking | Status | |
|---|---|---|
| firefox61 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: robwu)
References
Details
(Keywords: intermittent-failure)
Attachments
(1 file)
Filed by: apavel [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=173038363&repo=autoland https://queue.taskcluster.net/v1/task/PxEBYucwSaGZN3qh8kl1RQ/runs/0/artifacts/public/logs/live_backing.log 07:52:57 INFO - 295 INFO Console message: Warning: attempting to write 4961 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. 07:52:57 INFO - 296 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: open_extension_tab, Actual: open_extension_tab - 07:52:57 INFO - 297 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: connect_from_contentscript, Actual: connect_from_contentscript - 07:52:57 INFO - 298 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: connect_from_contentscript, Actual: connect_from_contentscript - 07:52:57 INFO - Buffered messages logged at 07:52:57 07:52:57 INFO - 299 INFO Console message: [JavaScript Error: "TypeError: win.gBrowser is undefined" {file: "resource:///modules/ProcessHangMonitor.jsm" line: 412}] 07:52:57 INFO - 300 INFO Console message: [JavaScript Error: "TypeError: win.gBrowser is undefined" {file: "resource:///modules/BrowserUsageTelemetry.jsm" line: 100}] 07:52:57 INFO - 301 INFO Console message: [JavaScript Error: "TypeError: win.gBrowser is undefined" {file: "resource:///modules/ProcessHangMonitor.jsm" line: 412}] 07:52:57 INFO - 302 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: ping, Actual: ping - 07:52:57 INFO - 303 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: disconnect-me, Actual: disconnect-me - 07:52:57 INFO - 304 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: disconnect-me, Actual: disconnect-me - 07:52:57 INFO - Buffered messages finished 07:52:57 ERROR - 305 INFO TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | Error: Error: Attempt to postMessage on disconnected port :: @moz-extension://d02e4296-f26d-451b-9e1a-ddf81bc13391/%7Bac268a1c-a040-4ca6-b809-16bd40142005%7D.js:17:13 07:52:57 INFO - - 07:52:57 INFO - Stack trace: 07:52:57 INFO - @moz-extension://d02e4296-f26d-451b-9e1a-ddf81bc13391/%7Bac268a1c-a040-4ca6-b809-16bd40142005%7D.js:19:13 07:52:57 INFO - 306 INFO Console message: Ignoring response to aborted listener for 256 07:52:57 INFO - 307 INFO Leaving test bound extension_tab_connect_and_move_tabs 07:52:57 INFO - Not taking screenshot here: see the one that was previously logged 07:52:57 ERROR - 308 INFO TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | message queue is empty - Got ["port_ping_ponged_before_disconnect"], expected [] 07:52:57 INFO - Stack trace: 07:52:57 INFO - chrome://mochikit/content/browser-test.js:test_is:1280 07:52:57 INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:27 07:52:57 INFO - chrome://mochikit/content/browser-test.js:Tester.prototype.nextTest<:675 07:52:57 INFO - testScope/test_finish/<@chrome://mochikit/content/browser-test.js:1372:11 07:52:57 INFO - run@chrome://mochikit/content/browser-test.js:1309:9 07:52:57 INFO - GECKO(7700) | MEMORY STAT | vsize 2099154MB | vsizeMaxContiguous 130240509MB | residentFast 438MB | heapAllocated 204MB 07:52:57 INFO - 309 INFO TEST-OK | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | took 2955ms 07:52:57 INFO - 310 INFO checking window state
|
Assignee | |
Comment 1•6 years ago
|
||
Given the duplicate log entries, I suspect that somewhere, there is an existing tab with URL "http://mochi.test:8888", which causes the content script to run in addition to the extension page. Consequently, the test in the onConnect handler is run twice, causing the test to fail when the end-of-test signal from the first test instance interrupts the second test instance. To fix this I am going to make the content script pattern more specific.
Assignee: nobody → rob
Status: NEW → ASSIGNED
Flags: needinfo?(rob)
| Comment hidden (mozreview-request) |
|
||
Comment 3•6 years ago
|
||
| mozreview-review | ||
Comment on attachment 8966960 [details] Bug 1453260 - run test script in specific page only https://reviewboard.mozilla.org/r/235646/#review241572 Ah yes, the main window is open on http://mochi.test:8888/ You could just use example.com or something instead but this works too.
Attachment #8966960 -
Flags: review?(aswan) → review+
Pushed by rob@robwu.nl: https://hg.mozilla.org/integration/autoland/rev/22ebb890e8ed run test script in specific page only r=aswan
|
||
Comment 5•6 years ago
|
||
| bugherder | ||
https://hg.mozilla.org/mozilla-central/rev/22ebb890e8ed
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
status-firefox61:
--- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla61
|
||
Comment 6•6 years ago
|
||
Given this log https://treeherder.mozilla.org/logviewer.html#?job_id=173737499&repo=autoland&lineNumber=3050 this fails doesn't seem to be fixed. 01:32:07 INFO - 253 INFO TEST-START | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js 01:32:08 INFO - GECKO(4752) | JavaScript error: resource:///modules/BrowserUsageTelemetry.jsm, line 100: TypeError: win.gBrowser is undefined 01:32:08 INFO - GECKO(4752) | JavaScript error: resource:///modules/ProcessHangMonitor.jsm, line 412: TypeError: win.gBrowser is undefined 01:32:09 INFO - GECKO(4752) | JavaScript error: resource:///modules/ProcessHangMonitor.jsm, line 412: TypeError: win.gBrowser is undefined 01:32:09 INFO - GECKO(4752) | JavaScript error: resource:///modules/BrowserUsageTelemetry.jsm, line 100: TypeError: win.gBrowser is undefined 01:32:09 INFO - GECKO(4752) | JavaScript error: resource:///modules/ProcessHangMonitor.jsm, line 412: TypeError: win.gBrowser is undefined 01:32:10 INFO - TEST-INFO | started process screenshot 01:32:10 INFO - TEST-INFO | screenshot: exit 0 01:32:10 INFO - Buffered messages logged at 01:32:07 01:32:10 INFO - 254 INFO Entering test bound contentscript_connect_and_move_tabs 01:32:10 INFO - 255 INFO Extension loaded 01:32:10 INFO - 256 INFO Console message: Warning: attempting to write 4881 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. 01:32:10 INFO - 257 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: connect_from_script, Actual: connect_from_script - 01:32:10 INFO - Buffered messages logged at 01:32:08 01:32:10 INFO - 258 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: ping, Actual: ping - 01:32:10 INFO - 259 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: disconnect-me, Actual: disconnect-me - 01:32:10 INFO - 260 INFO Leaving test bound contentscript_connect_and_move_tabs 01:32:10 INFO - 261 INFO Entering test bound extension_tab_connect_and_move_tabs 01:32:10 INFO - 262 INFO Extension loaded 01:32:10 INFO - 263 INFO Console message: Warning: attempting to write 4961 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. 01:32:10 INFO - 264 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: open_extension_tab, Actual: open_extension_tab - 01:32:10 INFO - 265 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: connect_from_script, Actual: connect_from_script - 01:32:10 INFO - 266 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: connect_from_script, Actual: connect_from_script - 01:32:10 INFO - Buffered messages logged at 01:32:09 01:32:10 INFO - 267 INFO Console message: [JavaScript Error: "TypeError: win.gBrowser is undefined" {file: "resource:///modules/BrowserUsageTelemetry.jsm" line: 100}] 01:32:10 INFO - 268 INFO Console message: [JavaScript Error: "TypeError: win.gBrowser is undefined" {file: "resource:///modules/ProcessHangMonitor.jsm" line: 412}] 01:32:10 INFO - 269 INFO Console message: [JavaScript Error: "TypeError: win.gBrowser is undefined" {file: "resource:///modules/ProcessHangMonitor.jsm" line: 412}] 01:32:10 INFO - Buffered messages logged at 01:32:10 01:32:10 INFO - 270 INFO Console message: [JavaScript Error: "TypeError: win.gBrowser is undefined" {file: "resource:///modules/BrowserUsageTelemetry.jsm" line: 100}] 01:32:10 INFO - 271 INFO Console message: [JavaScript Error: "TypeError: win.gBrowser is undefined" {file: "resource:///modules/ProcessHangMonitor.jsm" line: 412}] 01:32:10 INFO - 272 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: ping, Actual: ping - 01:32:10 INFO - 273 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: disconnect-me, Actual: disconnect-me - 01:32:10 INFO - 274 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: disconnect-me, Actual: disconnect-me - 01:32:10 INFO - Buffered messages finished 01:32:10 ERROR - 275 INFO TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | Error: Error: Attempt to postMessage on disconnected port :: @moz-extension://2b477953-e162-4a68-8365-92666154790f/%7Bee58ed18-10d5-4de9-a899-98ae113cad70%7D.js:17:13 01:32:10 INFO - - 01:32:10 INFO - Stack trace: 01:32:10 INFO - @moz-extension://2b477953-e162-4a68-8365-92666154790f/%7Bee58ed18-10d5-4de9-a899-98ae113cad70%7D.js:19:13 01:32:10 INFO - 276 INFO Console message: Ignoring response to aborted listener for 259 01:32:10 INFO - 277 INFO Leaving test bound extension_tab_connect_and_move_tabs 01:32:10 INFO - Not taking screenshot here: see the one that was previously logged 01:32:10 ERROR - 278 INFO TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | message queue is empty - Got ["port_ping_ponged_before_disconnect"], expected [] 01:32:10 INFO - Stack trace: 01:32:10 INFO - chrome://mochikit/content/browser-test.js:test_is:1280 01:32:10 INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:27 01:32:10 INFO - chrome://mochikit/content/browser-test.js:Tester.prototype.nextTest<:675 01:32:10 INFO - testScope/test_finish/<@chrome://mochikit/content/browser-test.js:1372:11 01:32:10 INFO - run@chrome://mochikit/content/browser-test.js:1309:9 01:32:10 INFO - GECKO(4752) | MEMORY STAT | vsize 2099129MB | vsizeMaxContiguous 130434458MB | residentFast 409MB | heapAllocated 184MB 01:32:10 INFO - 279 INFO TEST-OK | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | took 3355ms 01:32:10 INFO - 280 INFO checking window state 01:32:10 INFO - 281 INFO TEST-START | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_contentscript_animate.js 01:32:11 INFO - GECKO(4752) | MEMORY STAT | vsize 2099199MB | vsizeMaxContiguous 130434391MB | residentFast 423MB | heapAllocated 168MB 01:32:11 INFO - 282 INFO TEST-OK | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_contentscript_animate.js | took 870ms 01:32:11 INFO - 283 INFO checking window state 01:32:11 INFO - 284 INFO TEST-START | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_contentscript_connect.js 01:32:12 INFO - GECKO(4752) | MEMORY STAT | vsize 2099112MB | vsizeMaxContiguous 130434492MB | residentFast 411MB | heapAllocated 177MB 01:32:12 INFO - 285 INFO TEST-OK | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_contentscript_connect.js | took 561ms 01:32:12 INFO - 286 INFO checking window state 01:32:12 INFO - 287 INFO TEST-START | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_contextMenus.js 01:32:13 INFO - GECKO(4752) | console.warn: LoginRecipes: getRecipes: falling back to a synchronous message for: http://mochi.test:8888 01:32:13 INFO - GECKO(4752) | console.warn: nsLoginManager: searchLogins: `formSubmitURL` or `httpRealm` is recommended 01:32:13 INFO - GECKO(4752) | console.warn: nsLoginManager: searchLogins: `formSubmitURL` or `httpRealm` is recommended 01:32:13 INFO - GECKO(4752) | console.warn: nsLoginManager: searchLogins: `formSubmitURL` or `httpRealm` is recommended 01:32:13 INFO - GECKO(4752) | console.warn: nsLoginManager: searchLogins: `formSubmitURL` or `httpRealm` is recommended 01:32:14 INFO - GECKO(4752) | console.warn: nsLoginManager: searchLogins: `formSubmitURL` or `httpRealm` is recommended 01:32:14 INFO - GECKO(4752) | console.warn: nsLoginManager: searchLogins: `formSubmitURL` or `httpRealm` is recommended 01:32:15 INFO - GECKO(4752) | MEMORY STAT | vsize 2099118MB | vsizeMaxContiguous 130434481MB | residentFast 423MB | heapAllocated 176MB 01:32:15 INFO - 288 INFO TEST-OK | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_contextMenus.js | took 3682ms Could you please take a look at this?
Flags: needinfo?(rob)
|
|
Assignee | |
Comment 7•6 years ago
|
||
I believe that the new failure is caused by bug 1453163 (for the analysis, see https://bugzilla.mozilla.org/show_bug.cgi?id=1453163#c6 ). The log before the ultimate error message contains only one entry for the "connect_from_script" message in the first subtest (contentscript_connect_and_move_tabs) (In contrast, when this bug was reported, the "connect_from_contentscript" message appeared twice): > 254 INFO Entering test bound contentscript_connect_and_move_tabs > 255 INFO Extension loaded > 256 ... > 257 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: connect_from_script, Actual: connect_from_script - > 258 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: ping, Actual: ping - > 259 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: disconnect-me, Actual: disconnect-me - The log immediately before the error shows that the "connect_from_script" message in the second subtest (extension_tab_connect_and_move_tabs) appears twice. This looks like bug 1453163 ( https://bugzilla.mozilla.org/show_bug.cgi?id=1453163#c6 ): > 260 INFO Leaving test bound contentscript_connect_and_move_tabs > 261 INFO Entering test bound extension_tab_connect_and_move_tabs > 262 INFO Extension loaded > 263 ... > 264 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: open_extension_tab, Actual: open_extension_tab - > 265 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: connect_from_script, Actual: connect_from_script - > 266 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: connect_from_script, Actual: connect_from_script - > 275 INFO TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | Error: Error: Attempt to postMessage on disconnected port
Flags: needinfo?(rob)
| Comment hidden (Intermittent Failures Robot) |
|
||
Updated•6 years ago
|
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
|
|
Assignee | |
Comment 10•6 years ago
|
||
Bug 1453163 has been resolved.
Status: REOPENED → RESOLVED
Closed: 6 years ago → 6 years ago
Depends on: 1453163
Resolution: --- → FIXED
| Comment hidden (Intermittent Failures Robot) |
|
||
Updated•5 years ago
|
Product: Toolkit → WebExtensions
You need to log in
before you can comment on or make changes to this bug.
Description
•