diff --git a/src/commands/dump.cc b/src/commands/dump.cc index 94603ba..2b2e614 100644 --- a/src/commands/dump.cc +++ b/src/commands/dump.cc @@ -8,6 +8,7 @@ #include "heapprofiler/sampling_heap_profiler.h" #include "logger.h" #include "platform/platform.h" +#include "process_data.h" #include "report/node_report.h" #include "uv.h" #include "v8.h" @@ -273,7 +274,9 @@ void StopProfiling(EnvironmentData* env_data, void* data, static void ProfilingWatchDog(void* data) { // TODO(legendecas): environment data selector - EnvironmentData* env_data = EnvironmentData::GetCurrent(); + EnvironmentRegistry* registry = ProcessData::Get()->environment_registry(); + EnvironmentRegistry::NoExitScope scope(registry); + EnvironmentData* env_data = registry->GetMainThread(); BaseDumpData* dump_data = static_cast(data); string traceid = dump_data->traceid; DumpAction action = dump_data->action; @@ -325,7 +328,9 @@ static json DoDumpAction(json command, DumpAction action, string prefix, action_map.insert(make_pair(action, true)); // TODO(legendecas): environment data selector - EnvironmentData* env_data = EnvironmentData::GetCurrent(); + EnvironmentRegistry* registry = ProcessData::Get()->environment_registry(); + EnvironmentRegistry::NoExitScope scope(registry); + EnvironmentData* env_data = registry->GetMainThread(); // get file name switch (action) { diff --git a/src/environment_data.cc b/src/environment_data.cc index 848f2ea..2413c98 100644 --- a/src/environment_data.cc +++ b/src/environment_data.cc @@ -9,21 +9,13 @@ #include "xpf_v8.h" namespace xprofiler { +using v8::Boolean; using v8::Context; using v8::Isolate; using v8::Local; using v8::Number; using v8::Object; -// static -EnvironmentData* EnvironmentData::GetCurrent() { - EnvironmentRegistry* registry = ProcessData::Get()->environment_registry(); - EnvironmentRegistry::NoExitScope scope(registry); - - CHECK_NE(registry->begin(), registry->end()); - return *registry->begin(); -} - // static EnvironmentData* EnvironmentData::GetCurrent(v8::Isolate* isolate) { EnvironmentRegistry* registry = ProcessData::Get()->environment_registry(); @@ -131,7 +123,9 @@ void EnvironmentData::CollectStatistics(uv_async_t* handle) { } // javascript accessible -void JsSetupEnvironmentData(const Nan::FunctionCallbackInfo& info) { +// static +void EnvironmentData::JsSetupEnvironmentData( + const Nan::FunctionCallbackInfo& info) { Isolate* isolate = info.GetIsolate(); EnvironmentData* env_data = EnvironmentData::GetCurrent(isolate); HandleScope scope(isolate); @@ -142,7 +136,13 @@ void JsSetupEnvironmentData(const Nan::FunctionCallbackInfo& info) { data->Get(context, OneByteString(isolate, "threadId")) .ToLocalChecked() .As(); - env_data->set_thread_id(thread_id->Value()); + Local is_main_thread = + data->Get(context, OneByteString(isolate, "isMainThread")) + .ToLocalChecked() + .As(); + + env_data->thread_id_ = thread_id->Value(); + env_data->is_main_thread_ = is_main_thread->Value(); } } // namespace xprofiler diff --git a/src/environment_data.h b/src/environment_data.h index 8b66da2..f5ed31a 100644 --- a/src/environment_data.h +++ b/src/environment_data.h @@ -6,6 +6,7 @@ #include "commands/cpuprofiler/cpu_profiler.h" #include "commands/gcprofiler/gc_profiler.h" +#include "library/common.h" #include "logbypass/gc.h" #include "logbypass/heap.h" #include "logbypass/http.h" @@ -24,21 +25,23 @@ using InterruptCallback = std::function; class EnvironmentData { public: - // TODO(legendecas): remove this no-args GetCurrent. - static EnvironmentData* GetCurrent(); static EnvironmentData* GetCurrent(v8::Isolate* isolate); static EnvironmentData* GetCurrent( const Nan::FunctionCallbackInfo& info); static void Create(v8::Isolate* isolate); + static void JsSetupEnvironmentData( + const Nan::FunctionCallbackInfo& info); + void SendCollectStatistics(); void RequestInterrupt(InterruptCallback interrupt); inline v8::Isolate* isolate() { return isolate_; } inline uv_loop_t* loop() { return loop_; } - inline double thread_id() { return thread_id_; } - inline void set_thread_id(double thread_id) { thread_id_ = thread_id; } + + inline bool is_main_thread() { return is_main_thread_; } + inline ThreadId thread_id() { return thread_id_; } inline GcStatistics* gc_statistics() { return &gc_statistics_; } inline HttpStatistics* http_statistics() { return &http_statistics_; } @@ -62,10 +65,12 @@ class EnvironmentData { v8::Isolate* isolate_; uv_loop_t* loop_; uv_async_t statistics_async_; + + bool is_main_thread_ = false; /* We don't have a native method to get the uint64_t thread id. * Use the JavaScript number representation. */ - double thread_id_ = -1; + ThreadId thread_id_ = ThreadId(-1); Mutex interrupt_mutex_; std::list interrupt_requests_; @@ -77,9 +82,6 @@ class EnvironmentData { UvHandleStatistics uv_handle_statistics_; }; -// javascript accessible -void JsSetupEnvironmentData(const Nan::FunctionCallbackInfo& info); - } // namespace xprofiler #endif /* XPROFILER_SRC_ENVIRONMENT_DATA_H */ diff --git a/src/environment_registry.cc b/src/environment_registry.cc index b29b571..c8d1b30 100644 --- a/src/environment_registry.cc +++ b/src/environment_registry.cc @@ -36,6 +36,18 @@ EnvironmentData* EnvironmentRegistry::Get(v8::Isolate* isolate) { return it->second.get(); } +EnvironmentData* EnvironmentRegistry::GetMainThread() { + CHECK(disallow_exit_); + + for (auto it : *this) { + if (it->is_main_thread()) { + return it; + } + } + + return nullptr; +} + EnvironmentRegistry::Iterator EnvironmentRegistry::begin() { CHECK(disallow_exit_); return Iterator(map_.begin()); diff --git a/src/environment_registry.h b/src/environment_registry.h index 83f8db5..d866fab 100644 --- a/src/environment_registry.h +++ b/src/environment_registry.h @@ -49,6 +49,7 @@ class EnvironmentRegistry { void Register(v8::Isolate* isolate, std::unique_ptr env); std::unique_ptr Unregister(v8::Isolate* isolate); EnvironmentData* Get(v8::Isolate* isolate); + EnvironmentData* GetMainThread(); Iterator begin(); Iterator end(); diff --git a/src/library/common.h b/src/library/common.h index aee8e0d..9ccf47d 100644 --- a/src/library/common.h +++ b/src/library/common.h @@ -11,6 +11,11 @@ unsigned long GetUptime(); std::string GetStartTime(std::string format); size_t GetNextDiagFileId(); +/** + * Update the type when we can get integer thread_id from Node.js + */ +using ThreadId = double; + // commands #define COMMAND_CALLBACK(cb) \ void cb(nlohmann::json command, std::string (*format)(const char*, ...), \ diff --git a/src/logbypass/gc.cc b/src/logbypass/gc.cc index 4468fe6..fe4e4a6 100644 --- a/src/logbypass/gc.cc +++ b/src/logbypass/gc.cc @@ -105,28 +105,28 @@ void WriteGcStatusToLog(EnvironmentData* env_data, bool log_format_alinode) { gc_statistics->scavange_duration_last_record, gc_statistics->marksweep_duration_last_record); else - Info("gc", - "uptime: %lu, " - "total_gc_times: %u, " - "total_gc_duration: %lu, " - "total_scavange_duration: %lu, " - "total_marksweep_duration: %lu, " - "total_incremental_marking_duration: %lu, " - "gc_time_during_last_record: %lu, " - "scavange_duration_last_record: %lu, " - "marksweep_duration_last_record: %lu, " - "incremental_marking_duration_last_record: %lu", - GetUptime(), // uptime, s - // total - gc_statistics->total_gc_times, gc_statistics->total_gc_duration, - gc_statistics->total_scavange_duration, - gc_statistics->total_marksweep_duration, - gc_statistics->total_incremental_marking_duration, - // last record - gc_statistics->gc_time_during_last_record, - gc_statistics->scavange_duration_last_record, - gc_statistics->marksweep_duration_last_record, - gc_statistics->incremental_marking_duration_last_record); + InfoT("gc", env_data->thread_id(), + "uptime: %lu, " + "total_gc_times: %u, " + "total_gc_duration: %lu, " + "total_scavange_duration: %lu, " + "total_marksweep_duration: %lu, " + "total_incremental_marking_duration: %lu, " + "gc_time_during_last_record: %lu, " + "scavange_duration_last_record: %lu, " + "marksweep_duration_last_record: %lu, " + "incremental_marking_duration_last_record: %lu", + GetUptime(), // uptime, s + // total + gc_statistics->total_gc_times, gc_statistics->total_gc_duration, + gc_statistics->total_scavange_duration, + gc_statistics->total_marksweep_duration, + gc_statistics->total_incremental_marking_duration, + // last record + gc_statistics->gc_time_during_last_record, + gc_statistics->scavange_duration_last_record, + gc_statistics->marksweep_duration_last_record, + gc_statistics->incremental_marking_duration_last_record); // reset last record gc_statistics->reset(); } diff --git a/src/logbypass/heap.cc b/src/logbypass/heap.cc index c2f240c..e7c25f5 100644 --- a/src/logbypass/heap.cc +++ b/src/logbypass/heap.cc @@ -112,25 +112,27 @@ void WriteMemoryInfoToLog(EnvironmentData* env_data, bool log_format_alinode) { LOG_SPACE_INFO(read_only), LOG_SPACE_INFO(new_large_object), LOG_SPACE_INFO(code_large_object)); } else { - Info("memory", - COMMON_INFO_FORMATTERX SPACE_INFO_FORMATTER(new) SPACE_INFO_FORMATTER( - old) SPACE_INFO_FORMATTER(code) SPACE_INFO_FORMATTER(map) - SPACE_INFO_FORMATTER(lo) SPACE_INFO_FORMATTER(read_only) - SPACE_INFO_FORMATTER(new_lo) SPACE_INFO_FORMATTER(code_lo), - // rss - rss, - // heap statistics - heap_statistics->used_heap_size(), - heap_statistics->total_available_size(), - heap_statistics->total_heap_size(), heap_statistics->heap_size_limit(), - heap_statistics->total_heap_size_executable(), - heap_statistics->total_physical_size(), - heap_statistics->malloced_memory(), heap_statistics->external_memory(), - // space statistics - LOG_SPACE_INFO(new), LOG_SPACE_INFO(old), LOG_SPACE_INFO(code), - LOG_SPACE_INFO(map), LOG_SPACE_INFO(large_object), - LOG_SPACE_INFO(read_only), LOG_SPACE_INFO(new_large_object), - LOG_SPACE_INFO(code_large_object)); + InfoT( + "memory", env_data->thread_id(), + COMMON_INFO_FORMATTERX SPACE_INFO_FORMATTER(new) + SPACE_INFO_FORMATTER(old) SPACE_INFO_FORMATTER(code) + SPACE_INFO_FORMATTER(map) SPACE_INFO_FORMATTER(lo) + SPACE_INFO_FORMATTER(read_only) SPACE_INFO_FORMATTER(new_lo) + SPACE_INFO_FORMATTER(code_lo), + // rss + rss, + // heap statistics + heap_statistics->used_heap_size(), + heap_statistics->total_available_size(), + heap_statistics->total_heap_size(), heap_statistics->heap_size_limit(), + heap_statistics->total_heap_size_executable(), + heap_statistics->total_physical_size(), + heap_statistics->malloced_memory(), heap_statistics->external_memory(), + // space statistics + LOG_SPACE_INFO(new), LOG_SPACE_INFO(old), LOG_SPACE_INFO(code), + LOG_SPACE_INFO(map), LOG_SPACE_INFO(large_object), + LOG_SPACE_INFO(read_only), LOG_SPACE_INFO(new_large_object), + LOG_SPACE_INFO(code_large_object)); } } } // namespace xprofiler diff --git a/src/logbypass/http.cc b/src/logbypass/http.cc index 31e493c..0ef8ae9 100644 --- a/src/logbypass/http.cc +++ b/src/logbypass/http.cc @@ -109,18 +109,18 @@ void WriteHttpStatus(EnvironmentData* env_data, bool log_format_alinode, } } - Info("http", - "%s" - "live_http_request: %d, " - "http_response_close: %d, " - "http_response_sent: %d, " - "http_request_timeout: %d, " - "http_patch_timeout: %d, " - "http_rt: %.2lf", - format.c_str(), http_statistics->live_http_request, - http_statistics->http_response_close, - http_statistics->http_response_sent, - http_statistics->http_request_timeout, http_patch_timeout, rt); + InfoT("http", env_data->thread_id(), + "%s" + "live_http_request: %d, " + "http_response_close: %d, " + "http_response_sent: %d, " + "http_request_timeout: %d, " + "http_patch_timeout: %d, " + "http_rt: %.2lf", + format.c_str(), http_statistics->live_http_request, + http_statistics->http_response_close, + http_statistics->http_response_sent, + http_statistics->http_request_timeout, http_patch_timeout, rt); } // reset diff --git a/src/logbypass/libuv.cc b/src/logbypass/libuv.cc index d2b43e9..af6b314 100644 --- a/src/logbypass/libuv.cc +++ b/src/logbypass/libuv.cc @@ -83,27 +83,28 @@ void WriteLibuvHandleInfoToLog(EnvironmentData* env_data, uv_handle_statistics->active_timer_handles, uv_handle_statistics->active_handles); } else if (enable_log_uv_handles) { - Info("uv", - "active_handles: %d, " - "active_file_handles: %d, " - "active_and_ref_file_handles: %d, " - "active_tcp_handles: %d, " - "active_and_ref_tcp_handles: %d, " - "active_udp_handles: %d, " - "active_and_ref_udp_handles: %d, " - "active_timer_handles: %d, " - "active_and_ref_timer_handles: %d", - uv_handle_statistics->active_handles, - uv_handle_statistics->active_file_handles, - uv_handle_statistics->active_and_ref_file_handles, - uv_handle_statistics->active_tcp_handles, - uv_handle_statistics->active_and_ref_tcp_handles, - uv_handle_statistics->active_udp_handles, - uv_handle_statistics->active_and_ref_udp_handles, - uv_handle_statistics->active_timer_handles, - uv_handle_statistics->active_and_ref_timer_handles); + InfoT("uv", env_data->thread_id(), + "active_handles: %d, " + "active_file_handles: %d, " + "active_and_ref_file_handles: %d, " + "active_tcp_handles: %d, " + "active_and_ref_tcp_handles: %d, " + "active_udp_handles: %d, " + "active_and_ref_udp_handles: %d, " + "active_timer_handles: %d, " + "active_and_ref_timer_handles: %d", + uv_handle_statistics->active_handles, + uv_handle_statistics->active_file_handles, + uv_handle_statistics->active_and_ref_file_handles, + uv_handle_statistics->active_tcp_handles, + uv_handle_statistics->active_and_ref_tcp_handles, + uv_handle_statistics->active_udp_handles, + uv_handle_statistics->active_and_ref_udp_handles, + uv_handle_statistics->active_timer_handles, + uv_handle_statistics->active_and_ref_timer_handles); } else { - Info("uv", "active_handles: %d", uv_handle_statistics->active_handles); + InfoT("uv", env_data->thread_id(), "[%ld] active_handles: %d", + uv_handle_statistics->active_handles); } } } // namespace xprofiler diff --git a/src/logbypass/log.cc b/src/logbypass/log.cc index f2f4d22..78d0320 100644 --- a/src/logbypass/log.cc +++ b/src/logbypass/log.cc @@ -72,22 +72,33 @@ void LogByPass::CollectStatistics() { EnvironmentRegistry::NoExitScope scope(registry); bool log_format_alinode = GetFormatAsAlinode(); + // write cpu info + WriteCpuUsageInPeriod(log_format_alinode); + + if (log_format_alinode) { + EnvironmentData* env_data = registry->GetMainThread(); + if (env_data == nullptr) return; + Write(env_data, log_format_alinode); + return; + } + for (EnvironmentData* env_data : *registry) { - // write cpu info - WriteCpuUsageInPeriod(log_format_alinode); + Write(env_data, log_format_alinode); + } +} - // write heap memory info - WriteMemoryInfoToLog(env_data, log_format_alinode); +void LogByPass::Write(EnvironmentData* env_data, bool log_format_alinode) { + // write heap memory info + WriteMemoryInfoToLog(env_data, log_format_alinode); - // write gc status - WriteGcStatusToLog(env_data, log_format_alinode); + // write gc status + WriteGcStatusToLog(env_data, log_format_alinode); - // write libuv handle info - WriteLibuvHandleInfoToLog(env_data, log_format_alinode); + // write libuv handle info + WriteLibuvHandleInfoToLog(env_data, log_format_alinode); - // write http status - WriteHttpStatus(env_data, log_format_alinode, GetPatchHttpTimeout()); - } + // write http status + WriteHttpStatus(env_data, log_format_alinode, GetPatchHttpTimeout()); } void RunLogBypass(const FunctionCallbackInfo& info) { diff --git a/src/logbypass/log.h b/src/logbypass/log.h index 5a2d711..d553823 100644 --- a/src/logbypass/log.h +++ b/src/logbypass/log.h @@ -6,6 +6,7 @@ namespace xprofiler { +class EnvironmentData; class LogByPass final : public XpfThread { public: ~LogByPass() override{}; @@ -20,6 +21,7 @@ class LogByPass final : public XpfThread { void SendCollectStatistics(); void CollectStatistics(); + void Write(EnvironmentData* env_data, bool log_format_alinode); uv_timer_t cpu_interval_; uv_timer_t log_interval_; diff --git a/src/logger.cc b/src/logger.cc index 1a8f276..26d9df8 100644 --- a/src/logger.cc +++ b/src/logger.cc @@ -1,16 +1,17 @@ -#include - -#include - -#include "uv.h" +#include "logger.h" +#include #ifdef _WIN32 #include #endif +#include + #include "configure-inl.h" +#include "environment_data.h" #include "platform/platform.h" #include "util.h" +#include "uv.h" namespace xprofiler { using Nan::FunctionCallbackInfo; @@ -24,24 +25,6 @@ using v8::Local; using v8::String; using v8::Value; -#define LOG_WITH_LEVEL(level) \ - va_list args; \ - va_start(args, format); \ - Log(LOG_LEVEL::level, log_type, format, &args); \ - va_end(args); - -#define JS_LOG_WITH_LEVEL(level) \ - if (!info[0]->IsString() || !info[1]->IsString()) { \ - ThrowTypeError( \ - New("log type and content must be string!").ToLocalChecked()); \ - return; \ - } \ - Local log_type_string = To(info[0]).ToLocalChecked(); \ - Utf8String log_type(log_type_string); \ - Local log_content_string = To(info[1]).ToLocalChecked(); \ - Utf8String log_content(log_content_string); \ - Log(LOG_LEVEL::level, *log_type, *log_content); - static const int kMaxMessageLength = 2048; static const int kMaxFormatLength = 2048; @@ -87,7 +70,8 @@ static void WriteToFile(const LOG_LEVEL output_level, char* log) { } static void Log(const LOG_LEVEL output_level, const char* type, - const char* format, va_list* arglist = nullptr) { + ThreadId thread_id, const char* format, + va_list* arglist = nullptr) { LOG_LEVEL level = GetLogLevel(); if (level < output_level) { return; @@ -128,6 +112,7 @@ static void Log(const LOG_LEVEL output_level, const char* type, // get pid string pid = to_string(GetPid()); + string tid = to_string(static_cast(thread_id)); // add log prefix char tmp_format[kMaxFormatLength]; @@ -136,8 +121,9 @@ static void Log(const LOG_LEVEL output_level, const char* type, time_string_ms_alinode, level_string.c_str(), type, pid.c_str(), format); } else { - snprintf(tmp_format, sizeof(tmp_format), "[%s] [%s] [%s] [%s] [%s] %s\n", - time_string_ms, level_string.c_str(), type, pid.c_str(), + snprintf(tmp_format, sizeof(tmp_format), + "[%s] [%s] [%s] [%s] [%s] [%s] %s\n", time_string_ms, + level_string.c_str(), type, pid.c_str(), tid.c_str(), XPROFILER_VERSION, format); } @@ -169,17 +155,46 @@ void InitOnceLogger() { } /* native logger */ -void Info(const char* log_type, const char* format, ...) { - LOG_WITH_LEVEL(LOG_INFO) -} -void Error(const char* log_type, const char* format, ...) { - LOG_WITH_LEVEL(LOG_ERROR) -} +#define NATIVE_LOGGERS(V) \ + V(Info, LOG_INFO) \ + V(Error, LOG_ERROR) \ + V(Debug, LOG_DEBUG) + +#define DEFINE_LOGGER(name, level) \ + void name(const char* log_type, const char* format, ...) { \ + va_list args; \ + va_start(args, format); \ + Log(LOG_LEVEL::level, log_type, 0, format, &args); \ + va_end(args); \ + } +NATIVE_LOGGERS(DEFINE_LOGGER); +#undef DEFINE_LOGGER + +#define DEFINE_LOGGER(name, level) \ + void name##T(const char* log_type, ThreadId thread_id, const char* format, \ + ...) { \ + va_list args; \ + va_start(args, format); \ + Log(LOG_LEVEL::level, log_type, thread_id, format, &args); \ + va_end(args); \ + } +NATIVE_LOGGERS(DEFINE_LOGGER); +#undef DEFINE_LOGGER -void Debug(const char* log_type, const char* format, ...) { - LOG_WITH_LEVEL(LOG_DEBUG) -} +#define JS_LOG_WITH_LEVEL(level) \ + if (!info[0]->IsString() || !info[1]->IsString()) { \ + ThrowTypeError( \ + New("log type and content must be string!").ToLocalChecked()); \ + return; \ + } \ + EnvironmentData* env_data = EnvironmentData::GetCurrent(info); \ + \ + Local log_type_string = To(info[0]).ToLocalChecked(); \ + Utf8String log_type(log_type_string); \ + Local log_content_string = To(info[1]).ToLocalChecked(); \ + Utf8String log_content(log_content_string); \ + Log(level, *log_type, env_data->thread_id(), *log_content); /* js binding logger */ void JsInfo(const FunctionCallbackInfo& info) { @@ -193,4 +208,5 @@ void JsError(const FunctionCallbackInfo& info) { void JsDebug(const FunctionCallbackInfo& info) { JS_LOG_WITH_LEVEL(LOG_DEBUG) } + }; // namespace xprofiler diff --git a/src/logger.h b/src/logger.h index d318706..467f60e 100644 --- a/src/logger.h +++ b/src/logger.h @@ -16,6 +16,10 @@ void Info(const char* log_type, const char* format, ...); void Error(const char* log_type, const char* format, ...); void Debug(const char* log_type, const char* format, ...); +void InfoT(const char* log_type, ThreadId thread_id, const char* format, ...); +void ErrorT(const char* log_type, ThreadId thread_id, const char* format, ...); +void DebugT(const char* log_type, ThreadId thread_id, const char* format, ...); + // javascript accessible void JsInfo(const Nan::FunctionCallbackInfo& info); void JsError(const Nan::FunctionCallbackInfo& info); diff --git a/src/xprofiler.cc b/src/xprofiler.cc index 4b8e706..fdab886 100644 --- a/src/xprofiler.cc +++ b/src/xprofiler.cc @@ -41,7 +41,7 @@ NAN_MODULE_INIT(Initialize) { CREATE_JS_BINDING(error, JsError); CREATE_JS_BINDING(debug, JsDebug); - CREATE_JS_BINDING(setup, JsSetupEnvironmentData); + CREATE_JS_BINDING(setup, EnvironmentData::JsSetupEnvironmentData); // performance log CREATE_JS_BINDING(runLogBypass, RunLogBypass); diff --git a/test/fixtures/logbypass.test.js b/test/fixtures/logbypass.test.js index 653636f..740a8ae 100644 --- a/test/fixtures/logbypass.test.js +++ b/test/fixtures/logbypass.test.js @@ -174,4 +174,4 @@ function getTestCases(title, logdirBlocking, logdirNonBlocking, envConfig, struc exports = module.exports = getTestCases; -exports.getUvRules = getUvRules; \ No newline at end of file +exports.getUvRules = getUvRules; diff --git a/test/fixtures/utils.js b/test/fixtures/utils.js index b7e32d8..88b0bf2 100644 --- a/test/fixtures/utils.js +++ b/test/fixtures/utils.js @@ -8,7 +8,8 @@ const pack = require('../../package.json'); const MAGIC_BLURRY_TAG = pack.blurryTag; exports.xprofilerPrefixRegexp = - /\[\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\] \[(.+)\] \[(.+)\] \[(\d+)\] \[(\d{1,3}\.\d{1,3}\.\d{1,3}.*)\] (.*)/g; +// eslint-disable-next-line max-len + /\[\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\] \[(.+)\] \[(.+)\] \[(\d+)\] \[(\d+)\] \[(\d{1,3}\.\d{1,3}\.\d{1,3}[a-zA-Z0-9\-_]*)\] (.*)/g; exports.alinodePrefixRegexp = /\[\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{6}\] \[(.+)\] \[(.+)\] \[(\d+)\] (.*)/g; diff --git a/test/log.test.js b/test/log.test.js index ae702b0..d8f3e01 100644 --- a/test/log.test.js +++ b/test/log.test.js @@ -41,8 +41,9 @@ function parseXprofilerLog(type, content) { if (type === 'alinode') { obj.detail = matched[4]; } else { - obj.version = matched[4]; - obj.detail = matched[5]; + obj.tid = matched[4]; + obj.version = matched[5]; + obj.detail = matched[6]; } parsed.push(obj); } @@ -121,4 +122,4 @@ for (const testConfig of testConfigList) { }); } }); -} \ No newline at end of file +} diff --git a/test/logbypass.test.js b/test/logbypass.test.js index c8dd470..4e9d54f 100644 --- a/test/logbypass.test.js +++ b/test/logbypass.test.js @@ -59,8 +59,9 @@ function parseLog(logType, content, patt, alinode) { if (alinode) { detail = matched[4]; } else { - res.prefix.version = matched[4]; - detail = matched[5]; + res.prefix.tid = Number(matched[4]); + res.prefix.version = matched[5]; + detail = matched[6]; } // set detail @@ -118,9 +119,12 @@ for (const testCase of cases) { expect(/^info$|^error$|^debug$/.test(prefix.level)).to.be.ok(); expect(new RegExp(`^${type}$`).test(prefix.type)).to.be.ok(); expect(prefix.pid).to.be(pid); - if (!testCase.alinode) { - expect(prefix.version).to.be(pack.version); + if (testCase.alinode) { + return; } + expect(prefix.version).to.be(pack.version); + expect(Number.isFinite(prefix.tid)).to.be.ok(); + expect(Number.isInteger(prefix.tid)).to.be.ok(); }); const struct = testCase.struct[type]; @@ -145,4 +149,4 @@ for (const testCase of cases) { } }); } -} \ No newline at end of file +} diff --git a/xprofiler.js b/xprofiler.js index 31437cb..3199531 100644 --- a/xprofiler.js +++ b/xprofiler.js @@ -62,21 +62,23 @@ function start(config = {}) { // set config by user and env const finalConfig = exports.setConfig(config); - // check socket path - checkSocketPath(finalConfig); - - // clean & set logdir info to file - const logdir = finalConfig.log_dir; - clean(logdir); - utils.setLogDirToFile(logdir); - - if (process.env.XPROFILER_UNIT_TEST_SINGLE_MODULE !== 'YES') { - // start performance log thread - exports.runLogBypass(); - // start commands listener thread - exports.runCommandsListener(); - // set hooks - exports.setHooks(); + if (workerThreads.isMainThread) { + // check socket path + checkSocketPath(finalConfig); + + // clean & set logdir info to file + const logdir = finalConfig.log_dir; + clean(logdir); + utils.setLogDirToFile(logdir); + + if (process.env.XPROFILER_UNIT_TEST_SINGLE_MODULE !== 'YES') { + // start performance log thread + exports.runLogBypass(); + // start commands listener thread + exports.runCommandsListener(); + // set hooks + exports.setHooks(); + } } // patch modules