995463 - Better handle changed preferences during tests

Status: NEW

(Testing :: Mochitest, defect)

Description

[Gregory Szorc [:gps]]

Conceptually, each mochitest file/test is standalone. You should be able to run it in isolation and get the same result as if you ran it as part of a series. You should be able to run tests in random order and get the same results.

Unfortunately, many tests don't do this. They modify global state and leave modified state unbeknownst to the unfortunate tests that run after them.

As long as we run tests in the same process, we'll always have to deal with mutated global state. However, that doesn't mean we can't help keep the problem in check.

I propose one of the following:

a) Failing tests if they modify a preference but don't reset the preference before they are finished

b) Have the test harness watch for changed preferences and revert state after each test file automatically.

"b" is certainly easier on developers (it allows us to be lazy w.r.t. test cleanup). The downside is it might be too easy. Do we want to require test authors to know about which preferences they are modifying? But what if some other component a test is utilizing now starts mutating a new preference. Do all tests using that component need to be updated to clear that other component's pref state? That would seem annoying.

I think "a" is unreasonable and we should pursue "b".

Is there a good reason why we shouldn't do this? The only blocker I can think of is performance. We'll need to take a snapshot of all the preferences at the beginning of the test suite and reconcile differences at the end of each test. This can be made more efficient with a prefs observer. But considering people can waste hours tracking down failures due to a subtle pref flip, I think a slight performance hit (if there is even one) is justified.

Comment 1

[Gregory Szorc [:gps]]

Attachment: Reset changed preferences after each browser chrome test

Preferences are global state that often get mutated as part of a test.
Many tests mutate preferences but don't revert those changes. This means
tests can interfere with each other by leaving unexpected changes
around. This can lead to unexpected failures when running tests in
isolation or when test order is randomized (tests silently depend
on the execution of another test).

This patch attempts to address the issue of cross-test preference
contamination for browser chrome tests. The JavaScript test runner now
takes a snapshot of preferences before execution and restores that
snapshot after each test file has completed. Preferences that have been
created are deleted. Preferences that have been deleted are restored.
Preferenced that have been mutated are reverted.

---

This patch still needs a test. And, it will likely require fixing a
bunch of tests. I will be shocked if we don't have a handful of bc tests
fail.

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

Comment 2

[Gregory Szorc [:gps]]

Here's a slightly better patch: https://tbpl.mozilla.org/?tree=Try&rev=0051db0f7431

Comment 3

[:Gavin Sharp [email: [e-mail]]]

There might be valid reasons for prefs to change during a test that aren't related to the test itself, and indiscriminately force-resetting them could cause trouble. Interesting to see what the try results say!

Comment 4

[Gregory Szorc [:gps]]

Yeah, I could see a few services that store state in preferences getting confused, especially if they are initializing while tests are executing. Of course, that's also a bug: we should ensure all services are initialized before running tests. We currently don't have an easy way to do that - a handful of services run on timers after session restore.

Chalk up another reason to write a more robust service management framework.

Comment 5

[Gregory Szorc [:gps]]

And we have our first failure!

browser_crash_detection.js is failing when attempting to retrieve the unset pref toolkit.startup.last_success. The log at https://tbpl.mozilla.org/php/getParsedLog.php?id=37666507&tree=Try&full=1 shows this pref being reset during a much earlier test. Upon investigation, the routine that sets the pref (http://dxr.mozilla.org/mozilla-central/source/toolkit/components/startup/nsAppStartup.cpp#904) appears to be called 30s after startup.

I have issues with the implementation of the test. That 30/35s delay is wasting a lot of resources! I'll file some bugs.

We may have to hard-code a reset exception for this one pref.

Comment 6

[Ryan VanderMeulen [:RyanVM]]

I don't think it matters much at the moment because you're getting plenty of fodder from the existing runs, but I'll point out that the devtools tests aren't running on Try until bug 995529 is fixed (hopefully Monday).

Comment 7

[:Gavin Sharp [email: [e-mail]]]

