Closed Bug 1805328 Opened 2 years ago Closed 2 years ago

Intermittent toolkit/components/extensions/test/xpcshell/test_ext_contentscript_errors.js | single tracking bug

Categories

(WebExtensions :: General, defect, P5)

defect

Tracking

(firefox-esr102 unaffected, firefox108 unaffected, firefox109 unaffected, firefox110 wontfix, firefox111 wontfix, firefox112 fixed)

RESOLVED FIXED
112 Branch
Tracking Status
firefox-esr102 --- unaffected
firefox108 --- unaffected
firefox109 --- unaffected
firefox110 --- wontfix
firefox111 --- wontfix
firefox112 --- fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, intermittent-testcase, regression)

Regressed by: 1410932

Failure log on trunk: https://treeherder.mozilla.org/logviewer?job_id=399430109&repo=autoland&lineNumber=2807

[task 2022-12-13T05:05:25.418Z] 05:05:25     INFO -  TEST-PASS | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_contentscript_errors.js | check_remote - [check_remote : 1] useRemoteWebExtensions matches - true == true
[task 2022-12-13T05:05:25.418Z] 05:05:25     INFO -  TEST-PASS | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_contentscript_errors.js | check_remote - [check_remote : 1] testing from extension process - false == false
[task 2022-12-13T05:05:25.418Z] 05:05:25     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2022-12-13T05:05:25.418Z] 05:05:25     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2022-12-13T05:05:25.418Z] 05:05:25     INFO -  (xpcshell/head.js) | test check_remote finished (2)
[task 2022-12-13T05:05:25.419Z] 05:05:25     INFO -  xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_contentscript_errors.js | Starting test_cached_contentscript_on_document_start
[task 2022-12-13T05:05:25.419Z] 05:05:25     INFO -  (xpcshell/head.js) | test test_cached_contentscript_on_document_start pending (2)
[task 2022-12-13T05:05:25.419Z] 05:05:25     INFO -  "Extension attached"
[task 2022-12-13T05:05:25.419Z] 05:05:25     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2022-12-13T05:05:25.419Z] 05:05:25     INFO -  PID 14284 | console.error: (new TypeError("NetworkError: Network request failed", "resource://services-settings/Utils.jsm", 230))
[task 2022-12-13T05:05:25.420Z] 05:05:25     INFO -  PID 14284 | JavaScript error: moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script1.js, line 2: Error: Object exception
[task 2022-12-13T05:05:25.420Z] 05:05:25     INFO -  PID 14284 | JavaScript error: moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script2.js, line 2: uncaught exception: String exception
[task 2022-12-13T05:05:25.420Z] 05:05:25     INFO -  PID 14284 | JavaScript error: moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script3.js, line 2: ReferenceError: undefinedSymbol is not defined
[task 2022-12-13T05:05:25.420Z] 05:05:25     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "Error: Object exception" {file: "moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script1.js" line: 2}]
[task 2022-12-13T05:05:25.420Z] 05:05:25     INFO -  @moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script1.js:2:15
[task 2022-12-13T05:05:25.420Z] 05:05:25     INFO -  inject@resource://gre/modules/ExtensionContent.jsm:589:25
[task 2022-12-13T05:05:25.420Z] 05:05:25     INFO -  "
[task 2022-12-13T05:05:25.421Z] 05:05:25     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "uncaught exception: String exception" {file: "moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script2.js" line: 2}]
[task 2022-12-13T05:05:25.421Z] 05:05:25     INFO -  @moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script2.js:2:9
[task 2022-12-13T05:05:25.421Z] 05:05:25     INFO -  inject@resource://gre/modules/ExtensionContent.jsm:589:25
[task 2022-12-13T05:05:25.421Z] 05:05:25     INFO -  "
[task 2022-12-13T05:05:25.421Z] 05:05:25     INFO -  PID 14284 | JavaScript error: moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script4.js, line 2: SyntaxError: expected expression, got ')'
[task 2022-12-13T05:05:25.422Z] 05:05:25     INFO -  PID 14284 | JavaScript error: , line 0: uncaught exception: rejected promise
[task 2022-12-13T05:05:25.422Z] 05:05:25     INFO -  PID 14284 | JavaScript error: moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script4.js, line 2: SyntaxError: expected expression, got ')'
[task 2022-12-13T05:05:25.422Z] 05:05:25     INFO -  PID 14284 | JavaScript error: moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script4.js, line 2: SyntaxError: expected expression, got ')'
[task 2022-12-13T05:05:25.422Z] 05:05:25     INFO -  PID 14284 | JavaScript error: moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script5.js, line 11: ReferenceError: asyncUndefinedSymbol is not defined
[task 2022-12-13T05:05:25.422Z] 05:05:25     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "ReferenceError: undefinedSymbol is not defined" {file: "moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script3.js" line: 2}]
[task 2022-12-13T05:05:25.422Z] 05:05:25     INFO -  @moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script3.js:2:9
[task 2022-12-13T05:05:25.423Z] 05:05:25     INFO -  inject@resource://gre/modules/ExtensionContent.jsm:589:25
[task 2022-12-13T05:05:25.423Z] 05:05:25     INFO -  "
[task 2022-12-13T05:05:25.423Z] 05:05:25     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "SyntaxError: expected expression, got ')'" {file: "moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script4.js" line: 2}]"
[task 2022-12-13T05:05:25.423Z] 05:05:25     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "SyntaxError: expected expression, got ')'" {file: "moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script4.js" line: 2 column: 8 source: "        )"}]"
[task 2022-12-13T05:05:25.423Z] 05:05:25     INFO -  PID 14284 | JavaScript error: moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script5.js, line 7: Error: async function exception
[task 2022-12-13T05:05:25.424Z] 05:05:25     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "uncaught exception: rejected promise"]"
[task 2022-12-13T05:05:25.424Z] 05:05:25     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "SyntaxError: expected expression, got ')'" {file: "moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script4.js" line: 2 column: 8 source: "        )"}]"
[task 2022-12-13T05:05:25.424Z] 05:05:25     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "SyntaxError: expected expression, got ')'" {file: "moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script4.js" line: 2 column: 8 source: "        )"}]"
[task 2022-12-13T05:05:25.424Z] 05:05:25     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "ReferenceError: asyncUndefinedSymbol is not defined" {file: "moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script5.js" line: 11}]
[task 2022-12-13T05:05:25.425Z] 05:05:25     INFO -  @moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script5.js:11:11
[task 2022-12-13T05:05:25.425Z] 05:05:25     INFO -  "
[task 2022-12-13T05:05:25.425Z] 05:05:25     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "Error: async function exception" {file: "moz-extension://8529abac-3fc2-4922-b07d-60a1f15d1d88/script5.js" line: 7}]"
[task 2022-12-13T05:05:25.425Z] 05:05:25     INFO -  Unexpected exception [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIConsoleService.unregisterListener]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://testing-common/content-task.js line 112 > eval :: <TOP_LEVEL> :: line 4"  data: no]
[task 2022-12-13T05:05:25.425Z] 05:05:25     INFO -  undefined
[task 2022-12-13T05:05:25.425Z] 05:05:25     INFO -  exiting test
[task 2022-12-13T05:05:25.426Z] 05:05:25  WARNING -  TEST-UNEXPECTED-FAIL | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_contentscript_errors.js | test_cached_contentscript_on_document_start - [test_cached_contentscript_on_document_start : 86] Extension left running at test shutdown - "running" == "unloaded"
[task 2022-12-13T05:05:25.426Z] 05:05:25     INFO -  resource://testing-common/ExtensionXPCShellUtils.jsm:ExtensionWrapper/<:86
[task 2022-12-13T05:05:25.426Z] 05:05:25     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test/<:649
[task 2022-12-13T05:05:25.426Z] 05:05:25     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:658
[task 2022-12-13T05:05:25.426Z] 05:05:25     INFO -  -e:null:1
[task 2022-12-13T05:05:25.427Z] 05:05:25     INFO -  exiting test
[task 2022-12-13T05:05:25.427Z] 05:05:25     INFO -  NS_ERROR_ABORT:
[task 2022-12-13T05:05:25.427Z] 05:05:25     INFO -  _abort_failed_test@/builds/worker/workspace/build/tests/xpcshell/head.js:863:20
[task 2022-12-13T05:05:25.427Z] 05:05:25     INFO -  do_report_result@/builds/worker/workspace/build/tests/xpcshell/head.js:964:5
[task 2022-12-13T05:05:25.427Z] 05:05:25     INFO -  Assert<@/builds/worker/workspace/build/tests/xpcshell/head.js:71:21
[task 2022-12-13T05:05:25.427Z] 05:05:25     INFO -  Assert.prototype.report@resource://testing-common/Assert.sys.mjs:240:10
[task 2022-12-13T05:05:25.428Z] 05:05:25     INFO -  equal@resource://testing-common/Assert.sys.mjs:282:8
[task 2022-12-13T05:05:25.428Z] 05:05:25     INFO -  ExtensionWrapper/<@resource://testing-common/ExtensionXPCShellUtils.jsm:86:24
[task 2022-12-13T05:05:25.428Z] 05:05:25     INFO -  _execute_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:649:28
[task 2022-12-13T05:05:25.428Z] 05:05:25     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:658:5
[task 2022-12-13T05:05:25.428Z] 05:05:25     INFO -  @-e:1:1
[task 2022-12-13T05:05:25.428Z] 05:05:25     INFO -  "Force a GC"
[task 2022-12-13T05:05:25.429Z] 05:05:25     INFO -  Error: Found unexpected files in temporary directory: generated-extension.xpi at resource://testing-common/AddonTestUtils.jsm:339
[task 2022-12-13T05:05:25.429Z] 05:05:25     INFO -  init/<@resource://testing-common/AddonTestUtils.jsm:339:15
[task 2022-12-13T05:05:25.429Z] 05:05:25     INFO -  _execute_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:649:28
[task 2022-12-13T05:05:25.429Z] 05:05:25     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:661:16
[task 2022-12-13T05:05:25.429Z] 05:05:25     INFO -  @-e:1:1
[task 2022-12-13T05:05:25.429Z] 05:05:25     INFO -  <<<<<<<
[task 2022-12-13T05:05:25.431Z] 05:05:25     INFO -  INFO | Result summary:
[task 2022-12-13T05:05:25.432Z] 05:05:25     INFO -  INFO | Passed: 224
[task 2022-12-13T05:05:25.433Z] 05:05:25  WARNING -  INFO | Failed: 1
[task 2022-12-13T05:05:25.433Z] 05:05:25  WARNING -  One or more unittests failed.
[task 2022-12-13T05:05:25.434Z] 05:05:25     INFO -  INFO | Todo: 0
[task 2022-12-13T05:05:25.435Z] 05:05:25     INFO -  INFO | Retried: 3
[task 2022-12-13T05:05:25.435Z] 05:05:25     INFO -  SUITE-END | took 2214s
[task 2022-12-13T05:05:25.437Z] 05:05:25     INFO -  Node moz-http2 server shutting down ...
[task 2022-12-13T05:05:25.437Z] 05:05:25     INFO -  http3Server server shutting down ...
[task 2022-12-13T05:05:25.579Z] 05:05:25    ERROR - Return code: 1
[task 2022-12-13T05:05:25.581Z] 05:05:25     INFO - TinderboxPrint: xpcshell-xpcshell<br/>224/<em class="testfail">1</em>/0
[task 2022-12-13T05:05:25.582Z] 05:05:25  WARNING - # TBPL FAILURE #
Component: Add-Ons: Extensions API → Developer Tools
Flags: needinfo?(poirot.alex)
Product: Thunderbird → WebExtensions

