Closed Bug 1558420 Opened 5 years ago Closed 5 years ago

Intermittent toolkit/components/antitracking/test/browser/browser_partitionedLocalStorage_events.js | The value is received - "tracker-0.10254258463579913" == "tracker-0.5449241136995779" -

Categories

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

Product:
Core
Component:
DOM: Security
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla72
Tracking Flags:
Tracking Status
firefox-esr68 --- unaffected
firefox70 --- wontfix
firefox71 --- wontfix
firefox72 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: ehsan.akhgari)

References

(Blocks 1 open bug, Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [test isolation][domsecurity-intermittent][stockwell unknown])

Attachments

(5 files)

Bug 1558420 - Part 1: Add an API for creating a sessionstorage manager and a cache object;
47 bytes, text/x-phabricator-request
Details | Review
Bug 1558420 - Part 2: Fix the logic for switching the localStorage object from partitioned to non-partitioned and vice-versa;
47 bytes, text/x-phabricator-request
Details | Review
Bug 1558420 - Part 3: Fix the incorrect usage of closures in browser_partitionedLocalStorage_events.js and update the test expectations;
47 bytes, text/x-phabricator-request
Details | Review
Bug 1558420 - Part 4: Do not report anti-tracking notifications when blocking storage access for sandboxed documents;
47 bytes, text/x-phabricator-request
Details | Review
Bug 1558420 - Part 5: Remove an invalid assertion;
47 bytes, text/x-phabricator-request
Details | Review

Filed by: nbeleuzu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=251104295&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/XAg5htLgSkamifzoJAbYsg/runs/0/artifacts/public/logs/live_backing.log

