1493599 - Expose blocked resource reason on nsILoadInfo

Status: VERIFIED FIXED

(Core :: Networking, enhancement, P2)

Description

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Necko should expose a reason for blocked HTTP resources.

This new Necko API should allow Firefox DevTools to inform the user that some HTTP resources has been blocked as well as explain why.

See also bug 1157817 (covers the DevTools part)

Jan Honza Odvarko

Comment 1

[Honza Bambas (:mayhemer)]

In detail, the proposal is: 
https://bugzilla.mozilla.org/show_bug.cgi?id=1157817#c14

Comment 2

[Honza Bambas (:mayhemer)]

There is more than one way to block a request:

1. nsCORSListenerProxy, CheckRequestApproved that logs to console with LogBlockedRequest; could add the reason in some form on the requests load info, note that the reason given to LogBlockedRequest is a name of a localization property bundle string (like "CORSMissingAllowOrigin"), not something we want to expose as the reason, probably.


2. nsIContentPolicy implementers (around 7 active) having two methods: ShouldLoad and ShouldProcess, taking load info and uri of the content in question.

nsContentPolicy is a central service that calls registered blockers (mPolicies).  it may be called before a channel is created (e.g. from css script loader).  it's also called from AsyncOpen2 (child and parent) implementations via nsContentSecurityManager::doContentSecurityCheck.  in the former case, provided load info is just temp, no channel is created, so nothing in the net monitor already.  in the latter case, we can add the reason on the load info, as that is the load info attached to the channel being open; but I'm not sure the channel will be logged at all as well - we fail asyncOpen2 synchronously, so, no parent channel even created, and thus no on-http-* invoked.

note that mixed content blocker belongs here as well, it logs only to the web console via LogMixedContentMessage and we have no channel to add and annotate in the net panel.  quick check shows that anything logged in the console as "Blocked loading mixed .." doesn't have a net panel counter part.


3. tracker blocking and fast-blocking: a channel is examined after opening by a classifier, that classifier may Cancel() the channel with NS_ERROR_TRACKING_URI/NS_ERROR_TRACKING_ANNOTATION_URI.


there can be even more of specific blockers, I only know about these.

to sum, it looks like we want to:
- add an enum of all possible reasons of cancellation on nsiloadinfo
- add a r/w attr on nsiloadinfo to set/get the reason, setter always overrides, for simplicity
- set the reason in 
  a. CORS checking 
  b. tracker blocking

I don't see a way to have mixed content blocked channels in net panel with the reason exposed.  if we so much want it, it needs a serious overhaul of few things.

Comment 3

[Honza Bambas (:mayhemer)]

Attachment: v1

reason exposed as int, see nsILoadInfo for details.  comment 2 explains why only on this place.

Comment 4

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Sorry for the delay!

I finally found some time to test this, but the patch is not synced
with latest head. Could you please rebase it, thanks!

Honza

Comment 5

[Honza Bambas (:mayhemer)]

You will very likely be faster than me ;) Won't get to this sooner than next week, if then.

Comment 6

[Honza Bambas (:mayhemer)]

Andrea, I would use some help with rebasing the patch here. I managed to hg rebase it, but there is a too big conflict at hunk [1]. The purpose was to mark the channel as 'classified from tracking.' Right now, after patch [2], I can't see where to put that particular NS_SetRequestBlockingReason call.

Can you please navigate me to the right place? Also, could it just be added as another case: at [3]?

Thanks!

[1] https://bugzilla.mozilla.org/attachment.cgi?id=9019083&action=diff#a/netwerk/base/nsChannelClassifier.cpp_sec2
[2] https://hg.mozilla.org/mozilla-central/rev/0cc5e8d1a09d
[3] https://bugzilla.mozilla.org/attachment.cgi?id=9019083&action=diff#a/netwerk/base/nsChannelClassifier.cpp_sec3

Comment 7

[Honza Bambas (:mayhemer)]

