webRequest callbacks not called after 302 redirection

VERIFIED FIXED in Firefox 61

Status

defect
P1
normal
VERIFIED FIXED
Last year
Last year

People

(Reporter: fab, Assigned: mixedpuppy)

Tracking

59 Branch
mozilla61
Dependency tree / graph

Firefox Tracking Flags

(firefox-esr52 unaffected, firefox59 wontfix, firefox60 wontfix, firefox61 verified)

Details

Attachments

(3 attachments)

User Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:59.0) Gecko/20100101 Firefox/59.0
Build ID: 20180316021353

Steps to reproduce:

1) Create a basic WebExtension with the following permission in "manifest.json":
"permissions": [ "webRequest", "<all_urls>" ]
and in the Javascript some basic logging on various webrequest events:

function makeLogger(label) {
    return function (evt) {
        console.log(label + " : " + evt.url + " - " + evt.statusCode)
    }
}

browser.webRequest.onHeadersReceived.addListener(
    makeLogger("Header"),
    {urls: ["<all_urls>"]}
)

browser.webRequest.onResponseStarted.addListener(makeLogger("RespStart"),
{urls: ["<all_urls>"]}
)

browser.webRequest.onCompleted.addListener(makeLogger("RespCompl"),
{urls: ["<all_urls>"]}
)

2) Open a URL that performs a redirection. In my case, if I open "google.com", I get a redirection to an URL starting with https://www.google.co.jp/



Actual results:

The HTTP request for original request (ex: google.com) is logged (with code 302), but the target URL of the redirection (ex: google.co.jp) is not logged at all. The images referenced by the target of the redirection are properly logged.
Note that if the final URL is manually requested, then it is properly logged.


Expected results:

According to the documentation [1], an event should be generated at each stage of the diagram. The "onHeadersReceived" callback should be called for the 302, then again for the target page, then the "onResponseStarted" callback should be invoke, and at last the one for "onCompleted".

[1] https://developer.mozilla.org/en-US/Add-ons/WebExtensions/API/webRequest
Fabimaru, thanks for the report.
I'm not sure what to make from the browser console in regards to expected results while using the reduced testcase, therefore as an initial triage, I'm moving this to Webextensions/Untriaged since I'm equally inclined to have this in /Developer Tools or /General.
Component: Untriaged → WebExtensions: Untriaged
Product: Firefox → Toolkit
A bit more detailed and repeatable scenario, still based on the "Sample minimal extension":
- make sure the extension is installed
- open a blank tab
- open the regular developer tools and their "Network" tab
- open the browser console
- open in the tab this URL: http://fabsk.eu/misc/1448599/redir.php
- then press control-F5

Note: The page "redir.php" only performs a 302 redirection to "text.txt".

Actual result:
- in the Network tab, you can see a HTTP request to "redir.php" getting an 302 response with a redirection to "text.txt", followed by a HTTP request to "text.txt" (200 response)
- in the browser console, the following logs are visible:
  - "Header : http://fabsk.eu/misc/1448599/redir.php - 302" (for the 'onHeadersReceived' listener for the original URL)
  - (some logs for "favicon.ico")
  - "Header : http://fabsk.eu/misc/1448599/text.txt - 200" (for the 'onHeadersReceived' listener for the reload request)
  - "RespStart : http://fabsk.eu/misc/1448599/text.txt - 200" (for the 'onResponseStarted' listener for the reload request)
  - "RespCompl : http://fabsk.eu/misc/1448599/text.txt - 200" (for the 'onCompleted' listener for the reload request)

Expected result:
- in the Network tab, same as "actual result"
- in the browser console, the following sequence should have been displayed:
  - "Header : http://fabsk.eu/misc/1448599/redir.php - 302" (for the 'onHeadersReceived' listener for the original URL)
  - (some logs for "favicon.ico")
  - "Header : http://fabsk.eu/misc/1448599/text.txt - 200" (for the 'onHeadersReceived' listener for the redirected URL)
  - "RespStart : http://fabsk.eu/misc/1448599/text.txt - 200" (for the 'onResponseStarted' listener for the redirected URL)
  - "RespCompl : http://fabsk.eu/misc/1448599/text.txt - 200" (for the 'onCompleted' listener for the redirected URL)
  - "Header : http://fabsk.eu/misc/1448599/text.txt - 200" (for the 'onHeadersReceived' listener for the reload request)
  - "RespStart : http://fabsk.eu/misc/1448599/text.txt - 200" (for the 'onHeadersReceived' listener for the reload request)
  - "RespCompl : http://fabsk.eu/misc/1448599/text.txt - 200" (for the 'onHeadersReceived' listener for the reload request)
