Merge pull request #9506 from webpack/logging/status

Improve infrastructure logging
This commit is contained in:
Tobias Koppers 2019-08-01 16:45:48 +02:00 committed by GitHub
commit 40755384bf
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
24 changed files with 525 additions and 353 deletions

View File

@ -88,7 +88,7 @@ class Compiler extends Tapable {
watchClose: new SyncHook([]),
/** @type {SyncBailHook<string, string, any[]>} */
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
@ -103,6 +103,8 @@ class Compiler extends Tapable {
/** @type {SyncBailHook<string, Entry>} */
entryOption: new SyncBailHook(["context", "entry"])
};
// TODO webpack 5 remove this
this.hooks.infrastructurelog = this.hooks.infrastructureLog;
this._pluginCompat.tap("Compiler", options => {
switch (options.name) {
@ -223,7 +225,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);
}

View File

@ -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 => {
@ -90,6 +93,10 @@ module.exports = class MultiCompiler extends Tapable {
}
}
getInfrastructureLogger(name) {
return this.compilers[0].getInfrastructureLogger(name);
}
validateDependencies(callback) {
const edges = new Set();
const missing = [];

View File

@ -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;

View File

@ -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 = "<s> ";
break;
case LogType.profile:
color = colors.magenta;
prefix = "<p> ";
@ -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;
}

View File

@ -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);
}

View File

