From a399bbbf522f1a7a2d5dc2804d2b62bd18367a7e Mon Sep 17 00:00:00 2001
From: Rhys Arkins <rhys@arkins.net>
Date: Sat, 13 Jun 2020 08:37:56 +0200
Subject: [PATCH] feat: log host stats per run

Closes #6357
---
 lib/util/http/index.ts               |  8 ++++++
 lib/workers/repository/index.ts      |  2 ++
 lib/workers/repository/stats.spec.ts | 37 ++++++++++++++++++++++++
 lib/workers/repository/stats.ts      | 42 ++++++++++++++++++++++++++++
 4 files changed, 89 insertions(+)
 create mode 100644 lib/workers/repository/stats.spec.ts
 create mode 100644 lib/workers/repository/stats.ts

diff --git a/lib/util/http/index.ts b/lib/util/http/index.ts
index f685aa47f06c22..6358a65eede4a7 100644
--- a/lib/util/http/index.ts
+++ b/lib/util/http/index.ts
@@ -102,11 +102,19 @@ export class Http<GetOptions = HttpOptions, PostOptions = HttpPostOptions> {
         return cloneResponse<T>(await cachedRes);
       }
     }
+    const startTime = Date.now();
     const promisedRes = got(url, options);
     if (options.method === 'get') {
       runCache.set(cacheKey, promisedRes); // always set if it's a get
     }
     const res = await promisedRes;
+    const httpRequests = runCache.get('http-requests') || [];
+    httpRequests.push({
+      method: options.method,
+      url,
+      duration: Date.now() - startTime,
+    });
+    runCache.set('http-requests', httpRequests);
     return cloneResponse<T>(res);
   }
 
diff --git a/lib/workers/repository/index.ts b/lib/workers/repository/index.ts
index da3ef084086631..a7ca533fc5b4cc 100644
--- a/lib/workers/repository/index.ts
+++ b/lib/workers/repository/index.ts
@@ -10,6 +10,7 @@ import { ensureMasterIssue } from './master-issue';
 import { ensureOnboardingPr } from './onboarding/pr';
 import { extractDependencies, updateRepo } from './process';
 import { ProcessResult, processResult } from './result';
+import { printRequestStats } from './stats';
 
 let renovateVersion = 'unknown';
 try {
@@ -55,6 +56,7 @@ export async function renovateRepository(
   }
   const splits = getSplits();
   logger.debug(splits, 'Repository timing splits (milliseconds)');
+  printRequestStats();
   logger.info({ durationMs: splits.total }, 'Repository finished');
   return repoResult;
 }
diff --git a/lib/workers/repository/stats.spec.ts b/lib/workers/repository/stats.spec.ts
new file mode 100644
index 00000000000000..a391efba56c2ae
--- /dev/null
+++ b/lib/workers/repository/stats.spec.ts
@@ -0,0 +1,37 @@
+import * as runCache_ from '../../util/cache/run';
+import { printRequestStats } from './stats';
+
+jest.mock('../../util/cache/run');
+
+const runCache: any = runCache_ as any;
+
+describe('workers/repository/stats', () => {
+  describe('printRequestStats()', () => {
+    it('runs', () => {
+      runCache.get = jest.fn(() => [
+        {
+          method: 'get',
+          url: 'https://api.github.com/api/v3/user',
+          duration: 100,
+        },
+        {
+          method: 'post',
+          url: 'https://api.github.com/graphql',
+          duration: 130,
+        },
+        {
+          method: 'post',
+          url: 'https://api.github.com/graphql',
+          duration: 150,
+        },
+        {
+          method: 'get',
+          url: 'https://api.github.com/api/v3/repositories',
+          duration: 500,
+        },
+        { method: 'get', url: 'https://auth.docker.io', duration: 200 },
+      ]);
+      expect(printRequestStats()).toBeUndefined();
+    });
+  });
+});
diff --git a/lib/workers/repository/stats.ts b/lib/workers/repository/stats.ts
new file mode 100644
index 00000000000000..167a8b659df7b3
--- /dev/null
+++ b/lib/workers/repository/stats.ts
@@ -0,0 +1,42 @@
+import URL from 'url';
+import { logger } from '../../logger';
+import * as runCache from '../../util/cache/run';
+
+export function printRequestStats(): void {
+  const httpRequests = runCache.get('http-requests');
+  if (!httpRequests) {
+    return;
+  }
+  httpRequests.sort((a, b) => {
+    if (a.url === b.url) {
+      return 0;
+    }
+    if (a.url < b.url) {
+      return -1;
+    }
+    return 1;
+  });
+  const allRequests: string[] = [];
+  const requestHosts: Record<string, number[]> = {};
+  for (const request of httpRequests) {
+    allRequests.push(
+      `${request.method.toUpperCase()} ${request.url} ${request.duration}`
+    );
+    const { hostname } = URL.parse(request.url);
+    requestHosts[hostname] = requestHosts[hostname] || [];
+    requestHosts[hostname].push(request.duration);
+  }
+  logger.trace({ allRequests, requestHosts }, 'full stats');
+  const hostStats: string[] = [];
+  let totalRequests = 0;
+  for (const [hostname, requests] of Object.entries(requestHosts)) {
+    const hostRequests = requests.length;
+    totalRequests += hostRequests;
+    const requestSum = requests.reduce((a, b) => a + b, 0);
+    const avg = Math.round(requestSum / hostRequests);
+    const requestCount =
+      `${hostRequests} ` + (hostRequests > 1 ? 'requests' : 'request');
+    hostStats.push(`${hostname}, ${requestCount}, ${avg}ms average`);
+  }
+  logger.debug({ hostStats, totalRequests }, 'http statistics');
+}