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.

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

request.log(err) show an empty object #2744

Closed
kevinsimper opened this issue Aug 28, 2015 · 17 comments
Closed

request.log(err) show an empty object #2744

kevinsimper opened this issue Aug 28, 2015 · 17 comments
Labels
non issue Issue is not a problem or requires changes

Comments

@kevinsimper
Copy link

That is because you can't stringify an Error, but Hapi.js does try anyways because typeof error === 'object'.

I propose that

  • stringifying a console.error is wrong, since it can't show linebreaks, so an error.stack looks bad, it should just console.error without JSON.stringify
  • it should use data instanceof Error
@kevinsimper
Copy link
Author

Does somebody has a opinion? :)

@AdriVanHoudt
Copy link
Contributor

Well console.error would not show up in logging if you use Good for instance, I do server.log(err.message) in some cases, it depends

@kevinsimper
Copy link
Author

@AdriVanHoudt Thanks for you reply 👍

Yes, but the stacktrace would be good to have as well, but the request log purposely stringified it here
https://github.com/hapijs/hapi/blob/master/lib/request.js#L257

@gergoerdosi
Copy link
Contributor

stringifying a console.error is wrong, since it can't show linebreaks

It can, we just need to change Hoek.stringify(data) to Hoek.stringify(data, null, 4).

@kevinsimper
Copy link
Author

@gergoerdosi It is not that json can't be prettified, it is that the Error.stack contains breaks and they will be converted to \n in JSON.stringify

@gergoerdosi
Copy link
Contributor

Can you please add a sample code? I'm trying to reproduce the problem, but the stack is displayed correctly for me:

var Hapi = require('hapi');

// Create a server with a host and port
var server = new Hapi.Server({ debug: { request: ['error'] } });
server.connection({
    host: 'localhost',
    port: 8080
});

// Add the route
server.route({
    method: 'GET',
    path:'/hello',
    handler: function (request, reply) {
        request.log(['error'], new Error('test'));
        reply('hello');
    }
});

// Start the server
server.start(function () {
    console.log('Server running at:', server.info.uri);
});

This outputs:

$ node index.js 
Server running at: http://localhost:8080
Debug: error 
    Error: test
    at server.route.handler (/index.js:15:32)
    at Object.internals.handler (/node_modules/hapi/lib/handler.js:93:36)
    at /node_modules/hapi/lib/handler.js:28:23
    at internals.Protect.run (/node_modules/hapi/lib/protect.js:56:5)
    at exports.execute (/node_modules/hapi/lib/handler.js:22:22)
    at /node_modules/hapi/lib/request.js:377:13
    at iterate (/node_modules/hapi/node_modules/items/lib/index.js:35:13)
    at done (/node_modules/hapi/node_modules/items/lib/index.js:27:25)
    at /node_modules/hapi/node_modules/hoek/lib/index.js:841:22
    at process._tickDomainCallback (node.js:381:11)

@kevinsimper
Copy link
Author

I did not understand the code properly and how hapi.js works together with good and good-console. I should have mentioned that I used good. There is actually no error.

To help on my shame for creating this issue, I donated 50 danish kroners to red cross to help children in syria.

Thanks for your answers!
image

@AdriVanHoudt
Copy link
Contributor

@gergoerdosi try using Good console and then you will see what he means and yeah true it will convert to \n but there is no other way to log it to let's say a log file otherwise, you can parse it back into multiline on read.

Also no shame! Cool to donate though

@hueniverse hueniverse added the non issue Issue is not a problem or requires changes label Sep 12, 2015
@kevinsimper
Copy link
Author

I dug into it some more, now that i knew it was handle more by good and it is actually fairly complicated because each reporter decide themselves how they show the output. That means that the if you fix so that good-console shows an error with error.stack, and you are also using good-file and good-loggly, you also have to fix it in those.

I thought it was the same output, but it is not. I wanted to just log my javascript errors, but it seems not that easy.

@AdriVanHoudt
Copy link
Contributor

Good-console will do that for you, but as @gergoerdosi showed just doing the log, hapi will print it out for you nicely, or you can make your fork of good-console that does as you described in your original post with the console.error thing

@gergoerdosi
Copy link
Contributor

Changing SafeStringify(data.data) to SafeStringify(data.data, Object.getOwnPropertyNames(data.data)) should do the trick in good-console. However json-stringify-safe raises an error with this code. I created an issue:

moll/json-stringify-safe#14

If this gets fixed in json-stringify-safe, we can look into changing the code in good-console to support Error.

@AdriVanHoudt
Copy link
Contributor

@gergoerdosi what does passing the property names do? (not familiar with safestringify)

@gergoerdosi
Copy link
Contributor

@AdriVanHoudt Properties in Error objects are non-emurable, that's why Error objects can't be stringified. Whitelisting the property names is a little trick that makes JSON.stringify() to select those properties.

> var error = new Error('test')
undefined
> JSON.stringify(error)
'{}'
> JSON.stringify(error, Object.getOwnPropertyNames(error))
'{"stack":"Error: test\\n    at repl:1:13\\n    at REPLServer.defaultEval (repl.js:132:27)\\n    at bound (domain.js:254:14)\\n    at REPLServer.runBound [as eval] (domain.js:267:12)\\n    at REPLServer.<anonymous> (repl.js:279:12)\\n    at REPLServer.emit (events.js:107:17)\\n    at REPLServer.Interface._onLine (readline.js:214:10)\\n    at REPLServer.Interface._line (readline.js:553:8)\\n    at REPLServer.Interface._ttyWrite (readline.js:830:14)\\n    at ReadStream.onkeypress (readline.js:109:10)","message":"test"}'

Not sure this is the best way to solve this problem, but it's one.

@AdriVanHoudt
Copy link
Contributor

I see, is it perf?

@gergoerdosi
Copy link
Contributor

Not really. I just did a test now, JSON.stringify() with Object.getOwnPropertyNames(error) is 93% slower than without it. Well, we could then move stringification to an internal function and check for data.data instanceof Error as suggested by @kevinsimper.

Anyway, this is not a hapi issue. @kevinsimper: Open an issue in good-console if you want and we can continue the discussion there.

@kevinsimper
Copy link
Author

The problem is not only with good-console, it applies to every good- reporter, so good-file, good-loggly etc.

But the problem is not either in good, because all that library does is being an enabler for all the reporters.

I solved it anyways in a hacky way, where i change the Error prototype to be enumerable.

Object.defineProperty(Error.prototype, 'stack', {
  configurable: true,
  enumerable: true
})

and then not using good-console for the request.log, but using the built in

if(process.env.NODE_ENV === 'development') {
  serverOptions.debug = {
    request: ['error', 'mongo']
  }
}
var server = new Hapi.Server(serverOptions)

@DamodarSojka
Copy link

DamodarSojka commented May 26, 2016

So is changing Error object the way to solve this problem? Is there a better way?
I had an intuition that good was meant to help with logging.
Please correct me if I am missing something.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
non issue Issue is not a problem or requires changes
Projects
None yet
Development

No branches or pull requests

5 participants