-
-
Notifications
You must be signed in to change notification settings - Fork 1.6k
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Exponential backoff if Sentry server returns 429 #839
Changes from all commits
7927930
c67f2dd
0c6a622
fffb7d9
02dbb14
fcea70e
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -61,6 +61,7 @@ function Raven() { | |
this._keypressTimeout; | ||
this._location = _window.location; | ||
this._lastHref = this._location && this._location.href; | ||
this._resetBackoff(); | ||
|
||
for (var method in this._originalConsole) { // eslint-disable-line guard-for-in | ||
this._originalConsoleMethods[method] = this._originalConsole[method]; | ||
|
@@ -197,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(); | ||
}, | ||
|
||
/* | ||
|
@@ -1320,6 +1325,48 @@ Raven.prototype = { | |
return httpData; | ||
}, | ||
|
||
_resetBackoff: function() { | ||
this._backoffDuration = 0; | ||
this._backoffStart = null; | ||
}, | ||
|
||
_shouldBackoff: function() { | ||
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 - 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-Expose-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 */ | ||
} | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. What typically appears there? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. The actual reason. So an example string would be like:
or
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Okay. That could be useful for completely different reasons. (Does Retry-After say something about rate limiting? Or completely independent?) There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
This is only related to rate limiting and won't exist on any other response as of today. |
||
|
||
|
||
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(); | ||
}, | ||
|
||
_send: function(data) { | ||
var globalOptions = this._globalOptions; | ||
|
@@ -1385,6 +1432,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); | ||
}, | ||
|
||
|
@@ -1434,13 +1488,21 @@ Raven.prototype = { | |
data: data, | ||
options: globalOptions, | ||
onSuccess: function success() { | ||
self._resetBackoff(); | ||
|
||
self._triggerEvent('success', { | ||
data: data, | ||
src: url | ||
}); | ||
callback && callback(); | ||
}, | ||
onError: function failure(error) { | ||
self._logDebug('error', 'Raven transport failed to send: ', error); | ||
|
||
if (error.request) { | ||
self._setBackoffState(error.request); | ||
} | ||
|
||
self._triggerEvent('failure', { | ||
data: data, | ||
src: url | ||
|
@@ -1468,7 +1530,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); | ||
} | ||
} | ||
|
||
|
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -1137,6 +1137,95 @@ 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 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'); | ||
|
||
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 +1277,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 () { | ||
|
@@ -1466,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('//[email protected]/3'); | ||
|
||
Raven._backoffStart = 100; | ||
Raven._backoffDuration = 2000; | ||
|
||
Raven.setDSN(SENTRY_DSN); | ||
|
||
assert.equal(Raven._backoffStart, null); | ||
assert.equal(Raven._backoffDuration, 0); | ||
}); | ||
}); | ||
|
||
describe('.config', function() { | ||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'd suggest that we
console.log
or something that this is happening. That way we're not dropping things in the dark without any insight as to why if someone were to debug. Including ourselves.