path: root/services/sync/modules/policies.js

/* This Source Code Form is subject to the terms of the Mozilla Public
 * License, v. 2.0. If a copy of the MPL was not distributed with this
 * file, You can obtain one at http://mozilla.org/MPL/2.0/. */

var EXPORTED_SYMBOLS = ["ErrorHandler", "SyncScheduler"];

const { XPCOMUtils } = ChromeUtils.importESModule(
  "resource://gre/modules/XPCOMUtils.sys.mjs"
);
const { Log } = ChromeUtils.importESModule(
  "resource://gre/modules/Log.sys.mjs"
);
const {
  CREDENTIALS_CHANGED,
  ENGINE_APPLY_FAIL,
  ENGINE_UNKNOWN_FAIL,
  IDLE_OBSERVER_BACK_DELAY,
  LOGIN_FAILED_INVALID_PASSPHRASE,
  LOGIN_FAILED_LOGIN_REJECTED,
  LOGIN_FAILED_NETWORK_ERROR,
  LOGIN_FAILED_NO_PASSPHRASE,
  LOGIN_SUCCEEDED,
  MASTER_PASSWORD_LOCKED,
  MASTER_PASSWORD_LOCKED_RETRY_INTERVAL,
  MAX_ERROR_COUNT_BEFORE_BACKOFF,
  MINIMUM_BACKOFF_INTERVAL,
  MULTI_DEVICE_THRESHOLD,
  NO_SYNC_NODE_FOUND,
  NO_SYNC_NODE_INTERVAL,
  OVER_QUOTA,
  RESPONSE_OVER_QUOTA,
  SCORE_UPDATE_DELAY,
  SERVER_MAINTENANCE,
  SINGLE_USER_THRESHOLD,
  STATUS_OK,
  SYNC_FAILED_PARTIAL,
  SYNC_SUCCEEDED,
  kSyncBackoffNotMet,
  kSyncMasterPasswordLocked,
} = ChromeUtils.import("resource://services-sync/constants.js");
const { Svc, Utils } = ChromeUtils.import("resource://services-sync/util.js");
const { logManager } = ChromeUtils.import(
  "resource://gre/modules/FxAccountsCommon.js"
);
const { Async } = ChromeUtils.import("resource://services-common/async.js");
const { CommonUtils } = ChromeUtils.import(
  "resource://services-common/utils.js"
);

const lazy = {};

ChromeUtils.defineModuleGetter(
  lazy,
  "Status",
  "resource://services-sync/status.js"
);
ChromeUtils.defineModuleGetter(
  lazy,
  "AddonManager",
  "resource://gre/modules/AddonManager.jsm"
);
XPCOMUtils.defineLazyGetter(lazy, "fxAccounts", () => {
  return ChromeUtils.import(
    "resource://gre/modules/FxAccounts.jsm"
  ).getFxAccountsSingleton();
});
XPCOMUtils.defineLazyServiceGetter(
  lazy,
  "IdleService",
  "@mozilla.org/widget/useridleservice;1",
  "nsIUserIdleService"
);
XPCOMUtils.defineLazyServiceGetter(
  lazy,
  "CaptivePortalService",
  "@mozilla.org/network/captive-portal-service;1",
  "nsICaptivePortalService"
);

// Get the value for an interval that's stored in preferences. To save users
// from themselves (and us from them!) the minimum time they can specify
// is 60s.
function getThrottledIntervalPreference(prefName) {
  return Math.max(Svc.Prefs.get(prefName), 60) * 1000;
}

