Skip to content

Commit 88860e3

Browse files
fix(mentor): wave 27 — loop-3 audit fixes
Third audit loop. Three P0s the prior loops missed: P0-1 — Drift-detection test was itself tautological. It constructed MentorAgentProperties manually with the literal "pi-mentor-runner.mjs" and asserted that string equalled the constant. The @DefaultValue was never bound; renaming it would not have failed the test. Replaced with a real round-trip through Spring's Binder against an empty property source — that actually exercises @DefaultValue resolution. P0-2 — runner_post_turn_gc / runner_prewarm_ok / runner_prewarm_failed events were write-only telemetry. The runner emitted them on every turn + every cold start; Java's translator allow-listed them and dropped them; no consumer read them. They were added to counter wave-24's "no observability" criticism but never wired through. Pure stdout noise. Cut entirely. If we want production observability for GC/prewarm, that's a separate, deliberate commit (wired to MeterRegistry, with a real consumer). Side effect: handleHello re-entrance pollution disappears (no more bogus runner_prewarm_ok durationMs=0 on reattach). P0-3 — handleHello idempotency: solved by P0-2 (no events emitted → nothing to pollute). P1 — global.gc() fired on EVERY agent_end, including 1-token turns. STW major GC costs 50-200 ms on a 100 MB heap (Node 22, nodejs/node#43378+); for a "Reply: ready." turn that allocated 100 KB the cost is all pause, no benefit. Gated on process.memoryUsage().heapUsed >= 64 MB so the call only fires when there's genuinely something to compact. P1 — Marginal-RSS gate: switched from Math.abs() to Math.max(0, signed). Wave 25 introduced abs() with the rationale "bloat AND release both trigger investigation"; loop 3 caught the flaw: a runner whose RSS happens to drop between floor and K-opens samples (V8 GC timing, allocator decay) is not a regression. Only growth is. The signed-delta clamped at 0 asserts the direction we care about and avoids false-positive flakes on a normal V8 scavenge. P1 — Allocator self-check at runner startup. PiRuntimeFactory passes LD_PRELOAD=/usr/local/lib/libjemalloc.so.2 and the Dockerfile creates the per-arch symlink at build time. If either drifts (symlink missing on a future image, env clobbered by deploy config) ld.so silently falls back to glibc and the wave-25 jemalloc tuning silently disappears. Now reads /proc/self/maps at startup and logs a single WARN line on glibc fallback. Currently fires correctly on the host stress harness (no Docker → no LD_PRELOAD); silent in production unless drift happens. Translator allowlist + test entries for the dropped event types removed in lockstep. Validated: PiRuntimeFactoryTest 29 + PiEventToUiChunkTranslatorTest 33 + all mentor unit tests green. Live stress N=3 (cold-start 64 ms, peak RSS 165-170 MB) + N=3×K=5 (peak RSS 169-172 MB) — 0 failures, all budgets satisfied. Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
1 parent 3ab7f54 commit 88860e3

5 files changed

Lines changed: 70 additions & 106 deletions

File tree

‎server/application-server/src/main/java/de/tum/in/www1/hephaestus/agent/mentor/chat/wire/PiEventToUiChunkTranslator.java‎

Lines changed: 1 addition & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -60,15 +60,7 @@ public List<UIMessageChunk> translate(JsonNode piEvent, TranslatorState state) {
6060
"session_info_changed",
6161
"thinking_level_changed",
6262
"auto_retry_start",
63-
"auto_retry_end",
64-
// Hephaestus-runner-emitted observability events — see pi-mentor-runner.mjs.
65-
// These are runner-scoped (threadId may be null); we drop them at the chunk
66-
// layer and rely on a dedicated metrics path (TODO: wire to InteractiveSandboxMetrics)
67-
// to count + time them. Without this allowlist entry every mentor turn / cold start
68-
// would WARN about protocol drift, defeating the drift-detection signal.
69-
"runner_post_turn_gc",
70-
"runner_prewarm_ok",
71-
"runner_prewarm_failed" -> List.of();
63+
"auto_retry_end" -> List.of();
7264
default -> {
7365
log.warn("Unknown Pi event type '{}' — dropping. Protocol drift?", type);
7466
yield List.of();

‎server/application-server/src/main/resources/agent/pi-mentor-runner.mjs‎

Lines changed: 37 additions & 67 deletions
Original file line numberDiff line numberDiff line change
@@ -405,41 +405,11 @@ async function handleHello(id /*, params */) {
405405
//
406406
// Fired AFTER the hello reply because Pi SDK module evaluation runs synchronously between
407407
// dynamic-import yield points; firing before the reply would delay hello by the load time.
408-
// The exact load duration is workload-dependent (transitive imports through
409-
// core/resource-loader pull in highlight.js / Ink); the runner_post_warm event below
410-
// makes it observable.
408+
// Failure is logged to stderr (the runner has no structured-event observability surface
409+
// wired yet) and ensureRuntime's own cooldown handles retry on subsequent demand.
411410
if (!PROTOCOL_ONLY) {
412-
const start = process.hrtime.bigint();
413411
setImmediate(() => {
414-
ensureRuntime().then(
415-
() => {
416-
const durationMs = Number(process.hrtime.bigint() - start) / 1e6;
417-
// Notification event (threadId:null since prewarm is runner-scoped).
418-
// Java MentorEventTranslator ignores unknown types — no wire schema bump.
419-
writeFrame({
420-
jsonrpc: "2.0",
421-
method: "event",
422-
params: {
423-
threadId: null,
424-
event: { type: "runner_prewarm_ok", durationMs },
425-
},
426-
});
427-
},
428-
(e) => {
429-
log("prewarm ensureRuntime failed (will retry on demand):", e);
430-
writeFrame({
431-
jsonrpc: "2.0",
432-
method: "event",
433-
params: {
434-
threadId: null,
435-
event: {
436-
type: "runner_prewarm_failed",
437-
error: String(e?.message ?? e),
438-
},
439-
},
440-
});
441-
}
442-
);
412+
ensureRuntime().catch((e) => log("prewarm ensureRuntime failed (will retry on demand):", e));
443413
});
444414
}
445415
}
@@ -512,58 +482,37 @@ function forwardEvent(state, event) {
512482
// The watchdog synthesises its own agent_end at the end of a forced rebind (see
513483
// runWatchdogRebind). That path emits its own agent_end via sendEvent directly — it
514484
// does NOT route through forwardEvent — so this branch only fires for genuine
515-
// SDK-emitted turn completions. If that invariant ever changes, a `state.gcDoneThisTurn`
516-
// flag would gate against double-firing.
485+
// SDK-emitted turn completions.
517486
clearTurnWatchdog(state);
518487
state.inFlight = false;
519488
maybePostTurnGc();
520489
}
521490
}
522491

523492
/**
524-
* Best-effort post-turn V8 compaction. Returns dirty pages from the just-finished turn back to
525-
* the OS before the user goes idle. Triggered only when {@code --expose-gc} was passed (mentor
526-
* runner; not practice). The actual RSS reduction depends on V8 build + heap state and is not
527-
* contractually guaranteed — we surface duration + RSS-before/after as a structured event so a
528-
* production gauge (or grep) can validate that the call did anything useful.
493+
* Best-effort post-turn V8 compaction. Triggered only when {@code --expose-gc} was passed
494+
* (mentor; not practice). Effect-only: we do NOT emit observability events for this — write-only
495+
* telemetry that no Java consumer reads is just stdout noise. If we ever want a production
496+
* metric for GC behavior, wire it deliberately through a dedicated metrics path.
529497
*
530-
* <p>Yielded via setImmediate so the agent_end frame drains to the kernel pipe buffer first
531-
* (Java still observes the frame ordering it would have without this).
498+
* <p>Gated on heap-watermark: a full STW major GC costs ~50–200 ms on a 100 MB heap; for a
499+
* just-finished 1-token turn the cost is all pause, no benefit. Only fire if V8's own heap
500+
* has grown past the 64 MB mark — below that, V8's own scavenger handles things without our
501+
* help.
532502
*
533-
* <p>The emitted event uses {@code threadId: null} — V8 GC is a process-global concern; tagging
534-
* with a specific threadId would mislead the Java-side fan-out into routing it to a single
535-
* subscriber, which is the wrong scope (every thread shares the same heap).
503+
* <p>Yielded via setImmediate so the agent_end frame drains to the kernel pipe buffer first.
536504
*/
505+
const POST_TURN_GC_HEAP_THRESHOLD_BYTES = 64 * 1024 * 1024;
506+
537507
function maybePostTurnGc() {
538508
if (typeof global.gc !== "function") return;
509+
if (process.memoryUsage().heapUsed < POST_TURN_GC_HEAP_THRESHOLD_BYTES) return;
539510
setImmediate(() => {
540-
const before = process.memoryUsage().rss;
541-
const start = process.hrtime.bigint();
542-
let ok = true;
543511
try {
544512
global.gc();
545513
} catch (e) {
546-
ok = false;
547514
log("post-turn gc threw:", e);
548515
}
549-
const durationMs = Number(process.hrtime.bigint() - start) / 1e6;
550-
const after = process.memoryUsage().rss;
551-
// Notification (threadId:null) — runner-scoped, like runner_prewarm_*. Allow-listed in
552-
// PiEventToUiChunkTranslator so it does not WARN as protocol drift.
553-
writeFrame({
554-
jsonrpc: "2.0",
555-
method: "event",
556-
params: {
557-
threadId: null,
558-
event: {
559-
type: "runner_post_turn_gc",
560-
ok,
561-
durationMs,
562-
rssBeforeBytes: before,
563-
rssAfterBytes: after,
564-
},
565-
},
566-
});
567516
});
568517
}
569518

@@ -1061,6 +1010,27 @@ function start() {
10611010
});
10621011
}
10631012

1013+
// Allocator self-check. PiRuntimeFactory passes LD_PRELOAD=…/libjemalloc.so.2 in the
1014+
// mentor runner's spawn env, and the Dockerfile creates the per-arch symlink at build time.
1015+
// If either of those drifts (symlink missing on a future image, env var clobbered by a
1016+
// future deploy config), ld.so silently falls back to glibc malloc and the wave-22+ tuning
1017+
// (MALLOC_CONF dirty_decay, narenas) disappears. Without this check the regression would
1018+
// only manifest as a slow RSS bloat in production with no clear cause. One stderr line at
1019+
// startup is enough — ops can grep for it.
1020+
if (!PROTOCOL_ONLY) {
1021+
try {
1022+
const maps = readFileSync("/proc/self/maps", "utf8");
1023+
if (!/libjemalloc/.test(maps)) {
1024+
log(
1025+
"WARN allocator self-check: libjemalloc NOT loaded into this process — " +
1026+
"falling back to glibc malloc. Memory tuning from PiRuntimeFactory#nodeEnvFor " +
1027+
"is disabled. Check Dockerfile symlink + LD_PRELOAD env."
1028+
);
1029+
}
1030+
} catch {
1031+
// /proc/self/maps unavailable (non-Linux, very locked-down containers). Silent.
1032+
}
1033+
}
10641034
announceReady();
10651035
// SDK prewarm is intentionally NOT triggered here — it now fires inside handleHello
10661036
// after the reply is written. Pi SDK module evaluation is synchronous (~300-400 ms) and

