Bug 1289932 - Send/Handle push messages for send tab to device. r=markh

MozReview-Commit-ID: WD4XzRtl86

--HG--
extra : rebase_source : 418c96ee8a3311c9724862a3385749ddddd339ce
This commit is contained in:
Edouard Oger 2016-08-02 10:09:30 -07:00
parent e8d58192dd
commit b55da91b9a
9 changed files with 268 additions and 90 deletions

View File

@ -50,6 +50,7 @@ var publicProperties = [
"invalidateCertificate",
"loadAndPoll",
"localtimeOffsetMsec",
"notifyDevices",
"now",
"promiseAccountsChangeProfileURI",
"promiseAccountsForceSigninURI",
@ -400,6 +401,29 @@ FxAccountsInternal.prototype = {
return new AccountState(storage);
},
/**
* Send a message to a set of devices in the same account
*
* @return Promise
*/
notifyDevices: function(deviceIds, payload, TTL) {
if (!Array.isArray(deviceIds)) {
deviceIds = [deviceIds];
}
return this.currentAccountState.getUserAccountData()
.then(data => {
if (!data) {
throw this._error(ERROR_NO_ACCOUNT);
}
if (!data.sessionToken) {
throw this._error(ERROR_AUTH_ERROR,
"notifyDevices called without a session token");
}
return this.fxAccountsClient.notifyDevices(data.sessionToken, deviceIds,
payload, TTL);
});
},
/**
* Return the current time in milliseconds as an integer. Allows tests to
* manipulate the date to simulate certificate expiration.

View File

@ -418,6 +418,31 @@ this.FxAccountsClient.prototype = {
return this._request(path, "POST", creds, body);
},
/**
* Sends a message to other devices. Must conform with the push payload schema:
* https://github.com/mozilla/fxa-auth-server/blob/master/docs/pushpayloads.schema.json
*
* @method notifyDevice
* @param sessionTokenHex
* Session token obtained from signIn
* @param deviceIds
* Devices to send the message to
* @param payload
* Data to send with the message
* @return Promise
* Resolves to an empty object:
* {}
*/
notifyDevices(sessionTokenHex, deviceIds, payload, TTL = 0) {
const body = {
to: deviceIds,
payload,
TTL
};
return this._request("/account/devices/notify", "POST",
deriveHawkCredentials(sessionTokenHex, "sessionToken"), body);
},
/**
* Update the session or name for an existing device
*

View File

@ -92,6 +92,7 @@ exports.ON_FXA_UPDATE_NOTIFICATION = "fxaccounts:update";
exports.ON_DEVICE_DISCONNECTED_NOTIFICATION = "fxaccounts:device_disconnected";
exports.ON_PASSWORD_CHANGED_NOTIFICATION = "fxaccounts:password_changed";
exports.ON_PASSWORD_RESET_NOTIFICATION = "fxaccounts:password_reset";
exports.ON_COLLECTION_CHANGED_NOTIFICATION = "sync:collection_changed";
exports.FXA_PUSH_SCOPE_ACCOUNT_UPDATE = "chrome://fxa-device-update";

View File

@ -169,6 +169,8 @@ FxAccountsPushService.prototype = {
case ON_PASSWORD_RESET_NOTIFICATION:
return this._onPasswordChanged();
break;
case ON_COLLECTION_CHANGED_NOTIFICATION:
Services.obs.notifyObservers(null, ON_COLLECTION_CHANGED_NOTIFICATION, payload.data.collections);
default:
this.log.warn("FxA Push command unrecognized: " + payload.command);
}

View File

@ -45,7 +45,7 @@ MAX_IGNORE_ERROR_COUNT: 5,
// Backoff intervals
MINIMUM_BACKOFF_INTERVAL: 15 * 60 * 1000, // 15 minutes
MAXIMUM_BACKOFF_INTERVAL: 8 * 60 * 60 * 1000, // 8 hours
MAXIMUM_BACKOFF_INTERVAL: 8 * 60 * 60 * 1000, // 8 hours
// HMAC event handling timeout.
// 10 minutes: a compromise between the multi-desktop sync interval
@ -101,6 +101,9 @@ MAX_UPLOAD_BYTES: 1024 * 1023, // just under 1MB
MAX_HISTORY_UPLOAD: 5000,
MAX_HISTORY_DOWNLOAD: 5000,
// TTL of the message sent to another device when sending a tab
NOTIFY_TAB_SENT_TTL_SECS: 1 * 3600, // 1 hour
// Top-level statuses:
STATUS_OK: "success.status_ok",
SYNC_FAILED: "error.sync.failed",

View File

@ -21,6 +21,9 @@ Cu.import("resource://services-sync/record.js");
Cu.import("resource://services-sync/resource.js");
Cu.import("resource://services-sync/util.js");
XPCOMUtils.defineLazyModuleGetter(this, "fxAccounts",
"resource://gre/modules/FxAccounts.jsm");
/*
* Trackers are associated with a single engine and deal with
* listening for changes to their particular data type.
@ -1477,10 +1480,12 @@ SyncEngine.prototype = {
+ failed_ids.join(", "));
// Clear successfully uploaded objects.
for (let key in resp.obj.success) {
let id = resp.obj.success[key];
const succeeded_ids = Object.values(resp.obj.success);
for (let id of succeeded_ids) {
delete this._modified[id];
}
this._onRecordsWritten(succeeded_ids, failed_ids);
}
let postQueue = up.newPostQueue(this._log, handleResponse);
@ -1511,6 +1516,11 @@ SyncEngine.prototype = {
}
},
_onRecordsWritten(succeeded, failed) {
// Implement this method to take specific actions against successfully
// uploaded records and failed records.
},
// Any cleanup necessary.
// Save the current snapshot so as to calculate changes at next sync
_syncFinish: function () {

View File

@ -48,7 +48,8 @@ Utils.deferGetSet(ClientsRec,
"cleartext",
["name", "type", "commands",
"version", "protocols",
"formfactor", "os", "appPackage", "application", "device"]);
"formfactor", "os", "appPackage", "application", "device",
"fxaDeviceId"]);
this.ClientEngine = function ClientEngine(service) {
@ -176,6 +177,13 @@ ClientEngine.prototype = {
return client ? client.name : "";
},
getClientFxaDeviceId(id) {
if (this._store._remoteClients[id]) {
return this._store._remoteClients[id].fxaDeviceId;
}
return null;
},
isMobile: function isMobile(id) {
if (this._store._remoteClients[id])
return this._store._remoteClients[id].type == DEVICE_TYPE_MOBILE;
@ -237,6 +245,31 @@ ClientEngine.prototype = {
SyncEngine.prototype._uploadOutgoing.call(this);
},
_onRecordsWritten(succeeded, failed) {
// Notify other devices that their own client collection changed
const idsToNotify = succeeded.reduce((acc, id) => {
if (id == this.localID) {
return acc;
}
const fxaDeviceId = this.getClientFxaDeviceId(id);
return fxaDeviceId ? acc.concat(fxaDeviceId) : acc;
}, []);
if (idsToNotify.length > 0) {
this._notifyCollectionChanged(idsToNotify);
}
},
_notifyCollectionChanged(ids) {
const message = {
version: 1,
command: "sync:collection_changed",
data: {
collections: ["clients"]
}
};
fxAccounts.notifyDevices(ids, message, NOTIFY_TAB_SENT_TTL_SECS);
},
_syncFinish() {
// Record histograms for our device types, and also write them to a pref
// so non-histogram telemetry (eg, UITelemetry) has easy access to them.

View File

@ -359,6 +359,7 @@ Sync11Service.prototype = {
}
Svc.Obs.add("weave:service:setup-complete", this);
Svc.Obs.add("sync:collection_changed", this); // Pulled from FxAccountsCommon
Svc.Prefs.observe("engine.", this);
this.scheduler = new SyncScheduler(this);
@ -485,6 +486,13 @@ Sync11Service.prototype = {
observe: function observe(subject, topic, data) {
switch (topic) {
// Ideally this observer should be in the SyncScheduler, but it would require
// some work to know about the sync specific engines. We should move this there once it does.
case "sync:collection_changed":
if (data.includes("clients")) {
this.sync([]); // [] = clients collection only
}
break;
case "weave:service:setup-complete":
let status = this._checkSetup();
if (status != STATUS_DISABLED && status != CLIENT_NOT_CONFIGURED)

View File

@ -31,10 +31,10 @@ function check_record_version(user, id) {
let cleartext = rec.decrypt(Service.collectionKeys.keyForCollection("clients"));
_("Payload is " + JSON.stringify(cleartext));
do_check_eq(Services.appinfo.version, cleartext.version);
do_check_eq(2, cleartext.protocols.length);
do_check_eq("1.1", cleartext.protocols[0]);
do_check_eq("1.5", cleartext.protocols[1]);
equal(Services.appinfo.version, cleartext.version);
equal(2, cleartext.protocols.length);
equal("1.1", cleartext.protocols[0]);
equal("1.5", cleartext.protocols[1]);
}
add_test(function test_bad_hmac() {
@ -64,7 +64,7 @@ add_test(function test_bad_hmac() {
let coll = user.collection("clients");
// Treat a non-existent collection as empty.
do_check_eq(expectedCount, coll ? coll.count() : 0, stack);
equal(expectedCount, coll ? coll.count() : 0, stack);
}
function check_client_deleted(id) {
@ -77,7 +77,7 @@ add_test(function test_bad_hmac() {
generateNewKeys(Service.collectionKeys);
let serverKeys = Service.collectionKeys.asWBO("crypto", "keys");
serverKeys.encrypt(Service.identity.syncKeyBundle);
do_check_true(serverKeys.upload(Service.resource(Service.cryptoKeysURL)).success);
ok(serverKeys.upload(Service.resource(Service.cryptoKeysURL)).success);
}
try {
@ -89,11 +89,11 @@ add_test(function test_bad_hmac() {
generateNewKeys(Service.collectionKeys);
_("First sync, client record is uploaded");
do_check_eq(engine.lastRecordUpload, 0);
equal(engine.lastRecordUpload, 0);
check_clients_count(0);
engine._sync();
check_clients_count(1);
do_check_true(engine.lastRecordUpload > 0);
ok(engine.lastRecordUpload > 0);
// Our uploaded record has a version.
check_record_version(user, engine.localID);
@ -109,7 +109,7 @@ add_test(function test_bad_hmac() {
generateNewKeys(Service.collectionKeys);
let serverKeys = Service.collectionKeys.asWBO("crypto", "keys");
serverKeys.encrypt(Service.identity.syncKeyBundle);
do_check_true(serverKeys.upload(Service.resource(Service.cryptoKeysURL)).success);
ok(serverKeys.upload(Service.resource(Service.cryptoKeysURL)).success);
_("Sync.");
engine._sync();
@ -130,8 +130,8 @@ add_test(function test_bad_hmac() {
engine._sync();
_("Old record was not deleted, new one uploaded.");
do_check_eq(deletedCollections.length, 0);
do_check_eq(deletedItems.length, 0);
equal(deletedCollections.length, 0);
equal(deletedItems.length, 0);
check_clients_count(2);
_("Now try the scenario where our keys are wrong *and* there's a bad record.");
@ -162,14 +162,14 @@ add_test(function test_bad_hmac() {
generateNewKeys(Service.collectionKeys);
let oldKey = Service.collectionKeys.keyForCollection();
do_check_eq(deletedCollections.length, 0);
do_check_eq(deletedItems.length, 0);
equal(deletedCollections.length, 0);
equal(deletedItems.length, 0);
engine._sync();
do_check_eq(deletedItems.length, 1);
equal(deletedItems.length, 1);
check_client_deleted(oldLocalID);
check_clients_count(1);
let newKey = Service.collectionKeys.keyForCollection();
do_check_false(oldKey.equals(newKey));
ok(!oldKey.equals(newKey));
} finally {
Svc.Prefs.resetBranch("");
@ -181,12 +181,12 @@ add_test(function test_bad_hmac() {
add_test(function test_properties() {
_("Test lastRecordUpload property");
try {
do_check_eq(Svc.Prefs.get("clients.lastRecordUpload"), undefined);
do_check_eq(engine.lastRecordUpload, 0);
equal(Svc.Prefs.get("clients.lastRecordUpload"), undefined);
equal(engine.lastRecordUpload, 0);
let now = Date.now();
engine.lastRecordUpload = now / 1000;
do_check_eq(engine.lastRecordUpload, Math.floor(now / 1000));
equal(engine.lastRecordUpload, Math.floor(now / 1000));
} finally {
Svc.Prefs.resetBranch("");
run_next_test();
@ -288,30 +288,30 @@ add_test(function test_sync() {
try {
_("First sync. Client record is uploaded.");
do_check_eq(clientWBO(), undefined);
do_check_eq(engine.lastRecordUpload, 0);
equal(clientWBO(), undefined);
equal(engine.lastRecordUpload, 0);
engine._sync();
do_check_true(!!clientWBO().payload);
do_check_true(engine.lastRecordUpload > 0);
ok(!!clientWBO().payload);
ok(engine.lastRecordUpload > 0);
_("Let's time travel more than a week back, new record should've been uploaded.");
engine.lastRecordUpload -= MORE_THAN_CLIENTS_TTL_REFRESH;
let lastweek = engine.lastRecordUpload;
clientWBO().payload = undefined;
engine._sync();
do_check_true(!!clientWBO().payload);
do_check_true(engine.lastRecordUpload > lastweek);
ok(!!clientWBO().payload);
ok(engine.lastRecordUpload > lastweek);
_("Remove client record.");
engine.removeClientData();
do_check_eq(clientWBO().payload, undefined);
equal(clientWBO().payload, undefined);
_("Time travel one day back, no record uploaded.");
engine.lastRecordUpload -= LESS_THAN_CLIENTS_TTL_REFRESH;
let yesterday = engine.lastRecordUpload;
engine._sync();
do_check_eq(clientWBO().payload, undefined);
do_check_eq(engine.lastRecordUpload, yesterday);
equal(clientWBO().payload, undefined);
equal(engine.lastRecordUpload, yesterday);
} finally {
Svc.Prefs.resetBranch("");
@ -336,16 +336,16 @@ add_test(function test_client_name_change() {
let initialScore = tracker.score;
do_check_eq(Object.keys(tracker.changedIDs).length, 0);
equal(Object.keys(tracker.changedIDs).length, 0);
Svc.Prefs.set("client.name", "new name");
_("new name: " + engine.localName);
do_check_neq(initialName, engine.localName);
do_check_eq(Object.keys(tracker.changedIDs).length, 1);
do_check_true(engine.localID in tracker.changedIDs);
do_check_true(tracker.score > initialScore);
do_check_true(tracker.score >= SCORE_INCREMENT_XLARGE);
notEqual(initialName, engine.localName);
equal(Object.keys(tracker.changedIDs).length, 1);
ok(engine.localID in tracker.changedIDs);
ok(tracker.score > initialScore);
ok(tracker.score >= SCORE_INCREMENT_XLARGE);
Svc.Obs.notify("weave:engine:stop-tracking");
@ -369,15 +369,15 @@ add_test(function test_send_command() {
engine._sendCommandToClient(action, args, remoteId);
let newRecord = store._remoteClients[remoteId];
do_check_neq(newRecord, undefined);
do_check_eq(newRecord.commands.length, 1);
notEqual(newRecord, undefined);
equal(newRecord.commands.length, 1);
let command = newRecord.commands[0];
do_check_eq(command.command, action);
do_check_eq(command.args.length, 2);
do_check_eq(command.args, args);
equal(command.command, action);
equal(command.args.length, 2);
equal(command.args, args);
do_check_neq(tracker.changedIDs[remoteId], undefined);
notEqual(tracker.changedIDs[remoteId], undefined);
run_next_test();
});
@ -411,24 +411,24 @@ add_test(function test_command_validation() {
engine.sendCommand(action, args, remoteId);
let newRecord = store._remoteClients[remoteId];
do_check_neq(newRecord, undefined);
notEqual(newRecord, undefined);
if (expectedResult) {
_("Ensuring command is sent: " + action);
do_check_eq(newRecord.commands.length, 1);
equal(newRecord.commands.length, 1);
let command = newRecord.commands[0];
do_check_eq(command.command, action);
do_check_eq(command.args, args);
equal(command.command, action);
equal(command.args, args);
do_check_neq(engine._tracker, undefined);
do_check_neq(engine._tracker.changedIDs[remoteId], undefined);
notEqual(engine._tracker, undefined);
notEqual(engine._tracker.changedIDs[remoteId], undefined);
} else {
_("Ensuring command is scrubbed: " + action);
do_check_eq(newRecord.commands, undefined);
equal(newRecord.commands, undefined);
if (store._tracker) {
do_check_eq(engine._tracker[remoteId], undefined);
equal(engine._tracker[remoteId], undefined);
}
}
@ -452,7 +452,7 @@ add_test(function test_command_duplication() {
engine.sendCommand(action, args, remoteId);
let newRecord = store._remoteClients[remoteId];
do_check_eq(newRecord.commands.length, 1);
equal(newRecord.commands.length, 1);
_("Check variant args length");
newRecord.commands = [];
@ -464,7 +464,7 @@ add_test(function test_command_duplication() {
_("Make sure we spot a real dupe argument.");
engine.sendCommand(action, [{ x: "bar" }], remoteId);
do_check_eq(newRecord.commands.length, 2);
equal(newRecord.commands.length, 2);
run_next_test();
});
@ -481,7 +481,7 @@ add_test(function test_command_invalid_client() {
error = ex;
}
do_check_eq(error.message.indexOf("Unknown remote client ID: "), 0);
equal(error.message.indexOf("Unknown remote client ID: "), 0);
run_next_test();
});
@ -506,7 +506,7 @@ add_test(function test_process_incoming_commands() {
Svc.Obs.add(ev, handler);
// logout command causes processIncomingCommands to return explicit false.
do_check_false(engine.processIncomingCommands());
ok(!engine.processIncomingCommands());
});
add_test(function test_filter_duplicate_names() {
@ -703,31 +703,31 @@ add_test(function test_command_sync() {
_("Checking remote record was downloaded.");
let clientRecord = engine._store._remoteClients[remoteId];
do_check_neq(clientRecord, undefined);
do_check_eq(clientRecord.commands.length, 0);
notEqual(clientRecord, undefined);
equal(clientRecord.commands.length, 0);
_("Send a command to the remote client.");
engine.sendCommand("wipeAll", []);
do_check_eq(clientRecord.commands.length, 1);
equal(clientRecord.commands.length, 1);
engine._sync();
_("Checking record was uploaded.");
do_check_neq(clientWBO(engine.localID).payload, undefined);
do_check_true(engine.lastRecordUpload > 0);
notEqual(clientWBO(engine.localID).payload, undefined);
ok(engine.lastRecordUpload > 0);
do_check_neq(clientWBO(remoteId).payload, undefined);
notEqual(clientWBO(remoteId).payload, undefined);
Svc.Prefs.set("client.GUID", remoteId);
engine._resetClient();
do_check_eq(engine.localID, remoteId);
equal(engine.localID, remoteId);
_("Performing sync on resetted client.");
engine._sync();
do_check_neq(engine.localCommands, undefined);
do_check_eq(engine.localCommands.length, 1);
notEqual(engine.localCommands, undefined);
equal(engine.localCommands.length, 1);
let command = engine.localCommands[0];
do_check_eq(command.command, "wipeAll");
do_check_eq(command.args.length, 0);
equal(command.command, "wipeAll");
equal(command.args.length, 0);
} finally {
Svc.Prefs.resetBranch("");
@ -763,18 +763,18 @@ add_test(function test_send_uri_to_client_for_display() {
let newRecord = store._remoteClients[remoteId];
do_check_neq(newRecord, undefined);
do_check_eq(newRecord.commands.length, 1);
notEqual(newRecord, undefined);
equal(newRecord.commands.length, 1);
let command = newRecord.commands[0];
do_check_eq(command.command, "displayURI");
do_check_eq(command.args.length, 3);
do_check_eq(command.args[0], uri);
do_check_eq(command.args[1], engine.localID);
do_check_eq(command.args[2], title);
equal(command.command, "displayURI");
equal(command.args.length, 3);
equal(command.args[0], uri);
equal(command.args[1], engine.localID);
equal(command.args[2], title);
do_check_true(tracker.score > initialScore);
do_check_true(tracker.score - initialScore >= SCORE_INCREMENT_XLARGE);
ok(tracker.score > initialScore);
ok(tracker.score - initialScore >= SCORE_INCREMENT_XLARGE);
_("Ensure unknown client IDs result in exception.");
let unknownId = Utils.makeGUID();
@ -786,7 +786,7 @@ add_test(function test_send_uri_to_client_for_display() {
error = ex;
}
do_check_eq(error.message.indexOf("Unknown remote client ID: "), 0);
equal(error.message.indexOf("Unknown remote client ID: "), 0);
Svc.Prefs.resetBranch("");
Service.recordManager.clearCache();
@ -819,17 +819,17 @@ add_test(function test_receive_display_uri() {
let handler = function(subject, data) {
Svc.Obs.remove(ev, handler);
do_check_eq(subject[0].uri, uri);
do_check_eq(subject[0].clientId, remoteId);
do_check_eq(subject[0].title, title);
do_check_eq(data, null);
equal(subject[0].uri, uri);
equal(subject[0].clientId, remoteId);
equal(subject[0].title, title);
equal(data, null);
run_next_test();
};
Svc.Obs.add(ev, handler);
do_check_true(engine.processIncomingCommands());
ok(engine.processIncomingCommands());
Svc.Prefs.resetBranch("");
Service.recordManager.clearCache();
@ -841,20 +841,20 @@ add_test(function test_optional_client_fields() {
const SUPPORTED_PROTOCOL_VERSIONS = ["1.1", "1.5"];
let local = engine._store.createRecord(engine.localID, "clients");
do_check_eq(local.name, engine.localName);
do_check_eq(local.type, engine.localType);
do_check_eq(local.version, Services.appinfo.version);
do_check_array_eq(local.protocols, SUPPORTED_PROTOCOL_VERSIONS);
equal(local.name, engine.localName);
equal(local.type, engine.localType);
equal(local.version, Services.appinfo.version);
deepEqual(local.protocols, SUPPORTED_PROTOCOL_VERSIONS);
// Optional fields.
// Make sure they're what they ought to be...
do_check_eq(local.os, Services.appinfo.OS);
do_check_eq(local.appPackage, Services.appinfo.ID);
equal(local.os, Services.appinfo.OS);
equal(local.appPackage, Services.appinfo.ID);
// ... and also that they're non-empty.
do_check_true(!!local.os);
do_check_true(!!local.appPackage);
do_check_true(!!local.application);
ok(!!local.os);
ok(!!local.appPackage);
ok(!!local.application);
// We don't currently populate device or formfactor.
// See Bug 1100722, Bug 1100723.
@ -1070,6 +1070,78 @@ add_test(function test_send_uri_ack() {
}
});
add_test(function test_command_sync() {
_("Notify other clients when writing their record.");
engine._store.wipe();
generateNewKeys(Service.collectionKeys);
let contents = {
meta: {global: {engines: {clients: {version: engine.version,
syncID: engine.syncID}}}},
clients: {},
crypto: {}
};
let server = serverForUsers({"foo": "password"}, contents);
new SyncTestingInfrastructure(server.server);
let user = server.user("foo");
let collection = server.getCollection("foo", "clients");
let remoteId = Utils.makeGUID();
let remoteId2 = Utils.makeGUID();
function clientWBO(id) {
return user.collection("clients").wbo(id);
}
_("Create remote client record 1");
server.insertWBO("foo", "clients", new ServerWBO(remoteId, encryptPayload({
id: remoteId,
name: "Remote client",
type: "desktop",
commands: [],
version: "48",
protocols: ["1.5"]
}), Date.now() / 1000));
_("Create remote client record 2");
server.insertWBO("foo", "clients", new ServerWBO(remoteId2, encryptPayload({
id: remoteId2,
name: "Remote client 2",
type: "mobile",
commands: [],
version: "48",
protocols: ["1.5"]
}), Date.now() / 1000));
try {
equal(collection.count(), 2, "2 remote records written");
engine._sync();
equal(collection.count(), 3, "3 remote records written (+1 for the synced local record)");
let notifiedIds;
engine.sendCommand("wipeAll", []);
engine._tracker.addChangedID(engine.localID);
engine.getClientFxaDeviceId = (id) => "fxa-" + id;
engine._notifyCollectionChanged = (ids) => (notifiedIds = ids);
_("Syncing.");
engine._sync();
deepEqual(notifiedIds, ["fxa-fake-guid-00","fxa-fake-guid-01"]);
ok(!notifiedIds.includes(engine.getClientFxaDeviceId(engine.localID)),
"We never notify the local device");
} finally {
Svc.Prefs.resetBranch("");
Service.recordManager.clearCache();
try {
server.deleteCollections("foo");
} finally {
server.stop(run_next_test);
}
}
});
function run_test() {
initTestLogging("Trace");
Log.repository.getLogger("Sync.Engine.Clients").level = Log.Level.Trace;