Skip to content
Merged
4 changes: 2 additions & 2 deletions .claude/skills/incremental-build/architecture.md
Original file line number Diff line number Diff line change
Expand Up @@ -147,7 +147,7 @@ At build completion, `#revalidateSourceIndex()` re-reads all source files and co
-> Create fresh ResourceIndex from all source resources
-> #combinedIndexState = INITIAL

prepareProjectBuildAndValidateCache()
validateCache({prepareForBuild: true})
-> State is INITIAL -> return false (no cache to validate)

For each task:
Expand Down Expand Up @@ -178,7 +178,7 @@ projectSourcesChanged(changedPaths) / dependencyResourcesChanged(changedPaths)
-> Records changed paths
-> Sets #combinedIndexState = REQUIRES_UPDATE

prepareProjectBuildAndValidateCache()
validateCache({prepareForBuild: true})
-> State is REQUIRES_UPDATE
-> #flushPendingChanges():
#updateSourceIndex(changedPaths) -> reads resources from source reader
Expand Down
8 changes: 4 additions & 4 deletions .claude/skills/incremental-build/performance-investigation.md
Original file line number Diff line number Diff line change
Expand Up @@ -134,10 +134,10 @@ perf Validated result cache for project sap.ui.core in 13 ms
After validation:

```
perf prepareProjectBuildAndValidateCache for sap.ui.core completed in 34 ms (usesCache=true)
perf validateCache for sap.ui.core completed in 34 ms (usesCache=true)
info ✔ Skipping build of library project sap.ui.core
OR
perf prepareProjectBuildAndValidateCache for sap.m completed in 0.48 ms (usesCache=false)
perf validateCache for sap.m completed in 0.48 ms (usesCache=false)
info ❯ Building library project sap.m...
```

Expand Down Expand Up @@ -238,9 +238,9 @@ All `log.perf()` statements by source file:
| `BuildContext.js` | `Parallel source index initialization completed` | Total time for parallel `initSourceIndex` across all projects |
| `BuildContext.js` | `getRequiredProjectContexts completed` | Discovery + index init for all required projects |
| `ProjectBuildContext.js` | `getDependenciesReader completed` | Creating the dependency reader for a project |
| `ProjectBuildContext.js` | `ProjectBuildCache.prepareProjectBuildAndValidateCache completed` | Full cache validation for one project |
| `ProjectBuildContext.js` | `ProjectBuildCache.validateCache completed` | Full cache validation for one project |
| `ProjectBuilder.js` | `getRequiredProjectContexts completed` | Top-level timing (includes context creation) |
| `ProjectBuilder.js` | `prepareProjectBuildAndValidateCache for {project} completed` | Per-project validation with `usesCache` flag |
| `ProjectBuilder.js` | `validateCache for {project} completed` | Per-project validation with `usesCache` flag |
| `TaskRunner.js` | `Task {name} finished in {N} ms` | Individual task execution time |
| `ProjectBuildCache.js` | `#initSourceIndex fromCacheWithDelta` | Delta detection: resource count, changed count |
| `ProjectBuildCache.js` | `Initialized source index for project` | Total source index init (glob + cache read + delta) |
Expand Down
65 changes: 27 additions & 38 deletions packages/logger/lib/loggers/Serve.js
Original file line number Diff line number Diff line change
Expand Up @@ -19,73 +19,62 @@ import Logger from "./Logger.js";
class Serve extends Logger {
static SERVE_STATUS_EVENT_NAME = "ui5.serve-status";

ready() {
const level = "info";
// Emit a `ui5.serve-status` event; if no listener is attached, fall back to
// a plain log line at the same level. All public status methods route
// through here so the event payload shape (`{level, status, ...}`) and the
// no-listener fallback stay in sync across states.
#emitStatus(status, payload, fallbackMessage, {level = "info"} = {}) {
const hasListeners = this._emit(Serve.SERVE_STATUS_EVENT_NAME, {
level,
status: "serve-ready",
status,
...payload,
});
if (!hasListeners) {
this._log(level, `Server ready`);
this._log(level, fallbackMessage);
}
}

ready() {
this.#emitStatus("serve-ready", {}, `Server ready`);
}

stale(changedProjects) {
if (!changedProjects || !Array.isArray(changedProjects)) {
throw new Error("loggers/Serve#stale: Missing or incorrect changedProjects parameter");
}
const level = "info";
const hasListeners = this._emit(Serve.SERVE_STATUS_EVENT_NAME, {
level,
status: "serve-stale",
changedProjects,
});
if (!hasListeners) {
this._log(level, `Sources changed in: ${changedProjects.join(", ")}`);
this.#emitStatus("serve-stale", {changedProjects},
`Sources changed in: ${changedProjects.join(", ")}`);
}

validating(validatingProjects) {
if (!validatingProjects || !Array.isArray(validatingProjects)) {
throw new Error(
"loggers/Serve#validating: Missing or incorrect validatingProjects parameter");
}
this.#emitStatus("serve-validating", {validatingProjects},
`Validating caches for: ${validatingProjects.join(", ")}`);
}

building() {
const level = "info";
const hasListeners = this._emit(Serve.SERVE_STATUS_EVENT_NAME, {
level,
status: "serve-building",
});
if (!hasListeners) {
this._log(level, `Building...`);
}
this.#emitStatus("serve-building", {}, `Building...`);
}

buildDone(hrtime) {
if (!Array.isArray(hrtime) || hrtime.length !== 2 ||
typeof hrtime[0] !== "number" || typeof hrtime[1] !== "number") {
throw new Error("loggers/Serve#buildDone: Missing or incorrect hrtime parameter");
}
const level = "info";
const hasListeners = this._emit(Serve.SERVE_STATUS_EVENT_NAME, {
level,
status: "serve-build-done",
hrtime,
});
if (!hasListeners) {
this._log(level, `Build finished in ${prettyHrtime(hrtime)}`);
}
this.#emitStatus("serve-build-done", {hrtime},
`Build finished in ${prettyHrtime(hrtime)}`);
}

// Named serveError rather than error to avoid shadowing Logger.prototype.error
serveError(error) {
if (!error) {
throw new Error("loggers/Serve#serveError: Missing error parameter");
}
const level = "error";
const hasListeners = this._emit(Serve.SERVE_STATUS_EVENT_NAME, {
level,
status: "serve-error",
error,
});
if (!hasListeners) {
this._log(level, `Server error: ${error.message || error}`);
}
this.#emitStatus("serve-error", {error},
`Server error: ${error.message || error}`, {level: "error"});
}
}

Expand Down
16 changes: 13 additions & 3 deletions packages/logger/lib/writers/InteractiveConsole.js
Original file line number Diff line number Diff line change
Expand Up @@ -9,13 +9,13 @@ import {createProjectState, setProject, enableProjectPlaceholders} from "./inter
import {createServerState, setListening, enableServerPlaceholders} from "./interactiveConsole/state/server.js";
import {
createBuildState, beginBuild, advanceToProject, setTask, transitionTo, setError, STATES,
enableBuildPlaceholders,
SPINNING_STATES, enableBuildPlaceholders,
} from "./interactiveConsole/state/build.js";
import {
renderHeaderRegion, renderProjectRegion, renderServerRegion, renderBuildRegion,
} from "./interactiveConsole/render.js";

// Spinner tick interval while in `building` state.
// Spinner tick interval while in `building` or `validating` state.
const BUILDING_TICK_MS = 120;

// Decode the tail of `stream.write(chunk[, encoding][, callback])`. `encoding`
Expand Down Expand Up @@ -341,6 +341,11 @@ class InteractiveConsole {
}

#handleServeStatus(evt) {
// validatingProjects is a VALIDATING-only payload; clear it on any other
// transition so a stale list doesn't linger in the banner state.
if (evt.status !== "serve-validating") {
this.#buildState.validatingProjects = [];
}
switch (evt.status) {
case "serve-ready":
this.#transitionTo(STATES.READY);
Expand All @@ -353,6 +358,11 @@ class InteractiveConsole {
beginBuild(this.#buildState, this.#buildState.projectOrder);
this.#transitionTo(STATES.BUILDING);
break;
case "serve-validating":
this.#buildState.validatingProjects = evt.validatingProjects || [];
this.#buildState.spinFrame = 0;
this.#transitionTo(STATES.VALIDATING);
break;
case "serve-build-done":
this.#buildState.lastBuildHrtime = Array.isArray(evt.hrtime) ? evt.hrtime : null;
this.#transitionTo(STATES.READY);
Expand Down Expand Up @@ -393,7 +403,7 @@ class InteractiveConsole {
if (this.#stopped) {
return;
}
if (this.#buildState.state !== STATES.BUILDING) {
if (!SPINNING_STATES.has(this.#buildState.state)) {
return;
}
this.#tickTimer = setInterval(() => {
Expand Down
13 changes: 13 additions & 0 deletions packages/logger/lib/writers/interactiveConsole/render.js
Original file line number Diff line number Diff line change
Expand Up @@ -150,6 +150,19 @@ function renderStatusLine(state) {
case STATES.STALE:
return `${label}${chalk.yellow(figures.circle)} ${chalk.yellow(pad("stale"))} ` +
`${chalk.dim("· files changed, rebuild on next request")}`;
case STATES.VALIDATING: {
const frame = SPINNER_FRAMES[state.spinFrame % SPINNER_FRAMES.length];
const parts = [
`${chalk.cyan(frame)} ${chalk.cyan(pad("validating cache"))}`,
chalk.dim("·"),
chalk.dim("checking dependency caches"),
];
const count = state.validatingProjects.length;
if (count > 0) {
parts.push(chalk.dim("·"), chalk.dim(`${count} project${count === 1 ? "" : "s"}`));
}
return `${label}${parts.join(" ")}`;
}
case STATES.BUILDING: {
const frame = SPINNER_FRAMES[state.spinFrame % SPINNER_FRAMES.length];
const parts = [
Expand Down
9 changes: 9 additions & 0 deletions packages/logger/lib/writers/interactiveConsole/state/build.js
Original file line number Diff line number Diff line change
Expand Up @@ -7,9 +7,15 @@ export const STATES = Object.freeze({
READY: "ready",
STALE: "stale",
BUILDING: "building",
VALIDATING: "validating",
ERROR: "error",
});

// States that animate a spinner. Consulted by both the tick scheduler in the
// interactive console writer and the status-line renderer, so a state either
// spins in both places or in neither.
export const SPINNING_STATES = new Set([STATES.BUILDING, STATES.VALIDATING]);

export function createBuildState() {
return {
state: STATES.INITIAL,
Expand All @@ -22,6 +28,9 @@ export function createBuildState() {
// Names of projects collected via `serve-stale` payloads — used to label
// the stale state if/when the renderer wants to.
changedProjects: [],
// Names of projects collected via `serve-validating` payloads — used to
// label the validating state if/when the renderer wants to.
validatingProjects: [],
// Frame counter for the spinner (incremented by the tick loop).
spinFrame: 0,
// Most recent error captured by `serve-error`.
Expand Down
32 changes: 32 additions & 0 deletions packages/logger/test/lib/loggers/Serve.js
Original file line number Diff line number Diff line change
Expand Up @@ -56,6 +56,26 @@ test.serial("stale: Missing parameter", (t) => {
}, "Threw with expected error message");
});

test.serial("validating emits serve-validating", (t) => {
const {serveLogger, statusHandler} = t.context;
serveLogger.validating(["library.a", "library.b"]);
t.is(statusHandler.callCount, 1, "One serve-status event emitted");
t.deepEqual(statusHandler.getCall(0).args[0], {
level: "info",
status: "serve-validating",
validatingProjects: ["library.a", "library.b"],
}, "Status event has expected payload");
});

test.serial("validating: Missing parameter", (t) => {
const {serveLogger} = t.context;
t.throws(() => {
serveLogger.validating();
}, {
message: "loggers/Serve#validating: Missing or incorrect validatingProjects parameter",
}, "Threw with expected error message");
});

test.serial("building emits serve-building", (t) => {
const {serveLogger, statusHandler} = t.context;
serveLogger.building();
Expand Down Expand Up @@ -129,6 +149,18 @@ test.serial("No event listener: stale", (t) => {
t.is(logHandler.callCount, 0, "No log event emitted");
});

test.serial("No event listener: validating", (t) => {
const {serveLogger, statusHandler, logHandler, logStub} = t.context;
process.off(ServeLogger.SERVE_STATUS_EVENT_NAME, statusHandler);
serveLogger.validating(["library.a", "library.b"]);
t.is(logStub.callCount, 1, "_log got called once");
t.is(logStub.getCall(0).args[0], "info", "Logged with expected log-level");
t.is(logStub.getCall(0).args[1],
"Validating caches for: library.a, library.b",
"Logged expected message");
t.is(logHandler.callCount, 0, "No log event emitted");
});

test.serial("No event listener: building", (t) => {
const {serveLogger, statusHandler, logHandler, logStub} = t.context;
process.off(ServeLogger.SERVE_STATUS_EVENT_NAME, statusHandler);
Expand Down
53 changes: 53 additions & 0 deletions packages/logger/test/lib/writers/InteractiveConsole.js
Original file line number Diff line number Diff line change
Expand Up @@ -535,6 +535,40 @@ test.serial("serve-status: serve-stale without a payload falls back to an empty
writer.disable();
});

test.serial("serve-status: serve-validating records projects and transitions to VALIDATING", (t) => {
const {writer, stderr} = createWriter();
process.emit("ui5.serve-status", {
status: "serve-validating",
validatingProjects: ["library.a", "library.b"],
});
const state = writer._getStateForTest().build;
t.is(state.state, STATES.VALIDATING);
t.deepEqual(state.validatingProjects, ["library.a", "library.b"]);
const tail = stripAnsi(stderr.writes.slice(-5).join(""));
t.regex(tail, /validating/);
writer.disable();
});

test.serial("serve-status: serve-validating without a payload falls back to an empty list", (t) => {
const {writer} = createWriter();
process.emit("ui5.serve-status", {status: "serve-validating"});
t.deepEqual(writer._getStateForTest().build.validatingProjects, []);
writer.disable();
});

test.serial("serve-status: transitions away from VALIDATING clear validatingProjects", (t) => {
const {writer} = createWriter();
process.emit("ui5.serve-status", {
status: "serve-validating",
validatingProjects: ["library.a"],
});
t.deepEqual(writer._getStateForTest().build.validatingProjects, ["library.a"]);
process.emit("ui5.serve-status", {status: "serve-ready"});
t.deepEqual(writer._getStateForTest().build.validatingProjects, [],
"validatingProjects cleared on transition away from VALIDATING");
writer.disable();
});

test.serial("serve-status: serve-error coerces a non-Error payload to a string", (t) => {
const {writer} = createWriter();
process.emit("ui5.serve-status", {status: "serve-error", error: "plain string failure"});
Expand Down Expand Up @@ -634,6 +668,25 @@ test.serial("spinner tick advances spinFrame while BUILDING", (t) => {
writer.disable();
});

test.serial("spinner tick advances spinFrame while VALIDATING", (t) => {
const clock = sinon.useFakeTimers();
t.teardown(() => clock.restore());

const {writer, stderr} = createWriter();
process.emit("ui5.serve-status", {
status: "serve-validating",
validatingProjects: ["library.a"],
});
const frameBefore = writer._getStateForTest().build.spinFrame;
stderr.writes.length = 0;
clock.tick(150);
const frameAfter = writer._getStateForTest().build.spinFrame;
t.true(frameAfter > frameBefore, "spinFrame advanced on tick");
t.true(stderr.writes.length > 0, "tick triggered a re-render");
writer.disable();
});


// ---- process.stdout / process.stderr interception ---------------------------
// InteractiveConsole replaces process.stdout.write / process.stderr.write while
// active so writes that bypass @ui5/logger (custom tasks, third-party libs) get
Expand Down
25 changes: 25 additions & 0 deletions packages/logger/test/lib/writers/interactiveConsole/render.js
Original file line number Diff line number Diff line change
Expand Up @@ -253,6 +253,30 @@ test("renderBuildRegion: stale state includes 'files changed' hint", (t) => {
t.regex(plain, /Status\s+.+?\s+stale\s+·\s+files changed/);
});

test("renderBuildRegion: validating state includes 'checking dependency caches' hint", (t) => {
const state = createBuildState();
transitionTo(state, STATES.VALIDATING);
const plain = renderBuildRegion(state).map(stripAnsi).join("\n");
t.regex(plain, /Status\s+.+?\s+validating cache\s+·\s+checking dependency caches/);
t.notRegex(plain, /project/, "no counter fragment when validatingProjects is empty");
});

test("renderBuildRegion: validating state appends singular project count", (t) => {
const state = createBuildState();
state.validatingProjects = ["library.a"];
transitionTo(state, STATES.VALIDATING);
const plain = renderBuildRegion(state).map(stripAnsi).join("\n");
t.regex(plain, /·\s+1 project(?!s)/);
});

test("renderBuildRegion: validating state appends plural project count", (t) => {
const state = createBuildState();
state.validatingProjects = ["library.a", "library.b"];
transitionTo(state, STATES.VALIDATING);
const plain = renderBuildRegion(state).map(stripAnsi).join("\n");
t.regex(plain, /·\s+2 projects/);
});

test("renderBuildRegion: building state renders project counter + project + task", (t) => {
const state = createBuildState();
beginBuild(state, ["proj-a", "my.app", "proj-c"]);
Expand Down Expand Up @@ -375,6 +399,7 @@ const COLOR_BY_STATE = [
{state: STATES.READY, wrap: (x) => chalk.green(x), word: "ready", name: "green"},
{state: STATES.STALE, wrap: (x) => chalk.yellow(x), word: "stale", name: "yellow"},
{state: STATES.BUILDING, wrap: (x) => chalk.yellow(x), word: "building", name: "yellow"},
{state: STATES.VALIDATING, wrap: (x) => chalk.cyan(x), word: "validating cache", name: "cyan"},
{state: STATES.ERROR, wrap: (x) => chalk.red(x), word: "error", name: "red"},
];
for (const {state: s, wrap, word, name} of COLOR_BY_STATE) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@ test("createBuildState: starts in INITIAL with empty counters", (t) => {
t.is(state.totalProjects, 0);
t.deepEqual(state.projectOrder, []);
t.deepEqual(state.changedProjects, []);
t.deepEqual(state.validatingProjects, []);
t.is(state.spinFrame, 0);
t.is(state.errorMessage, "");
t.is(state.lastBuildHrtime, null);
Expand Down
Loading
Loading