1763198 - Intermittent toolkit/components/extensions/test/xpcshell/test_ext_contentscript_permissions_change.js | single tracking bug

Status: RESOLVED INCOMPLETE

(WebExtensions :: General, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=373484938&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/THTxI20_Ss-ezZ3cusOC0w/runs/0/artifacts/public/logs/live_backing.log

---

[task 2022-04-05T16:57:56.424Z] 16:57:56     INFO -  TEST-START | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_contentscript_permissions_change.js
[task 2022-04-05T16:57:59.961Z] 16:57:59  WARNING -  TEST-UNEXPECTED-FAIL | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_contentscript_permissions_change.js | xpcshell return code: 0
[task 2022-04-05T16:57:59.963Z] 16:57:59     INFO -  TEST-INFO took 3535ms
[task 2022-04-05T16:57:59.963Z] 16:57:59     INFO -  >>>>>>>
[task 2022-04-05T16:57:59.964Z] 16:57:59     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2022-04-05T16:57:59.967Z] 16:57:59     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2022-04-05T16:57:59.967Z] 16:57:59     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2022-04-05T16:57:59.968Z] 16:57:59     INFO -  running event loop
[task 2022-04-05T16:57:59.970Z] 16:57:59     INFO -  xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_contentscript_permissions_change.js | Starting setup check_remote
[task 2022-04-05T16:57:59.971Z] 16:57:59     INFO -  (xpcshell/head.js) | test check_remote pending (2)
[task 2022-04-05T16:57:59.971Z] 16:57:59     INFO -  TEST-PASS | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_contentscript_permissions_change.js | check_remote - [check_remote : 1] useRemoteWebExtensions matches - true == true
[task 2022-04-05T16:57:59.977Z] 16:57:59     INFO -  TEST-PASS | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_contentscript_permissions_change.js | check_remote - [check_remote : 1] testing from extension process - false == false
[task 2022-04-05T16:57:59.980Z] 16:57:59     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2022-04-05T16:57:59.981Z] 16:57:59     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2022-04-05T16:57:59.981Z] 16:57:59     INFO -  (xpcshell/head.js) | test check_remote finished (2)
[task 2022-04-05T16:57:59.981Z] 16:57:59     INFO -  xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_contentscript_permissions_change.js | Starting test_contentscript_mv3_permissions
[task 2022-04-05T16:57:59.982Z] 16:57:59     INFO -  (xpcshell/head.js) | test test_contentscript_mv3_permissions pending (2)
[task 2022-04-05T16:57:59.982Z] 16:57:59     INFO -  "Extension attached"
[task 2022-04-05T16:57:59.982Z] 16:57:59     INFO -  "Extension attached"
[task 2022-04-05T16:57:59.983Z] 16:57:59     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2022-04-05T16:57:59.987Z] 16:57:59     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "can't access property "patterns", this.allowedOrigins is null" {file: "resource://gre/modules/Extension.jsm" line: 2272}]
[task 2022-04-05T16:57:59.987Z] 16:57:59     INFO -  Extension/<@resource://gre/modules/Extension.jsm:2272:24
[task 2022-04-05T16:57:59.988Z] 16:57:59     INFO -  emit@resource://gre/modules/ExtensionCommon.jsm:322:32
[task 2022-04-05T16:57:59.988Z] 16:57:59     INFO -  emit@resource://gre/modules/Extension.jsm:2385:25
[task 2022-04-05T16:57:59.989Z] 16:57:59     INFO -  add@resource://gre/modules/ExtensionPermissions.jsm:339:17
[task 2022-04-05T16:57:59.989Z] 16:57:59     INFO -  _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:240:6
[task 2022-04-05T16:57:59.990Z] 16:57:59     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:603:5
[task 2022-04-05T16:57:59.990Z] 16:57:59     INFO -  @-e:1:1
[task 2022-04-05T16:57:59.990Z] 16:57:59     INFO -  "
[task 2022-04-05T16:57:59.991Z] 16:57:59     INFO -  "Granted initial permissions for both."
[task 2022-04-05T16:57:59.991Z] 16:57:59     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "can't access property "patterns", this.allowedOrigins is null" {file: "resource://gre/modules/Extension.jsm" line: 2272}]
[task 2022-04-05T16:57:59.992Z] 16:57:59     INFO -  Extension/<@resource://gre/modules/Extension.jsm:2272:24
[task 2022-04-05T16:57:59.992Z] 16:57:59     INFO -  emit@resource://gre/modules/ExtensionCommon.jsm:322:32
[task 2022-04-05T16:57:59.993Z] 16:57:59     INFO -  emit@resource://gre/modules/Extension.jsm:2385:25
[task 2022-04-05T16:57:59.993Z] 16:57:59     INFO -  add@resource://gre/modules/ExtensionPermissions.jsm:339:17
[task 2022-04-05T16:57:59.993Z] 16:57:59     INFO -  _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:240:6
[task 2022-04-05T16:57:59.994Z] 16:57:59     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:603:5
[task 2022-04-05T16:57:59.994Z] 16:57:59     INFO -  @-e:1:1
[task 2022-04-05T16:57:59.995Z] 16:57:59     INFO -  "
[task 2022-04-05T16:57:59.995Z] 16:57:59     INFO -  "beta@test registering content scripts"
[task 2022-04-05T16:57:59.995Z] 16:57:59     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "NetworkError: Network request failed" {file: "resource://services-settings/Utils.jsm" line: 153}]
[task 2022-04-05T16:57:59.995Z] 16:57:59     INFO -  fetch/</request.onerror@resource://services-settings/Utils.jsm:153:26
[task 2022-04-05T16:57:59.996Z] 16:57:59     INFO -  _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:240:6
[task 2022-04-05T16:57:59.996Z] 16:57:59     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:603:5
[task 2022-04-05T16:57:59.997Z] 16:57:59     INFO -  @-e:1:1
[task 2022-04-05T16:57:59.997Z] 16:57:59     INFO -  "
[task 2022-04-05T16:57:59.998Z] 16:57:59     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "NetworkError: Network request failed" {file: "resource://services-settings/Utils.jsm" line: 153}]
[task 2022-04-05T16:57:59.998Z] 16:57:59     INFO -  fetch/</request.onerror@resource://services-settings/Utils.jsm:153:26
[task 2022-04-05T16:57:59.998Z] 16:57:59     INFO -  _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:240:6
[task 2022-04-05T16:57:59.998Z] 16:57:59     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:603:5
[task 2022-04-05T16:57:59.998Z] 16:57:59     INFO -  @-e:1:1
[task 2022-04-05T16:57:59.998Z] 16:57:59     INFO -  "
[task 2022-04-05T16:57:59.999Z] 16:57:59     INFO -  PID 6370 | ###!!! [Parent][PBackgroundParent] Error: RunMessage(msgname=PRemoteWorkerService::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-04-05T16:58:00.000Z] 16:57:59     INFO -  "Loaded a page from example.com."
[task 2022-04-05T16:58:00.000Z] 16:58:00     INFO -  "alpha@test script on example.com"
[task 2022-04-05T16:58:00.001Z] 16:58:00     INFO -  "Got a message from alpha@test on example.com."
[task 2022-04-05T16:58:00.001Z] 16:58:00     INFO -  PID 6370 | ###!!! [Parent][PBackgroundParent] Error: RunMessage(msgname=PRemoteWorkerService::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-04-05T16:58:00.002Z] 16:58:00     INFO -  PID 6370 | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-04-05T16:58:00.002Z] 16:58:00     INFO -  "Revoked example.net permissions from Alpha."
[task 2022-04-05T16:58:00.003Z] 16:58:00     INFO -  "Loaded a page from example.net."
[task 2022-04-05T16:58:00.003Z] 16:58:00     INFO -  "alpha@test script on example.net"
[task 2022-04-05T16:58:00.004Z] 16:58:00     INFO -  "beta@test script on example.net"
[task 2022-04-05T16:58:00.004Z] 16:58:00     INFO -  "Got a message from beta@test on example.net."
[task 2022-04-05T16:58:00.005Z] 16:58:00     INFO -  "Done, unloading Alpha and Beta."
[task 2022-04-05T16:58:00.005Z] 16:58:00     INFO -  PID 6370 | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-04-05T16:58:00.006Z] 16:58:00     INFO -  PID 6370 | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-04-05T16:58:00.006Z] 16:58:00     INFO -  (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2022-04-05T16:58:00.007Z] 16:58:00     INFO -  (xpcshell/head.js) | test test_contentscript_mv3_permissions finished (2)
[task 2022-04-05T16:58:00.007Z] 16:58:00     INFO -  (xpcshell/head.js) | test run_next_test 2 finished (1)
[task 2022-04-05T16:58:00.008Z] 16:58:00     INFO -  exiting test
[task 2022-04-05T16:58:00.008Z] 16:58:00  WARNING -  TEST-UNEXPECTED-FAIL | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_contentscript_permissions_change.js | test_contentscript_mv3_permissions - [test_contentscript_mv3_permissions : 146] message queue is empty - "[\\"alpha@test_on_example.net\\"]" == "[]"
[task 2022-04-05T16:58:00.009Z] 16:58:00     INFO -  resource://testing-common/ExtensionXPCShellUtils.jsm:clearMessageQueues:146
[task 2022-04-05T16:58:00.010Z] 16:58:00     INFO -  resource://testing-common/ExtensionXPCShellUtils.jsm:ExtensionWrapper/<:88
[task 2022-04-05T16:58:00.011Z] 16:58:00     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test/<:667
[task 2022-04-05T16:58:00.012Z] 16:58:00     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:679
[task 2022-04-05T16:58:00.012Z] 16:58:00     INFO -  -e:null:1
[task 2022-04-05T16:58:00.012Z] 16:58:00     INFO -  exiting test
[task 2022-04-05T16:58:00.013Z] 16:58:00     INFO -  NS_ERROR_ABORT:
[task 2022-04-05T16:58:00.014Z] 16:58:00     INFO -  _abort_failed_test@/builds/worker/workspace/build/tests/xpcshell/head.js:874:20
[task 2022-04-05T16:58:00.014Z] 16:58:00     INFO -  do_report_result@/builds/worker/workspace/build/tests/xpcshell/head.js:975:5
[task 2022-04-05T16:58:00.015Z] 16:58:00     INFO -  Assert<@/builds/worker/workspace/build/tests/xpcshell/head.js:75:21
[task 2022-04-05T16:58:00.016Z] 16:58:00     INFO -  proto.report@resource://testing-common/Assert.jsm:228:10
[task 2022-04-05T16:58:00.016Z] 16:58:00     INFO -  equal@resource://testing-common/Assert.jsm:270:8
[task 2022-04-05T16:58:00.016Z] 16:58:00     INFO -  clearMessageQueues@resource://testing-common/ExtensionXPCShellUtils.jsm:146:22
[task 2022-04-05T16:58:00.017Z] 16:58:00     INFO -  ExtensionWrapper/<@resource://testing-common/ExtensionXPCShellUtils.jsm:88:12
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  _execute_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:667:28
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:679:16
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  @-e:1:1
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  "Force a GC"
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  PID 6370 | ###!!! [Parent][PBackgroundParent] Error: RunMessage(msgname=PRemoteWorkerService::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  PID 6370 | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  PID 6370 | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  PID 6370 | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  <<<<<<<
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  INFO | Result summary:
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  INFO | Passed: 206
[task 2022-04-05T16:58:00.018Z] 16:58:00  WARNING -  INFO | Failed: 1
[task 2022-04-05T16:58:00.018Z] 16:58:00  WARNING -  One or more unittests failed.
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  INFO | Todo: 0
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  INFO | Retried: 1
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  SUITE-END | took 693s
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  Node moz-http2 server shutting down ...
[task 2022-04-05T16:58:00.018Z] 16:58:00     INFO -  http3Server server shutting down ...
[task 2022-04-05T16:58:00.139Z] 16:58:00    ERROR - Return code: 1

