1887852 - sendBeacon not working when used inside an unloading iframe

Status: RESOLVED FIXED

(DevTools :: Netmonitor, defect, P2)

Description

[esroyo]

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

Steps to reproduce:

1 - Visit https://esroyo.github.io/iframe-postmessage-lost/
2 - Do not unfocus the tab while following this steps
3 - Open Inspector - Network
4 - Open Inspector - Console (split with Network) by pressing ESC
5 - Click on "Open an iframe" button
6 - Click on "Close iframe" button

Context:

• The iframe has a listener for the event "visibilitychange".
• When closing the iframe as a consequence of the button click, this event triggers.
• In the callback of that event, which is correctly executed, we are using three APIs: console.log, postMessage and navigator.sendBeacon.
• The browser executes all of them without errors.

      console.log('[iframe] I have been hidden.');
      console.log('[iframe] Message my last words...');
      parent.postMessage({ msg: 'He has kill\'d me, mother: Run away, I pray you!' }, '*');
      console.log('[iframe] Beacon too:', navigator.sendBeacon('https://www.thehotelsnetwork.com/agent/probe'));

Actual results:

Unexpected results:

• The console.log calls made in the iframe did not effectively end up showing anything in the console.
• The navigator.sendBeacon call did not send the request, although that API should specifically guarantee delivery.
• The postMessage call does work as expected in this simple example. However I have been in more complex real-world situations on which that also didn't work.

Expected results:

Expected results:

• The console.log calls made in the iframe should have been shown in the console as:

[iframe] I have been hidden.
[iframe] Message my last words...
[iframe] Beacon too: true

