fix: print a better error message on prepare pkg failure (#5847)

ref #5845

.changeset/four-colts-care.md

@@ -0,0 +1,11 @@
+---
+"@pnpm/plugin-commands-publishing": patch
+"@pnpm/store-connection-manager": patch
+"@pnpm/default-reporter": patch
+"@pnpm/prepare-package": patch
+"@pnpm/client": patch
+"@pnpm/node.fetcher": patch
+"pnpm": patch
+---
+
+Report to the console when a git-hosted dependency is built [#5847](https://github.com/pnpm/pnpm/pull/5847).

.changeset/sweet-items-scream.md

@@ -0,0 +1,7 @@
+---
+"@pnpm/tarball-fetcher": patch
+"@pnpm/git-fetcher": patch
+"pnpm": patch
+---
+
+Print more contextual information when a git-hosted package fails to be prepared for installation [#5847](https://github.com/pnpm/pnpm/pull/5847).

cli/default-reporter/src/reporterForClient/reportLifecycleScripts.ts

@@ -10,6 +10,7 @@ import { formatPrefix, formatPrefixNoTrim } from './utils/formatPrefix'
 import { hlValue } from './outputConstants'
 
 const NODE_MODULES = `${path.sep}node_modules${path.sep}`
+const TMP_DIR_IN_STORE = `tmp${path.sep}_tmp_` // git-hosted dependencies are built in these temporary directories
 
 // When streaming processes are spawned, use this color for prefix
 const colorWheel = ['cyan', 'magenta', 'blue', 'yellow', 'green', 'red']
@@ -65,7 +66,7 @@ export function reportLifecycleScripts (
     .forEach((log: LifecycleLog) => {
       const key = `${log.stage}:${log.depPath}`
       lifecycleMessages[key] = lifecycleMessages[key] || {
-        collapsed: log.wd.includes(NODE_MODULES),
+        collapsed: log.wd.includes(NODE_MODULES) || log.wd.includes(TMP_DIR_IN_STORE),
         output: [],
         startTime: process.hrtime(),
         status: formatIndentedStatus(chalk.magentaBright('Running...')),
@@ -113,8 +114,13 @@ function renderCollapsedScriptOutput (
     maxWidth: number
   }
 ) {
-  messageCache.label = messageCache.label ??
-    `${highlightLastFolder(formatPrefixNoTrim(opts.cwd, log.wd))}: Running ${log.stage} script`
+  if (!messageCache.label) {
+    messageCache.label = highlightLastFolder(formatPrefixNoTrim(opts.cwd, log.wd))
+    if (log.wd.includes(TMP_DIR_IN_STORE)) {
+      messageCache.label += ` [${log.depPath}]`
+    }
+    messageCache.label += `: Running ${log.stage} script`
+  }
   if (!opts.exit) {
     updateMessageCache(log, messageCache, opts)
     return `${messageCache.label}...`
@@ -191,7 +197,7 @@ function updateMessageCache (
     if (log['exitCode'] === 0) {
       messageCache.status = formatIndentedStatus(chalk.magentaBright(`Done in ${time}`))
     } else {
-      messageCache.status = formatIndentedStatus(chalk.red(`Failed in ${time}`))
+      messageCache.status = formatIndentedStatus(chalk.red(`Failed in ${time} at ${log.wd}`))
     }
   } else {
     messageCache.output.push(formatIndentedOutput(opts.maxWidth, log))

cli/default-reporter/test/reportingLifecycleScripts.ts

@@ -17,7 +17,6 @@ const OUTPUT_INDENTATION = chalk.magentaBright('│')
 const STATUS_INDENTATION = chalk.magentaBright('└─')
 const STATUS_RUNNING = chalk.magentaBright('Running...')
 const STATUS_DONE = chalk.magentaBright('Done in 1s')
-const STATUS_FAILED = chalk.red('Failed in 1s')
 const EOL = '\n'
 
 function replaceTimeWith1Sec (text: string) {
@@ -651,6 +650,79 @@ ${chalk.gray('node_modules/.registry.npmjs.org/qar/1.0.0/node_modules/')}qar: Ru
   })
 })
 
+test('collapses lifecycle output from preparation of a git-hosted dependency', (done) => {
+  const output$ = toOutput$({
+    context: { argv: ['install'] },
+    reportingOptions: { outputMaxWidth: 79 },
+    streamParser: createStreamParser(),
+  })
+
+  const wdOfFoo = path.resolve(process.cwd(), 'tmp/_tmp_01243')
+
+  lifecycleLogger.debug({
+    depPath: 'registry.npmjs.org/foo/1.0.0',
+    optional: false,
+    script: 'node foo',
+    stage: 'preinstall',
+    wd: wdOfFoo,
+  })
+  lifecycleLogger.debug({
+    depPath: 'registry.npmjs.org/foo/1.0.0',
+    line: 'foo 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20',
+    stage: 'preinstall',
+    stdio: 'stdout',
+    wd: wdOfFoo,
+  })
+  lifecycleLogger.debug({
+    depPath: 'registry.npmjs.org/foo/1.0.0',
+    optional: false,
+    script: 'node foo',
+    stage: 'postinstall',
+    stdio: 'stdout',
+    wd: wdOfFoo,
+  })
+  lifecycleLogger.debug({
+    depPath: 'registry.npmjs.org/foo/1.0.0',
+    line: 'foo I',
+    stage: 'postinstall',
+    stdio: 'stdout',
+    wd: wdOfFoo,
+  })
+  lifecycleLogger.debug({
+    depPath: 'registry.npmjs.org/foo/1.0.0',
+    line: 'foo II',
+    stage: 'postinstall',
+    stdio: 'stdout',
+    wd: wdOfFoo,
+  })
+  lifecycleLogger.debug({
+    depPath: 'registry.npmjs.org/foo/1.0.0',
+    line: 'foo III',
+    stage: 'postinstall',
+    stdio: 'stdout',
+    wd: wdOfFoo,
+  })
+  lifecycleLogger.debug({
+    depPath: 'registry.npmjs.org/foo/1.0.0',
+    exitCode: 0,
+    optional: false,
+    stage: 'postinstall',
+    wd: wdOfFoo,
+  })
+
+  expect.assertions(1)
+
+  output$.pipe(skip(2), take(1), map(normalizeNewline)).subscribe({
+    complete: () => done(),
+    error: done,
+    next: (output: unknown) => {
+      expect(replaceTimeWith1Sec(output as string)).toBe(`\
+${chalk.gray('tmp')}_tmp_01234: Running preinstall script...
+${chalk.gray('tmp')}_tmp_01234: Running postinstall script, done in 1s`)
+    },
+  })
+})
+
 test('output of failed optional dependency is not shown', (done) => {
   const output$ = toOutput$({
     context: { argv: ['install'] },
@@ -734,7 +806,7 @@ test('output of failed non-optional dependency is printed', (done) => {
 ${chalk.gray('node_modules/.registry.npmjs.org/foo/1.0.0/node_modules/')}foo: Running install script, failed in 1s
 .../foo/1.0.0/node_modules/foo ${INSTALL}$ node foo
 ${OUTPUT_INDENTATION} foo 0 1 2 3 4 5 6 7 8 9
-${STATUS_INDENTATION} ${STATUS_FAILED}`)
+${STATUS_INDENTATION} ${failedAt(wd)}`)
     },
   })
 })
@@ -780,7 +852,7 @@ test('do not fail if the debug log has no output', (done) => {
 ${chalk.gray('node_modules/.registry.npmjs.org/foo/1.0.0/node_modules/')}foo: Running install script, failed in 1s
 .../foo/1.0.0/node_modules/foo ${INSTALL}$ node foo
 ${OUTPUT_INDENTATION} 
-${STATUS_INDENTATION} ${STATUS_FAILED}`)
+${STATUS_INDENTATION} ${failedAt(wd)}`)
     },
   })
 })
@@ -844,3 +916,7 @@ Running ${POSTINSTALL} for ${hlPkgId('registry.npmjs.org/bar/1.0.0')}: ${childOu
     },
   })
 })
