diff --git a/lib/remote.js b/lib/remote.js index 2aef9f8..b06daa8 100644 --- a/lib/remote.js +++ b/lib/remote.js @@ -2,6 +2,7 @@ const { Minipass } = require('minipass') const fetch = require('minipass-fetch') const promiseRetry = require('promise-retry') const ssri = require('ssri') +const { log } = require('proc-log') const CachingMinipassPipeline = require('./pipeline.js') const { getAgent } = require('@npmcli/agent') @@ -89,6 +90,7 @@ const remoteFetch = (request, options) => { options.onRetry(res) } + log.http('fetch', `${req.method} ${req.url} failed with ${res.status}, retrying`) return retryHandler(res) } @@ -112,6 +114,7 @@ const remoteFetch = (request, options) => { options.onRetry(err) } + log.http('fetch', `${req.method} ${req.url} failed with ${err.code}, retrying`) return retryHandler(err) } }, options.retry).catch((err) => { diff --git a/test/fetch.js b/test/fetch.js index 51b25e2..2754bb1 100644 --- a/test/fetch.js +++ b/test/fetch.js @@ -74,6 +74,14 @@ t.test('500-level responses not thrown', async t => { t.test('calls opts.onRetry', async t => { t.test('when request is retriable', async (t) => { + const logs = [] + const logHandler = (...logparams) => { + logs.push(...logparams) + } + process.on('log', logHandler) + t.teardown(() => { + process.off('log', logHandler) + }) const srv = nock(HOST) .get('/test-onretry') .reply(500) @@ -95,10 +103,23 @@ t.test('calls opts.onRetry', async t => { t.same(res.headers.get('x-fetch-attempts'), '2', 'set the appropriate header') t.equal(calledOnRetry, true, 'should have called onRetry') t.equal(retryNotification, 1, 'should have called method once') + t.strictSame(logs, [ + 'http', + 'fetch', + 'GET https://make-fetch-happen.npm/test-onretry failed with 500, retrying', + ]) t.ok(srv.isDone()) }) t.test('when request is retriable; and caught', async (t) => { + const logs = [] + const logHandler = (...logparams) => { + logs.push(...logparams) + } + process.on('log', logHandler) + t.teardown(() => { + process.off('log', logHandler) + }) const srv = nock(HOST) .get('/catch-retry') .replyWithError({ @@ -128,6 +149,11 @@ t.test('calls opts.onRetry', async t => { t.equal(calledOnRetry, true, 'should have called onRetry') const buf = await res.buffer() t.same(buf, CONTENT, 'request succeeded') + t.strictSame(logs, [ + 'http', + 'fetch', + 'GET https://make-fetch-happen.npm/catch-retry failed with ECONNRESET, retrying', + ]) t.ok(srv.isDone()) })