feat: better reporting of child processes output

PR #1573

* feat(reporting): collapse build output of deps inside node_modules

ref #1440

* feat(reporting): nicer reporting of lifecycle output

* feat(reporting): print the number of collapsed lines

* feat(reporting): always print the status of the child processes

* refactor: reporting

* feat(reporting): nicer indentation

* feat(reporting): report duration of script run

close #1440
This commit is contained in:
Zoltan Kochan
2018-12-23 16:42:27 +02:00
committed by GitHub
parent e678bfac7d
commit ded5171a49
14 changed files with 779 additions and 236 deletions

View File

@@ -14,8 +14,10 @@ export type LifecycleMessage = {
stdio: 'stdout' | 'stderr',
} | {
exitCode: number,
optional: boolean,
} | {
script: string,
optional: boolean,
})
export type LifecycleLog = {name: 'pnpm:lifecycle'} & LogBase & LifecycleMessage

View File

@@ -49,12 +49,12 @@
"most": "1.7.3",
"normalize-path": "3.0.0",
"pretty-bytes": "5.1.0",
"pretty-time": "1.1.0",
"ramda": "0.26.1",
"right-pad": "1.0.1",
"semver": "5.6.0",
"stacktracey": "1.2.106",
"string-length": "2.0.0",
"string.prototype.padstart": "3.0.0",
"strip-ansi": "5.0.0",
"zen-push": "0.2.1"
},

View File

@@ -1,16 +1,17 @@
import { LifecycleLog } from '@pnpm/core-loggers'
import chalk from 'chalk'
import most = require('most')
import rightPad = require('right-pad')
import padStart = require('string.prototype.padstart')
import path = require('path')
import prettyTime = require('pretty-time')
import stripAnsi = require('strip-ansi')
import PushStream = require('zen-push')
import { EOL } from '../constants'
import {
hlValue,
PREFIX_MAX_LENGTH,
} from './outputConstants'
import formatPrefix from './utils/formatPrefix'
import formatPrefix, { formatPrefixNoTrim } from './utils/formatPrefix'
const NODE_MODULES = `${path.sep}node_modules${path.sep}`
export default (
log$: {
@@ -22,19 +23,21 @@ export default (
width: number,
},
) => {
// When the reporter is not append-only, the length of output is limited
// When the reporter is not append-only, the length of output is limited
// in order to reduce flickering
const formatLifecycle = formatLifecycleHideOverflow.bind(null, opts.appendOnly ? Infinity : opts.width)
if (opts.appendOnly) {
return most.of(
log$.lifecycle
.map((log: LifecycleLog) => ({ msg: formatLifecycle(opts.cwd, log) })),
.map((log: LifecycleLog) => ({ msg: formatLifecycleHideOverflowForAppendOnly(opts.cwd, log) })),
)
}
const lifecycleMessages: {
[depPath: string]: {
collapsed: boolean,
output: string[],
script: string,
startTime: [number, number],
status: string,
},
} = {}
const lifecycleStreamByDepPath: {
@@ -50,25 +53,28 @@ export default (
log$.lifecycle // tslint:disable-line
.forEach((log: LifecycleLog) => {
const key = `${log.stage}:${log.depPath}`
lifecycleMessages[key] = lifecycleMessages[key] || { output: [] }
if (log['script']) {
lifecycleMessages[key].script = formatLifecycle(opts.cwd, log)
lifecycleMessages[key] = lifecycleMessages[key] || {
collapsed: log.wd.includes(NODE_MODULES),
output: [],
startTime: process.hrtime(),
status: formatIndentedStatus(chalk.magentaBright('Running...')),
}
const exit = typeof log['exitCode'] === 'number'
let msg: string
if (lifecycleMessages[key].collapsed) {
msg = renderCollapsedScriptOutput(log, lifecycleMessages[key], { cwd: opts.cwd, exit, maxWidth: opts.width })
} else {
if (!lifecycleMessages[key].output.length || log['exitCode'] !== 0) {
lifecycleMessages[key].output.push(formatLifecycle(opts.cwd, log))
}
if (lifecycleMessages[key].output.length > 3) {
lifecycleMessages[key].output.shift()
}
msg = renderScriptOutput(log, lifecycleMessages[key], { cwd: opts.cwd, exit, maxWidth: opts.width })
}
if (exit) {
delete lifecycleMessages[key]
}
if (!lifecycleStreamByDepPath[key]) {
lifecycleStreamByDepPath[key] = new PushStream()
lifecyclePushStream.next(most.from(lifecycleStreamByDepPath[key].observable))
}
lifecycleStreamByDepPath[key].next({
msg: EOL + [lifecycleMessages[key].script].concat(lifecycleMessages[key].output).join(EOL),
})
if (typeof log['exitCode'] === 'number') {
lifecycleStreamByDepPath[key].next({ msg })
if (exit) {
lifecycleStreamByDepPath[key].complete()
}
})
@@ -76,33 +82,146 @@ export default (
return most.from(lifecyclePushStream.observable) as most.Stream<most.Stream<{ msg: string }>>
}
function renderCollapsedScriptOutput (
log: LifecycleLog,
messageCache: {
collapsed: boolean,
output: string[],
script: string,
startTime: [number, number],
status: string,
},
opts: {
cwd: string,
exit: boolean,
maxWidth: number,
},
) {
messageCache['label'] = messageCache['label'] ||
`${highlightLastFolder(formatPrefixNoTrim(opts.cwd, log.wd))}: Running ${log.stage} script`
if (!opts.exit) {
updateMessageCache(log, messageCache, opts)
return `${messageCache['label']}...`
}
const time = prettyTime(process.hrtime(messageCache.startTime))
if (log['exitCode'] === 0) {
return `${messageCache['label']}, done in ${time}`
}
if (log['optional'] === true) {
return `${messageCache['label']}, failed in ${time} (skipped as optional)`
}
return `${messageCache['label']}, failed in ${time}${EOL}${renderScriptOutput(log, messageCache, opts)}`
}
function renderScriptOutput (
log: LifecycleLog,
messageCache: {
collapsed: boolean,
output: string[],
script: string,
startTime: [number, number],
status: string,
},
opts: {
cwd: string,
exit: boolean,
maxWidth: number,
},
) {
updateMessageCache(log, messageCache, opts)
if (opts.exit && log['exitCode'] !== 0) {
return [
messageCache.script,
...messageCache.output,
messageCache.status,
].join(EOL)
}
if (messageCache.output.length > 10) {
return [
messageCache.script,
`[${messageCache.output.length - 10} lines collapsed]`,
...messageCache.output.slice(messageCache.output.length - 10),
messageCache.status,
].join(EOL)
}
return [
messageCache.script,
...messageCache.output,
messageCache.status,
].join(EOL)
}
function updateMessageCache (
log: LifecycleLog,
messageCache: {
collapsed: boolean,
output: string[],
script: string,
startTime: [number, number],
status: string,
},
opts: {
cwd: string,
exit: boolean,
maxWidth: number,
},
) {
if (log['script']) {
const prefix = formatLifecycleScriptPrefix(opts.cwd, log.wd, log.stage)
const maxLineWidth = opts.maxWidth - prefix.length - 2 + ANSI_ESCAPES_LENGTH_OF_PREFIX
messageCache.script = `${prefix}$ ${cutLine(log['script'], maxLineWidth)}`
} else if (opts.exit) {
const time = prettyTime(process.hrtime(messageCache.startTime))
if (log['exitCode'] === 0) {
messageCache.status = formatIndentedStatus(chalk.magentaBright(`Done in ${time}`))
} else {
messageCache.status = formatIndentedStatus(chalk.red(`Failed in ${time}`))
}
} else {
messageCache.output.push(formatIndentedOutput(opts.maxWidth, log))
}
}
function formatIndentedStatus (status: string) {
return `${chalk.magentaBright('└─')} ${status}`
}
function highlightLastFolder (p: string) {
const lastSlash = p.lastIndexOf('/') + 1
return `${chalk.gray(p.substr(0, lastSlash))}${p.substr(lastSlash)}`
}
const ANSI_ESCAPES_LENGTH_OF_PREFIX = hlValue(' ').length - 1
function formatLifecycleHideOverflow (
maxWidth: number,
function formatLifecycleHideOverflowForAppendOnly (
cwd: string,
logObj: LifecycleLog,
) {
const prefix = `${
logObj.wd === logObj.depPath
? rightPad(formatPrefix(cwd, logObj.wd), PREFIX_MAX_LENGTH)
: rightPad(logObj.depPath, PREFIX_MAX_LENGTH)
} | ${hlValue(padStart(logObj.stage, 11))}`
const prefix = formatLifecycleScriptPrefix(cwd, logObj.wd, logObj.stage)
if (typeof logObj['exitCode'] === 'number') {
if (logObj['exitCode'] === 0) {
return `${prefix}: Done`
} else {
return `${prefix}: Failed`
}
}
if (logObj['script']) {
return `${prefix}$ ${logObj['script']}`
}
if (logObj['exitCode'] === 0) {
return `${prefix}: done`
}
const maxLineWidth = maxWidth - prefix.length - 2 + ANSI_ESCAPES_LENGTH_OF_PREFIX
const line = formatLine(maxLineWidth, logObj)
const line = formatLine(Infinity, logObj)
return `${prefix}: ${line}`
}
function formatLine (maxWidth: number, logObj: LifecycleLog) {
if (typeof logObj['exitCode'] === 'number') return chalk.red(`Exited with ${logObj['exitCode']}`)
function formatIndentedOutput (maxWidth: number, logObj: LifecycleLog) {
return `${chalk.magentaBright('│')} ${formatLine(maxWidth - 2, logObj)}`
}
const line = stripAnsi(logObj['line']).substr(0, maxWidth)
function formatLifecycleScriptPrefix (cwd: string, wd: string, stage: string) {
return `${formatPrefix(cwd, wd)} ${hlValue(stage)}`
}
function formatLine (maxWidth: number, logObj: LifecycleLog) {
const line = cutLine(logObj['line'], maxWidth)
// TODO: strip only the non-color/style ansi escape codes
if (logObj['stdio'] === 'stderr') {
@@ -110,3 +229,7 @@ function formatLine (maxWidth: number, logObj: LifecycleLog) {
}
return line
}
function cutLine (line: string, maxLength: number) {
return stripAnsi(line).substr(0, maxLength)
}

View File

@@ -3,7 +3,7 @@ import path = require('path')
import { PREFIX_MAX_LENGTH } from '../outputConstants'
export default function formatPrefix (cwd: string, prefix: string) {
prefix = normalize(path.relative(cwd, prefix) || '.')
prefix = formatPrefixNoTrim(cwd, prefix)
if (prefix.length <= PREFIX_MAX_LENGTH) {
return prefix
@@ -19,3 +19,7 @@ export default function formatPrefix (cwd: string, prefix: string) {
return `...${shortPrefix.substr(separatorLocation)}`
}
export function formatPrefixNoTrim (cwd: string, prefix: string) {
return normalize(path.relative(cwd, prefix) || '.')
}

View File

@@ -3,7 +3,6 @@ import { PnpmConfigs } from '@pnpm/config'
import {
deprecationLogger,
hookLogger,
lifecycleLogger,
packageJsonLogger,
progressLogger,
rootLogger,
@@ -26,6 +25,7 @@ import path = require('path')
import R = require('ramda')
import StackTracey = require('stacktracey')
import test = require('tape')
import './reportingLifecycleScripts'
import './reportingScope'
const WARN = chalk.bgYellow.black('\u2009WARN\u2009')
@@ -37,9 +37,6 @@ const SUB = chalk.red('-')
const h1 = chalk.cyanBright
const hlValue = chalk.cyanBright
const hlPkgId = chalk['whiteBright']
const POSTINSTALL = hlValue('postinstall')
const PREINSTALL = hlValue(' preinstall')
const INSTALL = hlValue(' install')
const EOL = '\n'
@@ -515,175 +512,6 @@ test('prints summary correctly when the same package is specified both in option
})
})
test('groups lifecycle output', t => {
const output$ = toOutput$({
context: { argv: ['install'] },
reportingOptions: { outputMaxWidth: 79 },
streamParser: createStreamParser(),
})
const pkgId = 'registry.npmjs.org/foo/1.0.0'
const wd = process.cwd()
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
script: 'node foo',
stage: 'preinstall',
stdio: 'stdout',
wd,
})
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,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
script: 'node foo',
stage: 'postinstall',
stdio: 'stdout',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
line: 'foo I',
stage: 'postinstall',
stdio: 'stdout',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/bar/1.0.0',
script: 'node bar',
stage: 'postinstall',
stdio: 'stdout',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/bar/1.0.0',
line: 'bar I',
stage: 'postinstall',
stdio: 'stdout',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
line: 'foo II',
stage: 'postinstall',
stdio: 'stdout',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
line: 'foo III',
stage: 'postinstall',
stdio: 'stdout',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/qar/1.0.0',
script: 'node qar',
stage: 'install',
stdio: 'stdout',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/qar/1.0.0',
exitCode: 0,
stage: 'install',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
exitCode: 0,
stage: 'postinstall',
wd,
})
t.plan(1)
output$.skip(9).take(1).map(normalizeNewline).subscribe({
complete: () => t.end(),
error: t.end,
next: output => {
t.equal(output, EOL + stripIndents`
registry.npmjs.org/foo/1.0.0 | ${PREINSTALL}$ node foo
registry.npmjs.org/foo/1.0.0 | ${PREINSTALL}: foo 0 1 2 3 4 5 6 7 8 9
registry.npmjs.org/foo/1.0.0 | ${POSTINSTALL}$ node foo
registry.npmjs.org/foo/1.0.0 | ${POSTINSTALL}: foo I
registry.npmjs.org/foo/1.0.0 | ${POSTINSTALL}: foo II
registry.npmjs.org/foo/1.0.0 | ${POSTINSTALL}: foo III
registry.npmjs.org/bar/1.0.0 | ${POSTINSTALL}$ node bar
registry.npmjs.org/bar/1.0.0 | ${POSTINSTALL}: bar I
registry.npmjs.org/qar/1.0.0 | ${INSTALL}$ node qar
registry.npmjs.org/qar/1.0.0 | ${INSTALL}: done
`)
},
})
})
// Many libs use stderr for logging, so showing all stderr adds not much value
test['skip']('prints lifecycle progress', t => {
const output$ = toOutput$({
context: { argv: ['install'] },
streamParser: createStreamParser(),
})
const wd = process.cwd()
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
line: 'foo I',
script: 'postinstall',
stage: 'postinstall',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/bar/1.0.0',
line: 'bar I',
script: 'postinstall',
stage: 'postinstall',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
line: 'foo II',
script: 'postinstall',
stage: 'postinstall',
stdio: 'stderr',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
line: 'foo III',
script: 'postinstall',
stage: 'postinstall',
wd,
})
t.plan(1)
const childOutputColor = chalk.grey
const childOutputError = chalk.red
output$.skip(3).take(1).map(normalizeNewline).subscribe({
complete: () => t.end(),
error: t.end,
next: output => {
t.equal(output, stripIndents`
Running ${POSTINSTALL} for ${hlPkgId('registry.npmjs.org/foo/1.0.0')}: ${childOutputColor('foo I')}
Running ${POSTINSTALL} for ${hlPkgId('registry.npmjs.org/foo/1.0.0')}! ${childOutputError('foo II')}
Running ${POSTINSTALL} for ${hlPkgId('registry.npmjs.org/foo/1.0.0')}: ${childOutputColor('foo III')}
Running ${POSTINSTALL} for ${hlPkgId('registry.npmjs.org/bar/1.0.0')}: ${childOutputColor('bar I')}
`)
},
})
})
test('prints generic error', t => {
const output$ = toOutput$({
context: { argv: ['install'] },

View File

@@ -0,0 +1,574 @@
import { lifecycleLogger } from '@pnpm/core-loggers'
import { toOutput$ } from '@pnpm/default-reporter'
import { createStreamParser } from '@pnpm/logger'
import chalk from 'chalk'
import { stripIndents } from 'common-tags'
import normalizeNewline = require('normalize-newline')
import path = require('path')
import test = require('tape')
const hlValue = chalk.cyanBright
const hlPkgId = chalk['whiteBright']
const POSTINSTALL = hlValue('postinstall')
const PREINSTALL = hlValue('preinstall')
const INSTALL = hlValue('install')
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) {
return text
.replace(/Done in [a-z0-9μ]+/g, 'Done in 1s')
.replace(/done in [a-z0-9μ]+/g, 'done in 1s')
.replace(/Failed in [a-z0-9μ]+/g, 'Failed in 1s')
.replace(/failed in [a-z0-9μ]+/g, 'failed in 1s')
}
test('groups lifecycle output', t => {
const output$ = toOutput$({
context: { argv: ['install'] },
reportingOptions: { outputMaxWidth: 79 },
streamParser: createStreamParser(),
})
lifecycleLogger.debug({
depPath: 'packages/foo',
optional: false,
script: 'node foo',
stage: 'preinstall',
wd: 'packages/foo',
})
lifecycleLogger.debug({
depPath: 'packages/foo',
line: 'foo 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30',
stage: 'preinstall',
stdio: 'stdout',
wd: 'packages/foo',
})
lifecycleLogger.debug({
depPath: 'packages/foo',
optional: false,
script: 'node foo',
stage: 'postinstall',
wd: 'packages/foo',
})
lifecycleLogger.debug({
depPath: 'packages/foo',
line: 'foo I',
stage: 'postinstall',
stdio: 'stdout',
wd: 'packages/foo',
})
lifecycleLogger.debug({
depPath: 'packages/bar',
optional: false,
script: 'node bar',
stage: 'postinstall',
wd: 'packages/bar',
})
lifecycleLogger.debug({
depPath: 'packages/bar',
line: 'bar I',
stage: 'postinstall',
stdio: 'stdout',
wd: 'packages/bar',
})
lifecycleLogger.debug({
depPath: 'packages/foo',
line: 'foo II',
stage: 'postinstall',
stdio: 'stdout',
wd: 'packages/foo',
})
lifecycleLogger.debug({
depPath: 'packages/foo',
line: 'foo III',
stage: 'postinstall',
stdio: 'stdout',
wd: 'packages/foo',
})
lifecycleLogger.debug({
depPath: 'packages/qar',
optional: false,
script: 'node qar',
stage: 'install',
wd: 'packages/qar',
})
lifecycleLogger.debug({
depPath: 'packages/qar',
exitCode: 0,
optional: false,
stage: 'install',
wd: 'packages/qar'
})
lifecycleLogger.debug({
depPath: 'packages/foo',
exitCode: 0,
optional: false,
stage: 'postinstall',
wd: 'packages/foo'
})
t.plan(1)
output$.skip(9).take(1).map(normalizeNewline).subscribe({
complete: () => t.end(),
error: t.end,
next: (output: string) => {
t.equal(replaceTimeWith1Sec(output), stripIndents`
packages/foo ${PREINSTALL}$ node foo
${OUTPUT_INDENTATION} foo 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27
${STATUS_INDENTATION} ${STATUS_RUNNING}
packages/foo ${POSTINSTALL}$ node foo
${OUTPUT_INDENTATION} foo I
${OUTPUT_INDENTATION} foo II
${OUTPUT_INDENTATION} foo III
${STATUS_INDENTATION} ${STATUS_RUNNING}
packages/bar ${POSTINSTALL}$ node bar
${OUTPUT_INDENTATION} bar I
${STATUS_INDENTATION} ${STATUS_RUNNING}
packages/qar ${INSTALL}$ node qar
${STATUS_INDENTATION} ${STATUS_DONE}
`)
},
})
})
test('groups lifecycle output when append-only is used', t => {
const output$ = toOutput$({
context: { argv: ['install'] },
reportingOptions: {
appendOnly: true,
outputMaxWidth: 79,
},
streamParser: createStreamParser(),
})
lifecycleLogger.debug({
depPath: 'packages/foo',
optional: false,
script: 'node foo',
stage: 'preinstall',
wd: 'packages/foo',
})
lifecycleLogger.debug({
depPath: 'packages/foo',
line: 'foo 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30',
stage: 'preinstall',
stdio: 'stdout',
wd: 'packages/foo',
})
lifecycleLogger.debug({
depPath: 'packages/foo',
exitCode: 1,
optional: true,
stage: 'preinstall',
wd: 'packages/foo',
})
lifecycleLogger.debug({
depPath: 'packages/foo',
optional: false,
script: 'node foo',
stage: 'postinstall',
wd: 'packages/foo',
})
lifecycleLogger.debug({
depPath: 'packages/foo',
line: 'foo I',
stage: 'postinstall',
stdio: 'stdout',
wd: 'packages/foo',
})
lifecycleLogger.debug({
depPath: 'packages/bar',
optional: false,
script: 'node bar',
stage: 'postinstall',
wd: 'packages/bar',
})
lifecycleLogger.debug({
depPath: 'packages/bar',
line: 'bar I',
stage: 'postinstall',
stdio: 'stdout',
wd: 'packages/bar',
})
lifecycleLogger.debug({
depPath: 'packages/foo',
line: 'foo II',
stage: 'postinstall',
stdio: 'stdout',
wd: 'packages/foo',
})
lifecycleLogger.debug({
depPath: 'packages/foo',
line: 'foo III',
stage: 'postinstall',
stdio: 'stdout',
wd: 'packages/foo',
})
lifecycleLogger.debug({
depPath: 'packages/qar',
optional: false,
script: 'node qar',
stage: 'install',
wd: 'packages/qar',
})
lifecycleLogger.debug({
depPath: 'packages/qar',
exitCode: 0,
optional: false,
stage: 'install',
wd: 'packages/qar'
})
lifecycleLogger.debug({
depPath: 'packages/foo',
exitCode: 0,
optional: false,
stage: 'postinstall',
wd: 'packages/foo'
})
t.plan(1)
let allOutputs = [] as string[]
output$.take(11).map(normalizeNewline).subscribe({
complete: () => {
t.equal(allOutputs.join(EOL), stripIndents`
packages/foo ${PREINSTALL}$ node foo
packages/foo ${PREINSTALL}: foo 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30
packages/foo ${PREINSTALL}: Failed
packages/foo ${POSTINSTALL}$ node foo
packages/foo ${POSTINSTALL}: foo I
packages/bar ${POSTINSTALL}$ node bar
packages/bar ${POSTINSTALL}: bar I
packages/foo ${POSTINSTALL}: foo II
packages/foo ${POSTINSTALL}: foo III
packages/qar ${INSTALL}$ node qar
packages/qar ${INSTALL}: Done
`)
t.end()
},
error: t.end,
next: (output: string) => { allOutputs.push(output) },
})
})
test('collapse lifecycle output when it has too many lines', t => {
const output$ = toOutput$({
context: { argv: ['install'] },
reportingOptions: { outputMaxWidth: 79 },
streamParser: createStreamParser(),
})
lifecycleLogger.debug({
depPath: 'packages/foo',
optional: false,
script: 'node foo',
stage: 'postinstall',
wd: 'packages/foo',
})
for (let i = 0; i < 100; i++) {
lifecycleLogger.debug({
depPath: 'packages/foo',
line: `foo ${i}`,
stage: 'postinstall',
stdio: 'stdout',
wd: 'packages/foo',
})
}
lifecycleLogger.debug({
depPath: 'packages/foo',
exitCode: 0,
optional: false,
stage: 'postinstall',
wd: 'packages/foo'
})
t.plan(1)
output$.skip(101).take(1).map(normalizeNewline).subscribe({
complete: () => t.end(),
error: t.end,
next: (output: string) => {
t.equal(replaceTimeWith1Sec(output), stripIndents`
packages/foo ${POSTINSTALL}$ node foo
[90 lines collapsed]
${OUTPUT_INDENTATION} foo 90
${OUTPUT_INDENTATION} foo 91
${OUTPUT_INDENTATION} foo 92
${OUTPUT_INDENTATION} foo 93
${OUTPUT_INDENTATION} foo 94
${OUTPUT_INDENTATION} foo 95
${OUTPUT_INDENTATION} foo 96
${OUTPUT_INDENTATION} foo 97
${OUTPUT_INDENTATION} foo 98
${OUTPUT_INDENTATION} foo 99
${STATUS_INDENTATION} ${STATUS_DONE}
`)
},
})
})
test('collapses lifecycle output of packages from node_modules', t => {
const output$ = toOutput$({
context: { argv: ['install'] },
reportingOptions: { outputMaxWidth: 79 },
streamParser: createStreamParser(),
})
const wdOfFoo = path.resolve(process.cwd(), 'node_modules', '.registry.npmjs.org', 'foo', '1.0.0', 'node_modules', 'foo')
const wdOfBar = path.resolve(process.cwd(), 'node_modules', '.registry.npmjs.org', 'bar', '1.0.0', 'node_modules', 'bar')
const wdOfQar = path.resolve(process.cwd(), 'node_modules', '.registry.npmjs.org', 'qar', '1.0.0', 'node_modules', 'qar')
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/bar/1.0.0',
optional: false,
script: 'node bar',
stage: 'postinstall',
wd: wdOfBar,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/bar/1.0.0',
line: 'bar I',
stage: 'postinstall',
stdio: 'stdout',
wd: wdOfBar,
})
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/qar/1.0.0',
optional: false,
script: 'node qar',
stage: 'install',
wd: wdOfQar,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/qar/1.0.0',
exitCode: 0,
optional: false,
stage: 'install',
wd: wdOfQar,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
exitCode: 0,
optional: false,
stage: 'postinstall',
wd: wdOfFoo,
})
t.plan(1)
output$.skip(5).take(1).map(normalizeNewline).subscribe({
complete: () => t.end(),
error: t.end,
next: (output: string) => {
t.equal(replaceTimeWith1Sec(output), stripIndents`
${chalk.gray('node_modules/.registry.npmjs.org/foo/1.0.0/node_modules/')}foo: Running preinstall script...
${chalk.gray('node_modules/.registry.npmjs.org/foo/1.0.0/node_modules/')}foo: Running postinstall script, done in 1s
${chalk.gray('node_modules/.registry.npmjs.org/bar/1.0.0/node_modules/')}bar: Running postinstall script...
${chalk.gray('node_modules/.registry.npmjs.org/qar/1.0.0/node_modules/')}qar: Running install script, done in 1s
`)
},
})
})
test('output of failed optional dependency is not shown', t => {
const output$ = toOutput$({
context: { argv: ['install'] },
reportingOptions: { outputMaxWidth: 79 },
streamParser: createStreamParser(),
})
const wd = path.resolve(process.cwd(), 'node_modules', '.registry.npmjs.org', 'foo', '1.0.0', 'node_modules', 'foo')
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
optional: true,
script: 'node foo',
stage: 'install',
wd: wd,
})
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: 'install',
stdio: 'stdout',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
exitCode: 1,
optional: true,
stage: 'install',
wd,
})
t.plan(1)
output$.skip(1).take(1).map(normalizeNewline).subscribe({
complete: () => t.end(),
error: t.end,
next: (output: string) => {
t.equal(replaceTimeWith1Sec(output), stripIndents`
${chalk.gray('node_modules/.registry.npmjs.org/foo/1.0.0/node_modules/')}foo: Running install script, failed in 1s (skipped as optional)
`)
},
})
})
test('output of failed non-optional dependency is printed', t => {
const output$ = toOutput$({
context: { argv: ['install'] },
reportingOptions: { outputMaxWidth: 79 },
streamParser: createStreamParser(),
})
const wd = path.resolve(process.cwd(), 'node_modules', '.registry.npmjs.org', 'foo', '1.0.0', 'node_modules', 'foo')
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
optional: false,
script: 'node foo',
stage: 'install',
wd: wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
line: 'foo 0 1 2 3 4 5 6 7 8 9',
stage: 'install',
stdio: 'stdout',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
exitCode: 1,
optional: false,
stage: 'install',
wd,
})
t.plan(1)
output$.skip(1).take(1).map(normalizeNewline).subscribe({
complete: () => t.end(),
error: t.end,
next: (output: string) => {
t.equal(replaceTimeWith1Sec(output), stripIndents`
${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}
`)
},
})
})
// Many libs use stderr for logging, so showing all stderr adds not much value
test['skip']('prints lifecycle progress', t => {
const output$ = toOutput$({
context: { argv: ['install'] },
streamParser: createStreamParser(),
})
const wd = process.cwd()
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
line: 'foo I',
optional: false,
script: 'postinstall',
stage: 'postinstall',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/bar/1.0.0',
line: 'bar I',
optional: false,
script: 'postinstall',
stage: 'postinstall',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
line: 'foo II',
script: 'postinstall',
stage: 'postinstall',
stdio: 'stderr',
wd,
})
lifecycleLogger.debug({
depPath: 'registry.npmjs.org/foo/1.0.0',
line: 'foo III',
optional: false,
script: 'postinstall',
stage: 'postinstall',
wd,
})
t.plan(1)
const childOutputColor = chalk.grey
const childOutputError = chalk.red
output$.skip(3).take(1).map(normalizeNewline).subscribe({
complete: () => t.end(),
error: t.end,
next: output => {
t.equal(output, stripIndents`
Running ${POSTINSTALL} for ${hlPkgId('registry.npmjs.org/foo/1.0.0')}: ${childOutputColor('foo I')}
Running ${POSTINSTALL} for ${hlPkgId('registry.npmjs.org/foo/1.0.0')}! ${childOutputError('foo II')}
Running ${POSTINSTALL} for ${hlPkgId('registry.npmjs.org/foo/1.0.0')}: ${childOutputColor('foo III')}
Running ${POSTINSTALL} for ${hlPkgId('registry.npmjs.org/bar/1.0.0')}: ${childOutputColor('bar I')}
`)
},
})
})

View File

@@ -43,7 +43,7 @@ declare module 'normalize-path' {
export = normalize;
}
declare module 'string.prototype.padstart' {
function padStart (s: string, targetLength: number, padString?: string): string;
export = padStart;
declare module 'pretty-time' {
function prettyTime (time: [number, number]): string;
export = prettyTime;
}

View File

@@ -123,6 +123,7 @@ export default async (opts: HeadlessOptions) => {
const scriptsOpts = {
depPath: importer.prefix,
optional: false,
pkgRoot: importer.prefix,
rawNpmConfig: opts.rawNpmConfig,
rootNodeModulesDir: importer.modulesDir,
@@ -305,6 +306,7 @@ export default async (opts: HeadlessOptions) => {
const scriptsOpts = {
depPath: importer.prefix,
optional: false,
pkgRoot: importer.prefix,
rawNpmConfig: opts.rawNpmConfig,
rootNodeModulesDir: importer.modulesDir,

View File

@@ -53,6 +53,7 @@ export default async (
try {
const hasSideEffects = await runPostinstallHooks({
depPath,
optional: depNode.optional,
pkgRoot: depNode.peripheralLocation,
prepare: depNode.prepare,
rawNpmConfig: opts.rawNpmConfig,

View File

@@ -10,10 +10,11 @@ function noop () {} // tslint:disable-line:no-empty
export async function runPostinstallHooks (
opts: {
depPath: string,
rootNodeModulesDir: string,
rawNpmConfig: object,
optional?: boolean,
pkgRoot: string,
prepare?: boolean,
rawNpmConfig: object,
rootNodeModulesDir: string,
unsafePerm: boolean,
},
): Promise<boolean> {
@@ -46,16 +47,19 @@ export default async function runLifecycleHook (
pkg: PackageJson,
opts: {
depPath: string,
rootNodeModulesDir: string,
rawNpmConfig: object,
optional?: boolean,
pkgRoot: string,
rawNpmConfig: object,
rootNodeModulesDir: string,
stdio?: string,
unsafePerm: boolean,
},
) {
const optional = opts.optional === true
if (opts.stdio !== 'inherit') {
lifecycleLogger.debug({
depPath: opts.depPath,
optional,
script: pkg.scripts![stage],
stage,
wd: opts.pkgRoot,
@@ -101,6 +105,7 @@ export default async function runLifecycleHook (
lifecycleLogger.debug({
depPath: opts.depPath,
exitCode: code,
optional,
stage,
wd: opts.pkgRoot,
})

View File

@@ -11,10 +11,11 @@ test('runLifecycleHook()', async (t) => {
const pkgRoot = path.join(fixtures, 'simple')
const pkg = require(path.join(pkgRoot, 'package.json'))
await runLifecycleHook('postinstall', pkg, {
rootNodeModulesDir,
depPath: '/simple/1.0.0',
rawNpmConfig: {},
optional: false,
pkgRoot,
rawNpmConfig: {},
rootNodeModulesDir,
unsafePerm: true,
})
@@ -28,10 +29,11 @@ test('runPostinstallHooks()', async (t) => {
const pkg = require(path.join(pkgRoot, 'package.json'))
rimraf.sync(path.join(pkgRoot, 'output.json'))
await runPostinstallHooks({
rootNodeModulesDir,
depPath: '/with-many-scripts/1.0.0',
rawNpmConfig: {},
optional: false,
pkgRoot,
rawNpmConfig: {},
rootNodeModulesDir,
unsafePerm: true,
})
@@ -45,11 +47,12 @@ test('runPostinstallHooks() with prepare = true', async (t) => {
const pkg = require(path.join(pkgRoot, 'package.json'))
rimraf.sync(path.join(pkgRoot, 'output.json'))
await runPostinstallHooks({
rootNodeModulesDir,
depPath: '/with-many-scripts/1.0.0',
rawNpmConfig: {},
prepare: true,
optional: false,
pkgRoot,
prepare: true,
rawNpmConfig: {},
rootNodeModulesDir,
unsafePerm: true,
})

View File

@@ -329,6 +329,7 @@ export async function mutateModules (
const scriptsOpts = {
depPath: importer.prefix,
optional: false,
pkgRoot: importer.prefix,
rawNpmConfig: opts.rawNpmConfig,
rootNodeModulesDir: importer.modulesDir,
@@ -380,6 +381,7 @@ export async function mutateModules (
const scriptsOpts = {
depPath: importer.prefix,
optional: false,
pkgRoot: importer.prefix,
rawNpmConfig: opts.rawNpmConfig,
rootNodeModulesDir: importer.modulesDir,
@@ -853,6 +855,7 @@ async function installInContext (
try {
const hasSideEffects = await runPostinstallHooks({
depPath: pkg.absolutePath,
optional: pkg.optional,
pkgRoot: pkg.peripheralLocation,
prepare: pkg.prepare,
rawNpmConfig: opts.rawNpmConfig,

View File

@@ -161,6 +161,7 @@ async function runLifecycleHooksInDir (
) {
const scriptsOpts = {
depPath: prefix,
optional: false,
pkgRoot: prefix,
rawNpmConfig: opts.rawNpmConfig,
rootNodeModulesDir: opts.rootNodeModulesDir,
@@ -274,6 +275,7 @@ async function _rebuild (
try {
await runPostinstallHooks({
depPath: depAbsolutePath,
optional: pkgSnapshot.optional === true,
pkgRoot: path.join(modules, `.${depAbsolutePath}`, 'node_modules', pkgInfo.name),
prepare: pkgSnapshot.prepare,
rawNpmConfig: opts.rawNpmConfig,

View File

@@ -112,12 +112,12 @@ importers:
most: /most/1.7.3/most@1.7.3
normalize-path: 3.0.0
pretty-bytes: 5.1.0
pretty-time: 1.1.0
ramda: 0.26.1
right-pad: 1.0.1
semver: 5.6.0
stacktracey: 1.2.106
string-length: 2.0.0
string.prototype.padstart: 3.0.0
strip-ansi: 5.0.0
zen-push: 0.2.1
devDependencies:
@@ -160,13 +160,13 @@ importers:
normalize-newline: 3.0.0
normalize-path: 3.0.0
pretty-bytes: 5.1.0
pretty-time: 1.1.0
ramda: 0.26.1
right-pad: 1.0.1
rimraf: 2.6.2
semver: 5.6.0
stacktracey: 1.2.106
string-length: 2.0.0
string.prototype.padstart: 3.0.0
strip-ansi: 5.0.0
tape: 4.9.1
ts-node: 6.2.0
@@ -7982,6 +7982,12 @@ packages:
node: '>=0.10.0'
resolution:
integrity: sha1-QlfCVt8/sLRR1q/6qwIYhBJpgdw=
/pretty-time/1.1.0:
dev: false
engines:
node: '>=4'
resolution:
integrity: sha512-28iF6xPQrP8Oa6uxE6a1biz+lWeTOAPKggvjB8HAs6nVMKZwf5bG++632Dx614hIWgUPkgivRfG+a8uAXGTIbA==
/printable-characters/1.0.42:
dev: false
resolution:
@@ -9191,16 +9197,6 @@ packages:
node: '>= 0.4'
resolution:
integrity: sha1-86rvfBcZ8XDF6rHDK/eA2W4h8vA=
/string.prototype.padstart/3.0.0:
dependencies:
define-properties: 1.1.3
es-abstract: 1.12.0
function-bind: 1.1.1
dev: false
engines:
node: '>= 0.4'
resolution:
integrity: sha1-W8+tOfRkm7LQMSkuGbzwtRDUskI=
/string.prototype.trim/1.1.2:
dependencies:
define-properties: 1.1.3