From a47c69f8a5fc32e0066541b2ae6fd2107434bc69 Mon Sep 17 00:00:00 2001
From: Rhys Arkins <rhys@arkins.net>
Date: Fri, 8 May 2020 10:18:00 +0200
Subject: [PATCH] feat(internal): log timing splits per-repository
---
lib/util/split.spec.ts | 12 ++++++++++++
lib/util/split.ts | 18 ++++++++++++++++++
lib/workers/repository/index.ts | 9 +++++++--
.../repository/process/extract-update.ts | 14 +++++++++++---
lib/workers/repository/process/fetch.ts | 7 ++++---
5 files changed, 52 insertions(+), 8 deletions(-)
create mode 100644 lib/util/split.spec.ts
create mode 100644 lib/util/split.ts
diff --git a/lib/util/split.spec.ts b/lib/util/split.spec.ts
new file mode 100644
index 0000000000..f1f6260bfc
--- /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 0000000000..015f4d165c
--- /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 9e68bbb8d8..7613bb64f2 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 0cd6cc24c7..5a78f3bc1f 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 1b3daef5cc..d1be15d04f 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'
+ );
}
--
GitLab