Merge a4f0183 into 85065b8

lib/configure.js

@@ -34,7 +34,7 @@ function getFinalUserConfigure(envConfig, userConfig) {
 
   // replace value
   const flattern = configuration.map(config => Object.assign({}, config, { value: finalConfig[config.name] }));
-  return { flattern, origin: finalConfig };
+  return { flattern };
 }
 
 const simpleCheck = {
@@ -60,7 +60,7 @@ module.exports = function (user) {
   const envConfig = {};
   const userConfig = {};
   for (const config of configuration) {
-    const rules = Array.isArray(config.rules) ? config.rules.concat(config.format) : [config.format];
+    const rules = config.rules.concat(config.format);
     const key = config.name;
     const format = formatValue[config.format];
     const envValue = process.env[config.env];

lib/utils.js

@@ -85,7 +85,7 @@ exports.formatArgs = function (args) {
   }
 };
 
-exports.pair = function (name, format = 'boolean') {
+exports.pair = function (name, format) {
   const is = name.startsWith('enable_') && format === 'boolean';
   const pair = is ? [name, name.replace('enable_', 'disable_')] : [name];
   return { is, pair };

patch/http.js

@@ -4,24 +4,46 @@ const shimmer = require('./shimmer');
 const http = require('http');
 const https = require('https');
 
+const httpConfig = {
+  http_detail_profiling: false,
+  start_time: 0,
+};
+
+function getRequestDetail(req, res, start, sent) {
+  const offset = Number((Date.now() - httpConfig.start_time).toFixed(2));
+  const rt = Date.now() - start;
+  const url = req.url.slice(0, 1024);
+  return `${offset},${url},${req.method},${sent},${res.statusCode},${rt}`;
+}
+
 function requestListenerWrapper(original, methods) {
-  return function (req, res) {
-    const { addLiveRequest, addCloseRequest, addSentRequest,
-      addRequestTimeout, addHttpStatusCode, patch_http_timeout } = methods;
+  const { setHttpConfig, addLiveRequest, addCloseRequest, addSentRequest,
+    addRequestTimeout, addHttpStatusCode, addHttpProfilingDetail, patch_http_timeout } = methods;
+
+  setHttpConfig(httpConfig);
 
+  return function (req, res) {
     addLiveRequest();
 
+    const start = Date.now();
+
     const timer = setTimeout(() => {
       addRequestTimeout();
+      if (httpConfig.http_detail_profiling) {
+        const detail = getRequestDetail(req, res, start, 0);
+        addHttpProfilingDetail(detail);
+      }
     }, patch_http_timeout * 1000);
     timer.unref();
 
-    const start = Date.now();
-
     res.on('finish', () => {
       addHttpStatusCode(res.statusCode);
       addSentRequest(Date.now() - start);
       clearTimeout(timer);
+      if (httpConfig.http_detail_profiling) {
+        const detail = getRequestDetail(req, res, start, 1);
+        addHttpProfilingDetail(detail);
+      }
     });
 
     res.on('close', () => {

src/commands/cpuprofiler/cpu_profile.cc

@@ -1,5 +1,6 @@
 #include "cpu_profile.h"
 
+#include "configure-inl.h"
 #include "cpu_profile_node.h"
 #include "environment_data.h"
 #include "library/writer.h"
@@ -62,6 +63,22 @@ void CpuProfile::Serialize(v8::Isolate* isolate, CpuProfilePtr node,
   }
   writer.json_arrayend();
 
+  // http profiling detail
+  if (GetConfig<bool>("enable_http_profiling")) {
+    writer.json_arraystart("httpDetail");
+    HttpProfilingDetail* http_profiling_detail =
+        env_data->http_profiling_detail();
+    for (size_t i = 0; i < http_profiling_detail->samples.size(); i++) {
+      std::string detail = http_profiling_detail->samples.at(i);
+      writer.json_element(http_profiling_detail->samples.at(i));
+    }
+    http_profiling_detail->clear();
+    writer.json_arrayend();
+  } else {
+    writer.json_arraystart("httpDetail");
+    writer.json_arrayend();
+  }
+
   // write to file
   writer.json_end();
 }

src/commands/cpuprofiler/cpu_profiler.cc

@@ -1,7 +1,9 @@
 #include "cpu_profiler.h"
 
+#include "configure-inl.h"
 #include "cpu_profile.h"
 #include "environment_data.h"
+#include "logbypass/http.h"
 #include "xpf_v8.h"
 
 namespace xprofiler {
@@ -21,6 +23,9 @@ void CpuProfiler::StartProfiling(v8::Isolate* isolate, std::string t) {
         std::unique_ptr<CpuProfiler>(new CpuProfiler(isolate));
   }
   env_data->cpu_profiler->StartProfiling(t);
+  if (GetConfig<bool>("enable_http_profiling")) {
+    EnableHttpDetailProfiling(env_data);
+  }
 }
 
 void CpuProfiler::StopProfiling(v8::Isolate* isolate, std::string t,
@@ -33,6 +38,7 @@ void CpuProfiler::StopProfiling(v8::Isolate* isolate, std::string t,
   if (env_data->cpu_profiler->started_profiles_count() == 0) {
     env_data->cpu_profiler.reset();
   }
+  DisableHttpDetailProfiling(env_data);
 }
 
 CpuProfiler::CpuProfiler(v8::Isolate* isolate) : isolate_(isolate) {

src/environment_data.h

@@ -58,6 +58,9 @@ class EnvironmentData {
 
   inline GcStatistics* gc_statistics() { return &gc_statistics_; }
   inline HttpStatistics* http_statistics() { return &http_statistics_; }
+  inline HttpProfilingDetail* http_profiling_detail() {
+    return &http_profiling_detail_;
+  }
   inline MemoryStatistics* memory_statistics() { return &memory_statistics_; }
   inline UvHandleStatistics* uv_handle_statistics() {
     return &uv_handle_statistics_;
@@ -130,6 +133,7 @@ class EnvironmentData {
   GcStatistics gc_statistics_;
   MemoryStatistics memory_statistics_;
   HttpStatistics http_statistics_;
+  HttpProfilingDetail http_profiling_detail_;
   UvHandleStatistics uv_handle_statistics_;
 
   uint32_t closed_handle_count_ = 0;

src/jsapi/export_configure.cc

@@ -2,6 +2,7 @@
 
 #include "process_data.h"
 #include "util-inl.h"
+#include "xpf_v8.h"
 
 namespace xprofiler {
 using Nan::FunctionCallbackInfo;
@@ -45,6 +46,8 @@ using v8::Value;
 
 void Configure(const FunctionCallbackInfo<Value>& info) {
   Isolate* isolate = info.GetIsolate();
+  HandleScope scope(isolate);
+
   if (!info[0]->IsArray()) {
     ThrowTypeError(New<String>("config must be array!").ToLocalChecked());
     return;

src/jsapi/export_http.cc

@@ -2,13 +2,37 @@
 
 #include "environment_data.h"
 #include "logger.h"
+#include "util-inl.h"
+#include "xpf_v8.h"
 
 namespace xprofiler {
 using Nan::FunctionCallbackInfo;
 using v8::Value;
 
 constexpr char module_type[] = "http";
 
+void SetHttpConfig(const FunctionCallbackInfo<Value>& info) {
+  EnvironmentData* env_data = EnvironmentData::GetCurrent(info);
+  if (!env_data) {
+    return;
+  }
+  HttpStatistics* http_statistics = env_data->http_statistics();
+
+  v8::Isolate* isolate = info.GetIsolate();
+  HandleScope scope(isolate);
+
+  if (!info[0]->IsObject()) {
+    Nan::ThrowTypeError("Argument should be an object");
+    return;
+  }
+
+  v8::Local<v8::Object> config = Nan::To<v8::Object>(info[0]).ToLocalChecked();
+
+  // init
+  http_statistics->config.Reset(config);
+  http_statistics->config_initialized = true;
+}
+
 void AddLiveRequest(const FunctionCallbackInfo<Value>& info) {
   EnvironmentData* env_data = EnvironmentData::GetCurrent(info);
   if (env_data == nullptr) {
@@ -78,4 +102,25 @@ void AddHttpStatusCode(const FunctionCallbackInfo<Value>& info) {
   Mutex::ScopedLock lock(http_statistics->mutex);
   http_statistics->status_codes[status_code]++;
 }
+
+void AddHttpProfilingDetail(const Nan::FunctionCallbackInfo<v8::Value>& info) {
+  EnvironmentData* env_data = EnvironmentData::GetCurrent(info);
+  if (env_data == nullptr) {
+    return;
+  }
+  HttpProfilingDetail* http_profiling_detail =
+      env_data->http_profiling_detail();
+
+  if (!info[0]->IsString()) {
+    ErrorT(module_type, env_data->thread_id(),
+           "request detail must be string!");
+    return;
+  }
+
+  v8::Local<v8::String> detail = Nan::To<v8::String>(info[0]).ToLocalChecked();
+  Nan::Utf8String detail_s(detail);
+
+  Mutex::ScopedLock lock(http_profiling_detail->mutex);
+  http_profiling_detail->samples.emplace_back(*detail_s);
+}
 }  // namespace xprofiler

src/jsapi/export_http.h

@@ -5,11 +5,13 @@
 #include "xpf_mutex-inl.h"
 
 namespace xprofiler {
+void SetHttpConfig(const Nan::FunctionCallbackInfo<v8::Value>& info);
 void AddLiveRequest(const Nan::FunctionCallbackInfo<v8::Value>& info);
 void AddCloseRequest(const Nan::FunctionCallbackInfo<v8::Value>& info);
 void AddSentRequest(const Nan::FunctionCallbackInfo<v8::Value>& info);
 void AddRequestTimeout(const Nan::FunctionCallbackInfo<v8::Value>& info);
 void AddHttpStatusCode(const Nan::FunctionCallbackInfo<v8::Value>& info);
+void AddHttpProfilingDetail(const Nan::FunctionCallbackInfo<v8::Value>& info);
 }  // namespace xprofiler
 
 #endif /* XPROFILER_SRC_LOGBYPASS_HTTP_H */

src/logbypass/http.cc

@@ -2,8 +2,49 @@
 
 #include "environment_data.h"
 #include "logger.h"
+#include "util-inl.h"
+#include "xpf_v8.h"
+
+#ifdef _WIN32
+#include <time.h>
+#endif
 
 namespace xprofiler {
+
+#define SET_CONFIG(key, v8_type, value)                      \
+  Nan::Set(config, OneByteString(env_data->isolate(), #key), \
+           Nan::New<v8_type>(value));
+
+static void HttpDetailProfilingState(EnvironmentData* env_data, bool state) {
+  HttpStatistics* http_statistics = env_data->http_statistics();
+  if (!http_statistics->config_initialized) {
+    return;
+  }
+
+  HandleScope scope(env_data->isolate());
+  v8::Local<v8::Object> config = Nan::New(http_statistics->config);
+
+  time_t tt = time(NULL) * 1000;
+
+  if (state) {
+    SET_CONFIG(start_time, v8::Number, tt)
+    env_data->http_profiling_detail()->start_time = tt;
+  } else {
+    SET_CONFIG(start_time, v8::Number, 0)
+    env_data->http_profiling_detail()->end_time = tt;
+  }
+
+  SET_CONFIG(http_detail_profiling, v8::Boolean, state)
+}
+
+void EnableHttpDetailProfiling(EnvironmentData* env_data) {
+  HttpDetailProfilingState(env_data, true);
+}
+
+void DisableHttpDetailProfiling(EnvironmentData* env_data) {
+  HttpDetailProfilingState(env_data, false);
+}
+
 void WriteHttpStatus(EnvironmentData* env_data, bool log_format_alinode,
                      uint32_t http_patch_timeout) {
   HttpStatistics* http_statistics = env_data->http_statistics();

src/logbypass/http.h

@@ -9,6 +9,22 @@ class EnvironmentData;
 
 constexpr uint16_t kMaxHttpStatusCode = 1000;
 
+using HttpProfilingSamples = std::vector<std::string>;
+
+struct HttpProfilingDetail {
+  Mutex mutex;
+  int64_t start_time = 0;
+  int64_t end_time = 0;
+  HttpProfilingSamples samples;
+
+  void clear() {
+    Mutex::ScopedLock lock(mutex);
+    start_time = 0;
+    end_time = 0;
+    HttpProfilingSamples().swap(samples);
+  }
+};
+
 struct HttpStatistics {
   Mutex mutex;
   // http server
@@ -19,8 +35,14 @@ struct HttpStatistics {
   uint32_t http_rt = 0;  // ms
   // http status code: 0 ~ 999
   uint32_t status_codes[kMaxHttpStatusCode] = {0};
+
+  // http config
+  bool config_initialized = false;
+  Nan::Persistent<v8::Object> config;
 };
 
+void EnableHttpDetailProfiling(EnvironmentData* env_data);
+void DisableHttpDetailProfiling(EnvironmentData* env_data);
 void WriteHttpStatus(EnvironmentData* env_data, bool log_format_alinode,
                      uint32_t http_patch_timeout);
 }  // namespace xprofiler

src/xprofiler.cc

@@ -54,11 +54,13 @@ NAN_MODULE_INIT(Initialize) {
   CREATE_JS_BINDING(debug, JsDebug);
 
   // http status
+  CREATE_JS_BINDING(setHttpConfig, SetHttpConfig);
   CREATE_JS_BINDING(addLiveRequest, AddLiveRequest);
   CREATE_JS_BINDING(addCloseRequest, AddCloseRequest);
   CREATE_JS_BINDING(addSentRequest, AddSentRequest);
   CREATE_JS_BINDING(addRequestTimeout, AddRequestTimeout);
   CREATE_JS_BINDING(addHttpStatusCode, AddHttpStatusCode);
+  CREATE_JS_BINDING(addHttpProfilingDetail, AddHttpProfilingDetail);
 }
 
 NODE_MODULE_CONTEXT_AWARE(xprofiler, Initialize)

test/commands.test.js

@@ -51,12 +51,16 @@ function convertOptions(options) {
 
 describe('commands', () => {
   for (let i = 0; i < testConfig.length; i++) {
-    const { cmd, options = {}, profileRules, errored = false, xctlRules, xprofctlRules, platform } = testConfig[i];
+    const { cmd, options = {}, profileRules, profileCheck,
+      errored = false, xctlRules, xprofctlRules, platform, env = {} } = testConfig[i];
     for (let j = 0; j < testFiles.length; j++) {
       const { jspath, desc, threadId = 0 } = testFiles[j];
       const ospt = platform || currentPlatform;
       const title =
-        `[${ospt}] execute [${cmd}] on thread(${threadId}) with options: ${JSON.stringify(options)} ${desc}`;
+        `[${ospt}] execute [${cmd}] on thread(${threadId}) with `
+        + `options: ${JSON.stringify(options)}, `
+        + `env: ${JSON.stringify(env)} `
+        + desc;
       describe(title, function () {
         const commandExpiredTime = 5000;
         let resByXctl = '';
@@ -73,7 +77,7 @@ describe('commands', () => {
               XPROFILER_UNIT_TEST_TMP_HOMEDIR: tmphome,
               XPROFILER_LOG_LEVEL: 2,
               XPROFILER_LOG_TYPE: 1
-            })
+            }, env)
           });
           pid = p.pid;
 
@@ -153,6 +157,11 @@ describe('commands', () => {
               // check dump file
               if (profileRules && typeof profileRules === 'object') {
                 const profile = JSON.parse(fs.readFileSync(resByXctl.data.filepath, 'utf8'));
+                if (typeof profileCheck === 'function' && jspath.includes('normal')) {
+                  it(`profile content check should be ok`, function () {
+                    expect(profileCheck(profile)).to.be.ok();
+                  });
+                }
                 checkProfile(profileRules, profile);
               }