From e55bab0e3af44b6e7039a62fe68516e3e1b9d315 Mon Sep 17 00:00:00 2001 From: James M Snell Date: Thu, 12 Jul 2018 12:22:54 -0700 Subject: [PATCH 1/3] trace_events: add more process metadata Now that TracedValue has landed, add more detailed process `__metadata` including versions, arch, platform, release detail, and argv/execArgv to the trace event log. --- src/node.cc | 36 ++++++++++++++++ src/node_internals.h | 1 + test/parallel/test-trace-events-metadata.js | 46 +++++++++++++++++---- 3 files changed, 75 insertions(+), 8 deletions(-) diff --git a/src/node.cc b/src/node.cc index f9ac48c0770221..c113835047608c 100644 --- a/src/node.cc +++ b/src/node.cc @@ -1966,11 +1966,14 @@ void SetupProcessObject(Environment* env, v8::None, SideEffectType::kHasNoSideEffect).FromJust()); + auto trace_process = tracing::TracedValue::Create(); + // process.version READONLY_PROPERTY(process, "version", FIXED_ONE_BYTE_STRING(env->isolate(), NODE_VERSION)); + trace_process->BeginDictionary("versions"); // process.versions Local versions = Object::New(env->isolate()); READONLY_PROPERTY(process, "versions", versions); @@ -1983,39 +1986,52 @@ void SetupProcessObject(Environment* env, READONLY_PROPERTY(versions, "http_parser", FIXED_ONE_BYTE_STRING(env->isolate(), http_parser_version)); + trace_process->SetString("http_parser", http_parser_version); // +1 to get rid of the leading 'v' READONLY_PROPERTY(versions, "node", OneByteString(env->isolate(), NODE_VERSION + 1)); + trace_process->SetString("node", NODE_VERSION_STRING); + READONLY_PROPERTY(versions, "v8", OneByteString(env->isolate(), V8::GetVersion())); + trace_process->SetString("v8", V8::GetVersion()); + READONLY_PROPERTY(versions, "uv", OneByteString(env->isolate(), uv_version_string())); + trace_process->SetString("uv", uv_version_string()); + READONLY_PROPERTY(versions, "zlib", FIXED_ONE_BYTE_STRING(env->isolate(), ZLIB_VERSION)); + trace_process->SetString("zlib", ZLIB_VERSION); + READONLY_PROPERTY(versions, "ares", FIXED_ONE_BYTE_STRING(env->isolate(), ARES_VERSION_STR)); + trace_process->SetString("ares", ARES_VERSION_STR); const char node_modules_version[] = NODE_STRINGIFY(NODE_MODULE_VERSION); READONLY_PROPERTY( versions, "modules", FIXED_ONE_BYTE_STRING(env->isolate(), node_modules_version)); + trace_process->SetString("modules", node_modules_version); READONLY_PROPERTY(versions, "nghttp2", FIXED_ONE_BYTE_STRING(env->isolate(), NGHTTP2_VERSION)); + trace_process->SetString("nghttp2", NGHTTP2_VERSION); const char node_napi_version[] = NODE_STRINGIFY(NAPI_VERSION); READONLY_PROPERTY( versions, "napi", FIXED_ONE_BYTE_STRING(env->isolate(), node_napi_version)); + trace_process->SetString("napi", node_napi_version); #if HAVE_OPENSSL // Stupid code to slice out the version string. @@ -2037,16 +2053,21 @@ void SetupProcessObject(Environment* env, versions, "openssl", OneByteString(env->isolate(), &OPENSSL_VERSION_TEXT[i], j - i)); + trace_process->SetString("openssl", + std::string(&OPENSSL_VERSION_TEXT[i], j - i)); } #endif + trace_process->EndDictionary(); // process.arch READONLY_PROPERTY(process, "arch", OneByteString(env->isolate(), NODE_ARCH)); + trace_process->SetString("arch", NODE_ARCH); // process.platform READONLY_PROPERTY(process, "platform", OneByteString(env->isolate(), NODE_PLATFORM)); + trace_process->SetString("platform", NODE_PLATFORM); // process.release Local release = Object::New(env->isolate()); @@ -2054,10 +2075,16 @@ void SetupProcessObject(Environment* env, READONLY_PROPERTY(release, "name", OneByteString(env->isolate(), NODE_RELEASE)); + trace_process->BeginDictionary("release"); + auto traced_release = tracing::TracedValue::Create(); + trace_process->SetString("name", NODE_RELEASE); + #if NODE_VERSION_IS_LTS READONLY_PROPERTY(release, "lts", OneByteString(env->isolate(), NODE_VERSION_LTS_CODENAME)); + trace_process->SetString("lts", NODE_VERSION_LTS_CODENAME); #endif + trace_process->EndDictionary(); // if this is a release build and no explicit base has been set // substitute the standard release download URL @@ -2092,19 +2119,28 @@ void SetupProcessObject(Environment* env, // process.argv Local arguments = Array::New(env->isolate(), argc); + trace_process->BeginArray("argv"); for (int i = 0; i < argc; ++i) { arguments->Set(i, String::NewFromUtf8(env->isolate(), argv[i])); + trace_process->AppendString(argv[i]); } + trace_process->EndArray(); process->Set(FIXED_ONE_BYTE_STRING(env->isolate(), "argv"), arguments); // process.execArgv Local exec_arguments = Array::New(env->isolate(), exec_argc); + trace_process->BeginArray("execArgv"); for (int i = 0; i < exec_argc; ++i) { exec_arguments->Set(i, String::NewFromUtf8(env->isolate(), exec_argv[i])); + trace_process->AppendString(exec_argv[i]); } + trace_process->EndArray(); process->Set(FIXED_ONE_BYTE_STRING(env->isolate(), "execArgv"), exec_arguments); + TRACE_EVENT_METADATA1("__metadata", "node", + "process", std::move(trace_process)); + // create process.env Local process_env_template = ObjectTemplate::New(env->isolate()); diff --git a/src/node_internals.h b/src/node_internals.h index 860566e314cb98..53fc5015ac8294 100644 --- a/src/node_internals.h +++ b/src/node_internals.h @@ -32,6 +32,7 @@ #include "uv.h" #include "v8.h" #include "tracing/trace_event.h" +#include "tracing/traced_value.h" #include "node_perf_common.h" #include "node_debug_options.h" #include "node_api.h" diff --git a/test/parallel/test-trace-events-metadata.js b/test/parallel/test-trace-events-metadata.js index 7f9ccc3c7378d5..a0d5a96984f31a 100644 --- a/test/parallel/test-trace-events-metadata.js +++ b/test/parallel/test-trace-events-metadata.js @@ -23,25 +23,55 @@ const proc = cp.spawn(process.execPath, proc.once('exit', common.mustCall(() => { assert(common.fileExists(FILE_NAME)); fs.readFile(FILE_NAME, common.mustCall((err, data) => { - const traces = JSON.parse(data.toString()).traceEvents; + const traces = JSON.parse(data.toString()).traceEvents + .filter((trace) => trace.cat === '__metadata'); assert(traces.length > 0); assert(traces.some((trace) => - trace.cat === '__metadata' && trace.name === 'thread_name' && + trace.name === 'thread_name' && trace.args.name === 'JavaScriptMainThread')); assert(traces.some((trace) => - trace.cat === '__metadata' && trace.name === 'thread_name' && + trace.name === 'thread_name' && trace.args.name === 'BackgroundTaskRunner')); assert(traces.some((trace) => - trace.cat === '__metadata' && trace.name === 'version' && + trace.name === 'version' && trace.args.node === process.versions.node)); + + assert(traces.some((trace) => + trace.name === 'node' && + trace.args.process.versions.http_parser === + process.versions.http_parser && + trace.args.process.versions.node === + process.versions.node && + trace.args.process.versions.v8 === + process.versions.v8 && + trace.args.process.versions.uv === + process.versions.uv && + trace.args.process.versions.zlib === + process.versions.zlib && + trace.args.process.versions.ares === + process.versions.ares && + trace.args.process.versions.modules === + process.versions.modules && + trace.args.process.versions.nghttp2 === + process.versions.nghttp2 && + trace.args.process.versions.napi === + process.versions.napi && + trace.args.process.versions.openssl === + process.versions.openssl && + trace.args.process.arch === process.arch && + trace.args.process.platform === process.platform && + trace.args.process.release.name === process.release.name && + (!process.release.lts || + trace.args.process.release.lts === process.release.lts) && + Array.isArray(trace.args.process.argv) && + Array.isArray(trace.args.process.execArgv))); + if (!common.isSunOS) { // Changing process.title is currently unsupported on SunOS/SmartOS assert(traces.some((trace) => - trace.cat === '__metadata' && trace.name === 'process_name' && - trace.args.name === 'foo')); + trace.name === 'process_name' && trace.args.name === 'foo')); assert(traces.some((trace) => - trace.cat === '__metadata' && trace.name === 'process_name' && - trace.args.name === 'bar')); + trace.name === 'process_name' && trace.args.name === 'bar')); } })); })); From 2f37de4d7ab27a0ea0e0fe43e38d8e2e3e99e409 Mon Sep 17 00:00:00 2001 From: James M Snell Date: Thu, 12 Jul 2018 14:23:06 -0700 Subject: [PATCH 2/3] [Squash] Use a TraceStateObserver --- src/node.cc | 144 +++++++++++++------- src/node_internals.h | 1 - test/parallel/test-trace-events-metadata.js | 4 +- 3 files changed, 97 insertions(+), 52 deletions(-) diff --git a/src/node.cc b/src/node.cc index c113835047608c..533340eb17a96d 100644 --- a/src/node.cc +++ b/src/node.cc @@ -30,6 +30,7 @@ #include "node_debug_options.h" #include "node_perf.h" #include "node_context_data.h" +#include "tracing/traced_value.h" #if defined HAVE_PERFCTR #include "node_counters.h" @@ -289,11 +290,106 @@ static v8::Isolate* node_isolate; DebugOptions debug_options; +// Ensures that __metadata trace events are only emitted +// when tracing is enabled. +class NodeTraceStateObserver : + public v8::TracingController::TraceStateObserver { + public: + void OnTraceEnabled() override { + char name_buffer[512]; + if (uv_get_process_title(name_buffer, sizeof(name_buffer)) == 0) { + // Only emit the metadata event if the title can be retrieved + // successfully. Ignore it otherwise. + TRACE_EVENT_METADATA1("__metadata", "process_name", + "name", TRACE_STR_COPY(name_buffer)); + } + TRACE_EVENT_METADATA1("__metadata", "version", + "node", NODE_VERSION_STRING); + TRACE_EVENT_METADATA1("__metadata", "thread_name", + "name", "JavaScriptMainThread"); + + auto trace_process = tracing::TracedValue::Create(); + trace_process->BeginDictionary("versions"); + + const char http_parser_version[] = + NODE_STRINGIFY(HTTP_PARSER_VERSION_MAJOR) + "." + NODE_STRINGIFY(HTTP_PARSER_VERSION_MINOR) + "." + NODE_STRINGIFY(HTTP_PARSER_VERSION_PATCH); + + const char node_napi_version[] = NODE_STRINGIFY(NAPI_VERSION); + const char node_modules_version[] = NODE_STRINGIFY(NODE_MODULE_VERSION); + + trace_process->SetString("http_parser", http_parser_version); + trace_process->SetString("node", NODE_VERSION_STRING); + trace_process->SetString("v8", V8::GetVersion()); + trace_process->SetString("uv", uv_version_string()); + trace_process->SetString("zlib", ZLIB_VERSION); + trace_process->SetString("ares", ARES_VERSION_STR); + trace_process->SetString("modules", node_modules_version); + trace_process->SetString("nghttp2", NGHTTP2_VERSION); + trace_process->SetString("napi", node_napi_version); + +#if HAVE_OPENSSL + // Stupid code to slice out the version string. + { // NOLINT(whitespace/braces) + size_t i, j, k; + int c; + for (i = j = 0, k = sizeof(OPENSSL_VERSION_TEXT) - 1; i < k; ++i) { + c = OPENSSL_VERSION_TEXT[i]; + if ('0' <= c && c <= '9') { + for (j = i + 1; j < k; ++j) { + c = OPENSSL_VERSION_TEXT[j]; + if (c == ' ') + break; + } + break; + } + } + trace_process->SetString("openssl", + std::string(&OPENSSL_VERSION_TEXT[i], j - i)); + } +#endif + trace_process->EndDictionary(); + + trace_process->SetString("arch", NODE_ARCH); + trace_process->SetString("platform", NODE_PLATFORM); + + trace_process->BeginDictionary("release"); + trace_process->SetString("name", NODE_RELEASE); +#if NODE_VERSION_IS_LTS + trace_process->SetString("lts", NODE_VERSION_LTS_CODENAME); +#endif + trace_process->EndDictionary(); + TRACE_EVENT_METADATA1("__metadata", "node", + "process", std::move(trace_process)); + + // This only runs the first time tracing is enabled + controller_->RemoveTraceStateObserver(this); + delete this; + } + + void OnTraceDisabled() override { + // Do nothing here. This should never be called because the + // observer removes itself when OnTraceEnabled() is called. + UNREACHABLE(); + } + + explicit NodeTraceStateObserver(v8::TracingController* controller) : + controller_(controller) {} + ~NodeTraceStateObserver() override {} + + private: + v8::TracingController* controller_; +}; + static struct { #if NODE_USE_V8_PLATFORM void Initialize(int thread_pool_size) { tracing_agent_.reset(new tracing::Agent(trace_file_pattern)); auto controller = tracing_agent_->GetTracingController(); + controller->AddTraceStateObserver(new NodeTraceStateObserver(controller)); tracing::TraceEventHelper::SetTracingController(controller); StartTracingAgent(); platform_ = new NodePlatform(thread_pool_size, controller); @@ -1966,14 +2062,11 @@ void SetupProcessObject(Environment* env, v8::None, SideEffectType::kHasNoSideEffect).FromJust()); - auto trace_process = tracing::TracedValue::Create(); - // process.version READONLY_PROPERTY(process, "version", FIXED_ONE_BYTE_STRING(env->isolate(), NODE_VERSION)); - trace_process->BeginDictionary("versions"); // process.versions Local versions = Object::New(env->isolate()); READONLY_PROPERTY(process, "versions", versions); @@ -1986,52 +2079,36 @@ void SetupProcessObject(Environment* env, READONLY_PROPERTY(versions, "http_parser", FIXED_ONE_BYTE_STRING(env->isolate(), http_parser_version)); - trace_process->SetString("http_parser", http_parser_version); - // +1 to get rid of the leading 'v' READONLY_PROPERTY(versions, "node", OneByteString(env->isolate(), NODE_VERSION + 1)); - trace_process->SetString("node", NODE_VERSION_STRING); - READONLY_PROPERTY(versions, "v8", OneByteString(env->isolate(), V8::GetVersion())); - trace_process->SetString("v8", V8::GetVersion()); - READONLY_PROPERTY(versions, "uv", OneByteString(env->isolate(), uv_version_string())); - trace_process->SetString("uv", uv_version_string()); - READONLY_PROPERTY(versions, "zlib", FIXED_ONE_BYTE_STRING(env->isolate(), ZLIB_VERSION)); - trace_process->SetString("zlib", ZLIB_VERSION); - READONLY_PROPERTY(versions, "ares", FIXED_ONE_BYTE_STRING(env->isolate(), ARES_VERSION_STR)); - trace_process->SetString("ares", ARES_VERSION_STR); const char node_modules_version[] = NODE_STRINGIFY(NODE_MODULE_VERSION); READONLY_PROPERTY( versions, "modules", FIXED_ONE_BYTE_STRING(env->isolate(), node_modules_version)); - trace_process->SetString("modules", node_modules_version); - READONLY_PROPERTY(versions, "nghttp2", FIXED_ONE_BYTE_STRING(env->isolate(), NGHTTP2_VERSION)); - trace_process->SetString("nghttp2", NGHTTP2_VERSION); - const char node_napi_version[] = NODE_STRINGIFY(NAPI_VERSION); READONLY_PROPERTY( versions, "napi", FIXED_ONE_BYTE_STRING(env->isolate(), node_napi_version)); - trace_process->SetString("napi", node_napi_version); #if HAVE_OPENSSL // Stupid code to slice out the version string. @@ -2053,21 +2130,16 @@ void SetupProcessObject(Environment* env, versions, "openssl", OneByteString(env->isolate(), &OPENSSL_VERSION_TEXT[i], j - i)); - trace_process->SetString("openssl", - std::string(&OPENSSL_VERSION_TEXT[i], j - i)); } #endif - trace_process->EndDictionary(); // process.arch READONLY_PROPERTY(process, "arch", OneByteString(env->isolate(), NODE_ARCH)); - trace_process->SetString("arch", NODE_ARCH); // process.platform READONLY_PROPERTY(process, "platform", OneByteString(env->isolate(), NODE_PLATFORM)); - trace_process->SetString("platform", NODE_PLATFORM); // process.release Local release = Object::New(env->isolate()); @@ -2075,16 +2147,12 @@ void SetupProcessObject(Environment* env, READONLY_PROPERTY(release, "name", OneByteString(env->isolate(), NODE_RELEASE)); - trace_process->BeginDictionary("release"); auto traced_release = tracing::TracedValue::Create(); - trace_process->SetString("name", NODE_RELEASE); #if NODE_VERSION_IS_LTS READONLY_PROPERTY(release, "lts", OneByteString(env->isolate(), NODE_VERSION_LTS_CODENAME)); - trace_process->SetString("lts", NODE_VERSION_LTS_CODENAME); #endif - trace_process->EndDictionary(); // if this is a release build and no explicit base has been set // substitute the standard release download URL @@ -2119,28 +2187,19 @@ void SetupProcessObject(Environment* env, // process.argv Local arguments = Array::New(env->isolate(), argc); - trace_process->BeginArray("argv"); for (int i = 0; i < argc; ++i) { arguments->Set(i, String::NewFromUtf8(env->isolate(), argv[i])); - trace_process->AppendString(argv[i]); } - trace_process->EndArray(); process->Set(FIXED_ONE_BYTE_STRING(env->isolate(), "argv"), arguments); // process.execArgv Local exec_arguments = Array::New(env->isolate(), exec_argc); - trace_process->BeginArray("execArgv"); for (int i = 0; i < exec_argc; ++i) { exec_arguments->Set(i, String::NewFromUtf8(env->isolate(), exec_argv[i])); - trace_process->AppendString(exec_argv[i]); } - trace_process->EndArray(); process->Set(FIXED_ONE_BYTE_STRING(env->isolate(), "execArgv"), exec_arguments); - TRACE_EVENT_METADATA1("__metadata", "node", - "process", std::move(trace_process)); - // create process.env Local process_env_template = ObjectTemplate::New(env->isolate()); @@ -3573,17 +3632,6 @@ inline int Start(Isolate* isolate, IsolateData* isolate_data, Environment env(isolate_data, context, v8_platform.GetTracingAgent()); env.Start(argc, argv, exec_argc, exec_argv, v8_is_profiling); - char name_buffer[512]; - if (uv_get_process_title(name_buffer, sizeof(name_buffer)) == 0) { - // Only emit the metadata event if the title can be retrieved successfully. - // Ignore it otherwise. - TRACE_EVENT_METADATA1("__metadata", "process_name", "name", - TRACE_STR_COPY(name_buffer)); - } - TRACE_EVENT_METADATA1("__metadata", "version", "node", NODE_VERSION_STRING); - TRACE_EVENT_METADATA1("__metadata", "thread_name", "name", - "JavaScriptMainThread"); - const char* path = argc > 1 ? argv[1] : nullptr; StartInspector(&env, path, debug_options); diff --git a/src/node_internals.h b/src/node_internals.h index 53fc5015ac8294..860566e314cb98 100644 --- a/src/node_internals.h +++ b/src/node_internals.h @@ -32,7 +32,6 @@ #include "uv.h" #include "v8.h" #include "tracing/trace_event.h" -#include "tracing/traced_value.h" #include "node_perf_common.h" #include "node_debug_options.h" #include "node_api.h" diff --git a/test/parallel/test-trace-events-metadata.js b/test/parallel/test-trace-events-metadata.js index a0d5a96984f31a..01e019c1906956 100644 --- a/test/parallel/test-trace-events-metadata.js +++ b/test/parallel/test-trace-events-metadata.js @@ -62,9 +62,7 @@ proc.once('exit', common.mustCall(() => { trace.args.process.platform === process.platform && trace.args.process.release.name === process.release.name && (!process.release.lts || - trace.args.process.release.lts === process.release.lts) && - Array.isArray(trace.args.process.argv) && - Array.isArray(trace.args.process.execArgv))); + trace.args.process.release.lts === process.release.lts))); if (!common.isSunOS) { // Changing process.title is currently unsupported on SunOS/SmartOS From 8e2c8c9b94ad2402126c19c44f4b59152e6da250 Mon Sep 17 00:00:00 2001 From: James M Snell Date: Thu, 12 Jul 2018 14:30:12 -0700 Subject: [PATCH 3/3] [Squash] missed a delete --- src/node.cc | 2 -- 1 file changed, 2 deletions(-) diff --git a/src/node.cc b/src/node.cc index 533340eb17a96d..9b3fc57e3c6625 100644 --- a/src/node.cc +++ b/src/node.cc @@ -2147,8 +2147,6 @@ void SetupProcessObject(Environment* env, READONLY_PROPERTY(release, "name", OneByteString(env->isolate(), NODE_RELEASE)); - auto traced_release = tracing::TracedValue::Create(); - #if NODE_VERSION_IS_LTS READONLY_PROPERTY(release, "lts", OneByteString(env->isolate(), NODE_VERSION_LTS_CODENAME));