• The navigator.sendBeacon call should have send a beacon request to the example endpoint ( https://www.thehotelsnetwork.com/agent/probe ) and that should be visible in the Inspector - Network.

• The postMessage call should enqueue a "message" event in the parent frame. That happens correctly in this simple example.

In summary it seems as if the child frame were being destroyed aggressively by the browser. This destruction of the frame, seems to prevent certain APIs to finish their work. Specially sendBeacon seems to be the worse case as it should guarantee delivery.

Comment 1

[Ina Popescu, Desktop QA]

I've reproduced this issue on both Windows 10 x64 and Ubuntu 22.04 using Nightly 126.0a1 and Firefox 124.0.2 versions, following the STR from Comment 0. Therefore, I'm setting the component accordingly. If this isn't the right component, please feel free to change it to a more suitable one.

Comment 2

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

Moving to a more general DOM category since I think this has to do with iframe teardown, not the networking part. Perhaps asuth can look at it?

Comment 3

[Andrew Sutherland [:asuth] (he/him)]

tl;dr: This may just be a devtools artifact but someone should confirm we have sjs test coverage for this case; it looks like we may not have such coverage.

I tried to reproduce this under rr but ran into rr problems (see the mozilla pernosco channel), so my analysis is speculative, and unfortunately it's not trivial to find the visibilitychange event genesis (is it coming from the nsIFrame somehow?) in searchfox as-is.

The repro is based on trying to invoke sendBeacon during the visibilitychange event fired by the removal of the iframe which, when completed, will make the iframe not fully active and generally cause its own global to be dead (which has implications on callbacks firing in that global). The firing of the event by the spec should be early enough that the global is sufficiently alive for all purposes as long as it doesn't yield control flow.

I don't see any obvious test coverage for "call sendBeacon during visibilitychange that was added to the iframe global from within the iframe global" case in our tree, but searchfox as-is doesn't make that super easy to determine; here is an example of a removal in a beacon test that involves an sjs for verification but the beacon is sent on load and the remove triggered after the beacon call is sent rather than happening during the visibilitychange event. iframe-unload.html seems to be the relevant WPT on iframe unloading triggering visibilitychange but it looks like its listener is only added outside of the global.

It's quite possible that devtools' network monitor might have trouble in this case, as If I run this under the profiler I see the expected request to https://www.thehotelsnetwork.com/agent/probe. We do have some devtools sendBeacon coverage but it also does not seem to be trying to capture things during a visibilitychange event triggered by iframe removal.

In terms of where the bug should live, this definitely goes in DOM: Networking. mozilla::dom::Navigator::SendBeaconInternal definitely creates its own load group I believe to avoid being impacted by the call to LoadGroup::CancelWithReason in nsDocLoader::Stop, so I don't think there's anything unexpected going on from iframes here since the global should be alive at the time of the call and the load group should not be interfered with. That said, as Domenic references at https://github.com/w3c/beacon/issues/79 the spec for sendBeacon really should be further refined, as there could be fetch nuances that could come into play.

Comment 4

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

nchevobbe -- can you take a look at comment 3? Andrew had some questions about devtools and this and what tests we have. Thanks!

Comment 5

[Nicolas Chevobbe [:nchevobbe]]

I can reproduce the issue: I'm not seeing the console.logs nor the network request to thehotelsnetwork.com . If I add a breakpoint in the iframe visibilitychange handler, the debugger doesn't pause.
What probably occurs is that we're destroying the document target before those "events" are happening, which is why they don't appear.
This looks quite similar to the story about pausing on unload, which we fixed in Bug 1569775.
Starting from that, I wanted to check that unload was handled properly for the iframe, and forked the reporter page: https://ffx-devtools-late-visibilitychange.glitch.me/
There, the iframe has a unload event listener, on top of the visibilitychange one. In the handlers, I added items in localStorage, to assert that the handlers are indeed called, and see the order in which they are called.
Creating an iframe and then removing it, going to the storage panel, you should see 2 items, and see that visibilitychange seems to be fired before unload.
But , adding a breakpoint in the unload handler, or using a unload event listener doesn't work when closing the iframe, so we're clearly missing tests for this I think.

Alex, do you remember if we knew about this limitation for iframes? Not sure why this behaves differently from top level targets

Comment 6

[Sunil Mayya]

Thanks esroyo for opening the bug report.
I reproduced the issue locally and don't see the sendBeacon request in devtools.
However, I could see that we are sending a POST request in the networking logs.

[Parent 61814: Main Thread]: E/nsHttp http request [                                                                              
[Parent 61814: Main Thread]: E/nsHttp   POST /agent/probe HTTP/1.1                                                      
[Parent 61814: Main Thread]: E/nsHttp   Host: www.thehotelsnetwork.com                                                                                                                           
[Parent 61814: Main Thread]: E/nsHttp   User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:126.0) Gecko/20100101 Firefox/126.0      
[Parent 61814: Main Thread]: E/nsHttp   Accept: */*                                                         
[Parent 61814: Main Thread]: E/nsHttp   Accept-Language: en-US,en;q=0.5                          
[Parent 61814: Main Thread]: E/nsHttp   Accept-Encoding: gzip, deflate, br                         
[Parent 61814: Main Thread]: E/nsHttp   Origin: https://esroyo.github.io            
[Parent 61814: Main Thread]: E/nsHttp   Connection: keep-alive                       
[Parent 61814: Main Thread]: E/nsHttp   Referer: https://esroyo.github.io/                                 
[Parent 61814: Main Thread]: E/nsHttp   Sec-Fetch-Dest: empty                 
[Parent 61814: Main Thread]: E/nsHttp   Sec-Fetch-Mode: no-cors                                                            
[Parent 61814: Main Thread]: E/nsHttp   Sec-Fetch-Site: cross-site                          
[Parent 61814: Main Thread]: E/nsHttp   Priority: u=6                                               
[Parent 61814: Main Thread]: E/nsHttp   Content-Length: 0                                   
[Parent 61814: Main Thread]: E/nsHttp•••                                                                                                                                                           
[Parent 61814: Main Thread]: E/nsHttp ]   

Could you please confirm if the server has received the data?
I suspect the problem here is just that the request is not visible in the Devtools where as SendBeacon is working as expected?
Kindly confirm.

Comment 7

[Alexandre Poirot [:ochameau]]

Attachment: Bug 1887852 - [devtools] Only observe children docshell in browser toolbox and web extension targets.

The docshell should be observed only when "EveryFrameTarget" is off for the WindowGlobal Target Actor.
i.e. when followWindowGlobalLifeCycle is false and the target actor manages more than one WindowGlobal.

This docshell observing was destroying the target actor too early and was redundant with the code
managing WindowGlobal target actor lifecycle in the WindowGlobal Target Watcher class.

Comment 8

[Alexandre Poirot [:ochameau]]

(In reply to Nicolas Chevobbe [:nchevobbe] from comment #5)

Alex, do you remember if we knew about this limitation for iframes? Not sure why this behaves differently from top level targets

I wasn't aware of any limitation, but you identified one.
Thanks a lot for the test case, it was really useful!

There was at least this thing in WindowGlobalTarget Actor class, which was destroying itself too early and prevented to hit the late breakpoints.
With this patch, you can see the debugger pause, but for some reason, the variable preview on hover is broken (while inline preview works).
So this simple fix isn't enough to have everything working. I'll keep investigating.

Comment 9

[esroyo]

(In reply to Sunil Mayya from comment #6)

I reproduced the issue locally and don't see the sendBeacon request in devtools.
However, I could see that we are sending a POST request in the networking logs.
[...]
Could you please confirm if the server has received the data?
I suspect the problem here is just that the request is not visible in the Devtools where as SendBeacon is working as expected?
Hi Sunil Mayya, you are absolutely right. The request is successfully sent indeed, but not shown in the devtools.
I have made an second version of the reproduction example site: https://esroyo.github.io/iframe-postmessage-lost/v2/
In this new version, the parent top window uses an EventSource to display a message when the sendBeacon request arrives to the server.
Thanks all for taking the time to look into the issue, It is much appreciated.

Comment 10

[esroyo]

(In reply to Sunil Mayya from comment #6)

I reproduced the issue locally and don't see the sendBeacon request in devtools.
However, I could see that we are sending a POST request in the networking logs.
[...]
Could you please confirm if the server has received the data?
I suspect the problem here is just that the request is not visible in the Devtools where as SendBeacon is working as expected?

(Sorry for the bad formatting in my last comment, I can't seem to edit it)

Hi Sunil Mayya, you are absolutely right. The request is successfully sent indeed, but not shown in the devtools.
I have made an second version of the reproduction example site: https://esroyo.github.io/iframe-postmessage-lost/v2/
In this new version, the parent top window uses an EventSource to display a message when the sendBeacon request arrives to the server.
Thanks all for taking the time to look into the issue, It is much appreciated.

Comment 11

[Alexandre Poirot [:ochameau]]

Attachment: Bug 1887852 - [devtools] Avoid throwing on request done late during document unload.

Comment 12

[Alexandre Poirot [:ochameau]]

Nicolas highlighted breakpoints issues in comment 5 which should be addressed in a distinct bug as it involves some significant changes:
https://phabricator.services.mozilla.com/D207801

But the missing beacon request actually relates to a much simpler fix:
https://phabricator.services.mozilla.com/D207967

Thanks a lot esroyo for your test page, it was really handy to investigate this issue!

Comment 13

[Phabricator Automation]

Comment on attachment 9397261 [details]
Bug 1887852 - [devtools] Only observe children docshell in browser toolbox and web extension targets.

Revision D207801 was moved to bug 1892411. Setting attachment 9397261 [details] to obsolete.

Comment 14

[esroyo]

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

I'm glad It was useful to unveil those sneaky bugs. Great work @ochameau 👏 Thanks a lot for your assistance.

Comment 15

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/e7a9eff09994
[devtools] Avoid throwing on request done late during document unload. r=devtools-reviewers,nchevobbe

Comment 16

[Cosmin Sabou [:CosminS]]

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