1862389 - Intermittent browser/components/shopping/tests/browser/browser_shopping_onboarding.js | single tracking bug

Status: RESOLVED FIXED

(Firefox :: Messaging System, defect, P2)

Description

[Treeherder Bug Filer]

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

---

[task 2023-11-01T09:38:17.074Z] 09:38:17     INFO - TEST-START | browser/components/shopping/tests/browser/browser_shopping_onboarding.js
[task 2023-11-01T09:38:17.270Z] 09:38:17     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f4ff6308000 == 2 [pid = 10412] [id = 19]
[task 2023-11-01T09:38:17.271Z] 09:38:17     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 8 (7f4ff66de020) [pid = 10412] [serial = 58] [outer = 0]
[task 2023-11-01T09:38:17.278Z] 09:38:17     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 9 (7f4ff6308c00) [pid = 10412] [serial = 59] [outer = 7f4ff66de020]
[task 2023-11-01T09:38:17.478Z] 09:38:17     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 10 (7f4ff630a400) [pid = 10412] [serial = 60] [outer = 7f4ff66de020]
[task 2023-11-01T09:38:18.015Z] 09:38:18     INFO - GECKO(10187) | [Child 10412, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, NS_OK) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/caps/BasePrincipal.cpp:1150
[task 2023-11-01T09:38:18.382Z] 09:38:18     INFO - GECKO(10187) | console.warn: AboutWelcomeParent: Not handling AWPage:TELEMETRY_EVENT because the browser doesn't exist.
[task 2023-11-01T09:38:18.390Z] 09:38:18     INFO - GECKO(10187) | console.warn: AboutWelcomeParent: Not handling AWPage:ADD_SCREEN_IMPRESSION because the browser doesn't exist.
[task 2023-11-01T09:38:18.401Z] 09:38:18     INFO - GECKO(10187) | JavaScript error: , line 0: AbortError: Actor 'AboutWelcomeShopping' destroyed before query 'AWPage:ADD_SCREEN_IMPRESSION' was resolved
[task 2023-11-01T09:38:18.403Z] 09:38:18     INFO - GECKO(10187) | JavaScript error: , line 0: AbortError: Actor 'AboutWelcomeShopping' destroyed before query 'AWPage:TELEMETRY_EVENT' was resolved
[task 2023-11-01T09:38:18.407Z] 09:38:18     INFO - GECKO(10187) | JavaScript error: , line 0: InternalError: Promise rejection value is a non-unwrappable cross-compartment wrapper.
[task 2023-11-01T09:38:18.408Z] 09:38:18     INFO - GECKO(10187) | JavaScript error: , line 0: InternalError: Promise rejection value is a non-unwrappable cross-compartment wrapper.
[task 2023-11-01T09:38:18.643Z] 09:38:18     INFO - GECKO(10187) | [Child 10298: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (7f92be6305c0) [pid = 10298] [serial = 15] [outer = 0] [url = about:blank]
[task 2023-11-01T09:38:18.953Z] 09:38:18     INFO - TEST-INFO | started process screentopng
[task 2023-11-01T09:38:19.456Z] 09:38:19     INFO - TEST-INFO | screentopng: exit 0
[task 2023-11-01T09:38:19.457Z] 09:38:19     INFO - Buffered messages logged at 09:38:17
[task 2023-11-01T09:38:19.457Z] 09:38:19     INFO - Entering setup bound setup
[task 2023-11-01T09:38:19.458Z] 09:38:19     INFO - Leaving setup bound setup
[task 2023-11-01T09:38:19.458Z] 09:38:19     INFO - Entering test bound test_showOnboarding_notOptedIn
[task 2023-11-01T09:38:19.458Z] 09:38:19     INFO - Buffered messages logged at 09:38:18
[task 2023-11-01T09:38:19.458Z] 09:38:19     INFO - TEST-PASS | browser/components/shopping/tests/browser/browser_shopping_onboarding.js | message slot element exists - 1 == true - 
[task 2023-11-01T09:38:19.462Z] 09:38:19     INFO - TEST-PASS | browser/components/shopping/tests/browser/browser_shopping_onboarding.js | multi-stage-message-slot showing opt-in message rendered - "multi-stage-message-slot" == "multi-stage-message-slot" - 
[task 2023-11-01T09:38:19.463Z] 09:38:19     INFO - TEST-PASS | browser/components/shopping/tests/browser/browser_shopping_onboarding.js | message is shown - true == true - 
[task 2023-11-01T09:38:19.465Z] 09:38:19     INFO - Console message: [JavaScript Error: "AbortError: Actor 'AboutWelcomeShopping' destroyed before query 'AWPage:ADD_SCREEN_IMPRESSION' was resolved"]
[task 2023-11-01T09:38:19.467Z] 09:38:19     INFO - Console message: [JavaScript Error: "AbortError: Actor 'AboutWelcomeShopping' destroyed before query 'AWPage:TELEMETRY_EVENT' was resolved"]
[task 2023-11-01T09:38:19.468Z] 09:38:19     INFO - Console message: [JavaScript Error: "InternalError: Promise rejection value is a non-unwrappable cross-compartment wrapper."]
[task 2023-11-01T09:38:19.469Z] 09:38:19     INFO - Console message: [JavaScript Error: "InternalError: Promise rejection value is a non-unwrappable cross-compartment wrapper."]
[task 2023-11-01T09:38:19.470Z] 09:38:19     INFO - Buffered messages finished
[task 2023-11-01T09:38:19.472Z] 09:38:19     INFO - TEST-UNEXPECTED-FAIL | browser/components/shopping/tests/browser/browser_shopping_onboarding.js | Uncaught exception in test bound test_showOnboarding_notOptedIn - at chrome://mochitests/content/browser/browser/components/shopping/tests/browser/browser_shopping_onboarding.js:144 - TypeError: can't access property "length", events is null
[task 2023-11-01T09:38:19.478Z] 09:38:19     INFO - Stack trace:
[task 2023-11-01T09:38:19.479Z] 09:38:19     INFO - test_showOnboarding_notOptedIn@chrome://mochitests/content/browser/browser/components/shopping/tests/browser/browser_shopping_onboarding.js:144:20
[task 2023-11-01T09:38:19.480Z] 09:38:19     INFO - async*handleTask@chrome://mochikit/content/browser-test.js:1134:26
[task 2023-11-01T09:38:19.480Z] 09:38:19     INFO - _runTaskBasedTest@chrome://mochikit/content/browser-test.js:1206:18
[task 2023-11-01T09:38:19.481Z] 09:38:19     INFO - async*Tester_execTest@chrome://mochikit/content/browser-test.js:1348:14
[task 2023-11-01T09:38:19.481Z] 09:38:19     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:1123:14
[task 2023-11-01T09:38:19.482Z] 09:38:19     INFO - SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13
[task 2023-11-01T09:38:19.483Z] 09:38:19     INFO - Leaving test bound test_showOnboarding_notOptedIn
[task 2023-11-01T09:38:19.490Z] 09:38:19     INFO - Entering test bound test_hideOnboarding_optedIn
[task 2023-11-01T09:38:19.492Z] 09:38:19     INFO - GECKO(10187) | [Child 10361: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (7fb424c35800) [pid = 10361] [serial = 13] [outer = 0] [url = about:blank]
[task 2023-11-01T09:38:19.497Z] 09:38:19     INFO - GECKO(10187) | [Child 10361: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (7fb424c37400) [pid = 10361] [serial = 15] [outer = 0] [url = about:blank]
[task 2023-11-01T09:38:19.498Z] 09:38:19     INFO - GECKO(10187) | [Child 10361: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7fb424c38400 == 0 [pid = 10361] [id = 7] [url = about:blank]
[task 2023-11-01T09:38:19.499Z] 09:38:19     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f4ff630cc00 == 3 [pid = 10412] [id = 20]
[task 2023-11-01T09:38:19.509Z] 09:38:19     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 11 (7f4ff66de5c0) [pid = 10412] [serial = 61] [outer = 0]
[task 2023-11-01T09:38:19.510Z] 09:38:19     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 12 (7f4ff6fa1000) [pid = 10412] [serial = 62] [outer = 7f4ff66de5c0]
[task 2023-11-01T09:38:19.511Z] 09:38:19     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 13 (7f4ff6fa2c00) [pid = 10412] [serial = 63] [outer = 7f4ff66de5c0]
[task 2023-11-01T09:38:19.512Z] 09:38:19     INFO - GECKO(10187) | [Parent 10187: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 23 (7faf8d4d3400) [pid = 10187] [serial = 4] [outer = 0] [url = about:blank]
[task 2023-11-01T09:38:19.517Z] 09:38:19     INFO - GECKO(10187) | [Parent 10187: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 22 (7faf61d996a0) [pid = 10187] [serial = 23] [outer = 0] [url = about:blank]
[task 2023-11-01T09:38:19.521Z] 09:38:19     INFO - GECKO(10187) | [Parent 10187: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 21 (7faf56598980) [pid = 10187] [serial = 19] [outer = 0] [url = about:blank]
[task 2023-11-01T09:38:19.522Z] 09:38:19     INFO - GECKO(10187) | [Parent 10187: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 20 (7faf57235800) [pid = 10187] [serial = 20] [outer = 0] [url = about:blank]
[task 2023-11-01T09:38:19.559Z] 09:38:19     INFO - GECKO(10187) | console.error: "Failed to fetch product analysis data" (new Error("request failed", "resource:///actors/ShoppingSidebarChild.sys.mjs", 290))
[task 2023-11-01T09:38:19.618Z] 09:38:19     INFO - GECKO(10187) | [Parent 10187: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 19 (7faf57230800) [pid = 10187] [serial = 16] [outer = 0] [url = about:blank]
[task 2023-11-01T09:38:19.618Z] 09:38:19     INFO - GECKO(10187) | [Parent 10187: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (7faf66f57980) [pid = 10187] [serial = 15] [outer = 0] [url = about:blank]
[task 2023-11-01T09:38:19.633Z] 09:38:19     INFO - GECKO(10187) | [Parent 10187: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (7faf64ace400) [pid = 10187] [serial = 9] [outer = 0] [url = about:blank]
[task 2023-11-01T09:38:19.667Z] 09:38:19     INFO - GECKO(10187) | [Parent 10187: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (7faf565ca400) [pid = 10187] [serial = 24] [outer = 0] [url = about:blank]
[task 2023-11-01T09:38:19.686Z] 09:38:19     INFO - GECKO(10187) | [Child 10412, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, NS_OK) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/caps/BasePrincipal.cpp:1150
[task 2023-11-01T09:38:19.687Z] 09:38:19     INFO - GECKO(10187) | [Child 10412, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, NS_OK) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/caps/BasePrincipal.cpp:1150
[task 2023-11-01T09:38:19.769Z] 09:38:19     INFO - GECKO(10187) | [Child 10412, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, NS_OK) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/caps/BasePrincipal.cpp:1150
[task 2023-11-01T09:38:19.769Z] 09:38:19     INFO - GECKO(10187) | [Child 10412, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, NS_OK) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/caps/BasePrincipal.cpp:1150
[task 2023-11-01T09:38:19.954Z] 09:38:19     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 12 (7f4ff6fa1800) [pid = 10412] [serial = 54] [outer = 0] [url = about:shoppingsidebar]
[task 2023-11-01T09:38:19.955Z] 09:38:19     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 11 (7f4ff6f9f400) [pid = 10412] [serial = 53] [outer = 0] [url = about:blank]
[task 2023-11-01T09:38:19.956Z] 09:38:19     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f4ff6308000 == 2 [pid = 10412] [id = 19] [url = about:shoppingsidebar]
[task 2023-11-01T09:38:20.144Z] 09:38:20     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (7f4ff66de980) [pid = 10412] [serial = 55] [outer = 0] [url = about:shoppingsidebar]
[task 2023-11-01T09:38:20.551Z] 09:38:20     INFO - TEST-PASS | browser/components/shopping/tests/browser/browser_shopping_onboarding.js | message is hidden - true == true - 
[task 2023-11-01T09:38:20.587Z] 09:38:20     INFO - Leaving test bound test_hideOnboarding_optedIn
[task 2023-11-01T09:38:20.593Z] 09:38:20     INFO - Entering test bound test_hideOnboarding_onClose
[task 2023-11-01T09:38:20.690Z] 09:38:20     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f4ff630a000 == 3 [pid = 10412] [id = 21]
[task 2023-11-01T09:38:20.691Z] 09:38:20     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 11 (7f4ff66de980) [pid = 10412] [serial = 64] [outer = 0]
[task 2023-11-01T09:38:20.691Z] 09:38:20     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 12 (7f4ff630d800) [pid = 10412] [serial = 65] [outer = 7f4ff66de980]
[task 2023-11-01T09:38:20.798Z] 09:38:20     INFO - GECKO(10187) | [Child 10412: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 13 (7f4ff6fa1800) [pid = 10412] [serial = 66] [outer = 7f4ff66de980]
[task 2023-11-01T09:38:21.295Z] 09:38:21     INFO - GECKO(10187) | [Child 10412, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, NS_OK) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/caps/BasePrincipal.cpp:1150
[task 2023-11-01T09:38:21.296Z] 09:38:21     INFO - GECKO(10187) | [Child 10412, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, NS_OK) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/caps/BasePrincipal.cpp:1150
[task 2023-11-01T09:38:21.771Z] 09:38:21     INFO - TEST-PASS | browser/components/shopping/tests/browser/browser_shopping_onboarding.js | Shopping container element does not exist - true == true - 
[task 2023-11-01T09:38:21.946Z] 09:38:21     INFO - TEST-PASS | browser/components/shopping/tests/browser/browser_shopping_onboarding.js | 1 > 0 - 
[task 2023-11-01T09:38:21.950Z] 09:38:21     INFO - TEST-PASS | browser/components/shopping/tests/browser/browser_shopping_onboarding.js | "shopping" == "shopping" - 
[task 2023-11-01T09:38:21.955Z] 09:38:21     INFO - TEST-PASS | browser/components/shopping/tests/browser/browser_shopping_onboarding.js | "surface_not_now_clicked" == "surface_not_now_clicked" - 

Comment 1

[Noemi Erli[:noemi_erli]]

Retriggers and backfills reveals that this was cause by https://treeherder.mozilla.org/jobs?repo=autoland&searchStr=linux%2C18.04%2Cx64%2Cwebrender%2Cdebug%2Cmochitests%2Cwith%2Cnetworking%2Con%2Csocket%2Cprocess%2Ctest-linux1804-64-qr%2Fdebug-mochitest-browser-chrome-spi-nw%2Cbc7&revision=ec1ae79c683262b028e2dccb306c8bf77cfee877&selectedTaskRun=Q34X4zbnR_e14Da_G5PniQ.0

Comment 2

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

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

Comment 3

[Intermittent Failures Robot]

37 failures in 3356 pushes (0.011 failures/push) were associated with this bug in the last 7 days.

** 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: 21
• mozilla-central: 7
• mozilla-beta: 3
• try: 6

Platform and build breakdown:

• linux1804-64-asan-qr: 15
  • opt: 15
• linux1804-64-qr: 19
  • debug: 19
• windows11-64-2009-qr: 2
  • debug: 2
• windows11-32-2009-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1862389&startday=2023-10-30&endday=2023-11-05&tree=all

Comment 4

[Mimi Jung]

Attachment: Bug 1862389 - browser_shopping_onboarding events test to fail more gracefully

Comment 5

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/933ecd8bd849
browser_shopping_onboarding events test to fail more gracefully r=omc-reviewers,aminomancer

Comment 6

[Cristina Horotan [:chorotan]]

https://hg.mozilla.org/mozilla-central/rev/933ecd8bd849

Comment 7

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

The patch landed in nightly and beta is affected.
:nsauermann, is this bug important enough to require an uplift?

• If yes, please nominate the patch for beta approval.
• If no, please set status-firefox120 to wontfix.

For more information, please visit BugBot documentation.

Comment 8

[Intermittent Failures Robot]

18 failures in 3288 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

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

Platform and build breakdown:

• windows11-64-2009-qr: 4
  • debug: 4
• linux1804-64-qr: 8
  • debug: 8
• macosx1015-64-qr: 2
  • debug: 1
  • opt: 1
• linux1804-64-asan-qr: 4
  • opt: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1862389&startday=2023-11-06&endday=2023-11-12&tree=all