From 8bbdd08312b34cf746926f0ea672e01e96d49b47 Mon Sep 17 00:00:00 2001 From: Mathieu Hofman Date: Mon, 17 Jan 2022 21:55:33 +0000 Subject: [PATCH 1/9] feat(runner): add support for swingset vat events --- runner/lib/monitor/slog-monitor.js | 70 +++++++++++++++++++++++++++--- 1 file changed, 64 insertions(+), 6 deletions(-) diff --git a/runner/lib/monitor/slog-monitor.js b/runner/lib/monitor/slog-monitor.js index 6721e36..1f6fe80 100644 --- a/runner/lib/monitor/slog-monitor.js +++ b/runner/lib/monitor/slog-monitor.js @@ -3,9 +3,11 @@ import { warnOnRejection } from '../helpers/async.js'; +/** @typedef {import('../helpers/time.js').TimeValueS} TimeValueS */ + /** * @typedef {{ - * time: number, + * time: TimeValueS, * type: 'create-vat', * vatID: string, * name?: string, @@ -16,7 +18,7 @@ import { warnOnRejection } from '../helpers/async.js'; /** * @typedef {({ - * time: number, + * time: TimeValueS, * type: | * 'vat-startup-finish' | * 'replay-transcript-start' | // Renamed to 'start-replay' @@ -39,16 +41,51 @@ import { warnOnRejection } from '../helpers/async.js'; /** * @typedef {{ - * time: number, + * time: TimeValueS, * type: SlogCosmicSwingsetBlockEventTypes, * blockHeight?: number, - * blockTime: number + * blockTime: TimeValueS * }} SlogCosmicSwingsetBlockEvent */ +/** + * @typedef {{ + * time: TimeValueS, + * type: 'deliver', + * crankNum: number, + * vatID: string, + * deliveryNum: number, + * }} SlogCosmicSwingsetVatDeliveryEvent + */ + +/** + * @typedef {{ + * time: TimeValueS, + * type: 'deliver-result', + * crankNum: number, + * vatID: string, + * deliveryNum: number, + * dr: [ + * tag: 'ok' | 'error', + * message: null | string, + * usage: { compute: number } | null + * ], + * }} SlogCosmicSwingsetVatDeliveryResultEvent + */ + +/** + * @typedef { | + * SlogCosmicSwingsetVatDeliveryEvent | + * SlogCosmicSwingsetVatDeliveryResultEvent + * } SlogCosmicSwingsetVatEvent + */ + +/** @typedef {SlogCosmicSwingsetVatEvent["type"]} SlogCosmicSwingsetVatEventTypes */ + /** * @typedef { | * SlogVatEventTypes | + * SlogCosmicSwingsetVatEventTypes | * SlogCosmicSwingsetBlockEventTypes * } SlogSupportedEventTypes */ @@ -56,6 +93,7 @@ import { warnOnRejection } from '../helpers/async.js'; /** * @typedef { | * SlogVatEvent | + * SlogCosmicSwingsetVatEvent | * SlogCosmicSwingsetBlockEvent * } SlogSupportedEvent */ @@ -81,15 +119,23 @@ const swingsetStartupBlockSlogEventTypes = [ 'cosmic-swingset-bootstrap-block-finish', ]; +/** @type {SlogCosmicSwingsetVatEventTypes[]} */ +const swingsetActiveSlogEventTypes = ['deliver', 'deliver-result']; + /** @param {SlogSupportedEventTypes[]} eventTypes */ const filterSlogEvent = (eventTypes) => new RegExp(`^{"time":\\d+(?:\\.\\d+),"type":"(?:${eventTypes.join('|')})"`); -const slogEventRE = filterSlogEvent([ +const startEventRE = filterSlogEvent([ ...vatSlogEventTypes, ...swingsetRegularBlockSlogEventTypes, ...swingsetStartupBlockSlogEventTypes, ]); +const activeEventRE = filterSlogEvent([ + ...vatSlogEventTypes, + ...swingsetRegularBlockSlogEventTypes, + ...swingsetActiveSlogEventTypes, +]); /** * @param {Pick} chainInfo @@ -110,6 +156,8 @@ export const monitorSlog = async ( let slogBlocksSeen = 0; let slogLinesInBlock = 0; + let eventRE = startEventRE; + for await (const line of slogLines) { if (slogStart == null && chainMonitor) { // TODO: figure out a better way @@ -129,7 +177,7 @@ export const monitorSlog = async ( // Avoid JSON parsing or converting lines we don't care about // Parse as ascii, in case the payload has multi-byte chars, // the time and type tested prefix is guaranteed to be single-byte. - if (!slogEventRE.test(line.toString('ascii', 0, 100))) continue; + if (!eventRE.test(line.toString('ascii', 0, 100))) continue; const localEventTime = localTimeSource && localTimeSource.getTime(); @@ -173,6 +221,7 @@ export const monitorSlog = async ( } case 'cosmic-swingset-bootstrap-block-finish': { logPerfEvent('chain-first-init-finish'); + eventRE = activeEventRE; break; } case 'cosmic-swingset-begin-block': { @@ -183,6 +232,8 @@ export const monitorSlog = async ( // This will abruptly end the monitor if there is an error await chainMonitor.logProcessUsage(); } + // On restart, the first active slog event is a begin block + eventRE = activeEventRE; } console.log('begin-block', blockHeight); slogBlocksSeen += 1; @@ -202,6 +253,7 @@ export const monitorSlog = async ( if (event.blockHeight === 0) { // TODO: measure duration from start to finish logPerfEvent('chain-first-init-finish'); + eventRE = activeEventRE; } else { const { blockHeight = 0 } = event; // Finish line itself doesn't count @@ -218,6 +270,12 @@ export const monitorSlog = async ( } break; } + case 'deliver': { + break; + } + case 'deliver-result': { + break; + } default: { console.warn( 'Parsed an unexpected slog event:', From 0ef18a2c08650c17d758a18cb6e0a350b2e3e0f2 Mon Sep 17 00:00:00 2001 From: Mathieu Hofman Date: Mon, 17 Jan 2022 21:55:33 +0000 Subject: [PATCH 2/9] feat(runner): extract task events from loadgen output --- runner/lib/tasks/shared-loadgen.js | 42 +++++++++++++++++++++++++++--- runner/lib/tasks/types.d.ts | 7 ++++- 2 files changed, 45 insertions(+), 4 deletions(-) diff --git a/runner/lib/tasks/shared-loadgen.js b/runner/lib/tasks/shared-loadgen.js index 34f7bd5..e37536d 100644 --- a/runner/lib/tasks/shared-loadgen.js +++ b/runner/lib/tasks/shared-loadgen.js @@ -1,6 +1,7 @@ /* global process Buffer */ -import { PassThrough } from 'stream'; +import { PassThrough, Transform, pipeline as pipelineCallback } from 'stream'; +import { promisify } from 'util'; import { childProcessDone, @@ -11,9 +12,13 @@ import { PromiseAllOrErrors, tryTimeout } from '../helpers/async.js'; import { whenStreamSteps } from '../helpers/stream.js'; import { httpRequest, getConsoleAndStdio } from './helpers.js'; +const pipeline = promisify(pipelineCallback); + const loadgenStartRE = /deploy.*loadgen\/loop\.js/; const loadgenReadyRE = /server running/; +const jsonDataRE = /^\{.*\}$/; + /** * * @param {Object} powers @@ -67,7 +72,27 @@ export const makeLoadgenTask = ({ spawn }) => { launcherCp.stderr.pipe(stdio[2], { end: false }); launcherCp.stderr.pipe(errLines).pipe(combinedOutput); - const [deploying, tasksReady, outputParsed] = whenStreamSteps( + const taskEvents = new Transform({ + objectMode: true, + /** + * @param {string} data + * @param {string} encoding + * @param {(error?: Error | null, data?: Record) => void} callback + */ + transform(data, encoding, callback) { + if (jsonDataRE.test(data)) { + try { + callback(null, JSON.parse(data)); + return; + } catch (error) { + console.warn('Failed to parse loadgen event', data, error); + } + } + callback(); + }, + }); + + const [deploying, tasksReady, initialOutputParsed] = whenStreamSteps( combinedOutput, [{ matcher: loadgenStartRE }, { matcher: loadgenReadyRE }], { @@ -78,8 +103,16 @@ export const makeLoadgenTask = ({ spawn }) => { const cleanCombined = () => { launcherCp.stdout.unpipe(outLines); launcherCp.stderr.unpipe(errLines); + taskEvents.end(); }; - outputParsed.then(cleanCombined, cleanCombined); + + const outputParsed = initialOutputParsed.then( + () => pipeline(combinedOutput, new LineStreamTransform(), taskEvents), + (err) => { + cleanCombined(); + return Promise.reject(err); + }, + ); const done = PromiseAllOrErrors([outputParsed, loadgenDone]).then(() => {}); @@ -114,6 +147,9 @@ export const makeLoadgenTask = ({ spawn }) => { stop, done, ready, + taskEvents: { + [Symbol.asyncIterator]: () => taskEvents[Symbol.asyncIterator](), + }, }); }, async () => { diff --git a/runner/lib/tasks/types.d.ts b/runner/lib/tasks/types.d.ts index 96ca419..0f977bb 100644 --- a/runner/lib/tasks/types.d.ts +++ b/runner/lib/tasks/types.d.ts @@ -13,7 +13,12 @@ export type RunChainInfo = { readonly storageLocation: string; }; +export type RunLoadgenInfo = { + readonly taskEvents: AsyncIterable>; +}; + export type RunChainResult = TaskResult & RunChainInfo; +export type RunLoadgenResult = TaskResult & RunLoadgenInfo; export interface TaskBaseOptions { readonly stdout: import('stream').Writable; @@ -26,5 +31,5 @@ export interface OrchestratorTasks { setupTasks(options: TaskBaseOptions): Promise; runChain(options: TaskBaseOptions): Promise; runClient(options: TaskBaseOptions): Promise; - runLoadgen(options: TaskBaseOptions): Promise; + runLoadgen(options: TaskBaseOptions): Promise; } From d51c0aa366fb326b3a077c2af29ba6d1c5682952 Mon Sep 17 00:00:00 2001 From: Mathieu Hofman Date: Mon, 17 Jan 2022 21:55:33 +0000 Subject: [PATCH 3/9] feat(runner): Add stats objects --- runner/lib/main.js | 57 +++++++------ runner/lib/monitor/slog-monitor.js | 40 +++++---- runner/lib/stats/blocks.js | 67 ++++++++++++++++ runner/lib/stats/helpers.d.ts | 75 +++++++++++++++++ runner/lib/stats/helpers.js | 125 +++++++++++++++++++++++++++++ runner/lib/stats/run.js | 73 +++++++++++++++++ runner/lib/stats/stages.js | 77 ++++++++++++++++++ runner/lib/stats/types.d.ts | 42 ++++++++++ 8 files changed, 517 insertions(+), 39 deletions(-) create mode 100644 runner/lib/stats/blocks.js create mode 100644 runner/lib/stats/helpers.d.ts create mode 100644 runner/lib/stats/helpers.js create mode 100644 runner/lib/stats/run.js create mode 100644 runner/lib/stats/stages.js diff --git a/runner/lib/main.js b/runner/lib/main.js index 32222fa..819ccb0 100644 --- a/runner/lib/main.js +++ b/runner/lib/main.js @@ -26,6 +26,7 @@ import { makeTasks as makeTestnetTasks } from './tasks/testnet.js'; import { makeChainMonitor } from './monitor/chain-monitor.js'; import { monitorSlog } from './monitor/slog-monitor.js'; +import { makeRunStats } from './stats/run.js'; import { makeTimeSource } from './helpers/time.js'; /** @typedef {import('./helpers/async.js').Task} Task */ @@ -228,6 +229,8 @@ const main = async (progName, rawArgs, powers) => { ); await fsStreamReady(outputStream); + const runStats = makeRunStats(); + /** @type {import('./stats/types.js').LogPerfEvent} */ const logPerfEvent = (eventType, data = {}) => { outputStream.write( @@ -247,20 +250,21 @@ const main = async (progName, rawArgs, powers) => { }; /** - * @param {Object} param0 - * @param {boolean} param0.chainOnly - * @param {number} param0.durationConfig - * @param {unknown} param0.loadgenConfig - * @param {boolean} param0.withMonitor - * @param {boolean} param0.saveStorage + * @param {Object} config + * @param {boolean} config.chainOnly + * @param {number} config.durationConfig + * @param {unknown} config.loadgenConfig + * @param {boolean} config.withMonitor + * @param {boolean} config.saveStorage */ - const runStage = async ({ - chainOnly, - durationConfig, - loadgenConfig, - withMonitor, - saveStorage, - }) => { + const runStage = async (config) => { + const { + chainOnly, + durationConfig, + loadgenConfig, + withMonitor, + saveStorage, + } = config; /** @type {string | void} */ let chainStorageLocation; currentStageTimeSource = timeSource.shift(); @@ -275,13 +279,14 @@ const main = async (progName, rawArgs, powers) => { logPerfEvent('stage-start'); const stageStart = timeSource.shift(); + const stats = runStats.newStage({ + stageIndex: currentStage, + stageConfig: config, + }); + /** @type {Task} */ const spawnChain = async (nextStep) => { - stageConsole.log('Running chain', { - chainOnly, - durationConfig, - loadgenConfig, - }); + stageConsole.log('Running chain', config); logPerfEvent('run-chain-start'); const runChainResult = await runChain({ stdout: out, stderr: err }); logPerfEvent('run-chain-finish'); @@ -326,20 +331,16 @@ const main = async (progName, rawArgs, powers) => { /** @type {(() => void) | null} */ let resolveFirstEmptyBlock = firstEmptyBlockKit.resolve; - let blockCount = 0; - const notifier = { - /** @param {{blockHeight: number, slogLines: number}} block */ + /** @param {import('./stats/types.js').BlockStats} block */ blockDone(block) { - blockCount += 1; - if (resolveFirstBlockDone) { resolveFirstBlockDone(); resolveFirstBlockDone = null; } if (resolveFirstEmptyBlock) { - if (block.slogLines === 0 || blockCount > 10) { + if (block.slogLines === 0 || stats.blockCount > 10) { if (block.slogLines === 0) { logPerfEvent('stage-first-empty-block', { block: block.blockHeight, @@ -364,6 +365,7 @@ const main = async (progName, rawArgs, powers) => { { slogLines }, { ...makeConsole('monitor-slog', out, err), + stats, notifier, chainMonitor, localTimeSource: timeSource, @@ -531,7 +533,9 @@ const main = async (progName, rawArgs, powers) => { tasks.push(stageReady); } + stats.recordStart(); await sequential(...tasks)((stop) => stop); + stats.recordEnd(); }, async () => aggregateTryFinally( @@ -565,6 +569,7 @@ const main = async (progName, rawArgs, powers) => { await aggregateTryFinally( async () => { const { console: initConsole, out, err } = makeConsole('init'); + runStats.recordStart(); logPerfEvent('start', { cpuTimeOffset, timeOrigin: timeSource.timeOrigin, @@ -665,8 +670,12 @@ const main = async (progName, rawArgs, powers) => { saveStorage, }); } + + runStats.recordEnd(); }, async () => { + logPerfEvent('finish', { stats: runStats }); + outputStream.end(); await finished(outputStream); diff --git a/runner/lib/monitor/slog-monitor.js b/runner/lib/monitor/slog-monitor.js index 1f6fe80..2fc9c65 100644 --- a/runner/lib/monitor/slog-monitor.js +++ b/runner/lib/monitor/slog-monitor.js @@ -3,6 +3,8 @@ import { warnOnRejection } from '../helpers/async.js'; +/** @typedef {import('../stats/types.js').StageStats} StageStats */ +/** @typedef {import('../stats/types.js').BlockStats} BlockStats */ /** @typedef {import('../helpers/time.js').TimeValueS} TimeValueS */ /** @@ -140,7 +142,8 @@ const activeEventRE = filterSlogEvent([ /** * @param {Pick} chainInfo * @param {Object} param1 - * @param {{blockDone(stats: {blockHeight: number, slogLines: number}): void}} [param1.notifier] + * @param {StageStats} param1.stats + * @param {{blockDone(block: BlockStats): void}} [param1.notifier] * @param {ReturnType} [param1.chainMonitor] * @param {import("../stats/types.js").LogPerfEvent} param1.logPerfEvent * @param {import("../helpers/time.js").TimeSource} [param1.localTimeSource] @@ -148,13 +151,13 @@ const activeEventRE = filterSlogEvent([ */ export const monitorSlog = async ( { slogLines }, - { notifier, chainMonitor, localTimeSource, logPerfEvent, console }, + { stats, notifier, chainMonitor, localTimeSource, logPerfEvent, console }, ) => { /** @type {number | null} */ let slogStart = null; - let slogBlocksSeen = 0; - let slogLinesInBlock = 0; + /** @type {BlockStats | null} */ + let block = null; let eventRE = startEventRE; @@ -172,7 +175,9 @@ export const monitorSlog = async ( ); } - slogLinesInBlock += 1; + if (block) { + block.recordSlogLine(); + } // Avoid JSON parsing or converting lines we don't care about // Parse as ascii, in case the payload has multi-byte chars, @@ -226,7 +231,7 @@ export const monitorSlog = async ( } case 'cosmic-swingset-begin-block': { const { blockHeight = 0 } = event; - if (!slogBlocksSeen) { + if (!stats.blockCount) { logPerfEvent('stage-first-block', { block: blockHeight }); if (chainMonitor) { // This will abruptly end the monitor if there is an error @@ -236,37 +241,42 @@ export const monitorSlog = async ( eventRE = activeEventRE; } console.log('begin-block', blockHeight); - slogBlocksSeen += 1; + block = stats.newBlock({ blockHeight }); + block.recordStart(); break; } case 'cosmic-swingset-end-block-start': { - if (event.blockHeight === 0) { + if (!block) { // Before https://github.com/Agoric/agoric-sdk/pull/3491 // bootstrap didn't have it's own slog entry + // However in that case there is no begin-block logPerfEvent('chain-first-init-start'); } else { - slogLinesInBlock = 0; + const { blockHeight = 0 } = event; + assert(block.blockHeight === blockHeight); + block.recordSwingsetStart(); } break; } case 'cosmic-swingset-end-block-finish': { - if (event.blockHeight === 0) { + if (!block) { // TODO: measure duration from start to finish logPerfEvent('chain-first-init-finish'); eventRE = activeEventRE; } else { const { blockHeight = 0 } = event; - // Finish line itself doesn't count - slogLinesInBlock -= 1; - notifier && - notifier.blockDone({ blockHeight, slogLines: slogLinesInBlock }); + + assert(block.blockHeight === blockHeight); + block.recordEnd(); + notifier && notifier.blockDone(block); console.log( 'end-block', blockHeight, 'linesInBlock=', - slogLinesInBlock, + block.slogLines, ); + block = null; } break; } diff --git a/runner/lib/stats/blocks.js b/runner/lib/stats/blocks.js new file mode 100644 index 0000000..b83a6ac --- /dev/null +++ b/runner/lib/stats/blocks.js @@ -0,0 +1,67 @@ +/* eslint-disable prefer-object-spread */ + +import { makeRawStats, cloneData, copyProperties } from './helpers.js'; + +/** @typedef {import("./types.js").BlockStatsInitData} BlockStatsInitData */ +/** @typedef {import("./types.js").BlockStats} BlockStats */ + +/** + * @typedef {| + * 'slogLines' | + * never} RawBlockStatsProps + */ + +/** @type {import('./helpers.js').RawStatInit} */ +const rawBlockStatsInit = { + slogLines: { + default: -Infinity, + writeMulti: true, + }, +}; + +/** + * @param {BlockStatsInitData} data + * @returns {BlockStats} + */ +export const makeBlockStats = (data) => { + const { publicProps, privateSetters } = makeRawStats(rawBlockStatsInit); + + /** @type {BlockStats['recordStart']} */ + const recordStart = () => {}; + + let ended = false; + + /** @type {BlockStats['recordSwingsetStart']} */ + const recordSwingsetStart = () => { + privateSetters.slogLines(0); + }; + + /** @type {BlockStats['recordSlogLine']} */ + const recordSlogLine = () => { + if (!ended) { + privateSetters.slogLines(publicProps.slogLines + 1); + } + }; + + /** @type {BlockStats['recordEnd']} */ + const recordEnd = () => { + // Finish line itself doesn't count + privateSetters.slogLines(publicProps.slogLines - 1); + ended = true; + }; + + const stats = harden( + copyProperties( + { + recordStart, + recordEnd, + recordSwingsetStart, + recordSlogLine, + }, + cloneData(data), + publicProps, + ), + ); + + return stats; +}; diff --git a/runner/lib/stats/helpers.d.ts b/runner/lib/stats/helpers.d.ts new file mode 100644 index 0000000..591fc52 --- /dev/null +++ b/runner/lib/stats/helpers.d.ts @@ -0,0 +1,75 @@ +/* eslint-disable no-unused-vars,no-redeclare */ + +export type RawStatInitDescDefault = { + readonly default: T; + readonly writeMulti?: boolean; +}; +export type RawStatInitDescOptional = null | { + readonly default?: T; + readonly writeMulti?: boolean; +}; +export type RawStatInit = { + readonly [P in K]: [undefined] extends [T[P]] + ? RawStatInitDescOptional + : RawStatInitDescDefault; +}; +export type SavedStatData = { + -readonly [P in K]?: T[P]; +}; +export type PublicStatProps = { + readonly [P in K]: T[P]; +}; +export type PrivateStatSetters = { + readonly [P in K]: (value: T[P]) => void; +}; +export type MakeRawStatsReturnType = { + savedData: SavedStatData; + publicProps: PublicStatProps; + privateSetters: PrivateStatSetters; +}; + +export interface CollectionInserter { + (key: K, value: T): void; +} + +export interface CollectionCounter { + (): number; +} + +export type MakeStatsCollectionReturnType = { + collection: import('./types.js').StatsCollection; + insert: CollectionInserter; + getCount: CollectionCounter; +}; + +export declare function makeRawStats( + init: RawStatInit, +): MakeRawStatsReturnType; + +export declare function makeStatsCollection< + K extends string | number, + T +>(): MakeStatsCollectionReturnType; + +export declare function makeGetters any }>( + props: T, +): { + readonly [P in keyof T]: ReturnType; +}; + +export declare const rounder: (value: number) => number; + +export declare function cloneData(data: T): T; + +export declare function copyProperties(target: T, source: U): T & U; +export declare function copyProperties( + target: T, + source1: U, + source2: V, +): T & U & V; +export declare function copyProperties( + target: T, + source1: U, + source2: V, + source3: W, +): T & U & V & W; diff --git a/runner/lib/stats/helpers.js b/runner/lib/stats/helpers.js new file mode 100644 index 0000000..42a359e --- /dev/null +++ b/runner/lib/stats/helpers.js @@ -0,0 +1,125 @@ +import { makeRounder } from '../helpers/time.js'; + +/** + * @param {readonly [PropertyKey, () => any][]} entries + */ +const makeGetterObject = (entries) => + harden( + Object.create( + null, + Object.fromEntries( + entries.map(([key, get]) => [key, { get, enumerable: true }]), + ), + ), + ); + +/** @typedef {import('./helpers.js').RawStatInitDescDefault | import('./helpers.js').RawStatInitDescOptional} RawStatInitDesc */ + +/** + * @template T + * @template {keyof T} K + * @param {import('./helpers.js').RawStatInit} init + */ +export const makeRawStats = (init) => { + const initEntries = /** @type {[K, NonNullable][]} */ (Object.entries( + init, + ).map( + /** @param {[string, RawStatInitDesc]} entry */ + ([key, desc]) => [key, harden({ ...(desc || {}) })], + )); + const savedData = /** @type {import("./helpers.js").MakeRawStatsReturnType['savedData']} */ ({}); + const publicProps = /** @type {import("./helpers.js").MakeRawStatsReturnType['publicProps']} */ (makeGetterObject( + initEntries.map(([key, desc]) => [ + key, + () => (key in savedData ? savedData[key] : desc.default), + ]), + )); + const privateSetters = /** @type {import("./helpers.js").MakeRawStatsReturnType['privateSetters']} */ (harden( + Object.fromEntries( + initEntries.map(([key, desc]) => [ + key, + /** @param {any} value */ + (value) => { + if (!desc.writeMulti) { + assert(!(key in savedData)); + } + savedData[key] = value; + }, + ]), + ), + )); + return { savedData, publicProps, privateSetters }; +}; + +/** + * @template {string | number} K + * @template {any} T + * @returns {{ + * collection: import("./types.js").StatsCollection, + * insert: import("./helpers.js").CollectionInserter, + * getCount: import("./helpers.js").CollectionCounter, + * }} + */ +export const makeStatsCollection = () => { + let count = 0; + + const getCount = () => count; + + const collection = Object.create(null); + + /** + * @param {K} key + * @param {T} value + */ + const insert = (key, value) => { + assert(!(key in collection)); + Object.defineProperty(collection, key, { + value, + enumerable: true, + }); + count += 1; + }; + + return { + collection, + insert, + getCount, + }; +}; + +/** + * @template {{ [key: string]: () => any }} T + * @param {T} getters + * @returns {{ + * readonly [P in keyof T]: ReturnType; + * }} + */ +export const makeGetters = (getters) => + makeGetterObject(Object.entries(getters)); + +export const rounder = makeRounder(6); + +/** + * Note: hacky version of a deep clone + * Limitation: It will remove undefined values + * + * @template T + * @param {T} data + * @returns {T} + */ +export const cloneData = (data) => JSON.parse(JSON.stringify(data)); + +/** + * + * @param {{}} target + * @param {any[]} sources + * @returns {{}} + */ +export const copyProperties = (target, ...sources) => + Object.defineProperties( + target, + Object.assign( + {}, + ...sources.map((source) => Object.getOwnPropertyDescriptors(source)), + ), + ); diff --git a/runner/lib/stats/run.js b/runner/lib/stats/run.js new file mode 100644 index 0000000..f540480 --- /dev/null +++ b/runner/lib/stats/run.js @@ -0,0 +1,73 @@ +/* eslint-disable prefer-object-spread */ + +import { + makeRawStats, + makeStatsCollection, + makeGetters, + cloneData, + copyProperties, +} from './helpers.js'; +import { makeStageStats } from './stages.js'; + +/** @typedef {import("./types.js").StageStats} StageStats */ +/** @typedef {import("./types.js").RunStatsInitData} RunStatsInitData */ +/** @typedef {import("./types.js").RunStats} RunStats */ + +/** + * @typedef {| + * never} RawRunStatsProps + */ + +/** @type {import('./helpers.js').RawStatInit} */ +const rawRunStatsInit = {}; + +/** + * @param {RunStatsInitData} data + * @returns {RunStats} + */ +export const makeRunStats = (data = {}) => { + const { publicProps } = makeRawStats(rawRunStatsInit); + + /** @type {import("./helpers.js").MakeStatsCollectionReturnType} */ + const { + collection: stages, + insert: insertStage, + getCount: getStageCount, + } = makeStatsCollection(); + + /** @type {RunStats['newStage']} */ + const newStage = (stageData) => { + const { stageIndex } = stageData; + + assert(stageIndex === getStageCount()); + + const stageStats = makeStageStats(stageData); + insertStage(stageIndex, stageStats); + return stageStats; + }; + + const getBlockCount = () => + Object.values(stages).reduce( + (acc, stage) => acc + (stage ? stage.blockCount : 0), + 0, + ); + + const stats = harden( + copyProperties( + { + recordStart: () => {}, + recordEnd: () => {}, + newStage, + }, + cloneData(data), + publicProps, + makeGetters({ + stages: () => stages, + stageCount: getStageCount, + blockCount: getBlockCount, + }), + ), + ); + + return stats; +}; diff --git a/runner/lib/stats/stages.js b/runner/lib/stats/stages.js new file mode 100644 index 0000000..10c225c --- /dev/null +++ b/runner/lib/stats/stages.js @@ -0,0 +1,77 @@ +/* eslint-disable prefer-object-spread */ + +import { + makeRawStats, + makeStatsCollection, + cloneData, + makeGetters, + copyProperties, +} from './helpers.js'; +import { makeBlockStats } from './blocks.js'; + +/** @typedef {import("./types.js").BlockStats} BlockStats */ +/** @typedef {import("./types.js").StageStatsInitData} StageStatsInitData */ +/** @typedef {import("./types.js").StageStats} StageStats */ + +/** + * @typedef {| + * 'firstBlockHeight' | + * 'lastBlockHeight' | + * never } RawStageStatsProps + */ + +/** @type {import('./helpers.js').RawStatInit} */ +const rawStageStatsInit = { + firstBlockHeight: null, + lastBlockHeight: { + writeMulti: true, + }, +}; + +/** + * @param {StageStatsInitData} data + * @returns {StageStats} + */ +export const makeStageStats = (data) => { + const { publicProps, privateSetters } = makeRawStats(rawStageStatsInit); + + /** @type {import("./helpers.js").MakeStatsCollectionReturnType} */ + const { + collection: blocks, + insert: insertBlock, + getCount: getBlockCount, + } = makeStatsCollection(); + + /** @type {StageStats['newBlock']} */ + const newBlock = (blockData) => { + const { blockHeight } = blockData; + + assert(blockHeight); + + if (!getBlockCount()) { + privateSetters.firstBlockHeight(blockHeight); + } + privateSetters.lastBlockHeight(blockHeight); + const block = makeBlockStats(blockData); + insertBlock(blockHeight, block); + return block; + }; + + const stats = harden( + copyProperties( + { + recordStart: () => {}, + recordEnd: () => {}, + newBlock, + }, + cloneData(data), + publicProps, + makeGetters({ + blocks: () => blocks, + blockCount: getBlockCount, + }), + ), + ); + + return stats; +}; diff --git a/runner/lib/stats/types.d.ts b/runner/lib/stats/types.d.ts index 112afb1..abab4ee 100644 --- a/runner/lib/stats/types.d.ts +++ b/runner/lib/stats/types.d.ts @@ -3,3 +3,45 @@ export interface LogPerfEvent { (eventType: string, data?: Record): void; } + +export type StatsCollection = { + readonly [P in K]?: T; +}; + +export interface BlockStatsInitData { + readonly blockHeight: number; +} + +export interface BlockStats extends BlockStatsInitData { + recordStart(): void; + recordEnd(): void; + recordSwingsetStart(): void; + recordSlogLine(): void; + readonly slogLines: number; +} + +export interface StageStatsInitData { + readonly stageConfig: Readonly>; + readonly stageIndex: number; +} + +export interface StageStats extends StageStatsInitData { + recordStart(): void; + recordEnd(): void; + newBlock(data: BlockStatsInitData): BlockStats; + readonly blocks: StatsCollection; + readonly blockCount: number; + readonly firstBlockHeight: number | undefined; + readonly lastBlockHeight: number | undefined; +} + +export interface RunStatsInitData {} + +export interface RunStats extends RunStatsInitData { + recordStart(): void; + recordEnd(): void; + newStage(data: StageStatsInitData): StageStats; + readonly stages: StatsCollection; + readonly stageCount: number; + readonly blockCount: number; +} From e5654340d22eeb37657d4ead1582258af90da25f Mon Sep 17 00:00:00 2001 From: Mathieu Hofman Date: Mon, 17 Jan 2022 21:55:33 +0000 Subject: [PATCH 4/9] feat(runner): Add loadgen monitoring --- runner/lib/main.js | 8 +++ runner/lib/monitor/loadgen-monitor.js | 30 +++++++++++ runner/lib/stats/cycles.js | 77 +++++++++++++++++++++++++++ runner/lib/stats/run.js | 7 +++ runner/lib/stats/stages.js | 24 +++++++++ runner/lib/stats/types.d.ts | 20 +++++++ runner/lib/tasks/types.d.ts | 26 ++++++++- 7 files changed, 191 insertions(+), 1 deletion(-) create mode 100644 runner/lib/monitor/loadgen-monitor.js create mode 100644 runner/lib/stats/cycles.js diff --git a/runner/lib/main.js b/runner/lib/main.js index 819ccb0..bd2c707 100644 --- a/runner/lib/main.js +++ b/runner/lib/main.js @@ -26,6 +26,7 @@ import { makeTasks as makeTestnetTasks } from './tasks/testnet.js'; import { makeChainMonitor } from './monitor/chain-monitor.js'; import { monitorSlog } from './monitor/slog-monitor.js'; +import { monitorLoadgen } from './monitor/loadgen-monitor.js'; import { makeRunStats } from './stats/run.js'; import { makeTimeSource } from './helpers/time.js'; @@ -460,6 +461,11 @@ const main = async (progName, rawArgs, powers) => { logPerfEvent('loadgen-stopped'); }); + const monitorLoadgenDone = monitorLoadgen(runLoadgenResult, { + ...makeConsole('monitor-loadgen', out, err), + stats, + }); + await aggregateTryFinally( async () => { await orInterrupt(runLoadgenResult.ready); @@ -474,6 +480,8 @@ const main = async (progName, rawArgs, powers) => { runLoadgenResult.stop(); await done; } + + await monitorLoadgenDone; }, ); }; diff --git a/runner/lib/monitor/loadgen-monitor.js b/runner/lib/monitor/loadgen-monitor.js new file mode 100644 index 0000000..ee95284 --- /dev/null +++ b/runner/lib/monitor/loadgen-monitor.js @@ -0,0 +1,30 @@ +/** @typedef {import('../stats/types.js').StageStats} StageStats */ + +/** + * @param {import("../tasks/types.js").RunLoadgenInfo} loadgenInfo + * @param {Object} param1 + * @param {StageStats} param1.stats + * @param {Console} param1.console + */ +export const monitorLoadgen = async ({ taskEvents }, { stats, console }) => { + for await (const event of taskEvents) { + switch (event.type) { + case 'start': { + const { task, seq } = event; + console.log('start', task, seq); + const cycle = stats.getOrMakeCycle({ task, seq }); + cycle.recordStart(); + break; + } + case 'finish': { + const { task, seq, success } = event; + console.log('finish', event.task, event.seq); + const cycle = stats.getOrMakeCycle({ task, seq }); + cycle.recordEnd(success); + break; + } + case 'status': + default: + } + } +}; diff --git a/runner/lib/stats/cycles.js b/runner/lib/stats/cycles.js new file mode 100644 index 0000000..4b44329 --- /dev/null +++ b/runner/lib/stats/cycles.js @@ -0,0 +1,77 @@ +/* eslint-disable prefer-object-spread */ + +import { + makeRawStats, + makeGetters, + cloneData, + copyProperties, +} from './helpers.js'; + +/** @typedef {import("./types.js").CycleStatsInitData} CycleStatsInitData */ +/** @typedef {import("./types.js").CycleStats} CycleStats */ +/** @typedef {import("./types.js").StageStats} StageStats */ + +/** + * @typedef {| + * 'success' | + * 'startBlockHeight'| + * 'endBlockHeight' | + * never} RawCycleStatsProps + */ + +/** @type {import('./helpers.js').RawStatInit} */ +const rawCycleStatsInit = { + success: null, + startBlockHeight: null, + endBlockHeight: null, +}; + +/** + * @param {CycleStatsInitData} data + * @returns {import('./types.js').CycleStatsCollectionKey} + */ +export const makeCycleStatsKey = ({ task, seq }) => `${task}/${seq}`; + +/** + * @param {CycleStatsInitData} data + * @param {StageStats} [stageStats] + * @returns {CycleStats} + */ +export const makeCycleStats = (data, stageStats) => { + const { savedData, publicProps, privateSetters } = makeRawStats( + rawCycleStatsInit, + ); + + /** @type {CycleStats['recordStart']} */ + const recordStart = () => { + if (stageStats) { + privateSetters.startBlockHeight(stageStats.lastBlockHeight); + } + }; + + /** @type {CycleStats['recordEnd']} */ + const recordEnd = (successResult) => { + if (stageStats) { + privateSetters.endBlockHeight(stageStats.lastBlockHeight); + } + assert(typeof successResult === 'boolean'); + privateSetters.success(successResult); + }; + + const getBlockCount = () => + savedData.startBlockHeight && + savedData.endBlockHeight && + savedData.endBlockHeight - savedData.startBlockHeight; + + return harden( + copyProperties( + { + recordStart, + recordEnd, + }, + cloneData(data), + publicProps, + makeGetters({ blockCount: getBlockCount }), + ), + ); +}; diff --git a/runner/lib/stats/run.js b/runner/lib/stats/run.js index f540480..8b1aa43 100644 --- a/runner/lib/stats/run.js +++ b/runner/lib/stats/run.js @@ -52,6 +52,12 @@ export const makeRunStats = (data = {}) => { 0, ); + const getCycleCount = () => + Object.values(stages).reduce( + (acc, stage) => acc + (stage ? stage.cycleCount : 0), + 0, + ); + const stats = harden( copyProperties( { @@ -65,6 +71,7 @@ export const makeRunStats = (data = {}) => { stages: () => stages, stageCount: getStageCount, blockCount: getBlockCount, + cycleCount: getCycleCount, }), ), ); diff --git a/runner/lib/stats/stages.js b/runner/lib/stats/stages.js index 10c225c..7b7ffc3 100644 --- a/runner/lib/stats/stages.js +++ b/runner/lib/stats/stages.js @@ -8,8 +8,11 @@ import { copyProperties, } from './helpers.js'; import { makeBlockStats } from './blocks.js'; +import { makeCycleStats, makeCycleStatsKey } from './cycles.js'; /** @typedef {import("./types.js").BlockStats} BlockStats */ +/** @typedef {import("./types.js").CycleStats} CycleStats */ +/** @typedef {import("./types.js").CycleStatsCollectionKey} CycleStatsCollectionKey */ /** @typedef {import("./types.js").StageStatsInitData} StageStatsInitData */ /** @typedef {import("./types.js").StageStats} StageStats */ @@ -42,6 +45,13 @@ export const makeStageStats = (data) => { getCount: getBlockCount, } = makeStatsCollection(); + /** @type {import("./helpers.js").MakeStatsCollectionReturnType} */ + const { + collection: cycles, + insert: insertCycle, + getCount: getCycleCount, + } = makeStatsCollection(); + /** @type {StageStats['newBlock']} */ const newBlock = (blockData) => { const { blockHeight } = blockData; @@ -57,18 +67,32 @@ export const makeStageStats = (data) => { return block; }; + /** @type {StageStats['getOrMakeCycle']} */ + const getOrMakeCycle = (cycleData) => { + const key = makeCycleStatsKey(cycleData); + let cycle = cycles[key]; + if (!cycle) { + // eslint-disable-next-line no-use-before-define + cycle = makeCycleStats(cycleData, stats); + insertCycle(key, cycle); + } + return cycle; + }; const stats = harden( copyProperties( { recordStart: () => {}, recordEnd: () => {}, newBlock, + getOrMakeCycle, }, cloneData(data), publicProps, makeGetters({ blocks: () => blocks, + cycles: () => cycles, blockCount: getBlockCount, + cycleCount: getCycleCount, }), ), ); diff --git a/runner/lib/stats/types.d.ts b/runner/lib/stats/types.d.ts index abab4ee..85d9171 100644 --- a/runner/lib/stats/types.d.ts +++ b/runner/lib/stats/types.d.ts @@ -20,6 +20,22 @@ export interface BlockStats extends BlockStatsInitData { readonly slogLines: number; } +export interface CycleStatsInitData { + readonly task: string; + readonly seq: number; +} + +export type CycleStatsCollectionKey = `${string}/${number}`; + +export interface CycleStats extends CycleStatsInitData { + recordStart(): void; + recordEnd(success: boolean): void; + readonly success: boolean | undefined; + readonly startBlockHeight: number | undefined; + readonly endBlockHeight: number | undefined; + readonly blockCount: number | undefined; +} + export interface StageStatsInitData { readonly stageConfig: Readonly>; readonly stageIndex: number; @@ -29,8 +45,11 @@ export interface StageStats extends StageStatsInitData { recordStart(): void; recordEnd(): void; newBlock(data: BlockStatsInitData): BlockStats; + getOrMakeCycle(data: CycleStatsInitData): CycleStats; readonly blocks: StatsCollection; readonly blockCount: number; + readonly cycles: StatsCollection; + readonly cycleCount: number; readonly firstBlockHeight: number | undefined; readonly lastBlockHeight: number | undefined; } @@ -44,4 +63,5 @@ export interface RunStats extends RunStatsInitData { readonly stages: StatsCollection; readonly stageCount: number; readonly blockCount: number; + readonly cycleCount: number; } diff --git a/runner/lib/tasks/types.d.ts b/runner/lib/tasks/types.d.ts index 0f977bb..aba3084 100644 --- a/runner/lib/tasks/types.d.ts +++ b/runner/lib/tasks/types.d.ts @@ -1,6 +1,8 @@ /* global Buffer */ /* eslint-disable no-unused-vars,no-redeclare */ +import type { TimeValueS } from '../helpers/time.js'; + export type TaskResult = { readonly stop: () => void; readonly done: Promise; @@ -13,8 +15,30 @@ export type RunChainInfo = { readonly storageLocation: string; }; +export type TaskEventStatus = Record & { + time: TimeValueS; + type: 'status'; +}; + +export type TaskEventStart = { + time: TimeValueS; + type: 'start'; + task: string; + seq: number; +}; + +export type TaskEventFinish = { + time: TimeValueS; + type: 'finish'; + task: string; + seq: number; + success: boolean; +}; + +export type TaskEvent = TaskEventStatus | TaskEventStart | TaskEventFinish; + export type RunLoadgenInfo = { - readonly taskEvents: AsyncIterable>; + readonly taskEvents: AsyncIterable; }; export type RunChainResult = TaskResult & RunChainInfo; From 05ab84d6280f728c471fc43f4e47f4aa770eebe7 Mon Sep 17 00:00:00 2001 From: Mathieu Hofman Date: Mon, 17 Jan 2022 21:55:33 +0000 Subject: [PATCH 5/9] feat(runner): measure run, stage and cycle timing --- runner/lib/main.js | 35 ++++++++++++--- runner/lib/monitor/loadgen-monitor.js | 5 ++- runner/lib/stats/cycles.js | 18 ++++++-- runner/lib/stats/run.js | 46 +++++++++++++++++-- runner/lib/stats/stages.js | 65 +++++++++++++++++++++++++-- runner/lib/stats/types.d.ts | 51 ++++++++++++++++++--- 6 files changed, 195 insertions(+), 25 deletions(-) diff --git a/runner/lib/main.js b/runner/lib/main.js index bd2c707..2bceaac 100644 --- a/runner/lib/main.js +++ b/runner/lib/main.js @@ -291,6 +291,7 @@ const main = async (progName, rawArgs, powers) => { logPerfEvent('run-chain-start'); const runChainResult = await runChain({ stdout: out, stderr: err }); logPerfEvent('run-chain-finish'); + stats.recordChainStart(timeSource.getTime()); let chainExited = false; const done = runChainResult.done.finally(() => { @@ -377,6 +378,7 @@ const main = async (progName, rawArgs, powers) => { await aggregateTryFinally( async () => { await orInterrupt(runChainResult.ready); + stats.recordChainReady(timeSource.getTime()); logPerfEvent('chain-ready'); stageConsole.log('Chain ready'); @@ -414,9 +416,9 @@ const main = async (progName, rawArgs, powers) => { const spawnClient = async (nextStep) => { stageConsole.log('Running client'); logPerfEvent('run-client-start'); - const runClientStart = timeSource.shift(); const runClientResult = await runClient({ stdout: out, stderr: err }); logPerfEvent('run-client-finish'); + stats.recordClientStart(timeSource.getTime()); let clientExited = false; const done = runClientResult.done.finally(() => { @@ -427,9 +429,18 @@ const main = async (progName, rawArgs, powers) => { await aggregateTryFinally( async () => { await orInterrupt(runClientResult.ready); + stats.recordClientReady(timeSource.getTime()); logPerfEvent('client-ready', { - duration: runClientStart.now(), + duration: stats.clientInitDuration, }); + if (!runStats.walletDeployEndedAt) { + runStats.recordWalletDeployStart( + /** @type {number} */ (stats.clientStartedAt), + ); + runStats.recordWalletDeployEnd( + /** @type {number} */ (stats.clientReadyAt), + ); + } await nextStep(done); }, @@ -453,6 +464,7 @@ const main = async (progName, rawArgs, powers) => { stderr: err, config: loadgenConfig, }); + stats.recordLoadgenStart(timeSource.getTime()); logPerfEvent('run-loadgen-finish'); let loadgenExited = false; @@ -469,7 +481,16 @@ const main = async (progName, rawArgs, powers) => { await aggregateTryFinally( async () => { await orInterrupt(runLoadgenResult.ready); + stats.recordLoadgenReady(timeSource.getTime()); logPerfEvent('loadgen-ready'); + if (!runStats.loadgenDeployEndedAt) { + runStats.recordLoadgenDeployStart( + /** @type {number} */ (stats.loadgenStartedAt), + ); + runStats.recordLoadgenDeployEnd( + /** @type {number} */ (stats.loadgenReadyAt), + ); + } await nextStep(done); }, @@ -510,6 +531,7 @@ const main = async (progName, rawArgs, powers) => { stageConsole.log('Stage ready, no time to sleep, moving on'); } } + stats.recordReady(timeSource.getTime()); logPerfEvent('stage-ready'); await nextStep(sleeping).finally(sleepCancel.resolve); logPerfEvent('stage-shutdown'); @@ -540,10 +562,9 @@ const main = async (progName, rawArgs, powers) => { } else { tasks.push(stageReady); } - - stats.recordStart(); + stats.recordStart(timeSource.getTime()); await sequential(...tasks)((stop) => stop); - stats.recordEnd(); + stats.recordEnd(timeSource.getTime()); }, async () => aggregateTryFinally( @@ -577,7 +598,7 @@ const main = async (progName, rawArgs, powers) => { await aggregateTryFinally( async () => { const { console: initConsole, out, err } = makeConsole('init'); - runStats.recordStart(); + runStats.recordStart(timeSource.getTime()); logPerfEvent('start', { cpuTimeOffset, timeOrigin: timeSource.timeOrigin, @@ -679,7 +700,7 @@ const main = async (progName, rawArgs, powers) => { }); } - runStats.recordEnd(); + runStats.recordEnd(timeSource.getTime()); }, async () => { logPerfEvent('finish', { stats: runStats }); diff --git a/runner/lib/monitor/loadgen-monitor.js b/runner/lib/monitor/loadgen-monitor.js index ee95284..5e9b7fe 100644 --- a/runner/lib/monitor/loadgen-monitor.js +++ b/runner/lib/monitor/loadgen-monitor.js @@ -8,19 +8,20 @@ */ export const monitorLoadgen = async ({ taskEvents }, { stats, console }) => { for await (const event of taskEvents) { + const { time } = event; switch (event.type) { case 'start': { const { task, seq } = event; console.log('start', task, seq); const cycle = stats.getOrMakeCycle({ task, seq }); - cycle.recordStart(); + cycle.recordStart(time); break; } case 'finish': { const { task, seq, success } = event; console.log('finish', event.task, event.seq); const cycle = stats.getOrMakeCycle({ task, seq }); - cycle.recordEnd(success); + cycle.recordEnd(time, success); break; } case 'status': diff --git a/runner/lib/stats/cycles.js b/runner/lib/stats/cycles.js index 4b44329..7f0cb1e 100644 --- a/runner/lib/stats/cycles.js +++ b/runner/lib/stats/cycles.js @@ -5,6 +5,7 @@ import { makeGetters, cloneData, copyProperties, + rounder, } from './helpers.js'; /** @typedef {import("./types.js").CycleStatsInitData} CycleStatsInitData */ @@ -16,6 +17,8 @@ import { * 'success' | * 'startBlockHeight'| * 'endBlockHeight' | + * 'startedAt' | + * 'endedAt' | * never} RawCycleStatsProps */ @@ -24,6 +27,8 @@ const rawCycleStatsInit = { success: null, startBlockHeight: null, endBlockHeight: null, + startedAt: null, + endedAt: null, }; /** @@ -43,14 +48,16 @@ export const makeCycleStats = (data, stageStats) => { ); /** @type {CycleStats['recordStart']} */ - const recordStart = () => { + const recordStart = (time) => { + privateSetters.startedAt(time); if (stageStats) { privateSetters.startBlockHeight(stageStats.lastBlockHeight); } }; /** @type {CycleStats['recordEnd']} */ - const recordEnd = (successResult) => { + const recordEnd = (time, successResult) => { + privateSetters.endedAt(time); if (stageStats) { privateSetters.endBlockHeight(stageStats.lastBlockHeight); } @@ -63,6 +70,11 @@ export const makeCycleStats = (data, stageStats) => { savedData.endBlockHeight && savedData.endBlockHeight - savedData.startBlockHeight; + const getDuration = () => + savedData.startedAt && + savedData.endedAt && + rounder(savedData.endedAt - savedData.startedAt); + return harden( copyProperties( { @@ -71,7 +83,7 @@ export const makeCycleStats = (data, stageStats) => { }, cloneData(data), publicProps, - makeGetters({ blockCount: getBlockCount }), + makeGetters({ blockCount: getBlockCount, duration: getDuration }), ), ); }; diff --git a/runner/lib/stats/run.js b/runner/lib/stats/run.js index 8b1aa43..480bc8c 100644 --- a/runner/lib/stats/run.js +++ b/runner/lib/stats/run.js @@ -6,6 +6,7 @@ import { makeGetters, cloneData, copyProperties, + rounder, } from './helpers.js'; import { makeStageStats } from './stages.js'; @@ -15,18 +16,33 @@ import { makeStageStats } from './stages.js'; /** * @typedef {| + * 'startedAt' | + * 'endedAt' | + * 'walletDeployStartedAt' | + * 'walletDeployEndedAt' | + * 'loadgenDeployStartedAt' | + * 'loadgenDeployEndedAt' | * never} RawRunStatsProps */ /** @type {import('./helpers.js').RawStatInit} */ -const rawRunStatsInit = {}; +const rawRunStatsInit = { + startedAt: null, + endedAt: null, + walletDeployStartedAt: null, + walletDeployEndedAt: null, + loadgenDeployStartedAt: null, + loadgenDeployEndedAt: null, +}; /** * @param {RunStatsInitData} data * @returns {RunStats} */ export const makeRunStats = (data = {}) => { - const { publicProps } = makeRawStats(rawRunStatsInit); + const { savedData, publicProps, privateSetters } = makeRawStats( + rawRunStatsInit, + ); /** @type {import("./helpers.js").MakeStatsCollectionReturnType} */ const { @@ -58,11 +74,30 @@ export const makeRunStats = (data = {}) => { 0, ); + const getDuration = () => + savedData.startedAt && + savedData.endedAt && + rounder(savedData.endedAt - savedData.startedAt); + + const getWalletDeployDuration = () => + savedData.walletDeployStartedAt && + savedData.walletDeployEndedAt && + rounder(savedData.walletDeployEndedAt - savedData.walletDeployStartedAt); + + const getLoadgenDeployDuration = () => + savedData.loadgenDeployStartedAt && + savedData.loadgenDeployEndedAt && + rounder(savedData.loadgenDeployEndedAt - savedData.loadgenDeployStartedAt); + const stats = harden( copyProperties( { - recordStart: () => {}, - recordEnd: () => {}, + recordStart: privateSetters.startedAt, + recordEnd: privateSetters.endedAt, + recordWalletDeployStart: privateSetters.walletDeployStartedAt, + recordWalletDeployEnd: privateSetters.walletDeployEndedAt, + recordLoadgenDeployStart: privateSetters.loadgenDeployStartedAt, + recordLoadgenDeployEnd: privateSetters.loadgenDeployEndedAt, newStage, }, cloneData(data), @@ -72,6 +107,9 @@ export const makeRunStats = (data = {}) => { stageCount: getStageCount, blockCount: getBlockCount, cycleCount: getCycleCount, + duration: getDuration, + walletDeployDuration: getWalletDeployDuration, + loadgenDeployDuration: getLoadgenDeployDuration, }), ), ); diff --git a/runner/lib/stats/stages.js b/runner/lib/stats/stages.js index 7b7ffc3..994e6e9 100644 --- a/runner/lib/stats/stages.js +++ b/runner/lib/stats/stages.js @@ -6,6 +6,7 @@ import { cloneData, makeGetters, copyProperties, + rounder, } from './helpers.js'; import { makeBlockStats } from './blocks.js'; import { makeCycleStats, makeCycleStatsKey } from './cycles.js'; @@ -20,6 +21,15 @@ import { makeCycleStats, makeCycleStatsKey } from './cycles.js'; * @typedef {| * 'firstBlockHeight' | * 'lastBlockHeight' | + * 'startedAt' | + * 'readyAt' | + * 'endedAt' | + * 'chainStartedAt' | + * 'chainReadyAt' | + * 'clientStartedAt' | + * 'clientReadyAt' | + * 'loadgenStartedAt' | + * 'loadgenReadyAt' | * never } RawStageStatsProps */ @@ -29,6 +39,15 @@ const rawStageStatsInit = { lastBlockHeight: { writeMulti: true, }, + startedAt: null, + readyAt: null, + endedAt: null, + chainStartedAt: null, + chainReadyAt: null, + clientStartedAt: null, + clientReadyAt: null, + loadgenStartedAt: null, + loadgenReadyAt: null, }; /** @@ -36,7 +55,9 @@ const rawStageStatsInit = { * @returns {StageStats} */ export const makeStageStats = (data) => { - const { publicProps, privateSetters } = makeRawStats(rawStageStatsInit); + const { savedData, publicProps, privateSetters } = makeRawStats( + rawStageStatsInit, + ); /** @type {import("./helpers.js").MakeStatsCollectionReturnType} */ const { @@ -78,11 +99,44 @@ export const makeStageStats = (data) => { } return cycle; }; + + const getReadyDuration = () => + savedData.startedAt && + savedData.readyAt && + rounder(savedData.readyAt - savedData.startedAt); + + const getDuration = () => + savedData.startedAt && + savedData.endedAt && + rounder(savedData.endedAt - savedData.startedAt); + + const getChainInitDuration = () => + savedData.chainStartedAt && + savedData.chainReadyAt && + rounder(savedData.chainReadyAt - savedData.chainStartedAt); + + const getClientInitDuration = () => + savedData.clientStartedAt && + savedData.clientReadyAt && + rounder(savedData.clientReadyAt - savedData.clientStartedAt); + + const getLoadgenInitDuration = () => + savedData.loadgenStartedAt && + savedData.loadgenReadyAt && + rounder(savedData.loadgenReadyAt - savedData.loadgenStartedAt); + const stats = harden( copyProperties( { - recordStart: () => {}, - recordEnd: () => {}, + recordStart: privateSetters.startedAt, + recordReady: privateSetters.readyAt, + recordEnd: privateSetters.endedAt, + recordChainStart: privateSetters.chainStartedAt, + recordChainReady: privateSetters.chainReadyAt, + recordClientStart: privateSetters.clientStartedAt, + recordClientReady: privateSetters.clientReadyAt, + recordLoadgenStart: privateSetters.loadgenStartedAt, + recordLoadgenReady: privateSetters.loadgenReadyAt, newBlock, getOrMakeCycle, }, @@ -93,6 +147,11 @@ export const makeStageStats = (data) => { cycles: () => cycles, blockCount: getBlockCount, cycleCount: getCycleCount, + readyDuration: getReadyDuration, + duration: getDuration, + chainInitDuration: getChainInitDuration, + clientInitDuration: getClientInitDuration, + loadgenInitDuration: getLoadgenInitDuration, }), ), ); diff --git a/runner/lib/stats/types.d.ts b/runner/lib/stats/types.d.ts index 85d9171..87bc1b7 100644 --- a/runner/lib/stats/types.d.ts +++ b/runner/lib/stats/types.d.ts @@ -1,5 +1,7 @@ /* eslint-disable no-unused-vars,no-redeclare */ +import type { TimeValueS } from '../helpers/time.js'; + export interface LogPerfEvent { (eventType: string, data?: Record): void; } @@ -28,12 +30,15 @@ export interface CycleStatsInitData { export type CycleStatsCollectionKey = `${string}/${number}`; export interface CycleStats extends CycleStatsInitData { - recordStart(): void; - recordEnd(success: boolean): void; + recordStart(time: TimeValueS): void; + recordEnd(time: TimeValueS, success: boolean): void; readonly success: boolean | undefined; readonly startBlockHeight: number | undefined; readonly endBlockHeight: number | undefined; readonly blockCount: number | undefined; + readonly startedAt: TimeValueS | undefined; + readonly endedAt: TimeValueS | undefined; + readonly duration: number | undefined; } export interface StageStatsInitData { @@ -42,8 +47,15 @@ export interface StageStatsInitData { } export interface StageStats extends StageStatsInitData { - recordStart(): void; - recordEnd(): void; + recordStart(time: TimeValueS): void; + recordReady(time: TimeValueS): void; + recordEnd(time: TimeValueS): void; + recordChainStart(time: TimeValueS): void; + recordChainReady(time: TimeValueS): void; + recordClientStart(time: TimeValueS): void; + recordClientReady(time: TimeValueS): void; + recordLoadgenStart(time: TimeValueS): void; + recordLoadgenReady(time: TimeValueS): void; newBlock(data: BlockStatsInitData): BlockStats; getOrMakeCycle(data: CycleStatsInitData): CycleStats; readonly blocks: StatsCollection; @@ -52,16 +64,43 @@ export interface StageStats extends StageStatsInitData { readonly cycleCount: number; readonly firstBlockHeight: number | undefined; readonly lastBlockHeight: number | undefined; + readonly startedAt: TimeValueS | undefined; + readonly readyAt: TimeValueS | undefined; + readonly endedAt: TimeValueS | undefined; + readonly readyDuration: number | undefined; + readonly duration: number | undefined; + readonly chainStartedAt: TimeValueS | undefined; + readonly chainReadyAt: TimeValueS | undefined; + readonly chainInitDuration: number | undefined; + readonly clientStartedAt: TimeValueS | undefined; + readonly clientReadyAt: TimeValueS | undefined; + readonly clientInitDuration: number | undefined; + readonly loadgenStartedAt: TimeValueS | undefined; + readonly loadgenReadyAt: TimeValueS | undefined; + readonly loadgenInitDuration: number | undefined; } export interface RunStatsInitData {} export interface RunStats extends RunStatsInitData { - recordStart(): void; - recordEnd(): void; + recordStart(time: TimeValueS): void; + recordEnd(time: TimeValueS): void; newStage(data: StageStatsInitData): StageStats; + recordWalletDeployStart(time: TimeValueS): void; + recordWalletDeployEnd(time: TimeValueS): void; + recordLoadgenDeployStart(time: TimeValueS): void; + recordLoadgenDeployEnd(time: TimeValueS): void; readonly stages: StatsCollection; readonly stageCount: number; readonly blockCount: number; readonly cycleCount: number; + readonly startedAt: TimeValueS | undefined; + readonly endedAt: TimeValueS | undefined; + readonly duration: number | undefined; + readonly walletDeployStartedAt: TimeValueS | undefined; + readonly walletDeployEndedAt: TimeValueS | undefined; + readonly walletDeployDuration: number | undefined; + readonly loadgenDeployStartedAt: TimeValueS | undefined; + readonly loadgenDeployEndedAt: TimeValueS | undefined; + readonly loadgenDeployDuration: number | undefined; } From a9466e58011fe3f4255174be6e8e0fd463bb5729 Mon Sep 17 00:00:00 2001 From: Mathieu Hofman Date: Mon, 17 Jan 2022 21:55:33 +0000 Subject: [PATCH 6/9] feat(runner): Record if block stat was captured in live mode --- runner/lib/stats/blocks.js | 8 +++++++- runner/lib/stats/stages.js | 3 ++- runner/lib/stats/types.d.ts | 1 + 3 files changed, 10 insertions(+), 2 deletions(-) diff --git a/runner/lib/stats/blocks.js b/runner/lib/stats/blocks.js index b83a6ac..1466d40 100644 --- a/runner/lib/stats/blocks.js +++ b/runner/lib/stats/blocks.js @@ -8,6 +8,7 @@ import { makeRawStats, cloneData, copyProperties } from './helpers.js'; /** * @typedef {| * 'slogLines' | + * 'liveMode' | * never} RawBlockStatsProps */ @@ -17,13 +18,15 @@ const rawBlockStatsInit = { default: -Infinity, writeMulti: true, }, + liveMode: null, }; /** * @param {BlockStatsInitData} data + * @param {import("./types.js").StageStats} [stageStats] * @returns {BlockStats} */ -export const makeBlockStats = (data) => { +export const makeBlockStats = (data, stageStats) => { const { publicProps, privateSetters } = makeRawStats(rawBlockStatsInit); /** @type {BlockStats['recordStart']} */ @@ -34,6 +37,9 @@ export const makeBlockStats = (data) => { /** @type {BlockStats['recordSwingsetStart']} */ const recordSwingsetStart = () => { privateSetters.slogLines(0); + if (stageStats) { + privateSetters.liveMode(stageStats.chainReadyAt != null); + } }; /** @type {BlockStats['recordSlogLine']} */ diff --git a/runner/lib/stats/stages.js b/runner/lib/stats/stages.js index 994e6e9..f3c078e 100644 --- a/runner/lib/stats/stages.js +++ b/runner/lib/stats/stages.js @@ -83,7 +83,8 @@ export const makeStageStats = (data) => { privateSetters.firstBlockHeight(blockHeight); } privateSetters.lastBlockHeight(blockHeight); - const block = makeBlockStats(blockData); + // eslint-disable-next-line no-use-before-define + const block = makeBlockStats(blockData, stats); insertBlock(blockHeight, block); return block; }; diff --git a/runner/lib/stats/types.d.ts b/runner/lib/stats/types.d.ts index 87bc1b7..6c1e0cd 100644 --- a/runner/lib/stats/types.d.ts +++ b/runner/lib/stats/types.d.ts @@ -20,6 +20,7 @@ export interface BlockStats extends BlockStatsInitData { recordSwingsetStart(): void; recordSlogLine(): void; readonly slogLines: number; + readonly liveMode: boolean | undefined; } export interface CycleStatsInitData { From 709643c6ab6e9b13a77e1406e2234c737e53443d Mon Sep 17 00:00:00 2001 From: Mathieu Hofman Date: Mon, 17 Jan 2022 21:55:33 +0000 Subject: [PATCH 7/9] feat(runner): Capture run metadata --- Dockerfile | 2 +- runner/lib/main.js | 27 +++++++++++++++++-------- runner/lib/stats/run.js | 2 +- runner/lib/stats/types.d.ts | 11 +++++++++- runner/lib/tasks/local-chain.js | 2 ++ runner/lib/tasks/shared-env-info.js | 31 +++++++++++++++++++++++++++++ runner/lib/tasks/testnet.js | 2 ++ runner/lib/tasks/types.d.ts | 5 +++++ scripts/run-daily-perf.sh | 2 +- start.sh | 3 ++- 10 files changed, 74 insertions(+), 13 deletions(-) create mode 100644 runner/lib/tasks/shared-env-info.js diff --git a/Dockerfile b/Dockerfile index 84786b6..628e682 100644 --- a/Dockerfile +++ b/Dockerfile @@ -159,4 +159,4 @@ RUN mkdir -p $SDK_SRC $OUTPUT_DIR && chown $USER_UID:$USER_GID $SDK_SRC $OUTPUT_ USER $USER_UID:$USER_GID -ENTRYPOINT ["/tini", "--", "/app/start.sh", "--no-reset"] \ No newline at end of file +ENTRYPOINT ["/tini", "--", "/app/start.sh", "--no-reset", "--test-data.docker"] \ No newline at end of file diff --git a/runner/lib/main.js b/runner/lib/main.js index 2bceaac..b023338 100644 --- a/runner/lib/main.js +++ b/runner/lib/main.js @@ -207,13 +207,15 @@ const main = async (progName, rawArgs, powers) => { throw new Error(`Unexpected profile option: ${argv.profile}`); } - const { setupTasks, runChain, runClient, runLoadgen } = makeTasks({ - spawn, - fs, - findDirByPrefix: findByPrefix, - makeFIFO, - getProcessInfo, - }); + const { getEnvInfo, setupTasks, runChain, runClient, runLoadgen } = makeTasks( + { + spawn, + fs, + findDirByPrefix: findByPrefix, + makeFIFO, + getProcessInfo, + }, + ); const monitorInterval = Number(argv.monitorInterval || defaultMonitorIntervalMinutes) * 60 * 1000; @@ -230,7 +232,16 @@ const main = async (progName, rawArgs, powers) => { ); await fsStreamReady(outputStream); - const runStats = makeRunStats(); + const envInfo = await getEnvInfo({ stdout, stderr }); + + const runStats = makeRunStats({ + metadata: { + profile: argv.profile || 'local', + testnetOrigin, + ...envInfo, + testData: argv.testData, + }, + }); /** @type {import('./stats/types.js').LogPerfEvent} */ const logPerfEvent = (eventType, data = {}) => { diff --git a/runner/lib/stats/run.js b/runner/lib/stats/run.js index 480bc8c..24075c0 100644 --- a/runner/lib/stats/run.js +++ b/runner/lib/stats/run.js @@ -39,7 +39,7 @@ const rawRunStatsInit = { * @param {RunStatsInitData} data * @returns {RunStats} */ -export const makeRunStats = (data = {}) => { +export const makeRunStats = (data) => { const { savedData, publicProps, privateSetters } = makeRawStats( rawRunStatsInit, ); diff --git a/runner/lib/stats/types.d.ts b/runner/lib/stats/types.d.ts index 6c1e0cd..e9aff29 100644 --- a/runner/lib/stats/types.d.ts +++ b/runner/lib/stats/types.d.ts @@ -81,7 +81,16 @@ export interface StageStats extends StageStatsInitData { readonly loadgenInitDuration: number | undefined; } -export interface RunStatsInitData {} +export interface RunMetadata { + readonly profile: string; + readonly testnetOrigin?: string; + readonly agChainCosmosVersion?: unknown; + readonly testData?: unknown; +} + +export interface RunStatsInitData { + readonly metadata: RunMetadata; +} export interface RunStats extends RunStatsInitData { recordStart(time: TimeValueS): void; diff --git a/runner/lib/tasks/local-chain.js b/runner/lib/tasks/local-chain.js index 637031b..7a53094 100644 --- a/runner/lib/tasks/local-chain.js +++ b/runner/lib/tasks/local-chain.js @@ -19,6 +19,7 @@ import { wrapArgvMatcherIgnoreEnvShebang, getConsoleAndStdio, } from './helpers.js'; +import { makeGetEnvInfo } from './shared-env-info.js'; import { makeLoadgenTask } from './shared-loadgen.js'; const pipeline = promisify(pipelineCallback); @@ -265,6 +266,7 @@ export const makeTasks = ({ }; return harden({ + getEnvInfo: makeGetEnvInfo({ spawn }), setupTasks, runChain, runClient, diff --git a/runner/lib/tasks/shared-env-info.js b/runner/lib/tasks/shared-env-info.js new file mode 100644 index 0000000..3e870a0 --- /dev/null +++ b/runner/lib/tasks/shared-env-info.js @@ -0,0 +1,31 @@ +/* global process */ + +import { childProcessOutput } from '../helpers/child-process.js'; +import { asJSON } from '../helpers/stream.js'; + +/** + * + * @param {Object} powers + * @param {import("child_process").spawn} powers.spawn Node.js spawn + * @returns {import("./types.js").OrchestratorTasks['getEnvInfo']} + * + */ +export const makeGetEnvInfo = ({ spawn }) => { + return harden(async ({ stderr }) => { + const chainEnv = Object.create(process.env); + // Disable any lockdown options as that interferes with stdout + chainEnv.LOCKDOWN_OPTIONS = undefined; + + const versionCp = spawn( + 'ag-chain-cosmos', + ['version', '--long', '--output', 'json'], + { + stdio: ['ignore', 'pipe', stderr], + env: chainEnv, + }, + ); + const version = await childProcessOutput(versionCp, asJSON); + + return { agChainCosmosVersion: version }; + }); +}; diff --git a/runner/lib/tasks/testnet.js b/runner/lib/tasks/testnet.js index 1eb5dc3..2f11002 100644 --- a/runner/lib/tasks/testnet.js +++ b/runner/lib/tasks/testnet.js @@ -28,6 +28,7 @@ import { getConsoleAndStdio, fetchAsJSON, } from './helpers.js'; +import { makeGetEnvInfo } from './shared-env-info.js'; import { makeLoadgenTask } from './shared-loadgen.js'; const pipeline = promisify(pipelineCallback); @@ -431,6 +432,7 @@ export const makeTasks = ({ spawn: cpSpawn, fs, makeFIFO, getProcessInfo }) => { }; return harden({ + getEnvInfo: makeGetEnvInfo({ spawn }), setupTasks, runChain, runClient, diff --git a/runner/lib/tasks/types.d.ts b/runner/lib/tasks/types.d.ts index aba3084..13aa163 100644 --- a/runner/lib/tasks/types.d.ts +++ b/runner/lib/tasks/types.d.ts @@ -3,6 +3,10 @@ import type { TimeValueS } from '../helpers/time.js'; +export interface EnvInfo { + readonly agChainCosmosVersion?: unknown; +} + export type TaskResult = { readonly stop: () => void; readonly done: Promise; @@ -52,6 +56,7 @@ export interface TaskBaseOptions { } export interface OrchestratorTasks { + getEnvInfo(options: TaskBaseOptions): Promise; setupTasks(options: TaskBaseOptions): Promise; runChain(options: TaskBaseOptions): Promise; runClient(options: TaskBaseOptions): Promise; diff --git a/scripts/run-daily-perf.sh b/scripts/run-daily-perf.sh index bd74033..96f8674 100755 --- a/scripts/run-daily-perf.sh +++ b/scripts/run-daily-perf.sh @@ -29,7 +29,7 @@ do done echo "processing ${SDK_REVISION}" mkdir "${OUTPUT_DIR}" - DOCKER_ID=$(docker create -v "$(pwd)/${OUTPUT_DIR}:/out" -e SDK_REVISION=${SDK_REVISION} --name "${OUTPUT_DIR}" loadgen-runner --no-reset) || exit $? + DOCKER_ID=$(docker create -v "$(pwd)/${OUTPUT_DIR}:/out" -e SDK_REVISION=${SDK_REVISION} --name "${OUTPUT_DIR}" loadgen-runner --test-data.test-type=daily-perf) || exit $? docker start ${DOCKER_ID} docker wait ${DOCKER_ID} >"${OUTPUT_DIR}/exit_code" & DOCKER_WAIT_PID=$! diff --git a/start.sh b/start.sh index c09b940..5b63f35 100755 --- a/start.sh +++ b/start.sh @@ -34,6 +34,7 @@ then fi SDK_REVISION=$(git -C "${SDK_SRC}" rev-parse --short HEAD) +SDK_COMMIT_TIME=$(git -C "${SDK_SRC}" show -s --format=%ct ${SDK_REVISION}) AGORIC_BIN_DIR=/tmp/agoric-sdk-bin-${SDK_REVISION} mkdir -p ${AGORIC_BIN_DIR} @@ -56,4 +57,4 @@ ln -sf "$SDK_SRC/packages/cosmic-swingset/bin/ag-chain-cosmos" "${AGORIC_BIN_DIR cd "$LOADGEN_DIR" agoric install -exec ./runner/bin/loadgen-runner --output-dir="${OUTPUT_DIR}" "$@" 2>&1 +exec ./runner/bin/loadgen-runner --output-dir="${OUTPUT_DIR}" --test-data.sdk-revision=${SDK_REVISION} --test-data.sdk-commit-time=${SDK_COMMIT_TIME} "$@" 2>&1 From 5d4034af7bee15c9d9698fec868ed499464b49d1 Mon Sep 17 00:00:00 2001 From: Mathieu Hofman Date: Mon, 17 Jan 2022 21:55:33 +0000 Subject: [PATCH 8/9] feat(runner): Add stats summaries --- runner/lib/main.js | 22 ++++++ runner/lib/stats/blocks.js | 33 +++++++++ runner/lib/stats/cycles.js | 17 +++++ runner/lib/stats/helpers.d.ts | 32 +++++++++ runner/lib/stats/helpers.js | 93 +++++++++++++++++++++++++ runner/lib/stats/run.js | 119 ++++++++++++++++++++++++++----- runner/lib/stats/stages.js | 127 +++++++++++++++++++++++++++++++++- runner/lib/stats/types.d.ts | 34 ++++++++- 8 files changed, 455 insertions(+), 22 deletions(-) diff --git a/runner/lib/main.js b/runner/lib/main.js index b023338..b585628 100644 --- a/runner/lib/main.js +++ b/runner/lib/main.js @@ -598,6 +598,16 @@ const main = async (progName, rawArgs, powers) => { releaseInterrupt(); logPerfEvent('stage-finish'); + stageConsole.log('Live blocks stats:', { + ...((stats.blocksSummaries && stats.blocksSummaries.onlyLive) || { + blockCount: 0, + }), + }); + stageConsole.log('Cycles stats:', { + ...((stats.cyclesSummaries && stats.cyclesSummaries.all) || { + cycleCount: 0, + }), + }); currentStageTimeSource = timeSource; }, ), @@ -718,6 +728,18 @@ const main = async (progName, rawArgs, powers) => { outputStream.end(); + const { console } = makeConsole('summary'); + console.log('Live blocks stats:', { + ...(runStats.liveBlocksSummary || { + blockCount: 0, + }), + }); + console.log('Cycles stats:', { + ...(runStats.cyclesSummary || { + cycleCount: 0, + }), + }); + await finished(outputStream); }, ); diff --git a/runner/lib/stats/blocks.js b/runner/lib/stats/blocks.js index 1466d40..cb26413 100644 --- a/runner/lib/stats/blocks.js +++ b/runner/lib/stats/blocks.js @@ -21,6 +21,39 @@ const rawBlockStatsInit = { liveMode: null, }; +/** + * @typedef {| + * 'liveMode' | + * 'startBlockHeight' | + * 'endBlockHeight' | + * never} BlockStatsSumKeys + */ + +/** + * @param {import('./helpers.js').Sums} sums + * @returns {import('./types.js').BlockStatsSummary | undefined} + */ +export const makeBlockStatsSummary = ({ + values, + weights: blockCount, + totals, + items, + mins, + maxes, +}) => + blockCount + ? { + blockCount, + liveMode: + blockCount === totals.liveMode || + (items.liveMode === values && totals.liveMode === 0 + ? false + : undefined), + startBlockHeight: mins.startBlockHeight, + endBlockHeight: maxes.endBlockHeight, + } + : undefined; + /** * @param {BlockStatsInitData} data * @param {import("./types.js").StageStats} [stageStats] diff --git a/runner/lib/stats/cycles.js b/runner/lib/stats/cycles.js index 7f0cb1e..24b133d 100644 --- a/runner/lib/stats/cycles.js +++ b/runner/lib/stats/cycles.js @@ -6,6 +6,7 @@ import { cloneData, copyProperties, rounder, + percentageRounder, } from './helpers.js'; /** @typedef {import("./types.js").CycleStatsInitData} CycleStatsInitData */ @@ -31,6 +32,22 @@ const rawCycleStatsInit = { endedAt: null, }; +/** @typedef {'success' | 'blockCount' | 'duration'} CycleStatsSumKeys */ + +/** + * @param {import('./helpers.js').Sums} sums + * @returns {import('./types.js').CycleStatsSummary | undefined} + */ +export const makeCycleStatsSummary = ({ weights: cycleCount, averages }) => + cycleCount + ? { + cycleCount, + cycleSuccessRate: percentageRounder(averages.success), + avgBlockCount: rounder(averages.blockCount), + avgDuration: rounder(averages.duration), + } + : undefined; + /** * @param {CycleStatsInitData} data * @returns {import('./types.js').CycleStatsCollectionKey} diff --git a/runner/lib/stats/helpers.d.ts b/runner/lib/stats/helpers.d.ts index 591fc52..0019412 100644 --- a/runner/lib/stats/helpers.d.ts +++ b/runner/lib/stats/helpers.d.ts @@ -58,6 +58,7 @@ export declare function makeGetters any }>( }; export declare const rounder: (value: number) => number; +export declare const percentageRounder: (value: number) => number; export declare function cloneData(data: T): T; @@ -73,3 +74,34 @@ export declare function copyProperties( source2: V, source3: W, ): T & U & V & W; + +export declare function arrayGroupBy( + source: ReadonlyArray, + callback: (value: T, index: number, array: ReadonlyArray) => U, +): { + [key in U]: T[]; +}; + +type SumRecord = { + readonly [P in K]: number; +}; + +export type Sums = { + readonly values: number; + readonly weights: number; + readonly items: SumRecord; + readonly mins: SumRecord; + readonly maxes: SumRecord; + readonly totals: SumRecord; // weighted + readonly counts: SumRecord; // weighted + readonly averages: SumRecord; // weighted +}; + +type SummableRecord = { readonly [P in string]: number | undefined }; + +interface Summer { + add(value: T, weight?: 1 | number): void; + getSums(): Sums; +} + +export declare function makeSummer(): Summer; diff --git a/runner/lib/stats/helpers.js b/runner/lib/stats/helpers.js index 42a359e..b6e6535 100644 --- a/runner/lib/stats/helpers.js +++ b/runner/lib/stats/helpers.js @@ -98,6 +98,7 @@ export const makeGetters = (getters) => makeGetterObject(Object.entries(getters)); export const rounder = makeRounder(6); +export const percentageRounder = makeRounder(2, -2); /** * Note: hacky version of a deep clone @@ -123,3 +124,95 @@ export const copyProperties = (target, ...sources) => ...sources.map((source) => Object.getOwnPropertyDescriptors(source)), ), ); + +/** + * + * @param {ReadonlyArray} source + * @param {(value: unknown, index: number, array: ReadonlyArray) => PropertyKey} callback + */ +export const arrayGroupBy = (source, callback) => { + /** @type {{[key: PropertyKey]: unknown[]}} */ + const target = Object.create(null); + source.forEach((value, index) => { + const key = Reflect.ownKeys({ [callback(value, index, source)]: null })[0]; + if (key in target) { + target[key].push(value); + } else { + target[key] = [value]; + } + }); + + return target; +}; + +export const makeSummer = () => { + /** @type {Map} */ + const sumDatas = new Map(); + let weights = 0; + let values = 0; + + /** + * + * @param {Record} obj + * @param {number} [weight] + */ + const add = (obj, weight = 1) => { + values += 1; + weights += weight; + for (const [key, value] of Object.entries(obj)) { + let sumData = sumDatas.get(key); + if (!sumData) { + sumData = { + min: NaN, + max: NaN, + values: 0, + weights: 0, + total: 0, + }; + sumDatas.set(key, sumData); + } + if (value != null && !Number.isNaN(value)) { + sumData.values += 1; + sumData.weights += weight; + sumData.total += value * weight; + if (!(value > sumData.min)) { + sumData.min = value; + } + if (!(value < sumData.max)) { + sumData.max = value; + } + } + } + }; + + const getSums = () => { + const items = /** @type {Record} */ ({}); + const mins = /** @type {Record} */ ({}); + const maxes = /** @type {Record} */ ({}); + const totals = /** @type {Record} */ ({}); + const counts = /** @type {Record} */ ({}); + const averages = /** @type {Record} */ ({}); + + for (const [key, sumData] of sumDatas.entries()) { + items[key] = sumData.values; + mins[key] = sumData.min; + maxes[key] = sumData.max; + totals[key] = sumData.total; + counts[key] = sumData.weights; + averages[key] = sumData.total / sumData.weights; + } + + return harden({ + values, + weights, + items, + mins, + maxes, + totals, + counts, + averages, + }); + }; + + return harden({ add, getSums }); +}; diff --git a/runner/lib/stats/run.js b/runner/lib/stats/run.js index 24075c0..c6a126a 100644 --- a/runner/lib/stats/run.js +++ b/runner/lib/stats/run.js @@ -1,5 +1,7 @@ /* eslint-disable prefer-object-spread */ +import { makeBlockStatsSummary } from './blocks.js'; +import { makeCycleStatsSummary } from './cycles.js'; import { makeRawStats, makeStatsCollection, @@ -7,6 +9,7 @@ import { cloneData, copyProperties, rounder, + makeSummer, } from './helpers.js'; import { makeStageStats } from './stages.js'; @@ -22,6 +25,9 @@ import { makeStageStats } from './stages.js'; * 'walletDeployEndedAt' | * 'loadgenDeployStartedAt' | * 'loadgenDeployEndedAt' | + * 'totalBlockCount' | + * 'liveBlocksSummary' | + * 'cyclesSummary' | * never} RawRunStatsProps */ @@ -33,8 +39,33 @@ const rawRunStatsInit = { walletDeployEndedAt: null, loadgenDeployStartedAt: null, loadgenDeployEndedAt: null, + totalBlockCount: { default: 0, writeMulti: true }, + liveBlocksSummary: { writeMulti: true }, + cyclesSummary: { writeMulti: true }, }; +/** @param {import('./types.js').BlockStatsSummary} blockStatsSummary */ +const blockSummerTransform = ({ + liveMode, + startBlockHeight, + endBlockHeight, +}) => ({ + liveMode: liveMode !== undefined ? Number(liveMode) : undefined, + startBlockHeight, + endBlockHeight, +}); + +/** @param {import('./types.js').CycleStatsSummary} cycleStatsSummary */ +const cyclesSummerTransform = ({ + cycleSuccessRate, + avgBlockCount, + avgDuration, +}) => ({ + success: cycleSuccessRate / 100, + blockCount: avgBlockCount, + duration: avgDuration, +}); + /** * @param {RunStatsInitData} data * @returns {RunStats} @@ -51,29 +82,87 @@ export const makeRunStats = (data) => { getCount: getStageCount, } = makeStatsCollection(); + const getCyclesSummary = () => { + /** @type {import("./helpers.js").Summer>} */ + const summer = makeSummer(); + + for (const { + cyclesSummaries: { all: stageCyclesSummary = undefined } = {}, + } of /** @type {StageStats[]} */ (Object.values(stages))) { + if (stageCyclesSummary) { + summer.add( + cyclesSummerTransform(stageCyclesSummary), + stageCyclesSummary.cycleCount, + ); + } + } + + return makeCycleStatsSummary(summer.getSums()); + }; + + const getLiveBlocksSummary = () => { + /** @type {import("./helpers.js").Summer>} */ + const summer = makeSummer(); + + for (const { + blocksSummaries: { onlyLive: stageLiveBlocksSummary = undefined } = {}, + } of /** @type {StageStats[]} */ (Object.values(stages))) { + if (stageLiveBlocksSummary) { + summer.add( + blockSummerTransform(stageLiveBlocksSummary), + stageLiveBlocksSummary.blockCount, + ); + } + } + + return makeBlockStatsSummary(summer.getSums()); + }; + + const getTotalBlockCount = () => { + let blockCount = 0; + + for (const { + blocksSummaries: { all: stageAllBlocksSummary = undefined } = {}, + } of /** @type {StageStats[]} */ (Object.values(stages))) { + if (stageAllBlocksSummary) { + blockCount += stageAllBlocksSummary.blockCount; + } + } + + return blockCount; + }; + + const updateSummaries = () => { + privateSetters.cyclesSummary(getCyclesSummary()); + privateSetters.liveBlocksSummary(getLiveBlocksSummary()); + privateSetters.totalBlockCount(getTotalBlockCount()); + }; + + /** @type {RunStats['recordEnd']} */ + const recordEnd = (time) => { + privateSetters.endedAt(time); + + updateSummaries(); + }; + /** @type {RunStats['newStage']} */ const newStage = (stageData) => { const { stageIndex } = stageData; assert(stageIndex === getStageCount()); - const stageStats = makeStageStats(stageData); + updateSummaries(); + + const stageStats = makeStageStats({ + ...stageData, + previousCycleCount: publicProps.cyclesSummary + ? publicProps.cyclesSummary.cycleCount + : 0, + }); insertStage(stageIndex, stageStats); return stageStats; }; - const getBlockCount = () => - Object.values(stages).reduce( - (acc, stage) => acc + (stage ? stage.blockCount : 0), - 0, - ); - - const getCycleCount = () => - Object.values(stages).reduce( - (acc, stage) => acc + (stage ? stage.cycleCount : 0), - 0, - ); - const getDuration = () => savedData.startedAt && savedData.endedAt && @@ -93,7 +182,7 @@ export const makeRunStats = (data) => { copyProperties( { recordStart: privateSetters.startedAt, - recordEnd: privateSetters.endedAt, + recordEnd, recordWalletDeployStart: privateSetters.walletDeployStartedAt, recordWalletDeployEnd: privateSetters.walletDeployEndedAt, recordLoadgenDeployStart: privateSetters.loadgenDeployStartedAt, @@ -105,8 +194,6 @@ export const makeRunStats = (data) => { makeGetters({ stages: () => stages, stageCount: getStageCount, - blockCount: getBlockCount, - cycleCount: getCycleCount, duration: getDuration, walletDeployDuration: getWalletDeployDuration, loadgenDeployDuration: getLoadgenDeployDuration, diff --git a/runner/lib/stats/stages.js b/runner/lib/stats/stages.js index f3c078e..143de5b 100644 --- a/runner/lib/stats/stages.js +++ b/runner/lib/stats/stages.js @@ -7,9 +7,15 @@ import { makeGetters, copyProperties, rounder, + arrayGroupBy, + makeSummer, } from './helpers.js'; -import { makeBlockStats } from './blocks.js'; -import { makeCycleStats, makeCycleStatsKey } from './cycles.js'; +import { makeBlockStats, makeBlockStatsSummary } from './blocks.js'; +import { + makeCycleStats, + makeCycleStatsKey, + makeCycleStatsSummary, +} from './cycles.js'; /** @typedef {import("./types.js").BlockStats} BlockStats */ /** @typedef {import("./types.js").CycleStats} CycleStats */ @@ -19,6 +25,8 @@ import { makeCycleStats, makeCycleStatsKey } from './cycles.js'; /** * @typedef {| + * 'blocksSummaries' | + * 'cyclesSummaries' | * 'firstBlockHeight' | * 'lastBlockHeight' | * 'startedAt' | @@ -35,6 +43,8 @@ import { makeCycleStats, makeCycleStatsKey } from './cycles.js'; /** @type {import('./helpers.js').RawStatInit} */ const rawStageStatsInit = { + blocksSummaries: null, + cyclesSummaries: null, firstBlockHeight: null, lastBlockHeight: { writeMulti: true, @@ -50,6 +60,51 @@ const rawStageStatsInit = { loadgenReadyAt: null, }; +/** @param {BlockStats} blockStats */ +const blockSummerTransform = ({ blockHeight, liveMode }) => ({ + liveMode: liveMode !== undefined ? Number(liveMode) : undefined, + startBlockHeight: blockHeight, + endBlockHeight: blockHeight, +}); + +/** @param {CycleStats} cycleStats */ +const cyclesSummerTransform = ({ success, blockCount, duration }) => ({ + success: Number(success), + blockCount: blockCount || 0, + duration: duration || 0, +}); + +/** + * @param {BlockStats[] | undefined} blocks + */ +const generateBlocksSummary = (blocks = []) => { + /** @type {import("./helpers.js").Summer>} */ + const summer = makeSummer(); + + for (const stats of blocks) { + summer.add(blockSummerTransform(stats)); + } + + return makeBlockStatsSummary(summer.getSums()); +}; + +/** + * @param {CycleStats[] | undefined} cycles + */ +const generateCyclesSummary = (cycles = []) => { + /** @type {import("./helpers.js").Summer>} */ + const summer = makeSummer(); + + for (const stats of cycles) { + // Ignore unfinished cycles + if (stats.success !== undefined) { + summer.add(cyclesSummerTransform(stats)); + } + } + + return makeCycleStatsSummary(summer.getSums()); +}; + /** * @param {StageStatsInitData} data * @returns {StageStats} @@ -101,6 +156,72 @@ export const makeStageStats = (data) => { return cycle; }; + const getCyclesSummaries = () => { + /** + * @type {import('./helpers.js').MakeStatsCollectionReturnType< + * string, + * import('./types.js').CycleStatsSummary | undefined + * >} + */ + const { + collection: cyclesSummaries, + insert: setCyclesSummary, + } = makeStatsCollection(); + + const allCycles = /** @type {CycleStats[]} */ (Object.values(cycles)); + + const cyclesByTask = arrayGroupBy(allCycles, ({ task }) => task); + + setCyclesSummary('all', generateCyclesSummary(allCycles)); + + for (const [task, taskCycles] of Object.entries(cyclesByTask)) { + setCyclesSummary(task, generateCyclesSummary(taskCycles)); + } + + return cyclesSummaries; + }; + + const getBlocksSummaries = () => { + /** + * @type {import('./helpers.js').MakeStatsCollectionReturnType< + * import('./types.js').StageBlocksSummaryType, + * import('./types.js').BlockStatsSummary | undefined + * >} + */ + const { + collection: blocksSummaries, + insert: setBlocksSummary, + } = makeStatsCollection(); + + const allBlocks = /** @type {BlockStats[]} */ (Object.values(blocks)); + + const blocksByLiveMode = arrayGroupBy(allBlocks, ({ liveMode }) => + String(liveMode), + ); + + setBlocksSummary('all', generateBlocksSummary(allBlocks)); + setBlocksSummary('last100', generateBlocksSummary(allBlocks.slice(-100))); + setBlocksSummary('onlyLive', generateBlocksSummary(blocksByLiveMode.true)); + setBlocksSummary( + 'onlyCatchup', + generateBlocksSummary(blocksByLiveMode.false), + ); + + return blocksSummaries; + }; + + /** @type {StageStats['recordEnd']} */ + const recordEnd = (time) => { + privateSetters.endedAt(time); + + privateSetters.cyclesSummaries( + getCycleCount() ? getCyclesSummaries() : undefined, + ); + privateSetters.blocksSummaries( + getBlockCount() ? getBlocksSummaries() : undefined, + ); + }; + const getReadyDuration = () => savedData.startedAt && savedData.readyAt && @@ -131,7 +252,7 @@ export const makeStageStats = (data) => { { recordStart: privateSetters.startedAt, recordReady: privateSetters.readyAt, - recordEnd: privateSetters.endedAt, + recordEnd, recordChainStart: privateSetters.chainStartedAt, recordChainReady: privateSetters.chainReadyAt, recordClientStart: privateSetters.clientStartedAt, diff --git a/runner/lib/stats/types.d.ts b/runner/lib/stats/types.d.ts index e9aff29..17830c8 100644 --- a/runner/lib/stats/types.d.ts +++ b/runner/lib/stats/types.d.ts @@ -23,6 +23,13 @@ export interface BlockStats extends BlockStatsInitData { readonly liveMode: boolean | undefined; } +export type BlockStatsSummary = { + readonly liveMode: boolean | undefined; + readonly startBlockHeight: number; + readonly endBlockHeight: number; + readonly blockCount: number; +}; + export interface CycleStatsInitData { readonly task: string; readonly seq: number; @@ -42,11 +49,25 @@ export interface CycleStats extends CycleStatsInitData { readonly duration: number | undefined; } +export type CycleStatsSummary = { + readonly cycleCount: number; + readonly avgBlockCount: number; + readonly avgDuration: number; + readonly cycleSuccessRate: number; +}; + export interface StageStatsInitData { readonly stageConfig: Readonly>; readonly stageIndex: number; + readonly previousCycleCount: number; } +export type StageBlocksSummaryType = + | 'all' + | 'onlyLive' + | 'onlyCatchup' + | 'last100'; + export interface StageStats extends StageStatsInitData { recordStart(time: TimeValueS): void; recordReady(time: TimeValueS): void; @@ -63,6 +84,12 @@ export interface StageStats extends StageStatsInitData { readonly blockCount: number; readonly cycles: StatsCollection; readonly cycleCount: number; + readonly blocksSummaries: + | StatsCollection + | undefined; + readonly cyclesSummaries: + | StatsCollection<'all' | string, CycleStatsSummary | undefined> + | undefined; readonly firstBlockHeight: number | undefined; readonly lastBlockHeight: number | undefined; readonly startedAt: TimeValueS | undefined; @@ -95,15 +122,16 @@ export interface RunStatsInitData { export interface RunStats extends RunStatsInitData { recordStart(time: TimeValueS): void; recordEnd(time: TimeValueS): void; - newStage(data: StageStatsInitData): StageStats; + newStage(data: Omit): StageStats; recordWalletDeployStart(time: TimeValueS): void; recordWalletDeployEnd(time: TimeValueS): void; recordLoadgenDeployStart(time: TimeValueS): void; recordLoadgenDeployEnd(time: TimeValueS): void; readonly stages: StatsCollection; readonly stageCount: number; - readonly blockCount: number; - readonly cycleCount: number; + readonly totalBlockCount: number; + readonly liveBlocksSummary: BlockStatsSummary | undefined; + readonly cyclesSummary: CycleStatsSummary | undefined; readonly startedAt: TimeValueS | undefined; readonly endedAt: TimeValueS | undefined; readonly duration: number | undefined; From 6ff64f6aa65a2917a9673340e0bce267abec2033 Mon Sep 17 00:00:00 2001 From: Mathieu Hofman Date: Mon, 17 Jan 2022 21:55:33 +0000 Subject: [PATCH 9/9] feat(runner): Add more Block stats --- runner/lib/monitor/slog-monitor.js | 27 ++++-- runner/lib/stats/blocks.js | 136 ++++++++++++++++++++++++++--- runner/lib/stats/run.js | 22 +++++ runner/lib/stats/stages.js | 27 +++++- runner/lib/stats/types.d.ts | 44 +++++++++- 5 files changed, 234 insertions(+), 22 deletions(-) diff --git a/runner/lib/monitor/slog-monitor.js b/runner/lib/monitor/slog-monitor.js index 2fc9c65..a05b48b 100644 --- a/runner/lib/monitor/slog-monitor.js +++ b/runner/lib/monitor/slog-monitor.js @@ -230,7 +230,7 @@ export const monitorSlog = async ( break; } case 'cosmic-swingset-begin-block': { - const { blockHeight = 0 } = event; + const { time, blockHeight = 0, blockTime } = event; if (!stats.blockCount) { logPerfEvent('stage-first-block', { block: blockHeight }); if (chainMonitor) { @@ -241,8 +241,8 @@ export const monitorSlog = async ( eventRE = activeEventRE; } console.log('begin-block', blockHeight); - block = stats.newBlock({ blockHeight }); - block.recordStart(); + block = stats.newBlock({ blockHeight, blockTime }); + block.recordStart(time); break; } case 'cosmic-swingset-end-block-start': { @@ -252,9 +252,9 @@ export const monitorSlog = async ( // However in that case there is no begin-block logPerfEvent('chain-first-init-start'); } else { - const { blockHeight = 0 } = event; + const { time, blockHeight = 0 } = event; assert(block.blockHeight === blockHeight); - block.recordSwingsetStart(); + block.recordSwingsetStart(time); } break; } @@ -264,10 +264,10 @@ export const monitorSlog = async ( logPerfEvent('chain-first-init-finish'); eventRE = activeEventRE; } else { - const { blockHeight = 0 } = event; + const { time, blockHeight = 0 } = event; assert(block.blockHeight === blockHeight); - block.recordEnd(); + block.recordEnd(time); notifier && notifier.blockDone(block); console.log( @@ -284,6 +284,19 @@ export const monitorSlog = async ( break; } case 'deliver-result': { + if (block) { + let computrons; + const { + crankNum, + deliveryNum, + vatID, + dr: [, , usage], + } = event; + if (usage && typeof usage === 'object' && 'compute' in usage) { + computrons = usage.compute; + } + block.recordDelivery({ crankNum, deliveryNum, vatID, computrons }); + } break; } default: { diff --git a/runner/lib/stats/blocks.js b/runner/lib/stats/blocks.js index cb26413..d4b2f96 100644 --- a/runner/lib/stats/blocks.js +++ b/runner/lib/stats/blocks.js @@ -1,24 +1,62 @@ /* eslint-disable prefer-object-spread */ -import { makeRawStats, cloneData, copyProperties } from './helpers.js'; +import { + makeRawStats, + cloneData, + copyProperties, + rounder as timeRounder, + percentageRounder, +} from './helpers.js'; /** @typedef {import("./types.js").BlockStatsInitData} BlockStatsInitData */ /** @typedef {import("./types.js").BlockStats} BlockStats */ /** * @typedef {| - * 'slogLines' | * 'liveMode' | + * 'beginAt' | + * 'endStartAt' | + * 'endFinishAt' | + * 'slogLines' | + * 'deliveries' | + * 'firstCrankNum' | + * 'lastCrankNum' | + * 'computrons' | + * 'lag' | + * 'blockDuration' | + * 'chainBlockDuration' | + * 'idleTime' | + * 'cosmosTime' | + * 'swingsetTime' | + * 'processingTime' | + * 'swingsetPercentage' | + * 'processingPercentage' | * never} RawBlockStatsProps */ /** @type {import('./helpers.js').RawStatInit} */ const rawBlockStatsInit = { + liveMode: null, + beginAt: null, + endStartAt: null, + endFinishAt: null, slogLines: { default: -Infinity, writeMulti: true, }, - liveMode: null, + deliveries: { default: 0, writeMulti: true }, + firstCrankNum: null, + lastCrankNum: { writeMulti: true }, + computrons: { default: 0, writeMulti: true }, + lag: null, + blockDuration: null, + chainBlockDuration: null, + idleTime: null, + cosmosTime: null, + swingsetTime: null, + processingTime: null, + swingsetPercentage: null, + processingPercentage: null, }; /** @@ -26,6 +64,17 @@ const rawBlockStatsInit = { * 'liveMode' | * 'startBlockHeight' | * 'endBlockHeight' | + * 'lag' | + * 'blockDuration' | + * 'chainBlockDuration' | + * 'idleTime' | + * 'cosmosTime' | + * 'swingsetTime' | + * 'processingTime' | + * 'swingsetPercentage' | + * 'processingPercentage' | + * 'deliveries' | + * 'computrons' | * never} BlockStatsSumKeys */ @@ -36,6 +85,7 @@ const rawBlockStatsInit = { export const makeBlockStatsSummary = ({ values, weights: blockCount, + averages, totals, items, mins, @@ -51,6 +101,21 @@ export const makeBlockStatsSummary = ({ : undefined), startBlockHeight: mins.startBlockHeight, endBlockHeight: maxes.endBlockHeight, + avgLag: timeRounder(averages.lag), + avgBlockDuration: timeRounder(averages.blockDuration), + avgChainBlockDuration: timeRounder(averages.chainBlockDuration), + avgIdleTime: timeRounder(averages.idleTime), + avgCosmosTime: timeRounder(averages.cosmosTime), + avgSwingsetTime: timeRounder(averages.swingsetTime), + avgProcessingTime: timeRounder(averages.processingTime), + avgDeliveries: timeRounder(averages.deliveries), + avgComputrons: timeRounder(averages.computrons), + avgSwingsetPercentage: percentageRounder( + averages.swingsetPercentage / 100, + ), + avgProcessingPercentage: percentageRounder( + averages.processingPercentage / 100, + ), } : undefined; @@ -62,13 +127,27 @@ export const makeBlockStatsSummary = ({ export const makeBlockStats = (data, stageStats) => { const { publicProps, privateSetters } = makeRawStats(rawBlockStatsInit); - /** @type {BlockStats['recordStart']} */ - const recordStart = () => {}; + const prevBlock = stageStats && stageStats.blocks[data.blockHeight - 1]; - let ended = false; + privateSetters.chainBlockDuration( + prevBlock && data.blockTime - prevBlock.blockTime, + ); + + /** @type {BlockStats['recordStart']} */ + const recordStart = (time) => { + privateSetters.beginAt(time); + privateSetters.lag(timeRounder(time - data.blockTime)); + const prevBlockEndFinishAt = prevBlock && prevBlock.endFinishAt; + privateSetters.idleTime( + prevBlockEndFinishAt && timeRounder(time - prevBlockEndFinishAt), + ); + }; /** @type {BlockStats['recordSwingsetStart']} */ - const recordSwingsetStart = () => { + const recordSwingsetStart = (time) => { + privateSetters.endStartAt(time); + const { beginAt } = publicProps; + privateSetters.cosmosTime(beginAt && timeRounder(time - beginAt)); privateSetters.slogLines(0); if (stageStats) { privateSetters.liveMode(stageStats.chainReadyAt != null); @@ -77,16 +156,52 @@ export const makeBlockStats = (data, stageStats) => { /** @type {BlockStats['recordSlogLine']} */ const recordSlogLine = () => { - if (!ended) { + if (publicProps.endFinishAt === undefined) { privateSetters.slogLines(publicProps.slogLines + 1); } }; + /** @type {BlockStats['recordDelivery']} */ + const recordDelivery = ({ crankNum, computrons }) => { + privateSetters.deliveries(publicProps.deliveries + 1); + if (publicProps.firstCrankNum === undefined) { + privateSetters.firstCrankNum(crankNum); + } + const { lastCrankNum } = publicProps; + if (lastCrankNum === undefined || lastCrankNum < crankNum) { + privateSetters.lastCrankNum(crankNum); + } + if (computrons !== undefined) { + privateSetters.computrons(publicProps.computrons + computrons); + } + }; + /** @type {BlockStats['recordEnd']} */ - const recordEnd = () => { + const recordEnd = (time) => { + privateSetters.endFinishAt(time); + const { beginAt, endStartAt } = publicProps; + const swingsetTime = endStartAt && time - endStartAt; + const processingTime = beginAt && time - beginAt; + const prevBlockEndFinishAt = prevBlock && prevBlock.endFinishAt; + const blockDuration = prevBlockEndFinishAt && time - prevBlockEndFinishAt; + privateSetters.swingsetTime(swingsetTime && timeRounder(swingsetTime)); + privateSetters.processingTime( + processingTime && timeRounder(processingTime), + ); + privateSetters.blockDuration(blockDuration && timeRounder(blockDuration)); + privateSetters.swingsetPercentage( + swingsetTime && + blockDuration && + percentageRounder(swingsetTime / blockDuration), + ); + privateSetters.processingPercentage( + processingTime && + blockDuration && + percentageRounder(processingTime / blockDuration), + ); + // Finish line itself doesn't count privateSetters.slogLines(publicProps.slogLines - 1); - ended = true; }; const stats = harden( @@ -96,6 +211,7 @@ export const makeBlockStats = (data, stageStats) => { recordEnd, recordSwingsetStart, recordSlogLine, + recordDelivery, }, cloneData(data), publicProps, diff --git a/runner/lib/stats/run.js b/runner/lib/stats/run.js index c6a126a..f2d17c3 100644 --- a/runner/lib/stats/run.js +++ b/runner/lib/stats/run.js @@ -49,10 +49,32 @@ const blockSummerTransform = ({ liveMode, startBlockHeight, endBlockHeight, + avgLag, + avgBlockDuration, + avgChainBlockDuration, + avgIdleTime, + avgCosmosTime, + avgSwingsetTime, + avgProcessingTime, + avgDeliveries, + avgComputrons, + avgSwingsetPercentage, + avgProcessingPercentage, }) => ({ liveMode: liveMode !== undefined ? Number(liveMode) : undefined, startBlockHeight, endBlockHeight, + lag: avgLag, + blockDuration: avgBlockDuration, + chainBlockDuration: avgChainBlockDuration, + idleTime: avgIdleTime, + cosmosTime: avgCosmosTime, + swingsetTime: avgSwingsetTime, + processingTime: avgProcessingTime, + swingsetPercentage: avgSwingsetPercentage, + processingPercentage: avgProcessingPercentage, + deliveries: avgDeliveries, + computrons: avgComputrons, }); /** @param {import('./types.js').CycleStatsSummary} cycleStatsSummary */ diff --git a/runner/lib/stats/stages.js b/runner/lib/stats/stages.js index 143de5b..94dbb7b 100644 --- a/runner/lib/stats/stages.js +++ b/runner/lib/stats/stages.js @@ -61,10 +61,35 @@ const rawStageStatsInit = { }; /** @param {BlockStats} blockStats */ -const blockSummerTransform = ({ blockHeight, liveMode }) => ({ +const blockSummerTransform = ({ + blockHeight, + liveMode, + lag, + blockDuration, + chainBlockDuration, + idleTime, + cosmosTime, + swingsetTime, + processingTime, + swingsetPercentage, + processingPercentage, + deliveries, + computrons, +}) => ({ liveMode: liveMode !== undefined ? Number(liveMode) : undefined, startBlockHeight: blockHeight, endBlockHeight: blockHeight, + lag, + blockDuration, + chainBlockDuration, + idleTime, + cosmosTime, + swingsetTime, + processingTime, + swingsetPercentage, + processingPercentage, + deliveries, + computrons, }); /** @param {CycleStats} cycleStats */ diff --git a/runner/lib/stats/types.d.ts b/runner/lib/stats/types.d.ts index 17830c8..283b734 100644 --- a/runner/lib/stats/types.d.ts +++ b/runner/lib/stats/types.d.ts @@ -12,15 +12,40 @@ export type StatsCollection = { export interface BlockStatsInitData { readonly blockHeight: number; + readonly blockTime: TimeValueS; +} + +export interface BlockDeliveryData { + readonly crankNum: number; + readonly vatID: string; + readonly deliveryNum: number; + readonly computrons?: number | undefined; } export interface BlockStats extends BlockStatsInitData { - recordStart(): void; - recordEnd(): void; - recordSwingsetStart(): void; + recordStart(time: TimeValueS): void; + recordEnd(time: TimeValueS): void; + recordSwingsetStart(time: TimeValueS): void; recordSlogLine(): void; - readonly slogLines: number; + recordDelivery(data: BlockDeliveryData): void; readonly liveMode: boolean | undefined; + readonly beginAt: TimeValueS | undefined; + readonly endStartAt: TimeValueS | undefined; + readonly endFinishAt: TimeValueS | undefined; + readonly lag: number | undefined; // blockTime -> begin + readonly blockDuration: number | undefined; // prev.endFinish -> endFinish + readonly chainBlockDuration: number | undefined; // prev.blockTime -> blockTime + readonly idleTime: number | undefined; // prev.endFinish -> begin + readonly cosmosTime: number | undefined; // begin -> endStart + readonly swingsetTime: number | undefined; // endStart -> endFinish + readonly processingTime: number | undefined; // cosmosTime + swingsetTime + readonly swingsetPercentage: number | undefined; // swingsetTime / blockDuration + readonly processingPercentage: number | undefined; // processingTime / blockDuration + readonly slogLines: number; + readonly deliveries: number; + readonly firstCrankNum: number | undefined; + readonly lastCrankNum: number | undefined; + readonly computrons: number; } export type BlockStatsSummary = { @@ -28,6 +53,17 @@ export type BlockStatsSummary = { readonly startBlockHeight: number; readonly endBlockHeight: number; readonly blockCount: number; + readonly avgLag: number; + readonly avgBlockDuration: number; + readonly avgChainBlockDuration: number; + readonly avgIdleTime: number; + readonly avgCosmosTime: number; + readonly avgSwingsetTime: number; + readonly avgProcessingTime: number; + readonly avgSwingsetPercentage: number; + readonly avgProcessingPercentage: number; + readonly avgDeliveries: number; + readonly avgComputrons: number; }; export interface CycleStatsInitData {