(In reply to Gregory Szorc [:gps] from comment #4)
> Yeah, I could see a few services that store state in preferences getting
> confused, especially if they are initializing while tests are executing. Of
> course, that's also a bug: we should ensure all services are initialized
> before running tests.

I don't think that's realistic - we need to be able to have lazily instantiated services, in general, and I don't see a good reason why we should change that behavior in our test runs.

Comment 8

[Gregory Szorc [:gps]]

I'm not actively working on this. I still think it warrants some investigation.

Comment 9

[Gregory Szorc [:gps]]

Adding to Firefox backlog because not having this leads to inefficiency and increased test failure rate.

Test authors waste time writing code to reset preferences after tests run. That's inefficient.

When tests forget to reset prefs, those pref changes pollute subsequent tests in the process lifetime. This introduces hidden dependencies between tests. It is not infrequent for tests to move around to different batches when they are executed in automation. When they move, these implicit dependencies may cause tests to fail for seemingly no reason.

The status quo is an unnecessary time sink on many people and I'm asking it to be added to the Firefox Desktop Iteration because the Firefox Desktop group is the group most impacted by this legacy approach to testing.

Comment 10

[:Gavin Sharp [email: [e-mail]]]

gps: you can (now) add bugs to the backlog yourself (getting them prioritized is a different matter, need to raise it with desktop leadership)

Comment 11

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 12

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 13

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8564342 [details] [diff] [review]
prefchanges.patch

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

a handful of smaller issues.  code quality is important!

keep in mind this is reporting on preferences changed, resetting them could be confusing since the value might not be valid or useful to reset it to.  If everything uses pushPrefEnv, then we could ignore prefs changed there and report on what changes outside of that.

::: testing/mochitest/browser-test.js
@@ +19,5 @@
>  XPCOMUtils.defineLazyModuleGetter(this, "Services",
>    "resource://gre/modules/Services.jsm");
> + 
> +XPCOMUtils.defineLazyModuleGetter(this, "Preferences",
> +  "resource://gre/modules/Preferences.jsm"); 

nit: trailing whitespace here, also line 21 has whitespace on a blank line.

@@ +124,5 @@
>    });
> +  
> +  this._initialPrefs = new Map();
> +  let mutatedPrefs = this._mutatedPrefs = new Set();
> + 

nit: lines 125 and 128 have trailing whitespace.

@@ +127,5 @@
> +  let mutatedPrefs = this._mutatedPrefs = new Set();
> + 
> +  this._prefObserver = {
> +    observe: function (subject, topic, data) {
> +    mutatedPrefs.add(data);

please indent mutatedPrefs.add(data);

@@ +200,5 @@
> +    let prefKeys = Services.prefs.getChildList("", prefCount);
> +    for (let prefKey of prefKeys.sort()) {
> +      this._initialPrefs.set(prefKey, Preferences.get(prefKey));
> +    }
> +    Services.prefs.addObserver("", this._prefObserver, false);  

nit: whitespace on 198 and 204.

@@ -316,5 @@
> -      this.onConsoleMessage(aSubject);
> -    } else if (this.currentTest) {
> -      this.onDocumentCreated(aSubject);
> -    }
> -  },

why is this removed?  If there isn't a good reason, I assume we need it.

@@ +475,5 @@
>                                gConfig.dumpOutputDirectory,
>                                gConfig.dumpAboutMemoryAfterTest,
>                                gConfig.dumpDMDAfterTest);
>        }
> +      

nit: whitespace on this line.

@@ +477,5 @@
>                                gConfig.dumpDMDAfterTest);
>        }
> +      
> +      // Revert mutated preferences and restore initial conditions.
> +      this.resetPrefs();

this calls resetprefs, I don't think we want to do that- just alert on them.

@@ +784,5 @@
> +    for (let pref of this._mutatedPrefs) {
> +      this.SimpleTest.info("Pref " + pref + " was changed and we were not expecting it");
> +    }
> +  },
> +  

whitespace on line 788; the name and comment indicate reset, but we are just notifying for now.

::: testing/mochitest/tests/Harness_sanity/test_sanity.html
@@ +22,5 @@
>  
>  /** Test for sanity  **/
> +
> +SpecialPowers.pushPrefEnv({set: [['advanced.mailftp', true]]}, doTest());
> +

we have test_specialpowersPushPrefEnv.html already, lets leave this file alone.

::: testing/mochitest/tests/SimpleTest/TestRunner.js
@@ +8,5 @@
>  
>  "use strict";
>  
> +var failPrefs = [];
> +var whiteList = ["browser.startup.homepage_override.mstone","browser.startup.homepage_override.buildID","network.cookie.prefsMigrated",

add a comment as to what this is and why we have it.  I think as we determine what prefs are changed outside of the preferences we can determine what values to reset them to and what we want to ignore/reset.

@@ +792,5 @@
> +        changed_prefs = SpecialPowers.reportPrefsChanged();
> +        excludedPrefs = SpecialPowers.getClearedPrefs();
> +        for (var pref in changed_prefs) {
> +          if(excludedPrefs.indexOf(changed_prefs[pref]) == -1) {
> +          failPrefs.push(changed_prefs[pref]);

indent failPrefs.push(...) line

on the if condition above, add a space between if and (

@@ +814,5 @@
> +TestRunner.getFailPrefs = function() { 
> +    return failPrefs; 
> +}
> +
> +TestRunner.flushFailPrefs = function() { 

nit: whitespace on line 804, 814, 815, 818

::: testing/specialpowers/content/specialpowersAPI.js
@@ +1931,5 @@
>      return new File(path, options);
>    },
> +  
> +  reportPrefsChanged: function() {
> +  var preffs;

I would prefer 'prefs' instead of 'prefs'

@@ +1936,5 @@
> +  for(preffs in prefchanges) {
> +    if(exceptions.indexOf(prefchanges[preffs]) != -1) {
> +      var index = prefchanges.indexOf(prefchanges[preffs]);
> +      if(index != -1) {
> +        prefchanges.splice(index, 1);

I am not sure I understand fully what you are doing here.  Maybe you could add a comment for the for loop?

@@ +1954,5 @@
>  this.SpecialPowersAPI = SpecialPowersAPI;
>  this.bindDOMWindowUtils = bindDOMWindowUtils;
>  this.getRawComponents = getRawComponents;
> +
> +   

remove the extra blank line and ensure there is no whitespace on what is remaining.

also whitespace on lines: 1951, 1946, 1941, 1933, 1227

Comment 14

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 15

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 16

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8565116 [details] [diff] [review]
prefchanges.patch

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

in testrunner.js there are both 2 and 4 space indentation examples to work from, how about you ensure you code is 4 space indented.

::: testing/mochitest/browser-test.js
@@ +198,5 @@
>  
> +    let prefCount = {};
> +    let prefKeys = Services.prefs.getChildList("", prefCount);
> +    for (let prefKey of prefKeys.sort()) {
> +      this._initialPrefs.set(prefKey, Preferences.get(prefKey));

why do we get this, if we are just alerting, we don't need initial prefs.  Assuming we wanted to go this route this doesn't handle user changed preferences.

@@ +789,5 @@
> +   * Reset preferences to the state at the beginning of test execution.
> +   */
> +  resetPrefs: function Tester_resetPrefs() {
> +    for (let pref of this._mutatedPrefs) {
> +      this.SimpleTest.info("Pref " + pref + " was changed and we were not expecting it");

does this clear the list?  How do you work with the whitelist here?  Also the comment above indicates you are resetting to the initial state, when in fact we are alerting based upon it.

::: testing/mochitest/tests/Harness_sanity/test_sanity.html
@@ +20,5 @@
>  <pre id="test">
>  <script class="testbody" type="text/javascript">
>  
>  /** Test for sanity  **/
> +function doTest(){

who calls function doTest()?  If you want to keep this, indent the code inside the function and call it.  I am concerned that you have this here and the rest of the code is outside of it.

::: testing/mochitest/tests/SimpleTest/TestRunner.js
@@ +793,5 @@
> +        changed_prefs = SpecialPowers.reportPrefsChanged();
> +        excludedPrefs = SpecialPowers.getClearedPrefs();
> +        for (var pref in changed_prefs) {
> +          if (excludedPrefs.indexOf(changed_prefs[pref]) == -1) {
> +          failPrefs.push(changed_prefs[pref]);

indent this line properly.

::: testing/specialpowers/content/specialpowersAPI.js
@@ +1219,5 @@
>    },
>  
>    // Mimic the clearUserPref API
>    clearUserPref: function(aPrefName) {
> +    exceptions.push(aPrefName);

I am not sure we want to create exceptions for this.  Although it might be the right thing to do.

@@ +1942,5 @@
> +      }
> +    }
> +  }
> +    return prefchanges;
> +  },

please indent this function properly!

@@ +1957,5 @@
>  this.getRawComponents = getRawComponents;
> +
> +Services.prefs.addObserver("", function getChanges(subject, topic, data) {
> +  if(exceptions.indexOf(data) == -1)
> +  prefchanges.push(data);

add {} and indent this properly.

Comment 17

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 18

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8565517 [details] [diff] [review]
prefchanges.patch

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

in browser-test.js we do not support the whitelist, I would like to see us do that.

I also mentioned in my last review comments to ensure that we had 4 space indentation in all your code that you are adding/changing, please do that.

::: testing/mochitest/tests/SimpleTest/SimpleTest.js
@@ +403,2 @@
>      var log = message ? name + ' | ' + message : name;
> +    log = url + " " + log; //I intend to find a better solution to this.

we can't check this in with this change, but I suspect you have looked into this or we could remove this for now and add/fix this in a followup patch.

::: testing/mochitest/tests/SimpleTest/TestRunner.js
@@ +8,5 @@
>  
>  "use strict";
>  
> +var failPrefs = [];
> +//We find that some prefs are changed outside of tests. So, we wouldn't print out Test specific messages for these prefs and hence these are whitelisted

nit: please add a space between // and We.  Also a period at the end.

@@ +793,5 @@
> +        changed_prefs = SpecialPowers.reportPrefsChanged();
> +        excludedPrefs = SpecialPowers.getClearedPrefs();
> +        for (var pref in changed_prefs) {
> +          if (excludedPrefs.indexOf(changed_prefs[pref]) == -1) {
> +          failPrefs.push(changed_prefs[pref]);

hmm, didn't I mention in my last review to indent this properly?

@@ +890,5 @@
>  /**
>   * Print out table of any error messages found during looped run
>   */
>  TestRunner.displayLoopErrors = function(tableName, tests) {
> +  if (TestRunner.countResults(tests).notOK >0){

no need to change this, I am fine with the slight cleanup, but do fix the spacing in the entire line if you do that :)

@@ +910,5 @@
>  
>      //find the broken test
>      for (var testnum in tests){
>        curtest = tests[testnum];
> +      if ( !((curtest.todo && !curtest.result) || (curtest.result && !curtest.todo)) ){

no need to change this, I am fine with the slight cleanup, but do fix the spacing in the entire line if you do that :)

Comment 19

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 20

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 21

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 22

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8570585 [details] [diff] [review]
prefchanges.patch

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

do we need the whitelist and related api's in testrunner.js or can they live in SimpleTest.js?  I ask this because then we wouldn't need to include testrunner.js in browser-test.js.

a few small issues below and a few questions.  This code should be high quality code and it has a high chance of breaking random things, so lets get it right!

::: testing/mochitest/browser-test.js
@@ +19,5 @@
>  XPCOMUtils.defineLazyModuleGetter(this, "Services",
>    "resource://gre/modules/Services.jsm");
>  
> +XPCOMUtils.defineLazyModuleGetter(this, "Preferences",
> +  "resource://gre/modules/Preferences.jsm");

why do we need to load this module?  I suspect we don't need to.

::: testing/mochitest/tests/SimpleTest/SimpleTest.js
@@ +403,2 @@
>      var log = message ? name + ' | ' + message : name;
> +    if (log.endsWith("and we were not expecting it")) {

I really don't like this as a way to detect it, but I don't have an idea of what else to do right now.  Does this work for browser-chrome as well?

::: testing/mochitest/tests/SimpleTest/TestRunner.js
@@ +795,5 @@
>          SpecialPowers.flushAllAppsLaunchable();
> +        prefFails = SpecialPowers.reportPrefsChanged();
> +        var tempPref;
> +        var frameWindow = $('testframe').contentWindow.wrappedJSObject || $('testframe').contentWindow;
> +        for (tempPref in prefFails) {

I assume you can just define 'var tempPref' in the for loop and not above.

::: testing/specialpowers/content/specialpowersAPI.js
@@ +11,5 @@
>  var Cc = Components.classes;
>  var Cu = Components.utils;
>  
> +var prefchanges = [];
> +var  excludedPrefs = [];

you have two space between var and excludedPrefs, please make it 1 space.

@@ +1225,5 @@
>      var msg = {'op':'clear', 'prefName': aPrefName, 'prefType': ""};
>      this._sendSyncMessage('SPPrefService', msg);
>    },
>  
> +  getClearedPrefs: function() {

can we just call this 'getExcludedPrefs' ?  or maybe getPushedPrefs ?

Comment 23

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 24

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8571027 [details] [diff] [review]
prefchanges.patch

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

my list is shorter, and I still would like to see if we can define the whitelist stuff in SimpleTest intead of TestRunner.  Then we don't need to include TestRunner inside of browser-test.js.

::: testing/mochitest/tests/SimpleTest/TestRunner.js
@@ +794,3 @@
>          cleanUpCrashDumpFiles();
>          SpecialPowers.flushAllAppsLaunchable();
> +        prefFails = SpecialPowers.reportPrefsChanged();

can we just define prefFails here and not 3 lines up?

::: testing/specialpowers/content/specialpowersAPI.js
@@ +10,5 @@
>  var Ci = Components.interfaces;
>  var Cc = Components.classes;
>  var Cu = Components.utils;
>  
> +var prefchanges = [];

I would rather see this variable named: changedPrefs

@@ +1225,5 @@
>      var msg = {'op':'clear', 'prefName': aPrefName, 'prefType': ""};
>      this._sendSyncMessage('SPPrefService', msg);
>    },
>  
> +  flushClearedPrefs: function() {

this is called flushClearedPrefs, but we are flushing excludedPrefs.

Comment 25

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 26

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 27

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8571489 [details] [diff] [review]
prefchanges.patch

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

r+, please update this patch with the feedback below!  I am going to run this on try server.

::: testing/mochitest/tests/SimpleTest/SimpleTest.js
@@ +417,2 @@
>      var log = message ? name + ' | ' + message : name;
> +    if (log.endsWith("and we were not expecting it")) {

please add a comment here as to what this is for (with this bug number) and that we should find a more reliable way to handle this.

::: testing/specialpowers/content/specialpowersAPI.js
@@ +10,5 @@
>  var Ci = Components.interfaces;
>  var Cc = Components.classes;
>  var Cu = Components.utils;
>  
> +var prefchanges = [];

please make this variable: changedPrefs

Comment 28

[Joel Maher ( :jmaher ) (UTC -8)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=49962b3536b6

Comment 29

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 30

[Joel Maher ( :jmaher ) (UTC -8)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=4df5b2e5d2b7

Comment 31

[Joel Maher ( :jmaher ) (UTC -8)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=5ac52d119e22

Comment 32

[Joel Maher ( :jmaher ) (UTC -8)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=a3df06c7b4c0

Comment 33

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 34

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 35

[Kaustabh Datta Choudhury]

Attachment: prefchanges.patch

Comment 36

[Joel Maher ( :jmaher ) (UTC -8)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=4410078b8d96

Comment 37

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8578846 [details] [diff] [review]
prefchanges.patch

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

This patch is looking great.  I am concerned we don't need browser-test.js, lets verify we need it.

Also looking at the logs:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=98f1e6ae8004

::: testing/mochitest/browser-test.js
@@ +288,5 @@
>      else{
>        Services.console.unregisterListener(this);
>        Services.obs.removeObserver(this, "chrome-document-global-created");
>        Services.obs.removeObserver(this, "content-document-global-created");
> +      SpecialPowers.removePrefsObserver();

isn't this handled already in SimpleTest.js  executeCleanupFunction() ?

@@ +797,5 @@
> +        this.SimpleTest.info("Pref " + pref + " was changed and we were not expecting it");
> +      }
> +    }
> +    SpecialPowers.flushChangedPrefs();
> +  },

isn't this technically handled in TestRunner.js executeAfterFlushingMessageQueue() ?

Comment 38

[Gregory Szorc [:gps]]

jmaher: do you have any interest in reviving this bug? I think state that leaks between tests could be a source of intermittent failures and plugging the leak could make automation more stable. I /think/ the patches won't be too difficult to someone who knows the test harnesses well.

Comment 39

[Joel Maher ( :jmaher ) (UTC -8)]

I still think this is valid- although the full value we get from this will be limited since we do run all mochitests in --run-by-dir mode so there is no leaking of preferences.  We should put it on the radar for folks looking to fix/cleanup intermittents (wlach/gbrown who I just cc'd on this bug)