1 /* This Source Code Form is subject to the terms of the Mozilla Public
2 * License, v. 2.0. If a copy of the MPL was not distributed with this
3 * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
5 import { XPCOMUtils } from "resource://gre/modules/XPCOMUtils.sys.mjs";
7 import { Log } from "resource://gre/modules/Log.sys.mjs";
13 IDLE_OBSERVER_BACK_DELAY,
14 LOGIN_FAILED_INVALID_PASSPHRASE,
15 LOGIN_FAILED_LOGIN_REJECTED,
16 LOGIN_FAILED_NETWORK_ERROR,
17 LOGIN_FAILED_NO_PASSPHRASE,
19 MASTER_PASSWORD_LOCKED,
20 MASTER_PASSWORD_LOCKED_RETRY_INTERVAL,
21 MAX_ERROR_COUNT_BEFORE_BACKOFF,
22 MINIMUM_BACKOFF_INTERVAL,
23 MULTI_DEVICE_THRESHOLD,
25 NO_SYNC_NODE_INTERVAL,
30 SINGLE_USER_THRESHOLD,
35 kSyncMasterPasswordLocked,
36 } from "resource://services-sync/constants.sys.mjs";
38 import { Svc, Utils } from "resource://services-sync/util.sys.mjs";
40 import { logManager } from "resource://gre/modules/FxAccountsCommon.sys.mjs";
41 import { Async } from "resource://services-common/async.sys.mjs";
42 import { CommonUtils } from "resource://services-common/utils.sys.mjs";
46 ChromeUtils.defineESModuleGetters(lazy, {
47 AddonManager: "resource://gre/modules/AddonManager.sys.mjs",
48 Status: "resource://services-sync/status.sys.mjs",
50 ChromeUtils.defineLazyGetter(lazy, "fxAccounts", () => {
51 return ChromeUtils.importESModule(
52 "resource://gre/modules/FxAccounts.sys.mjs"
53 ).getFxAccountsSingleton();
55 XPCOMUtils.defineLazyServiceGetter(
58 "@mozilla.org/widget/useridleservice;1",
61 XPCOMUtils.defineLazyServiceGetter(
63 "CaptivePortalService",
64 "@mozilla.org/network/captive-portal-service;1",
65 "nsICaptivePortalService"
68 // Get the value for an interval that's stored in preferences. To save users
69 // from themselves (and us from them!) the minimum time they can specify
71 function getThrottledIntervalPreference(prefName) {
72 return Math.max(Svc.PrefBranch.getIntPref(prefName), 60) * 1000;
75 export function SyncScheduler(service) {
76 this.service = service;
80 SyncScheduler.prototype = {
81 _log: Log.repository.getLogger("Sync.SyncScheduler"),
84 LOGIN_FAILED_NO_PASSPHRASE,
85 LOGIN_FAILED_INVALID_PASSPHRASE,
86 LOGIN_FAILED_LOGIN_REJECTED,
90 * The nsITimer object that schedules the next sync. See scheduleNextSync().
94 setDefaults: function setDefaults() {
95 this._log.trace("Setting SyncScheduler policy values to defaults.");
97 this.singleDeviceInterval = getThrottledIntervalPreference(
98 "scheduler.fxa.singleDeviceInterval"
100 this.idleInterval = getThrottledIntervalPreference(
101 "scheduler.idleInterval"
103 this.activeInterval = getThrottledIntervalPreference(
104 "scheduler.activeInterval"
106 this.immediateInterval = getThrottledIntervalPreference(
107 "scheduler.immediateInterval"
110 // A user is non-idle on startup by default.
113 this.hasIncomingItems = false;
114 // This is the last number of clients we saw when previously updating the
115 // client mode. If this != currentNumClients (obtained from prefs written
116 // by the clients engine) then we need to transition to and from
117 // single and multi-device mode.
118 this.numClientsLastSync = 0;
122 this.clearSyncTriggers();
125 // nextSync is in milliseconds, but prefs can't hold that much
127 return Svc.PrefBranch.getIntPref("nextSync", 0) * 1000;
129 set nextSync(value) {
130 Svc.PrefBranch.setIntPref("nextSync", Math.floor(value / 1000));
133 get missedFxACommandsFetchInterval() {
134 return Services.prefs.getIntPref(
135 "identity.fxaccounts.commands.missed.fetch_interval"
139 get missedFxACommandsLastFetch() {
140 return Services.prefs.getIntPref(
141 "identity.fxaccounts.commands.missed.last_fetch",
146 set missedFxACommandsLastFetch(val) {
147 Services.prefs.setIntPref(
148 "identity.fxaccounts.commands.missed.last_fetch",
154 return this._syncInterval;
156 set syncInterval(value) {
157 if (value != this._syncInterval) {
158 Services.prefs.setIntPref("services.sync.syncInterval", value);
162 get syncThreshold() {
163 return this._syncThreshold;
165 set syncThreshold(value) {
166 if (value != this._syncThreshold) {
167 Services.prefs.setIntPref("services.sync.syncThreshold", value);
172 return this._globalScore;
174 set globalScore(value) {
175 if (this._globalScore != value) {
176 Services.prefs.setIntPref("services.sync.globalScore", value);
180 // Managed by the clients engine (by way of prefs)
182 return this.numDesktopClients + this.numMobileClients;
184 set numClients(value) {
185 throw new Error("Don't set numClients - the clients engine manages it.");
189 // Services.io.offline has slowly become fairly useless over the years - it
190 // no longer attempts to track the actual network state by default, but one
191 // thing stays true: if it says we're offline then we are definitely not online.
193 // We also ask the captive portal service if we are behind a locked captive
196 // We don't check on the NetworkLinkService however, because it gave us
197 // false positives in the past in a vm environment.
200 Services.io.offline ||
201 lazy.CaptivePortalService.state ==
202 lazy.CaptivePortalService.LOCKED_PORTAL
207 this._log.warn("Could not determine network status.", ex);
213 XPCOMUtils.defineLazyPreferenceGetter(
216 "services.sync.scheduler.idleTime"
218 XPCOMUtils.defineLazyPreferenceGetter(
221 "services.sync.maxResyncs",
225 // The number of clients we have is maintained in preferences via the
226 // clients engine, and only updated after a successsful sync.
227 XPCOMUtils.defineLazyPreferenceGetter(
230 "services.sync.clients.devices.desktop",
233 XPCOMUtils.defineLazyPreferenceGetter(
236 "services.sync.clients.devices.mobile",
240 // Scheduler state that seems to be read more often than it's written.
241 // We also check if the value has changed before writing in the setters.
242 XPCOMUtils.defineLazyPreferenceGetter(
245 "services.sync.syncThreshold",
246 SINGLE_USER_THRESHOLD
248 XPCOMUtils.defineLazyPreferenceGetter(
251 "services.sync.syncInterval",
252 this.singleDeviceInterval
254 XPCOMUtils.defineLazyPreferenceGetter(
257 "services.sync.globalScore",
262 init: function init() {
263 this._log.manageLevelFromPref("services.sync.log.logger.service.main");
265 this._initPrefGetters();
266 Svc.Obs.add("weave:engine:score:updated", this);
267 Svc.Obs.add("network:offline-status-changed", this);
268 Svc.Obs.add("network:link-status-changed", this);
269 Svc.Obs.add("captive-portal-detected", this);
270 Svc.Obs.add("weave:service:sync:start", this);
271 Svc.Obs.add("weave:service:sync:finish", this);
272 Svc.Obs.add("weave:engine:sync:finish", this);
273 Svc.Obs.add("weave:engine:sync:error", this);
274 Svc.Obs.add("weave:service:login:error", this);
275 Svc.Obs.add("weave:service:logout:finish", this);
276 Svc.Obs.add("weave:service:sync:error", this);
277 Svc.Obs.add("weave:service:backoff:interval", this);
278 Svc.Obs.add("weave:engine:sync:applied", this);
279 Svc.Obs.add("weave:service:setup-complete", this);
280 Svc.Obs.add("weave:service:start-over", this);
281 Svc.Obs.add("FxA:hawk:backoff:interval", this);
283 if (lazy.Status.checkSetup() == STATUS_OK) {
284 Svc.Obs.add("wake_notification", this);
285 Svc.Obs.add("captive-portal-login-success", this);
286 Svc.Obs.add("sleep_notification", this);
287 lazy.IdleService.addIdleObserver(this, this.idleTime);
291 // eslint-disable-next-line complexity
292 observe: function observe(subject, topic, data) {
293 this._log.trace("Handling " + topic);
295 case "weave:engine:score:updated":
296 if (lazy.Status.login == LOGIN_SUCCEEDED) {
297 CommonUtils.namedTimer(
305 case "network:link-status-changed":
306 // Note: NetworkLinkService is unreliable, we get false negatives for it
307 // in cases such as VMs (bug 1420802), so we don't want to use it in
308 // `get offline`, but we assume that it's probably reliable if we're
309 // getting status changed events. (We might be wrong about this, but
310 // if that's true, then the only downside is that we won't sync as
312 let isOffline = this.offline;
314 `Network link status changed to "${data}". Offline?`,
317 // Data may be one of `up`, `down`, `change`, or `unknown`. We only want
318 // to sync if it's "up".
319 if (data == "up" && !isOffline) {
320 this._log.debug("Network link looks up. Syncing.");
321 this.scheduleNextSync(0, { why: topic });
322 } else if (data == "down") {
323 // Unschedule pending syncs if we know we're going down. We don't do
324 // this via `checkSyncStatus`, since link status isn't reflected in
326 this.clearSyncTriggers();
329 case "network:offline-status-changed":
330 case "captive-portal-detected":
331 // Whether online or offline, we'll reschedule syncs
332 this._log.trace("Network offline status change: " + data);
333 this.checkSyncStatus();
335 case "weave:service:sync:start":
336 // Clear out any potentially pending syncs now that we're syncing
337 this.clearSyncTriggers();
339 // reset backoff info, if the server tells us to continue backing off,
340 // we'll handle that later
341 lazy.Status.resetBackoff();
343 this.globalScore = 0;
345 case "weave:service:sync:finish":
347 this.adjustSyncInterval();
350 lazy.Status.service == SYNC_FAILED_PARTIAL &&
353 this.requiresBackoff = false;
354 this.handleSyncError();
359 let nextSyncReason = "schedule";
360 this.updateGlobalScore();
362 this.globalScore > this.syncThreshold &&
363 lazy.Status.service == STATUS_OK
365 // The global score should be 0 after a sync. If it's not, either
366 // items were changed during the last sync (and we should schedule an
367 // immediate follow-up sync), or an engine skipped
369 if (this._resyncs <= this.maxResyncs) {
371 nextSyncReason = "resync";
374 `Resync attempt ${this._resyncs} exceeded ` +
375 `maximum ${this.maxResyncs}`
377 Svc.Obs.notify("weave:service:resyncs-finished");
381 Svc.Obs.notify("weave:service:resyncs-finished");
384 this._syncErrors = 0;
385 if (lazy.Status.sync == NO_SYNC_NODE_FOUND) {
386 // If we don't have a Sync node, override the interval, even if we've
387 // scheduled a follow-up sync.
388 this._log.trace("Scheduling a sync at interval NO_SYNC_NODE_FOUND.");
389 sync_interval = NO_SYNC_NODE_INTERVAL;
391 this.scheduleNextSync(sync_interval, { why: nextSyncReason });
393 case "weave:engine:sync:finish":
394 if (data == "clients") {
395 // Update the client mode because it might change what we sync.
396 this.updateClientMode();
399 case "weave:engine:sync:error":
400 // `subject` is the exception thrown by an engine's sync() method.
401 let exception = subject;
402 if (exception.status >= 500 && exception.status <= 504) {
403 this.requiresBackoff = true;
406 case "weave:service:login:error":
407 this.clearSyncTriggers();
409 if (lazy.Status.login == MASTER_PASSWORD_LOCKED) {
410 // Try again later, just as if we threw an error... only without the
412 this._log.debug("Couldn't log in: master password is locked.");
414 "Scheduling a sync at MASTER_PASSWORD_LOCKED_RETRY_INTERVAL"
416 this.scheduleAtInterval(MASTER_PASSWORD_LOCKED_RETRY_INTERVAL);
417 } else if (!this._fatalLoginStatus.includes(lazy.Status.login)) {
418 // Not a fatal login error, just an intermittent network or server
419 // issue. Keep on syncin'.
420 this.checkSyncStatus();
423 case "weave:service:logout:finish":
424 // Start or cancel the sync timer depending on if
425 // logged in or logged out
426 this.checkSyncStatus();
428 case "weave:service:sync:error":
429 // There may be multiple clients but if the sync fails, client mode
430 // should still be updated so that the next sync has a correct interval.
431 this.updateClientMode();
432 this.adjustSyncInterval();
434 this.handleSyncError();
436 case "FxA:hawk:backoff:interval":
437 case "weave:service:backoff:interval":
438 let requested_interval = subject * 1000;
440 "Got backoff notification: " + requested_interval + "ms"
442 // Leave up to 25% more time for the back off.
443 let interval = requested_interval * (1 + Math.random() * 0.25);
444 lazy.Status.backoffInterval = interval;
445 lazy.Status.minimumNextSync = Date.now() + requested_interval;
447 "Fuzzed minimum next sync: " + lazy.Status.minimumNextSync
450 case "weave:engine:sync:applied":
451 let numItems = subject.succeeded;
453 "Engine " + data + " successfully applied " + numItems + " items."
455 // Bug 1800186 - the tabs engine always reports incoming items, so we don't
456 // want special scheduling in this scenario.
457 // (However, even when we fix the underlying cause of that, we probably still can
458 // ignore tabs here - new incoming tabs don't need to trigger the extra syncs we do
459 // based on this flag.)
460 if (data != "tabs" && numItems) {
461 this.hasIncomingItems = true;
463 if (subject.newFailed) {
465 `Engine ${data} found ${subject.newFailed} new records that failed to apply`
469 case "weave:service:setup-complete":
470 Services.prefs.savePrefFile(null);
471 lazy.IdleService.addIdleObserver(this, this.idleTime);
472 Svc.Obs.add("wake_notification", this);
473 Svc.Obs.add("captive-portal-login-success", this);
474 Svc.Obs.add("sleep_notification", this);
476 case "weave:service:start-over":
479 lazy.IdleService.removeIdleObserver(this, this.idleTime);
481 if (ex.result != Cr.NS_ERROR_FAILURE) {
484 // In all likelihood we didn't have an idle observer registered yet.
489 this._log.trace("We're idle.");
491 // Adjust the interval for future syncs. This won't actually have any
492 // effect until the next pending sync (which will happen soon since we
493 // were just active.)
494 this.adjustSyncInterval();
497 this._log.trace("Received notification that we're back from idle.");
499 CommonUtils.namedTimer(
503 "... and we're idle again. " +
504 "Ignoring spurious back notification."
509 this._log.trace("Genuine return from idle. Syncing.");
510 // Trigger a sync if we have multiple clients.
511 if (this.numClients > 1) {
512 this.scheduleNextSync(0, { why: topic });
515 IDLE_OBSERVER_BACK_DELAY,
520 case "wake_notification":
521 this._log.debug("Woke from sleep.");
522 CommonUtils.nextTick(() => {
523 // Trigger a sync if we have multiple clients. We give it 2 seconds
524 // so the browser can recover from the wake and do more important
525 // operations first (timers etc).
526 if (this.numClients > 1) {
528 this._log.debug("Online, will sync in 2s.");
529 this.scheduleNextSync(2000, { why: topic });
534 case "captive-portal-login-success":
535 this._log.debug("Captive portal login success. Scheduling a sync.");
536 CommonUtils.nextTick(() => {
537 this.scheduleNextSync(3000, { why: topic });
540 case "sleep_notification":
541 if (this.service.engineManager.get("tabs")._tracker.modified) {
542 this._log.debug("Going to sleep, doing a quick sync.");
543 this.scheduleNextSync(0, { engines: ["tabs"], why: "sleep" });
549 adjustSyncInterval: function adjustSyncInterval() {
550 if (this.numClients <= 1) {
551 this._log.trace("Adjusting syncInterval to singleDeviceInterval.");
552 this.syncInterval = this.singleDeviceInterval;
556 // Only MULTI_DEVICE clients will enter this if statement
557 // since SINGLE_USER clients will be handled above.
559 this._log.trace("Adjusting syncInterval to idleInterval.");
560 this.syncInterval = this.idleInterval;
564 if (this.hasIncomingItems) {
565 this._log.trace("Adjusting syncInterval to immediateInterval.");
566 this.hasIncomingItems = false;
567 this.syncInterval = this.immediateInterval;
569 this._log.trace("Adjusting syncInterval to activeInterval.");
570 this.syncInterval = this.activeInterval;
574 updateGlobalScore() {
575 let engines = [this.service.clientsEngine].concat(
576 this.service.engineManager.getEnabled()
578 let globalScore = this.globalScore;
579 for (let i = 0; i < engines.length; i++) {
580 this._log.trace(engines[i].name + ": score: " + engines[i].score);
581 globalScore += engines[i].score;
582 engines[i]._tracker.resetScore();
584 this.globalScore = globalScore;
585 this._log.trace("Global score updated: " + globalScore);
589 this.updateGlobalScore();
590 this.checkSyncStatus();
594 * Query the number of known clients to figure out what mode to be in
596 updateClientMode: function updateClientMode() {
597 // Nothing to do if it's the same amount
598 let numClients = this.numClients;
599 if (numClients == this.numClientsLastSync) {
604 `Client count: ${this.numClientsLastSync} -> ${numClients}`
606 this.numClientsLastSync = numClients;
608 if (numClients <= 1) {
609 this._log.trace("Adjusting syncThreshold to SINGLE_USER_THRESHOLD");
610 this.syncThreshold = SINGLE_USER_THRESHOLD;
612 this._log.trace("Adjusting syncThreshold to MULTI_DEVICE_THRESHOLD");
613 this.syncThreshold = MULTI_DEVICE_THRESHOLD;
615 this.adjustSyncInterval();
619 * Check if we should be syncing and schedule the next sync, if it's not scheduled
621 checkSyncStatus: function checkSyncStatus() {
622 // Should we be syncing now, if not, cancel any sync timers and return
623 // if we're in backoff, we'll schedule the next sync.
624 let ignore = [kSyncBackoffNotMet, kSyncMasterPasswordLocked];
625 let skip = this.service._checkSync(ignore);
626 this._log.trace('_checkSync returned "' + skip + '".');
628 this.clearSyncTriggers();
632 let why = "schedule";
633 // Only set the wait time to 0 if we need to sync right away
635 if (this.globalScore > this.syncThreshold) {
636 this._log.debug("Global Score threshold hit, triggering sync.");
640 this.scheduleNextSync(wait, { why });
644 * Call sync() if Master Password is not locked.
646 * Otherwise, reschedule a sync for later.
648 syncIfMPUnlocked(engines, why) {
649 // No point if we got kicked out by the master password dialog.
650 if (lazy.Status.login == MASTER_PASSWORD_LOCKED && Utils.mpLocked()) {
652 "Not initiating sync: Login status is " + lazy.Status.login
655 // If we're not syncing now, we need to schedule the next one.
657 "Scheduling a sync at MASTER_PASSWORD_LOCKED_RETRY_INTERVAL"
659 this.scheduleAtInterval(MASTER_PASSWORD_LOCKED_RETRY_INTERVAL);
663 if (!Async.isAppReady()) {
664 this._log.debug("Not initiating sync: app is shutting down");
667 Services.tm.dispatchToMainThread(() => {
668 this.service.sync({ engines, why });
669 const now = Math.round(new Date().getTime() / 1000);
670 // Only fetch missed messages in a "scheduled" sync so we don't race against
671 // the Push service reconnecting on a network link change for example.
675 this.missedFxACommandsLastFetch + this.missedFxACommandsFetchInterval
677 lazy.fxAccounts.commands
678 .pollDeviceCommands()
680 this.missedFxACommandsLastFetch = now;
683 this._log.error("Fetching missed remote commands failed.", e);
690 * Set a timer for the next sync
692 scheduleNextSync(interval, { engines = null, why = null } = {}) {
693 // If no interval was specified, use the current sync interval.
694 if (interval == null) {
695 interval = this.syncInterval;
698 // Ensure the interval is set to no less than the backoff.
699 if (lazy.Status.backoffInterval && interval < lazy.Status.backoffInterval) {
701 "Requested interval " +
703 " ms is smaller than the backoff interval. " +
704 "Using backoff interval " +
705 lazy.Status.backoffInterval +
708 interval = lazy.Status.backoffInterval;
710 let nextSync = this.nextSync;
712 // There's already a sync scheduled. Don't reschedule if there's already
713 // a timer scheduled for sooner than requested.
714 let currentInterval = nextSync - Date.now();
716 "There's already a sync scheduled in " + currentInterval + " ms."
718 if (currentInterval < interval && this.syncTimer) {
720 "Ignoring scheduling request for next sync in " + interval + " ms."
726 // Start the sync right away if we're already late.
728 this._log.trace(`Requested sync should happen right away. (why=${why})`);
729 this.syncIfMPUnlocked(engines, why);
733 this._log.debug(`Next sync in ${interval} ms. (why=${why})`);
734 CommonUtils.namedTimer(
736 this.syncIfMPUnlocked(engines, why);
743 // Save the next sync time in-case sync is disabled (logout/offline/etc.)
744 this.nextSync = Date.now() + interval;
748 * Incorporates the backoff/retry logic used in error handling and elective
751 scheduleAtInterval: function scheduleAtInterval(minimumInterval) {
752 let interval = Utils.calculateBackoff(
754 MINIMUM_BACKOFF_INTERVAL,
755 lazy.Status.backoffInterval
757 if (minimumInterval) {
758 interval = Math.max(minimumInterval, interval);
762 "Starting client-initiated backoff. Next sync in " + interval + " ms."
764 this.scheduleNextSync(interval, { why: "client-backoff-schedule" });
767 autoConnect: function autoConnect() {
768 if (this.service._checkSetup() == STATUS_OK && !this.service._checkSync()) {
769 // Schedule a sync based on when a previous sync was scheduled.
770 // scheduleNextSync() will do the right thing if that time lies in
772 this.scheduleNextSync(this.nextSync - Date.now(), { why: "startup" });
778 * Deal with sync errors appropriately
780 handleSyncError: function handleSyncError() {
781 this._log.trace("In handleSyncError. Error count: " + this._syncErrors);
784 // Do nothing on the first couple of failures, if we're not in
785 // backoff due to 5xx errors.
786 if (!lazy.Status.enforceBackoff) {
787 if (this._syncErrors < MAX_ERROR_COUNT_BEFORE_BACKOFF) {
788 this.scheduleNextSync(null, { why: "reschedule" });
792 "Sync error count has exceeded " +
793 MAX_ERROR_COUNT_BEFORE_BACKOFF +
794 "; enforcing backoff."
796 lazy.Status.enforceBackoff = true;
799 this.scheduleAtInterval();
803 * Remove any timers/observers that might trigger a sync
805 clearSyncTriggers: function clearSyncTriggers() {
806 this._log.debug("Clearing sync triggers and the global score.");
807 this.globalScore = this.nextSync = 0;
809 // Clear out any scheduled syncs
810 if (this.syncTimer) {
811 this.syncTimer.clear();
816 export function ErrorHandler(service) {
817 this.service = service;
821 ErrorHandler.prototype = {
823 Svc.Obs.add("weave:engine:sync:applied", this);
824 Svc.Obs.add("weave:engine:sync:error", this);
825 Svc.Obs.add("weave:service:login:error", this);
826 Svc.Obs.add("weave:service:sync:error", this);
827 Svc.Obs.add("weave:service:sync:finish", this);
828 Svc.Obs.add("weave:service:start-over:finish", this);
833 initLogs: function initLogs() {
834 // Set the root Sync logger level based on a pref. All other logs will
835 // inherit this level unless they specifically override it.
838 .manageLevelFromPref(`services.sync.log.logger`);
839 // And allow our specific log to have a custom level via a pref.
840 this._log = Log.repository.getLogger("Sync.ErrorHandler");
841 this._log.manageLevelFromPref("services.sync.log.logger.service.main");
844 observe(subject, topic, data) {
845 this._log.trace("Handling " + topic);
847 case "weave:engine:sync:applied":
848 if (subject.newFailed) {
849 // An engine isn't able to apply one or more incoming records.
850 // We don't fail hard on this, but it usually indicates a bug,
851 // so for now treat it as sync error (c.f. Service._syncEngine())
852 lazy.Status.engines = [data, ENGINE_APPLY_FAIL];
853 this._log.debug(data + " failed to apply some records.");
856 case "weave:engine:sync:error": {
857 let exception = subject; // exception thrown by engine's sync() method
858 let engine_name = data; // engine name that threw the exception
860 this.checkServerError(exception);
862 lazy.Status.engines = [
864 exception.failureCode || ENGINE_UNKNOWN_FAIL,
866 if (Async.isShutdownException(exception)) {
869 " was interrupted due to the application shutting down"
872 this._log.debug(engine_name + " failed", exception);
876 case "weave:service:login:error":
877 this._log.error("Sync encountered a login error");
880 case "weave:service:sync:error": {
881 if (lazy.Status.sync == CREDENTIALS_CHANGED) {
882 this.service.logout();
885 let exception = subject;
886 if (Async.isShutdownException(exception)) {
887 // If we are shutting down we just log the fact, attempt to flush
888 // the log file and get out of here!
890 "Sync was interrupted due to the application shutting down"
896 // Not a shutdown related exception...
897 this._log.error("Sync encountered an error", exception);
901 case "weave:service:sync:finish":
902 this._log.trace("Status.service is " + lazy.Status.service);
904 // Check both of these status codes: in the event of a failure in one
905 // engine, Status.service will be SYNC_FAILED_PARTIAL despite
906 // Status.sync being SYNC_SUCCEEDED.
909 lazy.Status.sync == SYNC_SUCCEEDED &&
910 lazy.Status.service == STATUS_OK
912 // Great. Let's clear our mid-sync 401 note.
913 this._log.trace("Clearing lastSyncReassigned.");
914 Svc.PrefBranch.clearUserPref("lastSyncReassigned");
917 if (lazy.Status.service == SYNC_FAILED_PARTIAL) {
918 this._log.error("Some engines did not sync correctly.");
922 case "weave:service:start-over:finish":
923 // ensure we capture any logs between the last sync and the reset completing.
926 // although for privacy reasons we also delete all logs (but we allow
927 // a preference to avoid this to help with debugging.)
928 if (!Svc.PrefBranch.getBoolPref("log.keepLogsOnReset", false)) {
929 return logManager.removeAllLogs().then(() => {
930 Svc.Obs.notify("weave:service:remove-file-log");
936 // So we failed to delete the logs - take the ironic option of
937 // writing this error to the logs we failed to delete!
938 this._log.error("Failed to delete logs on reset", err);
944 async _dumpAddons() {
945 // Just dump the items that sync may be concerned with. Specifically,
946 // active extensions that are not hidden.
949 addons = await lazy.AddonManager.getAddonsByTypes(["extension"]);
951 this._log.warn("Failed to dump addons", e);
954 let relevantAddons = addons.filter(x => x.isActive && !x.hidden);
955 this._log.trace("Addons installed", relevantAddons.length);
956 for (let addon of relevantAddons) {
957 this._log.trace(" - ${name}, version ${version}, id ${id}", addon);
962 * Generate a log file for the sync that just completed
963 * and refresh the input & output streams.
965 async resetFileLog() {
966 // If we're writing an error log, dump extensions that may be causing problems.
967 if (logManager.sawError) {
968 await this._dumpAddons();
970 const logType = await logManager.resetFileLog();
971 if (logType == logManager.ERROR_LOG_WRITTEN) {
973 "Sync encountered an error - see about:sync-log for the log file."
976 Svc.Obs.notify("weave:service:reset-file-log");
980 * Handle HTTP response results or exceptions and set the appropriate
983 * This method also looks for "side-channel" warnings.
985 checkServerError(resp) {
986 // In this case we were passed a resolved value of Resource#_doRequest.
987 switch (resp.status) {
989 if (resp == RESPONSE_OVER_QUOTA) {
990 lazy.Status.sync = OVER_QUOTA;
995 this.service.logout();
996 this._log.info("Got 401 response; resetting clusterURL.");
997 this.service.clusterURL = null;
1000 if (Svc.PrefBranch.getBoolPref("lastSyncReassigned", false)) {
1001 // We got a 401 in the middle of the previous sync, and we just got
1002 // another. Login must have succeeded in order for us to get here, so
1003 // the password should be correct.
1004 // This is likely to be an intermittent server issue, so back off and
1005 // give it time to recover.
1006 this._log.warn("Last sync also failed for 401. Delaying next sync.");
1007 delay = MINIMUM_BACKOFF_INTERVAL;
1009 this._log.debug("New mid-sync 401 failure. Making a note.");
1010 Svc.PrefBranch.setBoolPref("lastSyncReassigned", true);
1012 this._log.info("Attempting to schedule another sync.");
1013 this.service.scheduler.scheduleNextSync(delay, { why: "reschedule" });
1020 lazy.Status.enforceBackoff = true;
1021 if (resp.status == 503 && resp.headers["retry-after"]) {
1022 let retryAfter = resp.headers["retry-after"];
1023 this._log.debug("Got Retry-After: " + retryAfter);
1024 if (this.service.isLoggedIn) {
1025 lazy.Status.sync = SERVER_MAINTENANCE;
1027 lazy.Status.login = SERVER_MAINTENANCE;
1030 "weave:service:backoff:interval",
1031 parseInt(retryAfter, 10)
1037 // In this other case we were passed a rejection value.
1038 switch (resp.result) {
1039 case Cr.NS_ERROR_UNKNOWN_HOST:
1040 case Cr.NS_ERROR_CONNECTION_REFUSED:
1041 case Cr.NS_ERROR_NET_TIMEOUT:
1042 case Cr.NS_ERROR_NET_RESET:
1043 case Cr.NS_ERROR_NET_INTERRUPT:
1044 case Cr.NS_ERROR_PROXY_CONNECTION_REFUSED:
1045 // The constant says it's about login, but in fact it just
1046 // indicates general network error.
1047 if (this.service.isLoggedIn) {
1048 lazy.Status.sync = LOGIN_FAILED_NETWORK_ERROR;
1050 lazy.Status.login = LOGIN_FAILED_NETWORK_ERROR;