GeezerVison is showing github.com — src: trace threadpool event · nodejs/node@4634aa9
File treeExpand file treeCollapse file tree Open diff view settings Expand file treeCollapse file tree Open diff view settings Collapse file Copy file name to clipboardExpand all lines: doc/api/tracing.md +4Lines changed: 4 additions & 0 deletions - Display the source diff
- Display the rich diff
| Original file line number | Diff line number | Diff line change |
|---|
@@ -22,6 +22,10 @@ The available categories are: | 22 | 22 | * `node.bootstrap`: Enables capture of Node.js bootstrap milestones. | 23 | 23 | * `node.console`: Enables capture of `console.time()` and `console.count()` | 24 | 24 | output. | | 25 | +* `node.threadpoolwork.sync`: Enables capture of trace data for threadpool | | 26 | + synchronous operations, such as `blob`, `zlib`, `crypto` and `node_api`. | | 27 | +* `node.threadpoolwork.async`: Enables capture of trace data for threadpool | | 28 | + asynchronous operations, such as `blob`, `zlib`, `crypto` and `node_api`. | 25 | 29 | * `node.dns.native`: Enables capture of trace data for DNS queries. | 26 | 30 | * `node.net.native`: Enables capture of trace data for network. | 27 | 31 | * `node.environment`: Enables capture of Node.js Environment milestones. | |
Collapse file Copy file name to clipboardExpand all lines: src/crypto/crypto_util.h +6-7Lines changed: 6 additions & 7 deletions | Original file line number | Diff line number | Diff line change |
|---|
@@ -333,14 +333,13 @@ class CryptoJob : public AsyncWrap, public ThreadPoolWork { | 333 | 333 | public: | 334 | 334 | using AdditionalParams = typename CryptoJobTraits::AdditionalParameters; | 335 | 335 |
| 336 | | - explicit CryptoJob( | 337 | | - Environment* env, | 338 | | - v8::Local<v8::Object> object, | 339 | | - AsyncWrap::ProviderType type, | 340 | | - CryptoJobMode mode, | 341 | | - AdditionalParams&& params) | | 336 | + explicit CryptoJob(Environment* env, | | 337 | + v8::Local<v8::Object> object, | | 338 | + AsyncWrap::ProviderType type, | | 339 | + CryptoJobMode mode, | | 340 | + AdditionalParams&& params) | 342 | 341 | : AsyncWrap(env, object, type), | 343 | | - ThreadPoolWork(env), | | 342 | + ThreadPoolWork(env, "crypto"), | 344 | 343 | mode_(mode), | 345 | 344 | params_(std::move(params)) { | 346 | 345 | // If the CryptoJob is async, then the instance will be | |
Collapse file Copy file name to clipboardExpand all lines: src/node_api.cc +1-1Lines changed: 1 addition & 1 deletion | Original file line number | Diff line number | Diff line change |
|---|
@@ -1069,7 +1069,7 @@ class Work : public node::AsyncResource, public node::ThreadPoolWork { | 1069 | 1069 | env->isolate, | 1070 | 1070 | async_resource, | 1071 | 1071 | *v8::String::Utf8Value(env->isolate, async_resource_name)), | 1072 | | - ThreadPoolWork(env->node_env()), | | 1072 | + ThreadPoolWork(env->node_env(), "node_api"), | 1073 | 1073 | _env(env), | 1074 | 1074 | _data(data), | 1075 | 1075 | _execute(execute), | |
Collapse file Copy file name to clipboardExpand all lines: src/node_blob.cc +5-6Lines changed: 5 additions & 6 deletions | Original file line number | Diff line number | Diff line change |
|---|
@@ -306,13 +306,12 @@ void Blob::GetDataObject(const v8::FunctionCallbackInfo<v8::Value>& args) { | 306 | 306 | } | 307 | 307 | } | 308 | 308 |
| 309 | | -FixedSizeBlobCopyJob::FixedSizeBlobCopyJob( | 310 | | - Environment* env, | 311 | | - Local<Object> object, | 312 | | - Blob* blob, | 313 | | - FixedSizeBlobCopyJob::Mode mode) | | 309 | +FixedSizeBlobCopyJob::FixedSizeBlobCopyJob(Environment* env, | | 310 | + Local<Object> object, | | 311 | + Blob* blob, | | 312 | + FixedSizeBlobCopyJob::Mode mode) | 314 | 313 | : AsyncWrap(env, object, AsyncWrap::PROVIDER_FIXEDSIZEBLOBCOPY), | 315 | | - ThreadPoolWork(env), | | 314 | + ThreadPoolWork(env, "blob"), | 316 | 315 | mode_(mode) { | 317 | 316 | if (mode == FixedSizeBlobCopyJob::Mode::SYNC) MakeWeak(); | 318 | 317 | source_ = blob->entries(); | |
Collapse file Copy file name to clipboardExpand all lines: src/node_internals.h +3-1Lines changed: 3 additions & 1 deletion | Original file line number | Diff line number | Diff line change |
|---|
@@ -258,7 +258,8 @@ class DebugSealHandleScope { | 258 | 258 |
| 259 | 259 | class ThreadPoolWork { | 260 | 260 | public: | 261 | | - explicit inline ThreadPoolWork(Environment* env) : env_(env) { | | 261 | + explicit inline ThreadPoolWork(Environment* env, const char* type) | | 262 | + : env_(env), type_(type) { | 262 | 263 | CHECK_NOT_NULL(env); | 263 | 264 | } | 264 | 265 | inline virtual ~ThreadPoolWork() = default; | @@ -274,6 +275,7 @@ class ThreadPoolWork { | 274 | 275 | private: | 275 | 276 | Environment* env_; | 276 | 277 | uv_work_t work_req_; | | 278 | + const char* type_; | 277 | 279 | }; | 278 | 280 |
| 279 | 281 | #define TRACING_CATEGORY_NODE "node" | |
Collapse file Copy file name to clipboardExpand all lines: src/node_v8_platform-inl.h +2-1Lines changed: 2 additions & 1 deletion | Original file line number | Diff line number | Diff line change |
|---|
@@ -109,14 +109,15 @@ struct V8Platform { | 109 | 109 | if (!initialized_) | 110 | 110 | return; | 111 | 111 | initialized_ = false; | 112 | | - | | 112 | + node::tracing::TraceEventHelper::SetAgent(nullptr); | 113 | 113 | StopTracingAgent(); | 114 | 114 | platform_->Shutdown(); | 115 | 115 | delete platform_; | 116 | 116 | platform_ = nullptr; | 117 | 117 | // Destroy tracing after the platform (and platform threads) have been | 118 | 118 | // stopped. | 119 | 119 | tracing_agent_.reset(nullptr); | | 120 | + // The observer remove itself in OnTraceEnabled | 120 | 121 | trace_state_observer_.reset(nullptr); | 121 | 122 | } | 122 | 123 |
| |
Collapse file Copy file name to clipboardExpand all lines: src/node_zlib.cc +1-1Lines changed: 1 addition & 1 deletion | Original file line number | Diff line number | Diff line change |
|---|
@@ -259,7 +259,7 @@ class CompressionStream : public AsyncWrap, public ThreadPoolWork { | 259 | 259 |
| 260 | 260 | CompressionStream(Environment* env, Local<Object> wrap) | 261 | 261 | : AsyncWrap(env, wrap, AsyncWrap::PROVIDER_ZLIB), | 262 | | - ThreadPoolWork(env), | | 262 | + ThreadPoolWork(env, "zlib"), | 263 | 263 | write_result_(nullptr) { | 264 | 264 | MakeWeak(); | 265 | 265 | } | |
Collapse file Copy file name to clipboardExpand all lines: src/threadpoolwork-inl.h +14-1Lines changed: 14 additions & 1 deletion | Original file line number | Diff line number | Diff line change |
|---|
| 24 | 24 |
| 25 | 25 | #if defined(NODE_WANT_INTERNALS) && NODE_WANT_INTERNALS | 26 | 26 |
| 27 | | -#include "util-inl.h" | 28 | 27 | #include "node_internals.h" | | 28 | +#include "tracing/trace_event.h" | | 29 | +#include "util-inl.h" | 29 | 30 |
| 30 | 31 | namespace node { | 31 | 32 |
| 32 | 33 | void ThreadPoolWork::ScheduleWork() { | 33 | 34 | env_->IncreaseWaitingRequestCounter(); | | 35 | + TRACE_EVENT_NESTABLE_ASYNC_BEGIN0( | | 36 | + TRACING_CATEGORY_NODE2(threadpoolwork, async), type_, this); | 34 | 37 | int status = uv_queue_work( | 35 | 38 | env_->event_loop(), | 36 | 39 | &work_req_, | 37 | 40 | [](uv_work_t* req) { | 38 | 41 | ThreadPoolWork* self = ContainerOf(&ThreadPoolWork::work_req_, req); | | 42 | + TRACE_EVENT_BEGIN0(TRACING_CATEGORY_NODE2(threadpoolwork, sync), | | 43 | + self->type_); | 39 | 44 | self->DoThreadPoolWork(); | | 45 | + TRACE_EVENT_END0(TRACING_CATEGORY_NODE2(threadpoolwork, sync), | | 46 | + self->type_); | 40 | 47 | }, | 41 | 48 | [](uv_work_t* req, int status) { | 42 | 49 | ThreadPoolWork* self = ContainerOf(&ThreadPoolWork::work_req_, req); | 43 | 50 | self->env_->DecreaseWaitingRequestCounter(); | | 51 | + TRACE_EVENT_NESTABLE_ASYNC_END1( | | 52 | + TRACING_CATEGORY_NODE2(threadpoolwork, async), | | 53 | + self->type_, | | 54 | + self, | | 55 | + "result", | | 56 | + status); | 44 | 57 | self->AfterThreadPoolWork(status); | 45 | 58 | }); | 46 | 59 | CHECK_EQ(status, 0); | |
Collapse file Copy file name to clipboardExpand all lines: src/tracing/trace_event.cc +7-2Lines changed: 7 additions & 2 deletions | Original file line number | Diff line number | Diff line change |
|---|
@@ -8,8 +8,13 @@ Agent* g_agent = nullptr; | 8 | 8 | v8::TracingController* g_controller = nullptr; | 9 | 9 |
| 10 | 10 | void TraceEventHelper::SetAgent(Agent* agent) { | 11 | | - g_agent = agent; | 12 | | - g_controller = agent->GetTracingController(); | | 11 | + if (agent) { | | 12 | + g_agent = agent; | | 13 | + g_controller = agent->GetTracingController(); | | 14 | + } else { | | 15 | + g_agent = nullptr; | | 16 | + g_controller = nullptr; | | 17 | + } | 13 | 18 | } | 14 | 19 |
| 15 | 20 | Agent* TraceEventHelper::GetAgent() { | |
Collapse file Copy file name to clipboard +71Lines changed: 71 additions & 0 deletions | Original file line number | Diff line number | Diff line change |
|---|
| | 1 | +'use strict'; | | 2 | +const common = require('../common'); | | 3 | +const assert = require('assert'); | | 4 | +const cp = require('child_process'); | | 5 | +const fs = require('fs'); | | 6 | +const path = require('path'); | | 7 | +const tmpdir = require('../common/tmpdir'); | | 8 | + | | 9 | +if (!common.hasCrypto) | | 10 | + common.skip('missing crypto'); | | 11 | + | | 12 | +const { hkdf } = require('crypto'); | | 13 | +const { deflate } = require('zlib'); | | 14 | +const { Blob } = require('buffer'); | | 15 | + | | 16 | +if (process.env.isChild === '1') { | | 17 | + hkdf('sha512', 'key', 'salt', 'info', 64, () => {}); | | 18 | + deflate('hello', () => {}); | | 19 | + // Make async call | | 20 | + const blob = new Blob(['h'.repeat(4096 * 2)]); | | 21 | + blob.arrayBuffer(); | | 22 | + return; | | 23 | +} | | 24 | + | | 25 | +tmpdir.refresh(); | | 26 | +const FILE_NAME = path.join(tmpdir.path, 'node_trace.1.log'); | | 27 | + | | 28 | +cp.spawnSync(process.execPath, | | 29 | + [ | | 30 | + '--trace-events-enabled', | | 31 | + '--trace-event-categories', | | 32 | + 'node.threadpoolwork.sync,node.threadpoolwork.async', | | 33 | + __filename, | | 34 | + ], | | 35 | + { | | 36 | + cwd: tmpdir.path, | | 37 | + env: { | | 38 | + ...process.env, | | 39 | + isChild: '1', | | 40 | + }, | | 41 | + }); | | 42 | + | | 43 | +assert(fs.existsSync(FILE_NAME)); | | 44 | +const data = fs.readFileSync(FILE_NAME); | | 45 | +const traces = JSON.parse(data.toString()).traceEvents; | | 46 | + | | 47 | +assert(traces.length > 0); | | 48 | + | | 49 | +let blobCount = 0; | | 50 | +let zlibCount = 0; | | 51 | +let cryptoCount = 0; | | 52 | + | | 53 | +traces.forEach((item) => { | | 54 | + if ([ | | 55 | + 'node,node.threadpoolwork,node.threadpoolwork.sync', | | 56 | + 'node,node.threadpoolwork,node.threadpoolwork.async', | | 57 | + ].includes(item.cat)) { | | 58 | + if (item.name === 'blob') { | | 59 | + blobCount++; | | 60 | + } else if (item.name === 'zlib') { | | 61 | + zlibCount++; | | 62 | + } else if (item.name === 'crypto') { | | 63 | + cryptoCount++; | | 64 | + } | | 65 | + } | | 66 | +}); | | 67 | + | | 68 | +// There are three types, each type has two async events and sync events at least | | 69 | +assert.ok(blobCount >= 4); | | 70 | +assert.ok(zlibCount >= 4); | | 71 | +assert.ok(cryptoCount >= 4); |
|