feat: support finish profiling before process exit (#203)

src/commands/dump.cc

@@ -135,16 +135,19 @@ void AfterDumpFile(Isolate* isolate, string& filepath, string notify_type,
          notify_type.c_str(), unique_key.c_str());                         \
   delete dump_data;
 
-#define CHECK_ERR(func)                                                   \
-  func;                                                                   \
-  if (err.Fail()) {                                                       \
-    DebugT(module_type, env_data->thread_id(), "<%s> %s error: %s",       \
-           notify_type.c_str(), unique_key.c_str(), err.GetErrMessage()); \
-    CLEAR_DATA;                                                           \
-    return;                                                               \
+#define CHECK_ERR(func)                                                     \
+  if (need_check) {                                                         \
+    func;                                                                   \
+    if (err.Fail()) {                                                       \
+      DebugT(module_type, env_data->thread_id(), "<%s> %s error: %s",       \
+             notify_type.c_str(), unique_key.c_str(), err.GetErrMessage()); \
+      CLEAR_DATA;                                                           \
+      return;                                                               \
+    }                                                                       \
   }
 
-void HandleAction(v8::Isolate* isolate, void* data, string notify_type) {
+void HandleAction(v8::Isolate* isolate, void* data, string notify_type,
+                  bool need_check = true) {
   BaseDumpData* dump_data = static_cast<BaseDumpData*>(data);
   string traceid = dump_data->traceid;
   DumpAction action = dump_data->action;
@@ -253,12 +256,60 @@ void HandleAction(v8::Isolate* isolate, void* data, string notify_type) {
   if (dump_data->run_once) {
     CLEAR_DATA;
   }
-  return;
 }
 
 #undef CHECK_ERR
 #undef CLEAR_DATA
 
+template <DumpAction action, typename T>
+T* CreateFinishDumpData(EnvironmentData* env_data) {
+  T* data = new T;
+  data->traceid = "finish";
+  data->thread_id = env_data->thread_id();
+  data->action = action;
+  return data;
+}
+
+void FinishSampling(Isolate* isolate, const char* reason) {
+  EnvironmentData* env_data = EnvironmentData::GetCurrent(isolate);
+
+  DebugT(module_type, env_data->thread_id(), "finish sampling because: %s.",
+         reason);
+
+  ActionMap current;
+  current.swap(*env_data->action_map());
+
+  void* data = nullptr;
+
+  for (auto itor : current) {
+    switch (itor.first) {
+      case START_CPU_PROFILING:
+        data = static_cast<void*>(
+            CreateFinishDumpData<STOP_CPU_PROFILING, CpuProfilerDumpData>(
+                env_data));
+        break;
+      case START_SAMPLING_HEAP_PROFILING:
+        data = static_cast<void*>(
+            CreateFinishDumpData<STOP_SAMPLING_HEAP_PROFILING,
+                                 SamplingHeapProfilerDumpData>(env_data));
+        break;
+      case START_GC_PROFILING:
+        data = static_cast<void*>(
+            CreateFinishDumpData<STOP_GC_PROFILING, GcProfilerDumpData>(
+                env_data));
+        break;
+      default:
+        break;
+    }
+
+    if (data == nullptr) {
+      continue;
+    }
+
+    HandleAction(isolate, data, reason, false);
+  }
+}
+
 static void WaitForProfile(uint64_t profiling_time) {
   uint64_t start = uv_hrtime();
   while (uv_hrtime() - start < profiling_time * 10e5) {

src/commands/dump.h

@@ -21,9 +21,9 @@ enum DumpAction {
   COREDUMP,
 };
 
-using ActionMap = std::unordered_map<int, bool>;
-using ConflictMap = std::unordered_map<int, std::vector<DumpAction>>;
-using DependentMap = std::unordered_map<int, DumpAction>;
+using ActionMap = std::unordered_map<DumpAction, bool>;
+using ConflictMap = std::unordered_map<DumpAction, std::vector<DumpAction>>;
+using DependentMap = std::unordered_map<DumpAction, DumpAction>;
 
 struct BaseDumpData {
   std::string traceid;
@@ -47,6 +47,8 @@ struct NodeReportDumpData : BaseDumpData {};
 
 struct CoreDumpData : BaseDumpData {};
 
+void FinishSampling(v8::Isolate* isolate, const char* reason);
+
 COMMAND_CALLBACK(StartCpuProfiling);
 COMMAND_CALLBACK(StopCpuProfiling);
 COMMAND_CALLBACK(Heapdump);

src/environment_data.cc

@@ -2,6 +2,7 @@
 
 #include <memory>
 
+#include "commands/dump.h"
 #include "logbypass/log.h"
 #include "process_data.h"
 #include "util-inl.h"
@@ -68,6 +69,9 @@ void EnvironmentData::AtExit(void* arg) {
   EnvironmentRegistry::NoExitScope scope(registry);
   std::unique_ptr<EnvironmentData> env_data = registry->Unregister(isolate);
 
+  // finish sampling
+  FinishSampling(isolate, "at_exit");
+
   for (auto callback : env_data->gc_epilogue_callbacks_) {
     Nan::RemoveGCEpilogueCallback(callback);
   }

src/hooks/fatal_error.cc

@@ -1,4 +1,5 @@
 #include "commands/coredumper/coredumper.h"
+#include "commands/dump.h"
 #include "commands/report/node_report.h"
 #include "configure-inl.h"
 #include "environment_data.h"
@@ -28,6 +29,11 @@ void DumpBeforeAbort(const char* location, const char* message) {
   EnvironmentData* env_data = EnvironmentData::GetCurrent(isolate);
   ThreadId thread_id = env_data->thread_id();
 
+#ifndef _WIN32
+  // finish sampling
+  FinishSampling(isolate, "fatal_error");
+#endif
+
   // generate report before abort
   if (GetEnableFatalErrorReport()) {
     string filepath = GetLogDir() + GetSep() + "x-fatal-error-" +

test/commands.test.js

@@ -74,13 +74,16 @@ describe('commands', () => {
             })
           });
           pid = p.pid;
+
+          // wait for xprofiler to start
           await new Promise(resolve => p.on('message', msg =>
             msg.type === utils.clientConst.xprofilerDone && resolve()));
-          await utils.sleep(500);
+
           // send cmd with xctl (function)
           console.log(`[${moment().format('YYYY-MM-DD HH:mm:ss')}]`, 'send xctl cmd.');
           resByXctl = await xctl(pid, threadId, cmd, options);
           await utils.sleep(500);
+
           // send cmd with xprofctl (cli)
           const extra = convertOptions(options);
           const nodeExe = currentPlatform === 'win32' ? 'node ' : '';
@@ -93,6 +96,8 @@ describe('commands', () => {
             })
           });
           resByXprofctl = resByXprofctl.stderr.trim() + resByXprofctl.stdout.trim();
+
+          // exit info
           console.log(`[${moment().format('YYYY-MM-DD HH:mm:ss')}]`, 'wait for child process done.');
           exitInfo = await utils.getChildProcessExitInfo(p);
         });

test/fixtures/command.test.js

@@ -394,7 +394,7 @@ exports = module.exports = function (logdir) {
   return filterTestCaseByPlatform(list);
 };
 
-exports.profileRule = { diag };
+exports.profileRule = { diag, cpuprofile, heapprofile, gcprofile };
 
 exports.checkProfile = checkProfile;
 

test/fixtures/exit.js

@@ -0,0 +1,18 @@
+'use strict';
+
+const os = require('os');
+const mm = require('mm');
+const xprofiler = require('../../');
+const utils = require('./utils');
+
+if (process.env.XPROFILER_UNIT_TEST_TMP_HOMEDIR) {
+  mm(os, 'homedir', () => process.env.XPROFILER_UNIT_TEST_TMP_HOMEDIR);
+}
+
+xprofiler();
+
+process.send({ type: utils.clientConst.xprofilerDone });
+
+setTimeout(() => {
+  // empty exit
+}, 2000);

test/fixtures/fatal-error.js

@@ -1,10 +1,21 @@
 'use strict';
 
+const os = require('os');
+const mm = require('mm');
 const xprofiler = require('../../');
+const utils = require('./utils');
+
+if (process.env.XPROFILER_UNIT_TEST_TMP_HOMEDIR) {
+  mm(os, 'homedir', () => process.env.XPROFILER_UNIT_TEST_TMP_HOMEDIR);
+}
+
 xprofiler();
 
+process.send({ type: utils.clientConst.xprofilerDone });
+
 const array = [];
+
 setInterval(() => {
   array.push(new Array(10e6).fill('*'));
   console.log('now rss:', process.memoryUsage().rss / 1024 / 1024 + ' Mb');
-}, 1);
+}, Number(process.env.XPROFILER_FATAL_ERROR_INTERVAL) || 1);

test/fixtures/unfinished.test.js

@@ -0,0 +1,125 @@
+'use strict';
+
+const fs = require('fs');
+const path = require('path');
+const { profileRule: { cpuprofile, heapprofile, gcprofile }, checkProfile } = require('./command.test');
+
+exports = module.exports = function () {
+  const list = [
+    // fatal error
+    {
+      title: '<fatal_error> cpu profiling',
+      jspath: path.join(__dirname, 'fatal-error.js'),
+      tid: 0,
+      cmd: 'start_cpu_profiling',
+      options: { profiling_time: 5 * 60 * 1000 },
+      checkExitInfo: false,
+      check(file) {
+        const content = fs.readFileSync(file, 'utf8').trim();
+        checkProfile(cpuprofile, JSON.parse(content));
+      }
+    },
+    {
+      title: '<fatal_error> heap profiling',
+      jspath: path.join(__dirname, 'fatal-error.js'),
+      tid: 0,
+      cmd: 'start_heap_profiling',
+      options: { profiling_time: 5 * 60 * 1000 },
+      checkExitInfo: false,
+      check(file) {
+        const content = fs.readFileSync(file, 'utf8').trim();
+        checkProfile(heapprofile, JSON.parse(content));
+      }
+    },
+    {
+      title: '<fatal_error> gc profiling',
+      jspath: path.join(__dirname, 'fatal-error.js'),
+      tid: 0,
+      cmd: 'start_gc_profiling',
+      options: { profiling_time: 5 * 60 * 1000 },
+      checkExitInfo: false,
+      check(file) {
+        const content = fs.readFileSync(file, 'utf8').trim();
+        checkProfile(gcprofile, JSON.parse(content));
+      }
+    },
+
+    // exit 0 with profiling time
+    {
+      title: '<at_exit> cpu profiling',
+      jspath: path.join(__dirname, 'exit.js'),
+      tid: 0,
+      cmd: 'start_cpu_profiling',
+      options: { profiling_time: 5 * 60 * 1000 },
+      checkExitInfo: true,
+      check(file) {
+        const content = fs.readFileSync(file, 'utf8').trim();
+        checkProfile(cpuprofile, JSON.parse(content));
+      }
+    },
+    {
+      title: '<at_exit> heap profiling',
+      jspath: path.join(__dirname, 'exit.js'),
+      tid: 0,
+      cmd: 'start_heap_profiling',
+      options: { profiling_time: 5 * 60 * 1000 },
+      checkExitInfo: true,
+      check(file) {
+        const content = fs.readFileSync(file, 'utf8').trim();
+        checkProfile(heapprofile, JSON.parse(content));
+      }
+    },
+    {
+      title: '<at_exit> gc profiling',
+      jspath: path.join(__dirname, 'exit.js'),
+      tid: 0,
+      cmd: 'start_gc_profiling',
+      options: { profiling_time: 5 * 60 * 1000 },
+      checkExitInfo: true,
+      check(file) {
+        const content = fs.readFileSync(file, 'utf8').trim();
+        checkProfile(gcprofile, JSON.parse(content));
+      }
+    },
+
+    // exit 0 with no profiling time
+    {
+      title: '<at_exit> cpu profiling',
+      jspath: path.join(__dirname, 'exit.js'),
+      tid: 0,
+      cmd: 'start_cpu_profiling',
+      options: undefined,
+      checkExitInfo: true,
+      check(file) {
+        const content = fs.readFileSync(file, 'utf8').trim();
+        checkProfile(cpuprofile, JSON.parse(content));
+      }
+    },
+    {
+      title: '<at_exit> heap profiling',
+      jspath: path.join(__dirname, 'exit.js'),
+      tid: 0,
+      cmd: 'start_heap_profiling',
+      options: undefined,
+      checkExitInfo: true,
+      check(file) {
+        const content = fs.readFileSync(file, 'utf8').trim();
+        checkProfile(heapprofile, JSON.parse(content));
+      }
+    },
+    {
+      title: '<at_exit> gc profiling',
+      jspath: path.join(__dirname, 'exit.js'),
+      tid: 0,
+      cmd: 'start_gc_profiling',
+      options: undefined,
+      checkExitInfo: true,
+      check(file) {
+        const content = fs.readFileSync(file, 'utf8').trim();
+        checkProfile(gcprofile, JSON.parse(content));
+      }
+    },
+  ];
+
+  return list;
+};