Skip to content

refactor: use sophisticated logger #1129

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
wants to merge 12 commits into
base: main
Choose a base branch
from
Draft

refactor: use sophisticated logger #1129

Show file tree
Hide file tree
Changes from 7 commits
Commits
Show all changes
12 commits
Select commit Hold shift + click to select a range
bb10d8a
feat: add logger
jase88 Dec 4, 2023
e7d6794
feat: add logger
jase88 Dec 4, 2023
3f600e3
feat: add default log level const
jase88 Dec 5, 2023
532f853
feat: adjust string interpolation via parameters
jase88 Dec 5, 2023
91b4b48
fix: wrong placeholder
jase88 Dec 5, 2023
ecaf9a3
feat: add child logger
jase88 Dec 5, 2023
40d10c8
Merge branch 'main' into main
jase88 Dec 6, 2023
f6b09ce
Merge branch 'main' into main
jkowalleck Dec 6, 2023
b5af86b
fix: writing to stderr
jase88 Dec 6, 2023
c3abef5
Merge remote-tracking branch 'origin/main'
jase88 Dec 6, 2023
49af968
fix: raise required node version
jase88 Dec 6, 2023
8f58bca
fix: disable timestamps
jase88 Dec 7, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions package.json
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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": {
Expand Down
83 changes: 42 additions & 41 deletions src/builders.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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'
Copy link
Member

@jkowalleck jkowalleck Dec 6, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the node: notation, this might not work on node14.0 -- which is a supported branch.
will add additional CI tests and have it tested

Copy link
Member

@jkowalleck jkowalleck Dec 6, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

test run including node 14.0.0

https://github.com/CycloneDX/cyclonedx-node-npm/actions/runs/7114640707/job/19369091011?pr=1129

Copy link
Member

@jkowalleck jkowalleck Dec 6, 2023 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

tests with node14.0.0 do not complete due to a transitive dependency that is not installable.


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'
Expand Down Expand Up @@ -57,15 +59,15 @@ export class BomBuilder {
flattenComponents: boolean
shortPURLs: boolean

console: Console
logger: Logger

constructor (
toolBuilder: BomBuilder['toolBuilder'],
componentBuilder: BomBuilder['componentBuilder'],
treeBuilder: BomBuilder['treeBuilder'],
purlFactory: BomBuilder['purlFactory'],
options: BomBuilderOptions,
console_: BomBuilder['console']
logger_: BomBuilder['logger']
) {
this.toolBuilder = toolBuilder
this.componentBuilder = componentBuilder
Expand All @@ -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 {
Expand All @@ -95,31 +97,33 @@ 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,
encoding: 'buffer',
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)
Expand All @@ -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')
}
}

Expand All @@ -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, {
Expand All @@ -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()),
Expand All @@ -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

Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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
}

Expand All @@ -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
}

Expand Down
57 changes: 31 additions & 26 deletions src/cli.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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',
Expand All @@ -38,6 +40,7 @@ enum Omittable {
const OutputStdOut = '-'

interface CommandOptions {
verbosity: VerbosityLevel
ignoreNpmErrors: boolean
packageLockOnly: boolean
omit: Omittable[]
Expand All @@ -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] [--] [<package-manifest>]'
).addOption(
new Option(
'--verbosity <verbosity>',
'Which verbosity level the logger should write to STDERR'
).choices(verbosityLevels
).default(defaultLogLevel)
).addOption(
new Option(
'--ignore-npm-errors',
Expand Down Expand Up @@ -189,36 +198,35 @@ const ExitCode: Readonly<Record<string, number>> = Object.freeze({
export async function run (process: NodeJS.Process): Promise<number> {
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')
}

Expand All @@ -241,7 +249,7 @@ export async function run (process: NodeJS.Process): Promise<number> {
flattenComponents: options.flattenComponents,
shortPURLs: options.shortPURLs
},
myConsole
logger.child({}, { msgPrefix: 'BomBuilder > ' })
).buildFromProjectDir(projectDir, process)

const spec = Spec.SpecVersionDict[options.specVersion]
Expand All @@ -262,36 +270,33 @@ export async function run (process: NodeJS.Process): Promise<number> {
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
Expand Down
Loading