feat: print a warning if network requests are slow (#10025)

* feat: print a warning if network requests are slow

* feat: print a warning if network requests are slow

add a new setting for fetch tarball speed

* feat: print a warning if network requests are slow

* fix: src/fetch.ts

* docs: add changeset

.changeset/happy-teams-tap.md

@@ -0,0 +1,16 @@
+---
+"@pnpm/store-connection-manager": minor
+"@pnpm/tarball-fetcher": minor
+"@pnpm/npm-resolver": minor
+"@pnpm/client": minor
+"@pnpm/config": minor
+"pnpm": minor
+---
+
+Added network performance monitoring to pnpm by implementing warnings for slow network requests, including both metadata fetches and tarball downloads.
+
+Added configuration options for warning thresholds: `fetchWarnTimeoutMs` and `fetchMinSpeedKiBps`.
+Warning messages are displayed when requests exceed time thresholds or fall below speed minimums
+
+Related PR: [#10025](https://github.com/pnpm/pnpm/pull/10025).
+

config/config/src/Config.ts

@@ -231,6 +231,8 @@ export interface Config extends OptionsFromRootManifest {
   preserveAbsolutePaths?: boolean
   minimumReleaseAge?: number
   minimumReleaseAgeExclude?: string[]
+  fetchWarnTimeoutMs?: number
+  fetchMinSpeedKiBps?: number
 }
 
 export interface ConfigWithDeprecatedSettings extends Config {

config/config/src/index.ts

@@ -146,6 +146,8 @@ export async function getConfig (opts: {
     'fetch-retry-maxtimeout': 60000,
     'fetch-retry-mintimeout': 10000,
     'fetch-timeout': 60000,
+    'fetch-warn-timeout-ms': 10_000, // 10 sec
+    'fetch-min-speed-ki-bps': 50, // 50 KiB/s
     'force-legacy-deploy': false,
     'git-shallow-hosts': [
       // Follow https://github.com/npm/git/blob/1e1dbd26bd5b87ca055defecc3679777cb480e2a/lib/clone.js#L13-L19

config/config/src/types.ts

@@ -25,6 +25,8 @@ export const types = Object.assign({
   'exclude-links-from-lockfile': Boolean,
   'extend-node-path': Boolean,
   'fetch-timeout': Number,
+  'fetch-warn-timeout-ms': Number,
+  'fetch-min-speed-ki-bps': Number,
   'fetching-concurrency': Number,
   filter: [String, Array],
   'filter-prod': [String, Array],

fetching/tarball-fetcher/src/index.ts

@@ -14,6 +14,7 @@ import { TarballIntegrityError } from '@pnpm/worker'
 import {
   createDownloader,
   type DownloadFunction,
+  type CreateDownloaderOptions,
 } from './remoteTarballFetcher.js'
 import { createLocalTarballFetcher } from './localTarballFetcher.js'
 import { createGitHostedTarballFetcher } from './gitHostedTarballFetcher.js'
@@ -38,11 +39,12 @@ export function createTarballFetcher (
     timeout?: number
     retry?: RetryTimeoutOptions
     offline?: boolean
-  }
+  } & Pick<CreateDownloaderOptions, 'fetchMinSpeedKiBps'>
 ): TarballFetchers {
   const download = createDownloader(fetchFromRegistry, {
     retry: opts.retry,
     timeout: opts.timeout,
+    fetchMinSpeedKiBps: opts.fetchMinSpeedKiBps,
   })
 
   const remoteTarballFetcher = fetchFromTarball.bind(null, {

fetching/tarball-fetcher/src/remoteTarballFetcher.ts

@@ -6,6 +6,7 @@ import { FetchError } from '@pnpm/error'
 import { type FetchResult, type FetchOptions } from '@pnpm/fetcher-base'
 import { type Cafs } from '@pnpm/cafs-types'
 import { type FetchFromRegistry } from '@pnpm/fetching-types'
+import { globalWarn } from '@pnpm/logger'
 import { addFilesFromTarball } from '@pnpm/worker'
 import * as retry from '@zkochan/retry'
 import throttle from 'lodash.throttle'
@@ -33,19 +34,22 @@ export interface NpmRegistryClient {
   fetch: (url: string, opts: { auth?: object }, cb: (err: Error, res: IncomingMessage) => void) => void
 }
 
+export interface CreateDownloaderOptions {
+  // retry
+  retry?: {
+    retries?: number
+    factor?: number
+    minTimeout?: number
+    maxTimeout?: number
+    randomize?: boolean
+  }
+  timeout?: number
+  fetchMinSpeedKiBps?: number
+}
+
 export function createDownloader (
   fetchFromRegistry: FetchFromRegistry,
-  gotOpts: {
-    // retry
-    retry?: {
-      retries?: number
-      factor?: number
-      minTimeout?: number
-      maxTimeout?: number
-      randomize?: boolean
-    }
-    timeout?: number
-  }
+  gotOpts: CreateDownloaderOptions
 ): DownloadFunction {
   const retryOpts = {
     factor: 10,
@@ -54,6 +58,7 @@ export function createDownloader (
     retries: 2,
     ...gotOpts.retry,
   }
+  const fetchMinSpeedKiBps = gotOpts.fetchMinSpeedKiBps ?? 50 // 50 KiB/s
 
   return async function download (url: string, opts: {
     getAuthHeaderByURI: (registry: string) => string | undefined
@@ -129,6 +134,7 @@ export function createDownloader (
         const onProgress = (size != null && size >= BIG_TARBALL_SIZE && opts.onProgress)
           ? throttle(opts.onProgress, 500)
           : undefined
+        const startTime = Date.now()
         let downloaded = 0
         const chunks: Buffer[] = []
         // This will handle the 'data', 'error', and 'end' events.
@@ -144,6 +150,12 @@ export function createDownloader (
             tarballUrl: url,
           })
         }
+        const elapsedSec = (Date.now() - startTime) / 1000
+        const avgKiBps = Math.floor((downloaded / elapsedSec) / 1024)
+        if (downloaded > 0 && elapsedSec > 1 && avgKiBps < fetchMinSpeedKiBps) {
+          const sizeKb = Math.floor(downloaded / 1024)
+          globalWarn(`Tarball download average speed ${avgKiBps} KiB/s (size ${sizeKb} KiB) is below ${fetchMinSpeedKiBps} KiB/s: ${url} (GET)`)
+        }
 
         data = Buffer.from(new SharedArrayBuffer(downloaded))
         let offset: number = 0

pkg-manager/client/src/index.ts

@@ -31,6 +31,7 @@ export type ClientOptions = {
   resolveSymlinksInInjectedDirs?: boolean
   includeOnlyPackageFiles?: boolean
   preserveAbsolutePaths?: boolean
+  fetchMinSpeedKiBps?: number
 } & ResolverFactoryOptions & AgentOptions
 
 export interface Client {
@@ -65,7 +66,7 @@ type Fetchers = {
 function createFetchers (
   fetchFromRegistry: FetchFromRegistry,
   getAuthHeader: GetAuthHeader,
-  opts: Pick<ClientOptions, 'rawConfig' | 'retry' | 'gitShallowHosts' | 'resolveSymlinksInInjectedDirs' | 'unsafePerm' | 'includeOnlyPackageFiles' | 'offline'>,
+  opts: Pick<ClientOptions, 'rawConfig' | 'retry' | 'gitShallowHosts' | 'resolveSymlinksInInjectedDirs' | 'unsafePerm' | 'includeOnlyPackageFiles' | 'offline' | 'fetchMinSpeedKiBps'>,
   customFetchers?: CustomFetchers
 ): Fetchers {
   const tarballFetchers = createTarballFetcher(fetchFromRegistry, getAuthHeader, opts)

resolving/npm-resolver/src/fetch.ts

@@ -1,5 +1,6 @@
 import url from 'url'
 import { requestRetryLogger } from '@pnpm/core-loggers'
+import { globalWarn } from '@pnpm/logger'
 import {
   FetchError,
   type FetchErrorRequest,
@@ -41,9 +42,15 @@ export class RegistryResponseError extends FetchError {
   }
 }
 
-export async function fromRegistry (
-  fetch: FetchFromRegistry,
-  fetchOpts: { retry: RetryTimeoutOptions, timeout: number },
+export interface FetchMetadataFromFromRegistryOptions {
+  fetch: FetchFromRegistry
+  retry: RetryTimeoutOptions
+  timeout: number
+  fetchWarnTimeoutMs: number
+}
+
+export async function fetchMetadataFromFromRegistry (
+  fetchOpts: FetchMetadataFromFromRegistryOptions,
   pkgName: string,
   registry: string,
   authHeaderValue?: string
@@ -53,8 +60,9 @@ export async function fromRegistry (
   return new Promise((resolve, reject) => {
     op.attempt(async (attempt) => {
       let response: RegistryResponse
+      const startTime = Date.now()
       try {
-        response = await fetch(uri, {
+        response = await fetchOpts.fetch(uri, {
           authHeaderValue,
           compress: true,
           retry: fetchOpts.retry,
@@ -76,7 +84,13 @@ export async function fromRegistry (
       // Here we only retry broken JSON responses.
       // Other HTTP issues are retried by the @pnpm/fetch library
       try {
-        resolve(await response.json())
+        const json = await response.json()
+        // Check if request took longer than expected
+        const elapsedMs = Date.now() - startTime
+        if (elapsedMs > fetchOpts.fetchWarnTimeoutMs) {
+          globalWarn(`Request took ${elapsedMs}ms: ${uri}`)
+        }
+        resolve(json)
       } catch (error: any) { // eslint-disable-line
         const timeout = op.retry(
           new PnpmError('BROKEN_METADATA_JSON', error.message)

resolving/npm-resolver/src/index.ts

@@ -39,7 +39,7 @@ import {
   type JsrRegistryPackageSpec,
   type RegistryPackageSpec,
 } from './parseBareSpecifier.js'
-import { fromRegistry, RegistryResponseError } from './fetch.js'
+import { fetchMetadataFromFromRegistry, type FetchMetadataFromFromRegistryOptions, RegistryResponseError } from './fetch.js'
 import { workspacePrefToNpm } from './workspacePrefToNpm.js'
 import { whichVersionIsPinned } from './whichVersionIsPinned.js'
 import { pickVersionByVersionRange } from './pickPackageFromMeta.js'
@@ -93,6 +93,7 @@ export interface ResolverFactoryOptions {
   saveWorkspaceProtocol?: boolean | 'rolling'
   preserveAbsolutePaths?: boolean
   strictPublishedByCheck?: boolean
+  fetchWarnTimeoutMs?: number
 }
 
 export interface NpmResolveResult extends ResolveResult {
@@ -128,11 +129,13 @@ export function createNpmResolver (
   if (typeof opts.cacheDir !== 'string') {
     throw new TypeError('`opts.cacheDir` is required and needs to be a string')
   }
-  const fetchOpts = {
+  const fetchOpts: FetchMetadataFromFromRegistryOptions = {
+    fetch: fetchFromRegistry,
     retry: opts.retry ?? {},
     timeout: opts.timeout ?? 60000,
+    fetchWarnTimeoutMs: opts.fetchWarnTimeoutMs ?? 10 * 1000, // 10 sec
   }
-  const fetch = pMemoize(fromRegistry.bind(null, fetchFromRegistry, fetchOpts), {
+  const fetch = pMemoize(fetchMetadataFromFromRegistry.bind(null, fetchOpts), {
     cacheKey: (...args) => JSON.stringify(args),
     maxAge: 1000 * 20, // 20 seconds
   })

store/store-connection-manager/src/createNewStoreController.ts

@@ -21,6 +21,8 @@ export type CreateNewStoreControllerOptions = CreateResolverOptions & Pick<Confi
 | 'force'
 | 'nodeVersion'
 | 'fetchTimeout'
+| 'fetchWarnTimeoutMs'
+| 'fetchMinSpeedKiBps'
 | 'gitShallowHosts'
 | 'ignoreScripts'
 | 'hooks'
@@ -63,6 +65,8 @@ export async function createNewStoreController (
     ca: opts.ca,
     cacheDir: opts.cacheDir,
     cert: opts.cert,
+    fetchWarnTimeoutMs: opts.fetchWarnTimeoutMs,
+    fetchMinSpeedKiBps: opts.fetchMinSpeedKiBps,
     fullMetadata,
     filterMetadata: fullMetadata,
     httpProxy: opts.httpProxy,