From 8f0a443e6c7d7a44dcb566d510096bf61cfe83fb Mon Sep 17 00:00:00 2001 From: Tobias Koppers Date: Sat, 27 Jul 2019 19:48:10 +0200 Subject: [PATCH 1/9] Colored console for node environment Status report in logger ProgressPlugins uses logger --- lib/ProgressPlugin.js | 83 +++-------- lib/Stats.js | 10 +- lib/logging/Logger.js | 7 +- lib/logging/createConsoleLogger.js | 71 ++++++---- lib/logging/runtime.js | 3 +- lib/logging/truncateArgs.js | 74 ++++++++++ lib/node/NodeEnvironmentPlugin.js | 4 +- lib/node/nodeConsole.js | 132 ++++++++++++++++++ .../__snapshots__/StatsTestCases.test.js.snap | 28 ++-- 9 files changed, 306 insertions(+), 106 deletions(-) create mode 100644 lib/logging/truncateArgs.js create mode 100644 lib/node/nodeConsole.js diff --git a/lib/ProgressPlugin.js b/lib/ProgressPlugin.js index 2f5c62ce6..93a5830ba 100644 --- a/lib/ProgressPlugin.js +++ b/lib/ProgressPlugin.js @@ -10,50 +10,14 @@ const schema = require("../schemas/plugins/ProgressPlugin.json"); /** @typedef {import("../declarations/plugins/ProgressPlugin").ProgressPluginArgument} ProgressPluginArgument */ /** @typedef {import("../declarations/plugins/ProgressPlugin").ProgressPluginOptions} ProgressPluginOptions */ -const createDefaultHandler = profile => { - let lineCaretPosition = 0; - let lastMessage = ""; +const createDefaultHandler = (profile, logger) => { let lastState; let lastStateTime; const defaultHandler = (percentage, msg, ...args) => { - let state = msg; - const details = args.filter(v => v.length); - const maxLineLength = process.stderr.columns || Infinity; - if (percentage < 1) { - percentage = Math.floor(percentage * 100); - msg = `${percentage}% ${msg}`; - if (percentage < 100) { - msg = ` ${msg}`; - } - if (percentage < 10) { - msg = ` ${msg}`; - } - - if (details.length) { - const maxTotalDetailsLength = maxLineLength - msg.length; - const totalDetailsLength = details.reduce( - (a, b) => a + b.length, - details.length // account for added space before each detail text - ); - const maxDetailLength = - totalDetailsLength < maxTotalDetailsLength - ? Infinity - : Math.floor(maxTotalDetailsLength / details.length); - - for (let detail of details) { - if (!detail) continue; - if (detail.length + 1 > maxDetailLength) { - const truncatePrefix = "..."; - detail = `${truncatePrefix}${detail.substr( - -(maxDetailLength - truncatePrefix.length - 1) - )}`; - } - msg += ` ${detail}`; - } - } - } + logger.status(`${Math.floor(percentage * 100)}%`, msg, ...args); if (profile) { + let state = msg; state = state.replace(/^\d+\/\d+\s+/, ""); if (percentage === 0) { lastState = null; @@ -61,33 +25,23 @@ const createDefaultHandler = profile => { } else if (state !== lastState || percentage === 1) { const now = Date.now(); if (lastState) { - const stateMsg = `${now - lastStateTime}ms ${lastState}`; - goToLineStart(stateMsg); - process.stderr.write(stateMsg + "\n"); - lineCaretPosition = 0; + const diff = now - lastStateTime; + const stateMsg = `${diff}ms ${lastState}`; + if (diff > 1000) { + logger.warn(stateMsg); + } else if (diff > 10) { + logger.info(stateMsg); + } else if (diff > 0) { + logger.log(stateMsg); + } else { + logger.debug(stateMsg); + } } lastState = state; lastStateTime = now; } } - if (lastMessage !== msg) { - goToLineStart(msg); - msg = msg.substring(0, maxLineLength); - process.stderr.write(msg); - lastMessage = msg; - } - }; - - const goToLineStart = nextMessage => { - let str = ""; - for (; lineCaretPosition > nextMessage.length; lineCaretPosition--) { - str += "\b \b"; - } - for (var i = 0; i < lineCaretPosition; i++) { - str += "\b"; - } - lineCaretPosition = nextMessage.length; - if (str) process.stderr.write(str); + if (percentage === 1) logger.status(); }; return defaultHandler; @@ -118,7 +72,12 @@ class ProgressPlugin { apply(compiler) { const { modulesCount } = this; - const handler = this.handler || createDefaultHandler(this.profile); + const handler = + this.handler || + createDefaultHandler( + this.profile, + compiler.getInfrastructureLogger("webpack.Progress") + ); const showEntries = this.showEntries; const showModules = this.showModules; const showActiveModules = this.showActiveModules; diff --git a/lib/Stats.js b/lib/Stats.js index 7a586cb4d..40bfd9ba7 100644 --- a/lib/Stats.js +++ b/lib/Stats.js @@ -755,6 +755,7 @@ class Stats { LogType.profile, LogType.profileEnd, LogType.time, + LogType.status, LogType.clear ]); collapsedGroups = true; @@ -1442,7 +1443,7 @@ class Stats { let indent = ""; for (const entry of logData.entries) { let color = colors.normal; - let prefix = ""; + let prefix = " "; switch (entry.type) { case LogType.clear: colors.normal(`${indent}-------`); @@ -1467,6 +1468,10 @@ class Stats { case LogType.debug: color = colors.normal; break; + case LogType.status: + color = colors.magenta; + prefix = " "; + break; case LogType.profile: color = colors.magenta; prefix = "

"; @@ -1481,13 +1486,14 @@ class Stats { break; case LogType.group: color = colors.cyan; + prefix = "<-> "; break; case LogType.groupCollapsed: color = colors.cyan; prefix = "<+> "; break; case LogType.groupEnd: - if (indent.length > 2) + if (indent.length >= 2) indent = indent.slice(0, indent.length - 2); continue; } diff --git a/lib/logging/Logger.js b/lib/logging/Logger.js index 6bdaea0db..e3101378d 100644 --- a/lib/logging/Logger.js +++ b/lib/logging/Logger.js @@ -26,7 +26,8 @@ const LogType = Object.freeze({ time: "time", // name, time as [seconds, nanoseconds] - clear: "clear" // no arguments + clear: "clear", // no arguments + status: "status" // message, arguments }); exports.LogType = LogType; @@ -78,6 +79,10 @@ class WebpackLogger { this[LOG_SYMBOL](LogType.clear); } + status(...args) { + this[LOG_SYMBOL](LogType.status, args); + } + group(...args) { this[LOG_SYMBOL](LogType.group, args); } diff --git a/lib/logging/createConsoleLogger.js b/lib/logging/createConsoleLogger.js index b6b49660d..8835d2615 100644 --- a/lib/logging/createConsoleLogger.js +++ b/lib/logging/createConsoleLogger.js @@ -15,8 +15,9 @@ const { LogType } = require("./Logger"); /** * @typedef {Object} LoggerOptions - * @property {false|true|"none"|"error"|"warn"|"info"|"log"|"verbose"} options.level loglevel - * @property {FilterTypes|boolean} options.debug filter for debug logging + * @property {false|true|"none"|"error"|"warn"|"info"|"log"|"verbose"} level loglevel + * @property {FilterTypes|boolean} debug filter for debug logging + * @property {Console & { status?: Function, logTime?: Function }} console the console to log to */ /** @@ -62,7 +63,7 @@ const LogLevel = { * @param {LoggerOptions} options options object * @returns {function(string, LogTypeEnum, any[]): void} logging function */ -module.exports = ({ level = "info", debug = false }) => { +module.exports = ({ level = "info", debug = false, console }) => { const debugFilters = typeof debug === "boolean" ? [() => debug] @@ -79,12 +80,12 @@ module.exports = ({ level = "info", debug = false }) => { * @returns {void} */ const logger = (name, type, args) => { - const labeledArgs = (prefix = "") => { + const labeledArgs = () => { if (Array.isArray(args)) { if (args.length > 0 && typeof args[0] === "string") { - return [`${prefix}[${name}] ${args[0]}`, ...args.slice(1)]; + return [`[${name}] ${args[0]}`, ...args.slice(1)]; } else { - return [`${prefix}[${name}]`, ...args]; + return [`[${name}]`, ...args]; } } else { return []; @@ -108,20 +109,33 @@ module.exports = ({ level = "info", debug = false }) => { break; case LogType.info: if (!debug && loglevel > LogLevel.info) return; - console.info(...labeledArgs(" ")); + console.info(...labeledArgs()); break; case LogType.warn: if (!debug && loglevel > LogLevel.warn) return; - console.warn(...labeledArgs(" ")); + console.warn(...labeledArgs()); break; case LogType.error: if (!debug && loglevel > LogLevel.error) return; - console.error(...labeledArgs(" ")); + console.error(...labeledArgs()); break; case LogType.trace: if (!debug) return; console.trace(); break; + case LogType.groupCollapsed: + if (!debug && loglevel > LogLevel.log) return; + if (!debug && loglevel > LogLevel.verbose) { + // eslint-disable-next-line node/no-unsupported-features/node-builtins + if (typeof console.groupCollapsed === "function") { + // eslint-disable-next-line node/no-unsupported-features/node-builtins + console.groupCollapsed(...labeledArgs()); + } else { + console.log(...labeledArgs()); + } + break; + } + // falls through case LogType.group: if (!debug && loglevel > LogLevel.log) return; // eslint-disable-next-line node/no-unsupported-features/node-builtins @@ -132,32 +146,25 @@ module.exports = ({ level = "info", debug = false }) => { console.log(...labeledArgs()); } break; - case LogType.groupCollapsed: - if (!debug && loglevel > LogLevel.log) return; - // eslint-disable-next-line node/no-unsupported-features/node-builtins - if (typeof console.groupCollapsed === "function") { - // eslint-disable-next-line node/no-unsupported-features/node-builtins - console.groupCollapsed(...labeledArgs()); - } else { - console.log(...labeledArgs(" ")); - } - break; case LogType.groupEnd: if (!debug && loglevel > LogLevel.log) return; // eslint-disable-next-line node/no-unsupported-features/node-builtins if (typeof console.groupEnd === "function") { // eslint-disable-next-line node/no-unsupported-features/node-builtins console.groupEnd(); - } else { - console.log(...labeledArgs(" ")); } break; - case LogType.time: + case LogType.time: { if (!debug && loglevel > LogLevel.log) return; - console.log( - `[${name}] ${args[0]}: ${args[1] * 1000 + args[2] / 1000000}ms` - ); + const ms = args[1] * 1000 + args[2] / 1000000; + const msg = `[${name}] ${args[0]}: ${ms}ms`; + if (typeof console.logTime === "function") { + console.logTime(msg); + } else { + console.log(msg); + } break; + } case LogType.profile: // eslint-disable-next-line node/no-unsupported-features/node-builtins if (typeof console.profile === "function") { @@ -180,6 +187,20 @@ module.exports = ({ level = "info", debug = false }) => { console.clear(); } break; + case LogType.status: + if (!debug && loglevel > LogLevel.info) return; + if (typeof console.status === "function") { + if (args.length === 0) { + console.status(); + } else { + console.status(...labeledArgs()); + } + } else { + if (args.length !== 0) { + console.info(...labeledArgs()); + } + } + break; default: throw new Error(`Unexpected LogType ${type}`); } diff --git a/lib/logging/runtime.js b/lib/logging/runtime.js index 7b4bbf7b2..18e2148be 100644 --- a/lib/logging/runtime.js +++ b/lib/logging/runtime.js @@ -5,7 +5,8 @@ const createConsoleLogger = require("./createConsoleLogger"); /** @type {createConsoleLogger.LoggerOptions} */ let currentDefaultLoggerOptions = { level: "info", - debug: false + debug: false, + console }; let currentDefaultLogger = createConsoleLogger(currentDefaultLoggerOptions); diff --git a/lib/logging/truncateArgs.js b/lib/logging/truncateArgs.js new file mode 100644 index 000000000..714e4624c --- /dev/null +++ b/lib/logging/truncateArgs.js @@ -0,0 +1,74 @@ +/* + MIT License http://www.opensource.org/licenses/mit-license.php + Author Tobias Koppers @sokra + */ + +"use strict"; + +/** + * @param {any[]} args items to be truncated + * @param {number} maxLength maximum length of args including spaces between + * @returns {string[]} truncated args + */ +const truncateArgs = (args, maxLength) => { + const lengths = args.map(a => `${a}`.length); + const availableLength = maxLength - lengths.length + 1; + + if (availableLength > 0 && args.length === 1) { + if (availableLength > 3) { + return ["..." + args[0].slice(-availableLength + 3)]; + } else { + return [args[0].slice(-availableLength)]; + } + } + + // Check if there is space for at least 4 chars per arg + if (availableLength < lengths.reduce((s, i) => s + Math.min(i, 4), 0)) { + // remove args + if (args.length > 1) + return truncateArgs(args.slice(0, args.length - 1), maxLength); + return []; + } + + let currentLength = lengths.reduce((a, b) => a + b, 0); + + // Check if all fits into maxLength + if (currentLength <= availableLength) return args; + + // Try to remove chars from the longest items until it fits + while (currentLength > availableLength) { + const maxLength = Math.max(...lengths); + const shorterItems = lengths.filter(l => l !== maxLength); + const nextToMaxLength = + shorterItems.length > 0 ? Math.max(...shorterItems) : 0; + const maxReduce = maxLength - nextToMaxLength; + let maxItems = lengths.length - shorterItems.length; + let overrun = currentLength - availableLength; + for (let i = 0; i < lengths.length; i++) { + if (lengths[i] === maxLength) { + const reduce = Math.min(Math.floor(overrun / maxItems), maxReduce); + lengths[i] -= reduce; + currentLength -= reduce; + overrun -= reduce; + maxItems--; + } + } + } + + // Return args reduced to length in lengths + return args.map((a, i) => { + const str = `${a}`; + const length = lengths[i]; + if (str.length === length) { + return str; + } else if (length > 6) { + return "..." + str.slice(-length + 3); + } else if (length > 0) { + return str.slice(-length); + } else { + return ""; + } + }); +}; + +module.exports = truncateArgs; diff --git a/lib/node/NodeEnvironmentPlugin.js b/lib/node/NodeEnvironmentPlugin.js index 8a236ea85..98c7985e9 100644 --- a/lib/node/NodeEnvironmentPlugin.js +++ b/lib/node/NodeEnvironmentPlugin.js @@ -9,6 +9,7 @@ const NodeOutputFileSystem = require("./NodeOutputFileSystem"); const NodeJsInputFileSystem = require("enhanced-resolve/lib/NodeJsInputFileSystem"); const CachedInputFileSystem = require("enhanced-resolve/lib/CachedInputFileSystem"); const createConsoleLogger = require("../logging/createConsoleLogger"); +const nodeConsole = require("./nodeConsole"); class NodeEnvironmentPlugin { constructor(options) { @@ -20,7 +21,8 @@ class NodeEnvironmentPlugin { Object.assign( { level: "info", - debug: false + debug: false, + console: nodeConsole }, this.options.infrastructureLogging ) diff --git a/lib/node/nodeConsole.js b/lib/node/nodeConsole.js new file mode 100644 index 000000000..016bbf2b9 --- /dev/null +++ b/lib/node/nodeConsole.js @@ -0,0 +1,132 @@ +/* + MIT License http://www.opensource.org/licenses/mit-license.php + Author Tobias Koppers @sokra +*/ + +"use strict"; + +const truncateArgs = require("../logging/truncateArgs"); +const util = require("util"); + +const tty = process.stderr.isTTY && process.env.TERM !== "dumb"; + +let currentStatusMessage = undefined; +let hasStatusMessage = false; +let currentIndent = ""; +let currentCollapsed = 0; + +const indent = (str, prefix, colorPrefix, colorSuffix) => { + if (str === "") return str; + prefix = currentIndent + prefix; + if (tty) { + return ( + prefix + + colorPrefix + + str.replace(/\n/g, colorSuffix + "\n" + prefix + colorPrefix) + + colorSuffix + ); + } else { + return prefix + str.replace(/\n/g, "\n" + prefix); + } +}; + +const clearStatusMessage = () => { + if (hasStatusMessage) { + process.stderr.write("\x1b[2K\r"); + hasStatusMessage = false; + } +}; + +const writeStatusMessage = () => { + if (!currentStatusMessage) return; + const l = process.stderr.columns; + const args = l ? truncateArgs(currentStatusMessage, l) : currentStatusMessage; + const str = args.join(" "); + const coloredStr = `\u001b[1m${str}\u001b[39m\u001b[22m`; + process.stderr.write(`\x1b[2K\r${coloredStr}`); + hasStatusMessage = true; +}; + +const writeColored = (prefix, colorPrefix, colorSuffix) => { + return (...args) => { + if (currentCollapsed > 0) return; + clearStatusMessage(); + // @ts-ignore + const str = indent(util.format(...args), prefix, colorPrefix, colorSuffix); + process.stderr.write(str + "\n"); + writeStatusMessage(); + }; +}; + +const writeGroupMessage = writeColored( + "<-> ", + "\u001b[1m\u001b[36m", + "\u001b[39m\u001b[22m" +); + +const writeGroupCollapsedMessage = writeColored( + "<+> ", + "\u001b[1m\u001b[36m", + "\u001b[39m\u001b[22m" +); + +module.exports = { + log: writeColored(" ", "\u001b[1m", "\u001b[22m"), + debug: writeColored(" ", "", ""), + trace: writeColored(" ", "", ""), + info: writeColored(" ", "\u001b[1m\u001b[32m", "\u001b[39m\u001b[22m"), + warn: writeColored(" ", "\u001b[1m\u001b[33m", "\u001b[39m\u001b[22m"), + error: writeColored(" ", "\u001b[1m\u001b[31m", "\u001b[39m\u001b[22m"), + logTime: writeColored(" ", "\u001b[1m\u001b[35m", "\u001b[39m\u001b[22m"), + group: (...args) => { + writeGroupMessage(...args); + if (currentCollapsed > 0) { + currentCollapsed++; + } else { + currentIndent += " "; + } + }, + groupCollapsed: (...args) => { + writeGroupCollapsedMessage(...args); + currentCollapsed++; + }, + groupEnd: () => { + if (currentCollapsed > 0) currentCollapsed--; + else if (currentIndent.length >= 2) + currentIndent = currentIndent.slice(0, currentIndent.length - 2); + }, + // eslint-disable-next-line node/no-unsupported-features/node-builtins + profile: console.profile && (name => console.profile(name)), + // eslint-disable-next-line node/no-unsupported-features/node-builtins + profileEnd: console.profileEnd && (name => console.profileEnd(name)), + clear: + tty && + // eslint-disable-next-line node/no-unsupported-features/node-builtins + console.clear && + (() => { + clearStatusMessage(); + // eslint-disable-next-line node/no-unsupported-features/node-builtins + console.clear(); + writeStatusMessage(); + }), + status: tty + ? (name, ...args) => { + if (name === undefined && args.length === 0) { + clearStatusMessage(); + currentStatusMessage = undefined; + } else if ( + typeof name === "string" && + name.startsWith("[webpack.Progress] ") + ) { + currentStatusMessage = [name.slice(19), ...args]; + writeStatusMessage(); + } else if (name === "[webpack.Progress]") { + currentStatusMessage = [...args]; + writeStatusMessage(); + } else { + currentStatusMessage = [name, ...args]; + writeStatusMessage(); + } + } + : writeColored(" ", "", "") +}; diff --git a/test/__snapshots__/StatsTestCases.test.js.snap b/test/__snapshots__/StatsTestCases.test.js.snap index 3e3fb1f58..130be5be1 100644 --- a/test/__snapshots__/StatsTestCases.test.js.snap +++ b/test/__snapshots__/StatsTestCases.test.js.snap @@ -1254,21 +1254,21 @@ Entrypoint main = main.js | at Object..module.exports (Xdir/logging/node_modules/custom-loader/index.js:5:9) A warning | at Object..module.exports (Xdir/logging/node_modules/custom-loader/index.js:6:9) -Unimportant +<-> Unimportant Info message - Just log - Just debug + Just log + Just debug Measure: Xms - Nested - Log inside collapsed group - Trace + <-> Nested + Log inside collapsed group + Trace | at Object..module.exports (Xdir/logging/node_modules/custom-loader/index.js:15:9) Measure: Xms ------- - After clear + After clear DEBUG LOG from node_modules/custom-loader/index.js Named Logger node_modules/custom-loader/index.js!index.js -Message with named logger" + Message with named logger" `; exports[`StatsTestCases should print correct stats for max-modules 1`] = ` @@ -1942,11 +1942,11 @@ chunk {3} 3.js 54 bytes <{0}> >{1}< [rendered] ModuleConcatenation bailout: Module is not an ECMAScript module LOG from MyPlugin -Group +<-> Group Error Warning Info - Log + Log <+> Collaped group + 3 hidden lines" `; @@ -2125,13 +2125,13 @@ chunk {3} 3.js 54 bytes <{0}> >{1}< [rendered] [0] Xms -> factory:Xms building:Xms = Xms LOG from MyPlugin -Group +<-> Group Error Warning Info - Log - Collaped group - Log inside collapsed group + Log + <-> Collaped group + Log inside collapsed group + 1 hidden lines LOG from webpack.buildChunkGraph.visitModules From 0c8d75c151d19a78fada2ea8b17a2fd3ebfbc6f1 Mon Sep 17 00:00:00 2001 From: Tobias Koppers Date: Wed, 31 Jul 2019 16:57:01 +0200 Subject: [PATCH 2/9] fix name for log hook --- lib/Compiler.js | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/lib/Compiler.js b/lib/Compiler.js index 97ae85c34..e07453398 100644 --- a/lib/Compiler.js +++ b/lib/Compiler.js @@ -86,7 +86,7 @@ class Compiler extends Tapable { watchClose: new SyncHook([]), /** @type {SyncBailHook} */ - infrastructurelog: new SyncBailHook(["origin", "type", "args"]), + infrastructureLog: new SyncBailHook(["origin", "type", "args"]), // TODO the following hooks are weirdly located here // TODO move them for webpack 5 @@ -101,6 +101,8 @@ class Compiler extends Tapable { /** @type {SyncBailHook} */ entryOption: new SyncBailHook(["context", "entry"]) }; + // TODO webpack 5 remove this + this.hooks.infrastructurelog = this.hooks.infrastructureLog; this._pluginCompat.tap("Compiler", options => { switch (options.name) { @@ -221,7 +223,7 @@ class Compiler extends Tapable { ); } } - if (this.hooks.infrastructurelog.call(name, type, args) === undefined) { + if (this.hooks.infrastructureLog.call(name, type, args) === undefined) { if (this.infrastructureLogger !== undefined) { this.infrastructureLogger(name, type, args); } From def294792902705299faafd43f034912b8a5a609 Mon Sep 17 00:00:00 2001 From: Tobias Koppers Date: Wed, 31 Jul 2019 16:57:26 +0200 Subject: [PATCH 3/9] add getInfrastructureLogger to MultiCompiler --- lib/MultiCompiler.js | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/lib/MultiCompiler.js b/lib/MultiCompiler.js index cdc7fb508..3055a4893 100644 --- a/lib/MultiCompiler.js +++ b/lib/MultiCompiler.js @@ -90,6 +90,10 @@ module.exports = class MultiCompiler extends Tapable { } } + getInfrastructureLogger(name) { + return this.compilers[0].getInfrastructureLogger(name); + } + validateDependencies(callback) { const edges = new Set(); const missing = []; From 56e12fd6207373b07eaa7bafe335f9d4af974348 Mon Sep 17 00:00:00 2001 From: Tobias Koppers Date: Wed, 31 Jul 2019 17:16:37 +0200 Subject: [PATCH 4/9] extract LogTestPlugin --- .../__snapshots__/StatsTestCases.test.js.snap | 34 ++++++++++++------- test/helpers/LogTestPlugin.js | 30 ++++++++++++++++ test/statsCases/logging/webpack.config.js | 18 ++-------- .../preset-detailed/webpack.config.js | 20 ++--------- .../webpack.config.js | 20 ++--------- .../preset-errors-warnings/webpack.config.js | 20 ++--------- .../preset-minimal/webpack.config.js | 20 ++--------- test/statsCases/preset-none/webpack.config.js | 20 ++--------- .../preset-normal/webpack.config.js | 20 ++--------- .../preset-verbose/webpack.config.js | 20 ++--------- 10 files changed, 67 insertions(+), 155 deletions(-) create mode 100644 test/helpers/LogTestPlugin.js diff --git a/test/__snapshots__/StatsTestCases.test.js.snap b/test/__snapshots__/StatsTestCases.test.js.snap index 130be5be1..f777c5f74 100644 --- a/test/__snapshots__/StatsTestCases.test.js.snap +++ b/test/__snapshots__/StatsTestCases.test.js.snap @@ -1244,9 +1244,13 @@ Built at: Thu Jan 01 1970 00:00:00 GMT Entrypoint main = main.js [0] ./index.js 0 bytes {0} [built] -LOG from MyPlugin - Plugin is now active -<+> Nested +LOG from LogTestPlugin +<-> Group + Info + Log + <+> Collaped group + Log + End + 3 hidden lines DEBUG LOG from node_modules/custom-loader/index.js node_modules/custom-loader/index.js!index.js @@ -1941,13 +1945,15 @@ chunk {3} 3.js 54 bytes <{0}> >{1}< [rendered] [5] ./e.js 22 bytes {1} [depth 2] [built] ModuleConcatenation bailout: Module is not an ECMAScript module -LOG from MyPlugin +LOG from LogTestPlugin <-> Group Error Warning Info Log <+> Collaped group + Log + End + 3 hidden lines" `; @@ -1955,9 +1961,9 @@ exports[`StatsTestCases should print correct stats for preset-errors-only 1`] = exports[`StatsTestCases should print correct stats for preset-errors-only-error 1`] = ` " -LOG from MyPlugin +LOG from LogTestPlugin Error -+ 9 hidden lines ++ 11 hidden lines ERROR in ./index.js Module not found: Error: Can't resolve 'does-not-exist' in 'Xdir/preset-errors-only-error' @@ -1966,19 +1972,19 @@ Module not found: Error: Can't resolve 'does-not-exist' in 'Xdir/preset-errors-o exports[`StatsTestCases should print correct stats for preset-errors-warnings 1`] = ` " -LOG from MyPlugin +LOG from LogTestPlugin Error Warning -+ 8 hidden lines" ++ 10 hidden lines" `; exports[`StatsTestCases should print correct stats for preset-minimal 1`] = ` " 6 modules -LOG from MyPlugin +LOG from LogTestPlugin Error Warning -+ 8 hidden lines" ++ 10 hidden lines" `; exports[`StatsTestCases should print correct stats for preset-minimal-simple 1`] = `" 1 module"`; @@ -2014,11 +2020,11 @@ Entrypoint main = main.js [4] ./d.js 22 bytes {1} [built] [5] ./e.js 22 bytes {1} [built] -LOG from MyPlugin +LOG from LogTestPlugin Error Warning Info -+ 7 hidden lines" ++ 9 hidden lines" `; exports[`StatsTestCases should print correct stats for preset-normal-performance 1`] = ` @@ -2124,7 +2130,7 @@ chunk {3} 3.js 54 bytes <{0}> >{1}< [rendered] amd require ./c [0] ./index.js 3:0-16 [0] Xms -> factory:Xms building:Xms = Xms -LOG from MyPlugin +LOG from LogTestPlugin <-> Group Error Warning @@ -2132,6 +2138,8 @@ LOG from MyPlugin Log <-> Collaped group Log inside collapsed group + Log + End + 1 hidden lines LOG from webpack.buildChunkGraph.visitModules diff --git a/test/helpers/LogTestPlugin.js b/test/helpers/LogTestPlugin.js new file mode 100644 index 000000000..0e1a1c321 --- /dev/null +++ b/test/helpers/LogTestPlugin.js @@ -0,0 +1,30 @@ +module.exports = class LogTestPlugin { + constructor(noTraced) { + this.noTraced = noTraced; + } + apply(compiler) { + const logSome = logger => { + logger.group("Group"); + if (!this.noTraced) { + logger.error("Error"); + logger.warn("Warning"); + } + logger.info("Info"); + logger.log("Log"); + logger.debug("Debug"); + logger.groupCollapsed("Collaped group"); + logger.log("Log inside collapsed group"); + logger.groupEnd(); + logger.log("Log"); + logger.groupEnd(); + logger.log("End"); + }; + compiler.hooks.compilation.tap("LogTestPlugin", compilation => { + const logger = compilation.getLogger("LogTestPlugin"); + logSome(logger); + + const otherLogger = compilation.getLogger("LogOtherTestPlugin"); + otherLogger.debug("debug message only"); + }); + } +}; diff --git a/test/statsCases/logging/webpack.config.js b/test/statsCases/logging/webpack.config.js index ce49b7dc9..8d89f8f6a 100644 --- a/test/statsCases/logging/webpack.config.js +++ b/test/statsCases/logging/webpack.config.js @@ -1,18 +1,4 @@ -class MyPlugin { - apply(compiler) { - compiler.hooks.compilation.tap("MyPlugin", compilation => { - const logger = compilation.getLogger("MyPlugin"); - logger.info("Plugin is now active"); - logger.debug("Debug message should not be visible"); - logger.groupCollapsed("Nested"); - logger.log("Log inside collapsed group"); - logger.groupEnd("Nested"); - - const otherLogger = compilation.getLogger("MyOtherPlugin"); - otherLogger.debug("debug message only"); - }); - } -} +const LogTestPlugin = require("../../helpers/LogTestPlugin"); module.exports = { mode: "production", @@ -26,7 +12,7 @@ module.exports = { } ] }, - plugins: [new MyPlugin()], + plugins: [new LogTestPlugin(true)], stats: { colors: true, logging: true, diff --git a/test/statsCases/preset-detailed/webpack.config.js b/test/statsCases/preset-detailed/webpack.config.js index 695022714..a41b087a2 100644 --- a/test/statsCases/preset-detailed/webpack.config.js +++ b/test/statsCases/preset-detailed/webpack.config.js @@ -1,24 +1,8 @@ -class MyPlugin { - apply(compiler) { - compiler.hooks.compilation.tap("MyPlugin", compilation => { - const logger = compilation.getLogger("MyPlugin"); - logger.group("Group"); - logger.error("Error"); - logger.warn("Warning"); - logger.info("Info"); - logger.log("Log"); - logger.debug("Debug"); - logger.groupCollapsed("Collaped group"); - logger.log("Log inside collapsed group"); - logger.groupEnd(); - logger.groupEnd(); - }); - } -} +const LogTestPlugin = require("../../helpers/LogTestPlugin"); module.exports = { mode: "production", entry: "./index", stats: "detailed", - plugins: [new MyPlugin()] + plugins: [new LogTestPlugin()] }; diff --git a/test/statsCases/preset-errors-only-error/webpack.config.js b/test/statsCases/preset-errors-only-error/webpack.config.js index 2ac283175..38a3f3201 100644 --- a/test/statsCases/preset-errors-only-error/webpack.config.js +++ b/test/statsCases/preset-errors-only-error/webpack.config.js @@ -1,24 +1,8 @@ -class MyPlugin { - apply(compiler) { - compiler.hooks.compilation.tap("MyPlugin", compilation => { - const logger = compilation.getLogger("MyPlugin"); - logger.group("Group"); - logger.error("Error"); - logger.warn("Warning"); - logger.info("Info"); - logger.log("Log"); - logger.debug("Debug"); - logger.groupCollapsed("Collaped group"); - logger.log("Log inside collapsed group"); - logger.groupEnd(); - logger.groupEnd(); - }); - } -} +const LogTestPlugin = require("../../helpers/LogTestPlugin"); module.exports = { mode: "production", entry: "./index", stats: "errors-only", - plugins: [new MyPlugin()] + plugins: [new LogTestPlugin()] }; diff --git a/test/statsCases/preset-errors-warnings/webpack.config.js b/test/statsCases/preset-errors-warnings/webpack.config.js index 038aa982f..f8ccd58cc 100644 --- a/test/statsCases/preset-errors-warnings/webpack.config.js +++ b/test/statsCases/preset-errors-warnings/webpack.config.js @@ -1,24 +1,8 @@ -class MyPlugin { - apply(compiler) { - compiler.hooks.compilation.tap("MyPlugin", compilation => { - const logger = compilation.getLogger("MyPlugin"); - logger.group("Group"); - logger.error("Error"); - logger.warn("Warning"); - logger.info("Info"); - logger.log("Log"); - logger.debug("Debug"); - logger.groupCollapsed("Collaped group"); - logger.log("Log inside collapsed group"); - logger.groupEnd(); - logger.groupEnd(); - }); - } -} +const LogTestPlugin = require("../../helpers/LogTestPlugin"); module.exports = { mode: "production", entry: "./index", stats: "errors-warnings", - plugins: [new MyPlugin()] + plugins: [new LogTestPlugin()] }; diff --git a/test/statsCases/preset-minimal/webpack.config.js b/test/statsCases/preset-minimal/webpack.config.js index 45e664f35..fd9934b2f 100644 --- a/test/statsCases/preset-minimal/webpack.config.js +++ b/test/statsCases/preset-minimal/webpack.config.js @@ -1,24 +1,8 @@ -class MyPlugin { - apply(compiler) { - compiler.hooks.compilation.tap("MyPlugin", compilation => { - const logger = compilation.getLogger("MyPlugin"); - logger.group("Group"); - logger.error("Error"); - logger.warn("Warning"); - logger.info("Info"); - logger.log("Log"); - logger.debug("Debug"); - logger.groupCollapsed("Collaped group"); - logger.log("Log inside collapsed group"); - logger.groupEnd(); - logger.groupEnd(); - }); - } -} +const LogTestPlugin = require("../../helpers/LogTestPlugin"); module.exports = { mode: "production", entry: "./index", stats: "minimal", - plugins: [new MyPlugin()] + plugins: [new LogTestPlugin()] }; diff --git a/test/statsCases/preset-none/webpack.config.js b/test/statsCases/preset-none/webpack.config.js index 0a3d5be8f..750ca8a51 100644 --- a/test/statsCases/preset-none/webpack.config.js +++ b/test/statsCases/preset-none/webpack.config.js @@ -1,24 +1,8 @@ -class MyPlugin { - apply(compiler) { - compiler.hooks.compilation.tap("MyPlugin", compilation => { - const logger = compilation.getLogger("MyPlugin"); - logger.group("Group"); - logger.error("Error"); - logger.warn("Warning"); - logger.info("Info"); - logger.log("Log"); - logger.debug("Debug"); - logger.groupCollapsed("Collaped group"); - logger.log("Log inside collapsed group"); - logger.groupEnd(); - logger.groupEnd(); - }); - } -} +const LogTestPlugin = require("../../helpers/LogTestPlugin"); module.exports = { mode: "production", entry: "./index", stats: false, - plugins: [new MyPlugin()] + plugins: [new LogTestPlugin()] }; diff --git a/test/statsCases/preset-normal/webpack.config.js b/test/statsCases/preset-normal/webpack.config.js index 5d85c8aab..ae534acc1 100644 --- a/test/statsCases/preset-normal/webpack.config.js +++ b/test/statsCases/preset-normal/webpack.config.js @@ -1,24 +1,8 @@ -class MyPlugin { - apply(compiler) { - compiler.hooks.compilation.tap("MyPlugin", compilation => { - const logger = compilation.getLogger("MyPlugin"); - logger.group("Group"); - logger.error("Error"); - logger.warn("Warning"); - logger.info("Info"); - logger.log("Log"); - logger.debug("Debug"); - logger.groupCollapsed("Collaped group"); - logger.log("Log inside collapsed group"); - logger.groupEnd(); - logger.groupEnd(); - }); - } -} +const LogTestPlugin = require("../../helpers/LogTestPlugin"); module.exports = { mode: "production", entry: "./index", stats: "normal", - plugins: [new MyPlugin()] + plugins: [new LogTestPlugin()] }; diff --git a/test/statsCases/preset-verbose/webpack.config.js b/test/statsCases/preset-verbose/webpack.config.js index e4d57fe96..bb9778aea 100644 --- a/test/statsCases/preset-verbose/webpack.config.js +++ b/test/statsCases/preset-verbose/webpack.config.js @@ -1,25 +1,9 @@ -class MyPlugin { - apply(compiler) { - compiler.hooks.compilation.tap("MyPlugin", compilation => { - const logger = compilation.getLogger("MyPlugin"); - logger.group("Group"); - logger.error("Error"); - logger.warn("Warning"); - logger.info("Info"); - logger.log("Log"); - logger.debug("Debug"); - logger.groupCollapsed("Collaped group"); - logger.log("Log inside collapsed group"); - logger.groupEnd(); - logger.groupEnd(); - }); - } -} +const LogTestPlugin = require("../../helpers/LogTestPlugin"); module.exports = { mode: "production", entry: "./index", profile: true, stats: "verbose", - plugins: [new MyPlugin()] + plugins: [new LogTestPlugin()] }; From 4c472adbf1ff080d367734e81c44fb99db664fd8 Mon Sep 17 00:00:00 2001 From: Tobias Koppers Date: Wed, 31 Jul 2019 17:29:21 +0200 Subject: [PATCH 5/9] capture infrastructure log --- test/StatsTestCases.test.js | 5 +++ .../__snapshots__/StatsTestCases.test.js.snap | 40 +++++++++++++++---- test/helpers/LogTestPlugin.js | 1 + 3 files changed, 38 insertions(+), 8 deletions(-) diff --git a/test/StatsTestCases.test.js b/test/StatsTestCases.test.js index 4ab834679..80e3c5498 100644 --- a/test/StatsTestCases.test.js +++ b/test/StatsTestCases.test.js @@ -6,6 +6,7 @@ const fs = require("fs"); const webpack = require("../lib/webpack"); const Stats = require("../lib/Stats"); +const captureStdio = require("./helpers/captureStdio"); /** * Escapes regular expression metacharacters @@ -66,7 +67,9 @@ describe("StatsTestCases", () => { }) ); }); + const captured = captureStdio(process.stderr); const c = webpack(options); + captured.restore(); const compilers = c.compilers ? c.compilers : [c]; compilers.forEach(c => { const ifs = c.inputFileSystem; @@ -111,6 +114,7 @@ describe("StatsTestCases", () => { let actual = stats.toString(toStringOptions); expect(typeof actual).toBe("string"); if (!hasColorSetting) { + actual = captured.toString() + actual; actual = actual .replace(/\u001b\[[0-9;]*m/g, "") .replace(/[.0-9]+(\s?ms)/g, "X$1") @@ -119,6 +123,7 @@ describe("StatsTestCases", () => { "$1 Thu Jan 01 1970 00:00:00 GMT" ); } else { + actual = captured.toStringRaw() + actual; actual = actual .replace(/\u001b\[1m\u001b\[([0-9;]*)m/g, "") .replace(/\u001b\[1m/g, "") diff --git a/test/__snapshots__/StatsTestCases.test.js.snap b/test/__snapshots__/StatsTestCases.test.js.snap index f777c5f74..8c43cd8ef 100644 --- a/test/__snapshots__/StatsTestCases.test.js.snap +++ b/test/__snapshots__/StatsTestCases.test.js.snap @@ -1236,7 +1236,8 @@ Child 4 chunks: `; exports[`StatsTestCases should print correct stats for logging 1`] = ` -"Hash: aa5b75cccf66cd9b1ffa +" [LogTestPlugin] Info +Hash: aa5b75cccf66cd9b1ffa Time: Xms Built at: Thu Jan 01 1970 00:00:00 GMT Asset Size Chunks Chunk Names @@ -1915,7 +1916,10 @@ chunk {6} preloaded3.js (preloaded3) 0 bytes <{2}> [rendered]" `; exports[`StatsTestCases should print correct stats for preset-detailed 1`] = ` -"Hash: 2b293d5b94136dfe6d9c +" [LogTestPlugin] Error + [LogTestPlugin] Warning + [LogTestPlugin] Info +Hash: 2b293d5b94136dfe6d9c Time: Xms Built at: Thu Jan 01 1970 00:00:00 GMT Asset Size Chunks Chunk Names @@ -1960,7 +1964,10 @@ LOG from LogTestPlugin exports[`StatsTestCases should print correct stats for preset-errors-only 1`] = `""`; exports[`StatsTestCases should print correct stats for preset-errors-only-error 1`] = ` -" +" [LogTestPlugin] Error + [LogTestPlugin] Warning + [LogTestPlugin] Info + LOG from LogTestPlugin Error + 11 hidden lines @@ -1971,7 +1978,10 @@ Module not found: Error: Can't resolve 'does-not-exist' in 'Xdir/preset-errors-o `; exports[`StatsTestCases should print correct stats for preset-errors-warnings 1`] = ` -" +" [LogTestPlugin] Error + [LogTestPlugin] Warning + [LogTestPlugin] Info + LOG from LogTestPlugin Error Warning @@ -1979,7 +1989,10 @@ LOG from LogTestPlugin `; exports[`StatsTestCases should print correct stats for preset-minimal 1`] = ` -" 6 modules +" [LogTestPlugin] Error + [LogTestPlugin] Warning + [LogTestPlugin] Info + 6 modules LOG from LogTestPlugin Error @@ -1997,14 +2010,22 @@ Child verbose: [0] ./index.js 8 bytes {0} [built]" `; -exports[`StatsTestCases should print correct stats for preset-none 1`] = `""`; +exports[`StatsTestCases should print correct stats for preset-none 1`] = ` +" [LogTestPlugin] Error + [LogTestPlugin] Warning + [LogTestPlugin] Info +" +`; exports[`StatsTestCases should print correct stats for preset-none-array 1`] = `""`; exports[`StatsTestCases should print correct stats for preset-none-error 1`] = `""`; exports[`StatsTestCases should print correct stats for preset-normal 1`] = ` -"Hash: 2b293d5b94136dfe6d9c +" [LogTestPlugin] Error + [LogTestPlugin] Warning + [LogTestPlugin] Info +Hash: 2b293d5b94136dfe6d9c Time: Xms Built at: Thu Jan 01 1970 00:00:00 GMT Asset Size Chunks Chunk Names @@ -2088,7 +2109,10 @@ Entrypoints: `; exports[`StatsTestCases should print correct stats for preset-verbose 1`] = ` -"Hash: 2b293d5b94136dfe6d9c +" [LogTestPlugin] Error + [LogTestPlugin] Warning + [LogTestPlugin] Info +Hash: 2b293d5b94136dfe6d9c Time: Xms Built at: Thu Jan 01 1970 00:00:00 GMT Asset Size Chunks Chunk Names diff --git a/test/helpers/LogTestPlugin.js b/test/helpers/LogTestPlugin.js index 0e1a1c321..3849e1046 100644 --- a/test/helpers/LogTestPlugin.js +++ b/test/helpers/LogTestPlugin.js @@ -19,6 +19,7 @@ module.exports = class LogTestPlugin { logger.groupEnd(); logger.log("End"); }; + logSome(compiler.getInfrastructureLogger("LogTestPlugin")); compiler.hooks.compilation.tap("LogTestPlugin", compilation => { const logger = compilation.getLogger("LogTestPlugin"); logSome(logger); From b89853ea12534c8ce8b74fa4ea3f89e01cfb4f9a Mon Sep 17 00:00:00 2001 From: Tobias Koppers Date: Wed, 31 Jul 2019 20:48:22 +0200 Subject: [PATCH 6/9] fix Compiler logging test --- test/Compiler.test.js | 100 +++++++++++++----------------------------- 1 file changed, 30 insertions(+), 70 deletions(-) diff --git a/test/Compiler.test.js b/test/Compiler.test.js index ba7dfa617..8507090ed 100644 --- a/test/Compiler.test.js +++ b/test/Compiler.test.js @@ -6,6 +6,7 @@ const path = require("path"); const webpack = require("../"); const WebpackOptionsDefaulter = require("../lib/WebpackOptionsDefaulter"); const MemoryFs = require("memory-fs"); +const captureStdio = require("./helpers/captureStdio"); describe("Compiler", () => { jest.setTimeout(20000); @@ -515,32 +516,12 @@ describe("Compiler", () => { }); }); describe("infrastructure logging", () => { - const CONSOLE_METHODS = [ - "error", - "warn", - "info", - "log", - "debug", - "trace", - "profile", - "profileEnd", - "group", - "groupEnd", - "groupCollapsed" - ]; - const spies = {}; + let capture; beforeEach(() => { - for (const method of CONSOLE_METHODS) { - if (console[method]) { - spies[method] = jest.spyOn(console, method).mockImplementation(); - } - } + capture = captureStdio(process.stderr); }); afterEach(() => { - for (const method in spies) { - spies[method].mockRestore(); - delete spies[method]; - } + capture.restore(); }); class MyPlugin { apply(compiler) { @@ -574,25 +555,18 @@ describe("Compiler", () => { }); compiler.outputFileSystem = new MemoryFs(); compiler.run((err, stats) => { - expect(spies.group).toHaveBeenCalledTimes(1); - expect(spies.group).toHaveBeenCalledWith("[MyPlugin] Group"); - expect(spies.groupCollapsed).toHaveBeenCalledTimes(1); - expect(spies.groupCollapsed).toHaveBeenCalledWith( - "[MyPlugin] Collaped group" - ); - expect(spies.error).toHaveBeenCalledTimes(1); - expect(spies.error).toHaveBeenCalledWith(" [MyPlugin] Error"); - expect(spies.warn).toHaveBeenCalledTimes(1); - expect(spies.warn).toHaveBeenCalledWith(" [MyPlugin] Warning"); - expect(spies.info).toHaveBeenCalledTimes(1); - expect(spies.info).toHaveBeenCalledWith(" [MyPlugin] Info"); - expect(spies.log).toHaveBeenCalledTimes(3); - expect(spies.log).toHaveBeenCalledWith("[MyPlugin] Log"); - expect(spies.log).toHaveBeenCalledWith( - "[MyPlugin] Log inside collapsed group" - ); - expect(spies.debug).toHaveBeenCalledTimes(0); - expect(spies.groupEnd).toHaveBeenCalledTimes(2); + expect(capture.toString().replace(/[\d.]+ms/, "Xms")) + .toMatchInlineSnapshot(` +"<-> [MyPlugin] Group + [MyPlugin] Error + [MyPlugin] Warning + [MyPlugin] Info + [MyPlugin] Log + <-> [MyPlugin] Collaped group + [MyPlugin] Log inside collapsed group + [MyPlugin] Time: Xms +" +`); done(); }); }); @@ -612,26 +586,19 @@ describe("Compiler", () => { }); compiler.outputFileSystem = new MemoryFs(); compiler.run((err, stats) => { - expect(spies.group).toHaveBeenCalledTimes(1); - expect(spies.group).toHaveBeenCalledWith("[MyPlugin] Group"); - expect(spies.groupCollapsed).toHaveBeenCalledTimes(1); - expect(spies.groupCollapsed).toHaveBeenCalledWith( - "[MyPlugin] Collaped group" - ); - expect(spies.error).toHaveBeenCalledTimes(1); - expect(spies.error).toHaveBeenCalledWith(" [MyPlugin] Error"); - expect(spies.warn).toHaveBeenCalledTimes(1); - expect(spies.warn).toHaveBeenCalledWith(" [MyPlugin] Warning"); - expect(spies.info).toHaveBeenCalledTimes(1); - expect(spies.info).toHaveBeenCalledWith(" [MyPlugin] Info"); - expect(spies.log).toHaveBeenCalledTimes(3); - expect(spies.log).toHaveBeenCalledWith("[MyPlugin] Log"); - expect(spies.log).toHaveBeenCalledWith( - "[MyPlugin] Log inside collapsed group" - ); - expect(spies.debug).toHaveBeenCalledTimes(1); - expect(spies.debug).toHaveBeenCalledWith("[MyPlugin] Debug"); - expect(spies.groupEnd).toHaveBeenCalledTimes(2); + expect(capture.toString().replace(/[\d.]+ms/, "Xms")) + .toMatchInlineSnapshot(` +"<-> [MyPlugin] Group + [MyPlugin] Error + [MyPlugin] Warning + [MyPlugin] Info + [MyPlugin] Log + [MyPlugin] Debug + <-> [MyPlugin] Collaped group + [MyPlugin] Log inside collapsed group + [MyPlugin] Time: Xms +" +`); done(); }); }); @@ -650,14 +617,7 @@ describe("Compiler", () => { }); compiler.outputFileSystem = new MemoryFs(); compiler.run((err, stats) => { - expect(spies.group).toHaveBeenCalledTimes(0); - expect(spies.groupCollapsed).toHaveBeenCalledTimes(0); - expect(spies.error).toHaveBeenCalledTimes(0); - expect(spies.warn).toHaveBeenCalledTimes(0); - expect(spies.info).toHaveBeenCalledTimes(0); - expect(spies.log).toHaveBeenCalledTimes(0); - expect(spies.debug).toHaveBeenCalledTimes(0); - expect(spies.groupEnd).toHaveBeenCalledTimes(0); + expect(capture.toString()).toMatchInlineSnapshot(`""`); done(); }); }); From 0b0e9e960819f508a975fa9693636cc5bf86370f Mon Sep 17 00:00:00 2001 From: Tobias Koppers Date: Thu, 1 Aug 2019 08:18:45 +0200 Subject: [PATCH 7/9] fix Progress and Stats Tests for colors and output --- lib/logging/truncateArgs.js | 4 ++-- lib/node/nodeConsole.js | 1 + test/ProgressPlugin.test.js | 22 +++++++++++++++------- test/StatsTestCases.test.js | 17 ++++++++++++----- test/helpers/captureStdio.js | 18 +++++++++++++++++- 5 files changed, 47 insertions(+), 15 deletions(-) diff --git a/lib/logging/truncateArgs.js b/lib/logging/truncateArgs.js index 714e4624c..53f52c835 100644 --- a/lib/logging/truncateArgs.js +++ b/lib/logging/truncateArgs.js @@ -23,7 +23,7 @@ const truncateArgs = (args, maxLength) => { } // Check if there is space for at least 4 chars per arg - if (availableLength < lengths.reduce((s, i) => s + Math.min(i, 4), 0)) { + if (availableLength < lengths.reduce((s, i) => s + Math.min(i, 6), 0)) { // remove args if (args.length > 1) return truncateArgs(args.slice(0, args.length - 1), maxLength); @@ -61,7 +61,7 @@ const truncateArgs = (args, maxLength) => { const length = lengths[i]; if (str.length === length) { return str; - } else if (length > 6) { + } else if (length > 5) { return "..." + str.slice(-length + 3); } else if (length > 0) { return str.slice(-length); diff --git a/lib/node/nodeConsole.js b/lib/node/nodeConsole.js index 016bbf2b9..dd09e0ecd 100644 --- a/lib/node/nodeConsole.js +++ b/lib/node/nodeConsole.js @@ -111,6 +111,7 @@ module.exports = { }), status: tty ? (name, ...args) => { + args = args.filter(Boolean); if (name === undefined && args.length === 0) { clearStatusMessage(); currentStatusMessage = undefined; diff --git a/test/ProgressPlugin.test.js b/test/ProgressPlugin.test.js index dbd6b377f..f202a31eb 100644 --- a/test/ProgressPlugin.test.js +++ b/test/ProgressPlugin.test.js @@ -3,19 +3,18 @@ const _ = require("lodash"); const path = require("path"); const MemoryFs = require("memory-fs"); -const webpack = require("../"); const captureStdio = require("./helpers/captureStdio"); +let webpack; + describe("ProgressPlugin", function() { - let _env; let stderr; beforeEach(() => { - _env = process.env; - stderr = captureStdio(process.stderr); + stderr = captureStdio(process.stderr, true); + webpack = require("../"); }); afterEach(() => { - process.env = _env; stderr && stderr.restore(); }); @@ -38,9 +37,18 @@ describe("ProgressPlugin", function() { expect(logs.length).toBeGreaterThan(20); logs.forEach(log => expect(log.length).toBeLessThanOrEqual(30)); expect(logs).toContain( - " 10% building ...ules ...tive", + "77% ...timization ...nksPlugin", "trims each detail string equally" ); + expect(logs).toContain( + "10% building ...dules 0 active", + "remove empty arguments" + ); + expect(logs).toContain( + "10% building ...dules 1 active", + "omit arguments when no space" + ); + expect(logs).toContain("93% ...hunk asset optimization"); }); }); @@ -88,7 +96,7 @@ const createSimpleCompiler = () => { return compiler; }; -const getLogs = logsStr => logsStr.split(/\u0008+/).filter(v => !(v === " ")); +const getLogs = logsStr => logsStr.split(/\r/).filter(v => !(v === " ")); const RunCompilerAsync = compiler => new Promise((resolve, reject) => { diff --git a/test/StatsTestCases.test.js b/test/StatsTestCases.test.js index 80e3c5498..84e0802cf 100644 --- a/test/StatsTestCases.test.js +++ b/test/StatsTestCases.test.js @@ -4,10 +4,11 @@ const path = require("path"); const fs = require("fs"); -const webpack = require("../lib/webpack"); const Stats = require("../lib/Stats"); const captureStdio = require("./helpers/captureStdio"); +let webpack; + /** * Escapes regular expression metacharacters * @param {string} str String to quote @@ -37,6 +38,14 @@ const tests = fs }); describe("StatsTestCases", () => { + let stderr; + beforeEach(() => { + stderr = captureStdio(process.stderr, true); + webpack = require("../lib/webpack"); + }); + afterEach(() => { + stderr.restore(); + }); tests.forEach(testName => { it("should print correct stats for " + testName, done => { jest.setTimeout(10000); @@ -67,9 +76,7 @@ describe("StatsTestCases", () => { }) ); }); - const captured = captureStdio(process.stderr); const c = webpack(options); - captured.restore(); const compilers = c.compilers ? c.compilers : [c]; compilers.forEach(c => { const ifs = c.inputFileSystem; @@ -114,7 +121,7 @@ describe("StatsTestCases", () => { let actual = stats.toString(toStringOptions); expect(typeof actual).toBe("string"); if (!hasColorSetting) { - actual = captured.toString() + actual; + actual = stderr.toString() + actual; actual = actual .replace(/\u001b\[[0-9;]*m/g, "") .replace(/[.0-9]+(\s?ms)/g, "X$1") @@ -123,7 +130,7 @@ describe("StatsTestCases", () => { "$1 Thu Jan 01 1970 00:00:00 GMT" ); } else { - actual = captured.toStringRaw() + actual; + actual = stderr.toStringRaw() + actual; actual = actual .replace(/\u001b\[1m\u001b\[([0-9;]*)m/g, "") .replace(/\u001b\[1m/g, "") diff --git a/test/helpers/captureStdio.js b/test/helpers/captureStdio.js index 86f4a75ef..db1bdf173 100644 --- a/test/helpers/captureStdio.js +++ b/test/helpers/captureStdio.js @@ -1,13 +1,22 @@ const stripAnsi = require("strip-ansi"); -module.exports = stdio => { +module.exports = (stdio, tty) => { let logs = []; const write = stdio.write; + const isTTY = stdio.isTTY; stdio.write = function(str) { logs.push(str); }; + if (tty !== undefined) stdio.isTTY = tty; + + // isTTY flag is only read once on initialization + // therefore we need to clear some module caches + // to get the mocked value + delete require.cache[require.resolve("../../")]; + delete require.cache[require.resolve("../../lib/node/NodeEnvironmentPlugin")]; + delete require.cache[require.resolve("../../lib/node/nodeConsole")]; return { data: logs, @@ -24,6 +33,13 @@ module.exports = stdio => { restore() { stdio.write = write; + stdio.isTTY = isTTY; + + delete require.cache[require.resolve("../../")]; + delete require.cache[ + require.resolve("../../lib/node/NodeEnvironmentPlugin") + ]; + delete require.cache[require.resolve("../../lib/node/nodeConsole")]; } }; }; From 98148b61c6b3ec8a12dc7a6a5679ac5ff3805a3a Mon Sep 17 00:00:00 2001 From: Tobias Koppers Date: Thu, 1 Aug 2019 08:20:34 +0200 Subject: [PATCH 8/9] add infrastructureLog hook to MulitCompiler --- lib/MultiCompiler.js | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/lib/MultiCompiler.js b/lib/MultiCompiler.js index 3055a4893..e9c3005e7 100644 --- a/lib/MultiCompiler.js +++ b/lib/MultiCompiler.js @@ -18,7 +18,10 @@ module.exports = class MultiCompiler extends Tapable { invalid: new MultiHook(compilers.map(c => c.hooks.invalid)), run: new MultiHook(compilers.map(c => c.hooks.run)), watchClose: new SyncHook([]), - watchRun: new MultiHook(compilers.map(c => c.hooks.watchRun)) + watchRun: new MultiHook(compilers.map(c => c.hooks.watchRun)), + infrastructureLog: new MultiHook( + compilers.map(c => c.hooks.infrastructureLog) + ) }; if (!Array.isArray(compilers)) { compilers = Object.keys(compilers).map(name => { From 1963e4018fcb192916240c688615bc5df91f3ce7 Mon Sep 17 00:00:00 2001 From: Tobias Koppers Date: Thu, 1 Aug 2019 12:01:56 +0200 Subject: [PATCH 9/9] improve tests for different infrastructure logging levels --- .../__snapshots__/StatsTestCases.test.js.snap | 43 ++++++++++++------- test/helpers/LogTestPlugin.js | 3 ++ .../preset-detailed/webpack.config.js | 3 ++ .../webpack.config.js | 3 ++ .../preset-errors-warnings/webpack.config.js | 3 ++ .../preset-minimal/webpack.config.js | 3 ++ .../preset-verbose/webpack.config.js | 3 ++ 7 files changed, 45 insertions(+), 16 deletions(-) diff --git a/test/__snapshots__/StatsTestCases.test.js.snap b/test/__snapshots__/StatsTestCases.test.js.snap index 8c43cd8ef..600b17f30 100644 --- a/test/__snapshots__/StatsTestCases.test.js.snap +++ b/test/__snapshots__/StatsTestCases.test.js.snap @@ -1252,7 +1252,7 @@ Entrypoint main = main.js <+> Collaped group Log End -+ 3 hidden lines ++ 6 hidden lines DEBUG LOG from node_modules/custom-loader/index.js node_modules/custom-loader/index.js!index.js An error @@ -1916,9 +1916,14 @@ chunk {6} preloaded3.js (preloaded3) 0 bytes <{2}> [rendered]" `; exports[`StatsTestCases should print correct stats for preset-detailed 1`] = ` -" [LogTestPlugin] Error - [LogTestPlugin] Warning - [LogTestPlugin] Info +"<-> [LogTestPlugin] Group + [LogTestPlugin] Error + [LogTestPlugin] Warning + [LogTestPlugin] Info + [LogTestPlugin] Log + <+> [LogTestPlugin] Collaped group + [LogTestPlugin] Log + [LogTestPlugin] End Hash: 2b293d5b94136dfe6d9c Time: Xms Built at: Thu Jan 01 1970 00:00:00 GMT @@ -1958,19 +1963,17 @@ LOG from LogTestPlugin <+> Collaped group Log End -+ 3 hidden lines" ++ 6 hidden lines" `; exports[`StatsTestCases should print correct stats for preset-errors-only 1`] = `""`; exports[`StatsTestCases should print correct stats for preset-errors-only-error 1`] = ` " [LogTestPlugin] Error - [LogTestPlugin] Warning - [LogTestPlugin] Info LOG from LogTestPlugin Error -+ 11 hidden lines ++ 14 hidden lines ERROR in ./index.js Module not found: Error: Can't resolve 'does-not-exist' in 'Xdir/preset-errors-only-error' @@ -1980,24 +1983,22 @@ Module not found: Error: Can't resolve 'does-not-exist' in 'Xdir/preset-errors-o exports[`StatsTestCases should print correct stats for preset-errors-warnings 1`] = ` " [LogTestPlugin] Error [LogTestPlugin] Warning - [LogTestPlugin] Info LOG from LogTestPlugin Error Warning -+ 10 hidden lines" ++ 13 hidden lines" `; exports[`StatsTestCases should print correct stats for preset-minimal 1`] = ` " [LogTestPlugin] Error [LogTestPlugin] Warning - [LogTestPlugin] Info 6 modules LOG from LogTestPlugin Error Warning -+ 10 hidden lines" ++ 13 hidden lines" `; exports[`StatsTestCases should print correct stats for preset-minimal-simple 1`] = `" 1 module"`; @@ -2045,7 +2046,7 @@ LOG from LogTestPlugin Error Warning Info -+ 9 hidden lines" ++ 12 hidden lines" `; exports[`StatsTestCases should print correct stats for preset-normal-performance 1`] = ` @@ -2109,9 +2110,17 @@ Entrypoints: `; exports[`StatsTestCases should print correct stats for preset-verbose 1`] = ` -" [LogTestPlugin] Error - [LogTestPlugin] Warning - [LogTestPlugin] Info +"<-> [LogTestPlugin] Group + [LogTestPlugin] Error + [LogTestPlugin] Warning + [LogTestPlugin] Info + [LogTestPlugin] Log + <-> [LogTestPlugin] Collaped group + [LogTestPlugin] Log inside collapsed group + <-> [LogTestPlugin] Inner group + [LogTestPlugin] Inner inner message + [LogTestPlugin] Log + [LogTestPlugin] End Hash: 2b293d5b94136dfe6d9c Time: Xms Built at: Thu Jan 01 1970 00:00:00 GMT @@ -2162,6 +2171,8 @@ LOG from LogTestPlugin Log <-> Collaped group Log inside collapsed group + <-> Inner group + Inner inner message Log End + 1 hidden lines diff --git a/test/helpers/LogTestPlugin.js b/test/helpers/LogTestPlugin.js index 3849e1046..78a778514 100644 --- a/test/helpers/LogTestPlugin.js +++ b/test/helpers/LogTestPlugin.js @@ -14,6 +14,9 @@ module.exports = class LogTestPlugin { logger.debug("Debug"); logger.groupCollapsed("Collaped group"); logger.log("Log inside collapsed group"); + logger.group("Inner group"); + logger.groupEnd(); + logger.log("Inner inner message"); logger.groupEnd(); logger.log("Log"); logger.groupEnd(); diff --git a/test/statsCases/preset-detailed/webpack.config.js b/test/statsCases/preset-detailed/webpack.config.js index a41b087a2..27d988981 100644 --- a/test/statsCases/preset-detailed/webpack.config.js +++ b/test/statsCases/preset-detailed/webpack.config.js @@ -4,5 +4,8 @@ module.exports = { mode: "production", entry: "./index", stats: "detailed", + infrastructureLogging: { + level: "log" + }, plugins: [new LogTestPlugin()] }; diff --git a/test/statsCases/preset-errors-only-error/webpack.config.js b/test/statsCases/preset-errors-only-error/webpack.config.js index 38a3f3201..0f4a73577 100644 --- a/test/statsCases/preset-errors-only-error/webpack.config.js +++ b/test/statsCases/preset-errors-only-error/webpack.config.js @@ -4,5 +4,8 @@ module.exports = { mode: "production", entry: "./index", stats: "errors-only", + infrastructureLogging: { + level: "error" + }, plugins: [new LogTestPlugin()] }; diff --git a/test/statsCases/preset-errors-warnings/webpack.config.js b/test/statsCases/preset-errors-warnings/webpack.config.js index f8ccd58cc..7697cda4e 100644 --- a/test/statsCases/preset-errors-warnings/webpack.config.js +++ b/test/statsCases/preset-errors-warnings/webpack.config.js @@ -4,5 +4,8 @@ module.exports = { mode: "production", entry: "./index", stats: "errors-warnings", + infrastructureLogging: { + level: "warn" + }, plugins: [new LogTestPlugin()] }; diff --git a/test/statsCases/preset-minimal/webpack.config.js b/test/statsCases/preset-minimal/webpack.config.js index fd9934b2f..85a5515e2 100644 --- a/test/statsCases/preset-minimal/webpack.config.js +++ b/test/statsCases/preset-minimal/webpack.config.js @@ -4,5 +4,8 @@ module.exports = { mode: "production", entry: "./index", stats: "minimal", + infrastructureLogging: { + level: "warn" + }, plugins: [new LogTestPlugin()] }; diff --git a/test/statsCases/preset-verbose/webpack.config.js b/test/statsCases/preset-verbose/webpack.config.js index bb9778aea..b4e977e78 100644 --- a/test/statsCases/preset-verbose/webpack.config.js +++ b/test/statsCases/preset-verbose/webpack.config.js @@ -5,5 +5,8 @@ module.exports = { entry: "./index", profile: true, stats: "verbose", + infrastructureLogging: { + level: "verbose" + }, plugins: [new LogTestPlugin()] };