diff --git a/services/sync/modules/async.js b/services/sync/modules/async.js index e72487282e4..effc3fb0390 100644 --- a/services/sync/modules/async.js +++ b/services/sync/modules/async.js @@ -43,6 +43,7 @@ const Cu = Components.utils; Cu.import("resource://weave/log4moz.js"); Cu.import("resource://weave/util.js"); +Cu.import("resource://weave/constants.js"); /* * Asynchronous generator helpers @@ -74,6 +75,8 @@ AsyncException.prototype = { function Generator(object, method, onComplete, args) { this._log = Log4Moz.Service.getLogger("Async.Generator"); + this._log.level = + Log4Moz.Level[Utils.prefs.getCharPref("log.logger.async")]; this._object = object; this._method = method; this.onComplete = onComplete; @@ -121,7 +124,9 @@ Generator.prototype = { get onComplete() { if (this._onComplete) return this._onComplete; - return function() { this._log.trace("Generator " + this.name + " has no onComplete"); }; + return function() { + //this._log.trace("Generator " + this.name + " has no onComplete"); + }; }, set onComplete(value) { if (value && typeof value != "function") @@ -164,7 +169,7 @@ Generator.prototype = { } else { this._log.error(Async.exceptionStr(this, e)); - this._log.trace("Stack trace:\n" + this.trace + + this._log.debug("Stack trace:\n" + this.trace + (e.trace? "\n" + e.trace : "")); } @@ -213,6 +218,11 @@ Generator.prototype = { }, _done: function AsyncGen__done(retval) { + if (!this._generator) { + this._log.error("Generator '" + this.name + "' called 'done' after it's finalized"); + this._log.trace("Initial stack trace:\n" + this.trace); + return; + } this._generator.close(); this._generator = null; this._timer = null; diff --git a/services/sync/modules/crypto.js b/services/sync/modules/crypto.js index 185e9079cba..5aca7bca5d7 100644 --- a/services/sync/modules/crypto.js +++ b/services/sync/modules/crypto.js @@ -88,6 +88,8 @@ WeaveCrypto.prototype = { _init: function Crypto__init() { this._log = Log4Moz.Service.getLogger("Service." + this._logName); + this._log.level = + Log4Moz.Level[Utils.prefs.getCharPref("log.logger.service.crypto")]; let branch = Cc["@mozilla.org/preferences-service;1"] .getService(Ci.nsIPrefBranch2); branch.addObserver("extensions.weave.encryption", this, false); @@ -163,7 +165,7 @@ WeaveCrypto.prototype = { // generates a random string that can be used as a passphrase _opensslRand: function Crypto__opensslRand(length) { if (!length) - length = 256; + length = 128; let outputFile = Utils.getTmp("output"); if (outputFile.exists()) @@ -180,7 +182,7 @@ WeaveCrypto.prototype = { }, // generates an rsa public/private key pair, with the private key encrypted - _opensslRSAKeyGen: function Crypto__opensslRSAKeyGen(password, algorithm, bits) { + _opensslRSAKeyGen: function Crypto__opensslRSAKeyGen(identity, algorithm, bits) { if (!algorithm) algorithm = "aes-256-cbc"; if (!bits) @@ -206,7 +208,7 @@ WeaveCrypto.prototype = { // nsIProcess doesn't support stdin, so we write a file instead let passFile = Utils.getTmp("pass"); let [passFOS] = Utils.open(passFile, ">", PERMS_PASSFILE); - passFOS.writeString(password); + passFOS.writeString(identity.password); passFOS.close(); try { @@ -235,7 +237,7 @@ WeaveCrypto.prototype = { }, // returns 'input' encrypted with the 'pubkey' public RSA key - _opensslRSAencrypt: function Crypto__opensslRSAencrypt(input, pubkey) { + _opensslRSAencrypt: function Crypto__opensslRSAencrypt(input, identity) { let inputFile = Utils.getTmp("input"); let [inputFOS] = Utils.open(inputFile, ">"); inputFOS.writeString(input); @@ -243,18 +245,23 @@ WeaveCrypto.prototype = { let keyFile = Utils.getTmp("key"); let [keyFOS] = Utils.open(keyFile, ">"); - keyFOS.writeString(pubkey); + keyFOS.writeString(identity.pubkey); keyFOS.close(); + let tmpFile = Utils.getTmp("tmp-output"); + if (tmpFile.exists()) + tmpFile.remove(false); + let outputFile = Utils.getTmp("output"); if (outputFile.exists()) outputFile.remove(false); this._openssl("rsautl", "-encrypt", "-pubin", "-inkey", "key", - "-in", "input", "-out", "output"); + "-in", "input", "-out", "tmp-output"); + this._openssl("base64", "-in", "tmp-output", "-out", "output"); let [outputFIS] = Utils.open(outputFile, "<"); - let output = Utils.readStream(outpusFIS); + let output = Utils.readStream(outputFIS); outputFIS.close(); outputFile.remove(false); @@ -262,7 +269,7 @@ WeaveCrypto.prototype = { }, // returns 'input' decrypted with the 'privkey' private RSA key and password - _opensslRSAdecrypt: function Crypto__opensslRSAdecrypt(input, privkey, password) { + _opensslRSAdecrypt: function Crypto__opensslRSAdecrypt(input, identity) { let inputFile = Utils.getTmp("input"); let [inputFOS] = Utils.open(inputFile, ">"); inputFOS.writeString(input); @@ -270,9 +277,13 @@ WeaveCrypto.prototype = { let keyFile = Utils.getTmp("key"); let [keyFOS] = Utils.open(keyFile, ">"); - keyFOS.writeString(privkey); + keyFOS.writeString(identity.privkey); keyFOS.close(); + let tmpFile = Utils.getTmp("tmp-output"); + if (tmpFile.exists()) + tmpFile.remove(false); + let outputFile = Utils.getTmp("output"); if (outputFile.exists()) outputFile.remove(false); @@ -280,12 +291,13 @@ WeaveCrypto.prototype = { // nsIProcess doesn't support stdin, so we write a file instead let passFile = Utils.getTmp("pass"); let [passFOS] = Utils.open(passFile, ">", PERMS_PASSFILE); - passFOS.writeString(password); + passFOS.writeString(identity.password); passFOS.close(); try { - this._openssl("rsautl", "-decrypt", "-inkey", "key", "-pass", - "file:pass", "-in", "input", "-out", "output"); + this._openssl("base64", "-d", "-in", "input", "-out", "tmp-output"); + this._openssl("rsautl", "-decrypt", "-inkey", "key", "-passin", + "file:pass", "-in", "tmp-output", "-out", "output"); } catch(e) { throw e; @@ -295,7 +307,43 @@ WeaveCrypto.prototype = { } let [outputFIS] = Utils.open(outputFile, "<"); - let output = Utils.readStream(outpusFIS); + let output = Utils.readStream(outputFIS); + outputFIS.close(); + outputFile.remove(false); + + return output; + }, + + // returns the public key from the private key + _opensslRSAkeydecrypt: function Crypto__opensslRSAkeydecrypt(identity) { + let keyFile = Utils.getTmp("key"); + let [keyFOS] = Utils.open(keyFile, ">"); + keyFOS.writeString(identity.privkey); + keyFOS.close(); + + let outputFile = Utils.getTmp("output"); + if (outputFile.exists()) + outputFile.remove(false); + + // nsIProcess doesn't support stdin, so we write a file instead + let passFile = Utils.getTmp("pass"); + let [passFOS] = Utils.open(passFile, ">", PERMS_PASSFILE); + passFOS.writeString(identity.password); + passFOS.close(); + + try { + this._openssl("rsa", "-in", "key", "-pubout", "-out", "output", + "-passin", "file:pass"); + + } catch(e) { + throw e; + + } finally { + passFile.remove(false); + } + + let [outputFIS] = Utils.open(outputFile, "<"); + let output = Utils.readStream(outputFIS); outputFIS.close(); outputFile.remove(false); @@ -445,21 +493,27 @@ WeaveCrypto.prototype = { self.done(ret); }, - RSAkeygen: function Crypto_RSAkeygen(password) { + RSAkeygen: function Crypto_RSAkeygen(identity) { let self = yield; - let ret = this._opensslRSAKeyGen(password); + let ret = this._opensslRSAKeyGen(identity); self.done(ret); }, - RSAencrypt: function Crypto_RSAencrypt(data, key) { + RSAencrypt: function Crypto_RSAencrypt(data, identity) { let self = yield; - let ret = this._opensslRSAencrypt(data, key); + let ret = this._opensslRSAencrypt(data, identity); self.done(ret); }, - RSAdecrypt: function Crypto_RSAdecrypt(data, key, password) { + RSAdecrypt: function Crypto_RSAdecrypt(data, identity) { let self = yield; - let ret = this._opensslRSAdecrypt(data, key, password); + let ret = this._opensslRSAdecrypt(data, identity); + self.done(ret); + }, + + RSAkeydecrypt: function Crypto_RSAkeydecrypt(identity) { + let self = yield; + let ret = this._opensslRSAkeydecrypt(identity); self.done(ret); } }; diff --git a/services/sync/modules/dav.js b/services/sync/modules/dav.js index 77c8e152a43..5b03126488c 100644 --- a/services/sync/modules/dav.js +++ b/services/sync/modules/dav.js @@ -45,6 +45,7 @@ Cu.import("resource://gre/modules/XPCOMUtils.jsm"); Cu.import("resource://weave/log4moz.js"); Cu.import("resource://weave/util.js"); Cu.import("resource://weave/async.js"); +Cu.import("resource://weave/constants.js"); Function.prototype.async = Async.sugar; @@ -57,8 +58,11 @@ function DAVCollection(baseURL) { this._baseURL = baseURL; this._authProvider = new DummyAuthProvider(); this._log = Log4Moz.Service.getLogger("Service.DAV"); + this._log.level = + Log4Moz.Level[Utils.prefs.getCharPref("log.logger.service.dav")]; } DAVCollection.prototype = { + __dp: null, get _dp() { if (!this.__dp) @@ -81,11 +85,23 @@ DAVCollection.prototype = { return this._loggedIn; }, + get locked() { + return !this._lockAllowed || this._token != null; + }, + + _lockAllowed: true, + get allowLock() { + return this._lockAllowed; + }, + set allowLock(value) { + this._lockAllowed = value; + }, + _makeRequest: function DC__makeRequest(op, path, headers, data) { let self = yield; let ret; - this._log.debug("Creating " + op + " request for " + this._baseURL + path); + this._log.debug(op + " request for " + path); let request = Cc["@mozilla.org/xmlextras/xmlhttprequest;1"].createInstance(); request = request.QueryInterface(Ci.nsIDOMEventTarget); @@ -106,9 +122,9 @@ DAVCollection.prototype = { let key; for (key in headers) { if (key == 'Authorization') - this._log.debug("HTTP Header " + key + ": ***** (suppressed)"); + this._log.trace("HTTP Header " + key + ": ***** (suppressed)"); else - this._log.debug("HTTP Header " + key + ": " + headers[key]); + this._log.trace("HTTP Header " + key + ": " + headers[key]); request.setRequestHeader(key, headers[key]); } @@ -155,7 +171,7 @@ DAVCollection.prototype = { this._makeRequest.async(this, self.cb, "GET", path2 + "/", this._defaultHeaders); let ret = yield; if (!(ret.status == 404 || ret.status == 500)) { // FIXME: 500 is a services.m.c oddity - this._log.debug("Skipping creation of path " + path2 + + this._log.trace("Skipping creation of path " + path2 + " (got status " + ret.status + ")"); } else { this._log.debug("Creating path: " + path2); @@ -211,6 +227,9 @@ DAVCollection.prototype = { }, LOCK: function DC_LOCK(path, data, onComplete) { + if (!this._lockAllowed) + throw "Cannot acquire lock (internal lock)"; + let headers = {'Content-type': 'text/xml; charset="utf-8"', 'Depth': 'infinity', 'Timeout': 'Second-600'}; @@ -326,7 +345,7 @@ DAVCollection.prototype = { let self = yield; this._token = null; - this._log.info("Acquiring lock"); + this._log.trace("Acquiring lock"); if (this._token) { this._log.debug("Lock called, but we already hold a token"); @@ -354,7 +373,7 @@ DAVCollection.prototype = { this._token = token.textContent; if (this._token) - this._log.debug("Lock acquired"); + this._log.trace("Lock acquired"); else this._log.warn("Could not acquire lock"); @@ -364,9 +383,9 @@ DAVCollection.prototype = { unlock: function DC_unlock() { let self = yield; - this._log.info("Releasing lock"); + this._log.trace("Releasing lock"); - if (this._token === null) { + if (!this.locked) { this._log.debug("Unlock called, but we don't hold a token right now"); self.done(true); yield; @@ -384,9 +403,9 @@ DAVCollection.prototype = { this._token = null; if (this._token) - this._log.info("Could not release lock"); + this._log.trace("Could not release lock"); else - this._log.info("Lock released (or we didn't have one)"); + this._log.trace("Lock released (or we didn't have one)"); self.done(!this._token); }, diff --git a/services/sync/modules/engines.js b/services/sync/modules/engines.js index fdd46dd1ad9..a7fb1ef9a2d 100644 --- a/services/sync/modules/engines.js +++ b/services/sync/modules/engines.js @@ -46,6 +46,7 @@ Cu.import("resource://weave/log4moz.js"); Cu.import("resource://weave/constants.js"); Cu.import("resource://weave/util.js"); Cu.import("resource://weave/crypto.js"); +Cu.import("resource://weave/identity.js"); Cu.import("resource://weave/stores.js"); Cu.import("resource://weave/syncCores.js"); Cu.import("resource://weave/async.js"); @@ -53,8 +54,8 @@ Cu.import("resource://weave/async.js"); Function.prototype.async = Async.sugar; let Crypto = new WeaveCrypto(); -function Engine(davCollection, cryptoId) { - //this._init(davCollection, cryptoId); +function Engine(davCollection, pbeId) { + //this._init(davCollection, pbeId); } Engine.prototype = { // "default-engine"; @@ -114,35 +115,36 @@ Engine.prototype = { this.__snapshot = value; }, - _init: function Engine__init(davCollection, cryptoId) { + _init: function Engine__init(davCollection, pbeId) { this._dav = davCollection; - this._cryptoId = cryptoId; + this._pbeId = pbeId; + this._engineId = new Identity(pbeId.realm + " - " + this.logName, + pbeId.username); this._log = Log4Moz.Service.getLogger("Service." + this.logName); + this._log.level = + Log4Moz.Level[Utils.prefs.getCharPref("log.logger.service.engine")]; this._osPrefix = "weave:" + this.name + ":"; this._snapshot.load(); }, - _getSymKey: function Engine__getCryptoId(cryptoId) { + _getSymKey: function Engine__getSymKey() { let self = yield; - let done = false; this._dav.GET(this.keysFile, self.cb); let keysResp = yield; Utils.ensureStatus(keysResp.status, "Could not get keys file.", [[200,300]]); - let keys = keysResp.responseText; + let keys = this._json.decode(keysResp.responseText); - if (!keys[this._userHash]) { - this._log.error("Keyring does not contain a key for this user"); - return; - } + if (!keys || !keys.ring || !keys.ring[this._engineId.userHash]) + throw "Keyring does not contain a key for this user"; - //Crypto.RSAdecrypt.async(Crypto, self.cb, - // keys[this._userHash], - - self.done(done); - yield; - this._log.warn("_getSymKey generator not properly closed"); + Crypto.RSAdecrypt.async(Crypto, self.cb, + keys.ring[this._engineId.userHash], this._pbeId); + let symkey = yield; + this._engineId.setTempPassword(symkey); + + self.done(true); }, _serializeCommands: function Engine__serializeCommands(commands) { @@ -165,11 +167,6 @@ Engine.prototype = { this._log.debug("Resetting server data"); this._os.notifyObservers(null, this._osPrefix + "reset-server:start", ""); - this._dav.lock.async(this._dav, self.cb); - let locked = yield; - if (!locked) - throw "Could not acquire lock, aborting server reset"; - // try to delete all 3, check status after this._dav.DELETE(this.statusFile, self.cb); let statusResp = yield; @@ -178,9 +175,6 @@ Engine.prototype = { this._dav.DELETE(this.deltasFile, self.cb); let deltasResp = yield; - this._dav.unlock.async(this._dav, self.cb); - let unlocked = yield; - Utils.ensureStatus(statusResp.status, "Could not delete status file.", [[200,300],404]); Utils.ensureStatus(snapshotResp.status, @@ -258,215 +252,184 @@ Engine.prototype = { _sync: function BmkEngine__sync() { let self = yield; - let synced = false, locked = null; - try { - this._log.info("Beginning sync"); - this._os.notifyObservers(null, this._osPrefix + "sync:start", ""); + this._log.info("Beginning sync"); - this._dav.lock.async(this._dav, self.cb); - locked = yield; + // Before we get started, make sure we have a remote directory to play in + this._dav.MKCOL(this.serverPrefix, self.cb); + let ret = yield; + if (!ret) + throw "Could not create remote folder"; - if (locked) - this._log.info("Lock acquired"); - else { - this._log.warn("Could not acquire lock, aborting sync"); - return; - } + // 1) Fetch server deltas + this._getServerData.async(this, self.cb); + let server = yield; - // Before we get started, make sure we have a remote directory to play in - this._dav.MKCOL(this.serverPrefix, self.cb); - let ret = yield; - if (!ret) - throw "Could not create remote folder"; + this._log.info("Local snapshot version: " + this._snapshot.version); + this._log.info("Server status: " + server.status); + this._log.info("Server maxVersion: " + server.maxVersion); + this._log.info("Server snapVersion: " + server.snapVersion); - // 1) Fetch server deltas - this._getServerData.async(this, self.cb); - let server = yield; + if (server.status != 0) { + this._log.fatal("Sync error: could not get server status, " + + "or initial upload failed. Aborting sync."); + return; + } - this._log.info("Local snapshot version: " + this._snapshot.version); - this._log.info("Server status: " + server.status); - this._log.info("Server maxVersion: " + server.maxVersion); - this._log.info("Server snapVersion: " + server.snapVersion); + // 2) Generate local deltas from snapshot -> current client status - if (server.status != 0) { - this._log.fatal("Sync error: could not get server status, " + - "or initial upload failed. Aborting sync."); - return; - } + let localJson = new SnapshotStore(); + localJson.data = this._store.wrap(); + this._core.detectUpdates(self.cb, this._snapshot.data, localJson.data); + let localUpdates = yield; - // 2) Generate local deltas from snapshot -> current client status + this._log.trace("local json:\n" + localJson.serialize()); + this._log.trace("Local updates: " + this._serializeCommands(localUpdates)); + this._log.trace("Server updates: " + this._serializeCommands(server.updates)); - let localJson = new SnapshotStore(); - localJson.data = this._store.wrap(); - this._core.detectUpdates(self.cb, this._snapshot.data, localJson.data); - let localUpdates = yield; + if (server.updates.length == 0 && localUpdates.length == 0) { + this._snapshot.version = server.maxVersion; + this._log.info("Sync complete: no changes needed on client or server"); + self.done(true); + return; + } + + // 3) Reconcile client/server deltas and generate new deltas for them. - this._log.trace("local json:\n" + localJson.serialize()); - this._log.trace("Local updates: " + this._serializeCommands(localUpdates)); - this._log.trace("Server updates: " + this._serializeCommands(server.updates)); + this._log.info("Reconciling client/server updates"); + this._core.reconcile(self.cb, localUpdates, server.updates); + ret = yield; - if (server.updates.length == 0 && localUpdates.length == 0) { - this._snapshot.version = server.maxVersion; - this._log.info("Sync complete (1): no changes needed on client or server"); - synced = true; - return; - } - - // 3) Reconcile client/server deltas and generate new deltas for them. + let clientChanges = ret.propagations[0]; + let serverChanges = ret.propagations[1]; + let clientConflicts = ret.conflicts[0]; + let serverConflicts = ret.conflicts[1]; - this._log.info("Reconciling client/server updates"); - this._core.reconcile(self.cb, localUpdates, server.updates); - ret = yield; + this._log.info("Changes for client: " + clientChanges.length); + this._log.info("Predicted changes for server: " + serverChanges.length); + this._log.info("Client conflicts: " + clientConflicts.length); + this._log.info("Server conflicts: " + serverConflicts.length); + this._log.trace("Changes for client: " + this._serializeCommands(clientChanges)); + this._log.trace("Predicted changes for server: " + this._serializeCommands(serverChanges)); + this._log.trace("Client conflicts: " + this._serializeConflicts(clientConflicts)); + this._log.trace("Server conflicts: " + this._serializeConflicts(serverConflicts)); - let clientChanges = ret.propagations[0]; - let serverChanges = ret.propagations[1]; - let clientConflicts = ret.conflicts[0]; - let serverConflicts = ret.conflicts[1]; + if (!(clientChanges.length || serverChanges.length || + clientConflicts.length || serverConflicts.length)) { + this._log.info("Sync complete: no changes needed on client or server"); + this._snapshot.data = localJson.data; + this._snapshot.version = server.maxVersion; + this._snapshot.save(); + self.done(true); + return; + } - this._log.info("Changes for client: " + clientChanges.length); - this._log.info("Predicted changes for server: " + serverChanges.length); - this._log.info("Client conflicts: " + clientConflicts.length); - this._log.info("Server conflicts: " + serverConflicts.length); - this._log.trace("Changes for client: " + this._serializeCommands(clientChanges)); - this._log.trace("Predicted changes for server: " + this._serializeCommands(serverChanges)); - this._log.trace("Client conflicts: " + this._serializeConflicts(clientConflicts)); - this._log.trace("Server conflicts: " + this._serializeConflicts(serverConflicts)); + if (clientConflicts.length || serverConflicts.length) { + this._log.warn("Conflicts found! Discarding server changes"); + } - if (!(clientChanges.length || serverChanges.length || - clientConflicts.length || serverConflicts.length)) { - this._log.info("Sync complete (2): no changes needed on client or server"); - this._snapshot.data = localJson.data; - this._snapshot.version = server.maxVersion; - this._snapshot.save(); - synced = true; - return; - } + let savedSnap = Utils.deepCopy(this._snapshot.data); + let savedVersion = this._snapshot.version; + let newSnapshot; - if (clientConflicts.length || serverConflicts.length) { - this._log.warn("Conflicts found! Discarding server changes"); - } - - let savedSnap = Utils.deepCopy(this._snapshot.data); - let savedVersion = this._snapshot.version; - let newSnapshot; - - // 3.1) Apply server changes to local store - if (clientChanges.length) { - this._log.info("Applying changes locally"); - // Note that we need to need to apply client changes to the - // current tree, not the saved snapshot - - localJson.applyCommands(clientChanges); - this._snapshot.data = localJson.data; - this._snapshot.version = server.maxVersion; - this._store.applyCommands(clientChanges); - newSnapshot = this._store.wrap(); - - this._core.detectUpdates(self.cb, this._snapshot.data, newSnapshot); - let diff = yield; - if (diff.length != 0) { - this._log.warn("Commands did not apply correctly"); - this._log.debug("Diff from snapshot+commands -> " + - "new snapshot after commands:\n" + - this._serializeCommands(diff)); - // FIXME: do we really want to revert the snapshot here? - this._snapshot.data = Utils.deepCopy(savedSnap); - this._snapshot.version = savedVersion; - } - this._snapshot.save(); - } - - // 3.2) Append server delta to the delta file and upload - - // Generate a new diff, from the current server snapshot to the - // current client snapshot. In the case where there are no - // conflicts, it should be the same as what the resolver returned + // 3.1) Apply server changes to local store + if (clientChanges.length) { + this._log.info("Applying changes locally"); + // Note that we need to need to apply client changes to the + // current tree, not the saved snapshot + localJson.applyCommands(clientChanges); + this._snapshot.data = localJson.data; + this._snapshot.version = server.maxVersion; + this._store.applyCommands(clientChanges); newSnapshot = this._store.wrap(); - this._core.detectUpdates(self.cb, server.snapshot, newSnapshot); - let serverDelta = yield; - // Log an error if not the same - if (!(serverConflicts.length || - Utils.deepEquals(serverChanges, serverDelta))) - this._log.warn("Predicted server changes differ from " + - "actual server->client diff (can be ignored in many cases)"); - - this._log.info("Actual changes for server: " + serverDelta.length); - this._log.debug("Actual changes for server: " + - this._serializeCommands(serverDelta)); - - if (serverDelta.length) { - this._log.info("Uploading changes to server"); - - this._snapshot.data = newSnapshot; - this._snapshot.version = ++server.maxVersion; - - server.deltas.push(serverDelta); - - if (server.formatVersion != STORAGE_FORMAT_VERSION || - this._encryptionChanged) { - this._fullUpload.async(this, self.cb); - let status = yield; - if (!status) - this._log.error("Could not upload files to server"); // eep? - - } else { - Crypto.PBEencrypt.async(Crypto, self.cb, - this._serializeCommands(server.deltas), - this._cryptoId); - let data = yield; - this._dav.PUT(this.deltasFile, data, self.cb); - let deltasPut = yield; - - let c = 0; - for (GUID in this._snapshot.data) - c++; - - this._dav.PUT(this.statusFile, - this._json.encode( - {GUID: this._snapshot.GUID, - formatVersion: STORAGE_FORMAT_VERSION, - snapVersion: server.snapVersion, - maxVersion: this._snapshot.version, - snapEncryption: server.snapEncryption, - deltasEncryption: Crypto.defaultAlgorithm, - itemCount: c}), self.cb); - let statusPut = yield; - - if (deltasPut.status >= 200 && deltasPut.status < 300 && - statusPut.status >= 200 && statusPut.status < 300) { - this._log.info("Successfully updated deltas and status on server"); - this._snapshot.save(); - } else { - // FIXME: revert snapshot here? - can't, we already applied - // updates locally! - need to save and retry - this._log.error("Could not update deltas on server"); - } - } + this._core.detectUpdates(self.cb, this._snapshot.data, newSnapshot); + let diff = yield; + if (diff.length != 0) { + this._log.warn("Commands did not apply correctly"); + this._log.debug("Diff from snapshot+commands -> " + + "new snapshot after commands:\n" + + this._serializeCommands(diff)); + // FIXME: do we really want to revert the snapshot here? + this._snapshot.data = Utils.deepCopy(savedSnap); + this._snapshot.version = savedVersion; } + this._snapshot.save(); + } - this._log.info("Sync complete"); - synced = true; + // 3.2) Append server delta to the delta file and upload - } catch (e) { - throw e; + // Generate a new diff, from the current server snapshot to the + // current client snapshot. In the case where there are no + // conflicts, it should be the same as what the resolver returned + + newSnapshot = this._store.wrap(); + this._core.detectUpdates(self.cb, server.snapshot, newSnapshot); + let serverDelta = yield; + + // Log an error if not the same + if (!(serverConflicts.length || + Utils.deepEquals(serverChanges, serverDelta))) + this._log.warn("Predicted server changes differ from " + + "actual server->client diff (can be ignored in many cases)"); + + this._log.info("Actual changes for server: " + serverDelta.length); + this._log.debug("Actual changes for server: " + + this._serializeCommands(serverDelta)); + + if (serverDelta.length) { + this._log.info("Uploading changes to server"); + + this._snapshot.data = newSnapshot; + this._snapshot.version = ++server.maxVersion; + + server.deltas.push(serverDelta); + + if (server.formatVersion != STORAGE_FORMAT_VERSION || + this._encryptionChanged) { + this._fullUpload.async(this, self.cb); + let status = yield; + if (!status) + this._log.error("Could not upload files to server"); // eep? - } finally { - let ok = false; - if (locked) { - this._dav.unlock.async(this._dav, self.cb); - ok = yield; - } - if (ok && synced) { - this._os.notifyObservers(null, this._osPrefix + "sync:success", ""); - self.done(true); } else { - this._os.notifyObservers(null, this._osPrefix + "sync:error", ""); - self.done(false); + Crypto.PBEencrypt.async(Crypto, self.cb, + this._serializeCommands(server.deltas), + this._engineId); + let data = yield; + this._dav.PUT(this.deltasFile, data, self.cb); + let deltasPut = yield; + + let c = 0; + for (GUID in this._snapshot.data) + c++; + + this._dav.PUT(this.statusFile, + this._json.encode( + {GUID: this._snapshot.GUID, + formatVersion: STORAGE_FORMAT_VERSION, + snapVersion: server.snapVersion, + maxVersion: this._snapshot.version, + snapEncryption: server.snapEncryption, + deltasEncryption: Crypto.defaultAlgorithm, + itemCount: c}), self.cb); + let statusPut = yield; + + if (deltasPut.status >= 200 && deltasPut.status < 300 && + statusPut.status >= 200 && statusPut.status < 300) { + this._log.info("Successfully updated deltas and status on server"); + this._snapshot.save(); + } else { + // FIXME: revert snapshot here? - can't, we already applied + // updates locally! - need to save and retry + this._log.error("Could not update deltas on server"); + } } } + + this._log.info("Sync complete"); + self.done(true); }, /* Get the deltas/combined updates from the server @@ -520,6 +483,9 @@ Engine.prototype = { break; } + this._getSymKey.async(this, self.cb); + yield; + if (status.formatVersion == 0) { ret.snapEncryption = status.snapEncryption = "none"; ret.deltasEncryption = status.deltasEncryption = "none"; @@ -548,7 +514,7 @@ Engine.prototype = { Utils.ensureStatus(resp.status, "Could not download snapshot."); Crypto.PBEdecrypt.async(Crypto, self.cb, resp.responseText, - this._cryptoId, + this._engineId, status.snapEncryption); let data = yield; snap.data = this._json.decode(data); @@ -559,7 +525,7 @@ Engine.prototype = { Utils.ensureStatus(resp.status, "Could not download deltas."); Crypto.PBEdecrypt.async(Crypto, self.cb, resp.responseText, - this._cryptoId, + this._engineId, status.deltasEncryption); data = yield; allDeltas = this._json.decode(data); @@ -576,7 +542,7 @@ Engine.prototype = { Utils.ensureStatus(resp.status, "Could not download deltas."); Crypto.PBEdecrypt.async(Crypto, self.cb, resp.responseText, - this._cryptoId, + this._engineId, status.deltasEncryption); let data = yield; allDeltas = this._json.decode(data); @@ -593,7 +559,7 @@ Engine.prototype = { Utils.ensureStatus(resp.status, "Could not download deltas."); Crypto.PBEdecrypt.async(Crypto, self.cb, resp.responseText, - this._cryptoId, + this._engineId, status.deltasEncryption); let data = yield; allDeltas = this._json.decode(data); @@ -659,11 +625,29 @@ Engine.prototype = { let self = yield; let ret = false; + Crypto.PBEkeygen.async(Crypto, self.cb); + let symkey = yield; + this._engineId.setTempPassword(symkey); + if (!this._engineId.password) + throw "Could not generate a symmetric encryption key"; + + Crypto.RSAencrypt.async(Crypto, self.cb, + this._engineId.password, this._pbeId); + let enckey = yield; + if (!enckey) + throw "Could not encrypt symmetric encryption key"; + + let keys = {ring: {}}; + keys.ring[this._engineId.userHash] = enckey; + this._dav.PUT(this.keysFile, this._json.encode(keys), self.cb); + let resp = yield; + Utils.ensureStatus(resp.status, "Could not upload keyring file."); + Crypto.PBEencrypt.async(Crypto, self.cb, this._snapshot.serialize(), - this._cryptoId); + this._engineId); let data = yield; - + this._dav.PUT(this.snapshotFile, data, self.cb); resp = yield; Utils.ensureStatus(resp.status, "Could not upload snapshot."); @@ -706,8 +690,8 @@ Engine.prototype = { } }; -function BookmarksEngine(davCollection, cryptoId) { - this._init(davCollection, cryptoId); +function BookmarksEngine(davCollection, pbeId) { + this._init(davCollection, pbeId); } BookmarksEngine.prototype = { get name() { return "bookmarks-engine"; }, @@ -730,8 +714,8 @@ BookmarksEngine.prototype = { }; BookmarksEngine.prototype.__proto__ = new Engine(); -function HistoryEngine(davCollection, cryptoId) { - this._init(davCollection, cryptoId); +function HistoryEngine(davCollection, pbeId) { + this._init(davCollection, pbeId); } HistoryEngine.prototype = { get name() { return "history-engine"; }, diff --git a/services/sync/modules/identity.js b/services/sync/modules/identity.js index 517b19ae496..fd6694e3a31 100644 --- a/services/sync/modules/identity.js +++ b/services/sync/modules/identity.js @@ -66,9 +66,39 @@ Identity.prototype = { get username() { return this._username; }, set username(value) { this._username = value; }, - _key: null, - get key() { return this._key; }, - set key(value) { this._key = value; }, + get userHash() { + //this._log.trace("Hashing username " + this.username); + + let converter = Cc["@mozilla.org/intl/scriptableunicodeconverter"]. + createInstance(Ci.nsIScriptableUnicodeConverter); + converter.charset = "UTF-8"; + + let hasher = Cc["@mozilla.org/security/hash;1"] + .createInstance(Ci.nsICryptoHash); + hasher.init(hasher.SHA1); + + let data = converter.convertToByteArray(this.username, {}); + hasher.update(data, data.length); + let rawHash = hasher.finish(false); + + // return the two-digit hexadecimal code for a byte + function toHexString(charCode) { + return ("0" + charCode.toString(16)).slice(-2); + } + + let hash = [toHexString(rawHash.charCodeAt(i)) for (i in rawHash)].join(""); + //this._log.trace("Username hashes to " + hash); + return hash; + }, + + _privkey: null, + get privkey() { return this._privkey; }, + set privkey(value) { this._privkey = value; }, + + // FIXME: get this from the privkey using crypto.js? + _pubkey: null, + get pubkey() { return this._pubkey; }, + set pubkey(value) { this._pubkey = value; }, _password: null, get password() { diff --git a/services/sync/modules/service.js b/services/sync/modules/service.js index 0a4ed2022c4..cdc7ff5c23c 100644 --- a/services/sync/modules/service.js +++ b/services/sync/modules/service.js @@ -62,17 +62,6 @@ let Crypto = new WeaveCrypto(); function WeaveSyncService() { this._init(); } WeaveSyncService.prototype = { - __prefs: null, - get _prefs() { - if (!this.__prefs) { - this.__prefs = Cc["@mozilla.org/preferences-service;1"] - .getService(Ci.nsIPrefService); - this.__prefs = this.__prefs.getBranch(PREFS_BRANCH); - this.__prefs.QueryInterface(Ci.nsIPrefBranch2); - } - return this.__prefs; - }, - __os: null, get _os() { if (!this.__os) @@ -134,13 +123,13 @@ WeaveSyncService.prototype = { }, get username() { - return this._prefs.getCharPref("username"); + return Utils.prefs.getCharPref("username"); }, set username(value) { if (value) - this._prefs.setCharPref("username", value); + Utils.prefs.setCharPref("username", value); else - this._prefs.clearUserPref("username"); + Utils.prefs.clearUserPref("username"); // fixme - need to loop over all Identity objects - needs some rethinking... this._mozId.username = value; @@ -153,30 +142,7 @@ WeaveSyncService.prototype = { get passphrase() { return this._cryptoId.password; }, set passphrase(value) { this._cryptoId.password = value; }, - get userPath() { - this._log.info("Hashing username " + this.username); - - let converter = Cc["@mozilla.org/intl/scriptableunicodeconverter"]. - createInstance(Ci.nsIScriptableUnicodeConverter); - converter.charset = "UTF-8"; - - let hasher = Cc["@mozilla.org/security/hash;1"] - .createInstance(Ci.nsICryptoHash); - hasher.init(hasher.SHA1); - - let data = converter.convertToByteArray(this.username, {}); - hasher.update(data, data.length); - let rawHash = hasher.finish(false); - - // return the two-digit hexadecimal code for a byte - function toHexString(charCode) { - return ("0" + charCode.toString(16)).slice(-2); - } - - let hash = [toHexString(rawHash.charCodeAt(i)) for (i in rawHash)].join(""); - this._log.debug("Username hashes to " + hash); - return hash; - }, + get userPath() { return this._mozId.userHash; }, get currentUser() { if (this._dav.loggedIn) @@ -185,20 +151,20 @@ WeaveSyncService.prototype = { }, get enabled() { - return this._prefs.getBoolPref("enabled"); + return Utils.prefs.getBoolPref("enabled"); }, get schedule() { if (!this.enabled) return 0; // manual/off - return this._prefs.getIntPref("schedule"); + return Utils.prefs.getIntPref("schedule"); }, _init: function WeaveSync__init() { this._initLogs(); this._log.info("Weave Sync Service Initializing"); - this._prefs.addObserver("", this, false); + Utils.prefs.addObserver("", this, false); if (!this.enabled) { this._log.info("Weave Sync disabled"); @@ -252,17 +218,19 @@ WeaveSyncService.prototype = { _initLogs: function WeaveSync__initLogs() { this._log = Log4Moz.Service.getLogger("Service.Main"); + this._log.level = + Log4Moz.Level[Utils.prefs.getCharPref("log.logger.service.main")]; let formatter = Log4Moz.Service.newFormatter("basic"); let root = Log4Moz.Service.rootLogger; - root.level = Log4Moz.Level[this._prefs.getCharPref("log.rootLogger")]; + root.level = Log4Moz.Level[Utils.prefs.getCharPref("log.rootLogger")]; let capp = Log4Moz.Service.newAppender("console", formatter); - capp.level = Log4Moz.Level[this._prefs.getCharPref("log.appender.console")]; + capp.level = Log4Moz.Level[Utils.prefs.getCharPref("log.appender.console")]; root.addAppender(capp); let dapp = Log4Moz.Service.newAppender("dump", formatter); - dapp.level = Log4Moz.Level[this._prefs.getCharPref("log.appender.dump")]; + dapp.level = Log4Moz.Level[Utils.prefs.getCharPref("log.appender.dump")]; root.addAppender(dapp); let brief = this._dirSvc.get("ProfD", Ci.nsIFile); @@ -279,35 +247,62 @@ WeaveSyncService.prototype = { verbose.create(verbose.NORMAL_FILE_TYPE, PERMS_FILE); let fapp = Log4Moz.Service.newFileAppender("rotating", brief, formatter); - fapp.level = Log4Moz.Level[this._prefs.getCharPref("log.appender.briefLog")]; + fapp.level = Log4Moz.Level[Utils.prefs.getCharPref("log.appender.briefLog")]; root.addAppender(fapp); let vapp = Log4Moz.Service.newFileAppender("rotating", verbose, formatter); - vapp.level = Log4Moz.Level[this._prefs.getCharPref("log.appender.debugLog")]; + vapp.level = Log4Moz.Level[Utils.prefs.getCharPref("log.appender.debugLog")]; root.addAppender(vapp); }, _lock: function weaveSync__lock() { - if (this._locked) { + let self = yield; + + this._dav.lock.async(this._dav, self.cb); + let locked = yield; + + if (!locked) { this._log.warn("Service lock failed: already locked"); this._os.notifyObservers(null, "weave:service-lock:error", ""); - return false; + self.done(false); + return; } - this._locked = true; + this._log.debug("Service lock acquired"); this._os.notifyObservers(null, "weave:service-lock:success", ""); - return true; + self.done(true); }, _unlock: function WeaveSync__unlock() { - this._locked = false; + let self = yield; + + this._dav.unlock.async(this._dav, self.cb); + let unlocked = yield; + + if (!unlocked) { + this._log.error("Service unlock failed"); + this._os.notifyObservers(null, "weave:service-unlock:error", ""); + self.done(false); + return; + } + this._log.debug("Service lock released"); this._os.notifyObservers(null, "weave:service-unlock:success", ""); + self.done(true); }, - _login: function WeaveSync__login() { + _login: function WeaveSync__login(password, passphrase) { let self = yield; try { + if (this._dav.locked) + throw "Could not login: could not acquire lock"; + this._dav.allowLock = false; + + // cache password & passphrase + // if null, we'll try to get them from the pw manager below + this._mozId.setTempPassword(password); + this._cryptoId.setTempPassword(passphrase); + this._log.debug("Logging in"); this._os.notifyObservers(null, "weave:service-login:start", ""); @@ -316,7 +311,7 @@ WeaveSyncService.prototype = { if (!this.password) throw "No password given or found in password manager"; - let serverURL = this._prefs.getCharPref("serverURL"); + let serverURL = Utils.prefs.getCharPref("serverURL"); this._dav.baseURL = serverURL + "user/" + this.userPath + "/"; this._log.info("Using server URL: " + this._dav.baseURL); @@ -354,7 +349,9 @@ WeaveSyncService.prototype = { "Could not get private key from server", [[200,300],404]); if (keyResp.status != 404) { - this._cryptoId.key = keyResp.responseText; + this._cryptoId.privkey = keyResp.responseText; + Crypto.RSAkeydecrypt.async(Crypto, self.cb, this._cryptoId); + this._cryptoId.pubkey = yield; } else { // FIXME: hack to wipe everyone's server data... needs to be removed at some point @@ -363,10 +360,11 @@ WeaveSyncService.prototype = { // generate a new key this._log.debug("Generating new RSA key"); - Crypto.RSAkeygen.async(Crypto, self.cb, this._cryptoId.password); + Crypto.RSAkeygen.async(Crypto, self.cb, this._cryptoId); let [privkey, pubkey] = yield; - this._cryptoId.key = privkey; + this._cryptoId.privkey = privkey; + this._cryptoId.pubkey = pubkey; this._dav.MKCOL("private/", self.cb); ret = yield; @@ -388,17 +386,34 @@ WeaveSyncService.prototype = { } this._passphrase = null; + this._dav.allowLock = true; this._os.notifyObservers(null, "weave:service-login:success", ""); self.done(true); } catch (e) { - this._log.warn(Async.exceptionStr(self, e)); - this._log.trace(e.trace); + this._dav.allowLock = true; this._os.notifyObservers(null, "weave:service-login:error", ""); - self.done(false); + throw e; } }, + // NOTE: doesn't lock because it's called from _login() which already holds the lock + _serverWipe: function WeaveSync__serverWipe() { + let self = yield; + + this._dav.listFiles.async(this._dav, self.cb); + let names = yield; + + for (let i = 0; i < names.length; i++) { + this._dav.DELETE(names[i], self.cb); + let resp = yield; + this._log.debug(resp.status); + } + + self.done(); + }, + + // NOTE: can't lock because it assumes the lock is being held ;) _resetLock: function WeaveSync__resetLock() { let self = yield; let success = false; @@ -425,76 +440,104 @@ WeaveSyncService.prototype = { } }, + _syncEngine: function WeaveSync__syncEngine(eng) { + let self = yield; + + this._os.notifyObservers(null, "weave:" + eng.name + ":sync:start", ""); + + let ret; + try { + eng.sync(self.cb); + ret = yield; + } catch (e) { + this._log.warn("Engine failed with error: " + Utils.exceptionStr(e)); + if (e.trace) + this._log.debug("Engine stack trace: " + Utils.stackTrace(e.trace)); + } + + if (ret) + this._os.notifyObservers(null, "weave:" + eng.name + ":sync:success", ""); + else + this._os.notifyObservers(null, "weave:" + eng.name + ":sync:error", ""); + + self.done(); + }, + _sync: function WeaveSync__sync() { let self = yield; - let success = false; try { - if (!this._lock()) - return; + this._lock.async(this, self.cb) + let locked = yield; + if (!locked) + return; this._os.notifyObservers(null, "weave:service:sync:start", ""); - if (this._prefs.getBoolPref("bookmarks")) { - this._bmkEngine.sync(self.cb); + if (Utils.prefs.getBoolPref("bookmarks")) { + this._syncEngine.async(this, self.cb, this._bmkEngine); yield; } - if (this._prefs.getBoolPref("history")) { - this._histEngine.sync(self.cb); + if (Utils.prefs.getBoolPref("history")) { + this._syncEngine.async(this, self.cb, this._histEngine); yield; } - success = true; - this._unlock(); + this._unlock.async(this, self.cb) + yield; + this._os.notifyObservers(null, "weave:service:sync:success", ""); } catch (e) { + this._unlock.async(this, self.cb) + yield; + this._os.notifyObservers(null, "weave:service:sync:error", ""); throw e; - - } finally { - if (success) - this._os.notifyObservers(null, "weave:service:sync:success", ""); - else - this._os.notifyObservers(null, "weave:service:sync:error", ""); - self.done(); } + + self.done(); }, _resetServer: function WeaveSync__resetServer() { let self = yield; - if (!this._lock()) - throw "Could not acrquire lock"; + this._lock.async(this, self.cb) + let locked = yield; + if (!locked) + return; - this._bmkEngine.resetServer(self.cb); - this._histEngine.resetServer(self.cb); + try { + this._bmkEngine.resetServer(self.cb); + this._histEngine.resetServer(self.cb); + + } catch (e) { + throw e; + + } finally { + this._unlock.async(this, self.cb) + yield; + } - this._unlock(); self.done(); }, _resetClient: function WeaveSync__resetClient() { let self = yield; - if (!this._lock()) - throw "Could not acrquire lock"; + this._lock.async(this, self.cb) + let locked = yield; + if (!locked) + return; - this._bmkEngine.resetClient(self.cb); - this._histEngine.resetClient(self.cb); + try { + this._bmkEngine.resetClient(self.cb); + this._histEngine.resetClient(self.cb); - this._unlock(); - self.done(); - }, + } catch (e) { + throw e; - _serverWipe: function WeaveSync__serverWipe() { - let self = yield; - - this._dav.listFiles.async(this._dav, self.cb); - let names = yield; - - for (let i = 0; i < names.length; i++) { - this._dav.DELETE(names[i], self.cb); - let resp = yield; - this._log.debug(resp.status); + } finally { + this._unlock.async(this, self.cb) + yield; } self.done(); @@ -519,14 +562,7 @@ WeaveSyncService.prototype = { // These are global (for all engines) login: function WeaveSync_login(password, passphrase) { - if (!this._lock()) - return; - // cache password & passphrase - // if null, _login() will try to get them from the pw manager - this._mozId.setTempPassword(password); - this._cryptoId.setTempPassword(passphrase); - let self = this; - this._login.async(this, function() {self._unlock()}); + this._login.async(this, null, password, passphrase); }, logout: function WeaveSync_logout() { @@ -537,12 +573,7 @@ WeaveSyncService.prototype = { this._os.notifyObservers(null, "weave:service-logout:success", ""); }, - resetLock: function WeaveSync_resetLock() { - if (!this._lock()) - return; - let self = this; - this._resetLock.async(this, function() {self._unlock()}); - }, + resetLock: function WeaveSync_resetLock() { this._resetLock.async(this); }, // These are per-engine diff --git a/services/sync/modules/util.js b/services/sync/modules/util.js index aa9b9688c65..990ecbb225f 100644 --- a/services/sync/modules/util.js +++ b/services/sync/modules/util.js @@ -278,6 +278,17 @@ let Utils = { return function innerBind() { return method.apply(object, arguments); } }, + _prefs: null, + get prefs() { + if (!this.__prefs) { + this.__prefs = Cc["@mozilla.org/preferences-service;1"] + .getService(Ci.nsIPrefService); + this.__prefs = this.__prefs.getBranch(PREFS_BRANCH); + this.__prefs.QueryInterface(Ci.nsIPrefBranch2); + } + return this.__prefs; + }, + /* * Event listener object * Used to handle XMLHttpRequest and nsITimer callbacks @@ -286,7 +297,9 @@ let Utils = { EventListener: function Weave_EventListener(handler, eventName) { this._handler = handler; this._eventName = eventName; - this._log = Log4Moz.Service.getLogger("Service.EventHandler"); + this._log = Log4Moz.Service.getLogger("Async.EventHandler"); + this._log.level = + Log4Moz.Level[Utils.prefs.getCharPref("log.logger.async")]; } }; diff --git a/services/sync/services-sync.js b/services/sync/services-sync.js index 4ff2bc74417..7dd634c3b02 100644 --- a/services/sync/services-sync.js +++ b/services/sync/services-sync.js @@ -13,9 +13,14 @@ pref("extensions.weave.bookmarks", true); pref("extensions.weave.history", true); pref("extensions.weave.schedule", 1); - -pref("extensions.weave.log.rootLogger", "Config"); pref("extensions.weave.log.appender.console", "Warn"); pref("extensions.weave.log.appender.dump", "Error"); pref("extensions.weave.log.appender.briefLog", "Info"); -pref("extensions.weave.log.appender.debugLog", "Config"); +pref("extensions.weave.log.appender.debugLog", "Trace"); + +pref("extensions.weave.log.rootLogger", "Debug"); +pref("extensions.weave.log.logger.async", "Debug"); +pref("extensions.weave.log.logger.service.crypto", "Debug"); +pref("extensions.weave.log.logger.service.dav", "Debug"); +pref("extensions.weave.log.logger.service.engine", "Debug"); +pref("extensions.weave.log.logger.service.main", "Trace");