TomFrost / Bristol

Insanely configurable logging for Node.js
MIT License
113 stars 19 forks source link

Use V8 JavaScriptStackTraceApi to find log origin #12

Closed bartekn closed 9 years ago

bartekn commented 9 years ago

_getOrigin method is extremely slow because regular expression is used to parse stack string. I've created a simple app: bristol-test to prove the point and observed that even only 30 calls to bristol.log under heavy load can slow the app 10 times.

In this PR I'm using JavaScriptStackTraceApi to get array of CallSite objects what allows to find a log call origin much faster. Overwriting Error.prepareStackTrace function looks bad but it's the only way to make this method faster. I'm switching to the original Error.prepareStackTrace function at the end of this method.

bristol-test results for 2000 request (200 concurent requests):

regexp method JavaScriptStackTraceApi method
Requests per second 149.55 794.86
Longest request [ms] 1531 385
TomFrost commented 9 years ago

This is much nicer. Perhaps it would be cleaner to subclass Error and override prepareStackTrace there -- then we avoid the dirtiness of overriding a native function, and we also wouldn't have to keep a reference to the original and set it back. We'd just create a new TraceableError each time. What do you think?

bartekn commented 9 years ago

I'm afraid it's not possible. Error.prepareStackTrace is a static method and V8 is calling it directly for all types of errors.

From the docs:

For efficiency stack traces are not formatted when they are captured but on demand, the first time the stack property is accessed. A stack trace is formatted by calling

Error.prepareStackTrace(error, structuredStackTrace)

and using whatever this call returns as the value of the stack property. If you assign a different function value to Error.prepareStackTrace that function will be used to format stack traces. It will be passed the error object that it is preparing a stack trace for and a structured representation of the stack. User stack trace formatters are free to format the stack trace however they want and even return non-string values. It is safe to retain references to the structured stack trace object after a call to prepareStackTrace completes so that it is also a valid return value. Note that the custom prepareStackTrace function is immediately called at the point when the error object is created (e.g. with new Error()).

TomFrost commented 9 years ago

Released in 0.3.3