+
+function failedAt (wd: string) {
+  return chalk.red(`Failed in 1s at ${wd}`)
+}

env/node.fetcher/src/index.ts

@@ -34,9 +34,11 @@ export async function fetchNode (fetch: FetchFromRegistry, version: string, targ
   }
   const getAuthHeader = () => undefined
   const fetchers = createTarballFetcher(fetch, getAuthHeader, {
-    rawConfig: {}, // This is not needed for fetching Node.js
     retry: opts.retry,
     timeout: opts.fetchTimeout,
+    // These are not needed for fetching Node.js
+    rawConfig: {},
+    unsafePerm: false,
   })
   const cafs = createCafsStore(opts.cafsDir)
   const fetchTarball = pickFetcher(fetchers, { tarball })

exec/prepare-package/package.json

@@ -29,8 +29,7 @@
   },
   "homepage": "https://github.com/pnpm/pnpm/blob/main/exec/prepare-package#readme",
   "dependencies": {
-    "@pnpm/error": "workspace:*",
-    "@pnpm/npm-lifecycle": "^2.0.0",
+    "@pnpm/lifecycle": "workspace:*",
     "@pnpm/read-package-json": "workspace:*",
     "@zkochan/rimraf": "^2.1.2",
     "execa": "npm:safe-execa@0.1.2",

exec/prepare-package/src/index.ts

@@ -1,10 +1,8 @@
 import path from 'path'
-import { PnpmError } from '@pnpm/error'
-import lifecycle from '@pnpm/npm-lifecycle'
+import { runLifecycleHook, RunLifecycleHookOptions } from '@pnpm/lifecycle'
 import { safeReadPackageJsonFromDir } from '@pnpm/read-package-json'
 import { PackageScripts } from '@pnpm/types'
 import rimraf from '@zkochan/rimraf'
-import execa from 'execa'
 import preferredPM from 'preferred-pm'
 import omit from 'ramda/src/omit'
 
@@ -16,23 +14,35 @@ const PREPUBLISH_SCRIPTS = [
   'postpublish',
 ]
 
-export async function preparePackage (opts: { rawConfig: object }, pkgDir: string) {
+export interface PreparePackageOptions {
+  rawConfig: object
+  unsafePerm?: boolean
+}
+
+export async function preparePackage (opts: PreparePackageOptions, pkgDir: string) {
   const manifest = await safeReadPackageJsonFromDir(pkgDir)
   if (manifest?.scripts == null || !packageShouldBeBuilt(manifest.scripts)) return
   const pm = (await preferredPM(pkgDir))?.name ?? 'npm'
-  // We can't prepare a package without running its lifecycle scripts.
-  // An alternative solution could be to throw an exception.
-  const config = omit(['ignore-scripts'], opts.rawConfig)
-  const env = lifecycle.makeEnv(manifest, { config })
-  const execOpts = { cwd: pkgDir, env, extendEnv: true }
+  const execOpts: RunLifecycleHookOptions = {
+    depPath: `${manifest.name}@${manifest.version}`,
+    pkgRoot: pkgDir,
+    // We can't prepare a package without running its lifecycle scripts.
+    // An alternative solution could be to throw an exception.
+    rawConfig: omit(['ignore-scripts'], opts.rawConfig),
+    rootModulesDir: pkgDir, // We don't need this property but there is currently no way to not set it.
+    unsafePerm: Boolean(opts.unsafePerm),
+  }
   try {
-    await execa(pm, ['install'], execOpts)
+    const installScriptName = `${pm}-install`
+    manifest.scripts[installScriptName] = `${pm} install`
+    await runLifecycleHook(installScriptName, manifest, execOpts)
     for (const scriptName of PREPUBLISH_SCRIPTS) {
       if (manifest.scripts[scriptName] == null || manifest.scripts[scriptName] === '') continue
-      await execa(pm, ['run', scriptName], execOpts)
+      await runLifecycleHook(scriptName, manifest, execOpts)
     }
   } catch (err: any) { // eslint-disable-line
-    throw new PnpmError('PREPARE_PKG_FAILURE', err.shortMessage ?? err.message)
+    err.code = 'ERR_PNPM_PREPARE_PACKAGE'
+    throw err
   }
   await rimraf(path.join(pkgDir, 'node_modules'))
 }

exec/prepare-package/tsconfig.json

@@ -15,14 +15,14 @@
     {
       "path": "../../__utils__/test-fixtures"
     },
-    {
-      "path": "../../packages/error"
-    },
     {
       "path": "../../packages/types"
     },
     {
       "path": "../../pkg-manifest/read-package-json"
+    },
+    {
+      "path": "../lifecycle"
     }
   ]
 }

