1899786 - Synchronous XMLHttpRequest prevents XML documents from being parsed/loaded when OMT decompression is enabled

Status: VERIFIED FIXED

(Core :: Networking, defect, P2)

Description

[Matthew Kogan]

User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:126.0) Gecko/20100101 Firefox/126.0

Steps to reproduce:

Install RSSPreview (https://addons.mozilla.org/en-US/firefox/addon/rsspreview/) and NoScript (https://addons.mozilla.org/en-US/firefox/addon/noscript/) in Firefox 126.0 or newer, open an RSS feed (e.g. https://feeds.bbci.co.uk/news/world/rss.xml), hit Reload.

Actual results:

Either none of or only the first few of the articles are visible.

Expected results:

All of the articles should be visible.

This worked fine until updating to Firefox 126.0.
I've also reported it to the extension developers:
https://github.com/aureliendavid/rsspreview/issues/85
https://github.com/hackademix/noscript/issues/356

Comment 1

[BugBot [:suhaib / :marco/ :calixte]]

The Bugbug bot thinks this bug should belong to the 'WebExtensions::Untriaged' component, and is moving the bug to that component. Please correct in case you think the bot is wrong.

Comment 2

[Rob Wu [:robwu]]

Could you run mozregression to see if this is really caused by a change in Firefox, and not merely a coincidence?

https://mozilla.github.io/mozregression/

Comment 3

[Alex Cornestean]

Hello,

I reproduced the issue on the latest Nightly (128.0a1/20240603160728), Beta (127.0/20240603152359) and Release (126.0.1/20240526221752) under Windows 10 x64 and Ubuntu 22.04 LTS.

The issue occurs as described in Comment 0.

Mozregression results:

2024-06-04T09:31:41.184000: DEBUG : Found commit message:
Bug 1356686: Put OMT decompression behind a pref r=necko-reviewers,valentin

Differential Revision: https://phabricator.services.mozilla.com/D204957

Pushlog: https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=a87db3b698e19b65bc001936fc7a8b80239a25dd&tochange=f5ac2d368c7d44f585bea0397dedcd879e2b8ab4

Comment 4

[BugBot [:suhaib / :marco/ :calixte]]

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

Comment 5

[BugBot [:suhaib / :marco/ :calixte]]

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

Comment 6

[Liz Henry (:lizzard)]

jesup or valentin, since you worked on the regressing bug, can you add any information or suggest an owner for this? Thanks!

Comment 7

[Randell Jesup [:jesup] (needinfo me)]

OMT decompression can change the order of events and timing. Since data being received is not processed on MT, other data can jump 'ahead' of it in the MT event queues, other incoming data that arrives after the compressed data my get processed first, etc.

A profile or an rr/pernosco trace may help in tracking this down, but likely it's a problem in the extension. Happy to answer questions and provide debugging hints

Comment 8

[Matthew Kogan]

Here's a profile from the latest Nightly build: https://share.firefox.dev/4bV20SZ
I used the "Networking" settings - hope that was the right thing to do.

Comment 9

[Donal Meehan [:dmeehan]]

Could you take a look at the profile from Comment 8
Does it point to anything that can be fixed in time for Fx129?

Comment 10

[Randell Jesup [:jesup] (needinfo me)]

A profile really doesn't tell me too much. What I would need is logs (via about:logging) with OMT decompression off, and with it on, loading the same page. I could at least look at what's different; however I'm not sure it's going to tell me much, as having decompression be asynchronous is totally valid from a web standards point of view. It can change the ordering of events; it could change the chunking size of data being delivered, etc, but none of that should matter to the web. Extensions are another matter; perhaps they could have a bug where they care. And in this case, it only fails if you combine those two specific extensions apparently; they work on their own.

Comment 11

[Matthew Kogan]

Attachment: omt_on.zip

Comment 12

[Matthew Kogan]

Attachment: omt_off.zip

Comment 13

[Matthew Kogan]

Logs attached as requested.

Comment 14

[Rob Wu [:robwu]]

I'll take a look to see if there is an issue specific to extensions.

Comment 15

[Rob Wu [:robwu]]

RSSPreview is not causing the issue, but just helpful in visualizing the impact.

The problem is caused by NoScript - it sends a sync XHR request (that it will handle) very early (at document-element-inserted), while the document is still parsing/loading. With OMT, it seems that the remainder of the document gets lost.

I can reproduce the issue without any extensions at all, and I will attach a test case shortly.

Comment 16

[Rob Wu [:robwu]]

Attachment: sync-xhr-at-document-start-web-only.zip

STR:

1. Download the zip file, and extract it. It contains server.mjs and data.xml.
   • server.mjs is a server that serves data.xml (with and without gzip compression), and also offers an API endpoint ("respondslow") that responds to network requests with a 2 second delay.
   • data.xml is a copy of https://feeds.bbci.co.uk/news/world/rss.xml, with a <script> at the start that sends a sync XHR to "respondslow".
2. Start the server, node server.mjs
3. Visit http://localhost:8080/data.xml?raw to see how it should look like.
4. Visit http://localhost:8080/data.xml

Expected:

• Step 3: There is a 2 second delay (from the sync XHR) and then a bunch of text is shown.
• Step 4: same as step 3.

Actual:

• Step 3: as expected.
• Step 4: 2 second delay as expected, but then the document is blank.

Comment 17

[Rob Wu [:robwu]]

Here is a profile captured with the STR: https://share.firefox.dev/45NoeEg

"localhost (1/2)" is the data.xml?raw request for reference (without compression).

"localhost (2/2)" is the data.xml request (the one with gzip that triggers the bug with OMT enabled)

Comment 18

[Rob Wu [:robwu]]

Adjusting title to make it more specific now that I have reduced the issue.

jesup - could you take a look? See comments 15, 16 17.

Comment 19

[Matthew Kogan]

I had worked around this by setting network.decompression_off_mainthread to false in about:config, but since upgrading to Firefox 128.0 it isn't working again even with that setting. Is there another workaround now?

Comment 20

[Rob Wu [:robwu]]

(In reply to Matthew Kogan from comment #19)

I had worked around this by setting network.decompression_off_mainthread to false in about:config, but since upgrading to Firefox 128.0 it isn't working again even with that setting. Is there another workaround now?

The pref was renamed in bug 1899112, to network.decompression_off_mainthread2

Comment 21

[Matthew Kogan]

Thanks very much, that has done the trick again.

Comment 22

[Randell Jesup [:jesup] (needinfo me)]

Looking at this (was on PTO)

Comment 23

[Giorgio Maone [:ma1]]

Please consider uplifting to esr128, since it affects the Tor Browser 14.x out of the box.

In the meanwhile I'm flipping the network.decompression_off_mainthread2 preference to false in alpha2, which we're going to release next week.

Comment 24

[Rob Wu [:robwu]]

FYI Giorgio is the author of NoScript (the add-on in the initial bug report) and became aware of this issue through another occurrence of this bug at https://github.com/hackademix/noscript/issues/372

Comment 25

[Giorgio Maone [:ma1]]

Added a work-around in NoScript 11.4.34rc2, but it's just another hack which might have side effects of its own, so still hoping for a real fix, thank you.

Comment 26

[Giorgio Maone [:ma1]]

NoScript 11.4.34 is out: it works around this problem for stable NoScript users and Tor Browser Alpha users.

Comment 27

[Valentin Gosu [:valentin]]

Randell, could you take another look?

Comment 28

[Randell Jesup [:jesup] (needinfo me)]

Looking at this again. The data is being decompressed properly; it's being handed off (on MainThread) to the parser. Looking to see what else could be going on. OMT decompression does allow other things to run on MT while we're waiting; perhaps that's exposing an unchecked ordering assumption elsewhere

Comment 29

[Randell Jesup [:jesup] (needinfo me)]

Verified this only affects XML documents. The "respondslow" bit isn't needed to reproduce.

Comment 30

[Randell Jesup [:jesup] (needinfo me)]

The issue is this script in the XML:

        try {
            let x = new XMLHttpRequest();
            x.open("GET", url.href, false);
            x.send();
            console.assert(x.responseText === "slow_from_server");
        } catch (e) {
            console.error(e);
        }

without that, it works.
The comment shortly before that says:
// Force different domain to try to make sure that we get a new socket (cross-origin request).

Comment 31

[Randell Jesup [:jesup] (needinfo me)]

Replacing the XHR with alert("foo") also causes the problem - i.e. the problem is spinning the event loop. Devtools shows the <rss> and <script> in both OMT and non-OMT; it shows <content> with the text in it for non-OMT

Comment 32

[Randell Jesup [:jesup] (needinfo me)]

Note that at least in Debug builds for me it's not 100% fail; my latest tests have shown about 25-50% success with OMT on, using the alert() version. Pretty sure I saw a few successes with XHR as well. Speaks to it being a timing issue between OnDataAvailable and something else

Comment 33

[Randell Jesup [:jesup] (needinfo me)]

Ok, what's happening is that in parsing the XML, we run the <script> in it, within nsParser::ResumeParse(). If the script does an XHR or calls alert(), etc, it can spin the event loop. If the OnStopRequest is already in the event queue, it can run. nsParser::OnStopRequest checks to see if it's executing script (or is in OnDataAvailable()->ResumeParse()), and if so doesn't call ResumeParse() with a flag to say it's the last one. Presumably that's why this is failing.
Before OMT Decompression, the decompression OnDataAvailable would synchronously call nsParser. Because of how the ChannelEventQueue used for enqueuing OnFoo events, when ODA is initially called the OnStopRequest can't be on the thread's Event queue yet. With OMT, ODA is async as far as consumers are concerned, and since ODA queued the MT event to call consumer's ODA's, the ChannelEventQueue would allow OnStop to be enqueued to the MT event queue. Now if the event queue is spun during MT ODA, it will see the OnStopRequest and run it (and cause this problem)

Comment 34

[Randell Jesup [:jesup] (needinfo me)]

Attachment: Bug 1899786: make nsParser handle event loop spinning causing OnStopRequest to run r=smaug!

ChannelEventQueue guarantees ordering of OnFoo events, but doesn't make
assertions about if they can be on the event queue or not when other
OnFoo's are running. nsParser spins the EventQueue from script, and so
can run OnStopRequest from within OnDataAvailable.

Comment 36

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/c502d2025998
make nsParser handle event loop spinning causing OnStopRequest to run r=smaug

Comment 37

[Serban Stanca [:SerbanS]]

https://hg.mozilla.org/mozilla-central/rev/c502d2025998

Comment 38

[Alex Cornestean]

Verified as Fixed. Tested on the latest Nightly (136.0a1/20250127092648) and Release (134.0.2/20250120135430) for comparison, on Windows 10 and Ubuntu 24.04 LTS.
I used NoScript v11.4.29 to correspond to the version that was available when the bug was reported, which does not include the workaround mentioned in Comment 25.

All articles from https://feeds.bbci.co.uk/news/world/rss.xml are visible when reloading the page, confirming the fix.

Comment 39

[Henri Sivonen (:hsivonen)]

Why was it necessary to add a new flag and defer setting eOnStop instead of relying on eOnStop? The pre-existing continuation code seems to assume that eOnStop can be reached before all the buffered data has been parsed.

Comment 40

[Randell Jesup [:jesup] (needinfo me)]

I suspect I didn't realize that about eOnStop; it wasn't obvious to me and I didn't want to take any chances given I wasn't an expert on that code. We could simplify if you're sure it's ok to set eOnStop earlier instead. Sorry I didn't r? to you; in retrospect I should have - I can't remember why I didn't

Comment 41

[Matthew Kogan]

This bug is back in Firefox 137.0, and even setting network.decompression_off_mainthread2 to false doesn't fix it for me.

Comment 42

[Rob Wu [:robwu]]

(In reply to Matthew Kogan from comment #41)

This bug is back in Firefox 137.0, and even setting network.decompression_off_mainthread2 to false doesn't fix it for me.

Please create a new bug report. If the STR are identical to this bug report, feel free to just point to this report.

It would help us a lot in the diagnosis of the issue if you run mozregression to identify the commit responsible for the regression. For more information on mozregression, see https://mozilla.github.io/mozregression/

Comment 43

[Matthew Kogan]

Sorry, it was my mistake - the RSS feed itself seems to have been discontinued or broken.

Comment 44

[Henri Sivonen (:hsivonen)]

(In reply to Randell Jesup [:jesup] (needinfo me) from comment #40)

I suspect I didn't realize that about eOnStop; it wasn't obvious to me and I didn't want to take any chances given I wasn't an expert on that code. We could simplify if you're sure it's ok to set eOnStop earlier instead. Sorry I didn't r? to you; in retrospect I should have - I can't remember why I didn't

Thanks. Filed bug 1957899.