Closed Bug 1296628 Opened 8 years ago Closed 2 years ago

During initial startup the Marionette frame script (listener.js) is loaded multiple times

Categories

(Remote Protocol :: Marionette, defect, P3)

Product:
Remote Protocol
Component:
Marionette
Version:
Version 3
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INVALID

People

(Reporter: ato, Unassigned)

References

Details

As is exemplified in bug 1239552, frame scripts are loaded twice in different configurations of Firefox.  This can be tested by putting a log message in the registerSelf() function in testing/marionette/listener.js.

When a frame script such as testing/marionette/listener.js is loaded unconditionally, IPC message handlers are registered twice.  This sometimes causes race conditions when the driver calls down to the listener.

Setting the aAllowDelayedLoad argument to loadFrameScript to false, causing the loaded script to not be implicitly loaded into child frames, solves the issue.  We appear to be calling loadFrameScript unnecessarily whenever a new browser is detected; we probably only need to call it on top-level frames.

This means we end up loading the script twice: Once implicitly, because aAllowDelayedLoad, and once explicitly, through GeckoDriver#whenBrowserStarted.

I encourage reading bug 1239552 in detail.  It contains a lot of important diagnostic information to address this.
Could this be the reason why we see bug like bug 1294456?
Flags: needinfo?(ato)
(In reply to Andreas Tolfsen ‹:ato› from comment #0)
> Setting the aAllowDelayedLoad argument to loadFrameScript to false, causing
> the loaded script to not be implicitly loaded into child frames, solves the
> issue.  We appear to be calling loadFrameScript unnecessarily whenever a new
> browser is detected; we probably only need to call it on top-level frames.

Which one do you mean here? I assume the one in driver.js? If you do that Marionette will hang in test_about_pages.py. I tried various combinations also with the call to loadFrameScript in frame.js but without success. I think we still miss an important part here.

> This means we end up loading the script twice: Once implicitly, because
> aAllowDelayedLoad, and once explicitly, through
> GeckoDriver#whenBrowserStarted.

'whenBrowserStarted' would only apply to the initial start of the browser, right? But wouldn't obey opening of tabs or other windows later?
(In reply to Henrik Skupin (:whimboo) from comment #1)
> Could this be the reason why we see bug like bug 1294456?

I don’t think so.

> Which one do you mean here? I assume the one in driver.js? If you do that Marionette will hang in test_about_pages.py. I tried various combinations also with the call to loadFrameScript in frame.js but without success. I think we still miss an important part here.

Yes, I still think something is missing here.  Need to investigate closer.

> 'whenBrowserStarted' would only apply to the initial start of the browser, right? But wouldn't obey opening of tabs or other windows later?

Right.
Flags: needinfo?(ato)
I noticed this problem today while experimenting with global event listeners in listener.js. After some investigation I figured out that the problem here is identical to what we see in bug 1340099. Reason is that for each socket connection attempt during startup we instantiate the GeckoDriver class three times, and as such trying to register the listener multiple times. 

Interesting is that we flip CONTENT_LISTENER_PREF to true after the first load and never run the loadFrameScript code again for a new session. But for the seconds connection attempt the preference has been reset to false. As such we load the frame script again. That should not happen, and I'm not sure where it is getting reset.
Doh! When we delete the session we reset this preference. So I checked the loaded frame scripts via mm.getDelayedFrameScripts() and at least for the initial tab I see it only once. Lets see how this works for newly opened tabs afterward.
Ok, I think I figured out what the actual situation is. Here we have one tab open:

> 1488542157588	Marionette	TRACE	conn7 -> [0,12,"getWindowHandles",null]
> 1488542157589	Marionette	TRACE	conn7 <- [1,12,null,["2147483649"]]

Now lets opening a new tab...

> 1488543515932	Marionette	DEBUG	loaded listener.js
> ******** REGISTER SELF *********** 11
> setup global event listener

It means we now got a new instance of listener.js loaded, and for testing I setup global event listeners for page load events. The registering happened for the window with the outer window id 11.

> ******** REGISTER SELF *********** 2147483653

Hm, we register again but now for another outer window id. Why? See below...

> * global event listener for: 11
> ** event type: pagehide
> ** event originalTarget href: about:blank
> ** current frame href: about:blank
> ** content href: about:blank
> ** ready state: uninitialized

Initially about:blank was loaded in a non-remoteness tab. Now Firefox navigates away...

> ++DOMWINDOW == 13 (0x12e752c00) [pid = 49311] [serial = 13] [outer = 0x124d8e400]
> * global event listener for: 2147483653
> ** event type: pageshow
> ** event originalTarget href: about:blank
> ** current frame href: about:blank
> ** content href: about:blank
> ** ready state: uninitialized

... and loads about:blank again but in a remoteness tab. Because of that the other register self call for 2147483653 is happening. And all this is happening due to the remoteness change, which I think is fine. The order of the output is still mixed-up but I would assume this is due to stdout caching.

I'm not sure what will happen when we use a real unique ID for content windows as to be done on bug 1311041. In that case we will register the listeners with the same ID again. How would that affect the driver calling down to the listener? Would it be happier now with having the same listener IDs for the same tab?
No longer blocks: 1294456
Flags: needinfo?(ato)
Just to add... the reload of about:blank after opening a new tab is expected due to bug 1261842.
(In reply to Henrik Skupin (:whimboo) from comment #6)

> I'm not sure what will happen when we use a real unique ID for content
> windows as to be done on bug 1311041. In that case we will register the
> listeners with the same ID again. How would that affect the driver calling
> down to the listener? Would it be happier now with having the same listener
> IDs for the same tab?

That sounds like a distinct possibility.  


We probably keep around duplicate entries in this.browsers and this.wins since GeckoDriver#addBrowser uses getOuterWindowId, and a window’s outerWindowID changes when a remoteness change occurs.  But I don’t think we rely on the ID we attribute to the window when we call mm.loadFrameScript?  GeckoDriver#whenBrowserStarted appears to be called indiscriminately when a session is started.

> ... and loads about:blank again but in a remoteness tab. Because of that the other register self call for 2147483653 is happening. And all this is happening due to the remoteness change, which I think is fine.

Yes, it is correct behaviour to load the frame script again when a browser becomes remote.  As far as I’m aware it is a fresh browser without the frame script we installed into the originally non-remote browser, and has lost all its state.
Flags: needinfo?(ato)
(In reply to Andreas Tolfsen ‹:ato› from comment #8)
> We probably keep around duplicate entries in this.browsers and this.wins
> since GeckoDriver#addBrowser uses getOuterWindowId, and a window’s
> outerWindowID changes when a remoteness change occurs.  But I don’t think we
> rely on the ID we attribute to the window when we call mm.loadFrameScript? 

I still don't understand all the communication via the proxy yet so it's hard for me to tell. But regarding the remoteness change and left-over entries in browsers and wins I don't see a problem. The remoteness is part of the tab but not the windows and registered browsers. But for tabs I wonder if we can get around this with code like that:

https://dxr.mozilla.org/mozilla-central/rev/8d026c60151005ad942e3d4389318fe28a0c8c54/browser/components/sessionstore/test/browser_remoteness_flip_on_restore.js#144-168

Maybe we should add this info to bug 1311041 too.

> GeckoDriver#whenBrowserStarted appears to be called indiscriminately when a
> session is started.

It's doing that because we wouldn't have any framescript loaded yet. And we have to instruct the application to automatically load the framescript for any new tab created or remoteness switch. We remove them all in deleteSession().

> Yes, it is correct behaviour to load the frame script again when a browser
> becomes remote.  As far as I’m aware it is a fresh browser without the frame
> script we installed into the originally non-remote browser, and has lost all
> its state.

Correct.

Regarding this bug can you please tell me what the underlying issue was? The multiple load during startup? If yet, we should close this bug as dupe of bug 1340099 or at least mark it as dependency.
Flags: needinfo?(ato)
> Regarding this bug can you please tell me what the underlying issue
> was? The multiple load during startup? If yet, we should close this
> bug as dupe of bug 1340099 or at least mark it as dependency.

This bug was never fixed, so we never found the underlying issue.
Flags: needinfo?(ato)
(In reply to Andreas Tolfsen ‹:ato› from comment #10)
> This bug was never fixed, so we never found the underlying issue.

Well, as layed out above I do not see a bug here. During startup this is clearly related to bug 1340099 and if you meat that when filing the bug we should dupe or mark dependent. For the other case when a remoteness change is happening, it is expected.

Is there another case when you are seeing this problem and which I missed?
Flags: needinfo?(ato)
I’m willing to accept the theory it is bug 1340099 that is causing this.
Flags: needinfo?(ato)
Ok, so updating the summary of the bug to make it clearer which loading we are actually referring to here.
Depends on: 1340099
Summary: Marionette frame scripts are loaded twice → During initialization the Marionette frame script (listener.js) is loaded multiple times
Summary: During initialization the Marionette frame script (listener.js) is loaded multiple times → During initial startup the Marionette frame script (listener.js) is loaded multiple times
Priority: -- → P3

Framescripts are no more used since we switched to the JSWindowActor API to be compatible with Fission.

Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INVALID
Product: Testing → Remote Protocol
You need to log in before you can comment on or make changes to this bug.