Skip to content

Commit 79992a0

Browse files
committed
Have a config option for collecting async IDs
1 parent a694680 commit 79992a0

File tree

4 files changed

+91
-58
lines changed

4 files changed

+91
-58
lines changed

bindings/profilers/wall.cc

Lines changed: 38 additions & 52 deletions
Original file line numberDiff line numberDiff line change
@@ -474,11 +474,13 @@ std::shared_ptr<ContextsByNode> WallProfiler::GetContextsByNode(
474474
sampleContext.context.get()->Get(isolate))
475475
.Check();
476476
}
477-
timedContext
478-
->Set(v8Context,
479-
asyncIdKey,
480-
NewNumberFromInt64(isolate, sampleContext.async_id))
481-
.Check();
477+
if (collectAsyncId_) {
478+
timedContext
479+
->Set(v8Context,
480+
asyncIdKey,
481+
NewNumberFromInt64(isolate, sampleContext.async_id))
482+
.Check();
483+
}
482484
}
483485
}
484486
array->Set(v8Context, array->Length(), timedContext).Check();
@@ -513,6 +515,7 @@ WallProfiler::WallProfiler(std::chrono::microseconds samplingPeriod,
513515
bool withContexts,
514516
bool workaroundV8Bug,
515517
bool collectCpuTime,
518+
bool collectAsyncId,
516519
bool isMainThread)
517520
: samplingPeriod_(samplingPeriod),
518521
includeLines_(includeLines),
@@ -524,6 +527,7 @@ WallProfiler::WallProfiler(std::chrono::microseconds samplingPeriod,
524527
// event just after triggers the issue.
525528
workaroundV8Bug_ = workaroundV8Bug && DD_WALL_USE_SIGPROF && detectV8Bug_;
526529
collectCpuTime_ = collectCpuTime && withContexts;
530+
collectAsyncId_ = collectAsyncId && withContexts;
527531

528532
if (withContexts_) {
529533
contexts_.reserve(duration * 2 / samplingPeriod);
@@ -544,8 +548,10 @@ WallProfiler::WallProfiler(std::chrono::microseconds samplingPeriod,
544548
jsArray_ = v8::Global<v8::Uint32Array>(isolate, jsArray);
545549
std::fill(fields_, fields_ + kFieldCount, 0);
546550

547-
isolate->AddGCPrologueCallback(&GCPrologueCallback, this);
548-
isolate->AddGCEpilogueCallback(&GCEpilogueCallback, this);
551+
if (collectAsyncId_) {
552+
isolate->AddGCPrologueCallback(&GCPrologueCallback, this);
553+
isolate->AddGCEpilogueCallback(&GCEpilogueCallback, this);
554+
}
549555
}
550556

551557
WallProfiler::~WallProfiler() {
@@ -559,13 +565,21 @@ void WallProfiler::Dispose(Isolate* isolate) {
559565

560566
g_profilers.RemoveProfiler(isolate, this);
561567

562-
if (isolate != nullptr) {
568+
if (isolate != nullptr && collectAsyncId_) {
563569
isolate->RemoveGCPrologueCallback(&GCPrologueCallback, this);
564570
isolate->RemoveGCEpilogueCallback(&GCEpilogueCallback, this);
565571
}
566572
}
567573
}
568574

575+
#define DD_WALL_PROFILER_GET_BOOLEAN_CONFIG(name) \
576+
auto name##Value = \
577+
Nan::Get(arg, Nan::New<v8::String>(#name).ToLocalChecked()); \
578+
if (name##Value.IsEmpty() || !name##Value.ToLocalChecked()->IsBoolean()) { \
579+
return Nan::ThrowTypeError(#name " must be a boolean."); \
580+
} \
581+
bool name = name##Value.ToLocalChecked().As<v8::Boolean>()->Value();
582+
569583
NAN_METHOD(WallProfiler::New) {
570584
if (info.Length() != 1 || !info[0]->IsObject()) {
571585
return Nan::ThrowTypeError("WallProfiler must have one object argument.");
@@ -604,50 +618,12 @@ NAN_METHOD(WallProfiler::New) {
604618
return Nan::ThrowTypeError("Duration must not be less than sample rate.");
605619
}
606620

607-
auto lineNumbersValue =
608-
Nan::Get(arg, Nan::New<v8::String>("lineNumbers").ToLocalChecked());
609-
if (lineNumbersValue.IsEmpty() ||
610-
!lineNumbersValue.ToLocalChecked()->IsBoolean()) {
611-
return Nan::ThrowTypeError("lineNumbers must be a boolean.");
612-
}
613-
bool lineNumbers =
614-
lineNumbersValue.ToLocalChecked().As<v8::Boolean>()->Value();
615-
616-
auto withContextsValue =
617-
Nan::Get(arg, Nan::New<v8::String>("withContexts").ToLocalChecked());
618-
if (withContextsValue.IsEmpty() ||
619-
!withContextsValue.ToLocalChecked()->IsBoolean()) {
620-
return Nan::ThrowTypeError("withContext must be a boolean.");
621-
}
622-
bool withContexts =
623-
withContextsValue.ToLocalChecked().As<v8::Boolean>()->Value();
624-
625-
auto workaroundV8BugValue =
626-
Nan::Get(arg, Nan::New<v8::String>("workaroundV8Bug").ToLocalChecked());
627-
if (workaroundV8BugValue.IsEmpty() ||
628-
!workaroundV8BugValue.ToLocalChecked()->IsBoolean()) {
629-
return Nan::ThrowTypeError("workaroundV8Bug must be a boolean.");
630-
}
631-
bool workaroundV8Bug =
632-
workaroundV8BugValue.ToLocalChecked().As<v8::Boolean>()->Value();
633-
634-
auto collectCpuTimeValue =
635-
Nan::Get(arg, Nan::New<v8::String>("collectCpuTime").ToLocalChecked());
636-
if (collectCpuTimeValue.IsEmpty() ||
637-
!collectCpuTimeValue.ToLocalChecked()->IsBoolean()) {
638-
return Nan::ThrowTypeError("collectCpuTime must be a boolean.");
639-
}
640-
bool collectCpuTime =
641-
collectCpuTimeValue.ToLocalChecked().As<v8::Boolean>()->Value();
642-
643-
auto isMainThreadValue =
644-
Nan::Get(arg, Nan::New<v8::String>("isMainThread").ToLocalChecked());
645-
if (isMainThreadValue.IsEmpty() ||
646-
!isMainThreadValue.ToLocalChecked()->IsBoolean()) {
647-
return Nan::ThrowTypeError("isMainThread must be a boolean.");
648-
}
649-
bool isMainThread =
650-
isMainThreadValue.ToLocalChecked().As<v8::Boolean>()->Value();
621+
DD_WALL_PROFILER_GET_BOOLEAN_CONFIG(lineNumbers);
622+
DD_WALL_PROFILER_GET_BOOLEAN_CONFIG(withContexts);
623+
DD_WALL_PROFILER_GET_BOOLEAN_CONFIG(workaroundV8Bug);
624+
DD_WALL_PROFILER_GET_BOOLEAN_CONFIG(collectCpuTime);
625+
DD_WALL_PROFILER_GET_BOOLEAN_CONFIG(collectAsyncId);
626+
DD_WALL_PROFILER_GET_BOOLEAN_CONFIG(isMainThread);
651627

652628
if (withContexts && !DD_WALL_USE_SIGPROF) {
653629
return Nan::ThrowTypeError("Contexts are not supported.");
@@ -657,6 +633,10 @@ NAN_METHOD(WallProfiler::New) {
657633
return Nan::ThrowTypeError("Cpu time collection requires contexts.");
658634
}
659635

636+
if (collectAsyncId && !withContexts) {
637+
return Nan::ThrowTypeError("Async ID collection requires contexts.");
638+
}
639+
660640
if (lineNumbers && withContexts) {
661641
// Currently custom contexts are not compatible with caller line
662642
// information, because it's not possible to associate context with line
@@ -682,6 +662,7 @@ NAN_METHOD(WallProfiler::New) {
682662
withContexts,
683663
workaroundV8Bug,
684664
collectCpuTime,
665+
collectAsyncId,
685666
isMainThread);
686667
obj->Wrap(info.This());
687668
info.GetReturnValue().Set(info.This());
@@ -693,6 +674,8 @@ NAN_METHOD(WallProfiler::New) {
693674
}
694675
}
695676

677+
#undef DD_WALL_PROFILER_GET_BOOLEAN_CONFIG
678+
696679
NAN_METHOD(WallProfiler::Start) {
697680
WallProfiler* wallProfiler =
698681
Nan::ObjectWrap::Unwrap<WallProfiler>(info.Holder());
@@ -1052,6 +1035,9 @@ int64_t GetAsyncIdNoGC(v8::Isolate* isolate) {
10521035
}
10531036

10541037
int64_t WallProfiler::GetAsyncId(v8::Isolate* isolate) {
1038+
if (!collectAsyncId_) {
1039+
return -1;
1040+
}
10551041
auto curGcCount = gcCount.load(std::memory_order_relaxed);
10561042
std::atomic_signal_fence(std::memory_order_acquire);
10571043
if (curGcCount > 0) {

bindings/profilers/wall.hh

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -71,6 +71,7 @@ class WallProfiler : public Nan::ObjectWrap {
7171
bool workaroundV8Bug_;
7272
static inline constexpr bool detectV8Bug_ = true;
7373
bool collectCpuTime_;
74+
bool collectAsyncId_;
7475
bool isMainThread_;
7576
int v8ProfilerStuckEventLoopDetected_ = 0;
7677
ProcessCpuClock::time_point startProcessCpuTime_{};
@@ -120,6 +121,7 @@ class WallProfiler : public Nan::ObjectWrap {
120121
bool withContexts,
121122
bool workaroundV8bug,
122123
bool collectCpuTime,
124+
bool collectAsyncId,
123125
bool isMainThread);
124126

125127
v8::Local<v8::Value> GetContext(v8::Isolate*);

ts/src/time-profiler.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -66,6 +66,7 @@ export interface TimeProfilerOptions {
6666
withContexts?: boolean;
6767
workaroundV8Bug?: boolean;
6868
collectCpuTime?: boolean;
69+
collectAsyncId?: boolean;
6970
}
7071

7172
const DEFAULT_OPTIONS: TimeProfilerOptions = {
@@ -75,6 +76,7 @@ const DEFAULT_OPTIONS: TimeProfilerOptions = {
7576
withContexts: false,
7677
workaroundV8Bug: true,
7778
collectCpuTime: false,
79+
collectAsyncId: false,
7880
};
7981

8082
export async function profile(options: TimeProfilerOptions = {}) {

ts/test/test-time-profiler.ts

Lines changed: 49 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -39,7 +39,7 @@ describe('Time Profiler', () => {
3939
assert.equal(profile.stringTable.strings!.indexOf('(program)'), -1);
4040
});
4141

42-
it('should update state', function () {
42+
it('should update state', function shouldUpdateState() {
4343
if (process.platform !== 'darwin' && process.platform !== 'linux') {
4444
this.skip();
4545
}
@@ -90,7 +90,7 @@ describe('Time Profiler', () => {
9090
assert(checked, 'No context found');
9191
});
9292

93-
it('should assign labels', function () {
93+
it('should have labels', function shouldHaveLabels() {
9494
if (process.platform !== 'darwin' && process.platform !== 'linux') {
9595
this.skip();
9696
}
@@ -129,10 +129,8 @@ describe('Time Profiler', () => {
129129
if (!context) {
130130
return {};
131131
}
132-
assert(
133-
typeof context.asyncId === 'number',
134-
'context.asyncId should be a number'
135-
);
132+
// Does not collect async IDs by default
133+
assert(typeof context.asyncId === 'undefined');
136134
const labels: LabelSet = {};
137135
for (const [key, value] of Object.entries(context.context ?? {})) {
138136
if (typeof value === 'string') {
@@ -356,6 +354,51 @@ describe('Time Profiler', () => {
356354
});
357355
});
358356

357+
it('should have async IDs when enabled', async function shouldCollectAsyncIDs() {
358+
if (process.platform !== 'darwin' && process.platform !== 'linux') {
359+
this.skip();
360+
}
361+
this.timeout(3000);
362+
363+
time.start({
364+
intervalMicros: PROFILE_OPTIONS.intervalMicros,
365+
durationMillis: PROFILE_OPTIONS.durationMillis,
366+
withContexts: true,
367+
lineNumbers: false,
368+
collectAsyncId: true,
369+
});
370+
let setDone: () => void;
371+
const done = new Promise<void>(resolve => {
372+
setDone = resolve;
373+
});
374+
375+
const testStart = hrtime.bigint();
376+
const testDurationNanos = PROFILE_OPTIONS.durationMillis * 1_000_000;
377+
setTimeout(loop, 0);
378+
379+
function loop() {
380+
const loopDurationNanos = PROFILE_OPTIONS.intervalMicros * 1_000;
381+
const loopStart = hrtime.bigint();
382+
while (hrtime.bigint() - loopStart < loopDurationNanos);
383+
if (hrtime.bigint() - testStart < testDurationNanos) {
384+
setTimeout(loop, 0);
385+
} else {
386+
setDone();
387+
}
388+
}
389+
390+
await done;
391+
392+
let asyncIdObserved = false;
393+
time.stop(false, ({context}: GenerateTimeLabelsArgs) => {
394+
if (!asyncIdObserved && typeof context?.asyncId === 'number') {
395+
asyncIdObserved = context?.asyncId !== -1;
396+
}
397+
return {};
398+
});
399+
assert(asyncIdObserved, 'Async ID was not observed');
400+
});
401+
359402
describe('profile (w/ stubs)', () => {
360403
// eslint-disable-next-line @typescript-eslint/no-explicit-any
361404
const sinonStubs: Array<sinon.SinonStub<any, any>> = [];

0 commit comments

Comments
 (0)