From 1c744a66e61ae7226037aef068725f13882a6c54 Mon Sep 17 00:00:00 2001 From: David Baker Date: Thu, 6 Oct 2016 18:29:05 +0100 Subject: [PATCH 1/3] Don't emit ERROR until a keepalive poke fails This accomplishes the same as https://github.com/matrix-org/matrix-js-sdk/pull/216/files, but without the client waiting 110 seconds for a sync request to time out. That is, don't display an error message a soon as a sync request fails, since we should accept that sometimes long lived HTTP connections will go away and that's fine. Also: * Use request rather than deprecated requestWithPrefix * http-api: The empty string may be falsy, but it's a valid prefix --- lib/http-api.js | 2 +- lib/sync.js | 32 +++++++++++++++++++++++++------- 2 files changed, 26 insertions(+), 8 deletions(-) diff --git a/lib/http-api.js b/lib/http-api.js index bc5ac51ed88..ac77d30b502 100644 --- a/lib/http-api.js +++ b/lib/http-api.js @@ -351,7 +351,7 @@ module.exports.MatrixHttpApi.prototype = { */ request: function(callback, method, path, queryParams, data, opts) { opts = opts || {}; - var prefix = opts.prefix || this.opts.prefix; + var prefix = opts.prefix !== undefined ? opts.prefix : this.opts.prefix; var fullUri = this.opts.baseUrl + prefix + path; return this.requestOtherUrl( diff --git a/lib/sync.js b/lib/sync.js index f1581cd329a..9cb7a737f50 100644 --- a/lib/sync.js +++ b/lib/sync.js @@ -406,7 +406,7 @@ SyncApi.prototype.sync = function() { self._sync({ filterId: filterId }); }, function(err) { - self._startKeepAlives().done(function() { + self._startKeepAlives(0).done(function() { getFilter(); }); self._updateSyncState("ERROR", { error: err }); @@ -546,12 +546,17 @@ SyncApi.prototype._sync = function(syncOptions) { console.error(err); debuglog("Starting keep-alive"); - self._syncConnectionLost = true; - self._startKeepAlives().done(function() { + // Note that we do *not* mark the sync connection as + // lost yet: we only do this if a keepalive poke + // fails, since long lived HTTP connections will + // go away sometimes and we shouldn't treat this as + // erroneous. + // We sent the first keep alive immediately because + // of this. + self._startKeepAlives(0).done(function() { self._sync(syncOptions); }); self._currentSyncRequest = null; - self._updateSyncState("ERROR", { error: err }); }); }; @@ -874,9 +879,15 @@ SyncApi.prototype._pokeKeepAlive = function() { } } - this.client._http.requestWithPrefix( - undefined, "GET", "/_matrix/client/versions", undefined, - undefined, "", 15 * 1000 + this.client._http.request( + undefined, // callback + "GET", "/_matrix/client/versions", + undefined, // queryParams + undefined, // data + { + prefix: '', + localTimeoutMs: 15 * 1000, + } ).done(function() { success(); }, function(err) { @@ -888,6 +899,13 @@ SyncApi.prototype._pokeKeepAlive = function() { // responses fail, this will mean we don't hammer in a loop. self._keepAliveTimer = setTimeout(success, 2000); } else { + // If we haven't already marked this sync + // connection as gone-away, do so now and + // emit an error. + if (!self._syncConnectionLost) { + self._syncConnectionLost = true; + self._updateSyncState("ERROR", { error: err }); + } self._keepAliveTimer = setTimeout( self._pokeKeepAlive.bind(self), 5000 + Math.floor(Math.random() * 5000) From cd5a88c71840a7f192f1871832802503e7acf90a Mon Sep 17 00:00:00 2001 From: David Baker Date: Thu, 6 Oct 2016 20:54:57 +0100 Subject: [PATCH 2/3] Fix tests * Go back to previous behaviour of continuing to emit ERROR states if it continues to fail * Don't set a timer if the timeout is zero * Change test to assert the continued-error behaviour, not exactly multiple syncs failing * Update other tests to fail the keepalive requests where appropriate --- lib/sync.js | 27 ++++++++++++++++----------- spec/unit/matrix-client.spec.js | 24 +++++++++++++++++++++--- 2 files changed, 37 insertions(+), 14 deletions(-) diff --git a/lib/sync.js b/lib/sync.js index 9cb7a737f50..941dab6ac58 100644 --- a/lib/sync.js +++ b/lib/sync.js @@ -856,10 +856,14 @@ SyncApi.prototype._startKeepAlives = function(delay) { clearTimeout(this._keepAliveTimer); } var self = this; - self._keepAliveTimer = setTimeout( - self._pokeKeepAlive.bind(self), - delay - ); + if (delay > 0) { + self._keepAliveTimer = setTimeout( + self._pokeKeepAlive.bind(self), + delay + ); + } else { + self._pokeKeepAlive(); + } if (!this._connectionReturnedDefer) { this._connectionReturnedDefer = q.defer(); } @@ -899,17 +903,18 @@ SyncApi.prototype._pokeKeepAlive = function() { // responses fail, this will mean we don't hammer in a loop. self._keepAliveTimer = setTimeout(success, 2000); } else { - // If we haven't already marked this sync - // connection as gone-away, do so now and - // emit an error. - if (!self._syncConnectionLost) { - self._syncConnectionLost = true; - self._updateSyncState("ERROR", { error: err }); - } self._keepAliveTimer = setTimeout( self._pokeKeepAlive.bind(self), 5000 + Math.floor(Math.random() * 5000) ); + // If we haven't already marked this sync + // connection as gone-away, do so now and + // emit an error. + // Note we do this after setting the timer: + // this lets the unit tests advance the mock + // clock when the get the error. + self._syncConnectionLost = true; + self._updateSyncState("ERROR", { error: err }); } }); }; diff --git a/spec/unit/matrix-client.spec.js b/spec/unit/matrix-client.spec.js index 738c3255838..0b8a34ed9fe 100644 --- a/spec/unit/matrix-client.spec.js +++ b/spec/unit/matrix-client.spec.js @@ -51,9 +51,10 @@ describe("MatrixClient", function() { // } // items are popped off when processed and block if no items left. ]; + var accept_keepalives; var pendingLookup = null; function httpReq(cb, method, path, qp, data, prefix) { - if (path === KEEP_ALIVE_PATH) { + if (path === KEEP_ALIVE_PATH && accept_keepalives) { return q(); } var next = httpLookups.shift(); @@ -143,8 +144,10 @@ describe("MatrixClient", function() { client._http.authedRequest.andCallFake(httpReq); client._http.authedRequestWithPrefix.andCallFake(httpReq); client._http.requestWithPrefix.andCallFake(httpReq); + client._http.request.andCallFake(httpReq); // set reasonable working defaults + accept_keepalives = true; pendingLookup = null; httpLookups = []; httpLookups.push(PUSH_RULES_RESPONSE); @@ -329,12 +332,19 @@ describe("MatrixClient", function() { it("should transition ERROR -> PREPARED after /sync if prev failed", function(done) { var expectedStates = []; + accept_keepalives = false; httpLookups = []; httpLookups.push(PUSH_RULES_RESPONSE); httpLookups.push(FILTER_RESPONSE); httpLookups.push({ method: "GET", path: "/sync", error: { errcode: "NOPE_NOPE_NOPE" } }); + httpLookups.push({ + method: "GET", path: KEEP_ALIVE_PATH, error: { errcode: "KEEPALIVE_FAIL" } + }); + httpLookups.push({ + method: "GET", path: KEEP_ALIVE_PATH, data: {} + }); httpLookups.push({ method: "GET", path: "/sync", data: SYNC_DATA }); @@ -354,10 +364,14 @@ describe("MatrixClient", function() { }); it("should transition SYNCING -> ERROR after a failed /sync", function(done) { + accept_keepalives = false; var expectedStates = []; httpLookups.push({ method: "GET", path: "/sync", error: { errcode: "NONONONONO" } }); + httpLookups.push({ + method: "GET", path: KEEP_ALIVE_PATH, error: { errcode: "KEEPALIVE_FAIL" } + }); expectedStates.push(["PREPARED", null]); expectedStates.push(["SYNCING", "PREPARED"]); @@ -394,13 +408,17 @@ describe("MatrixClient", function() { client.startClient(); }); - it("should transition ERROR -> ERROR if multiple /sync fails", function(done) { + it("should transition ERROR -> ERROR if keepalive keeps failing", function(done) { + accept_keepalives = false; var expectedStates = []; httpLookups.push({ method: "GET", path: "/sync", error: { errcode: "NONONONONO" } }); httpLookups.push({ - method: "GET", path: "/sync", error: { errcode: "NONONONONO" } + method: "GET", path: KEEP_ALIVE_PATH, error: { errcode: "KEEPALIVE_FAIL" } + }); + httpLookups.push({ + method: "GET", path: KEEP_ALIVE_PATH, error: { errcode: "KEEPALIVE_FAIL" } }); expectedStates.push(["PREPARED", null]); From 92ae4dda720795022d7210e1bfc2f1454b5da282 Mon Sep 17 00:00:00 2001 From: David Baker Date: Fri, 7 Oct 2016 11:29:52 +0100 Subject: [PATCH 3/3] Add short delay before keepalives + 'RECONNECTING' Changed my mind - it's a good idea to wait a short time before sending a keepalive request: this will make sure we never tightloop. This also adds a 'RECONNECTING' state for when a sync request has failed but there is no reason to suspect there is actually a connectivity problem. This is necessary for the tests to be able to advance the clock at the appropriate time, but could be nice for clients. Add a breaking change changelog entry since technically this is an API change that might break clients if they were relying on 'SYNCING' always coming before 'ERROR' for some reason. --- CHANGELOG.md | 8 ++++++++ lib/client.js | 9 +++++++-- lib/sync.js | 13 +++++++------ spec/unit/matrix-client.spec.js | 11 ++++++++--- 4 files changed, 30 insertions(+), 11 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index e0fcddafb5d..95bdc200dbc 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,11 @@ +Unreleased Changes +================== + +Breaking Changes +---------------- + * Add a 'RECONNECTING' state to the sync states. This is an additional state + between 'SYNCING' and 'ERROR', so most clients should not notice. + Changes in [0.6.2](https://github.com/matrix-org/matrix-js-sdk/releases/tag/v0.6.2) (2016-10-05) ================================================================================================ [Full Changelog](https://github.com/matrix-org/matrix-js-sdk/compare/v0.6.1...v0.6.2) diff --git a/lib/client.js b/lib/client.js index ce96b1c8560..a7905f71b8c 100644 --- a/lib/client.js +++ b/lib/client.js @@ -2867,6 +2867,9 @@ module.exports.CRYPTO_ENABLED = CRYPTO_ENABLED; * the server for updates. This may be called multiple times even if the state is * already ERROR. This is the equivalent of "syncError" in the previous * API. + *
  • RECONNECTING: The sync connedtion has dropped, but not in a way that should + * be considered erroneous. + *
    • *
  • STOPPED: The client has stopped syncing with server due to stopClient * being called. *
    • @@ -2876,8 +2879,10 @@ module.exports.CRYPTO_ENABLED = CRYPTO_ENABLED; * +---->STOPPED * | * +----->PREPARED -------> SYNCING <--+ - * | ^ | | - * null ------+ | +---------------+ | + * | ^ ^ | + * | | | | + * | | V | + * null ------+ | +-RECONNECTING<-+ | * | | V | * +------->ERROR ---------------------+ * diff --git a/lib/sync.js b/lib/sync.js index 941dab6ac58..49c48b2ceaf 100644 --- a/lib/sync.js +++ b/lib/sync.js @@ -406,7 +406,7 @@ SyncApi.prototype.sync = function() { self._sync({ filterId: filterId }); }, function(err) { - self._startKeepAlives(0).done(function() { + self._startKeepAlives().done(function() { getFilter(); }); self._updateSyncState("ERROR", { error: err }); @@ -550,13 +550,14 @@ SyncApi.prototype._sync = function(syncOptions) { // lost yet: we only do this if a keepalive poke // fails, since long lived HTTP connections will // go away sometimes and we shouldn't treat this as - // erroneous. - // We sent the first keep alive immediately because - // of this. - self._startKeepAlives(0).done(function() { + // erroneous. We set the state to 'reconnecting' + // instead, so that clients can onserve this state + // if they wish. + self._startKeepAlives().done(function() { self._sync(syncOptions); }); self._currentSyncRequest = null; + self._updateSyncState("RECONNECTING"); }); }; @@ -849,7 +850,7 @@ SyncApi.prototype._processSyncResponse = function(syncToken, data) { */ SyncApi.prototype._startKeepAlives = function(delay) { if (delay === undefined) { - delay = 5000 + Math.floor(Math.random() * 5000); + delay = 2000 + Math.floor(Math.random() * 5000); } if (this._keepAliveTimer !== null) { diff --git a/spec/unit/matrix-client.spec.js b/spec/unit/matrix-client.spec.js index 0b8a34ed9fe..0996a3056a7 100644 --- a/spec/unit/matrix-client.spec.js +++ b/spec/unit/matrix-client.spec.js @@ -253,6 +253,8 @@ describe("MatrixClient", function() { true, "retryImmediately returned false" ); jasmine.Clock.tick(1); + } else if (state === "RECONNECTING" && httpLookups.length > 0) { + jasmine.Clock.tick(10000); } else if (state === "SYNCING" && httpLookups.length === 0) { client.removeListener("sync", syncListener); done(); @@ -349,7 +351,8 @@ describe("MatrixClient", function() { method: "GET", path: "/sync", data: SYNC_DATA }); - expectedStates.push(["ERROR", null]); + expectedStates.push(["RECONNECTING", null]); + expectedStates.push(["ERROR", "RECONNECTING"]); expectedStates.push(["PREPARED", "ERROR"]); client.on("sync", syncChecker(expectedStates, done)); client.startClient(); @@ -375,7 +378,8 @@ describe("MatrixClient", function() { expectedStates.push(["PREPARED", null]); expectedStates.push(["SYNCING", "PREPARED"]); - expectedStates.push(["ERROR", "SYNCING"]); + expectedStates.push(["RECONNECTING", "SYNCING"]); + expectedStates.push(["ERROR", "RECONNECTING"]); client.on("sync", syncChecker(expectedStates, done)); client.startClient(); }); @@ -423,7 +427,8 @@ describe("MatrixClient", function() { expectedStates.push(["PREPARED", null]); expectedStates.push(["SYNCING", "PREPARED"]); - expectedStates.push(["ERROR", "SYNCING"]); + expectedStates.push(["RECONNECTING", "SYNCING"]); + expectedStates.push(["ERROR", "RECONNECTING"]); expectedStates.push(["ERROR", "ERROR"]); client.on("sync", syncChecker(expectedStates, done)); client.startClient();