Skip to content

Commit c4a9599

Browse files
authored
docs: clarify bounded body-logging size semantics and ordered-stage rationale (#86)
PR: #86
1 parent 955cd60 commit c4a9599

5 files changed

Lines changed: 114 additions & 0 deletions

File tree

docs/architecture.md

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -271,6 +271,10 @@ Shipped pillar/step implementations live in `http.pipeline.steps`: `DefaultRedir
271271
`DefaultRetryStep`, `AuthStep` (+ `BearerTokenAuthStep` / `KeyCredentialAuthStep`),
272272
`DefaultInstrumentationStep`, and the redirect/retry option types.
273273

274+
For why this layer uses ordered stages with pillar-uniqueness rather than nested `HttpClient`
275+
decorators — and the one cost that buys (the `next.copy()` re-drive contract) — see
276+
[Pipeline Mechanism](pipelines.md#why-ordered-stages-not-nested-decorators).
277+
274278
#### Recovery-aware primitives (`org.dexpace.sdk.core.pipeline`)
275279

276280
A lower-level layer that threads a sealed `ResponseOutcome` so recovery steps observe and

docs/http-body-logging-and-concurrency.md

Lines changed: 40 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,7 @@ and the concurrency decisions behind them.
1414
- [Architecture](#architecture)
1515
- [LoggableRequestBody — Tee-Write Strategy](#loggablerequestbody--tee-write-strategy)
1616
- [LoggableResponseBody — Drain-Once Strategy](#loggableresponsebody--drain-once-strategy)
17+
- [Logged body size vs. the body the consumer receives](#logged-body-size-vs-the-body-the-consumer-receives)
1718
- [Reading a Snapshot](#reading-a-snapshot)
1819
- [Internal Stream Utilities](#internal-stream-utilities)
1920
- [Concurrency Design](#concurrency-design)
@@ -240,6 +241,45 @@ retains whatever bytes were read before the failure and caches the exception:
240241
post-mortem logging that records "what we got" alongside the exception.
241242
- `captureException` surfaces the cached exception (or `null`) without triggering a drain.
242243

244+
### Logged body size vs. the body the consumer receives
245+
246+
When `HttpLogLevel.BODY_AND_HEADERS` is enabled, the instrumentation step
247+
(`DefaultInstrumentationStep` / `DefaultAsyncInstrumentationStep`) wraps the response body in a
248+
`LoggableResponseBody` bounded to `HttpInstrumentationOptions.bodyPreviewMaxBytes` (default
249+
8 KiB, `DEFAULT_BODY_PREVIEW_MAX_BYTES`). Two consequences follow that are easy to miss when
250+
reading the logs:
251+
252+
**1. The body delivered downstream can be larger than the logged preview.** The cap bounds only
253+
the in-memory *capture*, not the body. For a response larger than `bodyPreviewMaxBytes`, the
254+
step buffers the preview prefix and the wrapper then streams the full body to the consumer — it
255+
replays the captured prefix and continues from the live tail (see the bounded-capture diagram
256+
above). The preview you see in the log is a prefix; the consumer still reads every byte.
257+
258+
**2. The logged size fields measure different things.** The step emits two size-related fields
259+
on the `http.response` event, and they are not the same number for an over-cap body:
260+
261+
| Field | Source | What it reports |
262+
|---------------------------|----------------------------------------------|---------------------------------------------------------------------------------|
263+
| `response.body.size` | `loggableBody.snapshot(bodyPreviewMaxBytes)` | Size of the **captured preview** — bounded by `bodyPreviewMaxBytes` |
264+
| `response.body.preview` | the same captured bytes, decoded as UTF-8 | The preview text (a prefix for an over-cap body) |
265+
| `response.content.length` | `response.body.contentLength()` | The body's **true** length when the origin declared one (`Content-Length`); `-1` for unknown-length / streaming bodies |
266+
267+
So `response.body.size` is the *captured/preview* size, **not** necessarily the full body size.
268+
When a body exceeds the cap, `response.body.size` saturates near `bodyPreviewMaxBytes` while
269+
`response.content.length` still shows the real length. Read `content.length` (not
270+
`body.size`) when you need the full size, and treat `body.preview` as a prefix that may be
271+
truncated. The two agree only when the whole body fit within the cap — exactly the case where
272+
`contentLength()` itself returns the captured size (see **`contentLength()`** above).
273+
274+
**Streaming / unknown-length bodies (async path).** `DefaultAsyncInstrumentationStep` skips the
275+
capture entirely when `contentLength() < 0`, because the bounded drain would run on the
276+
future-completion thread and a slow producer could stall it. Such bodies stream to the consumer
277+
unwrapped, so they carry **no** `response.body.size` / `response.body.preview` fields at all —
278+
absence of those fields is expected for chunked or streaming responses, not a logging bug. The
279+
synchronous `DefaultInstrumentationStep` drains known-length and unknown-length bodies alike (it
280+
runs on the caller's thread), but the size-vs-preview distinction above applies to it just the
281+
same.
282+
243283
### Reading a Snapshot
244284

245285
The only logging output is a raw `ByteArray`:

docs/pipelines.md

Lines changed: 56 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -19,6 +19,7 @@ composable request/response processing.
1919
- [Functional Interfaces](#functional-interfaces)
2020
- [Immutable Pipeline State](#immutable-pipeline-state)
2121
- [Step Ordering and Dependencies](#step-ordering-and-dependencies)
22+
- [Why ordered stages, not nested decorators](#why-ordered-stages-not-nested-decorators)
2223
- [Usage Examples](#usage-examples)
2324
- [File Index](#file-index)
2425

@@ -476,6 +477,61 @@ Retry is **not** a request step — it lives in `ResponsePipeline.recoverySteps`
476477
the transport outcome and re-issue the request. Order recovery steps so retry runs before any
477478
status-to-exception mapping you do not want a transient failure to surface prematurely.
478479

480+
### Why ordered stages, not nested decorators
481+
482+
> This decision concerns the stage-based `http.pipeline` layer (`HttpPipeline`, `HttpStep`,
483+
> `Stage`) introduced under [Async Dispatch](#async-dispatch) and detailed in
484+
> `docs/architecture.md`, not the recovery-aware `pipeline` primitives above.
485+
486+
A common alternative to a step list is to nest cross-cutting concerns as `HttpClient`
487+
decorators — `RedirectClient(RetryClient(AuthClient(LoggingClient(transport))))` — where each
488+
wrapper calls `inner.execute(request)`. The `http.pipeline` layer deliberately uses an ordered
489+
list of `HttpStep`s keyed by a `Stage` enum instead, with five cross-cutting **pillar** stages
490+
(`REDIRECT``RETRY``AUTH``LOGGING``SERDE`, the last currently reserved/unused) that
491+
admit exactly one step each, plus the terminal `SEND` slot — also a singleton, but the transport
492+
hop itself rather than a configurable pillar. The reasons:
493+
494+
- **Deterministic, inspectable ordering.** `Stage.order` is the single source of truth for run
495+
order: lower-ordered stages run first (closer to the caller), higher ones run last (closer to
496+
the wire). `HttpPipelineBuilder.build()` flattens the stages in that fixed order, and the
497+
resulting `HttpPipeline.steps` is an unmodifiable, ordered list you can read back to see
498+
exactly what runs and in what sequence. A decorator tower encodes the same order implicitly in
499+
constructor nesting, which is harder to assemble correctly and impossible to enumerate after
500+
the fact.
501+
- **One place to reason about precedence.** Because the order lives in the `Stage` enum rather
502+
than scattered across nesting sites, "does auth run before or after the retry loop?" is
503+
answered by reading one enum, not by tracing who-wrapped-whom across call sites. Sparse `order`
504+
values (100s apart) and interleaved non-pillar stages (`PRE_AUTH`, `POST_LOGGING`, …) leave
505+
room to slot user steps at a precise point without renumbering or rebuilding the tower. The
506+
surgical `insertAfter` / `insertBefore` / `replace` edits operate against this declared order.
507+
- **Pillar-uniqueness invariants.** Redirect, retry, auth, logging, and serde are concerns you
508+
want *exactly one* of — two retry layers or two auth layers is almost always a bug. A pillar
509+
stage enforces that: installing a second step in a pillar replaces the first and emits a
510+
`pipeline.pillar.replaced` SLF4J warning (`HttpPipelineBuilder`). The shipped pillar steps go
511+
further and lock their slot at the type level — `RedirectStep`, `RetryStep`, `AuthStep`, and
512+
`InstrumentationStep` each declare `final override val stage`, so a subclass cannot relocate
513+
itself out of its pillar. Nested decorators cannot express "there is exactly one auth layer";
514+
nothing stops a caller wrapping `AuthClient` twice.
515+
- **Sync/async mirroring.** The async layer (`AsyncHttpStep`, `AsyncHttpPipeline`,
516+
`AsyncHttpPipelineBuilder`) reuses the identical `Stage` semantics and shares the staging
517+
policy via the internal `StagedSteps<S>` helper, so a step occupies the same ordered slot in
518+
both the blocking and the `CompletableFuture`-returning pipeline. Keeping order in the data
519+
(`Stage`) rather than in the control flow (constructor nesting) is what lets both runtimes
520+
share one ordering definition instead of each re-deriving it.
521+
522+
**The cost: the re-drive contract.** A decorator re-invokes downstream with a plain
523+
`inner.execute(request)`, which is hard to get wrong. A stage step instead receives a
524+
`PipelineNext` and calls `next.process()`; a step that needs to drive the downstream chain **more
525+
than once** — retry re-attempting, redirect following a hop, auth retrying after a 401 — must
526+
call `next.copy().process()` rather than reusing `next`. `PipelineNext` advances an internal
527+
cursor, so re-using the same instance resumes *past* the steps already visited on the previous
528+
pass instead of re-running the whole tail. Forgetting `copy()` fails silently — the second
529+
attempt skips steps rather than throwing — which is strictly more error-prone than a decorator's
530+
re-call. The shipped pillar steps follow the contract (`DefaultRetryStep`, `DefaultRedirectStep`,
531+
and `AuthStep` all re-drive via `next.copy().process()`); custom wrapping steps at the
532+
REDIRECT / RETRY / AUTH stages must do the same. See `PipelineNext.copy` and the `HttpStep`
533+
contract for the normative wording.
534+
479535
---
480536

481537
## Usage Examples

sdk-core/src/main/kotlin/org/dexpace/sdk/core/http/pipeline/steps/HttpInstrumentationOptions.kt

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -47,6 +47,18 @@ import org.dexpace.sdk.core.instrumentation.metrics.NoopMeter
4747
* return large downloads, server-sent events, gRPC, or chunked encodings whose size is unknown
4848
* ahead of time. [HttpLogLevel.BODY_AND_HEADERS] is intended for diagnostic builds against
4949
* small JSON/text payloads.
50+
*
51+
* Because the capture is a bounded preview, the logged `response.body.size` /
52+
* `response.body.preview` fields describe the **captured preview**, not necessarily the full
53+
* body: for a body larger than [bodyPreviewMaxBytes] the consumer still receives every byte
54+
* while those fields reflect only the preview prefix. The separate `response.content.length`
55+
* field carries the body's true length when the origin declared one. See
56+
* `docs/http-body-logging-and-concurrency.md` ("Logged body size vs. the body the consumer
57+
* receives").
58+
*
59+
* @property bodyPreviewMaxBytes Upper bound, in bytes, on the in-memory body capture under
60+
* [HttpLogLevel.BODY_AND_HEADERS]. Bounds the preview, not the body the consumer sees; the
61+
* logged `*.body.size` fields are capped by it. Defaults to [DEFAULT_BODY_PREVIEW_MAX_BYTES].
5062
*/
5163
public class HttpInstrumentationOptions
5264
@JvmOverloads

sdk-core/src/main/kotlin/org/dexpace/sdk/core/http/pipeline/steps/HttpLogLevel.kt

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,8 @@ public enum class HttpLogLevel {
2727
*
2828
* Capture is **bounded** to the configured preview size (`bodyPreviewMaxBytes`), so large
2929
* or streaming responses are not buffered whole — the caller still streams the remainder.
30+
* Consequently the logged `response.body.size` / `response.body.preview` fields reflect the
31+
* captured preview, not necessarily the full body, which can be larger than the preview.
3032
* See [HttpInstrumentationOptions] for the streaming and async-completion-thread caveats.
3133
*/
3234
BODY_AND_HEADERS,

0 commit comments

Comments
 (0)