Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG] npm ping uses cache when registry is offline #5870

Closed
2 tasks done
Metritutus opened this issue Nov 18, 2022 · 0 comments · Fixed by #7789
Closed
2 tasks done

[BUG] npm ping uses cache when registry is offline #5870

Metritutus opened this issue Nov 18, 2022 · 0 comments · Fixed by #7789
Labels
Bug thing that needs fixing Priority 2 secondary priority issue Release 9.x work is associated with a specific npm 9 release

Comments

@Metritutus
Copy link

Is there an existing issue for this?

  • I have searched the existing issues

This issue exists in the latest npm version

  • I am using the latest npm

Current Behavior

When using npm ping to check if a private registry was online, I noticed that it would claim a successful response after approximately 70000ms when the registry was definitely offline. I'm not sure if it's currently possible to configure the timeout period, but it would be very useful to be able to do so.

The private registry was a Verdaccio registry hosted on the local machine (launched with verdaccio --listen 127.0.0.1:4873), although I'm not sure this is of relevance for this issue.

Suspecting that there might be some sort of caching involved, I ran npm cache ls, which confirmed there was an entry in there for the ping request.

Interestingly, after cleaning the entry out of the cache, the next npm ping call still succeeds. It is only the subsequent ones (after the first ping since removing the entry from the cache) which fail as they should.

The commands and their output demonstrating the problem:

1) npm ping where the private registry is online:

npm ping --registry=http://127.0.0.1:4873/ --verbose

npm verb cli C:\Program Files\nodejs\node.exe C:\Users\<REDACTED>\AppData\Roaming\npm\node_modules\npm\bin\npm-cli.js
npm info using npm@9.1.2
npm info using node@v18.12.1
npm verb title npm ping
npm verb argv "ping" "--registry" "http://127.0.0.1:4873/" "--loglevel" "verbose"
npm verb logfile logs-max:10 dir:C:\Users\<REDACTED>\AppData\Local\npm-cache\_logs\2022-11-18T16_05_12_706Z-
npm verb logfile C:\Users\<REDACTED>\AppData\Local\npm-cache\_logs\2022-11-18T16_05_12_706Z-debug-0.log
npm notice PING http://127.0.0.1:4873/
npm http fetch GET 200 http://127.0.0.1:4873/-/ping?write=true 33ms (cache miss)
npm notice PONG 35ms
npm verb exit 0
npm info ok

2) npm ping where the private registry is offline:

npm ping --registry=http://127.0.0.1:4873/ --verbose

npm verb cli C:\Program Files\nodejs\node.exe C:\Users\<REDACTED>\AppData\Roaming\npm\node_modules\npm\bin\npm-cli.js
npm info using npm@9.1.2
npm info using node@v18.12.1
npm verb title npm ping
npm verb argv "ping" "--registry" "http://127.0.0.1:4873/" "--loglevel" "verbose"
npm verb logfile logs-max:10 dir:C:\Users\<REDACTED>\AppData\Local\npm-cache\_logs\2022-11-18T16_05_56_431Z-
npm verb logfile C:\Users\<REDACTED>\AppData\Local\npm-cache\_logs\2022-11-18T16_05_56_431Z-debug-0.log
npm notice PING http://127.0.0.1:4873/
npm http fetch GET 200 http://127.0.0.1:4873/-/ping?write=true 70061ms (cache stale)
npm notice PONG 70062ms
npm verb exit 0
npm info ok

3) npm cache clean the ping entry:

npm cache clean make-fetch-happen:request-cache:http://127.0.0.1:4873/-/ping?write=true --verbose

npm verb cli C:\Program Files\nodejs\node.exe C:\Users\<REDACTED>\AppData\Roaming\npm\node_modules\npm\bin\npm-cli.js
npm info using npm@9.1.2
npm info using node@v18.12.1
npm verb title npm cache clean make-fetch-happen:request-cache:http://127.0.0.1:4873/-/ping?write=true
npm verb argv "cache" "clean" "make-fetch-happen:request-cache:http://127.0.0.1:4873/-/ping?write=true" "--loglevel" "verbose"
npm verb logfile logs-max:10 dir:C:\Users\<REDACTED>\AppData\Local\npm-cache\_logs\2022-11-18T16_08_04_190Z-
npm verb logfile C:\Users\<REDACTED>\AppData\Local\npm-cache\_logs\2022-11-18T16_08_04_190Z-debug-0.log
Deleted: make-fetch-happen:request-cache:http://127.0.0.1:4873/-/ping?write=true
npm verb exit 0
npm info ok

