mirror of
https://github.com/microsoft/vscode.git
synced 2026-07-10 16:58:55 -05:00
Uses full dark modern theme for component fixtures & implements improved time travel scheduler
This commit is contained in:
committed by
Henning Dieterichs
parent
a832f4adb9
commit
656fbbce25
@@ -2654,3 +2654,8 @@ export class AsyncReader<T> {
|
||||
return this._extendBufferPromise;
|
||||
}
|
||||
}
|
||||
|
||||
export function createTimeout(ms: number, cb: () => void): IDisposable {
|
||||
const t = setTimeout(cb, ms);
|
||||
return toDisposable(() => clearTimeout(t));
|
||||
}
|
||||
|
||||
158
src/vs/base/test/common/executionGraph.test.ts
Normal file
158
src/vs/base/test/common/executionGraph.test.ts
Normal file
@@ -0,0 +1,158 @@
|
||||
/*---------------------------------------------------------------------------------------------
|
||||
* Copyright (c) Microsoft Corporation. All rights reserved.
|
||||
* Licensed under the MIT License. See License.txt in the project root for license information.
|
||||
*--------------------------------------------------------------------------------------------*/
|
||||
|
||||
import assert from 'assert';
|
||||
import { ensureNoDisposablesAreLeakedInTestSuite } from './utils.js';
|
||||
import {
|
||||
ExecutionEvent,
|
||||
ExecutionHistory,
|
||||
ExecutionRoot,
|
||||
renderLaneGraph,
|
||||
renderSwimlanes,
|
||||
} from './executionGraph.js';
|
||||
|
||||
/**
|
||||
* Fluent builder for hand-crafting `ExecutionHistory` literals in tests.
|
||||
* Keeps call sites short: `h.root('A')`, `h.fire(0, 'setTimeout', rootA)`,
|
||||
* `h.fire(16, 'rAF', parentEvent)`.
|
||||
*/
|
||||
class HistoryBuilder {
|
||||
readonly roots: ExecutionRoot[] = [];
|
||||
readonly events: ExecutionEvent[] = [];
|
||||
|
||||
root(label: string): ExecutionRoot {
|
||||
const r: ExecutionRoot = { label };
|
||||
this.roots.push(r);
|
||||
return r;
|
||||
}
|
||||
|
||||
fire(time: number, label: string, parent: ExecutionRoot | ExecutionEvent): ExecutionEvent {
|
||||
const isRoot = this.roots.includes(parent as ExecutionRoot);
|
||||
const root = isRoot ? (parent as ExecutionRoot) : (parent as ExecutionEvent).root;
|
||||
const parentEvent = isRoot ? undefined : (parent as ExecutionEvent);
|
||||
const event: ExecutionEvent = { time, label, root, parent: parentEvent };
|
||||
this.events.push(event);
|
||||
return event;
|
||||
}
|
||||
|
||||
build(): ExecutionHistory {
|
||||
return { roots: this.roots, events: this.events };
|
||||
}
|
||||
}
|
||||
|
||||
suite('executionGraph', () => {
|
||||
ensureNoDisposablesAreLeakedInTestSuite();
|
||||
|
||||
test('renderSwimlanes: empty history', () => {
|
||||
assert.strictEqual(renderSwimlanes({ roots: [], events: [] }), '(empty history)');
|
||||
});
|
||||
|
||||
test('renderSwimlanes: single root, linear chain', () => {
|
||||
const h = new HistoryBuilder();
|
||||
const A = h.root('A');
|
||||
const t0 = h.fire(0, 'setTimeout', A);
|
||||
const t1 = h.fire(16, 'rAF', t0);
|
||||
h.fire(32, 'rAF', t1);
|
||||
|
||||
// Slot-based indentation: all events are last-children, so all
|
||||
// share slot 0. No visual indentation for the tree structure.
|
||||
assert.strictEqual(renderSwimlanes(h.build()), [
|
||||
' A',
|
||||
' +0ms ├─ setTimeout',
|
||||
'+16ms └─ rAF',
|
||||
'+32ms └─ rAF',
|
||||
].join('\n'));
|
||||
});
|
||||
|
||||
test('renderSwimlanes: forest with forks across two roots', () => {
|
||||
const h = new HistoryBuilder();
|
||||
const A = h.root('A');
|
||||
const B = h.root('B');
|
||||
|
||||
// A: setTimeout(+0) spawns rAF(+16) and setTimeout(+50)
|
||||
// rAF(+16) -> rAF(+32)
|
||||
const aT0 = h.fire(0, 'setTimeout', A);
|
||||
const bT10 = h.fire(10, 'setTimeout', B);
|
||||
const aRaf16 = h.fire(16, 'requestAnimationFrame', aT0);
|
||||
const bRaf26 = h.fire(26, 'requestAnimationFrame', bT10);
|
||||
h.fire(32, 'requestAnimationFrame', aRaf16);
|
||||
h.fire(46, 'setTimeout', bRaf26);
|
||||
h.fire(50, 'setTimeout', aT0);
|
||||
|
||||
const out = renderSwimlanes(h.build());
|
||||
// Slot-based indentation: last-children share their parent's slot.
|
||||
// B lane: bT10 at slot 0, bRaf26 (last-child) at slot 0, bT46 (last-child) at slot 0.
|
||||
assert.strictEqual(out, [
|
||||
' A B',
|
||||
' +0ms ├─ setTimeout',
|
||||
'+10ms │ | ├─ setTimeout',
|
||||
'+16ms │ ├─ requestAnimationFrame │',
|
||||
'+26ms │ │ └─ requestAnimationFrame',
|
||||
'+32ms │ └─ requestAnimationFrame │',
|
||||
'+46ms │ └─ setTimeout',
|
||||
'+50ms └─ setTimeout',
|
||||
].join('\n'));
|
||||
});
|
||||
|
||||
test('renderSwimlanes: degenerate linked-list tree (5 nodes)', () => {
|
||||
const h = new HistoryBuilder();
|
||||
const A = h.root('A');
|
||||
const e1 = h.fire(0, 'n1', A);
|
||||
const e2 = h.fire(10, 'n2', e1);
|
||||
const e3 = h.fire(20, 'n3', e2);
|
||||
h.fire(30, 'n4', e3);
|
||||
|
||||
assert.strictEqual(renderSwimlanes(h.build()), [
|
||||
' A',
|
||||
' +0ms ├─ n1',
|
||||
'+10ms └─ n2',
|
||||
'+20ms └─ n3',
|
||||
'+30ms └─ n4',
|
||||
].join('\n'));
|
||||
});
|
||||
|
||||
test('renderLaneGraph: degenerate linked-list tree (5 nodes)', () => {
|
||||
const h = new HistoryBuilder();
|
||||
const A = h.root('A');
|
||||
const e1 = h.fire(0, 'n1', A);
|
||||
const e2 = h.fire(10, 'n2', e1);
|
||||
const e3 = h.fire(20, 'n3', e2);
|
||||
h.fire(30, 'n4', e3);
|
||||
|
||||
assert.strictEqual(renderLaneGraph(h.build()), [
|
||||
'+A',
|
||||
'└─╷─ [ +0ms] n1',
|
||||
' └─╷─ [ +10ms] n2',
|
||||
' └─╷─[ +20ms] n3',
|
||||
' └─[ +30ms] n4',
|
||||
].join('\n'));
|
||||
});
|
||||
|
||||
test('renderLaneGraph: forest with forks across two roots', () => {
|
||||
const h = new HistoryBuilder();
|
||||
const A = h.root('A');
|
||||
const B = h.root('B');
|
||||
|
||||
const aT0 = h.fire(0, 'setTimeout', A);
|
||||
const bT10 = h.fire(10, 'setTimeout', B);
|
||||
const aRaf16 = h.fire(16, 'requestAnimationFrame', aT0);
|
||||
const bRaf26 = h.fire(26, 'requestAnimationFrame', bT10);
|
||||
h.fire(32, 'requestAnimationFrame', aRaf16);
|
||||
h.fire(46, 'setTimeout', bRaf26);
|
||||
h.fire(50, 'setTimeout', aT0);
|
||||
|
||||
assert.strictEqual(renderLaneGraph(h.build()), [
|
||||
'+A',
|
||||
'└─╷─ [ +0ms] setTimeout',
|
||||
' │ +B',
|
||||
' │ └─╷─ [ +10ms] setTimeout',
|
||||
' ├───┼─╷─ [ +16ms] requestAnimationFrame',
|
||||
' │ └─┼─╷─[ +26ms] requestAnimationFrame',
|
||||
' │ └─┼─[ +32ms] requestAnimationFrame',
|
||||
' │ └─[ +46ms] setTimeout',
|
||||
' └─────────[ +50ms] setTimeout',
|
||||
].join('\n'));
|
||||
});
|
||||
});
|
||||
475
src/vs/base/test/common/executionGraph.ts
Normal file
475
src/vs/base/test/common/executionGraph.ts
Normal file
@@ -0,0 +1,475 @@
|
||||
/*---------------------------------------------------------------------------------------------
|
||||
* Copyright (c) Microsoft Corporation. All rights reserved.
|
||||
* Licensed under the MIT License. See License.txt in the project root for license information.
|
||||
*--------------------------------------------------------------------------------------------*/
|
||||
|
||||
/**
|
||||
* Plain, renderer-friendly description of an execution history produced by a
|
||||
* traced scheduler. These types have no dependency on the tracing or
|
||||
* scheduling implementation — they can be built by hand in tests or by the
|
||||
* `buildHistoryFromTasks` adapter below.
|
||||
*/
|
||||
|
||||
export interface ExecutionRoot {
|
||||
readonly label: string;
|
||||
}
|
||||
|
||||
export interface ExecutionEvent {
|
||||
/** Relative time (e.g. ms since startTime). Must be >= 0 and non-decreasing in history order. */
|
||||
readonly time: number;
|
||||
readonly label: string;
|
||||
readonly root: ExecutionRoot;
|
||||
/** `undefined` means this event is a direct child of its root. */
|
||||
readonly parent: ExecutionEvent | undefined;
|
||||
/** Caller frame extracted from the scheduling stack trace. */
|
||||
readonly detail?: string;
|
||||
}
|
||||
|
||||
export interface ExecutionHistory {
|
||||
/** Roots in first-appearance order (column order for renderers). */
|
||||
readonly roots: readonly ExecutionRoot[];
|
||||
/** Events in time order. */
|
||||
readonly events: readonly ExecutionEvent[];
|
||||
}
|
||||
|
||||
// -----------------------------------------------------------------------------
|
||||
// Adapter: ScheduledTask[] -> ExecutionHistory
|
||||
// -----------------------------------------------------------------------------
|
||||
|
||||
interface TraceLike {
|
||||
readonly parent: TraceLike | undefined;
|
||||
readonly root: { readonly label: string };
|
||||
}
|
||||
|
||||
interface ScheduledTaskLike {
|
||||
readonly time: number;
|
||||
readonly source: { toString(): string; readonly stackTrace?: string };
|
||||
readonly trace?: TraceLike;
|
||||
}
|
||||
|
||||
/**
|
||||
* A log entry to weave into the history alongside scheduled tasks. Each log is
|
||||
* tagged with the trace that was current when it was emitted.
|
||||
*/
|
||||
export interface LogEntryLike {
|
||||
readonly trace: TraceLike;
|
||||
readonly message: string;
|
||||
}
|
||||
|
||||
/**
|
||||
* Convert a list of scheduled tasks (each carrying a causal `trace`) into a
|
||||
* plain `ExecutionHistory`. Untraced tasks are dropped. A task's parent event
|
||||
* is the most recent earlier task whose `trace` is `task.trace.parent`; if
|
||||
* `task.trace.parent` is the trace root itself, the event has no parent event
|
||||
* (it is a direct child of the root).
|
||||
*
|
||||
* `logs` (if given) are interleaved as synthetic events: each log's parent is
|
||||
* the task event whose trace matches the log's current trace at emission
|
||||
* time (or the nearest ancestor task event), and its time is inherited from
|
||||
* that parent. Within a single parent task, logs are kept in emission order
|
||||
* and inserted directly after the parent event.
|
||||
*/
|
||||
export function buildHistoryFromTasks(
|
||||
tasks: readonly ScheduledTaskLike[],
|
||||
startTime: number,
|
||||
logs: readonly LogEntryLike[] = [],
|
||||
): ExecutionHistory {
|
||||
const rootByTrace = new Map<unknown, ExecutionRoot>();
|
||||
const roots: ExecutionRoot[] = [];
|
||||
const eventByTrace = new Map<unknown, ExecutionEvent>();
|
||||
const taskEvents: ExecutionEvent[] = [];
|
||||
|
||||
for (const task of tasks) {
|
||||
const trace = task.trace;
|
||||
if (!trace) { continue; }
|
||||
|
||||
let root = rootByTrace.get(trace.root);
|
||||
if (!root) {
|
||||
root = { label: trace.root.label };
|
||||
rootByTrace.set(trace.root, root);
|
||||
roots.push(root);
|
||||
}
|
||||
|
||||
// Find the parent event by walking up the trace chain until we hit
|
||||
// either a trace whose event we know, or the trace root.
|
||||
let parentEvent: ExecutionEvent | undefined;
|
||||
for (let p = trace.parent; p; p = p.parent) {
|
||||
const e = eventByTrace.get(p);
|
||||
if (e) { parentEvent = e; break; }
|
||||
}
|
||||
|
||||
const event: ExecutionEvent = {
|
||||
time: task.time - startTime,
|
||||
label: `${task.source}`,
|
||||
root,
|
||||
parent: parentEvent,
|
||||
detail: extractCallerFrame(task.source.stackTrace),
|
||||
};
|
||||
eventByTrace.set(trace, event);
|
||||
taskEvents.push(event);
|
||||
}
|
||||
|
||||
// Group log entries by their parent task event, preserving emission
|
||||
// order within each group. A log without an enclosing task event is
|
||||
// dropped (e.g. logs emitted at root before any task ran).
|
||||
const logsByParent = new Map<ExecutionEvent, ExecutionEvent[]>();
|
||||
for (const entry of logs) {
|
||||
let parentEvent: ExecutionEvent | undefined;
|
||||
for (let p: TraceLike | undefined = entry.trace; p; p = p.parent) {
|
||||
const e = eventByTrace.get(p);
|
||||
if (e) { parentEvent = e; break; }
|
||||
}
|
||||
if (!parentEvent) { continue; }
|
||||
|
||||
const logEvent: ExecutionEvent = {
|
||||
time: parentEvent.time,
|
||||
label: `log: ${entry.message}`,
|
||||
root: parentEvent.root,
|
||||
parent: parentEvent,
|
||||
};
|
||||
const bucket = logsByParent.get(parentEvent);
|
||||
if (bucket) { bucket.push(logEvent); }
|
||||
else { logsByParent.set(parentEvent, [logEvent]); }
|
||||
}
|
||||
|
||||
// Interleave: each task event followed by its logs in emission order.
|
||||
const events: ExecutionEvent[] = [];
|
||||
for (const e of taskEvents) {
|
||||
events.push(e);
|
||||
const ls = logsByParent.get(e);
|
||||
if (ls) { events.push(...ls); }
|
||||
}
|
||||
|
||||
return { roots, events };
|
||||
}
|
||||
|
||||
/**
|
||||
* Extract the first stack frame that is not from the scheduler/tracing
|
||||
* infrastructure. Returns `undefined` when no useful frame is found.
|
||||
*/
|
||||
const _skipFramePatterns = [
|
||||
/timeTravelScheduler|traceableTimeApi/,
|
||||
/RunOnceScheduler\.schedule/,
|
||||
/scheduleAtNextAnimationFrame/,
|
||||
/TimeoutTimer\.cancelAndSet/,
|
||||
/TimeoutTimer\.setIfNotSet/,
|
||||
/timeoutDeferred/,
|
||||
/createTimeout/,
|
||||
];
|
||||
|
||||
function extractCallerFrame(stackTrace: string | undefined): string | undefined {
|
||||
if (!stackTrace) { return undefined; }
|
||||
for (const line of stackTrace.split('\n')) {
|
||||
const trimmed = line.trim();
|
||||
if (!trimmed.startsWith('at ')) { continue; }
|
||||
if (_skipFramePatterns.some(p => p.test(trimmed))) { continue; }
|
||||
return trimmed.slice(3);
|
||||
}
|
||||
return undefined;
|
||||
}
|
||||
|
||||
// -----------------------------------------------------------------------------
|
||||
// Renderer: swimlane (one column per root)
|
||||
// -----------------------------------------------------------------------------
|
||||
|
||||
/**
|
||||
* Render `history` as a swimlane diagram: one column per root, events in the
|
||||
* column of their root, parent→child shown via `├─`/`└─` indentation, active
|
||||
* ancestors shown via `│` continuation lines.
|
||||
*
|
||||
* Example:
|
||||
* ```
|
||||
* A B
|
||||
* +0ms ├─ setTimeout
|
||||
* +10ms │ ├─ setTimeout
|
||||
* +16ms ├─ rAF │
|
||||
* +50ms └─ setTimeout
|
||||
* ```
|
||||
*/
|
||||
export function renderSwimlanes(history: ExecutionHistory): string {
|
||||
const { roots, events } = history;
|
||||
if (events.length === 0) { return '(empty history)'; }
|
||||
if (roots.length === 0) {
|
||||
return events.map(e => `[+${e.time}ms] ${e.label}`).join('\n');
|
||||
}
|
||||
|
||||
const n = events.length;
|
||||
|
||||
// Parent index per event (-1 = direct child of root).
|
||||
const parentOf = new Array<number>(n).fill(-1);
|
||||
const childrenOf: number[][] = Array.from({ length: n }, () => []);
|
||||
const indexOfEvent = new Map<ExecutionEvent, number>();
|
||||
for (let i = 0; i < n; i++) { indexOfEvent.set(events[i], i); }
|
||||
for (let i = 0; i < n; i++) {
|
||||
const p = events[i].parent;
|
||||
if (p) {
|
||||
const pi = indexOfEvent.get(p);
|
||||
if (pi !== undefined) {
|
||||
parentOf[i] = pi;
|
||||
childrenOf[pi].push(i);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// Is this event the last child of its parent event?
|
||||
const isLastChild = new Array<boolean>(n).fill(false);
|
||||
for (let i = 0; i < n; i++) {
|
||||
const p = parentOf[i];
|
||||
if (p >= 0 && childrenOf[p][childrenOf[p].length - 1] === i) { isLastChild[i] = true; }
|
||||
}
|
||||
|
||||
// Slot = visual column index for indentation. By default every child
|
||||
// gets its own column (slot = parent.slot + 1) so pure last-child chains
|
||||
// still show their depth structure. Once we pass the depth threshold,
|
||||
// last-children collapse into their parent's slot to keep deeply nested
|
||||
// traces from walking off the screen.
|
||||
const COLLAPSE_DEPTH_THRESHOLD = 6;
|
||||
const depthOf = new Array<number>(n).fill(0);
|
||||
const slotOf = new Array<number>(n).fill(0);
|
||||
for (let i = 0; i < n; i++) {
|
||||
const p = parentOf[i];
|
||||
if (p >= 0) {
|
||||
depthOf[i] = depthOf[p] + 1;
|
||||
const collapse = isLastChild[i] && depthOf[i] >= COLLAPSE_DEPTH_THRESHOLD;
|
||||
slotOf[i] = slotOf[p] + (collapse ? 0 : 1);
|
||||
}
|
||||
}
|
||||
|
||||
// Column width per root: indentation uses slots (last-children collapse
|
||||
// into their parent's slot), so width must be slot-based to avoid
|
||||
// reserving empty space for degenerate last-child chains.
|
||||
const widthOf = new Map<ExecutionRoot, number>();
|
||||
for (const r of roots) { widthOf.set(r, r.label.length); }
|
||||
for (let i = 0; i < n; i++) {
|
||||
const w = slotOf[i] * 3 + 3 + events[i].label.length;
|
||||
const cur = widthOf.get(events[i].root) ?? 0;
|
||||
if (w > cur) { widthOf.set(events[i].root, w); }
|
||||
}
|
||||
|
||||
// Compute time column width based on max time (rounded).
|
||||
const maxTime = n > 0 ? Math.max(...events.map(e => Math.round(e.time))) : 0;
|
||||
const timeColWidth = `+${maxTime}ms`.length;
|
||||
|
||||
const lines: string[] = [];
|
||||
|
||||
// Header: root labels centered in their columns.
|
||||
const header: string[] = [];
|
||||
for (const r of roots) {
|
||||
const w = widthOf.get(r)!;
|
||||
header.push(r.label.padStart(Math.ceil((w + r.label.length) / 2)).padEnd(w));
|
||||
}
|
||||
lines.push(`${' '.repeat(timeColWidth)} ${header.join(' ')}`.trimEnd());
|
||||
|
||||
// Compute lastChild index for each event (for drawing continuation lines).
|
||||
const lastChildOf = new Array<number>(n).fill(-1);
|
||||
for (let i = 0; i < n; i++) {
|
||||
const kids = childrenOf[i];
|
||||
if (kids.length > 0) { lastChildOf[i] = kids[kids.length - 1]; }
|
||||
}
|
||||
|
||||
// Per-root: set of "active ancestor" event indices (events with children
|
||||
// whose last child has not yet been rendered, i.e. lastChildOf[a] > i).
|
||||
const laneStacks = new Map<ExecutionRoot, Set<number>>();
|
||||
for (const r of roots) { laneStacks.set(r, new Set()); }
|
||||
|
||||
for (let i = 0; i < n; i++) {
|
||||
const event = events[i];
|
||||
const timeStr = `+${Math.round(event.time)}ms`.padStart(timeColWidth);
|
||||
|
||||
const parts: string[] = [];
|
||||
for (const r of roots) {
|
||||
const w = widthOf.get(r)!;
|
||||
const stack = laneStacks.get(r)!;
|
||||
|
||||
if (r === event.root) {
|
||||
// Event line: slot-based indentation, then `├─`/`└─` + label.
|
||||
// For each slot s in 0..(slot-1), show `│ ` if an ancestor
|
||||
// at slot s is still active (lastChild > current), else ` `.
|
||||
const slot = slotOf[i];
|
||||
const indent: string[] = [];
|
||||
for (let s = 0; s < slot; s++) {
|
||||
let hasActive = false;
|
||||
for (const a of stack) {
|
||||
if (slotOf[a] === s && lastChildOf[a] > i) { hasActive = true; break; }
|
||||
}
|
||||
indent.push(hasActive ? '│ ' : ' ');
|
||||
}
|
||||
const prefix = isLastChild[i] ? '└─ ' : '├─ ';
|
||||
parts.push(`${indent.join('')}${prefix}${event.label}`.padEnd(w));
|
||||
} else {
|
||||
// Cross-lane continuation. Draw `│` at each slot occupied by
|
||||
// an active ancestor (lastChild > i). Also show a `|` placeholder
|
||||
// at the slot of the next upcoming event if it's a non-last child.
|
||||
const activeSlots: number[] = [];
|
||||
for (const a of stack) {
|
||||
if (lastChildOf[a] > i) { activeSlots.push(slotOf[a]); }
|
||||
}
|
||||
const maxSlot = Math.max(...activeSlots, -1);
|
||||
const chars: string[] = new Array(Math.max(maxSlot + 1, 0)).fill(' ');
|
||||
for (const s of activeSlots) { chars[s] = '│ '; }
|
||||
|
||||
// Find the next event in root r strictly after i.
|
||||
let nextJ = -1;
|
||||
for (let j = i + 1; j < n; j++) {
|
||||
if (events[j].root === r) { nextJ = j; break; }
|
||||
}
|
||||
if (nextJ >= 0 && parentOf[nextJ] >= 0) {
|
||||
const s = slotOf[nextJ];
|
||||
// Reserve slot if next event will open a new branch (├─).
|
||||
if (!isLastChild[nextJ]) {
|
||||
while (chars.length <= s) { chars.push(' '); }
|
||||
if (chars[s] === ' ') { chars[s] = '| '; }
|
||||
}
|
||||
}
|
||||
|
||||
// Trim trailing empty cells.
|
||||
while (chars.length > 0 && chars[chars.length - 1] === ' ') { chars.pop(); }
|
||||
parts.push(chars.join('').padEnd(w));
|
||||
}
|
||||
}
|
||||
|
||||
lines.push(`${timeStr} ${parts.join(' ')}`.trimEnd());
|
||||
|
||||
// Stack maintenance: push this event if it has children, then pop
|
||||
// any ancestors whose last child was just rendered (propagating up).
|
||||
const stack = laneStacks.get(event.root)!;
|
||||
if (childrenOf[i].length > 0) { stack.add(i); }
|
||||
let cur = i;
|
||||
while (isLastChild[cur]) {
|
||||
const p = parentOf[cur];
|
||||
if (p < 0) { break; }
|
||||
stack.delete(p);
|
||||
cur = p;
|
||||
}
|
||||
}
|
||||
|
||||
return lines.join('\n');
|
||||
}
|
||||
|
||||
// -----------------------------------------------------------------------------
|
||||
// Renderer: interleaved lane graph (git-log style)
|
||||
// -----------------------------------------------------------------------------
|
||||
|
||||
/**
|
||||
* Render `history` as an interleaved-lane "git log" style graph. Each parent
|
||||
* event gets a column; columns are laid out left-to-right in event order.
|
||||
* Trace roots with at least one direct child become synthetic `+label` rows
|
||||
* inserted before their first child.
|
||||
*
|
||||
* Glyphs:
|
||||
* `╷` lane origin (this node is a parent)
|
||||
* `│` lane passes through
|
||||
* `├─` child connects; lane continues
|
||||
* `└─` last child connects; lane closes
|
||||
* `┼─` horizontal connector crosses an active lane
|
||||
* `──` horizontal connector crosses an empty column
|
||||
*/
|
||||
export function renderLaneGraph(history: ExecutionHistory): string {
|
||||
const { events } = history;
|
||||
if (events.length === 0) { return ''; }
|
||||
|
||||
interface Node {
|
||||
readonly label: string;
|
||||
readonly parent: Node | undefined;
|
||||
readonly isSynthetic: boolean;
|
||||
}
|
||||
|
||||
// Insert synthetic root nodes before their first child.
|
||||
const nodes: Node[] = [];
|
||||
const syntheticForRoot = new Map<ExecutionRoot, Node>();
|
||||
const nodeByEvent = new Map<ExecutionEvent, Node>();
|
||||
|
||||
// Which roots have at least one direct child event?
|
||||
const rootsWithChildren = new Set<ExecutionRoot>();
|
||||
for (const e of events) { if (!e.parent) { rootsWithChildren.add(e.root); } }
|
||||
|
||||
for (const e of events) {
|
||||
if (rootsWithChildren.has(e.root) && !syntheticForRoot.has(e.root)) {
|
||||
const syn: Node = { label: `+${e.root.label}`, parent: undefined, isSynthetic: true };
|
||||
syntheticForRoot.set(e.root, syn);
|
||||
nodes.push(syn);
|
||||
}
|
||||
const timeStr = `+${e.time}ms`.padStart(7);
|
||||
const parent = e.parent ? nodeByEvent.get(e.parent)! : syntheticForRoot.get(e.root);
|
||||
const node: Node = { label: `[${timeStr}] ${e.label}`, parent, isSynthetic: false };
|
||||
nodeByEvent.set(e, node);
|
||||
nodes.push(node);
|
||||
}
|
||||
|
||||
const n = nodes.length;
|
||||
const parentOf = new Array<number>(n).fill(-1);
|
||||
const childrenOf: number[][] = Array.from({ length: n }, () => []);
|
||||
const indexOfNode = new Map<Node, number>();
|
||||
for (let i = 0; i < n; i++) { indexOfNode.set(nodes[i], i); }
|
||||
for (let i = 0; i < n; i++) {
|
||||
const p = nodes[i].parent;
|
||||
if (p) {
|
||||
const pi = indexOfNode.get(p);
|
||||
if (pi !== undefined) { parentOf[i] = pi; childrenOf[pi].push(i); }
|
||||
}
|
||||
}
|
||||
|
||||
// Assign columns: every node with children gets its own column.
|
||||
const colOf = new Array<number>(n).fill(-1);
|
||||
let totalCols = 0;
|
||||
for (let i = 0; i < n; i++) {
|
||||
if (childrenOf[i].length > 0) { colOf[i] = totalCols++; }
|
||||
}
|
||||
|
||||
if (totalCols === 0) {
|
||||
return events.map(e => `[+${`${e.time}ms`.padStart(5)}] ${e.label}`).join('\n');
|
||||
}
|
||||
|
||||
const active = new Array<number>(totalCols).fill(-1);
|
||||
const lines: string[] = [];
|
||||
|
||||
for (let i = 0; i < n; i++) {
|
||||
const node = nodes[i];
|
||||
const pIdx = parentOf[i];
|
||||
const connectCol = pIdx >= 0 ? colOf[pIdx] : -1;
|
||||
const last = pIdx >= 0 && childrenOf[pIdx][childrenOf[pIdx].length - 1] === i;
|
||||
const opensCol = childrenOf[i].length > 0 ? colOf[i] : -1;
|
||||
const horizEnd = pIdx >= 0 ? (opensCol >= 0 ? opensCol : totalCols) : -1;
|
||||
|
||||
const chars: string[] = [];
|
||||
for (let c = 0; c < totalCols; c++) {
|
||||
const isActive = active[c] >= 0;
|
||||
const isConnect = c === connectCol;
|
||||
const isOpen = c === opensCol && !isConnect;
|
||||
const inHoriz = connectCol >= 0 && c > connectCol && c < horizEnd;
|
||||
|
||||
let g: string, s: string;
|
||||
if (isConnect) {
|
||||
g = last ? '└' : '├';
|
||||
s = '─';
|
||||
} else if (isOpen && node.isSynthetic) {
|
||||
g = '+';
|
||||
s = node.label.slice(1, 2) || '?';
|
||||
} else if (isOpen && connectCol >= 0) {
|
||||
g = '╷'; s = '─';
|
||||
} else if (isOpen) {
|
||||
g = '╷'; s = ' ';
|
||||
} else if (inHoriz && isActive) {
|
||||
g = '┼'; s = '─';
|
||||
} else if (inHoriz) {
|
||||
g = '─'; s = '─';
|
||||
} else if (isActive) {
|
||||
g = '│'; s = ' ';
|
||||
} else {
|
||||
g = ' '; s = ' ';
|
||||
}
|
||||
chars.push(g, s);
|
||||
}
|
||||
|
||||
if (last) { active[colOf[pIdx]] = -1; }
|
||||
if (opensCol >= 0) { active[opensCol] = i; }
|
||||
|
||||
if (node.isSynthetic) {
|
||||
lines.push(chars.join('').trimEnd());
|
||||
} else {
|
||||
lines.push(`${chars.join('')}${node.label}`);
|
||||
}
|
||||
}
|
||||
|
||||
return lines.join('\n');
|
||||
}
|
||||
@@ -4,9 +4,11 @@
|
||||
*--------------------------------------------------------------------------------------------*/
|
||||
|
||||
import { compareBy, numberComparator, tieBreakComparators } from '../../common/arrays.js';
|
||||
import { Emitter, Event } from '../../common/event.js';
|
||||
import { Disposable, IDisposable } from '../../common/lifecycle.js';
|
||||
import { CancellationToken, CancellationTokenSource } from '../../common/cancellation.js';
|
||||
import { Emitter } from '../../common/event.js';
|
||||
import { Disposable, DisposableStore, IDisposable } from '../../common/lifecycle.js';
|
||||
import { setTimeout0, setTimeout0IsFaster } from '../../common/platform.js';
|
||||
import { ROOT_TRACE, Trace, TraceContext } from './traceableTimeApi.js';
|
||||
|
||||
export type TimeOffset = number;
|
||||
|
||||
@@ -19,6 +21,12 @@ export interface ScheduledTask {
|
||||
readonly time: TimeOffset;
|
||||
readonly source: ScheduledTaskSource;
|
||||
readonly useRealAnimationFrame?: boolean;
|
||||
/**
|
||||
* Causal trace attached at schedule time. Used for attribution in
|
||||
* `toString()` and to re-install the trace when the task runs so that
|
||||
* the task body (and its microtask drain) observes it.
|
||||
*/
|
||||
readonly trace?: Trace;
|
||||
|
||||
run(): void;
|
||||
}
|
||||
@@ -38,6 +46,7 @@ export interface TimeApi {
|
||||
requestAnimationFrame?: ((callback: (time: number) => void) => number);
|
||||
cancelAnimationFrame?: ((id: number) => void);
|
||||
Date: DateConstructor;
|
||||
originalFunctions?: TimeApi;
|
||||
}
|
||||
|
||||
interface ExtendedScheduledTask extends ScheduledTask {
|
||||
@@ -98,122 +107,457 @@ export class TimeTravelScheduler implements Scheduler {
|
||||
}
|
||||
|
||||
installGlobally(options?: CreateVirtualTimeApiOptions): IDisposable {
|
||||
return overwriteGlobalTimeApi(createVirtualTimeApi(this, options));
|
||||
return pushGlobalTimeApi(createVirtualTimeApi(this, options));
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Termination policy of a single {@link AsyncSchedulerProcessor.run} call.
|
||||
*/
|
||||
export interface RunOptions {
|
||||
/**
|
||||
* If set, the run resolves once the token is cancelled AND the virtual queue
|
||||
* has been drained. Tasks scheduled before cancellation are still processed.
|
||||
* If unset, the run resolves as soon as the virtual queue is empty.
|
||||
*/
|
||||
readonly token?: CancellationToken;
|
||||
/**
|
||||
* If set, the run resolves once virtual time has reached this absolute
|
||||
* timestamp, OR there is no scheduled task with `time <= virtualDeadline`
|
||||
* (because then virtual time can never reach the deadline by itself).
|
||||
*/
|
||||
readonly virtualDeadline?: TimeOffset;
|
||||
/**
|
||||
* Maximum number of virtual tasks this run will tolerate executing while
|
||||
* its termination predicate is not yet satisfied. Exceeding this rejects
|
||||
* the run with a debug-friendly overflow error.
|
||||
*
|
||||
* Counted from the moment the run was started, not from processor creation.
|
||||
*/
|
||||
readonly maxTasks?: number;
|
||||
/**
|
||||
* Maximum causal chain depth (via {@link Trace.depth}) the run will
|
||||
* tolerate. If a task is about to execute whose trace depth exceeds this
|
||||
* limit, the run is rejected. Useful for catching runaway self-rescheduling
|
||||
* (a timer that keeps scheduling its own successor indefinitely).
|
||||
*/
|
||||
readonly maxTaskDepth?: number;
|
||||
}
|
||||
|
||||
type RunStatus = 'continue' | 'done' | { readonly error: Error };
|
||||
|
||||
/**
|
||||
* Internal record of a single {@link AsyncSchedulerProcessor.run} call.
|
||||
*
|
||||
* A {@link Run} is purely declarative: its termination predicate
|
||||
* ({@link evaluate}) is a pure function over the processor's observable state
|
||||
* (`scheduler.now`, `executedTotal`, the next task time, the token state).
|
||||
* The processor never mutates a run; it only inspects it and, when done,
|
||||
* resolves or rejects its {@link promise}.
|
||||
*/
|
||||
class Run {
|
||||
|
||||
private static _idCounter = 0;
|
||||
public readonly id = ++Run._idCounter;
|
||||
|
||||
public readonly promise: Promise<void>;
|
||||
private _resolve!: () => void;
|
||||
private _reject!: (e: Error) => void;
|
||||
private _settled = false;
|
||||
public get settled(): boolean { return this._settled; }
|
||||
|
||||
constructor(
|
||||
public readonly options: RunOptions,
|
||||
public readonly tasksExecutedAtStart: number,
|
||||
public readonly effectiveMaxTasks: number,
|
||||
) {
|
||||
this.promise = new Promise<void>((res, rej) => {
|
||||
this._resolve = res;
|
||||
this._reject = rej;
|
||||
});
|
||||
}
|
||||
|
||||
settle(error?: Error): void {
|
||||
if (this._settled) { return; }
|
||||
this._settled = true;
|
||||
if (error) { this._reject(error); } else { this._resolve(); }
|
||||
}
|
||||
|
||||
evaluate(scheduler: TimeTravelScheduler, executedTotal: number, peekNextTime: TimeOffset | undefined, makeOverflowError: () => Error): RunStatus {
|
||||
const localExecuted = executedTotal - this.tasksExecutedAtStart;
|
||||
if (localExecuted >= this.effectiveMaxTasks && scheduler.hasScheduledTasks) {
|
||||
return { error: makeOverflowError() };
|
||||
}
|
||||
|
||||
if (this.options.virtualDeadline !== undefined) {
|
||||
if (scheduler.now >= this.options.virtualDeadline) { return 'done'; }
|
||||
// Virtual time can only advance by executing tasks. If no scheduled
|
||||
// task can advance time up to the deadline, the run is effectively
|
||||
// done (otherwise the loop would idle-wait forever).
|
||||
if (peekNextTime === undefined || peekNextTime > this.options.virtualDeadline) { return 'done'; }
|
||||
}
|
||||
|
||||
if (this.options.token === undefined) {
|
||||
return scheduler.hasScheduledTasks ? 'continue' : 'done';
|
||||
}
|
||||
|
||||
if (this.options.token.isCancellationRequested && !scheduler.hasScheduledTasks) { return 'done'; }
|
||||
return 'continue';
|
||||
}
|
||||
|
||||
describe(executedTotal: number, startTime: TimeOffset): string {
|
||||
const parts: string[] = [`#${this.id}`];
|
||||
if (this.options.token) {
|
||||
parts.push(this.options.token.isCancellationRequested ? 'token=cancelled' : 'token=pending');
|
||||
}
|
||||
if (this.options.virtualDeadline !== undefined) {
|
||||
const delta = this.options.virtualDeadline - startTime;
|
||||
const sign = delta < 0 ? '-' : '+';
|
||||
parts.push(`virtualDeadline=${sign}${Math.abs(delta)}ms`);
|
||||
}
|
||||
const localExecuted = executedTotal - this.tasksExecutedAtStart;
|
||||
parts.push(`executed=${localExecuted}/${this.effectiveMaxTasks}`);
|
||||
return parts.join(' ');
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Drives a {@link TimeTravelScheduler} from the real microtask/macrotask queue,
|
||||
* yielding back to real time between virtual tasks so that promise callbacks
|
||||
* can run and (re)schedule virtual tasks before the next one is executed.
|
||||
*
|
||||
* # Invariants
|
||||
*
|
||||
* 1. **Single physical loop.** At any moment at most one async loop iterates
|
||||
* the virtual queue. Concurrent {@link run} calls compose by registering
|
||||
* additional {@link Run}s on the same loop.
|
||||
*
|
||||
* 2. **Yield-then-execute.** Each loop iteration yields to real time before
|
||||
* executing the next virtual task. No two virtual tasks run back-to-back
|
||||
* without a yield. Termination is re-evaluated after each yield.
|
||||
*
|
||||
* 3. **Termination is per-run and pure.** Each run carries its own termination
|
||||
* options ({@link RunOptions}); deadlines, tokens and maxTasks are never
|
||||
* stored as mutable processor state. This is what makes parallel runs with
|
||||
* different deadlines compose cleanly.
|
||||
*
|
||||
* 4. **Loop respects the strictest deadline.** The loop never advances virtual
|
||||
* time past `min(virtualDeadline of all active runs)`. Past-deadline runs
|
||||
* are settled before the loop attempts the next yield.
|
||||
*
|
||||
* 5. **Idle waits are explicit and breakable.** When the queue is empty (or
|
||||
* the next task is past every active deadline) the loop awaits a single
|
||||
* composite signal: a new task being scheduled, a run being added, or a
|
||||
* token being cancelled. It never busy-loops.
|
||||
*
|
||||
* 6. **Errors propagate via promise rejection.** A throwing virtual task or a
|
||||
* {@link RunOptions.maxTasks} overflow rejects the relevant run(s). No
|
||||
* sticky `_lastError` flag is left for the next caller.
|
||||
*
|
||||
* 7. **Disposal settles all runs.** {@link dispose} rejects every active run
|
||||
* with a disposal error and lets the loop drain naturally.
|
||||
*/
|
||||
export class AsyncSchedulerProcessor extends Disposable {
|
||||
private isProcessing = false;
|
||||
private readonly _history = new Array<ScheduledTask>();
|
||||
|
||||
private readonly _runs = new Map<Run, IDisposable>();
|
||||
private readonly _history: ScheduledTask[] = [];
|
||||
private _executedTotal = 0;
|
||||
|
||||
private _loopRunning = false;
|
||||
private _wakeup: (() => void) | undefined;
|
||||
|
||||
private readonly _defaultMaxTasks: number;
|
||||
private readonly _useSetImmediate: boolean;
|
||||
private readonly _realTimeApi: TimeApi;
|
||||
private readonly _startTime: TimeOffset;
|
||||
|
||||
public get history(): readonly ScheduledTask[] { return this._history; }
|
||||
|
||||
private readonly maxTaskCount: number;
|
||||
private readonly useSetImmediate: boolean;
|
||||
private readonly _realTimeApi: TimeApi;
|
||||
|
||||
private readonly queueEmptyEmitter = new Emitter<void>();
|
||||
public readonly onTaskQueueEmpty = this.queueEmptyEmitter.event;
|
||||
|
||||
private lastError: Error | undefined;
|
||||
private _virtualDeadline = Number.MAX_SAFE_INTEGER;
|
||||
|
||||
constructor(private readonly scheduler: TimeTravelScheduler, options?: { useSetImmediate?: boolean; maxTaskCount?: number; realTimeApi?: TimeApi }) {
|
||||
constructor(
|
||||
private readonly scheduler: TimeTravelScheduler,
|
||||
options?: { useSetImmediate?: boolean; maxTaskCount?: number; realTimeApi?: TimeApi }
|
||||
) {
|
||||
super();
|
||||
|
||||
this.maxTaskCount = options && options.maxTaskCount ? options.maxTaskCount : 100;
|
||||
this.useSetImmediate = options && options.useSetImmediate ? options.useSetImmediate : false;
|
||||
this._defaultMaxTasks = options?.maxTaskCount ?? 100;
|
||||
this._useSetImmediate = options?.useSetImmediate ?? false;
|
||||
this._realTimeApi = options?.realTimeApi ?? originalGlobalValues;
|
||||
this._startTime = scheduler.now;
|
||||
|
||||
this._register(scheduler.onTaskScheduled(() => {
|
||||
if (this.isProcessing) {
|
||||
return;
|
||||
} else {
|
||||
this.isProcessing = true;
|
||||
this._schedule();
|
||||
}
|
||||
}));
|
||||
this._register({ dispose: () => this._disposeAllRuns() });
|
||||
}
|
||||
|
||||
private _schedule() {
|
||||
// This allows promises created by a previous task to settle and schedule tasks before the next task is run.
|
||||
// Tasks scheduled in those promises might have to run before the current next task.
|
||||
Promise.resolve().then(() => {
|
||||
// When the next task requires a real animation frame (e.g. virtual rAF),
|
||||
// use the real browser rAF so the browser reflows before the callback runs.
|
||||
// This ensures DOM measurements like offsetHeight return accurate values.
|
||||
const nextTask = this.scheduler.peekNext();
|
||||
if (nextTask?.useRealAnimationFrame && this._realTimeApi.requestAnimationFrame) {
|
||||
this._realTimeApi.requestAnimationFrame(() => this._process());
|
||||
} else if (this.useSetImmediate && this._realTimeApi.setImmediate) {
|
||||
this._realTimeApi.setImmediate(() => this._process());
|
||||
} else if (setTimeout0IsFaster) {
|
||||
setTimeout0(() => this._process());
|
||||
} else {
|
||||
this._realTimeApi.setTimeout(() => this._process());
|
||||
/**
|
||||
* Start a run with the given termination policy.
|
||||
*
|
||||
* - With no options: resolves when the virtual queue is empty.
|
||||
* - With `token`: resolves when the token is cancelled AND the queue is
|
||||
* drained. Tasks scheduled before cancellation are still processed.
|
||||
* - With `virtualDeadline`: resolves when virtual time reaches the deadline,
|
||||
* or when no scheduled task remains within it.
|
||||
* - With `maxTasks`: rejects if the run executes more than that many virtual
|
||||
* tasks before its other termination conditions are satisfied.
|
||||
*
|
||||
* Multiple parallel runs share the same processing loop; each resolves
|
||||
* independently when its own predicate fires.
|
||||
*/
|
||||
run(options: RunOptions = {}): Promise<void> {
|
||||
return this._startRun(options);
|
||||
}
|
||||
|
||||
private _startRun(options: RunOptions): Promise<void> {
|
||||
const run = new Run(options, this._executedTotal, options.maxTasks ?? this._defaultMaxTasks);
|
||||
const cleanup = new DisposableStore();
|
||||
if (options.token) {
|
||||
cleanup.add(options.token.onCancellationRequested(() => this._wake()));
|
||||
}
|
||||
this._runs.set(run, cleanup);
|
||||
this._wake();
|
||||
void this._ensureLoopRunning();
|
||||
return run.promise;
|
||||
}
|
||||
|
||||
private _settleRun(run: Run, error?: Error): void {
|
||||
const cleanup = this._runs.get(run);
|
||||
if (!cleanup) { return; }
|
||||
this._runs.delete(run);
|
||||
cleanup.dispose();
|
||||
run.settle(error);
|
||||
}
|
||||
|
||||
private _disposeAllRuns(): void {
|
||||
const err = new Error('AsyncSchedulerProcessor disposed');
|
||||
for (const run of [...this._runs.keys()]) {
|
||||
this._settleRun(run, err);
|
||||
}
|
||||
this._wake();
|
||||
}
|
||||
|
||||
private _wake(): void {
|
||||
const w = this._wakeup;
|
||||
this._wakeup = undefined;
|
||||
w?.();
|
||||
}
|
||||
|
||||
private async _ensureLoopRunning(): Promise<void> {
|
||||
if (this._loopRunning) { return; }
|
||||
this._loopRunning = true;
|
||||
try {
|
||||
await this._loop();
|
||||
} finally {
|
||||
this._loopRunning = false;
|
||||
}
|
||||
}
|
||||
|
||||
private async _loop(): Promise<void> {
|
||||
while (true) {
|
||||
this._settleFinishedRuns();
|
||||
if (this._runs.size === 0) { return; }
|
||||
|
||||
const next = this.scheduler.peekNext();
|
||||
const minDeadline = this._minDeadline();
|
||||
|
||||
if (!next || next.time > minDeadline) {
|
||||
// Nothing actionable. Wait for a new task to be scheduled, a
|
||||
// token to be cancelled, a new run to be added, or disposal.
|
||||
await this._waitForChange();
|
||||
continue;
|
||||
}
|
||||
|
||||
// Invariant 2: yield to real time before each virtual execution.
|
||||
await this._yieldToReal(next);
|
||||
|
||||
// Re-check after yielding: anything could have changed.
|
||||
this._settleFinishedRuns();
|
||||
if (this._runs.size === 0) { return; }
|
||||
|
||||
const stillNext = this.scheduler.peekNext();
|
||||
if (!stillNext || stillNext.time > this._minDeadline()) { continue; }
|
||||
|
||||
// Check per-run maxTaskDepth: if this task's causal depth exceeds
|
||||
// any active run's limit, reject that run before executing.
|
||||
const taskDepth = stillNext.trace?.depth ?? 0;
|
||||
let overflowed = false;
|
||||
for (const run of [...this._runs.keys()]) {
|
||||
const limit = run.options.maxTaskDepth;
|
||||
if (limit !== undefined && taskDepth > limit) {
|
||||
this._settleRun(run, this._buildDepthOverflowError(run, taskDepth));
|
||||
overflowed = true;
|
||||
}
|
||||
}
|
||||
if (overflowed) { continue; }
|
||||
|
||||
try {
|
||||
// Execute the task under its causal trace so that its body
|
||||
// and subsequent microtask drain observe it. `runAsHandler`
|
||||
// keeps the trace in place across the microtask drain by
|
||||
// scheduling a seq-guarded reset on the next real-time tick.
|
||||
TraceContext.instance.runAsHandler(stillNext.trace ?? ROOT_TRACE, () => {
|
||||
const executed = this.scheduler.runNext();
|
||||
if (executed) {
|
||||
this._history.push(executed);
|
||||
this._executedTotal++;
|
||||
}
|
||||
}, this._realTimeApi);
|
||||
} catch (e) {
|
||||
const err = e instanceof Error ? e : new Error(String(e));
|
||||
// We can't tell which run "owned" the throwing task. Reject all
|
||||
// active runs so the failure is observed exactly once per caller.
|
||||
for (const run of [...this._runs.keys()]) {
|
||||
this._settleRun(run, err);
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
private _settleFinishedRuns(): void {
|
||||
const peekNextTime = this.scheduler.peekNext()?.time;
|
||||
for (const run of [...this._runs.keys()]) {
|
||||
if (run.settled) { continue; }
|
||||
const status = run.evaluate(this.scheduler, this._executedTotal, peekNextTime, () => this._buildOverflowError(run));
|
||||
if (status === 'done') {
|
||||
this._settleRun(run);
|
||||
} else if (typeof status === 'object') {
|
||||
this._settleRun(run, status.error);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
private _minDeadline(): TimeOffset {
|
||||
let m = Number.MAX_SAFE_INTEGER;
|
||||
for (const run of this._runs.keys()) {
|
||||
if (run.options.virtualDeadline !== undefined && run.options.virtualDeadline < m) {
|
||||
m = run.options.virtualDeadline;
|
||||
}
|
||||
}
|
||||
return m;
|
||||
}
|
||||
|
||||
private _waitForChange(): Promise<void> {
|
||||
return new Promise<void>(resolve => {
|
||||
const store = new DisposableStore();
|
||||
const fire = () => {
|
||||
if (this._wakeup === fire) { this._wakeup = undefined; }
|
||||
store.dispose();
|
||||
resolve();
|
||||
};
|
||||
this._wakeup = fire;
|
||||
store.add(this.scheduler.onTaskScheduled(fire));
|
||||
});
|
||||
}
|
||||
|
||||
private _process() {
|
||||
let executedTask: ScheduledTask | undefined;
|
||||
try {
|
||||
executedTask = this.scheduler.runNext();
|
||||
} catch (e) {
|
||||
console.error(`[TimeTravelScheduler] Task threw:`, e);
|
||||
}
|
||||
if (executedTask) {
|
||||
this._history.push(executedTask);
|
||||
|
||||
if (this.history.length >= this.maxTaskCount && this.scheduler.hasScheduledTasks) {
|
||||
const lastTasks = this._history.slice(Math.max(0, this.history.length - 10)).map(h => `${h.source.toString()}: ${h.source.stackTrace}`);
|
||||
this.lastError = new Error(`Queue did not get empty after processing ${this.history.length} items. These are the last ${lastTasks.length} scheduled tasks:\n${lastTasks.join('\n\n\n')}`);
|
||||
this.isProcessing = false;
|
||||
this.queueEmptyEmitter.fire();
|
||||
return;
|
||||
}
|
||||
|
||||
if (this.scheduler.now >= this._virtualDeadline && this.scheduler.hasScheduledTasks) {
|
||||
this.isProcessing = false;
|
||||
this.queueEmptyEmitter.fire();
|
||||
return;
|
||||
}
|
||||
}
|
||||
|
||||
if (this.scheduler.hasScheduledTasks) {
|
||||
this._schedule();
|
||||
} else {
|
||||
this.isProcessing = false;
|
||||
this.queueEmptyEmitter.fire();
|
||||
}
|
||||
}
|
||||
|
||||
waitForEmptyQueue(): Promise<void> {
|
||||
if (this.lastError) {
|
||||
const error = this.lastError;
|
||||
this.lastError = undefined;
|
||||
throw error;
|
||||
}
|
||||
if (!this.isProcessing) {
|
||||
return Promise.resolve();
|
||||
} else {
|
||||
return Event.toPromise(this.onTaskQueueEmpty).then(() => {
|
||||
if (this.lastError) {
|
||||
const error = this.lastError;
|
||||
this.lastError = undefined;
|
||||
throw error;
|
||||
private _yieldToReal(next: ScheduledTask): Promise<void> {
|
||||
return new Promise<void>(resolve => {
|
||||
// Drain microtasks first so promises chained to the previous task
|
||||
// can settle and schedule virtual tasks before the next runs.
|
||||
Promise.resolve().then(() => {
|
||||
if (next.useRealAnimationFrame && this._realTimeApi.requestAnimationFrame) {
|
||||
this._realTimeApi.requestAnimationFrame(() => resolve());
|
||||
} else if (this._useSetImmediate && this._realTimeApi.setImmediate) {
|
||||
this._realTimeApi.setImmediate(() => resolve());
|
||||
} else if (setTimeout0IsFaster) {
|
||||
setTimeout0(() => resolve());
|
||||
} else {
|
||||
this._realTimeApi.setTimeout(() => resolve());
|
||||
}
|
||||
});
|
||||
}
|
||||
});
|
||||
}
|
||||
|
||||
runForVirtualTimeMs(virtualTimeMs: number): Promise<void> {
|
||||
this._virtualDeadline = this.scheduler.now + virtualTimeMs;
|
||||
return this.waitForEmptyQueue().finally(() => {
|
||||
this._virtualDeadline = Number.MAX_SAFE_INTEGER;
|
||||
});
|
||||
private _buildOverflowError(run: Run): Error {
|
||||
const localExecuted = this._executedTotal - run.tasksExecutedAtStart;
|
||||
const limit = run.effectiveMaxTasks;
|
||||
return new Error(
|
||||
`[AsyncSchedulerProcessor] Run #${run.id} exceeded maxTasks (${limit}) — ` +
|
||||
`executed ${localExecuted} virtual task(s) and the queue is still not empty.\n\n` +
|
||||
this.toString()
|
||||
);
|
||||
}
|
||||
|
||||
private _buildDepthOverflowError(run: Run, taskDepth: number): Error {
|
||||
const limit = run.options.maxTaskDepth!;
|
||||
return new Error(
|
||||
`[AsyncSchedulerProcessor] Run #${run.id} exceeded maxTaskDepth (${limit}) — ` +
|
||||
`next task has causal depth ${taskDepth}. This usually indicates ` +
|
||||
`a runaway self-rescheduling timer.\n\n` +
|
||||
this.toString()
|
||||
);
|
||||
}
|
||||
|
||||
/**
|
||||
* A debug-friendly snapshot of the processor: virtual time, active runs,
|
||||
* recent history (with stack traces) and currently queued tasks.
|
||||
*/
|
||||
override toString(): string {
|
||||
const queued = this.scheduler.getScheduledTasks();
|
||||
const lines: string[] = [];
|
||||
const fmt = (task: ScheduledTask, indent: string) => formatScheduledTask(task, indent, this._startTime);
|
||||
|
||||
lines.push(
|
||||
`AsyncSchedulerProcessor { ` +
|
||||
`now=+${this.scheduler.now - this._startTime}ms, ` +
|
||||
`executed=${this._executedTotal}, ` +
|
||||
`queued=${queued.length}, ` +
|
||||
`runs=${this._runs.size}, ` +
|
||||
`loopRunning=${this._loopRunning} }`
|
||||
);
|
||||
|
||||
if (this._runs.size > 0) {
|
||||
lines.push('');
|
||||
lines.push('Active runs:');
|
||||
for (const run of this._runs.keys()) {
|
||||
lines.push(` ${run.describe(this._executedTotal, this._startTime)}`);
|
||||
}
|
||||
}
|
||||
|
||||
const HISTORY_LIMIT = 10;
|
||||
if (this._history.length > 0) {
|
||||
const recent = this._history.slice(-HISTORY_LIMIT);
|
||||
lines.push('');
|
||||
const omitted = this._history.length - recent.length;
|
||||
lines.push(`History (${recent.length}${omitted > 0 ? ` of ${this._history.length}` : ''}):`);
|
||||
for (const t of recent) {
|
||||
lines.push(fmt(t, ' '));
|
||||
}
|
||||
}
|
||||
|
||||
if (queued.length > 0) {
|
||||
const QUEUE_LIMIT = 20;
|
||||
const shown = queued.slice(0, QUEUE_LIMIT);
|
||||
lines.push('');
|
||||
lines.push(`Queued (${queued.length}):`);
|
||||
for (const t of shown) {
|
||||
lines.push(fmt(t, ' '));
|
||||
}
|
||||
if (queued.length > shown.length) {
|
||||
lines.push(` ... and ${queued.length - shown.length} more`);
|
||||
}
|
||||
}
|
||||
|
||||
return lines.join('\n');
|
||||
}
|
||||
}
|
||||
|
||||
function formatScheduledTask(task: ScheduledTask, indent: string, startTime: TimeOffset): string {
|
||||
const delta = task.time - startTime;
|
||||
const sign = delta < 0 ? '-' : '+';
|
||||
const time = `${sign}${Math.abs(delta)}ms`.padStart(8);
|
||||
const head = `${indent}[${time}] ${task.source.toString()}`;
|
||||
const lines: string[] = [head];
|
||||
if (task.trace) {
|
||||
lines.push(`${indent} trace: ${task.trace.describe()}`);
|
||||
}
|
||||
const stack = task.source.stackTrace;
|
||||
if (stack) {
|
||||
const stackLines = stack.split('\n').map(l => l.trim()).filter(l => l.length > 0);
|
||||
// Drop the leading "Error" line that `new Error().stack` produces,
|
||||
// then keep a few useful frames.
|
||||
const frames = (stackLines[0]?.startsWith('Error') ? stackLines.slice(1) : stackLines).slice(0, 5);
|
||||
for (const f of frames) {
|
||||
lines.push(`${indent} ${f}`);
|
||||
}
|
||||
}
|
||||
return lines.join('\n');
|
||||
}
|
||||
|
||||
export async function runWithFakedTimers<T>(options: { startTime?: number; useFakeTimers?: boolean; useSetImmediate?: boolean; maxTaskCount?: number }, fn: () => Promise<T>): Promise<T> {
|
||||
const useFakeTimers = options.useFakeTimers === undefined ? true : options.useFakeTimers;
|
||||
@@ -225,6 +569,12 @@ export async function runWithFakedTimers<T>(options: { startTime?: number; useFa
|
||||
const schedulerProcessor = new AsyncSchedulerProcessor(scheduler, { useSetImmediate: options.useSetImmediate, maxTaskCount: options.maxTaskCount });
|
||||
const globalInstallDisposable = scheduler.installGlobally();
|
||||
|
||||
// Start processing. With a token, run() keeps processing tasks until the
|
||||
// token is cancelled and the queue is drained, so tasks scheduled during
|
||||
// fn() are processed concurrently.
|
||||
const cts = new CancellationTokenSource();
|
||||
const runPromise = schedulerProcessor.run({ token: cts.token });
|
||||
|
||||
let didThrow = true;
|
||||
let result: T;
|
||||
try {
|
||||
@@ -233,13 +583,21 @@ export async function runWithFakedTimers<T>(options: { startTime?: number; useFa
|
||||
} finally {
|
||||
globalInstallDisposable.dispose();
|
||||
|
||||
// Signal that fn() is done: run() should drain the queue (for success)
|
||||
// or stop immediately (for error) and then resolve.
|
||||
// Since the global override is already disposed, no more tasks will be
|
||||
// scheduled during the final drain.
|
||||
cts.cancel();
|
||||
|
||||
try {
|
||||
if (!didThrow) {
|
||||
// We process the remaining scheduled tasks.
|
||||
// The global override is no longer active, so during this, no more tasks will be scheduled.
|
||||
await schedulerProcessor.waitForEmptyQueue();
|
||||
await runPromise;
|
||||
} else {
|
||||
// Avoid an unhandled rejection when disposal below rejects the run.
|
||||
runPromise.catch(() => { /* swallowed: fn() already failed */ });
|
||||
}
|
||||
} finally {
|
||||
cts.dispose();
|
||||
schedulerProcessor.dispose();
|
||||
}
|
||||
}
|
||||
@@ -258,6 +616,17 @@ export function captureGlobalTimeApi(): TimeApi {
|
||||
requestAnimationFrame: globalThis.requestAnimationFrame?.bind(globalThis),
|
||||
cancelAnimationFrame: globalThis.cancelAnimationFrame?.bind(globalThis),
|
||||
Date: globalThis.Date,
|
||||
originalFunctions: {
|
||||
setTimeout: globalThis.setTimeout,
|
||||
clearTimeout: globalThis.clearTimeout,
|
||||
setInterval: globalThis.setInterval,
|
||||
clearInterval: globalThis.clearInterval,
|
||||
setImmediate: globalThis.setImmediate,
|
||||
clearImmediate: globalThis.clearImmediate,
|
||||
requestAnimationFrame: globalThis.requestAnimationFrame,
|
||||
cancelAnimationFrame: globalThis.cancelAnimationFrame,
|
||||
Date: globalThis.Date,
|
||||
},
|
||||
};
|
||||
}
|
||||
|
||||
@@ -276,13 +645,16 @@ export function createVirtualTimeApi(scheduler: Scheduler, options?: CreateVirtu
|
||||
if (typeof handler === 'string') {
|
||||
throw new Error('String handler args should not be used and are not supported');
|
||||
}
|
||||
const stackTrace = new Error().stack;
|
||||
const trace = TraceContext.instance.currentTrace().child(`setTimeout(${timeout}ms)`, stackTrace);
|
||||
return scheduler.schedule({
|
||||
time: scheduler.now + timeout,
|
||||
run: () => { handler(); },
|
||||
source: {
|
||||
toString() { return 'setTimeout'; },
|
||||
stackTrace: new Error().stack,
|
||||
}
|
||||
stackTrace,
|
||||
},
|
||||
trace,
|
||||
});
|
||||
}
|
||||
|
||||
@@ -299,6 +671,7 @@ export function createVirtualTimeApi(scheduler: Scheduler, options?: CreateVirtu
|
||||
const validatedHandler = handler;
|
||||
let iterCount = 0;
|
||||
const stackTrace = new Error().stack;
|
||||
const baseTrace = TraceContext.instance.currentTrace().child(`setInterval(${interval}ms)`, stackTrace);
|
||||
let disposed = false;
|
||||
let lastDisposable: IDisposable;
|
||||
|
||||
@@ -316,7 +689,8 @@ export function createVirtualTimeApi(scheduler: Scheduler, options?: CreateVirtu
|
||||
source: {
|
||||
toString() { return `setInterval (iteration ${curIter})`; },
|
||||
stackTrace,
|
||||
}
|
||||
},
|
||||
trace: baseTrace.child(`tick #${curIter}`),
|
||||
});
|
||||
}
|
||||
schedule();
|
||||
@@ -370,12 +744,21 @@ export function createVirtualTimeApi(scheduler: Scheduler, options?: CreateVirtu
|
||||
};
|
||||
/* eslint-enable local/code-no-any-casts */
|
||||
|
||||
// Expose the real setTimeout as `originalFn` on the virtual one. The component-explorer
|
||||
// host's polling loop reads `globalThis.setTimeout.originalFn` to escape virtual time
|
||||
// when waiting for renders to settle. Without this, the host's poll re-arms inside
|
||||
// virtual time and triggers the AsyncSchedulerProcessor's depth-overflow guard.
|
||||
// eslint-disable-next-line local/code-no-any-casts
|
||||
(api.setTimeout as any).originalFn = originalGlobalValues.setTimeout;
|
||||
|
||||
if (options?.fakeRequestAnimationFrame) {
|
||||
let rafIdCounter = 0;
|
||||
const rafDisposables = new Map<number, IDisposable>();
|
||||
|
||||
api.requestAnimationFrame = (callback: (time: number) => void) => {
|
||||
const id = ++rafIdCounter;
|
||||
const stackTrace = new Error().stack;
|
||||
const trace = TraceContext.instance.currentTrace().child('requestAnimationFrame', stackTrace);
|
||||
// Advance virtual time by 16ms (~60fps). The task is marked with
|
||||
// useRealAnimationFrame so the AsyncSchedulerProcessor uses a real
|
||||
// browser rAF to schedule its execution, ensuring the browser
|
||||
@@ -390,8 +773,9 @@ export function createVirtualTimeApi(scheduler: Scheduler, options?: CreateVirtu
|
||||
},
|
||||
source: {
|
||||
toString() { return 'requestAnimationFrame'; },
|
||||
stackTrace: new Error().stack,
|
||||
}
|
||||
stackTrace,
|
||||
},
|
||||
trace,
|
||||
});
|
||||
rafDisposables.set(id, disposable);
|
||||
return id;
|
||||
@@ -409,7 +793,7 @@ export function createVirtualTimeApi(scheduler: Scheduler, options?: CreateVirtu
|
||||
return api;
|
||||
}
|
||||
|
||||
export function overwriteGlobalTimeApi(api: TimeApi): IDisposable {
|
||||
export function pushGlobalTimeApi(api: TimeApi): IDisposable {
|
||||
const captured = captureGlobalTimeApi();
|
||||
|
||||
// eslint-disable-next-line local/code-no-any-casts
|
||||
@@ -431,7 +815,7 @@ export function overwriteGlobalTimeApi(api: TimeApi): IDisposable {
|
||||
|
||||
return {
|
||||
dispose: () => {
|
||||
Object.assign(globalThis, captured);
|
||||
Object.assign(globalThis, captured.originalFunctions ?? captured);
|
||||
}
|
||||
};
|
||||
}
|
||||
|
||||
330
src/vs/base/test/common/traceableTimeApi.test.ts
Normal file
330
src/vs/base/test/common/traceableTimeApi.test.ts
Normal file
@@ -0,0 +1,330 @@
|
||||
/*---------------------------------------------------------------------------------------------
|
||||
* Copyright (c) Microsoft Corporation. All rights reserved.
|
||||
* Licensed under the MIT License. See License.txt in the project root for license information.
|
||||
*--------------------------------------------------------------------------------------------*/
|
||||
|
||||
import assert from 'assert';
|
||||
import { ensureNoDisposablesAreLeakedInTestSuite } from './utils.js';
|
||||
import {
|
||||
createTraceRoot,
|
||||
Trace,
|
||||
TraceContext,
|
||||
} from './traceableTimeApi.js';
|
||||
import { AsyncSchedulerProcessor, captureGlobalTimeApi, createVirtualTimeApi, TimeTravelScheduler } from './timeTravelScheduler.js';
|
||||
import { buildHistoryFromTasks, renderSwimlanes } from './executionGraph.js';
|
||||
import { DisposableStore } from '../../common/lifecycle.js';
|
||||
|
||||
/** Stable serialisation of a trace for snapshot assertions. */
|
||||
function traceInfo(t: Trace): { labels: string[]; rootLabel: string; depth: number } {
|
||||
const labels: string[] = [];
|
||||
for (let c: Trace | undefined = t; c; c = c.parent) { labels.push(c.label); }
|
||||
return { labels, rootLabel: t.root.label, depth: t.depth };
|
||||
}
|
||||
|
||||
suite('traceableTimeApi', () => {
|
||||
ensureNoDisposablesAreLeakedInTestSuite();
|
||||
|
||||
teardown(() => TraceContext.instance._resetForTesting());
|
||||
|
||||
test('Trace.describe builds causal chain from leaf to root', () => {
|
||||
const root = createTraceRoot('fixture');
|
||||
const t1 = root.child('setTimeout(100ms)');
|
||||
const t2 = t1.child('await continuation');
|
||||
assert.deepStrictEqual(traceInfo(t2), {
|
||||
labels: ['await continuation', 'setTimeout(100ms)', 'fixture'],
|
||||
rootLabel: 'fixture',
|
||||
depth: 2,
|
||||
});
|
||||
});
|
||||
|
||||
test('runWithTrace installs and restores synchronously; supports nesting', () => {
|
||||
const a = createTraceRoot('a');
|
||||
const b = createTraceRoot('b');
|
||||
const observations: string[] = [];
|
||||
observations.push(TraceContext.instance.currentTrace().label);
|
||||
TraceContext.instance.runWithTrace(a, () => {
|
||||
observations.push(TraceContext.instance.currentTrace().label);
|
||||
TraceContext.instance.runWithTrace(b, () => {
|
||||
observations.push(TraceContext.instance.currentTrace().label);
|
||||
});
|
||||
observations.push(TraceContext.instance.currentTrace().label);
|
||||
});
|
||||
observations.push(TraceContext.instance.currentTrace().label);
|
||||
assert.deepStrictEqual(observations, ['<root>', 'a', 'b', 'a', '<root>']);
|
||||
});
|
||||
|
||||
test('runAsHandler throws on sync re-entry', () => {
|
||||
const realTime = captureGlobalTimeApi();
|
||||
const a = createTraceRoot('a');
|
||||
const b = createTraceRoot('b');
|
||||
assert.throws(
|
||||
() => TraceContext.instance.runAsHandler(a, () => TraceContext.instance.runAsHandler(b, () => { }, realTime), realTime),
|
||||
/re-entrant runAsHandler/,
|
||||
);
|
||||
});
|
||||
|
||||
test('runAsHandler leaks trace across awaited microtasks', async () => {
|
||||
const realTime = captureGlobalTimeApi();
|
||||
const fixtureRoot = createTraceRoot('fixture');
|
||||
const observations: string[] = [];
|
||||
|
||||
await TraceContext.instance.runAsHandler(fixtureRoot, async () => {
|
||||
observations.push(TraceContext.instance.currentTrace().label);
|
||||
await Promise.resolve();
|
||||
observations.push(TraceContext.instance.currentTrace().label);
|
||||
await Promise.resolve().then(() => Promise.resolve());
|
||||
observations.push(TraceContext.instance.currentTrace().label);
|
||||
}, realTime);
|
||||
|
||||
assert.deepStrictEqual(observations, ['fixture', 'fixture', 'fixture']);
|
||||
});
|
||||
|
||||
test('tracing time api tags setTimeout, fires callback under captured trace', async () => {
|
||||
const realTime = captureGlobalTimeApi();
|
||||
const tracing = TraceContext.instance.createTracingTimeApi(realTime, realTime);
|
||||
const root = createTraceRoot('root');
|
||||
|
||||
const { promise, resolve } = deferred<Trace>();
|
||||
TraceContext.instance.runAsHandler(root, () => {
|
||||
tracing.setTimeout(() => resolve(TraceContext.instance.currentTrace()), 0);
|
||||
}, realTime);
|
||||
|
||||
const observed = await promise;
|
||||
assert.deepStrictEqual(traceInfo(observed), {
|
||||
labels: ['setTimeout(0ms)', 'root'],
|
||||
rootLabel: 'root',
|
||||
depth: 1,
|
||||
});
|
||||
});
|
||||
|
||||
test('tracing time api: nested setTimeout preserves full causal chain', async () => {
|
||||
const realTime = captureGlobalTimeApi();
|
||||
const tracing = TraceContext.instance.createTracingTimeApi(realTime, realTime);
|
||||
const root = createTraceRoot('root');
|
||||
|
||||
const { promise, resolve } = deferred<Trace>();
|
||||
TraceContext.instance.runAsHandler(root, () => {
|
||||
tracing.setTimeout(() => {
|
||||
tracing.setTimeout(() => resolve(TraceContext.instance.currentTrace()), 0);
|
||||
}, 0);
|
||||
}, realTime);
|
||||
|
||||
const observed = await promise;
|
||||
assert.deepStrictEqual(traceInfo(observed), {
|
||||
labels: ['setTimeout(0ms)', 'setTimeout(0ms)', 'root'],
|
||||
rootLabel: 'root',
|
||||
depth: 2,
|
||||
});
|
||||
});
|
||||
|
||||
test('setInterval: each tick gets a fresh child trace', async () => {
|
||||
const realTime = captureGlobalTimeApi();
|
||||
const tracing = TraceContext.instance.createTracingTimeApi(realTime, realTime);
|
||||
const root = createTraceRoot('root');
|
||||
|
||||
const observed: Trace[] = [];
|
||||
const { promise, resolve } = deferred<void>();
|
||||
let id: unknown;
|
||||
TraceContext.instance.runAsHandler(root, () => {
|
||||
id = tracing.setInterval(() => {
|
||||
observed.push(TraceContext.instance.currentTrace());
|
||||
if (observed.length === 3) { tracing.clearInterval(id); resolve(); }
|
||||
}, 5);
|
||||
}, realTime);
|
||||
|
||||
await promise;
|
||||
assert.deepStrictEqual(observed.map(t => traceInfo(t)), [
|
||||
{ labels: ['tick #1', 'setInterval(5ms)', 'root'], rootLabel: 'root', depth: 2 },
|
||||
{ labels: ['tick #2', 'setInterval(5ms)', 'root'], rootLabel: 'root', depth: 2 },
|
||||
{ labels: ['tick #3', 'setInterval(5ms)', 'root'], rootLabel: 'root', depth: 2 },
|
||||
]);
|
||||
});
|
||||
|
||||
test('concurrent runAsHandler via setTimeout 0: traces do not leak across handlers', async () => {
|
||||
const realTime = captureGlobalTimeApi();
|
||||
const tracing = TraceContext.instance.createTracingTimeApi(realTime, realTime);
|
||||
const a = createTraceRoot('a');
|
||||
const b = createTraceRoot('b');
|
||||
|
||||
const { promise: doneA, resolve: resA } = deferred<Trace>();
|
||||
const { promise: doneB, resolve: resB } = deferred<Trace>();
|
||||
TraceContext.instance.runAsHandler(a, () => {
|
||||
tracing.setTimeout(() => resA(TraceContext.instance.currentTrace()), 0);
|
||||
}, realTime);
|
||||
TraceContext.instance.runAsHandler(b, () => {
|
||||
tracing.setTimeout(() => resB(TraceContext.instance.currentTrace()), 0);
|
||||
}, realTime);
|
||||
|
||||
const [tA, tB] = await Promise.all([doneA, doneB]);
|
||||
assert.deepStrictEqual({
|
||||
aRoot: tA.root.label,
|
||||
aLabels: traceInfo(tA).labels,
|
||||
bRoot: tB.root.label,
|
||||
bLabels: traceInfo(tB).labels,
|
||||
}, {
|
||||
aRoot: 'a',
|
||||
aLabels: ['setTimeout(0ms)', 'a'],
|
||||
bRoot: 'b',
|
||||
bLabels: ['setTimeout(0ms)', 'b'],
|
||||
});
|
||||
});
|
||||
|
||||
test('buildHistoryFromTasks adapter: scheduler history feeds the renderer', async () => {
|
||||
const startTime = 1000;
|
||||
const store = new DisposableStore();
|
||||
const scheduler = new TimeTravelScheduler(startTime);
|
||||
const p = store.add(new AsyncSchedulerProcessor(scheduler, { maxTaskCount: 100 }));
|
||||
const vt = createVirtualTimeApi(scheduler, { fakeRequestAnimationFrame: true });
|
||||
|
||||
const rootA = createTraceRoot('A');
|
||||
const rootB = createTraceRoot('B');
|
||||
|
||||
// A: setTimeout(+0) spawns rAF(+16) and setTimeout(+50); rAF(+16) → rAF(+32).
|
||||
TraceContext.instance.runWithTrace(rootA, () => {
|
||||
vt.setTimeout(() => {
|
||||
vt.requestAnimationFrame!(() => {
|
||||
vt.requestAnimationFrame!(() => { /* A deep paint */ });
|
||||
});
|
||||
vt.setTimeout(() => { /* A delayed work */ }, 50);
|
||||
}, 0);
|
||||
});
|
||||
|
||||
// B: setTimeout(+10) → rAF(+26) → setTimeout(+46).
|
||||
TraceContext.instance.runWithTrace(rootB, () => {
|
||||
vt.setTimeout(() => {
|
||||
vt.requestAnimationFrame!(() => {
|
||||
vt.setTimeout(() => { /* B work */ }, 20);
|
||||
});
|
||||
}, 10);
|
||||
});
|
||||
|
||||
await p.run();
|
||||
|
||||
const history = buildHistoryFromTasks(p.history, startTime);
|
||||
assert.deepStrictEqual(
|
||||
{
|
||||
rootLabels: history.roots.map(r => r.label),
|
||||
events: history.events.map(e => ({
|
||||
time: e.time,
|
||||
label: e.label,
|
||||
root: e.root.label,
|
||||
parent: e.parent ? `${e.parent.label}@+${e.parent.time}` : undefined,
|
||||
})),
|
||||
},
|
||||
{
|
||||
rootLabels: ['A', 'B'],
|
||||
events: [
|
||||
{ time: 0, label: 'setTimeout', root: 'A', parent: undefined },
|
||||
{ time: 10, label: 'setTimeout', root: 'B', parent: undefined },
|
||||
{ time: 16, label: 'requestAnimationFrame', root: 'A', parent: 'setTimeout@+0' },
|
||||
{ time: 26, label: 'requestAnimationFrame', root: 'B', parent: 'setTimeout@+10' },
|
||||
{ time: 32, label: 'requestAnimationFrame', root: 'A', parent: 'requestAnimationFrame@+16' },
|
||||
{ time: 46, label: 'setTimeout', root: 'B', parent: 'requestAnimationFrame@+26' },
|
||||
{ time: 50, label: 'setTimeout', root: 'A', parent: 'setTimeout@+0' },
|
||||
],
|
||||
},
|
||||
);
|
||||
|
||||
// Sanity check: the renderer still works on adapter output. Output
|
||||
// correctness is covered by `executionGraph.test.ts`.
|
||||
assert.ok(renderSwimlanes(history).length > 0);
|
||||
|
||||
store.dispose();
|
||||
});
|
||||
|
||||
test('complex graph: async/await + setTimeout + setInterval + rAF interleave with preserved causality', async () => {
|
||||
const startTime = 1000;
|
||||
const store = new DisposableStore();
|
||||
const scheduler = new TimeTravelScheduler(startTime);
|
||||
const p = store.add(new AsyncSchedulerProcessor(scheduler, { maxTaskCount: 200 }));
|
||||
const vt = createVirtualTimeApi(scheduler, { fakeRequestAnimationFrame: true });
|
||||
const log = TraceContext.instance.log.bind(TraceContext.instance);
|
||||
|
||||
const rootA = createTraceRoot('A');
|
||||
const rootB = createTraceRoot('B');
|
||||
|
||||
// A: setTimeout(+1) runs an async handler that, after a microtask,
|
||||
// fans out into rAF (+16) and setInterval(10ms). The rAF callback
|
||||
// itself awaits a microtask before scheduling a setTimeout(+20).
|
||||
// The interval ticks twice and then clears itself.
|
||||
TraceContext.instance.runWithTrace(rootA, () => {
|
||||
vt.setTimeout(async () => {
|
||||
log('A:start');
|
||||
await Promise.resolve();
|
||||
log('A:after-await');
|
||||
vt.requestAnimationFrame!(async () => {
|
||||
log('A:rAF');
|
||||
await Promise.resolve();
|
||||
vt.setTimeout(() => log('A:post-rAF'), 20);
|
||||
});
|
||||
let ticks = 0;
|
||||
const id = vt.setInterval(() => {
|
||||
ticks++;
|
||||
log(`A:tick#${ticks}`);
|
||||
if (ticks === 2) { vt.clearInterval(id); }
|
||||
}, 10);
|
||||
}, 1);
|
||||
});
|
||||
|
||||
// B: setTimeout(+3) → rAF (+19) → setTimeout(+39). Starts close to A
|
||||
// so the two roots' events interleave on the timeline.
|
||||
TraceContext.instance.runWithTrace(rootB, () => {
|
||||
vt.setTimeout(() => {
|
||||
log('B:start');
|
||||
vt.requestAnimationFrame!(() => {
|
||||
log('B:rAF');
|
||||
vt.setTimeout(() => log('B:post-rAF'), 20);
|
||||
});
|
||||
}, 3);
|
||||
});
|
||||
|
||||
await p.run();
|
||||
|
||||
const history = buildHistoryFromTasks(p.history, startTime, TraceContext.instance.takeLog());
|
||||
assert.deepStrictEqual(
|
||||
{
|
||||
rootLabels: history.roots.map(r => r.label),
|
||||
events: history.events.map(e => ({
|
||||
time: e.time,
|
||||
label: e.label,
|
||||
root: e.root.label,
|
||||
parent: e.parent ? `${e.parent.label}@+${e.parent.time}` : undefined,
|
||||
})),
|
||||
},
|
||||
{
|
||||
rootLabels: ['A', 'B'],
|
||||
events: [
|
||||
{ time: 1, label: 'setTimeout', root: 'A', parent: undefined },
|
||||
{ time: 1, label: 'log: A:start', root: 'A', parent: 'setTimeout@+1' },
|
||||
{ time: 1, label: 'log: A:after-await', root: 'A', parent: 'setTimeout@+1' },
|
||||
{ time: 3, label: 'setTimeout', root: 'B', parent: undefined },
|
||||
{ time: 3, label: 'log: B:start', root: 'B', parent: 'setTimeout@+3' },
|
||||
{ time: 11, label: 'setInterval (iteration 1)', root: 'A', parent: 'setTimeout@+1' },
|
||||
{ time: 11, label: 'log: A:tick#1', root: 'A', parent: 'setInterval (iteration 1)@+11' },
|
||||
{ time: 17, label: 'requestAnimationFrame', root: 'A', parent: 'setTimeout@+1' },
|
||||
{ time: 17, label: 'log: A:rAF', root: 'A', parent: 'requestAnimationFrame@+17' },
|
||||
{ time: 19, label: 'requestAnimationFrame', root: 'B', parent: 'setTimeout@+3' },
|
||||
{ time: 19, label: 'log: B:rAF', root: 'B', parent: 'requestAnimationFrame@+19' },
|
||||
{ time: 21, label: 'setInterval (iteration 2)', root: 'A', parent: 'setTimeout@+1' },
|
||||
{ time: 21, label: 'log: A:tick#2', root: 'A', parent: 'setInterval (iteration 2)@+21' },
|
||||
{ time: 37, label: 'setTimeout', root: 'A', parent: 'requestAnimationFrame@+17' },
|
||||
{ time: 37, label: 'log: A:post-rAF', root: 'A', parent: 'setTimeout@+37' },
|
||||
{ time: 39, label: 'setTimeout', root: 'B', parent: 'requestAnimationFrame@+19' },
|
||||
{ time: 39, label: 'log: B:post-rAF', root: 'B', parent: 'setTimeout@+39' },
|
||||
],
|
||||
},
|
||||
);
|
||||
|
||||
// Sanity check: the renderer accepts the adapter output.
|
||||
assert.ok(renderSwimlanes(history).length > 0);
|
||||
|
||||
store.dispose();
|
||||
});
|
||||
});
|
||||
|
||||
function deferred<T>(): { promise: Promise<T>; resolve: (v: T) => void; reject: (e: unknown) => void } {
|
||||
let resolve!: (v: T) => void;
|
||||
let reject!: (e: unknown) => void;
|
||||
const promise = new Promise<T>((res, rej) => { resolve = res; reject = rej; });
|
||||
return { promise, resolve, reject };
|
||||
}
|
||||
352
src/vs/base/test/common/traceableTimeApi.ts
Normal file
352
src/vs/base/test/common/traceableTimeApi.ts
Normal file
@@ -0,0 +1,352 @@
|
||||
/*---------------------------------------------------------------------------------------------
|
||||
* Copyright (c) Microsoft Corporation. All rights reserved.
|
||||
* Licensed under the MIT License. See License.txt in the project root for license information.
|
||||
*--------------------------------------------------------------------------------------------*/
|
||||
|
||||
import { BugIndicatingError } from '../../common/errors.js';
|
||||
import type { TimeApi } from './timeTravelScheduler.js';
|
||||
|
||||
/**
|
||||
* # Trace / tracing time api — theory of operation
|
||||
*
|
||||
* ## The problem
|
||||
*
|
||||
* In a test runtime where many async activities interleave (parallel fixtures,
|
||||
* timers, promise chains), we want to ask of any scheduled action: "who
|
||||
* caused this?". Clean causal attribution is useful for:
|
||||
* - debugging ("which fixture left this timer queued?"),
|
||||
* - per-owner termination criteria ("queue drained *for my fixture*"),
|
||||
* - attribution in error messages.
|
||||
*
|
||||
* ## The model
|
||||
*
|
||||
* A {@link Trace} is an immutable value identifying a causal chain:
|
||||
*
|
||||
* Trace = { id; parent?: Trace; label: string; stack?: string; root: Trace }
|
||||
*
|
||||
* Roots have no parent. Every non-root trace's `root` points back to the top
|
||||
* of its chain. Traces are only created by user code, timer wrappers, or the
|
||||
* scheduler — never implicitly.
|
||||
*
|
||||
* ## The runtime state: {@link TraceContext}
|
||||
*
|
||||
* A {@link TraceContext} owns the mutable "current frame" slot plus a
|
||||
* boolean re-entry guard. Production code uses the shared
|
||||
* {@link TraceContext.instance}; tests can construct fresh instances for
|
||||
* full isolation. The slot is mutated by two primitives:
|
||||
*
|
||||
* - {@link TraceContext.runWithTrace}(t, fn): set current=t, run fn
|
||||
* synchronously, restore previous frame on exit. Nesting is supported.
|
||||
* Microtasks enqueued by fn that run *after* fn returns see the
|
||||
* restored trace. Use only for bounded synchronous regions.
|
||||
*
|
||||
* - {@link TraceContext.runAsHandler}(t, fn, resetApi): set current=t,
|
||||
* run fn, and
|
||||
* **do not restore synchronously**. The trace is reset on the next
|
||||
* macrotask via `resetApi.setTimeout(0)`, guarded by a sequence number.
|
||||
* Any microtask drain that follows `fn` — including `await` continuations
|
||||
* inside `fn` — inherits `t`. Throws if called while another runAsHandler
|
||||
* is on the JS call stack. Use for timer callbacks and other async
|
||||
* entry points (e.g. the fixture's render body).
|
||||
*
|
||||
* ## Why this works for attribution
|
||||
*
|
||||
* The JS event loop drains microtasks to completion between macrotasks. So
|
||||
* any microtask enqueued during a macrotask runs with whatever `_currentTrace`
|
||||
* that macrotask left behind. If that macrotask is a timer callback that
|
||||
* used `runAsHandler(t, ...)`, every continuation during its drain sees `t`,
|
||||
* and any timer scheduled during that drain captures `t` via the tracing
|
||||
* TimeApi wrapper.
|
||||
*
|
||||
* Across macrotasks, the chain is preserved by the wrapper: each call to
|
||||
* `setTimeout`/`setInterval`/`requestAnimationFrame` going through
|
||||
* {@link createTracingTimeApi} captures the current trace at schedule time
|
||||
* and re-installs it (as a child) via `runAsHandler` when the callback fires.
|
||||
*
|
||||
* ## Why the identity-guarded reset is correct
|
||||
*
|
||||
* Two macrotasks A, B firing back-to-back:
|
||||
*
|
||||
* [A] runAsHandler(t_A, fnA) -> _current = frame_A; schedule reset_A
|
||||
* [micro drain] -> await continuations see t_A
|
||||
* [B] runAsHandler(t_B, fnB) -> _current = frame_B; schedule reset_B
|
||||
* [micro drain] -> await continuations see t_B
|
||||
* [reset_A fires] -> sees _current !== frame_A -> no-op
|
||||
* [reset_B fires] -> _current = frame_A.prev (or its prev)
|
||||
*
|
||||
* Each `runAsHandler` mints a fresh {@link Frame}, so the active-frame
|
||||
* identity check rejects stale resets. This tolerates arbitrary
|
||||
* interleaving of concurrent handlers (e.g. parallel fixtures) correctly.
|
||||
*
|
||||
* ## Caveat: sync re-entry is a bug
|
||||
*
|
||||
* `runAsHandler` throws if another `runAsHandler` is already on the JS
|
||||
* stack. Timer callbacks never run nested on the same stack (the event
|
||||
* loop runs one at a time), so this throw only fires for misuse (e.g. a
|
||||
* handler synchronously calling another handler). Nested
|
||||
* {@link runWithTrace} is always fine — it push/pops synchronously.
|
||||
*/
|
||||
|
||||
export class Trace {
|
||||
private static _idCounter = 0;
|
||||
|
||||
public readonly id: number = ++Trace._idCounter;
|
||||
public readonly root: Trace;
|
||||
public readonly depth: number;
|
||||
public readonly createdAt: number = Date.now();
|
||||
|
||||
constructor(
|
||||
public readonly parent: Trace | undefined,
|
||||
public readonly label: string,
|
||||
public readonly stack: string | undefined = undefined,
|
||||
) {
|
||||
this.root = parent?.root ?? this;
|
||||
this.depth = (parent?.depth ?? -1) + 1;
|
||||
}
|
||||
|
||||
child(label: string, stack?: string): Trace {
|
||||
return new Trace(this, label, stack);
|
||||
}
|
||||
|
||||
/**
|
||||
* Renders the causal chain as "#id label ← #id label ← … ← #id label".
|
||||
*/
|
||||
describe(): string {
|
||||
const parts: string[] = [];
|
||||
for (let t: Trace | undefined = this; t; t = t.parent) {
|
||||
parts.push(`#${t.id} ${t.label}`);
|
||||
}
|
||||
return parts.join(' ← ');
|
||||
}
|
||||
|
||||
toString(): string { return this.describe(); }
|
||||
}
|
||||
|
||||
/** Sentinel root for "no known provenance". */
|
||||
export const ROOT_TRACE: Trace = new Trace(undefined, '<root>');
|
||||
|
||||
export function createTraceRoot(label: string, stack?: string): Trace {
|
||||
return new Trace(undefined, label, stack);
|
||||
}
|
||||
|
||||
// ============================================================================
|
||||
// TraceContext: encapsulated trace state
|
||||
// ============================================================================
|
||||
|
||||
export interface TracingTimeApiOptions {
|
||||
/** Capture a stack trace on every schedule call. Expensive; enable for
|
||||
* debugging only. */
|
||||
readonly captureStacks?: boolean;
|
||||
/** Observer hook. Called synchronously on schedule and on fire. */
|
||||
readonly onEvent?: (event: TracingTimeEvent) => void;
|
||||
}
|
||||
|
||||
export type TracingTimeEvent =
|
||||
| { readonly kind: 'schedule'; readonly api: string; readonly trace: Trace; readonly delayMs?: number }
|
||||
| { readonly kind: 'fire'; readonly api: string; readonly trace: Trace }
|
||||
| { readonly kind: 'throw'; readonly api: string; readonly trace: Trace; readonly error: unknown };
|
||||
|
||||
/**
|
||||
* A pushed/popped trace activation. A fresh `Frame` is minted by every
|
||||
* `runWithTrace` / `runAsHandler` call; identity is what the deferred
|
||||
* reset in `runAsHandler` uses to detect that it's stale.
|
||||
*/
|
||||
interface Frame {
|
||||
readonly trace: Trace;
|
||||
readonly prev: Frame | undefined;
|
||||
}
|
||||
|
||||
const ROOT_FRAME: Frame = { trace: ROOT_TRACE, prev: undefined };
|
||||
|
||||
/**
|
||||
* Holds the mutable "current frame" slot and exposes the trace propagation
|
||||
* primitives as methods.
|
||||
*
|
||||
* Invariants:
|
||||
* - Reads (`currentTrace()`) are pure.
|
||||
* - Writes happen only inside `runWithTrace` / `runAsHandler` bodies.
|
||||
* - Each call mints a fresh {@link Frame} object. A scheduled reset only
|
||||
* fires if `_current` still points at *its* frame — preventing a stale
|
||||
* reset from clobbering a newer installation.
|
||||
* - `_isHandlerRunning` is true iff a `runAsHandler` frame is on the JS
|
||||
* call stack. It returns to false between macrotasks.
|
||||
*
|
||||
* Production callers go through {@link TraceContext.instance}. Tests may
|
||||
* construct fresh instances to get full isolation.
|
||||
*/
|
||||
export class TraceContext {
|
||||
/** Shared default context. Production callers use this. */
|
||||
public static readonly instance = new TraceContext();
|
||||
|
||||
private _current: Frame = ROOT_FRAME;
|
||||
private _isHandlerRunning: boolean = false;
|
||||
private _log: { trace: Trace; message: string }[] = [];
|
||||
|
||||
currentTrace(): Trace { return this._current.trace; }
|
||||
|
||||
/**
|
||||
* Append `message` to an in-memory log, tagged with the current trace.
|
||||
* Useful for tests that want to assert the interleaving of work across
|
||||
* causally distinct roots. Drain via {@link takeLog}.
|
||||
*/
|
||||
log(message: string): void {
|
||||
this._log.push({ trace: this._current.trace, message });
|
||||
}
|
||||
|
||||
/** Drain and return all entries logged via {@link log}. */
|
||||
takeLog(): readonly { trace: Trace; message: string }[] {
|
||||
const entries = this._log;
|
||||
this._log = [];
|
||||
return entries;
|
||||
}
|
||||
|
||||
/**
|
||||
* Install `t` as the current trace for the synchronous duration of `fn`,
|
||||
* then restore the previous trace. Nestable. Does NOT propagate `t` into
|
||||
* microtasks enqueued by fn that run *after* fn returns.
|
||||
*
|
||||
* Use for bounded synchronous scopes (e.g. iterating a batch of tagged
|
||||
* callbacks within a single tick).
|
||||
*/
|
||||
runWithTrace<T>(t: Trace, fn: () => T): T {
|
||||
const prev = this._current;
|
||||
const next = { trace: t, prev };
|
||||
this._current = next;
|
||||
try {
|
||||
return fn();
|
||||
} finally {
|
||||
if (this._current !== next) {
|
||||
// eslint-disable-next-line no-unsafe-finally
|
||||
throw new BugIndicatingError(
|
||||
`traceableTimeApi: runWithTrace detected unexpected mutation. ` +
|
||||
`current=${this._current.trace.describe()}, expected=${t.describe()}`
|
||||
);
|
||||
}
|
||||
this._current = prev;
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Install `t` as the current trace, run `fn`, and keep `t` installed
|
||||
* through the microtask drain that follows. Restore the previous trace
|
||||
* via an identity-guarded `resetApi.setTimeout(0)` so that awaited
|
||||
* continuations within `fn` observe `t`.
|
||||
*
|
||||
* Throws if called while another `runAsHandler` frame is on the JS call
|
||||
* stack (synchronous re-entry is a bug).
|
||||
*/
|
||||
runAsHandler<T>(t: Trace, fn: () => T, resetApi: TimeApi): T {
|
||||
if (this._isHandlerRunning) {
|
||||
throw new Error(
|
||||
`traceableTimeApi: re-entrant runAsHandler detected. ` +
|
||||
`current=${this._current.trace.describe()}, incoming=${t.describe()}`
|
||||
);
|
||||
}
|
||||
const prev = this._current;
|
||||
const next: Frame = { trace: t, prev };
|
||||
this._current = next;
|
||||
this._isHandlerRunning = true;
|
||||
try {
|
||||
return fn();
|
||||
} finally {
|
||||
this._isHandlerRunning = false;
|
||||
// Do NOT restore synchronously: microtasks enqueued by fn (including
|
||||
// awaited continuations) must observe `t`. Schedule an
|
||||
// identity-guarded reset on the next macrotask via the raw
|
||||
// real-time API.
|
||||
//
|
||||
// `_current !== next` is the normal case when handlers
|
||||
// interleave: another `runAsHandler` ran between us scheduling
|
||||
// this reset and it firing, so it pushed its own frame and
|
||||
// queued its own reset that will do the restoring. Skipping
|
||||
// here is correct — see the class doc "identity-guarded reset".
|
||||
resetApi.setTimeout(() => {
|
||||
if (this._current === next) {
|
||||
this._current = prev;
|
||||
}
|
||||
}, 0);
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Wrap `wrapped` so that every scheduled callback is tagged with the
|
||||
* current trace at schedule time, and re-installed via
|
||||
* {@link runAsHandler} when it fires. `resetApi` is used to schedule
|
||||
* trace resets and must be a real-time API (pointing it at a virtual
|
||||
* API would prevent resets from ever firing).
|
||||
*
|
||||
* Re-entrancy with a virtual-time scheduler: do NOT stack this wrapper
|
||||
* over a virtual-time `TimeApi`. The scheduler already installs traces
|
||||
* via `runAsHandler` when it runs each task, and a second
|
||||
* `runAsHandler` from this wrapper would trip the sync re-entry guard.
|
||||
*/
|
||||
createTracingTimeApi(
|
||||
wrapped: TimeApi,
|
||||
resetApi: TimeApi,
|
||||
options: TracingTimeApiOptions = {},
|
||||
): TimeApi {
|
||||
const captureStacks = options.captureStacks ?? false;
|
||||
const onEvent = options.onEvent;
|
||||
|
||||
const capture = (label: string, delayMs?: number): Trace => {
|
||||
const stack = captureStacks ? new Error().stack : undefined;
|
||||
const t = this._current.trace.child(label, stack);
|
||||
onEvent?.({ kind: 'schedule', api: label, trace: t, delayMs });
|
||||
return t;
|
||||
};
|
||||
|
||||
const invoke = (trace: Trace, api: string, body: () => void): void => {
|
||||
onEvent?.({ kind: 'fire', api, trace });
|
||||
try {
|
||||
this.runAsHandler(trace, body, resetApi);
|
||||
} catch (e) {
|
||||
onEvent?.({ kind: 'throw', api, trace, error: e });
|
||||
throw e;
|
||||
}
|
||||
};
|
||||
|
||||
const api: TimeApi = {
|
||||
Date: wrapped.Date,
|
||||
setTimeout: (handler: () => void, ms?: number) => {
|
||||
const t = capture(`setTimeout(${ms ?? 0}ms)`, ms);
|
||||
return wrapped.setTimeout(() => invoke(t, 'setTimeout', handler), ms);
|
||||
},
|
||||
clearTimeout: (id: unknown) => wrapped.clearTimeout(id),
|
||||
setInterval: (handler: () => void, interval: number) => {
|
||||
const base = capture(`setInterval(${interval}ms)`, interval);
|
||||
let tickIdx = 0;
|
||||
return wrapped.setInterval(() => {
|
||||
const tickTrace = base.child(`tick #${++tickIdx}`);
|
||||
invoke(tickTrace, 'setInterval', handler);
|
||||
}, interval);
|
||||
},
|
||||
clearInterval: (id: unknown) => wrapped.clearInterval(id),
|
||||
};
|
||||
|
||||
if (wrapped.setImmediate) {
|
||||
api.setImmediate = (handler: () => void) => {
|
||||
const t = capture('setImmediate');
|
||||
return wrapped.setImmediate!(() => invoke(t, 'setImmediate', handler));
|
||||
};
|
||||
api.clearImmediate = (id: unknown) => wrapped.clearImmediate?.(id);
|
||||
}
|
||||
|
||||
if (wrapped.requestAnimationFrame) {
|
||||
api.requestAnimationFrame = (cb: (time: number) => void) => {
|
||||
const t = capture('requestAnimationFrame');
|
||||
return wrapped.requestAnimationFrame!(time => invoke(t, 'requestAnimationFrame', () => cb(time)));
|
||||
};
|
||||
api.cancelAnimationFrame = (id: number) => wrapped.cancelAnimationFrame?.(id);
|
||||
}
|
||||
|
||||
api.originalFunctions = wrapped.originalFunctions ?? wrapped;
|
||||
return api;
|
||||
}
|
||||
|
||||
/** Reset state. Only intended for tests. */
|
||||
_resetForTesting(): void {
|
||||
this._current = ROOT_FRAME;
|
||||
this._isHandlerRunning = false;
|
||||
this._log = [];
|
||||
}
|
||||
}
|
||||
@@ -6,21 +6,27 @@
|
||||
// This should be the only place that is allowed to import from @vscode/component-explorer
|
||||
// eslint-disable-next-line local/code-import-patterns
|
||||
import { defineFixture, defineFixtureGroup, defineFixtureVariants } from '@vscode/component-explorer';
|
||||
import { DisposableStore, toDisposable } from '../../../../base/common/lifecycle.js';
|
||||
import { DisposableStore, DisposableTracker, setDisposableTracker, toDisposable } from '../../../../base/common/lifecycle.js';
|
||||
import { URI } from '../../../../base/common/uri.js';
|
||||
// eslint-disable-next-line local/code-import-patterns
|
||||
import '../../../../../../build/vite/style.css';
|
||||
import '../../../browser/media/style.css';
|
||||
// Import auxiliaryBarPart.css here (before any contrib/chat CSS) so the cascade
|
||||
// matches the product: chat.css loads later and overrides the auxiliarybar
|
||||
// rules where applicable. Fixtures that wrap content in `.part.auxiliarybar`
|
||||
// rely on these rules to recolor inline editors with `--vscode-sideBar-background`.
|
||||
import '../../../browser/parts/auxiliarybar/media/auxiliaryBarPart.css';
|
||||
|
||||
// Theme
|
||||
import { IEnvironmentService } from '../../../../platform/environment/common/environment.js';
|
||||
import { IExtensionResourceLoaderService } from '../../../../platform/extensionResourceLoader/common/extensionResourceLoader.js';
|
||||
import { Registry } from '../../../../platform/registry/common/platform.js';
|
||||
import { getIconsStyleSheet } from '../../../../platform/theme/browser/iconsStyleSheet.js';
|
||||
import { ColorScheme } from '../../../../platform/theme/common/theme.js';
|
||||
import { ColorScheme, ThemeTypeSelector } from '../../../../platform/theme/common/theme.js';
|
||||
import { IColorTheme, IThemeService, IThemingRegistry, Extensions as ThemingExtensions } from '../../../../platform/theme/common/themeService.js';
|
||||
import { generateColorThemeCSS } from '../../../services/themes/browser/colorThemeCss.js';
|
||||
import { ColorThemeData } from '../../../services/themes/common/colorThemeData.js';
|
||||
import { COLOR_THEME_DARK_INITIAL_COLORS, COLOR_THEME_LIGHT_INITIAL_COLORS } from '../../../services/themes/common/workbenchThemeService.js';
|
||||
import { ExtensionData } from '../../../services/themes/common/workbenchThemeService.js';
|
||||
|
||||
// Instantiation
|
||||
import { SyncDescriptor } from '../../../../platform/instantiation/common/descriptors.js';
|
||||
@@ -82,6 +88,7 @@ import { IUndoRedoService } from '../../../../platform/undoRedo/common/undoRedo.
|
||||
import { UndoRedoService } from '../../../../platform/undoRedo/common/undoRedoService.js';
|
||||
import { IUserDataProfile } from '../../../../platform/userDataProfile/common/userDataProfile.js';
|
||||
import { IUserInteractionService, MockUserInteractionService } from '../../../../platform/userInteraction/browser/userInteractionService.js';
|
||||
import { IActionWidgetService } from '../../../../platform/actionWidget/browser/actionWidget.js';
|
||||
import { IAnyWorkspaceIdentifier } from '../../../../platform/workspace/common/workspace.js';
|
||||
import { TestMenuService } from '../workbenchTestServices.js';
|
||||
import { IAccessibilitySignalService } from '../../../../platform/accessibilitySignal/browser/accessibilitySignalService.js';
|
||||
@@ -102,7 +109,7 @@ import './fixtures.css';
|
||||
|
||||
// Import color registrations to ensure colors are available
|
||||
import { IdleDeadline, installFakeRunWhenIdle } from '../../../../base/common/async.js';
|
||||
import { AsyncSchedulerProcessor, TimeTravelScheduler, captureGlobalTimeApi, createLoggingTimeApi, createVirtualTimeApi, overwriteGlobalTimeApi } from '../../../../base/test/common/timeTravelScheduler.js';
|
||||
import { AsyncSchedulerProcessor, TimeTravelScheduler, captureGlobalTimeApi, createLoggingTimeApi, createVirtualTimeApi, pushGlobalTimeApi } from '../../../../base/test/common/timeTravelScheduler.js';
|
||||
import '../../../../platform/theme/common/colors/baseColors.js';
|
||||
import '../../../../platform/theme/common/colors/editorColors.js';
|
||||
import '../../../../platform/theme/common/colors/listColors.js';
|
||||
@@ -224,15 +231,55 @@ class NullStorageService implements IStorageService {
|
||||
const themingRegistry = Registry.as<IThemingRegistry>(ThemingExtensions.ThemingContribution);
|
||||
const mockEnvironmentService: IEnvironmentService = Object.create(null);
|
||||
|
||||
export const darkTheme = ColorThemeData.createUnloadedThemeForThemeType(
|
||||
ColorScheme.DARK,
|
||||
COLOR_THEME_DARK_INITIAL_COLORS
|
||||
);
|
||||
// Eagerly bundle all built-in theme JSON files so they can be served to
|
||||
// `_loadColorTheme` via the IExtensionResourceLoaderService code path. The
|
||||
// rspack config maps these JSON files to `asset/source`, so they are imported
|
||||
// as raw text (not parsed JSON) — this lets VS Code's JSONC parser handle
|
||||
// comments and trailing commas the way it does in the real product.
|
||||
/* eslint-disable local/code-import-patterns */
|
||||
import dark_modern from '../../../../../../extensions/theme-defaults/themes/dark_modern.json' with { type: 'json' };
|
||||
import dark_plus from '../../../../../../extensions/theme-defaults/themes/dark_plus.json' with { type: 'json' };
|
||||
import dark_vs from '../../../../../../extensions/theme-defaults/themes/dark_vs.json' with { type: 'json' };
|
||||
import light_modern from '../../../../../../extensions/theme-defaults/themes/light_modern.json' with { type: 'json' };
|
||||
import light_plus from '../../../../../../extensions/theme-defaults/themes/light_plus.json' with { type: 'json' };
|
||||
import light_vs from '../../../../../../extensions/theme-defaults/themes/light_vs.json' with { type: 'json' };
|
||||
import { createTraceRoot, TraceContext } from '../../../../base/test/common/traceableTimeApi.js';
|
||||
/* eslint-enable local/code-import-patterns */
|
||||
|
||||
export const lightTheme = ColorThemeData.createUnloadedThemeForThemeType(
|
||||
ColorScheme.LIGHT,
|
||||
COLOR_THEME_LIGHT_INITIAL_COLORS
|
||||
);
|
||||
const themeJsonModules: Record<string, string> = {
|
||||
'/extensions/theme-defaults/themes/dark_modern.json': dark_modern as unknown as string,
|
||||
'/extensions/theme-defaults/themes/dark_plus.json': dark_plus as unknown as string,
|
||||
'/extensions/theme-defaults/themes/dark_vs.json': dark_vs as unknown as string,
|
||||
'/extensions/theme-defaults/themes/light_modern.json': light_modern as unknown as string,
|
||||
'/extensions/theme-defaults/themes/light_plus.json': light_plus as unknown as string,
|
||||
'/extensions/theme-defaults/themes/light_vs.json': light_vs as unknown as string,
|
||||
};
|
||||
|
||||
const fixtureExtensionResourceLoaderService = new class implements IExtensionResourceLoaderService {
|
||||
declare readonly _serviceBrand: undefined;
|
||||
async readExtensionResource(uri: URI): Promise<string> {
|
||||
const content = themeJsonModules[uri.path];
|
||||
if (content === undefined) {
|
||||
throw new Error(`Fixture extension resource not found: ${uri.toString()}`);
|
||||
}
|
||||
return content;
|
||||
}
|
||||
supportsExtensionGalleryResources(): Promise<boolean> { return Promise.resolve(false); }
|
||||
isExtensionGalleryResource(): Promise<boolean> { return Promise.resolve(false); }
|
||||
getExtensionGalleryResourceURL(): Promise<URI | undefined> { return Promise.resolve(undefined); }
|
||||
};
|
||||
|
||||
function createBuiltInTheme(themePath: string, uiTheme: ThemeTypeSelector): ColorThemeData {
|
||||
const location = URI.parse(`file://${themePath}`);
|
||||
return ColorThemeData.fromExtensionTheme(
|
||||
{ id: themePath, path: themePath, uiTheme, _watch: false },
|
||||
location,
|
||||
ExtensionData.fromName('vscode', 'theme-defaults', true)
|
||||
);
|
||||
}
|
||||
|
||||
export const darkTheme = createBuiltInTheme('/extensions/theme-defaults/themes/dark_modern.json', ThemeTypeSelector.VS_DARK);
|
||||
export const lightTheme = createBuiltInTheme('/extensions/theme-defaults/themes/light_modern.json', ThemeTypeSelector.VS);
|
||||
|
||||
let globalStyleSheet: CSSStyleSheet | undefined;
|
||||
let iconsStyleSheetCache: CSSStyleSheet | undefined;
|
||||
@@ -296,6 +343,17 @@ function getThemeStyleSheet(theme: ColorThemeData): CSSStyleSheet {
|
||||
|
||||
let globalStylesInstalled = false;
|
||||
|
||||
let themesLoadedPromise: Promise<void> | undefined;
|
||||
function ensureThemesLoaded(): Promise<void> {
|
||||
if (!themesLoadedPromise) {
|
||||
themesLoadedPromise = Promise.all([
|
||||
darkTheme.ensureLoaded(fixtureExtensionResourceLoaderService),
|
||||
lightTheme.ensureLoaded(fixtureExtensionResourceLoaderService),
|
||||
]).then(() => undefined);
|
||||
}
|
||||
return themesLoadedPromise;
|
||||
}
|
||||
|
||||
function installGlobalStyles(): void {
|
||||
if (globalStylesInstalled) {
|
||||
return;
|
||||
@@ -310,7 +368,8 @@ function installGlobalStyles(): void {
|
||||
];
|
||||
}
|
||||
|
||||
export function setupTheme(container: HTMLElement, theme: ColorThemeData): void {
|
||||
export async function setupTheme(container: HTMLElement, theme: ColorThemeData): Promise<void> {
|
||||
await ensureThemesLoaded();
|
||||
installGlobalStyles();
|
||||
container.classList.add('monaco-workbench', getPlatformClass(), 'disable-animations', ...theme.classNames);
|
||||
}
|
||||
@@ -454,6 +513,13 @@ export function createEditorServices(disposables: DisposableStore, options?: Cre
|
||||
// User interaction service with focus simulation enabled (all elements appear focused in fixtures)
|
||||
defineInstance(IUserInteractionService, new MockUserInteractionService(true, false));
|
||||
|
||||
definePartialInstance(IActionWidgetService, {
|
||||
_serviceBrand: undefined,
|
||||
show: () => { },
|
||||
hide: () => { },
|
||||
get isVisible() { return false; },
|
||||
});
|
||||
|
||||
defineInstance(IAccessibilitySignalService, {
|
||||
_serviceBrand: undefined,
|
||||
playSignal: async () => { },
|
||||
@@ -646,6 +712,7 @@ export interface ComponentFixtureContext {
|
||||
export interface ComponentFixtureOptions {
|
||||
render: (context: ComponentFixtureContext) => void | Promise<void>;
|
||||
labels?: ThemedFixtureGroupLabels;
|
||||
virtualTime?: { enabled?: boolean; durationMs?: number };
|
||||
}
|
||||
|
||||
type ThemedFixtures = ReturnType<typeof defineFixtureVariants>;
|
||||
@@ -653,11 +720,20 @@ type ThemedFixtures = ReturnType<typeof defineFixtureVariants>;
|
||||
// Permanent logging layer that detects real timer API usage.
|
||||
// Includes handler source for identification since bundled stack traces are not useful.
|
||||
const realTimeApi = captureGlobalTimeApi();
|
||||
const loggingTimeApi = createLoggingTimeApi(realTimeApi, (name, stack, handler) => {
|
||||
const handlerStr = typeof handler === 'function' ? handler.toString().slice(0, 500) : String(handler);
|
||||
console.warn(`[ComponentFixture] Real ${name} called outside of virtual time.\nHandler: ${handlerStr}\nStack: ${stack}`);
|
||||
});
|
||||
overwriteGlobalTimeApi(loggingTimeApi);
|
||||
const logOutsideTime = false;
|
||||
if (logOutsideTime) {
|
||||
const loggingTimeApi = createLoggingTimeApi(realTimeApi, (name, stack, handler) => {
|
||||
const handlerStr = typeof handler === 'function' ? handler.toString().slice(0, 500) : String(handler);
|
||||
console.warn(`[ComponentFixture] Real ${name} called outside of virtual time.\nHandler: ${handlerStr}\nStack: ${stack}`);
|
||||
});
|
||||
pushGlobalTimeApi(loggingTimeApi);
|
||||
}
|
||||
|
||||
let fixtureRenderCounter = 0;
|
||||
|
||||
// See TODO in defineComponentFixture: leak errors detected during teardown are
|
||||
// stashed here and rethrown from the next fixture render.
|
||||
let pendingLeakErrorToThrow: Error | undefined;
|
||||
|
||||
/**
|
||||
* Creates Dark and Light fixture variants from a single render function.
|
||||
@@ -673,49 +749,117 @@ export function defineComponentFixture(options: ComponentFixtureOptions): Themed
|
||||
displayMode: { type: 'component' },
|
||||
background: theme === darkTheme ? 'dark' : 'light',
|
||||
render: async (container: HTMLElement, context) => {
|
||||
const disposableStore = context.addDisposable(new DisposableStore());
|
||||
// TODO: component-explorer currently ignores errors thrown from the
|
||||
// teardown disposable (where leak detection runs, after the screenshot).
|
||||
// Until it surfaces those, we stash the leak error and rethrow it from
|
||||
// the next fixture render so the failure still becomes visible.
|
||||
const pendingLeakError = pendingLeakErrorToThrow;
|
||||
pendingLeakErrorToThrow = undefined;
|
||||
if (pendingLeakError) {
|
||||
throw pendingLeakError;
|
||||
}
|
||||
|
||||
const schedulerStore = disposableStore.add(new DisposableStore());
|
||||
const scheduler = new TimeTravelScheduler(Date.now());
|
||||
const p = schedulerStore.add(new AsyncSchedulerProcessor(scheduler, {
|
||||
maxTaskCount: 100,
|
||||
realTimeApi,
|
||||
const disposableStore = new DisposableStore();
|
||||
|
||||
// Do not enable virtual time in explorer ui, as multiple fixtures are rendered in parallel.
|
||||
const virtualTimeEnabled = (options.virtualTime?.enabled ?? true) && context.host.kind !== 'explorer-ui';
|
||||
|
||||
// Detect disposable leaks the same way unit tests do (`ensureNoDisposablesAreLeakedInTestSuite`).
|
||||
// The tracker is global and therefore unsafe when fixtures render in parallel,
|
||||
// so it is only enabled outside the explorer UI (e.g. in screenshot/CI mode).
|
||||
const leakDetectionEnabled = false && context.host.kind !== 'explorer-ui';
|
||||
const tracker = leakDetectionEnabled ? new DisposableTracker() : undefined;
|
||||
if (tracker) {
|
||||
setDisposableTracker(tracker);
|
||||
}
|
||||
|
||||
const leakLabel = `${(options.labels ? resolveLabels(options.labels).join('/') : '<unlabeled>')}/${theme === darkTheme ? 'Dark' : 'Light'} (render#${fixtureRenderCounter + 1})`;
|
||||
|
||||
context.addDisposable(toDisposable(() => {
|
||||
disposableStore.dispose();
|
||||
if (tracker) {
|
||||
setDisposableTracker(null);
|
||||
const result = tracker.computeLeakingDisposables();
|
||||
if (result) {
|
||||
console.error(result.details);
|
||||
pendingLeakErrorToThrow = new Error(`[leak detected in previous fixture: ${leakLabel}] There are ${result.leaks.length} undisposed disposables!${result.details}`);
|
||||
}
|
||||
}
|
||||
}));
|
||||
|
||||
async function actualRender() {
|
||||
|
||||
setupTheme(container, theme);
|
||||
|
||||
const virtualTimeApi = createVirtualTimeApi(scheduler, { fakeRequestAnimationFrame: true });
|
||||
schedulerStore.add(overwriteGlobalTimeApi(virtualTimeApi));
|
||||
disposableStore.add(installFakeRunWhenIdle((_targetWindow, callback, _timeout?) => {
|
||||
return scheduler.schedule({
|
||||
time: scheduler.now,
|
||||
run: () => {
|
||||
const deadline: IdleDeadline = {
|
||||
didTimeout: true,
|
||||
timeRemaining: () => 50,
|
||||
};
|
||||
callback(deadline);
|
||||
},
|
||||
source: {
|
||||
toString() { return 'runWhenIdle'; },
|
||||
stackTrace: undefined,
|
||||
},
|
||||
});
|
||||
const schedulerStore = disposableStore.add(new DisposableStore());
|
||||
const scheduler = new TimeTravelScheduler(Date.now());
|
||||
const p = schedulerStore.add(new AsyncSchedulerProcessor(scheduler, {
|
||||
maxTaskCount: 100,
|
||||
realTimeApi,
|
||||
}));
|
||||
|
||||
const result = options.render({ container, disposableStore, theme });
|
||||
await setupTheme(container, theme);
|
||||
|
||||
const p2 = p.runForVirtualTimeMs(1000);
|
||||
const virtualTimeApi = createVirtualTimeApi(scheduler, { fakeRequestAnimationFrame: true });
|
||||
|
||||
await Promise.all([
|
||||
result instanceof Promise ? result : Promise.resolve(),
|
||||
p2,
|
||||
]);
|
||||
if (virtualTimeEnabled) {
|
||||
schedulerStore.add(pushGlobalTimeApi(virtualTimeApi));
|
||||
|
||||
disposableStore.add(installFakeRunWhenIdle((_targetWindow, callback, _timeout?) => {
|
||||
const stackTrace = new Error().stack;
|
||||
const trace = TraceContext.instance.currentTrace().child('runWhenIdle', stackTrace);
|
||||
return scheduler.schedule({
|
||||
time: scheduler.now,
|
||||
run: () => {
|
||||
const deadline: IdleDeadline = {
|
||||
didTimeout: true,
|
||||
timeRemaining: () => 50,
|
||||
};
|
||||
callback(deadline);
|
||||
},
|
||||
source: {
|
||||
toString() { return 'runWhenIdle'; },
|
||||
stackTrace,
|
||||
},
|
||||
trace,
|
||||
});
|
||||
}));
|
||||
}
|
||||
|
||||
try {
|
||||
const result = options.render({ container, disposableStore, theme });
|
||||
|
||||
const p2 = virtualTimeEnabled
|
||||
? p.run({ virtualDeadline: scheduler.now + (options.virtualTime?.durationMs ?? 1000), maxTasks: 100, maxTaskDepth: 5 })
|
||||
: Promise.resolve();
|
||||
|
||||
await Promise.all([
|
||||
result instanceof Promise ? result : Promise.resolve(),
|
||||
p2,
|
||||
]);
|
||||
} finally {
|
||||
if (virtualTimeEnabled && p.history.length > 0) {
|
||||
// TODO
|
||||
// const startTime = p.history[0].time;
|
||||
// const history = buildHistoryFromTasks(p.history, startTime);
|
||||
// console.log(`[ComponentFixture] ${themeLabel} virtual-time history (${p.history.length} tasks):\n${renderSwimlanes(history)}`);
|
||||
}
|
||||
schedulerStore.dispose();
|
||||
}
|
||||
|
||||
const drain = false;
|
||||
if (drain) {
|
||||
disposableStore.add(toDisposable(() => {
|
||||
p.run({ maxTasks: 100, maxTaskDepth: 5 });
|
||||
}));
|
||||
}
|
||||
}
|
||||
|
||||
await actualRender();
|
||||
// Every render gets its own trace root so that any diagnostics
|
||||
// output by the scheduler / processor shows exactly which fixture
|
||||
// caused each queued or historical timer, plus the full chain of
|
||||
// setTimeout/rAF calls that led to it.
|
||||
const themeLabel = theme === darkTheme ? 'Dark' : 'Light';
|
||||
const fixtureRoot = createTraceRoot(`render#${++fixtureRenderCounter}(${themeLabel})`);
|
||||
|
||||
await TraceContext.instance.runAsHandler(fixtureRoot, actualRender, realTimeApi);
|
||||
},
|
||||
});
|
||||
|
||||
|
||||
Reference in New Issue
Block a user