fix: don't log warnings when optional dependencies are skipped

ref pnpm/pnpm#1140

src/api/install.ts

@@ -44,6 +44,7 @@ import {DepGraphNode} from '../link/resolvePeers'
 import {
   packageJsonLogger,
   rootLogger,
+  skippedOptionalDependencyLogger,
   stageLogger,
   summaryLogger,
 } from '../loggers'
@@ -686,6 +687,14 @@ async function installInContext (
               }
             } catch (err) {
               if (installCtx.pkgByPkgId[pkg.id].optional) {
+                // TODO: add parents field to the log
+                skippedOptionalDependencyLogger.debug({
+                  details: err,
+                  id: pkg.id,
+                  name: pkg.name,
+                  reason: 'build_failure',
+                  version: pkg.version,
+                })
                 logger.warn({
                   err,
                   message: `Skipping failed optional dependency ${pkg.id}`,

src/install/getIsInstallable.ts

@@ -3,7 +3,10 @@ import {PackageManifest} from '@pnpm/types'
 import installChecks = require('pnpm-install-checks')
 import R = require('ramda')
 import {PkgByPkgId} from '../api/install'
-import {installCheckLogger} from '../loggers'
+import {
+  installCheckLogger,
+  skippedOptionalDependencyLogger,
+} from '../loggers'
 import {splitNodeId} from '../nodeIdUtils'
 
 export default async function getIsInstallable (
@@ -28,10 +31,13 @@ export default async function getIsInstallable (
   installCheckLogger.warn(warn)
 
   if (options.optional) {
-    const friendlyPath = nodeIdToFriendlyPath(options.nodeId, options.pkgByPkgId)
-    logger.warn({
-      message: `${friendlyPath ? `${friendlyPath}: ` : ''}Skipping failed optional dependency ${pkg.name}@${pkg.version}`,
-      warn,
+    skippedOptionalDependencyLogger.debug({
+      details: warn,
+      id: pkgId,
+      name: pkg.name,
+      parents: nodeIdToParents(options.nodeId, options.pkgByPkgId),
+      reason: 'incompatible_engine',
+      version: pkg.version,
     })
 
     return false
@@ -42,12 +48,18 @@ export default async function getIsInstallable (
   return true
 }
 
-function nodeIdToFriendlyPath (
+export function nodeIdToParents (
   nodeId: string,
   pkgByPkgId: PkgByPkgId,
 ) {
   const pkgIds = splitNodeId(nodeId).slice(2, -2)
   return pkgIds
-    .map((pkgId) => pkgByPkgId[pkgId].name)
-    .join(' > ')
+    .map((pkgId) => {
+      const pkg = pkgByPkgId[pkgId]
+      return {
+        id: pkg.id,
+        name: pkg.name,
+        version: pkg.version,
+      }
+    })
 }

src/loggers.ts

@@ -12,6 +12,7 @@ export const deprecationLogger = baseLogger('deprecation') as Logger<Deprecation
 export const rootLogger = baseLogger('root') as Logger<RootMessage>
 export const progressLogger = baseLogger('progress') as Logger<ProgressMessage>
 export const statsLogger = baseLogger('stats') as Logger<StatsMessage>
+export const skippedOptionalDependencyLogger = baseLogger('skipped-optional-dependency') as Logger<SkippedOptionalDependencyMessage>
 
 export type PackageJsonMessage = {
   initial: PackageJson,
@@ -87,6 +88,21 @@ export type StatsMessage = {
   removed: number,
 })
 
+export type SkippedOptionalDependencyMessage = {
+  details?: object,
+  parents?: Array<{id: string, name: string, version: string}>,
+} & ({
+  id: string,
+  name: string,
+  reason: 'incompatible_engine' | 'build_failure',
+  version: string,
+} | {
+  name: string | undefined,
+  version: string | undefined,
+  pref: string,
+  reason: 'resolution_failure',
+})
+
 export type ProgressLog = {name: 'pnpm:progress'} & LogBase & ProgressMessage
 
 export type StageLog = {name: 'pnpm:stage'} & LogBase & {message: 'resolution_started' | 'resolution_done' | 'importing_started' | 'importing_done'}

src/resolveDependencies.ts

@@ -26,8 +26,11 @@ import url = require('url')
 import {InstallContext, PkgByPkgId} from './api/install'
 import depsToSpecs from './depsToSpecs'
 import encodePkgId from './encodePkgId'
-import getIsInstallable from './install/getIsInstallable'
-import {deprecationLogger} from './loggers'
+import getIsInstallable, {nodeIdToParents} from './install/getIsInstallable'
+import {
+  deprecationLogger,
+  skippedOptionalDependencyLogger,
+} from './loggers'
 import logStatus from './logging/logInstallStatus'
 import {
   createNodeId,
@@ -270,9 +273,13 @@ async function install (
     })
   } catch (err) {
     if (wantedDependency.optional) {
-      logger.warn({
-        err,
-        message: `Skipping optional dependency ${wantedDependency.raw}. ${err.toString()}`,
+      skippedOptionalDependencyLogger.debug({
+        details: err,
+        name: wantedDependency.alias,
+        parents: nodeIdToParents(createNodeId(options.parentNodeId, 'fake-id'), ctx.pkgByPkgId),
+        pref: wantedDependency.pref,
+        reason: 'resolution_failure',
+        version: wantedDependency.alias ? wantedDependency.pref : undefined,
       })
       return null
     }

test/install/optionalDependencies.ts

@@ -44,9 +44,10 @@ test('skip non-existing optional dependency', async (t: tape.Test) => {
   await install(await testDefaults({reporter}))
 
   t.ok(reporter.calledWithMatch({
-    level: 'warn',
-    message: 'Skipping optional dependency i-do-not-exist@1000. Error: 404 Not Found: i-do-not-exist',
-    name: 'pnpm',
+    name: 'i-do-not-exist',
+    parents: [],
+    reason: 'resolution_failure',
+    version: '1000',
   }), 'warning reported')
 
   const m = project.requireModule('is-positive')
@@ -78,8 +79,11 @@ test('skip optional dependency that does not support the current OS', async (t:
   ])
 
   const logMatcher = sinon.match({
-    level: 'warn',
-    message: 'Skipping failed optional dependency not-compatible-with-any-os@1.0.0',
+    id: 'localhost+4873/not-compatible-with-any-os/1.0.0',
+    name: 'not-compatible-with-any-os',
+    parents: [],
+    reason: 'incompatible_engine',
+    version: '1.0.0',
   })
   const reportedTimes = reporter.withArgs(logMatcher).callCount
   t.equal(reportedTimes, 1, 'skipping optional dependency is logged')
@@ -99,8 +103,11 @@ test('skip optional dependency that does not support the current Node version',
   await project.storeHas('for-legacy-node', '1.0.0')
 
   const logMatcher = sinon.match({
-    level: 'warn',
-    message: 'Skipping failed optional dependency for-legacy-node@1.0.0',
+    id: 'localhost+4873/for-legacy-node/1.0.0',
+    name: 'for-legacy-node',
+    parents: [],
+    reason: 'incompatible_engine',
+    version: '1.0.0',
   })
   const reportedTimes = reporter.withArgs(logMatcher).callCount
   t.equal(reportedTimes, 1, 'skipping optional dependency is logged')
@@ -120,8 +127,11 @@ test('skip optional dependency that does not support the current pnpm version',
   await project.storeHas('for-legacy-pnpm', '1.0.0')
 
   const logMatcher = sinon.match({
-    level: 'warn',
-    message: 'Skipping failed optional dependency for-legacy-pnpm@1.0.0',
+    id: 'localhost+4873/for-legacy-pnpm/1.0.0',
+    name: 'for-legacy-pnpm',
+    parents: [],
+    reason: 'incompatible_engine',
+    version: '1.0.0',
   })
   const reportedTimes = reporter.withArgs(logMatcher).callCount
   t.equal(reportedTimes, 1, 'skipping optional dependency is logged')
@@ -153,8 +163,17 @@ test('optional subdependency is skipped', async (t: tape.Test) => {
   t.deepEqual(modulesInfo.skipped, ['localhost+4873/not-compatible-with-any-os/1.0.0'], 'optional subdep skipped')
 
   const logMatcher = sinon.match({
-    level: 'warn',
-    message: 'pkg-with-optional: Skipping failed optional dependency not-compatible-with-any-os@1.0.0',
+    id: 'localhost+4873/not-compatible-with-any-os/1.0.0',
+    name: 'not-compatible-with-any-os',
+    parents: [
+      {
+        id: 'localhost+4873/pkg-with-optional/1.0.0',
+        name: 'pkg-with-optional',
+        version: '1.0.0',
+      },
+    ],
+    reason: 'incompatible_engine',
+    version: '1.0.0',
   })
   const reportedTimes = reporter.withArgs(logMatcher).callCount
   t.equal(reportedTimes, 1, 'skipping optional dependency is logged')