4) npm ping where the private registry is offline:

npm ping --registry=http://127.0.0.1:4873/ --verbose

npm verb cli C:\Program Files\nodejs\node.exe C:\Users\<REDACTED>\AppData\Roaming\npm\node_modules\npm\bin\npm-cli.js
npm info using npm@9.1.2
npm info using node@v18.12.1
npm verb title npm ping
npm verb argv "ping" "--registry" "http://127.0.0.1:4873/" "--loglevel" "verbose"
npm verb logfile logs-max:10 dir:C:\Users\<REDACTED>\AppData\Local\npm-cache\_logs\2022-11-18T16_09_01_885Z-
npm verb logfile C:\Users\<REDACTED>\AppData\Local\npm-cache\_logs\2022-11-18T16_09_01_885Z-debug-0.log
npm notice PING http://127.0.0.1:4873/
npm notice PONG 70076ms
npm verb exit 0
npm info ok

5) npm ping where the private registry is offline:

npm ping --registry=http://127.0.0.1:4873/ --verbose

npm ping --registry=http://127.0.0.1:4873/ --verbose
npm verb cli C:\Program Files\nodejs\node.exe C:\Users\<REDACTED>\AppData\Roaming\npm\node_modules\npm\bin\npm-cli.js
npm info using npm@9.1.2
npm info using node@v18.12.1
npm verb title npm ping
npm verb argv "ping" "--registry" "http://127.0.0.1:4873/" "--loglevel" "verbose"
npm verb logfile logs-max:10 dir:C:\Users\<REDACTED>\AppData\Local\npm-cache\_logs\2022-11-18T16_10_51_182Z-
npm verb logfile C:\Users\<REDACTED>\AppData\Local\npm-cache\_logs\2022-11-18T16_10_51_182Z-debug-0.log
npm notice PING http://127.0.0.1:4873/
npm verb type system
npm verb stack FetchError: request to http://127.0.0.1:4873/-/ping?write=true failed, reason: connect ECONNREFUSED 127.0.0.1:4873
npm verb stack     at ClientRequest.<anonymous> (C:\Users\<REDACTED>\AppData\Roaming\npm\node_modules\npm\node_modules\minipass-fetch\lib\index.js:130:14)
npm verb stack     at ClientRequest.emit (node:events:513:28)
npm verb stack     at Socket.socketErrorListener (node:_http_client:494:9)
npm verb stack     at Socket.emit (node:events:525:35)
npm verb stack     at emitErrorNT (node:internal/streams/destroy:151:8)
npm verb stack     at emitErrorCloseNT (node:internal/streams/destroy:116:3)
npm verb stack     at process.processTicksAndRejections (node:internal/process/task_queues:82:21)
npm verb cwd C:\Users\<REDACTED>
npm verb Windows_NT 10.0.22621
npm verb node v18.12.1
npm verb npm  v9.1.2
npm ERR! code ECONNREFUSED
npm ERR! syscall connect
npm ERR! errno ECONNREFUSED
npm ERR! FetchError: request to http://127.0.0.1:4873/-/ping?write=true failed, reason: connect ECONNREFUSED 127.0.0.1:4873
npm ERR!     at ClientRequest.<anonymous> (C:\Users\<REDACTED>\AppData\Roaming\npm\node_modules\npm\node_modules\minipass-fetch\lib\index.js:130:14)
npm ERR!     at ClientRequest.emit (node:events:513:28)
npm ERR!     at Socket.socketErrorListener (node:_http_client:494:9)
npm ERR!     at Socket.emit (node:events:525:35)
npm ERR!     at emitErrorNT (node:internal/streams/destroy:151:8)
npm ERR!     at emitErrorCloseNT (node:internal/streams/destroy:116:3)
npm ERR!     at process.processTicksAndRejections (node:internal/process/task_queues:82:21)
npm ERR!  FetchError: request to http://127.0.0.1:4873/-/ping?write=true failed, reason: connect ECONNREFUSED 127.0.0.1:4873
npm ERR!     at ClientRequest.<anonymous> (C:\Users\<REDACTED>\AppData\Roaming\npm\node_modules\npm\node_modules\minipass-fetch\lib\index.js:130:14)
npm ERR!     at ClientRequest.emit (node:events:513:28)
npm ERR!     at Socket.socketErrorListener (node:_http_client:494:9)
npm ERR!     at Socket.emit (node:events:525:35)
npm ERR!     at emitErrorNT (node:internal/streams/destroy:151:8)
npm ERR!     at emitErrorCloseNT (node:internal/streams/destroy:116:3)
npm ERR!     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
npm ERR!   code: 'ECONNREFUSED',
npm ERR!   errno: 'ECONNREFUSED',
npm ERR!   syscall: 'connect',
npm ERR!   address: '127.0.0.1',
npm ERR!   port: 4873,
npm ERR!   type: 'system'
npm ERR! }
npm ERR!
npm ERR! If you are behind a proxy, please make sure that the
npm ERR! 'proxy' config is set properly.  See: 'npm help config'
npm verb exit 1
npm verb code 1