@ -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("<i> "));
console.info(...labeledArgs());
break;
case LogType.warn:
if (!debug && loglevel > LogLevel.warn) return;
console.warn(...labeledArgs("<w> "));
console.warn(...labeledArgs());
break;
case LogType.error:
if (!debug && loglevel > LogLevel.error) return;
console.error(...labeledArgs("<e> "));
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("<g> "));
}
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("</g> "));
}
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}`);
}

View File

@ -5,7 +5,8 @@ const createConsoleLogger = require("./createConsoleLogger");
/** @type {createConsoleLogger.LoggerOptions} */
let currentDefaultLoggerOptions = {
level: "info",
debug: false
debug: false,
console
};
let currentDefaultLogger = createConsoleLogger(currentDefaultLoggerOptions);

View File

@ -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, 6), 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 > 5) {
return "..." + str.slice(-length + 3);
} else if (length > 0) {
return str.slice(-length);
} else {
return "";
}
});
};
module.exports = truncateArgs;

View File

@ -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
)

133
lib/node/nodeConsole.js Normal file
View File

@ -0,0 +1,133 @@
/*
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("<i> ", "\u001b[1m\u001b[32m", "\u001b[39m\u001b[22m"),
warn: writeColored("<w> ", "\u001b[1m\u001b[33m", "\u001b[39m\u001b[22m"),
error: writeColored("<e> ", "\u001b[1m\u001b[31m", "\u001b[39m\u001b[22m"),
logTime: writeColored("<t> ", "\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) => {
args = args.filter(Boolean);
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("<s> ", "", "")
};

View File

@ -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("<e> [MyPlugin] Error");
expect(spies.warn).toHaveBeenCalledTimes(1);
expect(spies.warn).toHaveBeenCalledWith("<w> [MyPlugin] Warning");
expect(spies.info).toHaveBeenCalledTimes(1);
expect(spies.info).toHaveBeenCalledWith("<i> [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
<e> [MyPlugin] Error
<w> [MyPlugin] Warning
<i> [MyPlugin] Info
[MyPlugin] Log
<-> [MyPlugin] Collaped group
[MyPlugin] Log inside collapsed group
<t> [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("<e> [MyPlugin] Error");
expect(spies.warn).toHaveBeenCalledTimes(1);
expect(spies.warn).toHaveBeenCalledWith("<w> [MyPlugin] Warning");
expect(spies.info).toHaveBeenCalledTimes(1);
expect(spies.info).toHaveBeenCalledWith("<i> [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
<e> [MyPlugin] Error
<w> [MyPlugin] Warning
<i> [MyPlugin] Info
[MyPlugin] Log
[MyPlugin] Debug
<-> [MyPlugin] Collaped group
[MyPlugin] Log inside collapsed group
<t> [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();
});
});

View File

@ -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) => {

View File

@ -4,8 +4,10 @@
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
@ -36,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);
@ -111,6 +121,7 @@ describe("StatsTestCases", () => {
let actual = stats.toString(toStringOptions);
expect(typeof actual).toBe("string");
if (!hasColorSetting) {
actual = stderr.toString() + actual;
actual = actual
.replace(/\u001b\[[0-9;]*m/g, "")
.replace(/[.0-9]+(\s?ms)/g, "X$1")
@ -119,6 +130,7 @@ describe("StatsTestCases", () => {
"$1 Thu Jan 01 1970 00:00:00 GMT"
);
} else {
actual = stderr.toStringRaw() + actual;
actual = actual
.replace(/\u001b\[1m\u001b\[([0-9;]*)m/g, "<CLR=$1,BOLD>")
.replace(/\u001b\[1m/g, "<CLR=BOLD>")

View File

@ -1236,7 +1236,8 @@ Child 4 chunks:
`;
exports[`StatsTestCases should print correct stats for logging 1`] = `
"Hash: <CLR=BOLD>aa5b75cccf66cd9b1ffa</CLR>
"<i> <CLR=32,BOLD>[LogTestPlugin] Info</CLR>
Hash: <CLR=BOLD>aa5b75cccf66cd9b1ffa</CLR>
Time: <CLR=BOLD>X</CLR>ms
Built at: Thu Jan 01 1970 <CLR=BOLD>00:00:00</CLR> GMT
<CLR=BOLD>Asset</CLR> <CLR=BOLD>Size</CLR> <CLR=BOLD>Chunks</CLR> <CLR=39,BOLD><CLR=22> <CLR=39,BOLD><CLR=22><CLR=BOLD>Chunk Names</CLR>
@ -1244,31 +1245,35 @@ Built at: Thu Jan 01 1970 <CLR=BOLD>00:00:00</CLR> GMT
Entrypoint <CLR=BOLD>main</CLR> = <CLR=32,BOLD>main.js</CLR>
[0] <CLR=BOLD>./index.js</CLR> 0 bytes {<CLR=33,BOLD>0</CLR>}<CLR=32,BOLD> [built]</CLR>
<CLR=BOLD>LOG from MyPlugin</CLR>
<i> <CLR=32,BOLD>Plugin is now active</CLR>
<+> <CLR=36,BOLD>Nested</CLR>
+ 3 hidden lines
<CLR=BOLD>LOG from LogTestPlugin</CLR>
<-> <CLR=36,BOLD>Group</CLR>
<i> <CLR=32,BOLD>Info</CLR>
<CLR=BOLD>Log</CLR>
<+> <CLR=36,BOLD>Collaped group</CLR>
<CLR=BOLD>Log</CLR>
<CLR=BOLD>End</CLR>
+ 6 hidden lines
<CLR=31,BOLD>DEBUG </CLR><CLR=BOLD>LOG from node_modules/custom-loader/index.js node_modules/custom-loader/index.js!index.js</CLR>
<e> <CLR=31,BOLD>An error</CLR>
| at Object.<anonymous>.module.exports (Xdir/logging/node_modules/custom-loader/index.js:5:9)
<w> <CLR=33,BOLD>A warning</CLR>
| at Object.<anonymous>.module.exports (Xdir/logging/node_modules/custom-loader/index.js:6:9)
<CLR=36,BOLD>Unimportant</CLR>
<-> <CLR=36,BOLD>Unimportant</CLR>
<i> <CLR=32,BOLD>Info message</CLR>
<CLR=BOLD>Just log</CLR>
Just debug
<CLR=BOLD>Just log</CLR>
Just debug
<t> <CLR=35,BOLD>Measure: Xms</CLR>
<CLR=36,BOLD>Nested</CLR>
<CLR=BOLD>Log inside collapsed group</CLR>
Trace
<-> <CLR=36,BOLD>Nested</CLR>
<CLR=BOLD>Log inside collapsed group</CLR>
Trace
| at Object.<anonymous>.module.exports (Xdir/logging/node_modules/custom-loader/index.js:15:9)
<t> <CLR=35,BOLD>Measure: Xms</CLR>
-------
<CLR=BOLD>After clear</CLR>
<CLR=BOLD>After clear</CLR>
<CLR=31,BOLD>DEBUG </CLR><CLR=BOLD>LOG from node_modules/custom-loader/index.js Named Logger node_modules/custom-loader/index.js!index.js</CLR>
Message with named logger"
Message with named logger"
`;
exports[`StatsTestCases should print correct stats for max-modules 1`] = `
@ -1911,7 +1916,15 @@ chunk {6} preloaded3.js (preloaded3) 0 bytes <{2}> [rendered]"
`;
exports[`StatsTestCases should print correct stats for preset-detailed 1`] = `
"Hash: 2b293d5b94136dfe6d9c
"<-> [LogTestPlugin] Group
<e> [LogTestPlugin] Error
<w> [LogTestPlugin] Warning
<i> [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
Asset Size Chunks Chunk Names
@ -1941,23 +1954,26 @@ 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
Group
LOG from LogTestPlugin
<-> Group
<e> Error
<w> Warning
<i> Info
Log
Log
<+> Collaped group
+ 3 hidden lines"
Log
End
+ 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`] = `
"
LOG from MyPlugin
"<e> [LogTestPlugin] Error
LOG from LogTestPlugin
<e> Error
+ 9 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'
@ -1965,20 +1981,24 @@ 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
"<e> [LogTestPlugin] Error
<w> [LogTestPlugin] Warning
LOG from LogTestPlugin
<e> Error
<w> Warning
+ 8 hidden lines"
+ 13 hidden lines"
`;
exports[`StatsTestCases should print correct stats for preset-minimal 1`] = `
" 6 modules
"<e> [LogTestPlugin] Error
<w> [LogTestPlugin] Warning
6 modules
LOG from MyPlugin
LOG from LogTestPlugin
<e> Error
<w> Warning
+ 8 hidden lines"
+ 13 hidden lines"
`;
exports[`StatsTestCases should print correct stats for preset-minimal-simple 1`] = `" 1 module"`;
@ -1991,14 +2011,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`] = `
"<e> [LogTestPlugin] Error
<w> [LogTestPlugin] Warning
<i> [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
"<e> [LogTestPlugin] Error
<w> [LogTestPlugin] Warning
<i> [LogTestPlugin] Info
Hash: 2b293d5b94136dfe6d9c
Time: Xms
Built at: Thu Jan 01 1970 00:00:00 GMT
Asset Size Chunks Chunk Names
@ -2014,11 +2042,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
<e> Error
<w> Warning
<i> Info
+ 7 hidden lines"
+ 12 hidden lines"
`;
exports[`StatsTestCases should print correct stats for preset-normal-performance 1`] = `
@ -2082,7 +2110,18 @@ Entrypoints:
`;
exports[`StatsTestCases should print correct stats for preset-verbose 1`] = `
"Hash: 2b293d5b94136dfe6d9c
"<-> [LogTestPlugin] Group
<e> [LogTestPlugin] Error
<w> [LogTestPlugin] Warning
<i> [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
Asset Size Chunks Chunk Names
@ -2124,14 +2163,18 @@ 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
Group
LOG from LogTestPlugin
<-> Group
<e> Error
<w> Warning
<i> Info
Log
Collaped group
Log inside collapsed group
Log
<-> Collaped group
Log inside collapsed group
<-> Inner group
Inner inner message
Log
End
+ 1 hidden lines
LOG from webpack.buildChunkGraph.visitModules

View File

@ -0,0 +1,34 @@
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.group("Inner group");
logger.groupEnd();
logger.log("Inner inner message");
logger.groupEnd();
logger.log("Log");
logger.groupEnd();
logger.log("End");
};
logSome(compiler.getInfrastructureLogger("LogTestPlugin"));
compiler.hooks.compilation.tap("LogTestPlugin", compilation => {
const logger = compilation.getLogger("LogTestPlugin");
logSome(logger);
const otherLogger = compilation.getLogger("LogOtherTestPlugin");
otherLogger.debug("debug message only");
});
}
};

View File

@ -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")];
}
};
};

View File

@ -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,

View File

@ -1,24 +1,11 @@
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()]
infrastructureLogging: {
level: "log"
},
plugins: [new LogTestPlugin()]
};

View File

@ -1,24 +1,11 @@
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()]
infrastructureLogging: {
level: "error"
},
plugins: [new LogTestPlugin()]
};

View File

@ -1,24 +1,11 @@
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()]
infrastructureLogging: {
level: "warn"
},
plugins: [new LogTestPlugin()]
};

View File

@ -1,24 +1,11 @@
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()]
infrastructureLogging: {
level: "warn"
},
plugins: [new LogTestPlugin()]
};

View File

@ -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()]
};

View File

@ -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()]
};

View File

@ -1,25 +1,12 @@
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()]
infrastructureLogging: {
level: "verbose"
},
plugins: [new LogTestPlugin()]
};