Closed Bug 1553125 Opened 6 months ago Closed 6 months ago

[Intermittent] Normandy recipes are not always fetched at browser start-up with “app.normandy.dev_mode” set to true

Categories

(Firefox :: Normandy Client, defect)

defect
Not set

Tracking

()

VERIFIED FIXED
Firefox 69
Tracking Status
firefox-esr60 --- unaffected
firefox67 --- unaffected
firefox67.0.1 --- unaffected
firefox68 --- verified
firefox69 --- verified

People

(Reporter: acupsa, Assigned: mythmon)

Details

(Keywords: regression)

Attachments

(3 files)

[Affected versions]:

  • Firefox Beta 68.0b3 [Build ID 20190520131124, User Agent Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:68.0) Gecko/20100101 Firefox/68.0]
  • Firefox Nightly 69.0b1 [Build ID 20190521094447, User Agent Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:69.0) Gecko/20100101 Firefox/69.0]

[Affected Platforms]:

  • All Windows
  • All Mac
  • All Linux

[Prerequisites]:

  • Access to NORMANDY Delivery Console https://delivery-console.stage.mozaws.net/ is needed.
  • Set the app.normandy.dev_mode preference to true to run recipes immediately on startup.
  • Set the app.normandy.logging.level preference to 0 to enable more logging.
  • 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.
  • Set the preference value for app.normandy.api_url to https://stage.normandy.nonprod.cloudops.mozgcp.net/api/v1.
  • Set the services.settings.server preference to https://settings.stage.mozaws.net/v1.
  • You have one or more active recipes targeting a specific profile.
  • Have the browser console opened.

[Steps to reproduce]:

  1. Open the browser with the profile targeted in the prerequisites.
  2. Wait ~2-5 minutes.
  3. Observe the browser console.

[Expected result]:

  • The recipe from the prerequisites is fetched and executed.

[Actual result]:

[Notes]:

  • In some cases the recipes are fetched after restarting the browser after the errors are displayed in the browser console.
  • In some cases the errors are not displayed only after restarting the browser and the recipes are instantly fetched.
  • In some cases the recipes are not fetched at all.
  • I used the filter expression: 'andreea'|preferenceExists and I was expecting to get the following recipes: #714, #715, #716, #717
  • Here is a screen recording with the issue.
  • Attached a screenshot of errors I get in the browser console.

As of Firefox 68, Normandy relies on Remote Settings to fetch recipes. Because of this, a failure in RS means Normandy doesn't run at all. From the errors reported, that seems to be the case.

My theory about the recipes sometimes being fetched and sometimes not is that dev mode doesn't interact with the timer that also runs Normandy. Because of this, the first run triggered by dev mode might fail, but then the second run triggered by the timer might succeed. The opposite may also be true.

Something else to note: with dev mode turned on, Normandy should execute most recipes within seconds, not "~2-5 minutes". That 2-5 minute is when a normal timer-based run would kick in. In the screen recording I noticed a lot of scrollbar in the browser console that might contain useful info. Could you attach all of the console logs by right clicking on the console and choosing "Export visible messages to clipboard"? Attaching that in the bug would be helpful.

Attached the browser console logs.

While running the regression range for bug 1553198, I have noticed that builds downloaded with mozregression instantly fetch and execute recipes.
And while having a Firefox build with the same build ID as the one downloaded by mozregression, installed or unzipped, and opened from the cmd, it does not fetch recipes.

The only difference between a mozregression downloaded build and one from ftp.mozilla.org is that the mozregression one has the "Allow Nightly to send technical and interaction data to Mozilla" option off by default. And when I turn it back on, the recipes are fetched after the first restart.
I tried opening a profile of an unzipped build, and deactivate the option, restart and reactivate it and it still didn't fetch any recipes.

@mythmon, not sure if this will help debug this issue but I've started using the remote-settings-devtools addon to see if I can force a check for recipes. And it looks like my Local Timestamp is not in sync with the Remote Timestamp for main/normandy-recipes. If I clear the local data and the Force sync, the recipes are fetched on the next browser start-up.

