Open Bug 1781850 Opened 2 years ago Updated 1 year ago

Intermittent browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js | single tracking bug

Categories

(Core :: Privacy: Anti-Tracking, defect, P3)

defect

Tracking

()

REOPENED
Tracking Status
firefox-esr102 --- unaffected
firefox112 --- unaffected
firefox113 --- unaffected
firefox114 --- wontfix
firefox115 --- wontfix

People

(Reporter: jmaher, Assigned: tjr, NeedInfo)

References

(Regression)

Details

(Keywords: intermittent-failure, intermittent-testcase, regression, Whiteboard: [stockwell unknown][stockwell unknown])

Attachments

(1 file)

No description provided.

Additional information about this bug failures and frequency patterns can be found by running: ./mach test-info failure-report --bug 1781850

There have been 40 total failures in the last 7 days.
There are:

  • 26 failures on Windows 7 WebRender opt
  • 5 failures on Windows 7 WebRender Shippable opt
  • 1 failure on Windows 11 x64 22H2 WebRender debug
  • 3 failures on OS X 11 WebRender Shippable opt
  • 1 failure on OS X 10.15 WebRender Shippable opt
  • 1 failure on Linux 18.04 x64 WebRender tsan opt
  • 1 failure on Linux 18.04 x64 WebRender debug
  • 2 failures on Linux 18.04 x64 WebRender opt

Failure lines that were classified with this bug are:

  • Should not have rounded 'new content.Date().getTime()' to nearest 7.97 ms; saw 1681689110076. scenario: TEST_SCENARIO_8 - false == true - got false, expected true (operator ==);
  • Should not have rounded 'content.performance.now()' to nearest 7.97 ms; saw 407. scenario: TEST_SCENARIO_8 - false == true - got false, expected true (operator ==);
  • Should not have rounded 'new content.Event("").timeStamp' to nearest 7.97 ms; saw 407. scenario: TEST_SCENARIO_8 - false == true - got false, expected true (operator ==).

Recent failure log.

