import { Logger } from '@cirrusct/logging'; import * as mri from 'mri'; import { performance, PerformanceEntry, PerformanceObserver } from 'perf_hooks'; import { MrCliDebugOptions } from './MrCliDebugCliOptions'; import { RequireTimes } from './require-times'; export const dashCase = (base: string) => base.replace(/([a-zA-Z])(?=[A-Z])/g, '$1-').toLowerCase(); const l = (method: string, action: 'start' | 'end' = 'start') => { return `mr-cli.${method}.${action}`; }; export class MrCliDebug { public static get argv(): string[] { return MrCliDebug._argv; } public static markEntry = () => { performance.mark(l('cli', 'start')); MrCliDebug.processDebugCliOptions(); const handleExit = exitCode => { performance.mark(l('cli', 'end')); MrCliDebug._logger.debug({ exitCode: process.exitCode, }); performance.mark('mr-cli:end'); if (exitCode === 0) { MrCliDebug.measure(); // Print perf always for 'debug' log level, OR if mr-cli-debug-perf option set MrCliDebug._logger[MrCliDebug._printPerf ? 'info' : 'debug']( { ...MrCliDebug._measureEntries, }, 'Performance' ); // Generate Require Times Report if option was set if (MrCliDebug._rt) { MrCliDebug._rt.renderReport(MrCliDebug._rtOutputPath, MrCliDebug._logger); } } }; process.on('exit', handleExit); process.on('SIGINT', () => { process.exit(1); }); }; public static setLogger = (logger: Logger) => { MrCliDebug._logger = logger; MrCliDebug.observePerformance(logger); }; // CreateCliProgramDefinition public static markCreateCliProgramDefinitionStart = () => { performance.mark(l('createCliProgramDefinition', 'start')); }; public static markCreateCliProgramDefinitionEnd = () => { performance.mark(l('createCliProgramDefinition', 'end')); }; // StartMrProgram public static markStartMrProgramStart = () => { performance.mark(l('startMrProgram', 'start')); }; public static markStartMrProgramEnd = () => { performance.mark(l('startMrProgram', 'end')); }; // PreParseGlobalOptions public static markPreParseCliOptionsStart = () => { performance.mark(l('preParseCliOptions', 'start')); }; public static markPreParseCliOptionsEnd = () => { performance.mark(l('preParseCliOptions', 'end')); }; // ParseCli public static markParseCliStart = () => { performance.mark(l('parseCli', 'start')); }; public static markParseCliEnd = () => { performance.mark(l('parseCli', 'end')); }; // RunCommand public static markRunCommandStart = () => { performance.mark(l('runCommand', 'start')); }; public static markRunCommandEnd = () => { performance.mark(l('runCommand', 'end')); }; public static measure = () => { const dl = method => `mr-cli ${method}`; const measure = method => performance.measure(dl(method), l(method, 'start'), l(method, 'end')); measure('cli'); measure('createCliProgramDefinition'); measure('startMrProgram'); measure('preParseCliOptions'); measure('runCommand'); measure('parseCli'); }; private static _logger: Logger; private static _measureEntries = {}; private static _rt: RequireTimes; private static _rtOutputPath: string; private static _argv: string[] = process.argv.slice(0); private static _printPerf = false; private static processDebugCliOptions = () => { // processing command line manually to avoid calling into Cli module (and potentially disrupting debug ops) // this is a little ugly as need to account for camel case or dash case option name // all debug options start with same base const optionBaseName = 'cliDebug'; const optionsBaseNameDashed = dashCase(optionBaseName); const parsed = mri(process.argv.slice(2)); // find all options startign with base name and put values into a map with just the suffix representing debug option const mrCliDebugOptions: MrCliDebugOptions = Object.keys(parsed) .filter(o => { return ( o.toLowerCase().startsWith(optionBaseName.toLowerCase()) || o.toLowerCase().startsWith(optionsBaseNameDashed) ); }) .reduce((prev, curr) => { const dashedCaseKey = dashCase( curr.toLowerCase().startsWith(optionBaseName.toLowerCase()) ? curr.substr(optionBaseName.length) : curr.substr(optionsBaseNameDashed.length + 1) ); prev[dashedCaseKey] = parsed[curr]; return prev; }, {}); // Handle Options // Capture Require Times if (mrCliDebugOptions.rt) { MrCliDebug.initRT(mrCliDebugOptions.rt); } if (mrCliDebugOptions.perf) { MrCliDebug._printPerf = true; } }; private static initRT = (outputPath: string | boolean = process.cwd()) => { MrCliDebug._rt = new RequireTimes('mr-cli'); MrCliDebug._rtOutputPath = outputPath === true ? process.cwd() : (outputPath as string); }; private static observePerformance = (logger: Logger) => { const obs = new PerformanceObserver(items => { const data = {}; items.getEntries().forEach(m => { data[m.name] = m.duration; MrCliDebug._measureEntries[m.name] = m.duration; }); }); obs.observe({ entryTypes: ['measure'] }); }; }