Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
100 changes: 43 additions & 57 deletions AGENTS.md
Original file line number Diff line number Diff line change
Expand Up @@ -132,50 +132,41 @@ artifact ships the SBOM without per-image wiring.
### Logging Architecture

The STDIO transport uses stdout for JSON-RPC messages, so any stray stdout output
corrupts the protocol. Logging is configured in **two phases**, and both files are
load-bearing:

| Phase | Who configures | File | Why |
|---|---|---|---|
| 1 | logback's own `ContextInitializer`, on the first `LoggerFactory` touch | `logback.xml` | `NopStatusListener`, no appenders |
| 2 | Spring Boot's `LoggingApplicationListener` | `logback-spring.xml` | `<springProfile>` appenders |

**Phase 1 — why `logback.xml` must exist.** `ContextInitializer` only ever scans the
*standard* locations (`logback-test.xml`, `logback.xml`). It has never heard of
`logback-spring.xml`; that name is a Spring Boot convention. With no standard-location
file it falls back to `BasicConfigurator`. In a **native image** logback cannot read its
own manifest, so it always raises `|-WARN … Versions of logback-classic and ? are
different or unknown`, which trips `StatusPrinter.printInCaseOfErrorsOrWarnings()` and
flushes the whole `|-INFO` status list to **stdout** — landing in the middle of the MCP
JSON-RPC stream. On the JVM the version lookup succeeds, there is no WARN and nothing is
printed, so this is reproducible *only* in the native image:
corrupts the protocol. The setup follows Spring Boot's conventions: **one** logback
configuration, `logback-spring.xml`, resolved by Boot by convention, plus one line of
code in `Main` for the window before Boot exists.

**Why the `-spring` name and nothing else.** Boot's rule: `<springProfile>` "cannot be
used in the standard `logback.xml` file because it is loaded too early." A standard-
location file is worse than useless here: `AbstractLoggingSystem.initializeWithConventions()`
finds it first, reinitializes from it and **returns**, so the `-spring` variant is never
loaded and every `<springProfile>` appender is silently dropped. HTTP mode would run with
no console logs and no OTLP log export, and startup failures would exit 1 showing only
the banner. `LoggingConfigurationTest` fails the build if a `logback.xml` (or
`logback-test.xml`) ever reappears, or if `logging.config` is set in
`application.properties` to paper over one. `LOGGING_CONFIG` in the environment still
works as Boot's normal operator override for an *external* file.

**Why `Main` sets `logback.statusListenerClass`.** Logback initializes itself on the
first `LoggerFactory` touch, before Boot's `LoggingApplicationListener` runs. In a
**native image** it cannot read its own manifest, so `ContextInitializer.checkVersions()`
always raises `|-WARN … Versions of logback-classic and ? are different or unknown`, and
`LogbackServiceProvider` then calls `StatusPrinter.printInCaseOfErrorsOrWarnings()`,
flushing the whole `|-INFO` status list to **stdout** — in the middle of the MCP
JSON-RPC stream. That provider skips the print whenever a status listener is installed,
and `ContextInitializer.autoConfig()` installs one from the `logback.statusListenerClass`
system property *after* the version check but *before* the print. `Main.main()` therefore
sets that property to `NopStatusListener` as its first statement, unless an operator has
already set it (so `-Dlogback.statusListenerClass=ch.qos.logback.core.status.OnConsoleStatusListener`
still works for debugging logback itself). On the JVM the version lookup succeeds and
nothing is printed, so this is reproducible *only* in the native image:
`DockerImageMcpClientStdioIntegrationTest` under `./gradlew dockerIntegrationTest
-Pnative` is the sole test that covers it.

**Phase 2 — why `logging.config` must be set.** `AbstractLoggingSystem.initialize()`
resolves `logging.config` first and returns; only when it is empty does it fall through
to `initializeWithConventions()`, which finds the standard-location `logback.xml`,
reinitializes from it and **returns** — never loading the `-spring` variant. That is not
"one overrides the other", it **disables** the `-spring` file, taking every
`<springProfile>` appender with it. Boot's documented rule: `<springProfile>` "cannot be
used in the standard `logback.xml` file because it is loaded too early."

That trap was live in this repo (both files, no `logging.config`): HTTP mode ran with no
appenders at all — no console logs, no OTLP log export, and startup failures exited 1
showing only the Spring banner. `application.properties` now sets

```properties
logging.config=${LOGGING_CONFIG:classpath:logback-spring.xml}
```

