1769075 - Perma beta browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Uncaught exception in test - at chrome://mochitests/content/browser/browser/components/search/test/browser/browser_search_telemetry_sources_ads.js:178 - TypeError:

Status: RESOLVED FIXED

(Firefox :: Search, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2022-05-12T14:24:51.143Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.withads.urlbar in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:51.143Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.withads.urlbar_handoff in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:51.144Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.withads.urlbar_searchmode in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:51.145Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.withads.webextension in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:51.145Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.withads.unknown in scalars and expectedScalars - true == true - 
[task 2022-05-12T14:24:51.146Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.adclicks.about_home in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:51.146Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.adclicks.contextmenu in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:51.147Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.adclicks.about_newtab in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:51.148Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.adclicks.searchbar in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:51.148Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.adclicks.system in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:51.149Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.adclicks.urlbar in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:51.149Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.adclicks.urlbar_handoff in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:51.150Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.adclicks.urlbar_searchmode in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:51.151Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.adclicks.webextension in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:51.151Z] 14:24:51     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.adclicks.unknown in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:51.152Z] 14:24:51     INFO - Leaving test bound test_track_ad
[task 2022-05-12T14:24:51.152Z] 14:24:51     INFO - Entering test bound test_track_ad_on_DOMContentLoaded
[task 2022-05-12T14:24:51.152Z] 14:24:51     INFO - Buffered messages finished
[task 2022-05-12T14:24:51.153Z] 14:24:51     INFO - TEST-UNEXPECTED-FAIL | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Uncaught exception in test - at chrome://mochitests/content/browser/browser/components/search/test/browser/browser_search_telemetry_sources_ads.js:178 - TypeError: TestUtils.consoleMessageObserved is not a function
[task 2022-05-12T14:24:51.153Z] 14:24:51     INFO - Stack trace:
[task 2022-05-12T14:24:51.154Z] 14:24:51     INFO - test_track_ad_on_DOMContentLoaded@chrome://mochitests/content/browser/browser/components/search/test/browser/browser_search_telemetry_sources_ads.js:178:47
[task 2022-05-12T14:24:51.154Z] 14:24:51     INFO - handleTask@chrome://mochikit/content/browser-test.js:989:26
[task 2022-05-12T14:24:51.154Z] 14:24:51     INFO - _runTaskBasedTest@chrome://mochikit/content/browser-test.js:1061:18
[task 2022-05-12T14:24:51.154Z] 14:24:51     INFO - Leaving test bound test_track_ad_on_DOMContentLoaded
[task 2022-05-12T14:24:51.155Z] 14:24:51     INFO - Entering test bound test_track_ad_on_load_event
[task 2022-05-12T14:24:51.155Z] 14:24:51     INFO - GECKO(6576) | console.debug: SearchTelemetry: "Counting" "slow-page-load.in-content:sap:ff" "for" "http://mochi.test:8888/browser/browser/components/search/test/browser/slow_loading_page_with_ads_on_load_event.html?s=test&abc=ff"
[task 2022-05-12T14:24:53.091Z] 14:24:53     INFO - Console message: [JavaScript Warning: "The character encoding of a framed document was not declared. The document may appear different if viewed without the document framing it." {file: "http://mochi.test:8888/browser/browser/components/search/test/browser/searchTelemetry.html" line: 0}]
[task 2022-05-12T14:24:54.126Z] 14:24:54     INFO - GECKO(6576) | console.debug: SearchTelemetry: "Counting ads in page for" "slow-page-load" "tagged" "unknown" "http://mochi.test:8888/browser/browser/components/search/test/browser/slow_loading_page_with_ads_on_load_event.html?s=test&abc=ff"
[task 2022-05-12T14:24:54.159Z] 14:24:54     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should only have one key - 1 == 1 - 
[task 2022-05-12T14:24:54.163Z] 14:24:54     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Histogram should have the expected key: slow-page-load.in-content:sap:ff - true == true - 
[task 2022-05-12T14:24:54.163Z] 14:24:54     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have counted the correct number of visits for slow-page-load.in-content:sap:ff - 1 == 1 - 
[task 2022-05-12T14:24:54.164Z] 14:24:54     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Scalar browser.search.content.unknown should have been added. - true == true - 
[task 2022-05-12T14:24:54.166Z] 14:24:54     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have counted the correct number of visits for browser.search.content.unknown - {"slow-page-load:tagged:ff":1} deepEqual {"slow-page-load:tagged:ff":1} - 
[task 2022-05-12T14:24:54.167Z] 14:24:54     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Scalar browser.search.with_ads should have been added. - true == true - 
[task 2022-05-12T14:24:54.168Z] 14:24:54     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have counted the correct number of visits for browser.search.with_ads - {"slow-page-load:sap":1} deepEqual {"slow-page-load:sap":1} - 
[task 2022-05-12T14:24:54.168Z] 14:24:54     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Scalar browser.search.withads.unknown should have been added. - true == true - 
[task 2022-05-12T14:24:54.169Z] 14:24:54     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have counted the correct number of visits for browser.search.withads.unknown - {"slow-page-load:tagged":1} deepEqual {"slow-page-load:tagged":1} - 
[task 2022-05-12T14:24:54.169Z] 14:24:54     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.with_ads in scalars and expectedScalars - true == true - 
[task 2022-05-12T14:24:54.170Z] 14:24:54     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.ad_clicks in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:54.171Z] 14:24:54     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.withads.about_home in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:54.171Z] 14:24:54     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.withads.contextmenu in scalars and expectedScalars - false == false - 
[task 2022-05-12T14:24:54.172Z] 14:24:54     INFO - TEST-PASS | browser/components/search/test/browser/browser_search_telemetry_sources_ads.js | Should have matched browser.search.withads.about_newtab in scalars and expectedScalars - false == false - 

