Skip to content
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.

Sign up for GitHub

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

Jump to bottom

Log a thrown error's status when available #5

Open
wants to merge 2 commits into
base: master
Choose a base branch
from
Open

Log a thrown error's status when available #5

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
027120c
Log a thrown error's status when available
Nov 3, 2016
dc99e66
Combine error-related unit tests
Nov 3, 2016
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion src/index.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -360,7 +360,7 @@ export default function createLogger(options = {}) {
let $status;

if (exception) {
$status = colorize('fatal')('ERR');
$status = colorize('fatal')(exception.status || 'ERR');
} else if (status >= 100 && status < 200) {
$status = colorize('info')(status);
} else if (status < 300) {
Expand Down
0 .../logger_should_log_an_unhandled_error.log → ..._error_is_thrown_should_log_the_error.log
View file
Open in desktop
File renamed without changes.
4 changes: 4 additions & 0 deletions test/fixtures/logger_when_an_error_is_thrown_should_log_the_error_status_if_avaiable.log
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,4 @@
──‣ ┈┈┈┈┈ GET┈ ┬ /
╎ { Error
╎  at stack status: 504 }
504 ┈┈0ms GET┈ ┴ /
68 changes: 49 additions & 19 deletions test/index.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -273,31 +273,61 @@ describe('logger', () => {
expect(this.output, 'to equal', fixtures[title]);
});

it('should log an unhandled error', async function () {
const title = this.test.fullTitle();
const createLogger = this.createLogger(title);
describe('when an error is thrown', () => {
it('should log the error', async function () {
const title = this.test.fullTitle();
const createLogger = this.createLogger(title);

const logger = createLogger();
const logger = createLogger();

const context = {
method: 'GET',
originalUrl: '/'
};
const context = {
method: 'GET',
originalUrl: '/'
};

const next = () => {
const error = new Error();
error.stack = 'Error\n at stack';
const next = () => {
const error = new Error();
error.stack = 'Error\n at stack';

throw error;
};
throw error;
};

try {
await logger(context, next);
} catch (error) {
// Not interested in this one
}
try {
await logger(context, next);
} catch (error) {
// Not interested in this one
}

expect(this.output, 'to equal', fixtures[title]);
expect(this.output, 'to equal', fixtures[title]);
});

it('should log the error status if avaiable', async function () {
const title = this.test.fullTitle();
const createLogger = this.createLogger(title);

const logger = createLogger();

const context = {
method: 'GET',
originalUrl: '/'
};

const next = () => {
const error = new Error('GatewayTimeout');
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I would have expected at least that "GatewayTimeout" also got logged.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ctx.throw formats the error message as such. with an actual koa app, I had this in the logs:

──‣ ┈┈┈┈┈ GET┈ ┬ /
               ╎ ServiceUnavailableError: Yo
               ╎     at Object.throw (node_modules/koa/lib/context.js:91:23)
               ╎     at app.use (server.js:44:22)
               ╎     at dispatch (node_modules/koa-compose/index.js:44:32)
               ╎     at next (node_modules/koa-compose/index.js:45:18)
               ╎     at logger (/home/jmu/Projects/concurrency-logger/src/index.js:323:19)
               ╎     at dispatch (node_modules/koa-compose/index.js:44:32)
               ╎     at next (node_modules/koa-compose/index.js:45:18)
               ╎     at app.use (server.js:8:11)
               ╎     at dispatch (node_modules/koa-compose/index.js:44:32)
               ╎     at node_modules/koa-compose/index.js:36:12
503 ┈┈1ms GET┈ ┴ /

In this case Yo was my custom error message. Maybe I should put that into the fake error stack?

Copy link
Owner

@pablosichert pablosichert Nov 3, 2016 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks like the formatting is different only because of overwriting .stack in the test cases. We need to make sure that it produces the same output for all environments, though.

Edit: I'm referring to the brackets vs no brackets around the log

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Your custom error class is something like class ServiceUnavailableError extends Error {}?

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We need to make sure that it produces the same output for all environments

Yeah I figured that's why the stack was overwritten. I'm not sure either why the new one has the curly brackets..

It's not a custom error, I'm using this to throw the error:

app.use(async context => {
    context.throw(503, 'Yo');
});

Then koa prepends the error message with 'ServiceUnavailableError: '. Also note that with the actual error (in the comment above), the error doesn't have curly brackets. Making it all the more puzzing :)

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ha. Found it:

> var util = require('util')
undefined
> var err = new Error()
undefined
> err.stack = 'Err\n stack'
'Err\n stack'
> util.inspect(err)
'Err\n stack'
> err.status = 504
504
> util.inspect(err)
'{ Err\n stack status: 504 }'
>

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So this is the culprit

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe that even makes sense, when you attach some custom properties to an error.

But why didn't it print the brackets (with status inside) in the log you pasted?

An option would be if (arg instanceof Error) and roll our own pretty printing. I would be happy if it would work without needing to maintain that, though.

error.status = 504;
error.stack = 'Error\n at stack';

throw error;
};

try {
await logger(context, next);
} catch (error) {
// Not interested in this one
}

expect(this.output, 'to equal', fixtures[title]);
});
});

it('should expose context.log method', async function() {
Expand Down