Provide getReport API to return the contents of node-report. #48

hhellyer · 2017-01-30T13:20:58Z

These changes add a new function to the node-report API - getReport() to address issue #39. The getReport() function returns the string contents of node report to the caller instead of writing it to a file and returning the file name. This makes it easier for other modules to build on node-report.

This is limited to non-fatal uses of node-report, there is no event listener API. A Node.js program can’t listen on a fatal event callback and get the contents of a node-report as at that point Node.js is broken. Similarly the output cannot be streamed, it is returned as one object representing a snapshot of a point in time, as processing the data via a callback while it was still being gathered would change the state of the process we are reporting on.

To implement this I switched from using fprintf for output to C++ streams. This makes it trivial to switch between using a file stream or a string stream for output and the getReport path just passing a different stream object to the triggerReport path. There were two places in node-report where we passed our file stream to internal functions for them to write to.

In one case in the stack walking code there is no other suitable API so we use a temporary file and read it back in.
In another location where were were walking the libuv event loop via uv_print_all_handles. I have switched API’s to uv_walk, which allows us to look directly at each handle.
This loses the ability to see internal handles, however there only appear to be a couple of those and they are probably uninteresting. We gain the ability to get hold of the real uv_handle_t structures on the event loop and inspect them further which we can exploit in a future enhancement to give the user information about things like tcp connections and write queue sizes. (Anything publicly available via the libuv public API’s.) That would probably have been of sufficient benefit to switch API’s anyway.

This change also fixes a bug where when node-report always closed the handle it was writing to, even if it was using stderr/stdout.

mhdawson

Generally looks good, left a few comments. Is the output format when writing to a file the exact same as before except for not having the internal handles as you mentioned ?

mhdawson · 2017-01-30T22:49:30Z

src/node_report.cc

-        fprintf(fp, "\nMachine: %ls %ls\n", os_info->sv101_name,
-                os_info->sv101_comment);
+        out << "\nMachine: " << os_info->sv101_name << " " <<  os_info->sv101_comment << "\n";
+


extra blank line, remove

mhdawson · 2017-01-30T22:50:25Z

src/node_report.cc

+      Message::PrintCurrentStackTrace(isolate, stack_fp);
+      std::fflush(stack_fp);
+      std::rewind(stack_fp);
+      while( std::fgets(stack_buf, sizeof(stack_buf), stack_fp) != nullptr ) {


extra spaces after while( and before closing )

mhdawson · 2017-01-30T22:52:06Z

src/node_report.cc

    }
    if (i > 0) {
-       fprintf(fp, ",");
+       out << ",";


I think there is an extra indent space

mhdawson · 2017-01-30T22:56:34Z

src/node_report.cc


  // Print NodeReport version
  // e.g. NodeReport version: 1.0.6 (built against Node.js v6.9.1)
-  fprintf(fp, "\nNodeReport version: %s (built against Node.js v%s)\n",
-          NODEREPORT_VERSION, NODE_VERSION_STRING);
+  out << "\nNodeReport version: " << NODEREPORT_VERSION << " (built against Node.js v" << NODE_VERSION_STRING << ")\n";


I'm guessing this line is now too long so we need some wrapping

mhdawson · 2017-01-30T22:58:31Z

src/node_report.cc

  } else {
    if (frame->IsConstructor()) {
-      fprintf(fp, "%s [constructor] (%s:%i:%i)\n", *fn_name_s, *script_name, line_number, column);
+      out  << *fn_name_s << " [constructor] (" << *script_name << ":" << line_number << ":" << column << ")\n";


Another long line, overall I think we need to go through an make sure we've not pushed lines over the limit, especially since we may turn on the linter soon.

mhdawson · 2017-01-30T23:01:06Z

src/node_report.cc

+      std::fflush(stack_fp);
+      std::rewind(stack_fp);
+      while( std::fgets(stack_buf, sizeof(stack_buf), stack_fp) != nullptr ) {
+        out << stack_buf;


It feels a bit painful to do this even in the case of when we are writing out to a file as it gets written to a file twice. Having said that I don't have a good idea for how to avoid and be able to easily switch the output of the stream.

This might be something to put on our todo list in terms of working with V8 to get an API that can be used without having to write to a file.

hhellyer · 2017-01-31T10:18:04Z

The format of the output for the handles section (and everything else) should be the same as before. The handles section has lost one flags column but that indicated if a flag was internal to libuv and we don't get those anymore so it would never bet set.

I kept the format the same as I was trying to do a simple like for like swap from fprintf to streams. For the record though I don't believe we are keeping the format tightly locked down - it's intended to be human readable and anyone parsing it with other scripts does so at their own peril. :-)

I agree that using a temporary file is messy, it's also a bit awkward that depending on the type of failure we use two different methods of obtaining a stack. Hopefully having a use case like node-report will let us push some improvements back into Node itself.

Regarding the code format changes, I'll fix anything this introduces but I tried various formatters on nodereport.cc and it's going to need a fair few changes when that's turned on anyway. An 80 character limit is going to mess up all the print statements that print 80 '=' characters as dividers. (We can fix that by having a constant or doing std::string(80, '=') and probably several other ways but that's a separate PR.)

I'll push a tidy up to the formatting issues a bit later on.

richardlau

Some questions.

richardlau · 2017-02-01T19:58:05Z

src/node_report.cc

+  char buf[64];
+
+  // List all the types so we get a compile warning if we've missed one,
+  // (using default: supresses the compiler warning.)


I don't see a default: in the switch statement.

I've listed all the types so I can ommit the default: statement. If a new type is added the compiler will warn it's not being handled rather than just let the default: swallow it.

richardlau · 2017-02-01T20:05:55Z

src/node_report.cc

+      }
+      // Calling close on a file from tmpfile *should* delete it.
+      std::fclose(stack_fp);
+    }


I suppose there's no fallback here if std::tmpfile() fails? Should we emit some sort of message, e.g. "Unable to obtain stack trace"?

richardlau · 2017-02-01T21:10:17Z

Also would be good to have tests and documentation.

hhellyer · 2017-02-02T15:09:52Z

I've pushed an update with tests and doc changed. I've ran it via citgm and verified the new test is running there too:
https://ci.nodejs.org/view/post-mortem/job/nodereport-continuous-integration/41/
( @mhdawson - citgm seems to be working nicely here.)

hhellyer · 2017-02-02T15:11:51Z

(Test file changes look better if we ignore whitespace: https://github.com/nodejs/node-report/pull/48/files?w=1 )

richardlau

LGTM

rnchamberlain · 2017-02-03T15:57:26Z

src/module.cc

+  std::ostringstream out;
+
+  GetNodeReport(isolate, kJavaScript, "JavaScript API", __func__, out);
+  // Return value is the NodeReport filename


This comment looks wrong, probably cut&pasted, the return value for this API is the report string

Good spot, I'll fix that.

rnchamberlain · 2017-02-03T16:37:13Z

src/node_report.cc


  HANDLE hProcess = GetCurrentProcess();
  SymSetOptions(SYMOPT_LOAD_LINES | SYMOPT_UNDNAME | SYMOPT_DEFERRED_LOADS);
  SymInitialize(hProcess, nullptr, TRUE);
+  char buf[64];


I wonder if 64 chars will always be enough for symbol+filename etc. Maybe we can afford to be more generous. The snprintf() will just truncate, so it's safe anyway.

That was a bug, buf was being filled and the output was being truncated on Windows.
I've re-written the block so only the "%2d: [pc=0x%p]" part is formatted to buf as that's the only part that required the format specifiers, the rest can be written with <<.

rnchamberlain · 2017-02-03T16:38:06Z

src/node_report.cc

  void* frames[256];
-  fprintf(fp, "\n================================================================================");
-  fprintf(fp, "\n==== Native Stack Trace ========================================================\n\n");
+  char buf[64];


On this path the buffer only ever has to hold the result of "%2d: [pc=0x%p]" which should fit into 64 characters.

mhdawson

LGTM once Richard C's comments are addressed.

richardlau

Still LGTM with some nits.

richardlau · 2017-02-06T20:02:42Z

src/node_report.cc

@@ -878,16 +878,12 @@ void PrintNativeStack(std::ostream& out) {
      DWORD dwOffset = 0;
      IMAGEHLP_LINE64 line;
      line.SizeOfStruct = sizeof(line);
+      snprintf(buf, sizeof(buf), "%2d: [pc=0x%p]", i, reinterpret_cast<void*>(pSymbol->Address));
+      out << buf << " " << pSymbol->Name << " [+";


I wonder if it's worth inserting a comment with sample output lines (one for each branch of the nested if statement) as it's now harder to tell what the output is supposed to look like as the formatting is split between the snprintf prior to the if statement and << statements both here and in the nested if statement.

richardlau · 2017-02-06T20:09:00Z

src/module.cc

@@ -78,7 +78,7 @@ NAN_METHOD(GetReport) {
  std::ostringstream out;

  GetNodeReport(isolate, kJavaScript, "JavaScript API", __func__, out);
-  // Return value is the NodeReport filename
+  // Return value is the contents of a NodeReport as a string.


Suggestion: Since this is a newly introduced line, replace "NodeReport" with "report" so it doesn't need to change again for #52.

If #52 is merged first I'll need to make changes here, if this one is merged first then the renaming one will need updates. I'll make sure it gets done at that point with everything else rather than do just one of the (many) changes I'll probably need to make ahead of time.

#52 has now been merged, please can you rebase and update accordingly?

richardlau · 2017-02-06T20:17:10Z

I'm 👍 to using C++ streams, but will ask the following question so that we've documented that we've considered it:

Since we have to write out a temporary file anyway and read it back in to get the stack traces, presumably there would have been much less code change if we were to simply write out the whole report to a temporary file and then read the report back in and return the contents?

richardlau · 2017-02-06T20:24:26Z

Also I don't think this has been noted previously but a nice side effect of this PR is that we now get a libuv handle summary on Windows. 🎉

hhellyer · 2017-02-07T09:45:26Z

Writing to a file and then reading back in is (frankly) a bit rubbish. It's something we are stuck with for the moment and will hopefully resolve. It's only used in one of the paths where we write a stack trace. (Having to use different methods depending on the state of v8 is also annoying.)

With the changes in this PR there are plenty of situations where we avoid writing a temporary file at all. Once this is merged I'm happy to raise an issue we can investigate removing (or improving) the call. v8.h already has a TODO to fix it:

  // TODO(1245381): Print to a string instead of on a FILE.
  static void PrintCurrentStackTrace(Isolate* isolate, FILE* out);

mhdawson

Still LGTM from me

These changes add a new function to the node-report API - getReport(). This returns the string contents of node report to the caller instead of writing it to a file and returning the file name. This makes it easier for other tools to build on node-report. To implement this I switched from using fprintf for output to C++ streams. This makes it trivial to switch between using a file stream or a string stream for output and the getReport path just passing a different stream object to the triggerReport path.

richardlau

Since #52 has landed, please can you rebase and update the documentation and comments accordingly?

Remove a couple of occurances of "NodeReport".

hhellyer · 2017-02-10T09:08:10Z

I had done the rebase (or just flattened it onto the new master) but I missed a couple of occurrences of "NodeReport". I've fixed those.

These changes add a new function to the node-report API - getReport(). This returns the string contents of node report to the caller instead of writing it to a file and returning the file name. This makes it easier for other tools to build on node-report. To implement this I switched from using fprintf for output to C++ streams. This makes it trivial to switch between using a file stream or a string stream for output and the getReport path just passing a different stream object to the triggerReport path. PR-URL: #48 Reviewed-By: Richard Chamberlain <richard_chamberlain@uk.ibm.com> Reviewed-By: Michael Dawson <michael_dawson@ca.ibm.com> Reviewed-By: Richard Lau <riclau@uk.ibm.com>

rnchamberlain · 2017-02-10T15:13:17Z

Landed as c3ee5a0

rnchamberlain · 2017-02-10T15:23:21Z

CI build/test, on Node v6: https://ci.nodejs.org/view/post-mortem/job/nodereport-continuous-integration/49/

mhdawson reviewed Jan 30, 2017

View reviewed changes

richardlau reviewed Feb 1, 2017

View reviewed changes

richardlau approved these changes Feb 2, 2017

View reviewed changes

rnchamberlain reviewed Feb 3, 2017

View reviewed changes

mhdawson approved these changes Feb 3, 2017

View reviewed changes

richardlau approved these changes Feb 6, 2017

View reviewed changes

mhdawson approved these changes Feb 7, 2017

View reviewed changes

hhellyer force-pushed the stream_output branch from 297b3e6 to dc461ad Compare February 9, 2017 14:25

rnchamberlain mentioned this pull request Feb 9, 2017

Error building nodereport #55

Closed

richardlau suggested changes Feb 9, 2017

View reviewed changes

Provide getReport API to return the contents of node-report.

da29b1e

Remove a couple of occurances of "NodeReport".

richardlau approved these changes Feb 10, 2017

View reviewed changes

rnchamberlain closed this Feb 10, 2017

This was referenced Feb 10, 2017

aix: improve readability of os version #57

Closed

test: fix test-api-getreport.js #58

Closed

Reporting of machine name broken on Windows #59

Closed

richardlau mentioned this pull request Mar 8, 2017

Additional information for libuv handles #73

Closed

hhellyer deleted the stream_output branch April 26, 2017 14:53

Provide getReport API to return the contents of node-report. #48

Provide getReport API to return the contents of node-report. #48

Conversation

hhellyer commented Jan 30, 2017

mhdawson left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

hhellyer commented Jan 31, 2017

richardlau left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

richardlau commented Feb 1, 2017

hhellyer commented Feb 2, 2017

hhellyer commented Feb 2, 2017

richardlau left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

mhdawson left a comment

Choose a reason for hiding this comment

richardlau left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

richardlau commented Feb 6, 2017

richardlau commented Feb 6, 2017

hhellyer commented Feb 7, 2017

mhdawson left a comment

Choose a reason for hiding this comment

richardlau left a comment

Choose a reason for hiding this comment

hhellyer commented Feb 10, 2017

rnchamberlain commented Feb 10, 2017

rnchamberlain commented Feb 10, 2017