This is an automated email from the ASF dual-hosted git repository. jamesbognar pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/juneau.git
commit ae4cc786c77c86a068d566335343c0f5e867e1e5 Author: James Bognar <[email protected]> AuthorDate: Sun Aug 16 18:50:01 2026 -0400 Fix flaky MCP tools/call schema-validation timeout under load: decouple validation compute budget from the structural-traversal wall-clock deadline McpSchemaSafety.validateInput anchored a single 100ms wall-clock deadline, spent it on the two structural JsonValueSafety.check() passes plus the schema-to-bean conversion, and only then computed the schema-validation compute budget as whatever share of that same deadline happened to remain. Under heavy concurrent load (e.g. juneau-integration-tests with forkCount=8) those pre-phases could consume the entire 100ms on the (possibly preempted) request thread, collapsing the remaining share to ~0 and tripping a false-positive -32602 on a trivial validation - exactly the flake seen in Characterization_Test.a01_wireIsUnchanged[31] under CI load. validateBounded now hands the validation task a fresh MAX_VALIDATION_MILLIS budget measured from when the task itself starts running, independent of how much wall-clock the earlier structural pre-checks consumed. The structural checks keep their existing shared deadline unchanged, the DoS guard is unchanged (validation CPU is still capped at 100ms), and the external contract is unchanged (a genuine overrun still returns the same -32602). Adds McpSchemaSafety_Test#d08, a deterministic regression test that reproduces the false-positive via the awaitBounded/TaskStart seam: it derives the exact "stale, already-exhausted deadline" value the old code fed into the compute-budget check and confirms that value alone (independent of machine load) still trips the guard on otherwise-trivial bounded work, while the fresh budget the fix now uses does not. --- .../rest/server/mcp/v20260728/McpSchemaSafety.java | 42 +++++++---- .../server/mcp/v20260728/McpSchemaSafety_Test.java | 88 ++++++++++++++++++++++ 2 files changed, 114 insertions(+), 16 deletions(-) diff --git a/juneau-rest/juneau-rest-server-mcp-v20260728/src/main/java/org/apache/juneau/rest/server/mcp/v20260728/McpSchemaSafety.java b/juneau-rest/juneau-rest-server-mcp-v20260728/src/main/java/org/apache/juneau/rest/server/mcp/v20260728/McpSchemaSafety.java index 3336430f29..8b0c0c95e7 100644 --- a/juneau-rest/juneau-rest-server-mcp-v20260728/src/main/java/org/apache/juneau/rest/server/mcp/v20260728/McpSchemaSafety.java +++ b/juneau-rest/juneau-rest-server-mcp-v20260728/src/main/java/org/apache/juneau/rest/server/mcp/v20260728/McpSchemaSafety.java @@ -48,9 +48,12 @@ import org.apache.juneau.rest.server.mcp.McpSchema; * code path that opens a network connection or a file to dereference one. * * <p> - * Validation itself runs on a fixed-size pool of daemon threads and is bounded by the same overall budget: if - * a pathological schema (for example a catastrophically-backtracking {@code pattern}) fails to complete in - * time, the task is cancelled and a {@code -32602} error is raised instead of hanging the request thread. + * Validation itself runs on a fixed-size pool of daemon threads and is bounded by its own independent compute + * budget ({@link #MAX_VALIDATION_MILLIS}), measured fresh from when the validation task actually starts running + * — <b>not</b> from the structural-traversal deadline above, so wall-clock time spent in the structural + * pre-checks or the schema-bean conversion never shrinks it (see {@link #validateBounded} for why). If a + * pathological schema (for example a catastrophically-backtracking {@code pattern}) fails to complete in time, + * the task is cancelled and a {@code -32602} error is raised instead of hanging the request thread. * * <p> * <b>Cancellation actually reclaims the worker thread.</b> When the budget trips, {@link #awaitBounded} calls @@ -178,19 +181,24 @@ final class McpSchemaSafety { throw new McpException(McpRevision.CODE_INVALID_PARAMS, e.getMessage()); } var jsonSchema = Json.to(Json.of(schemaMap), JsonSchema.class); - validateBounded(jsonSchema, args, deadline); + validateBounded(jsonSchema, args); } /** - * Runs {@link JsonSchemaValidator} on a daemon thread and enforces the remaining share of the shared - * {@link JsonValueSafety} deadline against the task's own compute time - never against however long it had - * to wait in {@link #VALIDATION_POOL} for a free thread, and (when CPU timing is available) never against - * wall-clock time it spent preempted rather than running. + * Runs {@link JsonSchemaValidator} on a daemon thread and enforces a fresh {@link #MAX_VALIDATION_MILLIS} + * compute budget against the task's own compute time - deliberately <b>not</b> the caller's remaining share + * of the structural-traversal deadline computed in {@link #validateInput}. That deadline is a wall-clock + * budget that is already partially spent by the two {@link JsonValueSafety#check} calls and the + * schema-to-bean conversion above, both of which run on the (possibly preempted) request thread under load; + * deriving the validation budget from whatever wall-clock happened to remain would let purely-external + * scheduling pressure - not any property of the schema or arguments being validated - trip a false-positive + * {@code -32602} on a trivial validation. Anchoring a fresh budget here, measured from when the pool task + * actually starts (see {@link TaskStart#capture}), keeps the DoS guard (validation CPU still capped at + * {@link #MAX_VALIDATION_MILLIS}) independent of that pre-check wall-clock entirely. Also never against + * however long the task had to wait in {@link #VALIDATION_POOL} for a free thread, and (when CPU timing is + * available) never against wall-clock time it spent preempted rather than running. */ - private static void validateBounded(JsonSchema<?> schema, Object value, long deadlineNanos) { - var remaining = JsonValueSafety.remainingNanos(deadlineNanos); - if (remaining == 0) - throw validationTimeoutException(); + private static void validateBounded(JsonSchema<?> schema, Object value) { var started = new CountDownLatch(1); var taskStart = new AtomicReference<TaskStart>(); var future = VALIDATION_POOL.submit(() -> { @@ -199,7 +207,7 @@ final class McpSchemaSafety { JsonSchemaValidator.of(schema).validate(value); return null; }); - awaitBounded(future, started, taskStart, remaining); + awaitBounded(future, started, taskStart, MILLISECONDS.toNanos(MAX_VALIDATION_MILLIS)); } /** @@ -222,8 +230,9 @@ final class McpSchemaSafety { /** * Waits for a submitted validation task to complete, charging only its own compute time against - * {@code remaining} (the caller's share of the shared {@link JsonValueSafety} deadline) - never however long - * it had to wait in {@link #VALIDATION_POOL} for a free thread. + * {@code remaining} (the caller's compute budget, a fresh interval unrelated to any other deadline the + * caller may separately be tracking) - never however long it had to wait in {@link #VALIDATION_POOL} for a + * free thread. * * <p> * This waits in two phases. First, {@code started} is awaited so the calling thread learns exactly when the @@ -243,7 +252,8 @@ final class McpSchemaSafety { * @param future The in-flight (or already-complete) validation task. * @param started Counted down by the task as its first instruction, once it actually begins running. * @param taskStart Set by the task (before counting down {@code started}) to its {@link TaskStart} snapshot. - * @param remaining The caller's remaining share of the shared deadline, in nanoseconds, captured before submission. + * @param remaining The caller's compute budget, in nanoseconds, captured fresh before submission (see + * {@link #validateBounded} for why this must be independent of any pre-existing wall-clock deadline). */ static void awaitBounded(Future<?> future, CountDownLatch started, AtomicReference<TaskStart> taskStart, long remaining) { try { diff --git a/juneau-rest/juneau-rest-server-mcp-v20260728/src/test/java/org/apache/juneau/rest/server/mcp/v20260728/McpSchemaSafety_Test.java b/juneau-rest/juneau-rest-server-mcp-v20260728/src/test/java/org/apache/juneau/rest/server/mcp/v20260728/McpSchemaSafety_Test.java index 40371222f8..eedef30b93 100644 --- a/juneau-rest/juneau-rest-server-mcp-v20260728/src/test/java/org/apache/juneau/rest/server/mcp/v20260728/McpSchemaSafety_Test.java +++ b/juneau-rest/juneau-rest-server-mcp-v20260728/src/test/java/org/apache/juneau/rest/server/mcp/v20260728/McpSchemaSafety_Test.java @@ -29,6 +29,7 @@ import org.apache.juneau.bean.jsonrpc.*; import org.apache.juneau.bean.jsonschema.*; import org.apache.juneau.bean.mcp.v20260728.*; import org.apache.juneau.commons.inject.*; +import org.apache.juneau.commons.utils.*; import org.apache.juneau.marshall.collections.*; import org.apache.juneau.marshall.marshaller.*; import org.apache.juneau.rest.server.mcp.McpExchange; @@ -356,6 +357,93 @@ class McpSchemaSafety_Test { assertTrue(burnedMs < 200, () -> "validation-pool worker kept burning CPU after budget trip: " + burnedMs + "ms"); } + @SuppressWarnings({ + "java:S2925" // Thread.sleep deterministically exhausts the simulated pre-check deadline; burnCpuFor's timer-bounded loop models a bounded compute cost. Neither is a wait-and-hope delay. + }) + @Test + void d08_staleSharedDeadlineBudget_falselyTripsTrivialValidation_freshBudgetDoesNot() { + // Regression test for the flaky Characterization_Test false-positive (McpSchemaSafety.validateInput -> + // validateBounded): the OLD code derived the validation task's compute budget from + // JsonValueSafety.remainingNanos(sharedDeadline) - the caller's remaining share of the SAME wall-clock + // deadline already partially spent by the two structural JsonValueSafety.check() calls and the + // schema-to-bean conversion. Under heavy concurrent load those pre-phases can consume the entire 100ms + // deadline, collapsing "remaining" to ~0 - at which point even bounded, genuinely-trivial validation + // work trips -32602 purely from external scheduling pressure, not from anything about the schema or + // arguments being validated. The fix (validateBounded) instead hands the task a FRESH + // MAX_VALIDATION_MILLIS budget, measured from when the task itself starts running, so the identical + // pre-delay has zero effect. + // + // Reproduces this deterministically (no dependence on machine load) via the same JsonValueSafety + // deadline/remaining arithmetic the OLD code used, feeding the result into the still-live + // awaitBounded/TaskStart seam: the SAME bounded ~30ms "validation" work is run twice - once under the + // literal OLD-style stale/collapsed budget (a real deadline slept past, then remainingNanos()'d down to + // 0) and once under the CURRENT fresh budget - proving the outcome now depends only on the fresh + // budget, not on how much wall-clock some unrelated earlier phase had already spent. + var boundedWorkMillis = 30; + assertTrue(boundedWorkMillis < McpSchemaSafety.MAX_SCHEDULING_MILLIS, "test fixture assumption"); + + // Simulates the pre-check phase (structural checks + schema conversion) fully consuming the shared + // deadline under load - the exact wall-clock arithmetic the OLD validateBounded fed into awaitBounded. + var simulatedPreCheckDeadline = JsonValueSafety.deadlineNanos(); + sleepPastDeadline(simulatedPreCheckDeadline); + var staleRemaining = JsonValueSafety.remainingNanos(simulatedPreCheckDeadline); + assertEquals(0, staleRemaining, "test fixture assumption: simulated pre-check delay must fully exhaust the shared deadline"); + + // (a) OLD behavior: a budget derived from an already-exhausted shared deadline (remaining == 0) trips + // the guard even though the validation work itself is well within the real MAX_VALIDATION_MILLIS budget. + var e = assertThrows(McpException.class, () -> runBoundedTask(boundedWorkMillis, staleRemaining)); + assertEquals(-32602, e.getCode()); + assertContains("exceeded " + McpSchemaSafety.MAX_VALIDATION_MILLIS + " ms", e.getMessage()); + + // (b) FIX: the identical bounded work succeeds under a fresh MAX_VALIDATION_MILLIS budget - exactly as + // validateBounded now computes it - unaffected by how much wall-clock a caller's OTHER deadline had + // already spent. + assertDoesNotThrow(() -> runBoundedTask(boundedWorkMillis, + TimeUnit.MILLISECONDS.toNanos(McpSchemaSafety.MAX_VALIDATION_MILLIS))); + } + + /** Sleeps until {@code deadlineNanos} ({@link System#nanoTime()} units) has passed. */ + private static void sleepPastDeadline(long deadlineNanos) { + while (System.nanoTime() < deadlineNanos) { + var remainingMs = (deadlineNanos - System.nanoTime()) / 1_000_000 + 1; + try { + Thread.sleep(Math.max(1, remainingMs)); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + throw new AssertionError(e); + } + } + } + + /** Submits a task that burns CPU for {@code workMillis} and awaits it under {@code budgetNanos} via the real {@code awaitBounded} seam. */ + private static void runBoundedTask(long workMillis, long budgetNanos) throws InterruptedException { + var started = new CountDownLatch(1); + var taskStart = new AtomicReference<McpSchemaSafety.TaskStart>(); + var executor = Executors.newSingleThreadExecutor(); + try { + var future = executor.submit(() -> { + taskStart.set(McpSchemaSafety.TaskStart.capture()); + started.countDown(); + burnCpuFor(workMillis); + return null; + }); + McpSchemaSafety.awaitBounded(future, started, taskStart, budgetNanos); + } finally { + executor.shutdownNow(); + } + } + + /** Busy-spins for (approximately) {@code millis}, so the calling thread actually consumes CPU rather than sleeping. */ + private static void burnCpuFor(long millis) { + var deadline = System.nanoTime() + TimeUnit.MILLISECONDS.toNanos(millis); + var sink = 0L; + while (System.nanoTime() < deadline) + for (var i = 1; i < 100_000; i++) + sink += (long) Math.sqrt(i) * i; + if (sink == Long.MIN_VALUE) // never true; prevents the JIT from eliding the loop + throw new AssertionError(); + } + private static long poolCpuNanos(ThreadMXBean threadMx) { var total = 0L; for (var id : threadMx.getAllThreadIds()) {
