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 32222fa..b585628 100644 --- a/runner/lib/main.js +++ b/runner/lib/main.js @@ -26,6 +26,8 @@ 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'; /** @typedef {import('./helpers/async.js').Task} Task */ @@ -205,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; @@ -228,6 +232,17 @@ const main = async (progName, rawArgs, powers) => { ); await fsStreamReady(outputStream); + 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 = {}) => { outputStream.write( @@ -247,20 +262,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,16 +291,18 @@ 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'); + stats.recordChainStart(timeSource.getTime()); let chainExited = false; const done = runChainResult.done.finally(() => { @@ -326,20 +344,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 +378,7 @@ const main = async (progName, rawArgs, powers) => { { slogLines }, { ...makeConsole('monitor-slog', out, err), + stats, notifier, chainMonitor, localTimeSource: timeSource, @@ -374,6 +389,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'); @@ -411,9 +427,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(() => { @@ -424,9 +440,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); }, @@ -450,6 +475,7 @@ const main = async (progName, rawArgs, powers) => { stderr: err, config: loadgenConfig, }); + stats.recordLoadgenStart(timeSource.getTime()); logPerfEvent('run-loadgen-finish'); let loadgenExited = false; @@ -458,10 +484,24 @@ 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); + 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); }, @@ -472,6 +512,8 @@ const main = async (progName, rawArgs, powers) => { runLoadgenResult.stop(); await done; } + + await monitorLoadgenDone; }, ); }; @@ -500,6 +542,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'); @@ -530,8 +573,9 @@ const main = async (progName, rawArgs, powers) => { } else { tasks.push(stageReady); } - + stats.recordStart(timeSource.getTime()); await sequential(...tasks)((stop) => stop); + stats.recordEnd(timeSource.getTime()); }, async () => aggregateTryFinally( @@ -554,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; }, ), @@ -565,6 +619,7 @@ const main = async (progName, rawArgs, powers) => { await aggregateTryFinally( async () => { const { console: initConsole, out, err } = makeConsole('init'); + runStats.recordStart(timeSource.getTime()); logPerfEvent('start', { cpuTimeOffset, timeOrigin: timeSource.timeOrigin, @@ -665,10 +720,26 @@ const main = async (progName, rawArgs, powers) => { saveStorage, }); } + + runStats.recordEnd(timeSource.getTime()); }, async () => { + logPerfEvent('finish', { stats: runStats }); + 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/monitor/loadgen-monitor.js b/runner/lib/monitor/loadgen-monitor.js new file mode 100644 index 0000000..5e9b7fe --- /dev/null +++ b/runner/lib/monitor/loadgen-monitor.js @@ -0,0 +1,31 @@ +/** @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) { + 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(time); + break; + } + case 'finish': { + const { task, seq, success } = event; + console.log('finish', event.task, event.seq); + const cycle = stats.getOrMakeCycle({ task, seq }); + cycle.recordEnd(time, success); + break; + } + case 'status': + default: + } + } +}; diff --git a/runner/lib/monitor/slog-monitor.js b/runner/lib/monitor/slog-monitor.js index 6721e36..a05b48b 100644 --- a/runner/lib/monitor/slog-monitor.js +++ b/runner/lib/monitor/slog-monitor.js @@ -3,9 +3,13 @@ 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 */ + /** * @typedef {{ - * time: number, + * time: TimeValueS, * type: 'create-vat', * vatID: string, * name?: string, @@ -16,7 +20,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 +43,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 +95,7 @@ import { warnOnRejection } from '../helpers/async.js'; /** * @typedef { | * SlogVatEvent | + * SlogCosmicSwingsetVatEvent | * SlogCosmicSwingsetBlockEvent * } SlogSupportedEvent */ @@ -81,20 +121,29 @@ 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 * @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] @@ -102,13 +151,15 @@ const slogEventRE = 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; for await (const line of slogLines) { if (slogStart == null && chainMonitor) { @@ -124,12 +175,14 @@ 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, // 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,48 +226,76 @@ export const monitorSlog = async ( } case 'cosmic-swingset-bootstrap-block-finish': { logPerfEvent('chain-first-init-finish'); + eventRE = activeEventRE; break; } case 'cosmic-swingset-begin-block': { - const { blockHeight = 0 } = event; - if (!slogBlocksSeen) { + const { time, blockHeight = 0, blockTime } = event; + if (!stats.blockCount) { logPerfEvent('stage-first-block', { block: blockHeight }); if (chainMonitor) { // 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; + block = stats.newBlock({ blockHeight, blockTime }); + block.recordStart(time); 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 { time, blockHeight = 0 } = event; + assert(block.blockHeight === blockHeight); + block.recordSwingsetStart(time); } 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 }); + const { time, blockHeight = 0 } = event; + + assert(block.blockHeight === blockHeight); + block.recordEnd(time); + notifier && notifier.blockDone(block); console.log( 'end-block', blockHeight, 'linesInBlock=', - slogLinesInBlock, + block.slogLines, ); + block = null; + } + break; + } + case 'deliver': { + 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; } diff --git a/runner/lib/stats/blocks.js b/runner/lib/stats/blocks.js new file mode 100644 index 0000000..d4b2f96 --- /dev/null +++ b/runner/lib/stats/blocks.js @@ -0,0 +1,222 @@ +/* eslint-disable prefer-object-spread */ + +import { + makeRawStats, + cloneData, + copyProperties, + rounder as timeRounder, + percentageRounder, +} from './helpers.js'; + +/** @typedef {import("./types.js").BlockStatsInitData} BlockStatsInitData */ +/** @typedef {import("./types.js").BlockStats} BlockStats */ + +/** + * @typedef {| + * '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, + }, + 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, +}; + +/** + * @typedef {| + * 'liveMode' | + * 'startBlockHeight' | + * 'endBlockHeight' | + * 'lag' | + * 'blockDuration' | + * 'chainBlockDuration' | + * 'idleTime' | + * 'cosmosTime' | + * 'swingsetTime' | + * 'processingTime' | + * 'swingsetPercentage' | + * 'processingPercentage' | + * 'deliveries' | + * 'computrons' | + * never} BlockStatsSumKeys + */ + +/** + * @param {import('./helpers.js').Sums} sums + * @returns {import('./types.js').BlockStatsSummary | undefined} + */ +export const makeBlockStatsSummary = ({ + values, + weights: blockCount, + averages, + totals, + items, + mins, + maxes, +}) => + blockCount + ? { + blockCount, + liveMode: + blockCount === totals.liveMode || + (items.liveMode === values && totals.liveMode === 0 + ? false + : 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; + +/** + * @param {BlockStatsInitData} data + * @param {import("./types.js").StageStats} [stageStats] + * @returns {BlockStats} + */ +export const makeBlockStats = (data, stageStats) => { + const { publicProps, privateSetters } = makeRawStats(rawBlockStatsInit); + + const prevBlock = stageStats && stageStats.blocks[data.blockHeight - 1]; + + 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 = (time) => { + privateSetters.endStartAt(time); + const { beginAt } = publicProps; + privateSetters.cosmosTime(beginAt && timeRounder(time - beginAt)); + privateSetters.slogLines(0); + if (stageStats) { + privateSetters.liveMode(stageStats.chainReadyAt != null); + } + }; + + /** @type {BlockStats['recordSlogLine']} */ + const recordSlogLine = () => { + 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 = (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); + }; + + const stats = harden( + copyProperties( + { + recordStart, + recordEnd, + recordSwingsetStart, + recordSlogLine, + recordDelivery, + }, + cloneData(data), + publicProps, + ), + ); + + return stats; +}; diff --git a/runner/lib/stats/cycles.js b/runner/lib/stats/cycles.js new file mode 100644 index 0000000..24b133d --- /dev/null +++ b/runner/lib/stats/cycles.js @@ -0,0 +1,106 @@ +/* eslint-disable prefer-object-spread */ + +import { + makeRawStats, + makeGetters, + cloneData, + copyProperties, + rounder, + percentageRounder, +} 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' | + * 'startedAt' | + * 'endedAt' | + * never} RawCycleStatsProps + */ + +/** @type {import('./helpers.js').RawStatInit} */ +const rawCycleStatsInit = { + success: null, + startBlockHeight: null, + endBlockHeight: null, + startedAt: null, + 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} + */ +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 = (time) => { + privateSetters.startedAt(time); + if (stageStats) { + privateSetters.startBlockHeight(stageStats.lastBlockHeight); + } + }; + + /** @type {CycleStats['recordEnd']} */ + const recordEnd = (time, successResult) => { + privateSetters.endedAt(time); + if (stageStats) { + privateSetters.endBlockHeight(stageStats.lastBlockHeight); + } + assert(typeof successResult === 'boolean'); + privateSetters.success(successResult); + }; + + const getBlockCount = () => + savedData.startBlockHeight && + savedData.endBlockHeight && + savedData.endBlockHeight - savedData.startBlockHeight; + + const getDuration = () => + savedData.startedAt && + savedData.endedAt && + rounder(savedData.endedAt - savedData.startedAt); + + return harden( + copyProperties( + { + recordStart, + recordEnd, + }, + cloneData(data), + publicProps, + makeGetters({ blockCount: getBlockCount, duration: getDuration }), + ), + ); +}; diff --git a/runner/lib/stats/helpers.d.ts b/runner/lib/stats/helpers.d.ts new file mode 100644 index 0000000..0019412 --- /dev/null +++ b/runner/lib/stats/helpers.d.ts @@ -0,0 +1,107 @@ +/* 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 const percentageRounder: (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; + +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 new file mode 100644 index 0000000..b6e6535 --- /dev/null +++ b/runner/lib/stats/helpers.js @@ -0,0 +1,218 @@ +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); +export const percentageRounder = makeRounder(2, -2); + +/** + * 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)), + ), + ); + +/** + * + * @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 new file mode 100644 index 0000000..f2d17c3 --- /dev/null +++ b/runner/lib/stats/run.js @@ -0,0 +1,227 @@ +/* eslint-disable prefer-object-spread */ + +import { makeBlockStatsSummary } from './blocks.js'; +import { makeCycleStatsSummary } from './cycles.js'; +import { + makeRawStats, + makeStatsCollection, + makeGetters, + cloneData, + copyProperties, + rounder, + makeSummer, +} 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 {| + * 'startedAt' | + * 'endedAt' | + * 'walletDeployStartedAt' | + * 'walletDeployEndedAt' | + * 'loadgenDeployStartedAt' | + * 'loadgenDeployEndedAt' | + * 'totalBlockCount' | + * 'liveBlocksSummary' | + * 'cyclesSummary' | + * never} RawRunStatsProps + */ + +/** @type {import('./helpers.js').RawStatInit} */ +const rawRunStatsInit = { + startedAt: null, + endedAt: null, + walletDeployStartedAt: null, + 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, + 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 */ +const cyclesSummerTransform = ({ + cycleSuccessRate, + avgBlockCount, + avgDuration, +}) => ({ + success: cycleSuccessRate / 100, + blockCount: avgBlockCount, + duration: avgDuration, +}); + +/** + * @param {RunStatsInitData} data + * @returns {RunStats} + */ +export const makeRunStats = (data) => { + const { savedData, publicProps, privateSetters } = makeRawStats( + rawRunStatsInit, + ); + + /** @type {import("./helpers.js").MakeStatsCollectionReturnType} */ + const { + collection: stages, + insert: insertStage, + 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()); + + updateSummaries(); + + const stageStats = makeStageStats({ + ...stageData, + previousCycleCount: publicProps.cyclesSummary + ? publicProps.cyclesSummary.cycleCount + : 0, + }); + insertStage(stageIndex, stageStats); + return stageStats; + }; + + 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: privateSetters.startedAt, + recordEnd, + recordWalletDeployStart: privateSetters.walletDeployStartedAt, + recordWalletDeployEnd: privateSetters.walletDeployEndedAt, + recordLoadgenDeployStart: privateSetters.loadgenDeployStartedAt, + recordLoadgenDeployEnd: privateSetters.loadgenDeployEndedAt, + newStage, + }, + cloneData(data), + publicProps, + makeGetters({ + stages: () => stages, + stageCount: getStageCount, + duration: getDuration, + walletDeployDuration: getWalletDeployDuration, + loadgenDeployDuration: getLoadgenDeployDuration, + }), + ), + ); + + return stats; +}; diff --git a/runner/lib/stats/stages.js b/runner/lib/stats/stages.js new file mode 100644 index 0000000..94dbb7b --- /dev/null +++ b/runner/lib/stats/stages.js @@ -0,0 +1,307 @@ +/* eslint-disable prefer-object-spread */ + +import { + makeRawStats, + makeStatsCollection, + cloneData, + makeGetters, + copyProperties, + rounder, + arrayGroupBy, + makeSummer, +} from './helpers.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 */ +/** @typedef {import("./types.js").CycleStatsCollectionKey} CycleStatsCollectionKey */ +/** @typedef {import("./types.js").StageStatsInitData} StageStatsInitData */ +/** @typedef {import("./types.js").StageStats} StageStats */ + +/** + * @typedef {| + * 'blocksSummaries' | + * 'cyclesSummaries' | + * 'firstBlockHeight' | + * 'lastBlockHeight' | + * 'startedAt' | + * 'readyAt' | + * 'endedAt' | + * 'chainStartedAt' | + * 'chainReadyAt' | + * 'clientStartedAt' | + * 'clientReadyAt' | + * 'loadgenStartedAt' | + * 'loadgenReadyAt' | + * never } RawStageStatsProps + */ + +/** @type {import('./helpers.js').RawStatInit} */ +const rawStageStatsInit = { + blocksSummaries: null, + cyclesSummaries: null, + firstBlockHeight: null, + lastBlockHeight: { + writeMulti: true, + }, + startedAt: null, + readyAt: null, + endedAt: null, + chainStartedAt: null, + chainReadyAt: null, + clientStartedAt: null, + clientReadyAt: null, + loadgenStartedAt: null, + loadgenReadyAt: null, +}; + +/** @param {BlockStats} blockStats */ +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 */ +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} + */ +export const makeStageStats = (data) => { + const { savedData, publicProps, privateSetters } = makeRawStats( + rawStageStatsInit, + ); + + /** @type {import("./helpers.js").MakeStatsCollectionReturnType} */ + const { + collection: blocks, + insert: insertBlock, + 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; + + assert(blockHeight); + + if (!getBlockCount()) { + privateSetters.firstBlockHeight(blockHeight); + } + privateSetters.lastBlockHeight(blockHeight); + // eslint-disable-next-line no-use-before-define + const block = makeBlockStats(blockData, stats); + insertBlock(blockHeight, block); + 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 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 && + 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: privateSetters.startedAt, + recordReady: privateSetters.readyAt, + recordEnd, + recordChainStart: privateSetters.chainStartedAt, + recordChainReady: privateSetters.chainReadyAt, + recordClientStart: privateSetters.clientStartedAt, + recordClientReady: privateSetters.clientReadyAt, + recordLoadgenStart: privateSetters.loadgenStartedAt, + recordLoadgenReady: privateSetters.loadgenReadyAt, + newBlock, + getOrMakeCycle, + }, + cloneData(data), + publicProps, + makeGetters({ + blocks: () => blocks, + cycles: () => cycles, + blockCount: getBlockCount, + cycleCount: getCycleCount, + readyDuration: getReadyDuration, + duration: getDuration, + chainInitDuration: getChainInitDuration, + clientInitDuration: getClientInitDuration, + loadgenInitDuration: getLoadgenInitDuration, + }), + ), + ); + + return stats; +}; diff --git a/runner/lib/stats/types.d.ts b/runner/lib/stats/types.d.ts index 112afb1..283b734 100644 --- a/runner/lib/stats/types.d.ts +++ b/runner/lib/stats/types.d.ts @@ -1,5 +1,180 @@ /* eslint-disable no-unused-vars,no-redeclare */ +import type { TimeValueS } from '../helpers/time.js'; + export interface LogPerfEvent { (eventType: string, data?: Record): void; } + +export type StatsCollection = { + readonly [P in K]?: T; +}; + +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(time: TimeValueS): void; + recordEnd(time: TimeValueS): void; + recordSwingsetStart(time: TimeValueS): void; + recordSlogLine(): void; + 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 = { + readonly liveMode: boolean | undefined; + 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 { + readonly task: string; + readonly seq: number; +} + +export type CycleStatsCollectionKey = `${string}/${number}`; + +export interface CycleStats extends CycleStatsInitData { + 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 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; + 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; + 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; + 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 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; + recordEnd(time: TimeValueS): void; + 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 totalBlockCount: number; + readonly liveBlocksSummary: BlockStatsSummary | undefined; + readonly cyclesSummary: CycleStatsSummary | undefined; + 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; +} 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/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/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 96ca419..13aa163 100644 --- a/runner/lib/tasks/types.d.ts +++ b/runner/lib/tasks/types.d.ts @@ -1,6 +1,12 @@ /* global Buffer */ /* eslint-disable no-unused-vars,no-redeclare */ +import type { TimeValueS } from '../helpers/time.js'; + +export interface EnvInfo { + readonly agChainCosmosVersion?: unknown; +} + export type TaskResult = { readonly stop: () => void; readonly done: Promise; @@ -13,7 +19,34 @@ 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; +}; + export type RunChainResult = TaskResult & RunChainInfo; +export type RunLoadgenResult = TaskResult & RunLoadgenInfo; export interface TaskBaseOptions { readonly stdout: import('stream').Writable; @@ -23,8 +56,9 @@ export interface TaskBaseOptions { } export interface OrchestratorTasks { + getEnvInfo(options: TaskBaseOptions): Promise; setupTasks(options: TaskBaseOptions): Promise; runChain(options: TaskBaseOptions): Promise; runClient(options: TaskBaseOptions): Promise; - runLoadgen(options: TaskBaseOptions): Promise; + runLoadgen(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