909129 - Marionette leaking imported scripts

Status: RESOLVED FIXED

(Remote Protocol :: Marionette, defect)

Description

[Jonathan Griffin (:jgriffin)]

When we call import_script, we write the contents of the imported script to a file; for B2G we use /data/local/tmp/marionettescriptchrome.  Subsequent imports get appended to this file.

But, we never delete this file, so a test that imports the same script over the course of many tests causes the size of this file to bloat.

We should delete this file on session end.

Comment 1

[Jonathan Griffin (:jgriffin)]

Actually, this isn't a complete solution.  We should probably compute the hash of each imported script (https://developer.mozilla.org/en-US/docs/XPCOM_Interface_Reference/nsICryptoHash#Computing_the_Hash_of_a_File) in order to avoid saving duplicate copies.

Comment 3

[Malini Das [:mdas] - Away, not checking bugmail]

Attachment: don't import duplicates and add ability to clear imported scripts

jgriffin's on pto, can you take this review?

This patch ensures that we don't append the same script to the import script file (if import_script is called on the same file), allows you to have separate scripts accessible in either chrome or content (before it was just one script) and also allows you to clear imported scripts in their respective contexts.

Comment 4

[David Burns :automatedtester]

Comment on attachment 810665 [details] [diff] [review]
don't import duplicates and add ability to clear imported scripts

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

looks good other than the tiny nits :)

::: testing/marionette/client/marionette/tests/unit/test_import_script.py
@@ +26,5 @@
> +          if (FileUtils == undefined) {
> +            checkTimer.initWithCallback(f, 100, Components.interfaces.nsITimer.TYPE_ONE_SHOT);
> +            return;
> +          }
> +          let importedScripts = FileUtils.getFile('TmpD', ['marionetteContentScripts']); 

nit: White space at end of line

@@ +44,5 @@
> +          if (FileUtils == undefined) {
> +            checkTimer.initWithCallback(f, 100, Components.interfaces.nsITimer.TYPE_ONE_SHOT);
> +            return;
> +          }
> +          let importedScripts = FileUtils.getFile('TmpD', ['marionetteContentScripts']); 

nit: white space at the end of line

Comment 5

[Malini Das [:mdas] - Away, not checking bugmail]

landed in m-i:

https://hg.mozilla.org/integration/mozilla-inbound/rev/961256d21b8e

Comment 6

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

Backed out in http://hg.mozilla.org/integration/mozilla-inbound/rev/d110fa56f680

for multiple Mnw failures like "assignment to undeclared variable MARIONETTE_TIMEOUT": https://tbpl.mozilla.org/php/getParsedLog.php?id=28474530&tree=Mozilla-Inbound

Comment 7

[Malini Das [:mdas] - Away, not checking bugmail]

Trying a new patch:

https://tbpl.mozilla.org/?tree=Try&rev=27e996c98726

Comment 8

[Malini Das [:mdas] - Away, not checking bugmail]

Nevermind, forgot to run non-webapi tests locally, must fix a few more issues.

Comment 9

[Malini Das [:mdas] - Away, not checking bugmail]

Attachment: don't import duplicates and add ability to clear imported scripts v2.0

The original exception handling wasn't very good, this improves it and fixes failures. It's looking good on try:

https://tbpl.mozilla.org/?tree=Try&rev=d051ddf78a67

Comment 10

[David Burns :automatedtester]

Comment on attachment 812938 [details] [diff] [review]
don't import duplicates and add ability to clear imported scripts v2.0

looks good just some nits I missed the last time.



>
>+    def check_file_exists(self):
>+        return self.marionette.execute_script("""
>+        let FileUtils = SpecialPowers.Cu.import("resource://gre/modules/FileUtils.jsm").FileUtils;
>+        let importedScripts = FileUtils.getFile('TmpD', ['marionetteContentScripts']); 
>+        return importedScripts.exists();
>+        """, special_powers=True)
>+
>+    def get_file_size(self):
>+        return self.marionette.execute_script("""
>+        let FileUtils = SpecialPowers.Cu.import("resource://gre/modules/FileUtils.jsm").FileUtils;
>+        let importedScripts = FileUtils.getFile('TmpD', ['marionetteContentScripts']); 
>+        return importedScripts.fileSize;
>+        """, special_powers=True)