npm ERR! A complete log of this run can be found in:
npm ERR!     C:\Users\<REDACTED>\AppData\Local\npm-cache\_logs\2022-11-18T16_10_51_182Z-debug-0.log

Expected Behavior

npm ping responses should not be cached. It should accurately report whether or not the specified registry is actually online, rather than returning a cached response after timing out.

Steps To Reproduce

  1. With the private registry online, run the following command: npm ping --registry=http://127.0.0.1:4873/ --verbose
  2. Shut down the private registry.
  3. With the private registry offline, run the following command: npm ping --registry=http://127.0.0.1:4873/ --verbose

Environment

  • npm: 9.1.2
  • Node.js: 18.12.1
  • OS Name: Windows 11 22H2 (OS Build 22621.674)
  • System Model Name: N/A
  • npm config:
; "builtin" config from C:\Users\<REDACTED>\AppData\Roaming\npm\node_modules\npm\npmrc

prefix = "C:\\Users\\<REDACTED>\\AppData\\Roaming\\npm"

; "cli" config from command line options

location = "project"

; node bin location = C:\Program Files\nodejs\node.exe
; node version = v18.12.1
; npm local prefix = C:\Users\<REDACTED>
; npm version = 9.1.2
; cwd = C:\Users\<REDACTED>
; HOME = C:\Users\<REDACTED>
; Run `npm config ls -l` to show all defaults.
@Metritutus Metritutus added Bug thing that needs fixing Needs Triage needs review for next steps Release 9.x work is associated with a specific npm 9 release labels Nov 18, 2022
@Metritutus Metritutus changed the title [BUG] npm ping uses cache when registry is offline [BUG] npm ping uses cache when registry is offline Nov 22, 2022
@fritzy fritzy added Priority 2 secondary priority issue and removed Needs Triage needs review for next steps labels Nov 22, 2022
@lukekarrys lukekarrys assigned lukekarrys and unassigned lukekarrys May 11, 2024
wraithgar pushed a commit that referenced this issue Sep 30, 2024
…7789)

Ping: Don't use cache so ping does not report ping sucess incorrectly if
it's offline or no internet
Doctor: Don't use cache for pinging the registry. 

Fixes: #5870
Fixes: #3576
Fixes: #4112

<details>
<summary>Testing of ping and doctor </summary>

```sh
# -- current npm last ping resuts in cached request replying PONG

~/workarea/npm-cli $ npm ping --registry=http://localhost:4873 -ddd
npm verbose cli /Users/milaninfy/.nvm/versions/node/v22.9.0/bin/node /Users/milaninfy/.nvm/versions/node/v22.9.0/bin/npm
npm info using npm@10.8.3
npm info using node@v22.9.0
npm silly config load:file:/Users/milaninfy/.nvm/versions/node/v22.9.0/lib/node_modules/npm/npmrc
npm silly config load:file:/Users/milaninfy/workarea/npm-cli/.npmrc
npm silly config load:file:/Users/milaninfy/.npmrc
npm silly config load:file:/Users/milaninfy/.nvm/versions/node/v22.9.0/etc/npmrc
npm verbose title npm ping
npm verbose argv "ping" "--registry" "http://localhost:4873" "--loglevel" "silly"
npm verbose logfile logs-max:10 dir:/Users/milaninfy/.npm/_logs/2024-09-26T20_37_04_583Z-
npm verbose logfile /Users/milaninfy/.npm/_logs/2024-09-26T20_37_04_583Z-debug-0.log
npm notice PING http://localhost:4873/
npm silly logfile start cleaning logs, removing 1 files
npm silly logfile done cleaning log files
npm http fetch GET http://localhost:4873/-/ping?write=true attempt 1 failed with ECONNREFUSED
npm http fetch GET http://localhost:4873/-/ping?write=true attempt 2 failed with ECONNREFUSED
npm http fetch GET http://localhost:4873/-/ping?write=true attempt 3 failed with ECONNREFUSED
npm http fetch GET 200 http://localhost:4873/-/ping?write=true 70045ms (cache stale)
npm notice PONG 70046ms
npm verbose cwd /Users/milaninfy/workarea/npm-cli
npm verbose os Darwin 23.6.0
npm verbose node v22.9.0
npm verbose npm  v10.8.3
npm verbose exit 0
npm info ok


# -- After the change npm last ping resuts in failure after retries

~/workarea/npm-cli $ lnpm ping --registry=http://localhost:4873 -ddd
npm verbose cli /Users/milaninfy/.nvm/versions/node/v22.9.0/bin/node /Users/milaninfy/workarea/npm-cli/index.js
npm info using npm@10.8.3
npm info using node@v22.9.0
npm silly config load:file:/Users/milaninfy/workarea/npm-cli/npmrc
npm silly config load:file:/Users/milaninfy/workarea/npm-cli/.npmrc
npm silly config load:file:/Users/milaninfy/.npmrc
npm silly config load:file:/Users/milaninfy/.nvm/versions/node/v22.9.0/etc/npmrc
npm verbose title npm ping
npm verbose argv "ping" "--registry" "http://localhost:4873" "--loglevel" "silly"
npm verbose logfile logs-max:10 dir:/Users/milaninfy/.npm/_logs/2024-09-26T20_38_51_059Z-
npm verbose logfile /Users/milaninfy/.npm/_logs/2024-09-26T20_38_51_059Z-debug-0.log
npm notice PING http://localhost:4873/
npm silly logfile start cleaning logs, removing 1 files
npm http fetch GET http://localhost:4873/-/ping?write=true attempt 1 failed with ECONNREFUSED
npm silly logfile done cleaning log files
npm http fetch GET http://localhost:4873/-/ping?write=true attempt 2 failed with ECONNREFUSED
npm http fetch GET http://localhost:4873/-/ping?write=true attempt 3 failed with ECONNREFUSED
npm verbose type system
npm verbose stack FetchError: request to http://localhost:4873/-/ping?write=true failed, reason: 
npm verbose stack     at ClientRequest.<anonymous> (/Users/milaninfy/workarea/npm-cli/node_modules/minipass-fetch/lib/index.js:130:14)
npm verbose stack     at ClientRequest.emit (node:events:519:28)
npm verbose stack     at emitErrorEvent (node:_http_client:103:11)
npm verbose stack     at _destroy (node:_http_client:886:9)
npm verbose stack     at onSocketNT (node:_http_client:906:5)
npm verbose stack     at process.processTicksAndRejections (node:internal/process/task_queues:91:21)
npm error code ECONNREFUSED
npm error errno ECONNREFUSED
npm error FetchError: request to http://localhost:4873/-/ping?write=true failed, reason: 
npm error     at ClientRequest.<anonymous> (/Users/milaninfy/workarea/npm-cli/node_modules/minipass-fetch/lib/index.js:130:14)
npm error     at ClientRequest.emit (node:events:519:28)
npm error     at emitErrorEvent (node:_http_client:103:11)
npm error     at _destroy (node:_http_client:886:9)
npm error     at onSocketNT (node:_http_client:906:5)
npm error     at process.processTicksAndRejections (node:internal/process/task_queues:91:21) {
npm error   code: 'ECONNREFUSED',
npm error   errno: 'ECONNREFUSED',
npm error   type: 'system'
npm error }
npm error
npm error If you are behind a proxy, please make sure that the
npm error 'proxy' config is set properly.  See: 'npm help config'
npm verbose cwd /Users/milaninfy/workarea/npm-cli
npm verbose os Darwin 23.6.0
npm verbose node v22.9.0
npm verbose npm  v10.8.3
npm verbose exit 1
npm verbose code 1
npm error A complete log of this run can be found in: /Users/milaninfy/.npm/_logs/2024-09-26T20_38_51_059Z-debug-0.log





# -- npm doctor ping resuts in success due to cache hit


~/workarea/npm-cli $ npm doctor --registry=http://localhost:4873 -ddd
npm verbose cli /Users/milaninfy/.nvm/versions/node/v22.9.0/bin/node /Users/milaninfy/.nvm/versions/node/v22.9.0/bin/npm
npm info using npm@10.8.3
npm info using node@v22.9.0
npm silly config load:file:/Users/milaninfy/.nvm/versions/node/v22.9.0/lib/node_modules/npm/npmrc
npm silly config load:file:/Users/milaninfy/workarea/npm-cli/.npmrc
npm silly config load:file:/Users/milaninfy/.npmrc
npm silly config load:file:/Users/milaninfy/.nvm/versions/node/v22.9.0/etc/npmrc
npm verbose title npm doctor
npm verbose argv "doctor" "--registry" "http://localhost:4873" "--loglevel" "silly"
npm verbose logfile logs-max:10 dir:/Users/milaninfy/.npm/_logs/2024-09-26T20_40_30_672Z-
npm verbose logfile /Users/milaninfy/.npm/_logs/2024-09-26T20_40_30_672Z-debug-0.log
npm info doctor Running checkup
Connecting to the registry
npm info doctor Pinging registry
npm silly logfile start cleaning logs, removing 1 files
npm silly logfile done cleaning log files
npm http fetch GET http://localhost:4873/-/ping?write=true attempt 1 failed with ECONNREFUSED
npm http fetch GET 200 http://localhost:4873/-/ping?write=true 48ms (cache stale)
Ok



# -- after the changes npm doctor ping correctly resuts in failure after retires

~/workarea/npm-cli $ lnpm doctor --registry=http://localhost:4873 -ddd
npm verbose cli /Users/milaninfy/.nvm/versions/node/v22.9.0/bin/node /Users/milaninfy/workarea/npm-cli/index.js
npm info using npm@10.8.3
npm info using node@v22.9.0
npm silly config load:file:/Users/milaninfy/workarea/npm-cli/npmrc
npm silly config load:file:/Users/milaninfy/workarea/npm-cli/.npmrc
npm silly config load:file:/Users/milaninfy/.npmrc
npm silly config load:file:/Users/milaninfy/.nvm/versions/node/v22.9.0/etc/npmrc
npm verbose title npm doctor
npm verbose argv "doctor" "--registry" "http://localhost:4873" "--loglevel" "silly"
npm verbose logfile logs-max:10 dir:/Users/milaninfy/.npm/_logs/2024-09-26T20_41_05_904Z-
npm verbose logfile /Users/milaninfy/.npm/_logs/2024-09-26T20_41_05_904Z-debug-0.log
npm info doctor Running checkup
Connecting to the registry
npm info doctor Pinging registry
npm silly logfile start cleaning logs, removing 1 files
npm http fetch GET http://localhost:4873/-/ping?write=true attempt 1 failed with ECONNREFUSED
npm silly logfile done cleaning log files
npm http fetch GET http://localhost:4873/-/ping?write=true attempt 2 failed with ECONNREFUSED
npm http fetch GET http://localhost:4873/-/ping?write=true attempt 3 failed with ECONNREFUSED
Not ok
request to http://localhost:4873/-/ping?write=true failed, reason: 

```

</detail>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug thing that needs fixing Priority 2 secondary priority issue Release 9.x work is associated with a specific npm 9 release
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants