import { logger } from '~test/util.ts'; import * as memCache from './cache/memory/index.ts'; import { AbandonedPackageStats, DatasourceCacheStats, GetDatasourceReleasesStats, GitOperationStats, HttpCacheStats, HttpStats, LookupStats, PackageCacheStats, makeTimingReport, } from './stats.ts'; describe('util/stats', () => { beforeEach(() => { memCache.init(); }); describe('makeTimingReport', () => { it('supports empty data', () => { const res = makeTimingReport([]); expect(res).toEqual({ avgMs: 0, count: 0, maxMs: 0, medianMs: 0, totalMs: 0, }); }); it('supports single data point', () => { const res = makeTimingReport([100]); expect(res).toEqual({ avgMs: 100, count: 1, maxMs: 100, medianMs: 100, totalMs: 100, }); }); it('supports multiple data points', () => { const res = makeTimingReport([100, 200, 400]); expect(res).toEqual({ avgMs: 233, count: 3, maxMs: 400, medianMs: 200, totalMs: 700, }); }); it('does not overflow the call stack for large datasets', () => { const res = makeTimingReport( Array.from({ length: 200_000 }).fill(1), ); expect(res).toEqual({ avgMs: 1, count: 200_000, maxMs: 1, medianMs: 1, totalMs: 200_000, }); }); }); describe('LookupStats', () => { beforeEach(() => { vi.useFakeTimers(); }); afterEach(() => { vi.useRealTimers(); }); it('returns empty report', () => { const res = LookupStats.getReport(); expect(res).toEqual({}); }); it('writes data points', () => { LookupStats.write('npm', 100); LookupStats.write('npm', 200); LookupStats.write('npm', 400); LookupStats.write('docker', 1000); const res = LookupStats.getReport(); expect(res).toEqual({ docker: { avgMs: 1000, count: 1, maxMs: 1000, medianMs: 1000, totalMs: 1000, }, npm: { avgMs: 233, count: 3, maxMs: 400, medianMs: 200, totalMs: 700, }, }); }); it('wraps a function', async () => { const res = await LookupStats.wrap('npm', () => { vi.advanceTimersByTime(100); return Promise.resolve('foo'); }); expect(res).toBe('foo'); expect(LookupStats.getReport()).toEqual({ npm: { avgMs: 100, count: 1, maxMs: 100, medianMs: 100, totalMs: 100, }, }); }); it('logs report', () => { LookupStats.write('npm', 100); LookupStats.write('npm', 200); LookupStats.write('npm', 400); LookupStats.write('docker', 1000); LookupStats.report(); expect(logger.logger.debug).toHaveBeenCalledTimes(1); const [data, msg] = logger.logger.debug.mock.calls[0]; expect(msg).toBe('Lookup statistics'); expect(data).toEqual({ docker: { avgMs: 1000, count: 1, maxMs: 1000, medianMs: 1000, totalMs: 1000, }, npm: { avgMs: 233, count: 3, maxMs: 400, medianMs: 200, totalMs: 700, }, }); }); }); describe('GetDatasourceReleasesStats', () => { beforeEach(() => { vi.useFakeTimers(); }); afterEach(() => { vi.useRealTimers(); }); it('returns empty report', () => { const res = GetDatasourceReleasesStats.getReport(); expect(res).toEqual({ stats: { avgMs: 0, count: 0, maxMs: 0, medianMs: 0, totalMs: 0, }, datasources: {}, }); }); it('writes data points', () => { GetDatasourceReleasesStats.write( 'npm', 'https://registry.npmjs.org', 'lodash', 100, ); GetDatasourceReleasesStats.write( 'npm', 'https://registry.npmjs.org', 'lodash', 200, ); GetDatasourceReleasesStats.write( 'npm', 'https://jfrog.company.com/artifactory', 'foo', 400, ); GetDatasourceReleasesStats.write( 'docker', 'https://registry.docker.com', 'alpine', 1000, ); GetDatasourceReleasesStats.write( 'docker', 'https://registry.docker.com', 'memcached', 2000, ); GetDatasourceReleasesStats.write( 'docker', 'https://registry.docker.com', 'istio/pilot', 3000, ); const res = GetDatasourceReleasesStats.getReport(); expect(res).toEqual({ stats: { avgMs: 1117, count: 6, maxMs: 3000, medianMs: 1000, totalMs: 6700, }, datasources: { npm: { stats: { avgMs: 233, count: 3, maxMs: 400, medianMs: 200, totalMs: 700, }, registryUrls: { 'https://registry.npmjs.org': { stats: { avgMs: 150, count: 2, maxMs: 200, medianMs: 200, totalMs: 300, }, packages: { lodash: { avgMs: 150, count: 2, maxMs: 200, medianMs: 200, totalMs: 300, }, }, }, 'https://jfrog.company.com/artifactory': { stats: { avgMs: 400, count: 1, maxMs: 400, medianMs: 400, totalMs: 400, }, packages: { foo: { avgMs: 400, count: 1, maxMs: 400, medianMs: 400, totalMs: 400, }, }, }, }, }, docker: { stats: { avgMs: 2000, count: 3, maxMs: 3000, medianMs: 2000, totalMs: 6000, }, registryUrls: { 'https://registry.docker.com': { stats: { avgMs: 2000, count: 3, maxMs: 3000, medianMs: 2000, totalMs: 6000, }, packages: { alpine: { avgMs: 1000, count: 1, maxMs: 1000, medianMs: 1000, totalMs: 1000, }, memcached: { avgMs: 2000, count: 1, maxMs: 2000, medianMs: 2000, totalMs: 2000, }, 'istio/pilot': { avgMs: 3000, count: 1, maxMs: 3000, medianMs: 3000, totalMs: 3000, }, }, }, }, }, }, }); }); it('wraps a function', async () => { const res = await GetDatasourceReleasesStats.wrap( 'npm', 'https://registry.npmjs.org', 'lodash', () => { vi.advanceTimersByTime(100); return Promise.resolve('foo'); }, ); expect(res).toBe('foo'); expect(GetDatasourceReleasesStats.getReport()).toEqual({ stats: { avgMs: 100, count: 1, maxMs: 100, medianMs: 100, totalMs: 100, }, datasources: { npm: { stats: { avgMs: 100, count: 1, maxMs: 100, medianMs: 100, totalMs: 100, }, registryUrls: { 'https://registry.npmjs.org': { stats: { avgMs: 100, count: 1, maxMs: 100, medianMs: 100, totalMs: 100, }, packages: { lodash: { avgMs: 100, count: 1, maxMs: 100, medianMs: 100, totalMs: 100, }, }, }, }, }, }, }); }); it('logs report', () => { GetDatasourceReleasesStats.write( 'npm', 'https://registry.npmjs.org', 'lodash', 100, ); GetDatasourceReleasesStats.write( 'npm', 'https://registry.npmjs.org', 'lodash', 200, ); GetDatasourceReleasesStats.write( 'npm', 'https://jfrog.company.com/artifactory', 'foo', 400, ); GetDatasourceReleasesStats.write( 'docker', 'https://registry.docker.com', 'alpine', 1000, ); GetDatasourceReleasesStats.write( 'docker', 'https://registry.docker.com', 'memcached', 2000, ); GetDatasourceReleasesStats.write( 'docker', 'https://registry.docker.com', 'istio/pilot', 3000, ); GetDatasourceReleasesStats.report(); expect(logger.logger.trace).toHaveBeenCalledTimes(1); const [traceData, traceMsg] = logger.logger.trace.mock.calls[0]; expect(traceMsg).toBe('getReleases statistics with packages'); expect(traceData).toEqual({ stats: { avgMs: 1117, count: 6, maxMs: 3000, medianMs: 1000, totalMs: 6700, }, datasources: { npm: { stats: { avgMs: 233, count: 3, maxMs: 400, medianMs: 200, totalMs: 700, }, registryUrls: { 'https://registry.npmjs.org': { stats: { avgMs: 150, count: 2, maxMs: 200, medianMs: 200, totalMs: 300, }, packages: { lodash: { avgMs: 150, count: 2, maxMs: 200, medianMs: 200, totalMs: 300, }, }, }, 'https://jfrog.company.com/artifactory': { stats: { avgMs: 400, count: 1, maxMs: 400, medianMs: 400, totalMs: 400, }, packages: { foo: { avgMs: 400, count: 1, maxMs: 400, medianMs: 400, totalMs: 400, }, }, }, }, }, docker: { stats: { avgMs: 2000, count: 3, maxMs: 3000, medianMs: 2000, totalMs: 6000, }, registryUrls: { 'https://registry.docker.com': { stats: { avgMs: 2000, count: 3, maxMs: 3000, medianMs: 2000, totalMs: 6000, }, packages: { alpine: { avgMs: 1000, count: 1, maxMs: 1000, medianMs: 1000, totalMs: 1000, }, memcached: { avgMs: 2000, count: 1, maxMs: 2000, medianMs: 2000, totalMs: 2000, }, 'istio/pilot': { avgMs: 3000, count: 1, maxMs: 3000, medianMs: 3000, totalMs: 3000, }, }, }, }, }, }, }); expect(logger.logger.debug).toHaveBeenCalledTimes(1); const [debugData, debugMsg] = logger.logger.debug.mock.calls[0]; expect(debugMsg).toBe('getReleases statistics summary'); expect(debugData).toEqual({ stats: { avgMs: 1117, count: 6, maxMs: 3000, medianMs: 1000, totalMs: 6700, }, datasources: { npm: { stats: { avgMs: 233, count: 3, maxMs: 400, medianMs: 200, totalMs: 700, }, registryUrls: { 'https://registry.npmjs.org': { stats: { avgMs: 150, count: 2, maxMs: 200, medianMs: 200, totalMs: 300, }, }, 'https://jfrog.company.com/artifactory': { stats: { avgMs: 400, count: 1, maxMs: 400, medianMs: 400, totalMs: 400, }, }, }, }, docker: { stats: { avgMs: 2000, count: 3, maxMs: 3000, medianMs: 2000, totalMs: 6000, }, registryUrls: { 'https://registry.docker.com': { stats: { avgMs: 2000, count: 3, maxMs: 3000, medianMs: 2000, totalMs: 6000, }, }, }, }, }, }); }); }); describe('PackageCacheStats', () => { beforeEach(() => { vi.useFakeTimers(); }); it('returns empty report', () => { const res = PackageCacheStats.getReport(); expect(res).toEqual({ get: { avgMs: 0, count: 0, maxMs: 0, medianMs: 0, totalMs: 0 }, set: { avgMs: 0, count: 0, maxMs: 0, medianMs: 0, totalMs: 0 }, }); }); it('writes data points', () => { PackageCacheStats.writeGet(100); PackageCacheStats.writeGet(200); PackageCacheStats.writeGet(400); PackageCacheStats.writeSet(1000); const res = PackageCacheStats.getReport(); expect(res).toEqual({ get: { avgMs: 233, count: 3, maxMs: 400, medianMs: 200, totalMs: 700, }, set: { avgMs: 1000, count: 1, maxMs: 1000, medianMs: 1000, totalMs: 1000, }, }); }); it('wraps get function', async () => { const res = await PackageCacheStats.wrapGet(() => { vi.advanceTimersByTime(100); return Promise.resolve('foo'); }); expect(res).toBe('foo'); expect(PackageCacheStats.getReport()).toEqual({ get: { avgMs: 100, count: 1, maxMs: 100, medianMs: 100, totalMs: 100 }, set: { avgMs: 0, count: 0, maxMs: 0, medianMs: 0, totalMs: 0 }, }); }); it('wraps set function', async () => { await PackageCacheStats.wrapSet(() => { vi.advanceTimersByTime(100); return Promise.resolve(); }); expect(PackageCacheStats.getReport()).toEqual({ get: { avgMs: 0, count: 0, maxMs: 0, medianMs: 0, totalMs: 0 }, set: { avgMs: 100, count: 1, maxMs: 100, medianMs: 100, totalMs: 100 }, }); }); it('logs report', () => { PackageCacheStats.writeGet(100); PackageCacheStats.writeGet(200); PackageCacheStats.writeGet(400); PackageCacheStats.writeSet(1000); PackageCacheStats.report(); expect(logger.logger.debug).toHaveBeenCalledTimes(1); const [data, msg] = logger.logger.debug.mock.calls[0]; expect(msg).toBe('Package cache statistics'); expect(data).toEqual({ get: { avgMs: 233, count: 3, maxMs: 400, medianMs: 200, totalMs: 700, }, set: { avgMs: 1000, count: 1, maxMs: 1000, medianMs: 1000, totalMs: 1000, }, }); }); }); describe('DatasourceCacheStats', () => { it('collects data points', () => { DatasourceCacheStats.hit('crate', 'https://foo.example.com', 'foo'); DatasourceCacheStats.miss('maven', 'https://bar.example.com', 'bar'); DatasourceCacheStats.set('npm', 'https://baz.example.com', 'baz'); DatasourceCacheStats.skip('rubygems', 'https://qux.example.com', 'qux'); const report = DatasourceCacheStats.getReport(); expect(report).toEqual({ long: { crate: { 'https://foo.example.com': { foo: { read: 'hit' } }, }, maven: { 'https://bar.example.com': { bar: { read: 'miss' } }, }, npm: { 'https://baz.example.com': { baz: { write: 'set' } }, }, rubygems: { 'https://qux.example.com': { qux: { write: 'skip' } }, }, }, short: { crate: { 'https://foo.example.com': { hit: 1, miss: 0, set: 0, skip: 0 }, }, maven: { 'https://bar.example.com': { hit: 0, miss: 1, set: 0, skip: 0 }, }, npm: { 'https://baz.example.com': { hit: 0, miss: 0, set: 1, skip: 0 }, }, rubygems: { 'https://qux.example.com': { hit: 0, miss: 0, set: 0, skip: 1 }, }, }, }); }); it('reports', () => { DatasourceCacheStats.hit('crate', 'https://foo.example.com', 'foo'); DatasourceCacheStats.miss('maven', 'https://bar.example.com', 'bar'); DatasourceCacheStats.set('npm', 'https://baz.example.com', 'baz'); DatasourceCacheStats.skip('rubygems', 'https://qux.example.com', 'qux'); DatasourceCacheStats.report(); expect(logger.logger.trace).toHaveBeenCalledTimes(1); expect(logger.logger.debug).toHaveBeenCalledTimes(1); }); }); describe('HttpStats', () => { it('returns empty report', () => { const res = HttpStats.getReport(); expect(res).toEqual({ hostRequests: {}, hosts: {}, rawRequests: [], requests: 0, urls: {}, }); }); it('writes data points', () => { HttpStats.write({ method: 'GET', url: 'https://example.com/foo', reqMs: 100, queueMs: 10, status: 200, }); HttpStats.write({ method: 'GET', url: 'https://example.com/foo', reqMs: 200, queueMs: 20, status: 200, }); HttpStats.write({ method: 'GET', url: 'https://example.com/bar', reqMs: 400, queueMs: 40, status: 200, }); HttpStats.write({ method: 'GET', url: 'https://example.com/foo', reqMs: 800, queueMs: 80, status: 404, }); HttpStats.write({ method: 'GET', url: '', reqMs: 100, queueMs: 100, status: 400, }); const res = HttpStats.getReport(); expect(res).toEqual({ hostRequests: { 'example.com': [ { method: 'GET', queueMs: 40, reqMs: 400, status: 200, url: 'https://example.com/bar', }, { method: 'GET', queueMs: 10, reqMs: 100, status: 200, url: 'https://example.com/foo', }, { method: 'GET', queueMs: 20, reqMs: 200, status: 200, url: 'https://example.com/foo', }, { method: 'GET', queueMs: 80, reqMs: 800, status: 404, url: 'https://example.com/foo', }, ], }, hosts: { 'example.com': { count: 4, queueAvgMs: 38, queueMaxMs: 80, queueMedianMs: 40, reqAvgMs: 375, reqMaxMs: 800, reqMedianMs: 400, }, }, rawRequests: [ 'GET https://example.com/bar 200 400 40', 'GET https://example.com/foo 200 100 10', 'GET https://example.com/foo 200 200 20', 'GET https://example.com/foo 404 800 80', ], requests: 5, urls: { 'https://example.com/bar': { GET: { '200': 1, }, }, 'https://example.com/foo': { GET: { '200': 2, '404': 1, }, }, }, }); }); it('logs report', () => { HttpStats.write({ method: 'GET', url: 'https://example.com/foo', reqMs: 100, queueMs: 10, status: 200, }); HttpStats.write({ method: 'GET', url: 'https://example.com/foo', reqMs: 200, queueMs: 20, status: 200, }); HttpStats.write({ method: 'GET', url: 'https://example.com/bar', reqMs: 400, queueMs: 40, status: 200, }); HttpStats.write({ method: 'GET', url: 'https://example.com/foo', reqMs: 800, queueMs: 80, status: 404, }); HttpStats.report(); expect(logger.logger.trace).toHaveBeenCalledTimes(2); const [traceData, traceMsg] = logger.logger.trace.mock.calls[0]; expect(traceMsg).toBe('HTTP full statistics'); expect(traceData).toEqual({ rawRequests: [ 'GET https://example.com/bar 200 400 40', 'GET https://example.com/foo 200 100 10', 'GET https://example.com/foo 200 200 20', 'GET https://example.com/foo 404 800 80', ], hostRequests: { 'example.com': [ { method: 'GET', queueMs: 40, reqMs: 400, status: 200, url: 'https://example.com/bar', }, { method: 'GET', queueMs: 10, reqMs: 100, status: 200, url: 'https://example.com/foo', }, { method: 'GET', queueMs: 20, reqMs: 200, status: 200, url: 'https://example.com/foo', }, { method: 'GET', queueMs: 80, reqMs: 800, status: 404, url: 'https://example.com/foo', }, ], }, }); const [trace2Data, trace2Msg] = logger.logger.trace.mock.calls[1]; expect(trace2Msg).toBe('HTTP URL statistics'); expect(trace2Data).toEqual({ urls: { 'https://example.com/bar': { GET: { '200': 1, }, }, 'https://example.com/foo': { GET: { '200': 2, '404': 1, }, }, }, }); expect(logger.logger.debug).toHaveBeenCalledTimes(1); const [debugData, debugMsg] = logger.logger.debug.mock.calls[0]; expect(debugMsg).toBe('HTTP statistics'); expect(debugData).toEqual({ hosts: { 'example.com': { count: 4, queueAvgMs: 38, queueMaxMs: 80, queueMedianMs: 40, reqAvgMs: 375, reqMaxMs: 800, reqMedianMs: 400, }, }, requests: 4, }); }); }); describe('HttpCacheStats', () => { it('returns empty data', () => { const res = HttpCacheStats.getData(); expect(res).toEqual({}); }); it('ignores wrong url', () => { HttpCacheStats.incLocalHits(''); expect(HttpCacheStats.getData()).toEqual({}); }); it('writes data points', () => { HttpCacheStats.incLocalHits('https://example.com/foo'); HttpCacheStats.incLocalHits('https://example.com/foo'); HttpCacheStats.incLocalMisses('https://example.com/foo'); HttpCacheStats.incLocalMisses('https://example.com/bar'); HttpCacheStats.incRemoteHits('https://example.com/bar'); HttpCacheStats.incRemoteMisses('https://example.com/bar'); const res = HttpCacheStats.getData(); expect(res).toEqual({ 'https://example.com/bar': { hit: 1, miss: 1, localMiss: 1, }, 'https://example.com/foo': { hit: 0, miss: 0, localHit: 2, localMiss: 1, }, }); }); it('prints report', () => { HttpCacheStats.incLocalHits('https://example.com/foo'); HttpCacheStats.incLocalHits('https://example.com/foo'); HttpCacheStats.incLocalMisses('https://example.com/foo'); HttpCacheStats.incLocalMisses('https://example.com/bar'); HttpCacheStats.incRemoteHits('https://example.com/bar'); HttpCacheStats.incRemoteMisses('https://example.com/bar'); HttpCacheStats.report(); expect(logger.logger.debug).toHaveBeenCalledTimes(1); const [data, msg] = logger.logger.debug.mock.calls[0]; expect(msg).toBe('HTTP cache statistics'); expect(data).toEqual({ 'https://example.com': { '/foo': { hit: 0, localHit: 2, localMiss: 1, miss: 0 }, '/bar': { hit: 1, localMiss: 1, miss: 1 }, }, }); }); }); describe('AbandonedPackageStats', () => { beforeEach(() => { memCache.init(); }); it('returns empty report', () => { const res = AbandonedPackageStats.getReport(); expect(res).toEqual({}); }); it('writes data points', () => { AbandonedPackageStats.write( 'npm', 'package1', '2023-01-01T00:00:00.000Z', ); AbandonedPackageStats.write( 'npm', 'package2', '2023-02-01T00:00:00.000Z', ); AbandonedPackageStats.write( 'docker', 'image1', '2023-03-01T00:00:00.000Z', ); const data = AbandonedPackageStats.getData(); expect(data).toEqual([ { datasource: 'npm', packageName: 'package1', mostRecentTimestamp: '2023-01-01T00:00:00.000Z', }, { datasource: 'npm', packageName: 'package2', mostRecentTimestamp: '2023-02-01T00:00:00.000Z', }, { datasource: 'docker', packageName: 'image1', mostRecentTimestamp: '2023-03-01T00:00:00.000Z', }, ]); const report = AbandonedPackageStats.getReport(); expect(report).toEqual({ npm: { package1: '2023-01-01T00:00:00.000Z', package2: '2023-02-01T00:00:00.000Z', }, docker: { image1: '2023-03-01T00:00:00.000Z', }, }); }); it('logs report', () => { AbandonedPackageStats.write( 'npm', 'package1', '2023-01-01T00:00:00.000Z', ); AbandonedPackageStats.write( 'docker', 'image1', '2023-03-01T00:00:00.000Z', ); AbandonedPackageStats.report(); expect(logger.logger.debug).toHaveBeenCalledTimes(1); const [data, msg] = logger.logger.debug.mock.calls[0]; expect(msg).toBe('Abandoned package statistics'); expect(data).toEqual({ npm: { package1: '2023-01-01T00:00:00.000Z', }, docker: { image1: '2023-03-01T00:00:00.000Z', }, }); }); it('does not log report when no data', () => { AbandonedPackageStats.report(); expect(logger.logger.debug).not.toHaveBeenCalled(); }); }); describe('GitOperationsStats', () => { beforeEach(() => { memCache.init(); vi.useFakeTimers(); }); afterEach(() => { vi.useRealTimers(); }); it('returns empty report', () => { const res = GitOperationStats.getReport(); expect(res).toEqual({}); }); it('writes data points', () => { GitOperationStats.write('pull', 1000); GitOperationStats.write('push', 100); GitOperationStats.write('push', 50000); const report = GitOperationStats.getReport(); expect(report).toEqual({ pull: { avgMs: 1000, count: 1, maxMs: 1000, medianMs: 1000, totalMs: 1000, }, push: { avgMs: 25050, count: 2, maxMs: 50000, medianMs: 50000, totalMs: 50100, }, }); }); it('rounds total towards ceiling when preparing report', () => { GitOperationStats.write('pull', 1000.4); GitOperationStats.write('pull', 500.4); GitOperationStats.write('pull', 700.2); GitOperationStats.write('pull', 5.500000001); const report = GitOperationStats.getReport(); expect(report).toEqual({ pull: { avgMs: 552, count: 4, // NOTE these are the raw values maxMs: 1000.4, medianMs: 700.2, // NOTE that the total is rounded toward the ceiling totalMs: 2207, }, }); }); it('logs report', () => { for (let i = 0; i < 5; i++) { GitOperationStats.write('other', 4000); } GitOperationStats.report(); expect(logger.logger.debug).toHaveBeenCalledTimes(1); const [data, msg] = logger.logger.debug.mock.calls[0]; expect(msg).toBe('Git operations statistics'); expect(data).toEqual({ other: { avgMs: 4000, count: 5, maxMs: 4000, medianMs: 4000, totalMs: 20_000, }, }); }); }); });