which takes the `initializeWithSpecificConfig` branch and skips the standard locations
altogether. `LoggingConfigurationTest` fails the build if either half of the pairing is
removed, or if an appender is ever added to the phase-1 file.
-Pnative` is the sole test that covers it end to end.

Contents of `logback-spring.xml`:

- A `NopStatusListener` suppressing logback's internal status messages (`|-INFO`,
`|-WARN`), which are written straight to stdout and bypass the appenders.
- A `NopStatusListener` suppressing logback's internal status messages during Boot's
own (re)configuration, which are written straight to stdout and bypass the appenders.
- `<springProfile>` blocks scoping appenders per transport mode:
- **HTTP**: Boot's own `console-appender.xml` (so `logging.pattern.console` /
`logging.charset.console` / `logging.threshold.console` behave as in a stock Boot
Expand All @@ -184,31 +175,26 @@ Contents of `logback-spring.xml`:
- **STDIO**: No appenders defined, so nothing can reach stdout. The OTEL appender is
intentionally excluded too.
- `application-stdio.properties` additionally sets `logging.pattern.console=` (empty
pattern) as a second line of defence.

`SolrNativeHints` registers **both** files as native-image resources — in a native image
`getResource()` only sees registered resources, so an unregistered `logback.xml` is
exactly as absent as a deleted one, and phase 1 falls straight back to
`BasicConfigurator`.
pattern), the idiom Spring AI documents for STDIO servers, as a second line of defence.

Phase 2 works differently under AOT: `LogbackLoggingSystem` checks
`initializeFromAotGeneratedArtifactsIfPossible()` *before* reading `logging.config`, and
replays `META-INF/spring/logback-model` — the model `processAot` serialized from whatever
configuration Boot loaded at AOT time. So `logging.config` has to be set for the AOT run
too, which it is, being in `application.properties`. Verify with:
Under AOT, `LogbackLoggingSystem` replays `META-INF/spring/logback-model` — the model
`processAot` serialized from `logback-spring.xml` — before looking at the classpath.
Verify with:

```bash
strings build/resources/aot/META-INF/spring/logback-model | grep -E 'SpringProfile|OpenTelemetry'
```

`SpringProfileModel` is serialized unresolved, so profiles are still evaluated at runtime;
the `logback-spring.xml` resource hint is belt-and-braces for the non-AOT path.
the `logback-spring.xml` resource hint in `SolrNativeHints` is belt-and-braces for the
non-AOT path.

**Init order**: logback.xml → Spring Boot starts → `logging.config` → logback-spring.xml
→ application-{profile}.properties
**Init order**: `Main` sets `logback.statusListenerClass` → first logger touch (logback
self-init, silent) → Spring Boot starts → logback-spring.xml → application-{profile}.properties

**Debugging tip**: if an HTTP-mode startup fails with no output, logging config is the
first suspect — check that `logging.config` still resolves to `logback-spring.xml`.
**Debugging tip**: if an HTTP-mode startup fails with no output, check that no
`logback.xml` has crept onto the classpath; `LoggingConfigurationTest` should already
have caught it.

### Docker image strategy

Expand Down Expand Up @@ -272,7 +258,7 @@ buildpacks (`bootBuildImage -Pnative`). Key configuration:
generic `Object` dispatch): `CollectionCreationResult`, `SolrHealthStatus`,
`SolrMetrics`, `IndexStats`, `QueryStats`, `CacheStats`, `CacheInfo`,
`HandlerStats`, `HandlerInfo`, `SearchResponse`
- **Resource**: `logback.xml` (see Logging Architecture above)
- **Resource**: `logback-spring.xml` (see Logging Architecture above)
- **Wire format:** `SolrConfig` uses `XMLRequestWriter` instead of the default
`JavaBinRequestWriter`. The JavaBin binary codec uses deep reflection that would
require extensive additional native image hints.
Expand Down
12 changes: 7 additions & 5 deletions dev-docs/graalvm-native-image.md
Original file line number Diff line number Diff line change
Expand Up @@ -162,11 +162,13 @@ container and value types.
are package-private records the MCP framework dispatches via generic
`Object`, so AOT can't see them. They're registered by name with
`registerTypeIfPresent`.
- **`logback.xml` resource.** Registered as a resource pattern so logback's
early (pre-Spring) initialization finds it and installs the `NopStatusListener`.
Without it, logback falls through to `BasicConfigurator` and writes status
lines to stdout, corrupting STDIO framing. (See the Logging Architecture
section of `AGENTS.md`.)
- **`logback-spring.xml` resource.** Registered as a resource pattern as
belt-and-braces for the non-AOT path; under AOT Boot replays the serialized
logback model instead. Logback's own pre-Spring status output, which would
otherwise land on stdout in the native image and corrupt STDIO framing, is
silenced by `Main` via the `logback.statusListenerClass` system property, so
no early `logback.xml` is needed. (See the Logging Architecture section of
`AGENTS.md`.)

### Adding a hint when a native run fails

Expand Down
16 changes: 6 additions & 10 deletions docs/security/keycloak.md
Original file line number Diff line number Diff line change
Expand Up @@ -869,23 +869,19 @@ public String getSchema(String collection) { ... }

### `bootRun` exits with code 1 and prints nothing

This is the most common failure, and the hardest to read, because **HTTP mode
currently produces no application log output**: `logback.xml` is picked up by
logback's own self-initialization, so Spring Boot never applies
`logback-spring.xml`, where the `http` profile's console appender is defined.
Gradle reports only:
This is the most common failure. HTTP mode logs to the console through the
`http` profile's appender in `logback-spring.xml`, so the real exception is
normally in the Gradle output just above the summary:

```
> Task :bootRun FAILED
Execution failed for task ':bootRun'.
> Process 'command '.../bin/java'' finished with non-zero exit value 1
```

Re-run with logging forced on to see the real exception:

```bash
LOGGING_CONFIG=classpath:logback-spring.xml ./gradlew bootRun
```
If there is genuinely no application output, something has disabled logging
(for example a stray `logback.xml` on the classpath, which
`LoggingConfigurationTest` guards against); check that first.

The usual cause is that the realm does not exist yet:

Expand Down
2 changes: 1 addition & 1 deletion docs/security/stdio.md
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,7 @@ that launched the process. No code changes are required for STDIO security.
| Communication is stdin/stdout only | MCP framing per spec | No socket to reach; input arrives over an inherited file descriptor |
| Trust boundary = OS process owner | Launcher runs the binary | Same model as any local CLI; OS user permissions are the auth. Note the boundary is **any process that can reach the server's stdin**, not only the direct parent — a descriptor can be inherited or passed on, so isolate by OS user rather than assuming a single writer |
| Spring Security autoconfig disabled | `application-stdio.properties` excludes `SecurityAutoConfiguration` and `ManagementWebSecurityAutoConfiguration` | Belt-and-suspenders; the filter chain has nothing to do without a servlet container |
| `stdout` is reserved for JSON-RPC | `logback.xml` + empty `logging.pattern.console` (see [Logging Architecture in CLAUDE.md](../../CLAUDE.md#logging-architecture)) | Prevents log lines from being mis-parsed as MCP frames |
| `stdout` is reserved for JSON-RPC | No appenders under the `stdio` profile in `logback-spring.xml`, empty `logging.pattern.console`, and `Main` silencing logback's own status output (see [Logging Architecture in CLAUDE.md](../../CLAUDE.md#logging-architecture)) | Prevents log lines from being mis-parsed as MCP frames |

## Operational guidance for STDIO deployments

Expand Down
33 changes: 33 additions & 0 deletions src/main/java/org/apache/solr/mcp/server/Main.java
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@
*/
package org.apache.solr.mcp.server;

import ch.qos.logback.core.status.NopStatusListener;
import org.apache.solr.mcp.server.collection.CollectionService;
import org.apache.solr.mcp.server.indexing.IndexingService;
import org.apache.solr.mcp.server.schema.SchemaService;
Expand Down Expand Up @@ -110,7 +111,39 @@ public class Main {
public Main() {
}

/**
* Logback's own system property naming the status listener to install during
* its self-initialization.
*/
static final String LOGBACK_STATUS_LISTENER_PROPERTY = "logback.statusListenerClass";

public static void main(String[] args) {
silenceLogbackStatusOutput();
SpringApplication.run(Main.class, args);
}

/**
* Keeps logback's internal status messages off stdout, which the STDIO
* transport reserves for JSON-RPC.
*
* <p>
* Logback initializes itself on the first {@code LoggerFactory} touch, long
* before Spring Boot's logging system runs. In a native image it cannot read
* its version from the manifest, raises a {@code |-WARN}, and
* {@code LogbackServiceProvider} then prints its whole status list to stdout -
* unless a status listener is already installed. It installs one from this
* system property before deciding whether to print, so setting it here, before
* anything can touch a logger, is the earliest and only hook. Spring Boot's
* later configuration ({@code logback-spring.xml}) is unaffected.
*
* <p>
* An explicit {@code -Dlogback.statusListenerClass=...} on the command line
* wins, so logback's own configuration can still be debugged with
* {@code OnConsoleStatusListener}.
*/
static void silenceLogbackStatusOutput() {
if (System.getProperty(LOGBACK_STATUS_LISTENER_PROPERTY) == null) {
System.setProperty(LOGBACK_STATUS_LISTENER_PROPERTY, NopStatusListener.class.getName());
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -125,19 +125,12 @@ public void registerHints(RuntimeHints hints, @Nullable ClassLoader classLoader)
"org.springaicommunity.mcp.context.DefaultMetaProvider",
MemberCategory.INVOKE_DECLARED_CONSTRUCTORS);

// Both logging configurations must be reachable in the native image;
// they serve different initialization phases.
//
// logback.xml is read by logback's own ContextInitializer before
// Spring Boot exists. In a native image getResource() only sees
// registered resources, so without this hint logback finds nothing,
// falls back to BasicConfigurator and dumps its |-INFO status lines
// to stdout — which corrupts the MCP STDIO JSON-RPC framing.
//
// logback-spring.xml is what Spring Boot loads (application.properties
// sets logging.config to it) and carries the <springProfile>
// appenders. See LoggingConfigurationTest.
hints.resources().registerPattern("logback.xml");
// logback-spring.xml is the only logback configuration; Spring Boot
// resolves it by convention. Under AOT the parsed model is replayed
// from META-INF/spring/logback-model, so this hint is belt-and-braces
// for the non-AOT path. Logback's own pre-Spring status output is
// silenced by Main, not by a second configuration file; see
// LoggingConfigurationTest.
hints.resources().registerPattern("logback-spring.xml");
}
}
Expand Down
15 changes: 0 additions & 15 deletions src/main/resources/application.properties
Original file line number Diff line number Diff line change
Expand Up @@ -28,18 +28,3 @@ spring.ai.mcp.server.version=1.0.0
solr.url=${SOLR_URL:http://localhost:8983/solr/}
# Enable virtual threads for improved concurrency
spring.threads.virtual.enabled=true
# Logging configuration.
#
# Point Spring Boot explicitly at logback-spring.xml. Without this, Boot runs
# AbstractLoggingSystem.initializeWithConventions(), which finds the
# standard-location logback.xml first, reinitializes from it and returns --
# logback-spring.xml is never loaded and every <springProfile> appender is
# silently dropped. Setting logging.config takes the initializeWithSpecificConfig
# branch instead, which skips the standard locations entirely.
#
# logback.xml still ships, but only to configure logback's OWN initialization,
# which runs before Spring Boot and only ever looks at the standard locations.
# See logback.xml and LoggingConfigurationTest.
#
# LOGGING_CONFIG in the environment still overrides this.
logging.config=${LOGGING_CONFIG:classpath:logback-spring.xml}
24 changes: 8 additions & 16 deletions src/main/resources/logback-spring.xml
Original file line number Diff line number Diff line change
Expand Up @@ -16,23 +16,15 @@
limitations under the License.
-->
<!--
The application's real logging configuration: everything Spring Boot-managed
lives here, including the per-profile appenders.
The one and only logback configuration. Spring Boot resolves the "-spring"
variant by convention, and that suffix is required: <springProfile> "cannot
be used in the standard logback.xml file because it is loaded too early"
(Spring Boot reference documentation). Do not add a logback.xml next to it:
Boot would initialize from that file and never load this one.

It must keep the "-spring" name - <springProfile> "cannot be used in the
standard logback.xml file because it is loaded too early" (Spring Boot
reference documentation).

It is reached only because application.properties sets
logging.config=classpath:logback-spring.xml. Without that property Spring
Boot runs AbstractLoggingSystem.initializeWithConventions(), which resolves
the standard Logback locations first, finds logback.xml, reinitializes from
it and returns - this file would never be loaded and every <springProfile>
appender below would silently disappear.

logback.xml is a separate, deliberate file covering the phase before Spring
Boot exists; see its comment. LoggingConfigurationTest enforces that the two
stay paired with logging.config.
Logback's own status output during its pre-Spring self-initialization is
silenced by Main (logback.statusListenerClass), which is why no early
configuration file is needed. See LoggingConfigurationTest.
-->
<configuration>
<!--
Expand Down
Loading