[task 2019-06-11T07:32:31.907Z] 07:32:31 INFO - TEST-PASS | toolkit/components/antitracking/test/browser/browser_partitionedLocalStorage_events.js | One event - 1 == 1 -
[task 2019-06-11T07:32:31.908Z] 07:32:31 INFO - Leaving test bound
[task 2019-06-11T07:32:31.908Z] 07:32:31 INFO - Entering test bound
[task 2019-06-11T07:32:31.910Z] 07:32:31 INFO - Running test with storage principal enabled with the new localStorage backend and prefValue: 4 (Test #4)
[task 2019-06-11T07:32:31.911Z] 07:32:31 INFO - Creating a non-tracker top-level context
[task 2019-06-11T07:32:31.911Z] 07:32:31 INFO - The non-tracker page opens a tracker iframe
[task 2019-06-11T07:32:31.913Z] 07:32:31 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.net/browser/toolkit/components/antitracking/test/browser/page.html" line: 0}]
[task 2019-06-11T07:32:31.913Z] 07:32:31 INFO - Iframe loading...
[task 2019-06-11T07:32:31.914Z] 07:32:31 INFO - Setting localStorage value in ifr...
[task 2019-06-11T07:32:31.914Z] 07:32:31 INFO - Getting the value from ifr...
[task 2019-06-11T07:32:31.916Z] 07:32:31 INFO - TEST-PASS | toolkit/components/antitracking/test/browser/browser_partitionedLocalStorage_events.js | The value is correctly set in ifr - true == true -
[task 2019-06-11T07:32:31.916Z] 07:32:31 INFO - Navigate...
[task 2019-06-11T07:32:31.918Z] 07:32:31 INFO - Console message: [JavaScript Warning: "Request to access cookie or storage on “https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html” was blocked because it came from a tracker and content blocking is enabled." {file: "http://example.net/browser/toolkit/components/antitracking/test/browser/page.html" line: 26 column: 0 source: "https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html"}]
[task 2019-06-11T07:32:31.919Z] 07:32:31 INFO - Console message: [JavaScript Warning: "Request to access cookie or storage on “https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html” was blocked because it came from a tracker and content blocking is enabled." {file: "http://example.net/browser/toolkit/components/antitracking/test/browser/page.html" line: 26 column: 0 source: "https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html"}]
[task 2019-06-11T07:32:31.920Z] 07:32:31 INFO - Console message: [JavaScript Warning: "Request to access cookie or storage on “https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html” was blocked because it came from a tracker and content blocking is enabled." {file: "http://example.net/browser/toolkit/components/antitracking/test/browser/page.html" line: 12 column: 4 source: "https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html"}]
[task 2019-06-11T07:32:31.925Z] 07:32:31 INFO - Console message: [JavaScript Warning: "Request to access cookie or storage on “https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html” was blocked because it came from a tracker and content blocking is enabled." {file: "http://example.net/browser/toolkit/components/antitracking/test/browser/page.html" line: 7 column: 4 source: "https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html"}]
[task 2019-06-11T07:32:31.928Z] 07:32:31 INFO - Console message: [JavaScript Warning: "Request to access cookie or storage on “https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html” was blocked because it came from a tracker and content blocking is enabled." {file: "http://example.net/browser/toolkit/components/antitracking/test/browser/page.html" line: 0}]
[task 2019-06-11T07:32:31.929Z] 07:32:31 INFO - Getting the value from ifr...
[task 2019-06-11T07:32:31.929Z] 07:32:31 INFO - Buffered messages finished
[task 2019-06-11T07:32:31.930Z] 07:32:31 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/antitracking/test/browser/browser_partitionedLocalStorage_events.js | The value is received - "tracker-0.10254258463579913" == "tracker-0.5449241136995779" -
[task 2019-06-11T07:32:31.930Z] 07:32:31 INFO - Stack trace:
[task 2019-06-11T07:32:31.932Z] 07:32:31 INFO - resource://testing-common/content-task.js line 59 > eval:null:42
[task 2019-06-11T07:32:31.935Z] 07:32:31 INFO - Leaving test bound
[task 2019-06-11T07:32:31.936Z] 07:32:31 INFO - Entering test bound
[task 2019-06-11T07:32:31.944Z] 07:32:31 INFO - Running test with storage principal enabled with the new localStorage backend and prefValue: 4 (Test #5)
[task 2019-06-11T07:32:31.944Z] 07:32:31 INFO - Console message: [JavaScript Warning: "Request to access cookie or storage on “https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html?0.9917463869583917” was blocked because it came from a tracker and content blocking is enabled." {file: "http://example.net/browser/toolkit/components/antitracking/test/browser/page.html" line: 26 column: 0 source: "https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html?0.9917463869583917"}]
[task 2019-06-11T07:32:31.945Z] 07:32:31 INFO - Console message: [JavaScript Warning: "Request to access cookie or storage on “https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html?0.9917463869583917” was blocked because it came from a tracker and content blocking is enabled." {file: "http://example.net/browser/toolkit/components/antitracking/test/browser/page.html" line: 26 column: 0 source: "https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html?0.9917463869583917"}]
[task 2019-06-11T07:32:31.955Z] 07:32:31 INFO - Console message: [JavaScript Warning: "Request to access cookie or storage on “https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html?0.9917463869583917” was blocked because it came from a tracker and content blocking is enabled." {file: "http://example.net/browser/toolkit/components/antitracking/test/browser/page.html" line: 7 column: 4 source: "https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/localStorageEvents.html?0.9917463869583917"}]
[task 2019-06-11T07:32:31.956Z] 07:32:31 INFO - Creating a non-tracker top-level context
[task 2019-06-11T07:32:31.956Z] 07:32:31 INFO - The non-tracker page opens a tracker iframe
[task 2019-06-11T07:32:31.964Z] 07:32:31 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.net/browser/toolkit/components/antitracking/test/browser/page.html" line: 0}]
[task 2019-06-11T07:32:31.965Z] 07:32:31 INFO - Iframe loading...
[task 2019-06-11T07:32:31.965Z] 07:32:31 INFO - Setting localStorage value in ifr...
[task 2019-06-11T07:32:31.966Z] 07:32:31 INFO - Getting the value from ifr...
[task 2019-06-11T07:32:31.967Z] 07:32:31 INFO - TEST-PASS | toolkit/components/antitracking/test/browser/browser_partitionedLocalStorage_events.js | The value is correctly set in ifr - true == true -

Performed test isolation run with 100 iterations. Did not reproduce the original failure.

Full run bc7

  • 3x Bug 1556172 - Intermittent browser/base/content/test/about/browser_aboutCertError.js | Correct error message found - Got , expected SEC_ERROR_EXPIRED_CERTIFICATE
  • 4x Bug 1503084 - Intermittent accessible/tests/browser/e10s/browser_caching_name.js | <random text> - Got name from (alt|value), expected test4
  • 1x Bug 1321388 - Intermittent browser/components/extensions/test/browser/browser_ext_windows_allowScriptsToClose.js | Test timed out
    TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_windows_allowScriptsToClose.js | Test timed out -
    TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_windows_allowScriptsToClose.js | Extension left running at test shutdown -
    TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_windows_allowScriptsToClose.js | Found a browser window after previous test timed out -
    TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_windows_allowScriptsToClose.js | Uncaught exception received from previously timed out test - at chrome://mochitests/content/browser/browser/components/extensions/test/browser/browser_ext_windows_allowScriptsToClose.js:62 - ReferenceError: info is not defined

Directory test bc7-id

no failures

Individual test bc7-it

  • 1x Bug 1553983 Intermittent PROCESS-CRASH | Main app process exited normally | application crashed [@ js::ContextChecks::check(JSObject *,int)]
Whiteboard: [stockwell isolation]
Whiteboard: [stockwell isolation] → [stockwell isolation][domsecurity-intermittent]
Whiteboard: [stockwell isolation][domsecurity-intermittent] → [test isolation][domsecurity-intermittent]
Whiteboard: [test isolation][domsecurity-intermittent] → [test isolation-][domsecurity-intermittent]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

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

Recent log failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=261817802&repo=autoland&lineNumber=41649

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

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: REOPENED → RESOLVED
Closed: 5 years ago → 5 years ago
Resolution: --- → INCOMPLETE
Whiteboard: [test isolation-][domsecurity-intermittent] → [test isolation][domsecurity-intermittent]

New occurrence: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=272530327&repo=autoland&lineNumber=71691

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

The 2 things are unrelated. I just changed how the worker is executed in the test, no platform code has been touched in bug 1590075.

Flags: needinfo?(amarchesini)

Kashav can it be from bug 1578465?

Flags: needinfo?(kmadan)

Ehsan do you have the time to take a look at this? there are several similar bugs https://bugzilla.mozilla.org/buglist.cgi?quicksearch=browser_partitioned&list_id=14962262

Flags: needinfo?(ehsan)
Whiteboard: [test isolation][domsecurity-intermittent] → [test isolation][domsecurity-intermittent][stockwell needswork:owner]

(In reply to Andreea Pavel [:apavel] from comment #11)

Kashav can it be from bug 1578465?

Probably not, bug 1578465 was backed out on the 24th, but we're still seeing these.

Flags: needinfo?(kmadan)

I think this is a regression from bug 1556082. I believe this condition is incorrect...

Regressed by: 1556082
Blocks: 1559635

Andrea please take a look.

Flags: needinfo?(ehsan) → needinfo?(amarchesini)

(In reply to Andreea Pavel [:apavel] from comment #16)

Andrea please take a look.

Sorry if I wasn't clear, I was looking at this, this bug just happened to open the Pandora's box and I found several problems after comment 15, but I finally have fixes for all of them.

The first issue was what I noted in comment 15. That bug would cause the partitioned local storage object to sometimes get replaced with a normal local storage object.

After fixing that, I noticed that browser_partitionedLocalStorage_events.js and browser_partitionedLocalStorage.js both started to show a lot of test failures. Basically any test that was checking whether local storage was being partitioned based on the origin of the top-level window was broken. It turns out that the PartitionedLocalStorage class that was initially added for the privacy.restrict3rdpartystorage.partitionedHosts pref doesn't actually partition storage, but rather it isolates it. This was the intention for that pref, but not the intention for storage partitioning where we actually want a partitioned storage space, so I had to fix that next.

After that I saw that browser_partitionedLocalStorage_events.js still doesn't fully pass. After some investigation I realized it has a subtle bug where we capture variables from the runAllTests() closure, which means we'd be reading the value of the variable as it was the last time the function was called, which wasn't the intention... So I then fixed the test and its expectations to match reality in the end.

Flags: needinfo?(amarchesini)

Oh, one last wrinkle I forgot to mention.

This GetStorage call in nsWindowWatcher::OpenWindowInternal when running browser_storageAccessPromiseRejectHandlerUserInteraction.js ends up lazily creating a SessionStorage object, leading to an anti-tracking check. Since that test has a sandbox iframe this leads to us bailing out here and reporting an error notification. The test however expects no error notifications.

It is misleading to report notifications about blocking a tracker because of a sandboxed iframe, so I have a patch to fix that as well.

No longer blocks: 1559635
Blocks: 1585547
Blocks: 1590689
Blocks: 1552056
Blocks: DynamicFirstPartyIsolation

On the try server these patches now hit the same assertions as bug 1533759.

That seems to be a regression from part 3 of bug 1525245. The failing assertion seems to have been added because of this code block. However what wasn't paid attention was that SessionStorage objects can also be created from other call sites (for example window.open(), or C++ callers, and for those callers the anti-tracking check, if it has failed, could have failed for other reasons (for example the case I caught under the debugger was a failure due to STATE_COOKIES_BLOCKED_BY_PERMISSION because of this permission.

I think this assertion is just invalid and should be removed.

Blocks: 1533759
No longer blocks: 1533759

(In reply to :ehsan akhgari from comment #17)

(In reply to Andreea Pavel [:apavel] from comment #16)

Andrea please take a look.

Sorry if I wasn't clear, I was looking at this, this bug just happened to open the Pandora's box and I found several problems after comment 15, but I finally have fixes for all of them.

Oh, sorry. Thank you.

Ehsan, this has 55 total failures in the last 7 days, most of them on windows7-32-shippable opt: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-11-03&endday=2019-11-10&tree=trunk&bug=1558420 Is this still work in progress? Thank you.

Flags: needinfo?(ehsan)
Pushed by eakhgari@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/9517978401ad
Part 1: Add an API for creating a sessionstorage manager and a cache object; r=baku
https://hg.mozilla.org/integration/autoland/rev/fe5c2a0ec2ef
Part 2: Fix the logic for switching the localStorage object from partitioned to non-partitioned and vice-versa; r=baku
https://hg.mozilla.org/integration/autoland/rev/29e8ca52bc04
Part 3: Fix the incorrect usage of closures in browser_partitionedLocalStorage_events.js and update the test expectations; r=baku
https://hg.mozilla.org/integration/autoland/rev/37292e7f1266
Part 4: Do not report anti-tracking notifications when blocking storage access for sandboxed documents; r=baku
https://hg.mozilla.org/integration/autoland/rev/89e2c52c7b28
Part 5: Remove an invalid assertion; r=baku

(In reply to Cosmin Sabou [:CosminS] from comment #30)

Ehsan, this has 55 total failures in the last 7 days, most of them on windows7-32-shippable opt: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-11-03&endday=2019-11-10&tree=trunk&bug=1558420 Is this still work in progress? Thank you.

Sorry, I was out sick...

Flags: needinfo?(ehsan)
Regressions: 1595923
Assignee: nobody → ehsan
No longer blocks: 1585547
No longer blocks: 1552056
No longer blocks: 1590689
Has Regression Range: --- → yes
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: