1623921 - filterResponseData fails after HTTP redirection

Status: RESOLVED FIXED

(WebExtensions :: Request Handling, defect, P1)

Description

[gwarser]

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:76.0) Gecko/20100101 Firefox/76.0

Steps to reproduce:

As by this bug on uBlock Origin tracker: https://github.com/uBlockOrigin/uBlock-issues/issues/942

1. Install latest uBlock Origin
2. Check "I am an advanced user (required reading)" in settings
3. Add this to My rules:

* * 3p block
taz.de * 1p-script block
taz.de * inline-script block

2. Add this to My filters:

taz.de##^.community.full
taz.de##^.rack.article
taz.de##^.sect_description
taz.de##^.shariff
taz.de##^.tail
taz.de##^#footer
taz.de##^#reward:xpath(../..)

3. Visit https://taz.de/!5670441/.
4. Observe the 301 to https://taz.de/Buergermeister-Wahl-in-Stuttgart/!5670441/.
5. Observe that the above rules are applied.
6. Observe that the above filters are not applied.
7. Visit https://taz.de/Buergermeister-Wahl-in-Stuttgart/!5670441/.
8. Observe that the rules are applied.
9. Observe that the filters are applied.

Actual results:

Most noticeable: footer section with comments is not removed when accessing through link shortener.

Expected results:

Footer sections should be removed when accessing page by link shortener or direct link.

Bisected to: https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=ff0b109afd62c3c2dd396463bb3632228e959ff3&tochange=a4c51f3f0bb1dd51ded827d3049d633f56662a7f -> https://bugzilla.mozilla.org/show_bug.cgi?id=1590898

Comment 1

[gwarser]

Simpler to reproduce, but it suffers from bug 1590898: https://bit.ly/2Wqw7Ol (uBO test page for Procedural HTML filters, last two can be red because implemented in dev version)

Add filters from the page to My filters, then access the page using shortener or directly.

Comment 2

[Shane Caraveo (:mixedpuppy)]

Ok, I think there is certainly a problem here. The test addon doesn't create a stream filter for the 301 response. It does create the filter when it gets the 200 response. Tossing in some debug output I see:

