From 792793054c7b614e605110a8e0874459528cb2ca Mon Sep 17 00:00:00 2001 From: Ben Vinegar Date: Wed, 25 Jan 2017 19:25:35 -0800 Subject: [PATCH 1/6] Exponential backoff if Sentry server returns 429 --- src/raven.js | 22 +++++++++++- test/raven.test.js | 89 ++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 110 insertions(+), 1 deletion(-) diff --git a/src/raven.js b/src/raven.js index 662c668dbee3..33f90c2c38af 100644 --- a/src/raven.js +++ b/src/raven.js @@ -61,6 +61,8 @@ function Raven() { this._keypressTimeout; this._location = _window.location; this._lastHref = this._location && this._location.href; + this._backoffDuration = 0; + this._backoffStart = null; for (var method in this._originalConsole) { // eslint-disable-line guard-for-in this._originalConsoleMethods[method] = this._originalConsole[method]; @@ -1320,8 +1322,15 @@ Raven.prototype = { return httpData; }, + _shouldBackoff: function() { + return this._backoffDuration && now() - this._backoffStart < this._backoffDuration; + }, _send: function(data) { + if (this._shouldBackoff()) { + return; + } + var globalOptions = this._globalOptions; var baseData = { @@ -1434,6 +1443,9 @@ Raven.prototype = { data: data, options: globalOptions, onSuccess: function success() { + self._backoffDuration = 0; + self._backoffStart = null; + self._triggerEvent('success', { data: data, src: url @@ -1441,6 +1453,12 @@ Raven.prototype = { callback && callback(); }, onError: function failure(error) { + // too many requests + if (!self._shouldBackoff() && error.request && error.request.status === 429) { + self._backoffDuration = self._backoffDuration * 2 || 1000; + self._backoffStart = now(); + } + self._triggerEvent('failure', { data: data, src: url @@ -1468,7 +1486,9 @@ Raven.prototype = { opts.onSuccess(); } } else if (opts.onError) { - opts.onError(new Error('Sentry error code: ' + request.status)); + var err = new Error('Sentry error code: ' + request.status); + err.request = request; + opts.onError(err); } } diff --git a/test/raven.test.js b/test/raven.test.js index e160e06858c7..15a4105b0938 100644 --- a/test/raven.test.js +++ b/test/raven.test.js @@ -1137,6 +1137,77 @@ describe('globals', function() { assert.equal(data.message, shortMessage); assert.equal(data.exception.values[0].value, shortMessage); }); + + it('should bail out if time elapsed does not exceed backoffDuration', function () { + this.sinon.stub(Raven, 'isSetup').returns(true); + this.sinon.stub(Raven, '_makeRequest'); + + Raven._backoffDuration = 1000; + Raven._backoffStart = 100; + this.clock.tick(100); // tick 100 ms - NOT past backoff duration + + Raven._send({message: 'bar'}); + assert.isFalse(Raven._makeRequest.called); + }); + + it('should proceed if time elapsed exceeds backoffDuration', function () { + this.sinon.stub(Raven, 'isSetup').returns(true); + this.sinon.stub(Raven, '_makeRequest'); + + Raven._backoffDuration = 1000; + Raven._backoffStart = 100; + this.clock.tick(1000); // advance clock 1000 ms - past backoff duration + + Raven._send({message: 'bar'}); + assert.isTrue(Raven._makeRequest.called); + }); + + it('should set backoffDuration and backoffStart if onError is fired w/ 429 response', function () { + this.sinon.stub(Raven, 'isSetup').returns(true); + this.sinon.stub(Raven, '_makeRequest'); + + Raven._send({message: 'bar'}); + var opts = Raven._makeRequest.lastCall.args[0]; + var mockError = new Error('429: Too many requests'); + mockError.request = { + status: 429 + }; + opts.onError(mockError); + + assert.equal(Raven._backoffStart, 100); // clock is at 100ms + assert.equal(Raven._backoffDuration, 1000); + + this.clock.tick(1); // only 1ms + opts.onError(mockError); + + // since the backoff has started, a subsequent 429 within the backoff period + // should not not the start/duration + assert.equal(Raven._backoffStart, 100); + assert.equal(Raven._backoffDuration, 1000); + + this.clock.tick(1000); // move past backoff period + opts.onError(mockError); + + // another failure has occurred, this time *after* the backoff period - should increase + assert.equal(Raven._backoffStart, 1101); + assert.equal(Raven._backoffDuration, 2000); + }); + + it('should reset backoffDuration and backoffStart if onSuccess is fired (200)', function () { + this.sinon.stub(Raven, 'isSetup').returns(true); + this.sinon.stub(Raven, '_makeRequest'); + + Raven._backoffDuration = 1000; + Raven._backoffStart = 0; + this.clock.tick(1001); // tick clock just past time necessary + + Raven._send({message: 'bar'}); + var opts = Raven._makeRequest.lastCall.args[0]; + opts.onSuccess({}); + + assert.equal(Raven._backoffStart, null); // clock is at 100ms + assert.equal(Raven._backoffDuration, 0); + }); }); describe('makeRequest', function() { @@ -1188,6 +1259,24 @@ describe('globals', function() { window.XDomainRequest = oldXDR }); + + it('should pass a request object to onError', function (done) { + XMLHttpRequest.prototype.withCredentials = true; + + Raven._makeRequest({ + url: 'http://localhost/', + auth: {a: '1', b: '2'}, + data: {foo: 'bar'}, + options: Raven._globalOptions, + onError: function (error) { + assert.equal(error.request.status, 429); + done(); + } + }); + + var lastXhr = this.requests[this.requests.length - 1]; + lastXhr.respond(429, {'Content-Type': 'text/html'}, 'Too many requests'); + }); }); describe('handleOnErrorStackInfo', function () { From c67f2dd4c15f322f7e2354893269e85f3433969a Mon Sep 17 00:00:00 2001 From: Ben Vinegar Date: Wed, 25 Jan 2017 23:21:20 -0800 Subject: [PATCH 2/6] Use Retry-After if available --- src/raven.js | 36 ++++++++++++++++++++++++++++++++---- test/raven.test.js | 18 ++++++++++++++++++ 2 files changed, 50 insertions(+), 4 deletions(-) diff --git a/src/raven.js b/src/raven.js index 33f90c2c38af..d61d37d05f14 100644 --- a/src/raven.js +++ b/src/raven.js @@ -1326,6 +1326,36 @@ Raven.prototype = { return this._backoffDuration && now() - this._backoffStart < this._backoffDuration; }, + _setBackoffState: function(request) { + // if we are already in a backoff state, don't change anything + if (this._shouldBackoff()) + return; + + var status = request.status; + + // 400 - project_id doesn't exist or some other fatal + // 401 - nvalid/revoked dsn + // 429 - too many requests + if (!(status === 400 || status === 401 || status === 429)) + return; + + var retry; + try { + // If Retry-After is not in Access-Control-Allow-Headers, most + // browsers will throw an exception trying to access it + retry = request.getResponseHeader('Retry-After'); + retry = parseInt(retry, 10); + } catch (e) { + /* eslint no-empty:0 */ + } + + this._backoffDuration = retry + ? retry + : this._backoffDuration * 2 || 1000; + + this._backoffStart = now(); + }, + _send: function(data) { if (this._shouldBackoff()) { return; @@ -1453,10 +1483,8 @@ Raven.prototype = { callback && callback(); }, onError: function failure(error) { - // too many requests - if (!self._shouldBackoff() && error.request && error.request.status === 429) { - self._backoffDuration = self._backoffDuration * 2 || 1000; - self._backoffStart = now(); + if (error.request) { + self._setBackoffState(error.request); } self._triggerEvent('failure', { diff --git a/test/raven.test.js b/test/raven.test.js index 15a4105b0938..391f7159bf5b 100644 --- a/test/raven.test.js +++ b/test/raven.test.js @@ -1193,6 +1193,24 @@ describe('globals', function() { assert.equal(Raven._backoffDuration, 2000); }); + + it('should set backoffDuration to value of Retry-If header if present', function () { + this.sinon.stub(Raven, 'isSetup').returns(true); + this.sinon.stub(Raven, '_makeRequest'); + + Raven._send({message: 'bar'}); + var opts = Raven._makeRequest.lastCall.args[0]; + var mockError = new Error('401: Unauthorized'); + mockError.request = { + status: 401, + getResponseHeader: sinon.stub().withArgs('Retry-After').returns('1337') + }; + opts.onError(mockError); + + assert.equal(Raven._backoffStart, 100); // clock is at 100ms + assert.equal(Raven._backoffDuration, 1337); // converted to int + }); + it('should reset backoffDuration and backoffStart if onSuccess is fired (200)', function () { this.sinon.stub(Raven, 'isSetup').returns(true); this.sinon.stub(Raven, '_makeRequest'); From 0c6a622d20896cab77f79d076bfa79d91b5ceb6d Mon Sep 17 00:00:00 2001 From: Ben Vinegar Date: Thu, 26 Jan 2017 12:58:53 -0800 Subject: [PATCH 3/6] Add logging for transport failure + suppressed error --- src/raven.js | 16 +++++++++++----- 1 file changed, 11 insertions(+), 5 deletions(-) diff --git a/src/raven.js b/src/raven.js index d61d37d05f14..ca3fd6289349 100644 --- a/src/raven.js +++ b/src/raven.js @@ -1328,8 +1328,9 @@ Raven.prototype = { _setBackoffState: function(request) { // if we are already in a backoff state, don't change anything - if (this._shouldBackoff()) + if (this._shouldBackoff()) { return; + } var status = request.status; @@ -1357,10 +1358,6 @@ Raven.prototype = { }, _send: function(data) { - if (this._shouldBackoff()) { - return; - } - var globalOptions = this._globalOptions; var baseData = { @@ -1424,6 +1421,13 @@ Raven.prototype = { return; } + // Backoff state: Sentry server previously responded w/ an error (e.g. 429 - too many requests), + // so drop requests until "cool-off" period has elapsed. + if (this._shouldBackoff()) { + this._logDebug('warn', 'Raven dropped error due to backoff: ', data); + return; + } + this._sendProcessedPayload(data); }, @@ -1483,6 +1487,8 @@ Raven.prototype = { callback && callback(); }, onError: function failure(error) { + self._logDebug('error', 'Raven transport failed to send: ', error); + if (error.request) { self._setBackoffState(error.request); } From fffb7d96fa948b17d1b75b023bce9901b90cd3db Mon Sep 17 00:00:00 2001 From: Ben Vinegar Date: Thu, 26 Jan 2017 13:21:21 -0800 Subject: [PATCH 4/6] Fix comments --- src/raven.js | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/src/raven.js b/src/raven.js index ca3fd6289349..727d60e481f1 100644 --- a/src/raven.js +++ b/src/raven.js @@ -1327,7 +1327,7 @@ Raven.prototype = { }, _setBackoffState: function(request) { - // if we are already in a backoff state, don't change anything + // If we are already in a backoff state, don't change anything if (this._shouldBackoff()) { return; } @@ -1335,14 +1335,14 @@ Raven.prototype = { var status = request.status; // 400 - project_id doesn't exist or some other fatal - // 401 - nvalid/revoked dsn + // 401 - invalid/revoked dsn // 429 - too many requests if (!(status === 400 || status === 401 || status === 429)) return; var retry; try { - // If Retry-After is not in Access-Control-Allow-Headers, most + // If Retry-After is not in Access-Control-Expose-Headers, most // browsers will throw an exception trying to access it retry = request.getResponseHeader('Retry-After'); retry = parseInt(retry, 10); @@ -1350,8 +1350,11 @@ Raven.prototype = { /* eslint no-empty:0 */ } + this._backoffDuration = retry + // If Sentry server returned a Retry-After value, use it ? retry + // Otherwise, double the last backoff duration (starts at 1 sec) : this._backoffDuration * 2 || 1000; this._backoffStart = now(); From 02dbb1446c419e93554392030e86c47ee1769382 Mon Sep 17 00:00:00 2001 From: Ben Vinegar Date: Fri, 27 Jan 2017 12:47:19 -0800 Subject: [PATCH 5/6] setDSN resets backoff state --- src/raven.js | 15 +++++++++++---- test/raven.test.js | 12 ++++++++++++ 2 files changed, 23 insertions(+), 4 deletions(-) diff --git a/src/raven.js b/src/raven.js index 727d60e481f1..c4d1c05725e6 100644 --- a/src/raven.js +++ b/src/raven.js @@ -61,8 +61,7 @@ function Raven() { this._keypressTimeout; this._location = _window.location; this._lastHref = this._location && this._location.href; - this._backoffDuration = 0; - this._backoffStart = null; + this._resetBackoff(); for (var method in this._originalConsole) { // eslint-disable-line guard-for-in this._originalConsoleMethods[method] = this._originalConsole[method]; @@ -199,6 +198,10 @@ Raven.prototype = { self._globalEndpoint = self._globalServer + '/' + path + 'api/' + self._globalProject + '/store/'; + + // Reset backoff state since we may be pointing at a + // new project/server + this._resetBackoff(); }, /* @@ -1322,6 +1325,11 @@ Raven.prototype = { return httpData; }, + _resetBackoff: function() { + this._backoffDuration = 0; + this._backoffStart = null; + }, + _shouldBackoff: function() { return this._backoffDuration && now() - this._backoffStart < this._backoffDuration; }, @@ -1480,8 +1488,7 @@ Raven.prototype = { data: data, options: globalOptions, onSuccess: function success() { - self._backoffDuration = 0; - self._backoffStart = null; + self._resetBackoff(); self._triggerEvent('success', { data: data, diff --git a/test/raven.test.js b/test/raven.test.js index 391f7159bf5b..1e73effa4593 100644 --- a/test/raven.test.js +++ b/test/raven.test.js @@ -1573,6 +1573,18 @@ describe('Raven (public API)', function() { assert.equal(Raven._globalEndpoint, 'http://example.com:80/api/2/store/'); assert.equal(Raven._globalProject, '2'); }); + + it('should reset the backoff state', function() { + Raven.config('//def@lol.com/3'); + + Raven._backoffStart = 100; + Raven._backoffDuration = 2000; + + Raven.setDSN(SENTRY_DSN); + + assert.equal(Raven._backoffStart, null); + assert.equal(Raven._backoffDuration, 0); + }); }); describe('.config', function() { From fcea70eae3e68bbe2ff97f53cf387ed5fc3cdf61 Mon Sep 17 00:00:00 2001 From: Ben Vinegar Date: Fri, 27 Jan 2017 13:10:39 -0800 Subject: [PATCH 6/6] RN plugin transport now passes request object on error --- plugins/react-native.js | 4 +++- test/plugins/react-native.test.js | 4 +++- 2 files changed, 6 insertions(+), 2 deletions(-) diff --git a/plugins/react-native.js b/plugins/react-native.js index 95f77084cb68..7cad2fef45a1 100644 --- a/plugins/react-native.js +++ b/plugins/react-native.js @@ -182,7 +182,9 @@ reactNativePlugin._transport = function (options) { } } else { if (options.onError) { - options.onError(new Error('Sentry error code: ' + request.status)); + var err = new Error('Sentry error code: ' + request.status); + err.request = request; + options.onError(err); } } }; diff --git a/test/plugins/react-native.test.js b/test/plugins/react-native.test.js index 48b40e7f301a..8ef9eea33a5c 100644 --- a/test/plugins/react-native.test.js +++ b/test/plugins/react-native.test.js @@ -174,8 +174,10 @@ describe('React Native plugin', function () { var lastXhr = this.requests.shift(); lastXhr.respond(401); - assert.isTrue(onError.calledOnce); assert.isFalse(onSuccess.calledOnce); + assert.isTrue(onError.calledOnce); + assert.isTrue(onError.lastCall.args[0] instanceof Error); + assert.equal(onError.lastCall.args[0].request.status, 401); }); it('should call onSuccess callback on success', function () {