Set release status flags based on info from the regressing bug 1410932

At least for Thunderbird it's reproducible with --verify (but not without)
./mach test --sequential --verify toolkit/components/extensions/test/xpcshell/test_ext_contentscript_errors.js

I am seeing this fail intermittent on a Firefox build on Windows as well. When it fails, this.consoleErrorListener and this.collectedErrors are undefined in the second ContentTask.spawn:

https://searchfox.org/mozilla-central/rev/d9dbf648b2f7557f6f06d27cce58546cc539cb2b/toolkit/components/extensions/test/xpcshell/test_ext_contentscript_errors.js#111-114

The logged this in case of success:

{
    collectedErrors: [
        {
            innerWindowID: 4294967298, 
            message: "Error: Object exception"
        },
        {
            innerWindowID: 4294967298,
            message: "uncaught exception: String exception"
        },
        {
            innerWindowID: 4294967298,
            message: "ReferenceError: undefinedSymbol is not defined"
        },
        {
            innerWindowID: 4294967298,
            message: "SyntaxError: expected expression, got ')'"
        },
        {
            innerWindowID: 4294967298, 
            message: "uncaught exception: rejected promise"
        },
        {
            innerWindowID: 4294967298,
            message: "ReferenceError: asyncUndefinedSymbol is not defined"
        },
        {
            innerWindowID: 4294967298,
            message: "Error: async function exception"
        }
    ], 
    consoleErrorListener: error => {
        0:13.28 pid:4476       error.QueryInterface(Ci.nsIScriptError);
        0:13.28 pid:4476       // Ignore errors from ExtensionContent.jsm
        0:13.28 pid:4476       if (error.innerWindowID) {
        0:13.28 pid:4476         this.collectedErrors.push({
        0:13.28 pid:4476           innerWindowID: error.innerWindowID,
        0:13.28 pid:4476           message: error.errorMessage,
        0:13.28 pid:4476         });
        0:13.28 pid:4476       }
        0:13.28 pid:4476     
    }
}

The logged this in case of fail:

{}

I have no idea why this is lost.

This seems to be the same issue as described in https://bugzilla.mozilla.org/show_bug.cgi?id=1814293#c3.

See Also: → 1814293

Relevant discussion: https://phabricator.services.mozilla.com/D169537?id=681994#inline-935978

While the error is reported in an extension test, the issue is independent of extensions and an issue with ContentFrameMessageManager and navigations. Hopefully someone will figure out the cause, but I guess that this bug may eventually close because the test was refactored in https://phabricator.services.mozilla.com/D169537?id=681994 to avoid this issue.

Component: Developer Tools → General
Flags: needinfo?(poirot.alex)
Assignee: nobody → continuation
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → 112 Branch
You need to log in before you can comment on or make changes to this bug.