Skip to content

[Scheduler Profiler] Use microsecond precision #17010

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
acdlite merged 1 commit into from
Oct 7, 2019
Merged

[Scheduler Profiler] Use microsecond precision #17010

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
35 changes: 19 additions & 16 deletions packages/scheduler/src/SchedulerProfiling.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -103,13 +103,16 @@ export function stopLoggingProfilingEvents(): ArrayBuffer | null {

export function markTaskStart(
task: {id: number, priorityLevel: PriorityLevel},
time: number,
ms: number,
) {
if (enableProfiling) {
profilingState[QUEUE_SIZE]++;

if (eventLog !== null) {
logEvent([TaskStartEvent, time, task.id, task.priorityLevel]);
// performance.now returns a float, representing milliseconds. When the
// event is logged, it's coerced to an int. Convert to microseconds to
// maintain extra degrees of precision.
logEvent([TaskStartEvent, ms * 1000, task.id, task.priorityLevel]);
}
}
}
Expand All @@ -119,15 +122,15 @@ export function markTaskCompleted(
id: number,
priorityLevel: PriorityLevel,
},
time: number,
ms: number,
) {
if (enableProfiling) {
profilingState[PRIORITY] = NoPriority;
profilingState[CURRENT_TASK_ID] = 0;
profilingState[QUEUE_SIZE]--;

if (eventLog !== null) {
logEvent([TaskCompleteEvent, time, task.id]);
logEvent([TaskCompleteEvent, ms * 1000, task.id]);
}
}
}
Expand All @@ -137,13 +140,13 @@ export function markTaskCanceled(
id: number,
priorityLevel: PriorityLevel,
},
time: number,
ms: number,
) {
if (enableProfiling) {
profilingState[QUEUE_SIZE]--;

if (eventLog !== null) {
logEvent([TaskCancelEvent, time, task.id]);
logEvent([TaskCancelEvent, ms * 1000, task.id]);
}
}
}
Expand All @@ -153,22 +156,22 @@ export function markTaskErrored(
id: number,
priorityLevel: PriorityLevel,
},
time: number,
ms: number,
) {
if (enableProfiling) {
profilingState[PRIORITY] = NoPriority;
profilingState[CURRENT_TASK_ID] = 0;
profilingState[QUEUE_SIZE]--;

if (eventLog !== null) {
logEvent([TaskErrorEvent, time, task.id]);
logEvent([TaskErrorEvent, ms * 1000, task.id]);
}
}
}

export function markTaskRun(
task: {id: number, priorityLevel: PriorityLevel},
time: number,
ms: number,
) {
if (enableProfiling) {
runIdCounter++;
Expand All @@ -178,37 +181,37 @@ export function markTaskRun(
profilingState[CURRENT_RUN_ID] = runIdCounter;

if (eventLog !== null) {
logEvent([TaskRunEvent, time, task.id, runIdCounter]);
logEvent([TaskRunEvent, ms * 1000, task.id, runIdCounter]);
}
}
}

export function markTaskYield(task: {id: number}, time: number) {
export function markTaskYield(task: {id: number}, ms: number) {
if (enableProfiling) {
profilingState[PRIORITY] = NoPriority;
profilingState[CURRENT_TASK_ID] = 0;
profilingState[CURRENT_RUN_ID] = 0;

if (eventLog !== null) {
logEvent([TaskYieldEvent, time, task.id, runIdCounter]);
logEvent([TaskYieldEvent, ms * 1000, task.id, runIdCounter]);
}
}
}

export function markSchedulerSuspended(time: number) {
export function markSchedulerSuspended(ms: number) {
if (enableProfiling) {
mainThreadIdCounter++;

if (eventLog !== null) {
logEvent([SchedulerSuspendEvent, time, mainThreadIdCounter]);
logEvent([SchedulerSuspendEvent, ms * 1000, mainThreadIdCounter]);
}
}
}

export function markSchedulerUnsuspended(time: number) {
export function markSchedulerUnsuspended(ms: number) {
if (enableProfiling) {
if (eventLog !== null) {
logEvent([SchedulerResumeEvent, time, mainThreadIdCounter]);
logEvent([SchedulerResumeEvent, ms * 1000, mainThreadIdCounter]);
}
}
}
11 changes: 6 additions & 5 deletions packages/scheduler/src/__tests__/SchedulerProfiling-test.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -213,15 +213,16 @@ describe('Scheduler', () => {

// Now we can render the tasks as a flamegraph.
const labelColumnWidth = 30;
const msPerChar = 50;
// Scheduler event times are in microseconds
const microsecondsPerChar = 50000;

let result = '';

const mainThreadLabelColumn = '!!! Main thread ';
let mainThreadTimelineColumn = '';
let isMainThreadBusy = true;
for (const time of mainThreadRuns) {
const index = time / msPerChar;
const index = time / microsecondsPerChar;
mainThreadTimelineColumn += (isMainThreadBusy ? '█' : '░').repeat(
index - mainThreadTimelineColumn.length,
);
Expand All @@ -244,18 +245,18 @@ describe('Scheduler', () => {
labelColumn += ' '.repeat(labelColumnWidth - labelColumn.length - 1);

// Add empty space up until the start mark
let timelineColumn = ' '.repeat(task.start / msPerChar);
let timelineColumn = ' '.repeat(task.start / microsecondsPerChar);

let isRunning = false;
for (const time of task.runs) {
const index = time / msPerChar;
const index = time / microsecondsPerChar;
timelineColumn += (isRunning ? '█' : '░').repeat(
index - timelineColumn.length,
);
isRunning = !isRunning;
}

const endIndex = task.end / msPerChar;
const endIndex = task.end / microsecondsPerChar;
timelineColumn += (isRunning ? '█' : '░').repeat(
endIndex - timelineColumn.length,
);
Expand Down