diff --git a/lib/fetcher.js b/lib/fetcher.js index cc2c2db7..f2ac9761 100644 --- a/lib/fetcher.js +++ b/lib/fetcher.js @@ -188,7 +188,15 @@ class FetcherBase { // private // Note: cacache will raise a EINTEGRITY error if the integrity doesn't match #tarballFromCache () { - return cacache.get.stream.byDigest(this.cache, this.integrity, this.opts) + const startTime = Date.now() + const stream = cacache.get.stream.byDigest(this.cache, this.integrity, this.opts) + const elapsedTime = Date.now() - startTime + // cache is good, so log it as a hit in particular since there was no fetch logged + log.http( + 'cache', + `${this.spec} ${elapsedTime}ms (cache hit)` + ) + return stream } get [_.cacheFetches] () { diff --git a/test/fetcher.js b/test/fetcher.js index 8b2adb36..6f857b35 100644 --- a/test/fetcher.js +++ b/test/fetcher.js @@ -207,6 +207,10 @@ t.test('extract', t => { }).extract(target + '/badcache') .then(({ resolved, integrity }) => { t.match(logs, [ + ['http', + 'cache', + /file:test\/fixtures\/abbrev-1.1.1.tgz.*(cache hit)/, + ], ['warn', 'tar', 'zlib: incorrect header check'], [ 'silly', @@ -298,7 +302,11 @@ t.test('extract', t => { algorithm: 'sha512', sri: Object, }, 'got expected error') - t.same(logs, [ + t.match(logs, [ + ['http', + 'cache', + /file:test\/fixtures\/abbrev-1.1.1.tgz.*(cache hit)/, + ], [ 'silly', 'tarball',