feat: print info after install about hardlinked/copied packages in node_moduels/.pnpm

PR #2679
close #2572

Co-authored-by: Zoltan Kochan <z@kochan.io>

.changeset/few-cows-jump.md

@@ -0,0 +1,5 @@
+---
+"@pnpm/default-reporter": minor
+---
+
+Print info after install about hardlinked/copied packages in `node_modules/.pnpm`

.changeset/spicy-worms-lick.md

@@ -0,0 +1,6 @@
+---
+"@pnpm/core-loggers": minor
+"@pnpm/get-context": minor
+---
+
+Use `contextLogger` to log `virtualStoreDir`, `storeDir`, and `currentLockfileExists`.

.changeset/twelve-sloths-design.md

@@ -0,0 +1,6 @@
+---
+"@pnpm/core-loggers": minor
+"@pnpm/package-store": minor
+---
+
+Add packageImportMethod logger.

packages/core-loggers/src/all.ts

@@ -1,3 +1,4 @@
+export * from './contextLogger'
 export * from './deprecationLogger'
 export * from './fetchingProgressLogger'
 export * from './hookLogger'
@@ -6,6 +7,7 @@ export * from './installCheckLogger'
 export * from './lifecycleLogger'
 export * from './linkLogger'
 export * from './packageManifestLogger'
+export * from './packageImportMethodLogger'
 export * from './progressLogger'
 export * from './registryLogger'
 export * from './requestRetryLogger'

packages/core-loggers/src/contextLogger.ts

@@ -0,0 +1,13 @@
+import baseLogger, {
+  LogBase,
+} from '@pnpm/logger'
+
+export const contextLogger = baseLogger('context')
+
+export interface ContextMessage {
+  currentLockfileExists: boolean,
+  storeDir: string,
+  virtualStoreDir: string,
+}
+
+export type ContextLog = {name: 'pnpm:context'} & LogBase & ContextMessage

packages/core-loggers/src/index.ts

@@ -1,6 +1,7 @@
 export * from './all'
 
 import {
+  ContextLog,
   DeprecationLog,
   FetchingProgressLog,
   HookLog,
@@ -8,6 +9,7 @@ import {
   InstallCheckLog,
   LifecycleLog,
   LinkLog,
+  PackageImportMethodLog,
   PackageManifestLog,
   ProgressLog,
   RegistryLog,
@@ -21,6 +23,7 @@ import {
 } from './all'
 
 export type Log =
+  | ContextLog
   | DeprecationLog
   | FetchingProgressLog
   | HookLog
@@ -29,6 +32,7 @@ export type Log =
   | LifecycleLog
   | LinkLog
   | PackageManifestLog
+  | PackageImportMethodLog
   | ProgressLog
   | RegistryLog
   | RequestRetryLog

packages/core-loggers/src/packageImportMethodLogger.ts

@@ -0,0 +1,11 @@
+import baseLogger, {
+  LogBase,
+} from '@pnpm/logger'
+
+export const packageImportMethodLogger = baseLogger('package-import-method')
+
+export interface PackageImportMethodMessage {
+  method: 'clone' | 'hardlink' | 'copy',
+}
+
+export type PackageImportMethodLog = {name: 'pnpm:package-import-method'} & LogBase & PackageImportMethodMessage

packages/default-reporter/src/index.ts

@@ -77,6 +77,7 @@ export function toOutput$ (
   }
 ): most.Stream<string> {
   opts = opts || {}
+  const contextPushStream = new PushStream()
   const fetchingProgressPushStream = new PushStream()
   const progressPushStream = new PushStream()
   const stagePushStream = new PushStream()
@@ -84,6 +85,7 @@ export function toOutput$ (
   const summaryPushStream = new PushStream()
   const lifecyclePushStream = new PushStream()
   const statsPushStream = new PushStream()
+  const packageImportMethodPushStream = new PushStream()
   const installCheckPushStream = new PushStream()
   const registryPushStream = new PushStream()
   const rootPushStream = new PushStream()
@@ -97,6 +99,9 @@ export function toOutput$ (
   setTimeout(() => { // setTimeout is a workaround for a strange bug in most https://github.com/cujojs/most/issues/491
     opts.streamParser['on']('data', (log: logs.Log) => {
       switch (log.name) {
+        case 'pnpm:context':
+          contextPushStream.next(log)
+          break
         case 'pnpm:fetching-progress':
           fetchingProgressPushStream.next(log)
           break
@@ -118,6 +123,9 @@ export function toOutput$ (
         case 'pnpm:stats':
           statsPushStream.next(log)
           break
+        case 'pnpm:package-import-method':
+          packageImportMethodPushStream.next(log)
+          break
         case 'pnpm:install-check':
           installCheckPushStream.next(log)
           break
@@ -155,6 +163,7 @@ export function toOutput$ (
     })
   }, 0)
   const log$ = {
+    context: most.from<logs.ContextLog>(contextPushStream.observable),
     deprecation: most.from<logs.DeprecationLog>(deprecationPushStream.observable),
     fetchingProgress: most.from<logs.FetchingProgressLog>(fetchingProgressPushStream.observable),
     hook: most.from<logs.HookLog>(hookPushStream.observable),
@@ -162,6 +171,7 @@ export function toOutput$ (
     lifecycle: most.from<logs.LifecycleLog>(lifecyclePushStream.observable),
     link: most.from<logs.LinkLog>(linkPushStream.observable),
     other: most.from<logs.Log>(otherPushStream.observable),
+    packageImportMethod: most.from<logs.PackageImportMethodLog>(packageImportMethodPushStream.observable),
     packageManifest: most.from<logs.PackageManifestLog>(packageManifestPushStream.observable),
     progress: most.from<logs.ProgressLog>(progressPushStream.observable),
     registry: most.from<logs.RegistryLog>(registryPushStream.observable),

packages/default-reporter/src/reporterForClient/index.ts

@@ -3,6 +3,7 @@ import * as logs from '@pnpm/core-loggers'
 import { LogLevel } from '@pnpm/logger'
 import most = require('most')
 import reportBigTarballsProgress from './reportBigTarballsProgress'
+import reportContext from './reportContext'
 import reportDeprecations from './reportDeprecations'
 import reportHooks from './reportHooks'
 import reportInstallChecks from './reportInstallChecks'
@@ -17,6 +18,7 @@ import reportSummary from './reportSummary'
 
 export default function (
   log$: {
+    context: most.Stream<logs.ContextLog>,
     fetchingProgress: most.Stream<logs.FetchingProgressLog>,
     progress: most.Stream<logs.ProgressLog>,
     stage: most.Stream<logs.StageLog>,
@@ -34,6 +36,7 @@ export default function (
     hook: most.Stream<logs.HookLog>,
     scope: most.Stream<logs.ScopeLog>,
     skippedOptionalDependency: most.Stream<logs.SkippedOptionalDependencyLog>,
+    packageImportMethod: most.Stream<logs.PackageImportMethodLog>,
   },
   opts: {
     appendOnly?: boolean,
@@ -79,6 +82,7 @@ export default function (
     reportScope(log$.scope, { isRecursive: opts.isRecursive, cmd: opts.cmd }),
     reportSkippedOptionalDependencies(log$.skippedOptionalDependency, { cwd }),
     reportHooks(log$.hook, { cwd, isRecursive: opts.isRecursive }),
+    reportContext(log$, { cwd }),
   ]
 
   if (!opts.appendOnly) {

packages/default-reporter/src/reporterForClient/reportContext.ts

@@ -0,0 +1,42 @@
+import { ContextLog, PackageImportMethodLog } from '@pnpm/core-loggers'
+import most = require('most')
+import path = require('path')
+
+export default (
+  log$: {
+    context: most.Stream<ContextLog>,
+    packageImportMethod: most.Stream<PackageImportMethodLog>,
+  },
+  opts: { cwd: string }
+) => {
+  return most.combine(
+      (context, packageImportMethod) => {
+        if (context.currentLockfileExists) {
+          return most.never()
+        }
+        let method!: string
+        switch (packageImportMethod.method) {
+          case 'copy':
+            method = 'copied'
+            break
+          case 'clone':
+            method = 'cloned'
+            break
+          case 'hardlink':
+            method = 'hard linked'
+            break
+          default:
+            method = packageImportMethod.method
+            break
+        }
+        return most.of({
+          msg: `\
+Packages are ${method} from the content-addressable store to the virtual store.
+  Content-addressable store is at: ${context.storeDir}
+  Virtual store is at:             ${path.relative(opts.cwd, context.virtualStoreDir)}`,
+        })
+      },
+      log$.context.take(1),
+      log$.packageImportMethod.take(1)
+    )
+}

packages/default-reporter/test/index.ts

@@ -20,6 +20,7 @@ import path = require('path')
 import R = require('ramda')
 import StackTracey = require('stacktracey')
 import test = require('tape')
+import './reportingContext'
 import './reportingErrors'
 import './reportingLifecycleScripts'
 import './reportingProgress'

packages/default-reporter/test/reportingContext.ts

@@ -0,0 +1,70 @@
+import { contextLogger, packageImportMethodLogger } from '@pnpm/core-loggers'
+import { toOutput$ } from '@pnpm/default-reporter'
+import {
+  createStreamParser,
+} from '@pnpm/logger'
+import delay from 'delay'
+import test = require('tape')
+
+test('print context and import method info', (t) => {
+  const output$ = toOutput$({
+    context: {
+      argv: ['install'],
+    },
+    streamParser: createStreamParser(),
+  })
+
+  contextLogger.debug({
+    currentLockfileExists: false,
+    storeDir: '~/.pnpm-store/v3',
+    virtualStoreDir: 'node_modules/.pnpm',
+  })
+  packageImportMethodLogger.debug({
+    method: 'hardlink',
+  })
+
+  t.plan(1)
+
+  output$.take(1).subscribe({
+    complete: () => t.end(),
+    error: t.end,
+    next: output => {
+      t.equal(output, `\
+Packages are hard linked from the content-addressable store to the virtual store.
+  Content-addressable store is at: ~/.pnpm-store/v3
+  Virtual store is at:             node_modules/.pnpm`)
+    },
+  })
+})
+
+test('do not print info if not fresh install', async (t) => {
+  const output$ = toOutput$({
+    context: {
+      argv: ['install'],
+    },
+    streamParser: createStreamParser(),
+  })
+
+  contextLogger.debug({
+    currentLockfileExists: true,
+    storeDir: '~/.pnpm-store/v3',
+    virtualStoreDir: 'node_modules/.pnpm',
+  })
+  packageImportMethodLogger.debug({
+    method: 'hardlink',
+  })
+
+  t.plan(1)
+
+  const subscription = output$.subscribe({
+    complete: () => t.end(),
+    error: t.end,
+    next: (msg) => {
+      t.notOk(msg)
+    },
+  })
+
+  await delay(10)
+  t.ok('output$ has no event')
+  subscription.unsubscribe()
+})

packages/get-context/src/index.ts

@@ -1,4 +1,4 @@
-import { packageManifestLogger } from '@pnpm/core-loggers'
+import { contextLogger, packageManifestLogger } from '@pnpm/core-loggers'
 import PnpmError from '@pnpm/error'
 import { Lockfile } from '@pnpm/lockfile-file'
 import logger from '@pnpm/logger'
@@ -161,7 +161,11 @@ export default async function getContext<T> (
       virtualStoreDir,
     }),
   }
-
+  contextLogger.debug({
+    currentLockfileExists: ctx.existsCurrentLockfile,
+    storeDir: opts.storeDir,
+    virtualStoreDir,
+  })
   return ctx
 }
 
@@ -428,6 +432,11 @@ export async function getContextForSingleImporter (
     initial: manifest,
     prefix: opts.dir,
   })
+  contextLogger.debug({
+    currentLockfileExists: ctx.existsCurrentLockfile,
+    storeDir: opts.storeDir,
+    virtualStoreDir,
+  })
 
   return ctx
 }

packages/package-store/src/storeController/createImportPackage.ts

@@ -1,4 +1,4 @@
-import { importingLogger } from '@pnpm/core-loggers'
+import { importingLogger, packageImportMethodLogger } from '@pnpm/core-loggers'
 import { globalInfo, globalWarn } from '@pnpm/logger'
 import { PackageFilesResponse } from '@pnpm/store-controller-types'
 import fs = require('mz/fs')
@@ -31,13 +31,16 @@ function createImportPackage (packageImportMethod?: 'auto' | 'hardlink' | 'copy'
   // - copy: copy the packages, do not try to link them first
   switch (packageImportMethod || 'auto') {
     case 'clone':
+      packageImportMethodLogger.debug({ method: 'clone' })
       return clonePkg
     case 'hardlink':
+      packageImportMethodLogger.debug({ method: 'hardlink' })
       return hardlinkPkg
     case 'auto': {
       return createAutoImporter()
     }
     case 'copy':
+      packageImportMethodLogger.debug({ method: 'copy' })
       return copyPkg
     default:
       throw new Error(`Unknown package import method ${packageImportMethod}`)
@@ -59,6 +62,7 @@ function createAutoImporter () {
   ) {
     try {
       await clonePkg(to, opts)
+      packageImportMethodLogger.debug({ method: 'clone' })
       auto = clonePkg
       return
     } catch (err) {
@@ -66,12 +70,14 @@ function createAutoImporter () {
     }
     try {
       await hardlinkPkg(to, opts)
+      packageImportMethodLogger.debug({ method: 'hardlink' })
       auto = hardlinkPkg
       return
     } catch (err) {
       if (!err.message.startsWith('EXDEV: cross-device link not permitted')) throw err
       globalWarn(err.message)
       globalInfo('Falling back to copying packages from store')
+      packageImportMethodLogger.debug({ method: 'copy' })
       auto = copyPkg
       await auto(to, opts)
     }