import { logger } from '../../test/util'; import * as memCache from './cache/memory'; import { DatasourceCacheStats, HttpCacheStats, HttpStats, LookupStats, PackageCacheStats, makeTimingReport, } from './stats'; 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, }); }); }); describe('LookupStats', () => { beforeEach(() => { jest.useFakeTimers(); }); afterEach(() => { jest.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', () => { jest.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('PackageCacheStats', () => { beforeEach(() => { jest.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(() => { jest.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(() => { jest.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 }, }, }); }); }); });