Open Bug 1595610 Opened 5 years ago Updated 11 months ago

webRequest.onHeadersReceived not fired for cached response after script-initiated navigation

Categories

(WebExtensions :: Request Handling, defect)

defect

Tracking

(Not tracked)

REOPENED

People

(Reporter: kernp25, Unassigned, NeedInfo)

References

Details

Attachments

(18 files, 4 obsolete files)

98.01 KB, image/png
Details
23.84 KB, image/png
Details
88.13 KB, image/png
Details
3.62 MB, video/mp4
Details
66.06 KB, image/png
Details
39.82 KB, application/octet-stream
Details
28.21 KB, application/octet-stream
Details
58.35 KB, image/png
Details
36.45 KB, image/png
Details
39.16 KB, image/png
Details
22.73 KB, image/png
Details
886 bytes, application/x-zip-compressed
Details
43.51 KB, application/octet-stream
Details
1.60 MB, video/mp4
Details
101.07 KB, image/png
Details
673.24 KB, application/octet-stream
Details
932.37 KB, application/octet-stream
Details
979.80 KB, application/octet-stream
Details
Attached file manifest.zip (obsolete) —
  1. Install test add-on
  2. Open Solicitud_beca_Toyota_2019_2020.doc

Actual results:
webRequest is not firing for https://view.officeapps.live.com/op/errorpage.htm?llcc=en-US

Expected results:
webRequest should fire for https://view.officeapps.live.com/op/errorpage.htm?llcc=en-US (so i can use webRequest.filterResponseData)

In Google Chrome it works as expected:
frameId: 0
initiator: "https://view.officeapps.live.com"
method: "GET"
parentFrameId: -1
requestId: "1289"
statusCode: 200
statusLine: "HTTP/1.1 200"
tabId: 23
timeStamp: 1573504743027.031
type: "main_frame"
url: "https://view.officeapps.live.com/op/errorpage.htm?llcc=en-US"

Flags: needinfo?(mixedpuppy)

My nightly version:
72.0a1 (2019-11-11) (64-Bit)

Flags: needinfo?(hani.yacoub)
See Also: → 1595621

After performing the steps to reproduce provided in both Firefox and Chrome it look like the results are quite similar.
Could you please provide more details or a recording of the expected result?

Flags: needinfo?(kernp25)

Really stange, because now it seems to work (it was not working before).
Tested on 72.0a1 (2019-11-18) (64-Bit).

Flags: needinfo?(mixedpuppy)
Flags: needinfo?(kernp25)
Flags: needinfo?(hani.yacoub)
Attached image firefox_XuWlxcsRet.png

Maybe there was a bug in Nightly?

I've tested on the Nightly builds that were released on 2019-11-11 (Build ID:20191111215252 and Build ID:20191119043902).
When I input the example link into the browser two requests are fired (see attached) but unless there's an issue with that, I am going to set this bug as Invalid.
If it can be reproduced again then it can be reopened.

Flags: needinfo?(kernp25)

Not reproducible. Please provide more details if possible.

Note that if you use location to navigate, and the only change is the reference fragment, then it is possible for the page to not (re)load anew.

And when you try to reproduce, make sure that the location assignment only happens after the webRequest listener has been added.

Status: UNCONFIRMED → RESOLVED
Closed: 5 years ago
Resolution: --- → INVALID
Attached video DFe4oiFFpX.mp4
Flags: needinfo?(kernp25)

Thus bug still exists. Can you look at the video?

Flags: needinfo?(rob)

Only at the end of the video you will see that it fires for https://view.officeapps.live.com/op/errorpage.htm?llcc=de-DE

Attached image firefox_j6WSyMRNfY.png

I can see the video, but cannot reproduce locally.

Which version of Firefox are you using?

In your video there are lots of add-ons. Does the issue only happen with a certain combination of add-ons?

Can you reproduce the problem when the devtools of the tab is open, and if yes, can you export the contents of the network tab as HAR?

Flags: needinfo?(rob)

