diff --git a/package.json b/package.json index fa776ffc9..beb498157 100644 --- a/package.json +++ b/package.json @@ -55,6 +55,8 @@ "commander": "^10.0.0", "normalize-package-data": "^3||^4||^5||^6", "packageurl-js": "^1.2.1", + "pino": "^8.16.2", + "pino-pretty": "^10.2.3", "xmlbuilder2": "^3.0.2" }, "devDependencies": { @@ -74,7 +76,7 @@ }, "type": "commonjs", "engines": { - "node": ">=14", + "node": ">=14.17.0", "npm": "6 - 10" }, "directories": { diff --git a/src/builders.ts b/src/builders.ts index 07419cd12..0aff40a95 100644 --- a/src/builders.ts +++ b/src/builders.ts @@ -17,12 +17,14 @@ SPDX-License-Identifier: Apache-2.0 Copyright (c) OWASP Foundation. All Rights Reserved. */ +import { existsSync } from 'node:fs' +import * as path from 'node:path' + import { type Builders, Enums, type Factories, Models, Utils } from '@cyclonedx/cyclonedx-library' -import { existsSync } from 'fs' import * as normalizePackageData from 'normalize-package-data' import { type PackageURL } from 'packageurl-js' -import * as path from 'path' +import { type Logger } from './logger' import { makeNpmRunner, type runFunc } from './npmRunner' import { PropertyNames, PropertyValueBool } from './properties' import { versionCompare } from './versionCompare' @@ -57,7 +59,7 @@ export class BomBuilder { flattenComponents: boolean shortPURLs: boolean - console: Console + logger: Logger constructor ( toolBuilder: BomBuilder['toolBuilder'], @@ -65,7 +67,7 @@ export class BomBuilder { treeBuilder: BomBuilder['treeBuilder'], purlFactory: BomBuilder['purlFactory'], options: BomBuilderOptions, - console_: BomBuilder['console'] + logger_: BomBuilder['logger'] ) { this.toolBuilder = toolBuilder this.componentBuilder = componentBuilder @@ -80,7 +82,7 @@ export class BomBuilder { this.flattenComponents = options.flattenComponents ?? false this.shortPURLs = options.shortPURLs ?? false - this.console = console_ + this.logger = logger_ } buildFromProjectDir (projectDir: string, process: NodeJS.Process): Models.Bom { @@ -95,7 +97,7 @@ export class BomBuilder { private getNpmVersion (npmRunner: runFunc, process_: NodeJS.Process): string { let version: string - this.console.info('INFO | detect NPM version ...') + this.logger.info('detect NPM version ...') try { version = npmRunner(['--version'], { env: process_.env, @@ -103,23 +105,25 @@ export class BomBuilder { maxBuffer: Number.MAX_SAFE_INTEGER // DIRTY but effective }).toString().trim() } catch (runError: any) { - this.console.group('DEBUG | npm-ls: STDOUT') - this.console.debug('%s', runError.stdout) - this.console.groupEnd() - this.console.group('WARN | npm-ls: MESSAGE') - this.console.warn('%s', runError.message) - this.console.groupEnd() - this.console.group('ERROR | npm-ls: STDERR') - this.console.error('%s', runError.stderr) - this.console.groupEnd() + const { stdout, message, stderr } = runError + + this.logger.debug('npm-ls: STDOUT') + this.logger.debug('%s', stdout) + + this.logger.warn('npm-ls: MESSAGE') + this.logger.warn('%s', message) + + this.logger.error('npm-ls: STDERR') + this.logger.error('%s', stderr) + throw runError } - this.console.debug('DEBUG | detected NPM version %j', version) + this.logger.debug('detected NPM version %j', version) return version } private fetchNpmLs (projectDir: string, process_: NodeJS.Process): [any, string | undefined] { - const npmRunner = makeNpmRunner(process_, this.console) + const npmRunner = makeNpmRunner(process_, this.logger) const npmVersionR = this.getNpmVersion(npmRunner, process_) const npmVersionT = this.versionTuple(npmVersionR) @@ -140,7 +144,7 @@ export class BomBuilder { if (npmVersionT[0] >= 7) { args.push('--package-lock-only') } else { - this.console.warn('WARN | your NPM does not support "--package-lock-only", internally skipped this option') + this.logger.warn('your NPM does not support "--package-lock-only", internally skipped this option') } } @@ -154,20 +158,19 @@ export class BomBuilder { for (const odt of this.omitDependencyTypes) { switch (odt) { case 'dev': - this.console.warn('WARN | your NPM does not support "--omit=%s", internally using "--production" to mitigate', odt) + this.logger.warn('your NPM does not support "--omit=%s", internally using "--production" to mitigate', odt) args.push('--production') break case 'peer': case 'optional': - this.console.warn('WARN | your NPM does not support "--omit=%s", internally skipped this option', odt) + this.logger.warn('your NPM does not support "--omit=%s", internally skipped this option', odt) break } } } - // TODO use instead ? : https://www.npmjs.com/package/debug ? - this.console.info('INFO | gather dependency tree ...') - this.console.debug('DEBUG | npm-ls: run npm with %j in %j', args, projectDir) + this.logger.info('gather dependency tree ...') + this.logger.debug('npm-ls: run npm with %j in %j', args, projectDir) let npmLsReturns: Buffer try { npmLsReturns = npmRunner(args, { @@ -177,24 +180,23 @@ export class BomBuilder { maxBuffer: Number.MAX_SAFE_INTEGER // DIRTY but effective }) } catch (runError: any) { - // this.console.group('DEBUG | npm-ls: STDOUT') - // this.console.debug('%s', runError.stdout) - // this.console.groupEnd() - this.console.group('WARN | npm-ls: MESSAGE') - this.console.warn('%s', runError.message) - this.console.groupEnd() - this.console.group('ERROR | npm-ls: STDERR') - this.console.error('%s', runError.stderr) - this.console.groupEnd() + const { message, stderr } = runError + + this.logger.warn('npm-ls: MESSAGE') + this.logger.warn('%s', message) + + this.logger.error('npm-ls: STDERR') + this.logger.error('%s', stderr) + if (!this.ignoreNpmErrors) { throw new Error(`npm-ls exited with errors: ${ runError.status as string ?? 'noStatus'} ${ runError.signal as string ?? 'noSignal'}`) } - this.console.debug('DEBUG | npm-ls exited with errors that are to be ignored.') + this.logger.debug('npm-ls exited with errors that are to be ignored.') npmLsReturns = runError.stdout ?? Buffer.alloc(0) } - // this.console.debug('stdout: %s', npmLsReturns) + try { return [ JSON.parse(npmLsReturns.toString()), @@ -207,8 +209,7 @@ export class BomBuilder { } buildFromNpmLs (data: any, npmVersion?: string): Models.Bom { - // TODO use instead ? : https://www.npmjs.com/package/debug ? - this.console.info('INFO | build BOM ...') + this.logger.info('build BOM ...') // region all components & dependencies @@ -327,7 +328,7 @@ export class BomBuilder { dep = _dep ?? new DummyComponent(Enums.ComponentType.Library, `InterferedDependency.${depName as string}`) if (dep instanceof DummyComponent) { - this.console.warn('WARN | InterferedDependency $j', dep.name) + this.logger.warn('InterferedDependency $j', dep.name) } allComponents.set(depData.path, dep) @@ -415,21 +416,21 @@ export class BomBuilder { // older npm-ls versions (v6) hide properties behind a `_` const isOptional = (data.optional ?? data._optional) === true if (isOptional && this.omitDependencyTypes.has('optional')) { - this.console.debug('DEBUG | omit optional component: %j %j', data.name, data._id) + this.logger.debug('omit optional component: %j %j', data.name, data._id) return false } // older npm-ls versions (v6) hide properties behind a `_` const isDev = (data.dev ?? data._development) === true if (isDev && this.omitDependencyTypes.has('dev')) { - this.console.debug('DEBUG | omit dev component: %j %j', data.name, data._id) + this.logger.debug('omit dev component: %j %j', data.name, data._id) return false } // attention: `data.devOptional` are not to be skipped with devs, since they are still required by optionals. const isDevOptional = data.devOptional === true if (isDevOptional && this.omitDependencyTypes.has('dev') && this.omitDependencyTypes.has('optional')) { - this.console.debug('DEBUG | omit devOptional component: %j %j', data.name, data._id) + this.logger.debug('omit devOptional component: %j %j', data.name, data._id) return false } @@ -448,7 +449,7 @@ export class BomBuilder { const component = this.componentBuilder.makeComponent(_dataC, type) if (component === undefined) { - this.console.debug('DEBUG | skip broken component: %j %j', data.name, data._id) + this.logger.debug('skip broken component: %j %j', data.name, data._id) return undefined } diff --git a/src/cli.ts b/src/cli.ts index 45e2b6a42..30165cdc2 100644 --- a/src/cli.ts +++ b/src/cli.ts @@ -17,12 +17,14 @@ SPDX-License-Identifier: Apache-2.0 Copyright (c) OWASP Foundation. All Rights Reserved. */ +import { existsSync, openSync, writeSync } from 'node:fs' +import { dirname, resolve } from 'node:path' + import { Builders, Enums, Factories, Serialize, Spec, Validation } from '@cyclonedx/cyclonedx-library' import { Argument, Command, Option } from 'commander' -import { existsSync, openSync, writeSync } from 'fs' -import { dirname, resolve } from 'path' import { BomBuilder, TreeBuilder } from './builders' +import { createLogger, defaultLogLevel, type VerbosityLevel, verbosityLevels } from './logger' enum OutputFormat { JSON = 'JSON', @@ -38,6 +40,7 @@ enum Omittable { const OutputStdOut = '-' interface CommandOptions { + verbosity: VerbosityLevel ignoreNpmErrors: boolean packageLockOnly: boolean omit: Omittable[] @@ -58,6 +61,12 @@ function makeCommand (process: NodeJS.Process): Command { ).usage( // Need to add the `[--]` manually, to indicate how to stop a variadic option. '[options] [--] []' + ).addOption( + new Option( + '--verbosity ', + 'Which verbosity level the logger should write to STDERR' + ).choices(verbosityLevels + ).default(defaultLogLevel) ).addOption( new Option( '--ignore-npm-errors', @@ -189,36 +198,35 @@ const ExitCode: Readonly> = Object.freeze({ export async function run (process: NodeJS.Process): Promise { process.title = 'cyclonedx-node-npm' - // all output shall be bound to stdError - stdOut is for result output only - const myConsole = new console.Console(process.stderr, process.stderr) - const program = makeCommand(process) program.parse(process.argv) const options: CommandOptions = program.opts() - myConsole.debug('DEBUG | options: %j', options) + const logger = createLogger(options.verbosity) + + logger.debug('options: %j', options) const packageFile = resolve(process.cwd(), program.args[0] ?? 'package.json') if (!existsSync(packageFile)) { throw new Error(`missing project's manifest file: ${packageFile}`) } - myConsole.debug('DEBUG | packageFile: %s', packageFile) + logger.debug('packageFile: %s', packageFile) const projectDir = dirname(packageFile) - myConsole.info('INFO | projectDir: %s', projectDir) + logger.info('projectDir: %s', projectDir) if (existsSync(resolve(projectDir, 'npm-shrinkwrap.json'))) { - myConsole.debug('DEBUG | detected a npm shrinkwrap file') + logger.debug('detected a npm shrinkwrap file') } else if (existsSync(resolve(projectDir, 'package-lock.json'))) { - myConsole.debug('DEBUG | detected a package lock file') + logger.debug('detected a package lock file') } else if (!options.packageLockOnly && existsSync(resolve(projectDir, 'node_modules'))) { - myConsole.debug('DEBUG | detected a node_modules dir') + logger.debug('detected a node_modules dir') // npm7 and later also might put a `node_modules/.package-lock.json` file } else { - myConsole.log('LOG | No evidence: no package lock file nor npm shrinkwrap file') + logger.trace('No evidence: no package lock file nor npm shrinkwrap file') if (!options.packageLockOnly) { - myConsole.log('LOG | No evidence: no node_modules dir') + logger.trace('No evidence: no node_modules dir') } - myConsole.info('INFO | ? Did you forget to run `npm install` on your project accordingly ?') + logger.info('Did you forget to run `npm install` on your project accordingly ?') throw new Error('missing evidence') } @@ -241,7 +249,7 @@ export async function run (process: NodeJS.Process): Promise { flattenComponents: options.flattenComponents, shortPURLs: options.shortPURLs }, - myConsole + logger.child({}, { msgPrefix: 'BomBuilder > ' }) ).buildFromProjectDir(projectDir, process) const spec = Spec.SpecVersionDict[options.specVersion] @@ -262,36 +270,33 @@ export async function run (process: NodeJS.Process): Promise { break } - myConsole.log('LOG | serialize BOM') + logger.trace('serialize BOM') const serialized = serializer.serialize(bom, { sortLists: options.outputReproducible, space: 2 }) if (options.validate) { - myConsole.log('LOG | try validate BOM result ...') + logger.trace('try validate BOM result ...') try { const validationErrors = await validator.validate(serialized) if (validationErrors !== null) { - myConsole.debug('DEBUG | BOM result invalid. details: ', validationErrors) - myConsole.error('ERROR | Failed to generate valid BOM.') - myConsole.warn( - 'WARN | Please report the issue and provide the npm lock file of the current project to:\n' + - ' | https://github.com/CycloneDX/cyclonedx-node-npm/issues/new?template=ValidationError-report.md&labels=ValidationError&title=%5BValidationError%5D') + logger.debug('BOM result invalid. details: ', validationErrors) + logger.error('Failed to generate valid BOM.') + logger.warn('Please report the issue and provide the npm lock file of the current project to: https://github.com/CycloneDX/cyclonedx-node-npm/issues/new?template=ValidationError-report.md&labels=ValidationError&title=%5BValidationError%5D') return ExitCode.FAILURE } } catch (err) { if (err instanceof Validation.MissingOptionalDependencyError) { - myConsole.info('INFO | skipped validate BOM:', err.message) + logger.info('skipped validate BOM:', err.message) } else { - myConsole.error('ERROR | unexpected error') + logger.error('unexpected error') throw err } } } - // TODO use instead ? : https://www.npmjs.com/package/debug ? - myConsole.log('LOG | writing BOM to', options.outputFile) + logger.trace('writing BOM to', options.outputFile) writeSync( options.outputFile === OutputStdOut ? process.stdout.fd diff --git a/src/logger.ts b/src/logger.ts new file mode 100644 index 000000000..41292c92c --- /dev/null +++ b/src/logger.ts @@ -0,0 +1,47 @@ +/*! +This file is part of CycloneDX generator for NPM projects. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. + +SPDX-License-Identifier: Apache-2.0 +Copyright (c) OWASP Foundation. All Rights Reserved. +*/ + +import { type BaseLogger, type Level, type LevelWithSilent, type LoggerExtras, pino } from 'pino' + +const logLevels: Level[] = ['debug', 'error', 'fatal', 'warn', 'info', 'trace'] as const +export const verbosityLevels: LevelWithSilent[] = [...logLevels, 'silent'] as const + +export type Logger = BaseLogger & LoggerExtras<{ + level: LevelWithSilent + name: string + transport: { options: { colorize: boolean, ignore: string }, target: string } +}> + +export type VerbosityLevel = LevelWithSilent + +export const createLogger: (verbosityLevel: VerbosityLevel) => Logger = (verbosityLevel: VerbosityLevel) => pino({ + name: 'cyclonedx-node-npm', + level: verbosityLevel, + timestamp: false, + transport: { + target: 'pino-pretty', + options: { + colorize: true, + ignore: 'pid,name,hostname', + destination: 2 + } + } +}) + +export const defaultLogLevel: VerbosityLevel = 'warn' diff --git a/src/npmRunner.ts b/src/npmRunner.ts index 4c32d53be..22f511c87 100644 --- a/src/npmRunner.ts +++ b/src/npmRunner.ts @@ -17,9 +17,11 @@ SPDX-License-Identifier: Apache-2.0 Copyright (c) OWASP Foundation. All Rights Reserved. */ -import { execFileSync, execSync, type ExecSyncOptionsWithBufferEncoding } from 'child_process' -import { existsSync } from 'fs' -import { resolve } from 'path' +import { execFileSync, execSync, type ExecSyncOptionsWithBufferEncoding } from 'node:child_process' +import { existsSync } from 'node:fs' +import { resolve } from 'node:path' + +import { type Logger } from './logger' /** !attention: args might not be shell-save. */ export type runFunc = (args: string[], options: ExecSyncOptionsWithBufferEncoding) => Buffer @@ -45,7 +47,7 @@ const jsMatcher = /\.[cm]?js$/ /** * @throws {Error} when npm path unexpected */ -function getExecPath (process_: NodeJS.Process, console_: Console): string | undefined { +function getExecPath (process_: NodeJS.Process, logger_: Logger): string | undefined { // `npm_execpath` will be whichever cli script has called this application by npm. // This can be `npm`, `npx`, or `undefined` if called by `node` directly. const execPath = process_.env.npm_execpath ?? '' @@ -55,7 +57,7 @@ function getExecPath (process_: NodeJS.Process, console_: Console): string | und if (npxMatcher.test(execPath)) { // `npm` must be used for executing `ls`. - console_.debug('DEBUG | command: npx-cli.js usage detected, checking for npm-cli.js ...') + logger_.debug('command: npx-cli.js usage detected, checking for npm-cli.js ...') // Typically `npm-cli.js` is alongside `npx-cli.js`, as such we attempt to use this and validate it exists. // Replace the script in the path, and normalise it with resolve (eliminates any extraneous path separators). const npmPath = resolve(execPath.replace(npxMatcher, '$1npm-cli.js')) @@ -69,20 +71,20 @@ function getExecPath (process_: NodeJS.Process, console_: Console): string | und throw new Error(`unexpected NPM execPath: ${execPath}`) } -export function makeNpmRunner (process_: NodeJS.Process, console_: Console): runFunc { - const execPath = getExecPath(process_, console_) +export function makeNpmRunner (process_: NodeJS.Process, logger_: Logger): runFunc { + const execPath = getExecPath(process_, logger_) if (execPath === undefined) { - console_.debug('DEBUG | makeNpmRunner caused execSync "npm"') + logger_.debug('makeNpmRunner caused execSync "npm"') // not shell-save - but this is okay four our use case - since we have complete control over `args` in the caller. return (args, options) => execSync('npm ' + args.join(' '), options) } if (jsMatcher.test(execPath)) { const nodeExecPath = process_.execPath - console_.debug('DEBUG | makeNpmRunner caused execFileSync "%s" with "-- %s"', nodeExecPath, execPath) + logger_.debug('makeNpmRunner caused execFileSync "%s" with "-- %s"', nodeExecPath, execPath) return (args, options) => execFileSync(nodeExecPath, ['--', execPath, ...args], options) } - console_.debug('DEBUG | makeNpmRunner caused execFileSync "%s"', execPath) + logger_.debug('makeNpmRunner caused execFileSync "%s"', execPath) return (args, options) => execFileSync(execPath, args, options) }