***** webRequest observer http-on-examine-response 368 301 https://taz.de/!5670441/
**** onChannelReplaced old channel 368
**** onChannelReplaced new channel 368
***** webRequest observer http-on-examine-response 368 200 https://taz.de/Buergermeister-Wahl-in-Stuttgart/!5670441/
console.log: "onHeadersReceived(): creating stream filter for 368 status 200"
==== StreamFilterParent::OnStartRequest channels differ aRequest(25113070) mChannel(https://taz.de/!5670441/) -> https://taz.de/Buergermeister-Wahl-in-Stuttgart/!5670441/
==== StreamFilterParent(27442400)::OnStartRequest REDIRECT disconnecting https://taz.de/Buergermeister-Wahl-in-Stuttgart/!5670441/
console.error: "onStreamError(368): Channel redirected"

So...it seems that the filter instance is created with the old channel somehow, even though the channel was replaced before the filter was created.

In the test addon, onHeadersReceived listener basically looks like:

        const statusCode = details.statusCode || 0;
        if ( statusCode !== 0 && (statusCode < 200 || statusCode >= 300) ) {
            return;
        }
        const requestId = details.requestId;
        console.log(`onHeadersReceived(): creating stream filter for ${details.requestId} status ${statusCode}`);
        const stream = browser.webRequest.filterResponseData(details.requestId);
        stream.ondata = function(ev) {
            this.write(ev.data);
            // this.disconnect();
            console.error(`onStreamData(${requestId})`);
        };
        stream.onstop = function() {
            this.close();
            console.error(`onStreamStop(${requestId})`);
        };
        stream.onerror = function() {
            console.error(`onStreamError(${requestId}): ${this.error}`);
        };

Comment 3

[Shane Caraveo (:mixedpuppy)]

Ok, one step further:

==== StreamFilterParent::Create got channel 369 [https://taz.de/Buergermeister-Wahl-in-Stuttgart/!5670441/]
+++ DocumentChannelChild::RecvAttachStreamFilter call Attach [https://taz.de/!5670441/]
==== StreamFilterParent::Attach got channel [https://taz.de/!5670441/]

Given a 301 redirect from a->b, the background scripts creates the stream filter ONLY for 'b'. For some reason, DocumentChannelChild ovewrites the channel with an old channel (itself), and then something (presumably nsHttpChannel, but I haven't dug that far) updates back to the correct channel during onStartRequest:

==== StreamFilterParent::OnStartRequest channels differ mChannel(https://taz.de/!5670441/) -> aRequest(https://taz.de/Buergermeister-Wahl-in-Stuttgart/!5670441/)

This causes the logic in StreamFilterParent::OnStartRequest to disconnect the filter as if the filter had been created during the 301.

DocumentChannelChild::RecvAttachStreamFilter was added in bug 1590898, so the regression is correct.

This is a pretty big break in the webrequest api.

Comment 4

[Shane Caraveo (:mixedpuppy)]

Attachment: Bug 1623921 test StreamFilter works with 301 redirect

Comment 5

[Shane Caraveo (:mixedpuppy)]

The attached test currently fails, it should pass.

Comment 6

[Matt Woodrow (:mattwoodrow)]

I think bug 1597159 should fix this! Will try test locally soon.

Comment 7

[Matt Woodrow (:mattwoodrow)]

The test passes for me locally, with the patches from bug 1597159 applied.

Comment 9

[gwarser]

Fixed on 20200409095500

Comment 10

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/09329f8a223b
test StreamFilter works with 301 redirect r=mattwoodrow

Comment 11

[Daniel Varga [:dvarga]]

https://hg.mozilla.org/mozilla-central/rev/09329f8a223b

Comment 12

[uBlock-user]

Starting to reproduce again on washingtonpost.com/science/2020/04/12/storm-inside/?arc404=true, see - https://github.com/uBlockOrigin/uAssets/issues/7224

Comment 13

[uBlock-user]

Status code there is 302 -- moved temporarily

Comment 14

[uBlock-user]

Simplied repro --

• Add the below filters in uBlock Origin in My filters pane -

gorhill.github.io##^#phf #a1 .fail:has(b)
gorhill.github.io##^#phf #a2 .fail:has(> a > b)
gorhill.github.io##^#phf #a3 .fail:not(:has(c))
gorhill.github.io##^#phf #a4 .fail:has-text(needle)
gorhill.github.io##^#phf #a5 .fail:has-text(/NEEDLE/i)
gorhill.github.io##^#phf #a6 .fail:not(:has-text(haystack))
gorhill.github.io##^#phf #a7 .fail > a > b:nth-ancestor(2)
gorhill.github.io##^#phf #a8:xpath(.//b/../..)
gorhill.github.io##^#phf #a9 .fail:min-text-length(300)
gorhill.github.io##^#phf #a10 .pass > a:has(b) + .fail
gorhill.github.io##^#phf #a11 .pass > a:has(b) + .fail:has(b)
gorhill.github.io##^#phf #a12 .fail:has(+ a)
gorhill.github.io##^#phf #a13 .fail:has(~ a:has(b))
gorhill.github.io##^#phf #a14 b:upward(2)
gorhill.github.io##^#phf #a15 b:upward(.fail)

• Browse to https://httpbin.org/redirect-to?url=https%3A%2F%2Fhttpbin.org%2Fredirect-to%3Furl%3Dhttps%253A%252F%252Fgorhill.github.io%252FuBlock%252Ftests%252Fprocedural-html-filters.html%26status_code%3D302&status_code=302 and observe all the tiles under "Tests" are titled "fail" and marked in Red.

Comment 15

[kernp25]

Attachment: firefox_8KT6QwoMJd.png

For me it works as expected in Firefox 77.

Comment 16

[uBlock-user]

Attachment: Capture.PNG

I can reproduce as per the above image, if the link is cached, you may require several tries.

Comment 17

[kernp25]

I reload the page all the time, but it still worked for me.

Can you show the network console output?
https://developer.mozilla.org/en-US/docs/Tools/Network_Monitor

Comment 18

[uBlock-user]

Attachment: Capture2.PNG

I copy paste the aformentioned URL in a new tab when I reproduce.

Comment 19

[kernp25]

This must be this bug: https://bugzilla.mozilla.org/show_bug.cgi?id=1595610

Because, there is no status code for the final url.

Can you test https://bugzilla.mozilla.org/attachment.cgi?id=9139046 (you need to change the url in the add-on ofc)

Can you confirm that it will fire the webRequest.onErrorOccurred event with the NS_ERROR_NET_ON_WAITING_FOR error?

Comment 20

[uBlock-user]

Sorry, I don't think I can.

@mixedpuppy, what do you think ?

Comment 21

[Shane Caraveo (:mixedpuppy)]

I think I'd like a new bug for this issue rather than continuing on a closed bug. Diagnosing a large addon with rules requires a lot of understanding of that addon, preferably a simple addon that illustrates the failure could be made available.