Closed Bug 1477380 Opened 6 years ago Closed 6 years ago

User branch studies are still set by the early-start pref system, causing study values to be discarded.

Categories

(Firefox :: Normandy Client, defect, P1)

63 Branch
defect

Tracking

()

VERIFIED FIXED
Firefox 63
Tracking Status
firefox-esr52 --- unaffected
firefox-esr60 --- wontfix
firefox61 + verified
firefox62 + verified
firefox63 + verified

People

(Reporter: jan, Assigned: mythmon)

References

(Blocks 1 open bug)

Details

(Keywords: nightly-community)

Attachments

(3 files)

I hate my typos. Sorry for spamming.

Win10, Nvidia GTX 1060 3GB

If I create a new profile, create gfx.webrender.all.qualified;true and restart, WebRender is active (about:support).

And this looks like a bug to me:
1.) Create a new profile, set app.normandy.dev_mode to true (or app.normandy.run_interval_seconds to 10), restart.
2.) app.normandy.startupExperimentPrefs.gfx.webrender.all.qualified;true (bold font) and 
gfx.webrender.all.qualified;true (default font weight) have been created. Restart.
3.) It's still Direct3D 11 (Advanced Layers) on about:support. Restart.
4.) Still the same.
Summary: Are startupExperimentPrefs applied to late? WebRender is not enabled → Are startupExperimentPrefs applied too late? WebRender is not enabled
Thanks for the report. This is an easy thing to miss (the feature being turned on, but not actually active). I'm glad someone caught it so quickly.

The recipe running for WebRender right now is using a default-branch pref study. These are known to be incompatible with features that require a restart. If WebRender needs a restart to be active, then the recipe needs updated to account for that.

This is a limitation of Normandy, but not a bug, so I'm going to move this into the component for Shield studies. Additionally, I'm going to work with the WebRender team to see if we can avoid this in the future.
Component: Normandy Client → Shield Study
Product: Firefox → Shield
Version: 63 Branch → unspecified
https://mozilla.logbot.info/gfx/20180720#c15048377
Thank you!

(In reply to Jan Andre Ikenmeyer [:darkspirit] from comment #1)
> 1.) Create a new profile, set app.normandy.dev_mode to true, restart.

A)
app.normandy.startupExperimentPrefs.gfx.webrender.all.qualified;true
and gfx.webrender.all.qualified;true have been created. Restart. Open about:support.
> Compositing	WebRender
> WEBRENDER	
> opt-in by default: WebRender is an opt-in feature
> available by user: Qualified enabled by pref

or

B)
app.normandy.startupExperimentPrefs.gfx.webrender.all.qualified;false
and gfx.webrender.all.qualified;false have been created. Restart. Open about:support.
> Compositing	Direct3D 11 (Advanced Layers)
> WEBRENDER	
> opt-in by default: WebRender is an opt-in feature
Assignee: nobody → mcooper
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
I restarted Nightly some more times, prefs are still true, but WebRender isn't enabled. Strange.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Comment 3 works as described, but after one more restart WebRender doesn't work again.
For comment 5 - is there some way to verify the behaviour?
Flags: needinfo?(mcooper)
I did a manual telemetry analysis looking at pings with a build id of 20180721100146 and wrQualified = available. I looked at what compositor these pings were using and got: defaultdict(int, {u'basic': 4, u'd3d11': 133, u'webrender': 11}). Which suggests that this is probably not working.
When testing this, as well as the value of the preference (expected to be true), it is also useful to know if the preference is set on the user branch or the default branch. In about:config, that can be seen by the boldness of the value. A bold value is on the user-branch, which is required for restartful features like this. Non-bold values are default-branch set, and likely won't work in this case.

Checking just the value isn't directly useful, since on a human timescale, the preference is set immediately. It is only on a code time scale do we see the pref not being set, which is why the boldness of the value (which branch it is on) is useful.

Additionally useful is to check logging. Setting app.normandy.logging.level to 0 before starting a profile is also helpful.

As far as my needinfo: I don't know how to verify that webrender is turned on or off, only if Normandy tried to turn it on. Jan, how did you verify that webrender was on or off?
Flags: needinfo?(mcooper) → needinfo?(jan)
The usual mechanism for checking that in-browser is to go to about:support and look at the "Compositing" field in the graphics section. From comment 4 it sounds like the pref doesn't persist? I would assume that when normandy sets a user-branch pref, it would remain set as long as the experiment is active. Can you confirm that?
Attached video 2018-07-23 17-33-12.mp4 —
Flags: needinfo?(jan)
(In reply to Jan Andre Ikenmeyer [:darkspirit] from comment #10)
> Created attachment 8994257 [details]
> 2018-07-23 17-33-12.mp4

"Target" of Desktop shortcut: "C:\Program Files\Firefox Nightly\firefox.exe" -P wr --no-remote
(In reply to Jan Andre Ikenmeyer [:darkspirit] from comment #10)
1) Getting normandy user ID + setting dev mode to true
2) Because of dev mode I get the WR study directly after startup: both prefs are true and bold. Have to restart.
3) treatment branch: WR is active: Longer startup (Compiling shaders once per Nightly update). Both prefs still true and bold.
4) treatment branch: no WR. Both prefs are still true, but gfx.webrender.all.qualified is not bold.
Summary: Are startupExperimentPrefs applied too late? WebRender is not enabled → WebRender study is not consistently enabling WebRender
and is not listed on about:studies ^^
Jan: thanks for the video, that's pretty useful (and I think I learned about an unrelated bug from it). Can you re-do it, including the Normandy logs? They show up in the browser console, if you set `app.normandy.logging.level=0`. This will include data about what Normandy is doing that we simply can't get any other way. If the results are similar enough to the previous video, it may be enough to simply copy/paste the logs to Bugzilla.

It is expected that this type of study will not be listed in about:studies. Preference studies aren't included in the listing there.
(In reply to Michael Cooper [:mythmon] from comment #14)
> Can you re-do it, including the Normandy logs?
Yes, I will rebooot!

> It is expected that this type of study will not be listed in about:studies. Preference studies aren't included in the listing there.
All studies have to be listed on about:studies. That is user expectation. Also, if things suddenly change one could see which study has completed and how to bring it back. Where can I see the following "user facing description"? ;)

(Thomas Elin [:relaas] from bug 1474484 comment 0)
> User facing title of the experiment: WebRender
> User facing description of the experiment: New generation graphics rendering engine
Attached file steps.txt —
(In reply to Michael Cooper [:mythmon] from comment #14)
> If the results are similar enough to the previous video, it may be enough to simply copy/paste the logs to Bugzilla.

Behavior seems to be consistent: WebRender is only enabled in the first Nightly session after "treatment" has created prefs (set to true), and otherwise not.

(comment 12 Nightly session No. 2: I can flip app.normandy.dev_mode back to false there and behavior seems to be the same.)
Thanks for the logs. They only showed enrollment activity, and never unenrollments. Given that the preference was being set back to not-user-set (not bold in about:config), that was very confusing. So I went digging.

Normandy's process for *default branch* studies is this: it immediately sets the default branch to the target value, and then it sets a second pref in the `app.normandy.startupExperimentPrefs.` namespace to the same value, but on the user branch. This is because changes to the default branch don't persist between restarts, and all the other storage options delay early startup too much. So then, when Firefox restarts, Normandy reads from the `startupExperimentPrefs` branch as fast as it can, and copies the values over to the default branch. This works well for must studies, but not for things like WebRender.

But that's all default branch studies. It shouldn't affect the study since it was changed to user branch, right? Except it does. It turns out that the system that sets up `startupExperimentPrefs` doesn't care if the study is user branch or default branch. So during startup, the default branch changes to the study value.

This is ok for a moment: since the pref was still true on the user branch while WebRender started, WebRender will still be enabled. The problem comes when Firefox writes the preferences to disk. When Firefox writes its to the profile, it only writes preferences that are different than their defaults. And since Normandy changed the default (in memory) for the preference, the preference is not considered changed, and so its value is not written to disk.

So now on the second restart after the study began, the pref does not have a user set value. It still quickly gets set to the study value on the default branch, but as we know that isn't compatible with WebRender. The effect of all this is that WebRender is on for one run of Firefox, and then turns back off in the next, and stays off. This exactly matches your video.

The fix for this should be simple: when storing the startupExperimentPrefs, we'll skip over any studies that aren't on the default branch. That should fix the above problem.
Component: Shield Study → Normandy Client
OS: Windows 10 → All
Product: Shield → Firefox
Hardware: x86_64 → All
Summary: WebRender study is not consistently enabling WebRender → User branch studies are still set by the early-start pref system, causing study values to be discarded.
Target Milestone: --- → Firefox 63
Version: unspecified → 63 Branch
Setting tracking flags. This affects all version of Firefox with pref studies. This doesn't affect ESR52, but only because ESR52 didn't have Normandy Client at all, as far as I can tell. These types of studies are rare, so I don't think this will need uplift to anything.
It turns out that one of the studies being planned right now, P-OMTP (bug 1476418) was going to run on Beta. We may want to uplift this patch to Beta because of that. Once this patch lands on Nightly, I plan to request Beta uplift.
Blocks: 1476418
Priority: -- → P1
Flags: qe-verify+
Comment on attachment 8994336 [details]
Bug 1477380 - Don't set startup prefs for user-branch Normandy pref-experiments r?Gijs

:Gijs (he/him) has approved the revision.

https://phabricator.services.mozilla.com/D2305
Attachment #8994336 - Flags: review+
(In reply to Jan Andre Ikenmeyer [:darkspirit] from comment #15)
> (In reply to Michael Cooper [:mythmon] from comment #14)
> > Can you re-do it, including the Normandy logs?
> Yes, I will rebooot!
> 
> > It is expected that this type of study will not be listed in about:studies. Preference studies aren't included in the listing there.
> All studies have to be listed on about:studies. That is user expectation.

I am sympathetic to this point... is there a separate bug on file discussing this? I recently had a confusing experience where the number of default rows in my location bar had changed, and I checked about:studies to see if that was why, and didn't see anything. Now I'm realizing that it might still have been a preference study... but there's no way for me as a user to find out. That's... not great.
Flags: needinfo?(mcooper)
See Also: → 1447499
Regarding about:studies, we already have a bug on file for that, as Jan found: bug 1447499. I agree that it is an issue, and it would be better for things to be there. It also isn't really related to this bug. Let keep any conversation about about:studies in bug 1447499.
Flags: needinfo?(mcooper)
Pushed by mcooper@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/856a8f38f2b0
Don't set startup prefs for user-branch Normandy pref-experiments r=Gijs
https://hg.mozilla.org/mozilla-central/rev/856a8f38f2b0
Status: REOPENED → RESOLVED
Closed: 6 years ago6 years ago
Resolution: --- → FIXED
I am not able to verify the fix because it looks like the WebRender study has been disabled. Bug 1447499 will be fixed before re-enabling it, right? Thank you! :)
We don't currently have any timeline for bug 1447499. However, even if it were fixed, about:studies would not be useful in validating this bug, since about:studies only shows the status of the recipe, not the state of the preferences system or the actual activation of features.

If you'd like to verify this fix now, you can still use the Normandy Devtools [0] to enroll in the study directly, even if it is disabled. (As of now the devtools can't control which branch you get enrolled in, however).

[0]: https://github.com/mozilla/normandy-devtools
(In reply to Michael Cooper [:mythmon] from comment #27)
> If you'd like to verify this fix now, you can still use the Normandy Devtools [0] to enroll in the study directly, even if it is disabled. (As of now the devtools can't control which branch you get enrolled in, however).
> 
> [0]: https://github.com/mozilla/normandy-devtools

Thank you!

Win10, Nvidia GTX 1060
(General observation: There is no longer an app.normandy.startupExperimentPrefs.gfx.webrender.all.qualified pref.)

=== CONTROL GROUP ===
Create a fresh profile. Start it.
Open https://github.com/mozilla/normandy-devtools/releases/download/v0.5.2/normandy-devtools.mozilla.com-0.5.2-signed.xpi, click on "Add" and click on its toolbar icon.
Search for "516 - Pref Flip Study: WebRender V1 Experiment [Bug 1474484]".
Open Browser Console (Ctrl+Shift+J). Click on the Run button of this study.
> 1532543253809	app.normandy.recipe-runner	INFO	Executing recipe "Pref Flip Study: WebRender V1 Experiment [Bug 1474484]" (action=preference-experiment)
> 1532543253809	app.normandy.preference-experiments	DEBUG	PreferenceExperiments.has(prefflip-webrender-1474484)
> 1532543253812	app.normandy.preference-experiments	DEBUG	PreferenceExperiments.start(prefflip-webrender-1474484, control)
> 1532543253812	app.normandy.preference-experiments	DEBUG	PreferenceExperiments.startObserver(prefflip-webrender-1474484)
Close Browser Console.
Open about:config, search for "gfx.webrender.all.qualified". It has been created and is false and bold because we are in the control group.
Restart Nightly. Open about:config, gfx.webrender.all.qualified is still false and bold. Open about:support, "Compositing" is still "Direct3D 11 (Advanced Layers)".
Restart Nightly. Open about:config, gfx.webrender.all.qualified is still false and bold. Open about:support, "Compositing" is still "Direct3D 11 (Advanced Layers)".
Click on the Normandy Devtools icon in the toolbar. Open Browser Console (Ctrl+Shift+J). Click on "Run Normandy".
> [...]
> 1532543532604	app.normandy.preference-experiments	DEBUG	PreferenceExperiments.stop(prefflip-webrender-1474484, {resetValue: true, reason: recipe-not-seen})
> 1532543532604	app.normandy.preference-experiments	DEBUG	PreferenceExperiments.hasObserver(prefflip-webrender-1474484)
> 1532543532604	app.normandy.preference-experiments	DEBUG	PreferenceExperiments.stopObserver(prefflip-webrender-1474484)
Close Browser Console. Open about:config, gfx.webrender.all.qualified is gone.


=== TREATMENT GROUP ===
Create a fresh profile. Start it.
Open https://github.com/mozilla/normandy-devtools/releases/download/v0.5.2/normandy-devtools.mozilla.com-0.5.2-signed.xpi, click on "Add" and click on its toolbar icon.
Search for "516 - Pref Flip Study: WebRender V1 Experiment [Bug 1474484]".
Open Browser Console (Ctrl+Shift+J). Click on the Run button of this study.
(I am again in the control group, so I have to create a new profile and redo steps until I am in the treatment group.)
> 1532543876783	app.normandy.recipe-runner	INFO	Executing recipe "Pref Flip Study: WebRender V1 Experiment [Bug 1474484]" (action=preference-experiment)
> 1532543876784	app.normandy.preference-experiments	DEBUG	PreferenceExperiments.has(prefflip-webrender-1474484)
> 1532543876786	app.normandy.preference-experiments	DEBUG	PreferenceExperiments.start(prefflip-webrender-1474484, treatment)
> 1532543876786	app.normandy.preference-experiments	DEBUG	PreferenceExperiments.startObserver(prefflip-webrender-1474484)
Close Browser Console.
Open about:config, search for "gfx.webrender.all.qualified". It has been created and is true and bold because we are in the treatment group.
Restart Nightly. Open about:config, gfx.webrender.all.qualified is still true and bold. Open about:support, "Compositing" is "WebRender".
And now, to finally verify the fix:
Restart Nightly. Open about:config, gfx.webrender.all.qualified is still true and bold. Open about:support, "Compositing" is "WebRender".
Restart Nightly. Open about:config, gfx.webrender.all.qualified is still true and bold. Open about:support, "Compositing" is "WebRender".
Restart Nightly. Open about:config, gfx.webrender.all.qualified is still true and bold. Open about:support, "Compositing" is "WebRender".
*** This bug is confirmed fixed. ***
Click on the Normandy Devtools icon in the toolbar. Open Browser Console (Ctrl+Shift+J). Click on "Run Normandy".
> [...]
> 1532544134622	app.normandy.preference-experiments	DEBUG	PreferenceExperiments.stop(prefflip-webrender-1474484, {resetValue: true, reason: recipe-not-seen})
> 1532544134622	app.normandy.preference-experiments	DEBUG	PreferenceExperiments.hasObserver(prefflip-webrender-1474484)
> 1532544134622	app.normandy.preference-experiments	DEBUG	PreferenceExperiments.stopObserver(prefflip-webrender-1474484)
Close Browser Console. Open about:config, gfx.webrender.all.qualified is gone.
Restart Nightly. Open about:support, "Compositing" is "Direct3D 11 (Advanced Layers)".


I don't know if relevant, but then I did these steps in the "treatment group" Nightly profile:
Click on the Normandy Devtools icon in the toolbar. Open Browser Console (Ctrl+Shift+J).
Search for "516 - Pref Flip Study: WebRender V1 Experiment [Bug 1474484]".
Click on the Run button of this study.
> 1532545075856	app.normandy.recipe-runner	INFO	Executing recipe "Pref Flip Study: WebRender V1 Experiment [Bug 1474484]" (action=preference-experiment)
> 1532545075856	app.normandy.preference-experiments	DEBUG	PreferenceExperiments.has(prefflip-webrender-1474484)
> 1532545075857	app.normandy.preference-experiments	DEBUG	PreferenceExperiments.get(prefflip-webrender-1474484)
> 1532545075857	app.normandy.normandy-driver.actions	DEBUG	Experiment prefflip-webrender-1474484 has expired, aborting.
This study has expired. I am unable to re-enable this study within this Nightly profile, but I don't need to either, I think?
Status: RESOLVED → VERIFIED
Your steps above look great, thanks for the verification.

> (General observation: There is no longer an app.normandy.startupExperimentPrefs.gfx.webrender.all.qualified pref.)

This is very good, as the existence of that pref is in fact the source of the original problem.

> This study has expired. I am unable to re-enable this study within this Nightly profile, but I don't need to either, I think?

This is expected. Studies can only be enrolled in once per profile by design. It would be nice if the devtools could force re-enroll in a study, but they can't as of now. It is something that may good to add in the future though.
Comment on attachment 8994336 [details]
Bug 1477380 - Don't set startup prefs for user-branch Normandy pref-experiments r?Gijs

Approval Request Comment
[Feature/Bug causing the regression]: 1371350
[User impact if declined]: User-branch Normandy studies do not work
[Is this code covered by automated tests?]: Yes
[Has the fix been verified in Nightly?]: Yes
[Needs manual test from QE? If yes, steps to reproduce]: No
[List of other uplifts needed for the feature/fix]: None
[Is the change risky?]: No
[Why is the change risky/not risky?]: It is a small change that has been well verified.
[String changes made/needed]: None
Attachment #8994336 - Flags: approval-mozilla-beta?
(In reply to Michael Cooper [:mythmon] from comment #29)
> This is expected. Studies can only be enrolled in once per profile by
> design. It would be nice if the devtools could force re-enroll in a study,
> but they can't as of now. It is something that may good to add in the future
> though.

Does this mean that we need to do a new study for webrender because everyone will have already enrolled but not kept webrender on?
Flags: needinfo?(mcooper)
I'll wait on mythmon's answer to uplift to beta.
It seems so. Telemetry of people with buildId 20180725103029 which includes this change has the following breakdown of wrQualified people using WebRender:

{u'basic': 4, u'd3d11': 227, u'webrender': 6})
(In reply to Jeff Muizelaar [:jrmuizel] from comment #31)
> Does this mean that we need to do a new study for webrender because everyone
> will have already enrolled but not kept webrender on?

A new recipe will need to be made on the server. I believe Rob has already done this. It will affect the timing of the study, but you don't need to create a new PHD or anything like that.
Flags: needinfo?(mcooper)
Comment on attachment 8994336 [details]
Bug 1477380 - Don't set startup prefs for user-branch Normandy pref-experiments r?Gijs

Fix for particular studies, let's uplift to beta.
Attachment #8994336 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
I've reproduced the issue on an affected Nightly version (63.0a1 20180722220044) then proceeded to verify the issue as fixed on:

63.0a1  20180731105217
62.0b13	20180730180407 (not sure why the build id states 07-30) 

Note that the bug will be still reproducible for recipes that have been started on a bad build - (e.g stale user has a june Nightly63 or a 62 b11, the recipe applies before update, then even though it is on a fixed version, given the fact that the recipe was started on the bad build, the recipe will still exibit the issue.
Confirmed with :mythmon that the above note is expected behavior for this fix, hence marking the issue as verified.
Flags: qe-verify+
Comment on attachment 8994336 [details]
Bug 1477380 - Don't set startup prefs for user-branch Normandy pref-experiments r?Gijs

This uplift would enable the study "Default Browser Prompt" [0] to run on 61.0.2.

Approval Request Comment
[Feature/Bug causing the regression]: bug 1371350
[User impact if declined]: User-branch Normandy studies do not work
[Is this code covered by automated tests?]: Yes
[Has the fix been verified in Nightly?]: Yes
[Needs manual test from QE? If yes, steps to reproduce]: Yes. STR above in this bug.
[List of other uplifts needed for the feature/fix]: None
[Is the change risky?]: No
[Why is the change risky/not risky?]: It is a small change, well tested and verified.
[String changes made/needed]: None

[0]: https://docs.google.com/document/d/1ERD4IqkKUwtFyelQ9q9IrZvNO4bfhTng1c07oGuWXJQ/edit
Attachment #8994336 - Flags: approval-mozilla-release?
Comment on attachment 8994336 [details]
Bug 1477380 - Don't set startup prefs for user-branch Normandy pref-experiments r?Gijs

Needed for a forthcoming study planned for 61.0.2. Also, this certainly explains some things with respect to some of our pref-off issues during the cycle! Thanks for adding a test too. Approved for 61.0.2.
Attachment #8994336 - Flags: approval-mozilla-release? → approval-mozilla-release+
Flags: in-testsuite+
Flags: qe-verify+
QA Contact: adrian.florinescu
Verified the fix as well on 61.0.2 candidate 20180807170231 on Windows 8.1, Ubuntu 16.04 and Osx 10.13.
Flags: qe-verify+
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: