Skip to content

Commit ff986e7

Browse files
author
DavidQ
committed
Complete Track 20B Stability & Monitoring
- added runtime error tracking - added performance monitoring hooks - standardized logging Roadmap: Track B [ ] -> [x]
1 parent 6a623a9 commit ff986e7

9 files changed

Lines changed: 226 additions & 28 deletions
Lines changed: 3 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -1,11 +1,3 @@
1-
- [ ] confirmed Track 20A docs already exist and are not re-done here
2-
- [ ] duplicate/superseded doc surfaces identified
3-
- [ ] authoritative current docs selected
4-
- [ ] unique content preserved before any deletion
5-
- [ ] duplicate/superseded docs removed safely
6-
- [ ] empty documentation directories removed safely
7-
- [ ] active references updated
8-
- [ ] onboarding flow validated end-to-end
9-
- [ ] no start_of_day changes
10-
- [ ] unrelated working-tree changes preserved
11-
- [ ] roadmap updated by status-only transitions only after successful validation
1+
- error tracking observable
2+
- performance metrics captured
3+
- logs consistent across modules
Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,21 @@
1+
# BUILD PR LEVEL 20.3
2+
3+
## Purpose
4+
Execute Track 20B Stability & Monitoring with real, testable work.
5+
6+
## Scope
7+
- runtime error tracking
8+
- performance monitoring hooks
9+
- logging standardization
10+
11+
## Acceptance
12+
- error tracking implemented and observable
13+
- performance hooks integrated
14+
- logging standardized across modules
15+
16+
## Roadmap
17+
This PR may advance:
18+
- runtime error tracking [ ] -> [x]
19+
- performance monitoring hooks [ ] -> [x]
20+
- logging standardization [ ] -> [x]
21+
- Track B [ ] -> [x]
Lines changed: 27 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,27 @@
1+
# BUILD_PR_LEVEL_20_3_TRACK_B_STABILITY_MONITORING_EXECUTION Validation
2+
3+
## Scope
4+
- runtime error tracking hooks
5+
- performance monitoring hooks
6+
- standardized logging format and usage
7+
8+
## Implementation summary
9+
1. Engine runtime monitoring hooks:
10+
- added error-tracking hook path with event emission (`engine:runtime-error`)
11+
- added performance hook path with frame payload emission (`engine:performance-frame`)
12+
2. Logging standardization:
13+
- standardized logger entry envelope to `engine.log.v1`
14+
- added explicit `event` field support for structured logging usage
15+
3. Logging usage normalization:
16+
- runtime hook and recovery/error-boundary logging now emits structured event metadata
17+
18+
## Runtime tests executed
19+
1. `node -e "import('./tests/runtime/Phase19RuntimeLifecycleValidation.test.mjs').then((m)=>m.run())"`
20+
- result: PASS
21+
2. `node --input-type=module -e "<alias-hook bootstrap>; import('./tests/runtime/Phase19IntegrationFlowPass.test.mjs').then((m)=>m.run())"`
22+
- result: PASS
23+
24+
## Track 20B status promotion backing
25+
- runtime error tracking: validated by runtime error hook assertions and event emission assertions
26+
- performance monitoring hooks: validated by performance payload and snapshot assertions
27+
- logging standardization: validated by logger format/event assertions

docs/roadmaps/MASTER_ROADMAP_HIGH_LEVEL.md

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -850,9 +850,9 @@
850850
- [x] validate deployment flow
851851

852852
### Track B ? Stability & Monitoring
853-
- [ ] runtime error tracking
854-
- [ ] performance monitoring hooks
855-
- [ ] logging standardization
853+
- [x] runtime error tracking
854+
- [x] performance monitoring hooks
855+
- [x] logging standardization
856856

857857
### Track C ? Documentation Completeness
858858
- [x] finalize developer docs

src/engine/core/Engine.js

Lines changed: 81 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -32,6 +32,7 @@ export default class Engine {
3232
audio = null,
3333
logger = null,
3434
camera3D = null,
35+
runtimeHooks = null,
3536
} = {}) {
3637
if (!canvas) {
3738
throw new Error('Engine requires a canvas.');
@@ -70,6 +71,10 @@ export default class Engine {
7071
});
7172
this.audio = audio || new AudioService();
7273
this.logger = logger || new Logger({ channel: 'engine' });
74+
this.runtimeHooks = {
75+
onError: typeof runtimeHooks?.onError === 'function' ? runtimeHooks.onError : null,
76+
onPerformance: typeof runtimeHooks?.onPerformance === 'function' ? runtimeHooks.onPerformance : null,
77+
};
7378
this.camera3D = camera3D || new Camera3D();
7479
this.settings = new SettingsSystem({
7580
namespace: 'toolboxaid:engine-settings',
@@ -116,8 +121,10 @@ export default class Engine {
116121
try {
117122
scene.setCamera3D(this.camera3D, this);
118123
} catch (error) {
119-
this.logger?.warn?.('Engine scene setCamera3D hook failed.', {
120-
error: error?.message || String(error),
124+
this.trackRuntimeError('scene.setCamera3D', error, {
125+
severity: 'warn',
126+
isolated: true,
127+
message: 'Engine scene setCamera3D hook failed.',
121128
});
122129
}
123130
return;
@@ -130,12 +137,50 @@ export default class Engine {
130137
try {
131138
scene.camera3D = this.camera3D;
132139
} catch (error) {
133-
this.logger?.warn?.('Engine scene camera3D assignment failed.', {
134-
error: error?.message || String(error),
140+
this.trackRuntimeError('scene.camera3D.assign', error, {
141+
severity: 'warn',
142+
isolated: true,
143+
message: 'Engine scene camera3D assignment failed.',
135144
});
136145
}
137146
}
138147

148+
trackRuntimeError(stage, error, { severity = 'error', isolated = false, context = {}, message = null } = {}) {
149+
const payload = {
150+
stage,
151+
isolated: isolated === true,
152+
severity,
153+
error: error?.message || String(error),
154+
timestamp: new Date().toISOString(),
155+
context: { ...context },
156+
};
157+
158+
const loggerMethod = severity === 'warn' ? 'warn' : 'error';
159+
this.logger?.[loggerMethod]?.(message || 'Engine runtime issue tracked.', {
160+
event: 'engine.runtime.error',
161+
stage: payload.stage,
162+
isolated: payload.isolated,
163+
error: payload.error,
164+
...payload.context,
165+
});
166+
167+
this.events?.emit?.('engine:runtime-error', payload);
168+
this.runtimeHooks.onError?.(payload);
169+
return payload;
170+
}
171+
172+
publishPerformanceFrame(frameData) {
173+
const snapshot = typeof this.metrics?.getSnapshot === 'function' ? this.metrics.getSnapshot() : null;
174+
const payload = {
175+
...frameData,
176+
snapshot: snapshot ? { ...snapshot } : null,
177+
timestamp: new Date().toISOString(),
178+
};
179+
this.events?.emit?.('engine:performance-frame', payload);
180+
this.runtimeHooks.onPerformance?.(payload);
181+
return payload;
182+
}
183+
139184
start() {
140185
if (this.input && typeof this.input.attach === 'function') {
141186
this.input.attach();
@@ -188,10 +233,20 @@ export default class Engine {
188233
let fixedUpdates = 0;
189234

190235
if (this.input && typeof this.input.update === 'function') {
191-
this.input.update(deltaSeconds);
236+
try {
237+
this.input.update(deltaSeconds);
238+
} catch (error) {
239+
this.trackRuntimeError('input.update', error, { severity: 'error' });
240+
throw error;
241+
}
192242
}
193243
if (this.audio && typeof this.audio.update === 'function') {
194-
this.audio.update(deltaSeconds);
244+
try {
245+
this.audio.update(deltaSeconds);
246+
} catch (error) {
247+
this.trackRuntimeError('audio.update', error, { severity: 'error' });
248+
throw error;
249+
}
195250
}
196251

197252
const updateStart = performance.now();
@@ -200,14 +255,21 @@ export default class Engine {
200255
try {
201256
this.scene.step3DPhysics(stepSeconds, this);
202257
} catch (error) {
203-
this.logger?.warn?.('Engine scene step3DPhysics hook failed.', {
204-
error: error?.message || String(error),
258+
this.trackRuntimeError('scene.step3DPhysics', error, {
259+
severity: 'warn',
260+
isolated: true,
261+
message: 'Engine scene step3DPhysics hook failed.',
205262
});
206263
}
207264
}
208265

209266
if (this.scene && typeof this.scene.update === 'function') {
210-
this.scene.update(stepSeconds, this);
267+
try {
268+
this.scene.update(stepSeconds, this);
269+
} catch (error) {
270+
this.trackRuntimeError('scene.update', error, { severity: 'error' });
271+
throw error;
272+
}
211273
}
212274
});
213275
fixedUpdates = tickerResult.steps;
@@ -217,7 +279,12 @@ export default class Engine {
217279
this.renderer.clear();
218280
this.backgroundImageLayer?.render?.(this.renderer, { scene: this.scene, engine: this });
219281
if (this.scene && typeof this.scene.render === 'function') {
220-
this.scene.render(this.renderer, this);
282+
try {
283+
this.scene.render(this.renderer, this);
284+
} catch (error) {
285+
this.trackRuntimeError('scene.render', error, { severity: 'error' });
286+
throw error;
287+
}
221288
}
222289
const fullscreenActive = this.fullscreen?.getState?.().active === true;
223290
const fullscreenElement = this.fullscreen?.documentRef?.fullscreenElement
@@ -226,13 +293,15 @@ export default class Engine {
226293
this.fullscreenBezelLayer?.sync?.({ fullscreenActive, fullscreenElement });
227294
renderDurationMs = performance.now() - renderStart;
228295

229-
this.metrics.recordFrame({
296+
const frameData = {
230297
dtSeconds: deltaSeconds,
231298
frameMs: performance.now() - frameStart,
232299
updateMs: updateDurationMs,
233300
renderMs: renderDurationMs,
234301
fixedUpdates,
235-
});
302+
};
303+
this.metrics.recordFrame(frameData);
304+
this.publishPerformanceFrame(frameData);
236305

237306
this.rafId = requestAnimationFrame(this.tick);
238307
}

src/engine/logging/ErrorBoundary.js

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,7 @@ export default class ErrorBoundary {
1414
return operation();
1515
} catch (error) {
1616
this.logger?.error('Operation failed gracefully.', {
17+
event: 'engine.error-boundary.operation-failed',
1718
error: error?.message || 'Unknown error',
1819
});
1920
return fallback;

src/engine/logging/Logger.js

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -22,11 +22,16 @@ export default class Logger {
2222
return null;
2323
}
2424

25+
const normalizedMessage = typeof message === 'string' ? message : String(message);
26+
const metaSource = (meta && typeof meta === 'object') ? meta : { value: meta };
27+
const { event = `${this.channel}.${level}`, ...normalizedMeta } = metaSource;
2528
const entry = {
29+
format: 'engine.log.v1',
2630
level,
2731
channel: this.channel,
28-
message,
29-
meta: { ...meta },
32+
event,
33+
message: normalizedMessage,
34+
meta: { ...normalizedMeta },
3035
timestamp: new Date().toISOString(),
3136
};
3237

src/engine/release/CrashRecoveryManager.js

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -32,6 +32,7 @@ export default class CrashRecoveryManager {
3232
};
3333
} catch (error) {
3434
this.logger?.error('Operation failed gracefully.', {
35+
event: 'engine.crash-recovery.operation-failed',
3536
error: error?.message || 'Unknown error',
3637
label,
3738
});

tests/runtime/Phase19RuntimeLifecycleValidation.test.mjs

Lines changed: 82 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,7 @@ Phase19RuntimeLifecycleValidation.test.mjs
66
*/
77
import assert from 'node:assert/strict';
88
import Engine from '../../src/engine/core/Engine.js';
9+
import { Logger } from '../../src/engine/logging/index.js';
910

1011
function createCanvas() {
1112
const canvas = {
@@ -76,6 +77,8 @@ function createHarness({
7677
fixedStepMs = 16,
7778
scene = null,
7879
logger = null,
80+
events = null,
81+
runtimeHooks = null,
7982
} = {}) {
8083
const attachCounts = {
8184
input: 0,
@@ -135,6 +138,10 @@ function createHarness({
135138
recordFrame(frame) {
136139
metrics.push(frame);
137140
},
141+
getSnapshot() {
142+
const latest = metrics.length > 0 ? metrics[metrics.length - 1] : null;
143+
return latest ? { ...latest } : { frameMs: 0, updateMs: 0, renderMs: 0, fixedUpdates: 0 };
144+
},
138145
},
139146
input: {
140147
attach() {
@@ -171,6 +178,8 @@ function createHarness({
171178
warn() {},
172179
error() {},
173180
},
181+
events,
182+
runtimeHooks,
174183
});
175184

176185
if (scene) {
@@ -350,9 +359,82 @@ function assertLongRunningStability() {
350359
}
351360
}
352361

362+
function assertRuntimeMonitoringHooksAndLoggingFormat() {
363+
const animationFrame = createAnimationFrameStub();
364+
try {
365+
const runtimeErrors = [];
366+
const performanceFrames = [];
367+
const emittedEvents = [];
368+
const logger = new Logger({ channel: 'runtime-test', level: 'debug' });
369+
370+
const harness = createHarness({
371+
logger,
372+
runtimeHooks: {
373+
onError(payload) {
374+
runtimeErrors.push(payload);
375+
},
376+
onPerformance(payload) {
377+
performanceFrames.push(payload);
378+
},
379+
},
380+
events: {
381+
emit(name, payload) {
382+
emittedEvents.push({ name, payload });
383+
return 0;
384+
},
385+
},
386+
scene: {
387+
step3DPhysics() {
388+
throw new Error('monitoring-hook-physics-failure');
389+
},
390+
update() {},
391+
render() {},
392+
},
393+
});
394+
395+
harness.engine.start();
396+
harness.engine.tick(1016);
397+
harness.engine.stop();
398+
399+
assert.equal(runtimeErrors.length >= 1, true, 'Runtime error hook should receive isolated runtime error payloads.');
400+
assert.equal(
401+
runtimeErrors.some((entry) => entry.stage === 'scene.step3DPhysics' && entry.isolated === true),
402+
true,
403+
'Runtime error hook should include scene.step3DPhysics stage metadata.'
404+
);
405+
assert.equal(performanceFrames.length >= 1, true, 'Performance monitoring hook should receive frame payloads.');
406+
assert.equal(
407+
performanceFrames.some((entry) => typeof entry.snapshot === 'object' && entry.snapshot !== null),
408+
true,
409+
'Performance monitoring hook payload should include metrics snapshot.'
410+
);
411+
assert.equal(
412+
emittedEvents.some((entry) => entry.name === 'engine:runtime-error'),
413+
true,
414+
'Engine should emit engine:runtime-error event when runtime errors are tracked.'
415+
);
416+
assert.equal(
417+
emittedEvents.some((entry) => entry.name === 'engine:performance-frame'),
418+
true,
419+
'Engine should emit engine:performance-frame event for monitoring consumers.'
420+
);
421+
422+
const entries = logger.getEntries();
423+
assert.equal(entries.length >= 1, true, 'Standardized logger should capture runtime monitoring logs.');
424+
assert.equal(
425+
entries.every((entry) => entry.format === 'engine.log.v1' && typeof entry.event === 'string' && entry.event.length > 0),
426+
true,
427+
'Logger entries should use the standardized log format and include event codes.'
428+
);
429+
} finally {
430+
animationFrame.restore();
431+
}
432+
}
433+
353434
export function run() {
354435
assertBootRunShutdownLifecycle();
355436
assertHotReloadAndResetFlows();
356437
assertErrorHandlingPaths();
357438
assertLongRunningStability();
439+
assertRuntimeMonitoringHooksAndLoggingFormat();
358440
}

0 commit comments

Comments
 (0)