(note for me: fastblock has been removed from httpchan at https://hg.mozilla.org/mozilla-central/diff/dd23df519c7e/netwerk/protocol/http/nsHttpChannel.cpp)

Comment 8

[Andrea Marchesini [:baku]]

Attachment: patch rebased

I haven't checked what the patch does in the detail. I just converted it to the new codebase.

Comment 9

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Thanks for the rebase Andrea!

I was testing the patch on my machine and the new nsILoadInfo.requestBlockingReason is always set to 0 for me.

Here is what I am doing:

1. Open DevTools Toolbox and Select the Network panel
2. Load https://googlesamples.github.io/web-fundamentals/fundamentals/security/prevent-mixed-content/active-mixed-content.html
3. Check out your system console for logs:

I created logs in:

• onStartRequest
  https://searchfox.org/mozilla-central/rev/5c8ea961d04767db723a0a15e3a8f7fbca154129/devtools/server/actors/network-monitor/network-response-listener.js#202

• onStopRequest
  https://searchfox.org/mozilla-central/rev/5c8ea961d04767db723a0a15e3a8f7fbca154129/devtools/server/actors/network-monitor/network-response-listener.js#320

I did something as follows when logging the value:

console.log(channel.loadInfo.requestBlockingReason);

Does the patch work for you?
Or am I doing something wrong?

Honza

Comment 10

[Honza Bambas (:mayhemer)]

Attachment: v2

thanks :baku!

• added also mixed content blocking (was missing in v1)

Honza, please check this one again.

Comment 11

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Thanks for the update!

I just tested the new patch with:
https://googlesamples.github.io/web-fundamentals/fundamentals/security/prevent-mixed-content/active-mixed-content.html

...and I am still only seeing 0 when reading channel.loadInfo.requestBlockingReason for all requests executed by the page.

The Console panel is showing that the page generates mixed content messages, so there should be some non-zero results.

Honza

Comment 12

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: blocked-reason-logging.patch

I am attaching a patch I am using for logging.
If you apply the patch on top of the platform/api patch and load the page (mentioned in the previous comment), you should see logs in the system console (there is always 0 for me).

Honza

Comment 13

[Honza Bambas (:mayhemer)]

Requests reporting 0 are not blocked.

Mixed content blocking happens at the time of asyncOpen, it makes asyncOpen fail, so then there is no onStart/StopRequest (and I don't know where from the _createNetworkEvent call comes). To handle this is beyond the scope of this bug, the information hangs of off the channel's load info (on child), though.

The patch works as it has to.

Comment 14

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Thanks for the update!

Here is another test case I have:
http://janodvarko.cz/tests/bugzilla/1493599/

1. Load the page, enable the Network panel
2. Click the button on the page
3. CORS request is executed and blocked, this error appears in the Console panel:
   Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remote resource at https://www.google.com/. (Reason: CORS header ‘Access-Control-Allow-Origin’ missing).

But, the blocked reason is always 0 for me.

Is this similar to the case above? (with mixed content)

Honza

​

Comment 15

[Honza Bambas (:mayhemer)]

Probably. At which point do you read the blocked reason value?

Comment 16

[Jan Honza Odvarko [:Honza] (always need-info? me)]

The Network panel (backend) is using nsIHttpActivityDistributor and listening for ACTIVITY_SUBTYPE_REQUEST_HEADER event. When this event happens the patch reads channel.loadInfo.requestBlockingReason flag and prints it using console.log.

There is also custom response listener (nsIRequestObserver) set at the same time (ACTIVITY_SUBTYPE_REQUEST_HEADER fired) through nsITraceableChannel. The patch reads channel.loadInfo.requestBlockingReason flag and prints it when onStartRequest and onStopRequest happens.

Honza

Comment 17

[Honza Bambas (:mayhemer)]

(In reply to Jan Honza Odvarko [:Honza] (need-info? me) from comment #16)

The Network panel (backend) is using nsIHttpActivityDistributor and listening for ACTIVITY_SUBTYPE_REQUEST_HEADER event.

This happens ONLY when we decide to do a network request for the channel (either when there is no cached content, it's bypassed by flags, has to be revalidated or when we race cache and network) but NOT when we go from the cache.

My patch add the info at CheckRequestApproved, called (between else) from here:
https://searchfox.org/mozilla-central/rev/60c4067b1cbb0f94d7dc2d7cdfa27ed579817fee/netwerk/protocol/http/nsCORSListenerProxy.cpp#423

But this gets called from inside nsContentSecurityManager::doContentSecurityCheck called from AsyncOpen. At that moment you definitely don't know about that channel.

Hence, we may need to invent a new http-on-* notification for such cases.

Err! No, we add the CORS proxy from doContentSecurityCheck, but CheckRequestApproved is called from OnStartRequest, so this should just work.

Comment 18

[Jan Honza Odvarko [:Honza] (always need-info? me)]

(In reply to Honza Bambas (:mayhemer) from comment #17)

(In reply to Jan Honza Odvarko [:Honza] (need-info? me) from comment #16)

The Network panel (backend) is using nsIHttpActivityDistributor and listening for ACTIVITY_SUBTYPE_REQUEST_HEADER event.

This happens ONLY when we decide to do a network request for the channel (either when there is no cached content, it's bypassed by flags, has to be revalidated or when we race cache and network) but NOT when we go from the cache.

Note that I have cache disabled when testing this API.

Err! No, we add the CORS proxy from doContentSecurityCheck, but CheckRequestApproved is called from OnStartRequest, so this should just work.

I can see that LogBlockedRequest is called with CORSMissingAllowOrigin (in CheckRequestApproved, C++), but when reading channel.loadInfo.requestBlockingReason later in onStart/StopRequest (JS) it says 0.
(this happens when I am using my test case: http://janodvarko.cz/tests/bugzilla/1493599/)

Honza

Comment 19

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Comment on attachment 9039849 [details] [diff] [review]
v2

Review of attachment 9039849 [details] [diff] [review]:
-----------------------------------------------------------------

Removing myself from the review for now since the patch doesn't work for me.

Honza: please let me know when you have an update, thanks!

Comment 20

[Honza Bambas (:mayhemer)]

Putting back to the triage pool, I have more important bugs assigned to me right now.

Comment 21

[:Harald Kirschner :digitarald]

Baku, could you help get this over the hump?

Comment 22

[Honza Bambas (:mayhemer)]

I think what we need is a new "on-http-failed-open" notification triggered somewhere from [1]. If it's enough to be triggered on the child process, it's easy to do. If it has to be propagated to the parent in this form (i.e. via the necko code), then we have way more work to do.

[1] https://searchfox.org/mozilla-central/rev/cb7faaf6b4ad2528390186f1ce64618dea71031e/netwerk/protocol/http/HttpChannelChild.cpp#2548

Comment 23

[Dragana Damjanovic [:dragana]]

Hi Jan, dev-tools run on the parent process. Can dev-tools get notification form a child process? I just want to know how much wotk it will be to implement comment #22.

Comment 24

[Jan Honza Odvarko [:Honza] (always need-info? me)]

@Alex, can you please look at the previous comment @23, thanks!

Honza

Comment 25

[Alexandre Poirot [:ochameau]]

Most of the inspection work in done from the parent process, but we had to also start listening from the content process because of service workers (We might stop doing that with the newest SW implementation, that I don't know yet).

So, you have a good example of observer service message being listened either from the parent process and/or the content process over here:
https://searchfox.org/mozilla-central/source/devtools/server/actors/network-monitor/network-observer.js#200-212

Hopefully, this event is for notifying about a new request and not about augmenting the information of one being already inspected in the parent process? As I don't think we have anything already augmenting parent process inspection with data from the content process.

Comment 26

[Dragana Damjanovic [:dragana]]

(In reply to Alexandre Poirot [:ochameau] from comment #25)

Most of the inspection work in done from the parent process, but we had to also start listening from the content process because of service workers (We might stop doing that with the newest SW implementation, that I don't know yet).

So, you have a good example of observer service message being listened either from the parent process and/or the content process over here:
https://searchfox.org/mozilla-central/source/devtools/server/actors/network-monitor/network-observer.js#200-212

Hopefully, this event is for notifying about a new request and not about augmenting the information of one being already inspected in the parent process? As I don't think we have anything already augmenting parent process inspection with data from the content process.

This will be a new request. The request is blocked so it will not get any other notification.

Comment 27

[Selena Deckelmann :selenamarie :selena]

:mayhemer -- can you pick this back up? It's now blocking a devtools feature from shipping.

Comment 28

[Honza Bambas (:mayhemer)]

(In reply to Selena Deckelmann :selenamarie :selena use ni? pronoun: she from comment #27)

:mayhemer -- can you pick this back up? It's now blocking a devtools feature from shipping.

Absolutely.

Comment 29

[Honza Bambas (:mayhemer)]

Attachment: Bug 1493599 - Expose reason of security blocking on nsILoadInfo and add new http observer notification for failed asyncOpens, r=honza,dragana

Comment 30

[Honza Bambas (:mayhemer)]

(In reply to Honza Bambas (:mayhemer) from comment #29)

Created attachment 9050329 [details]
Bug 1493599 - Expose reason of security blocking on nsILoadInfo and add new http observer notification for failed asyncOpens, r=honza,dragana

This patch adds a new notification for all failed httpchannelchild::asyncopen. it only fires on the child process. this is still just a wip, I wrote a stub for observing this new notification in the dev tool's net observer which should be updated by Honza or someone from the dev team.

please let me know how this works for you.

Comment 31

[Jan Honza Odvarko [:Honza] (always need-info? me)]

@tanhengyeow: can you please test the patch, thanks!

Honza

Comment 32

[Honza Bambas (:mayhemer)]

(In reply to Jan Honza Odvarko [:Honza] (always need-info? me) from comment #31)

@tanhengyeow: can you please test the patch, thanks!

Honza

Please note that the patch needs some additional code to be added at _httpFailedOpening in network-observer.js. I didn't know how to go on from that point.

Comment 33

[Hengyeow (:tanhengyeow)]

Hi :Honza

I pulled the patch, built the code (without artifact builds mode on), and tested the patch. Apart from a missing comma, I got this error when trying to open Devtools:

JavaScript error: resource://devtools/client/framework/attach-thread.js, line 79: TypeError: threadClient is undefined
console.error: "Exception while opening the toolbox" "Protocol error (unknownError): error occurred while processing 'startListeners: [Exception... \"Component returned failure code: 0x80004001 (NS_ERROR_NOT_IMPLEMENTED) [nsIObserverService.addObserver]\"  nsresult: \"0x80004001 (NS_ERROR_NOT_IMPLEMENTED)\"  location: \"JS frame :: resource://devtools/server/actors/network-monitor/network-observer.js :: init :: line 211\"  data: no]\nStack: init@resource://devtools/server/actors/network-monitor/network-observer.js:211:20\ninitialize@resource://devtools/server/actors/network-monitor.js:48:19\ncls@resource://devtools/shared/protocol.js:1254:25\nstartListeners@resource://devtools/server/actors/webconsole.js:617:13\nAsync*onPacket@resource://devtools/server/main.js:1291:58\nreceiveMessage@resource://devtools/shared/transport/child-transport.js:66:16\nMessageListener.receiveMessage*_addListener@resource://devtools/shared/transport/child-transport.js:40:14\nready@resource://devtools/shared/transport/child-transport.js:57:10\n_onConnection@resource://devtools/server/main.js:880:15\nconnectToParent@resource://devtools/server/main.js:296:17\nonConnect<@resource://devtools/server/startup/frame.js:59:35\nexports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:109:22\nMessageListener.receiveMessage*@resource://devtools/server/startup/frame.js:80:5\n@resource://devtools/server/startup/frame.js:160:5\nLine: 211, column: 0" "Protocol error (unknownError): error occurred while processing 'startListeners: [Exception... \"Component returned failure code: 0x80004001 (NS_ERROR_NOT_IMPLEMENTED) [nsIObserverService.addObserver]\"  nsresult: \"0x80004001 (NS_ERROR_NOT_IMPLEMENTED)\"  location: \"JS frame :: resource://devtools/server/actors/network-monitor/network-observer.js :: init :: line 211\"  data: no]\nStack: init@resource://devtools/server/actors/network-monitor/network-observer.js:211:20\ninitialize@resource://devtools/server/actors/network-monitor.js:48:19\ncls@resource://devtools/shared/protocol.js:1254:25\nstartListeners@resource://devtools/server/actors/webconsole.js:617:13\nAsync*onPacket@resource://devtools/server/main.js:1291:58\nreceiveMessage@resource://devtools/shared/transport/child-transport.js:66:16\nMessageListener.receiveMessage*_addListener@resource://devtools/shared/transport/child-transport.js:40:14\nready@resource://devtools/shared/transport/child-transport.js:57:10\n_onConnection@resource://devtools/server/main.js:880:15\nconnectToParent@resource://devtools/server/main.js:296:17\nonConnect<@resource://devtools/server/startup/frame.js:59:35\nexports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:109:22\nMessageListener.receiveMessage*@resource://devtools/server/startup/frame.js:80:5\n@resource://devtools/server/startup/frame.js:160:5\nLine: 211, column: 0"
undefined

As :mayhemer stated in the previous comment, I think additional code needs to be included "at _httpFailedOpening in network-observer.js" for it to be working so that we can test the patch properly. Still figuring out what to add, but thought I would give early feedback here first.

Comment 34

[Jan Honza Odvarko [:Honza] (always need-info? me)]

@tanhengyeow: thanks for testing!

I see, let's wait till :mayhemer has an updated version.

Honza

Comment 35

[Honza Bambas (:mayhemer)]

So, I fixed the two glitches, but adding dump() into the observer method doesn't show anything for me in the text console (maybe just because child process are not allowed to)

Can you please retest?

Comment 36

[Hengyeow (:tanhengyeow)]

Hi :mayhemer

I tested your new patch with steps from comment 14. The Disable cache option is checked in network panel as well.

I'm logging the output using the code from the patch highlighted in comment 12.

The results are all 0 to me, here's a snippet of the output I see:

console.log: "---> blocked reason 0, url: https://www.google.com/\n"
console.log: "---> blocked reason 0, url: https://www.google.com/\n"
console.log: "---> blocked reason 0, url: http://ocsp.pki.goog/GTSGIAG3\n"
console.log: "---> blocked reason onStartRequest 0, url: http://ocsp.pki.goog/GTSGIAG3\n"
console.log: "---> blocked reason onStopRequest 0, url: http://ocsp.pki.goog/GTSGIAG3\n"
console.log: "---> blocked reason onStartRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStartRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStopRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStopRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason 0, url: https://www.google.com/\n"
console.log: "---> blocked reason 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStartRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStartRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStopRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStopRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason 0, url: https://www.google.com/\n"
console.log: "---> blocked reason 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStartRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStartRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStopRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStopRequest 0, url: https://www.google.com/\n"

Comment 37

[Honza Bambas (:mayhemer)]

(In reply to Heng Yeow (:tanhengyeow) from comment #36)

Hi :mayhemer

I tested your new patch with steps from comment 14. The Disable cache option is checked in network panel as well.

I'm logging the output using the code from the patch highlighted in comment 12.

The results are all 0 to me, here's a snippet of the output I see:

console.log: "---> blocked reason 0, url: https://www.google.com/\n"
console.log: "---> blocked reason 0, url: https://www.google.com/\n"
console.log: "---> blocked reason 0, url: http://ocsp.pki.goog/GTSGIAG3\n"
console.log: "---> blocked reason onStartRequest 0, url: http://ocsp.pki.goog/GTSGIAG3\n"
console.log: "---> blocked reason onStopRequest 0, url: http://ocsp.pki.goog/GTSGIAG3\n"
console.log: "---> blocked reason onStartRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStartRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStopRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStopRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason 0, url: https://www.google.com/\n"
console.log: "---> blocked reason 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStartRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStartRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStopRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStopRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason 0, url: https://www.google.com/\n"
console.log: "---> blocked reason 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStartRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStartRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStopRequest 0, url: https://www.google.com/\n"
console.log: "---> blocked reason onStopRequest 0, url: https://www.google.com/\n"

I have no idea what you are doing, but if you are using the patch from comment 12, then it will definitely not work.

You have to fill in the part in network-observer.js, _httpFailedOpening. There is a comment: // ...
Only there you can see the reason.

Comment 38

[Hengyeow (:tanhengyeow)]

Hi :mayhemer

In my previous comment, I'm testing the patch with this test site, http://janodvarko.cz/tests/bugzilla/1493599/ as mentioned in comment 14.

The snippet of the output was logged in my terminal console by applying the patch from comment 12.

You have to fill in the part in network-observer.js, _httpFailedOpening. There is a comment: // ...
Only there you can see the reason.

I tried to log statements in the _httpFailedOpening function, but it is not triggered at all when tested with the test site, which meant logging statements won't show.

I placed debugger statement in that function as well, tested with the test site and confirmed that the function wasn't run at all.

We might need a different test method, or perhaps it is not reading the interface properly.

Comment 39

[Honza Bambas (:mayhemer)]

Just double checked that I am triggering the new notification from HttpChannelChild::AsyncOpen - let you know this happens ONLY on the content (child) process(es). I also confirmed that when no devtools window is open, there is no listener registered for the notification. When I open devtools in exactly one window there is then exactly one observer to the notification and it's being called. Honza O. has confirmed for me that my new code in network-observer.js that listens to that notification is correct and hence that it should trigger as expected. So I'm not sure what's happening and I'm not sure I can help more, I don't know the guts of network-observer at all - the problem must be there. Please ask Honza O for more help.

Comment 40

[Honza Bambas (:mayhemer)]

Mu comment 39 (and comment 37 actually too - I missed you are suddenly testing something the original test case now) is about the test case from comment 11.

The test case from comment 14 is doing something else. It tests CORS blocked request and that should be visible asynchronously (in OnStartRequest). Hence, checking with the logging patch from comment 12 was correct.

I'm going to look into it a bit more now.

Comment 41

[Honza Bambas (:mayhemer)]

OK, so for the test case from comment 14 I can see the following (added logging to where we set the blocking reason):

2019-03-15 10:57:49.989000 UTC - [Child 9404: Main Thread]: D/nsHttp HttpChannelChild::OnStartRequest [this=000001EFF28FF000]
2019-03-15 10:57:49.989000 UTC - [Child 9404: Main Thread]: V/loadinfo LoadInfo::SetRequestBlockingReason 000001EFF53BE370 0
2019-03-15 10:57:49.989000 UTC - [Child 9404: Main Thread]: D/nsHttp HttpChannelChild::DoOnStartRequest [this=000001EFF28FF000]
2019-03-15 10:57:49.989000 UTC - [Child 9404: Main Thread]: V/loadinfo LoadInfo::SetRequestBlockingReason 000001EFF53BE370 1005
2019-03-15 10:57:49.990000 UTC - [Child 9404: Main Thread]: D/nsHttp HttpChannelChild::Cancel [this=000001EFF28FF000, status=805303f4]
2019-03-15 10:57:49.990000 UTC - [Child 9404: Main Thread]: D/nsHttp HttpChannelChild::Cancel [this=000001EFF28FF000, status=805303f4]

The reason 1005 is from here:

 	xul.dll!mozilla::net::LoadInfo::SetRequestBlockingReason(1005) Line 1394	C++
 	xul.dll!NS_SetRequestBlockingReason(0x000001bd9b6f09b0, 1005) Line 2835	C++
 	xul.dll!NS_SetRequestBlockingReason(0x000001bda000c078, 1005) Line 2829	C++
 	xul.dll!LogBlockedRequest(0x000001bda000c078, 0x00007ff96c0d9d41, 0x0000000000000000, 1005, 0x000001bda000c078) Line 67	C++
 	xul.dll!nsCORSListenerProxy::CheckRequestApproved(0x000001bda000c078) Line 571	C++
 	xul.dll!nsCORSListenerProxy::OnStartRequest(0x000001bda000c078) Line 424	C++
	xul.dll!mozilla::net::HttpChannelChild::DoOnStartRequest(0x000001bda000c078, 0x0000000000000000) Line 668	C++
 	xul.dll!mozilla::net::HttpChannelChild::OnStartRequest(NS_OK, {...}, true, {...}, {...}, false, true, 0, 0, 0, {...}, {...}, {...}, {...}, 0, {...}, 0, true, {...}) Line 599	C++
 	xul.dll!mozilla::net::StartRequestEvent::Run() Line 438	C++
 	xul.dll!mozilla::net::ChannelEventQueue::RunOrEnqueue(0x000001bd9d0c8000, false) Line 211	C++
 	xul.dll!mozilla::net::HttpChannelChild::RecvOnStartRequest(NS_OK, {...}, true, {...}, {...}, false, true, 0, 0, 0, {...}, {...}, {...}, {...}, 0, 0, {...}, 0, true, {...}) Line 500	C++

To explain: blocking doesn't happen on the parent process, but solely on the content process. nsCORSListenerProxy intercepts the OnStartRequest call and sets the reason on the load info prior to calling the outer listener, which is an XHR in case devtools net monitor is not open.

When devtools are open, it is exactly the same! Apparently, you are observing only the channel on the parent process where the blocking doesn't happen at all and therefor there can't be any reason exposed.

You must observe onStartRequest on the child process (only?) to catch the blocking reason.

Comment 42

[Honza Bambas (:mayhemer)]

I think you should file a new bug for the devtools parts. This but should be dedicated only to the platform changes and the stub changes to expose the new failed-open notification.

Comment 43

[Jan Honza Odvarko [:Honza] (always need-info? me)]

(In reply to Honza Bambas (:mayhemer) from comment #42)

I think you should file a new bug for the devtools parts. This but should be dedicated only to the platform changes and the stub changes to expose the new failed-open notification.

There is already bug 1157817 that covers the DevTools part.

Honza

Comment 44

[Hengyeow (:tanhengyeow)]

From Comment 41:

To explain: blocking doesn't happen on the parent process, but solely on the content process. nsCORSListenerProxy intercepts the OnStartRequest call and sets the reason on the load info prior to calling the outer listener, which is an XHR in case devtools net monitor is not open.
When devtools are open, it is exactly the same! Apparently, you are observing only the channel on the parent process where the blocking doesn't happen at all and therefor there can't be any reason exposed.
You must observe onStartRequest on the child process (only?) to catch the blocking reason.

Hi :ochameau

Do you have any idea how we can listen to child/content processes on the devtools side? I tried to find the logs (reproduced from Comment 36) in the browser toolbox as well as browser content toolbox but wasn't able to find any.

Comment 45

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: blocked-reason-logging.patch

I've been testing this using the following STRs

1. Apply patch from Honza Bambas (needs minor rebasing on top of m-c)
2. Apply the attached 'logging' patch. There are logs from both child/parent process. There is a log from _httpFailedOpening (child process) and _createNetworkEvent (parent process)
3. Load http://janodvarko.cz/tests/bugzilla/1493599/ & open the Network panel
4. Click the button on the page to generate blocked request.
5. There is no log from _httpFailedOpening
6. Try loading https://poc.miki.it/strict-dynamic-tests/
7. There are many logs from _httpFailedOpening, but requestBlockingReason is always set to 0

@mayhemer: is there anything I am doing wrong?

Honza

Comment 46

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Comment on attachment 9057473 [details] [diff] [review]
blocked-reason-logging.patch

wrong patch attached

Comment 47

[Honza Bambas (:mayhemer)]

c45

Comment 48

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: blocked-reason-logging.patch

Comment 49

[Jan Honza Odvarko [:Honza] (always need-info? me)]

@mayhemer: did you have time to look at my comment?

It would be great it we can land this in 68.

Honza

Comment 50

[Honza Bambas (:mayhemer)]

(In reply to Jan Honza Odvarko [:Honza] (always need-info? me) from comment #45)

Created attachment 9057473 [details] [diff] [review]
blocked-reason-logging.patch

I've been testing this using the following STRs

1. Apply patch from Honza Bambas (needs minor rebasing on top of m-c)
2. Apply the attached 'logging' patch. There are logs from both child/parent process. There is a log from _httpFailedOpening (child process) and _createNetworkEvent (parent process)
3. Load http://janodvarko.cz/tests/bugzilla/1493599/ & open the Network panel
4. Click the button on the page to generate blocked request.
5. There is no log from _httpFailedOpening

because the only request to https://www.google.com/ is not blocked.

6. Try loading https://poc.miki.it/strict-dynamic-tests/
7. There are many logs from _httpFailedOpening, but requestBlockingReason is always set to 0

you found another case: CSP policy. adding it now.

Comment 51

[Jan Honza Odvarko [:Honza] (always need-info? me)]

@mayhemer: Thanks for the update, but I am seeing conflicts when applying the patch on the latest m-c

Update: issue fixed on my side

Honza

Comment 52

[Jan Honza Odvarko [:Honza] (always need-info? me)]

The patch works for me, thanks :mayhemer for working on this!

Honza

Comment 53

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/8f9398c8c37d
Expose reason of security blocking on nsILoadInfo and add new http observer notification for failed asyncOpens, r=Honza,dragana

Comment 54

[Razvan Maries]

https://hg.mozilla.org/mozilla-central/rev/8f9398c8c37d

Comment 55

[Jan Honza Odvarko [:Honza] (always need-info? me)]

I can confirm that the new platform API introduced in this bug is working as expected.
Thanks,
Honza

Comment 56

[Cristian Fogel [:cfogel]]

Since it requires a custom build + based on the above comment updating the status of this issue.
A quick check with STR from comment 14 revealed no issues.