function SyncScheduler(service) {
  this.service = service;
  this.init();
}
SyncScheduler.prototype = {
  _log: Log.repository.getLogger("Sync.SyncScheduler"),

  _fatalLoginStatus: [
    LOGIN_FAILED_NO_PASSPHRASE,
    LOGIN_FAILED_INVALID_PASSPHRASE,
    LOGIN_FAILED_LOGIN_REJECTED,
  ],

  /**
   * The nsITimer object that schedules the next sync. See scheduleNextSync().
   */
  syncTimer: null,

  setDefaults: function setDefaults() {
    this._log.trace("Setting SyncScheduler policy values to defaults.");

    this.singleDeviceInterval = getThrottledIntervalPreference(
      "scheduler.fxa.singleDeviceInterval"
    );
    this.idleInterval = getThrottledIntervalPreference(
      "scheduler.idleInterval"
    );
    this.activeInterval = getThrottledIntervalPreference(
      "scheduler.activeInterval"
    );
    this.immediateInterval = getThrottledIntervalPreference(
      "scheduler.immediateInterval"
    );

    // A user is non-idle on startup by default.
    this.idle = false;

    this.hasIncomingItems = false;
    // This is the last number of clients we saw when previously updating the
    // client mode. If this != currentNumClients (obtained from prefs written
    // by the clients engine) then we need to transition to and from
    // single and multi-device mode.
    this.numClientsLastSync = 0;

    this._resyncs = 0;

    this.clearSyncTriggers();
  },

  // nextSync is in milliseconds, but prefs can't hold that much
  get nextSync() {
    return Svc.Prefs.get("nextSync", 0) * 1000;
  },
  set nextSync(value) {
    Svc.Prefs.set("nextSync", Math.floor(value / 1000));
  },

  get missedFxACommandsFetchInterval() {
    return Services.prefs.getIntPref(
      "identity.fxaccounts.commands.missed.fetch_interval"
    );
  },

  get missedFxACommandsLastFetch() {
    return Services.prefs.getIntPref(
      "identity.fxaccounts.commands.missed.last_fetch",
      0
    );
  },

  set missedFxACommandsLastFetch(val) {
    Services.prefs.setIntPref(
      "identity.fxaccounts.commands.missed.last_fetch",
      val
    );
  },

  get syncInterval() {
    return this._syncInterval;
  },
  set syncInterval(value) {
    if (value != this._syncInterval) {
      Services.prefs.setIntPref("services.sync.syncInterval", value);
    }
  },

  get syncThreshold() {
    return this._syncThreshold;
  },
  set syncThreshold(value) {
    if (value != this._syncThreshold) {
      Services.prefs.setIntPref("services.sync.syncThreshold", value);
    }
  },

  get globalScore() {
    return this._globalScore;
  },
  set globalScore(value) {
    if (this._globalScore != value) {
      Services.prefs.setIntPref("services.sync.globalScore", value);
    }
  },

  // Managed by the clients engine (by way of prefs)
  get numClients() {
    return this.numDesktopClients + this.numMobileClients;
  },
  set numClients(value) {
    throw new Error("Don't set numClients - the clients engine manages it.");
  },

  get offline() {
    // Services.io.offline has slowly become fairly useless over the years - it
    // no longer attempts to track the actual network state by default, but one
    // thing stays true: if it says we're offline then we are definitely not online.
    //
    // We also ask the captive portal service if we are behind a locked captive
    // portal.
    //
    // We don't check on the NetworkLinkService however, because it gave us
    // false positives in the past in a vm environment.
    try {
      if (
        Services.io.offline ||
        lazy.CaptivePortalService.state ==
          lazy.CaptivePortalService.LOCKED_PORTAL
      ) {
        return true;
      }
    } catch (ex) {
      this._log.warn("Could not determine network status.", ex);
    }
    return false;
  },

  _initPrefGetters() {
    XPCOMUtils.defineLazyPreferenceGetter(
      this,
      "idleTime",
      "services.sync.scheduler.idleTime"
    );
    XPCOMUtils.defineLazyPreferenceGetter(
      this,
      "maxResyncs",
      "services.sync.maxResyncs",
      0
    );

    // The number of clients we have is maintained in preferences via the
    // clients engine, and only updated after a successsful sync.
    XPCOMUtils.defineLazyPreferenceGetter(
      this,
      "numDesktopClients",
      "services.sync.clients.devices.desktop",
      0
    );
    XPCOMUtils.defineLazyPreferenceGetter(
      this,
      "numMobileClients",
      "services.sync.clients.devices.mobile",
      0
    );

    // Scheduler state that seems to be read more often than it's written.
    // We also check if the value has changed before writing in the setters.
    XPCOMUtils.defineLazyPreferenceGetter(
      this,
      "_syncThreshold",
      "services.sync.syncThreshold",
      SINGLE_USER_THRESHOLD
    );
    XPCOMUtils.defineLazyPreferenceGetter(
      this,
      "_syncInterval",
      "services.sync.syncInterval",
      this.singleDeviceInterval
    );
    XPCOMUtils.defineLazyPreferenceGetter(
      this,
      "_globalScore",
      "services.sync.globalScore",
      0
    );
  },

  init: function init() {
    this._log.manageLevelFromPref("services.sync.log.logger.service.main");
    this.setDefaults();
    this._initPrefGetters();
    Svc.Obs.add("weave:engine:score:updated", this);
    Svc.Obs.add("network:offline-status-changed", this);
    Svc.Obs.add("network:link-status-changed", this);
    Svc.Obs.add("captive-portal-detected", this);
    Svc.Obs.add("weave:service:sync:start", this);
    Svc.Obs.add("weave:service:sync:finish", this);
    Svc.Obs.add("weave:engine:sync:finish", this);
    Svc.Obs.add("weave:engine:sync:error", this);
    Svc.Obs.add("weave:service:login:error", this);
    Svc.Obs.add("weave:service:logout:finish", this);
    Svc.Obs.add("weave:service:sync:error", this);
    Svc.Obs.add("weave:service:backoff:interval", this);
    Svc.Obs.add("weave:engine:sync:applied", this);
    Svc.Obs.add("weave:service:setup-complete", this);
    Svc.Obs.add("weave:service:start-over", this);
    Svc.Obs.add("FxA:hawk:backoff:interval", this);

    if (lazy.Status.checkSetup() == STATUS_OK) {
      Svc.Obs.add("wake_notification", this);
      Svc.Obs.add("captive-portal-login-success", this);
      Svc.Obs.add("sleep_notification", this);
      lazy.IdleService.addIdleObserver(this, this.idleTime);
    }
  },

  // eslint-disable-next-line complexity
  observe: function observe(subject, topic, data) {
    this._log.trace("Handling " + topic);
    switch (topic) {
      case "weave:engine:score:updated":
        if (lazy.Status.login == LOGIN_SUCCEEDED) {
          CommonUtils.namedTimer(
            this.calculateScore,
            SCORE_UPDATE_DELAY,
            this,
            "_scoreTimer"
          );
        }
        break;
      case "network:link-status-changed":
        // Note: NetworkLinkService is unreliable, we get false negatives for it
        // in cases such as VMs (bug 1420802), so we don't want to use it in
        // `get offline`, but we assume that it's probably reliable if we're
        // getting status changed events. (We might be wrong about this, but
        // if that's true, then the only downside is that we won't sync as
        // promptly).
        let isOffline = this.offline;
        this._log.debug(
          `Network link status changed to "${data}". Offline?`,
          isOffline
        );
        // Data may be one of `up`, `down`, `change`, or `unknown`. We only want
        // to sync if it's "up".
        if (data == "up" && !isOffline) {
          this._log.debug("Network link looks up. Syncing.");
          this.scheduleNextSync(0, { why: topic });
        } else if (data == "down") {
          // Unschedule pending syncs if we know we're going down. We don't do
          // this via `checkSyncStatus`, since link status isn't reflected in
          // `this.offline`.
          this.clearSyncTriggers();
        }
        break;
      case "network:offline-status-changed":
      case "captive-portal-detected":
        // Whether online or offline, we'll reschedule syncs
        this._log.trace("Network offline status change: " + data);
        this.checkSyncStatus();
        break;
      case "weave:service:sync:start":
        // Clear out any potentially pending syncs now that we're syncing
        this.clearSyncTriggers();

        // reset backoff info, if the server tells us to continue backing off,
        // we'll handle that later
        lazy.Status.resetBackoff();

        this.globalScore = 0;
        break;
      case "weave:service:sync:finish":
        this.nextSync = 0;
        this.adjustSyncInterval();

        if (
          lazy.Status.service == SYNC_FAILED_PARTIAL &&
          this.requiresBackoff
        ) {
          this.requiresBackoff = false;
          this.handleSyncError();
          return;
        }

        let sync_interval;
        let nextSyncReason = "schedule";
        this.updateGlobalScore();
        if (
          this.globalScore > this.syncThreshold &&
          lazy.Status.service == STATUS_OK
        ) {
          // The global score should be 0 after a sync. If it's not, either
          // items were changed during the last sync (and we should schedule an
          // immediate follow-up sync), or an engine skipped
          this._resyncs++;
          if (this._resyncs <= this.maxResyncs) {
            sync_interval = 0;
            nextSyncReason = "resync";
          } else {
            this._log.warn(
              `Resync attempt ${this._resyncs} exceeded ` +
                `maximum ${this.maxResyncs}`
            );
            Svc.Obs.notify("weave:service:resyncs-finished");
          }
        } else {
          this._resyncs = 0;
          Svc.Obs.notify("weave:service:resyncs-finished");
        }

        this._syncErrors = 0;
        if (lazy.Status.sync == NO_SYNC_NODE_FOUND) {
          // If we don't have a Sync node, override the interval, even if we've
          // scheduled a follow-up sync.
          this._log.trace("Scheduling a sync at interval NO_SYNC_NODE_FOUND.");
          sync_interval = NO_SYNC_NODE_INTERVAL;
        }
        this.scheduleNextSync(sync_interval, { why: nextSyncReason });
        break;
      case "weave:engine:sync:finish":
        if (data == "clients") {
          // Update the client mode because it might change what we sync.
          this.updateClientMode();
        }
        break;
      case "weave:engine:sync:error":
        // `subject` is the exception thrown by an engine's sync() method.
        let exception = subject;
        if (exception.status >= 500 && exception.status <= 504) {
          this.requiresBackoff = true;
        }
        break;
      case "weave:service:login:error":
        this.clearSyncTriggers();

        if (lazy.Status.login == MASTER_PASSWORD_LOCKED) {
          // Try again later, just as if we threw an error... only without the
          // error count.
          this._log.debug("Couldn't log in: master password is locked.");
          this._log.trace(
            "Scheduling a sync at MASTER_PASSWORD_LOCKED_RETRY_INTERVAL"
          );
          this.scheduleAtInterval(MASTER_PASSWORD_LOCKED_RETRY_INTERVAL);
        } else if (!this._fatalLoginStatus.includes(lazy.Status.login)) {
          // Not a fatal login error, just an intermittent network or server
          // issue. Keep on syncin'.
          this.checkSyncStatus();
        }
        break;
      case "weave:service:logout:finish":
        // Start or cancel the sync timer depending on if
        // logged in or logged out
        this.checkSyncStatus();
        break;
      case "weave:service:sync:error":
        // There may be multiple clients but if the sync fails, client mode
        // should still be updated so that the next sync has a correct interval.
        this.updateClientMode();
        this.adjustSyncInterval();
        this.nextSync = 0;
        this.handleSyncError();
        break;
      case "FxA:hawk:backoff:interval":
      case "weave:service:backoff:interval":
        let requested_interval = subject * 1000;
        this._log.debug(
          "Got backoff notification: " + requested_interval + "ms"
        );
        // Leave up to 25% more time for the back off.
        let interval = requested_interval * (1 + Math.random() * 0.25);
        lazy.Status.backoffInterval = interval;
        lazy.Status.minimumNextSync = Date.now() + requested_interval;
        this._log.debug(
          "Fuzzed minimum next sync: " + lazy.Status.minimumNextSync
        );
        break;
      case "weave:engine:sync:applied":
        let numItems = subject.succeeded;
        this._log.trace(
          "Engine " + data + " successfully applied " + numItems + " items."
        );
        // Bug 1800186 - the tabs engine always reports incoming items, so we don't
        // want special scheduling in this scenario.
        // (However, even when we fix the underlying cause of that, we probably still can
        // ignore tabs here - new incoming tabs don't need to trigger the extra syncs we do
        // based on this flag.)
        if (data != "tabs" && numItems) {
          this.hasIncomingItems = true;
        }
        if (subject.newFailed) {
          this._log.error(
            `Engine ${data} found ${subject.newFailed} new records that failed to apply`
          );
        }
        break;
      case "weave:service:setup-complete":
        Services.prefs.savePrefFile(null);
        lazy.IdleService.addIdleObserver(this, this.idleTime);
        Svc.Obs.add("wake_notification", this);
        Svc.Obs.add("captive-portal-login-success", this);
        Svc.Obs.add("sleep_notification", this);
        break;
      case "weave:service:start-over":
        this.setDefaults();
        try {
          lazy.IdleService.removeIdleObserver(this, this.idleTime);
        } catch (ex) {
          if (ex.result != Cr.NS_ERROR_FAILURE) {
            throw ex;
          }
          // In all likelihood we didn't have an idle observer registered yet.
          // It's all good.
        }
        break;
      case "idle":
        this._log.trace("We're idle.");
        this.idle = true;
        // Adjust the interval for future syncs. This won't actually have any
        // effect until the next pending sync (which will happen soon since we
        // were just active.)
        this.adjustSyncInterval();
        break;
      case "active":
        this._log.trace("Received notification that we're back from idle.");
        this.idle = false;
        CommonUtils.namedTimer(
          function onBack() {
            if (this.idle) {
              this._log.trace(
                "... and we're idle again. " +
                  "Ignoring spurious back notification."
              );
              return;
            }

            this._log.trace("Genuine return from idle. Syncing.");
            // Trigger a sync if we have multiple clients.
            if (this.numClients > 1) {
              this.scheduleNextSync(0, { why: topic });
            }
          },
          IDLE_OBSERVER_BACK_DELAY,
          this,
          "idleDebouncerTimer"
        );
        break;
      case "wake_notification":
        this._log.debug("Woke from sleep.");
        CommonUtils.nextTick(() => {
          // Trigger a sync if we have multiple clients. We give it 2 seconds
          // so the browser can recover from the wake and do more important
          // operations first (timers etc).
          if (this.numClients > 1) {
            if (!this.offline) {
              this._log.debug("Online, will sync in 2s.");
              this.scheduleNextSync(2000, { why: topic });
            }
          }
        });
        break;
      case "captive-portal-login-success":
        this._log.debug("Captive portal login success. Scheduling a sync.");
        CommonUtils.nextTick(() => {
          this.scheduleNextSync(3000, { why: topic });
        });
        break;
      case "sleep_notification":
        if (this.service.engineManager.get("tabs")._tracker.modified) {
          this._log.debug("Going to sleep, doing a quick sync.");
          this.scheduleNextSync(0, { engines: ["tabs"], why: "sleep" });
        }
        break;
    }
  },

  adjustSyncInterval: function adjustSyncInterval() {
    if (this.numClients <= 1) {
      this._log.trace("Adjusting syncInterval to singleDeviceInterval.");
      this.syncInterval = this.singleDeviceInterval;
      return;
    }

    // Only MULTI_DEVICE clients will enter this if statement
    // since SINGLE_USER clients will be handled above.
    if (this.idle) {
      this._log.trace("Adjusting syncInterval to idleInterval.");
      this.syncInterval = this.idleInterval;
      return;
    }

    if (this.hasIncomingItems) {
      this._log.trace("Adjusting syncInterval to immediateInterval.");
      this.hasIncomingItems = false;
      this.syncInterval = this.immediateInterval;
    } else {
      this._log.trace("Adjusting syncInterval to activeInterval.");
      this.syncInterval = this.activeInterval;
    }
  },

  updateGlobalScore() {
    let engines = [this.service.clientsEngine].concat(
      this.service.engineManager.getEnabled()
    );
    let globalScore = this.globalScore;
    for (let i = 0; i < engines.length; i++) {
      this._log.trace(engines[i].name + ": score: " + engines[i].score);
      globalScore += engines[i].score;
      engines[i]._tracker.resetScore();
    }
    this.globalScore = globalScore;
    this._log.trace("Global score updated: " + globalScore);
  },

  calculateScore() {
    this.updateGlobalScore();
    this.checkSyncStatus();
  },

  /**
   * Query the number of known clients to figure out what mode to be in
   */
  updateClientMode: function updateClientMode() {
    // Nothing to do if it's the same amount
    let numClients = this.numClients;
    if (numClients == this.numClientsLastSync) {
      return;
    }

    this._log.debug(
      `Client count: ${this.numClientsLastSync} -> ${numClients}`
    );
    this.numClientsLastSync = numClients;

    if (numClients <= 1) {
      this._log.trace("Adjusting syncThreshold to SINGLE_USER_THRESHOLD");
      this.syncThreshold = SINGLE_USER_THRESHOLD;
    } else {
      this._log.trace("Adjusting syncThreshold to MULTI_DEVICE_THRESHOLD");
      this.syncThreshold = MULTI_DEVICE_THRESHOLD;
    }
    this.adjustSyncInterval();
  },

  /**
   * Check if we should be syncing and schedule the next sync, if it's not scheduled
   */
  checkSyncStatus: function checkSyncStatus() {
    // Should we be syncing now, if not, cancel any sync timers and return
    // if we're in backoff, we'll schedule the next sync.
    let ignore = [kSyncBackoffNotMet, kSyncMasterPasswordLocked];
    let skip = this.service._checkSync(ignore);
    this._log.trace('_checkSync returned "' + skip + '".');
    if (skip) {
      this.clearSyncTriggers();
      return;
    }

    let why = "schedule";
    // Only set the wait time to 0 if we need to sync right away
    let wait;
    if (this.globalScore > this.syncThreshold) {
      this._log.debug("Global Score threshold hit, triggering sync.");
      wait = 0;
      why = "score";
    }
    this.scheduleNextSync(wait, { why });
  },

  /**
   * Call sync() if Master Password is not locked.
   *
   * Otherwise, reschedule a sync for later.
   */
  syncIfMPUnlocked(engines, why) {
    // No point if we got kicked out by the master password dialog.
    if (lazy.Status.login == MASTER_PASSWORD_LOCKED && Utils.mpLocked()) {
      this._log.debug(
        "Not initiating sync: Login status is " + lazy.Status.login
      );

      // If we're not syncing now, we need to schedule the next one.
      this._log.trace(
        "Scheduling a sync at MASTER_PASSWORD_LOCKED_RETRY_INTERVAL"
      );
      this.scheduleAtInterval(MASTER_PASSWORD_LOCKED_RETRY_INTERVAL);
      return;
    }

    if (!Async.isAppReady()) {
      this._log.debug("Not initiating sync: app is shutting down");
      return;
    }
    Services.tm.dispatchToMainThread(() => {
      this.service.sync({ engines, why });
      const now = Math.round(new Date().getTime() / 1000);
      // Only fetch missed messages in a "scheduled" sync so we don't race against
      // the Push service reconnecting on a network link change for example.
      if (
        why == "schedule" &&
        now >=
          this.missedFxACommandsLastFetch + this.missedFxACommandsFetchInterval
      ) {
        lazy.fxAccounts.commands
          .pollDeviceCommands()
          .then(() => {
            this.missedFxACommandsLastFetch = now;
          })
          .catch(e => {
            this._log.error("Fetching missed remote commands failed.", e);
          });
      }
    });
  },

  /**
   * Set a timer for the next sync
   */
  scheduleNextSync(interval, { engines = null, why = null } = {}) {
    // If no interval was specified, use the current sync interval.
    if (interval == null) {
      interval = this.syncInterval;
    }

    // Ensure the interval is set to no less than the backoff.
    if (lazy.Status.backoffInterval && interval < lazy.Status.backoffInterval) {
      this._log.trace(
        "Requested interval " +
          interval +
          " ms is smaller than the backoff interval. " +
          "Using backoff interval " +
          lazy.Status.backoffInterval +
          " ms instead."
      );
      interval = lazy.Status.backoffInterval;
    }
    let nextSync = this.nextSync;
    if (nextSync != 0) {
      // There's already a sync scheduled. Don't reschedule if there's already
      // a timer scheduled for sooner than requested.
      let currentInterval = nextSync - Date.now();
      this._log.trace(
        "There's already a sync scheduled in " + currentInterval + " ms."
      );
      if (currentInterval < interval && this.syncTimer) {
        this._log.trace(
          "Ignoring scheduling request for next sync in " + interval + " ms."
        );
        return;
      }
    }

    // Start the sync right away if we're already late.
    if (interval <= 0) {
      this._log.trace(`Requested sync should happen right away. (why=${why})`);
      this.syncIfMPUnlocked(engines, why);
      return;
    }

    this._log.debug(`Next sync in ${interval} ms. (why=${why})`);
    CommonUtils.namedTimer(
      () => {
        this.syncIfMPUnlocked(engines, why);
      },
      interval,
      this,
      "syncTimer"
    );

    // Save the next sync time in-case sync is disabled (logout/offline/etc.)
    this.nextSync = Date.now() + interval;
  },

  /**
   * Incorporates the backoff/retry logic used in error handling and elective
   * non-syncing.
   */
  scheduleAtInterval: function scheduleAtInterval(minimumInterval) {
    let interval = Utils.calculateBackoff(
      this._syncErrors,
      MINIMUM_BACKOFF_INTERVAL,
      lazy.Status.backoffInterval
    );
    if (minimumInterval) {
      interval = Math.max(minimumInterval, interval);
    }

    this._log.debug(
      "Starting client-initiated backoff. Next sync in " + interval + " ms."
    );
    this.scheduleNextSync(interval, { why: "client-backoff-schedule" });
  },

  autoConnect: function autoConnect() {
    if (this.service._checkSetup() == STATUS_OK && !this.service._checkSync()) {
      // Schedule a sync based on when a previous sync was scheduled.
      // scheduleNextSync() will do the right thing if that time lies in
      // the past.
      this.scheduleNextSync(this.nextSync - Date.now(), { why: "startup" });
    }
  },

  _syncErrors: 0,
  /**
   * Deal with sync errors appropriately
   */
  handleSyncError: function handleSyncError() {
    this._log.trace("In handleSyncError. Error count: " + this._syncErrors);
    this._syncErrors++;

    // Do nothing on the first couple of failures, if we're not in
    // backoff due to 5xx errors.
    if (!lazy.Status.enforceBackoff) {
      if (this._syncErrors < MAX_ERROR_COUNT_BEFORE_BACKOFF) {
        this.scheduleNextSync(null, { why: "reschedule" });
        return;
      }
      this._log.debug(
        "Sync error count has exceeded " +
          MAX_ERROR_COUNT_BEFORE_BACKOFF +
          "; enforcing backoff."
      );
      lazy.Status.enforceBackoff = true;
    }

    this.scheduleAtInterval();
  },

  /**
   * Remove any timers/observers that might trigger a sync
   */
  clearSyncTriggers: function clearSyncTriggers() {
    this._log.debug("Clearing sync triggers and the global score.");
    this.globalScore = this.nextSync = 0;

    // Clear out any scheduled syncs
    if (this.syncTimer) {
      this.syncTimer.clear();
    }
  },
};

