1032970 - maxStartTime is incorrectly disabling experiments which have already started

Status: VERIFIED FIXED

(Firefox Health Report Graveyard :: Client: Desktop, defect)

Description

[Benjamin Smedberg]

Found during QA of the search experiment, bug 1029818 comment 29-30. maxStartTime was set to 20-Jul-2014 in the experiment, and this caused currently-running experiments to be terminated.

The following was in the trace output:
1405882887653	Browser.Experiments.Experiments	DEBUG	ExperimentEntry #0::isApplicable() - id=[e-mail] - test 'maxStartTime' failed

Code is here:

It might be sufficient to add a condition `this._startDate ||` to the beginning of the condition, but we'll also need to add a test for this in http://mxr.mozilla.org/mozilla-central/source/browser/experiments/test/xpcshell/test_conditions.js

Comment 1

[Georg Fritzsche [:gfritzsche]]

(In reply to Benjamin Smedberg  [:bsmedberg] from comment #0)
> It might be sufficient to add a condition `this._startDate ||` to the
> beginning of the condition, but we'll also need to add a test for this in
> http://mxr.mozilla.org/mozilla-central/source/browser/experiments/test/
> xpcshell/test_conditions.js

Indeed, both sound right.

Comment 2

[Mike Hoye [:mhoye]]

Marking as diamond, shopping it around.

Comment 3

[Qeole]

I'm willing to work on this one (unless you prefer to keep it as a first bug for a new(er) contributor?).

Comment 4

[Mike Hoye [:mhoye]]

Go for it, we'd be glad for your efforts.

Comment 5

[Qeole]

So, let's see if I understand it correctly:

 * maxStartTime should be checked at install and prevent enabling of the addon if we have |now >= maxStartTime|;
 * but in bug 1029818 we realized that even after install, i.e. for further activations, maxStartTime is matched against current time and can cause unwanted uninstall of the experiment.
(I may mix up the correct terms, not sure about “activating” vs “enabling” etc, but I think I got the general idea?)

(In reply to Benjamin Smedberg  [:bsmedberg] Away 19-July through 3-Aug from comment #0)
> Code is here:
Well, I'm afraid it's not :) or at least I can't see it.
I searched on my own, and I'd say you meant there?:
https://mxr.mozilla.org/mozilla-central/source/browser/experiments/Experiments.jsm#1589

About the test in http://mxr.mozilla.org/mozilla-central/source/browser/experiments/test/xpcshell/test_conditions.js, I take it I should create a test that somehow sets _startTime property of an ExperimentEntry object to a defined value, then tries to activate() it with an expired maxStartTime value. And activation should succeed. Again, is it correct?
Should I insert this test in an existing task (called with add_task() in the file), or create a new one at the end of file?

(Not related to this, what's the diamond for on whiteboard? Is there somewhere I can get documentation about keywords/whiteboard values for bugzilla, other than the “What do those fields mean?” link?)

Comment 6

[Mike Hoye [:mhoye]]

Needinfo'ing Benjamin. 

Qeole: some people (though not Benjamin specifically) rely on the NeedInfo flag to know which bugs they should be looking at. If you've got a question for somebody specific, needinfo them to make sure they see it. 

Thanks for your help with this.

Comment 7

[Qeole]

I didn't set flag as I wasn't expecting an answer from someone in particular, and I confirm that Benjamin have quickly answered many of my questions so far, even when not flagged.

But thank you, I shall use it next time!

Comment 8

[Georg Fritzsche [:gfritzsche]]

(In reply to qeole from comment #5)
>  * maxStartTime should be checked at install and prevent enabling of the
> addon if we have |now >= maxStartTime|;

maxStartTime should be evaluated every time for experiments that were not started yet. If they were ever started, we shouldn't evaluate it anymore.

>  * but in bug 1029818 we realized that even after install, i.e. for further
> activations, maxStartTime is matched against current time and can cause
> unwanted uninstall of the experiment.

Right, we re-check the conditions regularly for both pending and active experiments (e.g. to see if we need to stop an active one).

> I searched on my own, and I'd say you meant there?:
> https://mxr.mozilla.org/mozilla-central/source/browser/experiments/
> Experiments.jsm#1589

Exactly :)
When an experiment is started we have _startDate set on it, so that is the proper thing to check.

> About the test in
> http://mxr.mozilla.org/mozilla-central/source/browser/experiments/test/
> xpcshell/test_conditions.js, I take it I should create a test that somehow
> sets _startTime property of an ExperimentEntry object to a defined value,
> then tries to activate() it with an expired maxStartTime value. And
> activation should succeed. Again, is it correct?
> Should I insert this test in an existing task (called with add_task() in the
> file), or create a new one at the end of file?

Looking at this again, adding this to test_api.js would be better:
dxr.mozilla.org/mozilla-central/source/browser/experiments/test/xpcshell/test_api.js
Otherwise we would need to set the internal properties to fake that the experiment got started (as test_conditions.js doesn't do a full test setup of the experiments system we couldn't properly activate it).

We can add a new test function via add_task that starts off like testEnabledAfterRestart().
Just add a maxStartTime on the manifest entry:
http://hg.mozilla.org/mozilla-central/annotate/a74600665875/browser/experiments/test/xpcshell/test_api.js#l1503
Then, instead of the restart promiseRestartManager and following lines:
* we move the fake time forward past maxStartTime via defineNow()
* |yield experiments.updateManifest()| to trigger a re-evaluation of the experiment conditions
* check that the experiment is still active

Comment 9

[Qeole]

Attachment: bug1032970-v1.patch

First version attached for feedback.

I added a test function in test_api.js as proposed by Georg in comment #8.
Test fails when running |mach xpcshell-test browser/experiments/test/| with old version of Experiments.jsm; with new version (containing the additional condition this.startDate ||), test is passed successfully.

Comment 10

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8458320 [details] [diff] [review]
bug1032970-v1.patch

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

This looks fine, thanks!

I only have minor comments below.

::: browser/experiments/test/xpcshell/test_api.js
@@ +1573,5 @@
> +  addons = yield getExperimentAddons();
> +  Assert.equal(addons.length, 1, "A single experiment add-on is installed.");
> +  Assert.ok(addons[0].isActive, "That experiment is active.");
> +
> +  dump("Setting current time to maxStartTime + 30 seconds and reloading manifest\n")

Missing semicolon.

@@ +1574,5 @@
> +  Assert.equal(addons.length, 1, "A single experiment add-on is installed.");
> +  Assert.ok(addons[0].isActive, "That experiment is active.");
> +
> +  dump("Setting current time to maxStartTime + 30 seconds and reloading manifest\n")
> +  let newCurrentTime = new Date(1000 * (gManifestObject.experiments[0].maxStartTime + 30));

30s might get a little close if we had a bad/slow/busy machine we're testing on. We can just use daily timespans etc. to be safe (SEC_/MS_IN_ONE_DAY).

If you introduce a local variables startDate & maxStartDate, you could use futureDate() here.
For the gManifestObject definition, dateToSeconds() helps out.
I know testEnabledAfterRestart() doesn't do this yet, but it would be nice for readability.

@@ +1582,5 @@
> +  addons = yield getExperimentAddons();
> +  Assert.equal(addons.length, 1, "The experiment is still there.");
> +  Assert.ok(addons[0].isActive, "It is still active.");
> +
> +  // END modif

Left-over?

Comment 11

[Qeole]

Attachment: bug1032970-v2.patch

Second version of patch, correcting missing semicolon and left-over comment, and rewriting the dates as suggested by Georg in comment #10.

I obtain same results with |mach xpcshell-test browser/experiments/test| as with previous patch (test passes with Experiments.jsm modification, and fails without it).

Comment 12

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8458651 [details] [diff] [review]
bug1032970-v2.patch

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

Thanks, this looks fine!

::: browser/experiments/test/xpcshell/test_api.js
@@ +1547,5 @@
> +
> +  // Dates the following tests are based on.
> +
> +  let baseDate     = new Date(2014, 5, 1, 12);
> +  let startDate    = baseDate;

Minor nit: baseDate equals startDate for this whole test, so it seems redundant.

Comment 13

[Qeole]

Attachment: bug1032970-v3.patch

Fixed it. I'm not sure I'm expected to ask for review again, but in doubt I prefer to do so.

Nitpicking here as well:
I removed |baseDate| and kept |startDate|. I considered basing |maxStartDate| and |endDate| on |now| (to make it clear it's in the future), but after all I thought it's probably clearer with |startDate| as sole base.

Comment 14

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8458664 [details] [diff] [review]
bug1032970-v3.patch

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

Looks good to me.
Usually when you get review+/r+ with only minor & obvious comments you can just go ahead.
Of course, if you prefer, requesting review again is fine.

Comment 15

[Qeole]

OK, thanks.
I'm asking for checkin.

Comment 16

[Georg Fritzsche [:gfritzsche]]

https://hg.mozilla.org/integration/fx-team/rev/ec060e0603dc

Comment 17

[Ryan VanderMeulen [:RyanVM]]

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

Comment 18

[Kamil Jozwiak [:kjozwiak]]

Attachment: Browser Console errors

Reproduced the original issue using the following build:
- http://ftp.mozilla.org/pub/mozilla.org/firefox/releases/latest-beta/win32/en-US/
- set "maxStartTime" to "1407934800" (Wed, 13 Aug 2014 13:00:00 GMT)
- installed the search experiment and moved the machines date to Wed, 13 Aug 2014 which expired/disabled the search experiment

Went through verification using the following builds:
- http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2014-08-11-03-02-03-mozilla-central/

Prerequisites:
- "maxStartTime": 1407934800
- "maxVersion": "34.*"
- "channel": ["nightly"]

Went through the following test cases:

I set "maxStartTime" to "1407934800" (Wed, 13 Aug 2014 13:00:00 GMT) under the search experiment manifest and ensured that:

- search experiment is being installed when the machines date < maxStartTime (August 11th, 12th)
- search experiment is not being installed when the machines date >= maxStartTime (August 13th, 14th, 15th)
- 1407942280826 Browser.Experiments.Experiments DEBUG ExperimentEntry #0::isApplicable() - id=[e-mail] - test 'maxStartTime' failed
- ensured that once the machines date == "maxStartTime", the search experiment wasn't disabled/removed
- ensured that once the machines date >= "endTime", the search experiment disabled correctly

Georg, the only thing that I ran into is that the search provider was not being restored once I hit 3 days remaining. This works perfectly fine while in the beta channel but doesn't appear to be working when testing via the Nightly channel. I'm not sure if this is a legitimate issue or due to changing the manifest to target Nightly which could be causing potential issues? I also received some error messages under the browser console (attached a screenshot of the errors). Would you mind taking a quick look?

manifest used: http://kamiljozwiak.com/firefox-manifest.json

Comment 19

[Georg Fritzsche [:gfritzsche]]

I'm not sure about the search provider restore not working, but that should not be related to the bug at hand as long as the experiment is properly getting started, ended and staying enabled.

You could file a new bug on this, CC Felipe & me and maybe needinfo?gavin if someone else is around now who would know about that issue (with Felipe being on PTO).

Comment 20

[Kamil Jozwiak [:kjozwiak]]

Thanks Georg, I created bug #1052545 to address the issue mentioned in comment #18.

Went through verification using the latest m-c build:
- http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2014-08-12-03-02-02-mozilla-central/

- went through the same test cases listed under comment #18
- experiment is being installed/started correctly when current date < maxStartTime
- experiment is not being disabled/removed when current date passes maxStartTime and the experiment has already been installed
- ensured that the experiment is being disabled/removed when reaching endTime
- experiment is not being installed when current date >= maxStartTime (ensured that the correct error is being displayed under the browser console)