Nit: Can you indent the JS so that its easier to skim over the file and see the differences for the tests above

> class TestImportScriptChrome(TestImportScript):
>     def setUp(self):
>         MarionetteTestCase.setUp(self)
>+        self.marionette.set_script_timeout(30000)
>         self.marionette.set_context("chrome")
>+
>+    def clear_other_context(self):
>+        self.marionette.set_context("content")
>+        self.marionette.clear_imported_scripts()
>+        self.marionette.set_context("chrome")
>+
>+    def check_file_exists(self):
>+        return self.marionette.execute_async_script("""
>+        Components.utils.import("resource://gre/modules/FileUtils.jsm");
>+        let checkTimer = Components.classes["@mozilla.org/timer;1"].createInstance(Components.interfaces.nsITimer);
>+        let f = function() {
>+          if (typeof FileUtils === 'undefined') {
>+            checkTimer.initWithCallback(f, 100, Components.interfaces.nsITimer.TYPE_ONE_SHOT);
>+            return;
>+          }
>+          let importedScripts = FileUtils.getFile('TmpD', ['marionetteChromeScripts']); 
>+          marionetteScriptFinished(importedScripts.exists());
>+        };
>+        checkTimer.initWithCallback(f, 100, Components.interfaces.nsITimer.TYPE_ONE_SHOT);
>+        """)
>+    def get_file_size(self):
>+        return self.marionette.execute_async_script("""
>+        Components.utils.import("resource://gre/modules/FileUtils.jsm");
>+        let checkTimer = Components.classes["@mozilla.org/timer;1"].createInstance(Components.interfaces.nsITimer);
>+        let f = function() {
>+          if (typeof FileUtils === 'undefined') {
>+            checkTimer.initWithCallback(f, 100, Components.interfaces.nsITimer.TYPE_ONE_SHOT);
>+            return;
>+          }
>+          let importedScripts = FileUtils.getFile('TmpD', ['marionetteChromeScripts']); 
>+          marionetteScriptFinished(importedScripts.fileSize);
>+        };
>+        checkTimer.initWithCallback(f, 100, Components.interfaces.nsITimer.TYPE_ONE_SHOT);
>+        """)
>+

Nit: indent again