Flags: needinfo?(mixedpuppy)
I'm guessing that doubling up on the text.txt output in the expected result is due to the reload you're going.  I'd expect that if you didn't do the reload, you'd only see the 302 output.  That is kind of what I'm experiencing.

I think it may be related to bug 1380186 comment 38, am working my way through testing this.
Assignee: nobody → mixedpuppy
Status: UNCONFIRMED → NEW
Component: WebExtensions: Untriaged → WebExtensions: Request Handling
Ever confirmed: true
Flags: needinfo?(mixedpuppy)
Priority: -- → P1
Comment on attachment 8964055 [details]
Bug 1448599 - fix WebRequest events for redirected channels when onBeforeRedirect is not used,

https://reviewboard.mozilla.org/r/232852/#review238308


Code analysis found 1 defect in this patch:
 - 1 defect found by mozlint

You can run this analysis locally with:
 - `./mach lint path/to/file` (JS/Python)


If you see a problem in this automated review, please report it here: http://bit.ly/2y9N9Vx


::: toolkit/components/extensions/test/xpcshell/test_ext_redirects.js:193
(Diff revision 1)
> +                    "onBeforeRequest", "onHeadersReceived", "onResponseStarted", "onCompleted"];
> +    browser.webRequest.onBeforeRequest.addListener(details => {
> +      if (details.url.includes("/redirect")) {
> +        browser.test.assertTrue(details.url.includes("/redirect"), "onBeforeRequest matches");
> +
> +      } else {

Error: Block must not be padded by blank lines. [eslint: padded-blocks]
Comment on attachment 8964055 [details]
Bug 1448599 - fix WebRequest events for redirected channels when onBeforeRedirect is not used,

https://reviewboard.mozilla.org/r/232852/#review238314


Code analysis found 1 defect in this patch:
 - 1 defect found by mozlint

You can run this analysis locally with:
 - `./mach lint path/to/file` (JS/Python)


If you see a problem in this automated review, please report it here: http://bit.ly/2y9N9Vx


::: toolkit/components/extensions/test/xpcshell/test_ext_redirects.js:195
(Diff revision 2)
> +                    "onBeforeRequest", "onHeadersReceived", "onResponseStarted", "onCompleted"];
> +    browser.webRequest.onBeforeRequest.addListener(details => {
> +      if (details.url.includes("/redirect")) {
> +        browser.test.assertTrue(details.url.includes("/redirect"), "onBeforeRequest matches");
> +
> +      } else {

Error: Block must not be padded by blank lines. [eslint: padded-blocks]
So, if webRequestBlocking is in permissions, the problem does not exist.  This may be why we haven't had any test failure or reports before.  All our redirect tests seem to have had blocking.
(In reply to Shane Caraveo (:mixedpuppy) from comment #10)
> So, if webRequestBlocking is in permissions, the problem does not exist. 

Thank you, it is a good work-around for the moment that allows me to handle the redirections.
Comment on attachment 8964055 [details]
Bug 1448599 - fix WebRequest events for redirected channels when onBeforeRedirect is not used,

https://reviewboard.mozilla.org/r/232852/#review238630

::: toolkit/components/extensions/test/xpcshell/test_ext_redirects.js:192
(Diff revision 3)
> +      if (details.url.includes("/redirect")) {
> +        browser.test.assertTrue(details.url.includes("/redirect"), "onBeforeRequest matches");

This is a tautology.
Attachment #8964055 - Flags: review?(kmaglione+bmo) → review+
Pushed by mixedpuppy@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/5c9c6f5a4ca3
fix WebRequest events for redirected channels when onBeforeRedirect is not used, r=kmag
https://hg.mozilla.org/mozilla-central/rev/5c9c6f5a4ca3
Status: NEW → RESOLVED
Closed: Last year
Resolution: --- → FIXED
Target Milestone: --- → mozilla61
Depends on: 1450872
Posted image Bug1448599.gif
I can  reproduce the issue on Firefox 59.0.2 (20180323154952) under Win 7 64-bit and Mac OS X 10.13.2 with the extension from the comment1 and the steps from comment3.

Before the reload I can see only the “302” output and after the reload I can see the “304” output and the “200” outputs mentioned in comment3.

This issue is verified as fixed on Firefox 61.0a1 (20180411100123) under Win 7 64-bit and Mac OS X 10.13.2.

Please see the attached video.
Status: RESOLVED → VERIFIED
Product: Toolkit → WebExtensions
You need to log in before you can comment on or make changes to this bug.