1.1 --- /dev/null Thu Jan 01 00:00:00 1970 +0000
1.2 +++ b/services/sync/tests/unit/test_node_reassignment.js Wed Dec 31 06:09:35 2014 +0100
1.3 @@ -0,0 +1,522 @@
1.4 +/* Any copyright is dedicated to the Public Domain.
1.5 + http://creativecommons.org/publicdomain/zero/1.0/ */
1.6 +
1.7 +_("Test that node reassignment responses are respected on all kinds of " +
1.8 + "requests.");
1.9 +
1.10 +Cu.import("resource://gre/modules/Log.jsm");
1.11 +Cu.import("resource://services-common/rest.js");
1.12 +Cu.import("resource://services-sync/constants.js");
1.13 +Cu.import("resource://services-sync/service.js");
1.14 +Cu.import("resource://services-sync/status.js");
1.15 +Cu.import("resource://services-sync/util.js");
1.16 +Cu.import("resource://testing-common/services/sync/rotaryengine.js");
1.17 +Cu.import("resource://testing-common/services/sync/utils.js");
1.18 +
1.19 +Service.engineManager.clear();
1.20 +
1.21 +function run_test() {
1.22 + Log.repository.getLogger("Sync.AsyncResource").level = Log.Level.Trace;
1.23 + Log.repository.getLogger("Sync.ErrorHandler").level = Log.Level.Trace;
1.24 + Log.repository.getLogger("Sync.Resource").level = Log.Level.Trace;
1.25 + Log.repository.getLogger("Sync.RESTRequest").level = Log.Level.Trace;
1.26 + Log.repository.getLogger("Sync.Service").level = Log.Level.Trace;
1.27 + Log.repository.getLogger("Sync.SyncScheduler").level = Log.Level.Trace;
1.28 + initTestLogging();
1.29 +
1.30 + ensureLegacyIdentityManager();
1.31 +
1.32 + Service.engineManager.register(RotaryEngine);
1.33 +
1.34 + // None of the failures in this file should result in a UI error.
1.35 + function onUIError() {
1.36 + do_throw("Errors should not be presented in the UI.");
1.37 + }
1.38 + Svc.Obs.add("weave:ui:login:error", onUIError);
1.39 + Svc.Obs.add("weave:ui:sync:error", onUIError);
1.40 +
1.41 + run_next_test();
1.42 +}
1.43 +
1.44 +/**
1.45 + * Emulate the following Zeus config:
1.46 + * $draining = data.get($prefix . $host . " draining");
1.47 + * if ($draining == "drain.") {
1.48 + * log.warn($log_host_db_status . " migrating=1 (node-reassignment)" .
1.49 + * $log_suffix);
1.50 + * http.sendResponse("401 Node reassignment", $content_type,
1.51 + * '"server request: node reassignment"', "");
1.52 + * }
1.53 + */
1.54 +const reassignBody = "\"server request: node reassignment\"";
1.55 +
1.56 +// API-compatible with SyncServer handler. Bind `handler` to something to use
1.57 +// as a ServerCollection handler.
1.58 +function handleReassign(handler, req, resp) {
1.59 + resp.setStatusLine(req.httpVersion, 401, "Node reassignment");
1.60 + resp.setHeader("Content-Type", "application/json");
1.61 + resp.bodyOutputStream.write(reassignBody, reassignBody.length);
1.62 +}
1.63 +
1.64 +/**
1.65 + * A node assignment handler.
1.66 + */
1.67 +function installNodeHandler(server, next) {
1.68 + let newNodeBody = server.baseURI;
1.69 + function handleNodeRequest(req, resp) {
1.70 + _("Client made a request for a node reassignment.");
1.71 + resp.setStatusLine(req.httpVersion, 200, "OK");
1.72 + resp.setHeader("Content-Type", "text/plain");
1.73 + resp.bodyOutputStream.write(newNodeBody, newNodeBody.length);
1.74 + Utils.nextTick(next);
1.75 + }
1.76 + let nodePath = "/user/1.0/johndoe/node/weave";
1.77 + server.server.registerPathHandler(nodePath, handleNodeRequest);
1.78 + _("Registered node handler at " + nodePath);
1.79 +}
1.80 +
1.81 +function prepareServer() {
1.82 + let deferred = Promise.defer();
1.83 + configureIdentity({username: "johndoe"}).then(() => {
1.84 + let server = new SyncServer();
1.85 + server.registerUser("johndoe");
1.86 + server.start();
1.87 + Service.serverURL = server.baseURI;
1.88 + Service.clusterURL = server.baseURI;
1.89 + do_check_eq(Service.userAPIURI, server.baseURI + "user/1.0/");
1.90 + deferred.resolve(server);
1.91 + });
1.92 + return deferred.promise;
1.93 +}
1.94 +
1.95 +function getReassigned() {
1.96 + try {
1.97 + return Services.prefs.getBoolPref("services.sync.lastSyncReassigned");
1.98 + } catch (ex if (ex.result == Cr.NS_ERROR_UNEXPECTED)) {
1.99 + return false;
1.100 + } catch (ex) {
1.101 + do_throw("Got exception retrieving lastSyncReassigned: " +
1.102 + Utils.exceptionStr(ex));
1.103 + }
1.104 +}
1.105 +
1.106 +/**
1.107 + * Make a test request to `url`, then watch the result of two syncs
1.108 + * to ensure that a node request was made.
1.109 + * Runs `between` between the two. This can be used to undo deliberate failure
1.110 + * setup, detach observers, etc.
1.111 + */
1.112 +function syncAndExpectNodeReassignment(server, firstNotification, between,
1.113 + secondNotification, url) {
1.114 + let deferred = Promise.defer();
1.115 + function onwards() {
1.116 + let nodeFetched = false;
1.117 + function onFirstSync() {
1.118 + _("First sync completed.");
1.119 + Svc.Obs.remove(firstNotification, onFirstSync);
1.120 + Svc.Obs.add(secondNotification, onSecondSync);
1.121 +
1.122 + do_check_eq(Service.clusterURL, "");
1.123 +
1.124 + // Track whether we fetched node/weave. We want to wait for the second
1.125 + // sync to finish so that we're cleaned up for the next test, so don't
1.126 + // run_next_test in the node handler.
1.127 + nodeFetched = false;
1.128 +
1.129 + // Verify that the client requests a node reassignment.
1.130 + // Install a node handler to watch for these requests.
1.131 + installNodeHandler(server, function () {
1.132 + nodeFetched = true;
1.133 + });
1.134 +
1.135 + // Allow for tests to clean up error conditions.
1.136 + between();
1.137 + }
1.138 + function onSecondSync() {
1.139 + _("Second sync completed.");
1.140 + Svc.Obs.remove(secondNotification, onSecondSync);
1.141 + Service.scheduler.clearSyncTriggers();
1.142 +
1.143 + // Make absolutely sure that any event listeners are done with their work
1.144 + // before we proceed.
1.145 + waitForZeroTimer(function () {
1.146 + _("Second sync nextTick.");
1.147 + do_check_true(nodeFetched);
1.148 + Service.startOver();
1.149 + server.stop(deferred.resolve);
1.150 + });
1.151 + }
1.152 +
1.153 + Svc.Obs.add(firstNotification, onFirstSync);
1.154 + Service.sync();
1.155 + }
1.156 +
1.157 + // Make sure that it works!
1.158 + let request = new RESTRequest(url);
1.159 + request.get(function () {
1.160 + do_check_eq(request.response.status, 401);
1.161 + Utils.nextTick(onwards);
1.162 + });
1.163 + yield deferred.promise;
1.164 +}
1.165 +
1.166 +add_task(function test_momentary_401_engine() {
1.167 + _("Test a failure for engine URLs that's resolved by reassignment.");
1.168 + let server = yield prepareServer();
1.169 + let john = server.user("johndoe");
1.170 +
1.171 + _("Enabling the Rotary engine.");
1.172 + let engine = Service.engineManager.get("rotary");
1.173 + engine.enabled = true;
1.174 +
1.175 + // We need the server to be correctly set up prior to experimenting. Do this
1.176 + // through a sync.
1.177 + let global = {syncID: Service.syncID,
1.178 + storageVersion: STORAGE_VERSION,
1.179 + rotary: {version: engine.version,
1.180 + syncID: engine.syncID}}
1.181 + john.createCollection("meta").insert("global", global);
1.182 +
1.183 + _("First sync to prepare server contents.");
1.184 + Service.sync();
1.185 +
1.186 + _("Setting up Rotary collection to 401.");
1.187 + let rotary = john.createCollection("rotary");
1.188 + let oldHandler = rotary.collectionHandler;
1.189 + rotary.collectionHandler = handleReassign.bind(this, undefined);
1.190 +
1.191 + // We want to verify that the clusterURL pref has been cleared after a 401
1.192 + // inside a sync. Flag the Rotary engine to need syncing.
1.193 + john.collection("rotary").timestamp += 1000;
1.194 +
1.195 + function between() {
1.196 + _("Undoing test changes.");
1.197 + rotary.collectionHandler = oldHandler;
1.198 +
1.199 + function onLoginStart() {
1.200 + // lastSyncReassigned shouldn't be cleared until a sync has succeeded.
1.201 + _("Ensuring that lastSyncReassigned is still set at next sync start.");
1.202 + Svc.Obs.remove("weave:service:login:start", onLoginStart);
1.203 + do_check_true(getReassigned());
1.204 + }
1.205 +
1.206 + _("Adding observer that lastSyncReassigned is still set on login.");
1.207 + Svc.Obs.add("weave:service:login:start", onLoginStart);
1.208 + }
1.209 +
1.210 + yield syncAndExpectNodeReassignment(server,
1.211 + "weave:service:sync:finish",
1.212 + between,
1.213 + "weave:service:sync:finish",
1.214 + Service.storageURL + "rotary");
1.215 +});
1.216 +
1.217 +// This test ends up being a failing fetch *after we're already logged in*.
1.218 +add_task(function test_momentary_401_info_collections() {
1.219 + _("Test a failure for info/collections that's resolved by reassignment.");
1.220 + let server = yield prepareServer();
1.221 +
1.222 + _("First sync to prepare server contents.");
1.223 + Service.sync();
1.224 +
1.225 + // Return a 401 for info requests, particularly info/collections.
1.226 + let oldHandler = server.toplevelHandlers.info;
1.227 + server.toplevelHandlers.info = handleReassign;
1.228 +
1.229 + function undo() {
1.230 + _("Undoing test changes.");
1.231 + server.toplevelHandlers.info = oldHandler;
1.232 + }
1.233 +
1.234 + yield syncAndExpectNodeReassignment(server,
1.235 + "weave:service:sync:error",
1.236 + undo,
1.237 + "weave:service:sync:finish",
1.238 + Service.infoURL);
1.239 +});
1.240 +
1.241 +add_task(function test_momentary_401_storage_loggedin() {
1.242 + _("Test a failure for any storage URL, not just engine parts. " +
1.243 + "Resolved by reassignment.");
1.244 + let server = yield prepareServer();
1.245 +
1.246 + _("Performing initial sync to ensure we are logged in.")
1.247 + Service.sync();
1.248 +
1.249 + // Return a 401 for all storage requests.
1.250 + let oldHandler = server.toplevelHandlers.storage;
1.251 + server.toplevelHandlers.storage = handleReassign;
1.252 +
1.253 + function undo() {
1.254 + _("Undoing test changes.");
1.255 + server.toplevelHandlers.storage = oldHandler;
1.256 + }
1.257 +
1.258 + do_check_true(Service.isLoggedIn, "already logged in");
1.259 + yield syncAndExpectNodeReassignment(server,
1.260 + "weave:service:sync:error",
1.261 + undo,
1.262 + "weave:service:sync:finish",
1.263 + Service.storageURL + "meta/global");
1.264 +});
1.265 +
1.266 +add_task(function test_momentary_401_storage_loggedout() {
1.267 + _("Test a failure for any storage URL, not just engine parts. " +
1.268 + "Resolved by reassignment.");
1.269 + let server = yield prepareServer();
1.270 +
1.271 + // Return a 401 for all storage requests.
1.272 + let oldHandler = server.toplevelHandlers.storage;
1.273 + server.toplevelHandlers.storage = handleReassign;
1.274 +
1.275 + function undo() {
1.276 + _("Undoing test changes.");
1.277 + server.toplevelHandlers.storage = oldHandler;
1.278 + }
1.279 +
1.280 + do_check_false(Service.isLoggedIn, "not already logged in");
1.281 + yield syncAndExpectNodeReassignment(server,
1.282 + "weave:service:login:error",
1.283 + undo,
1.284 + "weave:service:sync:finish",
1.285 + Service.storageURL + "meta/global");
1.286 +});
1.287 +
1.288 +add_task(function test_loop_avoidance_storage() {
1.289 + _("Test that a repeated failure doesn't result in a sync loop " +
1.290 + "if node reassignment cannot resolve the failure.");
1.291 +
1.292 + let server = yield prepareServer();
1.293 +
1.294 + // Return a 401 for all storage requests.
1.295 + let oldHandler = server.toplevelHandlers.storage;
1.296 + server.toplevelHandlers.storage = handleReassign;
1.297 +
1.298 + let firstNotification = "weave:service:login:error";
1.299 + let secondNotification = "weave:service:login:error";
1.300 + let thirdNotification = "weave:service:sync:finish";
1.301 +
1.302 + let nodeFetched = false;
1.303 + let deferred = Promise.defer();
1.304 +
1.305 + // Track the time. We want to make sure the duration between the first and
1.306 + // second sync is small, and then that the duration between second and third
1.307 + // is set to be large.
1.308 + let now;
1.309 +
1.310 + function onFirstSync() {
1.311 + _("First sync completed.");
1.312 + Svc.Obs.remove(firstNotification, onFirstSync);
1.313 + Svc.Obs.add(secondNotification, onSecondSync);
1.314 +
1.315 + do_check_eq(Service.clusterURL, "");
1.316 +
1.317 + // We got a 401 mid-sync, and set the pref accordingly.
1.318 + do_check_true(Services.prefs.getBoolPref("services.sync.lastSyncReassigned"));
1.319 +
1.320 + // Track whether we fetched node/weave. We want to wait for the second
1.321 + // sync to finish so that we're cleaned up for the next test, so don't
1.322 + // run_next_test in the node handler.
1.323 + nodeFetched = false;
1.324 +
1.325 + // Verify that the client requests a node reassignment.
1.326 + // Install a node handler to watch for these requests.
1.327 + installNodeHandler(server, function () {
1.328 + nodeFetched = true;
1.329 + });
1.330 +
1.331 + // Update the timestamp.
1.332 + now = Date.now();
1.333 + }
1.334 +
1.335 + function onSecondSync() {
1.336 + _("Second sync completed.");
1.337 + Svc.Obs.remove(secondNotification, onSecondSync);
1.338 + Svc.Obs.add(thirdNotification, onThirdSync);
1.339 +
1.340 + // This sync occurred within the backoff interval.
1.341 + let elapsedTime = Date.now() - now;
1.342 + do_check_true(elapsedTime < MINIMUM_BACKOFF_INTERVAL);
1.343 +
1.344 + // This pref will be true until a sync completes successfully.
1.345 + do_check_true(getReassigned());
1.346 +
1.347 + // The timer will be set for some distant time.
1.348 + // We store nextSync in prefs, which offers us only limited resolution.
1.349 + // Include that logic here.
1.350 + let expectedNextSync = 1000 * Math.floor((now + MINIMUM_BACKOFF_INTERVAL) / 1000);
1.351 + _("Next sync scheduled for " + Service.scheduler.nextSync);
1.352 + _("Expected to be slightly greater than " + expectedNextSync);
1.353 +
1.354 + do_check_true(Service.scheduler.nextSync >= expectedNextSync);
1.355 + do_check_true(!!Service.scheduler.syncTimer);
1.356 +
1.357 + // Undo our evil scheme.
1.358 + server.toplevelHandlers.storage = oldHandler;
1.359 +
1.360 + // Bring the timer forward to kick off a successful sync, so we can watch
1.361 + // the pref get cleared.
1.362 + Service.scheduler.scheduleNextSync(0);
1.363 + }
1.364 + function onThirdSync() {
1.365 + Svc.Obs.remove(thirdNotification, onThirdSync);
1.366 +
1.367 + // That'll do for now; no more syncs.
1.368 + Service.scheduler.clearSyncTriggers();
1.369 +
1.370 + // Make absolutely sure that any event listeners are done with their work
1.371 + // before we proceed.
1.372 + waitForZeroTimer(function () {
1.373 + _("Third sync nextTick.");
1.374 + do_check_false(getReassigned());
1.375 + do_check_true(nodeFetched);
1.376 + Service.startOver();
1.377 + server.stop(deferred.resolve);
1.378 + });
1.379 + }
1.380 +
1.381 + Svc.Obs.add(firstNotification, onFirstSync);
1.382 +
1.383 + now = Date.now();
1.384 + Service.sync();
1.385 + yield deferred.promise;
1.386 +});
1.387 +
1.388 +add_task(function test_loop_avoidance_engine() {
1.389 + _("Test that a repeated 401 in an engine doesn't result in a sync loop " +
1.390 + "if node reassignment cannot resolve the failure.");
1.391 + let server = yield prepareServer();
1.392 + let john = server.user("johndoe");
1.393 +
1.394 + _("Enabling the Rotary engine.");
1.395 + let engine = Service.engineManager.get("rotary");
1.396 + engine.enabled = true;
1.397 + let deferred = Promise.defer();
1.398 +
1.399 + // We need the server to be correctly set up prior to experimenting. Do this
1.400 + // through a sync.
1.401 + let global = {syncID: Service.syncID,
1.402 + storageVersion: STORAGE_VERSION,
1.403 + rotary: {version: engine.version,
1.404 + syncID: engine.syncID}}
1.405 + john.createCollection("meta").insert("global", global);
1.406 +
1.407 + _("First sync to prepare server contents.");
1.408 + Service.sync();
1.409 +
1.410 + _("Setting up Rotary collection to 401.");
1.411 + let rotary = john.createCollection("rotary");
1.412 + let oldHandler = rotary.collectionHandler;
1.413 + rotary.collectionHandler = handleReassign.bind(this, undefined);
1.414 +
1.415 + // Flag the Rotary engine to need syncing.
1.416 + john.collection("rotary").timestamp += 1000;
1.417 +
1.418 + function onLoginStart() {
1.419 + // lastSyncReassigned shouldn't be cleared until a sync has succeeded.
1.420 + _("Ensuring that lastSyncReassigned is still set at next sync start.");
1.421 + do_check_true(getReassigned());
1.422 + }
1.423 +
1.424 + function beforeSuccessfulSync() {
1.425 + _("Undoing test changes.");
1.426 + rotary.collectionHandler = oldHandler;
1.427 + }
1.428 +
1.429 + function afterSuccessfulSync() {
1.430 + Svc.Obs.remove("weave:service:login:start", onLoginStart);
1.431 + Service.startOver();
1.432 + server.stop(deferred.resolve);
1.433 + }
1.434 +
1.435 + let firstNotification = "weave:service:sync:finish";
1.436 + let secondNotification = "weave:service:sync:finish";
1.437 + let thirdNotification = "weave:service:sync:finish";
1.438 +
1.439 + let nodeFetched = false;
1.440 +
1.441 + // Track the time. We want to make sure the duration between the first and
1.442 + // second sync is small, and then that the duration between second and third
1.443 + // is set to be large.
1.444 + let now;
1.445 +
1.446 + function onFirstSync() {
1.447 + _("First sync completed.");
1.448 + Svc.Obs.remove(firstNotification, onFirstSync);
1.449 + Svc.Obs.add(secondNotification, onSecondSync);
1.450 +
1.451 + do_check_eq(Service.clusterURL, "");
1.452 +
1.453 + _("Adding observer that lastSyncReassigned is still set on login.");
1.454 + Svc.Obs.add("weave:service:login:start", onLoginStart);
1.455 +
1.456 + // We got a 401 mid-sync, and set the pref accordingly.
1.457 + do_check_true(Services.prefs.getBoolPref("services.sync.lastSyncReassigned"));
1.458 +
1.459 + // Track whether we fetched node/weave. We want to wait for the second
1.460 + // sync to finish so that we're cleaned up for the next test, so don't
1.461 + // run_next_test in the node handler.
1.462 + nodeFetched = false;
1.463 +
1.464 + // Verify that the client requests a node reassignment.
1.465 + // Install a node handler to watch for these requests.
1.466 + installNodeHandler(server, function () {
1.467 + nodeFetched = true;
1.468 + });
1.469 +
1.470 + // Update the timestamp.
1.471 + now = Date.now();
1.472 + }
1.473 +
1.474 + function onSecondSync() {
1.475 + _("Second sync completed.");
1.476 + Svc.Obs.remove(secondNotification, onSecondSync);
1.477 + Svc.Obs.add(thirdNotification, onThirdSync);
1.478 +
1.479 + // This sync occurred within the backoff interval.
1.480 + let elapsedTime = Date.now() - now;
1.481 + do_check_true(elapsedTime < MINIMUM_BACKOFF_INTERVAL);
1.482 +
1.483 + // This pref will be true until a sync completes successfully.
1.484 + do_check_true(getReassigned());
1.485 +
1.486 + // The timer will be set for some distant time.
1.487 + // We store nextSync in prefs, which offers us only limited resolution.
1.488 + // Include that logic here.
1.489 + let expectedNextSync = 1000 * Math.floor((now + MINIMUM_BACKOFF_INTERVAL) / 1000);
1.490 + _("Next sync scheduled for " + Service.scheduler.nextSync);
1.491 + _("Expected to be slightly greater than " + expectedNextSync);
1.492 +
1.493 + do_check_true(Service.scheduler.nextSync >= expectedNextSync);
1.494 + do_check_true(!!Service.scheduler.syncTimer);
1.495 +
1.496 + // Undo our evil scheme.
1.497 + beforeSuccessfulSync();
1.498 +
1.499 + // Bring the timer forward to kick off a successful sync, so we can watch
1.500 + // the pref get cleared.
1.501 + Service.scheduler.scheduleNextSync(0);
1.502 + }
1.503 +
1.504 + function onThirdSync() {
1.505 + Svc.Obs.remove(thirdNotification, onThirdSync);
1.506 +
1.507 + // That'll do for now; no more syncs.
1.508 + Service.scheduler.clearSyncTriggers();
1.509 +
1.510 + // Make absolutely sure that any event listeners are done with their work
1.511 + // before we proceed.
1.512 + waitForZeroTimer(function () {
1.513 + _("Third sync nextTick.");
1.514 + do_check_false(getReassigned());
1.515 + do_check_true(nodeFetched);
1.516 + afterSuccessfulSync();
1.517 + });
1.518 + }
1.519 +
1.520 + Svc.Obs.add(firstNotification, onFirstSync);
1.521 +
1.522 + now = Date.now();
1.523 + Service.sync();
1.524 + yield deferred.promise;
1.525 +});