Comment 1

[Ryan VanderMeulen [:RyanVM]]

The newly-added test in bug 1673868 depends on the consoleMessageObserved testing function added in bug 1756823, which didn't land until 102.

I'll run a Try push for the backport of the testing function:
https://hg.mozilla.org/mozilla-central/diff/ddc9c767509cf3e927e3cb22b3c05823e85cd0f4/testing/modules/TestUtils.jsm

Otherwise, we may need to rework the test a bit on Beta to avoid using that function.

Comment 2

[Ryan VanderMeulen [:RyanVM]]

Mark, I'm kind of surprised the linters didn't catch this because I feel like it's caught similar issues in the past. Is this a known limitation?

Comment 3

[Ryan VanderMeulen [:RyanVM]]

Try push for the consoleMessageObserved backport:
https://treeherder.mozilla.org/jobs?repo=try&revision=2f4d5465d542081ca3f4443440d0576010b96cb8

Comment 4

[Mark Banner (:standard8)]

(In reply to Ryan VanderMeulen [:RyanVM] from comment #2)

Mark, I'm kind of surprised the linters didn't catch this because I feel like it's caught similar issues in the past. Is this a known limitation?

Yes, the linter is static analysis, it generally doesn't check what is accessed within objects, only that the variables are in-scope/valid.

Comment 5

[Ryan VanderMeulen [:RyanVM]]

(In reply to Ryan VanderMeulen [:RyanVM] from comment #3)

Try push for the consoleMessageObserved backport:
https://treeherder.mozilla.org/jobs?repo=try&revision=2f4d5465d542081ca3f4443440d0576010b96cb8

This didn't work because there's other dependencies involved as well. Mandy's looking at it.

Comment 6

[Mandy Cheang [:mcheang][she/her]]

Attachment: Bug 1769075 - use Services.obs.addObserver rather than TestUtils.consoleMessageObserved in browser_search_telemetry_sources_ads.js test. r?standard8,RyanVM

The browser_search_telemetry_sources_ads test for patch D140969 and Bug 1752178
called TestUtils.consoleMessageObserved. However, consoleMessageObserved function
was causing failures on beta build because the function had not landed on beta yet.

A uplift was requested for patch D140969 to be in beta and so the patch landed
on beta before TestUtils.consoleMessageObserved became an available function in beta.

Comment 7

[Intermittent Failures Robot]

30 failures in 680 pushes (0.044 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-beta: 30

Platform and build breakdown:

• windows10-64-2004-asan-qr: 7
  • opt: 7
• windows10-64-2004-shippable-qr: 4
  • opt: 4
• windows10-64-2004-devedition-qr: 4
  • opt: 4
• macosx1015-64-devedition-qr: 4
  • opt: 4
• macosx1015-64-shippable-qr: 4
  • opt: 4
• macosx1100-64-shippable-qr: 4
  • opt: 4
• windows7-32-shippable-qr: 3
  • opt: 3

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

Comment 8

[bszekely]

https://hg.mozilla.org/releases/mozilla-beta/rev/9330df47ed96

Comment 9

[Intermittent Failures Robot]

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

This is the #44 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:

• mozilla-beta: 30

Platform and build breakdown:

• windows10-64-2004-asan-qr: 7
  • opt: 7
• windows10-64-2004-shippable-qr: 4
  • opt: 4
• windows10-64-2004-devedition-qr: 4
  • opt: 4
• macosx1015-64-devedition-qr: 4
  • opt: 4
• macosx1015-64-shippable-qr: 4
  • opt: 4
• macosx1100-64-shippable-qr: 4
  • opt: 4
• windows7-32-shippable-qr: 3
  • opt: 3

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