>    * Marionette API:
>    *
>    * All methods implementing a command from the client should create a
>@@ -1933,7 +1944,13 @@
> 
>       // if there is only 1 window left, delete the session
>       if (numOpenWindows === 1){
>-        this.sessionTearDown();
>+        try {
>+          this.sessionTearDown();
>+        }
>+        catch (e) {
>+          this.sendError("Could not clear session", 500, e.name + ": " + e.message, command_id);
>+          return;
>+        }
>         this.sendOk(command_id);
>         return;
>       }
>@@ -1987,23 +2004,23 @@
>     this.switchToGlobalMessageManager();
>     // reset frame to the top-most frame
>     this.curFrame = null;
>-    if (this.mainFrame) {
>-      this.mainFrame.focus();

More curiousity than anything, why are we no longer focusing on the main frame?

Comment 11

[Malini Das [:mdas] - Away, not checking bugmail]

(In reply to David Burns :automatedtester from comment #10)
> Comment on attachment 812938 [details] [diff] [review]
> don't import duplicates and add ability to clear imported scripts v2.0
> 
> looks good just some nits I missed the last time.
> 
> 
> 
> >
> >+    def check_file_exists(self):
> >+        return self.marionette.execute_script("""
> >+        let FileUtils = SpecialPowers.Cu.import("resource://gre/modules/FileUtils.jsm").FileUtils;
> >+        let importedScripts = FileUtils.getFile('TmpD', ['marionetteContentScripts']); 
> >+        return importedScripts.exists();
> >+        """, special_powers=True)
> >+
> >+    def get_file_size(self):
> >+        return self.marionette.execute_script("""
> >+        let FileUtils = SpecialPowers.Cu.import("resource://gre/modules/FileUtils.jsm").FileUtils;
> >+        let importedScripts = FileUtils.getFile('TmpD', ['marionetteContentScripts']); 
> >+        return importedScripts.fileSize;
> >+        """, special_powers=True)
> 
> Nit: Can you indent the JS so that its easier to skim over the file and see
> the differences for the tests above

Do you mean like:
    def get_file_size(self):
        return self.marionette.execute_script("""
          let FileUtils = SpecialPowers.Cu.import("resource://gre/modules/FileUtils.jsm").FileUtils;
          let importedScripts = FileUtils.getFile('TmpD', ['marionetteContentScripts']); 
          return importedScripts.fileSize;
        """, special_powers=True)

Or something else?
> 
> More curiousity than anything, why are we no longer focusing on the main
> frame?

I was overzealous with deleting lines:) I will restore that change when I land it.

Comment 12

[Malini Das [:mdas] - Away, not checking bugmail]

fixed and pushed to m-i:
https://hg.mozilla.org/integration/mozilla-inbound/rev/8ecb68f17618

Comment 13

[Carsten Book [:Tomcat]]

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

Comment 14

[Ed Morley [:emorley]]

Backed out for causing bug 924959 pretty frequently:
remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/c70064cbf84c

Comment 16

[Ed Morley [:emorley]]

And also test_import_script.TestImportScriptChrome.test_import_script_and_clear_in_chrome:
https://tbpl.mozilla.org/php/getParsedLog.php?id=28880369&tree=Mozilla-Central

Comment 17

[Jonathan Griffin (:jgriffin)]

The tests that are failing timeout when executing something like this:

09:02:34     INFO -  10-09 15:41:59.022    45    45 I Gecko   : 1381333318999	Marionette	DEBUG	Got request: executeWithCallback, data: {"specialPowers":false,"scriptTimeout":null,"newSandbox":true,"args":[],"value":"\n          Components.utils.import(\"resource://gre/modules/FileUtils.jsm\");\n          let checkTimer = Components.classes[\"@mozilla.org/timer;1\"].createInstance(Components.interfaces.nsITimer);\n          let f = function() {\n            if (typeof FileUtils === 'undefined') {\n              checkTimer.initWithCallback(f, 100, Components.interfaces.nsITimer.TYPE_ONE_SHOT);\n              return;\n            }\n            let importedScripts = FileUtils.getFile('TmpD', ['marionetteChromeScripts']); \n            marionetteScriptFinished(importedScripts.fileSize);\n          };\n          checkTimer.initWithCallback(f, 100, Components.interfaces.nsITimer.TYPE_ONE_SHOT);\n        ","filename":"test_import_script.py","to":"0","session":"6-b2g","line":157,"type":"executeAsyncScript"}, id: {846bc028-f37d-46e1-ae54-8490f07c9e92}

Why are we doing this strange "if (typeof FileUtils === 'undefined')" logic?  If FileUtils is undefined sometimes after Cu.import FileUtils.jsm, I think it's a bug we should file instead of trying to work around.

Comment 18

[Malini Das [:mdas] - Away, not checking bugmail]

(In reply to Jonathan Griffin (:jgriffin) from comment #17)
> The tests that are failing timeout when executing something like this:
> 
> 09:02:34     INFO -  10-09 15:41:59.022    45    45 I Gecko   :
> 1381333318999	Marionette	DEBUG	Got request: executeWithCallback, data:
> {"specialPowers":false,"scriptTimeout":null,"newSandbox":true,"args":[],
> "value":"\n         
> Components.utils.import(\"resource://gre/modules/FileUtils.jsm\");\n        
> let checkTimer =
> Components.classes[\"@mozilla.org/timer;1\"].createInstance(Components.
> interfaces.nsITimer);\n          let f = function() {\n            if
> (typeof FileUtils === 'undefined') {\n             
> checkTimer.initWithCallback(f, 100,
> Components.interfaces.nsITimer.TYPE_ONE_SHOT);\n              return;\n     
> }\n            let importedScripts = FileUtils.getFile('TmpD',
> ['marionetteChromeScripts']); \n           
> marionetteScriptFinished(importedScripts.fileSize);\n          };\n         
> checkTimer.initWithCallback(f, 100,
> Components.interfaces.nsITimer.TYPE_ONE_SHOT);\n       
> ","filename":"test_import_script.py","to":"0","session":"6-b2g","line":157,
> "type":"executeAsyncScript"}, id: {846bc028-f37d-46e1-ae54-8490f07c9e92}
> 
> Why are we doing this strange "if (typeof FileUtils === 'undefined')" logic?
> If FileUtils is undefined sometimes after Cu.import FileUtils.jsm, I think
> it's a bug we should file instead of trying to work around.

Yes, that makes more sense. I'm having trouble getting a repeatable test case right now though. I'll have to see if this problem is gone, or file a bug otherwise and block that test path.

Comment 19

[Malini Das [:mdas] - Away, not checking bugmail]

(In reply to Malini Das [:mdas] from comment #18)
> (In reply to Jonathan Griffin (:jgriffin) from comment #17)
> > The tests that are failing timeout when executing something like this:
> > 
> > 09:02:34     INFO -  10-09 15:41:59.022    45    45 I Gecko   :
> > 1381333318999	Marionette	DEBUG	Got request: executeWithCallback, data:
> > {"specialPowers":false,"scriptTimeout":null,"newSandbox":true,"args":[],
> > "value":"\n         
> > Components.utils.import(\"resource://gre/modules/FileUtils.jsm\");\n        
> > let checkTimer =
> > Components.classes[\"@mozilla.org/timer;1\"].createInstance(Components.
> > interfaces.nsITimer);\n          let f = function() {\n            if
> > (typeof FileUtils === 'undefined') {\n             
> > checkTimer.initWithCallback(f, 100,
> > Components.interfaces.nsITimer.TYPE_ONE_SHOT);\n              return;\n     
> > }\n            let importedScripts = FileUtils.getFile('TmpD',
> > ['marionetteChromeScripts']); \n           
> > marionetteScriptFinished(importedScripts.fileSize);\n          };\n         
> > checkTimer.initWithCallback(f, 100,
> > Components.interfaces.nsITimer.TYPE_ONE_SHOT);\n       
> > ","filename":"test_import_script.py","to":"0","session":"6-b2g","line":157,
> > "type":"executeAsyncScript"}, id: {846bc028-f37d-46e1-ae54-8490f07c9e92}
> > 
> > Why are we doing this strange "if (typeof FileUtils === 'undefined')" logic?
> > If FileUtils is undefined sometimes after Cu.import FileUtils.jsm, I think
> > it's a bug we should file instead of trying to work around.
> 
> Yes, that makes more sense. I'm having trouble getting a repeatable test
> case right now though. I'll have to see if this problem is gone, or file a
> bug otherwise and block that test path.

As an update, I haven't been able to reproduce the FileUtils error on either Firefox or on FXOS, so I'm going to just get rid of that load checker.

I'm currently building an emulator to repro the error that caused the backout.

Comment 20

[Malini Das [:mdas] - Away, not checking bugmail]

Attachment: fix leaking files

I've updated the patch, and it passes repeatedly on browser and in emulator. Try results are coming in green : https://tbpl.mozilla.org/?tree=Try&rev=a265e0b0cf32.

I'm using the "Cu.import into an empty scope" trick here since getting a repeatable test case has proven pretty fruitless, and this is our current workaround.

Comment 21

[Jonathan Griffin (:jgriffin)]

Comment on attachment 819876 [details] [diff] [review]
fix leaking files

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

lgtm

Comment 22

[Malini Das [:mdas] - Away, not checking bugmail]

thanks, landed in m-i:

https://hg.mozilla.org/integration/mozilla-inbound/rev/4334336fae4d

Comment 23

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/4334336fae4d

Comment 24

[Malini Das [:mdas] - Away, not checking bugmail]

pushed to aurora so we won't bog down testing this branch:
https://hg.mozilla.org/releases/mozilla-aurora/rev/ec442fac77c5

Comment 25

[Carsten Book [:Tomcat]]

had to backout this push to aurora the failure rate onMnw has gone from 5-10% failure rate to more like 30%. Failures stuff like 

https://tbpl.mozilla.org/php/getParsedLog.php?id=29579156&tree=Mozilla-Aurora

Comment 26

[Jonathan Griffin (:jgriffin)]

Hopefully it sticks this time:  https://hg.mozilla.org/releases/mozilla-b2g26_v1_2/rev/784db1b5712b