|
1 /* Any copyright is dedicated to the Public Domain. |
|
2 http://creativecommons.org/publicdomain/zero/1.0/ */ |
|
3 |
|
4 _("Test that node reassignment responses are respected on all kinds of " + |
|
5 "requests."); |
|
6 |
|
7 Cu.import("resource://gre/modules/Log.jsm"); |
|
8 Cu.import("resource://services-common/rest.js"); |
|
9 Cu.import("resource://services-sync/constants.js"); |
|
10 Cu.import("resource://services-sync/service.js"); |
|
11 Cu.import("resource://services-sync/status.js"); |
|
12 Cu.import("resource://services-sync/util.js"); |
|
13 Cu.import("resource://testing-common/services/sync/rotaryengine.js"); |
|
14 Cu.import("resource://testing-common/services/sync/utils.js"); |
|
15 |
|
16 Service.engineManager.clear(); |
|
17 |
|
18 function run_test() { |
|
19 Log.repository.getLogger("Sync.AsyncResource").level = Log.Level.Trace; |
|
20 Log.repository.getLogger("Sync.ErrorHandler").level = Log.Level.Trace; |
|
21 Log.repository.getLogger("Sync.Resource").level = Log.Level.Trace; |
|
22 Log.repository.getLogger("Sync.RESTRequest").level = Log.Level.Trace; |
|
23 Log.repository.getLogger("Sync.Service").level = Log.Level.Trace; |
|
24 Log.repository.getLogger("Sync.SyncScheduler").level = Log.Level.Trace; |
|
25 initTestLogging(); |
|
26 |
|
27 ensureLegacyIdentityManager(); |
|
28 |
|
29 Service.engineManager.register(RotaryEngine); |
|
30 |
|
31 // None of the failures in this file should result in a UI error. |
|
32 function onUIError() { |
|
33 do_throw("Errors should not be presented in the UI."); |
|
34 } |
|
35 Svc.Obs.add("weave:ui:login:error", onUIError); |
|
36 Svc.Obs.add("weave:ui:sync:error", onUIError); |
|
37 |
|
38 run_next_test(); |
|
39 } |
|
40 |
|
41 /** |
|
42 * Emulate the following Zeus config: |
|
43 * $draining = data.get($prefix . $host . " draining"); |
|
44 * if ($draining == "drain.") { |
|
45 * log.warn($log_host_db_status . " migrating=1 (node-reassignment)" . |
|
46 * $log_suffix); |
|
47 * http.sendResponse("401 Node reassignment", $content_type, |
|
48 * '"server request: node reassignment"', ""); |
|
49 * } |
|
50 */ |
|
51 const reassignBody = "\"server request: node reassignment\""; |
|
52 |
|
53 // API-compatible with SyncServer handler. Bind `handler` to something to use |
|
54 // as a ServerCollection handler. |
|
55 function handleReassign(handler, req, resp) { |
|
56 resp.setStatusLine(req.httpVersion, 401, "Node reassignment"); |
|
57 resp.setHeader("Content-Type", "application/json"); |
|
58 resp.bodyOutputStream.write(reassignBody, reassignBody.length); |
|
59 } |
|
60 |
|
61 /** |
|
62 * A node assignment handler. |
|
63 */ |
|
64 function installNodeHandler(server, next) { |
|
65 let newNodeBody = server.baseURI; |
|
66 function handleNodeRequest(req, resp) { |
|
67 _("Client made a request for a node reassignment."); |
|
68 resp.setStatusLine(req.httpVersion, 200, "OK"); |
|
69 resp.setHeader("Content-Type", "text/plain"); |
|
70 resp.bodyOutputStream.write(newNodeBody, newNodeBody.length); |
|
71 Utils.nextTick(next); |
|
72 } |
|
73 let nodePath = "/user/1.0/johndoe/node/weave"; |
|
74 server.server.registerPathHandler(nodePath, handleNodeRequest); |
|
75 _("Registered node handler at " + nodePath); |
|
76 } |
|
77 |
|
78 function prepareServer() { |
|
79 let deferred = Promise.defer(); |
|
80 configureIdentity({username: "johndoe"}).then(() => { |
|
81 let server = new SyncServer(); |
|
82 server.registerUser("johndoe"); |
|
83 server.start(); |
|
84 Service.serverURL = server.baseURI; |
|
85 Service.clusterURL = server.baseURI; |
|
86 do_check_eq(Service.userAPIURI, server.baseURI + "user/1.0/"); |
|
87 deferred.resolve(server); |
|
88 }); |
|
89 return deferred.promise; |
|
90 } |
|
91 |
|
92 function getReassigned() { |
|
93 try { |
|
94 return Services.prefs.getBoolPref("services.sync.lastSyncReassigned"); |
|
95 } catch (ex if (ex.result == Cr.NS_ERROR_UNEXPECTED)) { |
|
96 return false; |
|
97 } catch (ex) { |
|
98 do_throw("Got exception retrieving lastSyncReassigned: " + |
|
99 Utils.exceptionStr(ex)); |
|
100 } |
|
101 } |
|
102 |
|
103 /** |
|
104 * Make a test request to `url`, then watch the result of two syncs |
|
105 * to ensure that a node request was made. |
|
106 * Runs `between` between the two. This can be used to undo deliberate failure |
|
107 * setup, detach observers, etc. |
|
108 */ |
|
109 function syncAndExpectNodeReassignment(server, firstNotification, between, |
|
110 secondNotification, url) { |
|
111 let deferred = Promise.defer(); |
|
112 function onwards() { |
|
113 let nodeFetched = false; |
|
114 function onFirstSync() { |
|
115 _("First sync completed."); |
|
116 Svc.Obs.remove(firstNotification, onFirstSync); |
|
117 Svc.Obs.add(secondNotification, onSecondSync); |
|
118 |
|
119 do_check_eq(Service.clusterURL, ""); |
|
120 |
|
121 // Track whether we fetched node/weave. We want to wait for the second |
|
122 // sync to finish so that we're cleaned up for the next test, so don't |
|
123 // run_next_test in the node handler. |
|
124 nodeFetched = false; |
|
125 |
|
126 // Verify that the client requests a node reassignment. |
|
127 // Install a node handler to watch for these requests. |
|
128 installNodeHandler(server, function () { |
|
129 nodeFetched = true; |
|
130 }); |
|
131 |
|
132 // Allow for tests to clean up error conditions. |
|
133 between(); |
|
134 } |
|
135 function onSecondSync() { |
|
136 _("Second sync completed."); |
|
137 Svc.Obs.remove(secondNotification, onSecondSync); |
|
138 Service.scheduler.clearSyncTriggers(); |
|
139 |
|
140 // Make absolutely sure that any event listeners are done with their work |
|
141 // before we proceed. |
|
142 waitForZeroTimer(function () { |
|
143 _("Second sync nextTick."); |
|
144 do_check_true(nodeFetched); |
|
145 Service.startOver(); |
|
146 server.stop(deferred.resolve); |
|
147 }); |
|
148 } |
|
149 |
|
150 Svc.Obs.add(firstNotification, onFirstSync); |
|
151 Service.sync(); |
|
152 } |
|
153 |
|
154 // Make sure that it works! |
|
155 let request = new RESTRequest(url); |
|
156 request.get(function () { |
|
157 do_check_eq(request.response.status, 401); |
|
158 Utils.nextTick(onwards); |
|
159 }); |
|
160 yield deferred.promise; |
|
161 } |
|
162 |
|
163 add_task(function test_momentary_401_engine() { |
|
164 _("Test a failure for engine URLs that's resolved by reassignment."); |
|
165 let server = yield prepareServer(); |
|
166 let john = server.user("johndoe"); |
|
167 |
|
168 _("Enabling the Rotary engine."); |
|
169 let engine = Service.engineManager.get("rotary"); |
|
170 engine.enabled = true; |
|
171 |
|
172 // We need the server to be correctly set up prior to experimenting. Do this |
|
173 // through a sync. |
|
174 let global = {syncID: Service.syncID, |
|
175 storageVersion: STORAGE_VERSION, |
|
176 rotary: {version: engine.version, |
|
177 syncID: engine.syncID}} |
|
178 john.createCollection("meta").insert("global", global); |
|
179 |
|
180 _("First sync to prepare server contents."); |
|
181 Service.sync(); |
|
182 |
|
183 _("Setting up Rotary collection to 401."); |
|
184 let rotary = john.createCollection("rotary"); |
|
185 let oldHandler = rotary.collectionHandler; |
|
186 rotary.collectionHandler = handleReassign.bind(this, undefined); |
|
187 |
|
188 // We want to verify that the clusterURL pref has been cleared after a 401 |
|
189 // inside a sync. Flag the Rotary engine to need syncing. |
|
190 john.collection("rotary").timestamp += 1000; |
|
191 |
|
192 function between() { |
|
193 _("Undoing test changes."); |
|
194 rotary.collectionHandler = oldHandler; |
|
195 |
|
196 function onLoginStart() { |
|
197 // lastSyncReassigned shouldn't be cleared until a sync has succeeded. |
|
198 _("Ensuring that lastSyncReassigned is still set at next sync start."); |
|
199 Svc.Obs.remove("weave:service:login:start", onLoginStart); |
|
200 do_check_true(getReassigned()); |
|
201 } |
|
202 |
|
203 _("Adding observer that lastSyncReassigned is still set on login."); |
|
204 Svc.Obs.add("weave:service:login:start", onLoginStart); |
|
205 } |
|
206 |
|
207 yield syncAndExpectNodeReassignment(server, |
|
208 "weave:service:sync:finish", |
|
209 between, |
|
210 "weave:service:sync:finish", |
|
211 Service.storageURL + "rotary"); |
|
212 }); |
|
213 |
|
214 // This test ends up being a failing fetch *after we're already logged in*. |
|
215 add_task(function test_momentary_401_info_collections() { |
|
216 _("Test a failure for info/collections that's resolved by reassignment."); |
|
217 let server = yield prepareServer(); |
|
218 |
|
219 _("First sync to prepare server contents."); |
|
220 Service.sync(); |
|
221 |
|
222 // Return a 401 for info requests, particularly info/collections. |
|
223 let oldHandler = server.toplevelHandlers.info; |
|
224 server.toplevelHandlers.info = handleReassign; |
|
225 |
|
226 function undo() { |
|
227 _("Undoing test changes."); |
|
228 server.toplevelHandlers.info = oldHandler; |
|
229 } |
|
230 |
|
231 yield syncAndExpectNodeReassignment(server, |
|
232 "weave:service:sync:error", |
|
233 undo, |
|
234 "weave:service:sync:finish", |
|
235 Service.infoURL); |
|
236 }); |
|
237 |
|
238 add_task(function test_momentary_401_storage_loggedin() { |
|
239 _("Test a failure for any storage URL, not just engine parts. " + |
|
240 "Resolved by reassignment."); |
|
241 let server = yield prepareServer(); |
|
242 |
|
243 _("Performing initial sync to ensure we are logged in.") |
|
244 Service.sync(); |
|
245 |
|
246 // Return a 401 for all storage requests. |
|
247 let oldHandler = server.toplevelHandlers.storage; |
|
248 server.toplevelHandlers.storage = handleReassign; |
|
249 |
|
250 function undo() { |
|
251 _("Undoing test changes."); |
|
252 server.toplevelHandlers.storage = oldHandler; |
|
253 } |
|
254 |
|
255 do_check_true(Service.isLoggedIn, "already logged in"); |
|
256 yield syncAndExpectNodeReassignment(server, |
|
257 "weave:service:sync:error", |
|
258 undo, |
|
259 "weave:service:sync:finish", |
|
260 Service.storageURL + "meta/global"); |
|
261 }); |
|
262 |
|
263 add_task(function test_momentary_401_storage_loggedout() { |
|
264 _("Test a failure for any storage URL, not just engine parts. " + |
|
265 "Resolved by reassignment."); |
|
266 let server = yield prepareServer(); |
|
267 |
|
268 // Return a 401 for all storage requests. |
|
269 let oldHandler = server.toplevelHandlers.storage; |
|
270 server.toplevelHandlers.storage = handleReassign; |
|
271 |
|
272 function undo() { |
|
273 _("Undoing test changes."); |
|
274 server.toplevelHandlers.storage = oldHandler; |
|
275 } |
|
276 |
|
277 do_check_false(Service.isLoggedIn, "not already logged in"); |
|
278 yield syncAndExpectNodeReassignment(server, |
|
279 "weave:service:login:error", |
|
280 undo, |
|
281 "weave:service:sync:finish", |
|
282 Service.storageURL + "meta/global"); |
|
283 }); |
|
284 |
|
285 add_task(function test_loop_avoidance_storage() { |
|
286 _("Test that a repeated failure doesn't result in a sync loop " + |
|
287 "if node reassignment cannot resolve the failure."); |
|
288 |
|
289 let server = yield prepareServer(); |
|
290 |
|
291 // Return a 401 for all storage requests. |
|
292 let oldHandler = server.toplevelHandlers.storage; |
|
293 server.toplevelHandlers.storage = handleReassign; |
|
294 |
|
295 let firstNotification = "weave:service:login:error"; |
|
296 let secondNotification = "weave:service:login:error"; |
|
297 let thirdNotification = "weave:service:sync:finish"; |
|
298 |
|
299 let nodeFetched = false; |
|
300 let deferred = Promise.defer(); |
|
301 |
|
302 // Track the time. We want to make sure the duration between the first and |
|
303 // second sync is small, and then that the duration between second and third |
|
304 // is set to be large. |
|
305 let now; |
|
306 |
|
307 function onFirstSync() { |
|
308 _("First sync completed."); |
|
309 Svc.Obs.remove(firstNotification, onFirstSync); |
|
310 Svc.Obs.add(secondNotification, onSecondSync); |
|
311 |
|
312 do_check_eq(Service.clusterURL, ""); |
|
313 |
|
314 // We got a 401 mid-sync, and set the pref accordingly. |
|
315 do_check_true(Services.prefs.getBoolPref("services.sync.lastSyncReassigned")); |
|
316 |
|
317 // Track whether we fetched node/weave. We want to wait for the second |
|
318 // sync to finish so that we're cleaned up for the next test, so don't |
|
319 // run_next_test in the node handler. |
|
320 nodeFetched = false; |
|
321 |
|
322 // Verify that the client requests a node reassignment. |
|
323 // Install a node handler to watch for these requests. |
|
324 installNodeHandler(server, function () { |
|
325 nodeFetched = true; |
|
326 }); |
|
327 |
|
328 // Update the timestamp. |
|
329 now = Date.now(); |
|
330 } |
|
331 |
|
332 function onSecondSync() { |
|
333 _("Second sync completed."); |
|
334 Svc.Obs.remove(secondNotification, onSecondSync); |
|
335 Svc.Obs.add(thirdNotification, onThirdSync); |
|
336 |
|
337 // This sync occurred within the backoff interval. |
|
338 let elapsedTime = Date.now() - now; |
|
339 do_check_true(elapsedTime < MINIMUM_BACKOFF_INTERVAL); |
|
340 |
|
341 // This pref will be true until a sync completes successfully. |
|
342 do_check_true(getReassigned()); |
|
343 |
|
344 // The timer will be set for some distant time. |
|
345 // We store nextSync in prefs, which offers us only limited resolution. |
|
346 // Include that logic here. |
|
347 let expectedNextSync = 1000 * Math.floor((now + MINIMUM_BACKOFF_INTERVAL) / 1000); |
|
348 _("Next sync scheduled for " + Service.scheduler.nextSync); |
|
349 _("Expected to be slightly greater than " + expectedNextSync); |
|
350 |
|
351 do_check_true(Service.scheduler.nextSync >= expectedNextSync); |
|
352 do_check_true(!!Service.scheduler.syncTimer); |
|
353 |
|
354 // Undo our evil scheme. |
|
355 server.toplevelHandlers.storage = oldHandler; |
|
356 |
|
357 // Bring the timer forward to kick off a successful sync, so we can watch |
|
358 // the pref get cleared. |
|
359 Service.scheduler.scheduleNextSync(0); |
|
360 } |
|
361 function onThirdSync() { |
|
362 Svc.Obs.remove(thirdNotification, onThirdSync); |
|
363 |
|
364 // That'll do for now; no more syncs. |
|
365 Service.scheduler.clearSyncTriggers(); |
|
366 |
|
367 // Make absolutely sure that any event listeners are done with their work |
|
368 // before we proceed. |
|
369 waitForZeroTimer(function () { |
|
370 _("Third sync nextTick."); |
|
371 do_check_false(getReassigned()); |
|
372 do_check_true(nodeFetched); |
|
373 Service.startOver(); |
|
374 server.stop(deferred.resolve); |
|
375 }); |
|
376 } |
|
377 |
|
378 Svc.Obs.add(firstNotification, onFirstSync); |
|
379 |
|
380 now = Date.now(); |
|
381 Service.sync(); |
|
382 yield deferred.promise; |
|
383 }); |
|
384 |
|
385 add_task(function test_loop_avoidance_engine() { |
|
386 _("Test that a repeated 401 in an engine doesn't result in a sync loop " + |
|
387 "if node reassignment cannot resolve the failure."); |
|
388 let server = yield prepareServer(); |
|
389 let john = server.user("johndoe"); |
|
390 |
|
391 _("Enabling the Rotary engine."); |
|
392 let engine = Service.engineManager.get("rotary"); |
|
393 engine.enabled = true; |
|
394 let deferred = Promise.defer(); |
|
395 |
|
396 // We need the server to be correctly set up prior to experimenting. Do this |
|
397 // through a sync. |
|
398 let global = {syncID: Service.syncID, |
|
399 storageVersion: STORAGE_VERSION, |
|
400 rotary: {version: engine.version, |
|
401 syncID: engine.syncID}} |
|
402 john.createCollection("meta").insert("global", global); |
|
403 |
|
404 _("First sync to prepare server contents."); |
|
405 Service.sync(); |
|
406 |
|
407 _("Setting up Rotary collection to 401."); |
|
408 let rotary = john.createCollection("rotary"); |
|
409 let oldHandler = rotary.collectionHandler; |
|
410 rotary.collectionHandler = handleReassign.bind(this, undefined); |
|
411 |
|
412 // Flag the Rotary engine to need syncing. |
|
413 john.collection("rotary").timestamp += 1000; |
|
414 |
|
415 function onLoginStart() { |
|
416 // lastSyncReassigned shouldn't be cleared until a sync has succeeded. |
|
417 _("Ensuring that lastSyncReassigned is still set at next sync start."); |
|
418 do_check_true(getReassigned()); |
|
419 } |
|
420 |
|
421 function beforeSuccessfulSync() { |
|
422 _("Undoing test changes."); |
|
423 rotary.collectionHandler = oldHandler; |
|
424 } |
|
425 |
|
426 function afterSuccessfulSync() { |
|
427 Svc.Obs.remove("weave:service:login:start", onLoginStart); |
|
428 Service.startOver(); |
|
429 server.stop(deferred.resolve); |
|
430 } |
|
431 |
|
432 let firstNotification = "weave:service:sync:finish"; |
|
433 let secondNotification = "weave:service:sync:finish"; |
|
434 let thirdNotification = "weave:service:sync:finish"; |
|
435 |
|
436 let nodeFetched = false; |
|
437 |
|
438 // Track the time. We want to make sure the duration between the first and |
|
439 // second sync is small, and then that the duration between second and third |
|
440 // is set to be large. |
|
441 let now; |
|
442 |
|
443 function onFirstSync() { |
|
444 _("First sync completed."); |
|
445 Svc.Obs.remove(firstNotification, onFirstSync); |
|
446 Svc.Obs.add(secondNotification, onSecondSync); |
|
447 |
|
448 do_check_eq(Service.clusterURL, ""); |
|
449 |
|
450 _("Adding observer that lastSyncReassigned is still set on login."); |
|
451 Svc.Obs.add("weave:service:login:start", onLoginStart); |
|
452 |
|
453 // We got a 401 mid-sync, and set the pref accordingly. |
|
454 do_check_true(Services.prefs.getBoolPref("services.sync.lastSyncReassigned")); |
|
455 |
|
456 // Track whether we fetched node/weave. We want to wait for the second |
|
457 // sync to finish so that we're cleaned up for the next test, so don't |
|
458 // run_next_test in the node handler. |
|
459 nodeFetched = false; |
|
460 |
|
461 // Verify that the client requests a node reassignment. |
|
462 // Install a node handler to watch for these requests. |
|
463 installNodeHandler(server, function () { |
|
464 nodeFetched = true; |
|
465 }); |
|
466 |
|
467 // Update the timestamp. |
|
468 now = Date.now(); |
|
469 } |
|
470 |
|
471 function onSecondSync() { |
|
472 _("Second sync completed."); |
|
473 Svc.Obs.remove(secondNotification, onSecondSync); |
|
474 Svc.Obs.add(thirdNotification, onThirdSync); |
|
475 |
|
476 // This sync occurred within the backoff interval. |
|
477 let elapsedTime = Date.now() - now; |
|
478 do_check_true(elapsedTime < MINIMUM_BACKOFF_INTERVAL); |
|
479 |
|
480 // This pref will be true until a sync completes successfully. |
|
481 do_check_true(getReassigned()); |
|
482 |
|
483 // The timer will be set for some distant time. |
|
484 // We store nextSync in prefs, which offers us only limited resolution. |
|
485 // Include that logic here. |
|
486 let expectedNextSync = 1000 * Math.floor((now + MINIMUM_BACKOFF_INTERVAL) / 1000); |
|
487 _("Next sync scheduled for " + Service.scheduler.nextSync); |
|
488 _("Expected to be slightly greater than " + expectedNextSync); |
|
489 |
|
490 do_check_true(Service.scheduler.nextSync >= expectedNextSync); |
|
491 do_check_true(!!Service.scheduler.syncTimer); |
|
492 |
|
493 // Undo our evil scheme. |
|
494 beforeSuccessfulSync(); |
|
495 |
|
496 // Bring the timer forward to kick off a successful sync, so we can watch |
|
497 // the pref get cleared. |
|
498 Service.scheduler.scheduleNextSync(0); |
|
499 } |
|
500 |
|
501 function onThirdSync() { |
|
502 Svc.Obs.remove(thirdNotification, onThirdSync); |
|
503 |
|
504 // That'll do for now; no more syncs. |
|
505 Service.scheduler.clearSyncTriggers(); |
|
506 |
|
507 // Make absolutely sure that any event listeners are done with their work |
|
508 // before we proceed. |
|
509 waitForZeroTimer(function () { |
|
510 _("Third sync nextTick."); |
|
511 do_check_false(getReassigned()); |
|
512 do_check_true(nodeFetched); |
|
513 afterSuccessfulSync(); |
|
514 }); |
|
515 } |
|
516 |
|
517 Svc.Obs.add(firstNotification, onFirstSync); |
|
518 |
|
519 now = Date.now(); |
|
520 Service.sync(); |
|
521 yield deferred.promise; |
|
522 }); |