server: downgrade ECANCELED logs to debug

Just like we do for EPIPE and ECONNRESET, we can downgrade ECANCELED
client errors to the debug logging level rather than treating them as
errors.
This commit is contained in:
Court Ewing 2016-12-22 13:41:04 -05:00
parent 899d560caf
commit c2c2bbe42c
2 changed files with 85 additions and 7 deletions

View file

@ -17,6 +17,7 @@ function stubClientErrorEvent(errno) {
const stubEconnresetEvent = () => stubClientErrorEvent('ECONNRESET');
const stubEpipeEvent = () => stubClientErrorEvent('EPIPE');
const stubEcanceledEvent = () => stubClientErrorEvent('ECANCELED');
function assertDowngraded(transformed) {
expect(!!transformed).to.be(true);
@ -33,12 +34,6 @@ describe('server logging LogInterceptor', () => {
assertDowngraded(interceptor.downgradeIfEconnreset(event));
});
it('transforms EPIPE events', () => {
const interceptor = new LogInterceptor();
const event = stubEpipeEvent();
assertDowngraded(interceptor.downgradeIfEpipe(event));
});
it('does not match if the tags are not in order', () => {
const interceptor = new LogInterceptor();
const event = stubEconnresetEvent();
@ -59,4 +54,60 @@ describe('server logging LogInterceptor', () => {
expect(interceptor.downgradeIfEconnreset(event)).to.be(null);
});
});
describe('#downgradeIfEpipe()', () => {
it('transforms EPIPE events', () => {
const interceptor = new LogInterceptor();
const event = stubEpipeEvent();
assertDowngraded(interceptor.downgradeIfEpipe(event));
});
it('does not match if the tags are not in order', () => {
const interceptor = new LogInterceptor();
const event = stubEpipeEvent();
event.tags = [...event.tags.slice(1), event.tags[0]];
expect(interceptor.downgradeIfEpipe(event)).to.be(null);
});
it('ignores non EPIPE events', () => {
const interceptor = new LogInterceptor();
const event = stubClientErrorEvent('not EPIPE');
expect(interceptor.downgradeIfEpipe(event)).to.be(null);
});
it('ignores if tags are wrong', () => {
const interceptor = new LogInterceptor();
const event = stubEpipeEvent();
event.tags = ['different', 'tags'];
expect(interceptor.downgradeIfEpipe(event)).to.be(null);
});
});
describe('#downgradeIfEcanceled()', () => {
it('transforms ECANCELED events', () => {
const interceptor = new LogInterceptor();
const event = stubEcanceledEvent();
assertDowngraded(interceptor.downgradeIfEcanceled(event));
});
it('does not match if the tags are not in order', () => {
const interceptor = new LogInterceptor();
const event = stubEcanceledEvent();
event.tags = [...event.tags.slice(1), event.tags[0]];
expect(interceptor.downgradeIfEcanceled(event)).to.be(null);
});
it('ignores non ECANCELED events', () => {
const interceptor = new LogInterceptor();
const event = stubClientErrorEvent('not ECANCELED');
expect(interceptor.downgradeIfEcanceled(event)).to.be(null);
});
it('ignores if tags are wrong', () => {
const interceptor = new LogInterceptor();
const event = stubEcanceledEvent();
event.tags = ['different', 'tags'];
expect(interceptor.downgradeIfEcanceled(event)).to.be(null);
});
});
});

View file

@ -63,8 +63,35 @@ export class LogInterceptor extends Stream.Transform {
};
}
/**
* Since the upgrade to hapi 14, any socket write
* error is surfaced as a generic "client error"
* but "ECANCELED" specifically is not useful for the
* logs unless you are trying to debug edge-case behaviors.
*
* For that reason, we downgrade this from error to debug level
*
* @param {object} - log event
*/
downgradeIfEcanceled(event) {
const isClientError = doTagsMatch(event, ['connection', 'client', 'error']);
const isEcanceled = isClientError && get(event, 'data.errno') === 'ECANCELED';
if (!isEcanceled) return null;
return {
event: 'log',
pid: event.pid,
timestamp: event.timestamp,
tags: ['debug', 'connection', 'ecanceled'],
data: 'ECANCELED: Socket was closed by the client (probably the browser) before the response could be completed'
};
}
_transform(event, enc, next) {
const downgraded = this.downgradeIfEconnreset(event) || this.downgradeIfEpipe(event);
const downgraded = this.downgradeIfEconnreset(event)
|| this.downgradeIfEpipe(event)
|| this.downgradeIfEcanceled(event);
this.push(downgraded || event);
next();