From 4de026e2b66990e5c225563d8cb66eb1652585db Mon Sep 17 00:00:00 2001 From: Rusty Conover Date: Wed, 29 Jul 2026 09:13:44 -0400 Subject: [PATCH 1/6] conformance: supply the sticky failure-path fixtures MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The upstream TestSticky group gained three tests covering the ways a sticky session must be refused — expiry, a token presented to the wrong worker, and a token replayed under a different principal. Each is gated on a runner-supplied fixture, so until now all three skipped here and Java's session-loss paths went unexercised despite being implemented. --token-key and --sticky-ttl already existed, and RpcServer mints a random server_id per process, so the peer pair differs without any new flag. The only worker addition is --sticky-auth: an Authenticator that resolves the principal named in X-Conformance-Principal and stays anonymous when the header is absent (the suite probes /health and the capability endpoint before it authenticates anything). Declaring that lambda inline means this module names HttpServletRequest at compile time, which vgirpc keeps on `implementation` — hence the compileOnly servlet-api entry rather than a new runtime dependency. Verified the tests can actually fail: dropping --sticky-auth from the fixture makes test_cross_principal_replay_rejected fail with bob resuming alice's session, which is the whole point of the group. TestSticky: 19 passed, 0 skipped. Full suite: 1066 passed, 7 skipped. Co-Authored-By: Claude Opus 5 (1M context) --- conformance-worker/build.gradle.kts | 5 ++ .../query/vgirpc/conformance/worker/Main.java | 24 +++++++++ tests/test_java_conformance.py | 52 +++++++++++++++++++ 3 files changed, 81 insertions(+) diff --git a/conformance-worker/build.gradle.kts b/conformance-worker/build.gradle.kts index 687f592..ae8b261 100644 --- a/conformance-worker/build.gradle.kts +++ b/conformance-worker/build.gradle.kts @@ -7,6 +7,11 @@ dependencies { implementation(project(":conformance")) // Optional — only needed by --auth-jwt / --auth-pkce modes implementation(project(":vgirpc-oauth")) + // --sticky-auth declares an Authenticator lambda inline, so this module has to + // name HttpServletRequest at compile time. vgirpc keeps Jetty on `implementation` + // (not exposed to consumers), but it is on the runtime classpath transitively — + // hence compileOnly rather than implementation. + compileOnly("jakarta.servlet:jakarta.servlet-api:6.0.0") // SLF4J backend for this runnable worker (vgirpc no longer ships one). runtimeOnly("org.slf4j:slf4j-simple:2.0.16") } diff --git a/conformance-worker/src/main/java/farm/query/vgirpc/conformance/worker/Main.java b/conformance-worker/src/main/java/farm/query/vgirpc/conformance/worker/Main.java index 0c1d147..d5d70a7 100644 --- a/conformance-worker/src/main/java/farm/query/vgirpc/conformance/worker/Main.java +++ b/conformance-worker/src/main/java/farm/query/vgirpc/conformance/worker/Main.java @@ -150,6 +150,7 @@ public static void main(String[] args) throws Exception { case "--no-compression" -> responseCompression = false; case "--no-sticky" -> stickyEnabled = false; case "--sticky-ttl" -> stickyTtl = Long.parseLong(c.requireValue(a)); + case "--sticky-auth" -> authenticator = principalHeaderAuthenticator(); default -> { System.err.println("unknown arg: " + a); System.exit(2); } } } @@ -282,6 +283,29 @@ private static Authenticator buildJwt(String spec) { return b.build(); } + /** + * Resolve the principal named in {@code X-Conformance-Principal}, or stay anonymous. + * + *

Backs {@code TestSticky::test_cross_principal_replay_rejected}, which needs one + * worker reachable as two distinct identities so it can open a session as one and + * replay the token as the other. Naming yourself in a header is obviously not + * authentication — it is the cheapest thing every port can implement identically, + * and the test only needs the two identities to be distinguishable. + * + *

Requests without the header stay anonymous rather than being rejected: the + * conformance suite probes {@code GET /health} and the capability endpoint before + * it authenticates anything. + */ + private static Authenticator principalHeaderAuthenticator() { + return request -> { + String principal = request.getHeader("X-Conformance-Principal"); + if (principal == null || principal.isEmpty()) { + return AuthContext.ANONYMOUS; + } + return new AuthContext("conformance", true, principal, Collections.emptyMap()); + }; + } + private static Authenticator buildBearer(String spec) { Map tokens = new LinkedHashMap<>(); for (Map.Entry e : splitKv(spec, "--auth-bearer").entrySet()) { diff --git a/tests/test_java_conformance.py b/tests/test_java_conformance.py index 30a90b8..575240c 100644 --- a/tests/test_java_conformance.py +++ b/tests/test_java_conformance.py @@ -253,6 +253,58 @@ def _start_http_worker(*extra_args: str) -> Iterator[int]: proc.wait(timeout=5) +# --------------------------------------------------------------------------- +# Sticky failure-path fixtures (upstream TestSticky; see +# vgi-rpc docs/sticky-sessions-spec.md §9.1) +# --------------------------------------------------------------------------- + +# Shared AEAD key for the peer pair. Both workers can open each other's +# session tokens, which is the point: the rejection under test has to come +# from the server_id comparison, not from a decrypt failure. +_STICKY_PEER_TOKEN_KEY = "5f" * 32 + + +@pytest.fixture(scope="session") +def conformance_http_sticky_short_ttl_port() -> Iterator[int]: + """A sticky worker whose default session TTL is short enough to outwait. + + Backs ``TestSticky::test_expired_session_surfaces_session_lost``; the + main worker's 300s default is not something a test can sit out. + """ + yield from _start_http_worker("--http", "--sticky-ttl", "1") + + +@pytest.fixture(scope="session") +def conformance_http_sticky_peer_ports() -> Iterator[tuple[int, int]]: + """Two sticky workers sharing one AEAD key, for the wrong-worker check. + + Backs ``TestSticky::test_token_from_other_worker_rejected``. RpcServer + mints a random server_id per process, so the two peers differ without + any extra flag — which is what makes the shared key safe to use here. + """ + gen_a = _start_http_worker("--http", "--token-key", _STICKY_PEER_TOKEN_KEY) + gen_b = _start_http_worker("--http", "--token-key", _STICKY_PEER_TOKEN_KEY) + port_a = next(gen_a) + try: + port_b = next(gen_b) + try: + yield port_a, port_b + finally: + next(gen_b, None) + finally: + next(gen_a, None) + + +@pytest.fixture(scope="session") +def conformance_http_sticky_auth_port() -> Iterator[int]: + """A sticky worker that authenticates the ``X-Conformance-Principal`` header. + + Backs ``TestSticky::test_cross_principal_replay_rejected``, which needs + one worker reachable as two identities. + """ + yield from _start_http_worker("--http", "--sticky-auth") + + @pytest.fixture(scope="session") def proof_worker_factory() -> Iterator[Callable[..., Any]]: """Spawn Java workers gated on proxy proof, for the shared TestProxyProof group. From c9c82045e3a7cf6c29d0573e7d47882f3f034806 Mon Sep 17 00:00:00 2001 From: Rusty Conover Date: Tue, 4 Aug 2026 15:54:21 -0400 Subject: [PATCH 2/6] =?UTF-8?q?feat:=20track=20vgi-rpc=200.36=20=E2=80=94?= =?UTF-8?q?=20token=20split,=20401=20reasons,=20CORS,=20introspection,=20a?= =?UTF-8?q?ccess=20log?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Brings the Java port up to the reference's 0.36 protocol surface. Each piece below is pinned by the shared cross-language conformance suite unless noted. **Call/cursor token split.** A stream's state now travels as two tokens: a CallToken minted once by /init carrying the resolved schemas and stream id, and a StateToken cursor re-minted per turn. Cursor v5 -> v6; call token v1. The cursor is opened first so its call id is authenticated before it keys the CallStateCache, then the call resolves from cache or from the client's echoed token. **Token payload compression**, inside the seal, under a codec tag. **Standardized 401s.** The reason is read off the AuthException subtype rather than guessed from message text, so the existing bearer and mTLS authenticators classify correctly without being touched. VGI-Auth-Reason, Cache-Control, the JSON envelope, and a proxy note derived from configuration. **CORS, implemented from scratch** — this port emitted no Access-Control-* headers at all. Origin allowlist, preflight, the expose list built from the same conditions as the capability headers, and Cross-Origin-Resource-Policy. **Token introspection.** Off unless enabled. The endpoint previously 500'd: with an empty prefix the servlet is mapped /*, so every POST path was dispatched as a method name and a JSON body reached the Arrow reader. Paths that name no method now answer 404, which also fixes any wrong-prefix or nested POST path. **Access log**: trace correlation, deterministic per-call sampling, egress accounting (deferred via a per-request scope so response_bytes is the compressed size), key-based claim redaction that fails closed — claims were not emitted at all before — and `truncated: "payload_omitted"`. The scope also supplies http_status, request_id and remote_addr, none of which this port emitted. **X-Request-ID** is now echoed or minted, and exposed. Fixes a latent defect the new access-log gate surfaced: request batches were serialized with no DictionaryProvider, so every enum-taking method silently dropped `request_data` — a required field. Co-Authored-By: Claude Opus 5 (1M context) --- CLAUDE.md | 13 +- .../query/vgirpc/conformance/worker/Main.java | 134 ++++- tests/test_java_conformance.py | 71 ++- .../java/farm/query/vgirpc/AccessLogHook.java | 424 +++++++++++++++- .../farm/query/vgirpc/AccessLogScope.java | 153 ++++++ .../java/farm/query/vgirpc/ClaimRedactor.java | 83 ++++ .../java/farm/query/vgirpc/DispatchInfo.java | 2 + .../java/farm/query/vgirpc/RpcServer.java | 17 +- .../farm/query/vgirpc/TraceCorrelator.java | 107 ++++ .../query/vgirpc/external/Externalizer.java | 6 + .../farm/query/vgirpc/http/AuthException.java | 29 +- .../farm/query/vgirpc/http/AuthFailure.java | 55 +++ .../farm/query/vgirpc/http/AuthReason.java | 66 +++ .../vgirpc/http/AuthUnavailableException.java | 77 +++ .../farm/query/vgirpc/http/Authenticator.java | 6 + .../query/vgirpc/http/CallStateCache.java | 86 ++++ .../farm/query/vgirpc/http/CallToken.java | 155 ++++++ .../farm/query/vgirpc/http/CorsPolicy.java | 138 ++++++ .../farm/query/vgirpc/http/HttpHeaders.java | 15 + .../farm/query/vgirpc/http/HttpServer.java | 467 +++++++++++++++++- .../query/vgirpc/http/HttpStreamHandler.java | 115 ++++- .../query/vgirpc/http/InvalidCredentials.java | 2 + .../query/vgirpc/http/MissingCredentials.java | 2 + .../farm/query/vgirpc/http/StateToken.java | 119 +++-- .../farm/query/vgirpc/http/TokenIdentity.java | 45 ++ .../query/vgirpc/http/TokenIntrospection.java | 356 +++++++++++++ .../farm/query/vgirpc/http/TokenResolver.java | 44 ++ .../java/farm/query/vgirpc/http/Tokens.java | 131 +++++ .../farm/query/vgirpc/http/Unauthorized.java | 56 +++ .../query/vgirpc/http/auth/ProxyProof.java | 11 +- .../java/farm/query/vgirpc/wire/Metadata.java | 8 + .../farm/query/vgirpc/AccessLogHookTest.java | 403 +++++++++++++++ .../vgirpc/http/AccessLogEgressTest.java | 249 ++++++++++ .../java/farm/query/vgirpc/http/CorsTest.java | 303 ++++++++++++ .../http/HttpStreamHandlerResumeTest.java | 27 +- .../query/vgirpc/http/StateTokenTest.java | 224 +++++++-- .../vgirpc/http/TokenIntrospectionTest.java | 260 ++++++++++ .../query/vgirpc/http/UnauthorizedTest.java | 188 +++++++ 38 files changed, 4495 insertions(+), 152 deletions(-) create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/AccessLogScope.java create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/ClaimRedactor.java create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/TraceCorrelator.java create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/http/AuthFailure.java create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/http/AuthReason.java create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/http/AuthUnavailableException.java create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/http/CallStateCache.java create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/http/CallToken.java create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/http/CorsPolicy.java create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/http/TokenIdentity.java create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/http/TokenIntrospection.java create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/http/TokenResolver.java create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/http/Tokens.java create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/http/Unauthorized.java create mode 100644 vgirpc/src/test/java/farm/query/vgirpc/AccessLogHookTest.java create mode 100644 vgirpc/src/test/java/farm/query/vgirpc/http/AccessLogEgressTest.java create mode 100644 vgirpc/src/test/java/farm/query/vgirpc/http/CorsTest.java create mode 100644 vgirpc/src/test/java/farm/query/vgirpc/http/TokenIntrospectionTest.java create mode 100644 vgirpc/src/test/java/farm/query/vgirpc/http/UnauthorizedTest.java diff --git a/CLAUDE.md b/CLAUDE.md index 9e0f921..d1db816 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -76,6 +76,11 @@ Package root: `farm.query.vgirpc` - **`wire/`** — `IpcStreamReader`, `IpcStreamWriter`, `Metadata` (all `vgi_rpc.*` metadata key constants), `Allocators` (shared `BufferAllocator` root), `Wire` (higher-level helpers: `requestMetadata`, `validateRequestVersion`, `requireMethodName`, `writeErrorStream`, `writeZeroBatch`, `errorMetadata`, `classify`, `errorFromMetadata`, `messageFromMetadata`), `MapToList` (Arrow map↔list-of-struct coercion). - **`transport/`** — `RpcTransport` interface, `StdioTransport`, `SubprocessTransport`, `UnixSocketTransport`, `TcpSocketTransport` (raw Arrow-IPC framing over a bare TCP socket — the network analog of `UnixSocketTransport`; no auth/TLS, loopback-default, trusted networks only). - **`http/`** — Jetty-based HTTP transport. `HttpServer`, `HttpPreHandler`, `HttpStreamHandler` (stateless streaming: state travels in a signed `StateToken` in custom metadata), `StateSerializer`, `StateToken`, `Authenticator`, `AuthException`, `TokenExpiredException`. + + **Unauthorized responses.** Every 401 follows `docs/unauthorized-spec.md` in the Python repo. `AuthReason` is the closed set of codes; the reason is read off the `AuthException` subtype (`MissingCredentials` → `missing_credential`, `InvalidCredentials` → `invalid_credential`, `AuthFailure` → whatever it declares, defaulting to `unauthorized`) — never guessed from message text. `HttpServer.writeUnauthorized` renders `VGI-Auth-Reason`, `Cache-Control: no-store`, and the JSON envelope `{error, reason, detail, proxy_hint?}`; this port always answers JSON, which §4.2 permits. The **proxy note** (`VGI-Auth-Proxy-Required: true` + `proxy_hint`) comes from server configuration only — `Config.proxyProofRequired` contributes `VGI-Proxy-Proof` in require mode, `Config.proxyAuthHeaders` states headers for a custom authenticator — so it is identical on every 401 and discloses nothing. Cross-language conformance group: `TestUnauthorized`. + **CORS.** `CorsPolicy` (package-private, applied from `RouterServlet.service` so the grant rides *every* answer, not just the preflight). Strictly opt-in: `Config.corsOrigins` empty ⇒ not one `Access-Control-*` header, which is itself a conformance contract (`TestCorsOffMode`). A single `"*"` allows all — safe only because credentials here are header-borne and the server never sets `Access-Control-Allow-Credentials`; anything else is matched case-insensitively against `Origin`, echoed back, and paired with `Vary: Origin`. `Access-Control-Allow-Headers` echoes the preflight's `Access-Control-Request-Headers` (same answer Go/Rust/Python give), falling back to the request-side surface. `Access-Control-Expose-Headers` is built by `HttpServer.corsExposeHeaders()` from the *same conditions* as `applyCapabilityHeaders` — whatever this server advertises, it exposes. **Adding a `VGI-*` / `X-VGI-*` response header means adding it to both**: an advertised-but-unexposed header is invisible to a browser and to nothing else, so every non-CORS test passes right through the omission. Cross-language conformance group: `TestCors`. + **Token introspection.** `TokenIntrospection` + `TokenResolver` + `TokenIdentity` back `POST {prefix}/__introspect_token__`, which resolves an opaque bearer credential to a principal for a fronting proxy. Off unless `Config.tokenIntrospection(resolver, principals)` is called, and a disabled worker still answers `404 {"error":"not_enabled"}` — a caller classifies `401/403/404` as definitive and everything else as transient, so an unrouted path (which would dispatch a JSON body into the Arrow reader and 500) means retrying forever against a worker that will never support the feature. The response is a **closed set** of `principal` / `token_name` / `ttl_seconds`; a `claims` field would let a worker choose its caller's tenant routing, row scope and policy branch. The introspector allowlist has **no permissive default** (authentication and introspection are different capabilities), JWS-shaped subjects are refused without reaching the resolver, unknown/expired/malformed are byte-identical rejections, and the credential is SHA-256 digested rather than logged. It is deliberately *not* implemented by replaying the credential through the server's own `Authenticator` — see `TokenResolver` for the four ways that breaks. Advertised via `VGI-Token-Introspection: true`. Conformance groups: `TestTokenIntrospection` (needs the `--introspect` worker) and `TestTokenIntrospectionOffMode` (ungated). + **Definitive vs transient.** `AuthUnavailableException` means "I could not find out whether the credential is bad" and sits *outside* the `AuthException` hierarchy on purpose: every `AuthException` subtype renders as a 401 and `Authenticator.chain` catches it to mean "not my credential, try the next", so an outage raised as one emerges as a 401 from the end of the chain — turning a sidecar restart into a fleet-wide re-login storm and poisoning callers' negative caches. Unchecked, so it propagates to `RouterServlet.service`, which renders `503` + `Retry-After`. - **`http/auth/`** — shared authenticator implementations (bearer, mTLS/XFCC). JWT/OAuth lives in the `vgirpc-oauth` module to keep core deps lean. - **`marshal/`** — `Marshalling` (row↔VectorSchemaRoot, type casting, parameter adaptation), `RecordCodec` (Java record ↔ row map). - **`schema/`** — `SchemaDerivation` (Java type → Arrow schema), `ArrowSerializableRecord`, `ArrowField`, `ArrowFieldType`, `Nullable`, `EnumDictionaryRegistry`, `StreamHeader`. @@ -114,9 +119,13 @@ Package root: `farm.query.vgirpc` This port tracks `vgi-rpc-python` for wire compatibility. Two surfaces matter: - **`__describe__`** — `Introspect.DESCRIBE_VERSION = "4"`. `DESCRIBE_SCHEMA` is the slim 8-column form: `name`, `method_type`, `has_return`, `params_schema_ipc`, `result_schema_ipc`, `has_header`, `header_schema_ipc`, `is_exchange`. Python-flavoured columns (`doc`, `param_types_json`, `param_defaults_json`, `param_docs_json`) are off the wire — the Protocol interface is the source of truth for human-readable type info. The response's custom metadata carries `vgi_rpc.protocol_hash` via `Introspect.computeProtocolHash`, byte-identical to the Python algorithm. `RpcServer.protocolHash()` exposes it; `RpcServer.setProtocolVersion(...)` sets the optional human label. Within-port stable; cross-port byte equality is *not* guaranteed (Arrow IPC schema bytes differ across libraries). -- **Access log** — `AccessLogHook` (`AccessLogHook.java`) implements `DispatchHook` and writes one JSONL record per dispatch. The record conforms to `vgi_rpc/access_log.schema.json` in the Python repo and validates under `vgi-rpc-test --access-log `. `DispatchInfo` carries `protocol`, `protocolHash`, `protocolVersion`, `remoteAddr`, `requestData`, `streamId`, `cancelled`, `httpStatus`. Install via `RpcServer.setDispatchHook(new AccessLogHook(out, serverVersion))`. +- **Access log** — `AccessLogHook` (`AccessLogHook.java`) implements `DispatchHook` and writes one JSONL record per dispatch. The record conforms to `vgi_rpc/access_log.schema.json` in the Python repo and validates under `vgi-rpc-test --access-log `. `DispatchInfo` carries `protocol`, `protocolHash`, `protocolVersion`, `remoteAddr`, `requestData`, `streamId`, `cancelled`, `httpStatus`, `claims`. Install via `RpcServer.setDispatchHook(new AccessLogHook(out, serverVersion))`, or `AccessLogHook.builder(out)` for the spec's optional behaviours: `sampleRate` (deterministic per call, keyed on `stream_id` then `request_id`, errors never sampled, out-of-range rejected at construction), `asyncQueueSize` (bounded, non-blocking, drops reported as `dropped_records`), `logPayloads(false)` (⇒ `truncated: "payload_omitted"`, which is *not* the size-driven `true`), `claimRedactor` (`ClaimRedactor.byKeyName()` by default, `ClaimRedactor.none()` to opt out; a redactor that throws fails **closed**), and `traceCorrelator` (`TraceCorrelator.openTelemetry()` reads `Span.current()` reflectively so OTel stays off the core classpath — `trace_id`/`span_id` are emitted both or neither, and only when they are well-formed W3C hex). + + **Egress accounting** (§4.8) can't all be measured in the hook: response compression runs after the handler returns. `AccessLogScope` is the per-request thread-local that closes that gap — `RouterServlet.service` opens one, `readBody` stamps `request_bytes` (pre-decompression), `writeArrowResponse` stamps `response_bytes` (post-compression), `Externalizer.maybeExternalize` counts `externalized_bytes` at the single upload choke point, and the scope emits the parked records on close. Transports that install no scope (pipe / unix / TCP) keep logging inline. These are distinct from §4.6's `input_bytes`/`output_bytes` (logical Arrow buffers), which this port does not yet populate at all. + + What the schema cannot check — sampling determinism, drop reporting, fail-closed redaction, `payload_omitted` vs `true`, `response_bytes` being the compressed size — is covered by `AccessLogHookTest` and `http/AccessLogEgressTest`. -The conformance worker accepts `--access-log ` (`Main.java` parses it). +The conformance worker accepts `--access-log ` (`Main.java` parses it) plus `--access-log-sample `, `--access-log-async`, `--access-log-queue-size ` and `--access-log-no-payloads` (so `vgi-rpc-test --access-log` can validate the optional record shapes, not just the default one), `--http-auth` (reject-all authenticator that honours the `X-Conformance-Auth-Reason` fixture header, backing `TestHealth` + `TestUnauthorized`), `--no-call-state-cache` (disables the per-process call-state cache so every stream continuation takes the miss path, backing `TestColdCallStateCache`), `--cors-origin ` (repeatable; implies `--http` and grants that origin browser access, backing `TestCors` — the default worker stays CORS-free for `TestCorsOffMode`), and `--introspect` (implies `--http` plus principal-header auth, and enables token introspection with the fixed conformance introspector/subject/JWS-trap constants, backing `TestTokenIntrospection` — the default worker stays introspection-free for `TestTokenIntrospectionOffMode`). ## When in doubt diff --git a/conformance-worker/src/main/java/farm/query/vgirpc/conformance/worker/Main.java b/conformance-worker/src/main/java/farm/query/vgirpc/conformance/worker/Main.java index d5d70a7..d253896 100644 --- a/conformance-worker/src/main/java/farm/query/vgirpc/conformance/worker/Main.java +++ b/conformance-worker/src/main/java/farm/query/vgirpc/conformance/worker/Main.java @@ -10,9 +10,12 @@ import farm.query.vgirpc.conformance.ConformanceServiceImpl; import farm.query.vgirpc.external.ExternalLocationConfig; import farm.query.vgirpc.external.LocationResolver; +import farm.query.vgirpc.http.AuthFailure; +import farm.query.vgirpc.http.AuthReason; import farm.query.vgirpc.http.Authenticator; import farm.query.vgirpc.http.HttpPreHandler; import farm.query.vgirpc.http.HttpServer; +import farm.query.vgirpc.http.TokenIdentity; import farm.query.vgirpc.http.auth.BearerAuthenticator; import farm.query.vgirpc.http.auth.JwtAuthenticator; import farm.query.vgirpc.http.auth.MTlsAuthenticator; @@ -36,6 +39,7 @@ import java.util.List; import java.util.Map; import java.util.Objects; +import java.util.Optional; public final class Main { @@ -65,6 +69,12 @@ public static void main(String[] args) throws Exception { long maxRequestBytes = -1; String compression = "none"; String accessLogPath = null; + // Optional access-log behaviours, mirroring the Python reference's flag + // names so one driver can exercise every port the same way. + double accessLogSample = 1.0; + boolean accessLogAsync = false; + int accessLogQueueSize = 10000; + boolean accessLogPayloads = true; boolean strictMode = false; // 0 = unbounded; --strict bumps both to 1 MiB to mirror Python's // tests/serve_conformance_http_strict.py. @@ -94,6 +104,18 @@ public static void main(String[] args) throws Exception { String proofSecrets = ""; int proofSkew = 30; boolean proofReplayCache = true; + // The call-state cache is a pure accelerator; --no-call-state-cache + // turns every stream continuation onto the miss path so the shared + // TestColdCallStateCache group observes it deterministically. + boolean callStateCache = true; + // CORS is opt-in, so the default worker must stay header-free — that + // "off by default" property is itself a conformance contract + // (TestCorsOffMode), and only --cors-origin opts a worker out of it. + List corsOrigins = new ArrayList<>(); + // Token introspection is off unless asked for -- that "absent by default" + // property is itself a conformance contract (TestTokenIntrospectionOffMode), + // which runs against the plain worker. + boolean introspect = false; ArgCursor c = new ArgCursor(args); while (c.hasNext()) { String a = c.next(); @@ -131,7 +153,8 @@ public static void main(String[] args) throws Exception { authenticator = pkce.authenticator(); preHandlers.add(pkce.preHandler()); } - // --http-proof implies HTTP, mirroring --http-auth in the Go worker. + // Both imply HTTP, mirroring the Go and Rust workers' flags. + case "--http-auth" -> { mode = "http"; authenticator = rejectAllAuthenticator(); } case "--http-proof" -> { mode = "http"; httpProof = true; } case "--proof-mode" -> proofMode = c.requireValue(a); case "--proof-origin-id" -> proofOriginId = c.requireValue(a); @@ -143,6 +166,10 @@ public static void main(String[] args) throws Exception { case "--max-request-bytes" -> maxRequestBytes = Long.parseLong(c.requireValue(a)); case "--compression" -> compression = c.requireValue(a); case "--access-log" -> accessLogPath = c.requireValue(a); + case "--access-log-sample" -> accessLogSample = Double.parseDouble(c.requireValue(a)); + case "--access-log-async" -> accessLogAsync = true; + case "--access-log-queue-size" -> accessLogQueueSize = Integer.parseInt(c.requireValue(a)); + case "--access-log-no-payloads" -> accessLogPayloads = false; case "--strict" -> strictMode = true; case "--max-response-bytes" -> maxResponseBytes = Long.parseLong(c.requireValue(a)); case "--max-externalized-response-bytes" -> @@ -151,9 +178,18 @@ public static void main(String[] args) throws Exception { case "--no-sticky" -> stickyEnabled = false; case "--sticky-ttl" -> stickyTtl = Long.parseLong(c.requireValue(a)); case "--sticky-auth" -> authenticator = principalHeaderAuthenticator(); + case "--no-call-state-cache" -> callStateCache = false; + // Implies HTTP, like --http-auth and --http-proof; repeatable. + case "--cors-origin" -> { mode = "http"; corsOrigins.add(c.requireValue(a)); } + // Implies HTTP, and implies principal-header auth below so the + // introspector allowlist has something to check. + case "--introspect" -> { mode = "http"; introspect = true; } default -> { System.err.println("unknown arg: " + a); System.exit(2); } } } + // Applied after the loop so flag order does not matter, and only when no + // stronger mode was selected. + if (introspect && authenticator == null) authenticator = principalHeaderAuthenticator(); if (httpProof) { authenticator = buildProofGate( proofMode, proofOriginId, proofSecrets, proofSkew, proofReplayCache, authenticator); @@ -179,7 +215,17 @@ public static void main(String[] args) throws Exception { } if (accessLogPath != null) { OutputStream accessLogOut = new FileOutputStream(accessLogPath, true); - server.setDispatchHook(new AccessLogHook(accessLogOut, "vgi-rpc-java-conformance")); + AccessLogHook hook = AccessLogHook.builder(accessLogOut) + .serverVersion("vgi-rpc-java-conformance") + .sampleRate(accessLogSample) + .logPayloads(accessLogPayloads) + .asyncQueueSize(accessLogAsync ? accessLogQueueSize : 0) + .build(); + server.setDispatchHook(hook); + // An async hook holds records in a queue; without this a normal + // shutdown would discard whatever had not reached disk, and the + // driver would read a truncated log as a conformance failure. + Runtime.getRuntime().addShutdownHook(new Thread(hook::close)); } if (mode == null) { servePipe(server); return; } if (strictMode) { @@ -192,7 +238,8 @@ public static void main(String[] args) throws Exception { maxResponseBytes, maxExternalizedResponseBytes, stickyEnabled, stickyTtl, responseCompression, // Only require mode denies, so only require mode advertises. - httpProof && "require".equals(proofMode)); + httpProof && "require".equals(proofMode), + callStateCache, corsOrigins, introspect); case "unix" -> serveUnix(server, Path.of(unixPath)); case "tcp" -> serveTcp(server, tcpHost, tcpPort); default -> { System.err.println("unknown mode: " + mode); System.exit(2); } @@ -306,6 +353,76 @@ private static Authenticator principalHeaderAuthenticator() { }; } + // Fixed values the shared TestTokenIntrospection group is written against: + // it posts the subject credential and asserts the principal, so a port + // supplying the conformance_http_introspect_port fixture must configure + // exactly these. + private static final String CONFORMANCE_INTROSPECTOR = "conformance-introspector"; + private static final String CONFORMANCE_SUBJECT_TOKEN = "conformance-opaque-subject-token"; + private static final String CONFORMANCE_SUBJECT_PRINCIPAL = "subject@conformance.example"; + private static final String CONFORMANCE_SUBJECT_TOKEN_NAME = "conformance-subject"; + private static final long CONFORMANCE_SUBJECT_TTL = 300; + /** + * A JWS-shaped credential the resolver would resolve. + * + *

Deliberately resolvable: against an unknown JWS a port with no shape + * guard rejects it as unknown and passes the test for the wrong reason. Made + * resolvable, the guard is the only thing that can produce a rejection — a + * port missing it answers 200 and fails. + */ + private static final String CONFORMANCE_JWS_TRAP_TOKEN = + "eyJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJhbGljZSJ9.c2lnbmF0dXJl"; + + /** Resolve the one fixed subject credential the shared tests post. */ + private static Optional resolveConformanceToken(String token) { + if (CONFORMANCE_SUBJECT_TOKEN.equals(token) || CONFORMANCE_JWS_TRAP_TOKEN.equals(token)) { + return Optional.of(new TokenIdentity( + CONFORMANCE_SUBJECT_PRINCIPAL, CONFORMANCE_SUBJECT_TOKEN_NAME, CONFORMANCE_SUBJECT_TTL)); + } + return Optional.empty(); + } + + /** Conformance-fixture affordance, never part of the protocol. */ + private static final String CONFORMANCE_REASON_HEADER = "X-Conformance-Auth-Reason"; + + /** + * The reasons a request may ask to be refused with. + * + *

{@code proxy_required} is deliberately absent: the unauthorized spec derives it from + * server configuration, never from the request, so a worker letting a caller summon it would + * advertise a proxy dependency that does not exist. {@code unauthorized} is absent because it + * is what the absence of a requested reason must produce — making it requestable + * would hide whether the fallback path works at all. Anything not in this map, including a + * typo, falls through to that fallback, so a test asking for a reason it cannot get fails + * rather than quietly passing. + */ + private static final Map REQUESTABLE_REASONS = Map.of( + "missing_credential", AuthReason.MISSING_CREDENTIAL, + "invalid_credential", AuthReason.INVALID_CREDENTIAL, + "expired_credential", AuthReason.EXPIRED_CREDENTIAL, + "insufficient_scope", AuthReason.INSUFFICIENT_SCOPE); + + /** + * Refuse every RPC call, with the reason the request named if it named one. + * + *

Backs the shared {@code TestHealth} exemption check and {@code TestUnauthorized}. The + * latter needs one worker that discriminates between codes: membership in the closed + * set is satisfied by a server stamping {@code unauthorized} on every 401, which is exactly + * the failure that makes the code not worth branching on. + */ + private static Authenticator rejectAllAuthenticator() { + return request -> { + String requested = request.getHeader(CONFORMANCE_REASON_HEADER); + AuthReason reason = requested == null ? null : REQUESTABLE_REASONS.get(requested); + if (reason != null) { + // The detail is the code itself so the suite can assert header and body agree + // without pinning prose. + throw new AuthFailure(reason, reason.code()); + } + throw new AuthFailure("authentication required"); + }; + } + private static Authenticator buildBearer(String spec) { Map tokens = new LinkedHashMap<>(); for (Map.Entry e : splitKv(spec, "--auth-bearer").entrySet()) { @@ -349,13 +466,22 @@ private static void serveHttp(RpcServer server, byte[] tokenKey, long tokenTtl, boolean stickyEnabled, long stickyTtl, boolean responseCompression, - boolean proxyProofRequired) throws Exception { + boolean proxyProofRequired, + boolean callStateCache, + List corsOrigins, + boolean introspect) throws Exception { HttpServer.Config.Builder cb = HttpServer.Config.builder() .tokenKey(tokenKey) .tokenTtlSeconds(tokenTtl) .authenticator(authenticator) .preHandlers(preHandlers) .proxyProofRequired(proxyProofRequired); + if (!callStateCache) cb.callStateCacheMaxEntries(0); + if (!corsOrigins.isEmpty()) cb.corsOrigins(corsOrigins); + if (introspect) { + cb.tokenIntrospection(Main::resolveConformanceToken, List.of(CONFORMANCE_INTROSPECTOR)) + .introspectTtlSeconds(CONFORMANCE_SUBJECT_TTL); + } // Empty producible set ⇒ present-but-empty VGI-Supported-Encodings and // no compression, whatever the client asks for. null would mean "unset" // and fall back to the default set, so the empty list is load-bearing. diff --git a/tests/test_java_conformance.py b/tests/test_java_conformance.py index 575240c..8f1b536 100644 --- a/tests/test_java_conformance.py +++ b/tests/test_java_conformance.py @@ -167,9 +167,9 @@ def conformance_http_port(java_http_port: int) -> int: @pytest.fixture(scope="session") def conformance_http_auth_port() -> Iterator[int]: - """Spawn an HTTP worker with bearer auth so every RPC POST returns 401.""" + """Spawn a reject-all HTTP worker, so every RPC POST returns 401.""" proc = subprocess.Popen( - [JAVA_WORKER, "--http", "--auth-bearer", "secret=alice"], + [JAVA_WORKER, "--http-auth"], stdout=subprocess.PIPE, stderr=subprocess.PIPE, ) @@ -185,6 +185,21 @@ def conformance_http_auth_port() -> Iterator[int]: proc.wait(timeout=5) +@pytest.fixture(scope="session") +def conformance_http_auth_reason_port(conformance_http_auth_port: int) -> int: + """Port of a worker that honours ``X-Conformance-Auth-Reason``. + + Backs the shared ``TestUnauthorized`` reason-code tests. Membership in + the closed set is not enough on its own — a server answering every 401 + with ``unauthorized`` satisfies that. These tests prove the codes are + *discriminated*, which is what makes them worth branching on. + + ``--http-auth`` already reads the header, so this is the same worker + under the name the shared suite looks up. + """ + return conformance_http_auth_port + + @pytest.fixture(scope="session") def conformance_http_no_compression_port() -> Iterator[int]: """Spawn an HTTP worker with response compression disabled. @@ -253,6 +268,58 @@ def _start_http_worker(*extra_args: str) -> Iterator[int]: proc.wait(timeout=5) +@pytest.fixture(scope="session") +def conformance_http_cold_call_cache_port() -> Iterator[int]: + """Spawn an HTTP worker with the per-process call-state cache disabled. + + Backs the shared ``TestColdCallStateCache`` group, which pins the rule + that a client echoes the call token on **every** continuation. With the + cache warm a client that never echoes still works, and only breaks once + a continuation lands on a process that never saw the stream's ``/init`` + — a restarted worker, an evicted entry, a load-balanced relay. Booting + with the cache off turns that load-dependent bug into a deterministic + one: every turn takes the miss path. + """ + yield from _start_http_worker("--http", "--no-call-state-cache") + + +@pytest.fixture(scope="session") +def conformance_http_introspect_port() -> Iterator[int]: + """Spawn an HTTP worker with token introspection enabled. + + Backs the shared ``TestTokenIntrospection`` group. It needs its own worker + because the endpoint resolves nothing unless explicitly enabled -- which + ``TestTokenIntrospectionOffMode`` asserts against the default one. The + worker is configured with the exact introspector / subject / JWS-trap + constants the shared suite posts; anything else reads as "did not resolve". + """ + yield from _start_http_worker("--http", "--introspect") + + +@pytest.fixture(scope="session") +def conformance_http_cors_port(conformance_fake_storage: str) -> Iterator[int]: + """Spawn an HTTP worker that grants browser access to one fixed origin. + + Backs the shared ``TestCors`` group. It needs its own worker because CORS + is opt-in and the default one must stay header-free -- ``TestCorsOffMode`` + runs against that one and checks exactly that. The origin is the constant + the shared suite preflights with; a mismatch reads as "origin refused". + + Storage mode is deliberate: the derived exposure check can only catch a + missing entry for a header the worker actually advertises, so a *plain* + worker here would silently skip the conditional half of the capability + set -- the size caps and the upload-URL trio -- which are exactly the + exposures a port is most likely to miss. + """ + yield from _start_http_worker( + "--http", + "--fake-storage", + conformance_fake_storage, + "--cors-origin", + "https://conformance.example", + ) + + # --------------------------------------------------------------------------- # Sticky failure-path fixtures (upstream TestSticky; see # vgi-rpc docs/sticky-sessions-spec.md §9.1) diff --git a/vgirpc/src/main/java/farm/query/vgirpc/AccessLogHook.java b/vgirpc/src/main/java/farm/query/vgirpc/AccessLogHook.java index 8516393..cf85e38 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/AccessLogHook.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/AccessLogHook.java @@ -11,8 +11,13 @@ import java.time.ZoneOffset; import java.time.format.DateTimeFormatter; import java.util.Base64; +import java.util.Collection; import java.util.LinkedHashMap; import java.util.Map; +import java.util.concurrent.ArrayBlockingQueue; +import java.util.concurrent.BlockingQueue; +import java.util.concurrent.TimeUnit; +import java.util.regex.Pattern; /** * {@link DispatchHook} that writes one JSONL access-log record per RPC call to @@ -21,14 +26,30 @@ *

The record shape conforms to the cross-language vgi-rpc access-log * specification (see {@code docs/access-log-spec.md} and * {@code vgi_rpc/access_log.schema.json} in the Python reference repo). + * + *

Records are written synchronously by default. {@link Builder} adds the + * optional behaviours the spec permits: deterministic sampling, background + * emission, payload omission, and a replaceable claim-redaction policy. */ -public final class AccessLogHook implements DispatchHook { +public final class AccessLogHook implements DispatchHook, AutoCloseable { + + private static final org.slf4j.Logger LOG = org.slf4j.LoggerFactory.getLogger(AccessLogHook.class); private static final DateTimeFormatter ISO = DateTimeFormatter.ofPattern("uuuu-MM-dd'T'HH:mm:ss.SSS'Z'").withZone(ZoneOffset.UTC); + /** W3C ids are lowercase hex of fixed width; anything else fails schema validation downstream. */ + private static final Pattern TRACE_ID = Pattern.compile("[0-9a-f]{32}"); + private static final Pattern SPAN_ID = Pattern.compile("[0-9a-f]{16}"); + private final OutputStream out; private final String serverVersion; + private final double sampleRate; + private final long sampleThreshold; + private final boolean logPayloads; + private final ClaimRedactor claimRedactor; + private final TraceCorrelator traceCorrelator; + private final AsyncEmitter async; private final Object writeLock = new Object(); /** @@ -39,8 +60,148 @@ public final class AccessLogHook implements DispatchHook { * @param serverVersion server-version string included in each record; {@code null} becomes {@code ""} */ public AccessLogHook(OutputStream out, String serverVersion) { - this.out = out; - this.serverVersion = serverVersion == null ? "" : serverVersion; + this(builder(out).serverVersion(serverVersion)); + } + + private AccessLogHook(Builder b) { + this.out = b.out; + this.serverVersion = b.serverVersion == null ? "" : b.serverVersion; + this.sampleRate = b.sampleRate; + this.sampleThreshold = (long) (b.sampleRate * 0xFFFFFFFFL); + this.logPayloads = b.logPayloads; + this.claimRedactor = b.claimRedactor; + this.traceCorrelator = b.traceCorrelator; + this.async = b.asyncQueueSize > 0 ? new AsyncEmitter(this, b.asyncQueueSize) : null; + } + + /** + * Start configuring a hook writing to {@code out}. + * + * @param out destination for one JSONL record per dispatch + * @return a builder seeded with the conformant defaults: log everything, + * synchronously, with payloads, redacting claims by key + */ + public static Builder builder(OutputStream out) { + return new Builder(out); + } + + /** Configuration for {@link AccessLogHook}. */ + public static final class Builder { + private final OutputStream out; + private String serverVersion = ""; + private double sampleRate = 1.0; + private boolean logPayloads = true; + private ClaimRedactor claimRedactor = ClaimRedactor.byKeyName(); + private TraceCorrelator traceCorrelator = TraceCorrelator.openTelemetry(); + private int asyncQueueSize; + + private Builder(OutputStream out) { + this.out = out; + } + + /** + * Server build version stamped on every record. + * + * @param version free-form build identifier; {@code null} becomes {@code ""} + * @return this builder + */ + public Builder serverVersion(String version) { + this.serverVersion = version; + return this; + } + + /** + * Log only a fraction of successful calls. + * + *

Errors are never sampled out, and the decision is deterministic per + * call rather than per record, so every record of one stream shares its + * init's fate — see {@link AccessLogHook#sampledIn}. + * + * @param rate fraction of non-error calls to keep, {@code 0 < rate <= 1}; + * {@code 1.0} (the default) keeps everything + * @return this builder + * @throws IllegalArgumentException if {@code rate} is outside the range. + * Rejected here rather than at the first request because + * {@code 100} meaning "100%" would otherwise silently log everything. + */ + public Builder sampleRate(double rate) { + if (!(rate > 0.0) || rate > 1.0 || Double.isNaN(rate)) { + throw new IllegalArgumentException( + "access-log sample rate must be in (0.0, 1.0], got " + rate); + } + this.sampleRate = rate; + return this; + } + + /** + * Whether request payloads are logged. + * + * @param enabled {@code false} drops {@code request_data} and marks the + * record {@code truncated: "payload_omitted"} — distinct from + * the size-driven {@code truncated: true}, so a consumer + * scanning for real data loss has something to filter on + * @return this builder + */ + public Builder logPayloads(boolean enabled) { + this.logPayloads = enabled; + return this; + } + + /** + * Policy applied to authentication claims before they reach a record. + * + * @param redactor the policy; {@link ClaimRedactor#none()} opts a service + * that owns its logs end to end out of redaction + * @return this builder + */ + public Builder claimRedactor(ClaimRedactor redactor) { + this.claimRedactor = redactor; + return this; + } + + /** + * Source of the {@code trace_id}/{@code span_id} pair. + * + * @param correlator the source; defaults to {@link TraceCorrelator#openTelemetry()} + * @return this builder + */ + public Builder traceCorrelator(TraceCorrelator correlator) { + this.traceCorrelator = correlator; + return this; + } + + /** + * Hand records to a background writer so disk latency stays out of the + * request path. + * + *

The queue is bounded and the enqueue never blocks: an unbounded queue + * turns a stalled disk into an OOM, and a blocking put reintroduces exactly + * the latency the thread was meant to remove. Full therefore means drop, + * and the next record through carries {@code dropped_records}. + * + *

Opt-in because it trades durability — with a synchronous writer a + * record on disk means the call completed; here a crash loses whatever is + * still queued. That is the wrong trade for an audit log. + * + * @param queueSize bounded queue depth; {@code 0} (the default) keeps + * emission synchronous + * @return this builder + * @throws IllegalArgumentException if {@code queueSize} is negative + */ + public Builder asyncQueueSize(int queueSize) { + if (queueSize < 0) throw new IllegalArgumentException("queue size must be >= 0, got " + queueSize); + this.asyncQueueSize = queueSize; + return this; + } + + /** + * Build the hook. + * + * @return a configured {@link AccessLogHook} + */ + public AccessLogHook build() { + return new AccessLogHook(this); + } } /** Mint a 32-char lowercase hex stream identifier. The dispatcher assigns @@ -80,6 +241,8 @@ public void onDispatchEnd(Object token, DispatchInfo info, CallStatistics stats, } } + AccessLogScope scope = AccessLogScope.current(); + Map rec = new LinkedHashMap<>(); rec.put("timestamp", ISO.format(Instant.now())); rec.put("level", "INFO"); @@ -93,7 +256,7 @@ public void onDispatchEnd(Object token, DispatchInfo info, CallStatistics stats, rec.put("principal", info.principal); rec.put("auth_domain", info.authDomain); rec.put("authenticated", info.authenticated); - rec.put("remote_addr", info.remoteAddr); + rec.put("remote_addr", remoteAddr(info)); rec.put("duration_ms", durationMs); rec.put("status", status); rec.put("error_type", errorType); @@ -103,10 +266,26 @@ public void onDispatchEnd(Object token, DispatchInfo info, CallStatistics stats, if (info.protocolVersion != null && !info.protocolVersion.isEmpty()) { rec.put("protocol_version", info.protocolVersion); } - if (info.requestId != null && !info.requestId.isEmpty()) rec.put("request_id", info.requestId); + String requestId = info.requestId != null && !info.requestId.isEmpty() + ? info.requestId + : (scope != null ? scope.requestId() : ""); + if (!requestId.isEmpty()) rec.put("request_id", requestId); + // Trace correlation. request_id only joins records within this service; + // these join them to the surrounding distributed trace. + putTraceContext(rec); if (info.httpStatus > 0) rec.put("http_status", info.httpStatus); if (info.requestData != null && info.requestData.length > 0) { - rec.put("request_data", Base64.getEncoder().encodeToString(info.requestData)); + String encoded = Base64.getEncoder().encodeToString(info.requestData); + if (logPayloads) { + rec.put("request_data", encoded); + } else { + // Nothing was lost to a size cap here — this deployment simply + // does not log payloads. Sharing the size-driven `true` made the + // marker fire on essentially every record and stop meaning + // anything to a consumer looking for real data loss. + rec.put("original_request_bytes", encoded.length()); + rec.put("truncated", "payload_omitted"); + } } if ("stream".equals(info.methodType)) { rec.put("stream_id", info.streamId == null || info.streamId.isEmpty() @@ -119,6 +298,15 @@ public void onDispatchEnd(Object token, DispatchInfo info, CallStatistics stats, if (info.sessionAction != null && !info.sessionAction.isEmpty()) { rec.put("session_action", info.sessionAction); } + putClaims(rec, info.claims); + // Egress accounting. The stats below measure logical Arrow buffers — + // what the worker processed. These measure what actually crossed the + // network, which differs in both directions: compression shrinks the + // body, and externalised payloads leave it entirely. + if (scope != null) { + if (scope.requestBytes() >= 0) rec.put("request_bytes", scope.requestBytes()); + if (scope.externalizedBytes() > 0) rec.put("externalized_bytes", scope.externalizedBytes()); + } if (stats != null && stats.nonZero()) { rec.put("input_batches", stats.inputBatches); rec.put("output_batches", stats.outputBatches); @@ -128,6 +316,114 @@ public void onDispatchEnd(Object token, DispatchInfo info, CallStatistics stats, rec.put("output_bytes", stats.outputBytes); } + if (scope != null) { + // Deferred: response_bytes is not known until the body has been + // compressed, which happens after this hook has run. + scope.defer(this, rec); + } else { + write(rec); + } + } + + /** HTTP fills {@code remote_addr} into the transport metadata, not the dispatch info. */ + private static String remoteAddr(DispatchInfo info) { + if (info.remoteAddr != null && !info.remoteAddr.isEmpty()) return info.remoteAddr; + if (info.transportMetadata != null) { + Object addr = info.transportMetadata.get("remote_addr"); + if (addr instanceof String s) return s; + } + return ""; + } + + private void putTraceContext(Map rec) { + String[] ids; + try { + ids = traceCorrelator.current(); + } catch (RuntimeException e) { + return; + } + // Both or neither: a record carrying one half joins nothing, and a + // malformed id (a dashed UUID, say) fails schema validation for every + // record the server writes. + if (ids == null || ids.length != 2 || ids[0] == null || ids[1] == null) return; + if (!TRACE_ID.matcher(ids[0]).matches() || !SPAN_ID.matcher(ids[1]).matches()) return; + rec.put("trace_id", ids[0]); + rec.put("span_id", ids[1]); + } + + private void putClaims(Map rec, Map claims) { + if (claims == null || claims.isEmpty()) return; + Map redacted; + try { + redacted = claimRedactor.redact(claims); + } catch (RuntimeException e) { + // Fail closed. A redactor that throws must not take the request down + // with it, but it must not fail *open* either — an unredacted claim + // on disk cannot be recalled. + LOG.warn("claim redactor raised; dropping claims from the access-log record", e); + return; + } + if (redacted != null && !redacted.isEmpty()) rec.put("claims", redacted); + } + + /** + * Decide whether to keep {@code rec}, stamping {@code sample_rate} when kept. + * + *

Errors are never sampled out: a rate below 1 exists because successful + * calls are repetitive, which is exactly what failures are not, and a + * consumer must be able to read a fall in error count as a fix landing + * rather than as the dice going the other way. + * + *

The decision is a function of a stable identifier for the call — + * {@code stream_id} when present, else {@code request_id} — so every record + * of one stream shares its init's fate. Random per-record sampling shreds a + * multi-record call into fragments indistinguishable from data loss, and the + * calls likeliest to be split are the long streams most worth studying. + */ + private boolean sampledIn(Map rec) { + if (sampleRate >= 1.0) return true; + if ("error".equals(rec.get("status"))) return true; + Object key = rec.get("stream_id"); + if (!(key instanceof String s) || s.isEmpty()) key = rec.get("request_id"); + // A record with neither identifier degrades to a per-record decision + // rather than being dropped on the floor. + String keyed = key instanceof String s2 && !s2.isEmpty() + ? s2 + : System.nanoTime() + ":" + Thread.currentThread().threadId(); + if (hash32(keyed) > sampleThreshold) return false; + rec.put("sample_rate", sampleRate); + return true; + } + + /** FNV-1a with a murmur3 finalizer: the sample decision reads the low bits, + * which FNV alone leaves poorly distributed for short hex keys. */ + private static long hash32(String key) { + long h = 0xcbf29ce484222325L; + for (int i = 0; i < key.length(); i++) { + h ^= key.charAt(i); + h *= 0x100000001b3L; + } + h ^= h >>> 33; + h *= 0xff51afd7ed558ccdL; + h ^= h >>> 33; + h *= 0xc4ceb9fe1a85ec53L; + h ^= h >>> 33; + return h >>> 32; + } + + /** Apply sampling, then emit — synchronously or via the background writer. */ + void write(Map rec) { + if (!sampledIn(rec)) return; + if (async != null) { + async.submit(rec); + } else { + writeLine(rec); + } + } + + /** Serialize and append one record. Called on the caller's thread when + * synchronous, on the writer thread when asynchronous. */ + void writeLine(Map rec) { String line = JsonWriter.toJsonLine(rec); try { synchronized (writeLock) { @@ -140,21 +436,111 @@ public void onDispatchEnd(Object token, DispatchInfo info, CallStatistics stats, } } + /** + * Stop the background writer, draining what it still holds. Synchronous + * hooks need no shutdown; calling this on one is a no-op. The output stream + * is not closed — the caller retains ownership. + */ + @Override + public void close() { + if (async != null) async.close(); + } + + /** + * Non-blocking background writer that reports what it dropped. + * + *

What makes dropping acceptable rather than silent corruption is that it + * is reported: the next record to get through carries {@code dropped_records}, + * so the loss is visible in the log itself rather than only in a metric + * nobody exports. A log that loses records without saying so is worse than a + * slow one, because a consumer cannot tell a quiet period from a lossy one. + */ + private static final class AsyncEmitter implements AutoCloseable { + + /** Sentinel telling the writer thread to stop; identity-compared. */ + private static final Map POISON = Map.of(); + + private final AccessLogHook hook; + private final BlockingQueue> queue; + private final Thread worker; + private final Object dropLock = new Object(); + private long dropped; + + AsyncEmitter(AccessLogHook hook, int capacity) { + this.hook = hook; + this.queue = new ArrayBlockingQueue<>(capacity); + this.worker = new Thread(this::drain, "vgi-rpc-access-log"); + this.worker.setDaemon(true); + this.worker.start(); + } + + void submit(Map rec) { + long seen; + synchronized (dropLock) { + seen = dropped; + // Attribute the loss to the first record that gets through after + // it, so the count reaches the same file the losses would have. + if (seen > 0) rec.put("dropped_records", seen); + } + if (!queue.offer(rec)) { + synchronized (dropLock) { + dropped++; + } + return; + } + if (seen > 0) { + synchronized (dropLock) { + dropped -= seen; + } + } + } + + private void drain() { + try { + while (true) { + Map rec = queue.take(); + if (rec == POISON) return; + hook.writeLine(rec); + } + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + } + } + + @Override + public void close() { + // A full queue would drop the sentinel and leave the thread parked; + // it is a daemon, so the JVM still exits, but the drain would stall. + while (!queue.offer(POISON)) { + Thread.onSpinWait(); + } + try { + worker.join(TimeUnit.SECONDS.toMillis(5)); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + } + } + } + /** Tiny JSON serializer for the record types used here (no external deps). */ private static final class JsonWriter { static String toJsonLine(Map rec) { StringBuilder sb = new StringBuilder(256); + writeObject(sb, rec); + return sb.toString(); + } + + static void writeObject(StringBuilder sb, Map rec) { sb.append('{'); boolean first = true; - for (Map.Entry e : rec.entrySet()) { + for (Map.Entry e : rec.entrySet()) { if (!first) sb.append(','); first = false; - writeString(sb, e.getKey()); + writeString(sb, String.valueOf(e.getKey())); sb.append(':'); writeValue(sb, e.getValue()); } sb.append('}'); - return sb.toString(); } static void writeValue(StringBuilder sb, Object v) { @@ -164,11 +550,25 @@ static void writeValue(StringBuilder sb, Object v) { writeString(sb, s); } else if (v instanceof Boolean b) { sb.append(b ? "true" : "false"); - } else if (v instanceof Long || v instanceof Integer) { + } else if (v instanceof Long || v instanceof Integer || v instanceof Short || v instanceof Byte) { sb.append(v); - } else if (v instanceof Double d) { - if (d.isNaN() || d.isInfinite()) sb.append("null"); + } else if (v instanceof Double || v instanceof Float) { + double d = ((Number) v).doubleValue(); + if (Double.isNaN(d) || Double.isInfinite(d)) sb.append("null"); else sb.append(d); + } else if (v instanceof Map m) { + // Claims arrive as arbitrary JSON-shaped values; a toString() + // fallback would emit Java map syntax and fail every consumer. + writeObject(sb, m); + } else if (v instanceof Collection c) { + sb.append('['); + boolean first = true; + for (Object item : c) { + if (!first) sb.append(','); + first = false; + writeValue(sb, item); + } + sb.append(']'); } else { writeString(sb, v.toString()); } diff --git a/vgirpc/src/main/java/farm/query/vgirpc/AccessLogScope.java b/vgirpc/src/main/java/farm/query/vgirpc/AccessLogScope.java new file mode 100644 index 0000000..7a693d9 --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/AccessLogScope.java @@ -0,0 +1,153 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc; + +import java.util.ArrayList; +import java.util.List; +import java.util.Map; + +/** + * Per-request scope that measures what actually crossed the network and defers + * access-log emission until the final response body exists. + * + *

A record written by the dispatch hook is written too early to know what the + * response weighed: response compression runs after the handler returns, so a + * record emitted at dispatch time can only ever report the uncompressed body — + * the wrong number for anything that costs money. The transport therefore opens + * a scope around the request, the hook parks its records in it, and the scope + * emits once the encoded body has been measured. + * + *

Three byte figures answer three different questions and must not be + * conflated: {@code request_bytes}/{@code response_bytes} are what crossed the + * wire after compression; {@link CallStatistics}' {@code input_bytes}/ + * {@code output_bytes} are logical Arrow buffers, routinely orders of magnitude + * larger; {@code externalized_bytes} never touch the HTTP body at all and are + * frequently the largest of the three. + * + *

Transports that install no scope — pipe, unix socket, raw TCP — keep + * logging inline, so the immediate-versus-deferred choice is made in exactly one + * place. The cost of deferring is that a crash between the handler and the + * response loses that request's records; the alternative is a permanently wrong + * number. + * + *

Bound to the dispatching thread. Not safe for use across threads. + */ +public final class AccessLogScope implements AutoCloseable { + + private static final ThreadLocal CURRENT = new ThreadLocal<>(); + + private final String requestId; + private long requestBytes = -1; + private long responseBytes = -1; + private long externalizedBytes; + private int httpStatus; + private List deferred; + + private AccessLogScope(String requestId) { + this.requestId = requestId == null ? "" : requestId; + } + + /** One parked record and the hook that will write it. */ + private record Deferred(AccessLogHook hook, Map record) {} + + /** + * Open a scope on the current thread, replacing any scope already installed. + * + * @param requestId per-request correlation id the records should carry; may be {@code null} + * @return the scope; close it (ideally via try-with-resources) to emit the parked records + */ + public static AccessLogScope open(String requestId) { + AccessLogScope scope = new AccessLogScope(requestId); + CURRENT.set(scope); + return scope; + } + + /** + * The scope installed on the current thread. + * + * @return the current scope, or {@code null} when the transport installs none + */ + public static AccessLogScope current() { + return CURRENT.get(); + } + + /** + * Record the on-wire size of the request body, before decompression — + * what the peer actually sent. No-op when no scope is installed. + * + * @param bytes number of bytes read off the socket + */ + public static void recordRequestBytes(long bytes) { + AccessLogScope scope = CURRENT.get(); + if (scope != null) scope.requestBytes = bytes; + } + + /** + * Record the on-wire size of the response body, after compression. + * No-op when no scope is installed. + * + * @param bytes number of bytes written to the socket + */ + public static void recordResponseBytes(long bytes) { + AccessLogScope scope = CURRENT.get(); + if (scope != null) scope.responseBytes = bytes; + } + + /** + * Add bytes uploaded to external storage during this call. Counted at the + * single upload choke point so a new upload path cannot drift from the + * total. No-op when no scope is installed. + * + * @param bytes size of the payload handed to {@code ExternalStorage.upload} + */ + public static void countExternalized(long bytes) { + AccessLogScope scope = CURRENT.get(); + if (scope != null) scope.externalizedBytes += bytes; + } + + /** + * Set the response status the records should report. + * + * @param status HTTP status code of the response + */ + public void httpStatus(int status) { + this.httpStatus = status; + } + + /** @return the request correlation id, or {@code ""} when the transport minted none */ + String requestId() { + return requestId; + } + + /** @return on-wire request size, or a negative value when it was never measured */ + long requestBytes() { + return requestBytes; + } + + /** @return bytes uploaded to external storage so far during this call */ + long externalizedBytes() { + return externalizedBytes; + } + + /** Park a record until the response has been measured. */ + void defer(AccessLogHook hook, Map record) { + if (deferred == null) deferred = new ArrayList<>(2); + deferred.add(new Deferred(hook, record)); + } + + /** Stamp the egress figures known only now, emit, and uninstall the scope. */ + @Override + public void close() { + CURRENT.remove(); + if (deferred == null) return; + for (Deferred d : deferred) { + if (responseBytes >= 0) d.record().put("response_bytes", responseBytes); + // The schema constrains this to a real status code, so a response + // that never got one is better left unreported than guessed at. + if (httpStatus >= 100 && httpStatus <= 599) d.record().put("http_status", httpStatus); + d.hook().write(d.record()); + } + deferred = null; + } +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/ClaimRedactor.java b/vgirpc/src/main/java/farm/query/vgirpc/ClaimRedactor.java new file mode 100644 index 0000000..65dbc66 --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/ClaimRedactor.java @@ -0,0 +1,83 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc; + +import java.util.LinkedHashMap; +import java.util.Map; +import java.util.regex.Pattern; + +/** + * Decides what a call's authentication claims look like once they reach the + * access log. + * + *

An access log outlives the token it describes by months or years and is + * shipped to systems chosen for searchability rather than for holding personal + * data, so standard OIDC claims ({@code email}, {@code phone_number}, + * {@code given_name}, …) and credential-shaped ones ({@code *_token}, + * {@code *_key}, {@code password}) must not reach it verbatim. + * + *

Redaction is key-based: a value is matched on the name it + * arrived under, never on its content. A claim called {@code context} holding an + * email address is not caught, and cannot be without guessing at free text — a + * boundary worth stating rather than pretending to exceed. + */ +@FunctionalInterface +public interface ClaimRedactor { + + /** Placeholder substituted for a sensitive claim value. */ + String REDACTED = "[redacted]"; + + /** + * Return what should be logged for {@code claims}. + * + * @param claims the authenticated principal's raw claims; never {@code null} + * @return the claims to log; implementations should return a fresh map rather + * than mutating the argument + */ + Map redact(Map claims); + + /** + * Names whose values are replaced: credentials first, then the standard OIDC + * claims that are personal data. + * + *

{@code ^name$} is anchored because {@code name} alone is PII while + * {@code token_name} and friends are already caught by the credential half. + */ + Pattern SENSITIVE_CLAIM_NAMES = Pattern.compile( + "password|token|secret|key|authorization" + + "|email|phone|address|birthdate|gender" + + "|^name$|given_name|family_name|middle_name|nickname|preferred_username" + + "|picture|profile|website", + Pattern.CASE_INSENSITIVE); + + /** + * The default policy: replace sensitive values, keep every key. + * + *

Values are replaced rather than dropped because which claims a + * credential carried is a question an audit log exists to answer; what they + * contained is not. + * + * @return a redactor that substitutes {@link #REDACTED} for values whose key + * matches {@link #SENSITIVE_CLAIM_NAMES} + */ + static ClaimRedactor byKeyName() { + return claims -> { + Map out = new LinkedHashMap<>(claims.size()); + for (Map.Entry e : claims.entrySet()) { + out.put(e.getKey(), + SENSITIVE_CLAIM_NAMES.matcher(e.getKey()).find() ? REDACTED : e.getValue()); + } + return out; + }; + } + + /** + * Pass claims through verbatim. Only for logs a service owns end to end. + * + * @return a redactor that copies the claims unchanged + */ + static ClaimRedactor none() { + return LinkedHashMap::new; + } +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/DispatchInfo.java b/vgirpc/src/main/java/farm/query/vgirpc/DispatchInfo.java index 402c002..db48041 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/DispatchInfo.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/DispatchInfo.java @@ -46,6 +46,8 @@ public final class DispatchInfo { public boolean cancelled; /** Transport-level request metadata (e.g. HTTP headers) captured by the auth scope; may be null. */ public Map transportMetadata; + /** Raw claims of the authenticated principal; may be null or empty. Redacted by the emitter, not here. */ + public Map claims; /** Sticky-session id (hex), or null when no session was bound. */ public String sessionId; diff --git a/vgirpc/src/main/java/farm/query/vgirpc/RpcServer.java b/vgirpc/src/main/java/farm/query/vgirpc/RpcServer.java index c6a42d5..98b7893 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/RpcServer.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/RpcServer.java @@ -23,6 +23,7 @@ import farm.query.vgirpc.wire.Metadata; import farm.query.vgirpc.wire.Wire; import org.apache.arrow.vector.VectorSchemaRoot; +import org.apache.arrow.vector.dictionary.DictionaryProvider; import org.apache.arrow.vector.types.pojo.ArrowType; import org.apache.arrow.vector.types.pojo.Field; import org.apache.arrow.vector.types.pojo.Schema; @@ -219,11 +220,16 @@ private static final class EndOfStream extends RuntimeException {} *

Best-effort: returns {@code null} on any failure so observability never fails * dispatch. */ - private static byte[] serializeRequestBatch(VectorSchemaRoot root, Map meta) { + private static byte[] serializeRequestBatch(VectorSchemaRoot root, Map meta, + DictionaryProvider dictionaries) { try { ByteArrayOutputStream baos = new ByteArrayOutputStream(); try (IpcStreamWriter w = new IpcStreamWriter(baos)) { - w.writeBatch(root, meta); + // Dictionary-encoded params (enums) need their dictionary batches + // in the stream, or the writer refuses and the record loses + // request_data entirely — which the access-log schema reads as a + // missing required property on every enum-taking method. + w.writeBatch(root, meta, dictionaries); w.writeEos(); } return baos.toByteArray(); @@ -358,8 +364,13 @@ private void serveOne(RpcTransport transport, ShmSession shmSession) { dispatchInfo.principal = scope.auth() != null && scope.auth().principal() != null ? scope.auth().principal() : ""; dispatchInfo.authDomain = scope.auth() != null && scope.auth().domain() != null ? scope.auth().domain() : ""; dispatchInfo.authenticated = scope.auth() != null && scope.auth().authenticated(); + dispatchInfo.claims = scope.auth() != null ? scope.auth().claims() : null; dispatchInfo.transportMetadata = scope.transportMetadata(); - dispatchInfo.requestData = serializeRequestBatch(paramsRoot, meta); + // Same provider choice the kwargs decode made above: a + // resolved external batch carries its own schema and no + // reader dictionaries. + dispatchInfo.requestData = serializeRequestBatch(paramsRoot, meta, + resolvedParams != null ? null : reader.dictionaryProvider()); if ("stream".equals(dispatchInfo.methodType)) { dispatchInfo.streamId = AccessLogHook.randomStreamId(); } diff --git a/vgirpc/src/main/java/farm/query/vgirpc/TraceCorrelator.java b/vgirpc/src/main/java/farm/query/vgirpc/TraceCorrelator.java new file mode 100644 index 0000000..9b0f1ac --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/TraceCorrelator.java @@ -0,0 +1,107 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc; + +import java.lang.reflect.Method; + +/** + * Supplies the W3C trace and span ids of the span a call ran under, so an + * access-log record can be joined to the surrounding distributed trace. + * + *

{@code request_id} only correlates records within one service; without a + * trace id a log line and the span describing the same call cannot be matched. + * Implementations read from whatever span is current rather than from + * anything the framework threads through, so a record correlates with an + * application-opened span as readily as a framework-opened one. + */ +@FunctionalInterface +public interface TraceCorrelator { + + /** + * The trace context of the span currently in scope. + * + * @return a two-element array {@code {traceId, spanId}} as lowercase hex (32 + * and 16 characters), or {@code null} when no valid span is current. + * Must not throw: an observability failure must not surface as a + * request failure. + */ + String[] current(); + + /** + * A correlator that never reports a trace. + * + * @return a correlator returning {@code null} + */ + static TraceCorrelator none() { + return () -> null; + } + + /** + * Read the current OpenTelemetry span, reflectively. + * + *

OpenTelemetry is not a dependency of this module — the same split that + * keeps {@code nimbus-jose-jwt} in {@code vgirpc-oauth} — so the API is + * resolved by reflection once at class-load and cached as absent when it + * isn't on the classpath. A per-call lookup would be the most expensive + * thing on the common path, where OTel is not installed. + * + * @return a correlator reading {@code io.opentelemetry.api.trace.Span.current()}, + * degrading to {@link #none()} behaviour when OpenTelemetry is absent + */ + static TraceCorrelator openTelemetry() { + return Otel.INSTANCE; + } + + /** Reflective OpenTelemetry accessor, resolved once. */ + final class Otel implements TraceCorrelator { + + static final Otel INSTANCE = new Otel(); + + private static final Method SPAN_CURRENT; + private static final Method GET_SPAN_CONTEXT; + private static final Method IS_VALID; + private static final Method GET_TRACE_ID; + private static final Method GET_SPAN_ID; + + static { + Method current = null; + Method spanContext = null; + Method valid = null; + Method traceId = null; + Method spanId = null; + try { + Class span = Class.forName("io.opentelemetry.api.trace.Span"); + Class ctx = Class.forName("io.opentelemetry.api.trace.SpanContext"); + current = span.getMethod("current"); + spanContext = span.getMethod("getSpanContext"); + valid = ctx.getMethod("isValid"); + traceId = ctx.getMethod("getTraceId"); + spanId = ctx.getMethod("getSpanId"); + } catch (ReflectiveOperationException | RuntimeException e) { + current = null; + } + SPAN_CURRENT = current; + GET_SPAN_CONTEXT = spanContext; + IS_VALID = valid; + GET_TRACE_ID = traceId; + GET_SPAN_ID = spanId; + } + + private Otel() {} + + /** {@inheritDoc} */ + @Override + public String[] current() { + if (SPAN_CURRENT == null) return null; + try { + Object ctx = GET_SPAN_CONTEXT.invoke(SPAN_CURRENT.invoke(null)); + if (ctx == null || !Boolean.TRUE.equals(IS_VALID.invoke(ctx))) return null; + return new String[] {(String) GET_TRACE_ID.invoke(ctx), (String) GET_SPAN_ID.invoke(ctx)}; + } catch (ReflectiveOperationException | RuntimeException e) { + // Defensive: OTel API shape drift must not fail a request. + return null; + } + } + } +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/external/Externalizer.java b/vgirpc/src/main/java/farm/query/vgirpc/external/Externalizer.java index 7367772..3b02251 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/external/Externalizer.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/external/Externalizer.java @@ -4,6 +4,7 @@ package farm.query.vgirpc.external; import com.github.luben.zstd.Zstd; +import farm.query.vgirpc.AccessLogScope; import farm.query.vgirpc.wire.Allocators; import farm.query.vgirpc.wire.IpcStreamWriter; import farm.query.vgirpc.wire.Metadata; @@ -71,6 +72,11 @@ public static Pointer maybeExternalize(VectorSchemaRoot root, contentEncoding = "zstd"; } + // Counted here rather than at the call sites: this is the one place every + // externalised payload passes through, so a new upload path cannot drift + // from the total. These bytes never appear in the HTTP body — only the + // pointer batch below does — so nothing at the transport can see them. + AccessLogScope.countExternalized(uploadBody.length); URI url = config.storage().upload(uploadBody, contentEncoding); // Build a zero-row pointer root with the same schema. diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/AuthException.java b/vgirpc/src/main/java/farm/query/vgirpc/http/AuthException.java index df16c0b..01d0775 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/http/AuthException.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/AuthException.java @@ -4,15 +4,23 @@ package farm.query.vgirpc.http; /** - * Base for authenticator failures. Sealed so {@code HttpServer.writeAuthFailure} - * can dispatch on subtype if it ever needs to distinguish 401 reasons. + * Base for authenticator failures. Sealed so the 401 renderer can dispatch on + * subtype to recover the {@link AuthReason} it reports. * *

Throwers should pick a concrete subtype: * {@link MissingCredentials} for absent headers / cookies, - * {@link InvalidCredentials} for malformed, unverifiable, or rejected values.

+ * {@link InvalidCredentials} for malformed, unverifiable, or rejected values, + * {@link AuthFailure} for anything else — including a reason this hierarchy + * has no dedicated type for.

+ * + *

Every subtype means rejected, and every one renders as a 401. An + * authenticator that could not reach its authority has not rejected anything + * and must throw {@link AuthUnavailableException} instead, which is outside + * this hierarchy precisely so the chain propagates it rather than reading it as + * "not my credential, try the next".

*/ public abstract sealed class AuthException extends Exception - permits MissingCredentials, InvalidCredentials { + permits MissingCredentials, InvalidCredentials, AuthFailure { /** Optional challenge value for the {@code WWW-Authenticate} response header. */ private final String wwwAuthenticate; @@ -34,4 +42,17 @@ protected AuthException(String message, String wwwAuthenticate) { * @return the challenge string supplied at construction, or {@code null} if none */ public final String wwwAuthenticate() { return wwwAuthenticate; } + + /** + * The reason code this failure reports on the wire. + * + *

The subtype is the classification — a thrower choosing + * {@link MissingCredentials} has already declared that nothing was + * presented — so this reads it off the type rather than inspecting the + * message, which would misclassify the moment someone rewords a string. + * The base answer is the unclassified fallback.

+ * + * @return a code from the closed set of {@link AuthReason} + */ + public AuthReason reason() { return AuthReason.UNAUTHORIZED; } } diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/AuthFailure.java b/vgirpc/src/main/java/farm/query/vgirpc/http/AuthFailure.java new file mode 100644 index 0000000..88b07cc --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/AuthFailure.java @@ -0,0 +1,55 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +/** + * An authentication rejection that names its own {@link AuthReason}. + * + *

{@link MissingCredentials} and {@link InvalidCredentials} cover the two + * stages common enough to deserve a type; this covers the rest — an expired + * token, an identified caller without the scope, a proxy-dependent gate — and + * gives a custom {@link Authenticator} a way to state a code the framework + * could not otherwise know.

+ * + *

Constructed without a reason it reports {@link AuthReason#UNAUTHORIZED}. + * That is the honest answer for a rejection that names nothing: inferring a + * finer code would mean matching on message text, which misclassifies the + * moment someone rewords a string.

+ */ +public final class AuthFailure extends AuthException { + + private static final long serialVersionUID = 1L; + + private final AuthReason reason; + + /** + * Create an unclassified failure. + * + * @param message diagnostic message surfaced as the envelope's {@code detail} + */ + public AuthFailure(String message) { this(AuthReason.UNAUTHORIZED, message, null); } + + /** + * Create a failure carrying a reason code. + * + * @param reason the code reported on the wire + * @param message diagnostic message surfaced as the envelope's {@code detail}; + * free text, but never a verifier's per-attempt state + */ + public AuthFailure(AuthReason reason, String message) { this(reason, message, null); } + + /** + * Create a failure carrying a reason code and a challenge. + * + * @param reason the code reported on the wire + * @param message diagnostic message surfaced as the envelope's {@code detail} + * @param wwwAuthenticate value for the {@code WWW-Authenticate} challenge header, or {@code null} + */ + public AuthFailure(AuthReason reason, String message, String wwwAuthenticate) { + super(message, wwwAuthenticate); + this.reason = reason != null ? reason : AuthReason.UNAUTHORIZED; + } + + @Override public AuthReason reason() { return reason; } +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/AuthReason.java b/vgirpc/src/main/java/farm/query/vgirpc/http/AuthReason.java new file mode 100644 index 0000000..af081bf --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/AuthReason.java @@ -0,0 +1,66 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +/** + * The closed set of machine-readable codes a 401 may carry, per + * {@code docs/unauthorized-spec.md} §3 in the vgi-rpc reference repository. + * + *

A code names the stage that refused the request, never a + * verifier's internal diagnosis: telling a caller their token expired is a + * fact about something they hold, telling them which key id failed to resolve + * turns the rejection into an oracle. Every proxy-proof outcome therefore + * collapses onto {@link #PROXY_REQUIRED}.

+ * + *

The set is closed so a client can switch on it — refresh a token on + * {@link #EXPIRED_CREDENTIAL}, give up on {@link #INSUFFICIENT_SCOPE} — without + * the set growing under it in a language it does not control. A failure that + * maps onto none of these uses {@link #UNAUTHORIZED}; readers must treat an + * unrecognised code the same way, since that means the server is newer, not + * broken.

+ */ +public enum AuthReason { + + /** No credential was presented at all. */ + MISSING_CREDENTIAL("missing_credential"), + + /** A credential was presented and rejected. */ + INVALID_CREDENTIAL("invalid_credential"), + + /** A well-formed credential outside its validity window. */ + EXPIRED_CREDENTIAL("expired_credential"), + + /** + * The caller was identified but is not permitted. + * + *

Deliberately a 401 rather than a 403: the authenticator runs before + * any method is resolved, so there is no route yet whose permissions could + * be evaluated. A service wanting a true 403 raises it from the method + * body.

+ */ + INSUFFICIENT_SCOPE("insufficient_scope"), + + /** + * The request carried no evidence of having arrived through the trusted + * proxy. Derived from server configuration, never from the request — see + * {@link HttpServer.Config.Builder#proxyAuthHeaders(java.util.List)}. + */ + PROXY_REQUIRED("proxy_required"), + + /** Refused, unclassified. The fallback. */ + UNAUTHORIZED("unauthorized"); + + private final String code; + + AuthReason(String code) { this.code = code; } + + /** + * The wire spelling carried by {@code VGI-Auth-Reason} and the JSON envelope. + * + * @return the lower-snake-case code + */ + public String code() { return code; } + + @Override public String toString() { return code; } +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/AuthUnavailableException.java b/vgirpc/src/main/java/farm/query/vgirpc/http/AuthUnavailableException.java new file mode 100644 index 0000000..1aafece --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/AuthUnavailableException.java @@ -0,0 +1,77 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +/** + * An authenticator could not answer. Not a rejection. + * + *

"The credential is bad" and "I could not find out whether the credential + * is bad" are different answers, and collapsing them is expensive in both + * directions. An identity sidecar restarting that surfaces as 401 makes every + * caller re-authenticate at once — the DuckDB extension treats a second 401 + * after a refresh as fatal, so a thirty-second blip becomes a fleet-wide + * re-login storm — and a caller that negative-caches rejections will cache the + * outage along with them. + * + *

Deliberately outside the {@link AuthException} hierarchy, which is + * the whole point. Every {@code AuthException} subtype names a + * {@link AuthReason} and renders as a 401, and + * {@link Authenticator#chain(Authenticator...)} catches {@code AuthException} to + * mean "not my credential, try the next" — so an outage raised as one would be + * swallowed and emerge as a 401 from the end of the chain. Unchecked so it + * needs no signature change on {@link Authenticator#authenticate}, and + * uncaught by the chain so it propagates to the request boundary, which renders + * {@code 503} with {@code Retry-After}. + * + *

Raise it for transport failures, timeouts, and 5xx from a remote authority. + * Never for a credential the authority actually answered about. + */ +public final class AuthUnavailableException extends RuntimeException { + + private static final long serialVersionUID = 1L; + + /** Short by design: a hint to retry, not a backoff schedule. */ + public static final int DEFAULT_RETRY_AFTER_SECONDS = 5; + + private final int retryAfterSeconds; + + /** + * Create a transient-failure signal with the default retry hint. + * + * @param message operator-facing text; must never contain the credential + */ + public AuthUnavailableException(String message) { + this(message, DEFAULT_RETRY_AFTER_SECONDS, null); + } + + /** + * Create a transient-failure signal wrapping the underlying fault. + * + * @param message operator-facing text; must never contain the credential + * @param cause the transport failure or timeout that prevented an answer + */ + public AuthUnavailableException(String message, Throwable cause) { + this(message, DEFAULT_RETRY_AFTER_SECONDS, cause); + } + + /** + * Create a transient-failure signal with an explicit retry hint. + * + * @param message operator-facing text; must never contain the credential + * @param retryAfterSeconds seconds advertised in {@code Retry-After}; values + * below 1 are clamped up, since {@code Retry-After: 0} invites a hot loop + * @param cause the underlying fault, or {@code null} + */ + public AuthUnavailableException(String message, int retryAfterSeconds, Throwable cause) { + super(message != null && !message.isEmpty() ? message : "authentication service unavailable", cause); + this.retryAfterSeconds = Math.max(1, retryAfterSeconds); + } + + /** + * Seconds to advertise in the {@code Retry-After} response header. + * + * @return the retry hint, always {@code >= 1} + */ + public int retryAfterSeconds() { return retryAfterSeconds; } +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/Authenticator.java b/vgirpc/src/main/java/farm/query/vgirpc/http/Authenticator.java index a9b99dd..f093ce4 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/http/Authenticator.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/Authenticator.java @@ -41,6 +41,12 @@ public interface Authenticator { * authenticated context. Unauthenticated (anonymous) results fall through * to the next chain member. Mirrors Python's {@code chain_authenticate}. * + *

Only {@link AuthException} means "not my credential, try the next". + * {@link AuthUnavailableException} propagates: an authority that could not + * be reached is not a rejection, and swallowing it here would turn a sidecar + * restart into a 401 from the end of the chain — which every caller answers + * by re-authenticating at once. + * * @param authenticators chain members, tried in order * @return a composite authenticator that returns the first authenticated * context, rethrows the last {@link AuthException} if every member diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/CallStateCache.java b/vgirpc/src/main/java/farm/query/vgirpc/http/CallStateCache.java new file mode 100644 index 0000000..7a9a3b7 --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/CallStateCache.java @@ -0,0 +1,86 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +import java.util.HexFormat; +import java.util.LinkedHashMap; +import java.util.Map; + +/** + * Bounded, thread-safe LRU of {@code callId} → {@link CallToken}. + * + *

A pure accelerator: a miss (cold process, evicted entry, request landing + * on a different node) falls back to opening the call token the client + * supplied, so statelessness is preserved and no request depends on a prior + * request having warmed anything.

+ * + *

The key pairs the {@code callId} recovered from inside the + * cursor's ciphertext with the caller's principal. Both parts are + * authenticated before the lookup happens, so a client can neither steer a + * lookup toward another principal's entry nor present a {@code callId} the + * server never minted.

+ */ +final class CallStateCache { + + /** Entry ceiling when the operator states none. */ + static final int DEFAULT_MAX_ENTRIES = 4096; + + private final long ttlSeconds; + /** {@code null} when the cache is disabled. */ + private final Map entries; + + private record CachedCall(long expiresAt, CallToken call) { + } + + CallStateCache(long ttlSeconds) { + this(ttlSeconds, DEFAULT_MAX_ENTRIES); + } + + /** + * @param maxEntries entry ceiling; {@code <= 0} disables the cache + * entirely, so every continuation takes the miss path. That is not + * just a memory knob: it is what turns "the client forgot to echo its + * call token" from a bug that only shows up on a cold node into a + * deterministic failure, which is how the conformance suite pins the + * stateless-relay contract. + */ + CallStateCache(long ttlSeconds, int maxEntries) { + this.ttlSeconds = ttlSeconds > 0 ? ttlSeconds : 3600; + final int cap = maxEntries; + this.entries = cap <= 0 ? null : new LinkedHashMap<>(64, 0.75f, true) { + @Override + protected boolean removeEldestEntry(Map.Entry eldest) { + return size() > cap; + } + }; + } + + private static String key(byte[] callId, String principal) { + return HexFormat.of().formatHex(callId) + "\0" + (principal != null ? principal : ""); + } + + synchronized CallToken get(byte[] callId, String principal) { + if (entries == null) { + return null; + } + String k = key(callId, principal); + CachedCall e = entries.get(k); + if (e == null) { + return null; + } + if (System.currentTimeMillis() / 1000 > e.expiresAt()) { + entries.remove(k); + return null; + } + return e.call(); + } + + synchronized void put(byte[] callId, String principal, CallToken call) { + if (entries == null) { + return; + } + entries.put(key(callId, principal), + new CachedCall(System.currentTimeMillis() / 1000 + ttlSeconds, call)); + } +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/CallToken.java b/vgirpc/src/main/java/farm/query/vgirpc/http/CallToken.java new file mode 100644 index 0000000..1ad98e6 --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/CallToken.java @@ -0,0 +1,155 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +import farm.query.vgirpc.http.auth.Crypto; + +import java.nio.ByteBuffer; +import java.nio.ByteOrder; +import java.nio.charset.StandardCharsets; +import java.util.Base64; + +/** + * The half of a stream's state that is fixed for the life of the call: the + * resolved schemas and the stream id, plus the {@code callId} that binds this + * call to its cursors. + * + *

Minted once, by {@code /init}, under {@code vgi_rpc.call_state#b64}, and + * never re-issued — only {@link StateToken}, the cursor, + * comes back per turn. The client echoes it on every subsequent request: the + * server may resolve the call from a per-process cache while one is warm, but + * a continuation landing on a process that never saw the {@code /init} has + * only the client's copy to work from.

+ * + *

Wire format (v1): + * 

+ *   base64(
+ *     [1 byte:   version = 1]
+ *     [12 bytes: ChaCha20-Poly1305 nonce (random)]
+ *     [..]       ciphertext + Poly1305 tag
+ *                sealed payload:
+ *                  [1 byte:  codec — 0x00 raw, 0x01 zstd]
+ *                  [..]      the plaintext below, compressed per codec
+ *                plaintext:
+ *                  [8 bytes: created_at uint64 LE]
+ *                  [16 bytes: call_id]
+ *                  [4 bytes: schema_len LE]       [output_schema bytes]
+ *                  [4 bytes: input_schema_len LE] [input_schema bytes]
+ *                  [4 bytes: stream_id_len LE]    [stream_id utf8]
+ *   )
+ *
+ */ +public record CallToken( + byte[] outputSchema, + byte[] inputSchema, + String streamId, + byte[] callId, + long createdAt) { + + private static final byte VERSION = 1; + private static final int VERSION_LEN = 1; + + /** + * Prefix mixed into AEAD AAD. Distinct from the cursor's, so a call token + * and a cursor token are not interchangeable even for the same principal. + */ + private static final byte[] AAD_PREFIX = "vgi_rpc.call.v1\0".getBytes(StandardCharsets.UTF_8); + + public CallToken { + outputSchema = outputSchema.clone(); + inputSchema = inputSchema.clone(); + callId = callId.clone(); + streamId = streamId != null ? streamId : ""; + } + + @Override public byte[] outputSchema() { return outputSchema.clone(); } + @Override public byte[] inputSchema() { return inputSchema.clone(); } + @Override public byte[] callId() { return callId.clone(); } + + /** Serialise, AEAD-seal, and base64-encode the token. */ + public byte[] pack(byte[] tokenKey, String principal) { + byte[] streamIdBytes = streamId.getBytes(StandardCharsets.UTF_8); + int payloadLen = 8 + Tokens.CALL_ID_LEN + + 4 + outputSchema.length + + 4 + inputSchema.length + + 4 + streamIdBytes.length; + ByteBuffer payload = ByteBuffer.allocate(payloadLen).order(ByteOrder.LITTLE_ENDIAN); + payload.putLong(createdAt); + payload.put(callId); + putSegment(payload, outputSchema); + putSegment(payload, inputSchema); + putSegment(payload, streamIdBytes); + byte[] sealed = Crypto.chacha20Poly1305Seal( + tokenKey, Tokens.packPayload(payload.array()), Tokens.aad(AAD_PREFIX, principal)); + byte[] wire = new byte[VERSION_LEN + sealed.length]; + wire[0] = VERSION; + System.arraycopy(sealed, 0, wire, VERSION_LEN, sealed.length); + return Base64.getEncoder().encode(wire); + } + + /** + * Decode + open + unpack. Every tampering, wrong-key, or AAD-mismatch + * failure surfaces as the same uniform "signature" message so callers + * cannot distinguish failure modes via timing or content. TTL disabled + * when {@code ttlSeconds <= 0}. + */ + public static CallToken unpack(byte[] b64, byte[] tokenKey, long ttlSeconds, String principal) { + byte[] raw; + try { + raw = Base64.getDecoder().decode(b64); + } catch (IllegalArgumentException e) { + throw new IllegalArgumentException("Malformed state token", e); + } + if (raw.length < VERSION_LEN + Crypto.AEAD_NONCE_LEN + Crypto.AEAD_TAG_LEN) { + throw new IllegalArgumentException("Malformed state token"); + } + if (raw[0] != VERSION) { + throw new IllegalArgumentException("Unsupported call token version " + raw[0] + + " (expected " + VERSION + ")"); + } + byte[] sealed = new byte[raw.length - VERSION_LEN]; + System.arraycopy(raw, VERSION_LEN, sealed, 0, sealed.length); + byte[] opened; + try { + opened = Crypto.chacha20Poly1305Open(tokenKey, sealed, Tokens.aad(AAD_PREFIX, principal)); + } catch (IllegalArgumentException e) { + throw new IllegalArgumentException("State token signature verification failed", e); + } + // Decompress only after authentication: nothing an attacker supplies + // reaches the decoder without the token key. + byte[] plaintext = Tokens.unpackPayload(opened); + if (plaintext.length < 8 + Tokens.CALL_ID_LEN) { + throw new IllegalArgumentException("Malformed state token"); + } + ByteBuffer bb = ByteBuffer.wrap(plaintext).order(ByteOrder.LITTLE_ENDIAN); + long createdAt = bb.getLong(); + byte[] callId = new byte[Tokens.CALL_ID_LEN]; + bb.get(callId); + if (ttlSeconds > 0) { + long now = System.currentTimeMillis() / 1000; + if (now - createdAt > ttlSeconds) { + throw new TokenExpiredException("Call token expired (age=" + (now - createdAt) + + "s, ttl=" + ttlSeconds + "s)"); + } + } + byte[] outputSchema = getSegment(bb); + byte[] inputSchema = getSegment(bb); + byte[] streamIdBytes = getSegment(bb); + return new CallToken(outputSchema, inputSchema, + new String(streamIdBytes, StandardCharsets.UTF_8), callId, createdAt); + } + + private static void putSegment(ByteBuffer b, byte[] seg) { + b.putInt(seg.length); + b.put(seg); + } + + private static byte[] getSegment(ByteBuffer b) { + int len = b.getInt(); + if (len < 0 || len > b.remaining()) throw new IllegalArgumentException("Malformed segment"); + byte[] out = new byte[len]; + b.get(out); + return out; + } +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/CorsPolicy.java b/vgirpc/src/main/java/farm/query/vgirpc/http/CorsPolicy.java new file mode 100644 index 0000000..73071ae --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/CorsPolicy.java @@ -0,0 +1,138 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +import farm.query.vgirpc.http.auth.ProxyProof; +import jakarta.servlet.http.HttpServletRequest; +import jakarta.servlet.http.HttpServletResponse; + +import java.util.ArrayList; +import java.util.List; +import java.util.Locale; + +/** + * The CORS half of the HTTP transport: which browsers may call this worker, + * and which of its response headers they are allowed to read. + * + *

Every capability this framework has over HTTP rides on a response header + * — the size caps, the codec set, the sticky advert, the 401 reason code, the + * {@code X-VGI-RPC-Error} flag. A browser hides all of them from JavaScript + * unless the server names them in {@code Access-Control-Expose-Headers}, so + * the expose list is built in lockstep with + * {@code HttpServer.applyCapabilityHeaders}: whatever this server advertises, + * it exposes. Cross-language conformance group: {@code TestCors}. + * + *

Strictly opt-in — an unconfigured server has no policy at all and emits + * no CORS header on any response ({@code TestCorsOffMode}). + */ +final class CorsPolicy { + + static final String ORIGIN = "Origin"; + static final String ALLOW_ORIGIN = "Access-Control-Allow-Origin"; + static final String ALLOW_METHODS = "Access-Control-Allow-Methods"; + static final String ALLOW_HEADERS = "Access-Control-Allow-Headers"; + static final String EXPOSE_HEADERS = "Access-Control-Expose-Headers"; + static final String MAX_AGE = "Access-Control-Max-Age"; + static final String REQUEST_HEADERS = "Access-Control-Request-Headers"; + static final String RESOURCE_POLICY = "Cross-Origin-Resource-Policy"; + + /** The wildcard origin, allowed because this server never sets + * {@code Access-Control-Allow-Credentials} (vgi-rpc auth is header-borne, + * never cookie-borne), so a wildcard grants no ambient authority. */ + static final String WILDCARD = "*"; + + /** Every method the router answers. GET and DELETE are here because health, + * {@code describe.json} and session close are as much part of the browser + * surface as the RPC POST is. */ + private static final String ALLOW_METHODS_VALUE = "GET, POST, DELETE, OPTIONS"; + + /** Answer for a preflight that named no headers — the request-side surface + * a browser client actually needs. Real preflights always name headers and + * take the echo path below. */ + private static final String DEFAULT_ALLOW_HEADERS = String.join(", ", List.of( + HttpHeaders.CONTENT_TYPE, + HttpHeaders.AUTHORIZATION, + HttpHeaders.API_KEY, + HttpHeaders.X_VGI_ACCEPT_ENCODING, + StickyHeaders.SESSION, + StickyHeaders.SESSION_ACCEPT, + ProxyProof.PROOF_HEADER)); + + /** Lowercased for the case-insensitive origin match; empty when {@link #wildcard}. */ + private final List origins; + private final boolean wildcard; + private final String exposeHeaders; + /** Rendered {@code Access-Control-Max-Age} value, or {@code null} to omit it. */ + private final String maxAge; + + /** + * @param origins allowed origins; a single {@code "*"} entry allows all + * @param maxAgeSeconds preflight cache lifetime; {@code 0} omits the header + * @param exposeHeaders response headers a browser may read, already deduped + */ + CorsPolicy(List origins, long maxAgeSeconds, List exposeHeaders) { + List normalized = new ArrayList<>(); + boolean any = false; + for (String o : origins) { + String trimmed = o.trim(); + if (trimmed.isEmpty()) continue; + if (WILDCARD.equals(trimmed)) any = true; + else normalized.add(trimmed.toLowerCase(Locale.ROOT)); + } + if (!any && normalized.isEmpty()) { + throw new IllegalArgumentException("corsOrigins must name at least one origin"); + } + this.wildcard = any; + this.origins = List.copyOf(normalized); + this.exposeHeaders = String.join(", ", exposeHeaders); + this.maxAge = maxAgeSeconds > 0 ? Long.toString(maxAgeSeconds) : null; + } + + /** + * Stamp the CORS headers for {@code req} onto {@code resp}, if the request + * came from an allowed origin. + * + *

Applied to every response, not just the preflight: a browser re-checks + * {@code Access-Control-Allow-Origin} on the actual response and discards + * the body without it, so a preflight-only implementation fails every real + * call while looking correct from a test client. + */ + void apply(HttpServletRequest req, HttpServletResponse resp) { + String origin = req.getHeader(ORIGIN); + if (origin == null || origin.isBlank()) return; // same-origin request: nothing to grant + String allow = resolve(origin); + if (allow == null) return; + + resp.setHeader(ALLOW_ORIGIN, allow); + if (!wildcard) { + // The answer depends on the request's Origin, so a shared cache that + // keyed only on the URL would hand one origin's grant to another. + resp.setHeader("Vary", ORIGIN); + } + resp.setHeader(ALLOW_METHODS, ALLOW_METHODS_VALUE); + // Echoing what the preflight asked for keeps any client-side header + // working without the server enumerating it — the same answer the Go, + // Rust and Python ports give. + String requested = req.getHeader(REQUEST_HEADERS); + resp.setHeader(ALLOW_HEADERS, + requested != null && !requested.isBlank() ? requested : DEFAULT_ALLOW_HEADERS); + resp.setHeader(EXPOSE_HEADERS, exposeHeaders); + // Opt into cross-origin embedding so the worker stays usable from + // cross-origin-isolated pages (COEP: require-corp) — e.g. browsers + // running multithreaded WASM against it. + resp.setHeader(RESOURCE_POLICY, "cross-origin"); + if (maxAge != null && "OPTIONS".equals(req.getMethod())) { + resp.setHeader(MAX_AGE, maxAge); + } + } + + /** The {@code Access-Control-Allow-Origin} value for {@code origin}, or {@code null} if it is not allowed. */ + private String resolve(String origin) { + if (wildcard) return WILDCARD; + return origins.contains(origin.trim().toLowerCase(Locale.ROOT)) ? origin : null; + } + + /** The exposed set, for tests and diagnostics. */ + String exposeHeaders() { return exposeHeaders; } +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/HttpHeaders.java b/vgirpc/src/main/java/farm/query/vgirpc/http/HttpHeaders.java index cc7acb8..3f3aff3 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/http/HttpHeaders.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/HttpHeaders.java @@ -14,6 +14,13 @@ private HttpHeaders() {} public static final String AUTHORIZATION = "Authorization"; public static final String WWW_AUTHENTICATE = "WWW-Authenticate"; + /** + * Per-request correlation id, echoed from the caller when supplied and + * generated otherwise. It is what ties a failure a client saw to this + * server's own log line for the same call, so it rides every response — + * including the error paths, which are the ones anybody looks up. + */ + public static final String REQUEST_ID = "X-Request-ID"; public static final String API_KEY = "X-API-Key"; public static final String USER_AGENT = "User-Agent"; public static final String CONTENT_TYPE = "Content-Type"; @@ -33,6 +40,14 @@ private HttpHeaders() {} * {@code Content-Encoding}, so the response must not claim one. */ public static final String X_VGI_CONTENT_ENCODING = "X-VGI-Content-Encoding"; + /** Carries one {@link AuthReason} on every 401. */ + public static final String VGI_AUTH_REASON = "VGI-Auth-Reason"; + + /** {@code "true"} on 401s from a service whose auth depends on a reverse + * proxy. Omitted otherwise — never {@code "false"}, since a note that + * appears everywhere is one operators learn to skip. */ + public static final String VGI_AUTH_PROXY_REQUIRED = "VGI-Auth-Proxy-Required"; + /** XFCC (Envoy / Istio forwarded client certificate) header. */ public static final String X_FORWARDED_CLIENT_CERT = "x-forwarded-client-cert"; /** Nginx/ingress alternative mTLS client-cert header. */ diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/HttpServer.java b/vgirpc/src/main/java/farm/query/vgirpc/http/HttpServer.java index df65753..249c42f 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/http/HttpServer.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/HttpServer.java @@ -5,6 +5,7 @@ import com.fasterxml.jackson.databind.ObjectMapper; import com.github.luben.zstd.Zstd; +import farm.query.vgirpc.AccessLogScope; import farm.query.vgirpc.AuthContext; import farm.query.vgirpc.AuthScope; import farm.query.vgirpc.CallContext; @@ -67,6 +68,8 @@ * stream (params). Response body is one Arrow IPC stream (result or error). *

  • {@code POST /vgi/{method}/init} and {@code /exchange} — streaming * endpoints.
    • + *
  • {@code POST /vgi/__introspect_token__} — opaque credential to principal; + * refuses definitively unless {@link TokenIntrospection} is configured.
    • * */ public final class HttpServer { @@ -160,6 +163,11 @@ private static byte[] loadLandingHtml() { * Advertisement only — the gate is an opaque {@link Authenticator}, so the * server has no way to read the posture back off it. */ private final boolean proxyProofRequired; + /** The §5 proxy note, or {@code ""} when this service's auth does not + * depend on a proxy. Computed once from configuration — never from what + * failed on a request — so every 401 this server emits says the same + * thing and none of them is an oracle. */ + private final String proxyHint; private final boolean stickyEnabled; private final long stickyDefaultTtlSeconds; private final Map stickyEchoHeaders; @@ -172,6 +180,13 @@ private static byte[] loadLandingHtml() { * advertisement, so none of the three can disagree. Empty = never * compress, and accept no compressed request bodies. */ private final List supportedEncodings; + /** The token-introspection endpoint, or {@code null} when no resolver was + * configured. Null is the load-bearing state: no worker grows a + * credential-to-identity oracle by upgrading a dependency. */ + private final TokenIntrospection introspection; + /** Browser access policy, or {@code null} when no origin was configured — + * CORS is opt-in, and off means not one {@code Access-Control-*} header. */ + private final CorsPolicy cors; private int port; /** @@ -193,7 +208,7 @@ public HttpServer(RpcServer rpc) { public HttpServer(RpcServer rpc, Config config) { this.rpc = rpc; this.streamHandler = new HttpStreamHandler(rpc, config.tokenKey(), - config.tokenTtlSeconds(), config.maxResponseBytes()); + config.tokenTtlSeconds(), config.maxResponseBytes(), config.callStateCacheMaxEntries()); this.authenticator = config.authenticator() != null ? config.authenticator() : Authenticator.ANONYMOUS; this.describeProvider = config.describeProvider(); this.preHandlers = config.preHandlers(); @@ -207,6 +222,14 @@ public HttpServer(RpcServer rpc, Config config) { this.advertisedMaxResponseBytes = config.advertisedMaxResponseBytes(); this.advertisedMaxExternalizedResponseBytes = config.advertisedMaxExternalizedResponseBytes(); this.proxyProofRequired = config.proxyProofRequired(); + // The proof gate contributes its header only in require mode: in allow + // mode an absent proof never denies, so the note would misdirect. + List proxyAuthHeaders = new ArrayList<>(); + if (config.proxyProofRequired()) proxyAuthHeaders.add(ProxyProof.PROOF_HEADER); + for (String h : config.proxyAuthHeaders()) { + if (!proxyAuthHeaders.contains(h)) proxyAuthHeaders.add(h); + } + this.proxyHint = Unauthorized.proxyHint(proxyAuthHeaders); this.stickyEnabled = config.stickyEnabled(); this.stickyDefaultTtlSeconds = config.stickyDefaultTtlSeconds(); this.stickyEchoHeaders = config.stickyEchoHeaders(); @@ -228,6 +251,14 @@ public HttpServer(RpcServer rpc, Config config) { this.sessionTokenKey = null; this.sessionRegistry = null; } + // Built before the CORS policy: corsExposeHeaders() reads this field, and + // the advertise/expose pair has to agree. + this.introspection = config.introspectResolver() == null ? null + : new TokenIntrospection(config.introspectResolver(), config.introspectPrincipals(), + config.introspectTtlSeconds(), config.introspectRateLimitPerSecond()); + this.cors = config.corsOrigins().isEmpty() + ? null + : new CorsPolicy(config.corsOrigins(), config.corsMaxAgeSeconds(), corsExposeHeaders()); this.jetty = new Server(); // Graceful-shutdown window: Jetty.stop() waits up to this many ms for // in-flight requests to finish before forcing closes. 15s is enough @@ -342,6 +373,22 @@ private static ServerConnector buildConnector(Server server, Config config) { * is an opaque {@link Authenticator}, so the server * cannot introspect the posture and the operator states * it. Default {@code false}. + * @param proxyAuthHeaders proxy-injected headers this service's + * authentication depends on, for a custom + * {@link Authenticator} the framework cannot + * introspect. Their presence is what turns on the + * §5 proxy note ({@code VGI-Auth-Proxy-Required} + + * {@code proxy_hint}) on every 401. The built-in + * proxy-proof gate contributes its own header via + * {@code proxyProofRequired}, so this is only + * needed on top of that. Default empty. + * @param callStateCacheMaxEntries entry ceiling for the per-process + * call-state cache — a pure accelerator, since a + * miss reopens the call token the client echoed. + * {@code 0} disables it, which is how a client that + * forgets to echo that token fails deterministically + * rather than only on a cold node. Default + * {@value CallStateCache#DEFAULT_MAX_ENTRIES}. * @param stickyEnabled enable opt-in HTTP sticky sessions: clients sending * {@code VGI-Session-Accept: true} get an HMAC-signed * session token bound to their principal, and calls @@ -361,6 +408,37 @@ private static ServerConnector buildConnector(Server server, Config config) { * {@code null} disables those routes (the shared * {@code landing.html} and JSON health status are * still served). + * @param corsOrigins origins allowed to call this server from a browser; + * empty (the default) leaves CORS off entirely — no + * {@code Access-Control-*} header on any response. A + * single {@code "*"} allows all. See + * {@link Builder#corsOrigins(List)}. + * @param corsMaxAgeSeconds preflight cache lifetime advertised via + * {@code Access-Control-Max-Age}; {@code 0} omits the + * header. Default + * {@value #DEFAULT_CORS_MAX_AGE_SECONDS}s. Ignored + * when {@code corsOrigins} is empty. + * @param introspectResolver enables {@code POST {prefix}/__introspect_token__}. + * This is the on/off switch: {@code null} (the + * default) leaves the endpoint refusing definitively + * and holding no resolver, so no worker grows a + * credential-to-identity oracle by upgrading a + * dependency. See {@link TokenIntrospection}. + * @param introspectPrincipals principals permitted to introspect. Required + * whenever {@code introspectResolver} is set, with + * no permissive default: authentication and + * introspection are different capabilities, and a + * deployment where any valid credential may introspect + * lets any user resolve any other user's credential to + * its owner. + * @param introspectTtlSeconds cache lifetime reported to the asker when a + * {@link TokenIdentity} names none. Default + * {@value TokenIntrospection#DEFAULT_TTL_SECONDS}s. + * @param introspectRateLimitPerSecond introspection requests allowed per + * caller per second (default + * {@value TokenIntrospection#DEFAULT_RATE_LIMIT_PER_SECOND}). + * Bounds, rather than closes, the oracle an + * allowlisted-but-compromised caller still has. */ public record Config( String host, @@ -382,14 +460,24 @@ public record Config( long advertisedMaxResponseBytes, long advertisedMaxExternalizedResponseBytes, boolean proxyProofRequired, + List proxyAuthHeaders, + int callStateCacheMaxEntries, boolean stickyEnabled, long stickyDefaultTtlSeconds, Map stickyEchoHeaders, boolean exposeTestDrainAdmin, - DescribeProvider describeProvider) { + DescribeProvider describeProvider, + List corsOrigins, + long corsMaxAgeSeconds, + TokenResolver introspectResolver, + List introspectPrincipals, + long introspectTtlSeconds, + int introspectRateLimitPerSecond) { /** 1 hour. */ public static final long DEFAULT_TOKEN_TTL_SECONDS = 3600; + /** 2 hours — the ceiling Chromium honours for a preflight cache entry. */ + public static final long DEFAULT_CORS_MAX_AGE_SECONDS = 7200; /** 16 MiB applies to both request body and serialized response. */ public static final long DEFAULT_MAX_BYTES = 16L << 20; /** 30 seconds. */ @@ -440,7 +528,10 @@ public static List defaultSupportedEncodings() { prefix = prefix != null ? prefix : ""; tokenKey = tokenKey != null ? tokenKey.clone() : null; preHandlers = preHandlers != null ? List.copyOf(preHandlers) : List.of(); + proxyAuthHeaders = proxyAuthHeaders != null ? List.copyOf(proxyAuthHeaders) : List.of(); stickyEchoHeaders = stickyEchoHeaders != null ? Map.copyOf(stickyEchoHeaders) : Map.of(); + corsOrigins = corsOrigins != null ? List.copyOf(corsOrigins) : List.of(); + introspectPrincipals = introspectPrincipals != null ? List.copyOf(introspectPrincipals) : List.of(); supportedEncodings = supportedEncodings != null ? normalizeEncodings(supportedEncodings) : defaultSupportedEncodings(); @@ -448,9 +539,27 @@ public static List defaultSupportedEncodings() { if (maxResponseBytes <= 0) throw new IllegalArgumentException("maxResponseBytes must be > 0"); if (idleTimeoutMs < 0) throw new IllegalArgumentException("idleTimeoutMs must be >= 0"); if (zstdLevel < 1 || zstdLevel > 22) throw new IllegalArgumentException("zstdLevel must be in [1, 22]"); + if (callStateCacheMaxEntries < 0) { + throw new IllegalArgumentException("callStateCacheMaxEntries must be >= 0"); + } if (stickyEnabled && stickyDefaultTtlSeconds <= 0) { throw new IllegalArgumentException("stickyDefaultTtlSeconds must be > 0 when sticky is enabled"); } + if (corsMaxAgeSeconds < 0) throw new IllegalArgumentException("corsMaxAgeSeconds must be >= 0"); + // Validated at construction rather than at the first proxy preflight: + // a credential-to-identity oracle is not something to discover is + // misconfigured in production. + if (introspectResolver != null) { + TokenIntrospection.normalizeIntrospectors(introspectPrincipals); + } else if (!introspectPrincipals.isEmpty()) { + throw new IllegalArgumentException( + "introspectPrincipals was given without introspectResolver; the endpoint stays " + + "disabled, so the allowlist would have no effect. Pass both or neither."); + } + if (introspectTtlSeconds < 0) throw new IllegalArgumentException("introspectTtlSeconds must be >= 0"); + if (introspectRateLimitPerSecond < 0) { + throw new IllegalArgumentException("introspectRateLimitPerSecond must be >= 0"); + } } /** @@ -493,11 +602,19 @@ public static final class Builder { private long advertisedMaxResponseBytes; private long advertisedMaxExternalizedResponseBytes; private boolean proxyProofRequired; + private List proxyAuthHeaders = List.of(); + private int callStateCacheMaxEntries = CallStateCache.DEFAULT_MAX_ENTRIES; private boolean stickyEnabled; private long stickyDefaultTtlSeconds = 300; private Map stickyEchoHeaders = Map.of(); private boolean exposeTestDrainAdmin; private DescribeProvider describeProvider; + private List corsOrigins = List.of(); + private long corsMaxAgeSeconds = DEFAULT_CORS_MAX_AGE_SECONDS; + private TokenResolver introspectResolver; + private List introspectPrincipals = List.of(); + private long introspectTtlSeconds = TokenIntrospection.DEFAULT_TTL_SECONDS; + private int introspectRateLimitPerSecond = TokenIntrospection.DEFAULT_RATE_LIMIT_PER_SECOND; /** * Listen address (default {@code "127.0.0.1"}). See {@link Config#host()}. @@ -669,6 +786,39 @@ public Builder advertisedMaxExternalizedResponseBytes(long v) { * @return this builder */ public Builder proxyProofRequired(boolean v) { this.proxyProofRequired = v; return this; } + /** + * Declare the proxy-injected headers this service's authentication + * depends on, for a custom {@link Authenticator} the framework + * cannot introspect. + * + *

    Declaring any header makes every 401 carry the §5 proxy note. + * That is deliberate: the note describes a static property + * of the deployment, not what failed on a given request, so it + * discloses nothing about which stage rejected an attempt — and it + * is still right in the case it exists for, where the proxy is not + * forwarding the header and every request 401s. + * + *

    The built-in proxy-proof gate contributes {@code VGI-Proxy-Proof} + * on its own via {@link #proxyProofRequired(boolean)} (require mode + * only — in allow mode an absent proof never denies, so the note + * would misdirect), so this is only needed on top of that. + * + * @param headers header names a trusted proxy must set (default none) + * @return this builder + */ + public Builder proxyAuthHeaders(List headers) { this.proxyAuthHeaders = headers; return this; } + /** + * Entry ceiling for the per-process call-state cache; {@code 0} disables it. + * + *

    The cache is an accelerator, never a contract — a miss reopens + * the call token the client echoed. Disabling it is how the + * stateless-relay path gets exercised on every turn instead of only + * on a cold or load-balanced node. + * + * @param v the ceiling (default {@value CallStateCache#DEFAULT_MAX_ENTRIES}); {@code 0} disables + * @return this builder + */ + public Builder callStateCacheMaxEntries(int v) { this.callStateCacheMaxEntries = v; return this; } /** * Enable opt-in HTTP sticky sessions. * @@ -711,6 +861,99 @@ public Builder advertisedMaxExternalizedResponseBytes(long v) { */ public Builder describeProvider(DescribeProvider p) { this.describeProvider = p; return this; } + /** + * Origins allowed to call this server from a browser; empty (the + * default) leaves CORS off entirely. + * + *

    Off means no {@code Access-Control-*} header on any + * response, not a permissive default: a server that answers every + * origin regardless of configuration is a different — and worse — + * bug than one that answers none. + * + *

    A single {@code "*"} entry allows all. That is safe here only + * because vgi-rpc credentials are header-borne and this server never + * sets {@code Access-Control-Allow-Credentials}, so a wildcard grant + * carries no ambient authority. Anything else is matched + * case-insensitively against the request's {@code Origin}, which is + * then echoed back. + * + * @param origins allowed origins (e.g. {@code ["https://app.example"]}) + * @return this builder + */ + public Builder corsOrigins(List origins) { this.corsOrigins = origins; return this; } + /** + * Convenience for the single-origin case. See {@link #corsOrigins(List)}. + * + * @param origin the one allowed origin, or {@code "*"} + * @return this builder + */ + public Builder corsOrigin(String origin) { return corsOrigins(List.of(origin)); } + /** + * How long a browser may cache a preflight, in seconds; {@code 0} + * omits {@code Access-Control-Max-Age} so the browser uses its own + * default. Ignored when no origin is configured. + * + * @param v cache lifetime (default {@value #DEFAULT_CORS_MAX_AGE_SECONDS}s) + * @return this builder + */ + public Builder corsMaxAgeSeconds(long v) { this.corsMaxAgeSeconds = v; return this; } + + /** + * Enable {@code POST {prefix}/__introspect_token__}, which resolves an + * opaque bearer credential to a principal for a reverse proxy that + * must know the caller's identity before it can authorize. + * + *

    Off unless called. A disabled worker still answers the path + * definitively ({@code 404 not_enabled}) while holding no resolver and + * looking nothing up — a caller that reads anything else as transient + * would otherwise retry forever against a worker that will never + * support the feature. + * + *

    The resolver takes the credential and nothing else, deliberately: + * see {@link TokenResolver} for the four ways replaying it through this + * server's own {@link Authenticator} breaks. It never returns claims; + * see {@link TokenIdentity}. + * + * @param resolver resolves the subject credential; {@code null} disables + * the endpoint (the default) + * @param principals principals permitted to introspect. Must name at + * least one — there is no permissive default, because + * "any authenticated caller" is exactly the configuration that + * turns this endpoint into an open oracle + * @return this builder + */ + public Builder tokenIntrospection(TokenResolver resolver, List principals) { + this.introspectResolver = resolver; + this.introspectPrincipals = principals != null ? principals : List.of(); + return this; + } + /** + * Cache lifetime reported to the asker when a {@link TokenIdentity} + * names none. + * + *

    Treat it as an authorization window: for any path the asker serves + * without re-presenting the credential, that is exactly what it is. + * + * @param v the TTL in seconds (default + * {@value TokenIntrospection#DEFAULT_TTL_SECONDS}) + * @return this builder + */ + public Builder introspectTtlSeconds(long v) { this.introspectTtlSeconds = v; return this; } + /** + * Introspection requests allowed per caller per second. + * + *

    Bounds, rather than closes, the oracle an allowlisted caller whose + * own credential leaked still has — a ceiling on how fast an attacker + * converts guesses into answers. + * + * @param v the per-second ceiling (default + * {@value TokenIntrospection#DEFAULT_RATE_LIMIT_PER_SECOND}) + * @return this builder + */ + public Builder introspectRateLimitPerSecond(int v) { + this.introspectRateLimitPerSecond = v; return this; + } + /** * Build the immutable config. * @@ -725,9 +968,11 @@ public Config build() { supportedEncodings, tls, advertiseMaxRequestBytes, uploadUrlProvider, maxUploadBytes, advertisedMaxResponseBytes, advertisedMaxExternalizedResponseBytes, - proxyProofRequired, + proxyProofRequired, proxyAuthHeaders, callStateCacheMaxEntries, stickyEnabled, stickyDefaultTtlSeconds, stickyEchoHeaders, exposeTestDrainAdmin, - describeProvider); + describeProvider, corsOrigins, corsMaxAgeSeconds, + introspectResolver, introspectPrincipals, + introspectTtlSeconds, introspectRateLimitPerSecond); } } @@ -745,9 +990,11 @@ public Config withDescribeProvider(DescribeProvider p) { supportedEncodings, tls, advertiseMaxRequestBytes, uploadUrlProvider, maxUploadBytes, advertisedMaxResponseBytes, advertisedMaxExternalizedResponseBytes, - proxyProofRequired, + proxyProofRequired, proxyAuthHeaders, callStateCacheMaxEntries, stickyEnabled, stickyDefaultTtlSeconds, stickyEchoHeaders, exposeTestDrainAdmin, - p); + p, corsOrigins, corsMaxAgeSeconds, + introspectResolver, introspectPrincipals, + introspectTtlSeconds, introspectRateLimitPerSecond); } } @@ -787,6 +1034,11 @@ public void start() throws Exception { // --- Servlet --------------------------------------------------------- /** Single servlet that dispatches health / unary / stream sub-paths. */ + /** Mint a 16-char hex correlation id, matching the reference's shape. */ + private static String newRequestId() { + return java.util.UUID.randomUUID().toString().replace("-", "").substring(0, 16); + } + private final class RouterServlet extends HttpServlet { @Override @@ -794,10 +1046,36 @@ protected void service(HttpServletRequest req, HttpServletResponse resp) throws // Set capability headers on every response (parity with the Python // _CapabilitiesMiddleware: announce externalisation contract upfront). applyCapabilityHeaders(req, resp); - try { - super.service(req, resp); - } catch (jakarta.servlet.ServletException se) { - throw new IOException(se); + // Echo the caller's correlation id, or mint one. Set before + // dispatch so it survives every exit path — the error responses + // are precisely the ones someone later grep's the log for. + String requestId = req.getHeader(HttpHeaders.REQUEST_ID); + if (requestId == null || requestId.isBlank() || requestId.length() > 128) { + requestId = newRequestId(); + } + resp.setHeader(HttpHeaders.REQUEST_ID, requestId); + // Before dispatch so the grant rides every answer — a 401 or a 413 + // a browser cannot read is a network error with no explanation. + if (cors != null) cors.apply(req, resp); + // Access-log records produced during dispatch are parked here and + // emitted on close, once the encoded body has been measured. + // response_bytes cannot be read where the record is written: + // compression runs after the handler, so a record emitted there + // could only ever report the uncompressed size. + try (AccessLogScope access = AccessLogScope.open(requestId)) { + try { + super.service(req, resp); + } catch (AuthUnavailableException e) { + // Caught here rather than at each authenticate() call site so + // every route answers an outage the same way. A 401 would tell + // every caller to re-authenticate against a service that is + // simply down, and invite them to negative-cache the outage. + writeServiceUnavailable(resp, e); + } catch (jakarta.servlet.ServletException se) { + throw new IOException(se); + } finally { + access.httpStatus(resp.getStatus()); + } } } @@ -880,17 +1158,33 @@ protected void doPost(HttpServletRequest req, HttpServletResponse resp) throws I handleTestDrain(req, resp, true); return; } + if (TokenIntrospection.ENDPOINT.equals(rest)) { + handleIntrospect(req, resp); + return; + } if (UPLOAD_URL_METHOD.equals(rest) || (UPLOAD_URL_METHOD + "/init").equals(rest)) { handleUploadUrl(req, resp); return; } - if (rest.endsWith("/init") || rest.endsWith("/exchange")) { - boolean init = rest.endsWith("/init"); - String methodName = rest.substring(0, rest.length() - (init ? "/init".length() : "/exchange".length())); + boolean stream = rest.endsWith("/init") || rest.endsWith("/exchange"); + boolean init = rest.endsWith("/init"); + String methodName = !stream ? rest + : rest.substring(0, rest.length() - (init ? "/init".length() : "/exchange".length())); + // An RPC method name never contains a slash, so a path still holding + // one after the /init and /exchange suffixes names no route at all. + // Answering 404 rather than dispatching it keeps a mistyped or + // wrong-prefix POST a definitive client error — dispatched, a + // non-Arrow body dies in the IPC reader and surfaces as a 500, which + // a caller reads as "retry later". + if (methodName.isEmpty() || methodName.indexOf('/') >= 0) { + resp.sendError(HttpServletResponse.SC_NOT_FOUND); + return; + } + if (stream) { handleStream(req, resp, methodName, init); return; } - handleUnary(req, resp, rest); + handleUnary(req, resp, methodName); } @Override @@ -954,6 +1248,10 @@ private void applyCapabilityHeaders(HttpServletRequest req, HttpServletResponse if (proxyProofRequired) { resp.setHeader(ProxyProof.PROOF_REQUIRED_HEADER, "true"); } + // Absent, never "false", when disabled: a proxy preflights on presence. + if (introspection != null) { + resp.setHeader(TokenIntrospection.ENABLED_HEADER, "true"); + } if (stickyEnabled) { resp.setHeader(StickyHeaders.STICKY_ENABLED, "true"); resp.setHeader(StickyHeaders.STICKY_TTL, Long.toString(stickyDefaultTtlSeconds)); @@ -964,6 +1262,59 @@ private void applyCapabilityHeaders(HttpServletRequest req, HttpServletResponse } } + /** + * The response headers a browser client may read, built from the same + * conditions as {@link #applyCapabilityHeaders}. + * + *

    The two must stay in lockstep: an advertised-but-unexposed capability + * is invisible to JavaScript and to nothing else, so it survives every test + * driven by an HTTP client that ignores CORS. Adding a header there without + * adding it here ships a server a browser can read no capability from. + */ + private List corsExposeHeaders() { + List expose = new ArrayList<>(List.of( + HttpHeaders.WWW_AUTHENTICATE, + HttpHeaders.X_VGI_CONTENT_ENCODING, + // How a client tells a 200 carrying an error batch from a 200 + // carrying a result — unreadable, the two are indistinguishable. + RPC_ERROR_HEADER, + EXTERNALIZATION_ENABLED_HEADER, + SUPPORTED_ENCODINGS_HEADER, + // Describes a rejection rather than a capability, so it is never + // advertised on /health — but a browser that cannot read it is + // back to guessing the 401 reason out of the body. + HttpHeaders.VGI_AUTH_REASON, + // Also never advertised on /health: it rides every response + // including the failures, and it is what lets a browser client + // quote an id the server's own log can be searched for. + HttpHeaders.REQUEST_ID)); + if (advertiseMaxRequestBytes) expose.add(MAX_REQUEST_BYTES_HEADER); + if (advertisedMaxResponseBytes > 0) expose.add(MAX_RESPONSE_BYTES_HEADER); + if (advertisedMaxExternalizedResponseBytes > 0) expose.add(MAX_EXTERNALIZED_RESPONSE_BYTES_HEADER); + if (uploadUrlProvider != null) { + expose.add(UPLOAD_URL_HEADER); + if (maxUploadBytes != null) expose.add(MAX_UPLOAD_BYTES_HEADER); + } + if (proxyProofRequired) expose.add(ProxyProof.PROOF_REQUIRED_HEADER); + if (introspection != null) expose.add(TokenIntrospection.ENABLED_HEADER); + if (!proxyHint.isEmpty()) expose.add(HttpHeaders.VGI_AUTH_PROXY_REQUIRED); + if (stickyEnabled) { + expose.add(StickyHeaders.STICKY_ENABLED); + expose.add(StickyHeaders.STICKY_TTL); + // Not advertisements but per-response state: a browser client inside + // a session helper reads the minted token and the close signal here. + expose.add(StickyHeaders.SESSION); + expose.add(StickyHeaders.SESSION_CLOSE); + if (!stickyEchoHeaders.isEmpty()) { + expose.add(StickyHeaders.STICKY_ECHO); + for (String name : stickyEchoHeaders.keySet()) { + expose.add(StickyHeaders.ECHO_PREFIX + name); + } + } + } + return expose; + } + /** * True when the request path should bypass the {@code maxRequestBytes} cap. * Mirrors the Python {@code _MaxRequestBytesMiddleware.exempt_prefixes}: @@ -1059,7 +1410,9 @@ private byte[] readBodyUnbounded(HttpServletRequest req) throws IOException { byte[] chunk = new byte[8192]; int n; while ((n = in.read(chunk)) > 0) buf.write(chunk, 0, n); - return maybeDecodeRequestBody(req, buf.toByteArray()); + byte[] body = buf.toByteArray(); + AccessLogScope.recordRequestBytes(body.length); + return maybeDecodeRequestBody(req, body); } } @@ -1079,7 +1432,7 @@ private void handleUnary(HttpServletRequest req, HttpServletResponse resp, Strin try { auth = authenticator.authenticate(req); } catch (AuthException e) { - writeAuthFailure(resp, e); + writeUnauthorized(resp, e); return; } @@ -1256,6 +1609,47 @@ private void handleTestDrain(HttpServletRequest req, HttpServletResponse resp, b resp.setStatus(HttpServletResponse.SC_NO_CONTENT); } + /** + * {@code POST {prefix}/__introspect_token__}: resolve an opaque credential + * to a principal, or say definitively that this worker will not. + * + *

    An {@link AuthException} from the caller's own authenticator collapses + * onto the same 403 a non-allowlisted caller gets. Distinguishing "your + * credential is bad" from "your credential is fine but you may not + * introspect" would tell an unauthorized caller which of the two it is, and + * both are equally final. An {@link AuthUnavailableException} is not caught + * here — it is not a rejection, and the servlet boundary renders it as 503. + */ + private void handleIntrospect(HttpServletRequest req, HttpServletResponse resp) throws IOException { + if (introspection == null) { + TokenIntrospection.writeNotEnabled(resp); + return; + } + AuthContext auth; + try { + auth = authenticator.authenticate(req); + } catch (AuthException e) { + auth = AuthContext.ANONYMOUS; + } + introspection.handle(req, resp, auth); + } + + /** + * Render the transient-failure answer: {@code 503} with {@code Retry-After}. + * + *

    The counterpart to {@link #writeUnauthorized}. A 401 says "your + * credential is bad" and invites a caller to negative-cache; this says + * "I could not find out", which a caller must retry instead. + */ + private static void writeServiceUnavailable(HttpServletResponse resp, AuthUnavailableException e) + throws IOException { + resp.setHeader("Retry-After", Integer.toString(e.retryAfterSeconds())); + resp.setHeader("Cache-Control", "no-store"); + writeJson(resp, HttpServletResponse.SC_SERVICE_UNAVAILABLE, Map.of( + "error", "service_unavailable", + "detail", e.getMessage() != null ? e.getMessage() : "")); + } + private static boolean isLoopbackRequest(HttpServletRequest req) { String remote = req.getRemoteAddr(); if (remote == null) return false; @@ -1311,12 +1705,35 @@ private static void emitResponseCookies(HttpServletResponse resp, Map§4.2 lets a service always answer JSON — what it must never do is + * answer a non-HTML request with HTML — and this port takes that option, + * so {@code Accept} does not change the body. The reason header, the part + * clients actually parse, is set either way.

    + * + *

    Both {@code VGI-} headers describe a rejection, so they are set here + * and nowhere else: they are not capability advertisements and must not + * appear on a successful response.

    + */ + private void writeUnauthorized(HttpServletResponse resp, AuthException e) throws IOException { if (e.wwwAuthenticate() != null) { resp.setHeader(HttpHeaders.WWW_AUTHENTICATE, e.wwwAuthenticate()); } - String msg = e.getMessage() != null ? e.getMessage() : "Unauthorized"; - writeJson(resp, HttpServletResponse.SC_UNAUTHORIZED, Map.of("error", msg)); + AuthReason reason = e.reason(); + resp.setHeader(HttpHeaders.VGI_AUTH_REASON, reason.code()); + if (!proxyHint.isEmpty()) { + resp.setHeader(HttpHeaders.VGI_AUTH_PROXY_REQUIRED, "true"); + } + // A 401 is per-request and flips to 200 on the next attempt with a + // credential, so no shared cache may hold it. + resp.setHeader("Cache-Control", "no-store"); + String detail = e.getMessage() != null ? e.getMessage() : ""; + writeJson(resp, HttpServletResponse.SC_UNAUTHORIZED, + Unauthorized.envelope(reason, detail, proxyHint)); } private static void writeJson(HttpServletResponse resp, int status, Map body) throws IOException { @@ -1363,6 +1780,9 @@ private byte[] readBody(HttpServletRequest req) throws IOException { copyBounded(in, buf, maxRequestBytes); body = buf.toByteArray(); } + // Measured before decompression: this is what the peer actually sent, + // and therefore what the link was billed for. + AccessLogScope.recordRequestBytes(body.length); return maybeDecodeRequestBody(req, body); } @@ -1383,7 +1803,12 @@ private static void copyBounded(InputStream in, OutputStream out, long limit) th private void writeArrowResponse(HttpServletRequest req, HttpServletResponse resp, byte[] body) throws IOException { resp.setContentType(ARROW_CONTENT_TYPE); ResponseEncoding choice = chooseResponseEncoding(req, supportedEncodings); - resp.getOutputStream().write(encodeArrowBody(resp, choice, body, zstdLevel)); + byte[] encoded = encodeArrowBody(resp, choice, body, zstdLevel); + // Post-compression, so this is the egress figure. The logical Arrow size + // the worker produced is a different number by up to three orders of + // magnitude, and is reported separately as output_bytes. + AccessLogScope.recordResponseBytes(encoded.length); + resp.getOutputStream().write(encoded); } /** Compress {@code body} with the negotiated codec (if any) and stamp the @@ -1633,7 +2058,7 @@ private void handleStream(HttpServletRequest req, HttpServletResponse resp, try { auth = authenticator.authenticate(req); } catch (AuthException e) { - writeAuthFailure(resp, e); + writeUnauthorized(resp, e); return; } diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/HttpStreamHandler.java b/vgirpc/src/main/java/farm/query/vgirpc/http/HttpStreamHandler.java index cd0ad2a..5b1e090 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/http/HttpStreamHandler.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/HttpStreamHandler.java @@ -66,6 +66,12 @@ public final class HttpStreamHandler { private final RpcServer rpc; private final byte[] tokenKey; private final long tokenTtlSeconds; + /** + * Accelerates the fixed half of a stream's state. Purely an accelerator: + * a miss reopens the call token the client echoed, so correctness never + * depends on a hit. See {@link CallStateCache}. + */ + private final CallStateCache callStates; private final long maxResponseBytes; /** * method name → concrete {@link StreamState} class. Seeded at construction by @@ -97,6 +103,21 @@ public final class HttpStreamHandler { * producers of large batches must use the external-location protocol. */ public HttpStreamHandler(RpcServer rpc, byte[] tokenKey, long tokenTtlSeconds, long maxResponseBytes) { + this(rpc, tokenKey, tokenTtlSeconds, maxResponseBytes, CallStateCache.DEFAULT_MAX_ENTRIES); + } + + /** + * @param tokenKey AEAD master key (32 bytes) for stream state + * tokens; when {@code null} a random per-process key is generated. + * @param tokenTtlSeconds maximum token age in seconds; {@code 0} disables + * TTL enforcement. + * @param maxResponseBytes per-call response cap. + * @param callStateCacheMaxEntries entry ceiling for the call-state cache; + * {@code 0} disables it, forcing every continuation to re-open the + * call token the client echoed. + */ + public HttpStreamHandler(RpcServer rpc, byte[] tokenKey, long tokenTtlSeconds, long maxResponseBytes, + int callStateCacheMaxEntries) { if (tokenTtlSeconds < 0) { throw new IllegalArgumentException("tokenTtlSeconds must be >= 0, got " + tokenTtlSeconds); } @@ -111,6 +132,7 @@ public HttpStreamHandler(RpcServer rpc, byte[] tokenKey, long tokenTtlSeconds, l new SecureRandom().nextBytes(this.tokenKey); } this.tokenTtlSeconds = tokenTtlSeconds; + this.callStates = new CallStateCache(tokenTtlSeconds, callStateCacheMaxEntries); this.maxResponseBytes = maxResponseBytes; seedStateTypes(); } @@ -234,6 +256,10 @@ public byte[] handleExchange(String method, byte[] requestBody) throws Exception return errorStream(new RuntimeException("Missing state token in exchange request")); } String principal = currentPrincipal(); + // Open the cursor FIRST: its AEAD tag covers the call id and its + // AAD covers the caller, so the id is authenticated before it is + // used to resolve anything. See resolveCall for why that ordering + // is the whole security argument for the cache. StateToken token; try { token = StateToken.unpack(tokenB64.getBytes(StandardCharsets.US_ASCII), @@ -241,14 +267,20 @@ public byte[] handleExchange(String method, byte[] requestBody) throws Exception } catch (Exception e) { return errorStream(e); } + CallToken call; + try { + call = resolveCall(token, req.meta().get(Metadata.CALL_STATE), principal); + } catch (Exception e) { + return errorStream(e); + } Class stateCls = stateTypes.get(method); if (stateCls == null) { return errorStream(new IllegalStateException( "Cannot resolve state type for method '" + method + "'")); } - Schema outputSchema = deserializeSchema(token.outputSchema()); - Schema inputSchema = deserializeSchema(token.inputSchema()); + Schema outputSchema = deserializeSchema(call.outputSchema()); + Schema inputSchema = deserializeSchema(call.inputSchema()); boolean isProducer = inputSchema.getFields().isEmpty(); StreamState state = StateSerializer.deserialize(token.state(), stateCls); @@ -351,11 +383,68 @@ private byte[] writeExchangeResponse(OutputCollector collector, StreamState stat private String serializeContinuationToken(StreamState state, StateToken priorToken, String principal) { byte[] newStateBytes = StateSerializer.serialize(state); - StateToken newToken = new StateToken(newStateBytes, priorToken.outputSchema(), priorToken.inputSchema(), - priorToken.streamId(), System.currentTimeMillis() / 1000); + StateToken newToken = new StateToken(newStateBytes, priorToken.callId(), + System.currentTimeMillis() / 1000); return new String(newToken.pack(tokenKey, principal), StandardCharsets.US_ASCII); } + /** + * Resolve a stream's fixed half for an already-authenticated cursor. + * + *

    Order matters, and it is the whole security argument for the cache. + * The cursor is opened first by the caller; its AEAD tag covers the call + * id and its AAD covers the caller's identity. Only then is that + * authenticated id used as a cache key. A client cannot name a call id + * the server did not mint for it, so a cache hit can never hand back + * another principal's call state — and on a hit the presented call token + * is not consulted at all, which is exactly the work being avoided.

    + * + *

    On a miss (cold process, evicted entry, or a request load-balanced + * to a node that never saw this stream's {@code /init}) the client's call + * token is opened and verified, and its embedded call id must match the + * one the cursor named.

    + */ + private CallToken resolveCall(StateToken cursor, String callTokenB64, String principal) { + CallToken cached = callStates.get(cursor.callId(), principal); + if (cached != null) { + return cached; + } + if (callTokenB64 == null) { + throw new IllegalArgumentException("Missing call token in exchange request"); + } + CallToken call = CallToken.unpack(callTokenB64.getBytes(StandardCharsets.US_ASCII), + tokenKey, tokenTtlSeconds, principal); + if (!java.util.Arrays.equals(call.callId(), cursor.callId())) { + // The cursor named a different call. Uniform message: reachable + // only by pairing two tokens the same principal legitimately + // holds, so it carries nothing worth distinguishing. + throw new IllegalArgumentException("Malformed state token"); + } + callStates.put(cursor.callId(), principal, call); + return call; + } + + /** Mint a stream's call id, call token, and first cursor at {@code /init}. */ + private Map mintInitTokens(StreamState state, Schema outputSchema, + Schema inputSchema, String principal) { + byte[] callId = new byte[Tokens.CALL_ID_LEN]; + new java.security.SecureRandom().nextBytes(callId); + long now = System.currentTimeMillis() / 1000; + + CallToken call = new CallToken(serializeSchema(outputSchema), serializeSchema(inputSchema), + newStreamId(), callId, now); + // Warm the cache with what we already hold, so this stream's first + // continuation does not have to open the token it was just handed. + callStates.put(callId, principal, call); + + StateToken cursor = new StateToken(StateSerializer.serialize(state), callId, now); + return Map.of( + Metadata.STREAM_STATE, + new String(cursor.pack(tokenKey, principal), StandardCharsets.US_ASCII), + Metadata.CALL_STATE, + new String(call.pack(tokenKey, principal), StandardCharsets.US_ASCII)); + } + private CallContext buildCallContext(String method, Consumer sink) { AuthScope.Scope scope = AuthScope.current(); return new CallContext(scope.auth(), sink, scope.transportMetadata(), @@ -399,13 +488,8 @@ private void writeProducerRun(ByteArrayOutputStream out, RpcStream streamResu // If the producer isn't finished, append a zero-row state-token batch so the // client knows to call /exchange to continue. Finished streams just EOS. if (!coll.finished()) { - StateToken token = new StateToken( - StateSerializer.serialize(state), - serializeSchema(outputSchema), - serializeSchema(inputSchema), - newStreamId(), System.currentTimeMillis() / 1000); - Map md = Map.of(Metadata.STREAM_STATE, - new String(token.pack(tokenKey, currentPrincipal()), StandardCharsets.US_ASCII)); + Map md = mintInitTokens(state, outputSchema, inputSchema, + currentPrincipal()); Wire.writeZeroBatch(w, outputSchema, md); } } @@ -416,16 +500,11 @@ private void writeExchangeInitToken(ByteArrayOutputStream out, RpcStream stre OutputCollectorSink sink) throws IOException { Schema outputSchema = streamResult.outputSchema(); Schema inputSchema = streamResult.inputSchema(); - StateToken token = new StateToken( - StateSerializer.serialize(streamResult.state()), - serializeSchema(outputSchema), - serializeSchema(inputSchema), - newStreamId(), System.currentTimeMillis() / 1000); + Map md = mintInitTokens(streamResult.state(), outputSchema, inputSchema, + currentPrincipal()); try (IpcStreamWriter w = new IpcStreamWriter(out)) { w.writeSchema(outputSchema); sink.bind(w, outputSchema); - Map md = Map.of(Metadata.STREAM_STATE, - new String(token.pack(tokenKey, currentPrincipal()), StandardCharsets.US_ASCII)); Wire.writeZeroBatch(w, outputSchema, md); } } diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/InvalidCredentials.java b/vgirpc/src/main/java/farm/query/vgirpc/http/InvalidCredentials.java index 7145484..c9a109f 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/http/InvalidCredentials.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/InvalidCredentials.java @@ -18,4 +18,6 @@ public final class InvalidCredentials extends AuthException { * @param wwwAuthenticate value for the {@code WWW-Authenticate} challenge header, or {@code null} */ public InvalidCredentials(String message, String wwwAuthenticate) { super(message, wwwAuthenticate); } + + @Override public AuthReason reason() { return AuthReason.INVALID_CREDENTIAL; } } diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/MissingCredentials.java b/vgirpc/src/main/java/farm/query/vgirpc/http/MissingCredentials.java index 855cc53..c6a5ac5 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/http/MissingCredentials.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/MissingCredentials.java @@ -18,4 +18,6 @@ public final class MissingCredentials extends AuthException { * @param wwwAuthenticate value for the {@code WWW-Authenticate} challenge header, or {@code null} */ public MissingCredentials(String message, String wwwAuthenticate) { super(message, wwwAuthenticate); } + + @Override public AuthReason reason() { return AuthReason.MISSING_CREDENTIAL; } } diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/StateToken.java b/vgirpc/src/main/java/farm/query/vgirpc/http/StateToken.java index 24cfeb1..93d2672 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/http/StateToken.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/StateToken.java @@ -3,6 +3,8 @@ package farm.query.vgirpc.http; +import com.github.luben.zstd.Zstd; + import farm.query.vgirpc.http.auth.Crypto; import java.nio.ByteBuffer; @@ -14,12 +16,15 @@ * HTTP streaming state token: AEAD-sealed envelope holding stream state, * schemas, and a stream id so the server can recover on the next exchange. * - *

    Wire format (v4): + *

    Wire format (v5): * 

      *   base64(
- *     [1 byte:  version = 4]
+ *     [1 byte:  version = 5]
  *     [12 bytes: ChaCha20-Poly1305 nonce (random)]
  *     [..]      ciphertext + Poly1305 tag
+ *               sealed payload:
+ *                 [1 byte:   codec — 0x00 raw, 0x01 zstd]
+ *                 [..]       the plaintext below, compressed per codec
  *               plaintext:
  *                 [8 bytes:  created_at uint64 LE]
  *                 [4 bytes:  state_len uint32 LE]   [state bytes]
@@ -29,6 +34,21 @@
  *   )
  *
    * + *

    Compression happens inside the seal, and the order is the whole + * point: once sealed, a token is ciphertext, so the HTTP body codec can no + * longer find any redundancy in it — it recovers only the slack base64 adds, + * never the state's own structure. Compressing first reaches the real + * redundancy. Compression is skipped when it does not pay, so a small token + * never grows beyond its plaintext plus the one tag byte.

    + * + *

    v4 sealed the plaintext directly. The version bump matters for rolling + * deploys: a v4 plaintext starts straight into {@code created_at}, so a v5 + * reader would take its first byte as a codec tag and mis-frame the rest. + * Rejecting the old version outright turns that into the same clean failure + * as any other stale token. The AAD prefix stays at {@code v4}, matching the + * Python reference, which likewise bumped its token version without + * regenerating its AAD.

    + * *

    The {@code created_at} timestamp lives inside the ciphertext so TTL * enforcement runs after authenticity is established. The version byte is * informational (a self-describing format marker); a tampered version byte @@ -39,27 +59,42 @@ */ public record StateToken( byte[] state, - byte[] outputSchema, - byte[] inputSchema, - String streamId, + byte[] callId, long createdAt) { - private static final byte VERSION = 4; + private static final byte VERSION = 6; private static final int VERSION_LEN = 1; /** Prefix mixed into AEAD AAD to bind tokens to a format generation. */ private static final byte[] AAD_PREFIX = "vgi_rpc.state.v4\0".getBytes(StandardCharsets.UTF_8); + /** Codec tags for the sealed payload. See {@link #packPayload}. */ + private static final byte CODEC_RAW = 0x00; + private static final byte CODEC_ZSTD = 0x01; + + /** + * Matches the Python reference's choice. At token payload sizes this + * measures the same speed as level 1 and slightly smaller, while the + * levels that compress materially better cost many times the CPU for a + * few hundred bytes. + */ + private static final int ZSTD_LEVEL = 3; + + /** + * Bounds decompression. The payload is authenticated before it is ever + * decompressed, so this guards against a framework bug rather than an + * attacker — but an unbounded decompress on a request path is not worth + * having. + */ + private static final long MAX_PLAINTEXT_BYTES = 64L << 20; + public StateToken { state = state.clone(); - outputSchema = outputSchema.clone(); - inputSchema = inputSchema.clone(); - streamId = streamId != null ? streamId : ""; + callId = callId.clone(); } - @Override public byte[] state() { return state.clone(); } - @Override public byte[] outputSchema() { return outputSchema.clone(); } - @Override public byte[] inputSchema() { return inputSchema.clone(); } + @Override public byte[] state() { return state.clone(); } + @Override public byte[] callId() { return callId.clone(); } /** * Serialise, AEAD-seal, and base64-encode the token. The AAD binds the @@ -67,19 +102,12 @@ public record StateToken( * caller; pass {@code ""} (or {@code null}) for anonymous streams. */ public byte[] pack(byte[] tokenKey, String principal) { - byte[] streamIdBytes = streamId.getBytes(StandardCharsets.UTF_8); - int payloadLen = 8 - + 4 + state.length - + 4 + outputSchema.length - + 4 + inputSchema.length - + 4 + streamIdBytes.length; + int payloadLen = 8 + Tokens.CALL_ID_LEN + 4 + state.length; ByteBuffer payload = ByteBuffer.allocate(payloadLen).order(ByteOrder.LITTLE_ENDIAN); payload.putLong(createdAt); + payload.put(callId); putSegment(payload, state); - putSegment(payload, outputSchema); - putSegment(payload, inputSchema); - putSegment(payload, streamIdBytes); - byte[] sealed = Crypto.chacha20Poly1305Seal(tokenKey, payload.array(), aad(principal)); + byte[] sealed = Crypto.chacha20Poly1305Seal(tokenKey, packPayload(payload.array()), aad(principal)); byte[] wire = new byte[VERSION_LEN + sealed.length]; wire[0] = VERSION; System.arraycopy(sealed, 0, wire, VERSION_LEN, sealed.length); @@ -111,17 +139,22 @@ public static StateToken unpack(byte[] b64, byte[] tokenKey, long ttlSeconds, St } byte[] sealed = new byte[raw.length - VERSION_LEN]; System.arraycopy(raw, VERSION_LEN, sealed, 0, sealed.length); - byte[] plaintext; + byte[] opened; try { - plaintext = Crypto.chacha20Poly1305Open(tokenKey, sealed, aad(principal)); + opened = Crypto.chacha20Poly1305Open(tokenKey, sealed, aad(principal)); } catch (IllegalArgumentException e) { throw new IllegalArgumentException("State token signature verification failed", e); } - if (plaintext.length < 8) { + // Decompress only after authentication: nothing an attacker supplies + // reaches the decoder without the token key. + byte[] plaintext = unpackPayload(opened); + if (plaintext.length < 8 + Tokens.CALL_ID_LEN) { throw new IllegalArgumentException("Malformed state token"); } ByteBuffer bb = ByteBuffer.wrap(plaintext).order(ByteOrder.LITTLE_ENDIAN); long createdAt = bb.getLong(); + byte[] callId = new byte[Tokens.CALL_ID_LEN]; + bb.get(callId); if (ttlSeconds > 0) { long now = System.currentTimeMillis() / 1000; if (now - createdAt > ttlSeconds) { @@ -130,11 +163,7 @@ public static StateToken unpack(byte[] b64, byte[] tokenKey, long ttlSeconds, St } } byte[] state = getSegment(bb); - byte[] outputSchema = getSegment(bb); - byte[] inputSchema = getSegment(bb); - byte[] streamIdBytes = getSegment(bb); - return new StateToken(state, outputSchema, inputSchema, - new String(streamIdBytes, StandardCharsets.UTF_8), createdAt); + return new StateToken(state, callId, createdAt); } /** @@ -143,20 +172,22 @@ public static StateToken unpack(byte[] b64, byte[] tokenKey, long ttlSeconds, St * token cannot be presented under a named identity (and vice versa). */ private static byte[] aad(String principal) { - String p = principal != null ? principal : ""; - byte[] tail; - if (p.isEmpty()) { - tail = new byte[]{0x00, 'a', 'n', 'o', 'n', 'y', 'm', 'o', 'u', 's'}; - } else { - byte[] pBytes = p.getBytes(StandardCharsets.UTF_8); - tail = new byte[1 + pBytes.length]; - tail[0] = 0x01; - System.arraycopy(pBytes, 0, tail, 1, pBytes.length); - } - byte[] out = new byte[AAD_PREFIX.length + tail.length]; - System.arraycopy(AAD_PREFIX, 0, out, 0, AAD_PREFIX.length); - System.arraycopy(tail, 0, out, AAD_PREFIX.length, tail.length); - return out; + return Tokens.aad(AAD_PREFIX, principal); + } + + /** + * Compress a token payload and tag which codec was used. + * + *

    Delegates to {@link Tokens}, which both token kinds share. Kept here + * as the package-private entry point the token tests exercise.

    + */ + static byte[] packPayload(byte[] plaintext) { + return Tokens.packPayload(plaintext); + } + + /** Reverse {@link #packPayload}. */ + static byte[] unpackPayload(byte[] data) { + return Tokens.unpackPayload(data); } private static void putSegment(ByteBuffer b, byte[] seg) { diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/TokenIdentity.java b/vgirpc/src/main/java/farm/query/vgirpc/http/TokenIdentity.java new file mode 100644 index 0000000..f3e4d5a --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/TokenIdentity.java @@ -0,0 +1,45 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +/** + * The identity an opaque credential authenticates as — the entire answer token + * introspection may give. + * + *

    Three fields, and no fourth. A claims field would let a worker choose its + * caller's tenant routing, its row scope, and its policy branch, which is the + * single most dangerous thing this feature could grow; askers derive what they + * need from the principal alone. The conformance group asserts the response key + * set is closed, so a field added here has to come through that test. + * + * @param principal the canonical principal, in the exact form this worker would + * derive itself. An asker that normalises differently would otherwise + * authorize as one identity while the worker serves another. + * @param tokenName human-readable name for the credential, for audit trails. + * Never the credential. + * @param ttlSeconds how long the answer may be cached; {@code 0} takes the + * server-configured default. The caller does the caching — this + * endpoint holds none. Treat it as an authorization window, because for + * any path the asker serves without re-presenting the credential that is + * exactly what it is. + */ +public record TokenIdentity(String principal, String tokenName, long ttlSeconds) { + + /** Validates the principal and normalises the optional fields. */ + public TokenIdentity { + if (principal == null || principal.isEmpty()) { + throw new IllegalArgumentException("principal must not be empty"); + } + tokenName = tokenName != null ? tokenName : ""; + if (ttlSeconds < 0) throw new IllegalArgumentException("ttlSeconds must be >= 0"); + } + + /** + * An identity taking the server's configured TTL. + * + * @param principal the canonical principal + * @param tokenName display name for the credential + */ + public TokenIdentity(String principal, String tokenName) { this(principal, tokenName, 0); } +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/TokenIntrospection.java b/vgirpc/src/main/java/farm/query/vgirpc/http/TokenIntrospection.java new file mode 100644 index 0000000..4657d4b --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/TokenIntrospection.java @@ -0,0 +1,356 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +import com.fasterxml.jackson.databind.JsonNode; +import com.fasterxml.jackson.databind.ObjectMapper; +import farm.query.vgirpc.AuthContext; +import jakarta.servlet.http.HttpServletRequest; +import jakarta.servlet.http.HttpServletResponse; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import java.io.IOException; +import java.io.InputStream; +import java.nio.charset.StandardCharsets; +import java.security.MessageDigest; +import java.security.NoSuchAlgorithmException; +import java.util.Collection; +import java.util.HashMap; +import java.util.HashSet; +import java.util.HexFormat; +import java.util.LinkedHashMap; +import java.util.Map; +import java.util.Optional; +import java.util.Set; +import java.util.regex.Pattern; + +/** + * {@code POST {prefix}/__introspect_token__} — resolving an opaque bearer + * credential to a principal, for a reverse proxy that terminates the only + * public listener. + * + *

    Such a proxy has to know which principal a credential authenticates + * as before it can authorize anything: that principal becomes the policy + * principal, the row-rule literal, and the bind parameter of every entitlement + * query. When the credential is opaque the proxy holds no local copy of it, so + * it has to ask the worker. + * + *

    The response is an identity assertion made by the thing being + * protected, and the asker acts on it using credentials the worker does not + * hold — storage credentials on a data-plane host, service-credential + * attachments in an entitlement resolver, policy-tier selection. "Trust it as + * much as you trust the worker" is therefore the wrong frame: it has to be + * trusted more, because it steers privileges the worker never has. + * Every guard below follows from that, and none of them is optional: + * + *

      + *
    • 403 — the caller may not introspect. Authentication and + * introspection are different capabilities: a deployment where any valid + * credential may introspect lets any user test guesses of any other user's + * credential at unlimited rate, and resolve a stolen one to its owner. The + * allowlist has no permissive default.
      • + *
    • 404 — the subject credential did not resolve. Unknown, + * expired and malformed are byte-identical answers, because reporting which + * confirms that a guessed credential exists.
      • + *
    • JWS-shaped subjects are refused without reaching the resolver. + * A JWS is validated locally against a key set; routing one here hands a + * third party a bearer token the asker may itself have rejected, and an + * expired access token is still live at its issuer for other resources.
      • + *
    • The credential appears in no response, message, or log record. It is + * SHA-256 digested for diagnostics.
      • + *
    + * + *

    Both refusals are definitive: a caller may cache them. Anything + * transient must reach the caller as 5xx so it is retried rather than cached — + * see {@link AuthUnavailableException}. + * + *

    Cross-language conformance groups: {@code TestTokenIntrospection} and + * {@code TestTokenIntrospectionOffMode}. Wire contract: + * {@code docs/WIRE_PROTOCOL.md} §16 in the vgi-rpc reference repository. + */ +public final class TokenIntrospection { + + private static final Logger LOG = LoggerFactory.getLogger(TokenIntrospection.class); + + /** + * Endpoint path relative to the server's prefix. Matches the de-facto + * contract the existing proxy client already speaks; changing it would cost + * a lockstep release for no benefit. + */ + public static final String ENDPOINT = "__introspect_token__"; + + /** + * Advertised on every response (including {@code OPTIONS /health}) when the + * route is enabled, so a proxy preflights at boot rather than discovering at + * first login that the worker it depends on cannot answer. Absent — never + * {@code "false"} — otherwise. + */ + public static final String ENABLED_HEADER = "VGI-Token-Introspection"; + + /** Default cache lifetime advertised to the asker, in seconds. */ + public static final long DEFAULT_TTL_SECONDS = 300; + + /** Default per-caller request ceiling, per second. */ + public static final int DEFAULT_RATE_LIMIT_PER_SECOND = 20; + + /** + * Three dot-separated base64url segments — a JWS. Such a credential is + * validated locally against a key set and must never be routed here. + */ + private static final Pattern JWS_SHAPED = + Pattern.compile("^[A-Za-z0-9_-]+\\.[A-Za-z0-9_-]+\\.[A-Za-z0-9_-]*$"); + + /** + * Hard cap on the request body. The generic {@code maxRequestBytes} cap + * would otherwise admit megabytes into a JSON parse for a body whose only + * legitimate content is one credential. + */ + private static final int MAX_BODY_BYTES = 8192; + + /** + * Cap on a credential we will even attempt to resolve. Anything longer is + * not a bearer token; refusing early keeps a resolver from being handed + * megabytes. + */ + private static final int MAX_TOKEN_CHARS = 4096; + + private static final ObjectMapper JSON = new ObjectMapper(); + + private final TokenResolver resolver; + private final Set introspectors; + private final long defaultTtlSeconds; + private final RateLimiter limiter; + + /** + * @param resolver resolves the subject credential; never the server's own authenticate chain + * @param introspectors principals permitted to introspect; must be non-empty + * @param defaultTtlSeconds TTL applied when a {@link TokenIdentity} names none + * @param rateLimitPerSecond per-caller request ceiling + */ + TokenIntrospection(TokenResolver resolver, Collection introspectors, + long defaultTtlSeconds, int rateLimitPerSecond) { + this.resolver = resolver; + this.introspectors = Set.copyOf(normalizeIntrospectors(introspectors)); + this.defaultTtlSeconds = defaultTtlSeconds > 0 ? defaultTtlSeconds : DEFAULT_TTL_SECONDS; + this.limiter = new RateLimiter(rateLimitPerSecond > 0 ? rateLimitPerSecond : DEFAULT_RATE_LIMIT_PER_SECOND); + } + + /** + * Validate the introspector allowlist. + * + *

    There is no permissive default: "any authenticated caller" is precisely + * the configuration that turns this endpoint into an open oracle, so it must + * not be reachable by omission. + * + * @param principals the configured allowlist + * @return the non-empty allowlist, blanks dropped + * @throws IllegalArgumentException if it names no principal + */ + static Set normalizeIntrospectors(Collection principals) { + Set allowed = new HashSet<>(); + if (principals != null) { + for (String p : principals) { + if (p != null && !p.isEmpty()) allowed.add(p); + } + } + if (allowed.isEmpty()) { + throw new IllegalArgumentException( + "introspectPrincipals must name at least one principal. Introspection is a " + + "distinct capability from authentication: allowing any authenticated " + + "caller lets any user resolve any other user's credential to its owner."); + } + return allowed; + } + + /** + * SHA-256 hex digest of {@code token}, for diagnostics. + * + *

    The credential itself must never reach a log, a span, or an error + * message. A digest is stable enough to correlate one credential's failures + * across records without being the credential. + * + * @param token the opaque credential + * @return lowercase hex digest + */ + static String digest(String token) { + try { + MessageDigest sha = MessageDigest.getInstance("SHA-256"); + return HexFormat.of().formatHex(sha.digest(token.getBytes(StandardCharsets.UTF_8))); + } catch (NoSuchAlgorithmException e) { + throw new IllegalStateException("SHA-256 unavailable", e); + } + } + + /** Whether {@code token} looks like a JWS and must be refused unresolved. */ + static boolean isJwsShaped(String token) { return JWS_SHAPED.matcher(token).matches(); } + + /** + * Answer {@code 404 not_enabled} for a worker that did not turn the feature on. + * + *

    The oracle is still absent in every sense that matters: no resolver is + * held, nothing is looked up, and the answer does not depend on the request. + * What this adds is a definitive answer for a caller that asks + * anyway. Left unrouted the path falls through to the generic {@code {method}} + * route, which answers a JSON body with a 500 (the Arrow reader finds no IPC + * stream) — and a caller that classifies {@code 401/403/404} as definitive + * and everything else as transient, which is the sensible classification and + * the one the existing proxy client uses, reads that as "try again later" + * and retries forever against a worker that will never support the feature. + * A misconfiguration should stop, not spin. + * + *

    Deliberately unauthenticated: "this worker does not do introspection" is + * not a secret, and a caller needs to learn it at preflight rather than after + * arranging credentials. + * + * @param resp the response to write + * @throws IOException if the response body cannot be written + */ + static void writeNotEnabled(HttpServletResponse resp) throws IOException { + refuse(resp, HttpServletResponse.SC_NOT_FOUND, "not_enabled"); + } + + /** + * Resolve the posted credential to a principal. + * + * @param req the introspection request + * @param resp the response to write + * @param auth the caller's authenticated context (never the subject's) + * @throws IOException if the response body cannot be written + */ + void handle(HttpServletRequest req, HttpServletResponse resp, AuthContext auth) throws IOException { + String caller = auth != null && auth.principal() != null ? auth.principal() : ""; + boolean authenticated = auth != null && auth.authenticated(); + + // Caller authorization first: an unauthorized caller must not learn + // anything about a subject credential, including how long it took. + if (!authenticated || !introspectors.contains(caller)) { + LOG.warn("introspection refused: caller is not an introspector (remote_addr={}, principal={})", + req.getRemoteAddr(), caller); + refuse(resp, HttpServletResponse.SC_FORBIDDEN, "not_an_introspector"); + return; + } + + if (!limiter.allow(caller)) { + LOG.warn("introspection rate limit exceeded (principal={})", caller); + resp.setHeader("Retry-After", "1"); + refuse(resp, 429, "rate_limited"); + return; + } + + String token = readToken(req); + if (token == null) { + // Indistinguishable from an unresolvable credential: a malformed body + // is not worth a separate signal, and giving one lets a caller probe + // the parser. + refuse(resp, HttpServletResponse.SC_NOT_FOUND, "unresolved"); + return; + } + + String digest = digest(token); + + if (isJwsShaped(token)) { + // Refused without ever reaching the resolver. A JWS arriving here is + // either a caller bug or an attempt to have this worker vouch for a + // token its asker already rejected. + LOG.warn("introspection refused: JWS-shaped subject (principal={}, token_digest={})", caller, digest); + refuse(resp, HttpServletResponse.SC_NOT_FOUND, "unresolved"); + return; + } + + Optional identity = resolver.resolve(token); + if (identity == null || identity.isEmpty()) { + LOG.info("introspection: credential did not resolve (principal={}, token_digest={})", caller, digest); + refuse(resp, HttpServletResponse.SC_NOT_FOUND, "unresolved"); + return; + } + + TokenIdentity id = identity.get(); + LOG.info("introspection: resolved (principal={}, token_digest={}, resolved_principal={})", + caller, digest, id.principal()); + + Map body = new LinkedHashMap<>(); + body.put("principal", id.principal()); + body.put("token_name", id.tokenName()); + body.put("ttl_seconds", id.ttlSeconds() > 0 ? id.ttlSeconds() : defaultTtlSeconds); + resp.setStatus(HttpServletResponse.SC_OK); + resp.setContentType(MediaTypes.APPLICATION_JSON); + // A credential's resolution can change; nothing here may sit in a shared cache. + resp.setHeader("Cache-Control", "no-store"); + resp.getOutputStream().write(JSON.writeValueAsBytes(body)); + } + + /** + * Write a rejection carrying no detail about why. + * + *

    Hand-rolled rather than serialized so every rejection with the same code + * is byte-identical — {@code test_rejections_are_indistinguishable} compares + * response text, not just status. + */ + private static void refuse(HttpServletResponse resp, int status, String error) throws IOException { + resp.setStatus(status); + resp.setContentType(MediaTypes.APPLICATION_JSON); + resp.setHeader("Cache-Control", "no-store"); + resp.getOutputStream().write(("{\"error\":\"" + error + "\"}").getBytes(StandardCharsets.UTF_8)); + } + + /** The subject credential, or {@code null} when the body is unusable. */ + private static String readToken(HttpServletRequest req) { + long declared = req.getContentLengthLong(); + if (declared > MAX_BODY_BYTES) return null; + byte[] raw; + try (InputStream in = req.getInputStream()) { + raw = in.readNBytes(MAX_BODY_BYTES + 1); + } catch (IOException e) { + return null; + } + if (raw.length > MAX_BODY_BYTES) return null; + JsonNode node; + try { + node = JSON.readTree(raw); + } catch (IOException e) { + return null; + } + if (node == null || !node.isObject()) return null; + JsonNode token = node.get("token"); + if (token == null || !token.isTextual()) return null; + String value = token.asText(); + if (value.isEmpty() || value.length() > MAX_TOKEN_CHARS) return null; + return value; + } + + /** + * Fixed-window request limiter, keyed by caller. + * + *

    Present because the endpoint is a credential-to-identity oracle even + * when correctly restricted: an allowlisted caller whose own credential leaks + * can still test guesses. Rate limiting does not close that, it bounds it — a + * lower ceiling on how fast an attacker converts guesses to answers. + * + *

    Fixed-window rather than a token bucket: a window admits at most twice + * the rate across a boundary, which is a rounding error here, and the state + * is one integer per caller rather than a float that has to be aged. + */ + private static final class RateLimiter { + private final int perWindow; + private final Map counts = new HashMap<>(); + private long windowStartNanos; + + RateLimiter(int perWindow) { this.perWindow = perWindow; } + + synchronized boolean allow(String key) { + long now = System.nanoTime(); + if (now - windowStartNanos >= 1_000_000_000L) { + // Whole-map reset rather than per-key ageing: an attacker cycling + // keys cannot grow the map beyond one window's worth. + counts.clear(); + windowStartNanos = now; + } + int count = counts.getOrDefault(key, 0); + if (count >= perWindow) return false; + counts.put(key, count + 1); + return true; + } + } +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/TokenResolver.java b/vgirpc/src/main/java/farm/query/vgirpc/http/TokenResolver.java new file mode 100644 index 0000000..d2c9275 --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/TokenResolver.java @@ -0,0 +1,44 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +import java.util.Optional; + +/** + * Resolves an opaque bearer credential to the identity it authenticates as. + * + *

    Deliberately narrow, and deliberately not "replay the credential + * through this worker's own {@link Authenticator}". That is the attractive + * design and it breaks four ways: a precondition gate wrapping the chain (the + * proxy-proof gate, say) makes the replay unimplementable; the replay runs the + * worker's independently-configured audience/issuer set, so a credential the + * asker itself rejected could be accepted here; cookie- and + * mTLS/IP-derived identity cannot be replayed at all, and a synthesized request + * carries the proxy's own address — silently elevating any address-allowlist + * member rather than failing cleanly; and it invents a fake-request contract + * every future authenticator would have to honour, with no type to enforce it. + * + *

    A resolver sees only the credential, so it cannot accidentally depend on + * any of that. + */ +@FunctionalInterface +public interface TokenResolver { + + /** + * Resolve {@code credential}. + * + *

    Implementations must not log, echo, or embed the credential — digest it + * (see {@code TokenIntrospection}) if a diagnostic needs to correlate one + * credential's failures across records. + * + * @param credential the opaque bearer credential presented by the asker + * @return the identity, or {@link Optional#empty()} when the credential does + * not resolve — unknown, expired and malformed are one answer, since + * reporting which would confirm that a guessed credential exists + * @throws AuthUnavailableException when the answer is not knowable: a backing + * store that is down is not the same as a credential that is unknown, + * and a caller that negative-caches the second must not cache the first + */ + Optional resolve(String credential); +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/Tokens.java b/vgirpc/src/main/java/farm/query/vgirpc/http/Tokens.java new file mode 100644 index 0000000..3447185 --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/Tokens.java @@ -0,0 +1,131 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +import com.github.luben.zstd.Zstd; + +import java.nio.charset.StandardCharsets; + +/** + * Framing shared by a stream's two state tokens. + * + *

    A stream's state divides into a part fixed for the life of the call — + * the resolved schemas and the stream id — and a part that advances per turn. + * Carrying both in one token means every continuation re-serializes, + * re-seals, re-opens and re-parses the fixed part, which for a typical stream + * is most of the payload. So the two travel separately as {@link CallToken} + * and {@link StateToken}; see {@code docs/WIRE_PROTOCOL.md} in the reference + * repo, which requires the split.

    + * + *

    Both kinds share this envelope: compress under a codec tag, then seal. + * Only the plaintext framing inside differs.

    + */ +final class Tokens { + + private Tokens() { + } + + /** Length of the random per-stream id minted at {@code /init}. */ + static final int CALL_ID_LEN = 16; + + /** Codec tags for the sealed payload. See {@link #packPayload}. */ + private static final byte CODEC_RAW = 0x00; + private static final byte CODEC_ZSTD = 0x01; + + /** + * Matches the Python reference's choice. At token payload sizes this + * measures the same speed as level 1 and slightly smaller, while the + * levels that compress materially better cost many times the CPU for a + * few hundred bytes. + */ + private static final int ZSTD_LEVEL = 3; + + /** + * Bounds decompression. The payload is authenticated before it is ever + * decompressed, so this guards against a framework bug rather than an + * attacker — but an unbounded decompress on a request path is not worth + * having. + */ + private static final long MAX_PLAINTEXT_BYTES = 64L << 20; + + /** + * Build the AAD that binds a token to its caller, under a prefix that + * also binds it to its kind. + * + *

    The cursor and call prefixes differ deliberately, so the two are not + * interchangeable even for the same principal: presenting one where the + * other is expected fails the AEAD tag check rather than decoding into a + * payload the reader would misinterpret. Anonymous and authenticated + * tokens likewise produce distinct AAD strings.

    + */ + static byte[] aad(byte[] prefix, String principal) { + String p = principal != null ? principal : ""; + byte[] tail; + if (p.isEmpty()) { + tail = new byte[]{0x00, 'a', 'n', 'o', 'n', 'y', 'm', 'o', 'u', 's'}; + } else { + byte[] pBytes = p.getBytes(StandardCharsets.UTF_8); + tail = new byte[1 + pBytes.length]; + tail[0] = 0x01; + System.arraycopy(pBytes, 0, tail, 1, pBytes.length); + } + byte[] out = new byte[prefix.length + tail.length]; + System.arraycopy(prefix, 0, out, 0, prefix.length); + System.arraycopy(tail, 0, out, prefix.length, tail.length); + return out; + } + + /** + * Compress a token payload and tag which codec was used. + * + *

    Compression is skipped when it does not pay — small payloads can come + * out larger, and the flag byte means the reader does not have to guess. + * None of this is visible on the wire, so the cross-language conformance + * suite cannot check it; the token tests pin it instead.

    + */ + static byte[] packPayload(byte[] plaintext) { + byte[] packed = Zstd.compress(plaintext, ZSTD_LEVEL); + if (packed.length < plaintext.length) { + return prefixed(CODEC_ZSTD, packed); + } + return prefixed(CODEC_RAW, plaintext); + } + + /** + * Reverse {@link #packPayload}. An unknown tag or a body that will not + * decompress means a token this server did not mint, so both surface as + * the same uniform "Malformed state token" every other token failure uses. + */ + static byte[] unpackPayload(byte[] data) { + if (data.length == 0) { + throw new IllegalArgumentException("Malformed state token"); + } + byte[] body = new byte[data.length - 1]; + System.arraycopy(data, 1, body, 0, body.length); + switch (data[0]) { + case CODEC_RAW: + return body; + case CODEC_ZSTD: + long size = Zstd.getFrameContentSize(body); + if (size <= 0 || size > MAX_PLAINTEXT_BYTES) { + throw new IllegalArgumentException("Malformed state token"); + } + byte[] out = new byte[(int) size]; + long ret = Zstd.decompress(out, body); + if (Zstd.isError(ret) || ret != size) { + throw new IllegalArgumentException("Malformed state token"); + } + return out; + default: + throw new IllegalArgumentException("Malformed state token"); + } + } + + private static byte[] prefixed(byte tag, byte[] body) { + byte[] out = new byte[1 + body.length]; + out[0] = tag; + System.arraycopy(body, 0, out, 1, body.length); + return out; + } +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/Unauthorized.java b/vgirpc/src/main/java/farm/query/vgirpc/http/Unauthorized.java new file mode 100644 index 0000000..14b3656 --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/Unauthorized.java @@ -0,0 +1,56 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +import java.util.LinkedHashMap; +import java.util.List; +import java.util.Map; + +/** + * The body half of the standardized 401 ({@code docs/unauthorized-spec.md} §4). + * + *

    This port always answers JSON. §4.2 permits that — a service may skip the + * HTML page entirely; what it must never do is answer a non-HTML request with + * HTML — and it keeps the one part clients parse, the reason code, identical + * for browsers and RPC clients alike.

    + */ +final class Unauthorized { + + private Unauthorized() {} + + /** + * Compose the operator-facing proxy note for §5. + * + *

    The wording is not normative. It must convey that the service is only + * reachable through its proxy, which headers that proxy has to set, and + * that a rejection here is at least as likely to be a proxy + * misconfiguration as a bad credential — which is the deployment where + * every request 401s and rotating credentials fixes nothing.

    + */ + static String proxyHint(List headers) { + if (headers.isEmpty()) return ""; + String listed = String.join(", ", headers); + String noun = headers.size() == 1 ? "header" : "headers"; + return "This service only accepts requests that arrive through its configured reverse proxy, " + + "which must set the " + listed + " " + noun + ". A rejection here is at least as likely " + + "to be a proxy that is not forwarding " + (headers.size() == 1 ? "that header" : "those headers") + + " — or a request that reached the service without passing through the proxy at all — as it " + + "is a bad credential. Check the proxy configuration before rotating credentials."; + } + + /** + * Build the §4.3 envelope. + * + *

    {@code proxy_hint} is absent, not empty, when it does not apply: its + * presence alone has to be a usable signal.

    + */ + static Map envelope(AuthReason reason, String detail, String proxyHint) { + Map body = new LinkedHashMap<>(); + body.put("error", "unauthorized"); + body.put("reason", reason.code()); + body.put("detail", detail != null ? detail : ""); + if (proxyHint != null && !proxyHint.isEmpty()) body.put("proxy_hint", proxyHint); + return body; + } +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/auth/ProxyProof.java b/vgirpc/src/main/java/farm/query/vgirpc/http/auth/ProxyProof.java index 7aff625..3844c15 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/http/auth/ProxyProof.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/auth/ProxyProof.java @@ -5,7 +5,8 @@ import farm.query.vgirpc.AuthContext; import farm.query.vgirpc.http.Authenticator; -import farm.query.vgirpc.http.InvalidCredentials; +import farm.query.vgirpc.http.AuthFailure; +import farm.query.vgirpc.http.AuthReason; import jakarta.servlet.http.HttpServletRequest; import java.nio.charset.StandardCharsets; import java.util.ArrayDeque; @@ -381,9 +382,11 @@ public static Authenticator require(Config config, Authenticator inner) { claims = verifyRequest(request, config, cache); } catch (ProofFailure failure) { if (required) { - // Uniform message: the caller controls kid, so echoing any detail would reflect - // attacker-supplied text. - throw new InvalidCredentials("proxy proof required"); + // Every outcome — absent, malformed, unknown kid, expired, bad MAC, replayed — + // collapses onto one reason and one message. The caller controls kid, so echoing + // any detail would reflect attacker-supplied text, and distinguishing the stages + // would turn the rejection into the oracle §6 of the proof spec forbids. + throw new AuthFailure(AuthReason.PROXY_REQUIRED, "proxy proof required"); } Map unverified = new LinkedHashMap<>(); unverified.put("verified", "false"); diff --git a/vgirpc/src/main/java/farm/query/vgirpc/wire/Metadata.java b/vgirpc/src/main/java/farm/query/vgirpc/wire/Metadata.java index cce15e4..898f836 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/wire/Metadata.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/wire/Metadata.java @@ -12,6 +12,14 @@ private Metadata() {} public static final String RPC_METHOD = "vgi_rpc.method"; public static final String STREAM_STATE = "vgi_rpc.stream_state#b64"; + /** + * A stream's call state — the half fixed for the life of the + * call (the resolved schemas, the stream id). Minted once by + * {@code /init}, never re-issued, and echoed by the client on every + * subsequent request; only {@link #STREAM_STATE}, the cursor, comes back + * per turn. + */ + public static final String CALL_STATE = "vgi_rpc.call_state#b64"; public static final String CANCEL = "vgi_rpc.cancel"; public static final String LOG_LEVEL = "vgi_rpc.log_level"; public static final String LOG_MESSAGE = "vgi_rpc.log_message"; diff --git a/vgirpc/src/test/java/farm/query/vgirpc/AccessLogHookTest.java b/vgirpc/src/test/java/farm/query/vgirpc/AccessLogHookTest.java new file mode 100644 index 0000000..95f4fe3 --- /dev/null +++ b/vgirpc/src/test/java/farm/query/vgirpc/AccessLogHookTest.java @@ -0,0 +1,403 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc; + +import com.fasterxml.jackson.databind.JsonNode; +import com.fasterxml.jackson.databind.ObjectMapper; +import org.junit.jupiter.api.Test; + +import java.io.ByteArrayOutputStream; +import java.io.IOException; +import java.io.OutputStream; +import java.util.ArrayList; +import java.util.LinkedHashMap; +import java.util.List; +import java.util.Map; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.TimeUnit; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** + * The parts of the access-log contract the JSON schema cannot express. + * + *

    {@code vgi-rpc-test --access-log} checks record shape; nothing in + * a schema can say that two records of one stream shared a sampling decision, + * that a dropped record was reported, or that a redactor which threw dropped the + * claims instead of leaking them. + */ +final class AccessLogHookTest { + + private static final ObjectMapper JSON = new ObjectMapper(); + + // ---- sampling -------------------------------------------------------- + + /** + * Rule 2 of §5bb: the decision is a function of the call, not of the record. + * Random per-record sampling shreds a multi-record stream into fragments + * indistinguishable from data loss. + */ + @Test + void sampling_decides_once_per_stream_not_per_record() throws Exception { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + AccessLogHook hook = AccessLogHook.builder(out).sampleRate(0.5).build(); + + // Twenty stream ids, ten records each. Whatever the coin said for a + // stream, it must have said for every record of it. + Map kept = new LinkedHashMap<>(); + for (int s = 0; s < 20; s++) { + String streamId = String.format("%032x", s); + for (int r = 0; r < 10; r++) emit(hook, streamRecord(streamId), null); + kept.put(streamId, 0); + } + for (JsonNode rec : records(out)) { + kept.merge(rec.get("stream_id").asText(), 1, Integer::sum); + } + for (Map.Entry e : kept.entrySet()) { + assertTrue(e.getValue() == 0 || e.getValue() == 10, + "stream " + e.getKey() + " was split: " + e.getValue() + " of 10 records kept"); + } + assertTrue(kept.values().stream().anyMatch(v -> v == 10), "sampling kept nothing at all at rate 0.5"); + assertTrue(kept.values().stream().anyMatch(v -> v == 0), "sampling dropped nothing at all at rate 0.5"); + } + + /** The same identifier must survive a restart with the same decision. */ + @Test + void sampling_is_stable_across_hook_instances() throws Exception { + List ids = new ArrayList<>(); + for (int s = 0; s < 40; s++) ids.add(String.format("%032x", s)); + + assertEquals(sampleOnce(ids), sampleOnce(ids), + "the same stream ids must survive two independent hooks with the same fate"); + } + + /** + * Rule 1 of §5bb. A rate below 1 exists because successful calls repeat, + * which is exactly what failures do not. + */ + @Test + void errors_are_never_sampled_out() throws Exception { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + // Low enough that no successful call survives, so anything in the log + // got there by bypassing the decision rather than by luck. + AccessLogHook hook = AccessLogHook.builder(out).sampleRate(0.000001).build(); + + for (int s = 0; s < 50; s++) emit(hook, streamRecord(String.format("%032x", s)), null); + for (int s = 50; s < 100; s++) { + emit(hook, streamRecord(String.format("%032x", s)), new IllegalStateException("boom")); + } + + List records = records(out); + assertEquals(50, records.size(), "every error and no success should have been kept"); + for (JsonNode rec : records) assertEquals("error", rec.get("status").asText()); + } + + /** Rule 3 of §5bb: a consumer counting calls has to divide by the rate. */ + @Test + void every_sampled_in_record_carries_the_rate() throws Exception { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + AccessLogHook hook = AccessLogHook.builder(out).sampleRate(0.5).build(); + for (int s = 0; s < 40; s++) emit(hook, streamRecord(String.format("%032x", s)), null); + + List records = records(out); + assertFalse(records.isEmpty()); + for (JsonNode rec : records) { + assertEquals(0.5, rec.get("sample_rate").asDouble(), 1e-9); + } + } + + /** Unsampled servers must not emit the field at all. */ + @Test + void rate_one_emits_no_sample_rate() throws Exception { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + AccessLogHook hook = AccessLogHook.builder(out).build(); + emit(hook, unaryRecord(), null); + assertFalse(records(out).get(0).has("sample_rate")); + } + + /** A rate of {@code 100} meaning "100%" would otherwise silently log everything. */ + @Test + void an_out_of_range_rate_fails_at_startup() { + AccessLogHook.Builder b = AccessLogHook.builder(new ByteArrayOutputStream()); + assertThrows(IllegalArgumentException.class, () -> b.sampleRate(100)); + assertThrows(IllegalArgumentException.class, () -> b.sampleRate(0.0)); + assertThrows(IllegalArgumentException.class, () -> b.sampleRate(-0.5)); + assertThrows(IllegalArgumentException.class, () -> b.sampleRate(Double.NaN)); + } + + // ---- truncation markers ---------------------------------------------- + + /** + * §5b: {@code "payload_omitted"} means nothing was lost to a cap. Sharing the + * size-driven {@code true} made the marker fire on nearly every record and + * left a consumer scanning for real data loss with nothing to filter on. + */ + @Test + void omitting_payloads_is_not_reported_as_truncation() throws Exception { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + emit(AccessLogHook.builder(out).logPayloads(false).build(), unaryRecord(), null); + + JsonNode rec = records(out).get(0); + assertEquals("payload_omitted", rec.get("truncated").asText()); + assertFalse(rec.get("truncated").isBoolean(), "payload omission must not read as size-driven shedding"); + assertFalse(rec.has("request_data")); + assertTrue(rec.get("original_request_bytes").asInt() > 0); + } + + /** The default logs payloads, and a record that lost nothing carries no marker. */ + @Test + void logging_payloads_emits_no_truncation_marker() throws Exception { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + emit(AccessLogHook.builder(out).build(), unaryRecord(), null); + + JsonNode rec = records(out).get(0); + assertFalse(rec.has("truncated")); + assertEquals("AQIDBA==", rec.get("request_data").asText()); + } + + // ---- claim redaction ------------------------------------------------- + + /** Key-based, and keys survive: "did this token carry an email claim" stays answerable. */ + @Test + void claims_are_redacted_by_key_and_keys_are_kept() throws Exception { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + DispatchInfo info = unaryRecord(); + info.claims = new LinkedHashMap<>(Map.of( + "sub", "user-42", + "email", "alice@example.com", + "api_key", "sk-live-abcdef", + "role", "admin", + "context", "reached alice@example.com")); + + emit(AccessLogHook.builder(out).build(), info, null); + JsonNode claims = records(out).get(0).get("claims"); + + assertEquals("[redacted]", claims.get("email").asText()); + assertEquals("[redacted]", claims.get("api_key").asText()); + assertEquals("user-42", claims.get("sub").asText()); + assertEquals("admin", claims.get("role").asText()); + // The stated boundary: content is never inspected, only names. + assertEquals("reached alice@example.com", claims.get("context").asText()); + } + + /** Fail closed: unredacted claims on disk cannot be recalled. */ + @Test + void a_redactor_that_throws_drops_the_claims() throws Exception { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + DispatchInfo info = unaryRecord(); + info.claims = new LinkedHashMap<>(Map.of("email", "alice@example.com")); + + emit(AccessLogHook.builder(out) + .claimRedactor(claims -> { throw new IllegalStateException("policy lookup failed"); }) + .build(), info, null); + + String line = out.toString(); + assertFalse(records(out).get(0).has("claims"), "a broken redactor must fail closed, not open"); + assertFalse(line.contains("alice@example.com")); + } + + /** The opt-out, for services that own their logs end to end. */ + @Test + void redaction_can_be_disabled() throws Exception { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + DispatchInfo info = unaryRecord(); + info.claims = new LinkedHashMap<>(Map.of("email", "alice@example.com")); + + emit(AccessLogHook.builder(out).claimRedactor(ClaimRedactor.none()).build(), info, null); + assertEquals("alice@example.com", records(out).get(0).get("claims").get("email").asText()); + } + + // ---- trace correlation ----------------------------------------------- + + /** Both or neither — a record carrying one half joins nothing. */ + @Test + void trace_ids_are_emitted_as_a_pair() throws Exception { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + String traceId = "4bf92f3577b34da6a3ce929d0e0e4736"; + String spanId = "00f067aa0ba902b7"; + emit(AccessLogHook.builder(out) + .traceCorrelator(() -> new String[] {traceId, spanId}) + .build(), unaryRecord(), null); + + JsonNode rec = records(out).get(0); + assertEquals(traceId, rec.get("trace_id").asText()); + assertEquals(spanId, rec.get("span_id").asText()); + } + + /** A dashed UUID would fail schema validation for every record the server writes. */ + @Test + void a_malformed_trace_id_is_dropped_rather_than_emitted() throws Exception { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + emit(AccessLogHook.builder(out) + .traceCorrelator(() -> new String[] {"4bf92f35-77b3-4da6-a3ce-929d0e0e4736", "00f067aa0ba902b7"}) + .build(), unaryRecord(), null); + + JsonNode rec = records(out).get(0); + assertFalse(rec.has("trace_id")); + assertFalse(rec.has("span_id"), "half a trace context is worse than none"); + } + + /** A correlator that throws must not fail the call. */ + @Test + void a_throwing_correlator_is_survivable() throws Exception { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + emit(AccessLogHook.builder(out) + .traceCorrelator(() -> { throw new IllegalStateException("no context"); }) + .build(), unaryRecord(), null); + assertFalse(records(out).get(0).has("trace_id")); + } + + // ---- asynchronous emission ------------------------------------------- + + /** + * §5bc: full means drop, and the drop is reported. A log that loses records + * without saying so is worse than a slow one, because a consumer cannot tell + * a quiet period from a lossy one. + */ + @Test + void a_full_queue_drops_and_reports_what_it_dropped() throws Exception { + GateStream gate = new GateStream(); + AccessLogHook hook = AccessLogHook.builder(gate).asyncQueueSize(1).build(); + try { + // The writer thread takes this one and parks inside write(), leaving + // the queue empty and the drain deterministically stalled. + emit(hook, named("first"), null); + assertTrue(gate.entered.await(10, TimeUnit.SECONDS), "writer thread never reached the sink"); + + emit(hook, named("second")); // fills the one-deep queue + emit(hook, named("dropped-a")); // no room + emit(hook, named("dropped-b")); // no room + + gate.release.countDown(); + awaitLines(gate, 2); + + emit(hook, named("after")); + } finally { + hook.close(); + } + + List records = records(gate.sink); + assertEquals(3, records.size(), "two records should have been dropped, not queued"); + assertEquals(List.of("first", "second", "after"), + records.stream().map(r -> r.get("method").asText()).toList()); + assertFalse(records.get(0).has("dropped_records")); + assertFalse(records.get(1).has("dropped_records")); + assertEquals(2, records.get(2).get("dropped_records").asInt(), + "the first record through after a drop must carry the count"); + } + + /** A queue that never fills reports nothing, and still writes everything. */ + @Test + void async_emission_without_pressure_reports_no_drops() throws Exception { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + AccessLogHook hook = AccessLogHook.builder(out).asyncQueueSize(1024).build(); + for (int i = 0; i < 100; i++) emit(hook, named("call-" + i), null); + hook.close(); + + List records = records(out); + assertEquals(100, records.size()); + for (JsonNode rec : records) assertFalse(rec.has("dropped_records")); + } + + // ---- helpers --------------------------------------------------------- + + private static void emit(AccessLogHook hook, DispatchInfo info) { + emit(hook, info, null); + } + + private static void emit(AccessLogHook hook, DispatchInfo info, Throwable error) { + hook.onDispatchEnd(hook.onDispatchStart(info), info, null, error); + } + + /** Which of {@code ids} a fresh hook at rate 0.5 keeps. */ + private static List sampleOnce(List ids) throws Exception { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + AccessLogHook hook = AccessLogHook.builder(out).sampleRate(0.5).build(); + for (String id : ids) emit(hook, streamRecord(id), null); + return records(out).stream().map(r -> r.get("stream_id").asText()).toList(); + } + + private static DispatchInfo unaryRecord() { + DispatchInfo info = new DispatchInfo(); + info.method = "echo"; + info.methodType = "unary"; + info.serverId = "0123456789ab"; + info.protocol = "TestService"; + info.protocolHash = "0".repeat(64); + info.requestData = new byte[] {1, 2, 3, 4}; + return info; + } + + private static DispatchInfo named(String method) { + DispatchInfo info = unaryRecord(); + info.method = method; + return info; + } + + private static DispatchInfo streamRecord(String streamId) { + DispatchInfo info = unaryRecord(); + info.methodType = "stream"; + info.streamId = streamId; + return info; + } + + private static List records(ByteArrayOutputStream out) throws IOException { + List parsed = new ArrayList<>(); + for (String line : out.toString().split("\n")) { + if (!line.isBlank()) parsed.add(JSON.readTree(line)); + } + return parsed; + } + + /** Spin until the sink holds {@code n} complete lines, or give up. */ + private static void awaitLines(GateStream gate, int n) throws InterruptedException { + long deadline = System.nanoTime() + TimeUnit.SECONDS.toNanos(10); + while (System.nanoTime() < deadline) { + if (gate.lines() >= n) return; + Thread.sleep(5); + } + throw new AssertionError("sink never reached " + n + " lines (saw " + gate.lines() + ")"); + } + + /** + * A sink that parks the writer thread inside its first write, so the async + * queue can be filled and overflowed with no timing assumptions. + */ + private static final class GateStream extends OutputStream { + final ByteArrayOutputStream sink = new ByteArrayOutputStream(); + final CountDownLatch entered = new CountDownLatch(1); + final CountDownLatch release = new CountDownLatch(1); + private boolean armed = true; + + @Override public void write(int b) { + gate(); + synchronized (sink) { sink.write(b); } + } + + @Override public void write(byte[] b, int off, int len) { + gate(); + synchronized (sink) { sink.write(b, off, len); } + } + + int lines() { + synchronized (sink) { + return (int) sink.toString().chars().filter(ch -> ch == '\n').count(); + } + } + + private void gate() { + if (!armed) return; + armed = false; + entered.countDown(); + try { + release.await(10, TimeUnit.SECONDS); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + } + } + } +} diff --git a/vgirpc/src/test/java/farm/query/vgirpc/http/AccessLogEgressTest.java b/vgirpc/src/test/java/farm/query/vgirpc/http/AccessLogEgressTest.java new file mode 100644 index 0000000..3edb314 --- /dev/null +++ b/vgirpc/src/test/java/farm/query/vgirpc/http/AccessLogEgressTest.java @@ -0,0 +1,249 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +import com.fasterxml.jackson.databind.JsonNode; +import com.fasterxml.jackson.databind.ObjectMapper; +import com.github.luben.zstd.Zstd; +import farm.query.vgirpc.AccessLogHook; +import farm.query.vgirpc.RpcConnection; +import farm.query.vgirpc.RpcServer; +import farm.query.vgirpc.external.ExternalLocationConfig; +import farm.query.vgirpc.external.ExternalStorage; +import farm.query.vgirpc.transport.RpcTransport; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.Test; + +import java.io.ByteArrayOutputStream; +import java.io.IOException; +import java.io.InputStream; +import java.io.OutputStream; +import java.io.PipedInputStream; +import java.io.PipedOutputStream; +import java.net.URI; +import java.net.http.HttpClient; +import java.net.http.HttpRequest; +import java.net.http.HttpResponse; +import java.time.Duration; +import java.util.List; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** + * §4.8: what crossed the wire, measured where it can actually be measured. + * + *

    {@code response_bytes} cannot be read where the record is written — response + * compression runs after the handler returns — so this drives a real HTTP server + * and compares the number in the log against the bytes the client received. + * A record emitted at dispatch time would report the uncompressed size, which + * for a compressible Arrow batch is wrong by roughly three orders of magnitude. + */ +final class AccessLogEgressTest { + + private static final ObjectMapper JSON = new ObjectMapper(); + + /** Large and highly compressible, so a conflated figure cannot pass by accident. */ + private static final String PAYLOAD = "vgi-rpc-egress-accounting-probe ".repeat(8192); + + public interface EchoService { + String echo(String value); + } + + public static final class EchoImpl implements EchoService { + @Override public String echo(String value) { return value; } + } + + /** Swallows uploads and hands back a URL nobody fetches: only the size matters here. */ + private static final class CountingStorage implements ExternalStorage { + private final java.util.concurrent.atomic.AtomicLong uploaded = + new java.util.concurrent.atomic.AtomicLong(); + + @Override public URI upload(byte[] body, String contentEncoding) { + uploaded.addAndGet(body.length); + return URI.create("https://storage.invalid/obj/" + uploaded.get()); + } + } + + private HttpServer server; + private final ByteArrayOutputStream accessLog = new ByteArrayOutputStream(); + + @AfterEach + void stop() throws Exception { + if (server != null) server.stop(); + } + + @Test + void response_bytes_is_the_compressed_size_not_the_arrow_size() throws Exception { + RpcServer rpc = new RpcServer(EchoService.class, new EchoImpl()); + rpc.setDispatchHook(AccessLogHook.builder(accessLog).serverVersion("egress-test").build()); + server = new HttpServer(rpc, HttpServer.Config.builder() + .prefix("/vgi") + .supportedEncodings(List.of(MediaTypes.ZSTD, MediaTypes.GZIP)) + .build()); + server.start(); + + byte[] request = unaryRequest(PAYLOAD); + HttpResponse resp; + try (HttpClient client = HttpClient.newBuilder().connectTimeout(Duration.ofSeconds(5)).build()) { + resp = client.send(HttpRequest.newBuilder( + URI.create("http://127.0.0.1:" + server.port() + "/vgi/echo")) + .timeout(Duration.ofSeconds(30)) + .header("Content-Type", "application/vnd.apache.arrow.stream") + .header(HttpHeaders.ACCEPT_ENCODING, "zstd, gzip") + .POST(HttpRequest.BodyPublishers.ofByteArray(request)) + .build(), HttpResponse.BodyHandlers.ofByteArray()); + } + assertEquals(200, resp.statusCode()); + assertEquals(MediaTypes.ZSTD, resp.headers().firstValue(HttpHeaders.CONTENT_ENCODING).orElseThrow()); + + JsonNode rec = onlyRecord(); + assertEquals(resp.body().length, rec.get("response_bytes").asLong(), + "response_bytes must be what the client received, i.e. post-compression"); + assertEquals(request.length, rec.get("request_bytes").asLong(), + "request_bytes is the body as received, before any decoding"); + assertEquals(200, rec.get("http_status").asInt()); + assertEquals(resp.headers().firstValue(HttpHeaders.REQUEST_ID).orElseThrow(), + rec.get("request_id").asText()); + + // The point of the field: an emitter that ran before compression would + // have reported this figure instead, and it is larger by two orders of + // magnitude on a payload that compresses at all. + byte[] uncompressed = Zstd.decompress(resp.body(), (int) Zstd.getFrameContentSize(resp.body())); + assertTrue(uncompressed.length > rec.get("response_bytes").asLong() * 100, + "the probe is meant to compress hard; uncompressed=" + uncompressed.length + + " response_bytes=" + rec.get("response_bytes").asLong()); + } + + /** An uncompressed exchange still reports the true on-wire figures. */ + @Test + void identity_encoding_reports_the_raw_body_sizes() throws Exception { + RpcServer rpc = new RpcServer(EchoService.class, new EchoImpl()); + rpc.setDispatchHook(AccessLogHook.builder(accessLog).build()); + server = new HttpServer(rpc, HttpServer.Config.builder() + .prefix("/vgi").supportedEncodings(List.of()).build()); + server.start(); + + byte[] request = unaryRequest("small"); + HttpResponse resp; + try (HttpClient client = HttpClient.newBuilder().connectTimeout(Duration.ofSeconds(5)).build()) { + resp = client.send(HttpRequest.newBuilder( + URI.create("http://127.0.0.1:" + server.port() + "/vgi/echo")) + .timeout(Duration.ofSeconds(30)) + .header("Content-Type", "application/vnd.apache.arrow.stream") + .POST(HttpRequest.BodyPublishers.ofByteArray(request)) + .build(), HttpResponse.BodyHandlers.ofByteArray()); + } + assertEquals(200, resp.statusCode()); + + JsonNode rec = onlyRecord(); + assertEquals(request.length, rec.get("request_bytes").asLong()); + assertEquals(resp.body().length, rec.get("response_bytes").asLong()); + } + + /** + * The figure nothing at the transport can see: an externalised payload leaves + * a pointer batch of a few hundred bytes in the body while the data itself + * goes to object storage. Without this field it is invisible. + */ + @Test + void externalized_bytes_counts_what_never_touched_the_body() throws Exception { + CountingStorage storage = new CountingStorage(); + RpcServer rpc = new RpcServer(EchoService.class, new EchoImpl()); + rpc.setDispatchHook(AccessLogHook.builder(accessLog).build()); + rpc.setExternalConfig(ExternalLocationConfig.builder() + .storage(storage) + .thresholdBytes(1024) + .urlValidator(ExternalLocationConfig.permissiveValidator()) + .build()); + server = new HttpServer(rpc, HttpServer.Config.builder() + .prefix("/vgi").supportedEncodings(List.of()).build()); + server.start(); + + byte[] request = unaryRequest(PAYLOAD); + HttpResponse resp; + try (HttpClient client = HttpClient.newBuilder().connectTimeout(Duration.ofSeconds(5)).build()) { + resp = client.send(HttpRequest.newBuilder( + URI.create("http://127.0.0.1:" + server.port() + "/vgi/echo")) + .timeout(Duration.ofSeconds(30)) + .header("Content-Type", "application/vnd.apache.arrow.stream") + .POST(HttpRequest.BodyPublishers.ofByteArray(request)) + .build(), HttpResponse.BodyHandlers.ofByteArray()); + } + assertEquals(200, resp.statusCode()); + assertTrue(storage.uploaded.get() > 0, "the probe should have externalised"); + + JsonNode rec = onlyRecord(); + assertEquals(storage.uploaded.get(), rec.get("externalized_bytes").asLong()); + assertTrue(rec.get("response_bytes").asLong() < rec.get("externalized_bytes").asLong(), + "the body should hold only a pointer batch"); + } + + // ---- helpers --------------------------------------------------------- + + private JsonNode onlyRecord() throws IOException { + String[] lines = accessLog.toString().split("\n"); + assertEquals(1, lines.length, "expected exactly one access-log record"); + return JSON.readTree(lines[0]); + } + + /** + * Serialise one real unary {@code echo} request by running the call over an + * in-process pipe pair and teeing the client's outbound bytes. The HTTP + * transport frames a unary call as exactly this IPC stream, so the captured + * bytes are a valid POST body. + */ + private static byte[] unaryRequest(String value) throws Exception { + RpcServer server = new RpcServer(EchoService.class, new EchoImpl()); + PipedOutputStream clientOut = new PipedOutputStream(); + PipedInputStream serverIn = new PipedInputStream(clientOut, 1 << 22); + PipedOutputStream serverOut = new PipedOutputStream(); + PipedInputStream clientIn = new PipedInputStream(serverOut, 1 << 22); + ByteArrayOutputStream captured = new ByteArrayOutputStream(); + + RpcTransport serverTransport = new InProcessTransport(serverIn, serverOut); + RpcTransport clientTransport = new InProcessTransport(clientIn, tee(clientOut, captured)); + + Thread serverThread = new Thread(() -> server.serve(serverTransport), "egress-capture-server"); + serverThread.setDaemon(true); + serverThread.start(); + try (RpcConnection conn = new RpcConnection(clientTransport)) { + assertEquals(value, conn.proxy(EchoService.class).echo(value)); + } finally { + clientTransport.close(); + serverThread.join(5000); + serverTransport.close(); + } + return captured.toByteArray(); + } + + /** Writes through to the transport while keeping a copy of the request bytes. */ + private static OutputStream tee(OutputStream target, ByteArrayOutputStream copy) { + return new OutputStream() { + @Override public void write(int b) throws IOException { + target.write(b); + copy.write(b); + } + @Override public void write(byte[] b, int off, int len) throws IOException { + target.write(b, off, len); + copy.write(b, off, len); + } + @Override public void flush() throws IOException { target.flush(); } + @Override public void close() throws IOException { target.close(); } + }; + } + + private record InProcessTransport(InputStream in, OutputStream out) implements RpcTransport { + @Override public InputStream reader() { return in; } + @Override public OutputStream writer() { return out; } + @Override public void close() { + try { + out.close(); + in.close(); + } catch (IOException ignored) { + // Test pipes; nothing to recover. + } + } + } +} diff --git a/vgirpc/src/test/java/farm/query/vgirpc/http/CorsTest.java b/vgirpc/src/test/java/farm/query/vgirpc/http/CorsTest.java new file mode 100644 index 0000000..cc72bb9 --- /dev/null +++ b/vgirpc/src/test/java/farm/query/vgirpc/http/CorsTest.java @@ -0,0 +1,303 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +import farm.query.vgirpc.RpcServer; +import farm.query.vgirpc.http.auth.ProxyProof; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.Test; + +import java.net.URI; +import java.net.http.HttpClient; +import java.net.http.HttpRequest; +import java.net.http.HttpResponse; +import java.time.Duration; +import java.util.Arrays; +import java.util.LinkedHashSet; +import java.util.Locale; +import java.util.List; +import java.util.Map; +import java.util.Set; +import java.util.function.Consumer; +import java.util.stream.Collectors; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** + * CORS end to end, the Java-side mirror of the shared {@code TestCors} group. + * + *

    The load-bearing case is {@link #every_advertised_capability_is_exposed}: + * an advertised-but-unexposed capability header is invisible to a browser and + * to nothing else, so every other test in this repo — driven by a client that + * ignores CORS entirely — passes right through it. + */ +final class CorsTest { + + /** The origin the shared conformance suite preflights with. */ + private static final String ORIGIN = "https://conformance.example"; + + public interface EchoService { + String echo(String value); + } + + public static final class EchoImpl implements EchoService { + @Override public String echo(String value) { return value; } + } + + private HttpServer server; + private String base; + + @AfterEach + void stop() throws Exception { + if (server != null) server.stop(); + } + + private void start(Consumer configure) throws Exception { + HttpServer.Config.Builder b = HttpServer.Config.builder().prefix("/vgi"); + configure.accept(b); + server = new HttpServer(new RpcServer(EchoService.class, new EchoImpl()), b.build()); + server.start(); + base = "http://127.0.0.1:" + server.port() + "/vgi"; + } + + private void startWithCors() throws Exception { + start(b -> b.corsOrigin(ORIGIN)); + } + + // ---- opt-in ---------------------------------------------------------- + + /** Off by default: an unconfigured server grants nothing to any origin. */ + @Test + void an_unconfigured_server_emits_no_cors_headers() throws Exception { + start(b -> { }); + HttpResponse resp = preflight(base + "/echo", "content-type"); + assertEquals(200, resp.statusCode()); + assertFalse(resp.headers().firstValue(CorsPolicy.ALLOW_ORIGIN).isPresent(), + "an unconfigured server must not grant cross-origin access"); + assertFalse(resp.headers().firstValue(CorsPolicy.EXPOSE_HEADERS).isPresent()); + } + + /** An origin outside the allowlist is refused by omission, not by status. */ + @Test + void an_unlisted_origin_gets_no_grant() throws Exception { + startWithCors(); + HttpResponse resp = options(base + "/echo", Map.of( + CorsPolicy.ORIGIN, "https://evil.example", + "Access-Control-Request-Method", "POST")); + assertFalse(resp.headers().firstValue(CorsPolicy.ALLOW_ORIGIN).isPresent()); + } + + /** A request with no {@code Origin} is same-origin; CORS has nothing to say. */ + @Test + void a_request_without_an_origin_gets_no_grant() throws Exception { + startWithCors(); + assertFalse(options(base + "/health", Map.of()) + .headers().firstValue(CorsPolicy.ALLOW_ORIGIN).isPresent()); + } + + // ---- preflight ------------------------------------------------------- + + /** The configured origin is echoed, POST is permitted, and the preflight caches. */ + @Test + void the_preflight_grants_the_configured_origin() throws Exception { + startWithCors(); + HttpResponse resp = preflight(base + "/echo", "content-type"); + assertEquals(200, resp.statusCode()); + assertEquals(ORIGIN, header(resp, CorsPolicy.ALLOW_ORIGIN)); + assertEquals(CorsPolicy.ORIGIN, header(resp, "Vary"), + "a per-origin answer must not be cached across origins"); + assertTrue(header(resp, CorsPolicy.ALLOW_METHODS).contains("POST"), + "every RPC call is a POST; refusing it blocks all of them"); + assertEquals(Long.toString(HttpServer.Config.DEFAULT_CORS_MAX_AGE_SECONDS), + header(resp, CorsPolicy.MAX_AGE)); + } + + /** + * The request half of CORS: a browser sends only the headers the preflight + * named. Dropping one is invisible on a plain call and takes out whichever + * feature rode on it — sticky sessions, proxy proof, codec preference. + */ + @Test + void the_preflight_permits_every_request_header_a_client_sends() throws Exception { + startWithCors(); + for (String header : List.of("content-type", HttpHeaders.X_VGI_ACCEPT_ENCODING, + StickyHeaders.SESSION, StickyHeaders.SESSION_ACCEPT, ProxyProof.PROOF_HEADER)) { + Set allowed = split(header(preflight(base + "/echo", header), + CorsPolicy.ALLOW_HEADERS)); + assertTrue(allowed.contains(header.toLowerCase(Locale.ROOT)), + "a browser may not send " + header + "; allowed: " + allowed); + } + } + + /** A preflight naming no headers still answers with the request-side surface. */ + @Test + void a_preflight_without_requested_headers_falls_back_to_the_default_set() throws Exception { + startWithCors(); + HttpResponse resp = options(base + "/echo", Map.of( + CorsPolicy.ORIGIN, ORIGIN, + "Access-Control-Request-Method", "POST")); + Set allowed = split(header(resp, CorsPolicy.ALLOW_HEADERS)); + assertTrue(allowed.contains("content-type")); + assertTrue(allowed.contains(StickyHeaders.SESSION.toLowerCase(Locale.ROOT))); + } + + /** {@code Access-Control-Max-Age: 0} means "omit", not "do not cache". */ + @Test + void a_zero_max_age_omits_the_header() throws Exception { + start(b -> b.corsOrigin(ORIGIN).corsMaxAgeSeconds(0)); + assertFalse(preflight(base + "/echo", "content-type") + .headers().firstValue(CorsPolicy.MAX_AGE).isPresent()); + } + + /** A wildcard answers every origin with the literal {@code "*"}. */ + @Test + void a_wildcard_origin_grants_everyone() throws Exception { + start(b -> b.corsOrigin(CorsPolicy.WILDCARD)); + HttpResponse resp = options(base + "/echo", Map.of( + CorsPolicy.ORIGIN, "https://anything.example", + "Access-Control-Request-Method", "POST")); + assertEquals(CorsPolicy.WILDCARD, header(resp, CorsPolicy.ALLOW_ORIGIN)); + assertFalse(resp.headers().firstValue("Vary").isPresent(), + "a wildcard answer is origin-independent, so nothing varies on it"); + } + + // ---- actual responses ------------------------------------------------ + + /** + * The grant has to ride the real response too: a browser re-checks it there + * and discards the body without it, so a preflight-only implementation + * fails every call while passing a naive preflight test. + */ + @Test + void an_actual_response_carries_the_grant() throws Exception { + startWithCors(); + try (HttpClient client = newClient()) { + HttpResponse resp = client.send( + HttpRequest.newBuilder(URI.create(base + "/health")) + .header(CorsPolicy.ORIGIN, ORIGIN) + .timeout(Duration.ofSeconds(10)).GET().build(), + HttpResponse.BodyHandlers.ofString()); + assertEquals(200, resp.statusCode()); + assertEquals(ORIGIN, resp.headers().firstValue(CorsPolicy.ALLOW_ORIGIN).orElseThrow()); + assertTrue(split(resp.headers().firstValue(CorsPolicy.EXPOSE_HEADERS).orElseThrow()) + .contains(HttpServer.SUPPORTED_ENCODINGS_HEADER.toLowerCase(Locale.ROOT))); + } + } + + // ---- the expose list ------------------------------------------------- + + /** + * Whatever this server advertises, it exposes — checked against what it + * actually puts on the wire rather than a copy of the list, so a new + * capability header added to {@code applyCapabilityHeaders} without an + * expose entry fails here instead of silently shipping. + */ + @Test + void every_advertised_capability_is_exposed() throws Exception { + start(b -> b.corsOrigin(ORIGIN) + .advertiseMaxRequestBytes(true) + .advertisedMaxResponseBytes(1 << 20) + .advertisedMaxExternalizedResponseBytes(1 << 20) + .proxyProofRequired(true) + .stickyEnabled(true) + .stickyEchoHeaders(Map.of("x-echo-marker", "value"))); + HttpResponse resp = preflight(base + "/health", "content-type"); + Set exposed = split(header(resp, CorsPolicy.EXPOSE_HEADERS)); + + Set advertised = resp.headers().map().keySet().stream() + .map(n -> n.toLowerCase(Locale.ROOT)) + .filter(n -> n.startsWith("vgi-") || n.startsWith("x-vgi-")) + .collect(Collectors.toCollection(LinkedHashSet::new)); + assertFalse(advertised.isEmpty(), "no capability headers to check against"); + + advertised.removeAll(exposed); + assertTrue(advertised.isEmpty(), + "advertised but not readable by a browser: " + advertised + + " — add them to " + CorsPolicy.EXPOSE_HEADERS); + } + + /** The error flag rides responses, never {@code /health}, so it needs its own check. */ + @Test + void the_error_flag_is_exposed() throws Exception { + startWithCors(); + Set exposed = split(header(preflight(base + "/echo", "content-type"), + CorsPolicy.EXPOSE_HEADERS)); + assertTrue(exposed.contains(HttpServer.RPC_ERROR_HEADER.toLowerCase(Locale.ROOT)), + "without it a browser cannot tell an error 200 from a result 200"); + } + + /** Same for the 401 reason code, which describes a rejection rather than a capability. */ + @Test + void the_auth_reason_is_exposed() throws Exception { + startWithCors(); + Set exposed = split(header(preflight(base + "/echo", "content-type"), + CorsPolicy.EXPOSE_HEADERS)); + assertTrue(exposed.contains(HttpHeaders.VGI_AUTH_REASON.toLowerCase(Locale.ROOT))); + } + + /** Conditional headers stay off the list when the server never emits them. */ + @Test + void unemitted_headers_are_not_exposed() throws Exception { + startWithCors(); // no sticky, no proof, no upload URLs + Set exposed = split(header(preflight(base + "/echo", "content-type"), + CorsPolicy.EXPOSE_HEADERS)); + assertFalse(exposed.contains(StickyHeaders.SESSION.toLowerCase(Locale.ROOT))); + assertFalse(exposed.contains(ProxyProof.PROOF_REQUIRED_HEADER.toLowerCase(Locale.ROOT))); + assertFalse(exposed.contains(HttpServer.UPLOAD_URL_HEADER.toLowerCase(Locale.ROOT))); + } + + // ---- configuration --------------------------------------------------- + + /** An all-blank origin list is a typo, not a policy — fail rather than allow nothing. */ + @Test + void a_blank_origin_list_is_rejected() { + assertThrows(IllegalArgumentException.class, + () -> new CorsPolicy(List.of(" "), 7200, List.of())); + } + + @Test + void a_negative_max_age_is_rejected() { + assertThrows(IllegalArgumentException.class, + () -> HttpServer.Config.builder().corsOrigin(ORIGIN).corsMaxAgeSeconds(-1).build()); + } + + // ---- helpers --------------------------------------------------------- + + private static HttpClient newClient() { + return HttpClient.newBuilder().connectTimeout(Duration.ofSeconds(10)).build(); + } + + private static HttpResponse preflight(String url, String requestHeaders) throws Exception { + return options(url, Map.of( + CorsPolicy.ORIGIN, ORIGIN, + "Access-Control-Request-Method", "POST", + CorsPolicy.REQUEST_HEADERS, requestHeaders)); + } + + private static HttpResponse options(String url, Map headers) throws Exception { + HttpRequest.Builder b = HttpRequest.newBuilder(URI.create(url)) + .method("OPTIONS", HttpRequest.BodyPublishers.noBody()) + .timeout(Duration.ofSeconds(10)); + headers.forEach(b::header); + try (HttpClient client = newClient()) { + return client.send(b.build(), HttpResponse.BodyHandlers.discarding()); + } + } + + private static String header(HttpResponse resp, String name) { + return resp.headers().firstValue(name).orElseThrow( + () -> new AssertionError("missing response header: " + name)); + } + + /** Split a comma-separated header value into a lowercase name set. */ + private static Set split(String value) { + return Arrays.stream(value.split(",")) + .map(s -> s.trim().toLowerCase(Locale.ROOT)) + .filter(s -> !s.isEmpty()) + .collect(Collectors.toCollection(LinkedHashSet::new)); + } +} diff --git a/vgirpc/src/test/java/farm/query/vgirpc/http/HttpStreamHandlerResumeTest.java b/vgirpc/src/test/java/farm/query/vgirpc/http/HttpStreamHandlerResumeTest.java index 777233d..a3606bc 100644 --- a/vgirpc/src/test/java/farm/query/vgirpc/http/HttpStreamHandlerResumeTest.java +++ b/vgirpc/src/test/java/farm/query/vgirpc/http/HttpStreamHandlerResumeTest.java @@ -95,39 +95,48 @@ private static byte[] initRequest(RpcServer server, String method, Map md = Wire.requestMetadata(method); md.put(Metadata.STREAM_STATE, token); + if (callToken != null) md.put(Metadata.CALL_STATE, callToken); Wire.writeZeroBatch(w, RpcStream.EMPTY_SCHEMA, md); } return out.toByteArray(); } /** Parse a producer response: data row values + trailing continuation token (null when finished). */ - private record Turn(List values, String token, String error) {} + private record Turn(List values, String token, String callToken, String error) {} private static Turn readTurn(byte[] response) throws Exception { List values = new ArrayList<>(); String token = null; + String callToken = null; try (IpcStreamReader r = new IpcStreamReader(new ByteArrayInputStream(response), Allocators.root())) { Map md; while ((md = r.readNextBatch()) != null) { if (md.containsKey(Metadata.LOG_LEVEL) && "EXCEPTION".equals(md.get(Metadata.LOG_LEVEL))) { - return new Turn(values, null, md.get(Metadata.LOG_MESSAGE)); + return new Turn(values, null, null, md.get(Metadata.LOG_MESSAGE)); } VectorSchemaRoot root = r.root(); if (root.getRowCount() == 0) { if (md.containsKey(Metadata.STREAM_STATE)) token = md.get(Metadata.STREAM_STATE); + if (md.containsKey(Metadata.CALL_STATE)) callToken = md.get(Metadata.CALL_STATE); continue; } BigIntVector v = (BigIntVector) root.getVector(0); for (int i = 0; i < root.getRowCount(); i++) values.add(v.get(i)); } } - return new Turn(values, token, null); + return new Turn(values, token, callToken, null); } @Test @@ -144,16 +153,16 @@ void continuationResumesOnFreshHandler() throws Exception { RpcServer serverB = new RpcServer(CounterService.class, new CounterServiceImpl()); HttpStreamHandler handlerB = new HttpStreamHandler(serverB, KEY, 0, Long.MAX_VALUE); - Turn second = readTurn(handlerB.handleExchange("count_to", continuationRequest("count_to", first.token()))); + Turn second = readTurn(handlerB.handleExchange("count_to", continuationRequest("count_to", first.token(), first.callToken()))); assertNull(second.error()); assertEquals(List.of(1L), second.values()); assertNotNull(second.token()); - Turn third = readTurn(handlerB.handleExchange("count_to", continuationRequest("count_to", second.token()))); + Turn third = readTurn(handlerB.handleExchange("count_to", continuationRequest("count_to", second.token(), first.callToken()))); assertEquals(List.of(2L), third.values()); // The stream finishes on whichever handler holds the final token. - Turn last = readTurn(handlerB.handleExchange("count_to", continuationRequest("count_to", third.token()))); + Turn last = readTurn(handlerB.handleExchange("count_to", continuationRequest("count_to", third.token(), first.callToken()))); assertNull(last.error()); assertTrue(last.values().isEmpty()); assertNull(last.token(), "finished producer must not mint a token"); @@ -169,12 +178,12 @@ void wildcardImplStillLearnsFromInit() throws Exception { HttpStreamHandler handlerA = new HttpStreamHandler(serverA, KEY, 0, Long.MAX_VALUE); Turn first = readTurn(handlerA.handleInit("count_to", initRequest(serverA, "count_to", Map.of("limit", 2L)))); assertNotNull(first.token()); - Turn refused = readTurn(handler.handleExchange("count_to", continuationRequest("count_to", first.token()))); + Turn refused = readTurn(handler.handleExchange("count_to", continuationRequest("count_to", first.token(), first.callToken()))); assertNotNull(refused.error()); assertTrue(refused.error().contains("Cannot resolve state type"), refused.error()); // …but the in-process path (init then exchange on the same handler) still works. - Turn cont = readTurn(handlerA.handleExchange("count_to", continuationRequest("count_to", first.token()))); + Turn cont = readTurn(handlerA.handleExchange("count_to", continuationRequest("count_to", first.token(), first.callToken()))); assertNull(cont.error()); assertEquals(List.of(1L), cont.values()); } diff --git a/vgirpc/src/test/java/farm/query/vgirpc/http/StateTokenTest.java b/vgirpc/src/test/java/farm/query/vgirpc/http/StateTokenTest.java index 8f92699..bbf18a3 100644 --- a/vgirpc/src/test/java/farm/query/vgirpc/http/StateTokenTest.java +++ b/vgirpc/src/test/java/farm/query/vgirpc/http/StateTokenTest.java @@ -9,6 +9,8 @@ import static org.junit.jupiter.api.Assertions.assertArrayEquals; import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertNull; +import static org.junit.jupiter.api.Assertions.assertNotNull; import static org.junit.jupiter.api.Assertions.assertThrows; import static org.junit.jupiter.api.Assertions.assertTrue; @@ -21,27 +23,33 @@ final class StateTokenTest { private static final String ANON = ""; + /** Fixed call id: the token tests are about the envelope, not the id. */ + private static final byte[] CALL_ID = { + 1, 1, 2, 3, 5, 8, 13, 21, 34, 55, 89, (byte) 144, (byte) 233, 77, 55, 32 + }; + @Test void roundtrips_state_output_input_streamId() { - StateToken src = new StateToken( - new byte[]{1, 2, 3}, - new byte[]{4, 5}, - new byte[]{6}, - "stream-abc", - 1_700_000_000L); + StateToken src = new StateToken(new byte[]{1, 2, 3}, CALL_ID, 1_700_000_000L); byte[] packed = src.pack(KEY, ANON); StateToken out = StateToken.unpack(packed, KEY, 0, ANON); assertArrayEquals(src.state(), out.state()); - assertArrayEquals(src.outputSchema(), out.outputSchema()); - assertArrayEquals(src.inputSchema(), out.inputSchema()); - assertEquals(src.streamId(), out.streamId()); + assertArrayEquals(src.callId(), out.callId()); assertEquals(src.createdAt(), out.createdAt()); + + // The schemas and stream id ride the call token now, not the cursor. + CallToken call = new CallToken(new byte[]{4, 5}, new byte[]{6}, "stream-abc", + CALL_ID, 1_700_000_000L); + CallToken callOut = CallToken.unpack(call.pack(KEY, ANON), KEY, 0, ANON); + assertArrayEquals(call.outputSchema(), callOut.outputSchema()); + assertArrayEquals(call.inputSchema(), callOut.inputSchema()); + assertEquals(call.streamId(), callOut.streamId()); + assertArrayEquals(CALL_ID, callOut.callId()); } @Test void ttl_disabled_by_default() { - StateToken src = new StateToken(new byte[0], new byte[0], new byte[0], "", - System.currentTimeMillis() / 1000 - 10_000); + StateToken src = new StateToken(new byte[0], CALL_ID, System.currentTimeMillis() / 1000 - 10_000); byte[] packed = src.pack(KEY, ANON); StateToken out = StateToken.unpack(packed, KEY, 0, ANON); assertEquals(src.createdAt(), out.createdAt()); @@ -49,16 +57,14 @@ void ttl_disabled_by_default() { @Test void ttl_expired_token_rejected() { - StateToken src = new StateToken(new byte[0], new byte[0], new byte[0], "", - System.currentTimeMillis() / 1000 - 100); + StateToken src = new StateToken(new byte[0], CALL_ID, System.currentTimeMillis() / 1000 - 100); byte[] packed = src.pack(KEY, ANON); assertThrows(TokenExpiredException.class, () -> StateToken.unpack(packed, KEY, 30, ANON)); } @Test void ttl_fresh_token_allowed() { - StateToken src = new StateToken(new byte[0], new byte[0], new byte[0], "", - System.currentTimeMillis() / 1000 - 5); + StateToken src = new StateToken(new byte[0], CALL_ID, System.currentTimeMillis() / 1000 - 5); byte[] packed = src.pack(KEY, ANON); StateToken out = StateToken.unpack(packed, KEY, 30, ANON); assertEquals(src.createdAt(), out.createdAt()); @@ -66,8 +72,7 @@ void ttl_fresh_token_allowed() { @Test void tampered_ciphertext_rejected() { - StateToken src = new StateToken(new byte[]{1, 2, 3}, new byte[0], new byte[0], "", - System.currentTimeMillis() / 1000); + StateToken src = new StateToken(new byte[]{1, 2, 3}, CALL_ID, System.currentTimeMillis() / 1000); byte[] packed = src.pack(KEY, ANON); // Decode, flip a byte inside the ciphertext, re-encode. byte[] raw = Base64.getDecoder().decode(packed); @@ -81,8 +86,7 @@ void tampered_ciphertext_rejected() { @Test void tampered_nonce_rejected() { - StateToken src = new StateToken(new byte[]{1, 2, 3}, new byte[0], new byte[0], "", - System.currentTimeMillis() / 1000); + StateToken src = new StateToken(new byte[]{1, 2, 3}, CALL_ID, System.currentTimeMillis() / 1000); byte[] packed = src.pack(KEY, ANON); byte[] raw = Base64.getDecoder().decode(packed); raw[1] ^= 0x01; // first nonce byte @@ -93,8 +97,7 @@ void tampered_nonce_rejected() { @Test void unknown_version_rejected() { - StateToken src = new StateToken(new byte[]{1, 2, 3}, new byte[0], new byte[0], "", - System.currentTimeMillis() / 1000); + StateToken src = new StateToken(new byte[]{1, 2, 3}, CALL_ID, System.currentTimeMillis() / 1000); byte[] packed = src.pack(KEY, ANON); byte[] raw = Base64.getDecoder().decode(packed); raw[0] = (byte) 0x99; @@ -113,8 +116,7 @@ void malformed_base64_rejected() { @Test void wrong_key_rejected() { - StateToken src = new StateToken(new byte[]{1}, new byte[0], new byte[0], "", - System.currentTimeMillis() / 1000); + StateToken src = new StateToken(new byte[]{1}, CALL_ID, System.currentTimeMillis() / 1000); byte[] packed = src.pack(KEY, ANON); byte[] otherKey = new byte[32]; otherKey[0] = 99; @@ -123,8 +125,7 @@ void wrong_key_rejected() { @Test void principal_bound_token_accepted_by_same_principal() { - StateToken src = new StateToken(new byte[]{7, 7}, new byte[0], new byte[0], "s", - System.currentTimeMillis() / 1000); + StateToken src = new StateToken(new byte[]{7, 7}, CALL_ID, System.currentTimeMillis() / 1000); byte[] packed = src.pack(KEY, "alice"); StateToken out = StateToken.unpack(packed, KEY, 0, "alice"); assertArrayEquals(src.state(), out.state()); @@ -132,8 +133,7 @@ void principal_bound_token_accepted_by_same_principal() { @Test void wrong_principal_rejected() { - StateToken src = new StateToken(new byte[]{7, 7}, new byte[0], new byte[0], "s", - System.currentTimeMillis() / 1000); + StateToken src = new StateToken(new byte[]{7, 7}, CALL_ID, System.currentTimeMillis() / 1000); byte[] packed = src.pack(KEY, "alice"); // Bob presents Alice's token: AAD mismatch fails decryption. IllegalArgumentException e = assertThrows(IllegalArgumentException.class, @@ -143,9 +143,175 @@ void wrong_principal_rejected() { @Test void anonymous_token_rejected_by_named_principal() { - StateToken src = new StateToken(new byte[]{7, 7}, new byte[0], new byte[0], "s", - System.currentTimeMillis() / 1000); + StateToken src = new StateToken(new byte[]{7, 7}, CALL_ID, System.currentTimeMillis() / 1000); byte[] packed = src.pack(KEY, ANON); assertThrows(IllegalArgumentException.class, () -> StateToken.unpack(packed, KEY, 0, "alice")); } + + // --------------------------------------------------------------------- + // Token payload compression + // + // Token payloads are compressed *inside* the seal. The ordering is the + // whole point: once a token is sealed it is ciphertext, so the HTTP body + // codec can find no redundancy in it — it recovers only the slack base64 + // adds, never the state's own structure. Compressing before sealing + // reaches the real redundancy. + // + // None of this is visible on the wire, so the cross-language conformance + // suite cannot reach it; docs/WIRE_PROTOCOL.md in the reference repo + // makes it normative and asks each port to pin it with a language-local + // test like these. + // --------------------------------------------------------------------- + + private static byte[] repeat(String unit, int times) { + return unit.repeat(times).getBytes(java.nio.charset.StandardCharsets.UTF_8); + } + + @Test + void payload_is_compressed_when_redundant() { + byte[] plaintext = repeat("vgi-rpc-state-", 1000); + byte[] packed = StateToken.packPayload(plaintext); + assertEquals(0x01, packed[0], "expected the zstd codec tag"); + assertTrue(packed.length < plaintext.length / 4, + "expected real compression on a redundant payload, got " + + packed.length + " from " + plaintext.length); + } + + @Test + void payload_stays_raw_when_incompressible() { + // A byte ramp with no repeats gives the codec nothing to find. + // Skipping is what keeps the guarantee one-directional: a token may + // get smaller, never larger than its plaintext plus the one tag byte. + byte[] plaintext = new byte[256]; + for (int i = 0; i < plaintext.length; i++) { + plaintext[i] = (byte) i; + } + byte[] packed = StateToken.packPayload(plaintext); + assertEquals(0x00, packed[0], "expected the raw codec tag"); + assertEquals(plaintext.length + 1, packed.length, + "raw payload must not grow beyond the tag byte"); + } + + @Test + void payload_round_trips_under_either_codec() { + byte[] ramp = new byte[64]; + for (int i = 0; i < ramp.length; i++) { + ramp[i] = (byte) i; + } + byte[][] cases = { + new byte[0], + "x".getBytes(java.nio.charset.StandardCharsets.UTF_8), + ramp, + repeat("vgi-rpc-state-", 500), + }; + for (byte[] plaintext : cases) { + byte[] packed = StateToken.packPayload(plaintext); + assertArrayEquals(plaintext, StateToken.unpackPayload(packed), + "round trip changed the payload"); + } + } + + @Test + void malformed_payloads_are_rejected() { + // An unknown tag, an empty payload, or a body that will not + // decompress all mean a token this server did not mint, so all three + // surface as the same uniform error the caller maps to 400. + assertThrows(IllegalArgumentException.class, + () -> StateToken.unpackPayload(new byte[0])); + assertThrows(IllegalArgumentException.class, + () -> StateToken.unpackPayload(new byte[]{0x7f, 'p', 'a', 'y'})); + byte[] corrupt = new byte[]{0x01, 'n', 'o', 't', '-', 'z', 's', 't', 'd'}; + assertThrows(IllegalArgumentException.class, + () -> StateToken.unpackPayload(corrupt)); + } + + @Test + void sealed_token_shrinks_with_a_compressible_state() { + // End to end: compression inside the seal shrinks the token itself. + // Guards the ordering rather than the codec — a token sealed around + // an uncompressed payload comes out *larger* than its input once + // base64 inflation is counted, which is the regression this catches. + byte[] state = repeat("vgi-rpc-call-state-", 400); + StateToken src = new StateToken(state, CALL_ID, 1_700_000_000L); + + byte[] packed = src.pack(KEY, ANON); + assertTrue(packed.length < state.length / 4, + "sealed token (" + packed.length + "B) should be far smaller than its state (" + + state.length + "B)"); + + assertArrayEquals(state, StateToken.unpack(packed, KEY, 0, ANON).state(), + "state survived the seal"); + } + + // --------------------------------------------------------------------- + // The cursor/call split + // + // A cursor names a call; only an authenticated cursor may resolve one. + // See docs/WIRE_PROTOCOL.md in the reference repo. + // --------------------------------------------------------------------- + + @Test + void call_and_cursor_tokens_are_not_interchangeable() { + // The two AADs carry different version-tagged prefixes, so a swap + // fails the AEAD tag check rather than decoding into a payload the + // reader would misinterpret. + byte[] cursor = new StateToken(new byte[]{1}, CALL_ID, 1_700_000_000L).pack(KEY, ANON); + byte[] call = new CallToken(new byte[]{2}, new byte[]{3}, "sid", CALL_ID, 1_700_000_000L) + .pack(KEY, ANON); + + assertThrows(IllegalArgumentException.class, + () -> StateToken.unpack(call, KEY, 0, ANON)); + assertThrows(IllegalArgumentException.class, + () -> CallToken.unpack(cursor, KEY, 0, ANON)); + } + + @Test + void call_token_is_bound_to_its_principal() { + byte[] call = new CallToken(new byte[]{2}, new byte[]{3}, "sid", CALL_ID, 1_700_000_000L) + .pack(KEY, ANON); + assertThrows(IllegalArgumentException.class, + () -> CallToken.unpack(call, KEY, 0, "alice")); + } + + @Test + void call_state_cache_is_keyed_on_call_id_and_principal() { + // The cache is an accelerator, never a contract: it must not hand one + // principal another's call, and a cold entry simply misses so the + // caller falls back to the client's echoed token. + CallStateCache cache = new CallStateCache(3600); + CallToken call = new CallToken(new byte[]{2}, new byte[]{3}, "sid", CALL_ID, 1_700_000_000L); + + assertNull(cache.get(CALL_ID, ANON), "a cold cache must miss"); + cache.put(CALL_ID, "alice", call); + assertNull(cache.get(CALL_ID, "bob"), + "a call cached for one principal must not resolve for another"); + assertNotNull(cache.get(CALL_ID, "alice")); + + byte[] otherId = CALL_ID.clone(); + otherId[0] ^= 0xff; + assertNull(cache.get(otherId, "alice"), "a different call id must miss"); + } + + @Test + void an_expired_cache_entry_misses_rather_than_resolving() { + // Entries must never outlive the token that names them. + CallStateCache cache = new CallStateCache(-1_000); + cache.put(CALL_ID, ANON, new CallToken(new byte[]{2}, new byte[]{3}, "sid", + CALL_ID, 1_700_000_000L)); + // A negative TTL is clamped to the 1h default, so this entry is live; + // the point of the guard is that the clamp exists at all. + assertNotNull(cache.get(CALL_ID, ANON)); + } + + @Test + void a_disabled_cache_always_misses() { + // Zero entries is the operator knob behind --no-call-state-cache: it + // forces every continuation onto the path a relay or a restarted + // worker takes anyway, so a client that forgets to echo its call + // token fails here rather than in someone's deployment. + CallStateCache cache = new CallStateCache(3600, 0); + cache.put(CALL_ID, ANON, new CallToken(new byte[]{2}, new byte[]{3}, "sid", + CALL_ID, 1_700_000_000L)); + assertNull(cache.get(CALL_ID, ANON)); + } } diff --git a/vgirpc/src/test/java/farm/query/vgirpc/http/TokenIntrospectionTest.java b/vgirpc/src/test/java/farm/query/vgirpc/http/TokenIntrospectionTest.java new file mode 100644 index 0000000..a40aef3 --- /dev/null +++ b/vgirpc/src/test/java/farm/query/vgirpc/http/TokenIntrospectionTest.java @@ -0,0 +1,260 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +import farm.query.vgirpc.AuthContext; +import farm.query.vgirpc.RpcServer; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.Test; + +import java.io.ByteArrayOutputStream; +import java.io.PrintStream; +import java.net.URI; +import java.net.http.HttpClient; +import java.net.http.HttpRequest; +import java.net.http.HttpResponse; +import java.nio.charset.StandardCharsets; +import java.time.Duration; +import java.util.List; +import java.util.Map; +import java.util.Optional; +import java.util.concurrent.atomic.AtomicBoolean; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertNotEquals; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** + * The token-introspection guards the cross-language conformance group cannot + * observe from outside: what reaches the log, what reaches the resolver, and + * what a misconfiguration does at construction. + * + *

    The wire-visible guards — the allowlist, the JWS refusal, uniform + * rejections, the closed response key set — are pinned by + * {@code TestTokenIntrospection} in the shared suite. These are the ones a + * black-box HTTP client is blind to. + */ +final class TokenIntrospectionTest { + + public interface EchoService { String echo(String value); } + + public static final class EchoImpl implements EchoService { + @Override public String echo(String value) { return value; } + } + + private static final String PRINCIPAL_HEADER = "X-Test-Principal"; + private static final String INTROSPECTOR = "proxy@example"; + /** Distinctive enough that a substring search for it in a log is meaningful. */ + private static final String SUBJECT_TOKEN = "opaque-subject-credential-9f3a2b"; + private static final String UNKNOWN_TOKEN = "unknown-credential-7c1d4e"; + private static final String SUBJECT_PRINCIPAL = "alice@example"; + + private HttpServer server; + private String base; + + @AfterEach + void stop() throws Exception { + if (server != null) server.stop(); + } + + /** Boot a server whose introspector allowlist is exactly {@link #INTROSPECTOR}. */ + private void start(TokenResolver resolver) throws Exception { + start(HttpServer.Config.builder() + .prefix("/vgi") + .authenticator(principalHeaderAuthenticator()) + .tokenIntrospection(resolver, List.of(INTROSPECTOR))); + } + + private void start(HttpServer.Config.Builder builder) throws Exception { + server = new HttpServer(new RpcServer(EchoService.class, new EchoImpl()), builder.build()); + server.start(); + base = "http://127.0.0.1:" + server.port() + "/vgi"; + } + + /** Resolves only {@link #SUBJECT_TOKEN}; everything else does not resolve. */ + private static TokenResolver fixedResolver() { + return token -> SUBJECT_TOKEN.equals(token) + ? Optional.of(new TokenIdentity(SUBJECT_PRINCIPAL, "laptop", 120)) + : Optional.empty(); + } + + private static Authenticator principalHeaderAuthenticator() { + return req -> { + String principal = req.getHeader(PRINCIPAL_HEADER); + return principal == null || principal.isEmpty() + ? AuthContext.ANONYMOUS + : new AuthContext("test", true, principal, Map.of()); + }; + } + + // ---- guard 6: the credential is digested, never logged ---------------- + + /** + * The credential must appear in no log record — on the success path or the + * rejection path — while the digest must, or the endpoint is undiagnosable. + * + *

    Asserted against captured output rather than by reading the source + * because the failure mode is a well-meant {@code LOG.debug("token={}")} + * added later, which no wire-level test can see. + */ + @Test + void the_credential_never_reaches_the_log_but_its_digest_does() throws Exception { + start(fixedResolver()); + PrintStream realErr = System.err; + ByteArrayOutputStream captured = new ByteArrayOutputStream(); + String logged; + try { + System.setErr(new PrintStream(captured, true, StandardCharsets.UTF_8)); + assertEquals(200, introspect(INTROSPECTOR, SUBJECT_TOKEN).statusCode()); + assertEquals(404, introspect(INTROSPECTOR, UNKNOWN_TOKEN).statusCode()); + assertEquals(403, introspect("someone-else", SUBJECT_TOKEN).statusCode()); + System.err.flush(); + } finally { + logged = captured.toString(StandardCharsets.UTF_8); + System.setErr(realErr); + } + + // Without this the whole test passes vacuously on a silent logger. + assertTrue(logged.contains(TokenIntrospection.digest(SUBJECT_TOKEN)), + "the digest must be logged, or a credential's failures cannot be correlated: " + logged); + assertFalse(logged.contains(SUBJECT_TOKEN), "the subject credential reached the log"); + assertFalse(logged.contains(UNKNOWN_TOKEN), "a rejected credential reached the log"); + } + + /** Nor may either path echo the credential back to the caller. */ + @Test + void the_credential_never_reaches_the_response() throws Exception { + start(fixedResolver()); + assertFalse(body(introspect(INTROSPECTOR, SUBJECT_TOKEN)).contains(SUBJECT_TOKEN)); + assertFalse(body(introspect(INTROSPECTOR, UNKNOWN_TOKEN)).contains(UNKNOWN_TOKEN)); + } + + // ---- guard 4: JWS-shaped subjects never reach the resolver ------------- + + /** + * The conformance group can only see the rejection; that it happened + * before the resolver ran is the actual requirement. + * + *

    Routing a JWS onward hands a third party a bearer token the asker may + * itself have rejected, so a shape guard that merely reorders the answer + * after a resolver call has already leaked it. + */ + @Test + void a_jws_shaped_subject_is_refused_without_reaching_the_resolver() throws Exception { + AtomicBoolean consulted = new AtomicBoolean(); + start(token -> { + consulted.set(true); + return Optional.of(new TokenIdentity(SUBJECT_PRINCIPAL, "laptop", 120)); + }); + HttpResponse resp = introspect(INTROSPECTOR, "eyJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJhIn0.c2ln"); + assertEquals(404, resp.statusCode()); + assertFalse(consulted.get(), "the resolver saw a JWS it should never have been handed"); + } + + // ---- definitive vs transient ------------------------------------------ + + /** + * The type-level half of the distinction: an outage must not be catchable as + * a rejection, or every {@code catch (AuthException)} in the framework turns + * it into a 401. + */ + @Test + void an_unavailable_authority_is_not_an_auth_exception() { + assertFalse(AuthException.class.isAssignableFrom(AuthUnavailableException.class), + "AuthUnavailableException must stay outside the rejection hierarchy"); + } + + /** + * A chain advances past a rejection, but must propagate an outage. + * + *

    Swallowed here it would emerge as a 401 from the end of the chain, + * which every caller answers by re-authenticating at once — a thirty-second + * sidecar blip becoming a fleet-wide re-login storm. + */ + @Test + void chain_propagates_an_unavailable_authority_instead_of_advancing() { + Authenticator down = req -> { throw new AuthUnavailableException("identity sidecar unreachable"); }; + Authenticator wouldSucceed = req -> new AuthContext("test", true, "someone", Map.of()); + AuthUnavailableException e = assertThrows(AuthUnavailableException.class, + () -> Authenticator.chain(down, wouldSucceed).authenticate(HttpRequestStub.withHeaders(Map.of()))); + assertTrue(e.retryAfterSeconds() >= 1); + } + + /** ...and at the request boundary it renders 503 + Retry-After, never 401. */ + @Test + void an_unavailable_authenticator_answers_503_not_401() throws Exception { + start(HttpServer.Config.builder() + .prefix("/vgi") + .authenticator(req -> { throw new AuthUnavailableException("identity sidecar unreachable", 7, null); })); + HttpResponse resp = post(base + "/echo", "not-arrow-but-auth-runs-first"); + assertEquals(503, resp.statusCode()); + assertNotEquals(401, resp.statusCode()); + assertEquals("7", resp.headers().firstValue("Retry-After").orElseThrow()); + } + + /** + * A resolver outage is a 503 too, not the 404 that means "did not resolve". + * + *

    The two are the same shape on the wire and opposite in effect: a caller + * may negative-cache a 404, so a resolver that reported its backing store + * being down as one would lock out a live credential for the cache's + * lifetime. + */ + @Test + void a_resolver_outage_answers_503_not_a_definitive_rejection() throws Exception { + start(token -> { throw new AuthUnavailableException("token store unreachable"); }); + HttpResponse resp = introspect(INTROSPECTOR, SUBJECT_TOKEN); + assertEquals(503, resp.statusCode()); + assertTrue(resp.headers().firstValue("Retry-After").isPresent()); + } + + // ---- guard 3: the allowlist has no permissive default ----------------- + + /** Enabling the endpoint without naming an introspector must not build. */ + @Test + void an_empty_introspector_allowlist_is_rejected_at_construction() { + HttpServer.Config.Builder b = HttpServer.Config.builder() + .tokenIntrospection(fixedResolver(), List.of()); + assertThrows(IllegalArgumentException.class, b::build); + } + + /** An allowlist with no resolver is a config that silently does nothing. */ + @Test + void an_allowlist_without_a_resolver_is_rejected_at_construction() { + HttpServer.Config.Builder b = HttpServer.Config.builder() + .tokenIntrospection(null, List.of(INTROSPECTOR)); + assertThrows(IllegalArgumentException.class, b::build); + } + + // ---- helpers ---------------------------------------------------------- + + private HttpResponse introspect(String caller, String token) throws Exception { + HttpRequest.Builder req = HttpRequest.newBuilder(URI.create(base + "/" + TokenIntrospection.ENDPOINT)) + .timeout(Duration.ofSeconds(10)) + .header("Content-Type", MediaTypes.APPLICATION_JSON) + .POST(HttpRequest.BodyPublishers.ofString("{\"token\":\"" + token + "\"}")); + if (caller != null) req.header(PRINCIPAL_HEADER, caller); + try (HttpClient client = newClient()) { + return client.send(req.build(), HttpResponse.BodyHandlers.ofString()); + } + } + + private static HttpResponse post(String url, String body) throws Exception { + try (HttpClient client = newClient()) { + return client.send(HttpRequest.newBuilder(URI.create(url)) + .timeout(Duration.ofSeconds(10)) + .header("Content-Type", HttpServer.ARROW_CONTENT_TYPE) + .POST(HttpRequest.BodyPublishers.ofString(body)).build(), + HttpResponse.BodyHandlers.ofString()); + } + } + + private static String body(HttpResponse resp) { return resp.body(); } + + private static HttpClient newClient() { + return HttpClient.newBuilder().connectTimeout(Duration.ofSeconds(5)).build(); + } +} diff --git a/vgirpc/src/test/java/farm/query/vgirpc/http/UnauthorizedTest.java b/vgirpc/src/test/java/farm/query/vgirpc/http/UnauthorizedTest.java new file mode 100644 index 0000000..b7c8896 --- /dev/null +++ b/vgirpc/src/test/java/farm/query/vgirpc/http/UnauthorizedTest.java @@ -0,0 +1,188 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc.http; + +import com.fasterxml.jackson.databind.JsonNode; +import com.fasterxml.jackson.databind.ObjectMapper; +import farm.query.vgirpc.RpcServer; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.Test; + +import java.net.URI; +import java.net.http.HttpClient; +import java.net.http.HttpRequest; +import java.net.http.HttpResponse; +import java.time.Duration; +import java.util.List; +import java.util.Map; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** + * The standardized 401 of {@code docs/unauthorized-spec.md}, end to end. + * + *

    The cross-language {@code TestUnauthorized} group covers the wire shape + * against a spawned worker; these cover the two things it structurally cannot + * reach — the reason a Java exception type maps onto, and the fact + * that the proxy note is a function of server configuration rather than of the + * request that happened to be refused.

    + */ +final class UnauthorizedTest { + + private static final ObjectMapper JSON = new ObjectMapper(); + + public interface EchoService { + String echo(String value); + } + + public static final class EchoImpl implements EchoService { + @Override public String echo(String value) { return value; } + } + + private HttpServer server; + private String base; + + @AfterEach + void stop() throws Exception { + if (server != null) server.stop(); + } + + private void start(Authenticator auth, List proxyAuthHeaders) throws Exception { + server = new HttpServer(new RpcServer(EchoService.class, new EchoImpl()), + HttpServer.Config.builder() + .prefix("/vgi") + .authenticator(auth) + .proxyAuthHeaders(proxyAuthHeaders) + .build()); + server.start(); + base = "http://127.0.0.1:" + server.port() + "/vgi"; + } + + /** POST an empty body at a gated endpoint; auth runs before the body is parsed. */ + private HttpResponse post(String accept) throws Exception { + try (HttpClient client = HttpClient.newBuilder().connectTimeout(Duration.ofSeconds(5)).build()) { + HttpRequest.Builder b = HttpRequest.newBuilder(URI.create(base + "/echo")) + .timeout(Duration.ofSeconds(10)) + .POST(HttpRequest.BodyPublishers.ofByteArray(new byte[0])); + if (accept != null) b.header("Accept", accept); + return client.send(b.build(), HttpResponse.BodyHandlers.ofString()); + } + } + + // ---- reason classification ------------------------------------------- + + /** + * The exception subtype is the classification. A thrower picking + * {@link MissingCredentials} has already said nothing was presented, so + * reading it off the type is a declaration — unlike inspecting the + * message, which misclassifies the moment someone rewords a string. + */ + @Test + void exception_types_carry_their_own_reason() { + assertEquals(AuthReason.MISSING_CREDENTIAL, new MissingCredentials("no header").reason()); + assertEquals(AuthReason.INVALID_CREDENTIAL, new InvalidCredentials("bad token").reason()); + assertEquals(AuthReason.EXPIRED_CREDENTIAL, + new AuthFailure(AuthReason.EXPIRED_CREDENTIAL, "stale").reason()); + } + + /** A failure that names no reason lands on the fallback rather than a guess. */ + @Test + void unnamed_failure_is_unauthorized() { + assertEquals(AuthReason.UNAUTHORIZED, new AuthFailure("nope").reason()); + assertEquals(AuthReason.UNAUTHORIZED, new AuthFailure(null, "nope").reason()); + } + + // ---- envelope --------------------------------------------------------- + + /** Absent, not empty, when it does not apply — presence alone is the signal. */ + @Test + void envelope_omits_the_hint_when_it_does_not_apply() { + Map body = Unauthorized.envelope(AuthReason.INVALID_CREDENTIAL, "nope", ""); + assertFalse(body.containsKey("proxy_hint")); + assertEquals("unauthorized", body.get("error")); + assertEquals("invalid_credential", body.get("reason")); + assertEquals("nope", body.get("detail")); + } + + /** The note has to name the headers an operator must check. */ + @Test + void proxy_hint_names_the_headers() { + String hint = Unauthorized.proxyHint(List.of("VGI-Proxy-Proof", "x-forwarded-client-cert")); + assertTrue(hint.contains("VGI-Proxy-Proof"), hint); + assertTrue(hint.contains("x-forwarded-client-cert"), hint); + assertEquals("", Unauthorized.proxyHint(List.of())); + } + + // ---- wire shape ------------------------------------------------------- + + /** Header, body, and cache directive on a service with no proxy dependency. */ + @Test + void rejection_carries_the_reason_header_and_json_envelope() throws Exception { + start(request -> { throw new AuthFailure(AuthReason.INSUFFICIENT_SCOPE, "not for you"); }, List.of()); + HttpResponse resp = post("*/*"); + + assertEquals(401, resp.statusCode()); + assertEquals("insufficient_scope", + resp.headers().firstValue(HttpHeaders.VGI_AUTH_REASON).orElseThrow()); + assertTrue(resp.headers().firstValue("Cache-Control").orElseThrow().contains("no-store")); + assertTrue(resp.headers().firstValue("Content-Type").orElseThrow().startsWith("application/json")); + + JsonNode body = JSON.readTree(resp.body()); + assertEquals("unauthorized", body.get("error").asText()); + // Header and body must agree, or a client reading one and logging the + // other reports two different stories about the same rejection. + assertEquals("insufficient_scope", body.get("reason").asText()); + assertEquals("not for you", body.get("detail").asText()); + assertFalse(body.has("proxy_hint")); + assertTrue(resp.headers().firstValue(HttpHeaders.VGI_AUTH_PROXY_REQUIRED).isEmpty()); + } + + /** §4.2 permits always answering JSON; it forbids answering JSON requests with HTML. */ + @Test + void a_browser_request_still_gets_the_reason_header() throws Exception { + start(request -> { throw new AuthFailure("nope"); }, List.of()); + HttpResponse resp = post("text/html,application/xhtml+xml"); + assertEquals(401, resp.statusCode()); + assertEquals("unauthorized", + resp.headers().firstValue(HttpHeaders.VGI_AUTH_REASON).orElseThrow()); + } + + /** + * The note is derived from configuration, so it rides every 401 the server + * produces — including ones whose reason is not {@code proxy_required}. + * That is what lets it coexist with the uniform-rejection rule: it + * discloses nothing about which stage refused this attempt. + */ + @Test + void a_proxy_dependent_service_notes_it_on_every_rejection() throws Exception { + start(request -> { throw new InvalidCredentials("bad token"); }, + List.of("x-forwarded-client-cert")); + HttpResponse resp = post("*/*"); + + assertEquals(401, resp.statusCode()); + assertEquals("invalid_credential", + resp.headers().firstValue(HttpHeaders.VGI_AUTH_REASON).orElseThrow()); + assertEquals("true", + resp.headers().firstValue(HttpHeaders.VGI_AUTH_PROXY_REQUIRED).orElseThrow()); + String hint = JSON.readTree(resp.body()).get("proxy_hint").asText(); + assertTrue(hint.contains("x-forwarded-client-cert"), hint); + } + + /** Neither header is a capability advertisement, so success must be quiet. */ + @Test + void a_successful_response_carries_neither_header() throws Exception { + start(Authenticator.ANONYMOUS, List.of("x-forwarded-client-cert")); + try (HttpClient client = HttpClient.newBuilder().connectTimeout(Duration.ofSeconds(5)).build()) { + HttpResponse resp = client.send( + HttpRequest.newBuilder(URI.create(base + "/health")) + .timeout(Duration.ofSeconds(10)).GET().build(), + HttpResponse.BodyHandlers.ofString()); + assertEquals(200, resp.statusCode()); + assertTrue(resp.headers().firstValue(HttpHeaders.VGI_AUTH_REASON).isEmpty()); + assertTrue(resp.headers().firstValue(HttpHeaders.VGI_AUTH_PROXY_REQUIRED).isEmpty()); + } + } +} From 087c5696a3d5caee191d10a1d9961cafa2a8358b Mon Sep 17 00:00:00 2001 From: Rusty Conover Date: Tue, 4 Aug 2026 19:27:57 -0400 Subject: [PATCH 3/6] fix(access-log): serialize request_data before the stream is drained MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `serializeRequestBatch` ran after `reader.drain()`, and draining mutates the reader's root — so every record carried a zero-row batch. The kwargs snapshot immediately above already guarded against this and says so in a comment; the request_data capture did not follow it. Invisible until 0.36.1, whose validator round-trips the field instead of only checking it is present. Java is the one port that emits request_data at all — Go, Rust and TypeScript default to `payload_omitted`, so the new check never inspects anything there and passes vacuously. 121 of 133 records violated the schema before this; all pass now. Co-Authored-By: Claude Opus 5 (1M context) --- .../src/main/java/farm/query/vgirpc/RpcServer.java | 13 ++++++++----- 1 file changed, 8 insertions(+), 5 deletions(-) diff --git a/vgirpc/src/main/java/farm/query/vgirpc/RpcServer.java b/vgirpc/src/main/java/farm/query/vgirpc/RpcServer.java index 98b7893..ef3bb66 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/RpcServer.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/RpcServer.java @@ -318,6 +318,13 @@ private void serveOne(RpcTransport transport, ShmSession shmSession) { transport.writer().flush(); return; } + // Snapshot request_data here for the same reason the kwargs are + // snapshotted above: draining mutates the reader's root, so a + // batch serialized after it carries zero rows. Only worth the + // re-encode when a hook will actually consume it. + byte[] requestDataSnapshot = dispatchHook == null ? null + : serializeRequestBatch(paramsRoot, meta, + resolvedParams != null ? null : reader.dictionaryProvider()); // Drain remaining batches in this request stream so the next call sees a fresh stream try { reader.drain(); } catch (IOException ignore) {} String method; @@ -366,11 +373,7 @@ private void serveOne(RpcTransport transport, ShmSession shmSession) { dispatchInfo.authenticated = scope.auth() != null && scope.auth().authenticated(); dispatchInfo.claims = scope.auth() != null ? scope.auth().claims() : null; dispatchInfo.transportMetadata = scope.transportMetadata(); - // Same provider choice the kwargs decode made above: a - // resolved external batch carries its own schema and no - // reader dictionaries. - dispatchInfo.requestData = serializeRequestBatch(paramsRoot, meta, - resolvedParams != null ? null : reader.dictionaryProvider()); + dispatchInfo.requestData = requestDataSnapshot; if ("stream".equals(dispatchInfo.methodType)) { dispatchInfo.streamId = AccessLogHook.randomStreamId(); } From c8c4b3b1871c270956470be12b6cbfc7d5083804 Mon Sep 17 00:00:00 2001 From: Rusty Conover Date: Tue, 4 Aug 2026 19:50:56 -0400 Subject: [PATCH 4/6] ci: verify the access log against the spec in CI MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit vgi-rpc 0.37.0 added `--require-request-data`. This port already passes it — payloads are on by default here, and `--access-log-no-payloads` is the inverse flag — which is exactly why Java was the one port that caught a real request_data bug this week while the others passed vacuously by never emitting the field. So this is the CI half only. The step runs the validator unfiltered, so the zero-parameter methods stay in scope: a no-arg call sends an empty schema and no row, and a validator demanding one row unconditionally rejects it — the bug 0.36.1 shipped, which reported this correct port as non-conformant. `--access-log-debug` is accepted as a deliberate no-op. Java gates payloads with a builder flag rather than a logger level, so there is nothing for it to switch, but the arg parser exits 2 on unknown flags, which made the porting guide's literal command fail on Java and only Java. It must stay a no-op: inverting it to mirror `--access-log-no-payloads` would cost this port the default that lets it catch these bugs. Access-log conformance drifted precisely because verification was manual. Co-Authored-By: Claude Opus 5 (1M context) --- .github/workflows/ci.yml | 27 +++++++++++++++++++ CLAUDE.md | 4 ++- .../query/vgirpc/conformance/worker/Main.java | 8 ++++++ 3 files changed, 38 insertions(+), 1 deletion(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index ef3a414..661aff7 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -114,6 +114,11 @@ jobs: include: - name: launcher (pipe/unix, no shm) transports: pipe,subprocess,unix + # Access-log verification rides this lane rather than a job of its + # own: it is a pipe-transport run, and this lane already has the + # reference driver installed. Running it on all three would just + # repeat the same check. + access_log: true - name: launcher + shm transports: subprocess_shm - name: http @@ -159,3 +164,25 @@ jobs: env: CONFORMANCE_TRANSPORTS: ${{ matrix.transports }} run: python -m pytest tests/test_java_conformance.py -p no:cacheprovider -q --timeout=120 + + # The suite above proves the wire; this proves the access-log record, which + # nothing in CI checked until now — it was verified by hand, and drifted + # anyway. --require-request-data is what gives it teeth: without it the + # validator only checks request_data *when present*, so a worker that never + # emits the field passes vacuously. This worker logs payloads by default + # (no --access-log-debug needed), which is why it caught a request_data bug + # the ports that default to omitting it logged straight past. + # + # Deliberately unfiltered: a --filter that excluded the zero-parameter + # methods (void.*) would drop the empty-schema/no-row case, and that is the + # exact shape a bad validator rule mis-rejected in 0.36.1. The per-test + # timeout is raised off the 5s default because the first call also pays JVM + # startup and JIT on a shared runner. + - name: Verify access log (--require-request-data) + if: matrix.access_log + run: >- + vgi-rpc-test + --cmd "conformance-worker/build/install/conformance-worker/bin/conformance-worker --access-log $RUNNER_TEMP/java-access-log.jsonl" + --access-log "$RUNNER_TEMP/java-access-log.jsonl" + --require-request-data + --timeout 30 diff --git a/CLAUDE.md b/CLAUDE.md index d1db816..b7963a0 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -125,7 +125,9 @@ This port tracks `vgi-rpc-python` for wire compatibility. Two surfaces matter: What the schema cannot check — sampling determinism, drop reporting, fail-closed redaction, `payload_omitted` vs `true`, `response_bytes` being the compressed size — is covered by `AccessLogHookTest` and `http/AccessLogEgressTest`. -The conformance worker accepts `--access-log ` (`Main.java` parses it) plus `--access-log-sample `, `--access-log-async`, `--access-log-queue-size ` and `--access-log-no-payloads` (so `vgi-rpc-test --access-log` can validate the optional record shapes, not just the default one), `--http-auth` (reject-all authenticator that honours the `X-Conformance-Auth-Reason` fixture header, backing `TestHealth` + `TestUnauthorized`), `--no-call-state-cache` (disables the per-process call-state cache so every stream continuation takes the miss path, backing `TestColdCallStateCache`), `--cors-origin ` (repeatable; implies `--http` and grants that origin browser access, backing `TestCors` — the default worker stays CORS-free for `TestCorsOffMode`), and `--introspect` (implies `--http` plus principal-header auth, and enables token introspection with the fixed conformance introspector/subject/JWS-trap constants, backing `TestTokenIntrospection` — the default worker stays introspection-free for `TestTokenIntrospectionOffMode`). +The conformance worker accepts `--access-log ` (`Main.java` parses it) plus `--access-log-sample `, `--access-log-async`, `--access-log-queue-size ` and `--access-log-no-payloads` (so `vgi-rpc-test --access-log` can validate the optional record shapes, not just the default one), `--access-log-debug` (accepted and ignored — see below), `--http-auth` (reject-all authenticator that honours the `X-Conformance-Auth-Reason` fixture header, backing `TestHealth` + `TestUnauthorized`), `--no-call-state-cache` (disables the per-process call-state cache so every stream continuation takes the miss path, backing `TestColdCallStateCache`), `--cors-origin ` (repeatable; implies `--http` and grants that origin browser access, backing `TestCors` — the default worker stays CORS-free for `TestCorsOffMode`), and `--introspect` (implies `--http` plus principal-header auth, and enables token introspection with the fixed conformance introspector/subject/JWS-trap constants, backing `TestTokenIntrospection` — the default worker stays introspection-free for `TestTokenIntrospectionOffMode`). + +**Verifying the access log.** `vgi-rpc-test --access-log --require-request-data` is run by the `launcher` conformance lane in CI (`.github/workflows/ci.yml`), unfiltered so the zero-parameter methods — which send an empty schema and no row — stay in the sample. `--require-request-data` is the part that matters: without it `request_data` is only checked when present, so a worker that never emits it passes vacuously. This port logs payloads by **default**, which is why it caught a `request_data` bug the DEBUG-gated ports logged past; `--access-log-debug` exists only so the porting guide's canonical command line runs here unmodified, and must stay a no-op rather than becoming the inverse of `--access-log-no-payloads`. ## When in doubt diff --git a/conformance-worker/src/main/java/farm/query/vgirpc/conformance/worker/Main.java b/conformance-worker/src/main/java/farm/query/vgirpc/conformance/worker/Main.java index d253896..4318947 100644 --- a/conformance-worker/src/main/java/farm/query/vgirpc/conformance/worker/Main.java +++ b/conformance-worker/src/main/java/farm/query/vgirpc/conformance/worker/Main.java @@ -170,6 +170,14 @@ public static void main(String[] args) throws Exception { case "--access-log-async" -> accessLogAsync = true; case "--access-log-queue-size" -> accessLogQueueSize = Integer.parseInt(c.requireValue(a)); case "--access-log-no-payloads" -> accessLogPayloads = false; + // Accepted and ignored. The other ports gate request_data behind a + // DEBUG logger, so the porting guide's canonical verification command + // passes --access-log-debug to turn it on; this worker writes the + // record directly and logs payloads already, but rejecting an unknown + // arg would make that one command line fail on Java alone. Deliberately + // not the inverse of --access-log-no-payloads: payloads-by-default is + // what let this port catch a request_data bug the others logged past. + case "--access-log-debug" -> { } case "--strict" -> strictMode = true; case "--max-response-bytes" -> maxResponseBytes = Long.parseLong(c.requireValue(a)); case "--max-externalized-response-bytes" -> From 169967afe6b24106f5d3d7529e62b083c32af57b Mon Sep 17 00:00:00 2001 From: Rusty Conover Date: Tue, 4 Aug 2026 20:41:02 -0400 Subject: [PATCH 5/6] fix(access-log): record stream turns, and stop logging failures as ok Three gaps, one shared cause: every Java error path serializes the exception into the response body and then returns normally, so neither the HTTP layer nor the access-log hook could learn from control flow that a call had failed. CallOutcome is a thread-local set at the one choke point every error passes through, Wire.errorMetadata, and opened by RouterServlet.service and RpcServer.serveOne. Two readers depend on it. X-VGI-RPC-Error is now sent (reference 0.37.1's TestErrorHeader asserts it is sent, not merely CORS-exposed). More seriously, the same missing signal meant the access log reported status: "ok" for every raising call on *every* transport, not just HTTP -- the subprocess lane went from 0 error records to 10. HTTP stream calls now emit access-log records. HttpStreamHandler fires the dispatch hook once per turn -- one record per /init, one per /exchange -- matching spec section 1 and the reference's _dispatch_telemetry. The turn opens only once a request is a genuine dispatch, so a malformed body or unopenable cursor still logs nothing, the same boundary Python draws. stream_id is minted at init before mintInitTokens (so a producer finishing in one turn still gets one) and travels in the CallToken, so continuations recover it with no server state. DispatchInfo gains requestState/responseState carrying the decrypted cursor per section 4.4. Also supplies the optional conformance_http_access_log fixture so TestRequestId's correlation case runs instead of skipping, and adds TestHttpStreamAccessLog, which asserts records *exist* with the right shape before validating them -- a validator passing over records that were never emitted is not evidence, which is how this shipped. Known gap left alone: cap-overshoot records still say ok, because writeResponseCapError runs after onDispatchEnd computed the status. Co-Authored-By: Claude Opus 5 (1M context) --- .github/workflows/ci.yml | 20 ++ CLAUDE.md | 6 + tests/test_java_conformance.py | 185 ++++++++++++++ .../java/farm/query/vgirpc/AccessLogHook.java | 37 ++- .../java/farm/query/vgirpc/CallOutcome.java | 95 +++++++ .../java/farm/query/vgirpc/DispatchInfo.java | 13 + .../java/farm/query/vgirpc/RpcServer.java | 19 +- .../farm/query/vgirpc/http/HttpServer.java | 15 +- .../query/vgirpc/http/HttpStreamHandler.java | 231 ++++++++++++++---- .../java/farm/query/vgirpc/wire/Wire.java | 20 +- 10 files changed, 589 insertions(+), 52 deletions(-) create mode 100644 vgirpc/src/main/java/farm/query/vgirpc/CallOutcome.java diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 661aff7..90ad809 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -186,3 +186,23 @@ jobs: --access-log "$RUNNER_TEMP/java-access-log.jsonl" --require-request-data --timeout 30 + + # The step above validates the *launcher* worker's log, where a whole + # stream call is one dispatch and therefore one record. Over HTTP a stream + # is a chain of independent requests — one /init and one /exchange per + # continuation — and this server fired its dispatch hook only on the unary + # path, so streams produced no records at all. The validator passed + # regardless: it checks the records it is handed, and a log missing the + # traffic that carries the bytes has nothing wrong with the records it + # kept. Presence and shape are what has to be asserted, so this runs the + # group that drives real producer / exchange / failing streams over HTTP + # against a worker started with --access-log and reads its log back. + # + # Named as its own step rather than left to the full pytest run in this + # lane so the check is visible in the workflow, and so a regression here + # reports as itself rather than as one red line in a suite of a thousand. + - name: Verify HTTP stream access-log records + if: matrix.name == 'http' + run: >- + python -m pytest tests/test_java_conformance.py + -k TestHttpStreamAccessLog -p no:cacheprovider -q --timeout=120 diff --git a/CLAUDE.md b/CLAUDE.md index b7963a0..497780a 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -123,12 +123,18 @@ This port tracks `vgi-rpc-python` for wire compatibility. Two surfaces matter: **Egress accounting** (§4.8) can't all be measured in the hook: response compression runs after the handler returns. `AccessLogScope` is the per-request thread-local that closes that gap — `RouterServlet.service` opens one, `readBody` stamps `request_bytes` (pre-decompression), `writeArrowResponse` stamps `response_bytes` (post-compression), `Externalizer.maybeExternalize` counts `externalized_bytes` at the single upload choke point, and the scope emits the parked records on close. Transports that install no scope (pipe / unix / TCP) keep logging inline. These are distinct from §4.6's `input_bytes`/`output_bytes` (logical Arrow buffers), which this port does not yet populate at all. + **HTTP stream turns** (§1: "one record per `init` and one per `exchange`/`produce` continuation") are emitted by `HttpStreamHandler`, not `RpcServer` — HTTP streams never reach `serveOne`, so for a long time they produced no records at all while unary calls logged fine, which is backwards: streams are where the bytes are. `beginTurn`/`StreamTurn` fire the same `DispatchHook` per HTTP request, after the point the turn is a genuine dispatch (a malformed body or an unopenable cursor is refused earlier and logs nothing, matching the reference). The `stream_id` is minted at `/init` — before `mintInitTokens`, so a producer that finishes in one turn still gets one — and travels in the `CallToken`, which is how every continuation's record joins the init's without any server-side state. `DispatchInfo.requestState`/`responseState` carry the **decrypted** cursor (§4.4): the wire token is opaque AEAD, and a log a reader cannot decode without the server's token key is not an audit trail. Java's state blob is CBOR (`StateSerializer`), not the Arrow IPC the spec names — the schema only constrains it to base64, and plaintext-not-ciphertext is the property that matters. + + **`X-VGI-RPC-Error` and the `status` field** both need to know a call failed, and neither can learn it from control flow: every error path serializes the exception into the response body and then returns *normally*. `CallOutcome` (a thread-local opened by `RouterServlet.service` for HTTP and by `serveOne` for pipe/unix/TCP, nesting inertly when both apply) is set at the one choke point every error passes through — `Wire.errorMetadata` — so a new error path cannot forget to raise it. `writeArrowResponse` reads it to set the header (never unconditionally: a flag on every response is the same outage as no flag), and `AccessLogHook` reads it when the dispatcher reported no exception. + What the schema cannot check — sampling determinism, drop reporting, fail-closed redaction, `payload_omitted` vs `true`, `response_bytes` being the compressed size — is covered by `AccessLogHookTest` and `http/AccessLogEgressTest`. The conformance worker accepts `--access-log ` (`Main.java` parses it) plus `--access-log-sample `, `--access-log-async`, `--access-log-queue-size ` and `--access-log-no-payloads` (so `vgi-rpc-test --access-log` can validate the optional record shapes, not just the default one), `--access-log-debug` (accepted and ignored — see below), `--http-auth` (reject-all authenticator that honours the `X-Conformance-Auth-Reason` fixture header, backing `TestHealth` + `TestUnauthorized`), `--no-call-state-cache` (disables the per-process call-state cache so every stream continuation takes the miss path, backing `TestColdCallStateCache`), `--cors-origin ` (repeatable; implies `--http` and grants that origin browser access, backing `TestCors` — the default worker stays CORS-free for `TestCorsOffMode`), and `--introspect` (implies `--http` plus principal-header auth, and enables token introspection with the fixed conformance introspector/subject/JWS-trap constants, backing `TestTokenIntrospection` — the default worker stays introspection-free for `TestTokenIntrospectionOffMode`). **Verifying the access log.** `vgi-rpc-test --access-log --require-request-data` is run by the `launcher` conformance lane in CI (`.github/workflows/ci.yml`), unfiltered so the zero-parameter methods — which send an empty schema and no row — stay in the sample. `--require-request-data` is the part that matters: without it `request_data` is only checked when present, so a worker that never emits it passes vacuously. This port logs payloads by **default**, which is why it caught a `request_data` bug the DEBUG-gated ports logged past; `--access-log-debug` exists only so the porting guide's canonical command line runs here unmodified, and must stay a no-op rather than becoming the inverse of `--access-log-no-payloads`. +That lane is a *pipe* run, where a whole stream call is one dispatch and one record — it says nothing about HTTP, where a stream is a chain of requests. The `http` lane therefore also runs `TestHttpStreamAccessLog` (`tests/test_java_conformance.py`), which drives producer / exchange / failing streams against a worker started with `--access-log` and asserts the records **exist** and have the right shape before validating them. Presence is the assertion that matters: the schema validator reported PASS over a log with zero stream records for as long as the bug existed. The correlation half — `X-Request-ID` on the response equalling `request_id` in the log — is the shared suite's `TestRequestId`, gated on the `conformance_http_access_log` fixture in the same file. + ## When in doubt 1. Check the Python reference at `~/Development/vgi-rpc/vgi_rpc/` — behavior there is authoritative. diff --git a/tests/test_java_conformance.py b/tests/test_java_conformance.py index 8f1b536..fd8bd1e 100644 --- a/tests/test_java_conformance.py +++ b/tests/test_java_conformance.py @@ -7,6 +7,7 @@ import contextlib import os +import re import socket import subprocess import tempfile @@ -283,6 +284,31 @@ def conformance_http_cold_call_cache_port() -> Iterator[int]: yield from _start_http_worker("--http", "--no-call-state-cache") +@pytest.fixture(scope="session") +def conformance_http_access_log( + tmp_path_factory: pytest.TempPathFactory, +) -> Iterator[tuple[int, Path]]: + """Spawn an HTTP worker writing a JSONL access log, yielding ``(port, path)``. + + Backs the shared ``TestRequestId`` correlation case, which is the one + assertion the ``X-Request-ID`` field exists for: an id that appears on the + response but not in the log, or differs between them, looks like a working + trail right up to the moment somebody follows it. Checking that needs to + read back what the server logged for a request the suite itself made, which + no amount of poking at the wire substitutes for. + + Its own worker, because ``--access-log`` appends for the process's whole + life and the shared one is used by every other HTTP group. + """ + log_path = tmp_path_factory.mktemp("accesslog") / "conformance.jsonl" + gen = _start_http_worker("--http", "--access-log", str(log_path)) + port = next(gen) + try: + yield port, log_path + finally: + next(gen, None) + + @pytest.fixture(scope="session") def conformance_http_introspect_port() -> Iterator[int]: """Spawn an HTTP worker with token introspection enabled. @@ -677,3 +703,162 @@ def test_next_with_token_walks_whole_stream( # Resume from the first token: replays everything after batch 0. resumed = proxy_b.resume_stream("produce_n", tokens[0]) assert [ab.batch.column("value")[0].as_py() for ab in resumed] == [10, 20] + + +class TestHttpStreamAccessLog: + """Every HTTP turn of a stream call must produce an access-log record. + + ``vgi-rpc-test --access-log`` validates the *launcher* worker's log, where a + whole stream call is a single dispatch and therefore a single record. Over + HTTP a stream is a chain of independent requests — one ``/init`` and one + ``/exchange`` per continuation — and the Java server fired its dispatch hook + only on the unary path, so streams produced **no records at all**. The + validator passed anyway: it checks the records it is given, and there is + nothing wrong with a log that is merely missing the traffic that carries the + bytes. + + So this asserts presence and shape, which a schema check structurally + cannot: an init record carrying ``request_data``, at least one continuation + carrying none, and one ``stream_id`` joining them — plus the reference + validator over exactly those records, so shape and conformance are both + covered. + + ``docs/access-log-spec.md`` §1 ("Stream calls produce one record per init + and one per exchange/produce continuation") and §5. + """ + + #: A stream's lifecycle id: 32 lowercase hex, per the schema. + _STREAM_ID = re.compile(r"^[0-9a-f]{32}$") + + @staticmethod + def _await_records( + log_path: Path, method: str, minimum: int, timeout: float = 1.5 + ) -> list[dict[str, Any]]: + """Poll the log for at least *minimum* stream records naming *method*. + + The record is written as the response completes, so this waits on the + writer rather than racing it — a short wait, because the writer is + synchronous and has effectively already run by the time the client sees + the last response. It has to be short: the shared suite's module-level + ``pytest.mark.timeout(5)`` arrives here through the star-import and + outranks any ``--timeout`` on the command line, so a generous poll would + turn a missing-record failure into an unreadable timeout. + + Returns whatever it has at the deadline — the assertions, not this + helper, decide whether that is enough. + """ + import json + + found: list[dict[str, Any]] = [] + deadline = time.monotonic() + timeout + while time.monotonic() < deadline: + if log_path.exists(): + found = [ + rec + for line in log_path.read_text().splitlines() + if line.strip() + for rec in [json.loads(line)] + if rec.get("logger") == "vgi_rpc.access" + and rec.get("method") == method + and rec.get("method_type") == "stream" + ] + if len(found) >= minimum: + break + time.sleep(0.05) + return found + + def _assert_stream_shape(self, records: list[dict[str, Any]], method: str) -> None: + """Assert one init + at least one continuation, sharing a stream id.""" + from vgi_rpc.access_log_conformance import validate_access_logs + + assert records, ( + f"no access-log records for the {method!r} stream; HTTP stream turns must be " + f"logged like unary calls are — a validator over a log that omits them passes " + f"on nothing" + ) + stream_ids = {r.get("stream_id") for r in records} + assert len(stream_ids) == 1, ( + f"records for one {method!r} call must share one stream_id, saw {stream_ids}; " + f"without that the turns of a stream cannot be joined" + ) + stream_id = stream_ids.pop() + assert isinstance(stream_id, str) and self._STREAM_ID.match(stream_id), ( + f"stream_id must be 32 lowercase hex characters, got {stream_id!r}" + ) + + inits = [r for r in records if "request_data" in r] + conts = [r for r in records if "request_data" not in r] + assert len(inits) == 1, ( + f"exactly one {method!r} record must carry request_data (the /init turn), got " + f"{len(inits)} of {len(records)}" + ) + assert conts, ( + f"no continuation record for {method!r}: /exchange turns are where a stream's " + f"bytes actually move, and they were the half that went unlogged" + ) + for rec in records: + assert rec.get("http_status") == 200, f"expected http_status 200, got {rec.get('http_status')}" + assert rec.get("request_bytes", -1) >= 0, "stream turns must report request_bytes" + + violations = validate_access_logs(records) + assert not violations, f"stream records violate the access-log schema: {violations}" + + def test_producer_stream_logs_every_turn( + self, conformance_http_access_log: tuple[int, Path] + ) -> None: + """A producer stream logs its init and each continuation.""" + port, log_path = conformance_http_access_log + with http_connect(ConformanceService, f"http://127.0.0.1:{port}") as proxy: + values = [ab.batch.column("value")[0].as_py() for ab in proxy.produce_n(count=3)] + assert values == [0, 10, 20] + + # init + one continuation per remaining batch. + records = self._await_records(log_path, "produce_n", 4) + self._assert_stream_shape(records, "produce_n") + # The init mints the first cursor; the turn that closes the stream mints + # none, and its absence is the record saying so. + assert any("response_state" in r for r in records), "a turn that mints a cursor must log it" + assert any("request_state" in r for r in records), ( + "a continuation must log the decrypted state the client sent, not the " + "AEAD ciphertext a reader cannot open" + ) + + def test_exchange_stream_logs_every_turn( + self, conformance_http_access_log: tuple[int, Path] + ) -> None: + """A bidirectional exchange stream logs its init and each exchange.""" + from vgi_rpc.rpc import AnnotatedBatch + + port, log_path = conformance_http_access_log + with ( + http_connect(ConformanceService, f"http://127.0.0.1:{port}") as proxy, + proxy.exchange_accumulate() as session, + ): + first = session.exchange(AnnotatedBatch.from_pydict({"value": [1.0, 2.0]})) + second = session.exchange(AnnotatedBatch.from_pydict({"value": [10.0]})) + assert first.batch.column("running_sum")[0].as_py() == pytest.approx(3.0) + assert second.batch.column("running_sum")[0].as_py() == pytest.approx(13.0) + + records = self._await_records(log_path, "exchange_accumulate", 3) + self._assert_stream_shape(records, "exchange_accumulate") + + def test_failing_stream_turn_is_logged_as_an_error( + self, conformance_http_access_log: tuple[int, Path] + ) -> None: + """A raising turn answers 200, so only the record says it failed. + + The status line cannot: the exception rides the body as an EXCEPTION + batch. A record reporting ``ok`` for it would hide the failure from the + one place an operator looks for it. + """ + port, log_path = conformance_http_access_log + with http_connect(ConformanceService, f"http://127.0.0.1:{port}") as proxy: + with pytest.raises(Exception): + list(proxy.produce_error_on_init()) + + records = self._await_records(log_path, "produce_error_on_init", 1) + assert records, "a stream that raised on init produced no access-log record" + rec = records[-1] + assert rec["status"] == "error", f"expected status=error, got {rec['status']!r}" + assert rec["error_type"], "an error record must name the error type" + assert rec["error_message"], "an error record must carry the server-side message" diff --git a/vgirpc/src/main/java/farm/query/vgirpc/AccessLogHook.java b/vgirpc/src/main/java/farm/query/vgirpc/AccessLogHook.java index cf85e38..c852853 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/AccessLogHook.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/AccessLogHook.java @@ -228,17 +228,28 @@ public void onDispatchEnd(Object token, DispatchInfo info, CallStatistics stats, long startNs = token instanceof Long ? (Long) token : System.nanoTime(); double durationMs = Math.round((System.nanoTime() - startNs) / 10_000.0) / 100.0; - String status = error == null ? "ok" : "error"; + // A method that raised does not propagate: the dispatcher serializes the + // exception into the response and returns normally, so `error` is null + // for exactly the calls an operator most wants to find. CallOutcome is + // what the error was recorded on as it went onto the wire. + Throwable failure = error != null ? error : CallOutcome.currentError(); + + String status = failure == null ? "ok" : "error"; String errorType = ""; String errorMessage = ""; - if (error != null) { - if (error instanceof RpcError re) { + if (failure != null) { + if (failure instanceof RpcError re) { errorType = re.errorType(); errorMessage = re.getMessage() == null ? "" : re.getMessage(); } else { - errorType = error.getClass().getSimpleName(); - errorMessage = error.getMessage() == null ? error.toString() : error.getMessage(); + errorType = failure.getClass().getSimpleName(); + errorMessage = failure.getMessage() == null ? failure.toString() : failure.getMessage(); } + // The schema requires a non-empty error_message on every error + // record, and an exception carrying no message is not a reason to + // emit an unreadable one. + if (errorMessage.isEmpty()) errorMessage = failure.toString(); + if (errorType.isEmpty()) errorType = failure.getClass().getSimpleName(); } AccessLogScope scope = AccessLogScope.current(); @@ -291,6 +302,15 @@ public void onDispatchEnd(Object token, DispatchInfo info, CallStatistics stats, rec.put("stream_id", info.streamId == null || info.streamId.isEmpty() ? "00000000000000000000000000000000" : info.streamId); } + // Stream state, decrypted. The token on the wire is an opaque AEAD + // ciphertext; a log reader holding the server's token_key is not a + // situation to design for, so the plaintext is what gets logged. + // Gated with request_data: these are the same kind of payload and a + // deployment that opted out of one did not ask for the other. + if (logPayloads) { + putStateBytes(rec, "request_state", info.requestState); + putStateBytes(rec, "response_state", info.responseState); + } if (info.cancelled) rec.put("cancelled", true); if (info.sessionId != null && !info.sessionId.isEmpty()) { rec.put("session_id", info.sessionId); @@ -325,6 +345,13 @@ public void onDispatchEnd(Object token, DispatchInfo info, CallStatistics stats, } } + /** Base64 a decrypted state payload under {@code key}, skipping empties — + * the schema's base64 pattern admits no zero-length string. */ + private static void putStateBytes(Map rec, String key, byte[] state) { + if (state == null || state.length == 0) return; + rec.put(key, Base64.getEncoder().encodeToString(state)); + } + /** HTTP fills {@code remote_addr} into the transport metadata, not the dispatch info. */ private static String remoteAddr(DispatchInfo info) { if (info.remoteAddr != null && !info.remoteAddr.isEmpty()) return info.remoteAddr; diff --git a/vgirpc/src/main/java/farm/query/vgirpc/CallOutcome.java b/vgirpc/src/main/java/farm/query/vgirpc/CallOutcome.java new file mode 100644 index 0000000..4b167cd --- /dev/null +++ b/vgirpc/src/main/java/farm/query/vgirpc/CallOutcome.java @@ -0,0 +1,95 @@ +// Copyright 2025-2026 Query.Farm LLC +// SPDX-License-Identifier: Apache-2.0 + +package farm.query.vgirpc; + +/** + * Per-call record of whether the response being built carries an RPC error. + * + *

    A failed vgi-rpc call is not a failed HTTP request: the method was + * reached, it raised, and the exception travels back as an Arrow EXCEPTION + * batch inside a well-formed 200 response. Nothing about the + * status line says so, which is why {@code X-VGI-RPC-Error: true} exists and + * why something has to remember, between the point the error is serialized and + * the point the response headers are written, that this response is a failure. + * + *

    The dispatchers cannot carry that themselves: every error path writes the + * exception into the response body and then returns normally, so a + * caller looking only at control flow sees a success. The signal is instead + * taken at the one place every error passes through — + * {@code Wire.errorMetadata}, which builds the EXCEPTION batch's metadata — so + * a new error path cannot forget to raise it. + * + *

    Two readers depend on it: the HTTP transport, which sets the error flag on + * the response, and {@link AccessLogHook}, whose {@code status} field would + * otherwise report {@code "ok"} for a call whose whole payload is an exception. + * + *

    Scopes nest safely. The HTTP transport opens one per request; the + * dispatcher opens one per call for transports (pipe, unix, TCP) that have no + * request boundary of their own. Under HTTP the inner open is inert and the + * outer scope keeps the value alive until the response has been written. + * + *

    Bound to the dispatching thread. Not safe for use across threads. + */ +public final class CallOutcome implements AutoCloseable { + + private static final ThreadLocal CURRENT = new ThreadLocal<>(); + + /** Whether closing this handle uninstalls the scope, or it is a nested no-op. */ + private final boolean owner; + private Throwable error; + + private CallOutcome(boolean owner) { + this.owner = owner; + } + + /** + * Install a scope on the current thread, or join one already installed. + * + * @return a handle to close (ideally via try-with-resources); closing a + * nested handle leaves the enclosing scope untouched + */ + public static CallOutcome open() { + if (CURRENT.get() != null) return new CallOutcome(false); + CallOutcome scope = new CallOutcome(true); + CURRENT.set(scope); + return scope; + } + + /** + * Note that an error is being written into the response. No-op when no + * scope is installed. + * + *

    The first error wins: a decode failure that then trips a second + * failure on the way out should still be reported as what actually went + * wrong. + * + * @param t the exception being serialized into the response + */ + public static void recordError(Throwable t) { + CallOutcome scope = CURRENT.get(); + if (scope != null && scope.error == null && t != null) scope.error = t; + } + + /** + * The error this call put on the wire. + * + * @return the exception, or {@code null} when the call is so far a success + * (or no scope is installed) + */ + public static Throwable currentError() { + CallOutcome scope = CURRENT.get(); + return scope == null ? null : scope.error; + } + + /** @return whether this call has written an error into its response */ + public static boolean failed() { + return currentError() != null; + } + + /** Uninstall the scope, if this handle owns it. */ + @Override + public void close() { + if (owner) CURRENT.remove(); + } +} diff --git a/vgirpc/src/main/java/farm/query/vgirpc/DispatchInfo.java b/vgirpc/src/main/java/farm/query/vgirpc/DispatchInfo.java index db48041..b2389ed 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/DispatchInfo.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/DispatchInfo.java @@ -42,6 +42,19 @@ public final class DispatchInfo { public byte[] requestData; /** Stream lifecycle identifier (32-char lowercase hex); empty on unary. */ public String streamId = ""; + /** + * Decrypted stream state the client sent, on a stream continuation; null on + * unary and on stream init. The on-wire token is an opaque AEAD ciphertext — + * this is the plaintext, so a log reader can decode it without holding the + * server's token key. + */ + public byte[] requestState; + /** + * Decrypted stream state handed back to the client, on stream init and on + * any continuation that mints a fresh cursor. Null on unary and on the + * terminal continuation that closes the stream. + */ + public byte[] responseState; /** True when the client cancelled the stream before end-of-stream. */ public boolean cancelled; /** Transport-level request metadata (e.g. HTTP headers) captured by the auth scope; may be null. */ diff --git a/vgirpc/src/main/java/farm/query/vgirpc/RpcServer.java b/vgirpc/src/main/java/farm/query/vgirpc/RpcServer.java index ef3bb66..a1bd7c2 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/RpcServer.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/RpcServer.java @@ -115,6 +115,17 @@ public RpcServer(Class serviceInterface, Object impl, String serverId, boolea */ public void setDispatchHook(DispatchHook hook) { this.dispatchHook = hook; } + /** + * The installed dispatch hook, if any. + * + *

    Exposed so transports that dispatch outside {@link #serveOne} — the + * HTTP stream handler runs its own init/continuation turns — can fire the + * same hook and produce the same access-log records. + * + * @return the hook, or {@code null} when none is installed + */ + public DispatchHook dispatchHook() { return dispatchHook; } + /** * Operator-supplied free-form protocol-contract version label (optional). * @@ -249,7 +260,13 @@ public void serveOne(RpcTransport transport) { /** Handle exactly one RPC call, attaching/using the connection's shm session if present. */ private void serveOne(RpcTransport transport, ShmSession shmSession) { - try (IpcStreamReader reader = new IpcStreamReader(transport.reader(), Allocators.root())) { + // Opened per call so a pipe/unix/TCP transport — which has no request + // boundary of its own — still reports a raised method as status="error" + // in the access log. Under HTTP the servlet already installed one + // spanning the whole request, and this nests inertly inside it so the + // signal outlives dispatch and reaches the response headers. + try (CallOutcome outcome = CallOutcome.open(); + IpcStreamReader reader = new IpcStreamReader(transport.reader(), Allocators.root())) { Map meta; try { meta = reader.readNextBatch(); diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/HttpServer.java b/vgirpc/src/main/java/farm/query/vgirpc/http/HttpServer.java index 249c42f..6959fdc 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/http/HttpServer.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/HttpServer.java @@ -9,6 +9,7 @@ import farm.query.vgirpc.AuthContext; import farm.query.vgirpc.AuthScope; import farm.query.vgirpc.CallContext; +import farm.query.vgirpc.CallOutcome; import farm.query.vgirpc.RpcServer; import farm.query.vgirpc.RpcStream; import farm.query.vgirpc.SessionLostError; @@ -1062,7 +1063,12 @@ protected void service(HttpServletRequest req, HttpServletResponse resp) throws // response_bytes cannot be read where the record is written: // compression runs after the handler, so a record emitted there // could only ever report the uncompressed size. - try (AccessLogScope access = AccessLogScope.open(requestId)) { + // Spans the whole request, so an error serialized during dispatch is + // still visible when the response headers are written — a failed RPC + // answers 200 with the exception in the body, and X-VGI-RPC-Error is + // the only thing that says so. + try (CallOutcome outcome = CallOutcome.open(); + AccessLogScope access = AccessLogScope.open(requestId)) { try { super.service(req, resp); } catch (AuthUnavailableException e) { @@ -1801,6 +1807,13 @@ private static void copyBounded(InputStream in, OutputStream out, long limit) th } private void writeArrowResponse(HttpServletRequest req, HttpServletResponse resp, byte[] body) throws IOException { + // Every Arrow response body leaves through here, which makes this the + // one place the error flag can be raised without a new failure path + // being able to forget it. A failed call answers 200 — the exception + // rides the body as an EXCEPTION batch — so without this header a + // client reads a failure as a result. Setting it unconditionally would + // be the same outage in the other direction, hence the check. + if (CallOutcome.failed()) resp.setHeader(RPC_ERROR_HEADER, "true"); resp.setContentType(ARROW_CONTENT_TYPE); ResponseEncoding choice = chooseResponseEncoding(req, supportedEncodings); byte[] encoded = encodeArrowBody(resp, choice, body, zstdLevel); diff --git a/vgirpc/src/main/java/farm/query/vgirpc/http/HttpStreamHandler.java b/vgirpc/src/main/java/farm/query/vgirpc/http/HttpStreamHandler.java index 5b1e090..f23013b 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/http/HttpStreamHandler.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/http/HttpStreamHandler.java @@ -4,8 +4,12 @@ package farm.query.vgirpc.http; import farm.query.vgirpc.AnnotatedBatch; +import farm.query.vgirpc.AuthContext; import farm.query.vgirpc.AuthScope; import farm.query.vgirpc.CallContext; +import farm.query.vgirpc.CallOutcome; +import farm.query.vgirpc.DispatchHook; +import farm.query.vgirpc.DispatchInfo; import farm.query.vgirpc.MethodType; import farm.query.vgirpc.OutputCollector; import farm.query.vgirpc.RpcMethodInfo; @@ -63,6 +67,8 @@ */ public final class HttpStreamHandler { + private static final org.slf4j.Logger LOG = org.slf4j.LoggerFactory.getLogger(HttpStreamHandler.class); + private final RpcServer rpc; private final byte[] tokenKey; private final long tokenTtlSeconds; @@ -169,6 +175,85 @@ private static Class concreteStateArg(Type returnType) { return c.asSubclass(StreamState.class); } + // --- Access-log telemetry --------------------------------------------- + + /** + * One HTTP turn of a stream call, and the access-log record it produces. + * + *

    A stream over HTTP is not one dispatch but a chain of them: an + * {@code /init} and then an {@code /exchange} per continuation, each its own + * request with its own body, status and byte counts. The spec follows the + * wire — one record per turn, all sharing the {@code stream_id} minted at + * init — rather than pretending the chain is a single call whose duration + * spans the client's think time. + * + *

    Opened once the turn is a genuine dispatch: a malformed body or an + * unresolvable token is refused before a method runs and produces no + * record, matching the reference. + */ + private final class StreamTurn implements AutoCloseable { + private final DispatchHook hook; + private final DispatchInfo info; + private final Object token; + /** Set when the turn threw. Errors written into the body instead are + * picked up from {@link CallOutcome}, which the writer already records. */ + private Throwable thrown; + + StreamTurn(DispatchHook hook, DispatchInfo info, Object token) { + this.hook = hook; + this.info = info; + this.token = token; + } + + @Override + public void close() { + Throwable err = thrown != null ? thrown : CallOutcome.currentError(); + try { + hook.onDispatchEnd(token, info, null, err); + } catch (Throwable t) { + LOG.warn("dispatch hook end error: {}", t.toString()); + } + } + } + + /** + * Start a turn's telemetry, or return {@code null} when nothing is listening. + * + * @param method the stream method being dispatched + * @param streamId the stream's lifecycle id, shared by every turn + */ + private StreamTurn beginTurn(String method, String streamId) { + DispatchHook hook = rpc.dispatchHook(); + if (hook == null) return null; + DispatchInfo info = new DispatchInfo(); + info.method = method; + info.methodType = "stream"; + info.streamId = streamId; + info.serverId = rpc.serverId(); + info.protocol = rpc.protocolName(); + info.protocolHash = rpc.protocolHash(); + info.protocolVersion = rpc.protocolVersion(); + AuthScope.Scope scope = AuthScope.current(); + AuthContext auth = scope.auth(); + info.principal = auth != null && auth.principal() != null ? auth.principal() : ""; + info.authDomain = auth != null && auth.domain() != null ? auth.domain() : ""; + info.authenticated = auth != null && auth.authenticated(); + info.claims = auth != null ? auth.claims() : null; + info.transportMetadata = scope.transportMetadata(); + Object token = null; + try { + token = hook.onDispatchStart(info); + } catch (Throwable t) { + LOG.warn("dispatch hook start error: {}", t.toString()); + } + return new StreamTurn(hook, info, token); + } + + /** Record a field on a turn that may not exist (no hook installed). */ + private static void onTurn(StreamTurn turn, Consumer mutation) { + if (turn != null) mutation.accept(turn.info); + } + /** Handle {@code POST /{method}/init}. Returns response IPC bytes. */ public byte[] handleInit(String method, byte[] requestBody) throws Exception { RpcMethodInfo info = rpc.methods().get(method); @@ -200,6 +285,30 @@ public byte[] handleInit(String method, byte[] requestBody) throws Exception { OutputCollectorSink sink = new OutputCollectorSink(); CallContext ctx = buildCallContext(method, sink); + // Minted here rather than inside mintInitTokens so the init record + // carries it even when the producer finishes in one turn and no + // continuation token is ever issued — and so every later turn's record + // can be joined to this one. + String streamId = newStreamId(); + try (StreamTurn turn = beginTurn(method, streamId)) { + // The request body is already a self-contained Arrow IPC stream, so + // it is logged verbatim: byte-faithful, metadata intact, and free. + // Only the pipe transport, which reads from a shared stream with no + // discrete body, has to re-frame the batch. + onTurn(turn, i -> i.requestData = requestBody); + try { + return runInit(method, info, kwargs, requestMeta, ctx, sink, streamId, turn); + } catch (Throwable t) { + if (turn != null) turn.thrown = t; + throw t; + } + } + } + + /** The body of {@code /init}, wrapped by {@link #handleInit}'s telemetry. */ + private byte[] runInit(String method, RpcMethodInfo info, Map kwargs, + Map requestMeta, CallContext ctx, + OutputCollectorSink sink, String streamId, StreamTurn turn) throws Exception { RpcStream streamResult; try { Object[] args = ParameterBinder.bind(info.reflectMethod(), kwargs, ctx); @@ -229,9 +338,9 @@ public byte[] handleInit(String method, byte[] requestBody) throws Exception { writeHeaderIpcStream(out, streamResult.header(), sink); } if (streamResult.isProducer()) { - writeProducerRun(out, streamResult, ctx, sink, requestMeta); + writeProducerRun(out, streamResult, ctx, sink, requestMeta, streamId, turn); } else { - writeExchangeInitToken(out, streamResult, sink); + writeExchangeInitToken(out, streamResult, sink, streamId, turn); } return out.toByteArray(); } @@ -274,41 +383,22 @@ public byte[] handleExchange(String method, byte[] requestBody) throws Exception return errorStream(e); } - Class stateCls = stateTypes.get(method); - if (stateCls == null) { - return errorStream(new IllegalStateException( - "Cannot resolve state type for method '" + method + "'")); - } - Schema outputSchema = deserializeSchema(call.outputSchema()); - Schema inputSchema = deserializeSchema(call.inputSchema()); - boolean isProducer = inputSchema.getFields().isEmpty(); - StreamState state = StateSerializer.deserialize(token.state(), stateCls); - - CallContext ctx = buildCallContext(method, new OutputCollectorSink()); - - if (req.meta().containsKey(Metadata.CANCEL)) { - return handleCancel(outputSchema, state, ctx); - } - - VectorSchemaRoot castInput = null; - if (!isProducer && !ownedInput.getSchema().equals(inputSchema)) { + // The turn is a real dispatch only once the cursor has opened and + // named a call: everything above refuses the request before any + // state is rehydrated, and produces no record — same boundary the + // reference draws. The stream id rides in the call token, so every + // continuation's record joins the init's without server state. + try (StreamTurn turn = beginTurn(method, call.streamId())) { + // The plaintext the client's opaque AEAD cursor decrypted to. + // Logging the ciphertext would give a reader nothing they could + // decode without the server's token key. + onTurn(turn, i -> i.requestState = token.state()); try { - castInput = Marshalling.castRoot(ownedInput, inputSchema, Allocators.root()); - } catch (Exception castExc) { - return errorStream(new ClassCastException(castExc.getMessage())); - } - } - - try (VectorSchemaRoot maybeCast = castInput) { - VectorSchemaRoot actualInput = maybeCast != null ? maybeCast : ownedInput; - OutputCollector collector = new OutputCollector(outputSchema, rpc.serverId(), isProducer); - try { - state.process(new AnnotatedBatch(actualInput, req.meta()), collector, ctx); - if (!collector.finished()) collector.validate(); + return runExchange(method, req, ownedInput, token, call, principal, inputDicts, turn); } catch (Throwable t) { - return errorStream(t); + if (turn != null) turn.thrown = t; + throw t; } - return writeExchangeResponse(collector, state, token, outputSchema, isProducer, principal, inputDicts); } } } finally { @@ -316,6 +406,50 @@ public byte[] handleExchange(String method, byte[] requestBody) throws Exception } } + /** The body of {@code /exchange}, wrapped by {@link #handleExchange}'s telemetry. */ + private byte[] runExchange(String method, ExchangeRequest req, VectorSchemaRoot ownedInput, + StateToken token, CallToken call, String principal, + DictionaryProvider inputDicts, StreamTurn turn) throws Exception { + Class stateCls = stateTypes.get(method); + if (stateCls == null) { + return errorStream(new IllegalStateException( + "Cannot resolve state type for method '" + method + "'")); + } + Schema outputSchema = deserializeSchema(call.outputSchema()); + Schema inputSchema = deserializeSchema(call.inputSchema()); + boolean isProducer = inputSchema.getFields().isEmpty(); + StreamState state = StateSerializer.deserialize(token.state(), stateCls); + + CallContext ctx = buildCallContext(method, new OutputCollectorSink()); + + if (req.meta().containsKey(Metadata.CANCEL)) { + onTurn(turn, i -> i.cancelled = true); + return handleCancel(outputSchema, state, ctx); + } + + VectorSchemaRoot castInput = null; + if (!isProducer && !ownedInput.getSchema().equals(inputSchema)) { + try { + castInput = Marshalling.castRoot(ownedInput, inputSchema, Allocators.root()); + } catch (Exception castExc) { + return errorStream(new ClassCastException(castExc.getMessage())); + } + } + + try (VectorSchemaRoot maybeCast = castInput) { + VectorSchemaRoot actualInput = maybeCast != null ? maybeCast : ownedInput; + OutputCollector collector = new OutputCollector(outputSchema, rpc.serverId(), isProducer); + try { + state.process(new AnnotatedBatch(actualInput, req.meta()), collector, ctx); + if (!collector.finished()) collector.validate(); + } catch (Throwable t) { + return errorStream(t); + } + return writeExchangeResponse(collector, state, token, outputSchema, isProducer, principal, + inputDicts, turn); + } + } + // --- handleExchange sub-steps ----------------------------------------- /** Parsed exchange-request body: metadata (including the state token) plus the (owned) input batch. */ @@ -344,9 +478,11 @@ private byte[] handleCancel(Schema outputSchema, StreamState state, CallContext private byte[] writeExchangeResponse(OutputCollector collector, StreamState state, StateToken priorToken, Schema outputSchema, boolean isProducer, String principal, - DictionaryProvider inputDicts) throws IOException { + DictionaryProvider inputDicts, StreamTurn turn) throws IOException { boolean finished = collector.finished(); - String newTokenStr = finished ? null : serializeContinuationToken(state, priorToken, principal); + // Absent on the terminal turn: there is no outbound state when the + // stream closes, which is exactly what its absence in the record means. + String newTokenStr = finished ? null : serializeContinuationToken(state, priorToken, principal, turn); BoundedByteArrayOutputStream out = new BoundedByteArrayOutputStream(maxResponseBytes); try (IpcStreamWriter w = new IpcStreamWriter(out)) { @@ -381,8 +517,10 @@ private byte[] writeExchangeResponse(OutputCollector collector, StreamState stat return out.toByteArray(); } - private String serializeContinuationToken(StreamState state, StateToken priorToken, String principal) { + private String serializeContinuationToken(StreamState state, StateToken priorToken, String principal, + StreamTurn turn) { byte[] newStateBytes = StateSerializer.serialize(state); + onTurn(turn, i -> i.responseState = newStateBytes); StateToken newToken = new StateToken(newStateBytes, priorToken.callId(), System.currentTimeMillis() / 1000); return new String(newToken.pack(tokenKey, principal), StandardCharsets.US_ASCII); @@ -426,18 +564,21 @@ private CallToken resolveCall(StateToken cursor, String callTokenB64, String pri /** Mint a stream's call id, call token, and first cursor at {@code /init}. */ private Map mintInitTokens(StreamState state, Schema outputSchema, - Schema inputSchema, String principal) { + Schema inputSchema, String principal, + String streamId, StreamTurn turn) { byte[] callId = new byte[Tokens.CALL_ID_LEN]; new java.security.SecureRandom().nextBytes(callId); long now = System.currentTimeMillis() / 1000; CallToken call = new CallToken(serializeSchema(outputSchema), serializeSchema(inputSchema), - newStreamId(), callId, now); + streamId, callId, now); // Warm the cache with what we already hold, so this stream's first // continuation does not have to open the token it was just handed. callStates.put(callId, principal, call); - StateToken cursor = new StateToken(StateSerializer.serialize(state), callId, now); + byte[] stateBytes = StateSerializer.serialize(state); + onTurn(turn, i -> i.responseState = stateBytes); + StateToken cursor = new StateToken(stateBytes, callId, now); return Map.of( Metadata.STREAM_STATE, new String(cursor.pack(tokenKey, principal), StandardCharsets.US_ASCII), @@ -461,7 +602,8 @@ private static String currentPrincipal() { private void writeProducerRun(ByteArrayOutputStream out, RpcStream streamResult, CallContext ctx, OutputCollectorSink sink, - Map requestMeta) throws IOException { + Map requestMeta, + String streamId, StreamTurn turn) throws IOException { Schema outputSchema = streamResult.outputSchema(); Schema inputSchema = streamResult.inputSchema(); StreamState state = streamResult.state(); @@ -489,7 +631,7 @@ private void writeProducerRun(ByteArrayOutputStream out, RpcStream streamResu // client knows to call /exchange to continue. Finished streams just EOS. if (!coll.finished()) { Map md = mintInitTokens(state, outputSchema, inputSchema, - currentPrincipal()); + currentPrincipal(), streamId, turn); Wire.writeZeroBatch(w, outputSchema, md); } } @@ -497,11 +639,12 @@ private void writeProducerRun(ByteArrayOutputStream out, RpcStream streamResu } private void writeExchangeInitToken(ByteArrayOutputStream out, RpcStream streamResult, - OutputCollectorSink sink) throws IOException { + OutputCollectorSink sink, + String streamId, StreamTurn turn) throws IOException { Schema outputSchema = streamResult.outputSchema(); Schema inputSchema = streamResult.inputSchema(); Map md = mintInitTokens(streamResult.state(), outputSchema, inputSchema, - currentPrincipal()); + currentPrincipal(), streamId, turn); try (IpcStreamWriter w = new IpcStreamWriter(out)) { w.writeSchema(outputSchema); sink.bind(w, outputSchema); diff --git a/vgirpc/src/main/java/farm/query/vgirpc/wire/Wire.java b/vgirpc/src/main/java/farm/query/vgirpc/wire/Wire.java index 6d95865..b2f8b3a 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/wire/Wire.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/wire/Wire.java @@ -3,6 +3,7 @@ package farm.query.vgirpc.wire; +import farm.query.vgirpc.CallOutcome; import farm.query.vgirpc.HasErrorKind; import farm.query.vgirpc.RpcError; import farm.query.vgirpc.VersionError; @@ -134,8 +135,25 @@ private static boolean collectEmptyDictionaries(List fields, return any; } - /** Build the metadata for an error/log batch. */ + /** + * Build the metadata for an error/log batch. + * + *

    Also the single choke point at which a call is marked failed + * ({@link CallOutcome}). Every path that puts an exception on the wire — + * unary, stream init, stream continuation, transport-level rejection — ends + * up here, and every one of them then returns normally with the + * error inside a well-formed response. Recording it anywhere else would + * mean each new error path having to remember, and the two readers that + * depend on the signal (the {@code X-VGI-RPC-Error} response header and the + * access log's {@code status} field) silently reporting success when one + * forgot. + * + * @param t the exception being serialized + * @param serverId server id to stamp on the batch, or {@code null} + * @return the batch's custom metadata + */ public static Map errorMetadata(Throwable t, String serverId) { + CallOutcome.recordError(t); Message msg = Message.fromException(t); Map md = msg.addToMetadata(null); if (serverId != null) md.put(Metadata.SERVER_ID, serverId); From 04e1ae08890d9d5af7435994a886203c5da57d6b Mon Sep 17 00:00:00 2001 From: Rusty Conover Date: Tue, 4 Aug 2026 21:06:23 -0400 Subject: [PATCH 6/6] fix(access-log): a response-cap overshoot is an error, not an ok writeResponseCapError runs after onDispatchEnd has computed the record's status, so a hard cap overshoot was logged as status: "ok" while the response correctly carried X-VGI-RPC-Error: true and the client got an RpcError. Same shape as the raising-call bug in 169967a, different path. It survived because --strict and --access-log had never been combined: the strict-cap fixture writes no log, and the access-log fixture sets no cap. AccessLogScope.close now re-states each parked record from CallOutcome.currentError before stamping response_bytes/http_status. That works because RouterServlet.service opens CallOutcome outside AccessLogScope, so the error is still installed when the scope emits -- a nesting order that is now load-bearing and commented as such. restate only promotes ok -> error, so a record that already named its failure keeps it. Reuses the 169967a choke point rather than adding a second mechanism. Only hard caps promote. A producer soft overshoot stays ok, because continuation tokens cover it and nothing failed. The exchange /init record also stays ok -- promoting the whole call would blame the turn that succeeded. Side effect: sampledIn runs after restate, so an overshoot is now exempt from sampling, as spec section 5bb requires of any error. TestHttpResponseCapAccessLog covers unary overshoot, exchange overshoot (asserting /init stays ok) and the producer soft cap as a control against over-eager re-stating. Watched failing against the stashed fix: 2 failed, 1 passed, with a message naming the real defect. Found while verifying, not fixed here: - max_externalized_response_bytes is advertised and never enforced -- the field is only ever read to emit a header. A worker capped at 512 uploads 200,336 bytes and answers success. The shared suite has no enforcement test for it, so no port is checked. - error_type in the log is the Java class name (RuntimeException) while the wire sends the mapped Python name (RuntimeError), so consumers joining log records to client errors by type will not match. - http_status for an overshoot: Java logs 200 (what went on the wire), Python logs 500 (pre-conversion). Co-Authored-By: Claude Opus 5 (1M context) --- CLAUDE.md | 2 + tests/test_java_conformance.py | 175 ++++++++++++++++++ .../java/farm/query/vgirpc/AccessLogHook.java | 81 ++++++-- .../farm/query/vgirpc/AccessLogScope.java | 8 + 4 files changed, 250 insertions(+), 16 deletions(-) diff --git a/CLAUDE.md b/CLAUDE.md index 497780a..dff32fa 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -127,6 +127,8 @@ This port tracks `vgi-rpc-python` for wire compatibility. Two surfaces matter: **`X-VGI-RPC-Error` and the `status` field** both need to know a call failed, and neither can learn it from control flow: every error path serializes the exception into the response body and then returns *normally*. `CallOutcome` (a thread-local opened by `RouterServlet.service` for HTTP and by `serveOne` for pipe/unix/TCP, nesting inertly when both apply) is set at the one choke point every error passes through — `Wire.errorMetadata` — so a new error path cannot forget to raise it. `writeArrowResponse` reads it to set the header (never unconditionally: a flag on every response is the same outage as no flag), and `AccessLogHook` reads it when the dispatcher reported no exception. + It is read a *second* time, at `AccessLogScope.close`, because dispatch returning is not the moment the outcome is settled. `max_response_bytes` is enforced after the body exists (`HttpServer.writeResponseCapError`, unary and `/exchange`; producer `/init` is soft-capped and must stay `ok`), so an overshoot discards the body, answers an EXCEPTION batch, and lands *after* `onDispatchEnd` computed `status: "ok"`. `AccessLogHook.restate` promotes the parked record — `ok` → `error` only, since a record that already named a failure named the cause and the overshoot it tripped on the way out is a consequence. This works because `RouterServlet.service` opens `CallOutcome` *outside* `AccessLogScope`, so the error is still readable when the scope emits; keep that nesting order. `max_externalized_response_bytes` is **advertised but never enforced** here (the Python reference pre-flights it in `_app_unary`/`_app_stream`), so it has no overshoot path to log. Covered by `TestHttpResponseCapAccessLog`. + What the schema cannot check — sampling determinism, drop reporting, fail-closed redaction, `payload_omitted` vs `true`, `response_bytes` being the compressed size — is covered by `AccessLogHookTest` and `http/AccessLogEgressTest`. The conformance worker accepts `--access-log ` (`Main.java` parses it) plus `--access-log-sample `, `--access-log-async`, `--access-log-queue-size ` and `--access-log-no-payloads` (so `vgi-rpc-test --access-log` can validate the optional record shapes, not just the default one), `--access-log-debug` (accepted and ignored — see below), `--http-auth` (reject-all authenticator that honours the `X-Conformance-Auth-Reason` fixture header, backing `TestHealth` + `TestUnauthorized`), `--no-call-state-cache` (disables the per-process call-state cache so every stream continuation takes the miss path, backing `TestColdCallStateCache`), `--cors-origin ` (repeatable; implies `--http` and grants that origin browser access, backing `TestCors` — the default worker stays CORS-free for `TestCorsOffMode`), and `--introspect` (implies `--http` plus principal-header auth, and enables token introspection with the fixed conformance introspector/subject/JWS-trap constants, backing `TestTokenIntrospection` — the default worker stays introspection-free for `TestTokenIntrospectionOffMode`). diff --git a/tests/test_java_conformance.py b/tests/test_java_conformance.py index fd8bd1e..158b7f5 100644 --- a/tests/test_java_conformance.py +++ b/tests/test_java_conformance.py @@ -309,6 +309,28 @@ def conformance_http_access_log( next(gen, None) +@pytest.fixture(scope="session") +def conformance_http_capped_access_log( + tmp_path_factory: pytest.TempPathFactory, +) -> Iterator[tuple[int, Path]]: + """Spawn an HTTP worker with strict response caps *and* a JSONL access log. + + Backs ``TestHttpResponseCapAccessLog``. Neither existing worker can: the + strict-cap one writes no log, and the access-log one has no cap to + overshoot, so the one state where the two interact -- a response the server + threw away for being oversize -- is reachable from neither. Its own process + for the same reason ``conformance_http_access_log`` has one: ``--access-log`` + appends for the process's whole life. + """ + log_path = tmp_path_factory.mktemp("capaccesslog") / "conformance.jsonl" + gen = _start_http_worker("--http", "--strict", "--access-log", str(log_path)) + port = next(gen) + try: + yield port, log_path + finally: + next(gen, None) + + @pytest.fixture(scope="session") def conformance_http_introspect_port() -> Iterator[int]: """Spawn an HTTP worker with token introspection enabled. @@ -862,3 +884,156 @@ def test_failing_stream_turn_is_logged_as_an_error( assert rec["status"] == "error", f"expected status=error, got {rec['status']!r}" assert rec["error_type"], "an error record must name the error type" assert rec["error_message"], "an error record must carry the server-side message" + + +class TestHttpResponseCapAccessLog: + """A response-cap overshoot must be logged as the failure it is. + + The overshoot is detected *after* dispatch has returned: the body exists, + it is too big, so the server discards it and answers an EXCEPTION batch + instead. Every wire-visible signal agrees the call failed -- + ``X-VGI-RPC-Error: true``, and an ``RpcError`` on the client -- while the + access record, whose ``status`` was settled when dispatch ended, said + ``ok``. That is worse than a missing record: an operator diffing "errors + the clients saw" against "errors the server logged" gets a clean log and + concludes the clients are wrong. + + ``docs/access-log-spec.md`` §3 (``status`` is ``"error"`` for any failure) + and §4.1 (``error_message`` required and non-empty when it is). + """ + + @staticmethod + def _await_records( + log_path: Path, method: str, minimum: int, timeout: float = 2.0 + ) -> list[dict[str, Any]]: + """Poll the log for at least *minimum* records naming *method*. + + Short by design: the shared suite's module-level ``pytest.mark.timeout(5)`` + arrives here through the star-import, so a generous poll would turn a + missing-record failure into an unreadable timeout. Returns whatever it + has at the deadline -- the assertions decide whether that is enough. + """ + import json + + found: list[dict[str, Any]] = [] + deadline = time.monotonic() + timeout + while time.monotonic() < deadline: + if log_path.exists(): + found = [ + rec + for line in log_path.read_text().splitlines() + if line.strip() + for rec in [json.loads(line)] + if rec.get("logger") == "vgi_rpc.access" and rec.get("method") == method + ] + if len(found) >= minimum: + break + time.sleep(0.05) + return found + + @staticmethod + def _assert_cap_error(rec: dict[str, Any], method: str) -> None: + """Assert one record reports the cap overshoot the wire reported.""" + from vgi_rpc.access_log_conformance import validate_access_logs + + assert rec["status"] == "error", ( + f"{method!r} overshot max_response_bytes -- the client got an RpcError and the " + f"response carried X-VGI-RPC-Error -- but the access record says " + f"status={rec['status']!r}; the log is the only place that failure is visible " + f"after the fact" + ) + assert rec["error_type"], "an error record must name the error type" + assert "max_response_bytes" in rec.get("error_message", ""), ( + f"the record must say which cap was overshot, got " + f"error_message={rec.get('error_message')!r}" + ) + assert rec["message"].endswith(" error"), ( + f"the human-readable summary must agree with the structured status, got " + f"{rec['message']!r}" + ) + violations = validate_access_logs([rec]) + assert not violations, f"cap-overshoot record violates the access-log schema: {violations}" + + def _cap(self, port: int) -> int: + """The wire cap this worker advertises.""" + from vgi_rpc.http import http_capabilities + + caps = http_capabilities(base_url=f"http://127.0.0.1:{port}") + assert caps.max_response_bytes is not None, "fixture must advertise a wire cap" + return int(caps.max_response_bytes) + + def test_unary_overshoot_is_logged_as_an_error( + self, conformance_http_capped_access_log: tuple[int, Path] + ) -> None: + """A unary response discarded for overshooting the cap logs status=error.""" + from vgi_rpc.rpc import RpcError + + port, log_path = conformance_http_capped_access_log + with ( + http_connect(ConformanceService, f"http://127.0.0.1:{port}") as proxy, + pytest.raises(RpcError, match=r"max_response_bytes"), + ): + proxy.oversized_unary(target_bytes=self._cap(port) * 4) + + records = self._await_records(log_path, "oversized_unary", 1) + assert records, "the overshooting unary call produced no access-log record at all" + self._assert_cap_error(records[-1], "oversized_unary") + + def test_exchange_overshoot_is_logged_as_an_error( + self, conformance_http_capped_access_log: tuple[int, Path] + ) -> None: + """The overshooting stream turn logs error; the init turn that succeeded stays ok. + + Streams only began producing records at all in the commit before this + one, so this path has never been exercised for a cap overshoot. Both + halves matter: promoting the whole call to ``error`` would blame the + ``/init`` turn, which genuinely succeeded. + """ + from vgi_rpc.rpc import AnnotatedBatch, RpcError + + port, log_path = conformance_http_capped_access_log + target_rows = max(1024, (self._cap(port) * 4) // 16) + with ( + http_connect(ConformanceService, f"http://127.0.0.1:{port}") as proxy, + pytest.raises(RpcError, match=r"max_response_bytes"), + proxy.exchange_oversized(rows_per_batch=target_rows) as session, + ): + session.exchange(AnnotatedBatch.from_pydict({"value": [1.0]})) + + records = self._await_records(log_path, "exchange_oversized", 2) + assert len(records) >= 2, ( + f"expected an /init record and the overshooting /exchange record, got {len(records)}" + ) + inits = [r for r in records if "request_data" in r] + conts = [r for r in records if "request_data" not in r] + assert inits and conts, f"expected both an init and a continuation record, got {records}" + assert all(r["status"] == "ok" for r in inits), ( + "the /init turn answered a well-formed response under the cap; marking it failed " + "attributes the overshoot to the wrong turn" + ) + self._assert_cap_error(conts[-1], "exchange_oversized") + + def test_producer_soft_cap_is_not_logged_as_an_error( + self, conformance_http_capped_access_log: tuple[int, Path] + ) -> None: + """A producer overshoot is covered by a continuation, so nothing failed. + + The negative control on the other two: the wire cap is *soft* for + producer streams -- the framework mints a continuation token instead of + failing -- so no error reaches the wire and every record must still say + ``ok``. An implementation that re-stated status from the mere presence + of a cap overshoot would fail here. + """ + port, log_path = conformance_http_capped_access_log + target_rows = max(1024, (self._cap(port) * 2) // 16) + with http_connect(ConformanceService, f"http://127.0.0.1:{port}") as proxy: + batches = list(proxy.produce_oversized_batch(rows_per_batch=target_rows)) + assert sum(b.batch.num_rows for b in batches) == target_rows + + records = self._await_records(log_path, "produce_oversized_batch", 1) + assert records, "the producer stream produced no access-log record" + for rec in records: + assert rec["status"] == "ok", ( + f"a producer overshoot is absorbed by a continuation token, not an error; " + f"got status={rec['status']!r} error_message={rec.get('error_message')!r}" + ) diff --git a/vgirpc/src/main/java/farm/query/vgirpc/AccessLogHook.java b/vgirpc/src/main/java/farm/query/vgirpc/AccessLogHook.java index c852853..b8fab6d 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/AccessLogHook.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/AccessLogHook.java @@ -235,22 +235,9 @@ public void onDispatchEnd(Object token, DispatchInfo info, CallStatistics stats, Throwable failure = error != null ? error : CallOutcome.currentError(); String status = failure == null ? "ok" : "error"; - String errorType = ""; - String errorMessage = ""; - if (failure != null) { - if (failure instanceof RpcError re) { - errorType = re.errorType(); - errorMessage = re.getMessage() == null ? "" : re.getMessage(); - } else { - errorType = failure.getClass().getSimpleName(); - errorMessage = failure.getMessage() == null ? failure.toString() : failure.getMessage(); - } - // The schema requires a non-empty error_message on every error - // record, and an exception carrying no message is not a reason to - // emit an unreadable one. - if (errorMessage.isEmpty()) errorMessage = failure.toString(); - if (errorType.isEmpty()) errorType = failure.getClass().getSimpleName(); - } + Failure described = Failure.describe(failure); + String errorType = described == null ? "" : described.type(); + String errorMessage = described == null ? "" : described.message(); AccessLogScope scope = AccessLogScope.current(); @@ -345,6 +332,68 @@ public void onDispatchEnd(Object token, DispatchInfo info, CallStatistics stats, } } + /** The {@code error_type} / {@code error_message} pair a record reports for one failure. */ + private record Failure(String type, String message) { + + /** + * Describe {@code t}, or {@code null} when there is nothing to describe. + * + * @param t the exception that reached the wire, or {@code null} + */ + static Failure describe(Throwable t) { + if (t == null) return null; + String type; + String message; + if (t instanceof RpcError re) { + type = re.errorType(); + message = re.getMessage() == null ? "" : re.getMessage(); + } else { + type = t.getClass().getSimpleName(); + message = t.getMessage() == null ? t.toString() : t.getMessage(); + } + // The schema requires a non-empty error_message on every error + // record, and an exception carrying no message is not a reason to + // emit an unreadable one. + if (message.isEmpty()) message = t.toString(); + if (type.isEmpty()) type = t.getClass().getSimpleName(); + return new Failure(type, message); + } + } + + /** + * Re-state a parked record's outcome from an error that reached the wire + * after the dispatch hook had already run. + * + *

    {@link #onDispatchEnd} settles {@code status} at the moment dispatch + * returns, but that is not the moment the response is finished: the HTTP + * transport enforces {@code max_response_bytes} after the body + * exists, and an overshoot throws the body away and replaces it with an + * EXCEPTION batch. The call really did fail — {@code X-VGI-RPC-Error: true} + * says so on the wire — and a record still reading {@code ok} would deny it + * to the one consumer that cannot see the wire. + * + *

    Reads the same {@link CallOutcome} the error was recorded on, so this + * covers any late-serialized error rather than the response cap alone. Only + * ever promotes {@code ok} to {@code error}: a record that already named a + * failure named the one that caused it, and the cap overshoot it tripped on + * the way out is a consequence, not the cause. + * + * @param rec the parked record, mutated in place + * @param late the error learned after dispatch ended, or {@code null} + */ + static void restate(Map rec, Throwable late) { + Failure f = Failure.describe(late); + if (f == null || !"ok".equals(rec.get("status"))) return; + rec.put("status", "error"); + rec.put("error_type", f.type()); + rec.put("error_message", f.message()); + // Rebuilt from the record's own fields rather than re-plumbed from + // DispatchInfo; `message` is the same two values plus the status, and + // leaving it saying "ok" is how a human reader gets told the opposite + // of what the structured fields say. + rec.put("message", rec.get("protocol") + "." + rec.get("method") + " error"); + } + /** Base64 a decrypted state payload under {@code key}, skipping empties — * the schema's base64 pattern admits no zero-length string. */ private static void putStateBytes(Map rec, String key, byte[] state) { diff --git a/vgirpc/src/main/java/farm/query/vgirpc/AccessLogScope.java b/vgirpc/src/main/java/farm/query/vgirpc/AccessLogScope.java index 7a693d9..d9c232c 100644 --- a/vgirpc/src/main/java/farm/query/vgirpc/AccessLogScope.java +++ b/vgirpc/src/main/java/farm/query/vgirpc/AccessLogScope.java @@ -141,7 +141,15 @@ void defer(AccessLogHook hook, Map record) { public void close() { CURRENT.remove(); if (deferred == null) return; + // The outcome is one of the things known only now. A response-cap + // overshoot is detected after dispatch has returned: the body is + // discarded and replaced with an EXCEPTION batch, so the call whose + // record already said "ok" answers a failure. The enclosing CallOutcome + // outlives this scope (the transport opens it first and closes it last), + // which is why the error is still readable here. + Throwable late = CallOutcome.currentError(); for (Deferred d : deferred) { + AccessLogHook.restate(d.record(), late); if (responseBytes >= 0) d.record().put("response_bytes", responseBytes); // The schema constrains this to a real status code, so a response // that never got one is better left unreported than guessed at.