Closed Bug 1588916 Opened 6 years ago Closed 6 years ago

Users reporting pages no longer loading after Firefox 71 update with ublock origin /FPI

Categories

(Core :: Security, defect, P1)

71 Branch
defect

Tracking

()

RESOLVED WORKSFORME
Tracking Status
firefox-esr68 --- fixed
firefox69 --- unaffected
firefox70 --- unaffected
firefox71 + fixed
firefox72 --- fixed

People

(Reporter: philipp, Assigned: johannh)

References

(Regression)

Details

(Keywords: regression)

[Tracking Requested - why for this release]:
there are a numerous user reports on reddit saying that pages are no longer loading starting after an update to firefox 71 when ublock origin is installed (and apparently privacy.firstparty.isolate enabled):
https://old.reddit.com/r/firefox/comments/dib0fn/firefox_developer_edition_updated_to_version/
https://old.reddit.com/r/firefox/comments/ddls4g/weekly_nightly_discussion_for_20191005_20191011/f2uz8d7/
https://old.reddit.com/r/firefox/comments/ddls4g/weekly_nightly_discussion_for_20191005_20191011/f30dnzv/

i was affected myself last week but didn't think much of it at first as removing and reinstalling ublock origin fixed the issue (i had the assumption it might be due to a botched filterlist update originally).

restoring an older profile state and running mozregression led me to https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=9e28f08d69e558d1b76ae3fa8c24691e8e17ab49&tochange=a94015c87faad8fbee0b5d9af24dab4526caafd5 and bug 1554805 as the regressing change.

the symptoms are that the tab loading indicator is endlessly bouncing left/right but tabs stay blank - internal about: pages are loading successfully though. the browser console shows the following entry a couple of times which i assume might be related:

NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIInterfaceRequestor.getInterface] network-response-listener.js:84

Hmmm are you sure this is bug 1554805?

https://www.reddit.com/r/uBlockOrigin/comments/d4zlfi/ublock_on_firefox_preventing_pages_from_loading/ seems to indicate that this is a more general issue with uBlock Origin. Anecdotally I also fell victim to this bug but was unable to reproduce in any way after a restart, so I had to ignore it. That profile was on Firefox 70 and definitely without privacy.firstparty.isolate enabled.

Using your old profile, are you able to reliably reproduce? If so, would it be possible for you to share that profile with me?

I'm happy to help here but I'd like to wait for a bit more evidence before settling on bug 1554805 as the definitive cause.

Thank you for reporting this!

Component: Untriaged → General
Flags: needinfo?(madperson)

i'm fairly certain about the regression range since the pushlog where mozregression ended up on left little leeway and the timing where this hit me (and the others discussing in the reddit nightly thread) would also fit.

i've sent you a reduced snapshot of my profile via PM on slack, which should hopefully make it possible to reproduce and better debug the issue.

Flags: needinfo?(madperson)

Thanks! I'll take a look. My initial suspicion based on this information is that this happens when storage for the uBlock is corrupted in some way, which might have been caused by my change. It would also explain why this has happened before.

FWIW privacy.firstparty.isolate is not an officially supported configuration for Firefox. It's okay to track this for the sake of supporting Tor browser etc., I just want to make sure to manage expectations about the priority and urgency here.

Assignee: nobody → jhofmann
Status: NEW → ASSIGNED
Priority: -- → P1
Component: General → Security
Product: Firefox → Core

Though not using ublock origin none of the other WXs' storage DB exhibited any issue with their respective local storage DB, which would be likely if being a global/general issue.

none of the other WXs' storage DB exhibited any issue with their respective local storage DB

In case this matters, beside using browser.storage.local uBO also uses a separate indexedDB as a cache to store large chunks of data (filter lists etc.)

FWIW privacy.firstparty.isolate is not an officially supported configuration for Firefox. It's okay to track this for the sake of supporting Tor browser etc., I just want to make sure to manage expectations about the priority and urgency here.

It is very easy to enable via https://addons.mozilla.org/firefox/addon/first-party-isolation/ (this is how I enable it, in fact), so I think that in some sense the cat is out of the bag for support. It also isn't great that this used to work and has since gotten worse.

Untracking for 71 as TOR is following ESR (68) and this is not currently a default supported configuration for Firefox so not a show-stopper for the December release (I would of course evaluate a safe uplift to 71 if a patch materializes in the beta cycle)

setting esr to affected as well, since bug 1554805 got uplifted for 68.3.0esr.

it's unclear how many users would be affected by the combination of factors that trigger the problem, but once you are hit it feels quite severe. i'd suspect it could hit a couple of thousand users on release, as FPI is mentioned in a number of privacy guides and pre-configurations and privacy-minded users are quite likely using an adblocker as well.

Bug 1554805 has been backed out from ESR68 to avoid breaking Tor browser when 68.3 ships. We'll revisit that bug during the next cycle.

I am setting the flag for 71 back to affected because we don't have telemetry on the privacy.firstparty.isolate pref so we don't know how many people may use it in conjunction with uBllock Origin, that seems enough of an unknown to warrant an investigation given that uBO is a very popular extension.

if anyone wants to look into this while johann is out, i still have a zipped profile which is reproducing the problem around and would be happy to share it (ping me).

(In reply to [:philipp] from comment #11)

if anyone wants to look into this while johann is out, i still have a zipped profile which is reproducing the problem around and would be happy to share it (ping me).

I am interested in trying to reproduce the issue on my side to find out where exactly in uBO's code the failure is triggered.

(In reply to rhill@raymondhill.net from comment #12)

(In reply to [:philipp] from comment #11)

if anyone wants to look into this while johann is out, i still have a zipped profile which is reproducing the problem around and would be happy to share it (ping me).

I am interested in trying to reproduce the issue on my side to find out where exactly in uBO's code the failure is triggered.

i've reached out to your bugmail address

I'm mostly out right now, but I took another look at this to move things forward. Here are my (incomplete and potentially erroneous) results from looking at the profile Philipp provided:

From what I can tell is happening, when pages are stalled, uBlock doesn't have a suspendableListener to call and just keeps on suspending requests. So this call doesn't seem to be able to run. Why not? When uBlock is enabled or on startup, we can see complete stalling of the WebExtension process due to this stack running seemingly forever, which is definitely very suspicious and seems like it could be the cause of this. When this stack isn't running hot, the issue is not present. So they seem to be correlated, at the very least.

I've found two ways to prevent this from happening:

  • Intermittently by enabling and disabling uBlock a seemingly random amount of times. I don't really know what exactly makes uBO decide not to run the affected code, but apparently this triggers it.
  • Upgrading to 1.23.0, which completely fixes the issue.

The fact that this code probably shouldn't run so hot hints at some data mismatch causing wrong assumptions, maybe leading to an infinite loop, so this may be caused by my principal changes. However, the main issue (infinitely suspending loads and overheating) is not caused directly by Firefox and feels like it should be handled on uBO side by having more robust handling for storage issues. So, based on the information currently available, I would consider this bug a WONTFIX on Firefox side.

I've tried to reproduce this several times with 1.23 and was never successful, so I somewhat suspect that 1.23 might have just inadvertently fixed this issue.

Raymond, does the above description ring any bell with you? I'm not an expert on uBO internals, so it would be good to get a better idea on what that function stack is doing and why it might be stalling everything else. Also, how it could be related to storage issues (i.e. when storage mismatches, could this enter an infinite loop somehow)? Could 1.23 have fixed this?

Philipp, do we have any indication that this could be fixed permanently with uBO 1.23?

Flags: needinfo?(rhill)
Flags: needinfo?(madperson)

(In reply to [:philipp] from comment #13)

i've reached out to your bugmail address

Thanks, this has been very helpful in identifying the issue.

(In reply to Johann Hofmann [:johannh] - Away until Dec 3rd from comment #14)

Raymond, does the above description ring any bell with you? I'm not an expert on uBO internals, so it would be good to get a better idea on what that function stack is doing and why it might be stalling everything else. Also, how it could be related to storage issues (i.e. when storage mismatches, could this enter an infinite loop somehow)? Could 1.23 have fixed this?

TL;DR: I didn't expect uBO to end up using obsolete IndexedDB storage as each time uBO launches it detects and deletes obsolete data and then re-create it. The problem is that uBO has been switched to a different IndexedDB storage and for some reasons it came back to the original one which had not been made obsolete (because it was no longer used/visible to uBO in the meantime) and ended up using bad, obsolete data from it.


I could narrow down the issue to the fact that uBO 1.22.4 in the problematic profile was using filter lists which were compiled with uBO 1.19.0 while it thought the lists were compiled with a later version. This caused the code to execute with unexpected arguments passed to µBlock.BidiTrieContainer.add() -- where your profile results show it's where uBO spend all its time.

uBO pre-parses filter lists when they are loaded and save a "compiled" counterpart in its IndexedDB storage so that next time they are loaded without having to parse them -- parsing is the most expensive part when loading filter lists such as EasyList et al. However from time to time as I improve uBO's filtering engine, it happens regularly that the compiled format changes and in such case uBO will re-compile all filter lists and save the new resulting output to its indexedDB storage.

So I had to understand how come uBO was using obsolete compiled lists, as these should have been overwritten when it detected the format changed. So my understanding is this, chronologically:

  • uBO compiled filter lists for 1.19.0 (or before) and saved the results in its IndexedDB storage, named
    moz-extension+++ff3e360b-8c7c-4cb9-a839-caac8baa3a85.
  • User toggled on privacy.firstparty.isolate, which caused uBO to create a new IndexedDB storage for cache purpose, named
    moz-extension+++ff3e360b-8c7c-4cb9-a839-caac8baa3a85^firstPartyDomain=ff3e360b-8c7c-4cb9-a839-caac8baa3a85.
  • All is good so far.
  • However at some point, it seems Firefox went back to use the former IndexedDB, moz-extension+++ff3e360b-8c7c-4cb9-a839-caac8baa3a85, which is now populated with obsolete compiled data.
  • uBO now many versions past 1.19.0, thinks the compiled data is all good and tries to load it.

This caused bad data to be loaded in uBO and unexpected conditions to occur as a result. For instance, uBO was trying to load the filter "0", with a token at offset 1 -- this makes no sense whatsoever, and as a result the trie code was spinning forever.

Regardless of whether the IndexedDB swap can happen again in the future, I will think of something to prevent uBO from suffering this sort of issue in the future. I suspect this occurred as the development of privacy.firstparty.isolate was going along and is unlikely to occur again but given the severity of the issue for uBO, it's best to add better check for obsolete cached filter list data in uBO.

Flags: needinfo?(rhill)

(In reply to Johann Hofmann [:johannh] - Away until Dec 3rd from comment #14)

I've tried to reproduce this several times with 1.23 and was never successful, so I somewhat suspect that 1.23 might have just inadvertently fixed this issue.

I forgot to mention that the issue could not be reproduced in 1.23.0 because there was a format change between 1.22.4 and 1.23.0 and this caused the obsolete cache data to be destroyed at launch.

(In reply to Johann Hofmann [:johannh] - Away until Dec 3rd from comment #1)

Hmmm are you sure this is bug 1554805?

I can confirm the issue here was triggered by the fix to bug 1554805 -- if I understand correctly, extensions' own IndexedDB were no longer suffixed with ^firstPartyDomain= once bug 1554805 was fixed, hence causing uBO to fall back to the IndexedDB which by then contained obsolete data.

Flags: needinfo?(madperson)

Raymond, do I understand correctly from your last messages that users of 1.23.0 should not experience this bug? It's not clear to me what population is affected at the moment and if for exemple just uninstalling/reinstalling uBO would solve the data issue for people affected (if this is the case, we could add a release notes in the "known" issues section). Is there something you think should be fixed on the Firefox side for our upcoming releases? (71&72)
Thanks

Flags: needinfo?(rhill)

users of 1.23.0 should not experience this bug?

It depends, the issue occurs for users who migrate from a ("bad") version of Firefox which uses the suffix ^firstPartyDomain= in the IndexedDB storage name to a ("good") version which does not use the suffix ^firstPartyDomain= in the IndexedDB storage name. The issue could also occur I suppose by merely toggling privacy.firstparty.isolate setting which could cause uBO to end up using an obsolete IndexedDB storage.

For those who have made this sort of transition while using uBO, the issue will resolve itself if they also update to a uBO version for which there was a cached data format change, which is the case in uBO 1.23.0. I don't know how likely someone could migrate from "bad" Firefox version to "good" Firefox version while already using uBO 1.23.0 prior to the transition, in which case a reinstall of uBO will be necessary.

There was a flurry of "uBO stalls at launch" cases about a month ago at Reddit[1], and many were cases of users migrating from Firefox 70 to Firefox 71.0bx (or vice versa even maybe) -- so I do believe these were related to the issue described here.

Currently I added code for the next uBO release to ensure such unexpected IndexedDB storage change won't cause such issue. I will probably submit this version for publication on AMO today.


[1] https://www.reddit.com/r/uBlockOrigin/comments/d4zlfi/ublock_on_firefox_preventing_pages_from_loading/

Flags: needinfo?(rhill)

uBO 1.24.0 was released with a fix/workaround for this problem, so it should no longer be a concern for firefox 71.
thanks for that!

Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Resolution: --- → WORKSFORME
Has Regression Range: --- → yes
You need to log in before you can comment on or make changes to this bug.