I think the issue here is that we don't force a sync when we execute recipes for the dev_mode run. Instead we get some sort of race condition between when Normandy runs and when RS syncs the data, except the first time. When there is no data, RS always fetches. I am working on a patch to make Normandy's dev_mode trigger a sync even if there is already data, so that we can fix this.

Assignee: nobody → mcooper
Status: NEW → ASSIGNED
Pushed by mcooper@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/7beae3feb834
Force a recipes sync when Normandy is in dev mode r=leplatrem
Status: ASSIGNED → RESOLVED
Closed: 6 months ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 69

I have verified that the issue is no longer reproducible on the latest Nightly 69.0a1 (Build ID 20190530094559) on Windows 10, macOS 10.14, and Arch Linux 4.14.3.

@mythmon, is there any chance we can uplift this fix to Beta?

Status: RESOLVED → VERIFIED
Flags: needinfo?(mcooper)

Comment on attachment 9068181 [details]
Bug 1553125 - Force a recipes sync when Normandy is in dev mode r?leplatrem!

Beta/Release Uplift Approval Request

  • User impact if declined: Little to no user impact. This makes Normandy QA tests much easier to run.
  • Is this code covered by automated tests?: Yes
  • Has the fix been verified in Nightly?: Yes
  • Needs manual test from QE?: No
  • If yes, steps to reproduce:
  • List of other uplifts needed: None
  • Risk to taking this patch: Low
  • Why is the change risky/not risky? (and alternatives if risky): This is a change to a feature only used by QA and developers, and doesn't affect users.
  • String changes made/needed: none
Flags: needinfo?(mcooper)
Attachment #9068181 - Flags: approval-mozilla-beta?

Comment on attachment 9068181 [details]
Bug 1553125 - Force a recipes sync when Normandy is in dev mode r?leplatrem!

normandy fix, approved for 68.0b7

Attachment #9068181 - Flags: approval-mozilla-beta? → approval-mozilla-beta+

I tried uplifting the patch to beta and had a conflict in the grafting process in this file: toolkit/components/normandy/lib/RecipeRunner.jsm

Could you please take a look at this?

Flags: needinfo?(mcooper)

I tried the graft myself, and the merge conflict I got was the below. Removing the entire merge conflict (keeping the "local" side) resolve the conflict correctly for me. I've started a minimal try run with that change to confirm.

Alexandru: is this enough to uplift the patch?

<<<<<<< local
=======
  async setUpRemoteSettings() {
    const remoteSettingsGate = await gRemoteSettingsGate;
    if (await remoteSettingsGate.isEnabled()) {
      this.attachRemoteSettings();
    }
    const observer = {
      onEnable: this.attachRemoteSettings.bind(this),
      onDisable: this.detachRemoteSettings.bind(this),
    };
    remoteSettingsGate.addObserver(observer);
    CleanupManager.addCleanupHandler(() => remoteSettingsGate.removeObserver(observer));
  },

  attachRemoteSettings() {
    this.loadFromRemoteSettings = true;
    if (!this._onSync) {
      this._onSync = async () => {
        if (!this.enabled) {
          return;
        }
        this.run({ trigger: "sync" });
      };

      gRemoteSettingsClient.on("sync", this._onSync);
    }
  },

  detachRemoteSettings() {
    this.loadFromRemoteSettings = false;
    if (this._onSync) {
      // Ignore if no event listener was setup or was already removed (ie. pref changed while enabled).
      gRemoteSettingsClient.off("sync", this._onSync);
    }
    this._onSync = null;
  },

>>>>>>> graft
Flags: needinfo?(mcooper)

I have verified that the issue is no longer reproducible on the the latest Beta 68.0b8 (Build ID 20190606101422) on Windows 10, macOS 10.14, and Arch Linux 4.14.3.

You need to log in before you can comment on or make changes to this bug.