fetching/git-fetcher/src/index.ts

@@ -5,9 +5,15 @@ import rimraf from '@zkochan/rimraf'
 import execa from 'execa'
 import { URL } from 'url'
 
-export function createGitFetcher (createOpts: { gitShallowHosts?: string[], rawConfig: object }) {
+export interface CreateGitFetcherOptions {
+  gitShallowHosts?: string[]
+  rawConfig: object
+  unsafePerm?: boolean
+}
+
+export function createGitFetcher (createOpts: CreateGitFetcherOptions) {
   const allowedHosts = new Set(createOpts?.gitShallowHosts ?? [])
-  const preparePkg = preparePackage.bind(null, { rawConfig: createOpts.rawConfig })
+  const preparePkg = preparePackage.bind(null, { rawConfig: createOpts.rawConfig, unsafePerm: createOpts.unsafePerm })
 
   const gitFetcher: GitFetcher = async (cafs, resolution, opts) => {
     const tempLocation = await cafs.tempDir()
@@ -19,7 +25,12 @@ export function createGitFetcher (createOpts: { gitShallowHosts?: string[], rawC
       await execGit(['clone', resolution.repo, tempLocation])
     }
     await execGit(['checkout', resolution.commit], { cwd: tempLocation })
-    await preparePkg(tempLocation)
+    try {
+      await preparePkg(tempLocation)
+    } catch (err: any) { // eslint-disable-line
+      err.message = `Failed to prepare git-hosted package fetched from "${resolution.repo}": ${err.message}` // eslint-disable-line
+      throw err
+    }
     // removing /.git to make directory integrity calculation faster
     await rimraf(path.join(tempLocation, '.git'))
     const filesIndex = await cafs.addFilesFromDir(tempLocation, opts.manifest)

fetching/git-fetcher/test/index.ts

@@ -124,6 +124,20 @@ test('still able to shallow fetch for allowed hosts', async () => {
   expect(name).toEqual('is-positive')
 })
 
+test('fail when preparing a git-hosted package', async () => {
+  const cafsDir = tempy.directory()
+  const fetch = createGitFetcher({ rawConfig: {} }).git
+  const manifest = pDefer<DependencyManifest>()
+  await expect(
+    fetch(createCafsStore(cafsDir),
+      {
+        commit: 'ba58874aae1210a777eb309dd01a9fdacc7e54e7',
+        repo: 'https://github.com/pnpm-e2e/prepare-script-fails.git',
+        type: 'git',
+      }, { manifest })
+  ).rejects.toThrow('Failed to prepare git-hosted package fetched from "https://github.com/pnpm-e2e/prepare-script-fails.git": @pnpm.e2e/prepare-script-fails@1.0.0 npm-install: `npm install`')
+})
+
 function prefixGitArgs (): string[] {
   return process.platform === 'win32' ? ['-c', 'core.longpaths=true'] : []
 }

fetching/tarball-fetcher/src/gitHostedTarballFetcher.ts

@@ -10,17 +10,26 @@ interface Resolution {
   tarball: string
 }
 
-export function createGitHostedTarballFetcher (fetchRemoteTarball: FetchFunction, rawConfig: object): FetchFunction {
+export interface CreateGitHostedTarballFetcher {
+  rawConfig: object
+  unsafePerm?: boolean
+}
+
+export function createGitHostedTarballFetcher (fetchRemoteTarball: FetchFunction, fetcherOpts: CreateGitHostedTarballFetcher): FetchFunction {
   const fetch = async (cafs: Cafs, resolution: Resolution, opts: FetchOptions) => {
     const { filesIndex } = await fetchRemoteTarball(cafs, resolution, opts)
-
-    return { filesIndex: await prepareGitHostedPkg(filesIndex as FilesIndex, cafs, rawConfig) }
+    try {
+      return { filesIndex: await prepareGitHostedPkg(filesIndex as FilesIndex, cafs, fetcherOpts) }
+    } catch (err: any) { // eslint-disable-line
+      err.message = `Failed to prepare git-hosted package fetched from "${resolution.tarball}": ${err.message}` // eslint-disable-line
+      throw err
+    }
   }
 
   return fetch as FetchFunction
 }
 
-async function prepareGitHostedPkg (filesIndex: FilesIndex, cafs: Cafs, rawConfig: object) {
+async function prepareGitHostedPkg (filesIndex: FilesIndex, cafs: Cafs, opts: CreateGitHostedTarballFetcher) {
   const tempLocation = await cafs.tempDir()
   await cafs.importPackage(tempLocation, {
     filesResponse: {
@@ -29,7 +38,7 @@ async function prepareGitHostedPkg (filesIndex: FilesIndex, cafs: Cafs, rawConfi
     },
     force: true,
   })
-  await preparePackage({ rawConfig }, tempLocation)
+  await preparePackage(opts, tempLocation)
   const newFilesIndex = await cafs.addFilesFromDir(tempLocation)
   // Important! We cannot remove the temp location at this stage.
   // Even though we have the index of the package,

fetching/tarball-fetcher/src/index.ts

@@ -32,6 +32,7 @@ export function createTarballFetcher (
   getAuthHeader: GetAuthHeader,
   opts: {
     rawConfig: object
+    unsafePerm?: boolean
     timeout?: number
     retry?: RetryTimeoutOptions
     offline?: boolean
@@ -51,7 +52,7 @@ export function createTarballFetcher (
   return {
     localTarball: createLocalTarballFetcher(),
     remoteTarball: remoteTarballFetcher,
-    gitHostedTarball: createGitHostedTarballFetcher(remoteTarballFetcher, opts.rawConfig),
+    gitHostedTarball: createGitHostedTarballFetcher(remoteTarballFetcher, opts),
   }
 }