From f268daf6368b7d7c9c0b5d06875a40ab3f5a42f2 Mon Sep 17 00:00:00 2001 From: Richard Chamberlain Date: Thu, 9 Jun 2016 11:12:27 +0100 Subject: [PATCH 1/2] src: diagnostic NodeReport initial implementation Implementation of a diagnostic report for Node, intended for devt, test and production use, to capture and preserve information for problem determination. The code sits behind a new option "--nodereport-events=" which enables selective triggering of the report on unhandled exceptions, fatal errors and signals. The report is not enabled by default. Content of the NodeReport in the initial implementation consists of a header section containing the event type, timestamp, PID and Node version, a section containing the Javascript stack trace, a section containing V8 heap information and an OS platform information section. Existing V8 APIs are used to obtain the stack trace and V8 heap information. There are changes in node.cc to handle the command-line option and report triggering, and new files containing the report writer and testcase. Candidates for additional content in the NodeReport include: native stack traces; detailed JS stacktraces with call parameters, stack locals/references and code; long stack traces; libuv information; OS and hypervisor information and levels; CPU usage; GC history; module-specific information (inserted in the report via callback). --- node.gyp | 1 + src/node.cc | 68 ++++++ src/node_report.cc | 346 +++++++++++++++++++++++++++++++ src/node_report.h | 19 ++ test/parallel/test-nodereport.js | 54 +++++ 5 files changed, 488 insertions(+) create mode 100644 src/node_report.cc create mode 100644 src/node_report.h create mode 100644 test/parallel/test-nodereport.js diff --git a/node.gyp b/node.gyp index 05a5530a2b148e..9d9301b6a868a6 100644 --- a/node.gyp +++ b/node.gyp @@ -139,6 +139,7 @@ 'src/node_main.cc', 'src/node_os.cc', 'src/node_revert.cc', + 'src/node_report.cc', 'src/node_util.cc', 'src/node_v8.cc', 'src/node_stat_watcher.cc', diff --git a/src/node.cc b/src/node.cc index 0cf16a12dff08f..7e53bde541feee 100644 --- a/src/node.cc +++ b/src/node.cc @@ -7,6 +7,7 @@ #include "node_version.h" #include "node_internals.h" #include "node_revert.h" +#include "node_report.h" #if defined HAVE_PERFCTR #include "node_counters.h" @@ -151,6 +152,8 @@ static node_module* modpending; static node_module* modlist_builtin; static node_module* modlist_linked; static node_module* modlist_addon; +static const char* nodereport_events = ""; +static int nodereport_signal = 0; #if defined(NODE_HAVE_I18N_SUPPORT) // Path to ICU data (for i18n / Intl) @@ -186,6 +189,7 @@ static v8::Platform* default_platform; #ifdef __POSIX__ static uv_sem_t debug_semaphore; +static uv_async_t nodereport_trigger_async; #endif static void PrintErrorString(const char* format, ...) { @@ -1596,6 +1600,11 @@ static void ReportException(Environment* env, } fflush(stderr); + + // Trigger NodeReport if required + if (strstr(nodereport_events,"exception")) { + TriggerNodeReport(env->isolate(), kException, "Uncaught exception", "node::ReportException", message); + } } @@ -2336,6 +2345,10 @@ static void OnFatalError(const char* location, const char* message) { } else { PrintErrorString("FATAL ERROR: %s\n", message); } + // Trigger NodeReport if required + if (strstr(nodereport_events,"fatalerror")) { + TriggerNodeReport(Isolate::GetCurrent(), kFatalError, message, location); + } fflush(stderr); ABORT(); } @@ -3226,6 +3239,35 @@ static void SignalExit(int signo) { raise(signo); } +#ifdef __POSIX__ +// Callbacks for triggering NodeReport on external signal - these run on the main event loop thread +static void SignalDumpInterruptCallback(Isolate *isolate, void *data) { + if (nodereport_signal != 0) { + TriggerNodeReport(Isolate::GetCurrent(), kSignal_JS, signo_string(*((int *)data)), "node::SignalDumpInterruptCallback()"); + nodereport_signal = 0; + } +} +static void SignalDumpAsyncCallback(uv_async_t* handle) { + if (nodereport_signal != 0) { + TriggerNodeReport(Isolate::GetCurrent(), kSignal_UV, signo_string((int)(size_t)handle->data), "node::SignalDumpAsyncCallback()"); + nodereport_signal = 0; + } +} + +// Raw signal handler for triggering a NodeReport - runs on an arbitrary thread +static void SignalDump(int signo) { + // Check atomic for NodeReport already pending + if (__sync_val_compare_and_swap(&nodereport_signal, 0, signo) == 0) { + fprintf(stderr,"Signal %s received, triggering NodeReport\n", signo_string(signo)); + Isolate::GetCurrent()->RequestInterrupt(SignalDumpInterruptCallback, &nodereport_signal); + // Event loop may be idle, so also request an async callback + nodereport_trigger_async.data = (void *)(size_t)signo; + uv_async_send(&nodereport_trigger_async); + } else { + fprintf(stderr,"Signal %s received, NodeReport pending\n", signo_string(signo)); + } +} +#endif // Most of the time, it's best to use `console.error` to write // to the process.stderr stream. However, in some cases, such as @@ -3246,6 +3288,11 @@ void LoadEnvironment(Environment* env) { env->isolate()->SetFatalErrorHandler(node::OnFatalError); env->isolate()->AddMessageListener(OnMessage); + // If NodeReport requested for exception events, tell V8 to capture stack traces + if (strstr(nodereport_events,"exception")) { + env->isolate()->SetCaptureStackTraceForUncaughtExceptions(true, 32, v8::StackTrace::kDetailed); + } + // Compile, execute the src/node.js file. (Which was included as static C // string in node_natives.h. 'native_node' is the string containing that // source code.) @@ -3408,6 +3455,12 @@ static void PrintHelp() { #endif " --preserve-symlinks preserve symbolic links when resolving\n" " and caching modules.\n" +#endif + " --nodereport-events= trigger NodeReport on specified events:\n" +#ifdef _WIN32 + " exception+fatalerror\n" +#else + " exception+fatalerror+sigusr2+sigquit\n" #endif "\n" "Environment variables:\n" @@ -3566,6 +3619,8 @@ static void ParseArgs(int* argc, } else if (strcmp(arg, "--expose-internals") == 0 || strcmp(arg, "--expose_internals") == 0) { // consumed in js + } else if (strncmp(arg, "--nodereport-events=", 20) == 0) { + nodereport_events = arg + 20; } else { // V8 option. Pass through as-is. new_v8_argv[new_v8_argc] = arg; @@ -4065,6 +4120,19 @@ void Init(int* argc, if (v8_is_profiling) { uv_loop_configure(uv_default_loop(), UV_LOOP_BLOCK_SIGNAL, SIGPROF); } + + // If NodeReport requested on user signal, initialise async handler + if (strstr(nodereport_events,"sig")) { + uv_async_init(uv_default_loop(), &nodereport_trigger_async, SignalDumpAsyncCallback); + uv_unref(reinterpret_cast(&nodereport_trigger_async)); + // Now register the external signal handlers, as requested + if (strstr(nodereport_events,"sigquit")) { + RegisterSignalHandler(SIGQUIT, SignalDump, false); + } + if (strstr(nodereport_events,"sigusr2")) { + RegisterSignalHandler(SIGUSR2, SignalDump, false); + } + } #endif #if defined(NODE_HAVE_I18N_SUPPORT) diff --git a/src/node_report.cc b/src/node_report.cc new file mode 100644 index 00000000000000..036a3c9cd415aa --- /dev/null +++ b/src/node_report.cc @@ -0,0 +1,346 @@ +#include "node_report.h" +#include "node.h" +#include "node_natives.h" +#include "node_version.h" +#include "v8.h" +#include "time.h" +#include "zlib.h" +#include "ares.h" + +#include +#include +#include +#if !defined(_MSC_VER) + #include +#endif +#ifdef _WIN32 + #include +#else + #include + #include + #include + #include +#endif + +namespace node { + +using v8::HandleScope; +using v8::HeapStatistics; +using v8::HeapSpaceStatistics; +using v8::Isolate; +using v8::Local; +using v8::Message; +using v8::Object; +using v8::String; +using v8::StackFrame; +using v8::StackTrace; +using v8::V8; + +static void PrintStackFromMessage(FILE* fd, Isolate* isolate, Local message_handle); +static void PrintStackFromStackTrace(FILE* fd, Isolate* isolate, DumpEvent event); +static void PrintStackFrame(FILE* fd, Isolate* isolate, Local frame, int index); +static void PrintGCStatistics(FILE *fd, Isolate* isolate); +static void PrintSystemInformation(FILE *fd, Isolate* isolate); +static void WriteIntegerWithCommas(FILE *fd, size_t value); + +static int seq = 0; // sequence number for NodeReport filenames +const char* v8_states[] = {"JS","GC","COMPILER","OTHER","EXTERNAL","IDLE"}; + +#ifdef __POSIX__ +static struct {const char* description; int id;} rlimit_strings[] = { + {"core file size (blocks) ", RLIMIT_CORE}, + {"data seg size (kbytes) ", RLIMIT_DATA}, + {"file size (blocks) ", RLIMIT_FSIZE}, + {"max locked memory (bytes) ", RLIMIT_MEMLOCK}, + {"max memory size (kbytes) ", RLIMIT_RSS}, + {"open files ", RLIMIT_NOFILE}, + {"stack size (bytes) ", RLIMIT_STACK}, + {"cpu time (seconds) ", RLIMIT_CPU}, + {"max user processes ", RLIMIT_NPROC}, + {"virtual memory (kbytes) ", RLIMIT_AS} +}; +#endif + +/* + * API to write a triage dump (NodeReport) to file + */ +void TriggerNodeReport(Isolate* isolate, DumpEvent event, const char *message, const char *location) { + TriggerNodeReport(isolate, event, message, location, Local()); +} + +/* + * API to write a triage dump (NodeReport) to file - with additional V8 Message supplied + */ +void TriggerNodeReport(Isolate* isolate, DumpEvent event, const char *message, const char *location, Local message_handle) { + + // Construct the NodeReport filename, with timestamp, pid and sequence number + char filename[48] = "NodeReport"; + seq++; // TODO: sequence number atomic? + +#ifdef _WIN32 + SYSTEMTIME tm_struct; + GetLocalTime(&tm_struct); + DWORD pid = GetCurrentProcessId(); + + sprintf(&filename[10], ".%4d%02d%02d.%02d%02d%02d.%d.%03d.txt", + tm_struct.wYear,tm_struct.wMonth,tm_struct.wDay,tm_struct.wHour,tm_struct.wMinute,tm_struct.wSecond,pid,seq); +#else // UNIX + struct timeval time_val; + struct tm *tm_struct; + gettimeofday(&time_val, NULL); + + pid_t pid = getpid(); + + tm_struct = localtime(&time_val.tv_sec); + sprintf(&filename[10],".%4d%02d%02d.%02d%02d%02d.%d.%03d.txt", + tm_struct->tm_year+1900,tm_struct->tm_mon+1,tm_struct->tm_mday,tm_struct->tm_hour,tm_struct->tm_min,tm_struct->tm_sec,pid,seq); +#endif + + // Open the NodeReport file for writing + FILE *fd = fopen(filename, "w"); + fprintf(stderr,"\nWriting Node.js error report to file: %s\n", filename); + + // Print NodeReport title and event information + fprintf(fd,"================================================================================\n"); + fprintf(fd,"==== NodeReport ================================================================\n"); + + fprintf(fd,"\nEvent: %s, location: \"%s\"\n", message, location); + fprintf(fd,"Filename: %s\n", filename); + + // Print dump event date/time stamp +#ifdef _WIN32 + fprintf(fd,"Event time: %4d/%02d/%02d %02d:%02d:%02d\n", + tm_struct.wYear,tm_struct.wMonth,tm_struct.wDay,tm_struct.wHour,tm_struct.wMinute,tm_struct.wSecond); +#else // UNIX + fprintf(fd,"Event time: %4d/%02d/%02d %02d:%02d:%02d\n", + tm_struct->tm_year+1900,tm_struct->tm_mon+1,tm_struct->tm_mday,tm_struct->tm_hour,tm_struct->tm_min,tm_struct->tm_sec); +#endif + + // Print native process ID + fprintf(fd,"Process ID: %d\n", pid); + + // Print Node.js and deps component versions + fprintf(fd,"\nNode.js version: %s\n", NODE_VERSION); + fprintf(fd,"(v8: %s, libuv: %s, zlib: %s, ares: %s)\n", V8::GetVersion(), uv_version_string(), ZLIB_VERSION, ARES_VERSION_STR); + + // Print summary Javascript stack trace + fprintf(fd,"\n================================================================================\n"); + fprintf(fd,"==== Javascript stack trace ====================================================\n\n"); + + switch(event) { + case kException: + // Print Javascript stack trace as stored in the V8 exception Message object. We need V8 to + // have saved the stack trace, see isolate->SetCaptureStackTraceForUncaughtExceptions(). + if (!message_handle.IsEmpty()) { + PrintStackFromMessage(fd, isolate, message_handle); + } + break; + case kFatalError: + // Print Javascript stack using the Message::PrintCurrentStackTrace() API + Message::PrintCurrentStackTrace(isolate, fd); + break; + case kSignal_JS: + case kSignal_UV: + // Print Javascript stack using the StackTrace::StackTrace() and GetStackSample() APIs + PrintStackFromStackTrace(fd, isolate, event); + break; + } // end switch(event) + + // Print V8 Heap and Garbage Collector information + PrintGCStatistics(fd, isolate); + + // Print operating system information + PrintSystemInformation(fd, isolate); + + // TODO: Obtain and print libuv information, e.g. uv_print_all_handles() + // TODO: Print native stack + // TODO: Obtain and print CPU time information e.g. getrusage(), and/or the new V8 CPU time APIs + + fprintf(fd,"\n================================================================================\n"); + fclose(fd); + fprintf(stderr,"Node.js error report completed\n"); +} + +/* + * Function to print stack trace contained in supplied V8 Message object. + */ +static void PrintStackFromMessage(FILE* fd, Isolate* isolate, Local message_handle) { + + Local message_string = message_handle->Get(); + node::Utf8Value message_utf8(isolate, message_string); + Localstack = message_handle->GetStackTrace(); + + if (stack.IsEmpty()) { + fprintf(fd,"\nNo stack trace available from V8 Message: %s\n", *message_utf8); + return; + } + fprintf(fd,"V8 Message: %s\n", *message_utf8); + for (int i = 0; i < stack->GetFrameCount(); i++) { + PrintStackFrame(fd, isolate, stack->GetFrame(i), i); + } +} + +/* + * Function to print stack trace the StackTrace::StackTrace() and GetStackSample() APIs + */ +static void PrintStackFromStackTrace(FILE* fd, Isolate* isolate, DumpEvent event) { + v8::RegisterState state; + v8::SampleInfo info; + void* sample[255]; + + // Initialise the register state + state.pc = NULL; + state.fp = &state; + state.sp = &state; + + isolate->GetStackSample(state, sample, 255, &info); + fprintf(fd,"Javascript VM state: %s\n\n", v8_states[info.vm_state]); + if (event == kSignal_UV) { + fprintf(fd,"Signal received when event loop idle, no stack trace available\n"); + return; + } + Local stack = StackTrace::CurrentStackTrace(isolate, 255, StackTrace::kDetailed); + if (stack.IsEmpty()) { + fprintf(fd,"\nNo stack trace available from StackTrace::CurrentStackTrace()\n"); + return; + } + // Print the stack trace, adding in the pc values from the GetStackSample() call + for (int i=0; i < stack->GetFrameCount(); i++) { + PrintStackFrame(fd, isolate, stack->GetFrame(i), i); + if ((size_t)i < info.frames_count) { + fprintf(fd," program counter: %p\n", sample[i]); + } + } +} + +/* + * Function to print a Javascript stack frame from a V8 StackFrame object + */ +static void PrintStackFrame(FILE* fd, Isolate* isolate, Local frame, int i) { + node::Utf8Value fn_name_s(isolate, frame->GetFunctionName()); + node::Utf8Value script_name(isolate, frame->GetScriptName()); + const int line_number = frame->GetLineNumber(); + const int column = frame->GetColumn(); + + if (frame->IsEval()) { + if (frame->GetScriptId() == Message::kNoScriptIdInfo) { + fprintf(fd, "at [eval]:%i:%i\n", line_number, column); + } else { + fprintf(fd,"at [eval] (%s:%i:%i)\n",*script_name, line_number, column); + } + return; + } + + if (fn_name_s.length() == 0) { + fprintf(fd, "%d: %s:%i:%i\n", i+1, *script_name, line_number, column); + } else { + if (frame->IsConstructor()) { + fprintf(fd, "%d: %s [constructor] (%s:%i:%i)\n", i+1, *fn_name_s, *script_name, line_number, column); + } else { + fprintf(fd, "%d: %s (%s:%i:%i)\n", i+1, *fn_name_s, *script_name, line_number, column); + } + } +} + +/* + * Function to print V8 Javascript heap information. + * + * This uses the existing V8 HeapStatistics and HeapSpaceStatistics APIs. The isolate->GetGCStatistics(&heap_stats) + * internal V8 API could potentially provide some more useful information - the GC history strings and the handle counts + */ +static void PrintGCStatistics(FILE *fd, Isolate* isolate) { + HeapStatistics v8_heap_stats; + isolate->GetHeapStatistics(&v8_heap_stats); + + fprintf(fd,"\n================================================================================"); + fprintf(fd,"\n==== Javascript Heap and Garbage Collector =====================================\n"); + HeapSpaceStatistics v8_heap_space_stats; + // Loop through heap spaces + for (size_t i = 0; i < isolate->NumberOfHeapSpaces(); i++) { + isolate->GetHeapSpaceStatistics(&v8_heap_space_stats, i); + fprintf(fd,"\nHeap space name: %s",v8_heap_space_stats.space_name()); + fprintf(fd,"\n Memory size: "); + WriteIntegerWithCommas(fd, v8_heap_space_stats.space_size()); + fprintf(fd," bytes, committed memory: "); + WriteIntegerWithCommas(fd, v8_heap_space_stats.physical_space_size()); + fprintf(fd," bytes\n Capacity: "); + WriteIntegerWithCommas(fd, v8_heap_space_stats.space_used_size() + v8_heap_space_stats.space_available_size()); + fprintf(fd," bytes, used: "); + WriteIntegerWithCommas(fd, v8_heap_space_stats.space_used_size()); + fprintf(fd," bytes, available: "); + WriteIntegerWithCommas(fd, v8_heap_space_stats.space_available_size()); + fprintf(fd," bytes"); + } + + fprintf(fd,"\n\nTotal heap memory size: "); + WriteIntegerWithCommas(fd, v8_heap_stats.total_heap_size()); + fprintf(fd," bytes\nTotal heap committed memory: "); + WriteIntegerWithCommas(fd, v8_heap_stats.total_physical_size()); + fprintf(fd," bytes\nTotal used heap memory: "); + WriteIntegerWithCommas(fd, v8_heap_stats.used_heap_size()); + fprintf(fd," bytes\nTotal available heap memory: "); + WriteIntegerWithCommas(fd, v8_heap_stats.total_available_size()); + fprintf(fd," bytes\n\nHeap memory limit: "); + WriteIntegerWithCommas(fd, v8_heap_stats.heap_size_limit()); + fprintf(fd,"\n"); +} + +/* + * Function to print operating system information (e.g ulimits on UNIX platforms). + */ +static void PrintSystemInformation(FILE *fd, Isolate* isolate) { + + fprintf(fd,"\n================================================================================"); + fprintf(fd,"\n==== System Information ========================================================\n"); + + fprintf(fd,"\nPlatform: %s\nArchitecture: %s\n", NODE_PLATFORM, NODE_ARCH); + +#ifdef __POSIX__ + fprintf(fd,"\nResource soft limit hard limit\n"); + struct rlimit limit; + + for (size_t i = 0 ; i < arraysize(rlimit_strings); i++ ) { + if (getrlimit(rlimit_strings[i].id,&limit) == 0) { + fprintf(fd,"%s ",rlimit_strings[i].description); + if (limit.rlim_cur == RLIM_INFINITY) { + fprintf(fd," unlimited"); + } else { + fprintf(fd,"%16" PRIu64, limit.rlim_cur); + } + if (limit.rlim_max == RLIM_INFINITY) { + fprintf(fd," unlimited\n"); + } else { + fprintf(fd,"%16" PRIu64 "\n", limit.rlim_max); + } + } + } +#endif +} + +/* + * Utility function to print out integer values with commas between every thousand for readability. + */ +static void WriteIntegerWithCommas(FILE *fd, size_t value) { + int thousandsStack[7]; /* log1000(2^64-1) = 6.42. We never need more than 7 frames */ + int stackTop = 0; + int i; + size_t workingValue = value; + + do { + thousandsStack[stackTop++] = workingValue % 1000; + workingValue /= 1000; + } while (workingValue != 0); + + for (i = stackTop-1; i>=0; i--) { + if (i == (stackTop -1)) { + fprintf(fd,"%u",thousandsStack[i]); + } else { + fprintf(fd,"%03u",thousandsStack[i]); + } + if (i > 0) { + fprintf(fd,","); + } + } +} + +} // namespace node diff --git a/src/node_report.h b/src/node_report.h new file mode 100644 index 00000000000000..5bcc7d4453e0f7 --- /dev/null +++ b/src/node_report.h @@ -0,0 +1,19 @@ +#ifndef SRC_NODE_REPORT_H_ +#define SRC_NODE_REPORT_H_ + +#include "node.h" + +namespace node { +using v8::Isolate; +using v8::Local; +using v8::Message; + +enum DumpEvent {kException, kFatalError, kSignal_JS, kSignal_UV}; + +void TriggerNodeReport(Isolate* isolate, DumpEvent event, const char *message, const char *location); + +void TriggerNodeReport(Isolate* isolate, DumpEvent event, const char *message, const char *location, Local message_handle); + +} // namespace node + +#endif // SRC_NODE_REVERT_H_ diff --git a/test/parallel/test-nodereport.js b/test/parallel/test-nodereport.js new file mode 100644 index 00000000000000..627fdb4eb02874 --- /dev/null +++ b/test/parallel/test-nodereport.js @@ -0,0 +1,54 @@ +'use strict'; + +const common = require('../common'); +const assert = require('assert'); +const spawn = require('child_process').spawn; +const path = require('path'); +const readline = require('readline'); +const fs = require('fs'); + +var validationCount = 0; +var errorScript = path.join(common.fixturesDir, 'throws_error.js'); + +// Run child process, expected to throw an error and generate a NodeReport +console.log('test-nodereport.js: running child process to create NodeReport'); +var child = spawn(process.execPath, + ['--nodereport-events=exception', errorScript], + {cwd: common.tmpDir}); + +child.on('exit', function(code, signal) { + assert.ok(code !== 0); + assert.strictEqual(signal, null); + + // Locate and validate the NodeReport + fs.readdir(common.tmpDir, function(err, files) { + for (var i = 0; i < files.length; i++) { + if (files[i].substring(0, 10) == 'NodeReport' && + files[i].substring(27, 31) == child.pid) { + + // Located NodeReport with expected PID + console.log('test-nodereport.js: located NodeReport: ', + path.join(common.tmpDir, files[i])); + const reader = readline.createInterface({ + input: fs.createReadStream(path.join(common.tmpDir, files[i])) + }); + reader.on('line', (line) => { + //console.log('Line from file:', line); + if ((line.indexOf('==== NodeReport') > -1) || + (line.indexOf('==== Javascript stack trace') > -1) || + (line.indexOf('==== Javascript Heap') > -1) || + (line.indexOf('==== System Information') > -1)) { + validationCount++; // found expected section in NodeReport + } + }); + fs.unlink(path.join(common.tmpDir, files[i])); + } + } + }); +}); + +process.on('exit', function() { + console.log('test-nodereport.js: validation count: ', + validationCount, ' (expected: 4)'); + assert.equal(4, validationCount); +}); From 5feaf8b6763527854f5c47fc220d63eb653af927 Mon Sep 17 00:00:00 2001 From: Richard Chamberlain Date: Thu, 16 Jun 2016 10:22:26 +0100 Subject: [PATCH 2/2] src: signal handler, option parsing and lint fixes Fixes for PR review comments: 1. Line length, whitespace, snprintf etc fixes for lint 2. Add .h file to node.gyp 3. Re-write signal handler to hand over to separate thread. The fix shares the debug watchdog thread code. Actually sharing a single watchdog thread would be problematic because on semaphore wake-up the watchdog would need to know which signal was sent, and to allow for a debug signal arriving while a nodereport was in progress. 4. Add a parser for the --nodereport-events option, remove the use of strstr(). 5. Naming and checking improvements suggested by Ben --- node.gyp | 1 + src/node.cc | 119 ++++++---- src/node_report.cc | 373 +++++++++++++++++++------------ src/node_report.h | 17 +- test/parallel/test-nodereport.js | 3 +- 5 files changed, 320 insertions(+), 193 deletions(-) diff --git a/node.gyp b/node.gyp index 9d9301b6a868a6..92748aec4f9518 100644 --- a/node.gyp +++ b/node.gyp @@ -180,6 +180,7 @@ 'src/node_watchdog.h', 'src/node_wrap.h', 'src/node_revert.h', + 'src/node_report.h', 'src/node_i18n.h', 'src/pipe_wrap.h', 'src/tty_wrap.h', diff --git a/src/node.cc b/src/node.cc index 7e53bde541feee..6c80352eff5808 100644 --- a/src/node.cc +++ b/src/node.cc @@ -152,7 +152,7 @@ static node_module* modpending; static node_module* modlist_builtin; static node_module* modlist_linked; static node_module* modlist_addon; -static const char* nodereport_events = ""; +static unsigned int nodereport_events = 0; static int nodereport_signal = 0; #if defined(NODE_HAVE_I18N_SUPPORT) @@ -189,6 +189,7 @@ static v8::Platform* default_platform; #ifdef __POSIX__ static uv_sem_t debug_semaphore; +static uv_sem_t report_semaphore; static uv_async_t nodereport_trigger_async; #endif @@ -1602,8 +1603,9 @@ static void ReportException(Environment* env, fflush(stderr); // Trigger NodeReport if required - if (strstr(nodereport_events,"exception")) { - TriggerNodeReport(env->isolate(), kException, "Uncaught exception", "node::ReportException", message); + if (nodereport_events & NR_EXCEPTION) { + TriggerNodeReport(env->isolate(), kException, + "Uncaught exception", "node::ReportException", message); } } @@ -2346,7 +2348,7 @@ static void OnFatalError(const char* location, const char* message) { PrintErrorString("FATAL ERROR: %s\n", message); } // Trigger NodeReport if required - if (strstr(nodereport_events,"fatalerror")) { + if (nodereport_events & NR_FATALERROR) { TriggerNodeReport(Isolate::GetCurrent(), kFatalError, message, location); } fflush(stderr); @@ -3240,33 +3242,53 @@ static void SignalExit(int signo) { } #ifdef __POSIX__ -// Callbacks for triggering NodeReport on external signal - these run on the main event loop thread +// Callbacks for triggering NodeReport on external signal, run on event loop static void SignalDumpInterruptCallback(Isolate *isolate, void *data) { if (nodereport_signal != 0) { - TriggerNodeReport(Isolate::GetCurrent(), kSignal_JS, signo_string(*((int *)data)), "node::SignalDumpInterruptCallback()"); + TriggerNodeReport(Isolate::GetCurrent(), kSignal_JS, + signo_string(*(static_cast(data))), + "node::SignalDumpInterruptCallback()"); nodereport_signal = 0; } } static void SignalDumpAsyncCallback(uv_async_t* handle) { if (nodereport_signal != 0) { - TriggerNodeReport(Isolate::GetCurrent(), kSignal_UV, signo_string((int)(size_t)handle->data), "node::SignalDumpAsyncCallback()"); + size_t signo_data = reinterpret_cast(handle->data); + TriggerNodeReport(Isolate::GetCurrent(), kSignal_UV, + signo_string(static_cast(signo_data)), + "node::SignalDumpAsyncCallback()"); nodereport_signal = 0; } } // Raw signal handler for triggering a NodeReport - runs on an arbitrary thread static void SignalDump(int signo) { - // Check atomic for NodeReport already pending + // Check atomic for NodeReport already pending, storing the signal number if (__sync_val_compare_and_swap(&nodereport_signal, 0, signo) == 0) { - fprintf(stderr,"Signal %s received, triggering NodeReport\n", signo_string(signo)); - Isolate::GetCurrent()->RequestInterrupt(SignalDumpInterruptCallback, &nodereport_signal); - // Event loop may be idle, so also request an async callback - nodereport_trigger_async.data = (void *)(size_t)signo; - uv_async_send(&nodereport_trigger_async); - } else { - fprintf(stderr,"Signal %s received, NodeReport pending\n", signo_string(signo)); + uv_sem_post(&report_semaphore); // Hand-off to watchdog thread } } + +// Watchdog thread implementation for signal-triggered NodeReport +inline void* ReportSignalThreadMain(void* unused) { + for (;;) { + uv_sem_wait(&report_semaphore); + fprintf(stderr, "Signal %s received, triggering NodeReport\n", + signo_string(nodereport_signal)); + uv_mutex_lock(&node_isolate_mutex); + if (auto isolate = node_isolate) { + // Request interrupt callback for running Javascript code + isolate->RequestInterrupt(SignalDumpInterruptCallback, + &nodereport_signal); + // Event loop may be idle, so also request an async callback + size_t signo_data = static_cast(nodereport_signal); + nodereport_trigger_async.data = reinterpret_cast(signo_data); + uv_async_send(&nodereport_trigger_async); + } + uv_mutex_unlock(&node_isolate_mutex); + } + return nullptr; +} #endif // Most of the time, it's best to use `console.error` to write @@ -3288,9 +3310,10 @@ void LoadEnvironment(Environment* env) { env->isolate()->SetFatalErrorHandler(node::OnFatalError); env->isolate()->AddMessageListener(OnMessage); - // If NodeReport requested for exception events, tell V8 to capture stack traces - if (strstr(nodereport_events,"exception")) { - env->isolate()->SetCaptureStackTraceForUncaughtExceptions(true, 32, v8::StackTrace::kDetailed); + // If NodeReport requested for exceptions, tell V8 to capture stack trace + if (nodereport_events & NR_EXCEPTION) { + env->isolate()->SetCaptureStackTraceForUncaughtExceptions(true, 32, + v8::StackTrace::kDetailed); } // Compile, execute the src/node.js file. (Which was included as static C @@ -3620,7 +3643,8 @@ static void ParseArgs(int* argc, strcmp(arg, "--expose_internals") == 0) { // consumed in js } else if (strncmp(arg, "--nodereport-events=", 20) == 0) { - nodereport_events = arg + 20; + const char* events = arg + 20; + nodereport_events = ProcessNodeReportArgs(events); } else { // V8 option. Pass through as-is. new_v8_argv[new_v8_argc] = arg; @@ -3800,12 +3824,7 @@ inline void* DebugSignalThreadMain(void* unused) { return nullptr; } - -static int RegisterDebugSignalHandler() { - // Start a watchdog thread for calling v8::Debug::DebugBreak() because - // it's not safe to call directly from the signal handler, it can - // deadlock with the thread it interrupts. - CHECK_EQ(0, uv_sem_init(&debug_semaphore, 0)); +static int StartWatchdogThread(void *(*thread_main) (void* unused)) { pthread_attr_t attr; CHECK_EQ(0, pthread_attr_init(&attr)); // Don't shrink the thread's stack on FreeBSD. Said platform decided to @@ -3820,23 +3839,33 @@ static int RegisterDebugSignalHandler() { CHECK_EQ(0, pthread_sigmask(SIG_SETMASK, &sigmask, &sigmask)); pthread_t thread; const int err = - pthread_create(&thread, &attr, DebugSignalThreadMain, nullptr); + pthread_create(&thread, &attr, thread_main, nullptr); CHECK_EQ(0, pthread_sigmask(SIG_SETMASK, &sigmask, nullptr)); CHECK_EQ(0, pthread_attr_destroy(&attr)); if (err != 0) { fprintf(stderr, "node[%d]: pthread_create: %s\n", getpid(), strerror(err)); fflush(stderr); - // Leave SIGUSR1 blocked. We don't install a signal handler, - // receiving the signal would terminate the process. return -err; } - RegisterSignalHandler(SIGUSR1, EnableDebugSignalHandler); - // Unblock SIGUSR1. A pending SIGUSR1 signal will now be delivered. - sigemptyset(&sigmask); - sigaddset(&sigmask, SIGUSR1); - CHECK_EQ(0, pthread_sigmask(SIG_UNBLOCK, &sigmask, nullptr)); return 0; } + +static int RegisterDebugSignalHandler() { + // Start a watchdog thread for calling v8::Debug::DebugBreak() because + // it's not safe to call directly from the signal handler, it can + // deadlock with the thread it interrupts. + CHECK_EQ(0, uv_sem_init(&debug_semaphore, 0)); + const int err = StartWatchdogThread(DebugSignalThreadMain); + if (err == 0) { + RegisterSignalHandler(SIGUSR1, EnableDebugSignalHandler); + // Unblock SIGUSR1. A pending SIGUSR1 signal will now be delivered. + sigset_t sigmask; + sigemptyset(&sigmask); + sigaddset(&sigmask, SIGUSR1); + CHECK_EQ(0, pthread_sigmask(SIG_UNBLOCK, &sigmask, nullptr)); + } + return err; +} #endif // __POSIX__ @@ -4121,16 +4150,20 @@ void Init(int* argc, uv_loop_configure(uv_default_loop(), UV_LOOP_BLOCK_SIGNAL, SIGPROF); } - // If NodeReport requested on user signal, initialise async handler - if (strstr(nodereport_events,"sig")) { - uv_async_init(uv_default_loop(), &nodereport_trigger_async, SignalDumpAsyncCallback); - uv_unref(reinterpret_cast(&nodereport_trigger_async)); - // Now register the external signal handlers, as requested - if (strstr(nodereport_events,"sigquit")) { - RegisterSignalHandler(SIGQUIT, SignalDump, false); - } - if (strstr(nodereport_events,"sigusr2")) { - RegisterSignalHandler(SIGUSR2, SignalDump, false); + // Setup for NodeReport requested on external user signal + if (nodereport_events & NR_SIGQUIT || nodereport_events & NR_SIGUSR2) { + CHECK_EQ(0, uv_sem_init(&report_semaphore, 0)); + if (StartWatchdogThread(ReportSignalThreadMain) == 0) { + uv_async_init(uv_default_loop(), &nodereport_trigger_async, + SignalDumpAsyncCallback); + uv_unref(reinterpret_cast(&nodereport_trigger_async)); + // Now register the external signal handlers, as requested + if (nodereport_events & NR_SIGQUIT) { + RegisterSignalHandler(SIGQUIT, SignalDump, false); + } + if (nodereport_events & NR_SIGUSR2) { + RegisterSignalHandler(SIGUSR2, SignalDump, false); + } } } #endif diff --git a/src/node_report.cc b/src/node_report.cc index 036a3c9cd415aa..c8a40696d4eb78 100644 --- a/src/node_report.cc +++ b/src/node_report.cc @@ -10,44 +10,53 @@ #include #include #include + #if !defined(_MSC_VER) - #include +#include #endif + #ifdef _WIN32 - #include +#include #else - #include - #include - #include - #include +#include +#include +#include +#include #endif namespace node { -using v8::HandleScope; -using v8::HeapStatistics; using v8::HeapSpaceStatistics; +using v8::HeapStatistics; using v8::Isolate; using v8::Local; using v8::Message; -using v8::Object; -using v8::String; using v8::StackFrame; using v8::StackTrace; -using v8::V8; +using v8::String; -static void PrintStackFromMessage(FILE* fd, Isolate* isolate, Local message_handle); -static void PrintStackFromStackTrace(FILE* fd, Isolate* isolate, DumpEvent event); -static void PrintStackFrame(FILE* fd, Isolate* isolate, Local frame, int index); -static void PrintGCStatistics(FILE *fd, Isolate* isolate); -static void PrintSystemInformation(FILE *fd, Isolate* isolate); -static void WriteIntegerWithCommas(FILE *fd, size_t value); +using v8::V8; -static int seq = 0; // sequence number for NodeReport filenames -const char* v8_states[] = {"JS","GC","COMPILER","OTHER","EXTERNAL","IDLE"}; +static void PrintStackFromMessage(FILE* fp, Isolate* isolate, + Local message_handle); +static void PrintStackFromStackTrace(FILE* fp, Isolate* isolate, + DumpEvent event); +static void PrintStackFrame(FILE* fp, Isolate* isolate, + Local frame, int index); +static void PrintGCStatistics(FILE *fp, Isolate* isolate); +static void PrintSystemInformation(FILE *fp, Isolate* isolate); +static void WriteIntegerWithCommas(FILE *fp, size_t value); + +static int seq = 0; // sequence number for NodeReport filenames +const char* v8_states[] = { + "JS", "GC", "COMPILER", "OTHER", "EXTERNAL", "IDLE" +}; #ifdef __POSIX__ -static struct {const char* description; int id;} rlimit_strings[] = { +static struct { + const char* description; + int id; +} rlimit_strings[] = { {"core file size (blocks) ", RLIMIT_CORE}, {"data seg size (kbytes) ", RLIMIT_DATA}, {"file size (blocks) ", RLIMIT_FSIZE}, @@ -62,153 +71,216 @@ static struct {const char* description; int id;} rlimit_strings[] = { #endif /* - * API to write a triage dump (NodeReport) to file + * Function to process the --nodereport-events option. */ -void TriggerNodeReport(Isolate* isolate, DumpEvent event, const char *message, const char *location) { - TriggerNodeReport(isolate, event, message, location, Local()); +unsigned int ProcessNodeReportArgs(const char *args) { + if (strlen(args) == 0) { + fprintf(stderr, "Missing argument for --nodereport-events option\n"); + return 0; + } + // Parse the supplied event types + unsigned int event_flags = 0; + const char* cursor = args; + while (*cursor != '\0') { + if (!strncmp(cursor, "exception", sizeof("exception") - 1)) { + event_flags |= NR_EXCEPTION; + cursor += sizeof("exception") - 1; + } else if (!strncmp(cursor, "fatalerror", sizeof("fatalerror") - 1)) { + event_flags |= NR_FATALERROR; + cursor += sizeof("fatalerror") - 1; + } else if (!strncmp(cursor, "sigusr2", sizeof("sigusr2") - 1)) { + event_flags |= NR_SIGUSR2; + cursor += sizeof("sigusr2") - 1; + } else if (!strncmp(cursor, "sigquit", sizeof("sigquit") - 1)) { + event_flags |= NR_SIGQUIT; + cursor += sizeof("sigquit") - 1; + } else { + fprintf(stderr, + "Unrecognised argument for --nodereport-events option: %s\n", cursor); + return 0; + } + if (*cursor == '+') { + cursor++; // Hop over the '+' separator + } + } + return event_flags; } /* - * API to write a triage dump (NodeReport) to file - with additional V8 Message supplied + * API to write a NodeReport to file */ -void TriggerNodeReport(Isolate* isolate, DumpEvent event, const char *message, const char *location, Local message_handle) { +void TriggerNodeReport(Isolate* isolate, DumpEvent event, + const char *message, const char *location) { + TriggerNodeReport(isolate, event, message, location, Local()); +} +/* + * API to write a NodeReport to file - with additional V8 Message supplied + */ +void TriggerNodeReport(Isolate* isolate, DumpEvent event, + const char *message, const char *location, + Local message_handle) { // Construct the NodeReport filename, with timestamp, pid and sequence number char filename[48] = "NodeReport"; - seq++; // TODO: sequence number atomic? + seq++; #ifdef _WIN32 SYSTEMTIME tm_struct; GetLocalTime(&tm_struct); DWORD pid = GetCurrentProcessId(); - sprintf(&filename[10], ".%4d%02d%02d.%02d%02d%02d.%d.%03d.txt", - tm_struct.wYear,tm_struct.wMonth,tm_struct.wDay,tm_struct.wHour,tm_struct.wMinute,tm_struct.wSecond,pid,seq); -#else // UNIX + snprintf(&filename[strlen(filename)], sizeof(filename) - strlen(filename), + ".%4d%02d%02d.%02d%02d%02d.%d.%03d.txt", + tm_struct.wYear, tm_struct.wMonth, tm_struct.wDay, + tm_struct.wHour, tm_struct.wMinute, tm_struct.wSecond, + pid, seq); +#else // UNIX, OSX struct timeval time_val; - struct tm *tm_struct; + struct tm tm_struct; gettimeofday(&time_val, NULL); pid_t pid = getpid(); - tm_struct = localtime(&time_val.tv_sec); - sprintf(&filename[10],".%4d%02d%02d.%02d%02d%02d.%d.%03d.txt", - tm_struct->tm_year+1900,tm_struct->tm_mon+1,tm_struct->tm_mday,tm_struct->tm_hour,tm_struct->tm_min,tm_struct->tm_sec,pid,seq); + localtime_r(&time_val.tv_sec, &tm_struct); + snprintf(&filename[strlen(filename)], sizeof(filename) - strlen(filename), + ".%4d%02d%02d.%02d%02d%02d.%d.%03d.txt", + tm_struct.tm_year+1900, tm_struct.tm_mon+1, tm_struct.tm_mday, + tm_struct.tm_hour, tm_struct.tm_min, tm_struct.tm_sec, + pid, seq); #endif // Open the NodeReport file for writing - FILE *fd = fopen(filename, "w"); - fprintf(stderr,"\nWriting Node.js error report to file: %s\n", filename); + FILE *fp = fopen(filename, "w"); + if (fp == NULL) { + fprintf(stderr, "\nFailed to open Node.js report file: %s (errno: %d)\n", + filename, errno); + return; + } else { + fprintf(stderr, "\nWriting Node.js report to file: %s\n", filename); + } // Print NodeReport title and event information - fprintf(fd,"================================================================================\n"); - fprintf(fd,"==== NodeReport ================================================================\n"); + fprintf(fp, + "========================================================================" + "\n" + "==== NodeReport ========================================================" + "\n"); - fprintf(fd,"\nEvent: %s, location: \"%s\"\n", message, location); - fprintf(fd,"Filename: %s\n", filename); + fprintf(fp, "\nEvent: %s, location: \"%s\"\n", message, location); + fprintf(fp, "Filename: %s\n", filename); // Print dump event date/time stamp #ifdef _WIN32 - fprintf(fd,"Event time: %4d/%02d/%02d %02d:%02d:%02d\n", - tm_struct.wYear,tm_struct.wMonth,tm_struct.wDay,tm_struct.wHour,tm_struct.wMinute,tm_struct.wSecond); -#else // UNIX - fprintf(fd,"Event time: %4d/%02d/%02d %02d:%02d:%02d\n", - tm_struct->tm_year+1900,tm_struct->tm_mon+1,tm_struct->tm_mday,tm_struct->tm_hour,tm_struct->tm_min,tm_struct->tm_sec); + fprintf(fp, "Event time: %4d/%02d/%02d %02d:%02d:%02d\n", + tm_struct.wYear, tm_struct.wMonth, tm_struct.wDay, + tm_struct.wHour, tm_struct.wMinute, tm_struct.wSecond); +#else // UNIX, OSX + fprintf(fp, "Event time: %4d/%02d/%02d %02d:%02d:%02d\n", + tm_struct.tm_year+1900, tm_struct.tm_mon+1, tm_struct.tm_mday, + tm_struct.tm_hour, tm_struct.tm_min, tm_struct.tm_sec); #endif // Print native process ID - fprintf(fd,"Process ID: %d\n", pid); + fprintf(fp, "Process ID: %d\n", pid); // Print Node.js and deps component versions - fprintf(fd,"\nNode.js version: %s\n", NODE_VERSION); - fprintf(fd,"(v8: %s, libuv: %s, zlib: %s, ares: %s)\n", V8::GetVersion(), uv_version_string(), ZLIB_VERSION, ARES_VERSION_STR); + fprintf(fp, "\nNode.js version: %s\n", NODE_VERSION); + fprintf(fp, "(v8: %s, libuv: %s, zlib: %s, ares: %s)\n", + V8::GetVersion(), uv_version_string(), ZLIB_VERSION, ARES_VERSION_STR); // Print summary Javascript stack trace - fprintf(fd,"\n================================================================================\n"); - fprintf(fd,"==== Javascript stack trace ====================================================\n\n"); + fprintf(fp, "\n" + "========================================================================" + "\n" + "==== Javascript stack trace ============================================" + "\n\n"); - switch(event) { + switch (event) { case kException: - // Print Javascript stack trace as stored in the V8 exception Message object. We need V8 to - // have saved the stack trace, see isolate->SetCaptureStackTraceForUncaughtExceptions(). + // Print the stack as stored in the V8 exception Message object. Note we + // need to have called isolate->SetCaptureStackTraceForUncaughtExceptions() if (!message_handle.IsEmpty()) { - PrintStackFromMessage(fd, isolate, message_handle); + PrintStackFromMessage(fp, isolate, message_handle); } break; case kFatalError: - // Print Javascript stack using the Message::PrintCurrentStackTrace() API - Message::PrintCurrentStackTrace(isolate, fd); + // Print the stack using Message::PrintCurrentStackTrace() API + Message::PrintCurrentStackTrace(isolate, fp); break; case kSignal_JS: case kSignal_UV: - // Print Javascript stack using the StackTrace::StackTrace() and GetStackSample() APIs - PrintStackFromStackTrace(fd, isolate, event); + // Print the stack using StackTrace::StackTrace() and GetStackSample() APIs + PrintStackFromStackTrace(fp, isolate, event); break; - } // end switch(event) + } // end switch(event) // Print V8 Heap and Garbage Collector information - PrintGCStatistics(fd, isolate); - - // Print operating system information - PrintSystemInformation(fd, isolate); + PrintGCStatistics(fp, isolate); - // TODO: Obtain and print libuv information, e.g. uv_print_all_handles() - // TODO: Print native stack - // TODO: Obtain and print CPU time information e.g. getrusage(), and/or the new V8 CPU time APIs + // Print operating system information + PrintSystemInformation(fp, isolate); - fprintf(fd,"\n================================================================================\n"); - fclose(fd); - fprintf(stderr,"Node.js error report completed\n"); + fprintf(fp, "\n" + "========================================================================" + "\n"); + fclose(fp); + fprintf(stderr, "Node.js report completed\n"); } /* * Function to print stack trace contained in supplied V8 Message object. */ -static void PrintStackFromMessage(FILE* fd, Isolate* isolate, Local message_handle) { - +static void PrintStackFromMessage(FILE* fp, Isolate* isolate, + Local message_handle) { Local message_string = message_handle->Get(); node::Utf8Value message_utf8(isolate, message_string); Localstack = message_handle->GetStackTrace(); if (stack.IsEmpty()) { - fprintf(fd,"\nNo stack trace available from V8 Message: %s\n", *message_utf8); + fprintf(fp, "\nNo stack trace available from V8 Message: %s\n", + *message_utf8); return; } - fprintf(fd,"V8 Message: %s\n", *message_utf8); + fprintf(fp, "V8 Message: %s\n", *message_utf8); for (int i = 0; i < stack->GetFrameCount(); i++) { - PrintStackFrame(fd, isolate, stack->GetFrame(i), i); + PrintStackFrame(fp, isolate, stack->GetFrame(i), i); } } /* - * Function to print stack trace the StackTrace::StackTrace() and GetStackSample() APIs + * Function to print stack using StackTrace::StackTrace() and GetStackSample() */ -static void PrintStackFromStackTrace(FILE* fd, Isolate* isolate, DumpEvent event) { +static void PrintStackFromStackTrace(FILE* fp, Isolate* isolate, + DumpEvent event) { v8::RegisterState state; v8::SampleInfo info; - void* sample[255]; + void* samples[255]; // Initialise the register state state.pc = NULL; state.fp = &state; state.sp = &state; - isolate->GetStackSample(state, sample, 255, &info); - fprintf(fd,"Javascript VM state: %s\n\n", v8_states[info.vm_state]); + isolate->GetStackSample(state, samples, arraysize(samples), &info); + CHECK(static_cast(info.vm_state) < arraysize(v8_states)); + fprintf(fp, "Javascript VM state: %s\n\n", v8_states[info.vm_state]); if (event == kSignal_UV) { - fprintf(fd,"Signal received when event loop idle, no stack trace available\n"); + fprintf(fp, + "Signal received when event loop idle, no stack trace available\n"); return; } - Local stack = StackTrace::CurrentStackTrace(isolate, 255, StackTrace::kDetailed); + Local stack = StackTrace::CurrentStackTrace(isolate, 255, + StackTrace::kDetailed); if (stack.IsEmpty()) { - fprintf(fd,"\nNo stack trace available from StackTrace::CurrentStackTrace()\n"); + fprintf(fp, + "\nNo stack trace available from StackTrace::CurrentStackTrace()\n"); return; } - // Print the stack trace, adding in the pc values from the GetStackSample() call - for (int i=0; i < stack->GetFrameCount(); i++) { - PrintStackFrame(fd, isolate, stack->GetFrame(i), i); + // Print the stack trace, adding in the pc values from GetStackSample() + for (int i = 0; i < stack->GetFrameCount(); i++) { + PrintStackFrame(fp, isolate, stack->GetFrame(i), i); if ((size_t)i < info.frames_count) { - fprintf(fd," program counter: %p\n", sample[i]); + fprintf(fp, " program counter: %p\n", samples[i]); } } } @@ -216,7 +288,8 @@ static void PrintStackFromStackTrace(FILE* fd, Isolate* isolate, DumpEvent event /* * Function to print a Javascript stack frame from a V8 StackFrame object */ -static void PrintStackFrame(FILE* fd, Isolate* isolate, Local frame, int i) { +static void PrintStackFrame(FILE* fp, Isolate* isolate, + Local frame, int i) { node::Utf8Value fn_name_s(isolate, frame->GetFunctionName()); node::Utf8Value script_name(isolate, frame->GetScriptName()); const int line_number = frame->GetLineNumber(); @@ -224,20 +297,22 @@ static void PrintStackFrame(FILE* fd, Isolate* isolate, Local frame, if (frame->IsEval()) { if (frame->GetScriptId() == Message::kNoScriptIdInfo) { - fprintf(fd, "at [eval]:%i:%i\n", line_number, column); + fprintf(fp, "at [eval]:%i:%i\n", line_number, column); } else { - fprintf(fd,"at [eval] (%s:%i:%i)\n",*script_name, line_number, column); + fprintf(fp, "at [eval] (%s:%i:%i)\n", *script_name, line_number, column); } return; } if (fn_name_s.length() == 0) { - fprintf(fd, "%d: %s:%i:%i\n", i+1, *script_name, line_number, column); + fprintf(fp, "%d: %s:%i:%i\n", i+1, *script_name, line_number, column); } else { if (frame->IsConstructor()) { - fprintf(fd, "%d: %s [constructor] (%s:%i:%i)\n", i+1, *fn_name_s, *script_name, line_number, column); + fprintf(fp, "%d: %s [constructor] (%s:%i:%i)\n", i+1, + *fn_name_s, *script_name, line_number, column); } else { - fprintf(fd, "%d: %s (%s:%i:%i)\n", i+1, *fn_name_s, *script_name, line_number, column); + fprintf(fp, "%d: %s (%s:%i:%i)\n", i+1, + *fn_name_s, *script_name, line_number, column); } } } @@ -245,83 +320,91 @@ static void PrintStackFrame(FILE* fd, Isolate* isolate, Local frame, /* * Function to print V8 Javascript heap information. * - * This uses the existing V8 HeapStatistics and HeapSpaceStatistics APIs. The isolate->GetGCStatistics(&heap_stats) - * internal V8 API could potentially provide some more useful information - the GC history strings and the handle counts + * This uses the existing V8 HeapStatistics and HeapSpaceStatistics APIs. + * The isolate->GetGCStatistics(&heap_stats) internal V8 API could potentially + * provide some more useful information - the GC history and the handle counts */ -static void PrintGCStatistics(FILE *fd, Isolate* isolate) { +static void PrintGCStatistics(FILE *fp, Isolate* isolate) { HeapStatistics v8_heap_stats; isolate->GetHeapStatistics(&v8_heap_stats); - fprintf(fd,"\n================================================================================"); - fprintf(fd,"\n==== Javascript Heap and Garbage Collector =====================================\n"); + fprintf(fp, "\n" + "========================================================================" + "\n" + "==== Javascript Heap and Garbage Collector =============================" + "\n"); HeapSpaceStatistics v8_heap_space_stats; // Loop through heap spaces for (size_t i = 0; i < isolate->NumberOfHeapSpaces(); i++) { isolate->GetHeapSpaceStatistics(&v8_heap_space_stats, i); - fprintf(fd,"\nHeap space name: %s",v8_heap_space_stats.space_name()); - fprintf(fd,"\n Memory size: "); - WriteIntegerWithCommas(fd, v8_heap_space_stats.space_size()); - fprintf(fd," bytes, committed memory: "); - WriteIntegerWithCommas(fd, v8_heap_space_stats.physical_space_size()); - fprintf(fd," bytes\n Capacity: "); - WriteIntegerWithCommas(fd, v8_heap_space_stats.space_used_size() + v8_heap_space_stats.space_available_size()); - fprintf(fd," bytes, used: "); - WriteIntegerWithCommas(fd, v8_heap_space_stats.space_used_size()); - fprintf(fd," bytes, available: "); - WriteIntegerWithCommas(fd, v8_heap_space_stats.space_available_size()); - fprintf(fd," bytes"); + fprintf(fp, "\nHeap space name: %s", v8_heap_space_stats.space_name()); + fprintf(fp, "\n Memory size: "); + WriteIntegerWithCommas(fp, v8_heap_space_stats.space_size()); + fprintf(fp, " bytes, committed memory: "); + WriteIntegerWithCommas(fp, v8_heap_space_stats.physical_space_size()); + fprintf(fp, " bytes\n Capacity: "); + WriteIntegerWithCommas(fp, v8_heap_space_stats.space_used_size() + + v8_heap_space_stats.space_available_size()); + fprintf(fp, " bytes, used: "); + WriteIntegerWithCommas(fp, v8_heap_space_stats.space_used_size()); + fprintf(fp, " bytes, available: "); + WriteIntegerWithCommas(fp, v8_heap_space_stats.space_available_size()); + fprintf(fp, " bytes"); } - fprintf(fd,"\n\nTotal heap memory size: "); - WriteIntegerWithCommas(fd, v8_heap_stats.total_heap_size()); - fprintf(fd," bytes\nTotal heap committed memory: "); - WriteIntegerWithCommas(fd, v8_heap_stats.total_physical_size()); - fprintf(fd," bytes\nTotal used heap memory: "); - WriteIntegerWithCommas(fd, v8_heap_stats.used_heap_size()); - fprintf(fd," bytes\nTotal available heap memory: "); - WriteIntegerWithCommas(fd, v8_heap_stats.total_available_size()); - fprintf(fd," bytes\n\nHeap memory limit: "); - WriteIntegerWithCommas(fd, v8_heap_stats.heap_size_limit()); - fprintf(fd,"\n"); + fprintf(fp, "\n\nTotal heap memory size: "); + WriteIntegerWithCommas(fp, v8_heap_stats.total_heap_size()); + fprintf(fp, " bytes\nTotal heap committed memory: "); + WriteIntegerWithCommas(fp, v8_heap_stats.total_physical_size()); + fprintf(fp, " bytes\nTotal used heap memory: "); + WriteIntegerWithCommas(fp, v8_heap_stats.used_heap_size()); + fprintf(fp, " bytes\nTotal available heap memory: "); + WriteIntegerWithCommas(fp, v8_heap_stats.total_available_size()); + fprintf(fp, " bytes\n\nHeap memory limit: "); + WriteIntegerWithCommas(fp, v8_heap_stats.heap_size_limit()); + fprintf(fp, "\n"); } /* - * Function to print operating system information (e.g ulimits on UNIX platforms). + * Function to print operating system information. */ -static void PrintSystemInformation(FILE *fd, Isolate* isolate) { - - fprintf(fd,"\n================================================================================"); - fprintf(fd,"\n==== System Information ========================================================\n"); - - fprintf(fd,"\nPlatform: %s\nArchitecture: %s\n", NODE_PLATFORM, NODE_ARCH); +static void PrintSystemInformation(FILE *fp, Isolate* isolate) { + fprintf(fp, "\n" + "========================================================================" + "\n"); + fprintf(fp, + "==== System Information ================================================" + "\n"); + fprintf(fp, "\nPlatform: %s\nArchitecture: %s\n", NODE_PLATFORM, NODE_ARCH); #ifdef __POSIX__ - fprintf(fd,"\nResource soft limit hard limit\n"); + fprintf(fp, + "\nResource soft limit hard limit\n"); struct rlimit limit; - - for (size_t i = 0 ; i < arraysize(rlimit_strings); i++ ) { - if (getrlimit(rlimit_strings[i].id,&limit) == 0) { - fprintf(fd,"%s ",rlimit_strings[i].description); + + for (size_t i = 0; i < arraysize(rlimit_strings); i++) { + if (getrlimit(rlimit_strings[i].id, &limit) == 0) { + fprintf(fp, "%s ", rlimit_strings[i].description); if (limit.rlim_cur == RLIM_INFINITY) { - fprintf(fd," unlimited"); + fprintf(fp, " unlimited"); } else { - fprintf(fd,"%16" PRIu64, limit.rlim_cur); + fprintf(fp, "%16" PRIu64, limit.rlim_cur); } if (limit.rlim_max == RLIM_INFINITY) { - fprintf(fd," unlimited\n"); + fprintf(fp, " unlimited\n"); } else { - fprintf(fd,"%16" PRIu64 "\n", limit.rlim_max); + fprintf(fp, "%16" PRIu64 "\n", limit.rlim_max); } } } -#endif +#endif } /* - * Utility function to print out integer values with commas between every thousand for readability. + * Utility function to print out large integer values with commas. */ -static void WriteIntegerWithCommas(FILE *fd, size_t value) { - int thousandsStack[7]; /* log1000(2^64-1) = 6.42. We never need more than 7 frames */ +static void WriteIntegerWithCommas(FILE *fp, size_t value) { + int thousandsStack[8]; // Sufficient for max 64-bit number int stackTop = 0; int i; size_t workingValue = value; @@ -331,16 +414,16 @@ static void WriteIntegerWithCommas(FILE *fd, size_t value) { workingValue /= 1000; } while (workingValue != 0); - for (i = stackTop-1; i>=0; i--) { - if (i == (stackTop -1)) { - fprintf(fd,"%u",thousandsStack[i]); + for (i = stackTop-1; i >= 0; i--) { + if (i == (stackTop-1)) { + fprintf(fp, "%u", thousandsStack[i]); } else { - fprintf(fd,"%03u",thousandsStack[i]); + fprintf(fp, "%03u", thousandsStack[i]); } if (i > 0) { - fprintf(fd,","); + fprintf(fp, ","); } } } -} // namespace node +} // namespace node diff --git a/src/node_report.h b/src/node_report.h index 5bcc7d4453e0f7..dd29d58fdeb5b4 100644 --- a/src/node_report.h +++ b/src/node_report.h @@ -8,12 +8,23 @@ using v8::Isolate; using v8::Local; using v8::Message; +// Bit-flags for NodeReport trigger options +#define NR_EXCEPTION 0x01 +#define NR_FATALERROR 0x02 +#define NR_SIGUSR2 0x04 +#define NR_SIGQUIT 0x08 + enum DumpEvent {kException, kFatalError, kSignal_JS, kSignal_UV}; -void TriggerNodeReport(Isolate* isolate, DumpEvent event, const char *message, const char *location); +void TriggerNodeReport(Isolate* isolate, DumpEvent event, + const char *message, const char *location); + +void TriggerNodeReport(Isolate* isolate, DumpEvent event, + const char *message, const char *location, + Local message_handle); -void TriggerNodeReport(Isolate* isolate, DumpEvent event, const char *message, const char *location, Local message_handle); +unsigned int ProcessNodeReportArgs(const char *args); } // namespace node -#endif // SRC_NODE_REVERT_H_ +#endif // SRC_NODE_REPORT_H_ diff --git a/test/parallel/test-nodereport.js b/test/parallel/test-nodereport.js index 627fdb4eb02874..a6c8f8f33af6b1 100644 --- a/test/parallel/test-nodereport.js +++ b/test/parallel/test-nodereport.js @@ -24,8 +24,7 @@ child.on('exit', function(code, signal) { fs.readdir(common.tmpDir, function(err, files) { for (var i = 0; i < files.length; i++) { if (files[i].substring(0, 10) == 'NodeReport' && - files[i].substring(27, 31) == child.pid) { - + files[i].indexOf(child.pid) != -1) { // Located NodeReport with expected PID console.log('test-nodereport.js: located NodeReport: ', path.join(common.tmpDir, files[i]));