(In reply to Rob Wu [:robwu] from comment #12)

Which version of Firefox are you using?

74.0.1 (64-Bit)

In your video there are lots of add-ons. Does the issue only happen with a certain combination of add-ons?

I don't think so. I will test it again without add-ons.

Can you reproduce the problem when the devtools of the tab is open, and if yes, can you export the contents of the network tab as HAR?

I will try.

Attached file manifest.zip (obsolete) —

New improved test add-on.

Attachment #9107933 - Attachment is obsolete: true

I did again some testing: If you disable the cache (e.g. Disable cache option in devtools), then the issue does not seem to occur anymore.

Can you test again using the new test add-on?

Flags: needinfo?(rob)

Note: webRequest.onHeadersReceived was not called

Note: webRequest.onHeadersReceived was called

(In reply to kernp25 from comment #14)

Created attachment 9138989 [details]
manifest.zip

New improved test add-on.

This is basically the same as the original add-on, except it uses the webRequest.filterResponseData / StreamFilter API to modify the response upon onHeadersReceived instead of console.log. This is not relevant (because the bug is about onHeadersReceived not firing at all), so unless a good reason is given, I would use the reproduction steps from the first comment.

(In reply to kernp25 from comment #15)

I did again some testing: If you disable the cache (e.g. Disable cache option in devtools), then the issue does not seem to occur anymore.

Thanks for this bit of information. While I am still unable to reproduce, you clearly can, so I'll reopen the bug. There is at least one other cache-related bug report (bug 1543018, again not easily reproducible..), so perhaps your report may help there as well.

Status: RESOLVED → REOPENED
Ever confirmed: true
Flags: needinfo?(rob)
Resolution: INVALID → ---
See Also: → 1543018

In view.officeapps.live.com_Archive [20-04-08 00-04-00].har:
"status": 0, "statusText": "", "httpVersion": "", "headers": [], "cookies": [],

And in view.officeapps.live.com_Archive [20-04-08 00-08-20].har:
"status": 200, "statusText": "OK", "httpVersion": "HTTP/2.0",

Maybe this is the reason why onHeadersReceived is not called?
Because of response status 0?

I think that status 0 is just one of the symptoms. In the good case, almost every field except for content is populated. In the broken case, it is not:

Bad ( [20-04-08 00-04-00].har ):

        "response": {
          "status": 0,
          "statusText": "",
          "httpVersion": "",
          "headers": [], 
          "cookies": [], 
          "content": {
            "mimeType": "text/html",
            "size": 6275,
            "text": "<!DOCTYPE html ...(cut)..."
          },
          "redirectURL": "",
          "bodySize": 2202
        },

Good ( [20-04-08 00-08-20].har ):

        "response": {
          "status": 200,
          "statusText": "OK",
          "httpVersion": "HTTP/2.0",
          "headers": [
            { 
              "name": "cache-control",
              "value": "public,max-age=31536000"
            },
            { 
              "name": "content-length",
              "value": "2202"
            },
            ..... cut ....
          ],
          "cookies": [
            {
              "name": "",
              "value": ""
            }
          ],
          "content": {
            "mimeType": "text/html",
            "size": 6275,
            "text": "<!DOCTYPE html ...(cut)..."
          },
          "redirectURL": "",
          "headersSize": 0,
          "bodySize": 2202
        },
        "cache": {},
        "timings": {
          "blocked": 0,
          "dns": 0,
          "ssl": 0,
          "connect": 0,
          "send": 0,
          "wait": 0,
          "receive": 0
        },
        "time": 0,
        "_securityState": "secure"
      },

Summary: webRequest not firing when script uses window.location to navigate to new url → webRequest.onHeadersReceived not fired for cached response after script-initiated navigation
Attached image bf3BGHX5QL.png

Output of the devtools tab from the failed request.

Again: The issue does not seem to occur, if you disable the cache.
So it must have something to do with the cache?

Attached image gc7lWXphN9.png

This is the output from the devtools network tab after i reloaded the tab.

After i reloaded the tab, it has the status 304.

You might consider testing on top of D53187, or waiting for those patches to land then test.

And onHeadersReceived was called after i reloaded the tab.

Can you link the bug?

Attached image kdR4bJ7m7Z.png

This is the output from the devtools tab after webRequest.onHeadersReceived was called

But it seems that it works also for cached requests (look at picture).

It seems that if the response status is 0, then webRequest.onHeadersReceived is not called.

When i use webRequest.onBeforeRequest then it always works.
But webRequest.onHeadersReceived does not fire for response status 0.

So, this is the bug because of the response status 0?

Flags: needinfo?(rob)

When i use webRequest.onErrorOccurred then it shows this error: NS_ERROR_NET_ON_WAITING_FOR

Attached image firefox_2SfCYLQWEi.png

webRequest.onErrorOccurred output

This is the real error.

Why it fires the error NS_ERROR_NET_ON_WAITING_FOR?
Is this a bug in Firefox then?

Flags: needinfo?(rob) → needinfo?(mixedpuppy)
Attached file manifest.zip (obsolete) —

Test add-on to show the NS_ERROR_NET_ON_WAITING_FOR bug.

Attachment #9138989 - Attachment is obsolete: true

Can you confirm the NS_ERROR_NET_ON_WAITING_FOR error?

Flags: needinfo?(alexandru.cornestean)
Attached file manifest(4).zip

Improved test add-on.

Attachment #9139044 - Attachment is obsolete: true

(In reply to Shane Caraveo (:mixedpuppy) from comment #27)

You might consider testing on top of D53187, or waiting for those patches to land then test.

I don't think it has something to do with https://phabricator.services.mozilla.com/D53187

(In reply to Shane Caraveo (:mixedpuppy) from comment #27)

You might consider testing on top of D53187, or waiting for those patches to land then test.

https://phabricator.services.mozilla.com/D53187 seems to be about StreamFilters, whereas this bug is independent of that (see comment 19).

(In reply to kernp25 from comment #35)

When i use webRequest.onErrorOccurred then it shows this error: NS_ERROR_NET_ON_WAITING_FOR

Interesting. This is already a good start at narrowing the causes, since there are very few sources of this status.
Could you create a network log (https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging) and share the results of a good case and a bad case, with as little noise as possible? (preferably start with a blank profile with no add-ons besides yours).

(In reply to kernp25 from comment #40)

Can you confirm the NS_ERROR_NET_ON_WAITING_FOR error?

I cannot, and I doubt whether verification by QA makes any difference here, so I'll remove the flag.
Since you are quite responsive here, I think that your input can be more useful during the investigation.

Flags: needinfo?(alexandru.cornestean)

This log is from 77.0a1 (2020-04-08) (64-Bit)

(In reply to Rob Wu [:robwu] from comment #43)

I cannot, and I doubt whether verification by QA makes any difference here, so I'll remove the flag.
Since you are quite responsive here, I think that your input can be more useful during the investigation.

Can you test again but this time install https://addons.mozilla.org/firefox/addon/ublock-origin/

Flags: needinfo?(rob)
Attached video GKLTq3rdS0.mp4

Bug that happens without uBlock Origin installed.
webRequest.onErrorOccurred is also not called.

Can you also reproduce the above bug?
Without uBlock Origin?

With the above bug webRequest.onBeforeRequest is also not called.

It seems that if you have fission.autostart set to true in about:config then this bug seems to occur.
If fission.autostart is false then the bug does not occur.

Can you confirm?

I tried with the latest extension from comment 41, with and without uBlock Origin, with and without fission.autostart=true on Nightly 76.0a1 buildID 20200325093457 on Linux, and cannot reproduce this problem.

In comment 44 you provided another HAR even though I requested the log from about:networking. Could you visit about:networking, go to the Logging tab and follow the instructions to create a log file? This log is much more detailed than the HAR, because it records internal implementation details as well. See https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging

PS. Could you try to put your comments in one comment before posting a new comment? Every comment generates a bunch of e-mails to people who are (in)directly subscribed to this bug. Thanks for your help!

Flags: needinfo?(rob)

(In reply to Rob Wu [:robwu] from comment #50)

I tried with the latest extension from comment 41, with and without uBlock Origin, with and without fission.autostart=true on Nightly 76.0a1 buildID 20200325093457 on Linux, and cannot reproduce this problem.

Maybe the bug does not happen on linux? I have tested it on Windows 10.

I also modified your addon to check it on github page (this was my test page in comment to bug above), and for some reason both listeners are always called

Attached file bad_case.moz_log

webRequest.onErrorOccurred was called.

Attached file good_case.moz_log

webRequest.onHeadersReceived was called.

Maybe this will help you?

Flags: needinfo?(rob)
Attached file without_uBlock.moz_log (obsolete) —

Tested without uBlock enabled (the bug did not occur).

Bug also occured without uBlock enabled log.

Attachment #9140283 - Attachment is obsolete: true
Flags: needinfo?(mixedpuppy)
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: