Skip to content

Commit 9b47780

Browse files
RandomByteRandomByte
committed
feat(logger): Add module filtering, task-skip event
Allow filtering of log messages by module names using an environment variable UI5_LOG_MODULES. Inspired by the 'debug' npm package. **Examples:** * `UI5_LOG_MODULES=specifications:*,graph:Module,Build ui5 build` * `UI5_LOG_MODULES=graph:*,-graph:providers:* ui5 serve --verbose` Add a new log event "task-skip". Cherry-pick of SAP/ui5-logger#480 JIRA: CPOUI5FOUNDATION-1174
1 parent cadc077 commit 9b47780

File tree

4 files changed

+272
-1
lines changed

4 files changed

+272
-1
lines changed

‎packages/logger/lib/loggers/ProjectBuild.js‎

Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -83,6 +83,24 @@ class ProjectBuild extends Logger {
8383
this._log(level, `${this.#projectName}: Finished task ${taskName}`);
8484
}
8585
}
86+
87+
skipTask(taskName) {
88+
if (!this.#tasksToRun || !this.#tasksToRun.includes(taskName)) {
89+
throw new Error(`loggers/ProjectBuild#skipTask: Unknown task ${taskName}`);
90+
}
91+
const level = "info";
92+
const hasListeners = this._emit(ProjectBuild.PROJECT_BUILD_STATUS_EVENT_NAME, {
93+
level,
94+
projectName: this.#projectName,
95+
projectType: this.#projectType,
96+
taskName,
97+
status: "task-skip",
98+
});
99+
100+
if (!hasListeners) {
101+
this._log(level, `${this.#projectName}: Skipping task ${taskName}`);
102+
}
103+
}
86104
}
87105

88106
export default ProjectBuild;

‎packages/logger/lib/writers/Console.js‎

Lines changed: 91 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ class Console {
2121
#progressBarContainer;
2222
#progressBar;
2323
#progressProjectWeight;
24+
#moduleFilter;
2425

2526
constructor() {
2627
this._handleLogEvent = this.#handleLogEvent.bind(this);
@@ -29,6 +30,72 @@ class Console {
2930
this._handleBuildMetadataEvent = this.#handleBuildMetadataEvent.bind(this);
3031
this._handleProjectBuildMetadataEvent = this.#handleProjectBuildMetadataEvent.bind(this);
3132
this._handleStop = this.disable.bind(this);
33+
this.#initFiters();
34+
}
35+
36+
#initFiters() {
37+
const modulesPatterns = process.env.UI5_LOG_MODULES;
38+
if (!modulesPatterns) {
39+
this.#moduleFilter = null;
40+
return;
41+
}
42+
const enabledModules = [];
43+
const enabledNamespaces = [];
44+
const disabledModules = [];
45+
const disabledNamespaces = [];
46+
// Example of modulePattern: "module1,module2:submodule:subsubmodule,module3:*:-module3:submodule"
47+
modulesPatterns.split(",").forEach((modulePattern) => {
48+
const pattern = modulePattern.trim();
49+
if (pattern.startsWith("-")) {
50+
if (pattern.endsWith(":*")) {
51+
disabledNamespaces.push(pattern.substring(1, pattern.length - 2));
52+
} else {
53+
disabledModules.push(pattern.substring(1));
54+
}
55+
} else {
56+
if (pattern.endsWith(":*")) {
57+
enabledNamespaces.push(pattern.substring(0, pattern.length - 2));
58+
} else {
59+
enabledModules.push(pattern);
60+
}
61+
}
62+
});
63+
64+
this.#moduleFilter = {
65+
enabledModules,
66+
enabledNamespaces,
67+
disabledModules,
68+
disabledNamespaces,
69+
};
70+
}
71+
72+
#filterModule(moduleName) {
73+
if (!this.#moduleFilter) {
74+
return true;
75+
}
76+
if (this.#moduleFilter.disabledModules.includes(moduleName)) {
77+
return false;
78+
}
79+
if (this.#moduleFilter.enabledModules.includes(moduleName)) {
80+
return true;
81+
}
82+
const moduleParts = moduleName.split(":");
83+
for (let i = moduleParts.length - 1; i > 0; i--) {
84+
const namespace = moduleParts.slice(0, i).join(":");
85+
if (this.#moduleFilter.disabledNamespaces.includes(namespace)) {
86+
return false;
87+
}
88+
if (this.#moduleFilter.enabledNamespaces.includes(namespace)) {
89+
return true;
90+
}
91+
}
92+
93+
// If any module or namespace is enabled, all other modules are disabled by default
94+
if (this.#moduleFilter.enabledModules.length > 0 || this.#moduleFilter.enabledNamespaces.length > 0) {
95+
return false;
96+
}
97+
98+
return true;
3299
}
33100

34101
/**
@@ -137,7 +204,9 @@ class Console {
137204
}
138205

139206
#handleLogEvent({level, message, moduleName}) {
140-
this.#writeMessage(level, `${chalk.blue(moduleName)} ${message}`);
207+
if (this.#filterModule(moduleName)) {
208+
this.#writeMessage(level, `${chalk.blue(moduleName)} ${message}`);
209+
}
141210
}
142211

143212
#handleBuildMetadataEvent({projectsToBuild}) {
@@ -328,6 +397,27 @@ class Console {
328397
taskMetadata.executionEnded = true;
329398
message = `${chalk.green(figures.tick)} Finished task ${chalk.bold(taskName)}`;
330399

400+
// Update progress bar (if used)
401+
this._getProgressBar()?.increment(1);
402+
break;
403+
case "task-skip":
404+
if (taskMetadata.executionSkipped) {
405+
throw new Error(`writers/Console: ` +
406+
`Unexpected duplicate task-skip event for project ${projectName}, task ${taskName}`);
407+
}
408+
if (taskMetadata.executionStarted) {
409+
throw new Error(`writers/Console: ` +
410+
`Unexpected task-skip event for project ${projectName}, task ${taskName}. ` +
411+
`Task execution already started`);
412+
}
413+
if (taskMetadata.executionEnded) {
414+
throw new Error(`writers/Console: ` +
415+
`Unexpected task-skip event for project ${projectName}, task ${taskName}. ` +
416+
`Task execution already ended`);
417+
}
418+
taskMetadata.executionEnded = true;
419+
message = `${chalk.green(figures.tick)} Skipping task ${chalk.bold(taskName)}`;
420+
331421
// Update progress bar (if used)
332422
this._getProgressBar()?.increment(1);
333423
break;

‎packages/logger/test/lib/loggers/ProjectBuild.js‎

Lines changed: 55 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -228,3 +228,58 @@ test.serial("End task: Unknown task", (t) => {
228228
}, "Threw with expected error message");
229229
});
230230

231+
test.serial("Skip task", (t) => {
232+
const {projectBuildLogger, logHandler, metadataHandler, statusHandler, logStub} = t.context;
233+
projectBuildLogger.setTasks(["task.a"]);
234+
235+
projectBuildLogger.skipTask("task.a");
236+
237+
t.is(statusHandler.callCount, 1, "One build-status event emitted");
238+
t.deepEqual(statusHandler.getCall(0).args[0], {
239+
level: "info",
240+
projectName: "projectName",
241+
projectType: "projectType",
242+
status: "task-skip",
243+
taskName: "task.a",
244+
}, "Metadata event has expected payload");
245+
246+
t.is(logHandler.callCount, 0, "No log event emitted");
247+
t.is(metadataHandler.callCount, 1, "One build-metadata event emitted");
248+
t.is(logStub.callCount, 0, "_log was never called");
249+
});
250+
251+
test.serial("No event listener: Skip task", (t) => {
252+
const {projectBuildLogger, logHandler, metadataHandler, statusHandler, logStub} = t.context;
253+
process.off(ProjectBuildLogger.PROJECT_BUILD_STATUS_EVENT_NAME, statusHandler);
254+
projectBuildLogger.setTasks(["task.a"]);
255+
256+
projectBuildLogger.skipTask("task.a");
257+
t.is(logStub.callCount, 1, "_log got called once");
258+
t.is(logStub.getCall(0).args[0], "info", "Logged with expected log-level");
259+
t.is(logStub.getCall(0).args[1],
260+
"projectName: Skipping task task.a",
261+
"Logged expected message");
262+
263+
t.is(logHandler.callCount, 0, "No log event emitted");
264+
t.is(metadataHandler.callCount, 1, "One build-metadata event emitted");
265+
});
266+
267+
test.serial("Skip task: Unknown task", (t) => {
268+
const {projectBuildLogger} = t.context;
269+
270+
// Throws because no projects are set
271+
t.throws(() => {
272+
projectBuildLogger.skipTask("task.x");
273+
}, {
274+
message: `loggers/ProjectBuild#skipTask: Unknown task task.x`
275+
}, "Threw with expected error message");
276+
277+
projectBuildLogger.setTasks(["task.a"]);
278+
// Throws because given project is unknown
279+
t.throws(() => {
280+
projectBuildLogger.skipTask("task.x");
281+
}, {
282+
message: `loggers/ProjectBuild#skipTask: Unknown task task.x`
283+
}, "Threw with expected error message");
284+
});
285+

‎packages/logger/test/lib/writers/ConsoleFilter.js‎

Lines changed: 108 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,108 @@
1+
import test from "ava";
2+
import sinon from "sinon";
3+
import stripAnsi from "strip-ansi";
4+
import ConsoleWriter from "../../../lib/writers/Console.js";
5+
6+
test.serial.beforeEach((t) => {
7+
t.context.stderrWriteStub = sinon.stub(process.stderr, "write");
8+
t.context.originalIsTty = process.stderr.isTTY;
9+
process.env.UI5_LOG_LVL = "info";
10+
});
11+
12+
test.serial.afterEach.always((t) => {
13+
if (t.context.consoleWriter) {
14+
t.context.consoleWriter.disable();
15+
}
16+
sinon.restore();
17+
process.stderr.isTTY = t.context.originalIsTty;
18+
delete process.env.UI5_LOG_LVL;
19+
delete process.env.UI5_LOG_MODULES;
20+
});
21+
22+
test.serial("Module filtering: No filter", (t) => {
23+
const {stderrWriteStub} = t.context;
24+
t.context.consoleWriter = ConsoleWriter.init();
25+
26+
process.emit("ui5.log", {
27+
level: "info",
28+
message: "Message 1",
29+
moduleName: "my:module"
30+
});
31+
32+
t.is(stderrWriteStub.callCount, 1, "Logged one message");
33+
t.is(stripAnsi(stderrWriteStub.getCall(0).args[0]), `info my:module Message 1\n`,
34+
"Logged expected message");
35+
});
36+
37+
test.serial("Module filtering: Enable one module", (t) => {
38+
const {stderrWriteStub} = t.context;
39+
process.env.UI5_LOG_MODULES = "my:module";
40+
t.context.consoleWriter = ConsoleWriter.init();
41+
42+
process.emit("ui5.log", {level: "info", message: "Message 1", moduleName: "my:module"});
43+
process.emit("ui5.log", {level: "info", message: "Message 2", moduleName: "other:module"});
44+
45+
t.is(stderrWriteStub.callCount, 1, "Logged one message");
46+
t.is(stripAnsi(stderrWriteStub.getCall(0).args[0]), `info my:module Message 1\n`,
47+
"Logged expected message");
48+
});
49+
50+
test.serial("Module filtering: Enable one namespace", (t) => {
51+
const {stderrWriteStub} = t.context;
52+
process.env.UI5_LOG_MODULES = "my:*";
53+
t.context.consoleWriter = ConsoleWriter.init();
54+
55+
process.emit("ui5.log", {level: "info", message: "Message 1", moduleName: "my:module"});
56+
process.emit("ui5.log", {level: "info", message: "Message 2", moduleName: "my:other:module"});
57+
process.emit("ui5.log", {level: "info", message: "Message 3", moduleName: "other:module"});
58+
59+
t.is(stderrWriteStub.callCount, 2, "Logged two messages");
60+
t.is(stripAnsi(stderrWriteStub.getCall(0).args[0]), `info my:module Message 1\n`,
61+
"Logged expected message");
62+
t.is(stripAnsi(stderrWriteStub.getCall(1).args[0]), `info my:other:module Message 2\n`,
63+
"Logged expected message");
64+
});
65+
66+
test.serial("Module filtering: Disable one module", (t) => {
67+
const {stderrWriteStub} = t.context;
68+
process.env.UI5_LOG_MODULES = "-my:module";
69+
t.context.consoleWriter = ConsoleWriter.init();
70+
71+
process.emit("ui5.log", {level: "info", message: "Message 1", moduleName: "my:module"});
72+
process.emit("ui5.log", {level: "info", message: "Message 2", moduleName: "other:module"});
73+
74+
t.is(stderrWriteStub.callCount, 1, "Logged one message");
75+
t.is(stripAnsi(stderrWriteStub.getCall(0).args[0]), `info other:module Message 2\n`,
76+
"Logged expected message");
77+
});
78+
79+
test.serial("Module filtering: Disable one namespace", (t) => {
80+
const {stderrWriteStub} = t.context;
81+
process.env.UI5_LOG_MODULES = "-my:*";
82+
t.context.consoleWriter = ConsoleWriter.init();
83+
84+
process.emit("ui5.log", {level: "info", message: "Message 1", moduleName: "my:module"});
85+
process.emit("ui5.log", {level: "info", message: "Message 2", moduleName: "my:other:module"});
86+
process.emit("ui5.log", {level: "info", message: "Message 3", moduleName: "other:module"});
87+
88+
t.is(stderrWriteStub.callCount, 1, "Logged one message");
89+
t.is(stripAnsi(stderrWriteStub.getCall(0).args[0]), `info other:module Message 3\n`,
90+
"Logged expected message");
91+
});
92+
93+
test.serial("Module filtering: Combination of settings", (t) => {
94+
const {stderrWriteStub} = t.context;
95+
process.env.UI5_LOG_MODULES = "my:*, -my:other:module, other:module";
96+
t.context.consoleWriter = ConsoleWriter.init();
97+
98+
process.emit("ui5.log", {level: "info", message: "Message 1", moduleName: "my:module"});
99+
process.emit("ui5.log", {level: "info", message: "Message 2", moduleName: "my:other:module"});
100+
process.emit("ui5.log", {level: "info", message: "Message 3", moduleName: "other:module"});
101+
process.emit("ui5.log", {level: "info", message: "Message 4", moduleName: "another:module"});
102+
103+
t.is(stderrWriteStub.callCount, 2, "Logged two messages");
104+
t.is(stripAnsi(stderrWriteStub.getCall(0).args[0]), `info my:module Message 1\n`,
105+
"Logged expected message for my:module");
106+
t.is(stripAnsi(stderrWriteStub.getCall(1).args[0]), `info other:module Message 3\n`,
107+
"Logged expected message for other:module");
108+
});

0 commit comments

Comments
 (0)