adobe / helix-log

Log framework designed for use with project helix
Apache License 2.0
3 stars 9 forks source link

Prevent deep serialisation of non plain objects #89

Open tripodsan opened 4 years ago

tripodsan commented 4 years ago

Is your feature request related to a problem? Please describe. it is very convenient to pass objects for logging, like:

} catch (e) {
  error('something happened!', e);
}

but when the object is large (and deep), it could produce quite some log text. for example request throws a http.clientrequest as error, which produces a 400kb log entry.

Describe the solution you'd like

koraa commented 4 years ago

I do get that this can be annoying and it is something helix-log should address! Could you provide a list of specific instance where this is a problem?

I think this may be feature for the formatters; maybe as an option "inspectDepth"? but I would not change the default behaviour…

Finding a solution where too much is being logged IMHO is easier than noticing something accidentally was not logged…

provide good serializers for non-plain objects, like Error

Could you go into more detail as to what the api should look like?

if no serializer exists, only use inspect if the object has either a @@toStringTag or a util.inspect.custom method.

What should be done instead?

tripodsan commented 4 years ago

Could you provide a list of specific instance where this is a problem?

the major one I encountered was mentioned above: logging a http.clientrequest but also logging a express request or response as-is produces rarely a good log. that's why we added filters for http.IncomingMessage and http.ServerResponse:

https://github.com/adobe/openwhisk-action-logger/blob/cda6fabc2085812a41ec652681a78cf02bb2200e/src/logger.js#L73-L90

Could you go into more detail as to what the api should look like?

I don't think there should be an api. if a user wants his object to be logged it can add his own inspect.custom method.

What should be done instead?

[object] ?

koraa commented 4 years ago

Morning!

Would you mind opening a PR for the custom serializers? We might have to investigate which properties should be included, but since these are from core node modules I think it would be nice to have them in helix-log…

Regarding the issue: Given the information you sent in the helix chat, I am beginning to understand what's the problem here! Would you mind posting the info from chat here for completeness? I don't really want to quote without explicit permission…

Serializing the error with jsonifyForLog – it does terminate but produces excessively large output. Right? So we're not dealing with a circular data structure…we might need to add support for that anyways…

Could you post both outputs? I would like to find out why jsonifyForLog produces so much more output…

Now, given the new information, I definitely agree the behavior you describe is a problem – helix-log is effectively self-DOSing itself…

I don't really want to get rid of the ability to serialize arbitrary objects; it's a core tenant of helix-log's usefulness!

I can however think of a couple of steps we could take to improve the situation:

  1. Reintroduce the size/depth limitations for inspect()
  2. Introduce guards against self-referential data structures in jsonifyForLog
  3. Introduce size/depth limitations in jsonifyForLog
  4. Use inspect() as a backend for serializing unknown data structures in jsonifyForLog (since it seems to do a better job. We could even consider utilizing custom inspect implementations in jsonifyForLog, but that might be quite tough since it outputs a string instead of a simpler object…

I think we should implement some of those and then see how this affects the log output in the examples you gave.

What do you think?

tripodsan commented 4 years ago

@koraa sorry for the late response...I need some more time...

koraa commented 4 years ago

Take all the time you need; I am just very happy you raised this issue!