Skip to content
This repository has been archived by the owner on Jun 18, 2021. It is now read-only.

Allow Error object to be passed to node-report #82

Closed
wants to merge 6 commits into from
Closed
Show file tree
Hide file tree
Changes from 5 commits
Commits
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
20 changes: 20 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -69,6 +69,26 @@ can be specified as a parameter on the `triggerReport()` call.
nodereport.triggerReport("myReportName");
```

Both `triggerReport()` and `getReport()` can take an optional `Error` object
as a parameter. If an `Error` object is provided, the message and stack trace
from the object will be included in the report in the `JavaScript Exception
Details` section.
When using node-report to handle errors in a callback or an exception handler
this allows the report to include the location of the original error as well
as where it was handled.
If both a filename and `Error` object are passed to `triggerReport()` the
`Error` object should be the second parameter.

```js
try {
process.chdir('/foo/foo');
} catch (err) {
nodereport.triggerReport(err);
}
...
});
```

## Configuration

Additional configuration is available using the following APIs:
Expand Down
26 changes: 20 additions & 6 deletions src/module.cc
Original file line number Diff line number Diff line change
Expand Up @@ -51,6 +51,8 @@ NAN_METHOD(TriggerReport) {
Nan::HandleScope scope;
v8::Isolate* isolate = info.GetIsolate();
char filename[NR_MAXNAME + 1] = "";
v8::MaybeLocal<v8::Value> error;
int err_index = 0;

if (info[0]->IsString()) {
// Filename parameter supplied
Expand All @@ -60,9 +62,16 @@ NAN_METHOD(TriggerReport) {
} else {
Nan::ThrowError("node-report: filename parameter is too long");
}
err_index++;
}

// We need to pass the javascript object so we can query if for a stack trace.
Copy link

Choose a reason for hiding this comment

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

javascript -> JavaScript and if -> it

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Done.

if (info[err_index]->IsNativeError()) {
error = info[err_index];
}

if (nodereport_events & NR_APICALL) {
TriggerNodeReport(isolate, kJavaScript, "JavaScript API", __func__, filename);
TriggerNodeReport(isolate, kJavaScript, "JavaScript API", __func__, filename, error);
// Return value is the report filename
info.GetReturnValue().Set(Nan::New(filename).ToLocalChecked());
}
Expand All @@ -77,7 +86,12 @@ NAN_METHOD(GetReport) {
v8::Isolate* isolate = info.GetIsolate();
std::ostringstream out;

GetNodeReport(isolate, kJavaScript, "JavaScript API", __func__, out);
v8::MaybeLocal<v8::Value> error;
if (info[0]->IsNativeError()) {
error = info[0];
}

GetNodeReport(isolate, kJavaScript, "JavaScript API", __func__, error, out);
// Return value is the contents of a report as a string.
info.GetReturnValue().Set(Nan::New(out.str()).ToLocalChecked());
}
Expand Down Expand Up @@ -156,7 +170,7 @@ static void OnFatalError(const char* location, const char* message) {
}
// Trigger report if requested
if (nodereport_events & NR_FATALERROR) {
TriggerNodeReport(Isolate::GetCurrent(), kFatalError, message, location, nullptr);
TriggerNodeReport(Isolate::GetCurrent(), kFatalError, message, location, nullptr, v8::MaybeLocal<v8::Value>());
Copy link

Choose a reason for hiding this comment

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

Does this project wrap lines at 80 characters? If so, there are a number of long lines in this PR.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Of our six outstanding PR's four of them concern code formatting and the conversations got a bit bogged down. After the two outstanding functional PR's are merged I should probably do something like just run clang-format over the C source to standardise it a bit.

At the moment we are well over 80 in node_report.cc as it writes strings of 80 "=" char strings as section dividers in several places.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@cjihrig - Do you want me to push a fix to this or would you rather I dealt with long lines throughout the project in a separate PR?

Copy link

Choose a reason for hiding this comment

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

If the project doesn't enforce 80 character lines, or there are a bunch of other offenders, it's probably simpler to not hold up this PR and deal with them all in another PR. Your call.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

There's other places with the same problem so I should probably get the various PRs we have for linting C/C++ and JavaScript tidied up. That way we can do the all code formatting in one patch without muddling them up with functional changes.

}
fflush(stderr);
raise(SIGABRT);
Expand All @@ -165,7 +179,7 @@ static void OnFatalError(const char* location, const char* message) {
bool OnUncaughtException(v8::Isolate* isolate) {
// Trigger report if requested
if (nodereport_events & NR_EXCEPTION) {
TriggerNodeReport(isolate, kException, "exception", __func__, nullptr);
TriggerNodeReport(isolate, kException, "exception", __func__, nullptr, v8::MaybeLocal<v8::Value>());
}
if ((commandline_string.find("abort-on-uncaught-exception") != std::string::npos) ||
(commandline_string.find("abort_on_uncaught_exception") != std::string::npos)) {
Expand Down Expand Up @@ -231,7 +245,7 @@ static void SignalDumpInterruptCallback(Isolate* isolate, void* data) {
fprintf(stdout, "node-report: SignalDumpInterruptCallback triggering report\n");
}
TriggerNodeReport(isolate, kSignal_JS,
node::signo_string(report_signal), __func__, nullptr);
node::signo_string(report_signal), __func__, nullptr, v8::MaybeLocal<v8::Value>());
}
report_signal = 0;
}
Expand All @@ -246,7 +260,7 @@ static void SignalDumpAsyncCallback(uv_async_t* handle) {
fprintf(stdout, "node-report: SignalDumpAsyncCallback triggering NodeReport\n");
}
TriggerNodeReport(Isolate::GetCurrent(), kSignal_UV,
node::signo_string(report_signal), __func__, nullptr);
node::signo_string(report_signal), __func__, nullptr, v8::MaybeLocal<v8::Value>());
Copy link

Choose a reason for hiding this comment

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

It would be nice to not have all of the v8::MaybeLocal<v8::Value>()s around.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I've added a using v8::MaybeLocal so at least we can do MaybeLocal<Value>() - we already had a using v8::Value and this does make the new code in node_report.cc more consistent with the existing code.

I checked the Node.js source code to see if there was a better solution but that passes MaybeLocal<Value>() in lots of locations as well.

Copy link

Choose a reason for hiding this comment

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

What about passing nullptr when it's not actually used?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

The argument is pass-by-value not a pointer. IIRC You can't create an empty Local<Value> which is why I used MaybeLocal<Value> instead to allow us to pass no value object when there wasn't one available.

Copy link

Choose a reason for hiding this comment

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

Aren't you introducing the argument in this PR though? If so, you could make it a pointer.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I believe from the documentation for Local (and MaybeLocal) in deps/v8.h that Locals should be passed by value. The local is managing the reference to an object owned by V8's garbage collector, I'll admit I haven't dug that far into the implementation details but I've not seen any examples in the Node.js code or other modules where Locals are passed by reference.

In my head I have them in a similar category to std::shared_ptr (and other _ptr's) in C++ where you pass by value something which manages does the actual pointer management for you. I don't believe that they are actually large objects to pass by value, I don't think they really contain fields other than the reference itself.

If I'm wrong I'm happy to change it but I'm a bit wary that passing these by reference is really just a good way to introduce bugs and I'd like to be sure I'm handling these the right way.

Copy link

Choose a reason for hiding this comment

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

I haven't heard that about Locals, but I could be wrong. I did find this though - https://github.com/nodejs/node/blob/6bcf65d4a788a73b3c3f27d75796609f948f7885/src/async-wrap-inl.h#L57

Copy link
Contributor Author

@hhellyer hhellyer May 5, 2017

Choose a reason for hiding this comment

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

My reference is here:
https://github.com/nodejs/node/blob/master/deps/v8/include/v8.h#L190

I think pass by value is correct and I don't think briefly stack allocating an empty MaybeLocal is remotely expensive so I'm happy with it but also happy to learn the "correct" answer.

(I'm wary of following async-wrap as an example, I suspect it may be special as it probably is quite performance critical which isn't true of node-report code.)

Copy link

Choose a reason for hiding this comment

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

OK, I just talked with @fhinkel from V8 about it and they agreed to not use a reference.

}
report_signal = 0;
}
Expand Down
50 changes: 40 additions & 10 deletions src/node_report.cc
Original file line number Diff line number Diff line change
Expand Up @@ -82,10 +82,11 @@ typedef struct tm TIME_TYPE;
#endif

// Internal/static function declarations
static void WriteNodeReport(Isolate* isolate, DumpEvent event, const char* message, const char* location, char* filename, std::ostream &out, TIME_TYPE* time);
static void WriteNodeReport(Isolate* isolate, DumpEvent event, const char* message, const char* location, char* filename, std::ostream &out, v8::MaybeLocal<v8::Value> error, TIME_TYPE* time);
static void PrintCommandLine(std::ostream& out);
static void PrintVersionInformation(std::ostream& out);
static void PrintJavaScriptStack(std::ostream& out, Isolate* isolate, DumpEvent event, const char* location);
static void PrintJavaScriptErrorStack(std::ostream& out, Isolate* isolate, v8::MaybeLocal<v8::Value> error);
static void PrintStackFromStackTrace(std::ostream& out, Isolate* isolate, DumpEvent event);
static void PrintStackFrame(std::ostream& out, Isolate* isolate, Local<StackFrame> frame, int index, void* pc);
static void PrintNativeStack(std::ostream& out);
Expand Down Expand Up @@ -379,7 +380,7 @@ void SetCommandLine() {
* const char* location
* char* name - in/out - returns the report filename
******************************************************************************/
void TriggerNodeReport(Isolate* isolate, DumpEvent event, const char* message, const char* location, char* name) {
void TriggerNodeReport(Isolate* isolate, DumpEvent event, const char* message, const char* location, char* name, v8::MaybeLocal<v8::Value> error) {
Copy link

Choose a reason for hiding this comment

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

The comment before this line documents the parameters. error should probably be added there.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Good spot.

// Recursion check for report in progress, bail out
if (report_active) return;
report_active = true;
Expand Down Expand Up @@ -460,7 +461,7 @@ void TriggerNodeReport(Isolate* isolate, DumpEvent event, const char* message, c
// Pass our stream about by reference, not by copying it.
std::ostream &out = outfile.is_open() ? outfile : *outstream;

WriteNodeReport(isolate, event, message, location, filename, out, &tm_struct);
WriteNodeReport(isolate, event, message, location, filename, out, error, &tm_struct);

// Do not close stdout/stderr, only close files we opened.
if(outfile.is_open()) {
Expand All @@ -474,7 +475,7 @@ void TriggerNodeReport(Isolate* isolate, DumpEvent event, const char* message, c

}

void GetNodeReport(Isolate* isolate, DumpEvent event, const char* message, const char* location, std::ostream& out) {
void GetNodeReport(Isolate* isolate, DumpEvent event, const char* message, const char* location, v8::MaybeLocal<v8::Value> error, std::ostream& out) {
// Obtain the current time and the pid (platform dependent)
TIME_TYPE tm_struct;
#ifdef _WIN32
Expand All @@ -484,7 +485,7 @@ void GetNodeReport(Isolate* isolate, DumpEvent event, const char* message, const
gettimeofday(&time_val, nullptr);
localtime_r(&time_val.tv_sec, &tm_struct);
#endif
WriteNodeReport(isolate, event, message, location, nullptr, out, &tm_struct);
WriteNodeReport(isolate, event, message, location, nullptr, out, error, &tm_struct);
}

static void walkHandle(uv_handle_t* h, void* arg) {
Expand Down Expand Up @@ -531,7 +532,7 @@ static void walkHandle(uv_handle_t* h, void* arg) {
*out << buf;
}

static void WriteNodeReport(Isolate* isolate, DumpEvent event, const char* message, const char* location, char* filename, std::ostream &out, TIME_TYPE* tm_struct) {
static void WriteNodeReport(Isolate* isolate, DumpEvent event, const char* message, const char* location, char* filename, std::ostream &out, v8::MaybeLocal<v8::Value> error, TIME_TYPE* tm_struct) {

#ifdef _WIN32
DWORD pid = GetCurrentProcessId();
Expand Down Expand Up @@ -589,6 +590,11 @@ static void WriteNodeReport(Isolate* isolate, DumpEvent event, const char* messa
PrintNativeStack(out);
out << std::flush;

// Print the stack trace and message from the Error object.
// (If one was provided.)
PrintJavaScriptErrorStack(out, isolate, error);
out << std::flush;

// Print V8 Heap and Garbage Collector information
PrintGCStatistics(out, isolate);
out << std::flush;
Expand Down Expand Up @@ -791,6 +797,29 @@ static void PrintJavaScriptStack(std::ostream& out, Isolate* isolate, DumpEvent
#endif
}

static void PrintJavaScriptErrorStack(std::ostream& out, Isolate* isolate, v8::MaybeLocal<v8::Value> error) {
if (error.IsEmpty() || !error.ToLocalChecked()->IsNativeError()) {
return;
}

out << "\n================================================================================";
out << "\n==== JavaScript Exception Details ==============================================\n\n";
Local<Message> message = v8::Exception::CreateMessage(isolate, error.ToLocalChecked());
Nan::Utf8String message_str(message->Get());

out << *message_str << "\n\n";

Local<StackTrace> stack = v8::Exception::GetStackTrace(error.ToLocalChecked());
if (stack.IsEmpty()) {
out << "No stack trace available from Exception::GetStackTrace()\n";
return;
}
// Print the stack trace, samples are not available as the exception isn't from the current stack.
for (int i = 0; i < stack->GetFrameCount(); i++) {
PrintStackFrame(out, isolate, stack->GetFrame(i), i, nullptr);
}
}

/*******************************************************************************
* Function to print stack using GetStackSample() and StackTrace::StackTrace()
*
Expand Down Expand Up @@ -842,13 +871,14 @@ static void PrintStackFrame(std::ostream& out, Isolate* isolate, Local<StackFram
char buf[64];

// First print the frame index and the instruction address
if (pc != nullptr) {
#ifdef _WIN32
snprintf( buf, sizeof(buf), "%2d: [pc=0x%p] ", i, pc);
out << buf;
snprintf( buf, sizeof(buf), "%2d: [pc=0x%p] ", i, pc);
#else
snprintf( buf, sizeof(buf), "%2d: [pc=%p] ", i, pc);
out << buf;
snprintf( buf, sizeof(buf), "%2d: [pc=%p] ", i, pc);
#endif
out << buf;
}

// Now print the JavaScript function name and source information
if (frame->IsEval()) {
Expand Down
4 changes: 2 additions & 2 deletions src/node_report.h
Original file line number Diff line number Diff line change
Expand Up @@ -32,8 +32,8 @@ using v8::StackFrame;

enum DumpEvent {kException, kFatalError, kSignal_JS, kSignal_UV, kJavaScript};

void TriggerNodeReport(Isolate* isolate, DumpEvent event, const char* message, const char* location, char* name);
void GetNodeReport(Isolate* isolate, DumpEvent event, const char* message, const char* location, std::ostream& out);
void TriggerNodeReport(Isolate* isolate, DumpEvent event, const char* message, const char* location, char* name, v8::MaybeLocal<v8::Value> error);
void GetNodeReport(Isolate* isolate, DumpEvent event, const char* message, const char* location, v8::MaybeLocal<v8::Value> error, std::ostream& out);

unsigned int ProcessNodeReportEvents(const char* args);
unsigned int ProcessNodeReportSignal(const char* args);
Expand Down
13 changes: 12 additions & 1 deletion test/common.js
Original file line number Diff line number Diff line change
Expand Up @@ -58,11 +58,18 @@ exports.validateContent = function validateContent(data, t, options) {
const expectedVersions = options ?
options.expectedVersions || nodeComponents :
nodeComponents;
var plan = REPORT_SECTIONS.length + nodeComponents.length + 5;
const expectedException = options.expectedException;
if (options.expectedException) {
REPORT_SECTIONS.push('JavaScript Exception Details');
}

let plan = REPORT_SECTIONS.length + nodeComponents.length + 5;
if (options.commandline) plan++;
if (options.expectedException) plan++;
const glibcRE = /\(glibc:\s([\d.]+)/;
const nodeReportSection = getSection(reportContents, 'Node Report');
const sysInfoSection = getSection(reportContents, 'System Information');
const exceptionSection = getSection(reportContents, 'JavaScript Exception Details');
const libcPath = getLibcPath(sysInfoSection);
const libcVersion = getLibcVersion(libcPath);
if (glibcRE.test(nodeReportSection) && libcVersion) plan++;
Expand All @@ -84,6 +91,10 @@ exports.validateContent = function validateContent(data, t, options) {
new RegExp('Node.js version: ' + process.version),
'Node Report header section contains expected Node.js version');
}
if (options && options.expectedException) {
t.match(exceptionSection, new RegExp('Uncaught Error: ' + options.expectedException),
'Node Report JavaScript Exception contains expected message');
}
if (options && options.commandline) {
if (this.isWindows()) {
// On Windows we need to strip double quotes from the command line in
Expand Down
29 changes: 29 additions & 0 deletions test/test-api-pass-error.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,29 @@
'use strict';

// Testcase for passing an error object to the API call.

if (process.argv[2] === 'child') {
const nodereport = require('../');
try {
throw new Error("Testing error handling");
} catch (err) {
nodereport.triggerReport(err);
}
} else {
const common = require('./common.js');
Copy link

Choose a reason for hiding this comment

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

I think this can just be common instead of common.js

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I tested, it looks like it can. @sam-github had other comments about the test structure. At the moment it matches all the other tests and if we want to fix one up we should probably do all of them under a separate PR so I'm going to leave this for now.

const spawn = require('child_process').spawn;
const tap = require('tap');

const child = spawn(process.execPath, [__filename, 'child']);
Copy link
Contributor

Choose a reason for hiding this comment

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

I don't see why the test is spawning a child to call triggerReport(), why not just call it directly in the test? It looks like boilerplate copied from a test that must exist in order to get the report that doesn't apply here. If it is needed, probably needs a comment explaining why.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I believe most of the tests use spawn so the standard validation checks in common.js can check a known set of process arguments. I think @richardlau would be the person to ask if you want the history.

The test is a direct copy of test-api.js with a small change to how the triggerReport() call is made and an extra parameter to the common.validate() function. All the tests work along similar lines so I'll leave it how it is to make sure it fits the current model. If we want to change that we should do it under a separate PR so all the tests are consistent.

Copy link
Member

Choose a reason for hiding this comment

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

Yes, part of the standard validation checks in common.js is to check the command line, so our tests spawn as it's the only way to be certain what to expect.

Copy link
Member

Choose a reason for hiding this comment

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

Although the command line check can be skipped by not setting commandline on the options object passed to validate.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@sam-github Do you want this changed before you approve? I'm happy to raise a separate PR about changing the tests.

child.on('exit', (code) => {
tap.plan(3);
tap.equal(code, 0, 'Process exited cleanly');
const reports = common.findReports(child.pid);
tap.equal(reports.length, 1, 'Found reports ' + reports);
const report = reports[0];
common.validate(tap, report, {pid: child.pid,
commandline: child.spawnargs.join(' '),
Copy link
Contributor

Choose a reason for hiding this comment

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

I was half convinced by the argument for spawning above, then I read test/common.js, and now I'm not. The command line is just checked against what is passed in here, which could just as easily be process.argv.join(" ") as child.spawnargs.join(" "). Same comment for test/test-api.js, which I suspect was simply copied from the other non-API tests. The non-API tests obviously have to spawn, if you are testing the report generated by a fatal exception you need your child to be the one that dies with the fatal exception, but for API testing, I'm not seeing the need. For that matter, I don't think this test needs its own file. test/test-api.js should be changed to test both variants of triggerReport() and to not spawn children, making it a much more typical API test.

Copy link
Member

Choose a reason for hiding this comment

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

One of the problems we had with process.argv (#58 (comment)) is that Node.js rewrites argv (e.g. it resolves argv[0]). When we spawn we have control over the command line, so we know that if we spawn with a resolved path (e.g. process.execPath) the operating system will match what is reported by Node.js.

But as I pointed out elsewhere the command line check is optional -- We can leave out commandline from the options passed to common.validate and the check will be skipped.

expectedException: "Testing error handling",
});
});
}