[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - TEST-PASS | browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js | Should not have rounded 'new content.File([], "").lastModified' to nearest 7.97 ms; saw 1682169977740. scenario: TEST_SCENARIO_8 - true == true - 
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - Buffered messages finished
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - TEST-UNEXPECTED-FAIL | browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js | Should not have rounded 'new content.Date().getTime()' to nearest 7.97 ms; saw 1682169977738. scenario: TEST_SCENARIO_8 - false == true - got false, expected true (operator ==)
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - Stack trace:
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - ok@resource://specialpowers/SpecialPowersSandbox.sys.mjs:85:21
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - @chrome://mochitests/content/browser/browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js line 97 > eval:15:9
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - @chrome://mochitests/content/browser/browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js:154:19
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - execute@resource://specialpowers/SpecialPowersSandbox.sys.mjs:139:12
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - _spawnTask@resource://specialpowers/SpecialPowersChild.sys.mjs:1648:15
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - receiveMessage@resource://specialpowers/SpecialPowersChild.sys.mjs:261:21
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - JSActor query*receiveMessage@resource://specialpowers/SpecialPowersParent.sys.mjs:1388:14
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - JSActor query*spawn@resource://specialpowers/SpecialPowersChild.sys.mjs:1579:17
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - setupAndRunCrossOriginIsolatedTest@chrome://mochitests/content/browser/browser/components/resistfingerprinting/test/browser/head.js:233:23
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - async*runRTPTestDOM@chrome://mochitests/content/browser/browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js:240:9
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - async*handleTask@chrome://mochikit/content/browser-test.js:1127:26
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - _runTaskBasedTest@chrome://mochikit/content/browser-test.js:1199:18
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1341:14
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:1116:14
[task 2023-04-22T13:26:17.929Z] 13:26:17     INFO - SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13
[task 2023-04-22T13:26:17.937Z] 13:26:17     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - TEST-UNEXPECTED-FAIL | browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js | Should not have rounded 'content.performance.now()' to nearest 7.97 ms; saw 375. scenario: TEST_SCENARIO_8 - false == true - got false, expected true (operator ==)
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - Stack trace:
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - ok@resource://specialpowers/SpecialPowersSandbox.sys.mjs:85:21
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - @chrome://mochitests/content/browser/browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js line 97 > eval:15:9
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - @chrome://mochitests/content/browser/browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js:154:19
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - execute@resource://specialpowers/SpecialPowersSandbox.sys.mjs:139:12
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - _spawnTask@resource://specialpowers/SpecialPowersChild.sys.mjs:1648:15
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - receiveMessage@resource://specialpowers/SpecialPowersChild.sys.mjs:261:21
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - JSActor query*receiveMessage@resource://specialpowers/SpecialPowersParent.sys.mjs:1388:14
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - JSActor query*spawn@resource://specialpowers/SpecialPowersChild.sys.mjs:1579:17
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - setupAndRunCrossOriginIsolatedTest@chrome://mochitests/content/browser/browser/components/resistfingerprinting/test/browser/head.js:233:23
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - async*runRTPTestDOM@chrome://mochitests/content/browser/browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js:240:9
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - async*handleTask@chrome://mochikit/content/browser-test.js:1127:26
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - _runTaskBasedTest@chrome://mochikit/content/browser-test.js:1199:18
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1341:14
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:1116:14
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - TEST-UNEXPECTED-FAIL | browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js | Should not have rounded 'new content.Event("").timeStamp' to nearest 7.97 ms; saw 375. scenario: TEST_SCENARIO_8 - false == true - got false, expected true (operator ==)
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - Stack trace:
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - ok@resource://specialpowers/SpecialPowersSandbox.sys.mjs:85:21
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - @chrome://mochitests/content/browser/browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js line 97 > eval:15:9
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - @chrome://mochitests/content/browser/browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js:154:19
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - execute@resource://specialpowers/SpecialPowersSandbox.sys.mjs:139:12
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - _spawnTask@resource://specialpowers/SpecialPowersChild.sys.mjs:1648:15
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - receiveMessage@resource://specialpowers/SpecialPowersChild.sys.mjs:261:21
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - JSActor query*receiveMessage@resource://specialpowers/SpecialPowersParent.sys.mjs:1388:14
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - JSActor query*spawn@resource://specialpowers/SpecialPowersChild.sys.mjs:1579:17
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - setupAndRunCrossOriginIsolatedTest@chrome://mochitests/content/browser/browser/components/resistfingerprinting/test/browser/head.js:233:23
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - async*runRTPTestDOM@chrome://mochitests/content/browser/browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js:240:9
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - async*handleTask@chrome://mochikit/content/browser-test.js:1127:26
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - _runTaskBasedTest@chrome://mochikit/content/browser-test.js:1199:18
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1341:14
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:1116:14
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13
[task 2023-04-22T13:26:17.945Z] 13:26:17     INFO - TEST-PASS | browser/components/resistfingerprinting/test/browser/browser_cross_origin_isolated_reduce_time_precision.js | webCOOP+COEP=https://example.com expected to be coop+coep - 

Hello Tim! Any chance you could help us assign this to someone?

Thank you!

Flags: needinfo?(tihuang)
Whiteboard: [stockwell needswork:owner]

Tom, do you know of any recent changes that may cause this intermittent?

Flags: needinfo?(tom)
Flags: needinfo?(tihuang)
Flags: needinfo?(evilpies)
Flags: needinfo?(evilpies)

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

So this might be the intermittents we expected, and tried to minimize. It's reporting that these timestamps should not be rounded, but that they are. This could be because we are doing something wrong or it could be because the number just happened to be a value that is evenly(ish) divisible by the precision.

I suspect it is the latter. This is doubly true because scenario 8 is the highest precision (7.97 ms) meaning it is more likely to trigger. I would expect there to be some, smaller number, of failures on test scenarios 5 (13ms), test scenario 2 (100ms). I gather that comment 19 is not comprehensive of all failures, so I'm assuming that's the case.

So what do we do? Most of the failures are on opt, we could always disable the test on opt, but we'll still have intermittents on debug, just fewer. We could remove these test scenarios entirely, in which case we wouldn't be noticing the scenario where RFP is enabled on PBM, but we are accidentally applying it in normal windows.

I think we probably need to do the latter, although it sucks, because intermittents suck more. There should be other tests where we are verifying that RFP is not being applied in PBM. (It won't be testing time precision specifically, it will be testing some other API, like hardware concurrency, but it's still something.) I will leave the ni to verify that the other test exists, and then remove these scenarios.

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

There have been 37 total failures in the last 7 days.
There are:

  • 2 failures on linux1804-64-qr opt and debug
  • 2 failures on linux1804-64-shippable-qr opt
  • 3 failures on macosx1015-64-qr opt and debug
  • 1 failure on windows11-64-2009-ccov-qr opt
  • 2 failures on windows11-64-2009-qr opt
  • 16 failures on windows7-32-qr opt
  • 11 failures on windows7-32-shippable-qr opt

Recent failure log.

Tim, as the owner of this component, can you help us assign the bug to someone? Thank you.

Flags: needinfo?(tihuang)
Whiteboard: [stockwell unknown] → [stockwell unknown][stockwell needswork:owner]

Tom, I will assign this bug to you for now because you have an idea in comment 24 to reduce the intermittent.

Assignee: nobody → tom
Flags: needinfo?(tihuang)

I am leaving the 100ms case - hopefully that intermittent rate
is low enough that we can leave it and still test the scenario.

Pushed by tritter@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/bc038853ad36 Disable test scenarios that cause too many intermittents r=timhuang
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → FIXED
Target Milestone: --- → 115 Branch

Reopened this because the debug failures are still present, as specified in comment 24 and as encountered here.

Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Target Milestone: 115 Branch → ---
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: