Closed Bug 1642299 Opened 6 years ago Closed 4 years ago

Intermittent browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | expected counts should match for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 2 - 2 == 1

Categories

(Core :: DOM: Navigation, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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


[task 2020-06-01T09:11:58.988Z] 09:11:58 INFO - TEST-START | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js
[task 2020-06-01T09:11:59.007Z] 09:11:59 INFO - GECKO(7430) | Waiting for browser load
[task 2020-06-01T09:11:59.028Z] 09:11:59 INFO - GECKO(7430) | Saw state f0001 and status 0
[task 2020-06-01T09:11:59.230Z] 09:11:59 INFO - GECKO(7430) | Saw state c0010 and status 0
[task 2020-06-01T09:11:59.230Z] 09:11:59 INFO - GECKO(7430) | Browser loaded http://mochi.test:8888/browser/browser/modules/test/browser/contain_iframe.html
[task 2020-06-01T09:11:59.332Z] 09:11:59 INFO - TEST-INFO | started process screentopng
[task 2020-06-01T09:11:59.548Z] 09:11:59 INFO - TEST-INFO | screentopng: exit 0
[task 2020-06-01T09:11:59.549Z] 09:11:59 INFO - Buffered messages logged at 09:11:58
[task 2020-06-01T09:11:59.550Z] 09:11:59 INFO - Entering test bound test_numberOfSiteOriginsAfterTabClose
[task 2020-06-01T09:11:59.550Z] 09:11:59 INFO - Buffered messages logged at 09:11:59
[task 2020-06-01T09:11:59.551Z] 09:11:59 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | unexpected counts should be zero for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 1 - 0 == 0 -
[task 2020-06-01T09:11:59.551Z] 09:11:59 INFO - Buffered messages finished
[task 2020-06-01T09:11:59.551Z] 09:11:59 INFO - TEST-UNEXPECTED-FAIL | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | expected counts should match for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 2 - 2 == 1 - JS frame :: resource://testing-common/TelemetryTestUtils.jsm :: assertHistogram :: line 291
[task 2020-06-01T09:11:59.551Z] 09:11:59 INFO - Stack trace:
[task 2020-06-01T09:11:59.551Z] 09:11:59 INFO - resource://testing-common/TelemetryTestUtils.jsm:assertHistogram:291
[task 2020-06-01T09:11:59.551Z] 09:11:59 INFO - chrome://mochitests/content/browser/browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js:test_numberOfSiteOriginsAfterTabClose:48
[task 2020-06-01T09:11:59.552Z] 09:11:59 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1064
[task 2020-06-01T09:11:59.552Z] 09:11:59 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1104
[task 2020-06-01T09:11:59.552Z] 09:11:59 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:927
[task 2020-06-01T09:11:59.553Z] 09:11:59 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:918
[task 2020-06-01T09:11:59.553Z] 09:11:59 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | unexpected counts should be zero for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 3 - 0 == 0 -
[task 2020-06-01T09:11:59.554Z] 09:11:59 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | Should have found an entry for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 2 - true == true -
[task 2020-06-01T09:11:59.554Z] 09:11:59 INFO - Leaving test bound test_numberOfSiteOriginsAfterTabClose
[task 2020-06-01T09:11:59.555Z] 09:11:59 INFO - Entering test bound test_numberOfSiteOriginsAboutBlank
[task 2020-06-01T09:11:59.555Z] 09:11:59 INFO - GECKO(7430) | Waiting for browser load
[task 2020-06-01T09:11:59.555Z] 09:11:59 INFO - GECKO(7430) | Saw state c0010 and status 0
[task 2020-06-01T09:11:59.556Z] 09:11:59 INFO - GECKO(7430) | Browser loaded about:blank
[task 2020-06-01T09:11:59.652Z] 09:11:59 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | Histogram should have no values; had {} - {} deepEqual {} -
[task 2020-06-01T09:11:59.653Z] 09:11:59 INFO - Leaving test bound test_numberOfSiteOriginsAboutBlank
[task 2020-06-01T09:11:59.655Z] 09:11:59 INFO - Entering test bound test_numberOfSiteOriginsMultipleNavigations
[task 2020-06-01T09:11:59.683Z] 09:11:59 INFO - GECKO(7430) | Waiting for browser load
[task 2020-06-01T09:11:59.692Z] 09:11:59 INFO - GECKO(7430) | Saw state f0001 and status 0
[task 2020-06-01T09:11:59.788Z] 09:11:59 INFO - GECKO(7430) | Saw state c0010 and status 0
[task 2020-06-01T09:11:59.788Z] 09:11:59 INFO - GECKO(7430) | Browser loaded http://mochi.test:8888/browser/browser/modules/test/browser/contain_iframe.html
[task 2020-06-01T09:12:00.091Z] 09:12:00 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | unexpected counts should be zero for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 1 - 0 == 0 -
[task 2020-06-01T09:12:00.091Z] 09:12:00 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | expected counts should match for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 2 - 2 == 2 -
[task 2020-06-01T09:12:00.091Z] 09:12:00 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | unexpected counts should be zero for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 3 - 0 == 0 -
[task 2020-06-01T09:12:00.094Z] 09:12:00 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | Should have found an entry for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 2 - true == true -
[task 2020-06-01T09:12:00.095Z] 09:12:00 INFO - Leaving test bound test_numberOfSiteOriginsMultipleNavigations
[task 2020-06-01T09:12:00.096Z] 09:12:00 INFO - Entering test bound test_numberOfSiteOriginsAddAndRemove
[task 2020-06-01T09:12:00.117Z] 09:12:00 INFO - GECKO(7430) | Waiting for browser load
[task 2020-06-01T09:12:00.141Z] 09:12:00 INFO - GECKO(7430) | Saw state f0001 and status 0
[task 2020-06-01T09:12:00.200Z] 09:12:00 INFO - GECKO(7430) | Saw state c0010 and status 0
[task 2020-06-01T09:12:00.200Z] 09:12:00 INFO - GECKO(7430) | Browser loaded http://mochi.test:8888/browser/browser/modules/test/browser/blank_iframe.html
[task 2020-06-01T09:12:00.545Z] 09:12:00 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | unexpected counts should be zero for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 1 - 0 == 0 -
[task 2020-06-01T09:12:00.545Z] 09:12:00 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | expected counts should match for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 2 - 1 == 1 -
[task 2020-06-01T09:12:00.545Z] 09:12:00 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | unexpected counts should be zero for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 3 - 0 == 0 -
[task 2020-06-01T09:12:00.545Z] 09:12:00 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | Should have found an entry for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 2 - true == true -
[task 2020-06-01T09:12:00.545Z] 09:12:00 INFO - Leaving test bound test_numberOfSiteOriginsAddAndRemove
[task 2020-06-01T09:12:00.562Z] 09:12:00 INFO - GECKO(7430) | MEMORY STAT | vsize 3800MB | residentFast 411MB | heapAllocated 159MB
[task 2020-06-01T09:12:00.562Z] 09:12:00 INFO - TEST-OK | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | took 1580ms
[task 2020-06-01T09:12:00.589Z] 09:12:00 INFO - checking window state

Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=331402258&repo=mozilla-central&lineNumber=7250

[task 2021-02-26T23:50:47.254Z] 23:50:47 INFO - TEST-START | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js
[task 2021-02-26T23:50:47.623Z] 23:50:47 INFO - TEST-INFO | started process screentopng
[task 2021-02-26T23:50:47.887Z] 23:50:47 INFO - TEST-INFO | screentopng: exit 0
[task 2021-02-26T23:50:47.888Z] 23:50:47 INFO - Buffered messages logged at 23:50:47
[task 2021-02-26T23:50:47.888Z] 23:50:47 INFO - Entering test bound test_numberOfSiteOriginsAfterTabClose
[task 2021-02-26T23:50:47.889Z] 23:50:47 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | unexpected counts should be zero for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 1 - 0 == 0 -
[task 2021-02-26T23:50:47.889Z] 23:50:47 INFO - Buffered messages finished
[task 2021-02-26T23:50:47.890Z] 23:50:47 INFO - TEST-UNEXPECTED-FAIL | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | expected counts should match for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 2 - 2 == 1 - JS frame :: resource://testing-common/TelemetryTestUtils.jsm :: assertHistogram :: line 291
[task 2021-02-26T23:50:47.890Z] 23:50:47 INFO - Stack trace:
[task 2021-02-26T23:50:47.890Z] 23:50:47 INFO - resource://testing-common/TelemetryTestUtils.jsm:assertHistogram:291
[task 2021-02-26T23:50:47.891Z] 23:50:47 INFO - chrome://mochitests/content/browser/browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js:test_numberOfSiteOriginsAfterTabClose:49
[task 2021-02-26T23:50:47.891Z] 23:50:47 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | unexpected counts should be zero for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 3 - 0 == 0 -
[task 2021-02-26T23:50:47.892Z] 23:50:47 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | Should have found an entry for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 2 - true == true -
[task 2021-02-26T23:50:47.892Z] 23:50:47 INFO - Leaving test bound test_numberOfSiteOriginsAfterTabClose
[task 2021-02-26T23:50:47.892Z] 23:50:47 INFO - Entering test bound test_numberOfSiteOriginsAboutBlank
[task 2021-02-26T23:50:48.134Z] 23:50:48 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | Histogram should have no values; had {} - {} deepEqual {} -
[task 2021-02-26T23:50:48.134Z] 23:50:48 INFO - Leaving test bound test_numberOfSiteOriginsAboutBlank
[task 2021-02-26T23:50:48.138Z] 23:50:48 INFO - Entering test bound test_numberOfSiteOriginsMultipleNavigations
[task 2021-02-26T23:50:48.138Z] 23:50:48 INFO - GECKO(9306) | Waiting for browser load
[task 2021-02-26T23:50:48.138Z] 23:50:48 INFO - GECKO(9306) | Waiting for browser state change
[task 2021-02-26T23:50:48.167Z] 23:50:48 INFO - GECKO(9306) | Saw state f0001 and status 0
[task 2021-02-26T23:50:48.302Z] 23:50:48 INFO - GECKO(9306) | Saw state c0010 and status 0
[task 2021-02-26T23:50:48.303Z] 23:50:48 INFO - GECKO(9306) | Browser got expected state change http://mochi.test:8888/browser/browser/modules/test/browser/contain_iframe.html
[task 2021-02-26T23:50:48.572Z] 23:50:48 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | unexpected counts should be zero for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 1 - 0 == 0 -
[task 2021-02-26T23:50:48.572Z] 23:50:48 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | expected counts should match for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 2 - 2 == 2 -
[task 2021-02-26T23:50:48.573Z] 23:50:48 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | unexpected counts should be zero for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 3 - 0 == 0 -
[task 2021-02-26T23:50:48.573Z] 23:50:48 INFO - TEST-PASS | browser/modules/test/browser/browser_Telemetry_numberOfSiteOriginsPerDocument.js | Should have found an entry for FX_NUMBER_OF_UNIQUE_SITE_ORIGINS_PER_DOCUMENT at index 2 - true == true -
[task 2021-02-26T23:50:48.574Z] 23:50:48 INFO - Leaving test bound test_numberOfSiteOriginsMultipleNavigations
[task 2021-02-26T23:50:48.575Z] 23:50:48 INFO - Entering test bound test_numberOfSiteOriginsAddAndRemove

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

Redirecting to the component the test was added in.

:brennie, any insights?

Component: Telemetry → Performance
Flags: needinfo?(brennie)
Product: Toolkit → Core

I think this must be due to a race where BrowsingContext fields aren't being synced before we end up closing the tab. I don't know specifically how to fix this off hand, though.

Flags: needinfo?(brennie)
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Component: Performance → Telemetry
Product: Core → Toolkit

Given comment 19, this seems like it's not a Telemetry bug, but a bug in BrowsingContext. :mstange, is there evidence I'm missing that suggests this is more likely to be a Telemetry bug?

Flags: needinfo?(mstange.moz)

Ah, no, I just picked the next best component from bugs in the file history. I'll move it to DOM: Navigation.

Component: Telemetry → DOM: Navigation
Flags: needinfo?(mstange.moz)
Product: Toolkit → Core
Status: REOPENED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.