‎server/application-server/src/test/java/de/tum/in/www1/hephaestus/agent/mentor/chat/wire/PiEventToUiChunkTranslatorTest.java‎

Lines changed: 0 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -426,13 +426,6 @@ void piSessionLevelEvents_explicitlyDropped() throws Exception {
426426
"auto_retry_start",
427427
"auto_retry_end",
428428
"runner_ready",
429-
// Hephaestus-runner observability events emitted from pi-mentor-runner.mjs. They are
430-
// runner-scoped (post-turn GC + cold-start prewarm). Without these in the allowlist
431-
// every mentor turn / cold start would WARN "Protocol drift?" and the drift signal
432-
// would drown in noise.
433-
"runner_post_turn_gc",
434-
"runner_prewarm_ok",
435-
"runner_prewarm_failed",
436429
};
437430
for (String type : sessionEvents) {
438431
JsonNode event = mapper.readTree("{\"type\":\"" + type + "\"}");

‎server/application-server/src/test/java/de/tum/in/www1/hephaestus/agent/mentor/live/MentorSandboxStressTest.java‎

Lines changed: 11 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -163,23 +163,22 @@ void multiSessionPerRunner() throws Exception {
163163
);
164164
}
165165
if (k > 1) {
166-
// ABSOLUTE delta — a negative delta (V8 freed memory between samples) is real
167-
// signal, not noise to clamp. If after-K-opens drops 500 KB below the floor on
168-
// one runner and rises 5 MB on another, the previous .max() over signed deltas
169-
// would happily report the 5 MB / (k-1) figure while silently ignoring the
170-
// -500 KB / (k-1) (negative) — bug shape: drops-the-real-bound. Use the absolute
171-
// worst-case magnitude per runner so bloat AND release both trigger investigation.
172-
long maxMarginalKb = runners
166+
// Clamp negative deltas at 0 — a runner whose RSS DROPPED between the floor and
167+
// the K-opens sample (V8 freed memory, jemalloc decay timing) is not a
168+
// regression. Only growth is. The previous Math.abs() variant treated benign GC
169+
// timing as a "regression" with no actionable signal; this asserts only the
170+
// direction we care about.
171+
long maxMarginalGrowthKb = runners
173172
.stream()
174173
.filter(r -> r.rssAfterOpenKb > 0 && r.rssOneSessionFloorKb > 0)
175-
.mapToLong(r -> Math.abs(r.rssAfterOpenKb - r.rssOneSessionFloorKb) / (k - 1))
174+
.mapToLong(r -> Math.max(0L, (r.rssAfterOpenKb - r.rssOneSessionFloorKb) / (k - 1)))
176175
.max()
177176
.orElse(0L);
178-
if (maxMarginalKb > marginalBudgetKb) {
177+
if (maxMarginalGrowthKb > marginalBudgetKb) {
179178
throw new AssertionError(
180-
"marginal RSS / extra session regression: |delta|/extra-session=" +
181-
maxMarginalKb + " KB > budget=" + marginalBudgetKb +
182-
" KB — per-thread state bloated OR floor sample bad. " +
179+
"marginal RSS growth per extra session: " + maxMarginalGrowthKb +
180+
" KB > budget=" + marginalBudgetKb +
181+
" KB — per-thread state bloated. " +
183182
"Override budget via MARGINAL_RSS_BUDGET_KB env."
184183
);
185184
}

‎server/application-server/src/test/java/de/tum/in/www1/hephaestus/agent/runtime/PiRuntimeFactoryTest.java‎

Lines changed: 21 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -414,18 +414,28 @@ void nodeFlagsForPractice() {
414414
void mentorRunnerScriptConstantAgreesWithProperties() {
415415
// PiRuntimeFactory dispatches V8 flags by filename match against MENTOR_RUNNER_SCRIPT.
416416
// If MentorAgentProperties' default runnerScript ever drifts (rename, version bump,
417-
// operator change) the mentor would silently revert to the practice V8 profile —
418-
// no heap cap, no --expose-gc, no jemalloc preload. This test pins the alignment.
419-
de.tum.in.www1.hephaestus.agent.mentor.MentorAgentProperties props =
420-
new de.tum.in.www1.hephaestus.agent.mentor.MentorAgentProperties(
421-
"ghcr.io/ls1intum/hephaestus/agent-pi-mentor:latest",
422-
"pi-mentor-runner.mjs",
423-
100_000
417+
// operator override) the mentor silently reverts to the practice V8 profile —
418+
// no heap cap, no --expose-gc, no jemalloc preload.
419+
//
420+
// The previous version of this test constructed MentorAgentProperties manually with
421+
// the literal "pi-mentor-runner.mjs" and asserted that literal equalled the constant.
422+
// It would have passed even if @DefaultValue on MentorAgentProperties was renamed to
423+
// "pi-mentor-runner-v2.mjs" — the very drift it claimed to defend against. Fixed by
424+
// round-tripping through Spring's Binder against an empty source, which actually
425+
// exercises the @DefaultValue resolution.
426+
org.springframework.boot.context.properties.bind.Binder binder =
427+
new org.springframework.boot.context.properties.bind.Binder(
428+
org.springframework.boot.context.properties.source.ConfigurationPropertySources.from(
429+
new org.springframework.core.env.MapPropertySource("empty", Map.of())
430+
)
424431
);
425-
// Round-trip through @DefaultValue binding would set "pi-mentor-runner.mjs"; we
426-
// mirror that here. The assertion below catches a hand-edited default drift.
427-
assertThat(props.runnerScript())
428-
.as("MENTOR_RUNNER_SCRIPT constant must equal MentorAgentProperties default")
432+
de.tum.in.www1.hephaestus.agent.mentor.MentorAgentProperties bound = binder
433+
.bindOrCreate(
434+
"hephaestus.mentor.agent",
435+
de.tum.in.www1.hephaestus.agent.mentor.MentorAgentProperties.class
436+
);
437+
assertThat(bound.runnerScript())
438+
.as("MENTOR_RUNNER_SCRIPT must equal MentorAgentProperties.@DefaultValue('runnerScript')")
429439
.isEqualTo(PiRuntimeFactory.MENTOR_RUNNER_SCRIPT);
430440
}
431441

0 commit comments

Comments
 (0)