diff --git a/lib/util/split.spec.ts b/lib/util/split.spec.ts new file mode 100644 index 0000000000000000000000000000000000000000..f1f6260bfcae16353234933edde193bb7f78c3a9 --- /dev/null +++ b/lib/util/split.spec.ts @@ -0,0 +1,12 @@ +import { addSplit, getSplits, splitInit } from './split'; + +describe('util/split', () => { + it('adds splits and returns results', () => { + splitInit(); + addSplit('one'); + addSplit('two'); + const res = getSplits(); + expect(res.total).toBeDefined(); + expect(Object.keys(res.splits)).toHaveLength(2); + }); +}); diff --git a/lib/util/split.ts b/lib/util/split.ts new file mode 100644 index 0000000000000000000000000000000000000000..015f4d165c7e6798336ea341aa7e6551cd78f8a3 --- /dev/null +++ b/lib/util/split.ts @@ -0,0 +1,18 @@ +let startTime = 0; +let lastTime = 0; +let splits: Record<string, number> = {}; + +export function splitInit(): void { + splits = {}; + startTime = Date.now(); + lastTime = startTime; +} + +export function addSplit(name: string): void { + splits[name] = Date.now() - lastTime; + lastTime = Date.now(); +} + +export function getSplits(): any { + return { splits, total: Date.now() - startTime }; +} diff --git a/lib/workers/repository/index.ts b/lib/workers/repository/index.ts index 9e68bbb8d835d16147ee9ca8187748a69161c1b1..7613bb64f207e19d260761beabeb8bc84bcc6221 100644 --- a/lib/workers/repository/index.ts +++ b/lib/workers/repository/index.ts @@ -3,6 +3,7 @@ import fs from 'fs-extra'; import { RenovateConfig } from '../../config'; import { logger, setMeta } from '../../logger'; import { platform } from '../../platform'; +import { addSplit, getSplits, splitInit } from '../../util/split'; import handleError from './error'; import { finaliseRepo } from './finalise'; import { initRepo } from './init'; @@ -22,7 +23,7 @@ try { export async function renovateRepository( repoConfig: RenovateConfig ): Promise<ProcessResult> { - const startTime = Date.now(); + splitInit(); let config = { ...repoConfig }; setMeta({ repository: config.repository }); logger.info({ renovateVersion }, 'Repository started'); @@ -32,11 +33,13 @@ export async function renovateRepository( await fs.ensureDir(config.localDir); logger.debug('Using localDir: ' + config.localDir); config = await initRepo(config); + addSplit('init'); const { branches, branchList, packageFiles } = await extractDependencies( config ); await ensureOnboardingPr(config, packageFiles, branches); const res = await updateRepo(config, branches, branchList); + addSplit('update'); if (res !== 'automerged') { await ensureMasterIssue(config, branches); } @@ -51,6 +54,8 @@ export async function renovateRepository( if (config.localDir && !config.persistRepoData) { await fs.remove(config.localDir); } - logger.info({ durationMs: Date.now() - startTime }, 'Repository finished'); + const splits = getSplits(); + logger.debug(splits, 'Repository timing splits (milliseconds)'); + logger.info({ durationMs: splits.total }, 'Repository finished'); return repoResult; } diff --git a/lib/workers/repository/process/extract-update.ts b/lib/workers/repository/process/extract-update.ts index 0cd6cc24c76245f8e497401c950a5e244963407a..5a78f3bc1f5337f6ff2870ae965297b4ef6ab607 100644 --- a/lib/workers/repository/process/extract-update.ts +++ b/lib/workers/repository/process/extract-update.ts @@ -1,6 +1,7 @@ import { RenovateConfig } from '../../../config'; import { logger } from '../../../logger'; import { PackageFile } from '../../../manager/common'; +import { addSplit } from '../../../util/split'; import { BranchConfig } from '../../common'; import { extractAllDependencies } from '../extract'; import { branchifyUpgrades } from '../updates/branchify'; @@ -45,16 +46,20 @@ function extractStats(packageFiles: Record<string, PackageFile[]>): any { export async function extract(config: RenovateConfig): Promise<ExtractResult> { logger.debug('extractAndUpdate()'); - const startTime = Date.now(); const packageFiles = await extractAllDependencies(config); - const durationMs = Math.round(Date.now() - startTime); const stats = extractStats(packageFiles); logger.info( - { baseBranch: config.baseBranch, stats, durationMs }, + { baseBranch: config.baseBranch, stats }, `Dependency extraction complete` ); + addSplit( + config.baseBranches?.length ? `extract:${config.baseBranch}` : 'extract' + ); logger.trace({ config: packageFiles }, 'packageFiles'); await fetchUpdates(config, packageFiles); + addSplit( + config.baseBranches?.length ? `lookup:${config.baseBranch}` : 'lookup' + ); logger.debug({ config: packageFiles }, 'packageFiles with updates'); await raiseDeprecationWarnings(config, packageFiles); const { branches, branchList } = await branchifyUpgrades( @@ -62,6 +67,9 @@ export async function extract(config: RenovateConfig): Promise<ExtractResult> { packageFiles ); sortBranches(branches); + addSplit( + config.baseBranches?.length ? `branchify:${config.baseBranch}` : 'branchify' + ); return { branches, branchList, packageFiles }; } diff --git a/lib/workers/repository/process/fetch.ts b/lib/workers/repository/process/fetch.ts index 1b3daef5cc24e21901dd34bba5495460a4af62a0..d1be15d04f7e97fad60f3095e21e8134375c128d 100644 --- a/lib/workers/repository/process/fetch.ts +++ b/lib/workers/repository/process/fetch.ts @@ -114,11 +114,12 @@ export async function fetchUpdates( packageFiles: Record<string, PackageFile[]> ): Promise<void> { const managers = Object.keys(packageFiles); - const startTime = Date.now(); const allManagerJobs = managers.map((manager) => fetchManagerUpdates(config, packageFiles, manager) ); await Promise.all(allManagerJobs); - const durationMs = Math.round(Date.now() - startTime); - logger.info({ durationMs }, 'Package releases lookups complete'); + logger.debug( + { baseBranch: config.baseBranch }, + 'Package releases lookups complete' + ); }