feat(http): extend stats (#15104)

lib/util/http/host-rules.spec.ts

@@ -33,6 +33,7 @@ describe('util/http/host-rules', () => {
       hostType: 'npm',
       authType: 'Basic',
       token: 'XXX',
+      timeout: 5000,
     });
 
     hostRules.add({
@@ -80,6 +81,7 @@ describe('util/http/host-rules', () => {
           "authType": "Basic",
         },
         "hostType": "npm",
+        "timeout": 5000,
         "token": "XXX",
       }
     `);

lib/util/http/index.ts

@@ -58,21 +58,38 @@ function applyDefaultHeaders(options: Options): void {
 async function gotRoutine<T>(
   url: string,
   options: GotOptions,
-  requestStats: Partial<RequestStats>
+  requestStats: Omit<RequestStats, 'duration' | 'statusCode'>
 ): Promise<Response<T>> {
   logger.trace({ url, options }, 'got request');
 
-  // Cheat the TS compiler using `as` to pick a specific overload.
-  // Otherwise it doesn't typecheck.
-  const resp = await got<T>(url, { ...options, hooks } as GotJSONOptions);
-  const duration =
-    resp.timings.phases.total ?? /* istanbul ignore next: can't be tested */ 0;
-
-  const httpRequests = memCache.get('http-requests') || [];
-  httpRequests.push({ ...requestStats, duration });
-  memCache.set('http-requests', httpRequests);
+  let duration = 0;
+  let statusCode = 0;
+
+  try {
+    // Cheat the TS compiler using `as` to pick a specific overload.
+    // Otherwise it doesn't typecheck.
+    const resp = await got<T>(url, { ...options, hooks } as GotJSONOptions);
+    statusCode = resp.statusCode;
+    duration =
+      resp.timings.phases.total ??
+      /* istanbul ignore next: can't be tested */ 0;
+    return resp;
+  } catch (error) {
+    if (error instanceof RequestError) {
+      statusCode =
+        error.response?.statusCode ??
+        /* istanbul ignore next: can't be tested */ 0;
+      duration =
+        error.timings?.phases.total ??
+        /* istanbul ignore next: can't be tested */ 0;
+    }
 
-  return resp;
+    throw error;
+  } finally {
+    const httpRequests = memCache.get<RequestStats[]>('http-requests') || [];
+    httpRequests.push({ ...requestStats, duration, statusCode });
+    memCache.set('http-requests', httpRequests);
+  }
 }
 
 export class Http<GetOptions = HttpOptions, PostOptions = HttpPostOptions> {
@@ -143,7 +160,7 @@ export class Http<GetOptions = HttpOptions, PostOptions = HttpPostOptions> {
       const queueTask = (): Promise<Response<T>> => {
         const queueDuration = Date.now() - startTime;
         return gotRoutine(url, options, {
-          method: options.method,
+          method: options.method ?? 'get',
           url,
           queueDuration,
         });

lib/util/http/types.ts

@@ -29,6 +29,7 @@ export interface RequestStats {
   url: string;
   duration: number;
   queueDuration: number;
+  statusCode: number;
 }
 
 export type OutgoingHttpHeaders = Record<string, string | string[] | undefined>;

lib/workers/repository/stats.spec.ts

@@ -1,37 +1,149 @@
-import * as memCache_ from '../../util/cache/memory';
+import { logger, mocked } from '../../../test/util';
+import type { Logger } from '../../logger/types';
+import * as _memCache from '../../util/cache/memory';
+import type { RequestStats } from '../../util/http/types';
 import { printRequestStats } from './stats';
 
 jest.mock('../../util/cache/memory');
 
-const memCache: any = memCache_ as any;
+const memCache = mocked(_memCache);
+const log = logger.logger as jest.Mocked<Logger>;
 
 describe('workers/repository/stats', () => {
   describe('printRequestStats()', () => {
     it('runs', () => {
-      memCache.get = jest.fn(() => [
+      const stats: RequestStats[] = [
         {
           method: 'get',
           url: 'https://api.github.com/api/v3/user',
           duration: 100,
+          queueDuration: 0,
+          statusCode: 200,
         },
         {
           method: 'post',
           url: 'https://api.github.com/graphql',
           duration: 130,
+          queueDuration: 0,
+          statusCode: 401,
         },
         {
           method: 'post',
           url: 'https://api.github.com/graphql',
           duration: 150,
+          queueDuration: 0,
+          statusCode: 200,
+        },
+        {
+          method: 'post',
+          url: 'https://api.github.com/graphql',
+          duration: 20,
+          queueDuration: 10,
+          statusCode: 200,
         },
         {
           method: 'get',
           url: 'https://api.github.com/api/v3/repositories',
           duration: 500,
+          queueDuration: 0,
+          statusCode: 500,
+        },
+        {
+          method: 'get',
+          url: 'https://auth.docker.io',
+          duration: 200,
+          queueDuration: 0,
+          statusCode: 401,
         },
-        { method: 'get', url: 'https://auth.docker.io', duration: 200 },
-      ]);
+      ];
+      memCache.get.mockImplementationOnce(() => stats);
       expect(printRequestStats()).toBeUndefined();
+      expect(log.trace).toHaveBeenCalledOnce();
+      expect(log.debug).toHaveBeenCalledTimes(2);
+      expect(log.trace.mock.calls[0][0]).toMatchInlineSnapshot(`
+        Object {
+          "allRequests": Array [
+            "GET https://api.github.com/api/v3/repositories 500 500 0",
+            "GET https://api.github.com/api/v3/user 200 100 0",
+            "POST https://api.github.com/graphql 401 130 0",
+            "POST https://api.github.com/graphql 200 150 0",
+            "POST https://api.github.com/graphql 200 20 10",
+            "GET https://auth.docker.io 401 200 0",
+          ],
+          "requestHosts": Object {
+            "api.github.com": Array [
+              Object {
+                "duration": 500,
+                "method": "get",
+                "queueDuration": 0,
+                "statusCode": 500,
+                "url": "https://api.github.com/api/v3/repositories",
+              },
+              Object {
+                "duration": 100,
+                "method": "get",
+                "queueDuration": 0,
+                "statusCode": 200,
+                "url": "https://api.github.com/api/v3/user",
+              },
+              Object {
+                "duration": 130,
+                "method": "post",
+                "queueDuration": 0,
+                "statusCode": 401,
+                "url": "https://api.github.com/graphql",
+              },
+              Object {
+                "duration": 150,
+                "method": "post",
+                "queueDuration": 0,
+                "statusCode": 200,
+                "url": "https://api.github.com/graphql",
+              },
+              Object {
+                "duration": 20,
+                "method": "post",
+                "queueDuration": 10,
+                "statusCode": 200,
+                "url": "https://api.github.com/graphql",
+              },
+            ],
+            "auth.docker.io": Array [
+              Object {
+                "duration": 200,
+                "method": "get",
+                "queueDuration": 0,
+                "statusCode": 401,
+                "url": "https://auth.docker.io",
+              },
+            ],
+          },
+        }
+      `);
+      expect(log.debug.mock.calls[1][0]).toMatchInlineSnapshot(`
+        Object {
+          "hostStats": Object {
+            "api.github.com": Object {
+              "queueAvgMs": 2,
+              "requestAvgMs": 180,
+              "requestCount": 5,
+            },
+            "auth.docker.io": Object {
+              "queueAvgMs": 0,
+              "requestAvgMs": 200,
+              "requestCount": 1,
+            },
+          },
+          "totalRequests": 6,
+          "urls": Object {
+            "https://api.github.com/api/v3/repositories (GET,500)": 1,
+            "https://api.github.com/api/v3/user (GET,200)": 1,
+            "https://api.github.com/graphql (POST,200)": 2,
+            "https://api.github.com/graphql (POST,401)": 1,
+            "https://auth.docker.io (GET,401)": 1,
+          },
+        }
+      `);
     });
   });
 });

lib/workers/repository/stats.ts

@@ -22,17 +22,17 @@ export function printRequestStats(): void {
   const requestHosts: Record<string, RequestStats[]> = {};
   const rawUrls: Record<string, number> = {};
   for (const httpRequest of httpRequests) {
-    const { method, url, duration, queueDuration } = httpRequest;
+    const { method, url, duration, queueDuration, statusCode } = httpRequest;
     const [baseUrl] = url.split('?');
     // put method last for better sorting
-    const urlKey = `${baseUrl} (${method.toUpperCase()})`;
+    const urlKey = `${baseUrl} (${method.toUpperCase()},${statusCode})`;
     if (rawUrls[urlKey]) {
       rawUrls[urlKey] += 1;
     } else {
       rawUrls[urlKey] = 1;
     }
     allRequests.push(
-      `${method.toUpperCase()} ${url} ${duration} ${queueDuration}`
+      `${method.toUpperCase()} ${url} ${statusCode} ${duration} ${queueDuration}`
     );
     const { hostname } = URL.parse(url);