Comment 1

[Cristian Tuns]

Hello, I think this might be related to Bug 1751492, can you please take a look?

Comment 2

[Joel Maher ( :jmaher ) (UTC -8)]

it could be related, I am sort of surprised that this is both fission and socketprocess_networking && !fission, as well as different variants of linux.

quite likely we need to see if this is high frequency enough to disable.

We might need to add:

skip-if =
  os == "linux" && socketprocess_networking && !fission && debug # Bug 1759035
  os == "linux" && fission && (asan||tsan) # 1763198

lets see how this looks in 2 more days.

Comment 3

[Intermittent Failures Robot]

20 failures in 546 pushes (0.037 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-central: 6
• autoland: 14

Platform and build breakdown:

• linux1804-64-qr: 9
  • debug: 9
• linux1804-64-tsan-qr: 10
  • opt: 10
• linux1804-64-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1763198&startday=2022-04-06&endday=2022-04-06&tree=all

Comment 4

[Cosmin Sabou [:CosminS]]

This should go away after https://hg.mozilla.org/integration/autoland/rev/6c8c817086cb7083a6c4a85ad526f7270752b849. I'll revisit in couple of days.

Comment 5

[Intermittent Failures Robot]

55 failures in 2922 pushes (0.019 failures/push) were associated with this bug in the last 7 days.

This is the #9 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 38
• mozilla-central: 15
• try: 2

Platform and build breakdown:

• linux1804-64-asan-qr: 6
  • opt: 6
• linux1804-64-qr: 18
  • debug: 18
• linux1804-64-tsan-qr: 30
  • opt: 30
• windows10-64-2004-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1763198&startday=2022-04-04&endday=2022-04-10&tree=all

Comment 6

[Intermittent Failures Robot]

8 failures in 2948 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 6
• try: 1
• mozilla-central: 1

Platform and build breakdown:

• linux1804-64-asan-qr: 7
  • opt: 7
• linux1804-64-tsan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1763198&startday=2022-04-11&endday=2022-04-17&tree=all

Comment 7

[Cosmin Sabou [:CosminS]]

All the failures left here are on linux1804-64-asan-qr fission and under 10/week. Joel, should we adjust the skip-if clause?

https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2022-04-16&endday=2022-04-23&tree=trunk&bug=1763198

Comment 8

[Joel Maher ( :jmaher ) (UTC -8)]

that is great the pattern has changed, not many failures remaining, maybe not worth skipping, if it picks up with the same pattern, then yeah, asah + fission:

skip-if =
  os == "linux" && fission && asan # 1763198

Comment 9

[Intermittent Failures Robot]

6 failures in 3159 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 6

Platform and build breakdown:

• linux1804-64-asan-qr: 6
  • opt: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1763198&startday=2022-04-18&endday=2022-04-24&tree=all

Comment 10

[Intermittent Failures Robot]

7 failures in 3289 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 6
• mozilla-central: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • debug: 1
• linux1804-64-asan-qr: 5
  • opt: 5
• linux1804-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1763198&startday=2022-04-25&endday=2022-05-01&tree=all

Comment 11

[Intermittent Failures Robot]

8 failures in 3540 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 5
• mozilla-beta: 2
• mozilla-central: 1

Platform and build breakdown:

• linux1804-64-asan-qr: 7
  • opt: 7
• linux1804-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1763198&startday=2022-05-02&endday=2022-05-08&tree=all

Comment 12

[Intermittent Failures Robot]

6 failures in 3317 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 2
• mozilla-beta: 1
• mozilla-central: 2
• try: 1

Platform and build breakdown:

• linux1804-64-asan-qr: 4
  • opt: 4
• macosx1015-64-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1763198&startday=2022-05-09&endday=2022-05-15&tree=all

Comment 13

[Intermittent Failures Robot]

5 failures in 2694 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2
• autoland: 2
• mozilla-beta: 1

Platform and build breakdown:

• macosx1015-64-qr: 2
  • debug: 2
• linux1804-64-qr: 2
  • debug: 2
• linux1804-64-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1763198&startday=2022-05-16&endday=2022-05-22&tree=all

Comment 14

[Intermittent Failures Robot]

5 failures in 2624 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 5

Platform and build breakdown:

• macosx1015-64-qr: 2
  • debug: 2
• linux1804-64-asan-qr: 2
  • opt: 2
• linux1804-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1763198&startday=2022-05-23&endday=2022-05-29&tree=all

Comment 15

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.