From 7dec4ae9d1ccfeba317359ac49098e3058fecfe4 Mon Sep 17 00:00:00 2001 From: Wesley Wigham Date: Wed, 20 Sep 2017 13:22:12 -0700 Subject: [PATCH] Remove batching on unittest thread, use historical data to inform batching (#18578) * Remove batching on unittest thread * Batch more things, improve output, use past test perf as a better heuristic for future test runs * Fix merge sideeffect * Fix typo --- .gitignore | 1 + src/harness/parallel/host.ts | 157 +++++++++++++++++++++++++-------- src/harness/parallel/shared.ts | 2 +- src/harness/parallel/worker.ts | 13 ++- 4 files changed, 132 insertions(+), 41 deletions(-) diff --git a/.gitignore b/.gitignore index eb0df177040c9..8c83d319ed735 100644 --- a/.gitignore +++ b/.gitignore @@ -59,3 +59,4 @@ internal/ .idea yarn.lock package-lock.json +.parallelperf.json diff --git a/src/harness/parallel/host.ts b/src/harness/parallel/host.ts index 92e21b5ada30f..67d1a4db1a782 100644 --- a/src/harness/parallel/host.ts +++ b/src/harness/parallel/host.ts @@ -5,11 +5,10 @@ if (typeof describe === "undefined") { namespace Harness.Parallel.Host { interface ChildProcessPartial { - send(message: any, callback?: (error: Error) => void): boolean; + send(message: ParallelHostMessage, callback?: (error: Error) => void): boolean; on(event: "error", listener: (err: Error) => void): this; on(event: "exit", listener: (code: number, signal: string) => void): this; - on(event: "message", listener: (message: any) => void): this; - disconnect(): void; + on(event: "message", listener: (message: ParallelClientMessage) => void): this; } interface ProgressBarsOptions { @@ -27,23 +26,54 @@ namespace Harness.Parallel.Host { text?: string; } + const perfdataFileName = ".parallelperf.json"; + function readSavedPerfData(): {[testHash: string]: number} { + const perfDataContents = Harness.IO.readFile(perfdataFileName); + if (perfDataContents) { + return JSON.parse(perfDataContents); + } + return undefined; + } + + function hashName(runner: TestRunnerKind, test: string) { + return `tsrunner-${runner}://${test}`; + } + export function start() { initializeProgressBarsDependencies(); console.log("Discovering tests..."); const discoverStart = +(new Date()); const { statSync }: { statSync(path: string): { size: number }; } = require("fs"); const tasks: { runner: TestRunnerKind, file: string, size: number }[] = []; - let totalSize = 0; + const perfData = readSavedPerfData(); + let totalCost = 0; + let unknownValue: string | undefined; for (const runner of runners) { const files = runner.enumerateTestFiles(); for (const file of files) { - const size = statSync(file).size; + let size: number; + if (!perfData) { + size = statSync(file).size; + + } + else { + const hashedName = hashName(runner.kind(), file); + size = perfData[hashedName]; + if (size === undefined) { + size = Number.MAX_SAFE_INTEGER; + unknownValue = hashedName; + } + } tasks.push({ runner: runner.kind(), file, size }); - totalSize += size; + totalCost += size; } } tasks.sort((a, b) => a.size - b.size); - const batchSize = (totalSize / workerCount) * 0.9; + // 1 fewer batches than threads to account for unittests running on the final thread + const batchCount = runners.length === 1 ? workerCount : workerCount - 1; + const packfraction = 0.9; + const chunkSize = 1000; // ~1KB or 1s for sending batches near the end of a test + const batchSize = (totalCost / workerCount) * packfraction; // Keep spare tests for unittest thread in reserve console.log(`Discovered ${tasks.length} test files in ${+(new Date()) - discoverStart}ms.`); console.log(`Starting to run tests using ${workerCount} threads...`); const { fork }: { fork(modulePath: string, args?: string[], options?: {}): ChildProcessPartial; } = require("child_process"); @@ -59,7 +89,10 @@ namespace Harness.Parallel.Host { const progressUpdateInterval = 1 / progressBars._options.width; let nextProgress = progressUpdateInterval; + const newPerfData: {[testHash: string]: number} = {}; + const workers: ChildProcessPartial[] = []; + let closedWorkers = 0; for (let i = 0; i < workerCount; i++) { // TODO: Just send the config over the IPC channel or in the command line arguments const config: TestConfig = { light: Harness.lightMode, listenForWork: true, runUnitTests: runners.length === 1 ? false : i === workerCount - 1 }; @@ -67,7 +100,6 @@ namespace Harness.Parallel.Host { Harness.IO.writeFile(configPath, JSON.stringify(config)); const child = fork(__filename, [`--config="${configPath}"`]); child.on("error", err => { - child.disconnect(); console.error("Unexpected error in child process:"); console.error(err); return process.exit(2); @@ -81,7 +113,6 @@ namespace Harness.Parallel.Host { child.on("message", (data: ParallelClientMessage) => { switch (data.type) { case "error": { - child.disconnect(); console.error(`Test worker encounted unexpected error and was forced to close: Message: ${data.payload.error} Stack: ${data.payload.stack}`); @@ -97,6 +128,7 @@ namespace Harness.Parallel.Host { else { passingFiles++; } + newPerfData[hashName(data.payload.runner, data.payload.file)] = data.payload.duration; const progress = (failingFiles + passingFiles) / totalFiles; if (progress >= nextProgress) { @@ -106,20 +138,27 @@ namespace Harness.Parallel.Host { updateProgress(progress, errorResults.length ? `${errorResults.length} failing` : `${totalPassing} passing`, errorResults.length ? "fail" : undefined); } - if (failingFiles + passingFiles === totalFiles) { - // Done. Finished every task and collected results. - child.send({ type: "close" }); - child.disconnect(); - return outputFinalResult(); - } - if (tasks.length === 0) { - // No more tasks to distribute - child.send({ type: "close" }); - child.disconnect(); - return; - } if (data.type === "result") { - child.send({ type: "test", payload: tasks.pop() }); + if (tasks.length === 0) { + // No more tasks to distribute + child.send({ type: "close" }); + closedWorkers++; + if (closedWorkers === workerCount) { + outputFinalResult(); + } + return; + } + // Send tasks in blocks if the tasks are small + const taskList = [tasks.pop()]; + while (tasks.length && taskList.reduce((p, c) => p + c.size, 0) > chunkSize) { + taskList.push(tasks.pop()); + } + if (taskList.length === 1) { + child.send({ type: "test", payload: taskList[0] }); + } + else { + child.send({ type: "batch", payload: taskList }); + } } } } @@ -130,12 +169,13 @@ namespace Harness.Parallel.Host { // It's only really worth doing an initial batching if there are a ton of files to go through if (totalFiles > 1000) { console.log("Batching initial test lists..."); - const batches: { runner: TestRunnerKind, file: string, size: number }[][] = new Array(workerCount); - const doneBatching = new Array(workerCount); + const batches: { runner: TestRunnerKind, file: string, size: number }[][] = new Array(batchCount); + const doneBatching = new Array(batchCount); + let scheduledTotal = 0; batcher: while (true) { - for (let i = 0; i < workerCount; i++) { + for (let i = 0; i < batchCount; i++) { if (tasks.length === 0) { - // TODO: This indicates a particularly suboptimal packing + console.log(`Suboptimal packing detected: no tests remain to be stolen. Reduce packing fraction from ${packfraction} to fix.`); break batcher; } if (doneBatching[i]) { @@ -145,26 +185,36 @@ namespace Harness.Parallel.Host { batches[i] = []; } const total = batches[i].reduce((p, c) => p + c.size, 0); - if (total >= batchSize && !doneBatching[i]) { + if (total >= batchSize) { doneBatching[i] = true; continue; } - batches[i].push(tasks.pop()); + const task = tasks.pop(); + batches[i].push(task); + scheduledTotal += task.size; } - for (let j = 0; j < workerCount; j++) { + for (let j = 0; j < batchCount; j++) { if (!doneBatching[j]) { - continue; + continue batcher; } } break; } - console.log(`Batched into ${workerCount} groups with approximate total file sizes of ${Math.floor(batchSize)} bytes in each group.`); + const prefix = `Batched into ${batchCount} groups`; + if (unknownValue) { + console.log(`${prefix}. Unprofiled tests including ${unknownValue} will be run first.`); + } + else { + console.log(`${prefix} with approximate total ${perfData ? "time" : "file sizes"} of ${perfData ? ms(batchSize) : `${Math.floor(batchSize)} bytes`} in each group. (${(scheduledTotal / totalCost * 100).toFixed(1)}% of total tests batched)`); + } for (const worker of workers) { - const action: ParallelBatchMessage = { type: "batch", payload: batches.pop() }; - if (!action.payload[0]) { - throw new Error(`Tried to send invalid message ${action}`); + const payload = batches.pop(); + if (payload) { + worker.send({ type: "batch", payload }); + } + else { // Unittest thread - send off just one test + worker.send({ type: "test", payload: tasks.pop() }); } - worker.send(action); } } else { @@ -177,7 +227,6 @@ namespace Harness.Parallel.Host { updateProgress(0); let duration: number; - const ms = require("mocha/lib/ms"); function completeBar() { const isPartitionFail = failingFiles !== 0; const summaryColor = isPartitionFail ? "fail" : "green"; @@ -235,6 +284,8 @@ namespace Harness.Parallel.Host { reporter.epilogue(); } + Harness.IO.writeFile(perfdataFileName, JSON.stringify(newPerfData, null, 4)); // tslint:disable-line:no-null-keyword + process.exit(errorResults.length); } @@ -264,6 +315,38 @@ namespace Harness.Parallel.Host { let tty: { isatty(x: number): boolean }; let isatty: boolean; + const s = 1000; + const m = s * 60; + const h = m * 60; + const d = h * 24; + function ms(ms: number) { + let result = ""; + if (ms >= d) { + const count = Math.floor(ms / d); + result += count + "d"; + ms -= count * d; + } + if (ms >= h) { + const count = Math.floor(ms / h); + result += count + "h"; + ms -= count * h; + } + if (ms >= m) { + const count = Math.floor(ms / m); + result += count + "m"; + ms -= count * m; + } + if (ms >= s) { + const count = Math.round(ms / s); + result += count + "s"; + return result; + } + if (ms > 0) { + result += Math.round(ms) + "ms"; + } + return result; + } + function initializeProgressBarsDependencies() { Mocha = require("mocha"); Base = Mocha.reporters.Base; @@ -286,7 +369,7 @@ namespace Harness.Parallel.Host { const close = options.close || "]"; const complete = options.complete || "▬"; const incomplete = options.incomplete || Base.symbols.dot; - const maxWidth = Base.window.width - open.length - close.length - 30; + const maxWidth = Base.window.width - open.length - close.length - 34; const width = minMax(options.width || maxWidth, 10, maxWidth); this._options = { open, diff --git a/src/harness/parallel/shared.ts b/src/harness/parallel/shared.ts index ebfe327884993..2caabaff1d7cd 100644 --- a/src/harness/parallel/shared.ts +++ b/src/harness/parallel/shared.ts @@ -8,7 +8,7 @@ namespace Harness.Parallel { export type ParallelErrorMessage = { type: "error", payload: { error: string, stack: string } } | never; export type ErrorInfo = ParallelErrorMessage["payload"] & { name: string }; - export type ParallelResultMessage = { type: "result", payload: { passing: number, errors: ErrorInfo[] } } | never; + export type ParallelResultMessage = { type: "result", payload: { passing: number, errors: ErrorInfo[], duration: number, runner: TestRunnerKind, file: string } } | never; export type ParallelBatchProgressMessage = { type: "progress", payload: ParallelResultMessage["payload"] } | never; export type ParallelClientMessage = ParallelErrorMessage | ParallelResultMessage | ParallelBatchProgressMessage; } \ No newline at end of file diff --git a/src/harness/parallel/worker.ts b/src/harness/parallel/worker.ts index 56f8fd43c5813..1113039f4f776 100644 --- a/src/harness/parallel/worker.ts +++ b/src/harness/parallel/worker.ts @@ -12,9 +12,10 @@ namespace Harness.Parallel.Worker { testList.length = 0; } reportedUnitTests = true; + const start = +(new Date()); runner.initializeTests(); testList.forEach(({ name, callback, kind }) => executeCallback(name, callback, kind)); - return { errors, passing }; + return { errors, passing, duration: +(new Date()) - start }; } @@ -172,7 +173,13 @@ namespace Harness.Parallel.Worker { }); process.on("uncaughtException", error => { const message: ParallelErrorMessage = { type: "error", payload: { error: error.message, stack: error.stack } }; - process.send(message); + try { + process.send(message); + } + catch (e) { + console.error(error); + throw error; + } }); if (!runUnitTests) { // ensure unit tests do not get run @@ -189,7 +196,7 @@ namespace Harness.Parallel.Worker { } const instance = runners.get(runner); instance.tests = [file]; - return resetShimHarnessAndExecute(instance); + return { ...resetShimHarnessAndExecute(instance), runner, file }; } } } \ No newline at end of file