diff --git a/lib/util/http/host-rules.spec.ts b/lib/util/http/host-rules.spec.ts index 66412226d5a0bd60bab5f950535efc4258006c7a..7eb7d67ddc05c304b6ece79d5480b38de288fad2 100644 --- a/lib/util/http/host-rules.spec.ts +++ b/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", } `); diff --git a/lib/util/http/index.ts b/lib/util/http/index.ts index c3ae54dd8a3d7f7557a935f8f2eee246d65feafc..8482fa8f0c4550eac65b581bc63e6730665d62e0 100644 --- a/lib/util/http/index.ts +++ b/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, }); diff --git a/lib/util/http/types.ts b/lib/util/http/types.ts index b7f378961af573238badb865e129e841dbccb6cf..7e9a4302ad74ddb32ecadb870572d18e5c39beea 100644 --- a/lib/util/http/types.ts +++ b/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>; diff --git a/lib/workers/repository/stats.spec.ts b/lib/workers/repository/stats.spec.ts index a62796aa981944b6c0ae9ba7d567eff8f99dccb3..4a382991b694be1bd14737d0a420ee73b2abb024 100644 --- a/lib/workers/repository/stats.spec.ts +++ b/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, + }, + } + `); }); }); }); diff --git a/lib/workers/repository/stats.ts b/lib/workers/repository/stats.ts index 8a145ea8b126fd4d27cebe040546e8f4c9662b8b..ac23204b732deb6bade9fd31d28eb0d34062bcb8 100644 --- a/lib/workers/repository/stats.ts +++ b/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);