Closed Bug 1393920 Opened 7 years ago Closed 3 years ago

Intermittent toolkit/components/extensions/test/mochitest/test_chrome_ext_contentscript_telemetry.html | Test timed out.

Categories

(WebExtensions :: General, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED FIXED
mozilla70

People

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

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell fixed])

Attachments

(2 files)

See https://wiki.mozilla.org/Bugmasters/Projects/Bug_Handling/Bug_Husbandry#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
Product: Toolkit → WebExtensions
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 7 years ago6 years ago
Resolution: --- → INCOMPLETE

There are 20 total failures in the last 7 days on Linux platform: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-04-19&endday=2019-04-26&tree=trunk&bug=1393920

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=242774628&repo=autoland&lineNumber=3379

[task 2019-04-26T01:05:45.142Z] 01:05:45 INFO - TEST-START | toolkit/components/extensions/test/mochitest/test_chrome_ext_contentscript_telemetry.html
[task 2019-04-26T01:05:45.190Z] 01:05:45 INFO - GECKO(3336) | Console message: No chrome package registered for chrome://mochikit/contents/tests/SimpleTest/test.css
[task 2019-04-26T01:05:45.380Z] 01:05:45 INFO - GECKO(3336) | JavaScript error: undefined, line 0: Error: Missing host permission for the tab
[task 2019-04-26T01:05:45.380Z] 01:05:45 INFO - GECKO(3336) | Console message: [JavaScript Error: "Error: Missing host permission for the tab" {file: "undefined" line: 0}]
[task 2019-04-26T01:11:13.719Z] 01:11:13 INFO - TEST-INFO | started process screentopng
[task 2019-04-26T01:11:13.998Z] 01:11:13 INFO - TEST-INFO | screentopng: exit 0
[task 2019-04-26T01:11:13.999Z] 01:11:13 INFO - Buffered messages logged at 01:05:45
[task 2019-04-26T01:11:14.000Z] 01:11:14 INFO - add_task | Entering test test_contentscript_telemetry
[task 2019-04-26T01:11:14.001Z] 01:11:14 INFO - Extension loaded
[task 2019-04-26T01:11:14.002Z] 01:11:14 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_chrome_ext_contentscript_telemetry.html | No data recorded for histogram: WEBEXT_CONTENT_SCRIPT_INJECTION_MS.
[task 2019-04-26T01:11:14.003Z] 01:11:14 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_chrome_ext_contentscript_telemetry.html | No data recorded for histogram after startup: WEBEXT_CONTENT_SCRIPT_INJECTION_MS.
[task 2019-04-26T01:11:14.004Z] 01:11:14 INFO - Buffered messages finished
[task 2019-04-26T01:11:14.006Z] 01:11:14 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_chrome_ext_contentscript_telemetry.html | Test timed out.
[task 2019-04-26T01:11:14.006Z] 01:11:14 INFO - SimpleTest.ok@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:275:18
[task 2019-04-26T01:11:14.007Z] 01:11:14 INFO - reportError@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:121:22
[task 2019-04-26T01:11:14.008Z] 01:11:14 INFO - TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:142:7
[task 2019-04-26T01:11:14.008Z] 01:11:14 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-04-26T01:11:14.010Z] 01:11:14 INFO - setTimeout handler
TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-04-26T01:11:14.010Z] 01:11:14 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-04-26T01:11:14.010Z] 01:11:14 INFO - setTimeout handler
TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-04-26T01:11:14.011Z] 01:11:14 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-04-26T01:11:14.011Z] 01:11:14 INFO - setTimeout handler
TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-04-26T01:11:14.012Z] 01:11:14 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-04-26T01:11:14.013Z] 01:11:14 INFO - setTimeout handler
TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-04-26T01:11:14.013Z] 01:11:14 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-04-26T01:11:14.013Z] 01:11:14 INFO - setTimeout handler
TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-04-26T01:11:14.013Z] 01:11:14 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-04-26T01:11:14.013Z] 01:11:14 INFO - TestRunner.runTests/<@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:381:20
[task 2019-04-26T01:11:14.013Z] 01:11:14 INFO - promise callback
TestRunner.runTests@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:368:50
[task 2019-04-26T01:11:14.013Z] 01:11:14 INFO - RunSet.runtests@chrome://mochikit/content/tests/SimpleTest/setup.js:201:14
[task 2019-04-26T01:11:14.013Z] 01:11:14 INFO - RunSet.runall@chrome://mochikit/content/tests/SimpleTest/setup.js:180:12
[task 2019-04-26T01:11:14.013Z] 01:11:14 INFO - hookupTests@chrome://mochikit/content/tests/SimpleTest/setup.js:273:12
[task 2019-04-26T01:11:14.013Z] 01:11:14 INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:38:5
[task 2019-04-26T01:11:14.014Z] 01:11:14 INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:49:11
[task 2019-04-26T01:11:14.014Z] 01:11:14 INFO - EventHandlerNonNullgetTestManifest@chrome://mochikit/content/manifestLibrary.js:45:3
[task 2019-04-26T01:11:14.014Z] 01:11:14 INFO - hookup@chrome://mochikit/content/tests/SimpleTest/setup.js:253:5
[task 2019-04-26T01:11:14.014Z] 01:11:14 INFO - linkAndHookup@chrome://mochikit/content/harness.xul:45:3
[task 2019-04-26T01:11:14.014Z] 01:11:14 INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:38:5
[task 2019-04-26T01:11:14.014Z] 01:11:14 INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:49:11
[task 2019-04-26T01:11:14.014Z] 01:11:14 INFO - EventHandlerNonNull
getTestManifest@chrome://mochikit/content/manifestLibrary.js:45:3
[task 2019-04-26T01:11:14.014Z] 01:11:14 INFO - getTestList@chrome://mochikit/content/chrome-harness.js:251:3
[task 2019-04-26T01:11:14.014Z] 01:11:14 INFO - loadTests@chrome://mochikit/content/harness.xul:24:3
[task 2019-04-26T01:11:14.014Z] 01:11:14 INFO - EventListener.handleEvent*@chrome://mochikit/content/harness.xul:48:12
[task 2019-04-26T01:11:14.717Z] 01:11:14 INFO - Not taking screenshot here: see the one that was previously logged

