2011-06-27 06:22:49 -07:00
|
|
|
/* ***** BEGIN LICENSE BLOCK *****
|
|
|
|
* Version: MPL 1.1/GPL 2.0/LGPL 2.1
|
|
|
|
*
|
|
|
|
* The contents of this file are subject to the Mozilla Public License Version
|
|
|
|
* 1.1 (the "License"); you may not use this file except in compliance with
|
|
|
|
* the License. You may obtain a copy of the License at
|
|
|
|
* http://www.mozilla.org/MPL/
|
|
|
|
*
|
|
|
|
* Software distributed under the License is distributed on an "AS IS" basis,
|
|
|
|
* WITHOUT WARRANTY OF ANY KIND, either express or implied. See the License
|
|
|
|
* for the specific language governing rights and limitations under the
|
|
|
|
* License.
|
|
|
|
*
|
|
|
|
* The Original Code is Firefox Sync.
|
|
|
|
*
|
|
|
|
* The Initial Developer of the Original Code is
|
|
|
|
* the Mozilla Foundation.
|
|
|
|
* Portions created by the Initial Developer are Copyright (C) 2011
|
|
|
|
* the Initial Developer. All Rights Reserved.
|
|
|
|
*
|
|
|
|
* Contributor(s):
|
|
|
|
* Marina Samuel <msamuel@mozilla.com>
|
2011-06-29 20:12:16 -07:00
|
|
|
* Philipp von Weitershausen <philipp@weitershausen.de>
|
2011-09-08 16:52:07 -07:00
|
|
|
* Chenxia Liu <liuche@mozilla.com>
|
2011-06-27 06:22:49 -07:00
|
|
|
*
|
|
|
|
* Alternatively, the contents of this file may be used under the terms of
|
|
|
|
* either the GNU General Public License Version 2 or later (the "GPL"), or
|
|
|
|
* the GNU Lesser General Public License Version 2.1 or later (the "LGPL"),
|
|
|
|
* in which case the provisions of the GPL or the LGPL are applicable instead
|
|
|
|
* of those above. If you wish to allow use of your version of this file only
|
|
|
|
* under the terms of either the GPL or the LGPL, and not to allow others to
|
|
|
|
* use your version of this file under the terms of the MPL, indicate your
|
|
|
|
* decision by deleting the provisions above and replace them with the notice
|
|
|
|
* and other provisions required by the GPL or the LGPL. If you do not delete
|
|
|
|
* the provisions above, a recipient may use your version of this file under
|
|
|
|
* the terms of any one of the MPL, the GPL or the LGPL.
|
|
|
|
*
|
|
|
|
* ***** END LICENSE BLOCK ***** */
|
|
|
|
|
2011-10-02 01:16:22 -07:00
|
|
|
const EXPORTED_SYMBOLS = ["SyncScheduler",
|
|
|
|
"ErrorHandler",
|
|
|
|
"SendCredentialsController"];
|
2011-06-27 06:22:49 -07:00
|
|
|
|
2011-08-26 14:01:35 -07:00
|
|
|
const {classes: Cc, interfaces: Ci, utils: Cu, results: Cr} = Components;
|
2011-06-27 06:22:49 -07:00
|
|
|
|
|
|
|
Cu.import("resource://services-sync/constants.js");
|
|
|
|
Cu.import("resource://services-sync/log4moz.js");
|
|
|
|
Cu.import("resource://services-sync/util.js");
|
|
|
|
Cu.import("resource://services-sync/engines.js");
|
|
|
|
Cu.import("resource://services-sync/engines/clients.js");
|
|
|
|
Cu.import("resource://services-sync/status.js");
|
|
|
|
|
|
|
|
Cu.import("resource://services-sync/main.js"); // So we can get to Service for callbacks.
|
|
|
|
|
|
|
|
let SyncScheduler = {
|
|
|
|
_log: Log4Moz.repository.getLogger("Sync.SyncScheduler"),
|
|
|
|
|
2011-06-28 18:48:55 -07:00
|
|
|
/**
|
|
|
|
* The nsITimer object that schedules the next sync. See scheduleNextSync().
|
|
|
|
*/
|
|
|
|
syncTimer: null,
|
|
|
|
|
|
|
|
setDefaults: function setDefaults() {
|
2011-06-29 20:12:16 -07:00
|
|
|
this._log.trace("Setting SyncScheduler policy values to defaults.");
|
2011-06-29 20:12:24 -07:00
|
|
|
|
|
|
|
this.singleDeviceInterval = Svc.Prefs.get("scheduler.singleDeviceInterval") * 1000;
|
|
|
|
this.idleInterval = Svc.Prefs.get("scheduler.idleInterval") * 1000;
|
|
|
|
this.activeInterval = Svc.Prefs.get("scheduler.activeInterval") * 1000;
|
|
|
|
this.immediateInterval = Svc.Prefs.get("scheduler.immediateInterval") * 1000;
|
|
|
|
|
2011-06-28 18:48:55 -07:00
|
|
|
// A user is non-idle on startup by default.
|
|
|
|
this.idle = false;
|
|
|
|
|
|
|
|
this.hasIncomingItems = false;
|
|
|
|
this.numClients = 0;
|
|
|
|
|
|
|
|
this.nextSync = 0,
|
2011-06-29 20:12:24 -07:00
|
|
|
this.syncInterval = this.singleDeviceInterval;
|
2011-06-28 18:48:55 -07:00
|
|
|
this.syncThreshold = SINGLE_USER_THRESHOLD;
|
|
|
|
},
|
|
|
|
|
2011-06-27 06:22:49 -07:00
|
|
|
get globalScore() Svc.Prefs.get("globalScore", 0),
|
|
|
|
set globalScore(value) Svc.Prefs.set("globalScore", value),
|
|
|
|
|
|
|
|
init: function init() {
|
2011-06-29 20:12:16 -07:00
|
|
|
this._log.level = Log4Moz.Level[Svc.Prefs.get("log.logger.service.main")];
|
2011-06-28 18:48:55 -07:00
|
|
|
this.setDefaults();
|
2011-06-27 06:22:49 -07:00
|
|
|
Svc.Obs.add("weave:engine:score:updated", this);
|
|
|
|
Svc.Obs.add("network:offline-status-changed", 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);
|
2011-08-26 14:01:35 -07:00
|
|
|
Svc.Obs.add("weave:engine:sync:error", this);
|
2011-06-27 06:22:49 -07:00
|
|
|
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);
|
2011-07-21 12:20:55 -07:00
|
|
|
Svc.Obs.add("weave:service:ready", this);
|
2011-06-27 06:24:33 -07:00
|
|
|
Svc.Obs.add("weave:engine:sync:applied", this);
|
2011-07-21 12:21:34 -07:00
|
|
|
Svc.Obs.add("weave:service:setup-complete", this);
|
|
|
|
Svc.Obs.add("weave:service:start-over", this);
|
2011-08-26 14:01:35 -07:00
|
|
|
|
2011-07-21 12:21:34 -07:00
|
|
|
if (Status.checkSetup() == STATUS_OK) {
|
|
|
|
Svc.Idle.addIdleObserver(this, Svc.Prefs.get("scheduler.idleTime"));
|
|
|
|
}
|
|
|
|
|
2011-06-27 06:22:49 -07:00
|
|
|
},
|
|
|
|
|
|
|
|
observe: function observe(subject, topic, data) {
|
|
|
|
switch(topic) {
|
|
|
|
case "weave:engine:score:updated":
|
2011-09-06 09:17:26 -07:00
|
|
|
if (Status.login == LOGIN_SUCCEEDED) {
|
|
|
|
Utils.namedTimer(this.calculateScore, SCORE_UPDATE_DELAY, this,
|
|
|
|
"_scoreTimer");
|
|
|
|
}
|
2011-06-27 06:22:49 -07:00
|
|
|
break;
|
|
|
|
case "network:offline-status-changed":
|
|
|
|
// 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();
|
|
|
|
this.nextSync = 0;
|
|
|
|
|
|
|
|
// reset backoff info, if the server tells us to continue backing off,
|
|
|
|
// we'll handle that later
|
|
|
|
Status.resetBackoff();
|
|
|
|
|
|
|
|
this.globalScore = 0;
|
|
|
|
break;
|
|
|
|
case "weave:service:sync:finish":
|
2011-06-27 06:24:33 -07:00
|
|
|
this.adjustSyncInterval();
|
|
|
|
|
2011-06-27 06:22:49 -07:00
|
|
|
let sync_interval;
|
|
|
|
|
2011-08-26 14:01:35 -07:00
|
|
|
if (Status.service == SYNC_FAILED_PARTIAL && this.requiresBackoff) {
|
|
|
|
this.requiresBackoff = false;
|
|
|
|
this.handleSyncError();
|
|
|
|
return;
|
|
|
|
}
|
|
|
|
|
|
|
|
this._syncErrors = 0;
|
2011-06-27 06:22:49 -07:00
|
|
|
if (Status.sync == NO_SYNC_NODE_FOUND) {
|
2011-06-29 20:12:16 -07:00
|
|
|
this._log.trace("Scheduling a sync at interval NO_SYNC_NODE_FOUND.");
|
2011-06-27 06:22:49 -07:00
|
|
|
sync_interval = NO_SYNC_NODE_INTERVAL;
|
|
|
|
}
|
|
|
|
this.scheduleNextSync(sync_interval);
|
|
|
|
break;
|
|
|
|
case "weave:engine:sync:finish":
|
2011-07-29 18:47:39 -07:00
|
|
|
if (data == "clients") {
|
2011-06-27 06:22:49 -07:00
|
|
|
// Update the client mode because it might change what we sync.
|
|
|
|
this.updateClientMode();
|
|
|
|
}
|
|
|
|
break;
|
2011-08-26 14:01:35 -07:00
|
|
|
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;
|
2011-06-27 06:22:49 -07:00
|
|
|
case "weave:service:login:error":
|
|
|
|
this.clearSyncTriggers();
|
2011-08-26 14:01:35 -07:00
|
|
|
|
2011-06-27 06:22:49 -07:00
|
|
|
// Try again later, just as if we threw an error... only without the
|
|
|
|
// error count.
|
2011-06-29 20:12:16 -07:00
|
|
|
if (Status.login == MASTER_PASSWORD_LOCKED) {
|
|
|
|
this._log.debug("Couldn't log in: master password is locked.");
|
|
|
|
this._log.trace("Scheduling a sync at MASTER_PASSWORD_LOCKED_RETRY_INTERVAL");
|
2011-06-27 06:22:49 -07:00
|
|
|
this.scheduleAtInterval(MASTER_PASSWORD_LOCKED_RETRY_INTERVAL);
|
2011-06-29 20:12:16 -07:00
|
|
|
}
|
2011-06-27 06:22:49 -07:00
|
|
|
break;
|
|
|
|
case "weave:service:logout:finish":
|
|
|
|
// Start or cancel the sync timer depending on if
|
|
|
|
// logged in or logged out
|
|
|
|
this.checkSyncStatus();
|
2011-08-26 14:01:35 -07:00
|
|
|
break;
|
2011-06-27 06:22:49 -07:00
|
|
|
case "weave:service:sync:error":
|
2011-07-21 12:21:34 -07:00
|
|
|
// 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();
|
2011-06-27 06:24:33 -07:00
|
|
|
this.adjustSyncInterval();
|
2011-06-27 06:22:49 -07:00
|
|
|
this.handleSyncError();
|
|
|
|
break;
|
|
|
|
case "weave:service:backoff:interval":
|
|
|
|
let interval = (data + Math.random() * data * 0.25) * 1000; // required backoff + up to 25%
|
|
|
|
Status.backoffInterval = interval;
|
|
|
|
Status.minimumNextSync = Date.now() + data;
|
|
|
|
break;
|
2011-07-21 12:20:55 -07:00
|
|
|
case "weave:service:ready":
|
|
|
|
// Applications can specify this preference if they want autoconnect
|
|
|
|
// to happen after a fixed delay.
|
|
|
|
let delay = Svc.Prefs.get("autoconnectDelay");
|
|
|
|
if (delay) {
|
|
|
|
this.delayedAutoConnect(delay);
|
|
|
|
}
|
|
|
|
break;
|
2011-06-27 06:24:33 -07:00
|
|
|
case "weave:engine:sync:applied":
|
|
|
|
let numItems = subject.applied;
|
|
|
|
this._log.trace("Engine " + data + " applied " + numItems + " items.");
|
2011-08-26 14:01:35 -07:00
|
|
|
if (numItems)
|
2011-06-27 06:24:33 -07:00
|
|
|
this.hasIncomingItems = true;
|
|
|
|
break;
|
2011-07-21 12:21:34 -07:00
|
|
|
case "weave:service:setup-complete":
|
|
|
|
Svc.Idle.addIdleObserver(this, Svc.Prefs.get("scheduler.idleTime"));
|
|
|
|
break;
|
|
|
|
case "weave:service:start-over":
|
|
|
|
SyncScheduler.setDefaults();
|
2011-09-22 15:44:06 -07:00
|
|
|
try {
|
|
|
|
Svc.Idle.removeIdleObserver(this, Svc.Prefs.get("scheduler.idleTime"));
|
|
|
|
} catch (ex if (ex.result == Cr.NS_ERROR_FAILURE)) {
|
|
|
|
// In all likelihood we didn't have an idle observer registered yet.
|
|
|
|
// It's all good.
|
|
|
|
}
|
2011-07-21 12:21:34 -07:00
|
|
|
break;
|
2011-06-27 06:24:33 -07:00
|
|
|
case "idle":
|
2011-06-29 20:12:16 -07:00
|
|
|
this._log.trace("We're idle.");
|
2011-06-27 06:24:33 -07:00
|
|
|
this.idle = true;
|
2011-06-28 18:48:55 -07:00
|
|
|
// 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();
|
2011-06-27 06:24:33 -07:00
|
|
|
break;
|
|
|
|
case "back":
|
2011-06-29 20:12:16 -07:00
|
|
|
this._log.trace("We're no longer idle.");
|
2011-06-27 06:24:33 -07:00
|
|
|
this.idle = false;
|
2011-06-28 18:48:55 -07:00
|
|
|
// Trigger a sync if we have multiple clients.
|
|
|
|
if (this.numClients > 1) {
|
|
|
|
Utils.nextTick(Weave.Service.sync, Weave.Service);
|
|
|
|
}
|
2011-06-27 06:24:33 -07:00
|
|
|
break;
|
|
|
|
}
|
|
|
|
},
|
|
|
|
|
|
|
|
adjustSyncInterval: function adjustSyncInterval() {
|
|
|
|
if (this.numClients <= 1) {
|
2011-06-29 20:12:24 -07:00
|
|
|
this._log.trace("Adjusting syncInterval to singleDeviceInterval.");
|
|
|
|
this.syncInterval = this.singleDeviceInterval;
|
2011-06-27 06:24:33 -07:00
|
|
|
return;
|
|
|
|
}
|
|
|
|
// Only MULTI_DEVICE clients will enter this if statement
|
|
|
|
// since SINGLE_USER clients will be handled above.
|
|
|
|
if (this.idle) {
|
2011-06-29 20:12:24 -07:00
|
|
|
this._log.trace("Adjusting syncInterval to idleInterval.");
|
|
|
|
this.syncInterval = this.idleInterval;
|
2011-06-27 06:24:33 -07:00
|
|
|
return;
|
|
|
|
}
|
|
|
|
|
|
|
|
if (this.hasIncomingItems) {
|
2011-06-29 20:12:24 -07:00
|
|
|
this._log.trace("Adjusting syncInterval to immediateInterval.");
|
2011-06-27 06:24:33 -07:00
|
|
|
this.hasIncomingItems = false;
|
2011-06-29 20:12:24 -07:00
|
|
|
this.syncInterval = this.immediateInterval;
|
2011-06-27 06:24:33 -07:00
|
|
|
} else {
|
2011-06-29 20:12:24 -07:00
|
|
|
this._log.trace("Adjusting syncInterval to activeInterval.");
|
|
|
|
this.syncInterval = this.activeInterval;
|
2011-06-27 06:24:33 -07:00
|
|
|
}
|
2011-06-27 06:22:49 -07:00
|
|
|
},
|
|
|
|
|
|
|
|
calculateScore: function calculateScore() {
|
2011-08-09 09:25:12 -07:00
|
|
|
let engines = [Clients].concat(Engines.getEnabled());
|
2011-06-27 06:22:49 -07:00
|
|
|
for (let i = 0;i < engines.length;i++) {
|
|
|
|
this._log.trace(engines[i].name + ": score: " + engines[i].score);
|
|
|
|
this.globalScore += engines[i].score;
|
|
|
|
engines[i]._tracker.resetScore();
|
|
|
|
}
|
|
|
|
|
|
|
|
this._log.trace("Global score updated: " + this.globalScore);
|
|
|
|
this.checkSyncStatus();
|
|
|
|
},
|
|
|
|
|
|
|
|
/**
|
|
|
|
* Process the locally stored clients list to figure out what mode to be in
|
|
|
|
*/
|
|
|
|
updateClientMode: function updateClientMode() {
|
|
|
|
// Nothing to do if it's the same amount
|
2011-08-26 14:01:35 -07:00
|
|
|
let numClients = Clients.stats.numClients;
|
2011-06-27 06:24:33 -07:00
|
|
|
if (this.numClients == numClients)
|
2011-06-27 06:22:49 -07:00
|
|
|
return;
|
|
|
|
|
2011-06-27 06:24:33 -07:00
|
|
|
this._log.debug("Client count: " + this.numClients + " -> " + numClients);
|
|
|
|
this.numClients = numClients;
|
2011-06-27 06:22:49 -07:00
|
|
|
|
2011-06-27 06:24:33 -07:00
|
|
|
if (numClients <= 1) {
|
2011-06-29 20:12:16 -07:00
|
|
|
this._log.trace("Adjusting syncThreshold to SINGLE_USER_THRESHOLD");
|
2011-06-27 06:22:49 -07:00
|
|
|
this.syncThreshold = SINGLE_USER_THRESHOLD;
|
2011-06-29 20:12:16 -07:00
|
|
|
} else {
|
|
|
|
this._log.trace("Adjusting syncThreshold to MULTI_DEVICE_THRESHOLD");
|
2011-06-27 06:22:49 -07:00
|
|
|
this.syncThreshold = MULTI_DEVICE_THRESHOLD;
|
|
|
|
}
|
2011-06-27 06:24:33 -07:00
|
|
|
this.adjustSyncInterval();
|
2011-06-27 06:22:49 -07:00
|
|
|
},
|
|
|
|
|
|
|
|
/**
|
|
|
|
* 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
|
2011-07-13 15:20:07 -07:00
|
|
|
// if we're in backoff, we'll schedule the next sync.
|
|
|
|
let ignore = [kSyncBackoffNotMet, kSyncMasterPasswordLocked];
|
2011-06-27 06:22:49 -07:00
|
|
|
let skip = Weave.Service._checkSync(ignore);
|
|
|
|
this._log.trace("_checkSync returned \"" + skip + "\".");
|
|
|
|
if (skip) {
|
|
|
|
this.clearSyncTriggers();
|
|
|
|
return;
|
|
|
|
}
|
|
|
|
|
|
|
|
// 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;
|
|
|
|
}
|
|
|
|
this.scheduleNextSync(wait);
|
|
|
|
},
|
|
|
|
|
|
|
|
/**
|
|
|
|
* Call sync() if Master Password is not locked.
|
2011-08-26 14:01:35 -07:00
|
|
|
*
|
2011-06-27 06:22:49 -07:00
|
|
|
* Otherwise, reschedule a sync for later.
|
|
|
|
*/
|
|
|
|
syncIfMPUnlocked: function syncIfMPUnlocked() {
|
|
|
|
// No point if we got kicked out by the master password dialog.
|
|
|
|
if (Status.login == MASTER_PASSWORD_LOCKED &&
|
|
|
|
Utils.mpLocked()) {
|
|
|
|
this._log.debug("Not initiating sync: Login status is " + Status.login);
|
|
|
|
|
|
|
|
// If we're not syncing now, we need to schedule the next one.
|
2011-06-29 20:12:16 -07:00
|
|
|
this._log.trace("Scheduling a sync at MASTER_PASSWORD_LOCKED_RETRY_INTERVAL");
|
2011-06-27 06:22:49 -07:00
|
|
|
this.scheduleAtInterval(MASTER_PASSWORD_LOCKED_RETRY_INTERVAL);
|
|
|
|
return;
|
|
|
|
}
|
|
|
|
|
|
|
|
Utils.nextTick(Weave.Service.sync, Weave.Service);
|
|
|
|
},
|
|
|
|
|
|
|
|
/**
|
|
|
|
* Set a timer for the next sync
|
|
|
|
*/
|
|
|
|
scheduleNextSync: function scheduleNextSync(interval) {
|
|
|
|
// Figure out when to sync next if not given a interval to wait
|
|
|
|
if (interval == null || interval == undefined) {
|
|
|
|
// Check if we had a pending sync from last time
|
|
|
|
if (this.nextSync != 0)
|
2011-07-21 12:21:34 -07:00
|
|
|
interval = Math.min(this.syncInterval, (this.nextSync - Date.now()));
|
2011-06-27 06:22:49 -07:00
|
|
|
// Use the bigger of default sync interval and backoff
|
|
|
|
else
|
|
|
|
interval = Math.max(this.syncInterval, Status.backoffInterval);
|
|
|
|
}
|
|
|
|
|
|
|
|
// Start the sync right away if we're already late
|
|
|
|
if (interval <= 0) {
|
|
|
|
this.syncIfMPUnlocked();
|
|
|
|
return;
|
|
|
|
}
|
|
|
|
|
|
|
|
this._log.trace("Next sync in " + Math.ceil(interval / 1000) + " sec.");
|
2011-06-29 20:12:27 -07:00
|
|
|
Utils.namedTimer(this.syncIfMPUnlocked, interval, this, "syncTimer");
|
2011-06-27 06:22:49 -07:00
|
|
|
|
|
|
|
// 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);
|
|
|
|
if (minimumInterval)
|
|
|
|
interval = Math.max(minimumInterval, interval);
|
|
|
|
|
|
|
|
let d = new Date(Date.now() + interval);
|
|
|
|
this._log.config("Starting backoff, next sync at:" + d.toString());
|
|
|
|
|
|
|
|
this.scheduleNextSync(interval);
|
|
|
|
},
|
|
|
|
|
2011-07-21 12:20:55 -07:00
|
|
|
/**
|
|
|
|
* Automatically start syncing after the given delay (in seconds).
|
|
|
|
*
|
|
|
|
* Applications can define the `services.sync.autoconnectDelay` preference
|
|
|
|
* to have this called automatically during start-up with the pref value as
|
|
|
|
* the argument. Alternatively, they can call it themselves to control when
|
|
|
|
* Sync should first start to sync.
|
|
|
|
*/
|
|
|
|
delayedAutoConnect: function delayedAutoConnect(delay) {
|
|
|
|
if (Weave.Service._checkSetup() == STATUS_OK) {
|
|
|
|
Utils.namedTimer(this.autoConnect, delay * 1000, this, "_autoTimer");
|
|
|
|
}
|
|
|
|
},
|
|
|
|
|
|
|
|
autoConnect: function autoConnect() {
|
|
|
|
if (Weave.Service._checkSetup() == STATUS_OK && !Weave.Service._checkSync()) {
|
|
|
|
Utils.nextTick(Weave.Service.sync, Weave.Service);
|
|
|
|
}
|
|
|
|
|
|
|
|
// Once autoConnect is called we no longer need _autoTimer.
|
|
|
|
if (this._autoTimer) {
|
|
|
|
this._autoTimer.clear();
|
|
|
|
}
|
|
|
|
},
|
|
|
|
|
2011-06-27 06:22:49 -07:00
|
|
|
_syncErrors: 0,
|
|
|
|
/**
|
|
|
|
* Deal with sync errors appropriately
|
|
|
|
*/
|
|
|
|
handleSyncError: function handleSyncError() {
|
|
|
|
this._syncErrors++;
|
|
|
|
|
|
|
|
// Do nothing on the first couple of failures, if we're not in
|
|
|
|
// backoff due to 5xx errors.
|
|
|
|
if (!Status.enforceBackoff) {
|
|
|
|
if (this._syncErrors < MAX_ERROR_COUNT_BEFORE_BACKOFF) {
|
|
|
|
this.scheduleNextSync();
|
|
|
|
return;
|
|
|
|
}
|
|
|
|
Status.enforceBackoff = true;
|
|
|
|
}
|
|
|
|
|
|
|
|
this.scheduleAtInterval();
|
|
|
|
},
|
|
|
|
|
|
|
|
|
|
|
|
/**
|
|
|
|
* Remove any timers/observers that might trigger a sync
|
|
|
|
*/
|
|
|
|
clearSyncTriggers: function clearSyncTriggers() {
|
|
|
|
this._log.debug("Clearing sync triggers.");
|
|
|
|
|
|
|
|
// Clear out any scheduled syncs
|
2011-06-28 18:48:55 -07:00
|
|
|
if (this.syncTimer)
|
|
|
|
this.syncTimer.clear();
|
2011-06-27 06:22:49 -07:00
|
|
|
}
|
|
|
|
|
|
|
|
};
|
2011-08-26 14:01:35 -07:00
|
|
|
|
|
|
|
const LOG_PREFIX_SUCCESS = "success-";
|
|
|
|
const LOG_PREFIX_ERROR = "error-";
|
|
|
|
|
|
|
|
let ErrorHandler = {
|
|
|
|
|
2011-08-26 14:01:35 -07:00
|
|
|
/**
|
|
|
|
* Flag that turns on error reporting for all errors, incl. network errors.
|
|
|
|
*/
|
|
|
|
dontIgnoreErrors: false,
|
|
|
|
|
2011-08-26 14:01:35 -07:00
|
|
|
init: function init() {
|
2011-08-26 14:01:35 -07:00
|
|
|
Svc.Obs.add("weave:engine:sync:applied", this);
|
|
|
|
Svc.Obs.add("weave:engine:sync:error", this);
|
2011-08-26 14:01:35 -07:00
|
|
|
Svc.Obs.add("weave:service:login:error", this);
|
|
|
|
Svc.Obs.add("weave:service:sync:error", this);
|
|
|
|
Svc.Obs.add("weave:service:sync:finish", this);
|
|
|
|
|
|
|
|
this.initLogs();
|
|
|
|
},
|
|
|
|
|
|
|
|
initLogs: function initLogs() {
|
|
|
|
this._log = Log4Moz.repository.getLogger("Sync.ErrorHandler");
|
2011-08-26 14:01:35 -07:00
|
|
|
this._log.level = Log4Moz.Level[Svc.Prefs.get("log.logger.service.main")];
|
2011-09-08 16:52:07 -07:00
|
|
|
this._cleaningUpFileLogs = false;
|
2011-08-26 14:01:35 -07:00
|
|
|
|
|
|
|
let root = Log4Moz.repository.getLogger("Sync");
|
|
|
|
root.level = Log4Moz.Level[Svc.Prefs.get("log.rootLogger")];
|
|
|
|
|
|
|
|
let formatter = new Log4Moz.BasicFormatter();
|
|
|
|
let capp = new Log4Moz.ConsoleAppender(formatter);
|
|
|
|
capp.level = Log4Moz.Level[Svc.Prefs.get("log.appender.console")];
|
|
|
|
root.addAppender(capp);
|
|
|
|
|
|
|
|
let dapp = new Log4Moz.DumpAppender(formatter);
|
|
|
|
dapp.level = Log4Moz.Level[Svc.Prefs.get("log.appender.dump")];
|
|
|
|
root.addAppender(dapp);
|
|
|
|
|
|
|
|
let fapp = this._logAppender = new Log4Moz.StorageStreamAppender(formatter);
|
|
|
|
fapp.level = Log4Moz.Level[Svc.Prefs.get("log.appender.file.level")];
|
|
|
|
root.addAppender(fapp);
|
|
|
|
},
|
|
|
|
|
|
|
|
observe: function observe(subject, topic, data) {
|
|
|
|
switch(topic) {
|
2011-08-26 14:01:35 -07:00
|
|
|
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())
|
|
|
|
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);
|
|
|
|
|
|
|
|
Status.engines = [engine_name, exception.failureCode || ENGINE_UNKNOWN_FAIL];
|
|
|
|
this._log.debug(engine_name + " failed: " + Utils.exceptionStr(exception));
|
|
|
|
break;
|
2011-08-26 14:01:35 -07:00
|
|
|
case "weave:service:login:error":
|
2011-08-26 14:01:35 -07:00
|
|
|
if (this.shouldReportError()) {
|
2011-08-26 14:01:35 -07:00
|
|
|
this.resetFileLog(Svc.Prefs.get("log.appender.file.logOnError"),
|
|
|
|
LOG_PREFIX_ERROR);
|
2011-09-06 19:15:28 -07:00
|
|
|
this.notifyOnNextTick("weave:ui:login:error");
|
2011-08-30 15:38:31 -07:00
|
|
|
} else {
|
2011-09-06 19:15:28 -07:00
|
|
|
this.notifyOnNextTick("weave:ui:clear-error");
|
2011-08-26 14:01:35 -07:00
|
|
|
}
|
2011-08-26 14:01:35 -07:00
|
|
|
|
|
|
|
this.dontIgnoreErrors = false;
|
2011-08-26 14:01:35 -07:00
|
|
|
break;
|
|
|
|
case "weave:service:sync:error":
|
2011-08-26 14:01:35 -07:00
|
|
|
if (Status.sync == CREDENTIALS_CHANGED) {
|
|
|
|
Weave.Service.logout();
|
|
|
|
}
|
|
|
|
|
|
|
|
if (this.shouldReportError()) {
|
|
|
|
this.resetFileLog(Svc.Prefs.get("log.appender.file.logOnError"),
|
|
|
|
LOG_PREFIX_ERROR);
|
2011-09-06 19:15:28 -07:00
|
|
|
this.notifyOnNextTick("weave:ui:sync:error");
|
2011-08-26 14:01:35 -07:00
|
|
|
} else {
|
2011-09-06 19:15:28 -07:00
|
|
|
this.notifyOnNextTick("weave:ui:sync:finish");
|
2011-08-26 14:01:35 -07:00
|
|
|
}
|
2011-08-26 14:01:35 -07:00
|
|
|
|
|
|
|
this.dontIgnoreErrors = false;
|
2011-08-26 14:01:35 -07:00
|
|
|
break;
|
|
|
|
case "weave:service:sync:finish":
|
2011-08-26 14:01:35 -07:00
|
|
|
if (Status.service == SYNC_FAILED_PARTIAL) {
|
|
|
|
this._log.debug("Some engines did not sync correctly.");
|
|
|
|
this.resetFileLog(Svc.Prefs.get("log.appender.file.logOnError"),
|
|
|
|
LOG_PREFIX_ERROR);
|
2011-08-26 14:01:35 -07:00
|
|
|
|
|
|
|
if (this.shouldReportError()) {
|
2011-08-26 16:45:08 -07:00
|
|
|
this.dontIgnoreErrors = false;
|
2011-09-06 19:15:28 -07:00
|
|
|
this.notifyOnNextTick("weave:ui:sync:error");
|
2011-08-26 14:01:35 -07:00
|
|
|
break;
|
|
|
|
}
|
2011-08-26 14:01:35 -07:00
|
|
|
} else {
|
|
|
|
this.resetFileLog(Svc.Prefs.get("log.appender.file.logOnSuccess"),
|
|
|
|
LOG_PREFIX_SUCCESS);
|
|
|
|
}
|
2011-08-26 16:45:08 -07:00
|
|
|
this.dontIgnoreErrors = false;
|
2011-09-06 19:15:28 -07:00
|
|
|
this.notifyOnNextTick("weave:ui:sync:finish");
|
2011-08-26 14:01:35 -07:00
|
|
|
break;
|
|
|
|
}
|
|
|
|
},
|
|
|
|
|
2011-09-06 19:15:28 -07:00
|
|
|
notifyOnNextTick: function notifyOnNextTick(topic) {
|
|
|
|
Utils.nextTick(function() Svc.Obs.notify(topic));
|
|
|
|
},
|
|
|
|
|
2011-08-26 14:01:35 -07:00
|
|
|
/**
|
|
|
|
* Trigger a sync and don't muffle any errors, particularly network errors.
|
|
|
|
*/
|
|
|
|
syncAndReportErrors: function syncAndReportErrors() {
|
|
|
|
this._log.debug("Beginning user-triggered sync.");
|
|
|
|
|
|
|
|
this.dontIgnoreErrors = true;
|
|
|
|
Utils.nextTick(Weave.Service.sync, Weave.Service);
|
|
|
|
},
|
|
|
|
|
2011-09-08 16:52:07 -07:00
|
|
|
/**
|
|
|
|
* Finds all logs older than maxErrorAge and deletes them without tying up I/O.
|
|
|
|
*/
|
|
|
|
cleanupLogs: function cleanupLogs() {
|
|
|
|
let direntries = FileUtils.getDir("ProfD", ["weave", "logs"]).directoryEntries;
|
|
|
|
let oldLogs = [];
|
|
|
|
let index = 0;
|
|
|
|
let threshold = Date.now() - 1000 * Svc.Prefs.get("log.appender.file.maxErrorAge");
|
|
|
|
|
|
|
|
while (direntries.hasMoreElements()) {
|
|
|
|
let logFile = direntries.getNext().QueryInterface(Ci.nsIFile);
|
|
|
|
if (logFile.lastModifiedTime < threshold) {
|
|
|
|
oldLogs.push(logFile);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
// Deletes a file from oldLogs each tick until there are none left.
|
|
|
|
function deleteFile() {
|
|
|
|
if (index >= oldLogs.length) {
|
|
|
|
ErrorHandler._cleaningUpFileLogs = false;
|
|
|
|
Svc.Obs.notify("weave:service:cleanup-logs");
|
|
|
|
return;
|
|
|
|
}
|
|
|
|
try {
|
|
|
|
oldLogs[index].remove(false);
|
|
|
|
} catch (ex) {
|
|
|
|
ErrorHandler._log._debug("Encountered error trying to clean up old log file '"
|
|
|
|
+ oldLogs[index].leafName + "':"
|
|
|
|
+ Utils.exceptionStr(ex));
|
|
|
|
}
|
|
|
|
index++;
|
|
|
|
Utils.nextTick(deleteFile);
|
|
|
|
}
|
|
|
|
|
|
|
|
if (oldLogs.length > 0) {
|
|
|
|
ErrorHandler._cleaningUpFileLogs = true;
|
|
|
|
Utils.nextTick(deleteFile);
|
|
|
|
}
|
|
|
|
},
|
|
|
|
|
2011-08-26 14:01:35 -07:00
|
|
|
/**
|
|
|
|
* Generate a log file for the sync that just completed
|
|
|
|
* and refresh the input & output streams.
|
2011-08-26 14:01:35 -07:00
|
|
|
*
|
2011-08-26 14:01:35 -07:00
|
|
|
* @param flushToFile
|
|
|
|
* the log file to be flushed/reset
|
|
|
|
*
|
|
|
|
* @param filenamePrefix
|
|
|
|
* a value of either LOG_PREFIX_SUCCESS or LOG_PREFIX_ERROR
|
|
|
|
* to be used as the log filename prefix
|
|
|
|
*/
|
|
|
|
resetFileLog: function resetFileLog(flushToFile, filenamePrefix) {
|
|
|
|
let inStream = this._logAppender.getInputStream();
|
|
|
|
this._logAppender.reset();
|
|
|
|
if (flushToFile && inStream) {
|
|
|
|
try {
|
|
|
|
let filename = filenamePrefix + Date.now() + ".txt";
|
|
|
|
let file = FileUtils.getFile("ProfD", ["weave", "logs", filename]);
|
|
|
|
let outStream = FileUtils.openFileOutputStream(file);
|
|
|
|
NetUtil.asyncCopy(inStream, outStream, function () {
|
|
|
|
Svc.Obs.notify("weave:service:reset-file-log");
|
2011-09-08 16:52:07 -07:00
|
|
|
if (filenamePrefix == LOG_PREFIX_ERROR
|
|
|
|
&& !ErrorHandler._cleaningUpFileLogs) {
|
|
|
|
Utils.nextTick(ErrorHandler.cleanupLogs, ErrorHandler);
|
|
|
|
}
|
2011-08-26 14:01:35 -07:00
|
|
|
});
|
|
|
|
} catch (ex) {
|
|
|
|
Svc.Obs.notify("weave:service:reset-file-log");
|
|
|
|
}
|
|
|
|
} else {
|
|
|
|
Svc.Obs.notify("weave:service:reset-file-log");
|
|
|
|
}
|
|
|
|
},
|
|
|
|
|
|
|
|
/**
|
|
|
|
* Translates server error codes to meaningful strings.
|
2011-08-26 14:01:35 -07:00
|
|
|
*
|
2011-08-26 14:01:35 -07:00
|
|
|
* @param code
|
|
|
|
* server error code as an integer
|
|
|
|
*/
|
|
|
|
errorStr: function errorStr(code) {
|
|
|
|
switch (code.toString()) {
|
|
|
|
case "1":
|
|
|
|
return "illegal-method";
|
|
|
|
case "2":
|
|
|
|
return "invalid-captcha";
|
|
|
|
case "3":
|
|
|
|
return "invalid-username";
|
|
|
|
case "4":
|
|
|
|
return "cannot-overwrite-resource";
|
|
|
|
case "5":
|
|
|
|
return "userid-mismatch";
|
|
|
|
case "6":
|
|
|
|
return "json-parse-failure";
|
|
|
|
case "7":
|
|
|
|
return "invalid-password";
|
|
|
|
case "8":
|
|
|
|
return "invalid-record";
|
|
|
|
case "9":
|
|
|
|
return "weak-password";
|
|
|
|
default:
|
|
|
|
return "generic-server-error";
|
|
|
|
}
|
|
|
|
},
|
|
|
|
|
2011-08-26 14:01:35 -07:00
|
|
|
shouldReportError: function shouldReportError() {
|
|
|
|
if (Status.login == MASTER_PASSWORD_LOCKED) {
|
|
|
|
return false;
|
|
|
|
}
|
|
|
|
|
2011-08-26 16:45:08 -07:00
|
|
|
if (this.dontIgnoreErrors) {
|
|
|
|
return true;
|
|
|
|
}
|
|
|
|
|
2011-08-26 14:01:35 -07:00
|
|
|
let lastSync = Svc.Prefs.get("lastSync");
|
|
|
|
if (lastSync && ((Date.now() - Date.parse(lastSync)) >
|
|
|
|
Svc.Prefs.get("errorhandler.networkFailureReportTimeout") * 1000)) {
|
|
|
|
Status.sync = PROLONGED_SYNC_FAILURE;
|
|
|
|
return true;
|
|
|
|
}
|
|
|
|
|
2011-09-06 09:17:26 -07:00
|
|
|
return ([Status.login, Status.sync].indexOf(SERVER_MAINTENANCE) == -1 &&
|
2011-08-26 14:01:35 -07:00
|
|
|
[Status.login, Status.sync].indexOf(LOGIN_FAILED_NETWORK_ERROR) == -1);
|
2011-08-26 14:01:35 -07:00
|
|
|
},
|
|
|
|
|
|
|
|
/**
|
|
|
|
* Handle HTTP response results or exceptions and set the appropriate
|
|
|
|
* Status.* bits.
|
|
|
|
*/
|
|
|
|
checkServerError: function checkServerError(resp) {
|
|
|
|
switch (resp.status) {
|
|
|
|
case 400:
|
|
|
|
if (resp == RESPONSE_OVER_QUOTA) {
|
|
|
|
Status.sync = OVER_QUOTA;
|
|
|
|
}
|
|
|
|
break;
|
|
|
|
|
|
|
|
case 401:
|
|
|
|
Weave.Service.logout();
|
|
|
|
Status.login = LOGIN_FAILED_LOGIN_REJECTED;
|
|
|
|
break;
|
|
|
|
|
|
|
|
case 500:
|
|
|
|
case 502:
|
|
|
|
case 503:
|
|
|
|
case 504:
|
|
|
|
Status.enforceBackoff = true;
|
|
|
|
if (resp.status == 503 && resp.headers["retry-after"]) {
|
2011-09-06 09:17:26 -07:00
|
|
|
if (Weave.Service.isLoggedIn) {
|
|
|
|
Status.sync = SERVER_MAINTENANCE;
|
|
|
|
} else {
|
|
|
|
Status.login = SERVER_MAINTENANCE;
|
|
|
|
}
|
2011-08-26 14:01:35 -07:00
|
|
|
Svc.Obs.notify("weave:service:backoff:interval",
|
|
|
|
parseInt(resp.headers["retry-after"], 10));
|
|
|
|
}
|
|
|
|
break;
|
|
|
|
}
|
|
|
|
|
|
|
|
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.
|
2011-09-06 09:17:26 -07:00
|
|
|
if (Weave.Service.isLoggedIn) {
|
|
|
|
Status.sync = LOGIN_FAILED_NETWORK_ERROR;
|
|
|
|
} else {
|
|
|
|
Status.login = LOGIN_FAILED_NETWORK_ERROR;
|
|
|
|
}
|
2011-08-26 14:01:35 -07:00
|
|
|
break;
|
|
|
|
}
|
|
|
|
},
|
|
|
|
};
|
2011-10-02 01:16:22 -07:00
|
|
|
|
|
|
|
|
|
|
|
/**
|
|
|
|
* Send credentials over an active J-PAKE channel.
|
|
|
|
*
|
|
|
|
* This object is designed to take over as the JPAKEClient controller,
|
|
|
|
* presumably replacing one that is UI-based which would either cause
|
|
|
|
* DOM objects to leak or the JPAKEClient to be GC'ed when the DOM
|
|
|
|
* context disappears. This object stays alive for the duration of the
|
|
|
|
* transfer by being strong-ref'ed as an nsIObserver.
|
|
|
|
*
|
|
|
|
* Credentials are sent after the first sync has been completed
|
|
|
|
* (successfully or not.)
|
|
|
|
*
|
|
|
|
* Usage:
|
|
|
|
*
|
|
|
|
* jpakeclient.controller = new SendCredentialsController(jpakeclient);
|
|
|
|
*
|
|
|
|
*/
|
|
|
|
function SendCredentialsController(jpakeclient) {
|
|
|
|
this._log = Log4Moz.repository.getLogger("Sync.SendCredentialsController");
|
|
|
|
this._log.level = Log4Moz.Level[Svc.Prefs.get("log.logger.service.main")];
|
|
|
|
|
|
|
|
this._log.trace("Loading.");
|
|
|
|
this.jpakeclient = jpakeclient;
|
|
|
|
|
|
|
|
// Register ourselves as observers the first Sync finishing (either
|
|
|
|
// successfully or unsuccessfully, we don't care) or for removing
|
|
|
|
// this device's sync configuration, in case that happens while we
|
|
|
|
// haven't finished the first sync yet.
|
|
|
|
Services.obs.addObserver(this, "weave:service:sync:finish", false);
|
|
|
|
Services.obs.addObserver(this, "weave:service:sync:error", false);
|
|
|
|
Services.obs.addObserver(this, "weave:service:start-over", false);
|
|
|
|
}
|
|
|
|
SendCredentialsController.prototype = {
|
|
|
|
|
|
|
|
unload: function unload() {
|
|
|
|
this._log.trace("Unloading.");
|
|
|
|
try {
|
|
|
|
Services.obs.removeObserver(this, "weave:service:sync:finish");
|
|
|
|
Services.obs.removeObserver(this, "weave:service:sync:error");
|
|
|
|
Services.obs.removeObserver(this, "weave:service:start-over");
|
|
|
|
} catch (ex) {
|
|
|
|
// Ignore.
|
|
|
|
}
|
|
|
|
},
|
|
|
|
|
|
|
|
observe: function observe(subject, topic, data) {
|
|
|
|
switch (topic) {
|
|
|
|
case "weave:service:sync:finish":
|
|
|
|
case "weave:service:sync:error":
|
|
|
|
Utils.nextTick(this.sendCredentials, this);
|
|
|
|
break;
|
|
|
|
case "weave:service:start-over":
|
|
|
|
// This will call onAbort which will call unload().
|
|
|
|
this.jpakeclient.abort();
|
|
|
|
break;
|
|
|
|
}
|
|
|
|
},
|
|
|
|
|
|
|
|
sendCredentials: function sendCredentials() {
|
|
|
|
this._log.trace("Sending credentials.");
|
|
|
|
let credentials = {account: Weave.Service.account,
|
|
|
|
password: Weave.Service.password,
|
|
|
|
synckey: Weave.Service.passphrase,
|
|
|
|
serverURL: Weave.Service.serverURL};
|
|
|
|
this.jpakeclient.sendAndComplete(credentials);
|
|
|
|
},
|
|
|
|
|
|
|
|
// JPAKEClient controller API
|
|
|
|
|
|
|
|
onComplete: function onComplete() {
|
|
|
|
this._log.debug("Exchange was completed successfully!");
|
|
|
|
this.unload();
|
|
|
|
},
|
|
|
|
|
|
|
|
onAbort: function onAbort(error) {
|
|
|
|
// It doesn't really matter why we aborted, but the channel is closed
|
|
|
|
// for sure, so we won't be able to do anything with it.
|
|
|
|
this._log.debug("Exchange was aborted with error: " + error);
|
|
|
|
this.unload();
|
|
|
|
},
|
|
|
|
|
|
|
|
// Irrelevant methods for this controller:
|
|
|
|
displayPIN: function displayPIN() {},
|
|
|
|
onPairingStart: function onPairingStart() {},
|
|
|
|
onPaired: function onPaired() {}
|
|
|
|
};
|