function ErrorHandler(service) {
  this.service = service;
  this.init();
}
ErrorHandler.prototype = {
  init() {
    Svc.Obs.add("weave:engine:sync:applied", this);
    Svc.Obs.add("weave:engine:sync:error", this);
    Svc.Obs.add("weave:service:login:error", this);
    Svc.Obs.add("weave:service:sync:error", this);
    Svc.Obs.add("weave:service:sync:finish", this);
    Svc.Obs.add("weave:service:start-over:finish", this);

    this.initLogs();
  },

  initLogs: function initLogs() {
    // Set the root Sync logger level based on a pref. All other logs will
    // inherit this level unless they specifically override it.
    Log.repository
      .getLogger("Sync")
      .manageLevelFromPref(`services.sync.log.logger`);
    // And allow our specific log to have a custom level via a pref.
    this._log = Log.repository.getLogger("Sync.ErrorHandler");
    this._log.manageLevelFromPref("services.sync.log.logger.service.main");
  },

  observe(subject, topic, data) {
    this._log.trace("Handling " + topic);
    switch (topic) {
      case "weave:engine:sync:applied":
        if (subject.newFailed) {
          // An engine isn't able to apply one or more incoming records.
          // We don't fail hard on this, but it usually indicates a bug,
          // so for now treat it as sync error (c.f. Service._syncEngine())
          lazy.Status.engines = [data, ENGINE_APPLY_FAIL];
          this._log.debug(data + " failed to apply some records.");
        }
        break;
      case "weave:engine:sync:error": {
        let exception = subject; // exception thrown by engine's sync() method
        let engine_name = data; // engine name that threw the exception

        this.checkServerError(exception);

        lazy.Status.engines = [
          engine_name,
          exception.failureCode || ENGINE_UNKNOWN_FAIL,
        ];
        if (Async.isShutdownException(exception)) {
          this._log.debug(
            engine_name +
              " was interrupted due to the application shutting down"
          );
        } else {
          this._log.debug(engine_name + " failed", exception);
        }
        break;
      }
      case "weave:service:login:error":
        this._log.error("Sync encountered a login error");
        this.resetFileLog();
        break;
      case "weave:service:sync:error": {
        if (lazy.Status.sync == CREDENTIALS_CHANGED) {
          this.service.logout();
        }

        let exception = subject;
        if (Async.isShutdownException(exception)) {
          // If we are shutting down we just log the fact, attempt to flush
          // the log file and get out of here!
          this._log.error(
            "Sync was interrupted due to the application shutting down"
          );
          this.resetFileLog();
          break;
        }

        // Not a shutdown related exception...
        this._log.error("Sync encountered an error", exception);
        this.resetFileLog();
        break;
      }
      case "weave:service:sync:finish":
        this._log.trace("Status.service is " + lazy.Status.service);

        // Check both of these status codes: in the event of a failure in one
        // engine, Status.service will be SYNC_FAILED_PARTIAL despite
        // Status.sync being SYNC_SUCCEEDED.
        // *facepalm*
        if (
          lazy.Status.sync == SYNC_SUCCEEDED &&
          lazy.Status.service == STATUS_OK
        ) {
          // Great. Let's clear our mid-sync 401 note.
          this._log.trace("Clearing lastSyncReassigned.");
          Svc.Prefs.reset("lastSyncReassigned");
        }

        if (lazy.Status.service == SYNC_FAILED_PARTIAL) {
          this._log.error("Some engines did not sync correctly.");
        }
        this.resetFileLog();
        break;
      case "weave:service:start-over:finish":
        // ensure we capture any logs between the last sync and the reset completing.
        this.resetFileLog()
          .then(() => {
            // although for privacy reasons we also delete all logs (but we allow
            // a preference to avoid this to help with debugging.)
            if (!Svc.Prefs.get("log.keepLogsOnReset", false)) {
              return logManager.removeAllLogs().then(() => {
                Svc.Obs.notify("weave:service:remove-file-log");
              });
            }
            return null;
          })
          .catch(err => {
            // So we failed to delete the logs - take the ironic option of
            // writing this error to the logs we failed to delete!
            this._log.error("Failed to delete logs on reset", err);
          });
        break;
    }
  },

  async _dumpAddons() {
    // Just dump the items that sync may be concerned with. Specifically,
    // active extensions that are not hidden.
    let addons = [];
    try {
      addons = await lazy.AddonManager.getAddonsByTypes(["extension"]);
    } catch (e) {
      this._log.warn("Failed to dump addons", e);
    }

    let relevantAddons = addons.filter(x => x.isActive && !x.hidden);
    this._log.trace("Addons installed", relevantAddons.length);
    for (let addon of relevantAddons) {
      this._log.trace(" - ${name}, version ${version}, id ${id}", addon);
    }
  },

  /**
   * Generate a log file for the sync that just completed
   * and refresh the input & output streams.
   */
  async resetFileLog() {
    // If we're writing an error log, dump extensions that may be causing problems.
    if (logManager.sawError) {
      await this._dumpAddons();
    }
    const logType = await logManager.resetFileLog();
    if (logType == logManager.ERROR_LOG_WRITTEN) {
      console.error(
        "Sync encountered an error - see about:sync-log for the log file."
      );
    }
    Svc.Obs.notify("weave:service:reset-file-log");
  },

  /**
   * Handle HTTP response results or exceptions and set the appropriate
   * Status.* bits.
   *
   * This method also looks for "side-channel" warnings.
   */
  checkServerError(resp) {
    // In this case we were passed a resolved value of Resource#_doRequest.
    switch (resp.status) {
      case 400:
        if (resp == RESPONSE_OVER_QUOTA) {
          lazy.Status.sync = OVER_QUOTA;
        }
        break;

      case 401:
        this.service.logout();
        this._log.info("Got 401 response; resetting clusterURL.");
        this.service.clusterURL = null;

        let delay = 0;
        if (Svc.Prefs.get("lastSyncReassigned")) {
          // We got a 401 in the middle of the previous sync, and we just got
          // another. Login must have succeeded in order for us to get here, so
          // the password should be correct.
          // This is likely to be an intermittent server issue, so back off and
          // give it time to recover.
          this._log.warn("Last sync also failed for 401. Delaying next sync.");
          delay = MINIMUM_BACKOFF_INTERVAL;
        } else {
          this._log.debug("New mid-sync 401 failure. Making a note.");
          Svc.Prefs.set("lastSyncReassigned", true);
        }
        this._log.info("Attempting to schedule another sync.");
        this.service.scheduler.scheduleNextSync(delay, { why: "reschedule" });
        break;

      case 500:
      case 502:
      case 503:
      case 504:
        lazy.Status.enforceBackoff = true;
        if (resp.status == 503 && resp.headers["retry-after"]) {
          let retryAfter = resp.headers["retry-after"];
          this._log.debug("Got Retry-After: " + retryAfter);
          if (this.service.isLoggedIn) {
            lazy.Status.sync = SERVER_MAINTENANCE;
          } else {
            lazy.Status.login = SERVER_MAINTENANCE;
          }
          Svc.Obs.notify(
            "weave:service:backoff:interval",
            parseInt(retryAfter, 10)
          );
        }
        break;
    }

    // In this other case we were passed a rejection value.
    switch (resp.result) {
      case Cr.NS_ERROR_UNKNOWN_HOST:
      case Cr.NS_ERROR_CONNECTION_REFUSED:
      case Cr.NS_ERROR_NET_TIMEOUT:
      case Cr.NS_ERROR_NET_RESET:
      case Cr.NS_ERROR_NET_INTERRUPT:
      case Cr.NS_ERROR_PROXY_CONNECTION_REFUSED:
        // The constant says it's about login, but in fact it just
        // indicates general network error.
        if (this.service.isLoggedIn) {
          lazy.Status.sync = LOGIN_FAILED_NETWORK_ERROR;
        } else {
          lazy.Status.login = LOGIN_FAILED_NETWORK_ERROR;
        }
        break;
    }
  },
};