David, could you please assign this to someone?

Flags: needinfo?(ddurst)
Whiteboard: [stockwell needswork:owner]

There are 24 total failures in the last 7 days: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-07-08&endday=2019-07-15&tree=trunk&bug=1393920

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=256465019&repo=autoland&lineNumber=3462

[task 2019-07-15T02:41:59.796Z] 02:41:59 INFO - TEST-START | toolkit/components/extensions/test/mochitest/test_chrome_ext_contentscript_telemetry.html
[task 2019-07-15T02:42:00.128Z] 02:42:00 INFO - GECKO(3389) | JavaScript error: undefined, line 0: Error: No matching message handler
[task 2019-07-15T02:42:00.129Z] 02:42:00 INFO - GECKO(3389) | Console message: [JavaScript Error: "Error: No matching message handler" {file: "undefined" line: 0}]
[task 2019-07-15T02:47:28.351Z] 02:47:28 INFO - TEST-INFO | started process screentopng
[task 2019-07-15T02:47:28.636Z] 02:47:28 INFO - TEST-INFO | screentopng: exit 0
[task 2019-07-15T02:47:28.637Z] 02:47:28 INFO - Buffered messages logged at 02:41:59
[task 2019-07-15T02:47:28.637Z] 02:47:28 INFO - add_task | Entering test test_contentscript_telemetry
[task 2019-07-15T02:47:28.638Z] 02:47:28 INFO - Extension loaded
[task 2019-07-15T02:47:28.639Z] 02:47:28 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_chrome_ext_contentscript_telemetry.html | No data recorded for histogram: WEBEXT_CONTENT_SCRIPT_INJECTION_MS.
[task 2019-07-15T02:47:28.640Z] 02:47:28 INFO - Buffered messages logged at 02:42:00
[task 2019-07-15T02:47:28.640Z] 02:47:28 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_chrome_ext_contentscript_telemetry.html | No data recorded for histogram after startup: WEBEXT_CONTENT_SCRIPT_INJECTION_MS.
[task 2019-07-15T02:47:28.641Z] 02:47:28 INFO - Buffered messages finished
[task 2019-07-15T02:47:28.645Z] 02:47:28 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_chrome_ext_contentscript_telemetry.html | Test timed out.
[task 2019-07-15T02:47:28.645Z] 02:47:28 INFO - SimpleTest.ok@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:275:18
[task 2019-07-15T02:47:28.646Z] 02:47:28 INFO - reportError@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:121:22
[task 2019-07-15T02:47:28.646Z] 02:47:28 INFO - TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:142:7
[task 2019-07-15T02:47:28.647Z] 02:47:28 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-07-15T02:47:28.647Z] 02:47:28 INFO - setTimeout handler
TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-07-15T02:47:28.648Z] 02:47:28 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-07-15T02:47:28.648Z] 02:47:28 INFO - setTimeout handler
TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-07-15T02:47:28.649Z] 02:47:28 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-07-15T02:47:28.650Z] 02:47:28 INFO - setTimeout handler
TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-07-15T02:47:28.650Z] 02:47:28 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-07-15T02:47:28.651Z] 02:47:28 INFO - setTimeout handler
TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-07-15T02:47:28.652Z] 02:47:28 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-07-15T02:47:28.652Z] 02:47:28 INFO - setTimeout handler
TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-07-15T02:47:28.652Z] 02:47:28 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2019-07-15T02:47:28.653Z] 02:47:28 INFO - TestRunner.runTests/<@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:381:20
[task 2019-07-15T02:47:28.653Z] 02:47:28 INFO - promise callback
TestRunner.runTests@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:368:50
[task 2019-07-15T02:47:28.654Z] 02:47:28 INFO - RunSet.runtests@chrome://mochikit/content/tests/SimpleTest/setup.js:201:14
[task 2019-07-15T02:47:28.654Z] 02:47:28 INFO - RunSet.runall@chrome://mochikit/content/tests/SimpleTest/setup.js:180:12
[task 2019-07-15T02:47:28.654Z] 02:47:28 INFO - hookupTests@chrome://mochikit/content/tests/SimpleTest/setup.js:273:12
[task 2019-07-15T02:47:28.654Z] 02:47:28 INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:50:5
[task 2019-07-15T02:47:28.654Z] 02:47:28 INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:61:11
[task 2019-07-15T02:47:28.654Z] 02:47:28 INFO - EventHandlerNonNullgetTestManifest@chrome://mochikit/content/manifestLibrary.js:57:3
[task 2019-07-15T02:47:28.654Z] 02:47:28 INFO - hookup@chrome://mochikit/content/tests/SimpleTest/setup.js:253:5
[task 2019-07-15T02:47:28.654Z] 02:47:28 INFO - linkAndHookup@chrome://mochikit/content/harness.xul:45:3
[task 2019-07-15T02:47:28.654Z] 02:47:28 INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:50:5
[task 2019-07-15T02:47:28.654Z] 02:47:28 INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:61:11
[task 2019-07-15T02:47:28.654Z] 02:47:28 INFO - EventHandlerNonNull
getTestManifest@chrome://mochikit/content/manifestLibrary.js:57:3
[task 2019-07-15T02:47:28.654Z] 02:47:28 INFO - getTestList@chrome://mochikit/content/chrome-harness.js:258:3
[task 2019-07-15T02:47:28.654Z] 02:47:28 INFO - loadTests@chrome://mochikit/content/harness.xul:24:3
[task 2019-07-15T02:47:28.655Z] 02:47:28 INFO - EventListener.handleEvent*@chrome://mochikit/content/harness.xul:48:12
[task 2019-07-15T02:47:29.351Z] 02:47:29 INFO - Not taking screenshot here: see the one that was previously logged

Flags: needinfo?(ddurst)

Jim, could you take assign this to someone?

Flags: needinfo?(jmathies)
Flags: needinfo?(jmathies)
Whiteboard: [stockwell unknown] → [stockwell unknown], webext?

(In reply to Razvan Maries from comment #32)

Jim, could you take assign this to someone?

Please disable on linux if you need to, we don't consider this a priority as long as we have windows coverage.

Whiteboard: [stockwell unknown], webext? → [stockwell unknown]
Pushed by rmaries@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/0b230f9c9bde
Disabled test_chrome_ext_contentscript_telemetry.html on Linux64. r=jmaher
Whiteboard: [stockwell unknown] → [stockwell disabled]
Status: REOPENED → RESOLVED
Closed: 6 years ago5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla70
Assignee: nobody → rmaries
Status: RESOLVED → REOPENED
Keywords: leave-open
Resolution: FIXED → ---
Assignee: rmaries → nobody

This is happening because the test calls window.open and then immediately loads the extension with the expectation that the page has already finished loading. This is not the case.

I can reproduce this consistently if I load https instead of http (as part of working on bug 1741590). I'll fix this test and re-enable it here, and remove the https-first exception in the other bug.

Assignee: nobody → rob
Blocks: 1741590
Pushed by rob@robwu.nl:
https://hg.mozilla.org/integration/autoland/rev/6cce6af3325e
Fix intermittent failure in test_chrome_ext_contentscript_telemetry.html r=mixedpuppy
Status: REOPENED → RESOLVED
Closed: 5 years ago3 years ago
Keywords: leave-open
Resolution: --- → FIXED
Whiteboard: [stockwell disabled] → [stockwell fixed]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: