Closed Bug 1459899 Opened 6 years ago Closed 6 years ago

Normandy Rollout is updated when no recipe updates have been performed

Categories

(Firefox :: Normandy Client, defect, P1)

defect

Tracking

()

VERIFIED FIXED
Firefox 62
Tracking Status
firefox-esr52 --- unaffected
firefox-esr60 --- unaffected
firefox60 --- unaffected
firefox61 + verified
firefox62 --- verified

People

(Reporter: aflorinescu, Assigned: mythmon)

References

Details

Attachments

(1 file)

[Environment:] Windows 8.1 x64 62.0a1 20180507222648 [Prerequisites:] 1. Set the app.normandy.dev_mode preference to true to run recipes immediately on startup. 2. Set the app.normandy.logging.level preference to 0 to enable more logging. 3. Set the security.content.signature.root_hash preference to DB:74:CE:58:E4:F9:D0:9E:E0:42:36:BE:6C:C5:C4:F6:6A:E7:74:7D:C0:21:42:7A:03:BC:2F:57:0C:8B:9B:90. 4. Set the preference value for app.normandy.api_url set to https://normandy.stage.mozaws.net/api/v1 [Steps:] 1. Open Control Center (https://normandy-admin.stage.mozaws.net/) 2. Create a rollout recipe with the blob: { "preferences": [ { "preferenceName": "test.int.1", "value": 1 } ], "slug": "rollout-pref" } 3. Save, Approve, Publish the recipe. 4. Set prerequisites and open a Firefox client which supports rollouts (Fx61+) 5. Open Browser Console and notice the logs. 6. Restart Firefox. 7. Look again at browser console. [Actual Result:] 5. app.normandy.recipe-runner INFO Executing recipe "Rollout exp" (action=preference-rollout) app.normandy.action.PreferenceRolloutAction DEBUG Enrolled in preference rollout rollout-pref 7. app.normandy.recipe-runner INFO Executing recipe "rollout-pref" (action=preference-rollout) app.normandy.action.PreferenceRolloutAction DEBUG updating rollout-graduation1: test.int.1 previous value changed from null to 1 app.normandy.action.PreferenceRolloutAction DEBUG Updated preference rollout rollout-pref in about:telemtry -> normandy update preference_rollout rollout-pref {"previousState": "active"} [Expected Result:] No update should be performed upon restart, no telemetry event should be logged either. [Note:] Repeating step 6 produces the same AR.
I think the bug here is that when applying an existing recipe, we aren't distinguishing between a "previous" value that we set and one that was set as a built in. I suspect that the resolution will be to change the previous value less often, and possible only at start up and never at recipe evaluation.
Assignee: nobody → mcooper
Status: NEW → ASSIGNED
Priority: -- → P1
Comment on attachment 8974847 [details] Bug 1459899 - Reuse previous values when updating an existing rollout https://reviewboard.mozilla.org/r/243224/#review249208 Clearing review for now, because I'm not sure I understand the fix. My understanding of the previous code here was that we want to take care of the case where: 1. default pref value on Firefox version 142 is 5 2. we roll out a change to make it 10 3. user updates to Firefox 143 and now the default pref value becomes 6 Expected: previous value of the pref we store in the normandy db should be 6. I'm not convinced that happens anymore after the changes in this patch... but maybe I'm missing something? My gut understanding here is that we determine the new previous value "too late", or something, leading to it being the study value instead of the "real" previous value. ::: toolkit/components/normandy/actions/PreferenceRolloutAction.jsm:152 (Diff revision 1) > oldValue = oldPrefSpec.value; > + > + // Trust the old rollout for the values of `previousValue`, but don't > + // consider this a change, since it already matches the DB, and doesn't > + // have any other stateful effect. > + prefSpec.previousValue = oldPrefSpec.previousValue; Is it possible for there to be no previousValue stored, despite there having been a previous value?
Attachment #8974847 - Flags: review?(gijskruitbosch+bugs)
previousValue is updated in two ways: 1) When a *new* rollout is enrolled, the current value of the preference is stored before applying the new preference. 2) When Firefox starts, the rollout preference is applied (since the default branch is non-persistent), and the original value is stored in previousValue (This happens in Normandy.jsm and PreferenceRollouts.recordOriginalValues) The case you bring up, of upgrading Firefox, is handled by the second way. This patch doesn't actually change either of those two behaviors. What it does is--when updating an existing rollout--copying the previousValue from oldPrefSpec to newPrefSpec is no longer considered a change that needs to send telemetry and update the db. The mechanism for storing data in the db doesn't change. The change that seems most likely to be a change is the removal of the if statement. That if statement was to prevent sending telemetry/setting `changed=true` in the case there was no change. But since that never happens in any case now, the guard if is not needed. You may also notice that the old log line as actually incorrect: it described the opposite of what really happened.
Comment on attachment 8974847 [details] Bug 1459899 - Reuse previous values when updating an existing rollout https://reviewboard.mozilla.org/r/243224/#review249318 ::: toolkit/components/normandy/actions/PreferenceRolloutAction.jsm:47 (Diff revision 1) > })), > }; > > const existingRollout = await PreferenceRollouts.get(args.slug); > if (existingRollout) { > + // Trust the existing rollout about the previous values This comment should be removed. ::: toolkit/components/normandy/actions/PreferenceRolloutAction.jsm:152 (Diff revision 1) > oldValue = oldPrefSpec.value; > + > + // Trust the old rollout for the values of `previousValue`, but don't > + // consider this a change, since it already matches the DB, and doesn't > + // have any other stateful effect. > + prefSpec.previousValue = oldPrefSpec.previousValue; I can't of a situation that could cause that, and if it does happen, it would be hard to recover from, since we can't trust any source for the previous value. If it does happen, then at the next restart the previousValue should be set from the built-in default before the rollout's value is set.
Comment on attachment 8974847 [details] Bug 1459899 - Reuse previous values when updating an existing rollout https://reviewboard.mozilla.org/r/243224/#review249526 OK, thanks for the clarification. This makes a lot more sense now, and yes this looks good to me. :-)
Attachment #8974847 - Flags: review+
Pushed by mcooper@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/1e476d9ff4bb Reuse previous values when updating an existing rollout r=Gijs
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 62
Flags: qe-verify+
Please request Beta approval on this when you're comfortable doing so.
Flags: needinfo?(mcooper)
Flags: in-testsuite+
Comment on attachment 8974847 [details] Bug 1459899 - Reuse previous values when updating an existing rollout Approval Request Comment [Feature/Bug causing the regression]: 1440782 [User impact if declined]: Incorrect telemetry events will be sent [Is this code covered by automated tests?]: Yes [Has the fix been verified in Nightly?]: Pending [Needs manual test from QE? If yes, steps to reproduce]: Yes, STR in comment 0 [List of other uplifts needed for the feature/fix]: None [Is the change risky?]: No [Why is the change risky/not risky?]: The underlying behavior is not changed, only the logging. [String changes made/needed]: None
Flags: needinfo?(mcooper)
Attachment #8974847 - Flags: approval-mozilla-beta?
Comment on attachment 8974847 [details] Bug 1459899 - Reuse previous values when updating an existing rollout Fix for the new Telemetry pref rollout work shipping in 61. Approved for 61.0b6.
Attachment #8974847 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
Verified as fixed on: 61.0b6 20180517141400 62.0a1 20180520220103 Verified that the rollout recipe updates are not logged anymore on stale recipes and logged correctly when the rollout type recipes are indeed updated. Telemetry is also verified to be logged accordingly.
Status: RESOLVED → VERIFIED
Flags: qe-verify+
Something interesting came up with this bug. We recently shipped the first pref rollout, targeting 10% Beta 61 (bug 1462164). In the data for that we got a fair number of spurious update events, enough that I was worried something was wrong. We analyzed the events coming in, grouping by buildid. The update events stopped after buildid 20180514150347. All events from buildid 20180517141400 and later had only the expected enrollment events. This both confirms that the bug was real and would have caused problems, and that the fix worked as expected in the wild.
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: