Closed Bug 1527029 Opened 1 year ago Closed 5 months ago

Intermittent browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Test timed out

Categories

(WebExtensions :: Untriaged, defect, P3)

Desktop
macOS
defect

Tracking

(firefox-esr60 unaffected, firefox-esr68 fixed, firefox69 wontfix, firefox70 fixed, firefox71 fixed)

RESOLVED FIXED
mozilla71
Tracking Status
firefox-esr60 --- unaffected
firefox-esr68 --- fixed
firefox69 --- wontfix
firefox70 --- fixed
firefox71 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: robwu)

References

(Depends on 1 open bug)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [webext?][stockwell unknown])

Attachments

(1 file)

#[markdown(off)]
Filed by: cbrindusan [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=227654770&repo=autoland

https://queue.taskcluster.net/v1/task/QTsS-AjNRL6q0J3OI1wwow/runs/0/artifacts/public/logs/live_backing.log

08:12:30 INFO - TEST-START | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js
08:13:15 INFO - TEST-INFO | started process screencapture
08:13:15 INFO - TEST-INFO | screencapture: exit 0
08:13:15 INFO - Buffered messages logged at 08:12:30
08:13:15 INFO - Entering test bound testExecuteScript
08:13:15 INFO - Extension loaded
08:13:15 INFO - Console message: Warning: attempting to write 26937 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.
08:13:15 INFO - FRAMES: 15032385624 [{"url":"http://mochi.test:8888/browser/browser/components/extensions/test/browser/file_iframe_document.html","tabId":535,"frameId":0,"parentFrameId":-1},{"url":"http://mochi.test:8888/","tabId":535,"frameId":15032385624,"parentFrameId":0},{"url":"about:blank","tabId":535,"frameId":15032385625,"parentFrameId":0}]
08:13:15 INFO -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Got expected error -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Expected one callback result - Expected: 1, Actual: 1 -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Expected callback result - Expected: 42, Actual: 42 -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Result is an array -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Result has correct length - Expected: 2, Actual: 2 -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | First result is correct -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Second result is correct - Expected: http://mochi.test:8888/, Actual: http://mochi.test:8888/ -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Result is an array -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Result has correct length - Expected: 3, Actual: 3 -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | First result is correct -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Second result is correct - Expected: http://mochi.test:8888/, Actual: http://mochi.test:8888/ -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Thirds result is correct - Expected: about:blank, Actual: about:blank -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Expected callback result - Expected: 1, Actual: 1 -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Result is a string - Expected: string, Actual: string -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Result is correct -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Got expected fileName - Expected: <anonymous code>, Actual: <anonymous code> -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Got expected error - Expected: Script '<anonymous code>' result is non-structured-clonable data, Actual: Script '<anonymous code>' result is non-structured-clonable data -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Got expected fileName - Expected: <anonymous code>, Actual: <anonymous code> -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Got expected error - Expected: Script '<anonymous code>' result is non-structured-clonable data, Actual: Script '<anonymous code>' result is non-structured-clonable data -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Got expected error - Expected: Frame not found, or missing host permission, Actual: Frame not found, or missing host permission -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Got expected promise resolution value as result - Expected: 42, Actual: 42 -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Result is an array -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Result has correct length - Expected: 2, Actual: 2 -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | First result is correct -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Second result is correct - Expected: http://mochi.test:8888/, Actual: http://mochi.test:8888/ -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Expected one result - Expected: 1, Actual: 1 -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Result for frameId[0] is correct: http://mochi.test:8888/browser/browser/components/extensions/test/browser/file_iframe_document.html -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Expected one result - Expected: 1, Actual: 1 -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Result for frameId[1] is correct - Expected: http://mochi.test:8888/, Actual: http://mochi.test:8888/ -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Expected runtime message - Expected: script ran, Actual: script ran -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Expected one callback result - Expected: 1, Actual: 1 -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Expected callback result - Expected: undefined, Actual: undefined -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Expected one callback result - Expected: 1, Actual: 1 -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Expected callback result - Expected: 27, Actual: 27 -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Got expected error -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Got expected fileName -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Got expected error - Expected: Missing host permission for the tab, Actual: Missing host permission for the tab -
08:13:15 INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Script executed correctly in new tab - Expected: http://example.com/, Actual: http://example.com/ -
08:13:15 INFO - Buffered messages finished
08:13:15 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Test timed out -

Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → INCOMPLETE
Flags: needinfo?(jmathies)
Whiteboard: [stockwell needswork:owner]
Flags: needinfo?(jmathies)
OS: Unspecified → macOS
Priority: P5 → P3
Hardware: Unspecified → Desktop
Summary: Intermittent browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Test timed out - → Intermittent browser/components/extensions/test/browser/test-oop-extensions/browser_ext_tabs_executeScript.js | Test timed out
Whiteboard: [stockwell needswork:owner] → [stockwell needswork:owner][webext?]
Flags: needinfo?(rob)

The browser_ext_tabs_executeScript.js test occasionally times out.
Apparently the part of the test that opens "about:blank" and awaits the
result sometimes times out (tabs.executeScript does not resolve).

To avoid collateral damage by this small part of the test, the
"about:blank" test has been moved to its own file.

I have identified the cause of the test failure (both the part of the test that is failing, and also the cause of the test failure).

To make it easier to debug the cause of the test failure, I moved that part of a test to a separate file. That will resolve this bug, because the subject of this bug will no longer time out.

I'll file a separate bug to document the circumstances of the test failure.

When the patch in comment 15 lands, the intermittent bug filer bot might create a new bug for the new test. That's fine.

Assignee: nobody → rob
Status: REOPENED → ASSIGNED
Flags: needinfo?(rob)

Added "depends on bug 1581403" because that bug is causing the test failure.

When the patch in comment 15 lands, the separate test might still fail (it does, as shown at https://treeherder.mozilla.org/#/jobs?repo=try&selectedJob=266707309&revision=84a7d91f7b33418bcf9d980026485c8cf4211d9e&searchStr=tv ), but until we have a separate bug for it, it's probably best to link these two bugs for visibility.

Depends on: 1581403
Pushed by rob@robwu.nl:
https://hg.mozilla.org/integration/autoland/rev/aa8c886f5030
Split about:blank test from browser_ext_tabs_executeScript.js r=zombie
Status: ASSIGNED → RESOLVED
Closed: 1 year ago5 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla71
See Also: → 1581493
You need to log in before you can comment on or make changes to this bug.